Philipp v. Thunen
2014-Feb-03 20:02 UTC
[Samba] Samba 4.1.4 crashes with "invalid next size"
Server: Debian Wheezy 7.3, ECC RAM, updated via cron-apt Version: 4.1.4 Clients: Windows 8.1 Pro Environment: Active Directory, installed from scratch (no migration), roaming profiles, group policies for printers, network mappings, ... Hello everyone, I've upgraded my Samba installation from 4.0.14 (which was working more or less fine) to 4.1.4 yesterday - via Sernet packages, i. e. just replacing the repo URL from 4.0 to 4.1 - because I was hoping some strange phenomens were gone then, for example connections showing in smbstatus from clients which are already switched off. After my upgrade, I've tested several things like profiles, printing, and accessing shares, and everything was working fine. But today - when more than one client got connected -, they were disconnected or working very, very slow all the time. I've checked the samba logs and syslogs and have seen that various samba processes have crashed repeatedly. After shutting down all clients but mine and a quick reboot of the machine, samba even crashed immediately after I've tried to access one of the shares myself. I managed to increase the debug level to 10 and to save the logs (and two coredumps), one of the samba logs and the syslogs is quoted below. Google showed me some bugs which could be related to this [1], but none of them is related to the current 4.1.x release and I'm not sure if open.c or smb2_signing.c is to blame. To be able to work again, I forced a downgrade to 4.0.14. Can anyone give me a hint how to deal with this error? Can I give any more information? Thank you very much in advance! Regards Philipp [1] https://bugzilla.samba.org/show_bug.cgi?id=9853 https://bugzilla.samba.org/show_bug.cgi?id=10386 https://bugzilla.samba.org/show_bug.cgi?id=10225 (1) Syslog:> Feb 3 08:52:17 srv1 smbd[12385]: [2014/02/03 08:52:17.292097, 0] ../source3/smbd/open.c:1582(defer_open_done) > Feb 3 08:52:17 srv1 smbd[12385]: PANIC: assert failed at ../source3/smbd/open.c(1582): ret > Feb 3 08:52:17 srv1 smbd[12385]: [2014/02/03 08:52:17.292219, 0] ../source3/lib/util.c:785(smb_panic_s3) > Feb 3 08:52:17 srv1 smbd[12385]: PANIC (pid 12385): assert failed: ret > Feb 3 08:52:17 srv1 smbd[12385]: [2014/02/03 08:52:17.293088, 0] ../source3/lib/util.c:896(log_stack_trace) > Feb 3 08:52:17 srv1 smbd[12385]: BACKTRACE: 19 stack frames: > Feb 3 08:52:17 srv1 smbd[12385]: #0 /usr/lib/x86_64-linux-gnu/samba/libsmbconf.so.0(log_stack_trace+0x1a) [0x7fe8c887e2b9] > Feb 3 08:52:17 srv1 smbd[12385]: #1 /usr/lib/x86_64-linux-gnu/samba/libsmbconf.so.0(smb_panic_s3+0x55) [0x7fe8c887e3b7] > Feb 3 08:52:17 srv1 smbd[12385]: #2 /usr/lib/x86_64-linux-gnu/samba/libsamba-util.so.0(smb_panic+0x2d) [0x7fe8ca1beedb] > Feb 3 08:52:17 srv1 smbd[12385]: #3 /usr/lib/x86_64-linux-gnu/samba/libsmbd_base.so(+0xfc9e7) [0x7fe8c9da09e7] > Feb 3 08:52:17 srv1 smbd[12385]: #4 /usr/lib/x86_64-linux-gnu/samba/libtevent.so.0(_tevent_req_notify_callback+0x2a) [0x7fe8c9a9bd1e] > Feb 3 08:52:17 srv1 smbd[12385]: #5 /usr/lib/x86_64-linux-gnu/samba/libtevent.so.0(+0x4d30) [0x7fe8c9a9bd30] > Feb 3 08:52:17 srv1 smbd[12385]: #6 /usr/lib/x86_64-linux-gnu/samba/libtevent.so.0(+0x4d81) [0x7fe8c9a9bd81] > Feb 3 08:52:17 srv1 smbd[12385]: #7 /usr/lib/x86_64-linux-gnu/samba/libtevent.so.0(tevent_common_loop_timer_delay+0x19d) [0x7fe8c9a9ebd9] > Feb 3 08:52:17 srv1 smbd[12385]: #8 /usr/lib/x86_64-linux-gnu/samba/libsmbconf.so.0(run_events_poll+0x5f) [0x7fe8c889b920] > Feb 3 08:52:17 srv1 smbd[12385]: #9 /usr/lib/x86_64-linux-gnu/samba/libsmbconf.so.0(+0x44d21) [0x7fe8c889bd21] > Feb 3 08:52:17 srv1 smbd[12385]: #10 /usr/lib/x86_64-linux-gnu/samba/libtevent.so.0(_tevent_loop_once+0x92) [0x7fe8c9a9ae61] > Feb 3 08:52:17 srv1 smbd[12385]: #11 /usr/lib/x86_64-linux-gnu/samba/libsmbd_base.so(smbd_process+0xedd) [0x7fe8c9dc320f] > Feb 3 08:52:17 srv1 smbd[12385]: #12 /usr/sbin/smbd(+0x8fa1) [0x7fe8ca81ffa1] > Feb 3 08:52:17 srv1 smbd[12385]: #13 /usr/lib/x86_64-linux-gnu/samba/libsmbconf.so.0(run_events_poll+0x2eb) [0x7fe8c889bbac] > Feb 3 08:52:17 srv1 smbd[12385]: #14 /usr/lib/x86_64-linux-gnu/samba/libsmbconf.so.0(+0x44d21) [0x7fe8c889bd21] > Feb 3 08:52:17 srv1 smbd[12385]: #15 /usr/lib/x86_64-linux-gnu/samba/libtevent.so.0(_tevent_loop_once+0x92) [0x7fe8c9a9ae61] > Feb 3 08:52:17 srv1 smbd[12385]: #16 /usr/sbin/smbd(main+0x181c) [0x7fe8ca821d89] > Feb 3 08:52:17 srv1 smbd[12385]: #17 /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xfd) [0x7fe8c7312ead] > Feb 3 08:52:17 srv1 smbd[12385]: #18 /usr/sbin/smbd(+0x5fb9) [0x7fe8ca81cfb9] > Feb 3 08:52:17 srv1 smbd[12385]: [2014/02/03 08:52:17.293673, 0] ../source3/lib/dumpcore.c:317(dump_core) > Feb 3 08:52:17 srv1 smbd[12385]: dumping core in /var/log/samba/cores/smbd(2) Samba log for one of the clients:> [2014/02/03 10:01:15.823164, 5, pid=13235, effective(3000029, 100), real(3000029, 0)] ../source3/smbd/uid.c:363(change_to_user_internal) > Impersonated user: uid=(3000029,3000029), gid=(0,100) > [2014/02/03 10:01:15.823184, 4, pid=13235, effective(3000029, 100), real(3000029, 0), class=vfs] ../source3/smbd/vfs.c:838(vfs_ChDir) > vfs_ChDir to /samba/ra > [2014/02/03 10:01:15.823217, 4, pid=13235, effective(3000029, 100), real(3000029, 0), class=vfs] ../source3/smbd/vfs.c:849(vfs_ChDir) > vfs_ChDir got /samba/ra > [2014/02/03 10:01:15.823247, 10, pid=13235, effective(3000029, 100), real(3000029, 0)] ../source3/smbd/smb2_server.c:1780(smbd_smb2_request_verify_creditcharge) > mid 3, CreditCharge: 1, NeededCharge: 1 > [2014/02/03 10:01:15.823304, 10, pid=13235, effective(3000029, 100), real(3000029, 0)] ../source3/smbd/smb2_ioctl.c:394(smbd_smb2_ioctl_send) > smbd_smb2_ioctl: ctl_code[0x00140204] <no handle>, fnum [fsp is NULL] > [2014/02/03 10:01:15.823336, 10, pid=13235, effective(3000029, 100), real(3000029, 0)] ../source3/smbd/smb2_ioctl.c:291(smbd_smb2_request_ioctl_done) > smbd_smb2_request_ioctl_done: smbd_smb2_ioctl_recv returned 24 status NT_STATUS_OK > [2014/02/03 10:01:15.823358, 10, pid=13235, effective(3000029, 100), real(3000029, 0)] ../source3/smbd/smb2_server.c:2499(smbd_smb2_request_done_ex) > smbd_smb2_request_done_ex: idx[1] status[NT_STATUS_OK] body[48] dyn[yes:24] at ../source3/smbd/smb2_ioctl.c:358 > [2014/02/03 10:01:15.823375, 10, pid=13235, effective(3000029, 100), real(3000029, 0)] ../source3/smbd/smb2_server.c:874(smb2_set_operation_credit) > smb2_set_operation_credit: requested 1, charge 1, granted 1, current possible/max 482/512, total granted/max/low/range 31/8192/4/31 > [2014/02/03 10:01:15.823393, 5, pid=13235, effective(3000029, 100), real(3000029, 0)] ../libcli/smb/smb2_signing.c:92(smb2_signing_sign_pdu) > signed SMB2 message > *** glibc detected *** /usr/sbin/smbd: free(): invalid next size (fast): 0x00007ffd9b7f7160 *** > ======= Backtrace: ========> /lib/x86_64-linux-gnu/libc.so.6(+0x76d76)[0x7ffd9707dd76] > /lib/x86_64-linux-gnu/libc.so.6(cfree+0x6c)[0x7ffd97082aac] > /usr/lib/x86_64-linux-gnu/samba/libtalloc.so.2(_talloc_free+0x6ef)[0x7ffd995a249a] > /usr/lib/x86_64-linux-gnu/samba/libsmbd_base.so(+0x13319e)[0x7ffd99aea19e] > /usr/lib/x86_64-linux-gnu/samba/libsmbd_base.so(smbd_smb2_request_done_ex+0x83a)[0x7ffd99aeba58] > /usr/lib/x86_64-linux-gnu/samba/libsmbd_base.so(+0x140a5a)[0x7ffd99af7a5a] > /usr/lib/x86_64-linux-gnu/samba/libtevent.so.0(_tevent_req_notify_callback+0x2a)[0x7ffd997aed1e] > /usr/lib/x86_64-linux-gnu/samba/libsmbd_base.so(smbd_smb2_request_pending_queue+0x49)[0x7ffd99aebadf] > /usr/lib/x86_64-linux-gnu/samba/libsmbd_base.so(smbd_smb2_request_process_ioctl+0x819)[0x7ffd99af8301] > /usr/lib/x86_64-linux-gnu/samba/libsmbd_base.so(smbd_smb2_request_dispatch+0xc1f)[0x7ffd99ae9a5d] > /usr/lib/x86_64-linux-gnu/samba/libsmbd_base.so(+0x13373a)[0x7ffd99aea73a] > /usr/lib/x86_64-linux-gnu/samba/libsmbd_base.so(+0x13385e)[0x7ffd99aea85e] > /usr/lib/x86_64-linux-gnu/samba/libsmbconf.so.0(run_events_poll+0x2eb)[0x7ffd985aebac] > /usr/lib/x86_64-linux-gnu/samba/libsmbconf.so.0(+0x44d21)[0x7ffd985aed21] > /usr/lib/x86_64-linux-gnu/samba/libtevent.so.0(_tevent_loop_once+0x92)[0x7ffd997ade61] > /usr/lib/x86_64-linux-gnu/samba/libsmbd_base.so(smbd_process+0xedd)[0x7ffd99ad620f] > /usr/sbin/smbd(+0x8fa1)[0x7ffd9a532fa1] > /usr/lib/x86_64-linux-gnu/samba/libsmbconf.so.0(run_events_poll+0x2eb)[0x7ffd985aebac] > /usr/lib/x86_64-linux-gnu/samba/libsmbconf.so.0(+0x44d21)[0x7ffd985aed21] > /usr/lib/x86_64-linux-gnu/samba/libtevent.so.0(_tevent_loop_once+0x92)[0x7ffd997ade61] > /usr/sbin/smbd(main+0x181c)[0x7ffd9a534d89] > /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xfd)[0x7ffd97025ead] > /usr/sbin/smbd(+0x5fb9)[0x7ffd9a52ffb9] > ======= Memory map: =======> [...snipped...]
Hello Philipp, Am 03.02.2014 21:02, schrieb Philipp v. Thunen:>> [2014/02/03 10:01:15.823164, 5, pid=13235, effective(3000029, 100), real(3000029, 0)] ../source3/smbd/uid.c:363(change_to_user_internal) >> Impersonated user: uid=(3000029,3000029), gid=(0,100) >> [2014/02/03 10:01:15.823184, 4, pid=13235, effective(3000029, 100), real(3000029, 0), class=vfs] ../source3/smbd/vfs.c:838(vfs_ChDir) >> vfs_ChDir to /samba/ra >> [2014/02/03 10:01:15.823217, 4, pid=13235, effective(3000029, 100), real(3000029, 0), class=vfs] ../source3/smbd/vfs.c:849(vfs_ChDir) >> vfs_ChDir got /samba/ra >> [2014/02/03 10:01:15.823247, 10, pid=13235, effective(3000029, 100), real(3000029, 0)] ../source3/smbd/smb2_server.c:1780(smbd_smb2_request_verify_creditcharge) >> mid 3, CreditCharge: 1, NeededCharge: 1 >> [2014/02/03 10:01:15.823304, 10, pid=13235, effective(3000029, 100), real(3000029, 0)] ../source3/smbd/smb2_ioctl.c:394(smbd_smb2_ioctl_send) >> smbd_smb2_ioctl: ctl_code[0x00140204] <no handle>, fnum [fsp is NULL] >> [2014/02/03 10:01:15.823336, 10, pid=13235, effective(3000029, 100), real(3000029, 0)] ../source3/smbd/smb2_ioctl.c:291(smbd_smb2_request_ioctl_done) >> smbd_smb2_request_ioctl_done: smbd_smb2_ioctl_recv returned 24 status NT_STATUS_OK >> [2014/02/03 10:01:15.823358, 10, pid=13235, effective(3000029, 100), real(3000029, 0)] ../source3/smbd/smb2_server.c:2499(smbd_smb2_request_done_ex) >> smbd_smb2_request_done_ex: idx[1] status[NT_STATUS_OK] body[48] dyn[yes:24] at ../source3/smbd/smb2_ioctl.c:358 >> [2014/02/03 10:01:15.823375, 10, pid=13235, effective(3000029, 100), real(3000029, 0)] ../source3/smbd/smb2_server.c:874(smb2_set_operation_credit) >> smb2_set_operation_credit: requested 1, charge 1, granted 1, current possible/max 482/512, total granted/max/low/range 31/8192/4/31 >> [2014/02/03 10:01:15.823393, 5, pid=13235, effective(3000029, 100), real(3000029, 0)] ../libcli/smb/smb2_signing.c:92(smb2_signing_sign_pdu) >> signed SMB2 message >> *** glibc detected *** /usr/sbin/smbd: free(): invalid next size (fast): 0x00007ffd9b7f7160 ***Is this the same crash? https://bugzilla.samba.org/show_bug.cgi?id=10415 Regards, Marc