New issue
Advanced search Search tips
Note: Color blocks (like █ or █) mean that a user may not be available. Tooltip shows the reason.

Issue 848192 link

Starred by 2 users
Status: WontFix
Owner:
marcore@chromium.org
Closed: Jul 2
Cc:
marcore@chromium.org
█ jayhlee@chromium.org
mcasas@chromium.org
█ marc...@chromium.org
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 2
Type: Bug



Sign in to add a comment

white screen after wake-up Panther

Project Member Reported by marcore@chromium.org, May 31 2018 
ChromeOS version: 66.0.3359.158
ChromeOS device model: ASUS Chromebox CN60 Panther
Case#: 15838418

Description: when the ChromeBox is returning from sleep there is a white screen and the ChromeBox is unresponsive


Steps to reproduce: 
let the ChromeBox sleep (logs from eventlog.txt):
262 | 2018-05-29 10:11:38 | ACPI Enter | S3
wake up:
263 | 2018-05-29 10:24:36 | ACPI Wake | S3

Current Behavior / Reproduction: 
a white screen is shown
the customer is force to reboot the device:
267 | 2018-05-29 10:33:30 | Power Button Override
video: https://drive.google.com/open?id=19yX7DE8fIlp8kFIM98w86IDPCE-p71SI
Expected Behavior: 
the device shows the normal screen.

Drive link to logs: https://drive.google.com/open?id=1eLF5Rz8o8H6_LGp5oKx1j2ymZZFPbAI4

policy: https://drive.google.com/open?id=1RpG6LVwXTbI6dndV3Qix0QmYAHeGQhAG
customer info: https://drive.google.com/open?id=1fq3ADipCNs0eTYQm2FdVZ4h1yJGHXjBlH6Jn58G2zRw

the customer narrowed down a time frame to Tuesday, May 29th at around 10:20 am.
the monitor is connected via HDMI

Comment 1 by tbroch@chromium.org, Jun 9 2018

Components: OS>Kernel>Display
From logs it looks like the device woke from suspend properly and attempted to drive the screens accordingly.  There are quite a few power button presses (powerd log) which I assume were in response to white screen.

Nothing alarming in messages, ui or chrome log either AFAICT.  Included those log snippets below in case others seem something.

Does the repro happen every time?  
Does repro happen on multiple panther devices?  
Does repro happen on same panther with different external display?

Don't see anything that points to power in particular.  Adding display component as well for additional triage.

----------------------

from powerd log,

