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

Issue 709788 link

Starred by 2 users

Issue metadata

Status: Duplicate
Owner: ----
Closed: Apr 2017
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 3
Type: Bug



Sign in to add a comment

very long login delay on link with some chrome://flags set to non-default values

Project Member Reported by semenzato@chromium.org, Apr 9 2017

Issue description


This is similar to the delay when chrome://flags are set, and as a matter of fact, I have some chrome://flags set, but in the past the delay was never so long.  I just timed it, it was about 25s.

Note that this snippet of /home/chronos/user/log/chrome has a 25s delay just about at the right time.  However, it's not clear that there is anything blocking in there.


[16241:16241:0408/224708.295315:VERBOSE1:display_configurator.cc(217)] EnterState: display=SINGLE power=ALL_ON
[16241:16241:0408/224709.588180:INFO:remote_commands_invalidator.cc(32)] Initialize RemoteCommandsInvalidator.
[16241:16241:0408/224709.588305:INFO:remote_commands_invalidator.cc(57)] Starting RemoteCommandsInvalidator.
[16241:16241:0408/224709.588360:INFO:remote_commands_invalidator.cc(123)] RemoteCommandsInvalidator ReloadPolicyData.
[16241:16241:0408/224709.588410:INFO:remote_commands_invalidator.cc(147)] Register RemoteCommandsInvalidator.
[16241:16241:0408/224709.588460:INFO:remote_commands_invalidator.cc(83)] RemoteCommandsInvalidator state changed: 3
[16241:16241:0408/224709.588535:INFO:remote_commands_invalidator.cc(83)] RemoteCommandsInvalidator state changed: 3
[16241:16241:0408/224709.836654:VERBOSE1:display_configurator.cc(1061)] OnConfigured: success=1 new_display_state=SINGLE new_power_state=ALL_ON
[16241:16241:0408/224709.879478:VERBOSE1:display_color_manager_chromeos.cc(217)] No ICC file found with product id: 30e47903 for display id: 13761487533244416
[16241:16241:0408/224709.899532:ERROR:app_list_syncable_service.cc(1028)] Item not found in model: kfjbjgle { GCM } [wx] [INVALID[]]
[16241:16241:0408/224709.900108:ERROR:app_list_syncable_service.cc(1028)] Item not found in model: kbpgddbg { Hangouts call } [nzzk] [INVALID[]]
[16241:16241:0408/224709.900964:ERROR:app_list_syncable_service.cc(1028)] Item not found in model: kjebfhgl { Scratchpad } [nyn] [INVALID[]]
[16241:16241:0408/224709.901231:ERROR:app_list_syncable_service.cc(1028)] Item not found in model: fppdphmg { Google Play Movies } [nzzy] [INVALID[]]
[16241:16241:0408/224709.901549:ERROR:app_list_syncable_service.cc(1028)] Item not found in model: fobcpibf { Games } [nzs] [INVALID[]]
[16241:16241:0408/224709.902343:ERROR:app_list_syncable_service.cc(1028)] Item not found in model: bdehgigf { MindMeister } [wzzs] [INVALID[]]
[16241:16241:0408/224709.902730:ERROR:app_list_syncable_service.cc(1028)] Item not found in model: hcglmfcc { Google Photos } [nzyd] [INVALID[]]
[16241:16241:0408/224709.902968:ERROR:app_list_syncable_service.cc(1028)] Item not found in model: cnbgggch {  } [n] [zs]
[16241:16241:0408/224710.704914:VERBOSE1:oauth2_login_verifier.cc(82)] ListAccounts successful.
[16241:16336:0408/224710.750154:VERBOSE2:ppapi_plugin_process_host.cc(475)] ppapi plugin process launched.
[16241:16241:0408/224712.283202:INFO:remote_commands_service.cc(161)] Remote commands fetched.
[16241:16241:0408/224712.312422:WARNING:render_frame_host_impl.cc(2187)] OnDidStopLoading was called twice.
[16241:16241:0408/224715.924742:INFO:remote_commands_invalidator.cc(123)] RemoteCommandsInvalidator ReloadPolicyData.
[16241:16241:0408/224717.461499:VERBOSE1:user_image_manager_impl.cc(876)] Updating profile image for logged-in user.
[16241:16241:0408/224717.764779:WARNING:render_frame_host_impl.cc(2187)] OnDidStopLoading was called twice.
[16241:16241:0408/224742.801032: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)
[16241:16241:0408/224742.801738: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)
[16241:16241:0408/224742.815989:WARNING:statistics_provider.cc(370)] Requested statistic not found: Product_S/N
[16241:16241:0408/224742.816047:WARNING:statistics_provider.cc(370)] Requested statistic not found: serial_number
[16241:16241:0408/224742.816068:WARNING:statistics_provider.cc(370)] Requested statistic not found: Product_SN
[16241:16241:0408/224742.816088:WARNING:statistics_provider.cc(370)] Requested statistic not found: sn
[16241:16241:0408/224742.816626:WARNING:CONSOLE(0)] "/deep/ combinator is deprecated. See https://www.chromestatus.com/features/6750456638341120 for more details.", source:  (0)
 
This is the entire ui.LATEST:

