mash: browser_tests shutdown crashes in net::URLRequestContext::CreateRequest() |
||||||||
Issue descriptionChrome ToT r519699 on linux, target_os=chromeos browser_tests --mash --gtest_filter=DefaultProfileExtensionBrowserTest.NoExtensionHosts ... [56989:56989:1128/153531.340674:WARNING:pref_notifier_impl.cc(23)] Pref observer found at shutdown. [56989:56989:1128/153531.340794:WARNING:pref_notifier_impl.cc(23)] Pref observer found at shutdown. BrowserTestBase received signal: Segmentation fault. Backtrace: #0 0x7fccda0b15dd base::debug::StackTrace::StackTrace() #1 0x7fccda0afb5c base::debug::StackTrace::StackTrace() #2 0x0000066c8bde <unknown> #3 0x7fccbc51ecb0 <unknown> #4 0x7fccd97c8e9e net::URLRequestContext::CreateRequest() #5 0x7fccd23820ce content::ResourceDispatcherHostImpl::ContinuePendingBeginRequest() #6 0x7fccd237ecec content::ResourceDispatcherHostImpl::BeginRequest() #7 0x7fccd237d966 content::ResourceDispatcherHostImpl::OnRequestResourceInternal() #8 0x7fccd2392728 content::ResourceDispatcherHostImpl::OnRequestResourceWithMojo() #9 0x7fccd23d8e75 content::URLLoaderFactoryImpl::CreateLoaderAndStart() #10 0x7fccd23b9330 content::ResourceMessageFilter::CreateLoaderAndStart() #11 0x7fccd23b93b0 content::ResourceMessageFilter::CreateLoaderAndStart() #12 0x7fccd118f90a content::mojom::URLLoaderFactoryStubDispatch::Accept() #13 0x7fccd1ab2ae3 content::mojom::URLLoaderFactoryStub<>::Accept() #14 0x7fccd5c8015b mojo::InterfaceEndpointClient::HandleValidatedMessage() #15 0x7fccd5c7ecc1 mojo::InterfaceEndpointClient::HandleIncomingMessageThunk::Accept() #16 0x7fccd5c7d362 mojo::FilterChain::Accept() #17 0x7fccd5c82aef mojo::InterfaceEndpointClient::HandleIncomingMessage() #18 0x7fccd5bad18b IPC::(anonymous namespace)::ChannelAssociatedGroupController::Accept() #19 0x7fccd5c7d362 mojo::FilterChain::Accept() #20 0x7fccd5c71884 mojo::Connector::ReadSingleMessage() #21 0x7fccd5c726a1 mojo::Connector::ReadAllAvailableMessages() #22 0x7fccd5c724ee mojo::Connector::OnHandleReadyInternal() #23 0x7fccd5c723eb mojo::Connector::OnWatcherHandleReady() #24 0x7fccd5c7581f _ZN4base8internal13FunctorTraitsIMN4mojo9ConnectorEFvjEvE6InvokeIPS3_JjEEEvS5_OT_DpOT0_ #25 0x7fccd5c7574f _ZN4base8internal12InvokeHelperILb0EvE8MakeItSoIRKMN4mojo9ConnectorEFvjEJPS5_jEEEvOT_DpOT0_ #26 0x7fccd5c756e5 _ZN4base8internal7InvokerINS0_9BindStateIMN4mojo9ConnectorEFvjEJNS0_17UnretainedWrapperIS4_EEEEEFvjEE7RunImplIRKS6_RKNSt3__15tupleIJS8_EEEJLm0EEEEvOT_OT0_NSF_16integer_sequenceImJXspT1_EEEEOj #27 0x7fccd5c7561b _ZN4base8internal7InvokerINS0_9BindStateIMN4mojo9ConnectorEFvjEJNS0_17UnretainedWrapperIS4_EEEEEFvjEE3RunEPNS0_13BindStateBaseEj #28 0x7fccd5c6c86e _ZNKR4base17RepeatingCallbackIFvjEE3RunEj #29 0x7fccd5c7492f mojo::SimpleWatcher::DiscardReadyState() #30 0x7fccd5c74ba4 _ZN4base8internal13FunctorTraitsIPFvRKNS_17RepeatingCallbackIFvjEEEjRKN4mojo18HandleSignalsStateEEvE6InvokeIJS6_jSA_EEEvSC_DpOT_ #31 0x7fccd5c74b50 _ZN4base8internal12InvokeHelperILb0EvE8MakeItSoIRKPFvRKNS_17RepeatingCallbackIFvjEEEjRKN4mojo18HandleSignalsStateEEJS8_jSC_EEEvOT_DpOT0_ #32 0x7fccd5c74af0 _ZN4base8internal7InvokerINS0_9BindStateIPFvRKNS_17RepeatingCallbackIFvjEEEjRKN4mojo18HandleSignalsStateEEJS5_EEEFvjSB_EE7RunImplIRKSD_RKNSt3__15tupleIJS5_EEEJLm0EEEEvOT_OT0_NSK_16integer_sequenceImJXspT1_EEEEOjSB_ #33 0x7fccd5c74a26 _ZN4base8internal7InvokerINS0_9BindStateIPFvRKNS_17RepeatingCallbackIFvjEEEjRKN4mojo18HandleSignalsStateEEJS5_EEEFvjSB_EE3RunEPNS0_13BindStateBaseEjSB_ #34 0x7fccd5c0b5ce _ZNKR4base17RepeatingCallbackIFvjRKN4mojo18HandleSignalsStateEEE3RunEjS4_ #35 0x7fccd5c0ae84 mojo::SimpleWatcher::OnHandleReady() #36 0x7fccd5c0bdc3 _ZN4base8internal13FunctorTraitsIMN4mojo13SimpleWatcherEFvijRKNS2_18HandleSignalsStateEEvE6InvokeIRKNS_7WeakPtrIS3_EEJRKiRKjS6_EEEvS8_OT_DpOT0_ #37 0x7fccd5c0bd05 _ZN4base8internal12InvokeHelperILb1EvE8MakeItSoIRKMN4mojo13SimpleWatcherEFvijRKNS4_18HandleSignalsStateEERKNS_7WeakPtrIS5_EEJRKiRKjS8_EEEvOT_OT0_DpOT1_ #38 0x7fccd5c0bc62 _ZN4base8internal7InvokerINS0_9BindStateIMN4mojo13SimpleWatcherEFvijRKNS3_18HandleSignalsStateEEJNS_7WeakPtrIS4_EEijS5_EEEFvvEE7RunImplIRKS9_RKNSt3__15tupleIJSB_ijS5_EEEJLm0ELm1ELm2ELm3EEEEvOT_OT0_NSI_16integer_sequenceImJXspT1_EEEE #39 0x7fccd5c0badc _ZN4base8internal7InvokerINS0_9BindStateIMN4mojo13SimpleWatcherEFvijRKNS3_18HandleSignalsStateEEJNS_7WeakPtrIS4_EEijS5_EEEFvvEE3RunEPNS0_13BindStateBaseE #40 0x7fccda05d0b1 _ZNO4base12OnceCallbackIFvvEE3RunEv #41 0x7fccda0b63d0 base::debug::TaskAnnotator::RunTask() #42 0x7fccda1563c3 base::internal::IncomingTaskQueue::RunTask() #43 0x7fccda15e658 base::MessageLoop::RunTask() #44 0x7fccda15e8d3 base::MessageLoop::DeferOrRunPendingTask() #45 0x7fccda15ebd1 base::MessageLoop::DoWork() #46 0x7fccda164eb3 base::MessagePumpLibevent::Run() #47 0x7fccda15df06 base::MessageLoop::Run() #48 0x7fccda20fa9d base::RunLoop::Run() #49 0x7fccda2d4f82 base::Thread::Run() #50 0x7fccd1c35ce8 content::BrowserThreadImpl::IOThreadRun() #51 0x7fccd1c35f81 content::BrowserThreadImpl::Run() #52 0x7fccda2d5b40 base::Thread::ThreadMain() #53 0x7fccda2bb301 base::(anonymous namespace)::ThreadFunc() #54 0x7fccda4e2184 start_thread #55 0x7fccbc5e5ffd clone [1128/153531.915505:ERROR:kill_posix.cc(84)] Unable to terminate process group 56989: No such process (3) [1/1] DefaultProfileExtensionBrowserTest.NoExtensionHosts (CRASHED) The crash happens after the end of the test body, during teardown. Many of our browser_tests --mash fail with this crash, for example: -AffiliationCheck/EnterpriseDeviceAttributesTest.* -AffiliationCheck/UserAffiliationBrowserTest.* -DefaultProfileExtensionBrowserTest.* -ExistingUserControllerActiveDirectoryTest.* -ExistingUserControllerPublicSessionTest.* -ExistingUserControllerUntrustedTest.* -PreinstalledSigninExtensionsDeviceCloudPolicyBrowserTest.* -SigninExtensionsDeviceCloudPolicyBrowserTest.* -SigninProfileAppsPolicyPerChannelTest.* -SigninProfileAppsPolicyTest.* I've seen warnings about a keep alive registry not being empty, and also crashes about tasks not running on a valid sequence. This might be related somehow to login webui.
,
Nov 29 2017
haraken, are you familiar with this area? Or can you direct me to someone who is more familiar? I mostly work on Chrome OS UI and I'm not very familiar with the network loading code. The URLRequestContext object here is null: https://cs.chromium.org/chromium/src/content/browser/loader/resource_dispatcher_host_impl.cc?type=cs&q=content::ResourceDispatcherHostImpl::ContinuePendingBeginRequest&sq=package:chromium&l=1207 The URLRequestContext comes from a content::ResourceRequesterInfo through a series of callbacks. I'm not sure which class is actually generating the URLRequestContext. ResourceRequesterInfo has type_ RequesterType::RENDERER. The URL being loaded is "chrome://resources/html/polymer.html" I'm guessing a mojo message with a load request is coming in during browser process shutdown. There seems to be code in place to try to cancel or block network requests during shutdown. I'm guessing this is a lifetime issue, like the ResourceMessageFilter needs to explicitly close mojo bindings or cancel requests earlier in shutdown. However, I don't know this code at all and I'm pretty lost.
,
Nov 29 2017
kinuko: Would anyone in the loading team want to help on this?
,
Nov 29 2017
FYI, --mash is a flag that runs the chromeos system UI out-of-process. See go/mustash for details. It shouldn't affect this crash. I've seen this crash sometimes without the flag. I suspect the flag just changes timing.
,
Nov 30 2017
kinuko - if someone on the loading team would like to take this bug, please feel free to reassign. Otherwise I will keep looking.
More debugging notes:
* The URLRequestContext comes from a ChromeURLRequestContextGetter
* That getter had NotifyContextShuttingDown called, so it returns a null context
When I run the test without --mash I see these interesting logs during shutdown, after the test completes:
[159283:159283:1129/145955.024115:WARNING:url_request_context_getter.cc(43)] URLRequestContextGetter leaking due to no owning thread.
...
[159283:159283:1129/145955.048042:ERROR:keep_alive_registry.cc(88)] KeepAliveRegistry not empty at destruction time. State:{registered_count_=1, restart_allowed_count_=0, KeepAlives=[LOGIN_DISPLAY_HOST_WEBUI (1)]}
The crash with another test (ExistingUserControllerUntrustedTest.ExistingUserLoginForbidden) looks identical.
,
Nov 30 2017
Could this be caused by a piece of webui being destroyed too late in shutdown? It's possible the Chrome OS login screen (which is webui) is being destroyed late.
,
Nov 30 2017
,
Nov 30 2017
We leak LoginDisplayHostWebUI in these tests, both with and without --mash. If I force it to be deleted at the end of DefaultProfileExtensionBrowserTest.NoExtensionHosts the crash under --mash goes away. Hacky patch with lots of logging: https://chromium-review.googlesource.com/#/c/chromium/src/+/797473 I think we should not be leaking this object. xiyuan is going to take a look -- thanks! Other notes: * DefaultProfileExtensionBrowserTest.NoExtensionHosts is not flaky on the bots (without --mash) * DefaultProfileExtensionBrowserTest and ExistingUserControllerTest do not share a base class. * ExistingUserControllerTest sets up a MockLoginDisplayHost and a MockLoginDisplay. * SigninProfileAppsPolicyTest shares a base with ExistingUserControllerTest (it's DevicePolicyCrosBrowserTest) * SigninProfileAppsPolicyTest manipulates the sign-in profile, as does DefaultProfileExtensionBrowserTest * There's a maybe-related shutdown DCHECK I see sometimes in ~SiteProcessCountTracker, issue 784293 . I still don't know if the resource loading code requires all renderers/webui to be shut down before profile teardown. It seems like ResourceMessageFilter::OnChannelClosed() must be called to avoid this crash, and that happens if we don't leak the LoginDisplayHostWebUI, but I don't know who owns the channel or why it stays alive with --mash. +yhirano, I think you worked on the mojo URLLoaderFactory, do you know which channel needs to be closed here?
,
Dec 1 2017
LoginDisplayHostWebUI code cleans up webui using the following 2 signal: - NOTIFICATION_CLOSE_ALL_BROWSERS_REQUEST [1] - LoginDisplayHostWebUI::LoginWidgetDelegate::WindowClosing [2] In a real browser run, the 2 signal are the same thing. We get NOTIFICATION_CLOSE_ALL_BROWSERS_REQUEST on shutdown then it schedule LoginDisplayHostWebUI to be deleted. In browser test, the notification does not happen. In classic ash, this is fine because login screen widget is closed when shell shuts down. But in mash, we don't have code to close the login screen widget and since browser does not send the notification either, the login screen widget and its webui is leaked. [1] https://cs.chromium.org/chromium/src/chrome/browser/chromeos/login/ui/login_display_host_webui.cc?rcl=955ba583f11e21c4be789358a1e0dda4649ec7f3&l=950 [2] https://cs.chromium.org/chromium/src/chrome/browser/chromeos/login/ui/login_display_host_webui.cc?rcl=955ba583f11e21c4be789358a1e0dda4649ec7f3&l=408
,
Dec 8 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/a654738276e51308748bb6e7b527a0a24debef0a commit a654738276e51308748bb6e7b527a0a24debef0a Author: Xiyuan Xia <xiyuan@chromium.org> Date: Fri Dec 08 16:25:08 2017 Fix mash browser_tests shutdown crash The net::URLRequestContext::CreateRequest() crash at shutdown in mash browser_test is because ChromeOS login screen is leaked. The leak happens because the login screen cleans up on either NOTIFICATION_CLOSE_ALL_BROWSERS_REQUEST or its widget being closed. But neither happens in mash browser_tests. The CL fixes the issue by closing all widgets when leaving the main message loop to match the classic ash behavior. Bug: 789324 Change-Id: I71c83b61451194abe689673a42e19990bce363b3 Reviewed-on: https://chromium-review.googlesource.com/809830 Reviewed-by: Scott Violet <sky@chromium.org> Commit-Queue: Xiyuan Xia <xiyuan@chromium.org> Cr-Commit-Position: refs/heads/master@{#522790} [modify] https://crrev.com/a654738276e51308748bb6e7b527a0a24debef0a/chrome/browser/chromeos/login/ui/login_display_host_webui.cc [modify] https://crrev.com/a654738276e51308748bb6e7b527a0a24debef0a/chrome/browser/lifetime/application_lifetime_aura.cc [modify] https://crrev.com/a654738276e51308748bb6e7b527a0a24debef0a/chrome/test/base/in_process_browser_test.cc [modify] https://crrev.com/a654738276e51308748bb6e7b527a0a24debef0a/testing/buildbot/filters/mojo.fyi.mash.browser_tests.filter [modify] https://crrev.com/a654738276e51308748bb6e7b527a0a24debef0a/ui/views/mus/mus_client.cc [modify] https://crrev.com/a654738276e51308748bb6e7b527a0a24debef0a/ui/views/mus/mus_client.h
,
Dec 8 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/1a92b11ea28af4f0c1721ee0295e3e8cf8d8b7c2 commit 1a92b11ea28af4f0c1721ee0295e3e8cf8d8b7c2 Author: Xiyuan Xia <xiyuan@chromium.org> Date: Fri Dec 08 23:04:22 2017 cros: Update login screen shutdown code - Use NOTIFICATION_APP_TERMINATING since holding a keep alive ref no longer blocks it. And unlike CLOSE_ALL_BROWSERS_REQUEST, it is sent at the end of browser test; - Login screen should be closed on the app shutdown code path and tests no longer need to close it explicitly; Bug: 789324 Change-Id: I08cb0b5ca00d47fb445442a2f2c9eee0753b8a61 Reviewed-on: https://chromium-review.googlesource.com/817857 Reviewed-by: James Cook <jamescook@chromium.org> Reviewed-by: Yves Arrouye <drcrash@chromium.org> Commit-Queue: Xiyuan Xia <xiyuan@chromium.org> Cr-Commit-Position: refs/heads/master@{#522907} [modify] https://crrev.com/1a92b11ea28af4f0c1721ee0295e3e8cf8d8b7c2/chrome/browser/chromeos/login/existing_user_controller_browsertest.cc [modify] https://crrev.com/1a92b11ea28af4f0c1721ee0295e3e8cf8d8b7c2/chrome/browser/chromeos/login/login_browsertest.cc [modify] https://crrev.com/1a92b11ea28af4f0c1721ee0295e3e8cf8d8b7c2/chrome/browser/chromeos/login/login_manager_test.cc [modify] https://crrev.com/1a92b11ea28af4f0c1721ee0295e3e8cf8d8b7c2/chrome/browser/chromeos/login/test/oobe_base_test.cc [modify] https://crrev.com/1a92b11ea28af4f0c1721ee0295e3e8cf8d8b7c2/chrome/browser/chromeos/login/test/wizard_in_process_browser_test.cc [modify] https://crrev.com/1a92b11ea28af4f0c1721ee0295e3e8cf8d8b7c2/chrome/browser/chromeos/login/ui/captive_portal_window_browsertest.cc [modify] https://crrev.com/1a92b11ea28af4f0c1721ee0295e3e8cf8d8b7c2/chrome/browser/chromeos/login/ui/login_display_host_webui.cc [modify] https://crrev.com/1a92b11ea28af4f0c1721ee0295e3e8cf8d8b7c2/chrome/browser/chromeos/login/ui/login_display_host_webui.h [modify] https://crrev.com/1a92b11ea28af4f0c1721ee0295e3e8cf8d8b7c2/chrome/browser/extensions/api/enterprise_platform_keys/enterprise_platform_keys_apitest_nss.cc
,
Dec 8 2017
,
Jul 30
|
||||||||
►
Sign in to add a comment |
||||||||
Comment 1 by jamescook@chromium.org
, Nov 28 2017