[0529/101137:INFO:suspend_delay_controller.cc(223)] Notifying observers that suspend is ready
[0529/101137:INFO:suspender.cc(456)] Starting suspend
[0529/101137:INFO:main.cc(258)] Running "/usr/bin/powerd_setuid_helper --action=suspend  --suspend_wakeup_count_valid --suspend_wakeup_count=1"
[0529/102436:INFO:daemon.cc(687)] powerd_suspend returned 0
[0529/102436:INFO:suspender.cc(414)] Finishing request 36438018 successfully
[0529/102436:INFO:state_controller.cc(96)] Undimming screen
[0529/102436:INFO:display_power_setter.cc(67)] Asking DisplayService to undim the display in software
[0529/102436:INFO:state_controller.cc(96)] Turning screen on
[0529/102436:INFO:display_power_setter.cc(81)] Asking DisplayService to turn all displays on
[0529/102437:INFO:daemon.cc(1419)] Chrome is using normal display mode
[0529/102437:INFO:audio_client.cc(120)] Updated audio devices: headphones unplugged, HDMI active
[0529/102439:INFO:activity_logger.cc(20)] User activity reported
[0529/102452:INFO:daemon.cc(1419)] Chrome is using normal display mode
[0529/102507:INFO:daemon.cc(524)] Power button down
[0529/102507:INFO:main.cc(239)] Launching "sync"
[0529/102507:INFO:daemon.cc(524)] Power button up
[0529/102511:INFO:daemon.cc(524)] Power button down
[0529/102511:INFO:main.cc(239)] Launching "sync"
[0529/102511:INFO:daemon.cc(524)] Power button up
[0529/102515:INFO:daemon.cc(524)] Power button down
[0529/102515:INFO:main.cc(239)] Launching "sync"
[0529/102515:INFO:daemon.cc(524)] Power button up
[0529/102517:INFO:daemon.cc(524)] Power button down
[0529/102517:INFO:main.cc(239)] Launching "sync"
[0529/102517:INFO:daemon.cc(524)] Power button up
[0529/102521:INFO:daemon.cc(524)] Power button down
[0529/102521:INFO:main.cc(239)] Launching "sync"
[0529/102521:INFO:daemon.cc(524)] Power button up
[0529/102525:INFO:daemon.cc(524)] Power button down
[0529/102525:INFO:main.cc(239)] Launching "sync"
[0529/102525:INFO:daemon.cc(524)] Power button up
[0529/102527:INFO:daemon.cc(524)] Power button down
[0529/102527:INFO:main.cc(239)] Launching "sync"
[0529/102527:INFO:daemon.cc(524)] Power button up
[0529/102530:INFO:daemon.cc(524)] Power button down
[0529/102530:INFO:main.cc(239)] Launching "sync"
[0529/102530:INFO:daemon.cc(524)] Power button up
[0529/102537:INFO:daemon.cc(524)] Power button down
[0529/102537:INFO:main.cc(239)] Launching "sync"
[0529/102537:INFO:daemon.cc(524)] Power button up
[0529/102557:INFO:activity_logger.cc(20)] User activity stopped; last reported 20 sec ago
[0529/102722:INFO:daemon.cc(1419)] Chrome is using normal display mode
[0529/102723:INFO:daemon.cc(524)] Power button down
[0529/102723:INFO:main.cc(239)] Launching "sync"
[0529/102723:INFO:daemon.cc(524)] Power button up
[0529/102723:INFO:activity_logger.cc(20)] User activity reported
[0529/102743:INFO:activity_logger.cc(20)] User activity stopped; last reported 20 sec ago
[0529/102817:INFO:daemon.cc(1541)] Update operation is UPDATE_STATUS_CHECKING_FOR_UPDATE
[0529/102817:INFO:daemon.cc(1541)] Update operation is UPDATE_STATUS_IDLE
[0529/103249:INFO:daemon.cc(524)] Power button down
[0529/103249:INFO:main.cc(239)] Launching "sync"
[0529/103249:INFO:daemon.cc(524)] Power button up
[0529/103249:INFO:activity_logger.cc(20)] User activity reported
[0529/103256:INFO:daemon.cc(524)] Power button down
[0529/103256:INFO:main.cc(239)] Launching "sync"
[0529/103256:INFO:daemon.cc(524)] Power button up

from messages,