libva info: VA-API version 0.39.2
libva info: va_getDriverName() returns 0
libva info: Trying to open /usr/lib64/va/drivers/i965_drv_video.so
libva info: Found init function __vaDriverInit_0_39
libva info: va_openDriver() returns 0
device-enumerator: scan all dirs
  device-enumerator: scanning /sys/bus
  device-enumerator: scanning /sys/class
device-enumerator: scan all dirs
  device-enumerator: scanning /sys/bus
  device-enumerator: scanning /sys/class
[15525:15743:0408/224635.049748:ERROR:wallpaper_manager_base.cc(588)] Failed to load custom wallpaper from its original fallback file path: /home/chronos/custom_wallpapers/original/14a5cce06020715703c80daf933d6f1290822246/1423613415697
[15525:15743:0408/224635.050060:ERROR:wallpaper_manager_base.cc(597)] Failed to load previously selected custom wallpaper. Fallback to default wallpaper. Expected wallpaper path: /home/chronos/custom_wallpapers/large/14a5cce06020715703c80daf933d6f1290822246/1423613415697
device-enumerator: scan all dirs
  device-enumerator: scanning /sys/bus
  device-enumerator: scanning /sys/class
[15525:15525:0408/224635.105831:ERROR:device_event_log_impl.cc(137)] [22:46:35.105] Network: network_handler_callbacks.cc:84 not-supported: /device/wlan0: org.chromium.flimflam.Error.NotSupported: This WiFi device does not support MAC address randomization
[15525:15743:0408/224636.200470:ERROR:wallpaper_manager_base.cc(588)] Failed to load custom wallpaper from its original fallback file path: /home/chronos/custom_wallpapers/original/14a5cce06020715703c80daf933d6f1290822246/1423613415697
[15525:15743:0408/224636.203254:ERROR:wallpaper_manager_base.cc(597)] Failed to load previously selected custom wallpaper. Fallback to default wallpaper. Expected wallpaper path: /home/chronos/custom_wallpapers/large/14a5cce06020715703c80daf933d6f1290822246/1423613415697
[1:1:0408/224637.543238:ERROR:KeyboardEventManager.cpp(427)] Not implemented reached in static bool blink::KeyboardEventManager::currentCapsLockState()
[15525:15525:0408/224642.548446:ERROR:configuration_policy_handler_list.cc(92)] Unknown policy: NTPContentSuggestionsEnabled
[15525:15525:0408/224642.552950:ERROR:configuration_policy_handler_list.cc(92)] Unknown policy: NTPContentSuggestionsEnabled
[15525:15525:0408/224642.701953:ERROR:global_shortcut_listener_ozone.cc(26)] GlobalShortcutListenerOzone object created
[15525:15525:0408/224642.702006:ERROR:global_shortcut_listener_ozone.cc(48)] Not implemented reached in virtual bool extensions::GlobalShortcutListenerOzone::RegisterAcceleratorImpl(const ui::Accelerator&)
[15525:15525:0408/224642.702038:ERROR:global_shortcut_listener_ozone.cc(48)] Not implemented reached in virtual bool extensions::GlobalShortcutListenerOzone::RegisterAcceleratorImpl(const ui::Accelerator&)
[15525:15525:0408/224642.702067:ERROR:global_shortcut_listener_ozone.cc(48)] Not implemented reached in virtual bool extensions::GlobalShortcutListenerOzone::RegisterAcceleratorImpl(const ui::Accelerator&)
[15525:15525:0408/224642.702094:ERROR:global_shortcut_listener_ozone.cc(48)] Not implemented reached in virtual bool extensions::GlobalShortcutListenerOzone::RegisterAcceleratorImpl(const ui::Accelerator&)
[15525:15525:0408/224644.491407:ERROR:account_info_fetcher.cc(58)] OnGetTokenFailure: Request canceled.
[0408/224706.374101:WARNING:diagnostics_writer.cc(209)] [FAIL] 009 PathUserData (Path contents too large (10213071097) for: /home/chronos)
[0408/224706.376204:WARNING:diagnostics_writer.cc(209)] [FAIL] 016 JSONLocalState (File too big)
[0408/224706.379659:WARNING:diagnostics_writer.cc(209)] Finished 18 tests.
[0408/224706.379683:WARNING:diagnostics_writer.cc(209)] Finished Recovery for: Install type
[0408/224706.379693:WARNING:diagnostics_writer.cc(209)] Finished Recovery for: Chrome version test
[0408/224706.379701:WARNING:diagnostics_writer.cc(209)] Finished Recovery for: User data path
[0408/224706.379709:WARNING:diagnostics_writer.cc(209)] Finished Recovery for: Local state path
[0408/224706.379758:WARNING:diagnostics_writer.cc(209)] Finished Recovery for: App dictionaries directory path
[0408/224706.379781:WARNING:diagnostics_writer.cc(209)] Finished Recovery for: Resources path
[0408/224706.379793:WARNING:diagnostics_writer.cc(209)] Finished Recovery for: Available disk space
[0408/224706.379805:WARNING:diagnostics_writer.cc(209)] Finished Recovery for: User preferences integrity
[0408/224706.379816:WARNING:diagnostics_writer.cc(209)] Finished Recovery for: Local state integrity
[0408/224706.379827:WARNING:diagnostics_writer.cc(209)] Finished Recovery for: Bookmark file
[0408/224706.379838:WARNING:diagnostics_writer.cc(209)] Finished Recovery for: Web Data database
[0408/224706.379848:WARNING:diagnostics_writer.cc(209)] Finished Recovery for: Cookie database
[0408/224706.379859:WARNING:diagnostics_writer.cc(209)] Finished Recovery for: Favicons database
[0408/224706.379870:WARNING:diagnostics_writer.cc(209)] Finished Recovery for: History database
[0408/224706.379881:WARNING:diagnostics_writer.cc(209)] Finished Recovery for: Top Sites database
[0408/224706.379891:WARNING:diagnostics_writer.cc(209)] Finished Recovery for: Database tracker database
[0408/224706.379903:WARNING:diagnostics_writer.cc(209)] Finished Recovery for: NSS certificate database
[0408/224706.379914:WARNING:diagnostics_writer.cc(209)] Finished Recovery for: NSS Key database
[0408/224706.379921:WARNING:diagnostics_writer.cc(209)] Finished All Recovery operations.
libva info: VA-API version 0.39.2
libva info: va_getDriverName() returns 0
libva info: Trying to open /usr/lib64/va/drivers/i965_drv_video.so
libva info: Found init function __vaDriverInit_0_39
libva info: va_openDriver() returns 0
[16241:16241:0408/224706.763734:ERROR:configuration_policy_handler_list.cc(92)] Unknown policy: NTPContentSuggestionsEnabled
[16241:16241:0408/224706.982514:ERROR:global_shortcut_listener_ozone.cc(26)] GlobalShortcutListenerOzone object created
[16241:16241:0408/224706.982556:ERROR:global_shortcut_listener_ozone.cc(48)] Not implemented reached in virtual bool extensions::GlobalShortcutListenerOzone::RegisterAcceleratorImpl(const ui::Accelerator&)
[16241:16241:0408/224706.982578:ERROR:global_shortcut_listener_ozone.cc(48)] Not implemented reached in virtual bool extensions::GlobalShortcutListenerOzone::RegisterAcceleratorImpl(const ui::Accelerator&)
[16241:16241:0408/224706.982598:ERROR:global_shortcut_listener_ozone.cc(48)] Not implemented reached in virtual bool extensions::GlobalShortcutListenerOzone::RegisterAcceleratorImpl(const ui::Accelerator&)
[16241:16241:0408/224706.982618:ERROR:global_shortcut_listener_ozone.cc(48)] Not implemented reached in virtual bool extensions::GlobalShortcutListenerOzone::RegisterAcceleratorImpl(const ui::Accelerator&)
device-enumerator: scan all dirs
  device-enumerator: scanning /sys/bus
  device-enumerator: scanning /sys/class
