New issue
Advanced search Search tips

Issue 736815 link

Starred by 2 users

Issue metadata

Status: Archived
Owner:
Closed: Aug 2017
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 1
Type: Bug

Blocked on:
issue 740589



Sign in to add a comment

mushrome: Flaky crash in WindowTreeClient::SetDisplayConfiguration() in desktopui_MusLogin autotest

Project Member Reported by jamescook@chromium.org, Jun 26 2017

Issue description

Seen on board "candy" this morning. Other boards are fine, so this is probably flaky.

https://wmatrix.googleplex.com/testrun/unfiltered?test_ids=505015578
https://wmatrix.googleplex.com/unfiltered?hide_missing=True&releases=tot&tests=desktopui_MusLogin&days_back=14

Tail of the chrome log:

[5319:5319:0626/093613.722353:VERBOSE1:login_display_host_impl.cc(1187)] Login WebUI >> show login wnd on create
[5319:5319:0626/093613.754011:VERBOSE1:wizard_controller.cc(292)] Starting OOBE wizard with screen: unknown
[5319:5319:0626/093613.949051:VERBOSE1:wizard_controller.cc(450)] Showing network screen.
[1:5:0626/093614.086150:ERROR:layer_tree_host_impl.cc(2348)] Forcing zero-copy tile initialization as worker context is missing
[5319:5319:0626/093614.465154:VERBOSE1:display_configurator.cc(945)] Display snapshots invalidated.
[5319:5319:0626/093614.465218:VERBOSE1:update_display_configuration_task.cc(76)] OnDisplaysUpdated: new_display_state=SINGLE new_power_state=ALL_ON flags=0 force_configure=1 display_count=1
[5319:5319:0626/093614.465262:VERBOSE1:display_configurator.cc(213)] EnterState: display=SINGLE power=ALL_ON
[5319:5319:0626/093614.620327:WARNING:CONSOLE(0)] "Styling master document from stylesheets defined in HTML Imports is deprecated, and is planned to be removed in M65, around March 2018. Please refer to https://goo.gl/EGXzpw for possible migration paths.", source:  (0)
[5319:5319:0626/093614.770254:WARNING:CONSOLE(1)] "This file is deprecated. Please use `iron-flex-layout/iron-flex-layout-classes.html`, and one of the specific dom-modules instead", source: chrome://resources/polymer/v1_0/iron-flex-layout/classes/iron-shadow-flex-layout-extracted.js (1)
[5319:5319:0626/093614.798110:WARNING:CONSOLE(1)] "This file is deprecated. Please use `iron-flex-layout/iron-flex-layout-classes.html`, and one of the specific dom-modules instead", source: chrome://resources/polymer/v1_0/iron-flex-layout/classes/iron-flex-layout-extracted.js (1)
[5319:5319:0626/093614.935335:VERBOSE1:display_configurator.cc(1054)] OnConfigured: success=1 new_display_state=SINGLE new_power_state=ALL_ON
[5319:5319:0626/093614.936374:ERROR:screen_layout_observer.cc(262)] NOTREACHED() hit.

However, the crash isn't the NOTREACHED:

Crash reason:  SIGTRAP
Crash address: 0x0
Process uptime: not available

Thread 0 (crashed)
 0  chrome!aura::(anonymous namespace)::OnAckMustSucceed(bool) [window_tree_client.cc : 199 + 0x1]
 1  chrome!arc::mojom::AppInstance_CanHandleResolution_ForwardToCallback::Accept(mojo::Message*) [callback.h : 91 + 0x3]
 2  chrome!mojo::InterfaceEndpointClient::HandleValidatedMessage(mojo::Message*) [interface_endpoint_client.cc : 399 + 0x9]
 3  chrome!mojo::internal::MultiplexRouter::ProcessIncomingMessage(mojo::Message*, mojo::internal::MultiplexRouter::ClientCallBehavior, base::SequencedTaskRunner*) [multiplex_router.cc : 876 + 0xb]
 4  chrome!mojo::internal::MultiplexRouter::Accept(mojo::Message*) [multiplex_router.cc : 606 + 0xd]
 5  chrome!mojo::Connector::ReadSingleMessage(unsigned int*) [connector.cc : 390 + 0xd]
 6  chrome!mojo::Connector::ReadAllAvailableMessages() [connector.cc : 419 + 0xb]
 7  chrome!mojo::SimpleWatcher::OnHandleReady(int, unsigned int) [callback.h : 80 + 0x3]
 8  chrome!base::debug::TaskAnnotator::RunTask(char const*, base::PendingTask*) [callback.h : 91 + 0x3]
 9  chrome!base::MessageLoop::RunTask(base::PendingTask*) [message_loop.cc : 422 + 0xf]
