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

HTTP-Server: Graceful shutdown #97223

Merged
merged 19 commits into from
Apr 20, 2021

Conversation

afharo
Copy link
Member

@afharo afharo commented Apr 15, 2021

Summary

When shutting down, Kibana now waits up to server.shutdownTimeout (30 seconds by default) for all the ongoing HTTP requests to finish. During that period, it sets the response header connection to 'close' (instead of keep-alive), and rejects new connections (by responding 503).

Resolves #84452. We might need a follow up to cover #83612.

NOTE: As shown in the HTTP Server tests, the statement in the description above is true. However, during manual tests, I noticed slightly different behaviours depending on how Kibana is run:

  1. When running in prod mode (node scripts/kibana): it works as mentioned above.
  2. When running in dev mode (yarn start): The proxy that runs in front of it immediately closes the ongoing requests with 502 Bad Gateway.
  3. When running in dev mode + no proxy (yarn start --no-base-path): The dev watcher wrapping the process also kills the process immediately, leading to the ongoing requests to be immediately dropped due to the server closing the socket.

I noticed that both dev mode behaviours are caused by the CliDevMode triggering a duplicate of the SIGINT event. I've created #97439 to follow up on that issue.

Checklist

Delete any items that are not applicable to this PR.

For maintainers

@afharo afharo added release_note:enhancement v7.13.0 Team:Core Core services & architecture: plugins, logging, config, saved objects, http, ES client, i18n, etc labels Apr 15, 2021
@afharo afharo marked this pull request as ready for review April 15, 2021 10:48
@afharo afharo requested review from a team as code owners April 15, 2021 10:48
@elasticmachine
Copy link
Contributor

Pinging @elastic/kibana-core (Team:Core)

@afharo afharo added the Team:Operations Team label for Operations Team label Apr 15, 2021
@elasticmachine
Copy link
Contributor

Pinging @elastic/kibana-operations (Team:Operations)

@spalger
Copy link
Contributor

spalger commented Apr 15, 2021

The dev watcher wrapping the process also kills the process immediately, leading to the ongoing requests to be immediately dropped due to the server closing the socket

This shouldn't be what's happening, when CliDevMode observes SIGINT it sends SIGINT to the child process and waits up to 5 seconds for it to exit (we should probably update this to 30 seconds), unless it observes a second SIGINT.

@afharo
Copy link
Member Author

afharo commented Apr 15, 2021

This shouldn't be what's happening, when CliDevMode observes SIGINT it sends SIGINT to the child process and waits up to 5 seconds for it to exit (we should probably update this to 30 seconds), unless it observes a second SIGINT.

@spalger yeah! I see that in the code. I think the underlying issue is what we see when running it as node scripts/kibana: since it's detaching the process even when the requests are still running, CliDevMode simply exits on detach (giving this feeling that dev mode kills the process prematurely).

I'll try to find a way to hold the node scripts/kibana process from detaching. If I find out how, it will probably help us confirm the theory I just made up 😇


