josephlr
commented
7 years ago @fancytenseletters, I'm looking though your logs at logout and I don't see the line about dropping caches (logged here). Do you have any more logout logs available?
Open ghost opened 7 years ago
josephlr
commented
7 years ago @fancytenseletters, I'm looking though your logs at logout and I don't see the line about dropping caches (logged here). Do you have any more logout logs available?
ghost
commented
7 years ago Sorry I cut them too early. Here's more complete version:
sddm-helper[3809]: [PAM] Closing session
sddm-helper[3809]: pam_unix(sddm:session): session closed for user user1
pam_fscrypt[3809]: CloseSession(map[debug:true lock_policies:true drop_caches:true])
pam_fscrypt[3809]: Session count for UID=1001 updated to 0
pam_fscrypt[3809]: locking polices protected with login protector
pam_fscrypt[3809]: KeyctlLink(735815295, 111339262) = <nil>
pam_fscrypt[3809]: Setting privileges to "user1"
pam_fscrypt[3809]: Setregid(-1, 1001) = <nil>
pam_fscrypt[3809]: Setgroups([1001 6 7 90 91 92 93 95 96 98]) = <nil>
pam_fscrypt[3809]: Setreuid(-1, 1001) = <nil>
pam_fscrypt[3809]: Reading config from "/etc/fscrypt.conf"
pam_fscrypt[3809]: creating context for "user1"
pam_fscrypt[3809]: found ext4 filesystem "/" (/dev/sda5)
pam_fscrypt[3809]: listing descriptors in "/.fscrypt/protectors"
pam_fscrypt[3809]: found 1 descriptor(s)
pam_fscrypt[3809]: successfully read metadata from "/.fscrypt/protectors/6682ae84e70e99b3"
pam_fscrypt[3809]: Getting protector 6682ae84e70e99b3 from option
pam_fscrypt[3809]: successfully read metadata from "/.fscrypt/protectors/6682ae84e70e99b3"
pam_fscrypt[3809]: listing descriptors in "/.fscrypt/policies"
pam_fscrypt[3809]: found 1 descriptor(s)
pam_fscrypt[3809]: successfully read metadata from "/.fscrypt/policies/949471831dcf55cf"
pam_fscrypt[3809]: got data for 949471831dcf55cf from "/"
pam_fscrypt[3809]: successfully read metadata from "/.fscrypt/protectors/6682ae84e70e99b3"
pam_fscrypt[3809]: listing descriptors in "/home/.fscrypt/policies"
pam_fscrypt[3809]: found 1 descriptor(s)
pam_fscrypt[3809]: successfully read metadata from "/home/.fscrypt/policies/949471831dcf55cf"
pam_fscrypt[3809]: got data for 949471831dcf55cf from "/home"
pam_fscrypt[3809]: stat /run/user/0/.fscrypt: permission denied
pam_fscrypt[3809]: stat /run/user/0/.fscrypt/policies: permission denied
pam_fscrypt[3809]: stat /run/user/0/.fscrypt/protectors: permission denied
pam_fscrypt[3809]: stat /sys/firmware/efi/efivars/.fscrypt: invalid argument
pam_fscrypt[3809]: stat /sys/firmware/efi/efivars/.fscrypt/policies: invalid argument
pam_fscrypt[3809]: stat /sys/firmware/efi/efivars/.fscrypt/protectors: invalid argument
pam_fscrypt[3809]: stat /sys/kernel/debug/.fscrypt: permission denied
pam_fscrypt[3809]: stat /sys/kernel/debug/.fscrypt/policies: permission denied
pam_fscrypt[3809]: stat /sys/kernel/debug/.fscrypt/protectors: permission denied
pam_fscrypt[3809]: KeyctlSearch(735815295, logon, ext4:949471831dcf55cf) = 149252955, <nil>
pam_fscrypt[3809]: KeyctlSearch(735815295, logon, ext4:949471831dcf55cf) = 149252955, <nil>
pam_fscrypt[3809]: KeyctlInvalidate(149252955) = <nil>
pam_fscrypt[3809]: policy 949471831dcf55cf deprovisioned
pam_fscrypt[3809]: KeyctlSearch(735815295, logon, ext4:949471831dcf55cf) = -1, required key not available
pam_fscrypt[3809]: policy 949471831dcf55cf not provisioned
pam_fscrypt[3809]: Setting privileges to "root"
pam_fscrypt[3809]: Setreuid(-1, 0) = <nil>
pam_fscrypt[3809]: Setregid(-1, 0) = <nil>
pam_fscrypt[3809]: Setgroups([0 1 2 3 4 6 10 19]) = <nil>
pam_fscrypt[3809]: dropping inode caches at session close
pam_fscrypt[3809]: dropping page caches
pam_fscrypt[3809]: pam func succeeded
kernel: sddm-helper (3809): drop_caches: 2
sddm-helper[3809]: [PAM] Ended.
sddm[797]: Auth: sddm-helper exited successfully
sddm[797]: Socket server stopping...
sddm[797]: Socket server stopped.
sddm[797]: Display server stopping...
systemd[1]: session-7.scope: Killing process 3981 (kactivitymanage) with signal SIGTERM.
systemd[1]: Stopping Session 7 of user user1.
systemd[1]: Stopped Session 7 of user user1.
systemd-logind[768]: Removed session 7.
systemd[1]: Stopping User Manager for UID 1001...
systemd[3841]: Stopped dbus-org.kde.kwalletd5.service.
systemd[3841]: Stopping dbus-org.gnome.GConf.service...
dbus-launch[3863]: Caught SIGTERM, exiting
obexd[4076]: Terminating
systemd[3841]: Stopping D-Bus User Message Bus...
systemd[3841]: Stopping Sound Service...
systemd[3841]: Stopped target Default.
systemd[3841]: Stopping Bluetooth OBEX service...
systemd[3841]: Stopping dbus-ca.desrt.dconf.service...
systemd[3841]: Stopped dbus-org.gnome.GConf.service.
systemd[3841]: Stopped dbus-ca.desrt.dconf.service.
systemd[3841]: Stopped D-Bus User Message Bus.
systemd[3841]: Stopped Bluetooth OBEX service.
systemd[3841]: Stopped Sound Service.
systemd[3841]: Stopped target Basic System.
systemd[3841]: Stopped target Sockets.
systemd[3841]: Closed GnuPG cryptographic agent (ssh-agent emulation).
systemd[3841]: Closed GnuPG cryptographic agent and passphrase cache (restricted).
systemd[3841]: Closed GnuPG cryptographic agent and passphrase cache (access for web browsers).
systemd[3841]: Closed GnuPG network certificate management daemon.
systemd[3841]: Closed GnuPG cryptographic agent and passphrase cache.
systemd[3841]: Closed D-Bus User Message Bus Socket.
systemd[3841]: Stopped target Timers.
systemd[3841]: Stopped target Paths.
systemd[3841]: Closed Sound System.
systemd[3841]: Reached target Shutdown.
systemd[3841]: Starting Exit the Session...
systemd[3841]: Received SIGRTMIN+24 from PID 4426 (kill).
systemd[3847]: pam_unix(systemd-user:session): session closed for user user1
systemd[1]: Stopped User Manager for UID 1001.
systemd[1]: Removed slice User Slice of user1.
sddm[797]: Display server stopped.
sddm[797]: Running display stop script "/usr/share/sddm/scripts/Xstop"
sddm[797]: Removing display ":0" ...Ok this is weird. The lines:
pam_fscrypt[3809]: KeyctlSearch(735815295, logon, ext4:949471831dcf55cf) = 149252955, <nil>
pam_fscrypt[3809]: KeyctlInvalidate(149252955) = <nil>
pam_fscrypt[3809]: dropping inode caches at session close
pam_fscrypt[3809]: dropping page cachesshow that the key is getting revoked and then caches are being dropped. That should result in the plaintext no longer being visible. This might be a kernel caching issue. Let me check with some people about it.
Also, @fancytenseletters it looks like part of the logs for the login for user1 were also cut off. Do you have the rest of them?
josephlr
commented
7 years ago After talking to @ebiggers (who knows this stuff the best), there are two potential issues here:
I'm working on a patch to fix (1) and some related logging information. However, you are most likely hitting (2). "Fixing" this will involve updating the documentation to emphasize three key points about Linux filesystem encryption (i.e. the behavior of the kernel):
User 1 unlocks a globally readable directory, User 2 will be able to see it.User 2 has a currently open file or directory that is encrypted and unlocked, User 1 running fscrypt purge will not have any effect on the contents of that open file. The plaintext will still be visible.This documentation change should also address the concerns of #61.
ghost
commented
7 years ago Thank you for the reply. Two questions:
Filesystem encryption does not replace standard Unix access controls. If User 1 unlocks a globally readable directory, User 2 will be able to see it.
I don't understand this. What's the role of user keyrings then?
In my understanding Unix access controls grants permission for user2 to browse encrypted files but if user2 doesn't have relevant key in his keyring he should be able to see only it's encrypted form regardless if user1 unlocks them or not. I remember that you had to link user's keyring to root's to grant system daemons access to encrypted files.
If it's true that unlocking directory make it accessible to everyone who has unix permissions then there are little advantages of using fscrypt in multi user environment. Also when locking encrypted directory again is non trivial it's little better than full disk encryption if any. Perhaps some FUSE file based encryption systems offers more in this regard.
I'm sorry for complaining but those news make me sad. :disappointed:
ebiggers
commented
7 years ago As it doesn't happen with console login (everything is encrypted at logout) isn't it a timing issue? Maybe SDDM is blocking something during logout process.
First, just to clarify, this has nothing to do with whether the data (including both file contents and file names) written to disk is encrypted or not. This is solely a matter of how the operating system kernel presents files to userspace after the encryption key has been "revoked". It is indeed reasonable to expect the files should "appear encrypted" after key revocation, and I'm actually working on designing a better API which may improve the usability of this. However, note just because the files "appear encrypted" doesn't mean that the key was properly revoked. To properly revoke a key, all instances of the key and all plaintext must be sanitized from memory --- since it must be assumed than the attacker can compromise everything in memory. This is actually very difficult and is rarely (if ever) gotten correct with any encryption solution. Thus, focusing only on how the files are presented is somewhat missing the point.
Why only filenames stay visible while file contents are encrypted?
Again, the data being written to disk is still encrypted either way. But as for why the filenames are still being presented in plaintext form, there might be a process that still has one of the files in the directory tree open --- that will pin all parent directories. Or, alternatively the directory inode may be dirty; if the latter, the problem should be fixed by doing sync() before echo 2 > /proc/sys/vm/drop_caches.
Filesystem encryption does not replace standard Unix access controls. If User 1 unlocks a globally readable directory, User 2 will be able to see it. I don't understand this. What's the role of user keyrings then?
In my understanding Unix access controls grants permission for user2 to browse encrypted files but if user2 doesn't have relevant key in his keyring he should be able to see only it's encrypted form regardless if user1 unlocks them or not. I remember that you had to link user's keyring to root's to grant system daemons access to encrypted files.
The decision to search for the encryption keys in the keyrings "possessed" by the process accessing the filesystem was probably a mistake. Along with other changes I've been looking into moving to a global (or a per-filesystem) keyring instead, since a global keyring better reflects the actual semantics (including the semantics of the Linux VFS --- there can only be one "view" of a directory at a time) as well as the threats which encryption actually protects against. It is important to understand that the purpose of encryption is to protect the confidentiality of data written to disk. It is not an access control mechanism. Sure, we could theoretically make the kernel enforce access control based on "who has the key" or not, but in reality after anyone has added the key to the running system, the data is actually not being protected by encryption, it is only being protected by the correctness of the kernel. Thus to protect against other users on the online system you really might as well just use file permissions. After all, if a malicious user is able to circumvent file permissions by exploiting a kernel security vulnerability, they could just easily circumvent any "encryption"-related access control checks. No need to break your AES-256 key :-)
If it's true that unlocking directory make it accessible to everyone who has unix permissions then there are little advantages of using fscrypt in multi user environment.
Each user can have their data encrypted on-disk with a different key, and it's allowed to have unencrypted files on the same filesystem. Neither of those is not possible with block-device level encryption.
Also when locking encrypted directory again is non trivial it's little better than full disk encryption if any. Perhaps some FUSE file based encryption systems offers more in this regard.
It's true that other solutions such as dm-crypt and eCryptfs do currently have a clearer way to determine whether files should "appear encrypted" or not. However, they generally don't do any better at actually managing key material securely and securely revoking the encryption key(s).
josephlr
commented
7 years ago To add on to what @ebiggers mentioned,
I don't understand this. What's the role of user keyrings then?
In an idea world, we would not use the user keyring, there would just be a single global keyring that all users could add keys to (this doesn't risk a leak of key material as all encryption keys are of type logon, meaning the data cannot ever be returned to userspace).
However, due to a limitation to the keyrings API, any keyring that users can add keys to, users can delete keys from. Under the global keyring, users could launch a denial of service attack on other users by constantly deleting their keys.
This is the reason we use the user keyrings, not for confidentially, but for availability.
josephlr
commented
7 years ago @fancytenseletters, could you try running the same commands with #67? That will at least tell us if it is a syncing issue or an issue with SDDM holding the home directory open. I'm going to try to setup SDDM on Arch so I can test it myself.
ghost
commented
7 years ago # fscrypt --version
Version:
0.2.1-11-g6953697user1 logs in:
sddm[803]: Message received from greeter: Login
sddm[803]: Reading from "/usr/share/xsessions/plasma.desktop"
sddm[803]: Reading from "/usr/share/xsessions/plasma.desktop"
sddm[803]: Session "/usr/share/xsessions/plasma.desktop" selected, command: "/usr/bin/startkde"
sddm-helper[1195]: [PAM] Starting...
sddm-helper[1195]: [PAM] Authenticating...
sddm-helper[1195]: [PAM] Preparing to converse...
sddm-helper[1195]: [PAM] Conversation with 1 messages
pam_fscrypt[1195]: Authenticate()
pam_fscrypt[1195]: Setreuid(1001, 0) = <nil>
pam_fscrypt[1195]: keyringID(_uid.1001) = 749743258, <nil>
sddm-helper[1195]: [PAM] returning.
pam_fscrypt[1195]: Setreuid(0, 1001) = <nil>
sddm[803]: Authenticated successfully
pam_fscrypt[1195]: KeyctlLink(749743258, -2) = <nil>
pam_fscrypt[1195]: Setreuid(0, 0) = <nil>
pam_fscrypt[1195]: keyringID(_uid.0) = 311378727, <nil>
pam_fscrypt[1195]: KeyctlLink(311378727, -2) = <nil>
pam_fscrypt[1195]: KeyctlLink(749743258, 311378727) = <nil>
pam_fscrypt[1195]: Setting privileges to "user1"
pam_fscrypt[1195]: Setregid(-1, 1001) = <nil>
pam_fscrypt[1195]: Setgroups([1001 6 7 90 91 92 93 95 96 98]) = <nil>
pam_fscrypt[1195]: Setreuid(-1, 1001) = <nil>
pam_fscrypt[1195]: Reading config from "/etc/fscrypt.conf"
pam_fscrypt[1195]: creating context for "user1"
pam_fscrypt[1195]: found ext4 filesystem "/" (/dev/sda)
pam_fscrypt[1195]: listing descriptors in "/.fscrypt/protectors"
pam_fscrypt[1195]: found 1 descriptor(s)
pam_fscrypt[1195]: successfully read metadata from "/.fscrypt/protectors/6682ae84e70e99b3"
pam_fscrypt[1195]: Getting protector 6682ae84e70e99b3 from option
pam_fscrypt[1195]: copying AUTHTOK for use in the session open
pam_fscrypt[1195]: Setting privileges to "root"
pam_fscrypt[1195]: Setreuid(-1, 0) = <nil>
pam_fscrypt[1195]: Setregid(-1, 0) = <nil>
pam_fscrypt[1195]: Setgroups([0 1 2 3 4 6 10 19]) = <nil>
pam_fscrypt[1195]: pam func succeeded
sddm-helper[1195]: pam_unix(sddm:session): session opened for user user1 by (uid=0)
pam_fscrypt[1195]: OpenSession()
pam_fscrypt[1195]: Session count for UID=1001 updated to 1
pam_fscrypt[1195]: KeyctlLink(749743258, 311378727) = <nil>
pam_fscrypt[1195]: Setting privileges to "user1"
pam_fscrypt[1195]: Setregid(-1, 1001) = <nil>
pam_fscrypt[1195]: Setgroups([1001 6 7 90 91 92 93 95 96 98]) = <nil>
pam_fscrypt[1195]: Setreuid(-1, 1001) = <nil>
pam_fscrypt[1195]: Reading config from "/etc/fscrypt.conf"
pam_fscrypt[1195]: creating context for "user1"
pam_fscrypt[1195]: found ext4 filesystem "/" (/dev/sda)
pam_fscrypt[1195]: listing descriptors in "/.fscrypt/protectors"
pam_fscrypt[1195]: found 1 descriptor(s)
pam_fscrypt[1195]: successfully read metadata from "/.fscrypt/protectors/6682ae84e70e99b3"
pam_fscrypt[1195]: Getting protector 6682ae84e70e99b3 from option
pam_fscrypt[1195]: successfully read metadata from "/.fscrypt/protectors/6682ae84e70e99b3"
pam_fscrypt[1195]: listing descriptors in "/.fscrypt/policies"
pam_fscrypt[1195]: found 1 descriptor(s)
pam_fscrypt[1195]: successfully read metadata from "/.fscrypt/policies/949471831dcf55cf"
pam_fscrypt[1195]: got data for 949471831dcf55cf from "/"
pam_fscrypt[1195]: successfully read metadata from "/.fscrypt/protectors/6682ae84e70e99b3"
pam_fscrypt[1195]: listing descriptors in "/home/.fscrypt/policies"
pam_fscrypt[1195]: found 1 descriptor(s)
pam_fscrypt[1195]: successfully read metadata from "/home/.fscrypt/policies/949471831dcf55cf"
pam_fscrypt[1195]: got data for 949471831dcf55cf from "/home"
systemd[1]: proc-sys-fs-binfmt_misc.automount: Got automount request for /proc/sys/fs/binfmt_misc, triggered by 1195 (sddm-helper)
systemd[1]: Mounting Arbitrary Executable File Formats File System...
systemd[1]: Mounted Arbitrary Executable File Formats File System.
pam_fscrypt[1195]: stat /run/user/0/.fscrypt: permission denied
pam_fscrypt[1195]: stat /run/user/0/.fscrypt/policies: permission denied
pam_fscrypt[1195]: stat /run/user/0/.fscrypt/protectors: permission denied
pam_fscrypt[1195]: stat /run/user/995/.fscrypt: permission denied
pam_fscrypt[1195]: stat /run/user/995/.fscrypt/policies: permission denied
pam_fscrypt[1195]: stat /run/user/995/.fscrypt/protectors: permission denied
pam_fscrypt[1195]: stat /sys/firmware/efi/efivars/.fscrypt: invalid argument
pam_fscrypt[1195]: stat /sys/firmware/efi/efivars/.fscrypt/policies: invalid argument
pam_fscrypt[1195]: stat /sys/firmware/efi/efivars/.fscrypt/protectors: invalid argument
pam_fscrypt[1195]: stat /sys/kernel/debug/.fscrypt: permission denied
pam_fscrypt[1195]: stat /sys/kernel/debug/.fscrypt/policies: permission denied
pam_fscrypt[1195]: stat /sys/kernel/debug/.fscrypt/protectors: permission denied
pam_fscrypt[1195]: unlocking 2 policies protected with AUTHTOK
pam_fscrypt[1195]: running passphrase hash for protector 6682ae84e70e99b3
sddm-helper[975]: [PAM] Closing session
sddm-helper[975]: pam_unix(sddm-greeter:session): session closed for user sddm
sddm-helper[975]: [PAM] Ended.
systemd[1]: session-c1.scope: Killing process 975 (sddm-helper) with signal SIGTERM.
systemd[1]: Stopping Session c1 of user sddm.
sddm[803]: Auth: sddm-helper exited successfully
sddm[803]: Greeter stopped.
systemd[1]: Stopped Session c1 of user sddm.
systemd-logind[779]: Removed session c1.
systemd[1]: Stopping User Manager for UID 995...
systemd[981]: Stopping D-Bus User Message Bus...
dbus-launch[998]: Caught SIGTERM, exiting
systemd[981]: Stopped target Default.
systemd[981]: Stopped D-Bus User Message Bus.
systemd[981]: Stopped target Basic System.
systemd[981]: Stopped target Timers.
systemd[981]: Stopped target Sockets.
systemd[981]: Closed GnuPG network certificate management daemon.
systemd[981]: Closed GnuPG cryptographic agent and passphrase cache (access for web browsers).
systemd[981]: Closed Sound System.
systemd[981]: Closed GnuPG cryptographic agent and passphrase cache.
systemd[981]: Closed GnuPG cryptographic agent and passphrase cache (restricted).
systemd[981]: Closed GnuPG cryptographic agent (ssh-agent emulation).
systemd[981]: Stopped target Paths.
systemd[981]: Closed D-Bus User Message Bus Socket.
systemd[981]: Reached target Shutdown.
systemd[981]: Starting Exit the Session...
systemd[981]: Received SIGRTMIN+24 from PID 1209 (kill).
systemd[987]: pam_unix(systemd-user:session): session closed for user sddm
systemd[1]: Stopped User Manager for UID 995.
systemd[1]: Removed slice User Slice of sddm.
pam_fscrypt[1195]: valid wrapping key for protector 6682ae84e70e99b3
pam_fscrypt[1195]: KeyctlSearch(749743258, logon, ext4:949471831dcf55cf) = -1, required key not available
pam_fscrypt[1195]: keyringID(session) = 275631317, <nil>
pam_fscrypt[1195]: KeyctlSearch(275631317, keyring, _uid.1001) = 749743258, <nil>
pam_fscrypt[1195]: KeyctlAddKey(logon, ext4:949471831dcf55cf, <data>, 749743258) = 1022238537, <nil>
pam_fscrypt[1195]: policy 949471831dcf55cf provisioned
pam_fscrypt[1195]: KeyctlSearch(749743258, logon, ext4:949471831dcf55cf) = 1022238537, <nil>
pam_fscrypt[1195]: policy 949471831dcf55cf already provisioned
pam_fscrypt[1195]: Setting privileges to "root"
pam_fscrypt[1195]: Setreuid(-1, 0) = <nil>
pam_fscrypt[1195]: Setregid(-1, 0) = <nil>
pam_fscrypt[1195]: Setgroups([0 1 2 3 4 6 10 19]) = <nil>
pam_fscrypt[1195]: pam func succeeded
systemd[1]: Created slice User Slice of user1.
systemd[1]: Starting User Manager for UID 1001...
systemd-logind[779]: New session 4 of user user1.
systemd[1]: Started Session 4 of user user1.
systemd[1227]: pam_unix(systemd-user:session): session opened for user user1 by (uid=0)
systemd[1227]: Reached target Paths.
systemd[1227]: Reached target Timers.
systemd[1227]: Listening on GnuPG network certificate management daemon.
systemd[1227]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
systemd[1227]: Listening on Sound System.
systemd[1227]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
systemd[1227]: Starting D-Bus User Message Bus Socket.
systemd[1227]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
systemd[1227]: Listening on GnuPG cryptographic agent and passphrase cache.
systemd[1227]: Listening on D-Bus User Message Bus Socket.
systemd[1227]: Reached target Sockets.
systemd[1227]: Reached target Basic System.
systemd[1227]: Reached target Default.
systemd[1227]: Startup finished in 18ms.
systemd[1]: Started User Manager for UID 1001.
sddm-helper[1195]: Starting: "/usr/share/sddm/scripts/Xsession \"/usr/bin/startkde\""
sddm-helper[1254]: Adding cookie to "/home/user1/.Xauthority"
sddm[803]: Session started
systemd[1227]: Started D-Bus User Message Bus.
dbus-launch[1267]: Listening on inherited socket
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/com.google.code.AccountsSSO.SingleSignOn.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.kde.kwalletd5.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.kde.kpasswdserver.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.jackaudio.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/ca.desrt.dconf.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.kde.kglobalaccel.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/com.nokia.singlesignonui.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.freedesktop.ColorHelper.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.fedoraproject.Config.Printing.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.a11y.Bus.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.bluez.obex.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.kde.plasma.Notifications.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.ffado.Control.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.kde.dolphin.FileManager1.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.kde.kscreen.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.kde.kded5.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.kde.kssld5.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.gnome.GConf.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/com.canonical.indicators.webcredentials.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.gtk.GLib.PACRunner.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.kde.kioexecd.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.kde.kcookiejar5.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.kde.Spectacle.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/kf5_org.kde.kuiserver.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.freedesktop.systemd1.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.kde.fontinst.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.kde.krunner.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.gnome.keyring.PrivatePrompter.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.kde.kwalletd.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/com.nokia.SingleSignOn.Backup.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.freedesktop.Akonadi.Control.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.gnome.keyring.SystemPrompter.service'
dbus-launch[1267]: Loading service '/usr/share/dbus-1/services/org.kde.kiod5.service'
kaccess[1316]: kf5.kcoreaddons.kaboutdata: Could not initialize the equivalent properties of Q*Application: no instance (yet) existing.
dbus-launch[1267]: Activation request for 'org.kde.kglobalaccel'
systemd[1227]: Started dbus-org.kde.kglobalaccel.service.
dbus-launch[1267]: Activation request for 'ca.desrt.dconf'
systemd[1227]: Started dbus-ca.desrt.dconf.service.user1 logout:
kdeinit5[1305]: QThread: Destroyed while thread is still running
sddm-helper[1195]: [PAM] Closing session
sddm-helper[1195]: pam_unix(sddm:session): session closed for user user1
pam_fscrypt[1195]: CloseSession(map[debug:true lock_policies:true drop_caches:true])
pam_fscrypt[1195]: Session count for UID=1001 updated to 0
pam_fscrypt[1195]: locking polices protected with login protector
pam_fscrypt[1195]: KeyctlLink(38418302, 1063174483) = <nil>
pam_fscrypt[1195]: Setting privileges to "user1"
pam_fscrypt[1195]: Setregid(-1, 1001) = <nil>
pam_fscrypt[1195]: Setgroups([1001 6 7 90 91 92 93 95 96 98]) = <nil>
pam_fscrypt[1195]: Setreuid(-1, 1001) = <nil>
pam_fscrypt[1195]: Reading config from "/etc/fscrypt.conf"
pam_fscrypt[1195]: creating context for "user1"
pam_fscrypt[1195]: found ext4 filesystem "/" (/dev/sda)
pam_fscrypt[1195]: listing descriptors in "/.fscrypt/protectors"
pam_fscrypt[1195]: found 1 descriptor(s)
pam_fscrypt[1195]: successfully read metadata from "/.fscrypt/protectors/6682ae84e70e99b3"
pam_fscrypt[1195]: Getting protector 6682ae84e70e99b3 from option
pam_fscrypt[1195]: successfully read metadata from "/.fscrypt/protectors/6682ae84e70e99b3"
pam_fscrypt[1195]: listing descriptors in "/.fscrypt/policies"
pam_fscrypt[1195]: found 1 descriptor(s)
pam_fscrypt[1195]: successfully read metadata from "/.fscrypt/policies/949471831dcf55cf"
pam_fscrypt[1195]: got data for 949471831dcf55cf from "/"
pam_fscrypt[1195]: successfully read metadata from "/.fscrypt/protectors/6682ae84e70e99b3"
pam_fscrypt[1195]: listing descriptors in "/home/.fscrypt/policies"
pam_fscrypt[1195]: found 1 descriptor(s)
pam_fscrypt[1195]: successfully read metadata from "/home/.fscrypt/policies/949471831dcf55cf"
pam_fscrypt[1195]: got data for 949471831dcf55cf from "/home"
pam_fscrypt[1195]: stat /run/user/0/.fscrypt: permission denied
pam_fscrypt[1195]: stat /run/user/0/.fscrypt/policies: permission denied
pam_fscrypt[1195]: stat /run/user/0/.fscrypt/protectors: permission denied
pam_fscrypt[1195]: stat /sys/firmware/efi/efivars/.fscrypt: invalid argument
pam_fscrypt[1195]: stat /sys/firmware/efi/efivars/.fscrypt/policies: invalid argument
pam_fscrypt[1195]: stat /sys/firmware/efi/efivars/.fscrypt/protectors: invalid argument
pam_fscrypt[1195]: stat /sys/kernel/debug/.fscrypt: permission denied
pam_fscrypt[1195]: stat /sys/kernel/debug/.fscrypt/policies: permission denied
pam_fscrypt[1195]: stat /sys/kernel/debug/.fscrypt/protectors: permission denied
pam_fscrypt[1195]: KeyctlSearch(38418302, logon, ext4:949471831dcf55cf) = 291924544, <nil>
pam_fscrypt[1195]: KeyctlSearch(38418302, logon, ext4:949471831dcf55cf) = 291924544, <nil>
pam_fscrypt[1195]: KeyctlInvalidate(291924544) = <nil>
pam_fscrypt[1195]: policy 949471831dcf55cf deprovisioned
pam_fscrypt[1195]: KeyctlSearch(38418302, logon, ext4:949471831dcf55cf) = -1, required key not available
pam_fscrypt[1195]: policy 949471831dcf55cf not provisioned
pam_fscrypt[1195]: Setting privileges to "root"
pam_fscrypt[1195]: Setreuid(-1, 0) = <nil>
pam_fscrypt[1195]: Setregid(-1, 0) = <nil>
pam_fscrypt[1195]: Setgroups([0 1 2 3 4 6 10 19]) = <nil>
pam_fscrypt[1195]: dropping appropriate filesystem caches at session close
pam_fscrypt[1195]: syncing changes to filesystem
pam_fscrypt[1195]: freeing reclaimable inodes and dentries
pam_fscrypt[1195]: pam func succeeded
kernel: sddm-helper (1195): drop_caches: 2
kernel: echo (1706): drop_caches: 2
sddm-helper[1195]: [PAM] Ended.
sddm[758]: Auth: sddm-helper exited successfully
sddm[758]: Socket server stopping...
sddm[758]: Socket server stopped.
sddm[758]: Display server stopping...
systemd[1]: session-4.scope: Killing process 1403 (kactivitymanage) with signal SIGTERM.
systemd[1]: Stopping Session 4 of user user1.
systemd[1]: Stopped Session 4 of user user1.
systemd-logind[744]: Removed session 4.
systemd[1]: Stopping User Manager for UID 1001...
systemd[1231]: Stopping dbus-ca.desrt.dconf.service...
systemd[1231]: Stopping dbus-org.gnome.GConf.service...
systemd[1231]: Stopping Sound Service...
systemd[1231]: Stopping D-Bus User Message Bus...
systemd[1231]: Stopped target Default.
systemd[1231]: Stopping Bluetooth OBEX service...
systemd[1231]: Stopped dbus-ca.desrt.dconf.service.
systemd[1231]: obex.service: Main process exited, code=exited, status=1/FAILURE
systemd[1231]: Stopped Bluetooth OBEX service.
systemd[1231]: obex.service: Unit entered failed state.
systemd[1231]: obex.service: Failed with result 'exit-code'.
systemd[1231]: Stopped D-Bus User Message Bus.
systemd[1231]: Stopped dbus-org.gnome.GConf.service.
systemd[1231]: Stopped Sound Service.
systemd[1231]: Stopped target Basic System.
systemd[1231]: Stopped target Paths.
systemd[1231]: Stopped target Timers.
systemd[1231]: Stopped target Sockets.
systemd[1231]: Closed GnuPG network certificate management daemon.
systemd[1231]: Closed D-Bus User Message Bus Socket.
systemd[1231]: Closed GnuPG cryptographic agent and passphrase cache (restricted).
systemd[1231]: Closed GnuPG cryptographic agent (ssh-agent emulation).
systemd[1231]: Closed GnuPG cryptographic agent and passphrase cache.
systemd[1231]: Closed GnuPG cryptographic agent and passphrase cache (access for web browsers).
systemd[1231]: Closed Sound System.
systemd[1231]: Reached target Shutdown.
systemd[1231]: Starting Exit the Session...
systemd[1231]: Received SIGRTMIN+24 from PID 1718 (kill).
systemd[1251]: pam_unix(systemd-user:session): session closed for user user1
systemd[1]: Stopped User Manager for UID 1001.
systemd[1]: Removed slice User Slice of user1.
sddm[758]: Display server stopped.
sddm[758]: Running display stop script "/usr/share/sddm/scripts/Xstop"
sddm[758]: Removing display ":0" ...
sddm[758]: Adding new display on vt 1 ...
sddm[758]: Display server starting...
sddm[758]: Running: /usr/bin/X -nolisten tcp -nolisten local -auth /var/run/sddm/{296ef275-cd8c-4465-9503-dea755ad6c25} -background none -noreset -displayfd 19 vt1
sddm[758]: Setting default cursor
sddm[758]: Running display setup script "/usr/share/sddm/scripts/Xsetup"
sddm[758]: Display server started.
sddm[758]: Socket server starting...
sddm[758]: Socket server started.
sddm[758]: Greeter starting...
sddm[758]: Adding cookie to "/var/run/sddm/{296ef275-cd8c-4465-9503-dea755ad6c25}"
sddm-helper[1729]: [PAM] Starting...
sddm-helper[1729]: [PAM] Authenticating...
sddm-helper[1729]: pam_unix(sddm-greeter:session): session opened for user sddm by (uid=0)
sddm-helper[1729]: [PAM] returning.
systemd[1]: Created slice User Slice of sddm.
systemd[1]: Starting User Manager for UID 995...
systemd-logind[744]: New session c2 of user sddm.
systemd[1]: Started Session c2 of user sddm.
systemd[1736]: pam_unix(systemd-user:session): session opened for user sddm by (uid=0)
systemd[1736]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
systemd[1736]: Listening on Sound System.
systemd[1736]: Reached target Timers.
systemd[1736]: Reached target Paths.
systemd[1736]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
systemd[1736]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
systemd[1736]: Starting D-Bus User Message Bus Socket.
systemd[1736]: Listening on GnuPG network certificate management daemon.
systemd[1736]: Listening on GnuPG cryptographic agent and passphrase cache.
systemd[1736]: Listening on D-Bus User Message Bus Socket.
systemd[1736]: Reached target Sockets.
systemd[1736]: Reached target Basic System.
systemd[1736]: Reached target Default.
systemd[1736]: Startup finished in 30ms.
systemd[1]: Started User Manager for UID 995.
sddm[758]: Greeter session started successfully
sddm-greeter[1748]: High-DPI autoscaling not Enabled
sddm[758]: Message received from greeter: Connect
systemd[1736]: Started D-Bus User Message Bus.
dbus-launch[1752]: Listening on inherited socket
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/com.google.code.AccountsSSO.SingleSignOn.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.kde.kwalletd5.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.kde.kpasswdserver.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.jackaudio.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/ca.desrt.dconf.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.kde.kglobalaccel.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/com.nokia.singlesignonui.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.freedesktop.ColorHelper.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.fedoraproject.Config.Printing.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.a11y.Bus.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.bluez.obex.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.kde.plasma.Notifications.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.ffado.Control.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.kde.dolphin.FileManager1.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.kde.kscreen.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.kde.kded5.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.kde.kssld5.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.gnome.GConf.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/com.canonical.indicators.webcredentials.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.gtk.GLib.PACRunner.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.kde.kioexecd.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.kde.kcookiejar5.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.kde.Spectacle.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/kf5_org.kde.kuiserver.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.freedesktop.systemd1.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.kde.fontinst.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.kde.krunner.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.gnome.keyring.PrivatePrompter.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.kde.kwalletd.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/com.nokia.SingleSignOn.Backup.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.freedesktop.Akonadi.Control.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.gnome.keyring.SystemPrompter.service'
dbus-launch[1752]: Loading service '/usr/share/dbus-1/services/org.kde.kiod5.service'Encrypted directory view after user1 logout:
total 48
drwxr-xr-x 8 user1 user1 4096 Oct 3 12:35 .
drwxr-xr-x 6 root root 4096 Oct 3 11:49 ..
-rwxr-xr-x 1 user1 user1 44 Oct 1 22:59 .bash_history
drwxr-xr-x 5 user1 user1 4096 Oct 3 12:17 .cache
drwxr-xr-x 12 user1 user1 4096 Oct 3 12:36 .config
drwxr-xr-x 2 user1 user1 4096 Oct 1 21:55 Desktop
-rwxr-xr-x 1 user1 user1 16 Oct 1 21:55 .esd_auth
-rwxr-xr-x 1 user1 user1 336 Oct 1 21:55 .gtkrc-2.0
drwxr-xr-x 3 user1 user1 4096 Oct 1 21:55 .kde4
drwxr-xr-x 3 user1 user1 4096 Oct 1 21:55 .local
drwxr-xr-x 2 user1 user1 4096 Oct 1 21:55 Temp
-rw------- 1 user1 user1 51 Oct 3 12:35 .XauthorityManually purging keys:
# fscrypt purge / --verbose --force --user=user1
Setreuid(1001, 0) = <nil>
keyringID(_uid.1001) = 38418302, <nil>
Setreuid(0, 1001) = <nil>
KeyctlLink(38418302, -2) = <nil>
Setreuid(0, 0) = <nil>
keyringID(_uid.0) = 1063174483, <nil>
KeyctlLink(1063174483, -2) = <nil>
KeyctlLink(38418302, 1063174483) = <nil>
Reading config from "/etc/fscrypt.conf"
creating context for "user1"
found ext4 filesystem "/" (/dev/sda)
listing descriptors in "/.fscrypt/policies"
found 1 descriptor(s)
KeyctlLink(38418302, 1063174483) = <nil>
KeyctlSearch(38418302, logon, ext4:949471831dcf55cf) = -1, required key not available
Policies purged for "/".
syncing changes to filesystem
freeing reclaimable inodes and dentries
Encrypted data removed filesystem cache.Encrypted directory view after manual purge:
total 48
drwxr-xr-x 8 user1 user1 4096 Oct 3 12:35 .
drwxr-xr-x 6 root root 4096 Oct 3 11:49 ..
drwxr-xr-x 3 user1 user1 4096 Oct 1 21:55 4KuOWyB8JVvtSjQ5wWBs+3UWsPIAtebNN03,X6EhRRD
-rw------- 1 user1 user1 51 Oct 3 12:35 7Gkj14k6MhIjhqp,YpbkzY0ZmW5CZ8NWfjtIUvuXVYN
drwxr-xr-x 5 user1 user1 4096 Oct 3 12:17 cYjQyFUTZ0aueNUy49A2gC6rqu+hr9YqG+J0YxZuogN
drwxr-xr-x 3 user1 user1 4096 Oct 1 21:55 dUJK0ZvNyVKTTyY2aT4uwV70oxGuP4UpaaNTHH6f,PI
-rwxr-xr-x 1 user1 user1 16 Oct 1 21:55 gaVOjkDXQ,epFAzE0U9oaiJ1RZegg,E46fybSNZxyZJ
drwxr-xr-x 12 user1 user1 4096 Oct 3 12:36 GhiHtwJJ6Udq2iruRTdskoM3gOuZO0qwD8Y7db9ViYK
-rwxr-xr-x 1 user1 user1 44 Oct 1 22:59 kqzCh1XWtdVwkE,KK35Atmzw5sgMJX7LstIonhmQBjF
-rwxr-xr-x 1 user1 user1 336 Oct 1 21:55 mA2atU6muhkdiJ8+x11CDrSijNnTx6GymhU5fZQSIRM
drwxr-xr-x 2 user1 user1 4096 Oct 1 21:55 t3rX5lOToba9YDfnn,05o5AOxqs,8C+lilp7ayKpy5M
drwxr-xr-x 2 user1 user1 4096 Oct 1 21:55 xavy48JtAUzUGMEFTKfrwd,ckOdtF0I09FkVArPrg1NI tried invoking fscrypt purge / --verbose --force --user=user1 through pam_exec but it didn't work either.
ebiggers
commented
5 years ago To revisit this:
The best that fscrypt can do to return an encrypted directory tree to its ciphertext view is what it currently does: remove the key, sync, and drop caches. If that doesn't fully work, then there must be a process that still has one of the files or directories open. For example, if /home/foo is the encrypted directory being locked but a process still has the file /home/foo/bar/baz open, then /home/foo/bar/baz will remain accessible. Furthermore, filenames in /home/foo/bar and /home/foo will remain presented in plaintext (since all parent directories are pinned into cache by an open file too). There's nothing that fscrypt can do about this if the file remains open.
When we switch fscrypt to use the filesystem-level keyrings (https://github.com/google/fscrypt/pull/148), the kernel will start printing a warning message when a file is still in-use when an encryption key is removed. That will allow tracking down the cause of these types of bugs. However note that such bugs are really in other parts of the system, not in fscrypt --- though maybe we could try to work around them by retrying the key removal for a few seconds and hoping the file was only in-use temporarily.
When using SDDM display manager, filenames are still available in plaintext after user logs out. It's weird as file contents remain encrypted. It doesn't happen if user logs in from console. It also happened before https://github.com/google/fscrypt/issues/57 was fixed and I executed
fscrypt purgecommand on exit from script.Encrypted directory status before login:
Encrypted directory view before login:
user1 logs in:
Encrypted directory view after user1 login:
user1 logout:
Encrypted directory status after user1 logout:
Encrypted directory view after user1 logout: