[Samba] Upgrading a ctdb cluster: samba not listening on TCP port 445
Nicolas Zuber
n.zuber at physik.uni-stuttgart.de
Thu Feb 1 12:11:58 UTC 2018
Am Do 01.02.2018 um 12:04 schrieb Martin Schwenke:
> Hi Nicolas,
>
> On Thu, 1 Feb 2018 10:57:59 +0100, Nicolas Zuber via samba
> <samba at lists.samba.org> wrote:
>
>> I try to update two clustered samba file servers. Right now samba 4.7.0
>> with ctdb is running on both of them. To update samba I stopped ctdb on
>> one of the servers, and compiled and installed samba 4.7.1 with:
>>
>> ./configure --with-cluster-support --with-shared-modules=idmap_tdb2,idmap_ad,vfs_glusterfs --with-systemd
>>
>> Trying to start ctdb on the updated server fails with "
>> ctdb-eventd[19790]: 50.samba: samba not listening on TCP port 445" in
>> the ctdb.log. Trying to update directly to 4.7.3 or 4.7.4 shows the same
>> error message.
>>
>> Removing the "clustered = yes" from the smb.conf file and starting smbd
>> by hand works fine and the smbd process listens on port 445. Downgrading
>> again to 4.7.0 worked without any problems and ctdb and smbd are running
>> again without any problems, but this is only a temporary solution.
>>
>> Any help in how to debug this problem will be appreciated.
> The error about samba not listening is coming from CTDB's "monitor"
> event. Before this, CTDB's "startup" event would have attempted to
> start smbd. Can you find any evidence in log.smbd (or similar) about
> smbd failing somewhere?
>
> If there are no messages from smbd then I wonder if systemd might be
> getting in the way and not even trying to start smbd? Does journalctl
> (with whatever the standard options are) tell you anything useful?
>
> Thanks...
>
> peace & happiness,
> martin
Hi Martin,
the samba log is spammed with:
[2018/02/01 12:22:51.965183, 5]
../lib/dbwrap/dbwrap.c:160(dbwrap_check_lock_order)
check lock order 3 for g_lock.tdb
[2018/02/01 12:22:51.966145, 5]
../lib/dbwrap/dbwrap.c:128(dbwrap_lock_order_state_destructor)
release lock order 3 for g_lock.tdb
after starting the ctdb process and setting the log level to 5. If I set
the log level to 2 it shows that winbind and nmbd starts successfully
and no complains about a failed smbd process (see log below).
Checking with journal -lu smb shows no errors when starting ctdb:
"systemd[1]: Starting Samba SMB Daemon..." and "systemd[1]: Started
Samba SMB Daemon".
The systemd smb.service file looks like this:
[Unit]
Description=Samba SMB Daemon
After=syslog.target network.target nmb.service winbind.service
[Service]
Environment="PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/usr/local/samba/bin/:/usr/local/samba/sbin/"
Type=forking
ExecStart=/usr/local/samba/sbin/smbd
PIDFile=/usr/local/samba/var/run/smbd.pid
[Install]
WantedBy=multi-user.target
As far as I can see, the smbd process seems to start successfully and I have no idea why it is not listening on the port.
Thanks,
Nicolas
samba.log:
[2018/02/01 12:42:52.524438, 2] ../source3/lib/interface.c:345(add_interface)
added interface eno1 ip=172.1.1.4 bcast=172.1.255.255 netmask=255.255.0.0
[2018/02/01 12:42:52.524477, 2] ../source3/lib/interface.c:345(add_interface)
added interface enp4s0f1 ip=172.16.1.4 bcast=172.16.255.255 netmask=255.255.0.0
[2018/02/01 12:42:52.524493, 2] ../source3/lib/interface.c:345(add_interface)
added interface enp4s0f1 ip=172.16.1.55 bcast=172.16.255.255 netmask=255.255.0.0
[2018/02/01 12:42:52.524506, 2] ../source3/lib/interface.c:345(add_interface)
added interface enp4s0f0 ip=172.17.1.4 bcast=172.17.255.255 netmask=255.255.0.0
[2018/02/01 12:42:52.524520, 2] ../source3/lib/interface.c:345(add_interface)
added interface virbr0 ip=192.168.122.1 bcast=192.168.122.255 netmask=255.255.255.0
[2018/02/01 12:42:52.525029, 2] ../source3/lib/interface.c:345(add_interface)
added interface eno1 ip=172.1.1.4 bcast=172.1.255.255 netmask=255.255.0.0
[2018/02/01 12:42:52.525047, 2] ../source3/lib/interface.c:345(add_interface)
added interface enp4s0f1 ip=172.16.1.4 bcast=172.16.255.255 netmask=255.255.0.0
[2018/02/01 12:42:52.525061, 2] ../source3/lib/interface.c:345(add_interface)
added interface enp4s0f1 ip=172.16.1.55 bcast=172.16.255.255 netmask=255.255.0.0
[2018/02/01 12:42:52.525074, 2] ../source3/lib/interface.c:345(add_interface)
added interface enp4s0f0 ip=172.17.1.4 bcast=172.17.255.255 netmask=255.255.0.0
[2018/02/01 12:42:52.525088, 2] ../source3/lib/interface.c:345(add_interface)
added interface virbr0 ip=192.168.122.1 bcast=192.168.122.255 netmask=255.255.255.0
[2018/02/01 12:42:52.527622, 0] ../source3/winbindd/winbindd_cache.c:3170(initialize_winbindd_cache)
initialize_winbindd_cache: clearing cache and re-creating with version number 2
[2018/02/01 12:42:52.529264, 2] ../source3/winbindd/winbindd_util.c:283(add_trusted_domain_from_tdc)
Added domain BUILTIN (null) S-1-5-32
[2018/02/01 12:42:52.529360, 2] ../source3/winbindd/winbindd_util.c:283(add_trusted_domain_from_tdc)
Added domain FILE (null) SID
[2018/02/01 12:42:52.529432, 2] ../source3/winbindd/winbindd_util.c:283(add_trusted_domain_from_tdc)
Added domain PI5 MYDOMAIN SID
[2018/02/01 12:42:52.530113, 0] ../lib/util/become_daemon.c:124(daemon_ready)
STATUS=daemon 'winbindd' finished starting up and ready to serve connections
[2018/02/01 12:42:52.701886, 2] ../source3/lib/interface.c:345(add_interface)
added interface eno1 ip=172.1.1.4 bcast=172.1.255.255 netmask=255.255.0.0
[2018/02/01 12:42:52.701925, 2] ../source3/lib/interface.c:345(add_interface)
added interface enp4s0f1 ip=172.16.1.4 bcast=172.16.255.255 netmask=255.255.0.0
[2018/02/01 12:42:52.701940, 2] ../source3/lib/interface.c:345(add_interface)
added interface enp4s0f1 ip=172.16.1.55 bcast=172.16.255.255 netmask=255.255.0.0
[2018/02/01 12:42:52.701954, 2] ../source3/lib/interface.c:345(add_interface)
added interface enp4s0f0 ip=172.17.1.4 bcast=172.17.255.255 netmask=255.255.0.0
[2018/02/01 12:42:52.701972, 2] ../source3/lib/interface.c:345(add_interface)
added interface virbr0 ip=192.168.122.1 bcast=192.168.122.255 netmask=255.255.255.0
[2018/02/01 12:42:52.702123, 2] ../source3/nmbd/nmbd_subnetdb.c:180(make_subnet)
making subnet name:172.17.1.4 Broadcast address:172.17.255.255 Subnet mask:255.255.0.0
[2018/02/01 12:42:52.702383, 2] ../source3/nmbd/nmbd_subnetdb.c:180(make_subnet)
making subnet name:172.16.1.55 Broadcast address:172.16.255.255 Subnet mask:255.255.0.0
[2018/02/01 12:42:52.702515, 2] ../source3/nmbd/nmbd_subnetdb.c:180(make_subnet)
making subnet name:172.16.1.4 Broadcast address:172.16.255.255 Subnet mask:255.255.0.0
[2018/02/01 12:42:52.702661, 2] ../source3/nmbd/nmbd_subnetdb.c:180(make_subnet)
making subnet name:172.1.1.4 Broadcast address:172.1.255.255 Subnet mask:255.255.0.0
[2018/02/01 12:42:52.702690, 2] ../source3/nmbd/nmbd_subnetdb.c:180(make_subnet)
making subnet name:UNICAST_SUBNET Broadcast address:0.0.0.0 Subnet mask:0.0.0.0
[2018/02/01 12:42:52.702717, 2] ../source3/nmbd/nmbd_subnetdb.c:180(make_subnet)
making subnet name:REMOTE_BROADCAST_SUBNET Broadcast address:0.0.0.0 Subnet mask:0.0.0.0
[2018/02/01 12:42:52.702771, 2] ../source3/nmbd/nmbd_lmhosts.c:43(load_lmhosts_file)
load_lmhosts_file: Can't open lmhosts file /usr/local/samba/etc/lmhosts. Error was No such file or directory
[2018/02/01 12:42:52.703801, 0] ../lib/util/become_daemon.c:124(daemon_ready)
STATUS=daemon 'nmbd' finished starting up and ready to serve connections
[2018/02/01 12:42:52.707865, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response)
query_name_response: Multiple (2) responses received for a query on subnet 172.16.1.4 for name PI5<1d>.
This response was from IP 172.16.1.57, reporting an IP address of 172.16.1.57.
[2018/02/01 12:42:52.708061, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response)
query_name_response: Multiple (2) responses received for a query on subnet 172.16.1.55 for name PI5<1d>.
This response was from IP 172.16.1.57, reporting an IP address of 172.16.1.57.
[2018/02/01 12:42:52.710885, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response)
query_name_response: Multiple (2) responses received for a query on subnet 172.17.1.4 for name PI5<1d>.
This response was from IP 172.17.1.5, reporting an IP address of 172.17.1.5.
[2018/02/01 12:42:52.724314, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response)
query_name_response: Multiple (2) responses received for a query on subnet 172.1.1.4 for name PI5<1d>.
This response was from IP 172.1.1.3, reporting an IP address of 172.1.1.3.
[2018/02/01 12:42:52.760083, 2] ../source3/lib/interface.c:345(add_interface)
added interface eno1 ip=172.1.1.4 bcast=172.1.255.255 netmask=255.255.0.0
[2018/02/01 12:42:52.760125, 2] ../source3/lib/interface.c:345(add_interface)
added interface enp4s0f1 ip=172.16.1.4 bcast=172.16.255.255 netmask=255.255.0.0
[2018/02/01 12:42:52.760193, 2] ../source3/lib/interface.c:345(add_interface)
added interface enp4s0f1 ip=172.16.1.55 bcast=172.16.255.255 netmask=255.255.0.0
[2018/02/01 12:42:52.760208, 2] ../source3/lib/interface.c:345(add_interface)
added interface enp4s0f0 ip=172.17.1.4 bcast=172.17.255.255 netmask=255.255.0.0
[2018/02/01 12:42:52.760221, 2] ../source3/lib/interface.c:345(add_interface)
added interface virbr0 ip=192.168.122.1 bcast=192.168.122.255 netmask=255.255.255.0
[2018/02/01 12:42:52.760474, 1] ../source3/profile/profile_dummy.c:30(set_profile_level)
INFO: Profiling support unavailable in this build.
[2018/02/01 12:42:53.510134, 0] ../source3/nmbd/nmbd_mynames.c:36(my_name_register_failed)
my_name_register_failed: Failed to register my name FILE<20> on subnet 172.17.1.4.
[2018/02/01 12:42:53.510179, 0] ../source3/nmbd/nmbd_namelistdb.c:320(standard_fail_register)
standard_fail_register: Failed to register/refresh name FILE<20> on subnet 172.17.1.4
[2018/02/01 12:42:53.510201, 0] ../source3/nmbd/nmbd_mynames.c:36(my_name_register_failed)
my_name_register_failed: Failed to register my name FILE<03> on subnet 172.17.1.4.
[2018/02/01 12:42:53.510222, 0] ../source3/nmbd/nmbd_namelistdb.c:320(standard_fail_register)
standard_fail_register: Failed to register/refresh name FILE<03> on subnet 172.17.1.4
[2018/02/01 12:42:53.510245, 0] ../source3/nmbd/nmbd_mynames.c:36(my_name_register_failed)
my_name_register_failed: Failed to register my name FILE<00> on subnet 172.17.1.4.
[2018/02/01 12:42:53.510266, 0] ../source3/nmbd/nmbd_namelistdb.c:320(standard_fail_register)
standard_fail_register: Failed to register/refresh name FILE<00> on subnet 172.17.1.4
[2018/02/01 12:42:56.818658, 2] ../source3/nmbd/nmbd_elections.c:111(check_for_master_browser_fail)
check_for_master_browser_fail: Forcing election on workgroup PI5 subnet 192.168.122.1
[2018/02/01 12:42:59.821489, 2] ../source3/nmbd/nmbd_elections.c:41(send_election_dgram)
send_election_dgram: Sending election packet for workgroup PI5 on subnet 192.168.122.1
[2018/02/01 12:43:01.823528, 2] ../source3/nmbd/nmbd_elections.c:41(send_election_dgram)
send_election_dgram: Sending election packet for workgroup PI5 on subnet 192.168.122.1
[2018/02/01 12:43:03.825540, 2] ../source3/nmbd/nmbd_elections.c:41(send_election_dgram)
send_election_dgram: Sending election packet for workgroup PI5 on subnet 192.168.122.1
[2018/02/01 12:43:05.827617, 2] ../source3/nmbd/nmbd_elections.c:41(send_election_dgram)
send_election_dgram: Sending election packet for workgroup PI5 on subnet 192.168.122.1
[2018/02/01 12:43:07.121240, 2] ../source3/nmbd/nmbd_elections.c:41(send_election_dgram)
send_election_dgram: Sending election packet for workgroup PI5 on subnet 192.168.122.1
[2018/02/01 12:43:07.121288, 2] ../source3/nmbd/nmbd_elections.c:201(run_elections)
run_elections: >>> Won election for workgroup PI5 on subnet 192.168.122.1 <<<
[2018/02/01 12:43:07.121311, 2] ../source3/nmbd/nmbd_become_lmb.c:538(become_local_master_browser)
become_local_master_browser: Starting to become a master browser for workgroup PI5 on subnet 192.168.122.1
[2018/02/01 12:43:16.647156, 0] ../source3/nmbd/nmbd_become_lmb.c:397(become_local_master_stage2)
*****
Samba name server FILE is now a local master browser for workgroup PI5 on subnet 192.168.122.1
*****
--
Nicolas Zuber (MSc)
Universität Stuttgart
5. Physikalisches Institut
Pfaffenwaldring 57
D-70569 Stuttgart
Tel.: +49 (0)711 685 64977
More information about the samba
mailing list