New issue
Advanced search Search tips

Issue 593144 link

Starred by 1 user

Issue metadata

Status: Closed
Owner:
Closed: Nov 19
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 2
Type: Bug



Sign in to add a comment

Chrome claims to have previously crashed after login and then forces signing in again with GAIA

Project Member Reported by derat@chromium.org, Mar 8 2016

Issue description

7647.84.0 (Official Build) stable-channel peppy
48.0.2564.116

I have a stable-channel peppy device where I usually log into my corp account first and then add my personal account to the session. The last few days, I've been seeing a "Chrome didn't exit properly" or whatever butterbar when I log directly into my personal account, along with a notification that I need to sign out and sign back in. When signing in again, I always need to go through GAIA.

Here's a feedback report that I filed after signing back in: https://feedback.corp.google.com/product/208/neutron?lView=rd&lRSort=1&lROrder=2&lRFilter=1&lReport=6874319091

----

The Chrome user log from my session before the initial error ends with:

[1179:1179:0305/132606:WARNING:session_state_controller_delegate_chromeos.cc(27)] Requesting screen lock from SessionStateControllerDelegate
[1179:1179:0305/132606:VERBOSE1:screen_locker.cc(349)] Received LockScreen request from session manager
[1179:1179:0305/132606:VERBOSE1:screen_locker.cc(401)] Created ScreenLocker 0xfd73f46f5a0
[1179:1179:0305/132606:VERBOSE1:webui_screen_locker.cc(293)] Lock window ready; WebUI is not
...
[1179:1179:0305/132606:WARNING:device_cloud_policy_manager_chromeos.cc(221)] Failed to get machine id. This is only an error if the device has not yet been enrolled or claimed by a local user.
[1179:1179:0305/132607:INFO:screenlock_bridge.cc(145)] Focused user changed to XXX@gmail.com
[1179:1179:0305/132608:VERBOSE1:webui_screen_locker.cc(195)] WebUI ready; lock window is too
[1179:1179:0305/132608:VERBOSE1:screen_locker.cc(478)] ScreenLocker 0xfd73f46f5a0 is ready after 2.04369 second(s)
[1179:1179:0305/132608:VERBOSE1:screen_locker.cc(482)] Moving desktop background to locked container
[1179:1179:0305/132608:VERBOSE1:screen_locker.cc(487)] Emitting SCREEN_LOCK_STATE_CHANGED with state=1
[1179:1179:0305/132608:VERBOSE1:screen_locker.cc(492)] Calling session manager's HandleLockScreenShown D-Bus method
...
[1179:1538:0305/132613:ERROR:crash_handler_host_linux.cc(373)] Failed to write crash dump for pid 4487
[1179:1523:0305/132613:ERROR:zygote_host_impl_linux.cc(543)] Failed to send GetTerminationStatus message to zygote
[1179:1523:0305/132613:WARNING:zygote_host_impl_linux.cc(555)] Socket closed prematurely.
[1179:1523:0305/132613:WARNING:crash_handler_host_linux.cc(291)] Could not translate tid - assuming crashing thread is thread group leader; syscall_supported=1
[1179:1538:0305/132613:ERROR:crash_handler_host_linux.cc(373)] Failed to write crash dump for pid 12868

----

