CrOS: 10994.0.0
Chrome: 70.0.3530.0
ARC: 4971789

Cryptohome mounting fails and user session fails to start after OOBE. Public sessions can never be started.

FWIW, I've only tested on one device, which has been used in a number of enrollment scenarios including attestation-based Demo Mode enrollment. However, these repro steps are consistent after various methods of wiping the device and unlocking the TPM.

================================================================================

1. Starting at Welcome screen, progress through OOBE by selecting a network, accepting TOS, etc.
2. Sign in with a regular Google account
3. Click "Accept and continue" at sync confirmation screen
4. Accept ARC++ TOS

Expected: White screen with "Please wait" spinner appears very briefly, then user session starts and ARC++ apps begin installing. No cryptohome errors in logs.

Actual: White screen with "Please wait" spinner appears for a long time. ARC++ begins installing apps (according to notifications) but still at the the "Please wait" screen. The system tray has a "lock" button, but doesn't indicate an active user. 6/6 ARC++ apps finish installing. After 5 minutes, still at "Please wait" screen.

Clicking the system tray's "lock" button crashes Chrome. At that point, the sign-in screen comes up, and you can sign in normally.

Logs are attached. The interesting bits are displayed at the end.

================================================================================

If enrolling into a domain that enforces Public Sessions, the behavior is different. After enrollment, the sign-in screen shows the Public Session pod. However, trying to enter the Public Session has no effect other than adding the ARC++ Google Play notification to the system tray.

After rebooting, the "Sign in" dialog shows over the Public Session pod. Signing in doesn't work (because it's disabled for that domain), but the dialog can be dismissed to reveal the Public Session pod. Entering a Public Session still doesn't work, although I've gotten it to work very rarely by rebooting and trying repeatedly.

================================================================================

Everything works normally in the previous build on goldeneye:
CrOS: 10993.0.0
Chrome: 70.0.3524.2
ARC: 4966926

so the regression happened in that range.



From /var/log/chrome/chrome:

[1723:1723:0823/140315.637171:VERBOSE1:login_performer.cc(287)] Online login completion started.
[1723:1723:0823/140315.637325:VERBOSE1:cryptohome_authenticator.cc(811)] Resolved state to: 0
[1723:1723:0823/140315.638153:ERROR:device_event_log_impl.cc(159)] [14:03:15.638] Login: cryptohome_util.cc:131 GetKeyDataEx failed with no GetKeyDataReply extension in reply.
[1723:1723:0823/140315.641002:ERROR:device_event_log_impl.cc(159)] [14:03:15.640] Login: cryptohome_authenticator.cc:147 MountEx failed. Error: 32
[1723:1723:0823/140315.641040:ERROR:device_event_log_impl.cc(159)] [14:03:15.641] Login: cryptohome_authenticator.cc:971 Cryptohome failure: state(AuthState)=1, code(cryptohome::MountError)=32
[1723:1723:0823/140315.641059:VERBOSE1:cryptohome_authenticator.cc(811)] Resolved state to: 6
[1723:1723:0823/140318.197138:VERBOSE1:cryptohome_authenticator.cc(811)] Resolved state to: 13
[1723:1723:0823/140318.197197:VERBOSE1:cryptohome_authenticator.cc(701)] Login success
[1723:1723:0823/140318.197410:VERBOSE1:login_performer.cc(87)] LoginSuccess hash: 91ef7b46398eb6878c471fb52825972c5fc7e179
[1723:1723:0823/140318.197457:VERBOSE1:user_session_manager.cc(585)] Starting user session.


From /var/log/messages

2018-08-23T21:03:05.004515+00:00 WARNING cryptohomed[1516]: Could not load the device policy file.
...
2018-08-23T21:03:17.740841+00:00 WARNING cryptohomed[1516]: Could not load the device policy file.
2018-08-23T21:03:18.253259+00:00 INFO session_manager[1680]: [INFO:policy_key.cc(51)] No policy key on disk at /home/root/91ef7b46398eb6878c471fb52825972c5fc7e179/session_manager/policy/key
2018-08-23T21:03:18.268665+00:00 INFO cryptohomed[1516]: Putting a Pkcs11_Initialize on the mount thread.
2018-08-23T21:03:18.273725+00:00 INFO chapsd[1490]: Opening database in: /home/root/91ef7b46398eb6878c471fb52825972c5fc7e179/chaps
2018-08-23T21:03:18.304459+00:00 ERR session_manager[1680]: [ERROR:nss_util.cc(145)] Not checking key because size is 0
2018-08-23T21:03:18.323184+00:00 INFO chapsd[1490]: Importing opencryptoki objects.
2018-08-23T21:03:18.323237+00:00 WARNING chapsd[1490]: Did not find any opencryptoki objects to import.
2018-08-23T21:03:18.324236+00:00 WARNING session_manager[1680]: [WARNING:device_policy_service.cc(506)] Could not verify that owner key belongs to this user.
2018-08-23T21:03:18.324257+00:00 ERR session_manager[1680]: [ERROR:dbus_util.cc(13)] CreateError(...): Domain=dbus, Code=org.chromium.SessionManagerInterface.PubkeySetIllegal, Message=Could not verify that owner key belongs to this user.

 

Deleted: logs.zip 182 KB

logs.zip 182 KB Download