Add viro@, who is the author of the commit.

I actually use drm-intel, instead of upstream kernel. However, I believe you can reproduce with upstream kernel, as the commit is there also. 
https://anongit.freedesktop.org/git/drm-intel.git

I use drm-intel-nightly branch and the final commit is as follow
commit 88948818ebe64f25bf5dfb7406f8728dabdecc59
Author: Chris Wilson <chris@chris-wilson.co.uk>
Date:   Thu Jan 5 21:12:59 2017 +0000

    drm-tip: 2017y-01m-05d-21h-12m-36s UTC integration manifest

@DS: drm-intel-nightly is a branch with volatile SHA1s, so not useful to report bugs against:

# git fetch
From git://anongit.freedesktop.org/drm-intel
 + 362e5ebefe40...8f7458237916 drm-intel-nightly -> drm-intel/drm-intel-nightly  (forced update)
# git show 88948818ebe64f25bf5dfb7406f8728dabdecc59
fatal: bad object 88948818ebe64f25bf5dfb7406f8728dabdecc59

DS could you:
- either reproduce with a permanent SHA1 and report it here, or (less convenient):
- extract from the manifest the combination of permanent SHA1s?

I just got a chance to confirm this myself with kernel tag v4.10-rc4 (and userspace R57-9176.0.0)

Reverting:

  ecryptfs_lookup(): try either only encrypted or plaintext name

... I can login, otherwise I cannot. Here are the failing and successful /var/log/chrome/chrome logs:

without reverting:

[1446:1446:0117/184858.202184:VERBOSE1:existing_user_controller.cc(410)] Setting flow from PerformLogin
[1446:1446:0117/184858.202251:VERBOSE1:user_flow.cc(20)] Flow 0x59ecb4c4f80 got host 0x59ecbfb5000
[1446:1446:0117/184858.202318:VERBOSE1:login_performer.cc(286)] Offline auth started.
[1446:1446:0117/184858.890047:ERROR:device_event_log_impl.cc(140)] [18:48:58.889] Login: homedir_methods.cc:402 HomedirMethods MountEx error: 5
[1446:1446:0117/184858.890181:ERROR:device_event_log_impl.cc(140)] [18:48:58.890] Login: cryptohome_authenticator.cc:886 Cryptohome failure: state=2, code=1
[1446:1446:0117/184858.890209:VERBOSE1:cryptohome_authenticator.cc(730)] Resolved state to: 2
[1446:1446:0117/184858.890288:ERROR:device_event_log_impl.cc(140)] [18:48:58.890] Login: cryptohome_authenticator.cc:672 Login failed: Could not mount cryptohome.
[1446:1446:0117/184858.890401:ERROR:login_performer.cc(63)] Login failure, reason=1, error.state=0
[1446:1446:0117/184858.890514:VERBOSE1:existing_user_controller.cc(1041)] Could not mount cryptohome.
[1446:1446:0117/184858.890536:VERBOSE1:webui_login_display.cc(110)] Show error, error_id: 7543, attempts:1, help_topic_id: 188036
[1446:1446:0117/184858.890763:ERROR:core_oobe_handler.cc(204)] CoreOobeHandler::ShowSignInError: error_text=Sorry, your password could not be verified. Please try again.
Hit Control-Shift-Space to switch keyboard layout.
[1:1:0117/184858.902095:ERROR:KeyboardEventManager.cpp(424)] Not implemented reached in static bool blink::KeyboardEventManager::currentCapsLockState()


with the revert:

[1401:1401:0117/190505.880128:VERBOSE1:existing_user_controller.cc(410)] Setting flow from PerformLogin
[1401:1401:0117/190505.880289:VERBOSE1:user_flow.cc(20)] Flow 0xc182570c5c0 got host 0xc1825d786e0
[1401:1401:0117/190505.880391:VERBOSE1:login_performer.cc(286)] Offline auth started.
[1401:1401:0117/190506.805090:VERBOSE1:cryptohome_authenticator.cc(730)] Resolved state to: 12
[1401:1401:0117/190506.805229:VERBOSE1:cryptohome_authenticator.cc(637)] Login success
[1401:1401:0117/190506.805444:VERBOSE1:login_performer.cc(82)] LoginSuccess hash: d46d58f0dbdfb34bfbd82af9d7566d202aaee23c
[1401:1401:0117/190506.805519:VERBOSE1:user_session_manager.cc(483)] Starting user session.

