(This is Chromium 57.0.2941.0 and platform 9051.0.)

The description for the string used in the initial error points at a bunch of possible causes:

  <message name="IDS_LOGIN_ERROR_OWNER_KEY_LOST" desc="Couldn't sign in because the owner key has been lost, device settings corruption or incorrect local time.">
    Sign-in failed, please connect to the internet and try again.
  </message>

Is this message the actual the problem?

  [6198:6198:1206/170226.001382:ERROR:base_screen_handler_utils.cc(70)] Failed to deserialize 'derat.test@gmail.com'

Looking at AccountId::Deserialize() components/signin/core/account_id/account_id.cc, it appears that we expect this value to be a JSON object rather than a string. Was there some migration that didn't happen on my system due to me skipping versions? If so, are we certain that this can never happen to an end user whose system has been off for a long time?

This error message is displayed in two places in chrome/browser/chromeos/login/existing_user_controller.cc:

ExistingUserController::PolicyLoadFailed()
ExistingUserController::ContinueLoginIfDeviceNotDisabled()
  (if TrustedStatus is PERMANENTLY_UNTRUSTED)

PolicyLoadFailed() gets called from chrome/browser/chromeos/login/auth/chrome_login_performer.cc in response to the same PERMANENTLY_UNTRUSTED status (and also from LoginPerformer::LoginAsPublicSession()).

Telling the user to connect to the Internet when they're probably already connected is... not helpful. :-/

What would be an actually-helpful message to display here?

I'm guessing that the current message refers to the possibility that the we don't trust the owner key because the system clock is way off or something similar, right? Is that still something that can cause this? If we know that tlsdate is synced but still get PERMANENTLY_UNTRUSTED, what recourse does the user have? Do they need to do a powerwash?

Serialize + Deserialize are not used to store anything to permanent storage, so this error seems very strange to me.

base_screen_handler_utils.cc: ParseValue() expects a value from MakeValue(), but both of them are used only to talk to WebUI and this should not be affected by upgrade.

Could you remember what milestone it was previously? Also it is possible that you had partially broken ToT build with some bug that was fixed later before the branch...

And yes, I think this error (Failed to deserialize) leads to empty username, so user cannot be found.

It looks like this thould be assigned to me, but I need a reproducible scenario....

The last time I used it was early September, so I'd guess it was previously using Chrome 54. Re ToT brokenness, I'm not sure.

I'm still able to repro this consistently on this device. Is there any other info I can get that would help debug this?

I can also try building my own copy of Chrome (e.g. with extra logging) and pushing it to the device to see if the problem still shows up. Please tell me what I should log -- components/login/ has a bunch of overridden ParseValue() functions and a templatized GetArg() function, but I'm not sure how any of this code is called.

If you apply this patch: https://codereview.chromium.org/2559323006 , you should normally see messages like this:

[37839:37839:1209/050550.096778:ERROR:CONSOLE(3622)] "loadUsers: users:
[{"canRemove":false,"childUser":false,"displayName":"My Test User","emailAddress":"mytestuser@gmail.com","gaiaId":"12345678901234567890","initialAuthType":0,"isDesktopUser":false,"isMultiProfilesAllowed":true,"isOwner":false,"legacySupervisedUser":false,"publicAccount":false,"showPin":false,"signedIn":false,"username":"{\"email\":\"mytestuser@gmail.com\",\"gaia_id\":\"12345678901234567890\"}"}]", source: chrome://oobe/login.js (3622)

...

[37839:37839:1209/050559.528754:ERROR:CONSOLE(5266)] "chrome.send authenticateUser. username='{"email":"mytestuser@gmail.com","gaia_id":"12345678901234567890"}'", source: chrome://oobe/login.js (5266)

The first message says that the list of user was successfully uploaded to WebUI. The second one should appear after you enter user password. We should see serialized AccountId as "username" in both lines.

I think that the problem is that username in the initial list of users become corrupted for some strange reason and then Deserialize fails.

Thanks, here's the output using your patch. The source of the problem isn't obvious to me -- the output looks similar to what you pasted, unless I'm missing something.

[4817:4817:1209/122050.757938:ERROR:CONSOLE(3622)] "loadUsers: users:
[{"canRemove":false,"childUser":false,"displayName":"Daniel Erat","emailAddress":"derat.test@gmail.com","gaiaId":"111027791063639754194","initialAuthType":0,"isDesktopUser":false,"isMultiProfilesAllowed":true,"isOwner":true,"legacySupervisedUser":false,"publicAccount":false,"showPin":false,"signedIn":false,"username":"{\"email\":\"derattest@gmail.com\",\"gaia_id\":\"111027791063639754194\"}"}]", source: chrome://oobe/login.js (3622)
...
[4817:4817:1209/124432.521824:ERROR:CONSOLE(5266)] "chrome.send authenticateUser. username='{"email":"derattest@gmail.com","gaia_id":"111027791063639754194"}'", source: chrome://oobe/login.js (5266)
[4817:4817:1209/124432.522158:VERBOSE1:webui_login_display.cc(110)] Show error, error_id: 2720, attempts:1, help_topic_id: 188036
[4817:4817:1209/124432.522206:ERROR:core_oobe_handler.cc(204)] CoreOobeHandler::ShowSignInError: error_text=Sign-in failed, please connect to the internet and try again.
[4817:4817:1209/124432.536845:ERROR:base_screen_handler_utils.cc(70)] Failed to deserialize 'derat.test@gmail.com'