device-enumerator: scan all dirs
  device-enumerator: scanning /sys/bus
  device-enumerator: scanning /sys/class
device-enumerator: scan all dirs
  device-enumerator: scanning /sys/bus
[16241:16341:0408/224707.453739:ERROR:wallpaper_manager_base.cc(588)] Failed to load custom wallpaper from its original fallback file path: /home/chronos/custom_wallpapers/original/14a5cce06020715703c80daf933d6f1290822246/1423613415697
[16241:16341:0408/224707.453846:ERROR:wallpaper_manager_base.cc(597)] Failed to load previously selected custom wallpaper. Fallback to default wallpaper. Expected wallpaper path: /home/chronos/custom_wallpapers/large/14a5cce06020715703c80daf933d6f1290822246/1423613415697
  device-enumerator: scanning /sys/class
[16241:16241:0408/224707.514221:ERROR:configuration_policy_handler_list.cc(92)] Unknown policy: NTPContentSuggestionsEnabled
[16241:16241:0408/224707.767293:ERROR:device_event_log_impl.cc(137)] [22:47:07.767] Network: network_handler_callbacks.cc:84 not-supported: /device/wlan0: org.chromium.flimflam.Error.NotSupported: This WiFi device does not support MAC address randomization
[16241:16241:0408/224709.899532:ERROR:app_list_syncable_service.cc(1028)] Item not found in model: kfjbjgle { GCM } [wx] [INVALID[]]
[16241:16241:0408/224709.900108:ERROR:app_list_syncable_service.cc(1028)] Item not found in model: kbpgddbg { Hangouts call } [nzzk] [INVALID[]]
[16241:16241:0408/224709.900964:ERROR:app_list_syncable_service.cc(1028)] Item not found in model: kjebfhgl { Scratchpad } [nyn] [INVALID[]]
[16241:16241:0408/224709.901231:ERROR:app_list_syncable_service.cc(1028)] Item not found in model: fppdphmg { Google Play Movies } [nzzy] [INVALID[]]
[16241:16241:0408/224709.901549:ERROR:app_list_syncable_service.cc(1028)] Item not found in model: fobcpibf { Games } [nzs] [INVALID[]]
[16241:16241:0408/224709.902343:ERROR:app_list_syncable_service.cc(1028)] Item not found in model: bdehgigf { MindMeister } [wzzs] [INVALID[]]
[16241:16241:0408/224709.902730:ERROR:app_list_syncable_service.cc(1028)] Item not found in model: hcglmfcc { Google Photos } [nzyd] [INVALID[]]
[16241:16241:0408/224709.902968:ERROR:app_list_syncable_service.cc(1028)] Item not found in model: cnbgggch {  } [n] [zs]
[1,2133653376:05:47:11.651561] Native Client module will be loaded at base address 0x0000740800000000
device-enumerator: scan all dirs
  device-enumerator: scanning /sys/bus
  device-enumerator: scanning /sys/class
