Created attachment 8849 [details]
gdb; bt full

Any chance we can get a debug level 10 log of this? One way that I can imagine this happening is some wrong talloc hierarchy or a missing explicit free of the wait event.

(In reply to comment #2)
> Any chance we can get a debug level 10 log of this? One way that I can imagine
> this happening is some wrong talloc hierarchy or a missing explicit free of the
> wait event.

Hm, maybe if I end up with a repro. This crash seems intermittent & semi-rare, and I'm not sure I want to constantly run smbd in debug level 10 ...

Crash just happened again when logging in simultaneously on two machines as the domain administrator.

Using 4.1.0pre1-GIT-392b01f.

Will attach another backtrace, trying to make more of a repro.

Created attachment 8883 [details]
gdb; bt full (#2)

Still seeing this as of 4.1.0pre1-GIT-1c9ef67

commit 1c9ef675d1a44fb9b0d599f96391abf1e21981c1
Author: Volker Lendecke <vl@samba.org>
Date:   Fri May 17 15:14:58 2013 +0200

    smbd: Fix a ISO C90 forbids mixed declarations and code warning

    Signed-off-by: Volker Lendecke <vl@samba.org>
    Reviewed-by: Matthieu Patou <mat@matws.net>

    Autobuild-User(master): Matthieu Patou <mat@samba.org>
    Autobuild-Date(master): Sat May 18 01:40:04 CEST 2013 on sn-devel-104


FWIW, this user also triggered bug 9903.


Another smbd.log:

[2013/05/25 14:40:08.338658,  0] ../source3/smbd/oplock.c:333(oplock_timeout_handler)
  Oplock break failed for file betsy/Searches/desktop.ini -- replying anyway
[2013/05/25 14:40:08.339238,  0] ../source3/smbd/open.c:1527(defer_open_done)
  PANIC: assert failed at ../source3/smbd/open.c(1527): ret
[2013/05/25 14:40:08.339399,  0] ../source3/lib/util.c:810(smb_panic_s3)
  PANIC (pid 15161): assert failed: ret
[2013/05/25 14:40:08.340271,  0] ../source3/lib/util.c:921(log_stack_trace)
  BACKTRACE: 25 stack frames:
   #0 /usr/local/samba/lib/libsmbconf.so.0(log_stack_trace+0x1f) [0x7f9ca4103caa]
   #1 /usr/local/samba/lib/libsmbconf.so.0(smb_panic_s3+0x6c) [0x7f9ca4103afd]
   #2 /usr/local/samba/lib/libsamba-util.so.0(smb_panic+0x28) [0x7f9ca5b87c49]
   #3 /usr/local/samba/lib/private/libsmbd_base.so(+0x1397ae) [0x7f9ca56f67ae]
   #4 /usr/local/samba/lib/private/libtevent.so.0(_tevent_req_notify_callback+0x6a) [0x7f9ca53b1a13]
   #5 /usr/local/samba/lib/private/libtevent.so.0(+0x5a45) [0x7f9ca53b1a45]
   #6 /usr/local/samba/lib/private/libtevent.so.0(_tevent_req_done+0x25) [0x7f9ca53b1a6c]
   #7 /usr/local/samba/lib/libsmbconf.so.0(+0x35ef3) [0x7f9ca4115ef3]
   #8 /usr/local/samba/lib/private/libtevent.so.0(_tevent_req_notify_callback+0x6a) [0x7f9ca53b1a13]
   #9 /usr/local/samba/lib/private/libtevent.so.0(+0x5a45) [0x7f9ca53b1a45]
   #10 /usr/local/samba/lib/private/libtevent.so.0(_tevent_req_done+0x25) [0x7f9ca53b1a6c]
   #11 /usr/local/samba/lib/libsmbconf.so.0(+0x31436) [0x7f9ca4111436]
   #12 /usr/local/samba/lib/private/libtevent.so.0(tevent_common_loop_immediate+0x1f5) [0x7f9ca53b0f78]
   #13 /usr/local/samba/lib/libsmbconf.so.0(run_events_poll+0x56) [0x7f9ca4124de3]
   #14 /usr/local/samba/lib/libsmbconf.so.0(+0x454a7) [0x7f9ca41254a7]
   #15 /usr/local/samba/lib/private/libtevent.so.0(_tevent_loop_once+0xf4) [0x7f9ca53b00b2]
   #16 /usr/local/samba/lib/private/libsmbd_base.so(smbd_process+0x12ef) [0x7f9ca5725449]
   #17 /usr/local/samba/sbin/smbd() [0x409ec6]
   #18 /usr/local/samba/lib/libsmbconf.so.0(run_events_poll+0x55f) [0x7f9ca41252ec]
   #19 /usr/local/samba/lib/libsmbconf.so.0(+0x455b8) [0x7f9ca41255b8]
   #20 /usr/local/samba/lib/private/libtevent.so.0(_tevent_loop_once+0xf4) [0x7f9ca53b00b2]
   #21 /usr/local/samba/sbin/smbd() [0x40ab30]
   #22 /usr/local/samba/sbin/smbd(main+0x1709) [0x40c38a]
   #23 /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf5) [0x7f9ca2972ea5]
   #24 /usr/local/samba/sbin/smbd() [0x4055e9]
[2013/05/25 14:40:08.341474,  0] ../source3/lib/util.c:822(smb_panic_s3)
  smb_panic(): calling panic action [/bin/sleep 99999999]
Terminated
[2013/05/25 14:46:30.461501,  0] ../source3/lib/util.c:830(smb_panic_s3)
  smb_panic(): action returned status 143
[2013/05/25 14:46:30.461743,  0] ../source3/lib/dumpcore.c:317(dump_core)
  dumping core in /usr/local/samba/var/cores/smbd
[2013/05/25 14:46:30.541106,  1] ../source3/smbd/server.c:456(remove_child_pid)
  Scheduled cleanup of brl and lock database after unclean shutdown

Created attachment 8922 [details]
gdb; bt full (from 4.1.0pre1-GIT-1c9ef67)

(In reply to comment #2)
> Any chance we can get a debug level 10 log of this? One way that I can imagine
> this happening is some wrong talloc hierarchy or a missing explicit free of the
> wait event.

If I set "log level = 10" under [global] in smb.conf, will that force both samba & smbd into level 10 logging?

It should, yes

(In reply to comment #9)
> It should, yes

Still happening as of the recent commit:

commit 9f25ad44a93da09b3a7c14a4a1a0e78c5a1b529c
Author: Volker Lendecke <vl@samba.org>
Date:   Thu Jun 6 11:37:59 2013 +0200

    librpc: Shorten dcerpc_binding_handle_call a bit



It's tough to get a level 10 debug log, since that seems to really slow down the machine (and the crash happens very intermittently -- every 3-5 days with 15-20 users on Win8 Pro).

(Is there any alternative to level 10 debug logs? I'm trying a ramdisk now, but it'd be great if there were some buffer that just dumped recent level 10 logs on a crash.)

Attaching a level 8 log now. This might be related to bug 9842 -- I see that crash (around "krb5_cc_store_cred") after this open.c:1527 crash.


Built with commit:

commit af41eb6bd4889a7cd0c7a0bd1553e3534f8f06ad
Author: Aurélien Aptel <aurelien.aptel@gmail.com>
Date:   Fri Jun 28 17:34:26 2013 +0200

    docs-xml/manpages/smbclient.1.xml: fix case of -T flag in example.

    Signed-off-by: Aurélien Aptel <aurelien.aptel@gmail.com>
    Reviewed-by: David Disseldorp <ddiss@samba.org>

    Autobuild-User(master): David Disseldorp <ddiss@samba.org>
    Autobuild-Date(master): Fri Jun 28 17:45:31 CEST 2013 on sn-devel-1

Created attachment 9016 [details]
crash from user, "coco"

Created attachment 9017 [details]
level8_log.%U (1k lines)

Created attachment 9018 [details]
level8_log. (1k lines)

Created attachment 9019 [details]
smb.conf

Another crash, with more organized crash logs (level9+) and GDB at:
http://remote.aldinetravel.com/samba-crash/


There are consistently /two/ crashes, one always following the other:

$ grep panic *
log.coco.txt:[2013/07/08 08:30:52.766641,  0] ../source3/lib/util.c:822(smb_panic_s3)
log.coco.txt:  smb_panic(): calling panic action [/home/semenko/panic-action 17188]
log.%U.txt:[2013/07/08 08:31:27,  0] ../lib/util/fault.c:133(smb_panic_default)
log.%U.txt:  smb_panic(): calling panic action [/home/semenko/panic-action 3012]


Please let me know if there's any other info I can provide.

This is still crashing (though the winbind fixes mean it no longer causes a second panic), and I have some additional level 9 logs.

Is there a way to run samba with only the SMBD service logging at level 10? (e.g. can I add some service-specific log setting to smb.conf?).




[2013/07/19 13:21:06.127147,  5] ../lib/dbwrap/dbwrap.c:187(dbwrap_check_lock_order)
  check lock order 3 for /usr/local/samba/var/lock/dbwrap_watchers.tdb
[2013/07/19 13:21:06.127229,  5] ../lib/dbwrap/dbwrap.c:146(dbwrap_lock_order_state_destructor)
  release lock order 3 for /usr/local/samba/var/lock/dbwrap_watchers.tdb
[2013/07/19 13:21:06.127260,  5] ../source3/lib/messages.c:340(messaging_deregister)
  Deregistering messaging pointer for type 4003 - private_data=0x7f24cc06d890
[2013/07/19 13:21:06.127290,  0] ../source3/smbd/open.c:1527(defer_open_done)
  PANIC: assert failed at ../source3/smbd/open.c(1527): ret
[2013/07/19 13:21:06.127395,  0] ../source3/lib/util.c:810(smb_panic_s3)
  PANIC (pid 28451): assert failed: ret
[2013/07/19 13:21:06.128151,  0] ../source3/lib/util.c:921(log_stack_trace)
  BACKTRACE: 25 stack frames:
<SNIP>

This seems to have resolved itself (haven't seen it in a ~year). Closing.