Univention Bugzilla – Bug 43144
Samba: Multiple issues (4.1)
Last modified: 2016-12-19 14:43:53 CET
A security update for Samba is planned for Monday, December 19: * NDR Parsing ndr_pull_dnsp_name Heap-based Buffer Overflow Remote Code Execution Vulnerability (CVE-2016-2123) * Unconditional privilege delegation to Kerberos servers in trusted realms (CVE-2016-2125) * Flaws in Kerberos PAC validation can trigger privilege elevation (CVE-2016-2126)
I've re-built samba with the patches to 4.5.2 and 4.5.3. Initial tests looked good. The advisory doesn't mention any details yet.
*** Bug 43132 has been marked as a duplicate of this bug. ***
OK - patches OK - samba version 4.5-3 OK - window client join (win7, win8) OK - windows logon OK - univention-s4search, drs repl OK - kerberos OK - GPO's OK - share access TODO update jenkins tests
jenkins tests look good, but there is a problem with the update UCS 4.1-4 master with samba4, then i updated to the new samba packages. After that univention-s4search fails -> univention-s4search Failed to connect to ldap URL 'ldaps://master.four.test' - LDAP client internal error: NT_STATUS_CONNECTION_REFUSED Failed to connect to 'ldaps://master.four.test' with backend 'ldaps': (null) Failed to connect to ldaps://master.four.test - (null) even if i wait 1h, univention-s4search fails smbclient works -> smbclient //master/sysvol -UAdministrator Enter Administrator's password: Domain=[FOUR] OS=[Windows 6.1] Server=[Samba 4.5.3-Debian] smb: \> after samba restart, univention-s4search works
Yes, ldbsearch only works against localhost, not against the host IP, strange. smbclient works on both interfaces though.
I can reproduce t [2016/12/14 13:59:13.122929, 3, pid=16154, effective(0, 0), real(0, 0)] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) Kerberos: TGS-REQ authtime: 2016-12-14T13:59:12 starttime: 2016-12-14T13:59:13 endtime: 2016-12-14T23:59:12 renew till: unset [2016/12/14 13:59:13.127615, 3, pid=16154, effective(0, 0), real(0, 0)] ../source4/smbd/service_stream.c:66(stream_terminate_connection) Terminating connection - 'kdc_tcp_call_loop: tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED' [2016/12/14 13:59:13.127692, 3, pid=16154, effective(0, 0), real(0, 0)] ../source4/smbd/process_single.c:114(single_terminate) single_terminate: reason[kdc_tcp_call_loop: tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED] [2016/12/14 13:59:13.127792, 10, pid=16154, effective(0, 0), real(0, 0)] ../source3/lib/messages_dgm_ref.c:142(msg_dgm_ref_destructor) msg_dgm_ref_destructor: refs=0x562a679e2ef0 [2016/12/14 13:59:13.816622, 4, pid=16152, effective(0, 0), real(0, 0)] ../source4/lib/socket/interface.c:121(add_interface) added interface lo ip=::1 bcast= netmask=ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff [2016/12/14 13:59:13.816795, 4, pid=16152, effective(0, 0), real(0, 0)] ../source4/lib/socket/interface.c:121(add_interface) added interface lo ip=127.0.0.1 bcast=127.255.255.255 netmask=255.0.0.0 [2016/12/14 13:59:13.817224, 3, pid=16152, effective(0, 0), real(0, 0)] ../lib/util/util_net.c:256(interpret_string_addr_internal) interpret_string_addr_internal: getaddrinfo failed for name eth0 (flags 32) [Name or service not known] [2016/12/14 13:59:13.817306, 2, pid=16152, effective(0, 0), real(0, 0)] ../source4/lib/socket/interface.c:195(interpret_interface) interpret_interface: Can't find address for eth0 debug=10 -> "getaddrinfo failed for name eth0"
(In reply to Felix Botner from comment #6) > I can reproduce t > > [2016/12/14 13:59:13.122929, 3, pid=16154, effective(0, 0), real(0, 0)] > ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) > Kerberos: TGS-REQ authtime: 2016-12-14T13:59:12 starttime: > 2016-12-14T13:59:13 endtime: 2016-12-14T23:59:12 renew till: unset > [2016/12/14 13:59:13.127615, 3, pid=16154, effective(0, 0), real(0, 0)] > ../source4/smbd/service_stream.c:66(stream_terminate_connection) > Terminating connection - 'kdc_tcp_call_loop: tstream_read_pdu_blob_recv() > - NT_STATUS_CONNECTION_DISCONNECTED' > [2016/12/14 13:59:13.127692, 3, pid=16154, effective(0, 0), real(0, 0)] > ../source4/smbd/process_single.c:114(single_terminate) > single_terminate: reason[kdc_tcp_call_loop: tstream_read_pdu_blob_recv() - > NT_STATUS_CONNECTION_DISCONNECTED] > [2016/12/14 13:59:13.127792, 10, pid=16154, effective(0, 0), real(0, 0)] > ../source3/lib/messages_dgm_ref.c:142(msg_dgm_ref_destructor) > msg_dgm_ref_destructor: refs=0x562a679e2ef0 > [2016/12/14 13:59:13.816622, 4, pid=16152, effective(0, 0), real(0, 0)] > ../source4/lib/socket/interface.c:121(add_interface) > added interface lo ip=::1 bcast= > netmask=ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff > [2016/12/14 13:59:13.816795, 4, pid=16152, effective(0, 0), real(0, 0)] > ../source4/lib/socket/interface.c:121(add_interface) > added interface lo ip=127.0.0.1 bcast=127.255.255.255 netmask=255.0.0.0 > [2016/12/14 13:59:13.817224, 3, pid=16152, effective(0, 0), real(0, 0)] > ../lib/util/util_net.c:256(interpret_string_addr_internal) > interpret_string_addr_internal: getaddrinfo failed for name eth0 (flags > 32) [Name or service not known] > [2016/12/14 13:59:13.817306, 2, pid=16152, effective(0, 0), real(0, 0)] > ../source4/lib/socket/interface.c:195(interpret_interface) > interpret_interface: Can't find address for eth0 > > debug=10 -> "getaddrinfo failed for name eth0" this is the restart during the update
I've added some debugging messages to Samba. Bug even in your environment I cannot reproduce it, even though I also used "apt-get update; apt-get dselect-upgrade; apt-get dist-upgrade" to update. If you try it again, please set the samba/debug/level at least to 2 before updating.
We also have a separate report for winbindd (samba3) failing to start in UCS@school Jenkins, but only in the 4.0 to 4.1 updated ImportTests: UCSschool 4.0 to 4.1 Singleserver/ImportTests=ImportTests,SambaVersion=s3/ws/autotest-205-ucsschool-singleserver-s3.log =========================================================================== The following packages will be upgraded: univention-directory-manager-tools,python-univention-directory-manager,python-univention-directory-manager-cli,python-univention-connector-s4,samba-vfs-modules,samba-dsdb-modules,slapd,ldap-utils,libldap-2.4-2,winbind,libwbclient0,samba,samba-common-bin,smbclient,samba-common,libsmbclient,python-samba,samba-libs,univention-kernel-image,linux-libc-dev,univention-management-console-module-join,univention-join,univention-ssl,univention-mail-postfix Starting package upgrade ERROR: update failed. Please check /var/log/univention/updater.log =========================================================================== and ws/updater.log shows: =========================================================================== Vorbereitung zum Ersetzen von winbind 2:4.5.1-1.848.201611070734 (durch .../winbind_2%3a4.5.1-1.849.201612142005_amd64.deb) ... [...] ucs-school-umc-wizards (8.0.0-14.149.201611171707) wird eingerichtet ... Calling joinscript 38ucs-school-umc-wizards.inst ... 2016-12-14 19:11:23.208427560-05:00 (in joinscript_init) [...] samba (2:4.5.1-1.849.201612142005) wird eingerichtet ... Starting SMB/CIFS daemon: smbd. Starting NetBIOS name server: nmbd. Samba is not configured as AD DC. winbind (2:4.5.1-1.849.201612142005) wird eingerichtet ... Starting the Winbind daemon: winbind failed! invoke-rc.d: initscript winbind, action "start" failed. dpkg: Fehler beim Bearbeiten von winbind (--configure): Unterprozess installiertes post-installation-Skript gab den Fehlerwert 1 zurück [...] univention-join (8.0.4-7.521.201612071726) wird eingerichtet ... File: /etc/logrotate.d/univention-join Calling joinscript 20univention-join.inst ... 2016-12-14 19:12:06.738252002-05:00 (in joinscript_init) =========================================================================== So this happens between 19:11:23.208427560-05:00 and 19:12:06.738252002-05:00. In that time range log.winbindd shows *no* output (last entry before is at 19:19:04.272473 and the next after is at 19:21:15.880862). To compare, log.smbd shows some of our new debug output in that time range. So this looks like a different issue than the "getaddrinfo failed for name eth0" in Comment 6. Daniel noted that there is a slapd restart visible in syslog at (about) that time, but the autotest-205-ucsschool-singleserver-s3.log shows that the winbind start fails again two times after that, so it's unlikely that there is any correlation. I'm just spinning up a Jenkins test to see what's going on.
I think that the update of univention-basefiles is causing this. The univention-basefiles.postinst seems to run shortly after the samba.postinst and it seems to ifdown/up eth0 somehow. This is the full story of my research: These two messages have also been reported once in Ubuntu and there it was due to networkmanager not having the interface up in time for samba https://bugs.launchpad.net/ubuntu/+source/samba/+bug/836849 : * interpret_string_addr_internal: getaddrinfo failed for name eth0 (flags 32) [Name or service not known] * interpret_interface: Can't find address for eth0 And there you go, in Felix VM-snapshot I find these messages in syslog: ============================================================================= Dec 14 13:59:12 master named[9930]: received control channel command 'reload' [...] Dec 14 13:59:13 master ntpd[6293]: Deleting interface #7 eth0, fe80::5054:ff:feb0:56d7#123, interface stats: received=0, sent=0, dropped=0, active_time=1225 secs Dec 14 13:59:13 master ntpd[6293]: Deleting interface #3 eth0, 10.200.7.80#123, interface stats: received=0, sent=0, dropped=0, active_time=1225 secs Dec 14 13:59:13 master ntpd[6293]: peers refreshed ============================================================================= So at least ntpd also noticed an interface change in the same second. Let's look at /var/log/dpkg.log, shall we? ============================================================================= 2016-12-14 13:59:05 status unpacked samba:amd64 2:4.5.1-1.849.201612121623 2016-12-14 13:59:05 status half-configured samba:amd64 2:4.5.1-1.849.201612121623 2016-12-14 13:59:06 status installed samba:amd64 2:4.5.1-1.849.201612121623 [...] 2016-12-14 13:59:07 status unpacked univention-base-files:all 5.0.1-6.222.201612051558 2016-12-14 13:59:07 status half-configured univention-base-files:all 5.0.1-6.222.201612051558 2016-12-14 13:59:28 status triggers-awaited univention-base-files:all 5.0.1-6.222.201612051558 ============================================================================= So let's look at univention-base-files.postinst. There is a call to univention-config-registry register univention-base-files When I run that on my machine, I get: ============================================================================= File: /etc/modprobe.d/vmgfx.conf Multifile: /etc/network/interfaces Reloading bind9 daemon: ...samba4...done. Restarting Name Service Cache Daemon: nscd. Reloading bind9 daemon: ...samba4...done. Stopping univention-s4-connector daemon. done. Starting univention-s4-connector daemon. done. Reloading bind9 daemon: ...samba4...done. Reloading bind9 daemon: ...samba4...done. File: /etc/dhcp/dhclient.conf Restarting Name Service Cache Daemon: nscd. Restarting Univention Management Console Server. done. Reloading bind9 daemon: ...samba4...done. Reloading bind9 daemon: ...samba4...done. File: /etc/rsyslog.conf ============================================================================= Ok, let's stat the files in Felix VM-snapshot to narrow down the time interval: ============================================================================= root@master:~# stat /etc/modprobe.d/vmgfx.conf Datei: „/etc/modprobe.d/vmgfx.conf“ Größe: 653 Blöcke: 8 EA Block: 4096 reguläre Datei Gerät: fd00h/64768d Inode: 2355742 Verknüpfungen: 1 Zugriff: (0644/-rw-r--r--) Uid: ( 0/ root) Gid: ( 0/ root) Zugriff : 2016-12-14 13:59:24.006261000 +0100 Modifiziert: 2016-12-14 13:59:11.146261000 +0100 Geändert : 2016-12-14 13:59:11.146261000 +0100 Geburt : - root@master:~# stat /etc/network/interfaces Datei: „/etc/network/interfaces“ Größe: 684 Blöcke: 8 EA Block: 4096 reguläre Datei Gerät: fd00h/64768d Inode: 2355826 Verknüpfungen: 1 Zugriff: (0644/-rw-r--r--) Uid: ( 0/ root) Gid: ( 0/ root) Zugriff : 2016-12-14 13:59:18.250261000 +0100 Modifiziert: 2016-12-14 13:59:18.242261000 +0100 Geändert : 2016-12-14 13:59:18.242261000 +0100 Geburt : - root@master:~# stat /etc/rsyslog.conf Datei: „/etc/rsyslog.conf“ Größe: 3413 Blöcke: 8 EA Block: 4096 reguläre Datei Gerät: fd00h/64768d Inode: 2355931 Verknüpfungen: 1 Zugriff: (0644/-rw-r--r--) Uid: ( 0/ root) Gid: ( 0/ root) Zugriff : 2016-12-14 13:59:23.822261000 +0100 Modifiziert: 2016-12-14 13:59:23.994261000 +0100 Geändert : 2016-12-14 13:59:23.994261000 +0100 Geburt : - ============================================================================= From all of this, I have the impression that "something" is causing temporary interruption for eth0. Bug 32481 might be related. Apart from that, it's a bit surprising that the Samba daemons are taking so long to start up, that univention-basefiles has enough time to interfere: ============================================================================= [2016/12/14 13:59:06.488595, 0, pid=16096, effective(0, 0), real(0, 0)] ../source4/smbd/server.c:372(binary_smbd_main) samba version 4.5.3-Debian started. Copyright Andrew Tridgell and the Samba Team 1992-2016 ============================================================================= That's 6.64 seconds between start of samba and interface bind of the samba ldap_server process. Note that each of the 12 samba services (plus the forked smbd and winbind processes probably) do their own interface detection. Each of them could be hit by this!! The possible error scenarios are endless. All of this matches with my experience when trying to reproduce this in Felix VM: Two times, when I used "apt-get update; apt-get dselect-upgrade; apt-get dist-upgrade" to update, my ssh-connection to that VM terminated in the middle of the update. Since I was connected from home office via VPN I didn't think too much about it, but now it seems related. Also it matches my experience with UCS-updates of one of my VMs, where the SSH-connection would often terminate in the middle of a release update (univention-upgrade run without screen).
Comment 10 refers to to the univention-s4search issue reported by Felix in Comment 6. I'd say we can only do one thing now to avoid this during this update: adjust samba.postinst to sleep 10 seconds after the start of the daemons. I think I will even put it permanently, without any version checks, because waiting 10 seconds during update is *much* better than running into this randomly at some later errata update. Now about the winbindd issue of Comment 9: I was able to reproduce that in the Samba3 UCS@school singleserver Jenkins test. Basically it's unrelated and I opened Bug 43192 for it. But we need a workaround for it. I've adjusted winbind.postinst to stop any running winbinds before the DEBHELPER block which adds the winbind start. The package is compiling and the advisory is updated.
I've opened Bug 43193 for Comment 10, this needs to be fixed.
FAIL - samba postinst, we now wait 10s in samba.postinst, i don't understand this. I can't reproduce this anymore, but as it happened, i could have waited for hours and the situation would not have changed, only a samba restart helped? OK - windbind, postinst stops windbindd before starting
Come on, you read Comment 10, didn't you? Look into the updater.log of your snapshot, you see that samba.postinst runs and after that univention-base-files.postinst runs, which runs "univention-config-registry register univention-base-files". During that command eth0 when down for a short time and this cooincided with the start of the Samba ldap_server process. Now the samba.postinst waits 10 seconds after the samba-ad-dc start to avoid the ensuing eth0 if-up/down happening shortly after. My solution is not curing the problem after it happened (as in your case), it's avoiding it in the first place. If you disagree open another bug for that.
> Look into the updater.log of your snapshot Ah, actually you cannot, because you didn't use univention-upgrade, but apt-get dist-upgrade instead, which made debugging this unnecessary hard. Please avoid that by any means.
(In reply to Arvid Requate from comment #15) > > Look into the updater.log of your snapshot > > Ah, actually you cannot, because you didn't use univention-upgrade, but > apt-get dist-upgrade instead, which made debugging this unnecessary hard. > Please avoid that by any means. Ever heard of /var/log/apt/term.log? Gbb onq HPF hfrf "lrg nabgure iraqbe fcrpvsvp fbyhgvba"...
ok, ok, finally i got it ... sleep in the samba.postinst should buy the daemons enough time to start properly, before a univention-base-files update can mess with the interfaces
> Ever heard of /var/log/apt/term.log? Thanks, much appreciated. > Gbb onq HPF hfrf "lrg nabgure iraqbe fcrpvsvp fbyhgvba".. Jryy, gb or snve gurl ner whfg n jenccre sbe gur naablvat fcyvg orgjrra ncg-trg hcqngr naq ncg-trg [qvfg-hctenqr|vafgnyy]. Gurl pbzr va unaql.
<http://errata.software-univention.de/ucs/4.1/360.html>