Can you do

find /place/being/mounted/ ! -name 'ECRYPTFS_FNEK_ENCRYPTED.*'

It seems like something is in the lower filesystem that is not encrypted?

MountEx error 5 is:

  CRYPTOHOME_ERROR_MOUNT_FATAL = 5;

https://chromium.googlesource.com/chromiumos/platform/system_api/+/master/dbus/cryptohome/rpc.proto

CRYPTOHOME_ERROR_MOUNT_FATAL maps to MOUNT_ERROR_FATAL in cryptohome. The only places where MOUNT_ERROR_FATAL is set and there isn't a PLOG(ERROR) line are:


  if (non_owner && (ephemeral_users || mount_args.ensure_ephemeral)) {
    if (!mount_args.create_if_missing) {
      LOG(ERROR) << "An ephemeral cryptohome can only be mounted when its "
                 << "creation on-the-fly is allowed.";
      *mount_error = MOUNT_ERROR_USER_DOES_NOT_EXIST;
      return false;
    }

    if (!MountEphemeralCryptohome(credentials)) {
      homedirs_->Remove(credentials.username());
      *mount_error = MOUNT_ERROR_FATAL;
      return false;
    }


And:


  FilePath user_home = GetMountedUserHomePath(obfuscated_username);
  if (!SetupGroupAccess(FilePath(user_home))) {
    UnmountAll();
    *mount_error = MOUNT_ERROR_FATAL;
    return false;
  }


The first is unlikely: I don't think we're doing an ephemeral mount here; this is a real user login?

Are you able to check full system logs too? I'd like to see what cryptohome is reporting. I realize you're only looking at Chrome logs here?

I have a system in that state and I can ssh into it. How do I get cryptohome logs? 

They should all be visible in /var/log/messages (a grep for "cryptohome" should find them all).

See attached. 

Deleted: cryptohome_msgs.log 16.8 KB

cryptohome_msgs.log 16.8 KB View Download

Okay, it seems that this is breaking on the Downloads directory, which lives in the vault without filename encryption since it needs to be addressable when unmounted. The mentioned patch breaks support for unencrypted filenames when mounting with filename encryption. I've raised this with upstream.

Upstream kernel needs this patch: http://www.spinics.net/lists/keyrings/msg00644.html

ecryptfs use user session keyring which is not looked at if a session keyring exits.

Does this actually fix it? I'm pretty sure the issue is the mixed unencrypted/encrypted dentries.

That patch doesn't fix the issue. See attached log.

Deleted: messages_cryptohome.log 32.0 KB

messages_cryptohome.log 32.0 KB View Download

What board are you running it on? In logs from comments #11 and #15 I see a lot of errors with cryptohome trying to access trunksd: "Failed to call method: org.chromium.Trunks.SendCommand". Meaning that trunks daemon is not running.

That only makes sense on devices with TPM 2.0 chip. On other boards cryptohome shouldn't try using trunksd.

If it is indeed a board with TPM 2.0, check trunksd errors in the log. It's is possible that the TPM is in lockout, for example.

#16 - I use Acer Chromebook 14 (Model number CPS-471)
It use Skylake celeron, and overlay target is lars.

keescook - here's all logs of /home/chronos/user/log/chrome /var/log/chrome/chrome /var/log/messages
there are some cryptohomed warning and err
marc, I use linus master tree this time.

localhost ~ # tail -f /home/chronos/user/log/chrome /var/log/chrome/chrome /var/log/messages
[591:4309:0126/142215.778763:ERROR:cpu_data_collector.cc(279)] CPU freq stats not available in sysfs.
[591:591:0126/142216.955895:WARNING:CONSOLE(16101)] "Unrecognized message from GAIA: clearOldAttempts", source: chrome://oobe/oobe.js (16101)
[55:55:0126/142217.217731:ERROR:KeyboardEventManager.cpp(424)] Not implemented reached in static bool blink::KeyboardEventManager::currentCapsLockState()
[591:591:0126/142217.582375:WARNING:CONSOLE(16101)] "Unrecognized message from GAIA: showConfirmCancel", source: chrome://oobe/oobe.js (16101)
[591:591:0126/142221.020813:VERBOSE1:oauth2_token_fetcher.cc(82)] Got OAuth2 tokens!
[591:591:0126/142221.020882:VERBOSE1:oauth2_token_initializer.cc(32)] OAuth2 tokens fetched
[591:591:0126/142221.021027:VERBOSE1:existing_user_controller.cc(433)] Setting flow from PerformLogin
[591:591:0126/142221.021063:VERBOSE1:user_flow.cc(20)] Flow 0x100085029570 got host 0x100084ee2580
[591:591:0126/142221.021142:VERBOSE1:login_performer.cc(273)] Online login completion started.
[591:591:0126/142221.021419:VERBOSE1:cryptohome_authenticator.cc(730)] Resolved state to: 0
[591:591:0126/142221.074151:ERROR:user_session_manager.cc(1843)] OAuth2 token handle fetch failed.

==> /var/log/messages <==
2017-01-26T22:22:21.048433+00:00 WARNING cryptohomed[712]: Could not load the device policy file.

==> /var/log/chrome/chrome <==
[591:591:0126/142221.341680:ERROR:device_event_log_impl.cc(140)] [14:22:21.341] Login: homedir_methods.cc:402 HomedirMethods MountEx error: 5
[591:591:0126/142221.341867:ERROR:device_event_log_impl.cc(140)] [14:22:21.341] Login: cryptohome_authenticator.cc:886 Cryptohome failure: state=2, code=1
[591:591:0126/142221.341913:VERBOSE1:cryptohome_authenticator.cc(730)] Resolved state to: 2
[591:591:0126/142221.342005:ERROR:device_event_log_impl.cc(140)] [14:22:21.341] Login: cryptohome_authenticator.cc:672 Login failed: Could not mount cryptohome.
[591:591:0126/142221.342032:ERROR:login_performer.cc(63)] Login failure, reason=1, error.state=0
[591:591:0126/142221.342159:VERBOSE1:existing_user_controller.cc(1064)] Could not mount cryptohome.
[591:591:0126/142221.342195:VERBOSE1:webui_login_display.cc(110)] Show error, error_id: 2735, attempts:3, help_topic_id: 188036
[591:591:0126/142221.342230:ERROR:core_oobe_handler.cc(204)] CoreOobeHandler::ShowSignInError: error_text=Sorry, your email or password could not be verified. Please try again.
Hit Control-Shift-Space to switch keyboard layout.
[591:591:0126/142221.356338:VERBOSE1:gaia_screen_handler.cc(926)] LoadAuthExtension, force: 1, offline: 0
[591:591:0126/142221.357836:VERBOSE1:gaia_screen_handler.cc(926)] LoadAuthExtension, force: 1, offline: 0
[591:591:0126/142221.357892:VERBOSE1:gaia_screen_handler.cc(930)] Skip loading the Auth extension as it's already being loaded
[591:591:0126/142221.358358:INFO:signin_screen_handler.cc(1349)] Login WebUI >> active: 0, source: gaia-signin
[591:591:0126/142221.358482:INFO:signin_screen_handler.cc(1349)] Login WebUI >> active: 1, source: gaia-signin
[591:591:0126/142221.366325:VERBOSE1:signin_screen_handler.cc(1304)] Login WebUI >> loginVisible, src: oobe, webui_visible_: 1
[591:591:0126/142221.366751:INFO:signin_screen_handler.cc(1349)] Login WebUI >> active: 0, source: gaia-signin
[591:591:0126/142221.367138:INFO:signin_screen_handler.cc(1349)] Login WebUI >> active: 1, source: gaia-signin
[591:591:0126/142221.371869:VERBOSE1:signin_screen_handler.cc(1304)] Login WebUI >> loginVisible, src: oobe, webui_visible_: 1
[591:591:0126/142221.378151:VERBOSE1:gaia_screen_handler.cc(448)] Auth extension finished loading
[591:591:0126/142221.381467:VERBOSE1:signin_screen_handler.cc(1304)] Login WebUI >> loginVisible, src: gaia-loading, webui_visible_: 1
[591:591:0126/142221.381537:VERBOSE1:signin_screen_handler.cc(1304)] Login WebUI >> loginVisible, src: gaia-loading, webui_visible_: 1
[591:591:0126/142221.905555:VERBOSE1:gaia_screen_handler.cc(660)] Gaia is loaded
[591:591:0126/142221.905823:VERBOSE1:signin_screen_handler.cc(1304)] Login WebUI >> loginVisible, src: gaia-signin, webui_visible_: 1
[591:591:0126/142221.920495:WARNING:CONSOLE(16101)] "Unrecognized message from GAIA: showConfirmCancel", source: chrome://oobe/oobe.js (16101)

==> /var/log/messages <==
2017-01-26T22:22:21.330173+00:00 ERR cryptohomed[712]: stat() of /home/.shadow/12818b2ed8f55468ecd86331fd17c2c1eb018f56/mount/user failed.: No such file or directory
2017-01-26T22:22:21.330349+00:00 ERR cryptohomed[712]: Couldn't set up group access on directory: /home/.shadow/12818b2ed8f55468ecd86331fd17c2c1eb018f56/mount/user
2017-01-26T22:22:21.369854+00:00 WARNING cryptohomed[712]: PKCS#11 initialization requested but cryptohome is not mounted.

Adding a few other folks onto this thread who may know what's causing this

Upstream 88ae4ab9802eaa8e400e611f85883143d89d6b61 needs to be reverted until they have a better fix.

Thanks Kees. Who and where are "they"? I mean: could you point at some discussion  where we could help and keep track of progress? If not then is there some other, hopefully less ChromeOS-specific and better place this issue should be reported again to get more attention?

Tyler Hicks <tyhicks@canonical.com> is the "they". :) I chatted with him on IRC, and he's been working on a solution. If you want to email him (and CC linux-kernel@vger.kernel.org) to start a public thread, that'd be fine too. He's aware of the problem already, though.

