winbindd main process hangs on samba-dc

[Isaac Boukris]

Hi,

This issue was initially reported on ipa-dc, but I'm able to somewhat
reproduce in lab with samba-dc, by dropping returned tcp packet from a
DC from a trusted domain (iptables -A INPUT -p tcp -s 192.168.0.120 -j
DROP).

As you can see in the attached log, the main winbind process goes into
blocking DC calls such as get_sorted_dc_list(), and depending on the
amount of DCs to try, it may cause clients (such as wbinfo -p, or more
importantly, smbd!) to hang for minutes and to timeout.

Here for instance, we block for 5 second per DC:
[2020/09/08 20:27:49.595952,  3, pid=66128, effective(0, 0), real(0,
0)] ../../source3/lib/util_sock.c:447(open_socket_out_send)
  Connecting to 192.168.0.120 at port 445
[2020/09/08 20:27:49.601764,  3, pid=66128, effective(0, 0), real(0,
0)] ../../source3/lib/util_sock.c:447(open_socket_out_send)
  Connecting to 192.168.0.120 at port 139
[2020/09/08 20:27:54.603044, 10, pid=66128, effective(0, 0), real(0,
0), class=winbind]
../../source3/winbindd/winbindd_cm.c:1712(find_new_dc)
  find_new_dc: smbsock_any_connect failed for domain ACOM address
192.168.0.120. Error was NT_STATUS_IO_TIMEOUT

On a member machine i couldn't trigger it as it seems the
get_sorted_dc_list is done in the per-domain process (as well as the
call to fork_child_dc_connect()), while here it happens in the main
process.

Any ideas?
-------------- next part --------------
net cache flush; killall samba; samba -d11


Breakpoint 1, get_sorted_dc_list (domain=0x55e55bf47610 "ACOM", sitename=0x0, ip_list=0x7ffcb3fdbfb8, count=0x7ffcb3fdbfb4, ads_only=false)
    at ../../source3/libsmb/namequery.c:3944
3944		bool ordered = false;
(gdb) bt
#0  get_sorted_dc_list (domain=0x55e55bf47610 "ACOM", sitename=0x0, ip_list=0x7ffcb3fdbfb8, count=0x7ffcb3fdbfb4, ads_only=false)
    at ../../source3/libsmb/namequery.c:3944
#1  0x000055e55ac8fb5f in get_dcs (mem_ctx=0x55e55cf8bff0, domain=0x55e55c7fed30, dcs=0x7ffcb3fdc210, num_dcs=0x7ffcb3fdc20c, request_flags=4096)
    at ../../source3/winbindd/winbindd_cm.c:1624
#2  0x000055e55ac8fd20 in find_new_dc (mem_ctx=0x55e55cf8bff0, domain=0x55e55c7fed30, dcname=0x7ffcb3fdc2f0, pss=0x55e55c7fede0, fd=0x7ffcb3fdc2fc, 
    request_flags=4096) at ../../source3/winbindd/winbindd_cm.c:1685
#3  0x000055e55ac90b7f in cm_open_connection (domain=0x55e55c7fed30, new_conn=0x55e55c7fee70, need_rw_dc=true) at ../../source3/winbindd/winbindd_cm.c:1971
#4  0x000055e55ac91322 in init_dc_connection_network (domain=0x55e55c7fed30, need_rw_dc=true) at ../../source3/winbindd/winbindd_cm.c:2202
#5  0x000055e55ac8bfec in msg_try_to_go_online (msg=0x55e55bed6110, private_data=0x0, msg_type=1030, server_id=..., data=0x7ffcb3fdc5a8)
    at ../../source3/winbindd/winbindd_cm.c:185
#6  0x00007f253bdecd43 in messaging_dispatch_classic (msg_ctx=0x55e55bed6110, rec=0x7ffcb3fdc560) at ../../source3/lib/messages.c:1298
#7  0x00007f253bdecf03 in messaging_dispatch_rec (msg_ctx=0x55e55bed6110, ev=0x55e55bed8a50, rec=0x7ffcb3fdc560) at ../../source3/lib/messages.c:1361
#8  0x00007f253bdeaaf9 in messaging_recv_cb (ev=0x55e55bed8a50, msg=0x7ffcb3fdca18 <incomplete sequence \340>, msg_len=57, fds=0x7ffcb3fdc9cc, num_fds=0, 
    private_data=0x55e55bed6110) at ../../source3/lib/messages.c:435
#9  0x00007f253b1a491d in msg_dgm_ref_recv (ev=0x55e55bed8a50, msg=0x7ffcb3fdca18 <incomplete sequence \340>, msg_len=57, fds=0x7ffcb3fdc9cc, num_fds=0, 
    private_data=0x0) at ../../lib/messaging/messages_dgm_ref.c:144
#10 0x00007f253b1a33b1 in messaging_dgm_recv (ctx=0x55e55bed6ca0, ev=0x55e55bed8a50, buf=0x7ffcb3fdca18 <incomplete sequence \340>, buflen=57, 
    fds=0x7ffcb3fdc9cc, num_fds=0) at ../../lib/messaging/messages_dgm.c:1346
#11 0x00007f253b1a3057 in messaging_dgm_read_handler (ev=0x55e55bed8a50, fde=0x55e55bef14d0, flags=1, private_data=0x55e55bed6ca0)
    at ../../lib/messaging/messages_dgm.c:1295
#12 0x00007f253c9fa18c in tevent_common_invoke_fd_handler (fde=0x55e55bef14d0, flags=1, removed=0x0) at ../../lib/tevent/tevent_fd.c:138
#13 0x00007f253ca04a6d in epoll_event_loop (epoll_ev=0x55e55bef10b0, tvalp=0x7ffcb3fdcfb0) at ../../lib/tevent/tevent_epoll.c:736
#14 0x00007f253ca050b4 in epoll_event_loop_once (ev=0x55e55bed8a50, location=0x55e55acdb348 "../../source3/winbindd/winbindd.c:2016")
    at ../../lib/tevent/tevent_epoll.c:937
#15 0x00007f253ca01a12 in std_event_loop_once (ev=0x55e55bed8a50, location=0x55e55acdb348 "../../source3/winbindd/winbindd.c:2016")
    at ../../lib/tevent/tevent_standard.c:110
#16 0x00007f253c9f93f7 in _tevent_loop_once (ev=0x55e55bed8a50, location=0x55e55acdb348 "../../source3/winbindd/winbindd.c:2016")
    at ../../lib/tevent/tevent.c:772
#17 0x000055e55ac3cfbc in main (argc=4, argv=0x7ffcb3fdd398) at ../../source3/winbindd/winbindd.c:2016
-------------- next part --------------
A non-text attachment was scrubbed...
Name: log.winbindd
Type: application/octet-stream
Size: 107006 bytes
Desc: not available
URL: <http://lists.samba.org/pipermail/samba-technical/attachments/20200908/22485739/log.obj>