Bug 15527 - fd_handle_destructor() panics within an smbd_smb2_close() if vfs_stat_fsp() fails in fd_close()
Summary: fd_handle_destructor() panics within an smbd_smb2_close() if vfs_stat_fsp() f...
Status: RESOLVED FIXED
Alias: None
Product: Samba 4.1 and newer
Classification: Unclassified
Component: File services (show other bugs)
Version: 4.17.12
Hardware: All All
: P5 normal (vote)
Target Milestone: ---
Assignee: Jule Anger
QA Contact: Samba QA Contact
URL:
Keywords:
: 15587 (view as bug list)
Depends on:
Blocks:
 
Reported: 2023-12-06 19:31 UTC by Chris Pacejo
Modified: 2024-04-08 07:34 UTC (History)
2 users (show)

See Also:


Attachments
patch for v418,v419,v420 (5.29 KB, patch)
2024-03-14 08:46 UTC, Noel Power
npower: review? (jra)
slow: review+
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Chris Pacejo 2023-12-06 19:31:34 UTC
We’ve come across a crash in 4.17+ which is similar to that reported in bug 15487, except that the issue occurs with a file, not a stream.
 
In our case, the crash occurred when vfs_stat_fsp()/SMB_VFS_FSTAT() failed with STATUS_ACCESS_DENIED.  (The file in question is an Office lock (“~$”) file; I’m not sure what shenanigans Office plays here to have effected this situation.)  This is with a custom VFS so it’s possible we’ve violated some assumption that an fstat() on an open file should always succeed, but I see that (to take one example) vfs_ceph allows the possibility of an error return from fstat().

I would propose that the fix would be to ignore vfs_stat_fsp() errors during a close (as I believe was the pre-4.17 behavior), but seeing as the committed fix for bug 15487 (commit 633a3ee) does this explicitly only when the object is a stream (and not a file) gives me pause.
Comment 1 Jeremy Allison 2023-12-06 20:09:51 UTC
Can you upload a backtrace here ? I'm not saying this *can't* happen, as it obviously does for you :-).

The fix for https://bugzilla.samba.org/show_bug.cgi?id=15487 only considered the stream case as that was the test case we had, and it really didn't seem likely that fstat would fail for a valid fd open on a file.

It would be great to be able to find a reproducer for this.
Comment 2 Chris Pacejo 2023-12-14 18:07:12 UTC
Thanks for the quick reply!  Sorry for the delay on my end.  Backtrace here:

#0  0x00007f517b016ca0 in raise () from /lib64/libc.so.6
#1  0x00007f517b018148 in abort () from /lib64/libc.so.6
#2  0x00007f517e397a4b in dump_core () at ../../source3/lib/dumpcore.c:338
#3  0x00007f517e3a5a1c in smb_panic_s3 (why=<optimized out>) at ../../source3/lib/util.c:713
#4  0x00007f517bedc81a in smb_panic (why=why@entry=0x7f517ed9f4a8 "assert failed: (fh->fd == -1) || (fh->fd == AT_FDCWD)") at ../../lib/util/fault.c:198
#5  0x00007f517ecb893b in fd_handle_destructor (fh=fh@entry=0x558bd9a1b730) at ../../source3/smbd/fd_handle.c:39
#6  0x00007f517e5e1598 in _tc_free_internal (location=0x7f517eda5460 "../../source3/smbd/files.c:1706", tc=<optimized out>) at ../../lib/talloc/talloc.c:1158
#7  _talloc_free_internal (location=0x7f517eda5460 "../../source3/smbd/files.c:1706", ptr=0x558bd9a1b730) at ../../lib/talloc/talloc.c:1248
#8  _talloc_free (ptr=0x558bd9a1b730, location=0x7f517eda5460 "../../source3/smbd/files.c:1706") at ../../lib/talloc/talloc.c:1792
#9  0x00007f517ecc585e in fsp_free (fsp=0x558bd9aa7e50) at ../../source3/smbd/files.c:1706
#10 file_free (req=req@entry=0x558bd9a888c0, fsp=fsp@entry=0x558bd9aa7e50) at ../../source3/smbd/files.c:1799
#11 0x00007f517ed2e72c in smbd_smb2_close (out_file_attributes=0x558bd9a88768, out_end_of_file=0x558bd9a88760, out_allocation_size=0x558bd9a88758, out_change_ts=0x558bd9a88748, out_last_write_ts=0x558bd9a88738, 
    out_last_access_ts=0x558bd9a88728, out_creation_ts=0x558bd9a88718, out_flags=0x558bd9a88712, in_flags=<optimized out>, _fsp=0x558bd9a88708, req=0x558bd9a88150) at ../../source3/smbd/smb2_close.c:228