(I don't seem to be able to add CCs to this bug report, or I'd add him directly.)

Kees, Wu-Cheng, Conrad, any progress or even just some on-going public discussion about this? 

BTW this issue has been confirmed by many different people on many different upstream kernel versions, can you please update the "Status"? It is still stuck at "Untriaged".

The Components is currently "Internals->Logging" which may not help either.

Since this bug voids ChromeOS' "upstream first" policy could the priority be raised? Thx.

I've adjusted the tags and added Gwendal to CC...

With the aforementioned ecryptfs patch reverted on 4.10 based drm-tip kernel, I am still seeing the login issue on 9743 CPFE image. The logs look similar 

[1393:1393:0717/162052.633280:ERROR:device_event_log_impl.cc(156)] [16:20:52.633] Login: cryptohome_authenticator.cc:702 Login failed: Could not mount cryptohome.
[1393:1393:0717/162052.633338:ERROR:login_performer.cc(63)] Login failure, reason=1, error.state=0
[1393:1393:0717/162052.633476:VERBOSE1:existing_user_controller.cc(1205)] Could not mount cryptohome.
[1393:1393:0717/162052.633497:VERBOSE1:webui_login_display.cc(109)] Show error, error_id: 2459, attempts:1, help_topic_id: 188036
[1393:1393:0717/162052.633531:ERROR:core_oobe_handler.cc(171)] CoreOobeHandler::ShowSignInError: error_text=Sorry, your email or password could not be verified. Please try again.

