Version 4.15.5, btrfs with compression. vfs_btrfs module. OS: Alpine Linux These logs occur every couple of minutes. They only occur on one server but not on another. In what circumstances could this problem occur? I presume the fd in that file would be owned by the UID of the process, so access should work just fine? The errors occur when a client tries to access a file. The file can be read just fine by the client. Ideally those errors would not occur, or if they were benign, not be logged at error level. 2022-02-26T12:34:37.053231+01:00 FS1 daemon daemon.err smbd[21349]: [2022/02/26 12:34:37.053178, 0] ../../source3/modules/vfs_btrfs.c:493(btrfs_fget_compression) 2022-02-26T12:34:37.053321+01:00 FS1 daemon daemon.err smbd[21349]: btrfs_fget_compression: /proc open of /proc/self/fd/48 failed: Permission denied 2022-02-26T12:34:37.053503+01:00 FS1 daemon daemon.err smbd[21349]: [2022/02/26 12:34:37.053482, 0] ../../source3/modules/vfs_btrfs.c:493(btrfs_fget_compression) 2022-02-26T12:34:37.053539+01:00 FS1 daemon daemon.err smbd[21349]: btrfs_fget_compression: /proc open of /proc/self/fd/48 failed: Permission denied 2022-02-26T12:34:37.053773+01:00 FS1 daemon daemon.err smbd[21349]: [2022/02/26 12:34:37.053754, 0] ../../source3/modules/vfs_btrfs.c:493(btrfs_fget_compression) 2022-02-26T12:34:37.053822+01:00 FS1 daemon daemon.err smbd[21349]: btrfs_fget_compression: /proc open of /proc/self/fd/48 failed: Permission denied
Additional information: The problem seems to only occur with compressed file types like zip, tar, and some pdfs. Opening MSI and exe files does not cause such errors to be logged.
This happens when smbd has an O_PATH (pathref) file descriptor open, but does't have rights to open the /proc/self/fd/<filenumber> with O_RDONLY. It's coming from here: fd = open(p, O_RDONLY); if (fd == -1) { DBG_ERR("/proc open of %s failed: %s\n", p, strerror(errno)); return map_nt_error_from_unix(errno); } when we're trying to upgrade an fd opened with fd = open(pathname, O_PATH); and we don't have the permissions to do so. As not being able to return compression status isn't treated as a fatal error in the upper levels, probably the best thing to do is change the DBG_ERR level to DBG_WARNING or DBG_NOTICE. Ralph, do you agree ?
Naturally the FD of a process should be owned by its UID, no? If that is true, then generally that open() should work. So the question is why doesn't it then?
No, opening the /proc/self/fd/<fd-number> depends on the underlying permissions of the file it's opened on. Remember, we have an fd open with O_PATH, which requires no read or write permissions, only rx on the containing directory. So we try and upgrade to O_RDONLY (which allows reading of the contents of the file) and we don't have read permission on the underlying file the fd points to.
And yet reading the file over the CIFS share works. So how does that work if the file is actually not readable by samba?
(In reply to Noel Maximilian Kuntze from comment #5) Don't know :-). You'd have to post a debug level 10 see see exactly what is going on here.
Maybe a kernel bug? Can you update to a newer kernel and try again?
Created attachment 17201 [details] Debug level 10 logs
I got some debug level 10 logs for you there. Please let me know if they suffice, and if you need any other, or more logs. Thank you for your help thus far!
Kernel version is 5.15.12 btw.
The problem persists with kernel version 5.15.26.
@Ralph How do you want to proceed?
(In reply to Noel Maximilian Kuntze from comment #12) When I have time. I'm swamped with other stuff, sorry.
OK, I took a quick look at this and it's coming from: btrfs_fget_compression() 477 if (!fsp->fsp_flags.is_pathref) { 478 ret = ioctl(fsp_fd, FS_IOC_GETFLAGS, &flags); 479 if (ret < 0) { 480 DBG_WARNING("FS_IOC_GETFLAGS failed: %s, fd %lld\n", 481 strerror(errno), (long long)fd); 482 return map_nt_error_from_unix(errno); 483 } 484 if (flags & FS_COMPR_FL) { 485 *_compression_fmt = COMPRESSION_FORMAT_LZNT1; 486 } else { 487 *_compression_fmt = COMPRESSION_FORMAT_NONE; 488 } 489 return NT_STATUS_OK; 490 } 491 492 if (!fsp->fsp_flags.have_proc_fds) { 493 return NT_STATUS_NOT_IMPLEMENTED; 494 } 495 496 p = sys_proc_fd_path(fsp_fd, buf, sizeof(buf)); 497 if (p == NULL) { 498 return NT_STATUS_NO_MEMORY; 499 } 500 501 fd = open(p, O_RDONLY); 502 if (fd == -1) { 503 DBG_ERR("/proc open of %s failed: %s\n", p, strerror(errno)); 504 return map_nt_error_from_unix(errno); 505 } 506 507 ret = ioctl(fd, FS_IOC_GETFLAGS, &flags); The current file is a pathref file descriptor open with O_PATH, and we're now trying to upgrade that into a real file descriptor open with O_RDONLY in order to do the ioctl() call to get the inode flags. ioctl requires a non-pathref fd. What I suggest is changing the DBG_ERR() in line 503 to read: 503 DBG_ERR("%s /proc open of %s failed: %s\n", 504 fsp_str_dbg(fsp), 505 p, strerror(errno)); Note the addition of fsp_str_dbg(fsp). That will give you the relative path from the root of the share of the file that is giving problems. Then take a look at the permissions of this file and see if indeed it should allow a re-open with O_RDONLY.
If finally we could get MR 1832 in, then we could implement get/set compression easily a filesystem independent and this could be removed from special vfs objects like btrfs. I was working on that already but without the statx implementation getting in, this can't move on.
(In reply to Björn Jacke from comment #15) That's a separate issue Björn. Let's figure out the exact btrfs problem here first.
Logs `` [2022/06/13 00:12:40.535181, 0] ../../source3/modules/vfs_btrfs.c:493(btrfs_fget_compression) btrfs_fget_compression: /proc open of p318374 failed: /proc/self/fd/15 [2022/06/13 00:12:40.536026, 0] ../../source3/modules/vfs_btrfs.c:493(btrfs_fget_compression) btrfs_fget_compression: /proc open of p392493 failed: /proc/self/fd/15 [2022/06/13 00:12:40.536875, 0] ../../source3/modules/vfs_btrfs.c:493(btrfs_fget_compression) btrfs_fget_compression: /proc open of p631578 failed: /proc/self/fd/15 [2022/06/13 00:12:40.538171, 0] ../../source3/modules/vfs_btrfs.c:493(btrfs_fget_compression) btrfs_fget_compression: /proc open of p168731 failed: /proc/self/fd/15 The failed "files" are all users and not real files, the problem only occurs on compressed file types like some types of pdfs, tar, zip, ... . Somebody please take another look at this.
(In reply to Noel Maximilian Kuntze from comment #17) The DEBUG statements listed in your log don't seem to match the 4.15.x source code. We have: 486 p = sys_proc_fd_path(fsp_fd, buf, sizeof(buf)); 487 if (p == NULL) { 488 return NT_STATUS_NO_MEMORY; 489 } 490 491 fd = open(p, O_RDONLY); 492 if (fd == -1) { 493 DBG_ERR("/proc open of %s failed: %s\n", p, strerror(errno)); 494 return map_nt_error_from_unix(errno); 495 } sys_proc_fd_path returns: 1179 written = snprintf(buf, 1180 bufsize, 1181 proc_fd_pattern, 1182 fd); where proc_fd_pattern on Linux looks like: "/proc/self/fd/%d" So your error messages should be: btrfs_fget_compression: /proc open of /proc/self/fd/15 failed: <some error string from strerror(errno)>" If you can reproduce at will you need to catch this in a debugger to see what the values of "p" and "errno" are. Alternatively, recompile and add an extra debug statement showing the return from: 486 p = sys_proc_fd_path(fsp_fd, buf, sizeof(buf)); (i.e. print 'p', and ensure that p == buf).
(In reply to Jeremy Allison from comment #18) Thank you, following are the right logs. All the p[[:digit:]]+ stuff (p631578, ...) are user home directory names, so they're not files but directories. 2022-06-13T23:30:13.046459+02:00 FS1 daemon daemon.err smbd[11950]: btrfs_fget_compression: d487346 /proc open of /proc/self/fd/63 failed: Permission denied 2022-06-13T23:30:13.046824+02:00 FS1 daemon daemon.err smbd[11950]: [2022/06/13 23:30:13.046774, 0] ../../source3/modules/vfs_btrfs.c:493(btrfs_fget_compression) 2022-06-13T23:30:13.046988+02:00 FS1 daemon daemon.err smbd[11950]: btrfs_fget_compression: p318374 /proc open of /proc/self/fd/63 failed: Permission denied 2022-06-13T23:30:13.047423+02:00 FS1 daemon daemon.err smbd[11950]: [2022/06/13 23:30:13.047374, 0] ../../source3/modules/vfs_btrfs.c:493(btrfs_fget_compression) 2022-06-13T23:30:13.047551+02:00 FS1 daemon daemon.err smbd[11950]: btrfs_fget_compression: p392493 /proc open of /proc/self/fd/63 failed: Permission denied 2022-06-13T23:30:13.047905+02:00 FS1 daemon daemon.err smbd[11950]: [2022/06/13 23:30:13.047858, 0] ../../source3/modules/vfs_btrfs.c:493(btrfs_fget_compression) 2022-06-13T23:30:13.048030+02:00 FS1 daemon daemon.err smbd[11950]: btrfs_fget_compression: p631578 /proc open of /proc/self/fd/63 failed: Permission denied 2022-06-13T23:30:13.048504+02:00 FS1 daemon daemon.err smbd[11950]: [2022/06/13 23:30:13.048456, 0] ../../source3/modules/vfs_btrfs.c:493(btrfs_fget_compression) 2022-06-13T23:30:13.048633+02:00 FS1 daemon daemon.err smbd[11950]: btrfs_fget_compression: p168731 /proc open of /proc/self/fd/63 failed: Permission denied
(In reply to Noel Maximilian Kuntze from comment #19) So again, the problem seems to be we have rights to open with O_PATH, but not with O_RDONLY. What are the permissions on the files you're trying to access ?
(In reply to Jeremy Allison from comment #20) We ignore the error from SMB_VFS_FGET_COMPRESSION() anyway: if (fsp->conn->fs_capabilities & FILE_FILE_COMPRESSION) { bool compressed = false; status = dos_mode_check_compressed(fsp, &compressed); if (NT_STATUS_IS_OK(status) && compressed) { dosmode |= FILE_ATTRIBUTE_COMPRESSED; } } and in previous versions we just didn't log an error message. So I guess the appropriate fix is to just remove that from the module.
Created attachment 17345 [details] Patch for master
Comment on attachment 17345 [details] Patch for master LGTM. RB+ and pushed.
This bug was referenced in samba master: a6c9c86b2f4c7d74c9b74486bdd16feb42f77cc0