10  chrome!base::MessageLoop::DoWork() [message_loop.cc : 433 + 0xb]
11  chrome!base::MessagePumpLibevent::Run(base::MessagePump::Delegate*) [message_pump_libevent.cc : 219 + 0x9]
12  chrome!base::RunLoop::Run() [run_loop.cc : 111 + 0x5]
13  chrome!ChromeBrowserMainParts::MainMessageLoopRun(int*) [chrome_browser_main.cc : 1950 + 0x8]
14  chrome!content::BrowserMainLoop::RunMainMessageLoopParts() [browser_main_loop.cc : 1143 + 0x3]
15  chrome!content::BrowserMainRunnerImpl::Run() [browser_main_runner.cc : 142 + 0x5]
16  chrome!content::BrowserMain(content::MainFunctionParams const&) [browser_main.cc : 46 + 0x6]
17  chrome!content::ContentMainRunnerImpl::Run() [content_main_runner.cc : 704 + 0x8]
18  chrome!service_manager::Main(service_manager::MainParams const&) [main.cc : 469 + 0xa]
19  chrome!content::ContentMain(content::ContentMainParams const&) [content_main.cc : 19 + 0x8]
20  chrome!ChromeMain [chrome_main.cc : 125 + 0x5]

Callback is from  WindowTreeClient::SetDisplayConfiguration()

https://cs.chromium.org/chromium/src/ui/aura/mus/window_tree_client.cc?type=cs&q=OnAckMustSucceed&sq=package:chromium&l=1912

Rob thinks this might be related to simple display management.

 
Same failure on the previous build on gnawty. https://wmatrix.googleplex.com/testrun/unfiltered?test_ids=504820122

That build passed on the latest run, so this is definitely flaky, and probably not new.

I got more logs out of that one:

[8098:8098:0625/234505.842348:262082327:VERBOSE1:drm_device_handle.cc(83)] Succeeded authenticating /dev/dri/card0 in 0 ms with 1 attempt(s)
device-enumerator: scan all dirs
  device-enumerator: scanning /sys/bus
  device-enumerator: scanning /sys/class
[8098:8098:0625/234507.103950:263343814:VERBOSE1:drm_display_host_manager.cc(247)] Got display event ADD for /dev/dri/card0
[8098:8098:0625/234507.107416:263347280:VERBOSE1:drm_display_host_manager.cc(247)] Got display event ADD for /dev/dri/card1
[8099:8099:0625/234507.109791:ERROR:ash_window_tree_host_mus.cc(39)] Not implemented reached in virtual bool ash::AshWindowTreeHostMus::ConfineCursorToRootWindow()
[8098:8145:0625/234507.110448:263350311:VERBOSE1:drm_device_handle.cc(83)] Succeeded authenticating /dev/dri/card1 in 0 ms with 1 attempt(s)
[8098:8144:0625/234507.114878:263354742:VERBOSE1:drm_device_manager.cc(54)] Could not initialize DRM device for /sys/devices/platform/vgem/drm/card1
device-enumerator: scan all dirs
  device-enumerator: scanning /sys/bus
  device-enumerator: scanning /sys/class
[8098:8141:0625/234507.142214:263382078:ERROR:vaapi_wrapper.cc(1213)] Could not get a valid VA display
[8099:8099:0625/234507.355782:ERROR:layer_tree_host_impl.cc(2348)] Forcing zero-copy tile initialization as worker context is missing
[1:5:0625/234507.956551:ERROR:layer_tree_host_impl.cc(2348)] Forcing zero-copy tile initialization as worker context is missing
[8098:8144:0625/234508.400973:264640835:VERBOSE1:drm_display.cc(102)] DRM configuring: device=/sys/devices/pci0000:00/0000:00:02.0/drm/card0 crtc=29 connector=51 origin=0,0 size=1366x768
[8099:8099:0625/234508.870769:ERROR:screen_layout_observer.cc(262)] NOTREACHED() hit.
[8098:8098:0625/234508.874852:265114717:ERROR:display_manager.cc(103)] SetDisplayConfiguration passed unknown display id 3850489720471552
[8090:8090:0625/234513.137459:269377323:ERROR:chrome_main_delegate.cc(1187)] Main process exiting because service content_packaged_services quit unexpectedly.
[8227:8227:0625/234513.692724:269932708:VERBOSE1:drm_device_handle.cc(83)] Succeeded authenticating /dev/dri/card0 in 0 ms with 1 attempt(s)
Cc: mustash-autotest-bugs@google.com sky@chromium.org jamescook@chromium.org
 Issue 732436  has been merged into this issue.
