zfs returns enosys when calling fsetxattr

[Thadeu Lima de Souza Cascardo]

When xfstests are run on zfs, they expect acl calls (like fsetxattr) to either work or return ENOTSUP. zfs fails with ENOSYS, at least on arm64.

The result on calling the immutable tests of xfstests are:

acl: Function not implemented

[Colin Ian King (colin-king)]

@Thadeu, I'm having issues trying to reproduce this, which specific test is being run?

[Thadeu Lima de Souza Cascardo (cascardo)]

Hi, Colin.

The results are here:

http://10.246.72.4/test-results/4.15.0-12.13-generic/ms10-34-mcdivittB0-kernel__4.15.0-12.13__2018-03-08_22-50-00/ubuntu_zfs_xfs_generic/results/ubuntu_zfs_xfs_generic.079/debug/ubuntu_zfs_xfs_generic.079.DEBUG.html

It should be the t_immutable test or something like that, when I looked at the code.

Cascardo.

[Colin Ian King (colin-king)]

Thanks, I'll ask Sam for access to that H/W tomorrow.

[Colin Ian King (colin-king)]

Issue exists with 4.15 + today's upstream zfs v0.7.0-378_ga76f3d043

[Colin Ian King (colin-king)]

Does not occur with x86 ZFS on 4.15.

[Colin Ian King (colin-king)]

This also fails on ARM64 + ZFS 0.6.5.11-1ubuntu3.1 + 4.13.0-37-generic

[Colin Ian King (colin-king)]

And also ARM64 + 4.4.0-116-generic. I wonder why this used to pass.

[Colin Ian King (colin-king)]

arm64:

statfs("/mnt/scratch/079", {f_type=ZFS_SUPER_MAGIC, f_bsize=131072, f_blocks=15097, f_bfree=15097, f_bavail=15097, f_files=3864945, f_ffree=3864939, f_fsid={val=[2326582274, 8984039]}, f_namelen=255, f_frsize=131072, f_flags=ST_VALID|ST_RELATIME}) = 0
openat(AT_FDCWD, "/mnt/scratch/079/immutable.f", O_RDWR) = -1 EACCES (Permission denied)
openat(AT_FDCWD, "/mnt/scratch/079/immutable.f", O_WRONLY) = -1 EACCES (Permission denied)
openat(AT_FDCWD, "/mnt/scratch/079/immutable.f", O_RDWR|O_TRUNC) = -1 EACCES (Permission denied)
openat(AT_FDCWD, "/mnt/scratch/079/immutable.f", O_WRONLY|O_TRUNC) = -1 EACCES (Permission denied)
openat(AT_FDCWD, "/mnt/scratch/079/immutable.f", O_RDWR|O_APPEND) = -1 EACCES (Permission denied)
openat(AT_FDCWD, "/mnt/scratch/079/immutable.f", O_WRONLY|O_APPEND) = -1 EACCES (Permission denied)
openat(AT_FDCWD, "/mnt/scratch/079/immutable.f", O_RDWR|O_TRUNC|O_APPEND) = -1 EACCES (Permission denied)
openat(AT_FDCWD, "/mnt/scratch/079/immutable.f", O_WRONLY|O_TRUNC|O_APPEND) = -1 EACCES (Permission denied)
truncate("/mnt/scratch/079/immutable.f", 0) = -1 EACCES (Permission denied)
utimensat(AT_FDCWD, "/mnt/scratch/079/immutable.f", [{tv_sec=0, tv_nsec=0}, {tv_sec=0, tv_nsec=0}], 0) = -1 EPERM (Operation not permitted)
utimensat(AT_FDCWD, "/mnt/scratch/079/immutable.f", NULL, 0) = -1 EPERM (Operation not permitted)

