New issue
Advanced search Search tips

Issue 709693 link

Starred by 3 users

Issue metadata

Status: Fixed
Owner:
Closed: May 2017
Cc:
EstimatedDays: ----
NextAction: ----
OS: ----
Pri: 1
Type: Bug



Sign in to add a comment

cryptohome failing to mount

Project Member Reported by jdufault@chromium.org, Apr 8 2017

Issue description

Failure[1] when logging into Chrome in desktopui_ScreenLocker seems to be caused by cryptohome.


Example logs [2]:

chrome:    
    [12544:12544:0407/165602.816550:ERROR:device_event_log_impl.cc(137)] [16:56:02.816] Login: homedir_methods.cc:413 HomedirMethods MountEx error: 5
    [12544:12544:0407/165602.816612:ERROR:device_event_log_impl.cc(137)] [16:56:02.816] Login: cryptohome_authenticator.cc:900 Cryptohome failure: state=2, code=1
    [12544:12544:0407/165602.816634:VERBOSE1:cryptohome_authenticator.cc(745)] Resolved state to: 2
    [12544:12544:0407/165602.816767:ERROR:device_event_log_impl.cc(137)] [16:56:02.816] Login: cryptohome_authenticator.cc:678 Login failed: Could not mount cryptohome.
    [12544:12544:0407/165602.816820:ERROR:login_performer.cc(63)] Login failure, reason=1, error.state=0
    [12544:12544:0407/165602.816913:VERBOSE1:existing_user_controller.cc(1123)] Could not mount cryptohome.


messages:
    2017-04-07T21:40:51.012516+00:00 WARNING cryptohomed[820]: TSS: Got a list of valid IPs
    2017-04-07T21:40:51.012780+00:00 WARNING cryptohomed[820]: TSS: Could not connect to machine: localhost
    2017-04-07T21:40:51.012806+00:00 ERR cryptohomed[820]: TSS: Could not connect to any machine in the list.
    2017-04-07T21:40:51.012814+00:00 ERR cryptohomed[820]: TSS: Failed to send packet
    2017-04-07T21:40:51.113166+00:00 WARNING cryptohomed[820]: TSS: Failed unix connect: /var/run/tcsd.socket - No such file or directory
    2017-04-07T21:40:51.113233+00:00 WARNING cryptohomed[820]: TSS: Got a list of valid IPs
    2017-04-07T21:40:51.113501+00:00 WARNING cryptohomed[820]: TSS: Could not connect to machine: localhost
    2017-04-07T21:40:51.113525+00:00 ERR cryptohomed[820]: TSS: Could not connect to any machine in the list.
    2017-04-07T21:40:51.113534+00:00 ERR cryptohomed[820]: TSS: Failed to send packet
    2017-04-07T21:40:51.214249+00:00 WARNING cryptohomed[820]: TSS: Failed unix connect: /var/run/tcsd.socket - No such file or directory
    2017-04-07T21:40:51.214319+00:00 WARNING cryptohomed[820]: TSS: Got a list of valid IPs
    2017-04-07T21:40:51.214631+00:00 WARNING cryptohomed[820]: TSS: Could not connect to machine: localhost
    2017-04-07T21:40:51.214655+00:00 ERR cryptohomed[820]: TSS: Could not connect to any machine in the list.
    2017-04-07T21:40:51.214664+00:00 ERR cryptohomed[820]: TSS: Failed to send packet
    2017-04-07T21:40:51.315180+00:00 ERR cryptohomed[820]: TPM error 0x3011 (Communication failure): Error calling Tspi_Context_Connect
    2017-04-07T21:40:51.315295+00:00 ERR cryptohomed[820]: ConnectContextAsUser: Could not open the TPM
    2017-04-07T21:40:51.315316+00:00 ERR cryptohomed[820]: ExtendPCR: Failed to connect to the TPM.
    2017-04-07T21:40:51.315358+00:00 WARNING cryptohomed[820]: Failed to finalize boot lockbox.
    2017-04-07T21:40:51.315416+00:00 WARNING cryptohomed[820]: Could not load the device policy file.
    2017-04-07T21:40:51.316013+00:00 WARNING cryptohomed[820]: No valid keysets on disk for 93b58ca74bea4d48b61a7eb7450ac0e27acbff19
    2017-04-07T21:40:51.316034+00:00 ERR cryptohomed[820]: Failed to decrypt any keysets for 93b58ca74bea4d48b61a7eb7450ac0e27acbff19
    2017-04-07T21:40:51.316051+00:00 ERR cryptohomed[820]: Error, cryptohome must be re-created because of fatal error.
    2017-04-07T21:40:51.375621+00:00 ERR cryptohomed[820]: Fatal decryption error, but unable to remove cryptohome.
    2017-04-07T21:40:51.375975+00:00 WARNING cryptohomed[820]: PKCS#11 initialization requested but cryptohome is not mounted.
    