Cc: -mustash-autotest-bugs@google.com -sky@chromium.org
It looks like something weird is going on with the WindowTreeHost and the corresponding ws::Display is destroyed before DisplayManager::SetDisplayConfiguration() runs. Not sure what exactly is happening beyond that.

Comment 5 by sky@chromium.org, Jun 26 2017

Owner: kylec...@chromium.org
As Kyle mentions the NOTREACHED looks worrisome:

[5319:5319:0626/093614.936374:ERROR:screen_layout_observer.cc(262)] NOTREACHED() hit.


James extracted a link of a passing bot and it didn't have the NOTREACHED, so the NOTREACHED may be the real issue. Kyle said he would poke at this, so passing his way.
I haven't had much luck reproducing this but I've narrowed down what is happening. In the failing runs, DisplayConfigurator initially gets 0 displays and enters mode HEADLESS. Example logs from kefka:

[22254:22254:0707/182407.003057:1204558114:VERBOSE1:update_display_configuration_task.cc(76)] OnDisplaysUpdated: new_display_state=HEADLESS new_power_state=ALL_ON flags=1 force_configure=1 display_count=0
[22254:22254:0707/182407.003139:1204558193:VERBOSE1:display_configurator.cc(213)] EnterState: display=HEADLESS power=ALL_ON
[22254:22254:0707/182407.003183:1204558236:VERBOSE1:display_configurator.cc(1054)] OnConfigured: success=1 new_display_state=HEADLESS new_power_state=ALL_ON

I don't think this should happen because kefka has an internal display. Either DrmDisplayHostManager returns 0 displays incorrectly and ScreenManagerForwarding sends that over IPC correctly or ScreenManagerForwarding is sending 0 displays back to ForwardingDisplayDelegate incorrectly. I'm not sure which.

display::DisplayManager adds a dummy display in this case and continues with initializing a WindowTreeHost for that dummy display. When the real display information shows up later something goes wrong.

[22254:22254:0707/182408.267762:1205822822:VERBOSE1:display_configurator.cc(945)] Display snapshots invalidated.
[22254:22254:0707/182408.267858:1205822912:VERBOSE1:update_display_configuration_task.cc(76)] OnDisplaysUpdated: new_display_state=SINGLE new_power_state=ALL_ON flags=0 force_configure=1 display_count=1
[22254:22254:0707/182408.267910:1205822963:VERBOSE1:display_configurator.cc(213)] EnterState: display=SINGLE power=ALL_ON
[22252:22274:0707/182408.268179:1205823237:VERBOSE1:drm_display.cc(102)] DRM configuring: device=/sys/devices/pci0000:00/0000:00:02.0/drm/card0 crtc=26 connector=47 origin=0,0 size=1366x768
[22254:22254:0707/182408.463268:1206018329:VERBOSE1:display_configurator.cc(1054)] OnConfigured: success=1 new_display_state=SINGLE new_power_state=ALL_ON
[22254:22254:0707/182408.464749:1206019838:ERROR:screen_layout_observer.cc(262)] NOTREACHED() hit.
[22252:22252:0707/182408.466333:1206021392:ERROR:display_manager.cc(103)] SetDisplayConfiguration passed unknown display id 1881264395124736

It looks like ash doesn't understand that the dummy display and the real display are different displays. It doesn't destroy the old WindowTreeHost and create a new WindowTreeHost as a result. When ws::DisplayManager::SetDisplayConfiguration() gets the new display information it can't find a corresponding ws::Display and returns false. This result is sent back to ash which crashes because that is supposed to succeed.
Blockedon: 740589
Status: Fixed (was: Assigned)
Filed  issue 756941  to look at why it was sometimes starting in headless mode, but this crash was fixed.

Comment 9 by dchan@chromium.org, Jan 22 2018

Status: Archived (was: Fixed)
Components: -Internals>MUS Internals>Services>WindowService

Sign in to add a comment