[1,2133653376:05:47:19.245433] Native Client module will be loaded at base address 0x0000404f00000000
[16241:16343:0408/225324.613317:ERROR:change_list_processor.cc(315)] ApplyEntry failed: FILE_ERROR_NOT_A_DIRECTORY, title = IMVP8_KBL-Y_SA_Val_rev1_0.xlsx
Relevant part of /var/log/messages:

2017-04-08T22:46:51.030733-07:00 DEBUG kernel: [14141.306570] wlan0: cancelling probereq poll due to a received beacon
2017-04-08T22:46:52.599369-07:00 INFO session_manager[15496]: [INFO:child_exit_handler.cc(77)] Handling 15525 exit.
2017-04-08T22:46:52.599483-07:00 INFO session_manager[15496]: [INFO:session_manager_service.cc(274)] Exiting process is chrome.
2017-04-08T22:46:52.599546-07:00 INFO session_manager[15496]: [INFO:browser_job.cc(149)] Terminating process group: Ensuring browser processes are gone.
2017-04-08T22:46:52.599598-07:00 INFO session_manager[15496]: [INFO:system_utils_impl.cc(110)] Sending 9 to -15525 as 1000
2017-04-08T22:46:52.600274-07:00 INFO session_manager[15496]: [INFO:browser_job.cc(140)] Running child /opt/google/chrome/chrome --ppapi-flash-path=/opt/google/chrome/pepper/libpepflashplayer.so --ppapi-flash-version=25.0.0.127 --ui-prioritize-in-gpu-process --use-gl=egl --touch-calibration=0,0,0,50 --touch-noise-filtering --gpu-sandbox-failures-fatal=yes --enable-logging --log-level=1 --use-cras --enable-wayland-server --user-data-dir=/home/chronos --max-unused-resource-memory-usage-percentage=5 --login-profile=user --enable-natural-scroll-default --has-chromeos-keyboard --default-wallpaper-large=/usr/share/chromeos-assets/wallpaper/default_large.jpg --default-wallpaper-small=/usr/share/chromeos-assets/wallpaper/default_small.jpg --child-wallpaper-large=/usr/share/chromeos-assets/wallpaper/child_large.jpg --child-wallpaper-small=/usr/share/chromeos-assets/wallpaper/child_small.jpg --guest-wallpaper-large=/usr/share/chromeos-assets/wallpaper/guest_large.jpg --guest-wallpaper-small=/usr/share/chromeos-assets/wallpaper/guest_small.jpg --enable-prefixed-encrypted-media --enterprise-enrollment-initial-modulus=15 --enterprise-enrollment-modulus-limit=19 --login-user=semenzato@google.com --login-profile=14a5cce06020715703c80daf933d6f1290822246 --flag-switches-begin --enable-native-cups --flag-switches-end --vmodule=screen_locker=2,webui_screen_locker=2,lock_state_controller=2,webui_login_view=2,power_button_observer=2,*/ui/display/manager/chromeos/*=1,*/ash/display/*=1,*/ui/ozone/*=1,*zygote*=1,*plugin*=2,auto_enrollment_controller=1,*chromeos/login/*=1 
2017-04-08T22:46:55.341835-07:00 NOTICE temp_metrics[16265]: Setting fan RPM (temps: 1:25:7:28:9:56:): 0 -> 0
2017-04-08T22:46:59.967867-07:00 DEBUG kernel: [14150.240583] wlan0: detected beacon loss from AP - sending probe request
2017-04-08T22:47:00.041749-07:00 DEBUG kernel: [14150.315227] wlan0: cancelling probereq poll due to a received beacon
2017-04-08T22:47:05.379748-07:00 NOTICE temp_metrics[16298]: Setting fan RPM (temps: 1:25:7:28:9:54:): 0 -> 0
2017-04-08T22:47:05.967755-07:00 DEBUG kernel: [14156.238676] wlan0: detected beacon loss from AP - sending probe request
2017-04-08T22:47:05.981762-07:00 DEBUG kernel: [14156.252875] wlan0: cancelling probereq poll due to a received beacon
2017-04-08T22:47:07.390590-07:00 ERR chrome[16241]: [16241:16241:0408/224707.390535:INFO:remote_commands_service.cc(36)] Fetching remote commands.
2017-04-08T22:47:07.391476-07:00 ERR chrome[16241]: [16241:16241:0408/224707.391442:INFO:system_log_uploader.cc(182)] Creating system log uploader.
2017-04-08T22:47:07.391587-07:00 ERR chrome[16241]: [16241:16241:0408/224707.391551:INFO:system_log_uploader.cc(325)] Scheduling next system log upload 0 s from now.
2017-04-08T22:47:07.602942-07:00 ERR shill[1192]: [ERROR:error.cc(146)] [wifi.cc(776)]: This WiFi device does not support MAC address randomization
2017-04-08T22:47:07.602966-07:00 ERR shill[1192]: [ERROR:wifi.cc(776)] SetRandomMACEnabled(...): Domain=dbus, Code=org.chromium.flimflam.Error.NotSupported, Message=This WiFi device does not support MAC address randomization
2017-04-08T22:47:07.619893-07:00 ERR chrome[16241]: [16241:16241:0408/224707.619852:INFO:system_log_uploader.cc(305)] System log upload is disabled, rescheduling.
2017-04-08T22:47:07.620587-07:00 ERR chrome[16241]: [16241:16241:0408/224707.620546:INFO:system_log_uploader.cc(325)] Scheduling next system log upload 43200 s from now.
2017-04-08T22:47:09.588229-07:00 ERR chrome[16241]: [16241:16241:0408/224709.588180:INFO:remote_commands_invalidator.cc(32)] Initialize RemoteCommandsInvalidator.
2017-04-08T22:47:09.588325-07:00 ERR chrome[16241]: [16241:16241:0408/224709.588305:INFO:remote_commands_invalidator.cc(57)] Starting RemoteCommandsInvalidator.
2017-04-08T22:47:09.588377-07:00 ERR chrome[16241]: [16241:16241:0408/224709.588360:INFO:remote_commands_invalidator.cc(123)] RemoteCommandsInvalidator ReloadPolicyData.
2017-04-08T22:47:09.588427-07:00 ERR chrome[16241]: [16241:16241:0408/224709.588410:INFO:remote_commands_invalidator.cc(147)] Register RemoteCommandsInvalidator.
2017-04-08T22:47:09.588477-07:00 ERR chrome[16241]: [16241:16241:0408/224709.588460:INFO:remote_commands_invalidator.cc(83)] RemoteCommandsInvalidator state changed: 3
2017-04-08T22:47:09.588553-07:00 ERR chrome[16241]: [16241:16241:0408/224709.588535:INFO:remote_commands_invalidator.cc(83)] RemoteCommandsInvalidator state changed: 3
2017-04-08T22:47:12.283249-07:00 ERR chrome[16241]: [16241:16241:0408/224712.283202:INFO:remote_commands_service.cc(161)] Remote commands fetched.
2017-04-08T22:47:12.338937-07:00 INFO session_manager[15496]: [INFO:policy_service.cc(202)] Persisted policy to disk.
2017-04-08T22:47:12.350253-07:00 INFO session_manager[15496]: [INFO:policy_service.cc(202)] Persisted policy to disk.
2017-04-08T22:47:13.325406-07:00 INFO permission_broker[1169]: ProcessPath(/dev/hidraw0)
2017-04-08T22:47:13.387928-07:00 INFO permission_broker[1169]:   AllowUsbDeviceRule: IGNORE
2017-04-08T22:47:13.387992-07:00 INFO permission_broker[1169]:   AllowTtyDeviceRule: IGNORE
2017-04-08T22:47:13.388019-07:00 INFO permission_broker[1169]:   DenyClaimedUsbDeviceRule: IGNORE
2017-04-08T22:47:13.388060-07:00 INFO permission_broker[1169]:   DenyUninitializedDeviceRule: IGNORE
2017-04-08T22:47:13.388088-07:00 INFO permission_broker[1169]:   DenyUsbDeviceClassRule: IGNORE
2017-04-08T22:47:13.388112-07:00 INFO permission_broker[1169]:   DenyUsbDeviceClassRule: IGNORE
2017-04-08T22:47:13.388141-07:00 INFO permission_broker[1169]:   DenyUsbVendorIdRule: IGNORE
2017-04-08T22:47:13.388170-07:00 INFO permission_broker[1169]:   AllowHidrawDeviceRule: ALLOW
2017-04-08T22:47:13.388193-07:00 INFO permission_broker[1169]:   AllowGroupTtyDeviceRule: IGNORE
2017-04-08T22:47:13.388220-07:00 INFO permission_broker[1169]:   DenyGroupTtyDeviceRule: IGNORE
2017-04-08T22:47:13.388281-07:00 INFO permission_broker[1169]: message repeated 2 times: [   DenyGroupTtyDeviceRule: IGNORE]
2017-04-08T22:47:13.482361-07:00 INFO permission_broker[1169]:   DenyClaimedHidrawDeviceRule: IGNORE
2017-04-08T22:47:13.558799-07:00 INFO permission_broker[1169]:   DenyUnsafeHidrawDeviceRule: IGNORE
2017-04-08T22:47:13.558814-07:00 INFO permission_broker[1169]: Verdict for /dev/hidraw0: ALLOW
2017-04-08T22:47:14.933025-07:00 INFO session_manager[15496]: [INFO:child_exit_handler.cc(77)] Handling 16881 exit.
2017-04-08T22:47:15.455328-07:00 NOTICE temp_metrics[17101]: Setting fan RPM (temps: 1:26:7:28:9:71:): 0 -> 0
2017-04-08T22:47:15.924790-07:00 ERR chrome[16241]: [16241:16241:0408/224715.924742:INFO:remote_commands_invalidator.cc(123)] RemoteCommandsInvalidator ReloadPolicyData.
2017-04-08T22:47:19.946736-07:00 ERR kernel: [14170.213297] ecryptfs_decrypt_page: Error attempting to read lower page; rc = [-4]
2017-04-08T22:47:19.946754-07:00 ERR kernel: [14170.213308] ecryptfs_readpage: Error decrypting page; rc = [-4]
2017-04-08T22:47:25.661612-07:00 NOTICE temp_metrics[17261]: Setting fan RPM (temps: 1:24:7:28:9:78:): 0 -> 0
2017-04-08T22:47:25.957674-07:00 DEBUG chrom[16241]: --ppapi-flash-path=/opt/google/chrome/pepper/libpepflashplayer.so --ppapi-flash-version=25.0.0.127 --ui-prioritize-in-gpu-process --use-gl=egl --touch-calibration=0,0,0,50 --touch-noise-filtering --gpu-sandbox-failures-fatal=yes --enable-logging --log-level=1 --use-cras --enable-wayland-server --user-data-dir=/home/chronos --max-unused-resource-memory-usage-percentage=5 --login-profile=user --enable-natural-scroll-default --has-chromeos-keyboard --default-wallpaper-large=/usr/share/chromeos-assets/wallpaper/default_large.jpg --default-wallpaper-small=/usr/share/chromeos-assets/wallpaper/default_small.jpg --child-wallpaper-large=/usr/share/chromeos-assets/wallpaper/child_large.jpg --child-wallpaper-small=/usr/share/chromeos-assets/wallpaper/child_small.jpg --guest-wallpaper-large=/usr/share/chromeos-assets/wallpaper/guest_large.jpg --guest-wallpaper-small=/usr/share/chromeos-assets/wallpaper/guest_small.jpg --enable-prefixed-encrypted-media --enterprise-enrollment-initial-modulus=15 --enterprise-enrollment-modulus-limit=19 --login-user=semenzato@google.com --login-profile=14a5cce06020715703c80daf933d6f1290822246 --flag-switches-begin --enable-native-cups --flag-switches-end --vmodule=screen_locker=2,webui_screen_locker=2,lock_state_controller=2,webui_login_view=2,power_button_observer=2,*/ui/display/manager/chromeos/*=1,*/ash/display/*=1,*/ui/ozone/*=1,*zygote*=1,*plugin*=2,auto_enrollment_controller=1,*chromeos/login/*=1[16241]: cras_client: server_fd_state: wait_for_socket
2017-04-08T22:47:25.957747-07:00 DEBUG chrom[16241]: --ppapi-flash-path=/opt/google/chrome/pepper/libpepflashplayer.so --ppapi-flash-version=25.0.0.127 --ui-prioritize-in-gpu-process --use-gl=egl --touch-calibration=0,0,0,50 --touch-noise-filtering --gpu-sandbox-failures-fatal=yes --enable-logging --log-level=1 --use-cras --enable-wayland-server --user-data-dir=/home/chronos --max-unused-resource-memory-usage-percentage=5 --login-profile=user --enable-natural-scroll-default --has-chromeos-keyboard --default-wallpaper-large=/usr/share/chromeos-assets/wallpaper/default_large.jpg --default-wallpaper-small=/usr/share/chromeos-assets/wallpaper/default_small.jpg --child-wallpaper-large=/usr/share/chromeos-assets/wallpaper/child_large.jpg --child-wallpaper-small=/usr/share/chromeos-assets/wallpaper/child_small.jpg --guest-wallpaper-large=/usr/share/chromeos-assets/wallpaper/guest_large.jpg --guest-wallpaper-small=/usr/share/chromeos-assets/wallpaper/guest_small.jpg --enable-prefixed-encrypted-media --enterprise-enrollment-initial-modulus=15 --enterprise-enrollment-modulus-limit=19 --login-user=semenzato@google.com --login-profile=14a5cce06020715703c80daf933d6f1290822246 --flag-switches-begin --enable-native-cups --flag-switches-end --vmodule=screen_locker=2,webui_screen_locker=2,lock_state_controller=2,webui_login_view=2,power_button_observer=2,*/ui/display/manager/chromeos/*=1,*/ash/display/*=1,*/ui/ozone/*=1,*zygote*=1,*plugin*=2,auto_enrollment_controller=1,*chromeos/login/*=1[16241]: cras_client: server_fd_state: wait_for_writable
2017-04-08T22:47:25.957839-07:00 DEBUG chrom[16241]: --ppapi-flash-path=/opt/google/chrome/pepper/libpepflashplayer.so --ppapi-flash-version=25.0.0.127 --ui-prioritize-in-gpu-process --use-gl=egl --touch-calibration=0,0,0,50 --touch-noise-filtering --gpu-sandbox-failures-fatal=yes --enable-logging --log-level=1 --use-cras --enable-wayland-server --user-data-dir=/home/chronos --max-unused-resource-memory-usage-percentage=5 --login-profile=user --enable-natural-scroll-default --has-chromeos-keyboard --default-wallpaper-large=/usr/share/chromeos-assets/wallpaper/default_large.jpg --default-wallpaper-small=/usr/share/chromeos-assets/wallpaper/default_small.jpg --child-wallpaper-large=/usr/share/chromeos-assets/wallpaper/child_large.jpg --child-wallpaper-small=/usr/share/chromeos-assets/wallpaper/child_small.jpg --guest-wallpaper-large=/usr/share/chromeos-assets/wallpaper/guest_large.jpg --guest-wallpaper-small=/usr/share/chromeos-assets/wallpaper/guest_small.jpg --enable-prefixed-encrypted-media --enterprise-enrollment-initial-modulus=15 --enterprise-enrollment-modulus-limit=19 --login-user=semenzato@google.com --login-profile=14a5cce06020715703c80daf933d6f1290822246 --flag-switches-begin --enable-native-cups --flag-switches-end --vmodule=screen_locker=2,webui_screen_locker=2,lock_state_controller=2,webui_login_view=2,power_button_observer=2,*/ui/display/manager/chromeos/*=1,*/ash/display/*=1,*/ui/ozone/*=1,*zygote*=1,*plugin*=2,auto_enrollment_controller=1,*chromeos/login/*=1[16241]: cras_client: server_fd_state: first_message
2017-04-08T22:47:25.957887-07:00 DEBUG chrom[16241]: --ppapi-flash-path=/opt/google/chrome/pepper/libpepflashplayer.so --ppapi-flash-version=25.0.0.127 --ui-prioritize-in-gpu-process --use-gl=egl --touch-calibration=0,0,0,50 --touch-noise-filtering --gpu-sandbox-failures-fatal=yes --enable-logging --log-level=1 --use-cras --enable-wayland-server --user-data-dir=/home/chronos --max-unused-resource-memory-usage-percentage=5 --login-profile=user --enable-natural-scroll-default --has-chromeos-keyboard --default-wallpaper-large=/usr/share/chromeos-assets/wallpaper/default_large.jpg --default-wallpaper-small=/usr/share/chromeos-assets/wallpaper/default_small.jpg --child-wallpaper-large=/usr/share/chromeos-assets/wallpaper/child_large.jpg --child-wallpaper-small=/usr/share/chromeos-assets/wallpaper/child_small.jpg --guest-wallpaper-large=/usr/share/chromeos-assets/wallpaper/guest_large.jpg --guest-wallpaper-small=/usr/share/chromeos-assets/wallpaper/guest_small.jpg --enable-prefixed-encrypted-media --enterprise-enrollment-initial-modulus=15 --enterprise-enrollment-modulus-limit=19 --login-user=semenzato@google.com --login-profile=14a5cce06020715703c80daf933d6f1290822246 --flag-switches-begin --enable-native-cups --flag-switches-end --vmodule=screen_locker=2,webui_screen_locker=2,lock_state_controller=2,webui_login_view=2,power_button_observer=2,*/ui/display/manager/chromeos/*=1,*/ash/display/*=1,*/ui/ozone/*=1,*zygote*=1,*plugin*=2,auto_enrollment_controller=1,*chromeos/login/*=1[16241]: cras_client: server_fd_state: connected
2017-04-08T22:47:25.983519-07:00 INFO chrom[16241]: --ppapi-flash-path=/opt/google/chrome/pepper/libpepflashplayer.so --ppapi-flash-version=25.0.0.127 --ui-prioritize-in-gpu-process --use-gl=egl --touch-calibration=0,0,0,50 --touch-noise-filtering --gpu-sandbox-failures-fatal=yes --enable-logging --log-level=1 --use-cras --enable-wayland-server --user-data-dir=/home/chronos --max-unused-resource-memory-usage-percentage=5 --login-profile=user --enable-natural-scroll-default --has-chromeos-keyboard --default-wallpaper-large=/usr/share/chromeos-assets/wallpaper/default_large.jpg --default-wallpaper-small=/usr/share/chromeos-assets/wallpaper/default_small.jpg --child-wallpaper-large=/usr/share/chromeos-assets/wallpaper/child_large.jpg --child-wallpaper-small=/usr/share/chromeos-assets/wallpaper/child_small.jpg --guest-wallpaper-large=/usr/share/chromeos-assets/wallpaper/guest_large.jpg --guest-wallpaper-small=/usr/share/chromeos-assets/wallpaper/guest_small.jpg --enable-prefixed-encrypted-media --enterprise-enrollment-initial-modulus=15 --enterprise-enrollment-modulus-limit=19 --login-user=semenzato@google.com --login-profile=14a5cce06020715703c80daf933d6f1290822246 --flag-switches-begin --enable-native-cups --flag-switches-end --vmodule=screen_locker=2,webui_screen_locker=2,lock_state_controller=2,webui_login_view=2,power_button_observer=2,*/ui/display/manager/chromeos/*=1,*/ash/display/*=1,*/ui/ozone/*=1,*zygote*=1,*plugin*=2,auto_enrollment_controller=1,*chromeos/login/*=1[16241]: set rlimit success
2017-04-08T22:47:35.727281-07:00 NOTICE temp_metrics[17477]: Setting fan RPM (temps: 1:25:7:29:9:76:): 0 -> 0
2017-04-08T22:47:35.977015-07:00 INFO chrom[16241]: --ppapi-flash-path=/opt/google/chrome/pepper/libpepflashplayer.so --ppapi-flash-version=25.0.0.127 --ui-prioritize-in-gpu-process --use-gl=egl --touch-calibration=0,0,0,50 --touch-noise-filtering --gpu-sandbox-failures-fatal=yes --enable-logging --log-level=1 --use-cras --enable-wayland-server --user-data-dir=/home/chronos --max-unused-resource-memory-usage-percentage=5 --login-profile=user --enable-natural-scroll-default --has-chromeos-keyboard --default-wallpaper-large=/usr/share/chromeos-assets/wallpaper/default_large.jpg --default-wallpaper-small=/usr/share/chromeos-assets/wallpaper/default_small.jpg --child-wallpaper-large=/usr/share/chromeos-assets/wallpaper/child_large.jpg --child-wallpaper-small=/usr/share/chromeos-assets/wallpaper/child_small.jpg --guest-wallpaper-large=/usr/share/chromeos-assets/wallpaper/guest_large.jpg --guest-wallpaper-small=/usr/share/chromeos-assets/wallpaper/guest_small.jpg --enable-prefixed-encrypted-media --enterprise-enrollment-initial-modulus=15 --enterprise-enrollment-modulus-limit=19 --login-user=semenzato@google.com --login-profile=14a5cce06020715703c80daf933d6f1290822246 --flag-switches-begin --enable-native-cups --flag-switches-end --vmodule=screen_locker=2,webui_screen_locker=2,lock_state_controller=2,webui_login_view=2,power_button_observer=2,*/ui/display/manager/chromeos/*=1,*/ash/display/*=1,*/ui/ozone/*=1,*zygote*=1,*plugin*=2,auto_enrollment_controller=1,*chromeos/login/*=1[16241]: cras_client: remove stream 1638400
2017-04-08T22:47:40.977360-07:00 DEBUG chrom[16241]: --ppapi-flash-path=/opt/google/chrome/pepper/libpepflashplayer.so --ppapi-flash-version=25.0.0.127 --ui-prioritize-in-gpu-process --use-gl=egl --touch-calibration=0,0,0,50 --touch-noise-filtering --gpu-sandbox-failures-fatal=yes --enable-logging --log-level=1 --use-cras --enable-wayland-server --user-data-dir=/home/chronos --max-unused-resource-memory-usage-percentage=5 --login-profile=user --enable-natural-scroll-default --has-chromeos-keyboard --default-wallpaper-large=/usr/share/chromeos-assets/wallpaper/default_large.jpg --default-wallpaper-small=/usr/share/chromeos-assets/wallpaper/default_small.jpg --child-wallpaper-large=/usr/share/chromeos-assets/wallpaper/child_large.jpg --child-wallpaper-small=/usr/share/chromeos-assets/wallpaper/child_small.jpg --guest-wallpaper-large=/usr/share/chromeos-assets/wallpaper/guest_large.jpg --guest-wallpaper-small=/usr/share/chromeos-assets/wallpaper/guest_small.jpg --enable-prefixed-encrypted-media --enterprise-enrollment-initial-modulus=15 --enterprise-enrollment-modulus-limit=19 --login-user=semenzato@google.com --login-profile=14a5cce06020715703c80daf933d6f1290822246 --flag-switches-begin --enable-native-cups --flag-switches-end --vmodule=screen_locker=2,webui_screen_locker=2,lock_state_controller=2,webui_login_view=2,power_button_observer=2,*/ui/display/manager/chromeos/*=1,*/ash/display/*=1,*/ui/ozone/*=1,*zygote*=1,*plugin*=2,auto_enrollment_controller=1,*chromeos/login/*=1[16241]: cras_client: server_fd_state: disconnected

Comment 3 by derat@chromium.org, Apr 9 2017

If the system is in dev mode, can you send SIGABRT (or some other signal) to Chrome while it's hanging to convince it to dump a stack trace?

If it's not in dev mode, does the magic sysrq key still work for doing this?
#3 thanks, device is in normal mode.  A double alt-volup-x seemed to have no effect, but I collected another feedback report (not the one above), search for user:...

Cc: marc...@chromium.org pastarmovj@chromium.org
+marcheu, pastarmovj

I vaguely recall something about display panel initialization taking a long time, and something else about enterprise-related changes that forced a chrome restart on login when flags were set. Does that sound familiar?

Is the device enterprise enrolled?

This may be a duplicate of crbug.com/681278?

Comment 8 by derat@chromium.org, Apr 9 2017

Chrome needing to restart at login since Luigi has flags set is expected. 25 seconds is way too long for that to take, though, and indicates that something is wrong.
Yes, setting flags requires restart because some flags have to be present at init time to take effect. One thing that has always been discussed but never concluded was why restarting Chrome takes so long when not even the cryptohome is changed at this moment. At some point I had a hacked proof of concept which simply crashed the browser and it restarted in less than a second with the unpleasant side effect of having to click on recover tabs. :)
is:
2017-04-08T22:47:19.946736-07:00 ERR kernel: [14170.213297] ecryptfs_decrypt_page: Error attempting to read lower page; rc = [-4]
2017-04-08T22:47:19.946754-07:00 ERR kernel: [14170.213308] ecryptfs_readpage: Error decrypting page; rc = [-4]

Seen at every tries? This is not expected: given we are not unmounting or removing users, there is not reason to get a read error. Can we add some debug to tell which file trigger this error?
No sorry, this is on my pixel 1 in normal mode.

Mergedinto: 681278
Status: Duplicate (was: Untriaged)

Sign in to add a comment