1: https://luci-milo.appspot.com/buildbot/chromiumos.tryserver/pre_cq/26658
2: https://pantheon.corp.google.com/storage/browser/chromeos-image-archive/trybot-caroline-pre-cq/R59-9440.0.0-b26658/vm_test_results_1/smoke_suite/test_harness/all/SimpleTestVerify/1_autotest_tests/results-10-desktopui_ScreenLocker/desktopui_ScreenLocker/sysinfo/var/log_diff/
 
Cc: coconutruben@chromium.org gwendal@chromium.org
Based on the logs from the bug description tcsd daemon that communicates with the tpm is not running. So, cryptohomed can't communicate with the tpm through it, hence all the errors.

Here is why tcsd is not running:
2017-04-07T21:19:22.916349+00:00 NOTICE tpm-probe[495]: tpm is non-functional or tpm driver is missing
...
2017-04-07T21:19:23.323188+00:00 ERR tcsd[556]: TSS: Could not find a device to open!
2017-04-07T21:19:23.324094+00:00 WARNING kernel: [    9.323878] init: tcsd main process (556) terminated with status 137

And I don't see any output from the tpm driver probe in /var/log/messages. Did something change in the caroline image wrt tpm driver?
messages
551 KB View Download
Oh, wait, that's VM. So it is expected that tpm is not found and tcsd is not running...
Then the only actual error is this (the rest before it is just initialization after owning a new board w/o clearing the disk):
    2017-04-07T21:40:51.375621+00:00 ERR cryptohomed[820]: Fatal decryption error, but unable to remove cryptohome.
That might be another incarnation of  issue 699389 .
"Fatal decryption error, but unable to remove cryptohome."
it means we can not remove the user directories. base::RemoveFile should succeed even if the path does not exist.

If reproducible, it would be interesting to override platform::DeleteFile() and print more detailed errors ( platform::DeleteFile() calls base:DeleteFile() at
https://cs.corp.google.com/chromeos_public/src/aosp/external/libchrome/base/files/file_util_posix.cc?rcl=7b88bc885b9d8dc551beab840b853a79fa06494d&l=201

Note to self:
at https://cs.corp.google.com/chromeos_public/src/platform2/cryptohome/mount.cc?rcl=c7f6a6d912aed5391d9747c8d436e4d26ccf7dff&l=418

if (recreate_decrypt_fatal & (local_mount_error & MOUNT_ERROR_FATAL)) {
should be
if (recreate_decrypt_fatal && (local_mount_error & MOUNT_ERROR_FATAL)) {
We are lucky True == MOUNT_ERROR_FATAL.

Issue 710671 has been merged into this issue.
There is a workaround for removal issues here: https://chromium-review.googlesource.com/c/475030/. Still WIP, though, and breaks unit tests.
The work on the actual fix is going on in b/37189798. In particular, this WIP patch: https://chromium-review.googlesource.com/c/480906/
Status: Fixed (was: Assigned)
"Fatal decryption error, but unable to remove cryptohome" is fixed in b/37189798.
Marking this Fixed as well. Let's reopen if the same issue is still seen in the future.

Sign in to add a comment