Dan, could you apply another patch (attached) and tell which call gives the error string?

Deleted: debug-CallbackWrapper.patch 1.5 KB

debug-CallbackWrapper.patch 1.5 KB Download

Thanks!

[5204:5204:1214/100640.228360:ERROR:CONSOLE(3630)] "loadUsers: users:
[{"canRemove":false,"childUser":false,"displayName":"Daniel Erat","emailAddress":"derat.test@gmail.com","gaiaId":"111027791063639754194","initialAuthType":0,"isDesktopUser":false,"isMultiProfilesAllowed":true,"isOwner":true,"legacySupervisedUser":false,"publicAccount":false,"showPin":false,"signedIn":false,"username":"{\"email\":\"derattest@gmail.com\",\"gaia_id\":\"111027791063639754194\"}"}]", source: chrome://oobe/login.js (3630)

Then I type my password and hit Enter:

[5204:5204:1214/101229.686869:ERROR:CONSOLE(5274)] "chrome.send authenticateUser. username='{"email":"derattest@gmail.com","gaia_id":"111027791063639754194"}'", source: chrome://oobe/login.js (5274)
[5204:5204:1214/101229.687069:ERROR:base_screen_handler_utils.h(99)] CallbackWrapper: 'authenticateUser' - Started.
[5204:5204:1214/101229.687265:VERBOSE1:webui_login_display.cc(110)] Show error, error_id: 2723, attempts:1, help_topic_id: 188036
[5204:5204:1214/101229.687307:ERROR:core_oobe_handler.cc(204)] CoreOobeHandler::ShowSignInError: error_text=Sign-in failed, please connect to the internet and try again.
[5204:5204:1214/101229.687493:ERROR:base_screen_handler_utils.h(102)] CallbackWrapper: 'authenticateUser' - Finished.
[5204:5204:1214/101229.697942:ERROR:base_screen_handler_utils.h(99)] CallbackWrapper: 'firstIncorrectPasswordAttempt' - Started.
[5204:5204:1214/101229.698000:ERROR:base_screen_handler_utils.cc(70)] Failed to deserialize 'derat.test@gmail.com'
[5204:5204:1214/101229.698020:ERROR:base_screen_handler_utils.h(102)] CallbackWrapper: 'firstIncorrectPasswordAttempt' - Finished.

Then I type my password again and hit Enter. It just hangs this time with the password field and arrow grayed out (no spinner):

[5204:5204:1214/101317.274310:ERROR:CONSOLE(5274)] "chrome.send authenticateUser. username='{"email":"derattest@gmail.com","gaia_id":"111027791063639754194"}'", source: chrome://oobe/login.js (5274)
[5204:5204:1214/101317.274518:ERROR:base_screen_handler_utils.h(99)] CallbackWrapper: 'authenticateUser' - Started.
[5204:5204:1214/101317.274618:ERROR:base_screen_handler_utils.h(102)] CallbackWrapper: 'authenticateUser' - Finished.
[5204:5204:1214/101406.926303:VERBOSE1:gaia_screen_handler.cc(392)] OnPortalDetectionCompleted Online

That's the end of the log.

Yes, this is a bug in screen_account_picker calling firstIncorrectPasswordAttempt / maxIncorrectPasswordAttempts, but they both do nothing. So this is not the problem we are looking for.

In Local State there is a dictionary OAuthTokenStatus of "email" => OAuthTokenStatus where values are from:

  typedef enum {                                                                 
    OAUTH_TOKEN_STATUS_UNKNOWN = 0,                                              
    OAUTH2_TOKEN_STATUS_INVALID = 3,                                             
    OAUTH2_TOKEN_STATUS_VALID = 4,                                               
  } OAuthTokenStatus;  

What is the value for your test account?

It appears to think it's valid:

"OAuthTokenStatus":{"derattest@gmail.com":4}

Let me know if I should try changing it to a different value.

Any chance this is a canonicalization issue ("derat.test" vs. "derattest")? Local State consistently refers to the version without a period, but the deserialization error uses "derat.test".

<triage> Closing due to lack of activity. Please reopen if this is still relevant. </triage>