On Fri, Dec 18, 2020 at 1:47 AM Michael Labriola wrote: > > On Thu, Dec 17, 2020 at 4:56 PM Michael Labriola > wrote: > > > > On Thu, Dec 17, 2020 at 3:25 PM Amir Goldstein wrote: > > > > > > On Thu, Dec 17, 2020 at 9:46 PM Michael Labriola > > > wrote: > > > > > > > > On Thu, Dec 17, 2020 at 1:07 PM Amir Goldstein wrote: > > > > > > > > > > On Thu, Dec 17, 2020 at 6:22 PM Michael Labriola > > > > *snip* > > > > > > On Thu, Dec 17, 2020 at 7:00 AM Amir Goldstein wrote: > > > > > > Thanks, Amir. I didn't have CONFIG_DYNAMIC_DEBUG enabled, so > > > > > > > > > > I honestly don't expect to find much in the existing overlay debug prints > > > > > but you never know.. > > > > > I suspect you will have to add debug prints to find the problem. > > > > > > > > Ok, here goes. I had to setup a new virtual machine that doesn't use > > > > overlayfs for its root filesystem because turning on dynamic debug > > > > gave way too much output for a nice controlled test. It's exhibiting > > > > the same behavior as my previous tests (5.8 good, 5.9 bad). The is > > > > with a freshly compiled 5.9.15 w/ CONFIG_OVERLAY_FS_XINO_AUTO turned > > > > off and CONFIG_DYNAMIC_DEBUG turned on. Here's what we get: > > > > > > > > echo "file fs/overlayfs/* +p" > /sys/kernel/debug/dynamic_debug/control > > > > mount borky2.sqsh t > > > > mount -t tmpfs tmp tt > > > > mkdir -p tt/upper/{upper,work} > > > > mount -t overlay -o \ > > > > lowerdir=t,upperdir=tt/upper/upper,workdir=tt/upper/work blarg ttt > > > > [ 164.505193] overlayfs: mkdir(work/work, 040000) = 0 > > > > [ 164.505204] overlayfs: tmpfile(work/work, 0100000) = 0 > > > > [ 164.505209] overlayfs: create(work/#3, 0100000) = 0 > > > > [ 164.505210] overlayfs: rename(work/#3, work/#4, 0x4) > > > > [ 164.505216] overlayfs: unlink(work/#3) = 0 > > > > [ 164.505217] overlayfs: unlink(work/#4) = 0 > > > > [ 164.505221] overlayfs: setxattr(work/work, > > > > "trusted.overlay.opaque", "0", 1, 0x0) = 0 > > > > > > > > touch ttt/FOO > > > > touch: cannot touch 'ttt/FOO': No data available > > > > [ 191.919498] overlayfs: setxattr(upper/upper, > > > > "trusted.overlay.impure", "y", 1, 0x0) = 0 > > > > [ 191.919523] overlayfs: tmpfile(work/work, 0100644) = 0 > > > > [ 191.919788] overlayfs: tmpfile(work/work, 0100644) = 0 > > > > > > > > That give you any hints? I'll start reading through the overlayfs > > > > code. I've never actually looked at it, so I'll be planting printk > > > > calls at random. ;-) > > > > > > We have seen that open("FOO", O_WRONLY) fails > > > We know that FOO is lower at that time so that brings us to > > > > > > ovl_open > > > ovl_maybe_copy_up > > > ovl_copy_up_flags > > > ovl_copy_up_one > > > ovl_do_copy_up > > > ovl_set_impure > > > [ 191.919498] overlayfs: setxattr(upper/upper, > > > "trusted.overlay.impure", "y", 1, 0x0) = 0 > > > ovl_copy_up_tmpfile > > > ovl_do_tmpfile > > > [ 191.919523] overlayfs: tmpfile(work/work, 0100644) = 0 > > > ovl_copy_up_inode > > > This must be were we fail and likely in: > > > ovl_copy_xattr > > > vfs_getxattr > > > which can return -ENODATA, but it is not expected because the > > > xattrs returned by vfs_listxattr should exist... > > > > > > So first guess would be to add a debug print for xattr 'name' > > > and return value of vfs_getxattr(). > > > > Ok, here we go. I've added a bunch of printks all over the place. > > Here's what we've got. Things are unchanged during mount. Trying to > > touch FOO now gives me this: > > > > [ 114.365444] ovl_open: start > > [ 114.365450] ovl_maybe_copy_up: start > > [ 114.365452] ovl_maybe_copy_up: need copy up > > [ 114.365454] ovl_maybe_copy_up: ovl_want_write succeeded > > [ 114.365459] ovl_copy_up_one: calling ovl_do_copy_up() > > [ 114.365460] ovl_do_copy_up: start > > [ 114.365462] ovl_do_copy_up: impure > > [ 114.365464] ovl_set_impure: start > > [ 114.365484] overlayfs: setxattr(upper/upper, > > "trusted.overlay.impure", "y", 1, 0x0) = 0 > > [ 114.365486] ovl_copy_up_tmpfile: start > > [ 114.365507] overlayfs: tmpfile(work/work, 0100644) = 0 > > [ 114.365510] ovl_copy_up_inode: start > > [ 114.365511] ovl_copy_up_inode: ISREG && !metacopy > > [ 114.365625] ovl_copy_xattr: start > > [ 114.365630] ovl_copy_xattr: vfs_listxattr() returned 17 > > [ 114.365632] ovl_copy_xattr: buf allocated good > > [ 114.365634] ovl_copy_xattr: vfs_listxattr() returned 17 > > [ 114.365636] ovl_copy_xattr: slen=17 > > [ 114.365638] ovl_copy_xattr: name='security.selinux' > > SELinux? now that's not suspicious at all... > > > [ 114.365643] ovl_copy_xattr: vfs_getxattr returned size=-61 > > [ 114.365644] ovl_copy_xattr: cleaning up > > [ 114.365647] ovl_copy_up_inode: ovl_copy_xattr error=-61 > > [ 114.365649] ovl_copy_up_one: error=-61 > > [ 114.365651] ovl_copy_up_one: calling ovl_copy_up_end() > > [ 114.365653] ovl_copy_up_flags: ovl_copy_up_one error=-61 > > [ 114.365655] ovl_maybe_copy_up: ovl_copy_up_flags error=-61 > > [ 114.365658] ovl_open: ovl_maybe_copy_up error=-61 > > [ 114.365728] ovl_copy_up_one: calling ovl_do_copy_up() > > [ 114.365730] ovl_do_copy_up: start > > [ 114.365731] ovl_do_copy_up: impure > > [ 114.365733] ovl_set_impure: start > > [ 114.365735] ovl_copy_up_tmpfile: start > > [ 114.365748] overlayfs: tmpfile(work/work, 0100644) = 0 > > [ 114.365750] ovl_copy_up_inode: start > > [ 114.365752] ovl_copy_up_inode: ISREG && !metacopy > > [ 114.365770] ovl_copy_xattr: start > > [ 114.365773] ovl_copy_xattr: vfs_listxattr() returned 17 > > [ 114.365774] ovl_copy_xattr: buf allocated good > > [ 114.365776] ovl_copy_xattr: vfs_listxattr() returned 17 > > [ 114.365778] ovl_copy_xattr: slen=17 > > [ 114.365780] ovl_copy_xattr: name='security.selinux' > > [ 114.365784] ovl_copy_xattr: vfs_getxattr returned size=-61 > > [ 114.365785] ovl_copy_xattr: cleaning up > > [ 114.365787] ovl_copy_up_inode: ovl_copy_xattr error=-61 > > [ 114.365789] ovl_copy_up_one: error=-61 > > [ 114.365790] ovl_copy_up_one: calling ovl_copy_up_end() > > [ 114.365792] ovl_copy_up_flags: ovl_copy_up_one error=-61 > > > *snip* > > So, the selinux stuff made me raise an eyebrow... I've got selinux > enabled in my kernel so that it's there if I boot up a RHEL box with > this kernel. But I'm using Ubuntu right now, and the rest of SELinux > is not installed/enabled. There shouldn't be any selinux labels in > the files I slurped up into my squashfs image, so there shouldn't be > any in the squashfs, so of course that won't work. > > I tried compiling CONFIG_SELINUX=n and guess what, it works now. So > that's at least a work-around for me. > > So, for whatever reason, between 5.8 and 5.9, having CONFIG_SELINUX=y > but no security labels on the filesystem became a problem? Is this > something that needs to get fixed in overlayfs? Or do you think it's > a deeper problem that needs fixing elsewhere? > It's both :) Attached two patches that should each fix the issue independently, but we need to apply both. I only tested that they build. Please verify that each applied individually solves the problem. The selinux- patch fixes an selinux regression introduced in kernel v5.9 the regression is manifested in your test case but goes beyond overlayfs. The ovl- patch is a workaround for the selinux regression, but it is also a micro optimization that doesn't hurt, so worth applying it anyway. Thanks, Amir.