John P Janosik
2014-Mar-13 16:54 UTC
[Samba] Help with Possible Bug in Samba 4.1.5 on Connection Close
I've got a CTDB 2.5.2 Samba 4.1.5 cluster where I'm seeing smbd processes using too much CPU after the client connection is closed. Doing a truss against the smbd processes shows nothing during this time, so no syscalls seem to be involved. I rebuilt with debug enabled and took stack traces from an offending process spaces about 1 minute apart. Can anyone from the team tell me if this is something I should open a bugzilla for? Also any pointers for debugging this either way would be appreciated. Right now log level is set to 2 and there isn't anything interesting in the log. I can up the log level to 10 after I find a process in this state but the only additions to the log are regarding messageing_tdb signals. These additions are not frequent so I think most of the code paths using CPU must not be logging anything. [2014/03/13 11:32:13.773740, 2, pid=10420472] ../source3/smbd/service.c:848(make_connection_snum) adminib-pci1d7e (ipv4:9.42.212.29:60447) connect to service rtp initially as user jbcummin (uid=12443, gid=211) (pid 10420472) [2014/03/13 12:23:33.530533, 1, pid=10420472] ../source3/smbd/service.c:1122(close_cnum) adminib-pci1d7e (ipv4:9.42.212.29:60447) closed connection to service rtp stack 1: gettimeofday(??, ??) at 0xd0223d00 GetTimeOfDay(tval = 0x2ff20d80), line 54 in "time.c" timeval_current(), line 542 in "time.c" smbXsrv_session_close_loop(subreq = 0x2000cde8), line 243 in "smbXsrv_session.c" _tevent_req_notify_callback(req = 0x2000cde8, location = "../source3/lib/msg_channel.c:234"), line 101 in "tevent_req.c" tevent_req_finish(req = 0x2000cde8, state = TEVENT_REQ_USER_ERROR, location = "../source3/lib/msg_channel.c:234"), line 110 in "tevent_req.c" tevent_req_trigger(ev = 0x2000b2f8, im = 0x200c1528, private_data = 0x2000cde8), line 166 in "tevent_req.c" tevent_common_loop_immediate(ev = 0x2000b2f8), line 135 in "tevent_immediate.c" run_events_poll(ev = 0x2000b2f8, pollrtn = 0, pfds = (nil), num_pfds = 0), line 192 in "events.c" s3_event_loop_once(ev = 0x2000b2f8, location = "../source3/smbd/process.c:3626"), line 303 in "events.c" _tevent_loop_once(ev = 0x2000b2f8, location = "../source3/smbd/process.c:3626"), line 530 in "tevent.c" smbd_process(ev_ctx = 0x2000b2f8, msg_ctx = 0x2000b378, sock_fd = 40, interactive = @0x00000000), line 3626 in "process.c" unnamed block in smbd_accept_connection(ev = 0x2000b2f8, fde = 0x200c1598, flags = 1, private_data = 0x200c1548), line 621 in "server.c" smbd_accept_connection(ev = 0x2000b2f8, fde = 0x200c1598, flags = 1, private_data = 0x200c1548), line 621 in "server.c" unnamed block in run_events_poll(ev = 0x2000b2f8, pollrtn = 1, pfds = 0x200148a8, num_pfds = 7), line 257 in "events.c" run_events_poll(ev = 0x2000b2f8, pollrtn = 1, pfds = 0x200148a8, num_pfds = 7), line 257 in "events.c" s3_event_loop_once(ev = 0x2000b2f8, location = "../source3/smbd/server.c:943"), line 326 in "events.c" _tevent_loop_once(ev = 0x2000b2f8, location = "../source3/smbd/server.c:943"), line 530 in "tevent.c" unnamed block in smbd_parent_loop(ev_ctx = 0x2000b2f8, parent = 0x2000e6e8), line 943 in "server.c" smbd_parent_loop(ev_ctx = 0x2000b2f8, parent = 0x2000e6e8), line 943 in "server.c" server.main(argc = 2, argv = 0x2ff22b54), line 1577 in "server.c" stack 2: _talloc_free_internal(ptr = 0x2000cde8, location = "../source3/smbd/smbXsrv_session.c:247"), line 840 in "talloc.c" _talloc_free(ptr = 0x2000cde8, location = "../source3/smbd/smbXsrv_session.c:247"), line 1489 in "talloc.c" smbXsrv_session_close_loop(subreq = 0x2000cde8), line 247 in "smbXsrv_session.c" _tevent_req_notify_callback(req = 0x2000cde8, location = "../source3/lib/msg_channel.c:234"), line 101 in "tevent_req.c" tevent_req_finish(req = 0x2000cde8, state = TEVENT_REQ_USER_ERROR, location = "../source3/lib/msg_channel.c:234"), line 110 in "tevent_req.c" tevent_req_trigger(ev = 0x2000b2f8, im = 0x200c1528, private_data = 0x2000cde8), line 166 in "tevent_req.c" tevent_common_loop_immediate(ev = 0x2000b2f8), line 135 in "tevent_immediate.c" run_events_poll(ev = 0x2000b2f8, pollrtn = 0, pfds = (nil), num_pfds = 0), line 192 in "events.c" s3_event_loop_once(ev = 0x2000b2f8, location = "../source3/smbd/process.c:3626"), line 303 in "events.c" _tevent_loop_once(ev = 0x2000b2f8, location = "../source3/smbd/process.c:3626"), line 530 in "tevent.c" smbd_process(ev_ctx = 0x2000b2f8, msg_ctx = 0x2000b378, sock_fd = 40, interactive = @0x00000000), line 3626 in "process.c" unnamed block in smbd_accept_connection(ev = 0x2000b2f8, fde = 0x200c1598, flags = 1, private_data = 0x200c1548), line 621 in "server.c" smbd_accept_connection(ev = 0x2000b2f8, fde = 0x200c1598, flags = 1, private_data = 0x200c1548), line 621 in "server.c" unnamed block in run_events_poll(ev = 0x2000b2f8, pollrtn = 1, pfds = 0x200148a8, num_pfds = 7), line 257 in "events.c" run_events_poll(ev = 0x2000b2f8, pollrtn = 1, pfds = 0x200148a8, num_pfds = 7), line 257 in "events.c" s3_event_loop_once(ev = 0x2000b2f8, location = "../source3/smbd/server.c:943"), line 326 in "events.c" _tevent_loop_once(ev = 0x2000b2f8, location = "../source3/smbd/server.c:943"), line 530 in "tevent.c" unnamed block in smbd_parent_loop(ev_ctx = 0x2000b2f8, parent = 0x2000e6e8), line 943 in "server.c" smbd_parent_loop(ev_ctx = 0x2000b2f8, parent = 0x2000e6e8), line 943 in "server.c" server.main(argc = 2, argv = 0x2ff22b54), line 1577 in "server.c" stack 3: s3_event_loop_once(ev = 0x2000b2f8, location = "../source3/smbd/process.c:3626"), line 328 in "events.c" _tevent_loop_once(ev = 0x2000b2f8, location = "../source3/smbd/process.c:3626"), line 530 in "tevent.c" smbd_process(ev_ctx = 0x2000b2f8, msg_ctx = 0x2000b378, sock_fd = 40, interactive = @0x00000000), line 3626 in "process.c" unnamed block in smbd_accept_connection(ev = 0x2000b2f8, fde = 0x200c1598, flags = 1, private_data = 0x200c1548), line 621 in "server.c" smbd_accept_connection(ev = 0x2000b2f8, fde = 0x200c1598, flags = 1, private_data = 0x200c1548), line 621 in "server.c" unnamed block in run_events_poll(ev = 0x2000b2f8, pollrtn = 1, pfds = 0x200148a8, num_pfds = 7), line 257 in "events.c" run_events_poll(ev = 0x2000b2f8, pollrtn = 1, pfds = 0x200148a8, num_pfds = 7), line 257 in "events.c" s3_event_loop_once(ev = 0x2000b2f8, location = "../source3/smbd/server.c:943"), line 326 in "events.c" _tevent_loop_once(ev = 0x2000b2f8, location = "../source3/smbd/server.c:943"), line 530 in "tevent.c" unnamed block in smbd_parent_loop(ev_ctx = 0x2000b2f8, parent = 0x2000e6e8), line 943 in "server.c" smbd_parent_loop(ev_ctx = 0x2000b2f8, parent = 0x2000e6e8), line 943 in "server.c" server.main(argc = 2, argv = 0x2ff22b54), line 1577 in "server.c" stack 4: _talloc_free_internal(ptr = 0x2000dca8, location = "../source3/smbd/smbXsrv_session.c:247"), line 892 in "talloc.c" unnamed block in _talloc_free_children_internal(tc = 0x2000cdb8, ptr = 0x2000cde8, location = "../source3/smbd/smbXsrv_session.c:247"), line 1374 in "talloc.c" _talloc_free_children_internal(tc = 0x2000cdb8, ptr = 0x2000cde8, location = "../source3/smbd/smbXsrv_session.c:247"), line 1374 in "talloc.c" _talloc_free_internal(ptr = 0x2000cde8, location = "../source3/smbd/smbXsrv_session.c:247"), line 904 in "talloc.c" _talloc_free(ptr = 0x2000cde8, location = "../source3/smbd/smbXsrv_session.c:247"), line 1489 in "talloc.c" smbXsrv_session_close_loop(subreq = 0x2000cde8), line 247 in "smbXsrv_session.c" _tevent_req_notify_callback(req = 0x2000cde8, location = "../source3/lib/msg_channel.c:234"), line 101 in "tevent_req.c" tevent_req_finish(req = 0x2000cde8, state = TEVENT_REQ_USER_ERROR, location = "../source3/lib/msg_channel.c:234"), line 110 in "tevent_req.c" tevent_req_trigger(ev = 0x2000b2f8, im = 0x200c1528, private_data = 0x2000cde8), line 166 in "tevent_req.c" tevent_common_loop_immediate(ev = 0x2000b2f8), line 135 in "tevent_immediate.c" run_events_poll(ev = 0x2000b2f8, pollrtn = 0, pfds = (nil), num_pfds = 0), line 192 in "events.c" s3_event_loop_once(ev = 0x2000b2f8, location = "../source3/smbd/process.c:3626"), line 303 in "events.c" _tevent_loop_once(ev = 0x2000b2f8, location = "../source3/smbd/process.c:3626"), line 530 in "tevent.c" smbd_process(ev_ctx = 0x2000b2f8, msg_ctx = 0x2000b378, sock_fd = 40, interactive = @0x00000000), line 3626 in "process.c" unnamed block in smbd_accept_connection(ev = 0x2000b2f8, fde = 0x200c1598, flags = 1, private_data = 0x200c1548), line 621 in "server.c" smbd_accept_connection(ev = 0x2000b2f8, fde = 0x200c1598, flags = 1, private_data = 0x200c1548), line 621 in "server.c" unnamed block in run_events_poll(ev = 0x2000b2f8, pollrtn = 1, pfds = 0x200148a8, num_pfds = 7), line 257 in "events.c" run_events_poll(ev = 0x2000b2f8, pollrtn = 1, pfds = 0x200148a8, num_pfds = 7), line 257 in "events.c" s3_event_loop_once(ev = 0x2000b2f8, location = "../source3/smbd/server.c:943"), line 326 in "events.c" _tevent_loop_once(ev = 0x2000b2f8, location = "../source3/smbd/server.c:943"), line 530 in "tevent.c" unnamed block in smbd_parent_loop(ev_ctx = 0x2000b2f8, parent = 0x2000e6e8), line 943 in "server.c" smbd_parent_loop(ev_ctx = 0x2000b2f8, parent = 0x2000e6e8), line 943 in "server.c" server.main(argc = 2, argv = 0x2ff22b54), line 1577 in "server.c" John Janosik jpjanosi at us.ibm.com
Apparently Analagous Threads
Wisdom of the Ancients
