Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[APM] Add custom spans around async operations #90403

Merged
merged 21 commits into from
Feb 12, 2021

Conversation

dgieselaar
Copy link
Member

@dgieselaar dgieselaar commented Feb 5, 2021

Closes #86460.

Provides a withSpan utility that wraps an async operation in a custom span.

As almost every API call consists of multiple consecutive or parallel ES requests to various ES endpoints, it's hard to see from a trace waterfall what's triggering an ES request and what the intent is. There are also some issues in the Node.js agent where the semantics around span relationships (parent-child or sibling) are not always clear and might not work as expected.

To workaround these issues the withSpan helper starts a span, and creates a new async context for the async operation we want to track, essentially isolating it from other async operations, in order to have sane parent-child relationships.

See also:
elastic/apm-agent-nodejs#1964
elastic/apm-agent-nodejs#1963
elastic/apm-agent-nodejs#1889

Here's how a /api/apm/services transaction looks without the custom instrumentation:

image

And here's with custom instrumentation (collapsing the app spans):
image

@dgieselaar dgieselaar added release_note:skip Skip the PR/issue when compiling release notes v7.12.0 labels Feb 5, 2021
@dgieselaar dgieselaar marked this pull request as ready for review February 8, 2021 10:36
@dgieselaar dgieselaar requested a review from a team as a code owner February 8, 2021 10:36
@dgieselaar
Copy link
Member Author

@elasticmachine merge upstream

@botelastic botelastic bot added the Team:APM All issues that need APM UI Team support label Feb 8, 2021
@elasticmachine
Copy link
Contributor

Pinging @elastic/apm-ui (Team:apm)

@kibanamachine
Copy link
Contributor

💛 Build succeeded, but was flaky


Test Failures

Kibana Pipeline / general / Chrome X-Pack UI Functional Tests.x-pack/test/functional/apps/ingest_pipelines/feature_controls/ingest_pipelines_security·ts.Ingest pipelines app feature controls security global dashboard all with ingest_pipelines_user should render the "Ingest" section with ingest pipelines

Link to Jenkins

Standard Out

Failed Tests Reporter:
  - Test has not failed recently on tracked branches