UPDATE: In my tests, I noticed the parent CliDevMode process does not need to forward the SIGINT process. execa already does that thanks to the cleanup property (https://www.npmjs.com/package/execa/v/0.6.0#cleanup). After removing the call proc.kill('SIGINT'), it works in the same way as node scripts/kibana.

Next up is for me to find out how to stop node scripts/kibana from detaching before completing the graceful shutdown.

@afharo
Copy link
Member Author

afharo commented Apr 16, 2021

Next up is for me to find out how to stop node scripts/kibana from detaching before completing the graceful shutdown.

I found the reason for this! 🎉
We are spawning a child process here to add the preserve symlinks flags in the node process.

Kibana (the child) is handling the SIGINT and SIGTERM signals, but the parent wasn't, leading to the parent exiting, and the child to keep working until gracefully finishing. Now I've added a NOOP in the parent to those events. It'll close when the child finishes.

@afharo
Copy link
Member Author

afharo commented Apr 19, 2021

@elasticmachine merge upstream

Copy link
Contributor

@spalger spalger left a comment

Choose a reason for hiding this comment

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

CliDevMode gracefulTimeout change LGTM

Copy link
Contributor

@mshustov mshustov left a comment

Choose a reason for hiding this comment

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

several nits, LGTM for the Core changes

@afharo
Copy link
Member Author

afharo commented Apr 20, 2021

@elasticmachine merge upstream

@afharo afharo added the auto-backport Deprecated - use backport:version if exact versions are needed label Apr 20, 2021
@afharo afharo enabled auto-merge (squash) April 20, 2021 11:53
Copy link
Contributor

@rudolf rudolf left a comment

Choose a reason for hiding this comment

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

Can be done in a separate PR, but we should also document the config option.

@afharo afharo disabled auto-merge April 20, 2021 13:49
@afharo afharo enabled auto-merge (squash) April 20, 2021 13:49
@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/dashboard/sync_colors·ts.dashboard sync colors should sync colors on dashboard by default

Link to Jenkins

Standard Out

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

[00:00:00]       │
[00:00:00]         └-: dashboard
[00:00:00]           └-> "before all" hook in "dashboard"
[00:20:11]           └-: sync colors
[00:20:11]             └-> "before all" hook for "should sync colors on dashboard by default"
[00:20:11]             └-> "before all" hook for "should sync colors on dashboard by default"
[00:20:11]               │ info [logstash_functional] Loading "mappings.json"
[00:20:11]               │ info [logstash_functional] Loading "data.json.gz"
[00:20:11]               │ info [logstash_functional] Skipped restore for existing index "logstash-2015.09.22"
[00:20:11]               │ info [logstash_functional] Skipped restore for existing index "logstash-2015.09.20"
[00:20:11]               │ info [logstash_functional] Skipped restore for existing index "logstash-2015.09.21"
[00:20:12]               │ info [lens/basic] Loading "mappings.json"
[00:20:12]               │ info [lens/basic] Loading "data.json"
[00:20:12]               │ info [lens/basic] Loading "data.json.gz"
[00:20:12]               │ info [o.e.c.m.MetadataDeleteIndexService] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] [.kibana_task_manager_8.0.0_001/vFbTA6PTRu6DCl0-1lXxFw] deleting index
[00:20:12]               │ info [o.e.c.m.MetadataDeleteIndexService] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] [.kibana_8.0.0_001/pFrahXzPTU2wHMrcjBtADg] deleting index
[00:20:12]               │ info [o.e.c.m.MetadataDeleteIndexService] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] [.kibana_pre6.5.0_001/yX4C4ZUbQsybwkFPVwgxkw] deleting index
[00:20:12]               │ info [lens/basic] Deleted existing index ".kibana_8.0.0_001"
[00:20:12]               │ info [lens/basic] Deleted existing index ".kibana_task_manager_8.0.0_001"
[00:20:12]               │ info [lens/basic] Deleted existing index ".kibana_pre6.5.0_001"
[00:20:12]               │ info [o.e.c.m.MetadataCreateIndexService] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] [.kibana_1] creating index, cause [api], templates [], shards [1]/[0]
[00:20:12]               │ info [lens/basic] Created index ".kibana_1"
[00:20:12]               │ debg [lens/basic] ".kibana_1" settings {"index":{"auto_expand_replicas":"0-1","number_of_replicas":"0","number_of_shards":"1"}}
[00:20:12]               │ info [lens/basic] Indexed 24 docs into ".kibana_1"
[00:20:12]               │ debg Migrating saved objects
[00:20:12]               │ proc [kibana]   log   [12:47:53.585] [info][savedobjects-service] [.kibana_task_manager] INIT -> CREATE_NEW_TARGET. took: 6ms.
[00:20:12]               │ info [o.e.c.m.MetadataCreateIndexService] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] [.kibana_task_manager_8.0.0_001] creating index, cause [api], templates [], shards [1]/[1]
[00:20:12]               │ proc [kibana]   log   [12:47:53.596] [info][savedobjects-service] [.kibana] INIT -> WAIT_FOR_YELLOW_SOURCE. took: 19ms.
[00:20:12]               │ info [o.e.c.r.a.AllocationService] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] updating number_of_replicas to [0] for indices [.kibana_task_manager_8.0.0_001]
[00:20:12]               │ proc [kibana]   log   [12:47:53.607] [info][savedobjects-service] [.kibana] WAIT_FOR_YELLOW_SOURCE -> SET_SOURCE_WRITE_BLOCK. took: 11ms.
[00:20:12]               │ info [o.e.c.m.MetadataIndexStateService] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] adding block write to indices [[.kibana_1/Kl0L5q4xTwi0riWL5ZBfDQ]]
[00:20:12]               │ info [o.e.c.m.MetadataIndexStateService] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] completed adding block write to indices [.kibana_1]
[00:20:12]               │ proc [kibana]   log   [12:47:53.688] [info][savedobjects-service] [.kibana_task_manager] CREATE_NEW_TARGET -> MARK_VERSION_INDEX_READY. took: 103ms.
[00:20:12]               │ proc [kibana]   log   [12:47:53.721] [info][savedobjects-service] [.kibana] SET_SOURCE_WRITE_BLOCK -> CREATE_REINDEX_TEMP. took: 114ms.
[00:20:12]               │ proc [kibana]   log   [12:47:53.742] [info][savedobjects-service] [.kibana_task_manager] MARK_VERSION_INDEX_READY -> DONE. took: 54ms.
[00:20:12]               │ proc [kibana]   log   [12:47:53.742] [info][savedobjects-service] [.kibana_task_manager] Migration completed after 163ms
[00:20:12]               │ info [o.e.c.m.MetadataCreateIndexService] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] [.kibana_8.0.0_reindex_temp] creating index, cause [api], templates [], shards [1]/[1]
[00:20:12]               │ info [o.e.c.r.a.AllocationService] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] updating number_of_replicas to [0] for indices [.kibana_8.0.0_reindex_temp]
[00:20:13]               │ proc [kibana]   log   [12:47:53.809] [info][savedobjects-service] [.kibana] CREATE_REINDEX_TEMP -> REINDEX_SOURCE_TO_TEMP. took: 88ms.
[00:20:13]               │ proc [kibana]   log   [12:47:53.820] [info][savedobjects-service] [.kibana] REINDEX_SOURCE_TO_TEMP -> REINDEX_SOURCE_TO_TEMP_WAIT_FOR_TASK. took: 11ms.
[00:20:13]               │ info [o.e.c.m.MetadataMappingService] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] [.kibana_8.0.0_reindex_temp/mZfsDtMfSv-M6eKWceYpGA] update_mapping [_doc]
[00:20:13]               │ info [o.e.c.m.MetadataMappingService] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] [.kibana_8.0.0_reindex_temp/mZfsDtMfSv-M6eKWceYpGA] update_mapping [_doc]
[00:20:13]               │ info [o.e.c.m.MetadataMappingService] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] [.kibana_8.0.0_reindex_temp/mZfsDtMfSv-M6eKWceYpGA] update_mapping [_doc]
[00:20:13]               │ info [o.e.t.LoggingTaskListener] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] 31807 finished with response BulkByScrollResponse[took=117.1ms,timed_out=false,sliceId=null,updated=0,created=12,deleted=0,batches=1,versionConflicts=0,noops=0,retries=0,throttledUntil=0s,bulk_failures=[],search_failures=[]]
[00:20:13]               │ proc [kibana]   log   [12:47:54.031] [info][savedobjects-service] [.kibana] REINDEX_SOURCE_TO_TEMP_WAIT_FOR_TASK -> SET_TEMP_WRITE_BLOCK. took: 211ms.
[00:20:13]               │ info [o.e.c.m.MetadataIndexStateService] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] adding block write to indices [[.kibana_8.0.0_reindex_temp/mZfsDtMfSv-M6eKWceYpGA]]
[00:20:13]               │ info [o.e.c.m.MetadataIndexStateService] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] completed adding block write to indices [.kibana_8.0.0_reindex_temp]
[00:20:13]               │ proc [kibana]   log   [12:47:54.081] [info][savedobjects-service] [.kibana] SET_TEMP_WRITE_BLOCK -> CLONE_TEMP_TO_TARGET. took: 50ms.
[00:20:13]               │ info [o.e.c.m.MetadataCreateIndexService] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] applying create index request using existing index [.kibana_8.0.0_reindex_temp] metadata
[00:20:13]               │ info [o.e.c.m.MetadataCreateIndexService] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] [.kibana_8.0.0_001] creating index, cause [clone_index], templates [], shards [1]/[1]
[00:20:13]               │ info [o.e.c.r.a.AllocationService] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] updating number_of_replicas to [0] for indices [.kibana_8.0.0_001]
[00:20:13]               │ info [o.e.c.m.MetadataMappingService] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] [.kibana_8.0.0_001/bebO1lL2Qu-n3r1PQIhNKg] create_mapping
[00:20:13]               │ proc [kibana]   log   [12:47:54.192] [info][savedobjects-service] [.kibana] CLONE_TEMP_TO_TARGET -> OUTDATED_DOCUMENTS_SEARCH. took: 111ms.
[00:20:13]               │ proc [kibana]   log   [12:47:54.207] [info][savedobjects-service] [.kibana] OUTDATED_DOCUMENTS_SEARCH -> OUTDATED_DOCUMENTS_TRANSFORM. took: 15ms.
[00:20:13]               │ info [o.e.c.m.MetadataMappingService] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] [.kibana_8.0.0_001/bebO1lL2Qu-n3r1PQIhNKg] update_mapping [_doc]
[00:20:13]               │ info [o.e.c.m.MetadataMappingService] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] [.kibana_8.0.0_001/bebO1lL2Qu-n3r1PQIhNKg] update_mapping [_doc]
[00:20:14]               │ proc [kibana]   log   [12:47:55.122] [info][savedobjects-service] [.kibana] OUTDATED_DOCUMENTS_TRANSFORM -> OUTDATED_DOCUMENTS_SEARCH. took: 915ms.
[00:20:14]               │ proc [kibana]   log   [12:47:55.134] [info][savedobjects-service] [.kibana] OUTDATED_DOCUMENTS_SEARCH -> UPDATE_TARGET_MAPPINGS. took: 12ms.
[00:20:14]               │ info [o.e.c.m.MetadataMappingService] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] [.kibana_8.0.0_001/bebO1lL2Qu-n3r1PQIhNKg] update_mapping [_doc]
[00:20:14]               │ proc [kibana]   log   [12:47:55.217] [info][savedobjects-service] [.kibana] UPDATE_TARGET_MAPPINGS -> UPDATE_TARGET_MAPPINGS_WAIT_FOR_TASK. took: 83ms.
[00:20:14]               │ info [o.e.t.LoggingTaskListener] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] 31877 finished with response BulkByScrollResponse[took=26.8ms,timed_out=false,sliceId=null,updated=12,created=0,deleted=0,batches=1,versionConflicts=0,noops=0,retries=0,throttledUntil=0s,bulk_failures=[],search_failures=[]]
[00:20:14]               │ proc [kibana]   log   [12:47:55.327] [info][savedobjects-service] [.kibana] UPDATE_TARGET_MAPPINGS_WAIT_FOR_TASK -> MARK_VERSION_INDEX_READY. took: 110ms.
[00:20:14]               │ info [o.e.c.m.MetadataDeleteIndexService] [kibana-ci-immutable-ubuntu-18-tests-xxl-1618919616643118295] [.kibana_8.0.0_reindex_temp/mZfsDtMfSv-M6eKWceYpGA] deleting index
[00:20:14]               │ proc [kibana]   log   [12:47:55.370] [info][savedobjects-service] [.kibana] MARK_VERSION_INDEX_READY -> DONE. took: 43ms.
[00:20:14]               │ proc [kibana]   log   [12:47:55.371] [info][savedobjects-service] [.kibana] Migration completed after 1794ms
[00:20:14]               │ debg [lens/basic] Migrated Kibana index after loading Kibana data
[00:20:14]               │ debg [lens/basic] Ensured that default space exists in .kibana
[00:20:14]               │ debg applying update to kibana config: {"accessibility:disableAnimations":true,"dateFormat:tz":"UTC","visualization:visualize:legacyChartsLibrary":true}
[00:20:16]               │ debg applying update to kibana config: {"accessibility:disableAnimations":true,"dateFormat:tz":"UTC","visualization:visualize:legacyChartsLibrary":true}
[00:20:17]             └-> should sync colors on dashboard by default
[00:20:17]               └-> "before each" hook: global before each for "should sync colors on dashboard by default"
[00:20:17]               │ debg navigating to dashboard url: http://localhost:6111/app/dashboards#/list
[00:20:17]               │ debg navigate to: http://localhost:6111/app/dashboards#/list
[00:20:17]               │ debg browser[INFO] http://localhost:6111/app/dashboards?_t=1618922878159#/list 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:20:17]               │
[00:20:17]               │ debg browser[INFO] http://localhost:6111/bootstrap.js 41:19 "^ A single error about an inline script not firing due to content security policy is expected!"
[00:20:17]               │ debg ... sleep(700) start
[00:20:18]               │ debg ... sleep(700) end
[00:20:18]               │ debg returned from get, calling refresh
[00:20:18]               │ debg browser[INFO] http://localhost:6111/app/dashboards?_t=1618922878159#/list 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:20:18]               │
[00:20:18]               │ debg browser[INFO] http://localhost:6111/bootstrap.js 41:19 "^ A single error about an inline script not firing due to content security policy is expected!"
[00:20:18]               │ debg currentUrl = http://localhost:6111/app/dashboards#/list
[00:20:18]               │          appUrl = http://localhost:6111/app/dashboards#/list
[00:20:18]               │ debg TestSubjects.find(kibanaChrome)
[00:20:18]               │ debg Find.findByCssSelector('[data-test-subj="kibanaChrome"]') with timeout=60000
[00:20:20]               │ debg ... sleep(501) start
[00:20:20]               │ debg ... sleep(501) end
[00:20:20]               │ debg in navigateTo url = http://localhost:6111/app/dashboards#/list?_g=(filters:!(),refreshInterval:(pause:!t,value:0),time:(from:now-15m,to:now))
[00:20:20]               │ debg TestSubjects.exists(statusPageContainer)
[00:20:20]               │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="statusPageContainer"]') with timeout=2500
[00:20:23]               │ debg --- retry.tryForTime error: [data-test-subj="statusPageContainer"] is not displayed
[00:20:23]               │ debg TestSubjects.click(createDashboardPromptButton)
[00:20:23]               │ debg Find.clickByCssSelector('[data-test-subj="createDashboardPromptButton"]') with timeout=10000
[00:20:23]               │ debg Find.findByCssSelector('[data-test-subj="createDashboardPromptButton"]') with timeout=10000
[00:20:23]               │ debg DashboardAddPanel.clickAddNewPanelButton
[00:20:23]               │ debg TestSubjects.click(dashboardAddNewPanelButton)
[00:20:23]               │ debg Find.clickByCssSelector('[data-test-subj="dashboardAddNewPanelButton"]') with timeout=10000
[00:20:23]               │ debg Find.findByCssSelector('[data-test-subj="dashboardAddNewPanelButton"]') with timeout=10000
[00:20:24]               │ debg ... sleep(500) start
[00:20:24]               │ debg ... sleep(500) end
[00:20:24]               │ debg isGlobalLoadingIndicatorVisible
[00:20:24]               │ debg TestSubjects.exists(globalLoadingIndicator)
[00:20:24]               │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="globalLoadingIndicator"]') with timeout=1500
[00:20:26]               │ debg --- retry.tryForTime error: [data-test-subj="globalLoadingIndicator"] is not displayed
[00:20:26]               │ debg TestSubjects.exists(globalLoadingIndicator-hidden)
[00:20:26]               │ debg Find.existsByCssSelector('[data-test-subj="globalLoadingIndicator-hidden"]') with timeout=100000
[00:20:26]               │ debg lensPage.goToTimeRange()
[00:20:26]               │ debg TestSubjects.exists(noDataPopoverDismissButton)
[00:20:26]               │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="noDataPopoverDismissButton"]') with timeout=2500
[00:20:29]               │ debg --- retry.tryForTime error: [data-test-subj="noDataPopoverDismissButton"] is not displayed
[00:20:29]               │ debg Setting absolute range to Sep 19, 2015 @ 06:31:44.000 to Sep 23, 2015 @ 18:31:44.000
[00:20:29]               │ debg TestSubjects.exists(superDatePickerToggleQuickMenuButton)
[00:20:29]               │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="superDatePickerToggleQuickMenuButton"]') with timeout=20000
[00:20:29]               │ debg TestSubjects.exists(superDatePickerShowDatesButton)
[00:20:29]               │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="superDatePickerShowDatesButton"]') with timeout=2500
[00:20:29]               │ debg TestSubjects.click(superDatePickerShowDatesButton)
[00:20:29]               │ debg Find.clickByCssSelector('[data-test-subj="superDatePickerShowDatesButton"]') with timeout=10000
[00:20:29]               │ debg Find.findByCssSelector('[data-test-subj="superDatePickerShowDatesButton"]') with timeout=10000
[00:20:29]               │ debg TestSubjects.exists(superDatePickerstartDatePopoverButton)
[00:20:29]               │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="superDatePickerstartDatePopoverButton"]') with timeout=2500
[00:20:29]               │ debg TestSubjects.click(superDatePickerendDatePopoverButton)
[00:20:29]               │ debg Find.clickByCssSelector('[data-test-subj="superDatePickerendDatePopoverButton"]') with timeout=10000
[00:20:29]               │ debg Find.findByCssSelector('[data-test-subj="superDatePickerendDatePopoverButton"]') with timeout=10000
[00:20:30]               │ debg Find.findByCssSelector('div.euiPopover__panel-isOpen') with timeout=10000
[00:20:30]               │ debg TestSubjects.click(superDatePickerAbsoluteTab)
[00:20:30]               │ debg Find.clickByCssSelector('[data-test-subj="superDatePickerAbsoluteTab"]') with timeout=10000
[00:20:30]               │ debg Find.findByCssSelector('[data-test-subj="superDatePickerAbsoluteTab"]') with timeout=10000
[00:20:30]               │ debg TestSubjects.click(superDatePickerAbsoluteDateInput)
[00:20:30]               │ debg Find.clickByCssSelector('[data-test-subj="superDatePickerAbsoluteDateInput"]') with timeout=10000
[00:20:30]               │ debg Find.findByCssSelector('[data-test-subj="superDatePickerAbsoluteDateInput"]') with timeout=10000
[00:20:30]               │ debg TestSubjects.setValue(superDatePickerAbsoluteDateInput, Sep 23, 2015 @ 18:31:44.000)
[00:20:30]               │ debg TestSubjects.click(superDatePickerAbsoluteDateInput)
[00:20:30]               │ debg Find.clickByCssSelector('[data-test-subj="superDatePickerAbsoluteDateInput"]') with timeout=10000
[00:20:30]               │ debg Find.findByCssSelector('[data-test-subj="superDatePickerAbsoluteDateInput"]') with timeout=10000
[00:20:30]               │ debg TestSubjects.click(superDatePickerstartDatePopoverButton)
[00:20:30]               │ debg Find.clickByCssSelector('[data-test-subj="superDatePickerstartDatePopoverButton"]') with timeout=10000
[00:20:30]               │ debg Find.findByCssSelector('[data-test-subj="superDatePickerstartDatePopoverButton"]') with timeout=10000
[00:20:30]               │ debg Find.waitForElementStale with timeout=10000
[00:20:31]               │ debg Find.findByCssSelector('div.euiPopover__panel-isOpen') with timeout=10000
[00:20:31]               │ debg TestSubjects.click(superDatePickerAbsoluteTab)
[00:20:31]               │ debg Find.clickByCssSelector('[data-test-subj="superDatePickerAbsoluteTab"]') with timeout=10000
[00:20:31]               │ debg Find.findByCssSelector('[data-test-subj="superDatePickerAbsoluteTab"]') with timeout=10000
[00:20:31]               │ debg TestSubjects.click(superDatePickerAbsoluteDateInput)
[00:20:31]               │ debg Find.clickByCssSelector('[data-test-subj="superDatePickerAbsoluteDateInput"]') with timeout=10000
[00:20:31]               │ debg Find.findByCssSelector('[data-test-subj="superDatePickerAbsoluteDateInput"]') with timeout=10000
[00:20:31]               │ debg TestSubjects.setValue(superDatePickerAbsoluteDateInput, Sep 19, 2015 @ 06:31:44.000)
[00:20:31]               │ debg TestSubjects.click(superDatePickerAbsoluteDateInput)
[00:20:31]               │ debg Find.clickByCssSelector('[data-test-subj="superDatePickerAbsoluteDateInput"]') with timeout=10000
[00:20:31]               │ debg Find.findByCssSelector('[data-test-subj="superDatePickerAbsoluteDateInput"]') with timeout=10000
[00:20:31]               │ debg TestSubjects.exists(superDatePickerApplyTimeButton)
[00:20:31]               │ debg Find.existsByDisplayedByCssSelector('[data-test-subj="superDatePickerApplyTimeButton"]') with timeout=2500
[00:20:34]               │ debg --- retry.tryForTime error: [data-test-subj="superDatePickerApplyTimeButton"] is not displayed
[00:20:34]               │ debg TestSubjects.click(querySubmitButton)
[00:20:34]               │ debg Find.clickByCssSelector('[data-test-subj="querySubmitButton"]') with timeout=10000
[00:20:34]               │ debg Find.findByCssSelector('[data-test-subj="querySubmitButton"]') with timeout=10000
[00:20:34]               │ debg Find.waitForElementStale with timeout=10000
[00:20:35]               │ debg TestSubjects.exists(globalLoadingIndicator-hidden)
[00:20:35]               │ debg Find.existsByCssSelector('[data-test-subj="globalLoadingIndicator-hidden"]') with timeout=100000
[00:20:35]               │ debg lensPage.configureDimension([object Object])
[00:20:35]               │ debg TestSubjects.click(lns-layerPanel-0 > lnsXY_yDimensionPanel > lns-empty-dimension)
[00:20:35]               │ debg Find.clickByCssSelector('[data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"]') with timeout=10000
[00:20:35]               │ debg Find.findByCssSelector('[data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"]') with timeout=10000
[00:20:45]               │ debg --- retry.try error: Waiting for element to be located By(css selector, [data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"])
[00:20:45]               │      Wait timed out after 10013ms
[00:20:45]               │ debg Find.findByCssSelector('[data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"]') with timeout=10000
[00:20:55]               │ debg --- retry.try error: Waiting for element to be located By(css selector, [data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"])
[00:20:55]               │      Wait timed out after 10010ms
[00:20:56]               │ debg Find.findByCssSelector('[data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"]') with timeout=10000
[00:21:06]               │ debg --- retry.try error: Waiting for element to be located By(css selector, [data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"])
[00:21:06]               │      Wait timed out after 10042ms
[00:21:06]               │ debg Find.findByCssSelector('[data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"]') with timeout=10000
[00:21:16]               │ debg --- retry.try error: Waiting for element to be located By(css selector, [data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"])
[00:21:16]               │      Wait timed out after 10023ms
[00:21:17]               │ debg Find.findByCssSelector('[data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"]') with timeout=10000
[00:21:27]               │ debg --- retry.try error: Waiting for element to be located By(css selector, [data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"])
[00:21:27]               │      Wait timed out after 10028ms
[00:21:27]               │ debg Find.findByCssSelector('[data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"]') with timeout=10000
[00:21:37]               │ debg --- retry.try error: Waiting for element to be located By(css selector, [data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"])
[00:21:37]               │      Wait timed out after 10024ms
[00:21:38]               │ debg Find.findByCssSelector('[data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"]') with timeout=10000
[00:21:48]               │ debg --- retry.try error: Waiting for element to be located By(css selector, [data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"])
[00:21:48]               │      Wait timed out after 10052ms
[00:21:48]               │ debg Find.findByCssSelector('[data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"]') with timeout=10000
[00:21:58]               │ debg --- retry.try error: Waiting for element to be located By(css selector, [data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"])
[00:21:58]               │      Wait timed out after 10032ms
[00:21:59]               │ debg Find.findByCssSelector('[data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"]') with timeout=10000
[00:22:09]               │ debg --- retry.try error: Waiting for element to be located By(css selector, [data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"])
[00:22:09]               │      Wait timed out after 10017ms
[00:22:09]               │ debg Find.findByCssSelector('[data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"]') with timeout=10000
[00:22:20]               │ debg --- retry.try error: Waiting for element to be located By(css selector, [data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"])
[00:22:20]               │      Wait timed out after 10044ms
[00:22:20]               │ debg Find.findByCssSelector('[data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"]') with timeout=10000
[00:22:30]               │ debg --- retry.try error: Waiting for element to be located By(css selector, [data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"])
[00:22:30]               │      Wait timed out after 10032ms
[00:22:31]               │ debg Find.findByCssSelector('[data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"]') with timeout=10000
[00:22:41]               │ debg --- retry.try error: Waiting for element to be located By(css selector, [data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"])
[00:22:41]               │      Wait timed out after 10022ms
[00:22:41]               │ debg --- retry.try error: retry.try timeout: TimeoutError: Waiting for element to be located By(css selector, [data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"])
[00:22:41]               │      Wait timed out after 10022ms
[00:22:41]               │          at /dev/shm/workspace/parallel/1/kibana/node_modules/selenium-webdriver/lib/webdriver.js:842:17
[00:22:41]               │          at runMicrotasks (<anonymous>)
[00:22:41]               │          at processTicksAndRejections (internal/process/task_queues.js:93:5)
[00:22:42]               │ info Taking screenshot "/dev/shm/workspace/parallel/1/kibana/x-pack/test/functional/screenshots/failure/dashboard sync colors should sync colors on dashboard by default.png"
[00:22:42]               │ info Current URL is: http://localhost:6111/app/dashboards#/create?_g=(filters:!(),refreshInterval:(pause:!t,value:0),time:(from:%272015-09-19T06:31:44.000Z%27,to:%272015-09-23T18:31:44.000Z%27))&_a=(description:%27%27,filters:!(),fullScreenMode:!f,options:(hidePanelTitles:!f,useMargins:!t),query:(language:kuery,query:%27%27),tags:!(),timeRestore:!f,title:%27%27,viewMode:edit)
[00:22:42]               │ info Saving page source to: /dev/shm/workspace/parallel/1/kibana/x-pack/test/functional/failure_debug/html/dashboard sync colors should sync colors on dashboard by default.html
[00:22:42]               └- ✖ fail: dashboard sync colors should sync colors on dashboard by default
[00:22:42]               │      retry.try timeout: Error: retry.try timeout: TimeoutError: Waiting for element to be located By(css selector, [data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"])
[00:22:42]               │ Wait timed out after 10022ms
[00:22:42]               │     at /dev/shm/workspace/parallel/1/kibana/node_modules/selenium-webdriver/lib/webdriver.js:842:17
[00:22:42]               │     at runMicrotasks (<anonymous>)
[00:22:42]               │     at processTicksAndRejections (internal/process/task_queues.js:93:5)
[00:22:42]               │     at onFailure (/dev/shm/workspace/parallel/1/kibana/test/common/services/retry/retry_for_success.ts:17:9)
[00:22:42]               │     at retryForSuccess (/dev/shm/workspace/parallel/1/kibana/test/common/services/retry/retry_for_success.ts:57:13)
[00:22:42]               │     at Retry.try (/dev/shm/workspace/parallel/1/kibana/test/common/services/retry/retry.ts:32:14)
[00:22:42]               │     at Proxy.clickByCssSelector (/dev/shm/workspace/parallel/1/kibana/test/functional/services/common/find.ts:420:7)
[00:22:42]               │     at TestSubjects.click (/dev/shm/workspace/parallel/1/kibana/test/functional/services/common/test_subjects.ts:109:7)
[00:22:42]               │     at /dev/shm/workspace/parallel/1/kibana/x-pack/test/functional/page_objects/lens_page.ts:114:9
[00:22:42]               │     at runAttempt (/dev/shm/workspace/parallel/1/kibana/test/common/services/retry/retry_for_success.ts:27:15)
[00:22:42]               │     at retryForSuccess (/dev/shm/workspace/parallel/1/kibana/test/common/services/retry/retry_for_success.ts:66:21)
[00:22:42]               │     at Retry.try (/dev/shm/workspace/parallel/1/kibana/test/common/services/retry/retry.ts:32:14)
[00:22:42]               │     at Object.configureDimension (/dev/shm/workspace/parallel/1/kibana/x-pack/test/functional/page_objects/lens_page.ts:113:7)
[00:22:42]               │     at Context.<anonymous> (/dev/shm/workspace/parallel/1/kibana/x-pack/test/functional/apps/dashboard/sync_colors.ts:55:7)
[00:22:42]               │     at Object.apply (/dev/shm/workspace/parallel/1/kibana/node_modules/@kbn/test/src/functional_test_runner/lib/mocha/wrap_function.js:73:16)
[00:22:42]               │   Error: retry.try timeout: Error: retry.try timeout: TimeoutError: Waiting for element to be located By(css selector, [data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"])
[00:22:42]               │   Wait timed out after 10022ms
[00:22:42]               │       at /dev/shm/workspace/parallel/1/kibana/node_modules/selenium-webdriver/lib/webdriver.js:842:17
[00:22:42]               │       at runMicrotasks (<anonymous>)
[00:22:42]               │       at processTicksAndRejections (internal/process/task_queues.js:93:5)
[00:22:42]               │       at onFailure (/dev/shm/workspace/parallel/1/kibana/test/common/services/retry/retry_for_success.ts:17:9)
[00:22:42]               │       at retryForSuccess (/dev/shm/workspace/parallel/1/kibana/test/common/services/retry/retry_for_success.ts:57:13)
[00:22:42]               │       at Retry.try (/dev/shm/workspace/parallel/1/kibana/test/common/services/retry/retry.ts:32:14)
[00:22:42]               │       at Proxy.clickByCssSelector (/dev/shm/workspace/parallel/1/kibana/test/functional/services/common/find.ts:420:7)
[00:22:42]               │       at TestSubjects.click (/dev/shm/workspace/parallel/1/kibana/test/functional/services/common/test_subjects.ts:109:7)
[00:22:42]               │       at /dev/shm/workspace/parallel/1/kibana/x-pack/test/functional/page_objects/lens_page.ts:114:9
[00:22:42]               │       at runAttempt (/dev/shm/workspace/parallel/1/kibana/test/common/services/retry/retry_for_success.ts:27:15)
[00:22:42]               │       at retryForSuccess (/dev/shm/workspace/parallel/1/kibana/test/common/services/retry/retry_for_success.ts:66:21)
[00:22:42]               │       at Retry.try (/dev/shm/workspace/parallel/1/kibana/test/common/services/retry/retry.ts:32:14)
[00:22:42]               │       at Object.configureDimension (test/functional/page_objects/lens_page.ts:113:7)
[00:22:42]               │       at Context.<anonymous> (test/functional/apps/dashboard/sync_colors.ts:55:7)
[00:22:42]               │       at Object.apply (/dev/shm/workspace/parallel/1/kibana/node_modules/@kbn/test/src/functional_test_runner/lib/mocha/wrap_function.js:73:16)
[00:22:42]               │       at onFailure (/dev/shm/workspace/parallel/1/kibana/test/common/services/retry/retry_for_success.ts:17:9)
[00:22:42]               │       at retryForSuccess (/dev/shm/workspace/parallel/1/kibana/test/common/services/retry/retry_for_success.ts:57:13)
[00:22:42]               │       at Retry.try (/dev/shm/workspace/parallel/1/kibana/test/common/services/retry/retry.ts:32:14)
[00:22:42]               │       at Object.configureDimension (test/functional/page_objects/lens_page.ts:113:7)
[00:22:42]               │       at Context.<anonymous> (test/functional/apps/dashboard/sync_colors.ts:55:7)
[00:22:42]               │       at Object.apply (/dev/shm/workspace/parallel/1/kibana/node_modules/@kbn/test/src/functional_test_runner/lib/mocha/wrap_function.js:73:16)
[00:22:42]               │ 
[00:22:42]               │ 

Stack Trace

Error: retry.try timeout: Error: retry.try timeout: TimeoutError: Waiting for element to be located By(css selector, [data-test-subj="lns-layerPanel-0"] [data-test-subj="lnsXY_yDimensionPanel"] [data-test-subj="lns-empty-dimension"])
Wait timed out after 10022ms
    at /dev/shm/workspace/parallel/1/kibana/node_modules/selenium-webdriver/lib/webdriver.js:842:17
    at runMicrotasks (<anonymous>)
    at processTicksAndRejections (internal/process/task_queues.js:93:5)
    at onFailure (/dev/shm/workspace/parallel/1/kibana/test/common/services/retry/retry_for_success.ts:17:9)
    at retryForSuccess (/dev/shm/workspace/parallel/1/kibana/test/common/services/retry/retry_for_success.ts:57:13)
    at Retry.try (/dev/shm/workspace/parallel/1/kibana/test/common/services/retry/retry.ts:32:14)
    at Proxy.clickByCssSelector (/dev/shm/workspace/parallel/1/kibana/test/functional/services/common/find.ts:420:7)
    at TestSubjects.click (/dev/shm/workspace/parallel/1/kibana/test/functional/services/common/test_subjects.ts:109:7)
    at /dev/shm/workspace/parallel/1/kibana/x-pack/test/functional/page_objects/lens_page.ts:114:9
    at runAttempt (/dev/shm/workspace/parallel/1/kibana/test/common/services/retry/retry_for_success.ts:27:15)
    at retryForSuccess (/dev/shm/workspace/parallel/1/kibana/test/common/services/retry/retry_for_success.ts:66:21)
    at Retry.try (/dev/shm/workspace/parallel/1/kibana/test/common/services/retry/retry.ts:32:14)
    at Object.configureDimension (test/functional/page_objects/lens_page.ts:113:7)
    at Context.<anonymous> (test/functional/apps/dashboard/sync_colors.ts:55:7)
    at Object.apply (/dev/shm/workspace/parallel/1/kibana/node_modules/@kbn/test/src/functional_test_runner/lib/mocha/wrap_function.js:73:16)
    at onFailure (/dev/shm/workspace/parallel/1/kibana/test/common/services/retry/retry_for_success.ts:17:9)
    at retryForSuccess (/dev/shm/workspace/parallel/1/kibana/test/common/services/retry/retry_for_success.ts:57:13)
    at Retry.try (/dev/shm/workspace/parallel/1/kibana/test/common/services/retry/retry.ts:32:14)
    at Object.configureDimension (test/functional/page_objects/lens_page.ts:113:7)
    at Context.<anonymous> (test/functional/apps/dashboard/sync_colors.ts:55:7)
    at Object.apply (/dev/shm/workspace/parallel/1/kibana/node_modules/@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

@afharo afharo merged commit db7f279 into elastic:master Apr 20, 2021
@afharo afharo deleted the http_server/graceful-shutdown branch April 20, 2021 14:03
kibanamachine added a commit to kibanamachine/kibana that referenced this pull request Apr 20, 2021
Co-authored-by: Kibana Machine <42973632+kibanamachine@users.noreply.github.com>
@kibanamachine
Copy link
Contributor

💚 Backport successful

Status Branch Result
7.x

This backport PR will be merged automatically after passing CI.

kibanamachine added a commit that referenced this pull request Apr 20, 2021
Co-authored-by: Kibana Machine <42973632+kibanamachine@users.noreply.github.com>

Co-authored-by: Alejandro Fernández Haro <alejandro.haro@elastic.co>
@afharo afharo mentioned this pull request Apr 20, 2021
9 tasks
jbudz added a commit to jbudz/kibana that referenced this pull request May 24, 2021
The default setting for `server.shutdownTimeout` is 30s.  Docker's
default stop behavior is to send a SIGKILL after 10s.  This sets the
graceful shutdown behavior to be inline with Docker defaults.

Related to elastic#97223.  Closes elastic#97658
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
auto-backport Deprecated - use backport:version if exact versions are needed release_note:enhancement Team:Core Core services & architecture: plugins, logging, config, saved objects, http, ES client, i18n, etc Team:Operations Team label for Operations Team v7.13.0
Projects
None yet
Development

Successfully merging this pull request may close these issues.

SIGTERM should gracefully shutdown Kibana
8 participants