Bug 12815 - smbd core dump after upgrade 4.5.5 to 4.5.9 (on FreeNAS 9.10.2.U3 => 9.10.2.U4)
smbd core dump after upgrade 4.5.5 to 4.5.9 (on FreeNAS 9.10.2.U3 => 9.10.2.U4)
Status: RESOLVED DUPLICATE of bug 12798
Product: Samba 4.1 and newer
Classification: Unclassified
Component: File services
4.5.9
x64 FreeBSD
: P5 major
: ---
Assigned To: Samba QA Contact
Samba QA Contact
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2017-06-01 21:24 UTC by IGP IT
Modified: 2017-06-02 07:07 UTC (History)
1 user (show)

See Also:


Attachments
smbd core dumping (20.95 KB, image/png)
2017-06-01 21:24 UTC, IGP IT
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description IGP IT 2017-06-01 21:24:26 UTC
Created attachment 13245 [details]
smbd core dumping

I see repeated smbd core dumps after upgrading samba 4.5.5 to 4.5.9 (as part of upgrading FreeNAS 9.10.2.U3 => 9.10.2.U4). I had to revert to the very stable old version because the system is in productive use.

To be able to supply relevant debug information please advice which set of debug options i should set and which information i should supply. I can then try to upgrade again and try a reproduction. From the short time i had on the updated system i didnt see helpful information in the logs, yet. Probably because not enough was logged.

The issue occurs only with actual users accessing the system (core dump occurs every few minutes), in contrast, while idling over the weekend after the update smbd ran OK for 2-3 days.

So it is running on ZFS, some folders have ACLs attached for windows usage. There is no AD configured. Thanks.
Comment 1 Ralph Böhme 2017-06-02 06:14:28 UTC
This could be bug #12798 which will be fixed in 4.5.11.
Comment 2 IGP IT 2017-06-02 07:07:07 UTC
yes, it is a duplicate of bug #12798.

i added 

debug hires timestamp = yes
debug pid = yes
debug uid = yes
log level = 4

and could gather the following from the log file

[2017/06/02 08:37:03.625671,  0, pid=14283, effective(1097, 1000), real(0, 0)] ../source3/smbd/oplock.c:178(update_num_read_oplocks)
  PANIC: assert failed at ../source3/smbd/oplock.c(178): lease_type_is_exclusive(e_lease_type)
[2017/06/02 08:37:03.625686,  0, pid=14283, effective(1097, 1000), real(0, 0)] ../source3/lib/util.c:791(smb_panic_s3)
  PANIC (pid 14283): assert failed: lease_type_is_exclusive(e_lease_type)