[00:00:00]       │
[00:08:54]         └-: Ingest pipelines app
[00:08:54]           └-> "before all" hook in "Ingest pipelines app"
[00:08:54]           └-: feature controls
[00:08:54]             └-> "before all" hook in "feature controls"
[00:08:54]             └-: security
[00:08:54]               └-> "before all" hook in "security"
[00:08:54]               └-> "before all" hook in "security"
[00:08:54]                 │ info [empty_kibana] Loading "mappings.json"
[00:08:54]                 │ info [o.e.c.m.MetadataDeleteIndexService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] [.kibana_task_manager_8.0.0_001/JL9QzpUET-iFAKhIv24xLA] deleting index
[00:08:54]                 │ info [o.e.c.m.MetadataDeleteIndexService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] [.kibana_pre6.5.0_001/O9i_xDYxRAavlBaiELQieQ] deleting index
[00:08:54]                 │ info [o.e.c.m.MetadataDeleteIndexService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] [.kibana_8.0.0_001/zjERnm9KQPm1RjYnmI6LiQ] deleting index
[00:08:54]                 │ info [empty_kibana] Deleted existing index ".kibana_8.0.0_001"
[00:08:54]                 │ info [empty_kibana] Deleted existing index ".kibana_task_manager_8.0.0_001"
[00:08:54]                 │ info [empty_kibana] Deleted existing index ".kibana_pre6.5.0_001"
[00:08:54]                 │ info [o.e.c.m.MetadataCreateIndexService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] [.kibana] creating index, cause [api], templates [], shards [1]/[1]
[00:08:54]                 │ info [empty_kibana] Created index ".kibana"
[00:08:54]                 │ debg [empty_kibana] ".kibana" settings {"index":{"number_of_replicas":"1","number_of_shards":"1"}}
[00:08:55]                 │ info [o.e.c.m.MetadataMappingService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] [.kibana/nVej_tGQT9y7bltE5eFYEg] update_mapping [_doc]
[00:08:55]                 │ debg Migrating saved objects
[00:08:55]                 │ proc [kibana]   log   [12:17:00.264] [info][savedobjects-service] [.kibana_task_manager] INIT -> CREATE_NEW_TARGET
[00:08:55]                 │ proc [kibana]   log   [12:17:00.270] [info][savedobjects-service] [.kibana] INIT -> LEGACY_SET_WRITE_BLOCK
[00:08:55]                 │ info [o.e.c.m.MetadataCreateIndexService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] [.kibana_task_manager_8.0.0_001] creating index, cause [api], templates [], shards [1]/[1]
[00:08:55]                 │ info [o.e.c.r.a.AllocationService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] updating number_of_replicas to [0] for indices [.kibana_task_manager_8.0.0_001]
[00:08:55]                 │ info [o.e.c.m.MetadataIndexStateService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] adding block write to indices [[.kibana/nVej_tGQT9y7bltE5eFYEg]]
[00:08:55]                 │ info [o.e.c.m.MetadataIndexStateService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] completed adding block write to indices [.kibana]
[00:08:55]                 │ proc [kibana]   log   [12:17:00.330] [info][savedobjects-service] [.kibana_task_manager] CREATE_NEW_TARGET -> MARK_VERSION_INDEX_READY
[00:08:55]                 │ proc [kibana]   log   [12:17:00.347] [info][savedobjects-service] [.kibana] LEGACY_SET_WRITE_BLOCK -> LEGACY_CREATE_REINDEX_TARGET
[00:08:55]                 │ proc [kibana]   log   [12:17:00.363] [info][savedobjects-service] [.kibana_task_manager] MARK_VERSION_INDEX_READY -> DONE
[00:08:55]                 │ proc [kibana]   log   [12:17:00.364] [info][savedobjects-service] [.kibana_task_manager] Migration completed after 102ms
[00:08:55]                 │ info [o.e.c.m.MetadataCreateIndexService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] [.kibana_pre6.5.0_001] creating index, cause [api], templates [], shards [1]/[1]
[00:08:55]                 │ info [o.e.c.r.a.AllocationService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] updating number_of_replicas to [0] for indices [.kibana_pre6.5.0_001]
[00:08:55]                 │ proc [kibana]   log   [12:17:00.415] [info][savedobjects-service] [.kibana] LEGACY_CREATE_REINDEX_TARGET -> LEGACY_REINDEX
[00:08:55]                 │ info [o.e.t.LoggingTaskListener] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] 19929 finished with response BulkByScrollResponse[took=1.9ms,timed_out=false,sliceId=null,updated=0,created=0,deleted=0,batches=0,versionConflicts=0,noops=0,retries=0,throttledUntil=0s,bulk_failures=[],search_failures=[]]
[00:08:55]                 │ proc [kibana]   log   [12:17:00.421] [info][savedobjects-service] [.kibana] LEGACY_REINDEX -> LEGACY_REINDEX_WAIT_FOR_TASK
[00:08:55]                 │ proc [kibana]   log   [12:17:00.427] [info][savedobjects-service] [.kibana] LEGACY_REINDEX_WAIT_FOR_TASK -> LEGACY_DELETE
[00:08:55]                 │ info [o.e.c.m.MetadataDeleteIndexService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] [.kibana/nVej_tGQT9y7bltE5eFYEg] deleting index
[00:08:55]                 │ proc [kibana]   log   [12:17:00.463] [info][savedobjects-service] [.kibana] LEGACY_DELETE -> SET_SOURCE_WRITE_BLOCK
[00:08:55]                 │ info [o.e.c.m.MetadataIndexStateService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] adding block write to indices [[.kibana_pre6.5.0_001/cdMmN4noS-qSgdF9nCIVWg]]
[00:08:55]                 │ info [o.e.c.m.MetadataIndexStateService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] completed adding block write to indices [.kibana_pre6.5.0_001]
[00:08:55]                 │ proc [kibana]   log   [12:17:00.500] [info][savedobjects-service] [.kibana] SET_SOURCE_WRITE_BLOCK -> CREATE_REINDEX_TEMP
[00:08:55]                 │ info [o.e.c.m.MetadataCreateIndexService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] [.kibana_8.0.0_reindex_temp] creating index, cause [api], templates [], shards [1]/[1]
[00:08:55]                 │ info [o.e.c.r.a.AllocationService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] updating number_of_replicas to [0] for indices [.kibana_8.0.0_reindex_temp]
[00:08:55]                 │ info [o.e.c.r.a.AllocationService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] current.health="GREEN" message="Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[.kibana_8.0.0_reindex_temp][0]]])." previous.health="YELLOW" reason="shards started [[.kibana_8.0.0_reindex_temp][0]]"
[00:08:55]                 │ proc [kibana]   log   [12:17:00.553] [info][savedobjects-service] [.kibana] CREATE_REINDEX_TEMP -> REINDEX_SOURCE_TO_TEMP
[00:08:55]                 │ info [o.e.t.LoggingTaskListener] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] 19958 finished with response BulkByScrollResponse[took=1.7ms,timed_out=false,sliceId=null,updated=0,created=0,deleted=0,batches=0,versionConflicts=0,noops=0,retries=0,throttledUntil=0s,bulk_failures=[],search_failures=[]]
[00:08:55]                 │ proc [kibana]   log   [12:17:00.561] [info][savedobjects-service] [.kibana] REINDEX_SOURCE_TO_TEMP -> REINDEX_SOURCE_TO_TEMP_WAIT_FOR_TASK
[00:08:55]                 │ proc [kibana]   log   [12:17:00.566] [info][savedobjects-service] [.kibana] REINDEX_SOURCE_TO_TEMP_WAIT_FOR_TASK -> SET_TEMP_WRITE_BLOCK
[00:08:55]                 │ info [o.e.c.m.MetadataIndexStateService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] adding block write to indices [[.kibana_8.0.0_reindex_temp/odFFiAjxQ-mAq-l0QjzbRA]]
[00:08:55]                 │ info [o.e.c.m.MetadataIndexStateService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] completed adding block write to indices [.kibana_8.0.0_reindex_temp]
[00:08:55]                 │ proc [kibana]   log   [12:17:00.602] [info][savedobjects-service] [.kibana] SET_TEMP_WRITE_BLOCK -> CLONE_TEMP_TO_TARGET
[00:08:55]                 │ info [o.e.c.m.MetadataCreateIndexService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] applying create index request using existing index [.kibana_8.0.0_reindex_temp] metadata
[00:08:55]                 │ info [o.e.c.m.MetadataCreateIndexService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] [.kibana_8.0.0_001] creating index, cause [clone_index], templates [], shards [1]/[1]
[00:08:55]                 │ info [o.e.c.r.a.AllocationService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] updating number_of_replicas to [0] for indices [.kibana_8.0.0_001]
[00:08:55]                 │ info [o.e.c.m.MetadataMappingService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] [.kibana_8.0.0_001/hvnRwhuyS9-nlG2Vlir7MA] create_mapping
[00:08:55]                 │ info [o.e.c.r.a.AllocationService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] current.health="GREEN" message="Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[.kibana_8.0.0_001][0]]])." previous.health="YELLOW" reason="shards started [[.kibana_8.0.0_001][0]]"
[00:08:55]                 │ proc [kibana]   log   [12:17:00.690] [info][savedobjects-service] [.kibana] CLONE_TEMP_TO_TARGET -> OUTDATED_DOCUMENTS_SEARCH
[00:08:55]                 │ proc [kibana]   log   [12:17:00.699] [info][savedobjects-service] [.kibana] OUTDATED_DOCUMENTS_SEARCH -> UPDATE_TARGET_MAPPINGS
[00:08:55]                 │ info [o.e.c.m.MetadataMappingService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] [.kibana_8.0.0_001/hvnRwhuyS9-nlG2Vlir7MA] update_mapping [_doc]
[00:08:55]                 │ info [o.e.t.LoggingTaskListener] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] 19994 finished with response BulkByScrollResponse[took=1.5ms,timed_out=false,sliceId=null,updated=0,created=0,deleted=0,batches=0,versionConflicts=0,noops=0,retries=0,throttledUntil=0s,bulk_failures=[],search_failures=[]]
[00:08:55]                 │ proc [kibana]   log   [12:17:00.760] [info][savedobjects-service] [.kibana] UPDATE_TARGET_MAPPINGS -> UPDATE_TARGET_MAPPINGS_WAIT_FOR_TASK
[00:08:55]                 │ proc [kibana]   log   [12:17:00.766] [info][savedobjects-service] [.kibana] UPDATE_TARGET_MAPPINGS_WAIT_FOR_TASK -> MARK_VERSION_INDEX_READY
[00:08:55]                 │ info [o.e.c.m.MetadataDeleteIndexService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] [.kibana_8.0.0_reindex_temp/odFFiAjxQ-mAq-l0QjzbRA] deleting index
[00:08:55]                 │ proc [kibana]   log   [12:17:00.803] [info][savedobjects-service] [.kibana] MARK_VERSION_INDEX_READY -> DONE
[00:08:55]                 │ proc [kibana]   log   [12:17:00.803] [info][savedobjects-service] [.kibana] Migration completed after 543ms
[00:08:55]                 │ debg [empty_kibana] Migrated Kibana index after loading Kibana data
[00:08:55]                 │ debg [empty_kibana] Ensured that default space exists in .kibana
[00:08:55]                 │ debg applying update to kibana config: {"accessibility:disableAnimations":true,"dateFormat:tz":"UTC","visualization:visualize:legacyChartsLibrary":true}
[00:08:55]                 │ info [o.e.c.m.MetadataMappingService] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] [.kibana_8.0.0_001/hvnRwhuyS9-nlG2Vlir7MA] update_mapping [_doc]
[00:08:57]                 │ debg navigating to home url: http://localhost:61131/app/home#/
[00:08:57]                 │ debg navigate to: http://localhost:61131/app/home#/
[00:08:57]                 │ debg browser[INFO] http://localhost:61131/app/home?_t=1612786622650#/ 341 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:08:57]                 │
[00:08:57]                 │ debg browser[INFO] http://localhost:61131/bootstrap.js 42:19 "^ A single error about an inline script not firing due to content security policy is expected!"
[00:08:57]                 │ debg ... sleep(700) start
[00:08:58]                 │ debg ... sleep(700) end
[00:08:58]                 │ debg returned from get, calling refresh
[00:08:58]                 │ERROR browser[SEVERE] http://localhost:61131/40227/bundles/core/core.entry.js 12:158464 TypeError: Failed to fetch
[00:08:58]                 │          at fetch_Fetch.fetchResponse (http://localhost:61131/40227/bundles/core/core.entry.js:6:32451)
[00:08:58]                 │          at async interceptResponse (http://localhost:61131/40227/bundles/core/core.entry.js:6:28637)
[00:08:58]                 │          at async http://localhost:61131/40227/bundles/core/core.entry.js:6:31117
[00:08:58]                 │ debg browser[INFO] http://localhost:61131/app/home?_t=1612786622650#/ 341 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:08:58]                 │
[00:08:58]                 │ debg browser[INFO] http://localhost:61131/bootstrap.js 42:19 "^ A single error about an inline script not firing due to content security policy is expected!"
[00:08:59]                 │ debg currentUrl = http://localhost:61131/app/home#/
[00:08:59]                 │          appUrl = http://localhost:61131/app/home#/
[00:08:59]                 │ debg TestSubjects.find(kibanaChrome)
[00:08:59]                 │ debg Find.findByCssSelector('[data-test-subj="kibanaChrome"]') with timeout=60000
[00:08:59]                 │ debg ... sleep(501) start
[00:08:59]                 │ debg ... sleep(501) end
[00:08:59]                 │ debg in navigateTo url = http://localhost:61131/app/home#/
[00:08:59]                 │ debg TestSubjects.exists(statusPageContainer)
[00:08:59]                 │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="statusPageContainer"]') with timeout=2500
[00:09:02]                 │ debg --- retry.tryForTime error: [data-test-subj="statusPageContainer"] is not displayed
[00:09:17]               └-: global dashboard all with ingest_pipelines_user
[00:09:17]                 └-> "before all" hook for "should show the Stack Management nav link"
[00:09:17]                 └-> "before all" hook for "should show the Stack Management nav link"
[00:09:17]                   │ debg set roles = global_dashboard_all,ingest_pipelines_user
[00:09:17]                   │ debg creating user test_user
[00:09:17]                   │ info [o.e.x.s.a.u.TransportPutUserAction] [kibana-ci-immutable-ubuntu-16-tests-xxl-1612783359973032407] updated user [test_user]
[00:09:17]                   │ debg created user test_user
[00:09:17]                   │ debg TestSubjects.exists(kibanaChrome)
[00:09:17]                   │ debg Find.existsByCssSelector('[data-test-subj="kibanaChrome"]') with timeout=2500
[00:09:17]                   │ debg TestSubjects.find(kibanaChrome)
[00:09:17]                   │ debg Find.findByCssSelector('[data-test-subj="kibanaChrome"]') with timeout=100000
[00:09:17]                   │ debg browser[INFO] http://localhost:61131/app/management?_t=1612786635272 341 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:09:17]                   │
[00:09:17]                   │ debg browser[INFO] http://localhost:61131/bootstrap.js 42:19 "^ A single error about an inline script not firing due to content security policy is expected!"
[00:09:18]                 └-> should show the Stack Management nav link
[00:09:18]                   └-> "before each" hook: global before each for "should show the Stack Management nav link"
[00:09:18]                   │ debg isGlobalLoadingIndicatorVisible
[00:09:18]                   │ debg TestSubjects.exists(globalLoadingIndicator)
[00:09:18]                   │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="globalLoadingIndicator"]') with timeout=1500
[00:09:20]                   │ debg --- retry.tryForTime error: [data-test-subj="globalLoadingIndicator"] is not displayed
[00:09:20]                   │ debg TestSubjects.exists(globalLoadingIndicator-hidden)
[00:09:20]                   │ debg Find.existsByCssSelector('[data-test-subj="globalLoadingIndicator-hidden"]') with timeout=100000
[00:09:20]                   │ debg TestSubjects.exists(collapsibleNav)
[00:09:20]                   │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="collapsibleNav"]') with timeout=2500
[00:09:23]                   │ debg --- retry.tryForTime error: [data-test-subj="collapsibleNav"] is not displayed
[00:09:23]                   │ debg TestSubjects.click(toggleNavButton)
[00:09:23]                   │ debg Find.clickByCssSelector('[data-test-subj="toggleNavButton"]') with timeout=10000
[00:09:23]                   │ debg Find.findByCssSelector('[data-test-subj="toggleNavButton"]') with timeout=10000
[00:09:23]                   │ debg TestSubjects.find(collapsibleNav)
[00:09:23]                   │ debg Find.findByCssSelector('[data-test-subj="collapsibleNav"]') with timeout=10000
[00:09:23]                   │ debg Find.existsByCssSelector('[data-test-subj=collapsibleNav] > button') with timeout=2500
[00:09:23]                   │ debg Find.findByCssSelector('[data-test-subj=collapsibleNav] > button') with timeout=10000
[00:09:23]                   │ debg Find.clickByCssSelector('[data-test-subj=collapsibleNav] > button') with timeout=10000
[00:09:23]                   │ debg Find.findByCssSelector('[data-test-subj=collapsibleNav] > button') with timeout=10000
[00:09:23]                   └- ✓ pass  (5.4s) "Ingest pipelines app feature controls security global dashboard all with ingest_pipelines_user should show the Stack Management nav link"
[00:09:23]                 └-> should render the "Ingest" section with ingest pipelines
[00:09:23]                   └-> "before each" hook: global before each for "should render the "Ingest" section with ingest pipelines"
[00:09:23]                   │ debg navigating to management url: http://localhost:61131/app/management
[00:09:23]                   │ debg navigate to: http://localhost:61131/app/management
[00:09:24]                   │ debg browser[INFO] http://localhost:61131/app/management?_t=1612786649218 341 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:09:24]                   │
[00:09:24]                   │ debg browser[INFO] http://localhost:61131/bootstrap.js 42:19 "^ A single error about an inline script not firing due to content security policy is expected!"
[00:09:24]                   │ debg ... sleep(700) start
[00:09:24]                   │ debg ... sleep(700) end
[00:09:24]                   │ debg returned from get, calling refresh
[00:09:25]                   │ debg browser[INFO] http://localhost:61131/app/management?_t=1612786649218 341 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:09:25]                   │
[00:09:25]                   │ debg browser[INFO] http://localhost:61131/bootstrap.js 42:19 "^ A single error about an inline script not firing due to content security policy is expected!"
[00:09:25]                   │ debg currentUrl = http://localhost:61131/app/management
[00:09:25]                   │          appUrl = http://localhost:61131/app/management
[00:09:25]                   │ debg TestSubjects.find(kibanaChrome)
[00:09:25]                   │ debg Find.findByCssSelector('[data-test-subj="kibanaChrome"]') with timeout=60000
[00:09:25]                   │ debg ... sleep(501) start
[00:09:26]                   │ debg ... sleep(501) end
[00:09:26]                   │ debg in navigateTo url = http://localhost:61131/app/management
[00:09:26]                   │ debg TestSubjects.exists(statusPageContainer)
[00:09:26]                   │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="statusPageContainer"]') with timeout=2500
[00:09:28]                   │ debg --- retry.tryForTime error: [data-test-subj="statusPageContainer"] is not displayed
[00:09:29]                   │ debg Find.allByCssSelector('.mgtSideBarNav > .euiSideNav__content > .euiSideNavItem') with timeout=10000
[00:09:29]                   │ info Taking screenshot "/dev/shm/workspace/parallel/13/kibana/x-pack/test/functional/screenshots/failure/Ingest pipelines app feature controls security global dashboard all with ingest_pipelines_user should render the _Ingest_ section with ingest pipelines.png"
[00:09:29]                   │ info Current URL is: http://localhost:61131/app/management
[00:09:29]                   │ info Saving page source to: /dev/shm/workspace/parallel/13/kibana/x-pack/test/functional/failure_debug/html/Ingest pipelines app feature controls security global dashboard all with ingest_pipelines_user should render the _Ingest_ section with ingest pipelines.html
[00:09:29]                   └- ✖ fail: Ingest pipelines app feature controls security global dashboard all with ingest_pipelines_user should render the "Ingest" section with ingest pipelines
[00:09:29]                   │      Error: expected [ { sectionId: 'ingest',
[00:09:29]                   │     sectionLinks: [ 'ingest_pipelines', 'pipelines' ] },
[00:09:29]                   │   { sectionId: 'insightsAndAlerting',
[00:09:29]                   │     sectionLinks: [ 'watcher' ] } ] to have a length of 1 but got 2
[00:09:29]                   │       at Assertion.assert (/dev/shm/workspace/parallel/13/kibana/packages/kbn-expect/expect.js:100:11)
[00:09:29]                   │       at Assertion.length (/dev/shm/workspace/parallel/13/kibana/packages/kbn-expect/expect.js:374:8)
[00:09:29]                   │       at Context.<anonymous> (test/functional/apps/ingest_pipelines/feature_controls/ingest_pipelines_security.ts:63:34)
[00:09:29]                   │       at runMicrotasks (<anonymous>)
[00:09:29]                   │       at processTicksAndRejections (internal/process/task_queues.js:93:5)
[00:09:29]                   │       at Object.apply (/dev/shm/workspace/parallel/13/kibana/packages/kbn-test/src/functional_test_runner/lib/mocha/wrap_function.js:73:16)
[00:09:29]                   │ 
[00:09:29]                   │ 