2018-05-29T10:24:36.710499-04:00 INFO kernel: [ 6760.137285] PM: resume of devices complete after 129.121 msecs
2018-05-29T10:24:36.710500-04:00 WARNING kernel: [ 6760.157649] atkbd serio0: GETID failed
2018-05-29T10:24:36.710502-04:00 WARNING kernel: [ 6760.184272] atkbd serio0: atkbd: SETLEDS failed
2018-05-29T10:24:36.710503-04:00 WARNING kernel: [ 6760.241602] atkbd serio0: GETID failed
2018-05-29T10:24:36.710505-04:00 WARNING kernel: [ 6760.268226] atkbd serio0: atkbd: SETLEDS failed
2018-05-29T10:24:36.710510-04:00 INFO kernel: [ 6760.291790] ata1: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
2018-05-29T10:24:36.710512-04:00 INFO kernel: [ 6760.292523] ata1.00: configured for UDMA/133
2018-05-29T10:24:36.710513-04:00 WARNING kernel: [ 6760.323519] atkbd serio0: GETID failed
2018-05-29T10:24:36.710515-04:00 WARNING kernel: [ 6760.350144] atkbd serio0: atkbd: SETLEDS failed
2018-05-29T10:24:36.710517-04:00 WARNING kernel: [ 6760.405433] atkbd serio0: GETID failed
2018-05-29T10:24:36.710518-04:00 WARNING kernel: [ 6760.432053] atkbd serio0: atkbd: SETLEDS failed
2018-05-29T10:24:36.710520-04:00 WARNING kernel: [ 6760.487341] atkbd serio0: GETID failed
2018-05-29T10:24:36.710525-04:00 WARNING kernel: [ 6760.513959] atkbd serio0: atkbd: SETLEDS failed
2018-05-29T10:24:36.710527-04:00 ERR kernel: [ 6760.513982] atkbd serio0: probe failed
2018-05-29T10:24:36.710528-04:00 WARNING kernel: [ 6760.542622] psmouse serio0: GETID probe failed, retrying...
2018-05-29T10:24:36.710530-04:00 DEBUG kernel: [ 6760.596175] PM: Finishing wakeup.
2018-05-29T10:24:36.718166-04:00 NOTICE kernel: [ 6760.596184] Restarting tasks ... done.
2018-05-29T10:24:36.718185-04:00 INFO kernel: [ 6760.606919] video LNXVIDEO:00: Restoring backlight state
2018-05-29T10:24:36.720524-04:00 NOTICE powerd_suspend[11475]: wake source: SMI_STS: PM1 #015#012PM1_STS: WAK PWRBTN #015#012In relocation handler: cpu 0#015
2018-05-29T10:24:36.728964-04:00 NOTICE powerd_suspend[11484]: Skipping enable BT HCI mode change event on non-Intel BT
2018-05-29T10:24:36.735152-04:00 WARNING kernel: [ 6760.624433] atkbd serio1: GETID failed
2018-05-29T10:24:36.735721-04:00 NOTICE powerd_suspend[11491]: Resume finished
2018-05-29T10:24:36.762152-04:00 WARNING kernel: [ 6760.651080] atkbd serio1: atkbd: SETLEDS failed
2018-05-29T10:24:36.762166-04:00 ERR kernel: [ 6760.651094] atkbd serio1: probe failed
2018-05-29T10:24:36.777771-04:00 INFO laptop-mode[11502]: Warning: Configuration file /etc/laptop-mode/conf.d/board-specific/*.conf is not readable, skipping.
2018-05-29T10:24:36.789168-04:00 WARNING kernel: [ 6760.677670] psmouse serio1: GETID probe failed, retrying...
2018-05-29T10:24:36.795667-04:00 INFO laptop-mode[11523]: Laptop mode 
2018-05-29T10:24:36.797011-04:00 INFO laptop-mode[11524]: enabled, 
2018-05-29T10:24:36.802529-04:00 INFO laptop-mode[11526]: not active [unchanged]
2018-05-29T10:24:37.700158-04:00 INFO kernel: [ 6761.588693] [drm] Enabling RC6 states: RC6 on, RC6p off, RC6pp off
2018-05-29T10:24:37.746645-04:00 ERR chrome[9701]: [9701:9701:0529/102437.746577:INFO:remote_commands_invalidator.cc(45)] Shutdown RemoteCommandsInvalidator.
2018-05-29T10:24:37.746736-04:00 ERR chrome[9701]: [9701:9701:0529/102437.746702:INFO:remote_commands_invalidator.cc(68)] Stopping RemoteCommandsInvalidator.
2018-05-29T10:24:37.747676-04:00 ERR chrome[9701]: [9701:9701:0529/102437.747637:INFO:remote_commands_invalidator.cc(167)] Unregister RemoteCommandsInvalidator.
2018-05-29T10:24:45.113052-04:00 ERR chrome[9701]: [9701:9701:0529/102445.112961:INFO:remote_commands_invalidator.cc(32)] Initialize RemoteCommandsInvalidator.
2018-05-29T10:24:45.113747-04:00 ERR chrome[9701]: [9701:9701:0529/102445.113285:INFO:remote_commands_invalidator.cc(57)] Starting RemoteCommandsInvalidator.
2018-05-29T10:24:45.113815-04:00 ERR chrome[9701]: [9701:9701:0529/102445.113783:INFO:remote_commands_invalidator.cc(123)] RemoteCommandsInvalidator ReloadPolicyData.
2018-05-29T10:24:45.113860-04:00 ERR chrome[9701]: [9701:9701:0529/102445.113835:INFO:remote_commands_invalidator.cc(147)] Register RemoteCommandsInvalidator.
2018-05-29T10:24:45.115205-04:00 ERR chrome[9701]: [9701:9701:0529/102445.113935:INFO:remote_commands_invalidator.cc(83)] RemoteCommandsInvalidator state changed: 3
2018-05-29T10:24:45.115305-04:00 ERR chrome[9701]: [9701:9701:0529/102445.115274:INFO:remote_commands_invalidator.cc(83)] RemoteCommandsInvalidator state changed: 3
2018-05-29T10:24:46.164275-04:00 ERR chrome[9701]: [9701:9701:0529/102446.164190:INFO:remote_commands_invalidator.cc(94)] RemoteCommandsInvalidator received invalidation.
2018-05-29T10:24:46.164487-04:00 ERR chrome[9701]: [9701:9701:0529/102446.164352:INFO:remote_commands_invalidator.cc(110)] Invalidations acknowledged.
2018-05-29T10:24:46.164660-04:00 ERR chrome[9701]: [9701:9701:0529/102446.164622:INFO:remote_commands_service.cc(36)] Fetching remote commands.
2018-05-29T10:24:46.258621-04:00 ERR chrome[9701]: [9701:9701:0529/102446.258544:INFO:remote_commands_service.cc(161)] Remote commands fetched.

chrome log,
[9701:9701:0529/102450.373463:VERBOSE1:drm_display_host_manager.cc(247)] Got display event CHANGE for /dev/dri/card0
[9701:9701:0529/102451.019362:VERBOSE1:drm_display_host_manager.cc(247)] Got display event CHANGE for /dev/dri/card0
[9828:9833:0529/102452.124002:WARNING:screen_manager.cc(115)] Display controller (crtc=19) already present.
[9701:9701:0529/102452.124445:VERBOSE1:display_configurator.cc(954)] Display snapshots invalidated.
[9701:9701:0529/102452.124548:VERBOSE1:update_display_configuration_task.cc(68)] OnDisplaysUpdated: new_display_state=SINGLE new_power_state=ALL_ON flags=0 force_configure=1 display_count=1
[9701:9701:0529/102452.124613:VERBOSE1:display_configurator.cc(210)] EnterState: display=SINGLE power=ALL_ON
[9828:9833:0529/102452.124940:VERBOSE1:drm_display.cc(105)] DRM configuring: device=/sys/devices/pci0000:00/0000:00:02.0/drm/card0 crtc=19 connector=28 origin=0,0 size=1920x1080
[9701:9701:0529/102452.125494:VERBOSE1:display_configurator.cc(1060)] OnConfigured: success=1 new_display_state=SINGLE new_power_state=ALL_ON
[9701:9701:0529/102720.478679:VERBOSE1:drm_display_host_manager.cc(247)] Got display event CHANGE for /dev/dri/card0
[9701:9701:0529/102721.124105:VERBOSE1:drm_display_host_manager.cc(247)] Got display event CHANGE for /dev/dri/card0
[9828:9833:0529/102722.228989:WARNING:screen_manager.cc(115)] Display controller (crtc=19) already present.
[9701:9701:0529/102722.229456:VERBOSE1:display_configurator.cc(954)] Display snapshots invalidated.
[9701:9701:0529/102722.229565:VERBOSE1:update_display_configuration_task.cc(68)] OnDisplaysUpdated: new_display_state=SINGLE new_power_state=ALL_ON flags=0 force_configure=1 display_count=1
[9701:9701:0529/102722.229632:VERBOSE1:display_configurator.cc(210)] EnterState: display=SINGLE power=ALL_ON
[9828:9833:0529/102722.229962:VERBOSE1:drm_display.cc(105)] DRM configuring: device=/sys/devices/pci0000:00/0000:00:02.0/drm/card0 crtc=19 connector=28 origin=0,0 size=1920x1080
[9701:9701:0529/102722.230376:VERBOSE1:display_configurator.cc(1060)] OnConfigured: success=1 new_display_state=SINGLE new_power_state=ALL_ON

Comment 2 by tbroch@chromium.org, Jun 29 2018

Owner: marcore@chromium.org
Status: Assigned (was: Untriaged)
marcore@, is this still relevant in M-67?  Are we able to repro locally?

Comment 3 by marcore@chromium.org, Jul 2

Status: WontFix (was: Assigned)
I don't know.
I have tried to reproduce on my systems, but I'm unable to reproduce.
the customer didn't want to go on with the investigation.
on 31 may they said:
"I’m just going to wipe all the machines and see if the problem returns."

we haven't received any other communication from the customer since then.
►

Sign in to add a comment