#12 smbd_smb2_close_send (in_flags=<optimized out>, in_fsp=<optimized out>, smb2req=0x558bd9a88150, ev=<optimized out>, mem_ctx=0x558bd9a88150) at ../../source3/smbd/smb2_close.c:337
#13 smbd_smb2_request_process_close (req=req@entry=0x558bd9a88150) at ../../source3/smbd/smb2_close.c:72
#14 0x00007f517ed22363 in smbd_smb2_request_dispatch (req=req@entry=0x558bd9a88150) at ../../source3/smbd/smb2_server.c:3411
#15 0x00007f517ed23380 in smbd_smb2_io_handler (fde_flags=<optimized out>, xconn=0x558bd9a2a150) at ../../source3/smbd/smb2_server.c:5014
#16 smbd_smb2_connection_handler (ev=<optimized out>, fde=<optimized out>, flags=<optimized out>, private_data=<optimized out>) at ../../source3/smbd/smb2_server.c:5052
#17 0x00007f517d6ce2d3 in tevent_common_invoke_fd_handler (fde=fde@entry=0x558bd9a16980, flags=<optimized out>, removed=removed@entry=0x0) at ../../lib/tevent/tevent_fd.c:142
#18 0x00007f517d6d513a in epoll_event_loop (tvalp=0x7ffd3f181be0, epoll_ev=0x558bd9a45c50) at ../../lib/tevent/tevent_epoll.c:737
#19 epoll_event_loop_once (ev=<optimized out>, location=<optimized out>) at ../../lib/tevent/tevent_epoll.c:938
#20 0x00007f517d6d32c7 in std_event_loop_once (ev=0x558bd9a02a80, location=0x7f517edc3460 "../../source3/smbd/smb2_process.c:2012") at ../../lib/tevent/tevent_standard.c:110
#21 0x00007f517d6cd6fb in _tevent_loop_once (ev=ev@entry=0x558bd9a02a80, location=location@entry=0x7f517edc3460 "../../source3/smbd/smb2_process.c:2012") at ../../lib/tevent/tevent.c:825
#22 0x00007f517d6cd967 in tevent_common_loop_wait (ev=0x558bd9a02a80, location=0x7f517edc3460 "../../source3/smbd/smb2_process.c:2012") at ../../lib/tevent/tevent.c:948
#23 0x00007f517d6d3267 in std_event_loop_wait (ev=0x558bd9a02a80, location=0x7f517edc3460 "../../source3/smbd/smb2_process.c:2012") at ../../lib/tevent/tevent_standard.c:141
#24 0x00007f517ed10bae in smbd_process (ev_ctx=0x558bd9a02a80, msg_ctx=<optimized out>, sock_fd=34, interactive=<optimized out>) at ../../source3/smbd/smb2_process.c:2012
#25 0x0000558bd8dfc751 in smbd_accept_connection (ev=0x558bd9a02a80, fde=<optimized out>, flags=<optimized out>, private_data=<optimized out>) at ../../source3/smbd/server.c:1037
#26 0x00007f517d6ce2d3 in tevent_common_invoke_fd_handler (fde=fde@entry=0x558bd9a47100, flags=<optimized out>, removed=removed@entry=0x0) at ../../lib/tevent/tevent_fd.c:142
#27 0x00007f517d6d513a in epoll_event_loop (tvalp=0x7ffd3f181e60, epoll_ev=0x558bd9a117f0) at ../../lib/tevent/tevent_epoll.c:737
#28 epoll_event_loop_once (ev=<optimized out>, location=<optimized out>) at ../../lib/tevent/tevent_epoll.c:938
#29 0x00007f517d6d32c7 in std_event_loop_once (ev=0x558bd9a02a80, location=0x558bd8dff4c8 "../../source3/smbd/server.c:1381") at ../../lib/tevent/tevent_standard.c:110
#30 0x00007f517d6cd6fb in _tevent_loop_once (ev=ev@entry=0x558bd9a02a80, location=location@entry=0x558bd8dff4c8 "../../source3/smbd/server.c:1381") at ../../lib/tevent/tevent.c:825
#31 0x00007f517d6cd967 in tevent_common_loop_wait (ev=0x558bd9a02a80, location=0x558bd8dff4c8 "../../source3/smbd/server.c:1381") at ../../lib/tevent/tevent.c:948
#32 0x00007f517d6d3267 in std_event_loop_wait (ev=0x558bd9a02a80, location=0x558bd8dff4c8 "../../source3/smbd/server.c:1381") at ../../lib/tevent/tevent_standard.c:141
#33 0x0000558bd8df9c3f in smbd_parent_loop (parent=0x558bd9a0f590, ev_ctx=0x558bd9a02a80) at ../../source3/smbd/server.c:1381
#34 main (argc=<optimized out>, argv=<optimized out>) at ../../source3/smbd/server.c:2125


The contents of `fsp` and `fsp->fh` from frame 9 (fsp_free):

#9  0x00007f517ecc585e in fsp_free (fsp=0x558bd9aa7e50) at ../../source3/smbd/files.c:1706
1706            } else {
(gdb) l
1701
1702            TALLOC_FREE(fsp->fake_file_handle);
1703
1704            if (fh_get_refcount(fsp->fh) == 1) {
1705                    TALLOC_FREE(fsp->fh);
1706            } else {
1707                    size_t new_refcount = fh_get_refcount(fsp->fh) - 1;
1708                    fh_set_refcount(fsp->fh, new_refcount);
1709            }
1710

(gdb) print *fsp
$1 = {next = 0x0, prev = 0x0, fnum = 1316639649, op = 0x0, conn = 0x558bd9a4fdc0, fh = 0x558bd9a1b730, num_smb_operations = 0, file_id = {devid = 47, inode = 10013, extid = 0}, initial_allocation_size = 0, file_pid = 65279, 
  vuid = 3817400223, open_time = {tv_sec = 1700248134, tv_usec = 478656}, access_mask = 1245599, fsp_flags = {is_pathref = false, is_fsa = true, have_proc_fds = false, kernel_share_modes_taken = false, 
    update_write_time_triggered = true, update_write_time_on_close = false, write_time_forced = false, can_lock = true, can_read = true, can_write = true, modified = true, is_directory = false, is_dirfsp = false, 
    aio_write_behind = false, initial_delete_on_close = true, delete_on_close = false, is_sparse = false, backup_intent = false, use_ofd_locks = true, closing = true, lock_failure_seen = false, encryption_required = false, 
    fstat_before_close = true}, update_write_time_event = 0x0, close_write_time = {tv_sec = 0, tv_nsec = 1073741822}, close_change_time = {tv_sec = 0, tv_nsec = 1073741822}, write_time_forced = false, oplock_type = 0, 
  leases_db_seqnum = 0, lease_type = 0, lease = 0x0, sent_oplock_break = 0, oplock_timeout = 0x0, current_lock_count = 0, posix_flags = 0, fsp_name = 0x558bd9aa4420, name_hash = 870736911, mid = 790, vfs_extension = 0x0, 
  fake_file_handle = 0x0, notify = 0x0, base_fsp = 0x0, stream_fsp = 0x0, share_mode_flags_seqnum = 4176, share_mode_flags = 120, brlock_seqnum = 0, brlock_rec = 0x0, dptr = 0x0, print_file = 0x0, num_aio_requests = 0, 
  aio_requests = 0x0, blocked_smb1_lock_reqs = 0x0, lock_failure_offset = 0}

(gdb) print *fsp->fh
$2 = {ref_count = 1, fd = 512, position_information = 0, pos = 0, private_options = 0, gen_id = 351}


`status` in frame 11 (smbd_smb2_close) I had to track down with some register spelunking as it had dropped out of debug scope:

#11 0x00007f517ed2e72c in smbd_smb2_close (out_file_attributes=0x558bd9a88768, out_end_of_file=0x558bd9a88760, out_allocation_size=0x558bd9a88758, out_change_ts=0x558bd9a88748, out_last_write_ts=0x558bd9a88738, 
    out_last_access_ts=0x558bd9a88728, out_creation_ts=0x558bd9a88718, out_flags=0x558bd9a88712, in_flags=<optimized out>, _fsp=0x558bd9a88708, req=0x558bd9a88150) at ../../source3/smbd/smb2_close.c:228
warning: Source file is more recent than executable.
228                     file_free(smbreq, fsp);
(gdb) l
223
224             status = close_file_smb(smbreq, fsp, NORMAL_CLOSE);
225             if (!NT_STATUS_IS_OK(status)) {
226                     DEBUG(5,("smbd_smb2_close: close_file[%s]: %s\n",
227                              smb_fname_str_dbg(smb_fname), nt_errstr(status)));
228                     file_free(smbreq, fsp);
229                     *_fsp = fsp = NULL;
230                     return status;
231             }
232


here, `status` is 0xC0000022 (found from assembly spelunking: it's in %r10d before the active call):

   0x00007f517ed2e566 <+854>:   callq  0x7f517eca2290 <close_file_smb@plt>
   0x00007f517ed2e56b <+859>:   test   %eax,%eax
   0x00007f517ed2e56d <+861>:   mov    %eax,%r10d
   0x00007f517ed2e570 <+864>:   jne    0x7f517ed2e703 <smbd_smb2_request_process_close+1267>
[...]
   0x00007f517ed2e703 <+1267>:  mov    $0x1c,%edi
   0x00007f517ed2e708 <+1272>:  mov    %r10d,0x10(%rsp)
   0x00007f517ed2e70d <+1277>:  callq  0x7f517eca46c0 <debuglevel_get_class@plt>
   0x00007f517ed2e712 <+1282>:  cmp    $0x4,%eax
   0x00007f517ed2e715 <+1285>:  mov    0x10(%rsp),%r10d
   0x00007f517ed2e71a <+1290>:  jg     0x7f517ed2e741 <smbd_smb2_request_process_close+1329>
   0x00007f517ed2e71c <+1292>:  mov    %r14,%rsi
   0x00007f517ed2e71f <+1295>:  mov    %r13,%rdi
   0x00007f517ed2e722 <+1298>:  mov    %r10d,0x10(%rsp)
   0x00007f517ed2e727 <+1303>:  callq  0x7f517eca23b0 <file_free@plt>
=> 0x00007f517ed2e72c <+1308>:  mov    0x10(%rsp),%r10d
(gdb) x/xw $rsp+0x10
0x7ffd3f181a00: 0xc0000022

(which is STATUS_ACCESS_DENIED)
Comment 3 Ralph Böhme 2024-02-05 14:08:49 UTC
fstat() should not fail with EACCESS, please fix your filesystem. :) Ignoring the failure from fstat would change visible network behaviour, possibly returning outdated stat info, so imho we can't just ignore errors from fstat here.
Comment 4 Ralph Böhme 2024-02-05 14:20:53 UTC
Should have gone for a cup of coffee before closing this... I guess what is happening is that your fuse filesystem doesn't propely handle an fstat() on a handle where the last link is gone. The fsp has initial_delete_on_close set, so at that point we've called unlinkat() on the file.

I'm currently looking into handling this gracefully by setting

  fsp->fsp_flags.fstat_before_close = false;

in close_remove_share_mode(). We can do this as in close_remove_share_mode() we already called vfs_stat_fsp(), *before* calling unlinkat(), so it works in your case.

Pipeline: https://gitlab.com/samba-team/devel/samba/-/pipelines/1164871873
Comment 5 Ralph Böhme 2024-02-06 13:21:33 UTC
(In reply to Ralph Böhme from comment #4)
If the issue reproducible on your end? Can you test with the patch from https://gitlab.com/samba-team/samba/-/merge_requests/3509 ?
Comment 6 Chris Pacejo 2024-02-06 15:24:10 UTC
> your fuse filesystem doesn't propely handle an fstat() on a handle where the last link is gone

Ah, thanks for the analysis!  This sounds indeed like the case.  Thanks for the patch, will test with that soon.
Comment 7 Ralph Böhme 2024-02-20 10:36:20 UTC
(In reply to Chris Pacejo from comment #6)
Any update?
Comment 8 Chris Pacejo 2024-02-21 18:27:25 UTC
Sorry, I've been putting out a pair of fires the past two weeks which have taken priority.  Actually one of the issues is similar crash at this line: <https://gitlab.com/samba-team/samba/-/blob/samba-4.17.12/source3/smbd/files.c#L270>, which, per your earlier comments, have convinced me we need to fix our VFS not to allow open files to disappear.  (It's always been that way; it's just never caused issues prior to the new VFS layer.)

I've just about put of the most-urgent fire, so I can get back to the above crash today/tomorrow, and will be able to test the fix for the issue in this ticket as part of that.  Thanks for your patience!
Comment 9 Noel Power 2024-02-23 09:57:35 UTC
*** Bug 15587 has been marked as a duplicate of this bug. ***
Comment 10 Chris Pacejo 2024-02-27 02:09:54 UTC
Thank you for your patience; I did finally get some time today to repro this repeatably and test the above fix (https://gitlab.com/samba-team/samba/-/merge_requests/3509).  Without the fix, the test I'm running causes smbd to crash readily and repeatably.  With the above fix, I did still see it crash once, but by and large the issue is fixed.

The crash I did see looks identical to before:

(gdb) bt
#0  0x00007f8a2c0e6ca0 in raise () at /lib64/libc.so.6
#1  0x00007f8a2c0e8148 in abort () at /lib64/libc.so.6
#2  0x00007f8a2f467a4b in dump_core () at ../../source3/lib/dumpcore.c:338
#3  0x00007f8a2f475a1c in smb_panic_s3 (why=<optimized out>) at ../../source3/lib/util.c:713
#4  0x00007f8a2cfac81a in smb_panic (why=why@entry=0x7f8a2fe6f548 "assert failed: (fh->fd == -1) || (fh->fd == AT_FDCWD)") at ../../lib/util/fault.c:198
#5  0x00007f8a2fd8893b in fd_handle_destructor (fh=fh@entry=0x55bdcb70e380) at ../../source3/smbd/fd_handle.c:39
#6  0x00007f8a2f6b1598 in _tc_free_internal (location=0x7f8a2fe75500 "../../source3/smbd/files.c:1712", tc=<optimized out>) at ../../lib/talloc/talloc.c:1158
#7  0x00007f8a2f6b1598 in _talloc_free_internal (location=0x7f8a2fe75500 "../../source3/smbd/files.c:1712", ptr=0x55bdcb70e380) at ../../lib/talloc/talloc.c:1248
#8  0x00007f8a2f6b1598 in _talloc_free (ptr=0x55bdcb70e380, location=0x7f8a2fe75500 "../../source3/smbd/files.c:1712") at ../../lib/talloc/talloc.c:1792
#9  0x00007f8a2fd9585e in fsp_free (fsp=0x55bdcb72bc90) at ../../source3/smbd/files.c:1712
#10 0x00007f8a2fd9585e in file_free (req=req@entry=0x55bdcb6fdf00, fsp=fsp@entry=0x55bdcb72bc90)
    at ../../source3/smbd/files.c:1805
#11 0x00007f8a2fdfe7ac in smbd_smb2_close (out_file_attributes=0x55bdcb6fdda8, out_end_of_file=0x55bdcb6fdda0, out_allocation_size=0x55bdcb6fdd98, out_change_ts=0x55bdcb6fdd88, out_last_write_ts=0x55bdcb6fdd78, out_last_access_ts=0x55bdcb6fdd68, out_creation_ts=0x55bdcb6fdd58, out_flags=0x55bdcb6fdd52, in_flags=<optimized out>, _fsp=0x55bdcb6fdd48, req=0x55bdcb6fd7c0) at ../../source3/smbd/smb2_close.c:228
#12 0x00007f8a2fdfe7ac in smbd_smb2_close_send (in_flags=<optimized out>, in_fsp=<optimized out>, smb2req=0x55bdcb6fd7c0, ev=<optimized out>, mem_ctx=0x55bdcb6fd7c0) at ../../source3/smbd/smb2_close.c:337
#13 0x00007f8a2fdfe7ac in smbd_smb2_request_process_close (req=req@entry=0x55bdcb6fd7c0)
    at ../../source3/smbd/smb2_close.c:72
#14 0x00007f8a2fdf23e3 in smbd_smb2_request_dispatch (req=req@entry=0x55bdcb6fd7c0)
    at ../../source3/smbd/smb2_server.c:3411
#15 0x00007f8a2fdf3400 in smbd_smb2_io_handler (fde_flags=<optimized out>, xconn=0x55bdcb6fd1b0)
    at ../../source3/smbd/smb2_server.c:5014
#16 0x00007f8a2fdf3400 in smbd_smb2_connection_handler (ev=<optimized out>, fde=<optimized out>, flags=<optimized out>, private_data=<optimized out>) at ../../source3/smbd/smb2_server.c:5052
#17 0x00007f8a2e79e2d3 in tevent_common_invoke_fd_handler (fde=fde@entry=0x55bdcb6e92e0, flags=<optimized out>, removed=removed@entry=0x0) at ../../lib/tevent/tevent_fd.c:142
#18 0x00007f8a2e7a513a in epoll_event_loop (tvalp=0x7fff8f9efb50, epoll_ev=0x55bdcb6e84a0)
    at ../../lib/tevent/tevent_epoll.c:737
#19 0x00007f8a2e7a513a in epoll_event_loop_once (ev=<optimized out>, location=<optimized out>)
    at ../../lib/tevent/tevent_epoll.c:938
#20 0x00007f8a2e7a32c7 in std_event_loop_once (ev=0x55bdcb6d79b0, location=0x7f8a2fe93500 "../../source3/smbd/smb2_process.c:2012") at ../../lib/tevent/tevent_standard.c:110
#21 0x00007f8a2e79d6fb in _tevent_loop_once (ev=ev@entry=0x55bdcb6d79b0, location=location@entry=0x7f8a2fe93500 "../../source3/smbd/smb2_process.c:2012") at ../../lib/tevent/tevent.c:825
#22 0x00007f8a2e79d967 in tevent_common_loop_wait (ev=0x55bdcb6d79b0, location=0x7f8a2fe93500 "../../source3/smbd/smb2_process.c:2012") at ../../lib/tevent/tevent.c:948
#23 0x00007f8a2e7a3267 in std_event_loop_wait (ev=0x55bdcb6d79b0, location=0x7f8a2fe93500 "../../source3/smbd/smb2_process.c:2012") at ../../lib/tevent/tevent_standard.c:141
#24 0x00007f8a2fde0c2e in smbd_process (ev_ctx=0x55bdcb6d79b0, msg_ctx=<optimized out>, sock_fd=33, interactive=<optimized out>) at ../../source3/smbd/smb2_process.c:2012
#25 0x000055bdc9c03751 in smbd_accept_connection (ev=0x55bdcb6d79b0, fde=<optimized out>, flags=<optimized out>, private_data=<optimized out>) at ../../source3/smbd/server.c:1037
#26 0x00007f8a2e79e2d3 in tevent_common_invoke_fd_handler (fde=fde@entry=0x55bdcb6fbeb0, flags=<optimized out>, removed=removed@entry=0x0) at ../../lib/tevent/tevent_fd.c:142
#27 0x00007f8a2e7a513a in epoll_event_loop (tvalp=0x7fff8f9efdd0, epoll_ev=0x55bdcb6e6880)
    at ../../lib/tevent/tevent_epoll.c:737
#28 0x00007f8a2e7a513a in epoll_event_loop_once (ev=<optimized out>, location=<optimized out>)
    at ../../lib/tevent/tevent_epoll.c:938
#29 0x00007f8a2e7a32c7 in std_event_loop_once (ev=0x55bdcb6d79b0, location=0x55bdc9c064c8 "../../source3/smbd/server.c:1381") at ../../lib/tevent/tevent_standard.c:110
#30 0x00007f8a2e79d6fb in _tevent_loop_once (ev=ev@entry=0x55bdcb6d79b0, location=location@entry=0x55bdc9c064c8 "../../source3/smbd/server.c:1381") at ../../lib/tevent/tevent.c:825
#31 0x00007f8a2e79d967 in tevent_common_loop_wait (ev=0x55bdcb6d79b0, location=0x55bdc9c064c8 "../../source3/smbd/server.c:1381") at ../../lib/tevent/tevent.c:948
#32 0x00007f8a2e7a3267 in std_event_loop_wait (ev=0x55bdcb6d79b0, location=0x55bdc9c064c8 "../../source3/smbd/server.c:1381") at ../../lib/tevent/tevent_standard.c:141
#33 0x000055bdc9c00c3f in smbd_parent_loop (parent=0x55bdcb6e4590, ev_ctx=0x55bdcb6d79b0)
    at ../../source3/smbd/server.c:1381
#34 0x000055bdc9c00c3f in main (argc=<optimized out>, argv=<optimized out>) at ../../source3/smbd/server.c:2125
(gdb) f 9
#9  0x00007f8a2fd9585e in fsp_free (fsp=0x55bdcb72bc90) at ../../source3/smbd/files.c:1712
1712	../../source3/smbd/files.c: No such file or directory.
(gdb) print *fsp
$1 = {next = 0x0, prev = 0x0, fnum = 543128900, op = 0x0, conn = 0x55bdcb6d77d0, fh = 0x55bdcb70e380, 
  num_smb_operations = 0, file_id = {devid = 1, inode = 150031, extid = 0}, initial_allocation_size = 0, 
  file_pid = 13896, vuid = 3281370877, open_time = {tv_sec = 1708983797, tv_usec = 142471}, access_mask = 1180054, 
  fsp_flags = {is_pathref = false, is_fsa = true, have_proc_fds = false, kernel_share_modes_taken = false, 
    update_write_time_triggered = false, update_write_time_on_close = false, write_time_forced = false, 
    can_lock = true, can_read = false, can_write = true, modified = false, is_directory = false, 
    is_dirfsp = false, aio_write_behind = false, initial_delete_on_close = false, delete_on_close = false, 
    is_sparse = false, backup_intent = false, use_ofd_locks = true, closing = true, lock_failure_seen = false, 
    encryption_required = false, fstat_before_close = true}, update_write_time_event = 0x0, close_write_time = {
    tv_sec = 0, tv_nsec = 1073741822}, close_change_time = {tv_sec = 0, tv_nsec = 1073741822}, 
  write_time_forced = false, oplock_type = 0, leases_db_seqnum = 0, lease_type = 0, lease = 0x0, 
  sent_oplock_break = 0, oplock_timeout = 0x0, current_lock_count = 0, posix_flags = 0, fsp_name = 0x55bdcb732ef0, 
  name_hash = 1889288956, mid = 789, vfs_extension = 0x0, fake_file_handle = 0x0, notify = 0x0, base_fsp = 0x0, 
  stream_fsp = 0x0, share_mode_flags_seqnum = 0, share_mode_flags = 0, brlock_seqnum = 0, brlock_rec = 0x0, 
  dptr = 0x0, print_file = 0x0, num_aio_requests = 0, aio_requests = 0x0, blocked_smb1_lock_reqs = 0x0, 
  lock_failure_offset = 0}

Strangely `fstat_before_close` is set on this fsp; not sure how/why it did not get cleared in this case.

Finally, testing with the additional patch just posted here by Noel (https://gitlab.com/samba-team/samba/-/merge_requests/3526) seems to completely eliminate the issue.

Please let me know if I can give any further help; for our purposes this pair of patches seems to address the issue.
Comment 11 Samba QA Contact 2024-03-13 10:35:04 UTC
This bug was referenced in samba master:

6e6324cff29089a636823786183222a73fe7cb28
6ee3f809a54d7b833ff798e68a93ada00a215d4d
Comment 12 Noel Power 2024-03-14 08:46:26 UTC
Created attachment 18266 [details]
patch for v418,v419,v420

This copy of the patch applies currently without issues to v4-18-test, v4-19-test & v4-20-test
Comment 13 Ralph Böhme 2024-03-27 12:59:17 UTC
Reassigning to Jule for inclusion in 4.18, 4.19 and 4.20.
Comment 14 Jule Anger 2024-03-27 14:25:09 UTC
Pushed to autobuild-v4-{20,19}-test.
There will be no further 4.18 stable release.
Comment 15 Samba QA Contact 2024-03-27 15:42:03 UTC
This bug was referenced in samba v4-20-test:

72f7086825778ac434afdcab7251fecb5751ea44
aee05f11670df006e50c225bbd7bce597482e856
Comment 16 Samba QA Contact 2024-03-27 15:54:04 UTC
This bug was referenced in samba v4-19-test:

3634df5d59e9f47345932a00098aead7efe55009
0ac741b5705b7e0801a7ec5355d0f9be21e024c6
Comment 17 Jule Anger 2024-03-27 15:58:01 UTC
Closing out bug report.

Thanks!
Comment 18 Samba QA Contact 2024-03-27 17:13:08 UTC
This bug was referenced in samba v4-20-stable (Release samba-4.20.0):

72f7086825778ac434afdcab7251fecb5751ea44
aee05f11670df006e50c225bbd7bce597482e856
Comment 19 Samba QA Contact 2024-04-08 07:34:04 UTC
This bug was referenced in samba v4-19-stable (Release samba-4.19.6):

3634df5d59e9f47345932a00098aead7efe55009
0ac741b5705b7e0801a7ec5355d0f9be21e024c6