Stack Trace

Error: expected [ { sectionId: 'ingest',
    sectionLinks: [ 'ingest_pipelines', 'pipelines' ] },
  { sectionId: 'insightsAndAlerting',
    sectionLinks: [ 'watcher' ] } ] to have a length of 1 but got 2
    at Assertion.assert (/dev/shm/workspace/parallel/13/kibana/packages/kbn-expect/expect.js:100:11)
    at Assertion.length (/dev/shm/workspace/parallel/13/kibana/packages/kbn-expect/expect.js:374:8)
    at Context.<anonymous> (test/functional/apps/ingest_pipelines/feature_controls/ingest_pipelines_security.ts:63:34)
    at runMicrotasks (<anonymous>)
    at processTicksAndRejections (internal/process/task_queues.js:93:5)
    at Object.apply (/dev/shm/workspace/parallel/13/kibana/packages/kbn-test/src/functional_test_runner/lib/mocha/wrap_function.js:73:16)

Metrics [docs]

✅ unchanged

History

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

Copy link
Member

@vigneshshanmugam vigneshshanmugam left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nice one @dgieselaar 🎉

return promise
.then(
(res) => {
span.outcome = 'success';
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

hmmm not sure about this one. As outcome changes based on status code and the code here is based on the promise being resolved or rejected. Would double check with the current behaviour.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

To me this looks ok.

As outcome changes based on status code and the code here is based on the promise being resolved or rejected.

Isn't it rather: "transaction outcome changes based on status code."

So a transaction outcome doesn't depend on span outcome and vice versa. If a span fails it will only also fail the transaction if the error is not caught. Conversely, if a span succeeds, any other span could fail, causing the transaction to fail too.

Copy link
Member Author

@dgieselaar dgieselaar Feb 9, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

spans can also result in http requests, for instance when calling an external service (ie, spans can have outcomes based on status code as well). But this function wraps async operations, and it is the responsibility of that operation to reject or resolve based on its interpretation of the results. Interpreting requests is out of scope for this function.


const resource = new asyncHooks.AsyncResource('fake_async');

return resource.runInAsyncScope(() => {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pretty sure this would work for promise based cb, Did you happen to investigate if this wrapper works for callback based functions as well?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What do you mean?

@dgieselaar
Copy link
Member Author

@elasticmachine merge upstream

@kibanamachine
Copy link
Contributor

💚 Build Succeeded

Metrics [docs]

✅ unchanged

History

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

@dgieselaar dgieselaar merged commit a28318e into elastic:master Feb 12, 2021
@dgieselaar dgieselaar deleted the with-span branch February 12, 2021 18:34
spalger added a commit to spalger/kibana that referenced this pull request Feb 13, 2021
dgieselaar added a commit to dgieselaar/kibana that referenced this pull request Feb 13, 2021
dgieselaar added a commit that referenced this pull request Feb 13, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
release_note:skip Skip the PR/issue when compiling release notes Team:APM All issues that need APM UI Team support v7.12.0
Projects
None yet
Development

Successfully merging this pull request may close these issues.

[APM] Instrumentation for ES queries
5 participants