[2017/06/02 08:37:03.626106,  0, pid=14283, effective(1097, 1000), real(0, 0)] ../source3/lib/util.c:902(log_stack_trace)
  BACKTRACE: 25 stack frames:
   #0 0x80345c948 <smb_panic_s3+152> at /usr/local/lib/libsmbconf.so.0
   #1 0x800a854a5 <smb_panic+53> at /usr/local/lib/libsamba-util.so.0
   #2 0x80102efff <update_num_read_oplocks+303> at /usr/local/lib/samba/libsmbd-base-samba4.so
   #3 0x800f891c0 <create_file_default+47408> at /usr/local/lib/samba/libsmbd-base-samba4.so
   #4 0x800f84468 <create_file_default+27608> at /usr/local/lib/samba/libsmbd-base-samba4.so
   #5 0x800f7ec66 <create_file_default+5078> at /usr/local/lib/samba/libsmbd-base-samba4.so
   #6 0x800f7de65 <create_file_default+1493> at /usr/local/lib/samba/libsmbd-base-samba4.so
   #7 0x8010eb1cc <vfs_default_init+5356> at /usr/local/lib/samba/libsmbd-base-samba4.so
   #8 0x800f9be0c <smb_vfs_call_create_file+556> at /usr/local/lib/samba/libsmbd-base-samba4.so
   #9 0x800ff2f6d <smbd_smb2_request_process_create+13645> at /usr/local/lib/samba/libsmbd-base-samba4.so
   #10 0x800ff025e <smbd_smb2_request_process_create+2110> at /usr/local/lib/samba/libsmbd-base-samba4.so
   #11 0x800fdc14b <smbd_smb2_request_dispatch+5499> at /usr/local/lib/samba/libsmbd-base-samba4.so
   #12 0x800fe4469 <smbd_smb2_process_negprot+16761> at /usr/local/lib/samba/libsmbd-base-samba4.so
   #13 0x800fe3a86 <smbd_smb2_process_negprot+14230> at /usr/local/lib/samba/libsmbd-base-samba4.so
   #14 0x804e6a2d9 <tevent_req_set_cleanup_fn+5705> at /usr/local/lib/libtevent.so.0
   #15 0x804e66ff2 <_tevent_loop_once+114> at /usr/local/lib/libtevent.so.0
   #16 0x804e6a367 <tevent_req_set_cleanup_fn+5847> at /usr/local/lib/libtevent.so.0
   #17 0x800fbad90 <smbd_process+3872> at /usr/local/lib/samba/libsmbd-base-samba4.so
   #18 0x40d80e <main+20910> at /usr/local/sbin/smbd
   #19 0x804e6a2d9 <tevent_req_set_cleanup_fn+5705> at /usr/local/lib/libtevent.so.0
   #20 0x804e66ff2 <_tevent_loop_once+114> at /usr/local/lib/libtevent.so.0
   #21 0x804e6a367 <tevent_req_set_cleanup_fn+5847> at /usr/local/lib/libtevent.so.0
   #22 0x40c21f <main+15295> at /usr/local/sbin/smbd
   #23 0x40a79f <main+8511> at /usr/local/sbin/smbd
   #24 0x406ecf <_start+367> at /usr/local/sbin/smbd
[2017/06/02 08:37:03.626239,  0, pid=14283, effective(1097, 1000), real(0, 0)] ../source3/lib/util.c:803(smb_panic_s3)
  smb_panic(): calling panic action [/usr/local/libexec/samba/samba-backtrace]
mv: rename /var/log/samba4/samba.backtraces to /var/log/samba4/samba.backtraces.20170602083703: Permission denied
ptrace: Operation not permitted.
/mnt/vol1/IGC/13604: No such file or directory.
ptrace: Operation not permitted.
/mnt/vol1/IGC/13608: No such file or directory.
ptrace: Operation not permitted.
/mnt/vol1/IGC/13614: No such file or directory.
[2017/06/02 08:37:04.033625,  0, pid=14283, effective(1097, 1000), real(0, 0)] ../source3/lib/util.c:811(smb_panic_s3)
  smb_panic(): action returned status 0
[2017/06/02 08:37:04.033658,  4, pid=14283, effective(1097, 1000), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx)
  push_sec_ctx(1097, 1000) : sec_ctx_stack_ndx = 1
[2017/06/02 08:37:04.033675,  4, pid=14283, effective(1097, 1000), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx)
  push_conn_ctx(3276714422) : conn_ctx_stack_ndx = 0
[2017/06/02 08:37:04.033687,  4, pid=14283, effective(1097, 1000), real(0, 0)] ../source3/smbd/sec_ctx.c:320(set_sec_ctx_internal)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2017/06/02 08:37:04.033723,  0, pid=14283, effective(0, 0), real(0, 0)] ../source3/lib/dumpcore.c:303(dump_core)
  dumping core in /var/db/system/cores
[2017/06/02 08:37:04.254837,  4, pid=13608, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2017/06/02 08:37:04.254882,  4, pid=13608, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:491(push_conn_ctx)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2017/06/02 08:37:04.254896,  4, pid=13608, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:320(set_sec_ctx_internal)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2017/06/02 08:37:04.254958,  4, pid=13608, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:438(pop_sec_ctx)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2017/06/02 08:37:04.254973,  3, pid=13608, effective(0, 0), real(0, 0)] ../source3/smbd/server.c:859(remove_child_pid)
  ../source3/smbd/server.c:858 Unclean shutdown of pid 14283
Comment 3 IGP IT 2017-06-02 07:07:25 UTC

*** This bug has been marked as a duplicate of bug 12798 ***