Maybe this issue is similar to https://bugzilla.samba.org/show_bug.cgi?id=14685 A standalone Samba 4.16 Fileserver running in an unprivileged LXC container publishing shares on a bind mounted ZFS filesystem is occasionally logging the following error into /usr/local/samba/var/log.smbd: ../../source3/smbd/fd_handle.c:118(fsp_get_io_fd) fsp_get_io_fd: fsp [directory/file] is a path referencing fsp The stack trace for this error is: ../../lib/util/fault.c:245(log_stack_trace) BACKTRACE: #0 log_stack_trace + 0x37 [ip=0x7fd422d0575b] [sp=0x7ffd7b1da470] #1 fsp_get_io_fd + 0x9b [ip=0x7fd422fa65fd] [sp=0x7ffd7b1dad80] #2 vfs_default_durable_cookie + 0x13e [ip=0x7fd4230c2e49] [sp=0x7ffd7b1dada0] #3 vfswrap_durable_cookie + 0x2f [ip=0x7fd422fb4c1c] [sp=0x7ffd7b1daee0] #4 smb_vfs_call_durable_cookie + 0x5e [ip=0x7fd42304f04a] [sp=0x7ffd7b1daf10] #5 smbd_smb2_create_after_exec + 0x303 [ip=0x7fd423097931] [sp=0x7ffd7b1daf40] #6 smbd_smb2_create_send + 0x154c [ip=0x7fd423096348] [sp=0x7ffd7b1db030] #7 smbd_smb2_request_process_create + 0x76b [ip=0x7fd423093b1f] [sp=0x7ffd7b1db340] #8 smbd_smb2_request_dispatch + 0x157c [ip=0x7fd423085f30] [sp=0x7ffd7b1db450] #9 smbd_smb2_io_handler + 0x876 [ip=0x7fd42308ae6b] [sp=0x7ffd7b1db540] #10 smbd_smb2_connection_handler + 0x4a [ip=0x7fd42308af9a] [sp=0x7ffd7b1db5f0] #11 tevent_common_invoke_fd_handler + 0x121 [ip=0x7fd422d8f39e] [sp=0x7ffd7b1db630] #12 epoll_event_loop + 0x3a5 [ip=0x7fd422d9a503] [sp=0x7ffd7b1db670] #13 epoll_event_loop_once + 0x138 [ip=0x7fd422d9abe6] [sp=0x7ffd7b1db6d0] #14 std_event_loop_once + 0x5c [ip=0x7fd422d97357] [sp=0x7ffd7b1db720] #15 _tevent_loop_once + 0x122 [ip=0x7fd422d8e163] [sp=0x7ffd7b1db760] #16 tevent_common_loop_wait + 0x25 [ip=0x7fd422d8e4c1] [sp=0x7ffd7b1db7a0] #17 std_event_loop_wait + 0x5c [ip=0x7fd422d973f9] [sp=0x7ffd7b1db7d0] #18 _tevent_loop_wait + 0x2b [ip=0x7fd422d8e564] [sp=0x7ffd7b1db810] #19 smbd_process + 0xca7 [ip=0x7fd42306a139] [sp=0x7ffd7b1db830] #20 smbd_accept_connection + 0x3cd [ip=0x564fa8dbf0d0] [sp=0x7ffd7b1db8f0] #21 tevent_common_invoke_fd_handler + 0x121 [ip=0x7fd422d8f39e] [sp=0x7ffd7b1db9d0] #22 epoll_event_loop + 0x3a5 [ip=0x7fd422d9a503] [sp=0x7ffd7b1dba10] #23 epoll_event_loop_once + 0x138 [ip=0x7fd422d9abe6] [sp=0x7ffd7b1dba70] #24 std_event_loop_once + 0x5c [ip=0x7fd422d97357] [sp=0x7ffd7b1dbac0] #25 _tevent_loop_once + 0x122 [ip=0x7fd422d8e163] [sp=0x7ffd7b1dbb00] #26 tevent_common_loop_wait + 0x25 [ip=0x7fd422d8e4c1] [sp=0x7ffd7b1dbb40] #27 std_event_loop_wait + 0x5c [ip=0x7fd422d973f9] [sp=0x7ffd7b1dbb70] #28 _tevent_loop_wait + 0x2b [ip=0x7fd422d8e564] [sp=0x7ffd7b1dbbb0] #29 smbd_parent_loop + 0xa5 [ip=0x564fa8dbfdf7] [sp=0x7ffd7b1dbbd0] #30 main + 0x1841 [ip=0x564fa8dc1ef2] [sp=0x7ffd7b1dbc10] #31 __libc_start_main + 0xea [ip=0x7fd422960d0a] [sp=0x7ffd7b1dbf50] #32 _start + 0x2a [ip=0x564fa8dbbdea] [sp=0x7ffd7b1dc020] It looks like the error does not cause a real problem apart from cluttering the log.
Hmmm. That's a strange one. That can only happen if we're returning a durable handle from SMB2 create: if (!state->replay_operation && state->durable_requested && (fsp_lease_type(state->result) & SMB2_LEASE_HANDLE)) { status = SMB_VFS_DURABLE_COOKIE( state->result, state->op, &state->op->global->backend_cookie); if (!NT_STATUS_IS_OK(status)) { state->op->global->backend_cookie = data_blob_null; } } but the fsp->fd_handle->fd value is an fd open with O_PATH. I have a theory... Can you add a debug here please ? $ git diff diff --git a/source3/smbd/smb2_create.c b/source3/smbd/smb2_create.c index 932ec31a18a..5bc82955cf8 100644 --- a/source3/smbd/smb2_create.c +++ b/source3/smbd/smb2_create.c @@ -1425,6 +1425,13 @@ static void smbd_smb2_create_after_exec(struct tevent_req *req) if (!state->replay_operation && state->durable_requested && (fsp_lease_type(state->result) & SMB2_LEASE_HANDLE)) { + if (state->result->fsp_flags.is_pathref) { + DBG_ERR("Durable handle requested for file %s is a " + "pathref with access mask 0x%x\n", + fsp_str_dbg(state->result), + (unsigned int)state->result->access_mask); + } + status = SMB_VFS_DURABLE_COOKIE( state->result, state->op, That should tell me if my theory is correct.
...and at least for my part it's becoming even stranger. ;-) I hope you can make a meaning out of the following. This is the condensed output from the debug you asked me to add: [2022/04/12 11:17:43.268061, 0] ../../source3/smbd/smb2_create.c:1429(smbd_smb2_create_after_exec) smbd_smb2_create_after_exec: Durable handle requested for file directory1/file1 is a pathref with access mask 0x20080 [2022/04/12 11:17:43.310955, 0] ../../source3/smbd/smb2_create.c:1429(smbd_smb2_create_after_exec) smbd_smb2_create_after_exec: Durable handle requested for file directory1/file1 is a pathref with access mask 0x40080 [2022/04/12 11:17:43.349613, 0] ../../source3/smbd/smb2_create.c:1429(smbd_smb2_create_after_exec) smbd_smb2_create_after_exec: Durable handle requested for file directory1/file1 is a pathref with access mask 0x80080 [2022/04/12 11:17:52.380129, 0] ../../source3/smbd/smb2_create.c:1429(smbd_smb2_create_after_exec) smbd_smb2_create_after_exec: Durable handle requested for file directory1/file2 is a pathref with access mask 0x20080 [2022/04/12 11:17:52.419201, 0] ../../source3/smbd/smb2_create.c:1429(smbd_smb2_create_after_exec) smbd_smb2_create_after_exec: Durable handle requested for file directory1/file2 is a pathref with access mask 0x40080 [2022/04/12 11:17:52.457680, 0] ../../source3/smbd/smb2_create.c:1429(smbd_smb2_create_after_exec) smbd_smb2_create_after_exec: Durable handle requested for file directory1/file2 is a pathref with access mask 0x80080 [2022/04/12 11:18:00.586439, 0] ../../source3/smbd/smb2_create.c:1429(smbd_smb2_create_after_exec) smbd_smb2_create_after_exec: Durable handle requested for file directory2/file3 is a pathref with access mask 0x20080 [2022/04/12 11:18:00.625651, 0] ../../source3/smbd/smb2_create.c:1429(smbd_smb2_create_after_exec) smbd_smb2_create_after_exec: Durable handle requested for file directory2/file3 is a pathref with access mask 0x40080 [2022/04/12 11:18:00.665000, 0] ../../source3/smbd/smb2_create.c:1429(smbd_smb2_create_after_exec) smbd_smb2_create_after_exec: Durable handle requested for file directory2/file3 is a pathref with access mask 0x80080 [2022/04/12 11:18:07.272664, 0] ../../source3/smbd/smb2_create.c:1429(smbd_smb2_create_after_exec) smbd_smb2_create_after_exec: Durable handle requested for file directory2/file3 is a pathref with access mask 0x120080 [2022/04/12 11:18:18.459834, 0] ../../source3/smbd/smb2_create.c:1429(smbd_smb2_create_after_exec) smbd_smb2_create_after_exec: Durable handle requested for file directory3/file4 is a pathref with access mask 0x20080 [2022/04/12 11:18:18.498324, 0] ../../source3/smbd/smb2_create.c:1429(smbd_smb2_create_after_exec) smbd_smb2_create_after_exec: Durable handle requested for file directory3/file4 is a pathref with access mask 0x40080 [2022/04/12 11:18:18.537080, 0] ../../source3/smbd/smb2_create.c:1429(smbd_smb2_create_after_exec) smbd_smb2_create_after_exec: Durable handle requested for file directory3/file4 is a pathref with access mask 0x80080 [2022/04/12 11:18:24.620426, 0] ../../source3/smbd/smb2_create.c:1429(smbd_smb2_create_after_exec) smbd_smb2_create_after_exec: Durable handle requested for file directory3/file5 is a pathref with access mask 0x20080 [2022/04/12 11:18:24.659101, 0] ../../source3/smbd/smb2_create.c:1429(smbd_smb2_create_after_exec) smbd_smb2_create_after_exec: Durable handle requested for file directory3/file5 is a pathref with access mask 0x40080 [2022/04/12 11:18:24.697678, 0] ../../source3/smbd/smb2_create.c:1429(smbd_smb2_create_after_exec) smbd_smb2_create_after_exec: Durable handle requested for file directory3/file5 is a pathref with access mask 0x80080 For readability I have seperated the output from different files by a few blank lines.
No, it makes sense now and is pretty much what I expected to see. The client is asking for a durable handle on what we used to call a "stat" read. i.e. it wants access to file meta-data: FILE_READ_ATTRIBUTE = 0x00000080; READ_CONTROL = 0x00020000 WRITE_DAC = 0x00040000 WRITE_OWNER = 0x00080000 but *doesn't* want read or write access. On Linux, or systems with O_PATH, we leave the open file descriptor on the file as a pathref fd i.e. an fd opened with O_PATH. There is code in vfs_default_durable_cookie() to refuse a durable handle open on such an fd, but it's calling the wrong function. It's calling: 78 if (fsp_get_io_fd(fsp) == -1) { 79 return NT_STATUS_NOT_SUPPORTED; 80 } which when compiled with #define EVELOPER will cause fsp_get_io_fd() to panic (by design) or emit a debug level 0 message without DEVELOPER. But this isn't a fatal error here, so we should be using: if (fsp->fsp_flags.is_pathref) { return NT_STATUS_NOT_SUPPORTED; } instead. Interestingly enough, there's nothing I can see that we do on disconnect/reconnect that requires read or write access to the file, so a fix for another day might be to correctly support pathref durable handles. But for now, here is the fix: -------------------------------------------------- diff --git a/source3/smbd/durable.c b/source3/smbd/durable.c index a49bca6fd61..04eacc232e0 100644 --- a/source3/smbd/durable.c +++ b/source3/smbd/durable.c @@ -75,7 +75,7 @@ NTSTATUS vfs_default_durable_cookie(struct files_struct *fsp, return NT_STATUS_NOT_SUPPORTED; } - if (fsp_get_io_fd(fsp) == -1) { + if (fsp->fsp_flags.is_pathref) { return NT_STATUS_NOT_SUPPORTED; } -------------------------------------------------- If you can confirm it makes the message go away (it will :-) then I'll submit an MR and get this fixed upstream.
I can confirm that the error message is gone. That was a quick fix. Thank you very much!
MR: https://gitlab.com/samba-team/samba/-/merge_requests/2492
This bug was referenced in samba master: bb329d4de505d2c01ba45a06311c9dc6d87f8dec fe7daae8c4692b99ff08d4e3e48034d59ddee245
Created attachment 17280 [details] git-am fix for 4.16.next, 4.15.next. Back-port. Applies cleanly to 4.16.next, 4.15.next.
Ping Ralph... Can we get this in ? :-).
Reassigning to Jule for inclusion in 4.15 and 4.16.
Pushed to autobuild-v4-{16,15}-test.
This bug was referenced in samba v4-15-test: a236b193c42225a448e3c9c5f289c2812fecb2e9 e75837c115bc288758baa51001c66102d2fba61c
This bug was referenced in samba v4-16-test: c7e2b4c3e90ca90be265ea6ee518e980ea6a4364 25b7144283f7871ffba3c3adccbaa7313c4753ca
Closing out bug report. Thanks!
This bug was referenced in samba v4-16-stable (Release samba-4.16.2): c7e2b4c3e90ca90be265ea6ee518e980ea6a4364 25b7144283f7871ffba3c3adccbaa7313c4753ca
This bug was referenced in samba v4-15-stable (Release samba-4.15.8): a236b193c42225a448e3c9c5f289c2812fecb2e9 e75837c115bc288758baa51001c66102d2fba61c