thr3ads.net - samba - [Samba] Upgrading a ctdb cluster: samba not listening on TCP port 445 [Feb 2018]

If this information is useful, please help other people find it:
Share via:

Nicolas Zuber

2018-Feb-01 12:11 UTC

[Samba] Upgrading a ctdb cluster: samba not listening on TCP port 445

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,
> martinHi 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

Martin Schwenke

2018-Feb-02 09:27 UTC

head link

[Samba] Upgrading a ctdb cluster: samba not listening on TCP port 445

On Thu, 1 Feb 2018 13:11:58 +0100, Nicolas Zuber via samba
<samba at lists.samba.org> wrote:
> 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).
Now the guesses get more esoteric.  :-)

What do you see if you run "ss -tlnp src :445" as root?

I see smbd listening on both IPv4 and IPv6:

LISTEN     0      50
*:445                                  *:*
users:(("smbd",pid=2315,fd=36)) LISTEN     0
50                      :::445                                 :::*
users:(("smbd",pid=2315,fd=34))

If you see smbd listening on port 445 then what happens if you run:

# ctdb checktcpport 445
Failed to bind to TCP port 445

It should fail to bind, which is what CTDB's monitor event looks for
when testing to see smbd is listing on the port.

peace & happiness,
martin

Nicolas Zuber

2018-Feb-05 12:43 UTC

head link

[Samba] Upgrading a ctdb cluster: samba not listening on TCP port 445

Am Fr 02.02.2018 um 10:27 schrieb Martin Schwenke:> On Thu, 1 Feb 2018 13:11:58 +0100, Nicolas Zuber via samba
> <samba at lists.samba.org> wrote:
> 
>> 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).
> 
> Now the guesses get more esoteric.  :-)
> 
> What do you see if you run "ss -tlnp src :445" as root?
> 
> I see smbd listening on both IPv4 and IPv6:
> 
> LISTEN     0      50
> *:445                                  *:*
> users:(("smbd",pid=2315,fd=36)) LISTEN     0
> 50                      :::445                                 :::*
> users:(("smbd",pid=2315,fd=34))
> 
> If you see smbd listening on port 445 then what happens if you run:
> 
> # ctdb checktcpport 445
> Failed to bind to TCP port 445
> 
> It should fail to bind, which is what CTDB's monitor event looks for
> when testing to see smbd is listing on the port.
> 
> peace & happiness,
> martin
> 
Hello Martin,

Thank you very much for your help. When using the commands you 
suggested, it showed that samba was not listing on port 445 and ctdb 
checktcpport 445 did not fail. Somehow the upgrade process to 4.7.1 
worked after several tries and I tried to figure out why. During the 
investigation I found out that the smbd process failed after one minute 
(before that I was probably not patient enough to see smbd fail), 
reporting that samba 4.7.1 was running and it refused to start 4.7.4 (at 
this time I tried to directly upgrade to 4.7.4):

[2018/02/04 20:18:16.968393,  0] 
../source3/smbd/server.c:1532(smbd_claim_version)
Feb  4 20:18:16 fileb smbd[5835]:  smbd_claim_version: smbd 4.7.1 
already running, refusing to start version 4.7.4

The next thing was to stop ctdb on both file servers to do an offline 
upgrade. This worked fine without any problems. So it seems that a 
rolling upgrade from 4.7.1 to 4.7.4 did not work in my case in contrast 
to the information on the samba wiki:"For releases within a minor 
version (i.e. X.Y.Z to X.Y.Z'), rolling upgrades will work unless 
otherwise stated.". I could not find any information in the release 
notes that rolling upgrades do not work, but next time I will try to do 
an offline upgrade first.

Thank you for your time and help.

peace & happiness,
Nicolas

Seemingly Similar Threads

Search for more seemingly similar threads

samba - Feb 2018 - Upgrading a ctdb cluster: samba not listening on TCP port 445

[Samba] Upgrading a ctdb cluster: samba not listening on TCP port 445

[Samba] Upgrading a ctdb cluster: samba not listening on TCP port 445

[Samba] Upgrading a ctdb cluster: samba not listening on TCP port 445

Seemingly Similar Threads