Not able to login with drm-tip based on 4.15-rc6 kernel. This was with 10278 CPFE image.
Getting same "Could not mount cryptohome" error. On reverting the ecryptfs patch mentioned above, I was able to login. 

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/kernel/+/295b17d7562b9c9ccc7b743b46e18a6a3ba156b9

commit 295b17d7562b9c9ccc7b743b46e18a6a3ba156b9
Author: Guenter Roeck <groeck@chromium.org>
Date: Thu Jan 18 13:09:39 2018

CHROMIUM: Revert "ecryptfs_lookup(): try either only encrypted or plaintext name"

This reverts commit 88ae4ab9802eaa8e400e611f85883143d89d6b61.

Commit 88ae4ab9802e ("ecryptfs_lookup(): try either only encrypted or
plaintext name") introduces a regression preventing logins. Revert it
until the problem has been resolved.

BUG= chromium:680333 ,  chromium:793353 
TEST=Try to log in on graphics screen

Change-Id: I93449548c5e7ab61bc0d9adf842e346610a69abf
Signed-off-by: Guenter Roeck <groeck@chromium.org>
Reviewed-on: https://chromium-review.googlesource.com/869771
Commit-Ready: Gwendal Grignou <gwendal@chromium.org>
Reviewed-by: Gwendal Grignou <gwendal@chromium.org>

[modify] https://crrev.com/295b17d7562b9c9ccc7b743b46e18a6a3ba156b9/fs/ecryptfs/inode.c

> The mentioned patch breaks support for unencrypted filenames when mounting with filename encryption. I've raised this with upstream.

So is this really a confirmed kernel regression and if yes does anyone know what happened to "Don't break user space"? https://lkml.org/lkml/2012/12/23/75

It's not possible to login with any kernel between 4.7 and 4.15; and counting.

Has any upstream discussion moved beyond IRC and to lkml or some other public list?

It turns out that 88ae4ab9802e solves a real problem; prior to this commit, it was possible to create both an unencrypted and an encrypted file with the same inode within an ecryptfs mount (see https://bugs.launchpad.net/ecryptfs/+bug/1676107). I'd have to defer to Tyler, but it appears that it was just too difficult to support both.

At the same time, we are moving away from ecryptfs to encrypted ext4. New installations all use ext4. This means that the problem is only seen on older installations when updating the kernel to a new version. It might even be possible that the problem disappears if/when the system is reinstalled from scratch. Also, no Chromebook running its supported kernel will experience the problem. Given that, while undesirable and unfortunate, it is somewhat understandable that this doesn't exactly have high priority (if a fix is even possible).

Regarding "confirmed kernel regression" and "Don't break user space", I would argue that this is one of the famous corner cases. Is it more important to support both encrypted and unencrypted file names, or is it more important to guarantee data consistency ? The ecryptfs maintainers decided for the latter, and for my part I accept that decision, even if I may be a bit disgruntled about it (primarily because 88ae4ab9802e lacks context, not because I disagree with the decision).

Thanks Guenter, https://bugs.launchpad.net/ecryptfs/+bug/1326772 (filed in... 2014) provides the context and explanation we've been missing for so long. Very useful.

> At the same time, we are moving away from ecryptfs to encrypted ext4. New installations all use ext4. 

Could you precise "new" with some (vague) dates/branches and/or commits/issue numbers? We've reproduced this issue with fairly recent partner images (+ upstream kernels); I would say with images less than 1 month old.

> Okay, it seems that this is breaking on the Downloads directory, which lives in the vault without filename encryption since it needs to be addressable when unmounted

Any chance something as simple as deleting the Downloads directory would be enough to work around this issue? Hopefully it would be either not automatically re-generated, or re-generated with an encrypted name. That would be orders of magnitude more convenient than reverting this commit.

Use of ext4 crypto instead of ecryptfs is governed by several factors:
- use flag direncryption: if a board has this flag, on new install/power wash, new user directories will use ext4 crypto. Older board (current kernel <= 3.10) will stays with ecryptfs forever.
- On board where the flag is set, if the user is allowed to use ARC++ and wants to use it, her data will first be migrated from ecryptfs to ext4 crypto (user login is needed).

So - assuming the patch is not reverted - a machine is upgraded to kernel > 4.7 and a user has an account for a while and has not used ARC++, he  won't be able to login anymore.

For reference, UMA stats variable Cryptohome.HomedirEncryptionType tracks the type of encryption.

Some directories - tracked directories - are in clear to allow free'ing space. Cache, GCache, ... of users who haven't logged in for a while. Their content can be safely deleted [noone needs an old cache directory], even if the data is encrypted. See https://chromium.googlesource.com/chromiumos/platform/cryptohome/+/master/homedirs.cc#60
If a tracked directory is missing, it is re-created at login (see CreateTrackedSubdirectories() in mount.cc)

To solve the problem without the revert, we would need to migrate users to use encrypted tracked directory names all the time and use a special xattr ("user.TrackedDirectoryName") as we do with ext4 crypto to find the tracked directories. 

So if this is only impacting someone using ecryptfs on a kernel >4.7 then we are probably fine as it is, anything new enough to get the new kernel would be ext4 crypto. 

We would have to only watch out for this if we decided to try to migrate some older systems to a >4.7 kernel but that seems unlikely to happen in their lifespan.

#37: See #31 - the patch causing problems in v4.7+ has been reverted in chromeos-4.14, so this is not an issue, at least not for chromeos-4.14.

Right, I guess if we carry forward the CHROMIUM: revert of the patch then we should be good for all time. 

Unlike chromium:793353, this issue has always been about the ability for developers to test mainline kernels and never about any actual product. Sorry for any confusion that might have happened.

Log as yourself, open a shell, issue: mount | grep ecryptfs

If there are some match, you are using ecryptfs.

... and you need (to keep) the revert. Thx Gwendal.

Now the real fun is that upstream commit 88ae4ab9802e doesn't solve the problem it claims to solve.

Try the following:
- mount ecryptfs without file name encryption. Create a file.
- unmount
- mount same ecryptfs with file name encryption enabled. You'll see the file with "ls", but with unknown permissions.
- create another file with the same name. Write something else into it.
- now you'll have two files with the same name and the same content (pointing to the same inode)
- unmount
- mount again with file name encryption disabled. Now you'll see two different files, one with the real name and one with an encrypted name, with different contents.

I tested the above with v4.14.12.

Problem now is that ecryptfs_lookup() only finds a file if its name and encryption status matches. It doesn't find "myfile" unencrypted if file name encryption is enabled, and it doesn't find "myfile" encrypted if file name encryption is disabled. Arguably this is worse then before, where it did at least find the unencrypted file if file name encryption is enabled.

Effectively it is now easier than before to create the condition that was supposed to be fixed with 88ae4ab9802e. Previously, it was necessary to mount with file name encryption enabled, create a file, then do the same with file name encryption disabled, to create two files with the same name. This still works, only now the opposite approach works as well (create the unencrypted file first). Given that, I have no idea what 88ae4ab9802e is actually supposed to fix.

Submitted https://patchwork.kernel.org/patch/10217667/. We'll see what the upstream maintainer has to say.
Assigning to myself for tracking. Reducing severity since there is really nothing we can do at this point.

No answer to Guenter's patch on https://www.spinics.net/lists/ecryptfs/. Very little traffic there anyway.

Not much going on in "git log  v4.16-rc3 -- fs/ecryptfs/" either.

> At the same time, we are moving away from ecryptfs to encrypted ext4.

I could guess one reason why now.

Some upstream comments would/might help, though. So far there is silence.
It is also quite interesting that the people who triggered 88ae4ab9802e and thus really caused the problem never spoke up and complained that the "fix" made the situation even worse.

Necessary fix rejected upstream. Anyone interested in running chromebooks with upstream kernels needs to avoid using ecryptfs and should use ext4 instead.

> Necessary fix rejected upstream

Just for the record are you referring to this end of March 2018 discussion or something newer I didn't see?
https://www.spinics.net/lists/ecryptfs/msg01015.html

(+ another, belated "thanks" for root-causing and documenting this extremely thoroughly)

#48: Yes, that is correct.