The next Chrome system log begins with (I'm editing out a bunch of D-Bus log spam):

[1:1:0305/224529:VERBOSE1:zygote_main_linux.cc(564)] ZygoteMain: initializing 2 fork delegates
...
[1103:1103:0305/224529:WARNING:child_account_service.cc(288)] User instance wasn't found while setting child account flag.
[1103:1103:0305/224529:WARNING:auto_enrollment_controller.cc(248)] New auto-enrollment state: 1
...
[1103:1103:0305/224529:WARNING:auto_enrollment_controller.cc(194)] Device already owned, skipping auto-enrollment check.
[1103:1103:0305/224529:WARNING:auto_enrollment_controller.cc(248)] New auto-enrollment state: 5
...
[1103:1103:0305/224531:WARNING:device_cloud_policy_manager_chromeos.cc(221)] Failed to get machine id. This is only an error if the device has not yet been enrolled or claimed by a local user.
[1103:1103:0305/224531:INFO:screenlock_bridge.cc(145)] Focused user changed to XXX@gmail.com
[1103:1103:0305/224531:ERROR:logging.h(808)] Failed to call method: org.chromium.CryptohomeInterface.GetKeyDataEx: object_path= /org/chromium/Cryptohome: org.freedesktop.DBus.Error.ServiceUnknown: The name org.chromium.Cryptohome was not provided by any .service files
[1103:1103:0305/224531:ERROR:easy_unlock_get_keys_operation.cc(61)] Easy unlock failed to get key data, code=1
[1103:1103:0305/224531:ERROR:logging.h(808)] Failed to call method: org.chromium.CryptohomeInterface.TpmIsEnabled: object_path= /org/chromium/Cryptohome: org.freedesktop.DBus.Error.ServiceUnknown: The name org.chromium.Cryptohome was not provided by any .service files
[1103:1103:0305/224531:ERROR:logging.h(808)] Failed to call method: org.chromium.CryptohomeInterface.TpmIsEnabled: object_path= /org/chromium/Cryptohome: org.freedesktop.DBus.Error.ServiceUnknown: The name org.chromium.Cryptohome was not provided by any .service files
[1103:1103:0305/224531:ERROR:logging.h(808)] Failed to call method: org.chromium.CryptohomeInterface.GetKeyDataEx: object_path= /org/chromium/Cryptohome: org.freedesktop.DBus.Error.ServiceUnknown: The name org.chromium.Cryptohome was not provided by any .service files
[1103:1103:0305/224531:ERROR:easy_unlock_get_keys_operation.cc(61)] Easy unlock failed to get key data, code=1
[1103:1103:0305/224531:ERROR:logging.h(808)] Failed to call method: org.chromium.CryptohomeInterface.TpmIsEnabled: object_path= /org/chromium/Cryptohome: org.freedesktop.DBus.Error.ServiceUnknown: The name org.chromium.Cryptohome was not provided by any .service files
[1103:1103:0305/224531:WARNING:device_cloud_policy_manager_chromeos.cc(221)] Failed to get machine id. This is only an error if the device has not yet been enrolled or claimed by a local user.
[1103:1480:0305/224531:ERROR:device_status_collector.cc(121)] Unable to get volume status for 
[1103:1480:0305/224531:ERROR:device_status_collector.cc(121)] Unable to get volume status for 
[1103:1103:0305/224531:ERROR:logging.h(808)] Failed to call method: org.chromium.CryptohomeInterface.TpmAttestationDoesKeyExist: object_path= /org/chromium/Cryptohome: org.freedesktop.DBus.Error.ServiceUnknown: The name org.chromium.Cryptohome was not provided by any .service files
[1103:1103:0305/224531:ERROR:attestation_policy_observer.cc(54)] Cryptohome DBus method failed: Start@../../../../../../../home/chrome-bot/chrome_root/src/chrome/browser/chromeos/attestation/attestation_policy_observer.cc:181 - 0
[1103:1103:0305/224531:WARNING:device_management_service.cc(217)] DMServer request failed, status: 3, error: -106
[1103:1103:0305/224531:WARNING:device_management_service.cc(217)] DMServer request failed, status: 3, error: -106
[1103:1103:0305/224531:WARNING:device_management_service.cc(217)] DMServer request failed, status: 3, error: -106
[1103:1103:0305/224531:ERROR:logging.h(808)] Failed to call method: org.chromium.CryptohomeInterface.GetKeyDataEx: object_path= /org/chromium/Cryptohome: org.freedesktop.DBus.Error.ServiceUnknown: The name org.chromium.Cryptohome was not provided by any .service files
[1103:1103:0305/224531:ERROR:easy_unlock_get_keys_operation.cc(61)] Easy unlock failed to get key data, code=1
[1103:1103:0305/224531:ERROR:logging.h(808)] Failed to call method: org.chromium.CryptohomeInterface.TpmIsEnabled: object_path= /org/chromium/Cryptohome: org.freedesktop.DBus.Error.ServiceUnknown: The name org.chromium.Cryptohome was not provided by any .service files
[1103:1103:0305/224532:ERROR:logging.h(808)] Failed to call method: org.chromium.CryptohomeInterface.GetKeyDataEx: object_path= /org/chromium/Cryptohome: org.freedesktop.DBus.Error.ServiceUnknown: The name org.chromium.Cryptohome was not provided by any .service files
[1103:1103:0305/224532:ERROR:easy_unlock_get_keys_operation.cc(61)] Easy unlock failed to get key data, code=1
[1103:1103:0305/224532:ERROR:logging.h(808)] Failed to call method: org.chromium.CryptohomeInterface.TpmIsEnabled: object_path= /org/chromium/Cryptohome: org.freedesktop.DBus.Error.ServiceUnknown: The name org.chromium.Cryptohome was not provided by any .service files
[1457:1581:0306/054549:WARNING:channel.cc(358)] RawChannel write error

----

Could it be something like cryptohome not being ready yet by the time I logged in for the first time? The user log from when I logged in and got the error is mostly extension spam, but it also had this:

[1103:1443:0305/224541:WARNING:ipc_message_attachment_set.cc(53)] MessageAttachmentSet destroyed with unconsumed descriptors: 0/1
[1103:6527:0305/224544:ERROR:cert_verify_proc_nss.cc(924)] CERT_PKIXVerifyCert for 10.0.0.201 failed err=-8179
 
There might be two problems here.

One is that the secondary user (personal accont) profile is marked as unclean shutdown. The chrome log prior the error has crash handler lines. Did you see browser crash at all?

The other one is the secondary user is marked to have invalid oauth token, thus forcing Gaia flow on the next login. Not sure how it happened. 

Comment 2 by derat@chromium.org, Mar 8 2016

I didn't see any user-visible crashes, but this report of a signout crash from my client ID looks a bit suspicious:

https://crash.corp.google.com/browse?reportid=b3c7e63400000000

Thread 0 CRASHED [SIGABRT @ 0x000003e80000049b ] MAGIC SIGNATURE THREAD
0x00007fbc2d74bb82	(libc-2.19.so -raise.c:56 )	raise
0x00007fbc2d74d89f	(libc-2.19.so -abort.c:89 )	abort
0x00007fbc304e9124	(chrome -debugger_posix.cc:247 )	base::debug::BreakDebugger
0x00007fbc32206a19	(chrome -multi_user_window_manager_chromeos.cc:276 )	chrome::MultiUserWindowManagerChromeOS::~MultiUserWindowManagerChromeOS
0x00007fbc32206aa0	(chrome -multi_user_window_manager_chromeos.cc:285 )	chrome::MultiUserWindowManagerChromeOS::~MultiUserWindowManagerChromeOS
0x00007fbc32204f26	(chrome -multi_user_window_manager.cc:92 )	chrome::MultiUserWindowManager::DeleteInstance
0x00007fbc3232257e	(chrome -chrome_launcher_controller.cc:461 )	ChromeLauncherController::~ChromeLauncherController
0x00007fbc323227e0	(chrome -chrome_launcher_controller.cc:462 )	ChromeLauncherController::~ChromeLauncherController
0x00007fbc324800ee	(chrome -scoped_ptr.h:128 )	ash::Shell::~Shell
0x00007fbc32481850	(chrome -shell.cc:835 )	ash::Shell::~Shell
0x00007fbc3247dc66	(chrome -shell.cc:210 )	ash::Shell::DeleteInstance
0x00007fbc32318084	(chrome -ash_init.cc:103 )	chrome::CloseAsh
0x00007fbc3384db39	(chrome -chrome_browser_main.cc:1817 )	ChromeBrowserMainParts::PostMainMessageLoopRun
0x00007fbc32e855f0	(chrome -chrome_browser_main_chromeos.cc:784 )	chromeos::ChromeBrowserMainPartsChromeos::PostMainMessageLoopRun
0x00007fbc326c7360	(chrome -browser_main_loop.cc:980 )	content::BrowserMainLoop::ShutdownThreadsAndCleanUp
0x00007fbc32529fed	(chrome -browser_main_runner.cc:291 )	content::BrowserMainRunnerImpl::Shutdown
0x00007fbc32529dce	(chrome -browser_main.cc:46 )	content::BrowserMain
0x00007fbc304af969	(chrome -content_main_runner.cc:808 )	content::ContentMainRunnerImpl::Run
0x00007fbc304ae59a	(chrome -content_main.cc:19 )	content::ContentMain
0x00007fbc301479de	(chrome -chrome_main.cc:66 )	ChromeMain
0x00007fbc2d736fb5	(libc-2.19.so -libc-start.c:292 )	__libc_start_main
0x00007fbc3014782a	(chrome + 0x0108082a )	
0x00007fff85c47127	
I have seen this crash before. It happens when the profile's oauth token is marked as invalid. As a result, the AccounTrackerService removed the account info associated with the profile, which caused the multi_user_util::GetProfileFromAccountId to lose track and return nullptr. 

So the root cause here seems to be why the secondary user's oauth token becomes invalid.

You have not changed your personal account's password, right? And did you experience any sync problem or see the sign-out-and-back-in notification while using your personal account as a secondary user?

Comment 4 by derat@chromium.org, Mar 8 2016

Yeah, I haven't changed the password, and I don't think I've seen any sync problems or notifications while using it as a secondary user, only as the primary.
Status: Closed (was: Assigned)
<triage>
Dan, have you been able to reproduce this recently?
If so, please reopen so we can take another look at it.
</triage>
No, I haven't seen this in years.

Sign in to add a comment