Univention Bugzilla – Bug 53597
Failed to listen on :49154 - NT_STATUS_ADDRESS_ALREADY_ASSOCIATED after Samba4 restart
Last modified: 2023-01-12 14:14:16 CET
In our nightly tests, we sometimes see that Samba does not start again after a samba restart. Sometimes at setup, sometimes while already running tests. This is logged: stream_setup_socket: Failed to listen on 10.207.172.193:49154 - NT_STATUS_ADDRESS_ALREADY_ASSOCIATED [2021/07/15 00:09:25.946966, 0, pid=2417] ../../source4/rpc_server/dcerpc_server.c:3221(add_socket_rpc_tcp_iface) service_setup_stream_socket(address=10.207.172.193,port=49154) for samr rpcecho wkssvc mgmt failed - NT_STATUS_ADDRESS_ALREADY_ASSOCIATEDtask_server_terminate: task_server_terminate: [dcerpc: Failed to initialise end points] [2021/07/15 00:09:27.122242, 0, pid=2209] ../../lib/util/become_daemon.c:136(daemon_ready) --- +++ This bug was initially created as a clone of Bug #51535 +++ Bug #51535 references a similar problem, that occurs after a server password change, where port 135 is not available because some sessions were still active. I split this problem off because it happens after some samba restarts, in the dynamic port range.
[2022/01/30 01:20:05.764139, 0, pid=1964] ../../source4/smbd/service_stream.c:374(stream_setup_socket) stream_setup_socket: Failed to listen on 10.207.133.39:49154 - NT_STATUS_ADDRESS_ALREADY_ASSOCIATED [2022/01/30 01:20:05.764208, 0, pid=1964] ../../source4/rpc_server/dcerpc_server.c:3275(add_socket_rpc_tcp_iface) service_setup_stream_socket(address=10.207.133.39,port=49154) for samr rpcecho wkssvc mgmt failed - NT_STATUS_ADDRESS_ALREADY_ASSOCIATEDtask_server_terminate: task_server_terminate: [dcerpc: Failed to initialise end points] Happened again at UCS 4.4-8 http://jenkins.knut.univention.de:8080/job/UCS-4.4/job/UCS-4.4-8/job/AutotestJoin/lastCompletedBuild/SambaVersion=s4,Systemrolle=master-part-II/testReport/
On a UCS 5.0-1 primary directory node, that port is bound to: root@primary20:~# netstat -tanp | grep 49154 tcp 0 0 10.200.8.20:49154 0.0.0.0:* LISTEN 7733/samba: task[rp tcp 0 0 127.0.0.1:49154 0.0.0.0:* LISTEN 7733/samba: task[rp tcp6 0 0 ::1:49154 :::* LISTEN 7733/samba: task[rp root@primary20:~# ps fax: [...] 7719 ? S 0:00 \_ samba: tfork waiter process(7720) 7720 ? S 0:00 | \_ samba: task[rpc] pre-fork master 7727 ? S 0:00 | \_ samba: tfork waiter process(7733) 7733 ? S 0:02 | | \_ samba: task[rpc] pre-forked worker(0) [...] ## It has other ports open too (e.g. 135): root@primary20:~# netstat -tanp | grep 7733 tcp 0 0 10.200.8.20:49153 0.0.0.0:* LISTEN 7733/samba: task[rp tcp 0 0 127.0.0.1:49153 0.0.0.0:* LISTEN 7733/samba: task[rp tcp 0 0 10.200.8.20:49154 0.0.0.0:* LISTEN 7733/samba: task[rp tcp 0 0 127.0.0.1:49154 0.0.0.0:* LISTEN 7733/samba: task[rp tcp 0 0 10.200.8.20:135 0.0.0.0:* LISTEN 7733/samba: task[rp tcp 0 0 127.0.0.1:135 0.0.0.0:* LISTEN 7733/samba: task[rp tcp 0 0 10.200.8.20:49153 10.200.8.21:45838 VERBUNDEN 7733/samba: task[rp tcp6 0 0 ::1:49153 :::* LISTEN 7733/samba: task[rp tcp6 0 0 ::1:49154 :::* LISTEN 7733/samba: task[rp tcp6 0 0 ::1:135 :::* LISTEN 7733/samba: task[rp The rpc master process also has: root@primary20:~# netstat -tanp | grep 7720 tcp 0 0 10.200.8.20:49152 0.0.0.0:* LISTEN 7720/samba: task[rp tcp 0 0 127.0.0.1:49152 0.0.0.0:* LISTEN 7720/samba: task[rp tcp6 0 0 ::1:49152 :::* LISTEN 7720/samba: task[rp So I guess the "stop" phase of /etc/init.d/samba does not reliably terminate the process?
[2022/12/12 10:44:09.902008, 0, pid=14934] ../../source4/smbd/server.c:587(binary_smbd_main) samba version 4.10.18-Univention started. Copyright Andrew Tridgell and the Samba Team 1992-2019 [2022/12/12 10:44:14.350309, 0, pid=14935] ../../source4/smbd/server.c:773(binary_smbd_main) binary_smbd_main: samba: using 'standard' process model [2022/12/12 10:44:14.430614, 0, pid=14935] ../../lib/util/become_daemon.c:136(daemon_ready) daemon_ready: daemon 'samba' finished starting up and ready to serve connections [2022/12/12 10:44:14.582294, 0, pid=14954] ../../source4/smbd/service_stream.c:374(stream_setup_socket) stream_setup_socket: Failed to listen on ::1:135 - NT_STATUS_ADDRESS_ALREADY_ASSOCIATED [2022/12/12 10:44:14.582494, 0, pid=14954] ../../source4/rpc_server/dcerpc_server.c:3275(add_socket_rpc_tcp_iface) service_setup_stream_socket(address=::1,port=135) for epmapper mgmt failed - NT_STATUS_ADDRESS_ALREADY_ASSOCIATEDtask_server_terminate: task_server_terminate: [dcerpc: Failed to initialise end points] [2022/12/12 10:44:14.594119, 0, pid=14935] ../../source4/smbd/server.c:371(samba_terminate) samba_terminate: samba_terminate of samba 14935: dcerpc: Failed to initialise end points root@backup1:~# /etc/init.d/samba stop [ ok ] Stopping samba-ad-dc (via systemctl): samba-ad-dc.service. [ ok ] Stopping smbd (via systemctl): smbd.service. [ ok ] Stopping nmbd (via systemctl): nmbd.service. root@backup1:~# ps aufx |grep samba root 15723 0.0 0.0 14316 972 pts/0 S+ 10:44 0:00 | \_ grep samba root 15606 10.0 0.5 674312 43444 ? S 10:44 0:01 \_ /usr/bin/python2.7 /usr/lib/nagios/plugins/check_univention_samba_drs_failures root 6600 0.3 1.1 1730684 93352 ? Ssl Okt20 260:20 /usr/sbin/named -c /etc/bind/named.conf.samba4 -f -d 0 root 18177 0.0 0.3 1871728 27116 ? D Nov29 0:03 samba: conn[named_pipe] c[unix:] s[unix:/var/run/samba/ncalrpc/np/netlogon] server_id[18177] root 25579 0.0 0.3 1871728 26592 ? D Dez08 0:01 samba: conn[named_pipe] c[unix:] s[unix:/var/run/samba/ncalrpc/np/netlogon] server_id[25579] root@backup1:~# ps aufx |grep samba root 15725 0.0 0.0 14316 972 pts/0 S+ 10:44 0:00 | \_ grep samba root 15606 9.0 0.5 674312 43444 ? S 10:44 0:01 \_ /usr/bin/python2.7 /usr/lib/nagios/plugins/check_univention_samba_drs_failures root 6600 0.3 1.1 1730684 93352 ? Ssl Okt20 260:20 /usr/sbin/named -c /etc/bind/named.conf.samba4 -f -d 0 root 18177 0.0 0.3 1871728 28556 ? D Nov29 0:03 samba: conn[named_pipe] c[unix:] s[unix:/var/run/samba/ncalrpc/np/netlogon] server_id[18177] root 25579 0.0 0.3 1871728 27608 ? D Dez08 0:01 samba: conn[named_pipe] c[unix:] s[unix:/var/run/samba/ncalrpc/np/netlogon] server_id[25579] root@backup1:~# kill 18177 root@backup1:~# ps aufx |grep samba root 15727 0.0 0.0 14316 968 pts/0 S+ 10:45 0:00 | \_ grep samba root 15606 4.7 0.5 674312 43444 ? S 10:44 0:01 \_ /usr/bin/python2.7 /usr/lib/nagios/plugins/check_univention_samba_drs_failures root 6600 0.3 1.2 1730684 99592 ? Ssl Okt20 260:20 /usr/sbin/named -c /etc/bind/named.conf.samba4 -f -d 0 root 25579 0.0 0.4 1871728 35064 ? D Dez08 0:01 samba: conn[named_pipe] c[unix:] s[unix:/var/run/samba/ncalrpc/np/netlogon] server_id[25579] root@backup1:~# kill 25579 root@backup1:~# /etc/init.d/samba start [ ok ] Starting nmbd (via systemctl): nmbd.service. [ ok ] Starting smbd (via systemctl): smbd.service. [ ok ] Starting samba-ad-dc (via systemctl): samba-ad-dc.service. root@backup1:~# less /var/log/samba/log.samba