x86:
statfs("/mnt/scratch/079", {f_type=ZFS_SUPER_MAGIC, f_bsize=131072, f_blocks=15102, f_bfree=15102, f_bavail=15102, f_files=3866273, f_ffree=3866267, f_fsid={val=[4130572324, 1396799]}, f_namelen=255, f_frsize=131072, f_flags=ST_VALID|ST_RELATIME}) = 0
openat(AT_FDCWD, "/mnt/scratch/079/immutable.f", O_RDWR) = -1 EPERM (Operation not permitted)
openat(AT_FDCWD, "/mnt/scratch/079/immutable.f", O_WRONLY) = -1 EPERM (Operation not permitted)
openat(AT_FDCWD, "/mnt/scratch/079/immutable.f", O_RDWR|O_TRUNC) = -1 EPERM (Operation not permitted)
openat(AT_FDCWD, "/mnt/scratch/079/immutable.f", O_WRONLY|O_TRUNC) = -1 EPERM (Operation not permitted)
openat(AT_FDCWD, "/mnt/scratch/079/immutable.f", O_RDWR|O_APPEND) = -1 EPERM (Operation not permitted)
openat(AT_FDCWD, "/mnt/scratch/079/immutable.f", O_WRONLY|O_APPEND) = -1 EPERM (Operation not permitted)
openat(AT_FDCWD, "/mnt/scratch/079/immutable.f", O_RDWR|O_TRUNC|O_APPEND) = -1 EPERM (Operation not permitted)
openat(AT_FDCWD, "/mnt/scratch/079/immutable.f", O_WRONLY|O_TRUNC|O_APPEND) = -1 EPERM (Operation not permitted)
truncate("/mnt/scratch/079/immutable.f", 0) = -1 EPERM (Operation not permitted)
utime("/mnt/scratch/079/immutable.f", {actime=0, modtime=0}) = -1 EPERM (Operation not permitted)
utime("/mnt/scratch/079/immutable.f", NULL) = -1 EPERM (Operation not permitted)

[Colin Ian King (colin-king)]

Looking at the termination of t_immutable test program:

