Skip to content

[7.x] instrument task manager with apm transactions (#55356)#57390

Merged
pmuellr merged 1 commit intoelastic:7.xfrom
pmuellr:backport/7.x/pr-55356
Feb 12, 2020
Merged

[7.x] instrument task manager with apm transactions (#55356)#57390
pmuellr merged 1 commit intoelastic:7.xfrom
pmuellr:backport/7.x/pr-55356

Conversation

@pmuellr
Copy link
Contributor

@pmuellr pmuellr commented Feb 11, 2020

Backports the following commits to 7.x:

Adds some apm transaction boundaries for parts of task manager, so that
they will show up in APM as new types of transactions.  Should provide
some visibility into the ES calls made by task manager for alerting and
actions, especially under stress testing scenarios.
@pmuellr pmuellr added the backport This PR is a backport of another PR label Feb 11, 2020
@kibanamachine
Copy link
Contributor

💛 Build succeeded, but was flaky


Test Failures

Kibana Pipeline / kibana-xpack-agent / Chrome X-Pack UI Functional Tests.x-pack/test/functional/apps/rollup_job/tsvb·js.rollup job tsvb integration create rollup tsvb

Link to Jenkins

Standard Out

Failed Tests Reporter:
  - Test has failed 1 times on tracked branches: https://github.com/elastic/kibana/issues/57065

[00:00:00]       │
[00:28:27]         └-: rollup job
[00:28:27]           └-> "before all" hook
[00:29:47]           └-: tsvb integration
[00:29:47]             └-> "before all" hook
[00:29:47]             └-> "before all" hook
[00:29:47]               │ info [visualize/default] Loading "mappings.json"
[00:29:47]               │ info [visualize/default] Loading "data.json"
[00:29:47]               │ info [o.e.c.m.MetaDataDeleteIndexService] [kibana-ci-immutable-debian-tests-xl-1581463463933479829] [.kibana_2/okCQtEZNSVa6kdHdI9cvzQ] deleting index
[00:29:47]               │ info [o.e.c.m.MetaDataDeleteIndexService] [kibana-ci-immutable-debian-tests-xl-1581463463933479829] [.kibana_1/ap-YHco3SrC7M0sqdDFbAQ] deleting index
[00:29:47]               │ info [visualize/default] Deleted existing index [".kibana_2",".kibana_1"]
[00:29:47]               │ info [o.e.c.m.MetaDataCreateIndexService] [kibana-ci-immutable-debian-tests-xl-1581463463933479829] [.kibana] creating index, cause [api], templates [], shards [1]/[0], mappings [doc]
[00:29:47]               │ info [visualize/default] Created index ".kibana"
[00:29:47]               │ debg [visualize/default] ".kibana" settings {"index":{"number_of_shards":"1","auto_expand_replicas":"0-1","number_of_replicas":"0"}}
[00:29:47]               │ info [o.e.c.m.MetaDataCreateIndexService] [kibana-ci-immutable-debian-tests-xl-1581463463933479829] [metricbeat-7] creating index, cause [auto(bulk api)], templates [], shards [1]/[1], mappings []
[00:29:47]               │ info [o.e.c.m.MetaDataMappingService] [kibana-ci-immutable-debian-tests-xl-1581463463933479829] [metricbeat-7/tZLga3U0T9u6oBbLdaLiTw] create_mapping [_doc]
[00:29:47]               │ info [visualize/default] Indexed 8 docs into ".kibana"
[00:29:47]               │ info [visualize/default] Indexed 1 docs into "metricbeat-7"
[00:29:48]               │ info Creating index .kibana_2.
[00:29:48]               │ info [o.e.c.m.MetaDataCreateIndexService] [kibana-ci-immutable-debian-tests-xl-1581463463933479829] [.kibana_2] creating index, cause [api], templates [], shards [1]/[1], mappings [_doc]
[00:29:48]               │ info [o.e.c.r.a.AllocationService] [kibana-ci-immutable-debian-tests-xl-1581463463933479829] updating number_of_replicas to [0] for indices [.kibana_2]
[00:29:49]               │ info Reindexing .kibana to .kibana_1
[00:29:49]               │ info [o.e.c.m.MetaDataCreateIndexService] [kibana-ci-immutable-debian-tests-xl-1581463463933479829] [.kibana_1] creating index, cause [api], templates [], shards [1]/[1], mappings [_doc]
[00:29:49]               │ info [o.e.c.r.a.AllocationService] [kibana-ci-immutable-debian-tests-xl-1581463463933479829] updating number_of_replicas to [0] for indices [.kibana_1]
[00:29:49]               │ info [o.e.t.LoggingTaskListener] [kibana-ci-immutable-debian-tests-xl-1581463463933479829] 68488 finished with response BulkByScrollResponse[took=87.9ms,timed_out=false,sliceId=null,updated=0,created=8,deleted=0,batches=1,versionConflicts=0,noops=0,retries=0,throttledUntil=0s,bulk_failures=[],search_failures=[]]
[00:29:49]               │ info [o.e.c.m.MetaDataDeleteIndexService] [kibana-ci-immutable-debian-tests-xl-1581463463933479829] [.kibana/qEyjl7wPRhy57BuBd9t20A] deleting index
[00:29:49]               │ info Migrating .kibana_1 saved objects to .kibana_2
[00:29:49]               │ debg Migrating saved objects space:default, index-pattern:metricbeat-*, custom-space:index-pattern:metricbeat-*, index-pattern:logstash-*, custom_space:index-pattern:logstash-*, visualization:i-exist, custom_space:visualization:i-exist, query:okjpgs
[00:29:49]               │ info [o.e.c.m.MetaDataMappingService] [kibana-ci-immutable-debian-tests-xl-1581463463933479829] [.kibana_2/idkiVvz7SCqq8Leg5sOaLA] update_mapping [_doc]
[00:29:49]               │ info [o.e.c.m.MetaDataMappingService] [kibana-ci-immutable-debian-tests-xl-1581463463933479829] [.kibana_2/idkiVvz7SCqq8Leg5sOaLA] update_mapping [_doc]
[00:29:49]               │ info [o.e.c.m.MetaDataMappingService] [kibana-ci-immutable-debian-tests-xl-1581463463933479829] [.kibana_2/idkiVvz7SCqq8Leg5sOaLA] update_mapping [_doc]
[00:29:49]               │ info Pointing alias .kibana to .kibana_2.
[00:29:49]               │ info Finished in 762ms.
[00:29:49]               │ debg applying update to kibana config: {"accessibility:disableAnimations":true,"dateFormat:tz":"UTC"}
[00:29:49]               │ info [o.e.c.m.MetaDataMappingService] [kibana-ci-immutable-debian-tests-xl-1581463463933479829] [.kibana_2/idkiVvz7SCqq8Leg5sOaLA] update_mapping [_doc]
[00:29:50]             └-> create rollup tsvb
[00:29:50]               └-> "before each" hook: global before each
[00:29:50]               │ info [o.e.c.m.MetaDataCreateIndexService] [kibana-ci-immutable-debian-tests-xl-1581463463933479829] [rollup-source-data] creating index, cause [auto(bulk api)], templates [], shards [1]/[1], mappings []
[00:29:51]               │ info [o.e.c.m.MetaDataMappingService] [kibana-ci-immutable-debian-tests-xl-1581463463933479829] [rollup-source-data/_zYTobd7TMCACsJO-LFkYw] create_mapping [_doc]
[00:29:51]               │ info [o.e.c.m.MetaDataCreateIndexService] [kibana-ci-immutable-debian-tests-xl-1581463463933479829] [rollup-target-data] creating index, cause [api], templates [], shards [1]/[1], mappings [_doc]
[00:29:51]               │ debg navigating to visualize url: http://localhost:6121/app/kibana#/visualize
[00:29:51]               │ debg Navigate to: http://localhost:6121/app/kibana#/visualize
[00:29:51]               │ info [o.e.x.r.j.RollupJobTask] [kibana-ci-immutable-debian-tests-xl-1581463463933479829] Rollup job [tsvb-test-rollup-job-1581465428769] created.
[00:29:51]               │ info [o.e.c.m.MetaDataMappingService] [kibana-ci-immutable-debian-tests-xl-1581463463933479829] [rollup-target-data/84ZKIBgvQ7C6XJuDAU_cSA] update_mapping [_doc]
[00:29:51]               │ debg ... sleep(700) start
[00:29:51]               │ debg browser[INFO] http://localhost:6121/app/kibana?_t=1581467221839#/visualize 350 Refused to execute inline script because it violates the following Content Security Policy directive: "script-src 'unsafe-eval' 'self'". Either the 'unsafe-inline' keyword, a hash ('sha256-P5polb1UreUSOe5V/Pv7tc+yeZuJXiOi/3fqhGsU7BE='), or a nonce ('nonce-...') is required to enable inline execution.
[00:29:51]               │
[00:29:51]               │ debg browser[INFO] http://localhost:6121/bundles/app/kibana/bootstrap.js 8:19 "^ A single error about an inline script not firing due to content security policy is expected!"
[00:29:51]               │ debg ... sleep(700) end
[00:29:51]               │ debg returned from get, calling refresh
[00:29:52]               │ debg browser[INFO] http://localhost:6121/app/kibana?_t=1581467221839#/visualize 350 Refused to execute inline script because it violates the following Content Security Policy directive: "script-src 'unsafe-eval' 'self'". Either the 'unsafe-inline' keyword, a hash ('sha256-P5polb1UreUSOe5V/Pv7tc+yeZuJXiOi/3fqhGsU7BE='), or a nonce ('nonce-...') is required to enable inline execution.
[00:29:52]               │
[00:29:52]               │ debg browser[INFO] http://localhost:6121/bundles/app/kibana/bootstrap.js 8:19 "^ A single error about an inline script not firing due to content security policy is expected!"
[00:29:52]               │ debg currentUrl = http://localhost:6121/app/kibana#/visualize
[00:29:52]               │          appUrl = http://localhost:6121/app/kibana#/visualize
[00:29:52]               │ debg Find.findByCssSelector('[data-test-subj="kibanaChrome"]') with timeout=60000
[00:29:57]               │ debg TestSubjects.find(kibanaChrome)
[00:29:57]               │ debg Find.findByCssSelector('[data-test-subj="kibanaChrome"]') with timeout=10000
[00:29:57]               │ debg browser[INFO] http://localhost:6121/built_assets/dlls/vendors_3.bundle.dll.js 488:139970 "INFO: 2020-02-12T00:27:06Z
[00:29:57]               │        Adding connection to http://localhost:6121/elasticsearch
[00:29:57]               │
[00:29:57]               │      "
[00:29:57]               │ debg ... sleep(501) start
[00:29:57]               │ info [o.e.c.m.MetaDataMappingService] [kibana-ci-immutable-debian-tests-xl-1581463463933479829] [.kibana_2/idkiVvz7SCqq8Leg5sOaLA] update_mapping [_doc]
[00:29:57]               │ debg ... sleep(501) end
[00:29:57]               │ debg in navigateTo url = http://localhost:6121/app/kibana#/visualize?_g=(refreshInterval:(pause:!t,value:0),time:(from:now-15m,to:now))
[00:29:57]               │ debg TestSubjects.exists(statusPageContainer)
[00:29:57]               │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="statusPageContainer"]') with timeout=2500
[00:30:00]               │ debg --- retry.tryForTime error: [data-test-subj="statusPageContainer"] is not displayed
[00:30:00]               │ debg TestSubjects.exists(newItemButton)
[00:30:00]               │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="newItemButton"]') with timeout=2500
[00:30:00]               │ debg TestSubjects.click(newItemButton)
[00:30:00]               │ debg Find.clickByCssSelector('[data-test-subj="newItemButton"]') with timeout=10000
[00:30:00]               │ debg Find.findByCssSelector('[data-test-subj="newItemButton"]') with timeout=10000
[00:30:01]               │ debg TestSubjects.find(visNewDialogTypes)
[00:30:01]               │ debg Find.findByCssSelector('[data-test-subj="visNewDialogTypes"]') with timeout=10000
[00:30:01]               │ debg TestSubjects.click(visType-metrics)
[00:30:01]               │ debg Find.clickByCssSelector('[data-test-subj="visType-metrics"]') with timeout=10000
[00:30:01]               │ debg Find.findByCssSelector('[data-test-subj="visType-metrics"]') with timeout=10000
[00:30:01]               │ debg isGlobalLoadingIndicatorVisible
[00:30:01]               │ debg TestSubjects.exists(globalLoadingIndicator)
[00:30:01]               │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="globalLoadingIndicator"]') with timeout=1500
[00:30:03]               │ debg --- retry.tryForTime error: [data-test-subj="globalLoadingIndicator"] is not displayed
[00:30:03]               │ debg TestSubjects.exists(globalLoadingIndicator-hidden)
[00:30:03]               │ debg Find.existsByCssSelector('[data-test-subj="globalLoadingIndicator-hidden"]') with timeout=100000
[00:30:03]               │ debg TestSubjects.exists(tvbVisEditor)
[00:30:03]               │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="tvbVisEditor"]') with timeout=10000
[00:30:03]               │ debg openQuickSelectTimeMenu
[00:30:03]               │ debg TestSubjects.exists(superDatePickerQuickMenu)
[00:30:03]               │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="superDatePickerQuickMenu"]') with timeout=2500
[00:30:06]               │ debg --- retry.tryForTime error: [data-test-subj="superDatePickerQuickMenu"] is not displayed
[00:30:06]               │ debg opening quick select menu
[00:30:06]               │ debg TestSubjects.click(superDatePickerToggleQuickMenuButton)
[00:30:06]               │ debg Find.clickByCssSelector('[data-test-subj="superDatePickerToggleQuickMenuButton"]') with timeout=10000
[00:30:06]               │ debg Find.findByCssSelector('[data-test-subj="superDatePickerToggleQuickMenuButton"]') with timeout=10000
[00:30:07]               │ debg TestSubjects.click(superDatePickerCommonlyUsed_Last_24 hours)
[00:30:07]               │ debg Find.clickByCssSelector('[data-test-subj="superDatePickerCommonlyUsed_Last_24 hours"]') with timeout=10000
[00:30:07]               │ debg Find.findByCssSelector('[data-test-subj="superDatePickerCommonlyUsed_Last_24 hours"]') with timeout=10000
[00:30:07]               │ debg TestSubjects.find(metricTsvbTypeBtn)
[00:30:07]               │ debg Find.findByCssSelector('[data-test-subj="metricTsvbTypeBtn"]') with timeout=10000
[00:30:07]               │ debg TestSubjects.exists(tsvbMetricValue)
[00:30:07]               │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="tsvbMetricValue"]') with timeout=10000
[00:30:08]               │ debg TestSubjects.click(metricEditorPanelOptionsBtn)
[00:30:08]               │ debg Find.clickByCssSelector('[data-test-subj="metricEditorPanelOptionsBtn"]') with timeout=10000
[00:30:08]               │ debg Find.findByCssSelector('[data-test-subj="metricEditorPanelOptionsBtn"]') with timeout=10000
[00:30:08]               │ debg isGlobalLoadingIndicatorVisible
[00:30:08]               │ debg TestSubjects.exists(globalLoadingIndicator)
[00:30:08]               │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="globalLoadingIndicator"]') with timeout=1500
[00:30:09]               │ debg --- retry.tryForTime error: [data-test-subj="globalLoadingIndicator"] is not displayed
[00:30:10]               │ debg TestSubjects.exists(globalLoadingIndicator-hidden)
[00:30:10]               │ debg Find.existsByCssSelector('[data-test-subj="globalLoadingIndicator-hidden"]') with timeout=100000
[00:30:10]               │ debg TestSubjects.find(metricsIndexPatternInput)
[00:30:10]               │ debg Find.findByCssSelector('[data-test-subj="metricsIndexPatternInput"]') with timeout=10000
[00:30:10]               │ debg isGlobalLoadingIndicatorVisible
[00:30:10]               │ debg TestSubjects.exists(globalLoadingIndicator)
[00:30:10]               │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="globalLoadingIndicator"]') with timeout=1500
[00:30:12]               │ debg --- retry.tryForTime error: [data-test-subj="globalLoadingIndicator"] is not displayed
[00:30:12]               │ debg TestSubjects.exists(globalLoadingIndicator-hidden)
[00:30:12]               │ debg Find.existsByCssSelector('[data-test-subj="globalLoadingIndicator-hidden"]') with timeout=100000
[00:30:12]               │ debg TestSubjects.find(metricsIndexPatternInterval)
[00:30:12]               │ debg Find.findByCssSelector('[data-test-subj="metricsIndexPatternInterval"]') with timeout=10000
[00:30:12]               │ debg isGlobalLoadingIndicatorVisible
[00:30:12]               │ debg TestSubjects.exists(globalLoadingIndicator)
[00:30:12]               │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="globalLoadingIndicator"]') with timeout=1500
[00:30:14]               │ debg --- retry.tryForTime error: [data-test-subj="globalLoadingIndicator"] is not displayed
[00:30:14]               │ debg TestSubjects.exists(globalLoadingIndicator-hidden)
[00:30:14]               │ debg Find.existsByCssSelector('[data-test-subj="globalLoadingIndicator-hidden"]') with timeout=100000
[00:30:14]               │ debg TestSubjects.find(metricsDropLastBucket-no)
[00:30:14]               │ debg Find.findByCssSelector('[data-test-subj="metricsDropLastBucket-no"]') with timeout=10000
[00:30:14]               │ debg isGlobalLoadingIndicatorVisible
[00:30:14]               │ debg TestSubjects.exists(globalLoadingIndicator)
[00:30:14]               │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="globalLoadingIndicator"]') with timeout=1500
[00:30:16]               │ debg --- retry.tryForTime error: [data-test-subj="globalLoadingIndicator"] is not displayed
[00:30:17]               │ debg TestSubjects.exists(globalLoadingIndicator-hidden)
[00:30:17]               │ debg Find.existsByCssSelector('[data-test-subj="globalLoadingIndicator-hidden"]') with timeout=100000
[00:30:17]               │ debg ... sleep(3000) start
[00:30:20]               │ debg ... sleep(3000) end
[00:30:20]               │ debg Waiting up to 20000ms for rendering count to stabilize...
[00:30:20]               │ debg TestSubjects.find(visualizationLoader)
[00:30:20]               │ debg Find.findByCssSelector('[data-test-subj="visualizationLoader"]') with timeout=10000
[00:30:20]               │ debg -- firstCount=7
[00:30:20]               │ debg ... sleep(1000) start
[00:30:21]               │ debg ... sleep(1000) end
[00:30:21]               │ debg TestSubjects.find(visualizationLoader)
[00:30:21]               │ debg Find.findByCssSelector('[data-test-subj="visualizationLoader"]') with timeout=10000
[00:30:21]               │ debg -- secondCount=7
[00:30:21]               │ debg Find.findByCssSelector('.tvbVisMetric__value--primary') with timeout=10000
[00:30:21]               │ info Taking screenshot "/dev/shm/workspace/kibana/x-pack/test/functional/screenshots/failure/rollup job tsvb integration create rollup tsvb.png"
[00:30:21]               │ info Current URL is: http://localhost:6121/app/kibana#/visualize/create?type=metrics&_g=(refreshInterval:(pause:!t,value:0),time:(from:now-24h,to:now))&_a=(filters:!(),linked:!f,query:(language:kuery,query:%27%27),uiState:(),vis:(aggs:!(),params:(axis_formatter:number,axis_position:left,axis_scale:normal,background_color_rules:!((id:%276d0722c0-4d2e-11ea-98c0-110e3d78a33e%27)),default_index_pattern:%27metricbeat-*%27,default_timefield:%27@timestamp%27,drop_last_bucket:0,id:%2761ca57f0-469d-11e7-af02-69e470af7417%27,index_pattern:rollup-target-data,interval:%271d%27,isModelInvalid:!f,series:!((axis_position:right,chart_type:line,color:%2368BC00,fill:0.5,formatter:number,id:%2761ca57f1-469d-11e7-af02-69e470af7417%27,line_width:1,metrics:!((id:%2761ca57f2-469d-11e7-af02-69e470af7417%27,type:count)),point_size:1,separate_axis:0,split_mode:everything,stacked:none)),show_grid:1,show_legend:1,time_field:%27%27,type:metric),title:%27%27,type:metrics))
[00:30:21]               │ info Saving page source to: /dev/shm/workspace/kibana/x-pack/test/functional/failure_debug/html/rollup job tsvb integration create rollup tsvb.html
[00:30:21]               └- ✖ fail: "rollup job tsvb integration create rollup tsvb"
[00:30:21]               │

Stack Trace

{ Error: expected '0' to sort of equal '3'
    at Assertion.assert (/dev/shm/workspace/kibana/packages/kbn-expect/expect.js:100:11)
    at Assertion.eql (/dev/shm/workspace/kibana/packages/kbn-expect/expect.js:244:8)
    at Context.it (test/functional/apps/rollup_job/tsvb.js:90:27)
    at process._tickCallback (internal/process/next_tick.js:68:7) actual: '0', expected: '3', showDiff: true }

To update your PR or re-run it, just comment with:
@elasticmachine merge upstream

@pmuellr pmuellr merged commit f0cffca into elastic:7.x Feb 12, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

backport This PR is a backport of another PR

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants