I have already filed a different bug 9776 for mkdir. Now i have this core dump in same env when i copy a MS file from one folder to another My env is samba 4.0.4 running on a netgear 6 with debian wheezy OS. I have currently replaced the stock smbd that comes with netgear (that was also core dumping) with a debug version i built on my debian wheezy The client is a Windows 7 My smb.conf and other files are added to 9776 Can somebody please tell me what this 'invalid lock order means' Program terminated with signal 6, Aborted. #0 0x00007fcdcac89475 in raise () from /lib/x86_64-linux-gnu/libc.so.6 (gdb) bt #0 0x00007fcdcac89475 in raise () from /lib/x86_64-linux-gnu/libc.so.6 #1 0x00007fcdcac8c6f0 in abort () from /lib/x86_64-linux-gnu/libc.so.6 #2 0x00007fcdcd734002 in dump_core () at lib/dumpcore.c:336 #3 0x00007fcdcd741cd9 in smb_panic_s3 (why=0x7fcdcdd81e98 "invalid lock_order") at lib/util.c:833 #4 0x00007fcdcd731d3f in smb_panic (why=0x7fcdcdd81e98 "invalid lock_order") at ../lib/util/fault.c:159 #5 0x00007fcdcd726901 in dbwrap_check_lock_order (db=0x7fcdce196e70, mem_ctx=0x7fcdce1bc510) at ../lib/dbwrap/dbwrap.c:195 #6 0x00007fcdcd726a3d in dbwrap_fetch_locked_internal (db=0x7fcdce196e70, mem_ctx=0x7fcdce1fe8f0, key=..., db_fn=0x7fcdcd727a08 <db_tdb_fetch_locked>) at ../lib/dbwrap/dbwrap.c:225 #7 0x00007fcdcd726b37 in dbwrap_fetch_locked (db=0x7fcdce196e70, mem_ctx=0x7fcdce1fe8f0, key=...) at ../lib/dbwrap/dbwrap.c:245 #8 0x00007fcdcd3bfef3 in smbXsrv_open_global_allocate (db=0x7fcdce196e70, mem_ctx=0x7fcdce1fe8f0, _global=0x7fffa8b42788) at smbd/smbXsrv_open.c:507 #9 0x00007fcdcd3c0d12 in smbXsrv_open_create (conn=0x7fcdce196620, session_info=0x7fcdce1b2040, now=130105121568955660, _open=0x7fffa8b42828) at smbd/smbXsrv_open.c:811 #10 0x00007fcdcd2d0d1a in file_new (req=0x0, conn=0x7fcdce1aa5e0, result=0x7fffa8b42908) at smbd/files.c:100 #11 0x00007fcdcd348ee6 in create_file_unixpath (conn=0x7fcdce1aa5e0, req=0x0, smb_fname=0x7fcdce1e6b30, access_mask=2, share_access=7, create_disposition=1, create_options=0, file_attributes=0, oplock_request=8, allocation_size=0, private_flags=0, sd=0x0, ea_list=0x0, result=0x7fffa8b429e8, pinfo=0x7fffa8b429f0) at smbd/open.c:3793 #12 0x00007fcdcd349aa4 in create_file_default (conn=0x7fcdce1aa5e0, req=0x0, root_dir_fid=0, smb_fname=0x7fcdce1e6b30, access_mask=2, share_access=7, create_disposition=1, create_options=0, file_attributes=0, oplock_request=8, allocation_size=0, private_flags=0, sd=0x0, ea_list=0x0, result=0x7fffa8b42bd8, pinfo=0x0) at smbd/open.c:4213 #13 0x00007fcdcd3c91d0 in vfswrap_create_file (handle=0x7fcdce1a8fa0, req=0x0, root_dir_fid=0, smb_fname=0x7fcdce1e6b30, access_mask=2, share_access=7, create_disposition=1, create_options=0, file_attributes=0, oplock_request=8, allocation_size=0, private_flags=0, sd=0x0, ea_list=0x0, result=0x7fffa8b42bd8, pinfo=0x0) at modules/vfs_default.c:511 #14 0x00007fcdcd3550c0 in smb_vfs_call_create_file (handle=0x7fcdce1a8fa0, req=0x0, root_dir_fid=0, smb_fname=0x7fcdce1e6b30, access_mask=2, share_access=7, create_disposition=1, create_options=0, file_attributes=0, oplock_request=8, allocation_size=0, private_flags=0, sd=0x0, ea_list=0x0, result=0x7fffa8b42bd8, pinfo=0x0) at smbd/vfs.c:1529 #15 0x00007fcdcd34673f in open_file_fchmod (conn=0x7fcdce1aa5e0, smb_fname=0x7fcdce1e6b30, result=0x7fffa8b42bd8) at smbd/open.c:2778 #16 0x00007fcdcd33b813 in set_ea_dos_attribute (conn=0x7fcdce1aa5e0, smb_fname=0x7fcdce1e6b30, dosmode=32) at smbd/dosmode.c:428 #17 0x00007fcdcd33c429 in file_set_dosmode (conn=0x7fcdce1aa5e0, smb_fname=0x7fcdce1e6b30, dosmode=32, parent_dir=0x7fcdce1ba5f0 "Shared/TEST/New folder", newfile=true) at smbd/dosmode.c:767 #18 0x00007fcdcd3463ca in open_file_ntcreate (conn=0x7fcdce1aa5e0, req=0x7fcdce1f5730, access_mask=1442207, share_access=0, create_disposition=2, create_options=68, new_dos_attributes=0, oplock_request=2, private_flags=0, pinfo=0x7fffa8b430dc, fsp=0x7fcdce1de8f0) at smbd/open.c:2691 #19 0x00007fcdcd348fae in create_file_unixpath (conn=0x7fcdce1aa5e0, req=0x7fcdce1f5730, smb_fname=0x7fcdce1f58d0, access_mask=1442207, share_access=0, create_disposition=2, create_options=68, file_attributes=128, oplock_request=2, allocation_size=12698, private_flags=0, sd=0x0, ea_list=0x0, result=0x7fffa8b431a8, pinfo=0x7fffa8b431b0) at smbd/open.c:3817 #20 0x00007fcdcd349aa4 in create_file_default (conn=0x7fcdce1aa5e0, req=0x7fcdce1f5730, root_dir_fid=0, smb_fname=0x7fcdce1f58d0, access_mask=1442207, share_access=0, create_disposition=2, create_options=68, file_attributes=128, oplock_request=2, allocation_size=12698, private_flags=0, sd=0x0, ea_list=0x0, result=0x7fffa8b434c8, pinfo=0x7fffa8b434c4) at smbd/open.c:4213 #21 0x00007fcdcd3c91d0 in vfswrap_create_file (handle=0x7fcdce1a8fa0, req=0x7fcdce1f5730, root_dir_fid=0, smb_fname=0x7fcdce1f58d0, access_mask=1442207, share_access=0, create_disposition=2, create_options=68, file_attributes=128, oplock_request=2, allocation_size=12698, private_flags=0, sd=0x0, ea_list=0x0, result=0x7fffa8b434c8, pinfo=0x7fffa8b434c4) at modules/vfs_default.c:511 #22 0x00007fcdcd3550c0 in smb_vfs_call_create_file (handle=0x7fcdce1a8fa0, req=0x7fcdce1f5730, root_dir_fid=0, smb_fname=0x7fcdce1f58d0, access_mask=1442207, share_access=0, create_disposition=2, create_options=68, file_attributes=128, oplock_request=2, allocation_size=12698, private_flags=0, sd=0x0, ea_list=0x0, result=0x7fffa8b434c8, pinfo=0x7fffa8b434c4) at smbd/vfs.c:1529 #23 0x00007fcdcd399b45 in smbd_smb2_create_send (mem_ctx=0x7fcdce1f41c0, ev=0x7fcdce184330, smb2req=0x7fcdce1f41c0, in_oplock_level=9 '\t', in_impersonation_level=2, ---Type <return> to continue, or q <return> to quit--- in_desired_access=1442207, in_file_attributes=128, in_share_access=0, in_create_disposition=2, in_create_options=68, in_name=0x7fcdce1f4c50 "Shared\\TEST\\New folder\\New Microsoft Word Document - Copy.docx", in_context_blobs=...) at smbd/smb2_create.c:878 #24 0x00007fcdcd3972e0 in smbd_smb2_request_process_create (smb2req=0x7fcdce1f41c0) at smbd/smb2_create.c:231 #25 0x00007fcdcd38f075 in smbd_smb2_request_dispatch (req=0x7fcdce1f41c0) at smbd/smb2_server.c:2146 #26 0x00007fcdcd391d73 in smbd_smb2_request_incoming (subreq=0x0) at smbd/smb2_server.c:3143 #27 0x00007fcdcd7596b3 in _tevent_req_notify_callback (req=0x7fcdce1b6460, location=0x7fcdcdc0812d "smbd/smb2_server.c:2996") at ../lib/tevent/tevent_req.c:101 #28 0x00007fcdcd7596e5 in tevent_req_finish (req=0x7fcdce1b6460, state=TEVENT_REQ_DONE, location=0x7fcdcdc0812d "smbd/smb2_server.c:2996") at ../lib/tevent/tevent_req.c:110 #29 0x00007fcdcd75970c in _tevent_req_done (req=0x7fcdce1b6460, location=0x7fcdcdc0812d "smbd/smb2_server.c:2996") at ../lib/tevent/tevent_req.c:116 #30 0x00007fcdcd3917b4 in smbd_smb2_request_read_done (subreq=0x0) at smbd/smb2_server.c:2996 #31 0x00007fcdcd7596b3 in _tevent_req_notify_callback (req=0x7fcdce1f42d0, location=0x7fcdcdd7cfe0 "../lib/tsocket/tsocket_helpers.c:430") at ../lib/tevent/tevent_req.c:101 #32 0x00007fcdcd7596e5 in tevent_req_finish (req=0x7fcdce1f42d0, state=TEVENT_REQ_DONE, location=0x7fcdcdd7cfe0 "../lib/tsocket/tsocket_helpers.c:430") at ../lib/tevent/tevent_req.c:110 #33 0x00007fcdcd75970c in _tevent_req_done (req=0x7fcdce1f42d0, location=0x7fcdcdd7cfe0 "../lib/tsocket/tsocket_helpers.c:430") at ../lib/tevent/tevent_req.c:116 #34 0x00007fcdcd7149eb in tstream_readv_pdu_queue_done (subreq=0x7fcdce1f4540) at ../lib/tsocket/tsocket_helpers.c:430 #35 0x00007fcdcd7596b3 in _tevent_req_notify_callback (req=0x7fcdce1f4540, location=0x7fcdcdd7cd10 "../lib/tsocket/tsocket_helpers.c:245") at ../lib/tevent/tevent_req.c:101 #36 0x00007fcdcd7596e5 in tevent_req_finish (req=0x7fcdce1f4540, state=TEVENT_REQ_DONE, location=0x7fcdcdd7cd10 "../lib/tsocket/tsocket_helpers.c:245") at ../lib/tevent/tevent_req.c:110 #37 0x00007fcdcd75970c in _tevent_req_done (req=0x7fcdce1f4540, location=0x7fcdcdd7cd10 "../lib/tsocket/tsocket_helpers.c:245") at ../lib/tevent/tevent_req.c:116 #38 0x00007fcdcd7144d5 in tstream_readv_pdu_ask_for_next_vector (req=0x7fcdce1f4540) at ../lib/tsocket/tsocket_helpers.c:245 #39 0x00007fcdcd714700 in tstream_readv_pdu_readv_done (subreq=0x7fcdce1f4a70) at ../lib/tsocket/tsocket_helpers.c:319 #40 0x00007fcdcd7596b3 in _tevent_req_notify_callback (req=0x7fcdce1f4a70, location=0x7fcdcdd7c803 "../lib/tsocket/tsocket.c:604") at ../lib/tevent/tevent_req.c:101 #41 0x00007fcdcd7596e5 in tevent_req_finish (req=0x7fcdce1f4a70, state=TEVENT_REQ_DONE, location=0x7fcdcdd7c803 "../lib/tsocket/tsocket.c:604") at ../lib/tevent/tevent_req.c:110 #42 0x00007fcdcd75970c in _tevent_req_done (req=0x7fcdce1f4a70, location=0x7fcdcdd7c803 "../lib/tsocket/tsocket.c:604") at ../lib/tevent/tevent_req.c:116 #43 0x00007fcdcd713a33 in tstream_readv_done (subreq=0x0) at ../lib/tsocket/tsocket.c:604 #44 0x00007fcdcd7596b3 in _tevent_req_notify_callback (req=0x7fcdce1f4c40, location=0x7fcdcdd7de58 "../lib/tsocket/tsocket_bsd.c:1769") at ../lib/tevent/tevent_req.c:101 #45 0x00007fcdcd7596e5 in tevent_req_finish (req=0x7fcdce1f4c40, state=TEVENT_REQ_DONE, location=0x7fcdcdd7de58 "../lib/tsocket/tsocket_bsd.c:1769") at ../lib/tevent/tevent_req.c:110 #46 0x00007fcdcd759803 in tevent_req_trigger (ev=0x7fcdce184330, im=0x7fcdce1f4d00, private_data=0x7fcdce1f4c40) at ../lib/tevent/tevent_req.c:166 #47 0x00007fcdcd758254 in tevent_common_loop_immediate (ev=0x7fcdce184330) at ../lib/tevent/tevent_immediate.c:135 #48 0x00007fcdcd7547c1 in run_events_poll (ev=0x7fcdce184330, pollrtn=0, pfds=0x0, num_pfds=0) at lib/events.c:193 #49 0x00007fcdcd755051 in s3_event_loop_once (ev=0x7fcdce184330, location=0x7fcdcdbfe29c "smbd/process.c:3620") at lib/events.c:326 #50 0x00007fcdcd756821 in _tevent_loop_once (ev=0x7fcdce184330, location=0x7fcdcdbfe29c "smbd/process.c:3620") at ../lib/tevent/tevent.c:507 #51 0x00007fcdcd3700aa in smbd_process (ev_ctx=0x7fcdce184330, msg_ctx=0x7fcdce1831e0, sock_fd=35, interactive=false) at smbd/process.c:3620 #52 0x00007fcdcdbb8475 in smbd_accept_connection (ev=0x7fcdce184330, fde=0x7fcdce199a70, flags=1, private_data=0x7fcdce1999f0) at smbd/server.c:620 #53 0x00007fcdcd754e96 in run_events_poll (ev=0x7fcdce184330, pollrtn=1, pfds=0x7fcdce19bcf0, num_pfds=5) at lib/events.c:281 #54 0x00007fcdcd75512c in s3_event_loop_once (ev=0x7fcdce184330, location=0x7fcdcde6e608 "smbd/server.c:945") at lib/events.c:344 #55 0x00007fcdcd756821 in _tevent_loop_once (ev=0x7fcdce184330, location=0x7fcdcde6e608 "smbd/server.c:945") at ../lib/tevent/tevent.c:507 #56 0x00007fcdcdbb9007 in smbd_parent_loop (ev_ctx=0x7fcdce184330, parent=0x7fcdce186650) at smbd/server.c:945 #57 0x00007fcdcdbba6c4 in main (argc=1, argv=0x7fffa8b44838) at smbd/server.c:1563 (gdb)
Want to add that it seems to happen with any file copy not only MS work I copy a file from one folder to another.
Reproducer: [global] workgroup = SAMBA [tmp] path = /data/git read only = no create mask = 000 dos filemode = yes store dos attributes = yes You have to make sure that setfattr on the new file fails
I do not know if we mean the same I was able to get this to work my overriding getxattr/setxattr in my vfs module and calling SMB_VFS_NEXT_GETXATTR/SMB_VFS_NEXT_SETXATTR respectively in those 2 overrides and this fixed the issue.
Yes, we do mean the same thing. This panic triggers if for some reason the setxattr on a newly created file fails. This is what I triggered with the "create mask = 000". If your VFS module fails this call for another reason, this will also happen. The problem is probably not really simple to solve: We need a version of file_set_dosmode that takes an fsp instead of a name.
Thanks for the info
Ok Volker can you expand on exactly what the issue is ? You have obviously triaged this one, so it'll save me a lot of time if you just explain exactly what the trigger for this one is. Jeremy.
Oh never mind, I think I get it now :-). Jeremy.
Actually a VFS_SMB_LSETXATTR() would also do, but we don't have that either :-(. Jeremy.
Created attachment 8788 [details] (untested) patch for 4.0.x and master Actually, I think this patch will do the trick. open_file_fchmod() uses the flag INTERNAL_OPEN_ONLY, which passes in struct smb_request *req explicitly as NULL, as we should have no presence in the open file table as we're a transient open (all the oplock break and share mode code explicitly checks for INTERNAL_OPEN_ONLY and doesn't check for conflicts). So simply avoiding allocating the global state inside file_new() (like we do further down by not allocating fsp->mid or fsp->chain_fsp when req == NULL) should get around this problem. Can you test this and see if it fixes the problem ? Jeremy.
Ok, reproduced and tested here and it does indeed fix it. Jeremy.
Created attachment 8789 [details] git-am fix for master and 4.0.next. Fixes the problem in my tests. Volker please review. Cheers, Jeremy.
Created attachment 8796 [details] Updated git-am fix for master and 4.0.next Contains Volker's change to create_file_unixpath() to propagate down the req pointer. Jeremy.
Comment on attachment 8796 [details] Updated git-am fix for master and 4.0.next This patch looks good for this use case. But I fear we need a bit more. https://bugzilla.samba.org/show_bug.cgi?id=9776 looks like a similar bug, and we don't always pass INTERNAL_OPEN_ONLY or req=NULL for internal opens. I think we should have a flag on the request that says 'we need a file handle for the client'. I think the number of calls which need this is not high less than 10. And we'll notice if we don't return a file handle to the client. I guess this is easier than marking all internal opens.
(In reply to comment #13) > Comment on attachment 8796 [details] > Updated git-am fix for master and 4.0.next > > This patch looks good for this use case. But I fear we need a bit more. > > https://bugzilla.samba.org/show_bug.cgi?id=9776 Sorry, for the confusion this was the wrong bug... There was a bug Volker told me about a few days ago, regarding a lock order problem in rename_internals_fsp() or rename_internals(), but I don't remember the full details anymore:-( But the SMB_VFS_CREATE_FILE() within rename_internals(), seems to allocate a file handle without a needs, correct? If my memory is totally confused, just ignore me and apply the current patch, it's for sure better that what we have now... > looks like a similar bug, > and we don't always pass INTERNAL_OPEN_ONLY or req=NULL for internal opens. > > I think we should have a flag on the request that says 'we need a file handle > for the client'. > I think the number of calls which need this is not high less than 10. > And we'll notice if we don't return a file handle to the client. > > I guess this is easier than marking all internal opens.
INTERNAL_OPEN_ONLY is an old hack that is *very* narrowly used. It's used in the file_set_dosmode() in this fallback case (which ultimately needs fixing to do a fsp_set_dosmode, just not now :-), the old (unused) copy_file DOS SMB, in the printer driver update code and in the old "get/set security descriptor" via the Win9x svrsvc RPC call. The semantics are to create an fsp struct that doesn't have any entry in the share mode db, as it's a transient open that only exists for the length of one SMB call. I just checked and every call to SMB_VFS_CREATE_FILE() that passes INTERNAL_OPEN_ONLY always passes the req pointer as NULL, so I think this patch is good as is (so long as it passes make test :-). Jeremy.
(In reply to comment #15) > I just checked and every call to SMB_VFS_CREATE_FILE() that passes > INTERNAL_OPEN_ONLY always passes the req pointer as NULL, so I think this patch > is good as is (so long as it passes make test :-). Doesn't pass make test. Now the raw.streams test fails. Volker
Comment on attachment 8796 [details] Updated git-am fix for master and 4.0.next Fails raw.streams now. More work needed.
Thanks for being persistent Volker. I'll take a look ! Cheers, Jeremy.
Wow, this one is fascinating. I think we might be passing the raw.streams test by accident in the unpatched case :-). More when I've investigated this test against Windows. Jeremy.
I have figured out the problem here... but still working on a patch. Give me a little more time :-). Jeremy.
Problem is we get an NT_STATUS ok on opening the base name "base" of "base::stream_name", but then get an NT_STATUS_SHARING_VIOLATION on the open of "base::stream_name". So we defer the open. When we're rescheduled and called again the call to open "base" calls remove_deferred_open_message_smb(req->sconn, req->mid), which removes the timeout record we added from the open of "base::stream_name". So when that is called again we re-schedule ourselves again... :-). This started to happen as Volker's change now correctly propagates the req pointer into the open of the base name. Correct fix (as Windows does) is not to do the 1 second timeout of defer open when opening a stream name. Should have something tomorrow (or Wed by the latest). Jeremy.
Volker, can you remind me what test was failing that required the change to propagate the req struct into the base_fsp open ? I stupidly deleted that email, but I am now thinking that having req = NULL is correct there, as we really need to treat the base_fsp open as INTERNAL_ONLY (which actually was happening by default, as we have: if (req == NULL) { oplock_request |= INTERNAL_OPEN_ONLY; } inside create_file_unixpath(). Thanks, Jeremy.
Ok, gone through this really carefully (again :-) and the simplest fix is to actually add fsp_set_dosmode()/fsp_dos_mode() calls, and use them in the places where we actually have an fsp (which is actually quite a few places). So that's what I'll do :-). Means a longer patchset, but will clean up the code in the long run. Jeremy.
Created attachment 8807 [details] *completely untested* patchset to add the _fsp versions of the dosmode calls. Compiles, but no testing as yet :-). Just wanted to post my work-in-progress. I have to work from home much of tomorrow so will test there. Jeremy.
Created attachment 8817 [details] git-am fix for master and 4.0.next. Ok, here is a mode modest effort that avoids the case where we call open_file_fchmod() from inside create_file_unix(). Fixes the problem in testing here, I'll submit to master also. However, in the longer run I have a patchset that passes make test that adds set_dos_filemode_fsp()/dos_mode_fsp() and correctly uses them throughout the code. I'll submit that separately to master as a code cleanup. The goal is to remove open_file_fchmod() completely, and I think I can get there eventually, but not for a patchset that can go into 4.0.x :-). Jeremy.
Created attachment 8830 [details] git-am fix that went into master, cherry-picked for 4.0.next.
Comment on attachment 8830 [details] git-am fix that went into master, cherry-picked for 4.0.next. Please review for 4.0.next. This fix already went into master. Jeremy.
Comment on attachment 8830 [details] git-am fix that went into master, cherry-picked for 4.0.next. Looks good.
Karolin, can you please add the patch to 4.0. Thanks!
Pushed to autobuild-v4-0-test.
Pushed to v4-0-test. Closing out bug report. Thanks!
This panic can still be triggered if "store dos attributes" is disabled and the path based SMB_VFS_CHMOD() call in file_set_dosmode() fails, causing fsp based fallback via open_file_fchmod(). For now, I'll pick up Jeremy's fsp dosmode patch-set and see where I get. I really need this for the file compression implementation :-).
Created attachment 9207 [details] make test based reproduce
I should revive the work I have that removes open_file_fchmod() completely, maybe for 4.2.0. David please ping me to keep working on it ! Thanks, Jeremy.