ARM:
mprotect(0xffff86092000, 4096, PROT_READ) = 0
mprotect(0xffff860b3000, 4096, PROT_READ) = 0
munmap(0xffff86295000, 38279) = 0
openat(AT_FDCWD, "/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
lseek(4, 0, SEEK_CUR) = 0
fstat(4, {st_mode=S_IFREG|0644, st_size=1682, ...}) = 0
mmap(NULL, 1682, PROT_READ, MAP_SHARED, 4, 0) = 0xffff8629e000
lseek(4, 1682, SEEK_SET) = 1682
munmap(0xffff8629e000, 1682) = 0
close(4) = 0
dup(2) = 4
fcntl(4, F_GETFL) = 0x20002 (flags O_RDWR|0x20000)
fstat(4, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0
write(4, "acl: Function not implemented\n", 30acl: Function not implemented
) = 30
close(4) = 0
exit_group(1) = ?
+++ exited with 1 +++

x86 at same place:
mprotect(0x7f677e46f000, 4096, PROT_READ) = 0
mprotect(0x7f677e67d000, 4096, PROT_READ) = 0
munmap(0x7f677f097000, 165753) = 0
openat(AT_FDCWD, "/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
lseek(4, 0, SEEK_CUR) = 0
fstat(4, {st_mode=S_IFREG|0644, st_size=3023, ...}) = 0
mmap(NULL, 3023, PROT_READ, MAP_SHARED, 4, 0) = 0x7f677f0bf000
lseek(4, 3023, SEEK_SET) = 3023
munmap(0x7f677f0bf000, 3023) = 0
close(4) = 0
fsetxattr(3, "system.posix_acl_access", "\2\0\0\0\1\0\6\0\377\377\377\377\2\0\6\0\376\377\0\0\4\0\6\0\377\377\377\377\20\0\6", 44, 0) = -1 EOPNOTSUPP (Operation not supported)
fsetxattr(3, "trusted.test", "readonly", 8, XATTR_CREATE) = 0
fsetxattr(3, "user.test", "readonly", 8, XATTR_CREATE) = 0
..etc

So it's something different in the test program in the acl handling side

[Colin Ian King (colin-king)]

#0 __GI___libc_write (fd=4, buf=0xaaaaaaacbc40, nbytes=30) at ../sysdeps/unix/sysv/linux/write.c:25
#1 0x0000ffffb7ebf878 in _IO_new_file_write (f=0xaaaaaaac9850, data=0xaaaaaaacbc40, n=30) at fileops.c:1255
#2 0x0000ffffb7ebec28 in new_do_write (fp=0xaaaaaaac9850, data=0xaaaaaaacbc40 "acl: Function not implemented\n", to_do=to_do@entry=30) at fileops.c:510
#3 0x0000ffffb7ec0994 in _IO_new_do_write (fp=<optimized out>, data=<optimized out>, to_do=30) at fileops.c:486
#4 0x0000ffffb7ebff6c in _IO_new_file_xsputn (f=0xaaaaaaac9850, data=<optimized out>, n=1) at fileops.c:1323
#5 0x0000ffffb7e97064 in _IO_vfprintf_internal (s=0xaaaaaaac9850, format=0xffffb7f76008 "%s%s%s\n", ap=...) at vfprintf.c:1674
#6 0x0000ffffb7eb2180 in locked_vfxprintf (fp=fp@entry=0xaaaaaaac9850, fmt=<optimized out>, ap=...) at fxprintf.c:30
#7 0x0000ffffb7eb22e0 in __fxprintf (fp=fp@entry=0xaaaaaaac9850, fmt=fmt@entry=0xffffb7f76008 "%s%s%s\n") at fxprintf.c:74
#8 0x0000ffffb7eaf588 in perror_internal (fp=fp@entry=0xaaaaaaac9850, s=s@entry=0xaaaaaaab64d0 "acl", errnum=errnum@entry=38) at perror.c:39
#9 0x0000ffffb7eaf65c in __GI_perror (s=0xaaaaaaab64d0 "acl") at perror.c:74
#10 0x0000aaaaaaab256c in create_test_area (dir=0xfffffffff886 "foo") at t_immutable.c:2008
#11 0x0000aaaaaaaaba88 in main (argc=3, argv=0xfffffffff638) at t_immutable.c:2277

[Colin Ian King (colin-king)]

debugged further into fadd_acl, this calls acl_set_fd libacl/acl_set_fd.c:47, and this calls:

fsetxattr (filedes=filedes@entry=3, name=name@entry=0xaaaaaaab6958 "system.posix_acl_access", value=value@entry=0xaaaaaaacbc00, size=<optimized out>, flags=flags@entry=0)

..which returns -1 and errno = 38 (ENOSYS 38 Function not implemented)

this also occurs on a non-ZFS file system (e.g. ext4).

[Colin Ian King (colin-king)]

Looks like the wrapper in xfstests-bld/attr/libattr/syscalls.c returns the dreaded ENOSYS becuase XATTR_SYSCALLS is not defined. Silent and deadly.

#if HAVE_XATTR_SYSCALLS
# define SYSCALL(args...) syscall(args)
#else
# define SYSCALL(args...) ( errno = ENOSYS, -1 )
#endif

[Colin Ian King (colin-king)]

..and HAVE_XATTR_SYSCALLS is not defined because it does not have arch specific #defines for arm64. I'll add them in tomorrow and fix this up.

[Colin Ian King (colin-king)]

Attached is a fix to the tests, hopefully will be added to the autotest-client-tests repo ASAP.

[Colin Ian King (colin-king)]

Fix committed: http://kernel.ubuntu.com/git/ubuntu/autotest-client-tests.git/commit/?id=f727a4da264ee4d4ee9e848180df30f7a081f578

[Colin Ian King (colin-king)]

@Thadeu, do you mind re-testing this as the fix has now landed in autotests

[Po-Hsu Lin (cypressyew)]

Possible duplicate: arm64 system failed with test 079 in zfs_xfs_generic
bug 1732370

[Colin Ian King (colin-king)]

Yes, 1732370 is a duplicate, marked it as so.

[Colin Ian King (colin-king)]

OK, tests now pass, marking as fixed released.

http://10.246.72.4/test-results/4.15.0-13.14~16.04.1-generic/starmie-kernel__4.15.0-13.14~16.04.1__2018-03-21_08-32-00/ubuntu_zfs_xfs_generic/results/ubuntu_zfs_xfs_generic.079/debug/ubuntu_zfs_xfs_generic.079.DEBUG.html