Bug 13697 - smbd fails if winbind is running on default intall: create_local_token failed: NT_STATUS_ACCESS_DENIED
smbd fails if winbind is running on default intall: create_local_token failed...
Status: RESOLVED FIXED
Product: Samba 4.1 and newer
Classification: Unclassified
Component: Winbind
4.9.2
All All
: P1 regression
: ---
Assigned To: Karolin Seeger
Samba QA Contact
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2018-11-30 11:36 UTC by Andreas Hasenack
Modified: 2019-01-10 12:40 UTC (History)
6 users (show)

See Also:


Attachments
Log level 10 as requested. (14.08 KB, application/x-gzip)
2018-12-20 09:27 UTC, Louis
no flags Details
Log level 10 as requested. ( 4.9.4 logs ) (13.06 KB, application/x-gzip)
2018-12-20 10:00 UTC, Louis
no flags Details
Patch for v4-9-test (1.81 KB, patch)
2018-12-20 12:45 UTC, Stefan Metzmacher
ab: review+
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Andreas Hasenack 2018-11-30 11:36:08 UTC
With an smb.conf like this:
[global]
	log file = /var/log/samba/log.%m
	logging = file
	map to guest = Bad User
	max log size = 1000
	obey pam restrictions = Yes
	pam password change = Yes
	panic action = /usr/share/samba/panic-action %d
	passwd chat = *Enter\snew\s*\spassword:* %n\n *Retype\snew\s*\spassword:* %n\n *password\supdated\ssuccessfully* .
	passwd program = /usr/bin/passwd %u
	server role = standalone server
	server string = %h server (Samba, Ubuntu)
	unix password sync = Yes
	usershare allow guests = Yes
	idmap config * : backend = tdb


[printers]
	browseable = No
	comment = All Printers
	create mask = 0700
	path = /var/spool/samba
	printable = Yes


[print$]
	comment = Printer Drivers
	path = /var/lib/samba/printers


smbd fails to start if winbind is running already:
[2018/11/30 10:57:37.617273,  0] ../source3/auth/auth_util.c:1382(make_new_session_info_guest)
  create_local_token failed: NT_STATUS_ACCESS_DENIED
[2018/11/30 10:57:37.617377,  0] ../source3/smbd/server.c:2000(main)
  ERROR: failed to setup guest info.


This was mentioned in mailing lists in three threads that I could locate:
- https://lists.samba.org/archive/samba/2018-November/219540.html "Standalone Update 4.8.5 -> 4.9.2 smb fails to start ERROR: failed to setup guest info"
- https://lists.samba.org/archive/samba/2018-October/219059.html "smb.service fails to start after openSUSE Tumbleweed update"
- https://lists.samba.org/archive/samba-technical/2018-September/130369.html "Samba package 4.9.x samba smbd not playing with winbind"

It was suggested to run "net groupmap add sid=S-1-5-32-546 unixgroup=nobody type=builtin", and that indeed works around the issue (or fixes it?):

root@disco-samba49:~# net groupmap add sid=S-1-5-32-546 unixgroup=nobody type=builtin
Successfully added group nobody to the mapping db as a wellknown group

root@disco-samba49:~# net groupmap list
nobody (S-1-5-32-546) -> nobody
root@disco-samba49:~# 

I would like some guidance as to what packaged distributions of samba 4.9 should do. Should we run that comment in some post-install script, or is that something that samba should be doing internally on its own? It's not clear.
Comment 1 Andreas Hasenack 2018-11-30 13:33:15 UTC
Why is smbd behaving differently if winbind is running, when it's a standalone server anyway?
Comment 2 Louis 2018-12-05 07:50:04 UTC
Hai, 

This is happening since 4.9.0.
I've reported this one also at Debian. 
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=909465
The debian links shows more loggins. 

What i noticed. 
On Debian 9 with Debian packages (own/official Debians).

If samba/smbd is installed only, smbd starts with a Guest message in the logs, but it does start. 
If winbind is started, smbd is failing to detect the guest mapping.

Or better said, if winbind is started, the standalone server trying to use a member obligated setting and now it's in need of the line : idmap * range line. And that fails.
Comment 3 Andreas Hasenack 2018-12-05 12:31:30 UTC
> If samba/smbd is installed only, smbd starts with a Guest message in the logs,
> but it does start. 

I didn't see this happening, could you elaborate?

Here when I start 4.9.2 without a running winbind, default debian/ubuntu config, all I see in log.smbd is:

[2018/12/05 12:15:37.275579,  0] ../lib/util/become_daemon.c:138(daemon_ready)
  daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections

And I can connect to a share that allows the guest user just fine. Do you have a higher debug log set perhaps? Do you see other consequences?
Comment 4 Louis 2018-12-07 09:31:08 UTC
Hai, Sure, i have the following. 

Tested on Debian 9, i use the official Debian Samba packages, 4.9.2 from Debian Buster. 

I've done the following steps to reproduce it. 
i've used the default config, no changes, excepted adding the log level. 

apt-get install samba. 

[2018/12/07 10:13:40.034014,  0] ../lib/util/become_daemon.c:138(daemon_ready)
  daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections

===== removed samba again (no purge, needed the smb.conf) , added log level = 1 to smb.conf, install samba again.

===== Stop smbd, start smbd : systemctl stop/start smbd 
[2018/12/07 10:16:30.616965,  1] ../source3/profile/profile_dummy.c:30(set_profile_level)
  INFO: Profiling support unavailable in this build.
[2018/12/07 10:16:30.624770,  0] ../lib/util/become_daemon.c:138(daemon_ready)
  daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections
[2018/12/07 10:16:30.627259,  1] ../source3/printing/printer_list.c:234(printer_list_get_last_refresh)
  Failed to fetch record!

===== Stop samba, remove samba, now install samba and winbind

===== Stop samba and winbind, start samba and winbind
[2018/12/07 10:19:27.204989,  1] ../source3/profile/profile_dummy.c:30(set_profile_level)
  INFO: Profiling support unavailable in this build.
[2018/12/07 10:19:27.213650,  0] ../lib/util/become_daemon.c:138(daemon_ready)
  daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections
[2018/12/07 10:19:27.216095,  1] ../source3/printing/printer_list.c:234(printer_list_get_last_refresh)
  Failed to fetch record!

===== Stop samba and winbind, start samba and winbind with : systemctl start smbd winbind
[2018/12/07 10:20:39.746309,  1] ../source3/profile/profile_dummy.c:30(set_profile_level)
  INFO: Profiling support unavailable in this build.
[2018/12/07 10:20:39.754072,  0] ../source3/auth/auth_util.c:1382(make_new_session_info_guest)
  create_local_token failed: NT_STATUS_ACCESS_DENIED
[2018/12/07 10:20:39.754099,  0] ../source3/smbd/server.c:2000(main)
  ERROR: failed to setup guest info.

And here you go. 
results in : 

systemctl status smbd winbind
● smbd.service - Samba SMB Daemon
   Loaded: loaded (/lib/systemd/system/smbd.service; enabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since Fri 2018-12-07 10:20:39 CET; 4min 34s ago
     Docs: man:smbd(8)
           man:samba(7)
           man:smb.conf(5)
  Process: 16081 ExecStart=/usr/sbin/smbd --foreground --no-process-group $SMBDOPTIONS (code=exited, status=255)
 Main PID: 16081 (code=exited, status=255)

Dec 07 10:20:39 debian9test systemd[1]: Starting Samba SMB Daemon...
Dec 07 10:20:39 debian9test systemd[1]: smbd.service: Main process exited, code=exited, status=255/n/a
Dec 07 10:20:39 debian9test systemd[1]: Failed to start Samba SMB Daemon.
Dec 07 10:20:39 debian9test systemd[1]: smbd.service: Unit entered failed state.
Dec 07 10:20:39 debian9test systemd[1]: smbd.service: Failed with result 'exit-code'.

● winbind.service - Samba Winbind Daemon
   Loaded: loaded (/lib/systemd/system/winbind.service; enabled; vendor preset: enabled)
   Active: active (running) since Fri 2018-12-07 10:20:31 CET; 4min 42s ago
     Docs: man:winbindd(8)
           man:samba(7)
           man:smb.conf(5)
 Main PID: 16074 (winbindd)
   Status: "winbindd: ready to serve connections..."
    Tasks: 3 (limit: 19660)
   CGroup: /system.slice/winbind.service
           ├─16074 /usr/sbin/winbindd --foreground --no-process-group
           ├─16076 winbindd: domain child [DEBIAN9TEST]
           └─16085 winbindd: idmap child

Dec 07 10:20:31 debian9test systemd[1]: Starting Samba Winbind Daemon...
Dec 07 10:20:31 debian9test systemd[1]: Started Samba Winbind Daemon.

A not starting smbd. 

Now for the test, apt-get remove --purge samba samba-* winbind --autoremove and install it again, now with winbind. 
default configs, nothing changed. 

apt-get install samba winbind
Reading package lists... Done
Building dependency tree
Reading state information... Done
The following packages were automatically installed and are no longer required:
  dh-python libpython3.5-minimal libpython3.5-stdlib python3.5 python3.5-minimal
Use 'apt autoremove' to remove them.
The following additional packages will be installed:
  python-samba samba-common samba-common-bin samba-dsdb-modules samba-libs samba-vfs-modules
Suggested packages:
  python-gpgme bind9 bind9utils ctdb ldb-tools ntp | chrony smbldap-tools ufw heimdal-clients libnss-winbind libpam-winbind
Recommended packages:
  libcephfs2
The following NEW packages will be installed:
  python-samba samba samba-common samba-common-bin samba-dsdb-modules samba-libs samba-vfs-modules winbind
0 upgraded, 8 newly installed, 0 to remove and 259 not upgraded.
Need to get 0 B/10.9 MB of archives.
After this operation, 63.9 MB of additional disk space will be used.
Do you want to continue? [Y/n]
Preconfiguring packages ...
Selecting previously unselected package samba-libs:amd64.
(Reading database ... 37701 files and directories currently installed.)
Preparing to unpack .../0-samba-libs_2%3a4.9.2+dfsg-2_amd64.deb ...
Unpacking samba-libs:amd64 (2:4.9.2+dfsg-2) ...
Selecting previously unselected package python-samba.
Preparing to unpack .../1-python-samba_2%3a4.9.2+dfsg-2_amd64.deb ...
Unpacking python-samba (2:4.9.2+dfsg-2) ...
Selecting previously unselected package samba-common.
Preparing to unpack .../2-samba-common_2%3a4.9.2+dfsg-2_all.deb ...
Unpacking samba-common (2:4.9.2+dfsg-2) ...
Selecting previously unselected package samba-common-bin.
Preparing to unpack .../3-samba-common-bin_2%3a4.9.2+dfsg-2_amd64.deb ...
Unpacking samba-common-bin (2:4.9.2+dfsg-2) ...
Selecting previously unselected package samba.
Preparing to unpack .../4-samba_2%3a4.9.2+dfsg-2_amd64.deb ...
Unpacking samba (2:4.9.2+dfsg-2) ...
Selecting previously unselected package samba-dsdb-modules:amd64.
Preparing to unpack .../5-samba-dsdb-modules_2%3a4.9.2+dfsg-2_amd64.deb ...
Unpacking samba-dsdb-modules:amd64 (2:4.9.2+dfsg-2) ...
Selecting previously unselected package samba-vfs-modules:amd64.
Preparing to unpack .../6-samba-vfs-modules_2%3a4.9.2+dfsg-2_amd64.deb ...
Unpacking samba-vfs-modules:amd64 (2:4.9.2+dfsg-2) ...
Selecting previously unselected package winbind.
Preparing to unpack .../7-winbind_2%3a4.9.2+dfsg-2_amd64.deb ...
Unpacking winbind (2:4.9.2+dfsg-2) ...
Setting up samba-libs:amd64 (2:4.9.2+dfsg-2) ...
Setting up samba-vfs-modules:amd64 (2:4.9.2+dfsg-2) ...
Setting up python-samba (2:4.9.2+dfsg-2) ...
Setting up samba-common (2:4.9.2+dfsg-2) ...

Creating config file /etc/samba/smb.conf with new version
Processing triggers for libc-bin (2.27-8) ...
Processing triggers for systemd (232-25+deb9u6) ...
Processing triggers for man-db (2.7.6.1-2) ...
Setting up samba-common-bin (2:4.9.2+dfsg-2) ...
Checking smb.conf with testparm
Load smb config files from /etc/samba/smb.conf
Loaded services file OK.
Server role: ROLE_STANDALONE

Done
Setting up samba-dsdb-modules:amd64 (2:4.9.2+dfsg-2) ...
Setting up winbind (2:4.9.2+dfsg-2) ...
mkdir: created directory '/var/lib/samba/winbindd_privileged'
changed group of '/var/lib/samba/winbindd_privileged' from root to winbindd_priv
mode of '/var/lib/samba/winbindd_privileged' changed from 0755 (rwxr-xr-x) to 0750 (rwxr-x---)
Created symlink /etc/systemd/system/multi-user.target.wants/winbind.service → /lib/systemd/system/winbind.service.
Setting up samba (2:4.9.2+dfsg-2) ...
Samba is not being run as an AD Domain Controller: Masking samba-ad-dc.service
Please ignore the following error about deb-systemd-helper not finding those services.
(samba-ad-dc.service masked)
Job for smbd.service failed because the control process exited with error code.
See "systemctl status smbd.service" and "journalctl -xe" for details.
invoke-rc.d: initscript smbd, action "start" failed.
● smbd.service - Samba SMB Daemon
   Loaded: loaded (/lib/systemd/system/smbd.service; disabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since Fri 2018-12-07 10:27:10 CET; 6ms ago
     Docs: man:smbd(8)
           man:samba(7)
           man:smb.conf(5)
  Process: 17874 ExecStart=/usr/sbin/smbd --foreground --no-process-group $SMBDOPTIONS (code=exited, status=255)
 Main PID: 17874 (code=exited, status=255)

Dec 07 10:27:10 debian9test systemd[1]: Starting Samba SMB Daemon...
Dec 07 10:27:10 debian9test systemd[1]: smbd.service: Main process exited, code=exited, status=255/n/a
Dec 07 10:27:10 debian9test systemd[1]: Failed to start Samba SMB Daemon.
Dec 07 10:27:10 debian9test systemd[1]: smbd.service: Unit entered failed state.
Dec 07 10:27:10 debian9test systemd[1]: smbd.service: Failed with result 'exit-code'.
dpkg: error processing package samba (--configure):
 subprocess installed post-installation script returned error exit status 1
Processing triggers for libc-bin (2.27-8) ...
Processing triggers for systemd (232-25+deb9u6) ...
Errors were encountered while processing:
 samba
E: Sub-process /usr/bin/dpkg returned an error code (1)

if you need more, or higher debug levels, let me know.

The problem is in winbind and the guest mappings. 
smbd thinks that if winbind is installed its a domain member, at least thats what it looks like.
Comment 5 Andreas Hasenack 2018-12-10 11:49:50 UTC
I don't see an error regarding guest info when starting smbd *without* winbind running already:
===== Stop smbd, start smbd : systemctl stop/start smbd 
[2018/12/07 10:16:30.616965,  1] ../source3/profile/profile_dummy.c:30(set_profile_level)
  INFO: Profiling support unavailable in this build.
[2018/12/07 10:16:30.624770,  0] ../lib/util/become_daemon.c:138(daemon_ready)
  daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections
[2018/12/07 10:16:30.627259,  1] ../source3/printing/printer_list.c:234(printer_list_get_last_refresh)
  Failed to fetch record!

That "Failed" msg is something else. The guest setup error only happens when winbind is running before smbd is started, as stated in this bug.
Comment 6 Andrew Bartlett 2018-12-16 04:57:02 UTC
This bug is blocking Ubuntu from using Samba 4.9 and will likely cause issues getting Samba into the next Debian stable.
Comment 7 Stefan Metzmacher 2018-12-19 06:41:35 UTC
Can someone please provide level 10 logs from smbd and winbindd?
Comment 8 Louis 2018-12-20 09:27:18 UTC
Created attachment 14750 [details]
Log level 10 as requested.

hai, 

attached a log level 10 of the startup.. 

The steps i took.
( debian buster packages ) 

apt install samba winbind
- winbind starts smbd not. 
- stopped winbind.
- cleared logs.
- start winbind
- start smbd
- stopped smbd winbind
Comment 9 Louis 2018-12-20 09:33:42 UTC
but wait with spending a lot of time. 

https://bugzilla.samba.org/show_bug.cgi?id=12164 
May have fixed it also, im buildin 4.9.4 package as we speak. 


I'll report the result.
Comment 10 Louis 2018-12-20 10:00:55 UTC
Created attachment 14751 [details]
Log level 10 as requested. ( 4.9.4 logs )

Same steps as before, but now with 4.9.4.
Comment 11 Stefan Metzmacher 2018-12-20 12:45:52 UTC
Created attachment 14752 [details]
Patch for v4-9-test

This seems to be a 4.9 only bug introduced by

commit 0b261dc4e3f2d04131e1ff76a017aaee6e38e7b1
Author:     Stefan Metzmacher <metze@samba.org>
AuthorDate: Tue Mar 6 23:26:28 2018 +0100
Commit:     Andreas Schneider <asn@cryptomilk.org>
CommitDate: Mon Mar 19 20:30:49 2018 +0100

    s3:auth: make use of create_builtin_guests() in finalize_local_nt_token()

    This makes the Builtin_Guests handling more dynamic,
    by having a persistent storage for the memberships.

    Signed-off-by: Stefan Metzmacher <metze@samba.org>
    Reviewed-by: Andreas Schneider <asn@samba.org>
Comment 12 Alexander Bokovoy 2018-12-20 13:24:19 UTC
Comment on attachment 14752 [details]
Patch for v4-9-test

LGTM.
Comment 13 Louis 2018-12-20 16:02:29 UTC
I've just created a new package set with this patch includes and looks fixed to me now. 

No errors at install and/or startup, so look good to me. 

Thanks for the quick patch, i'll test a bit more before i use it.
Comment 14 Andreas Hasenack 2018-12-21 13:16:36 UTC
Tested in Ubuntu and also looks fixed. Thanks!
Comment 15 Karolin Seeger 2019-01-08 11:53:42 UTC
Pushed to autobuild-v4-9-test.
Comment 16 Karolin Seeger 2019-01-10 12:40:53 UTC
(In reply to Karolin Seeger from comment #15)
Pushed to v4-9-test.
Closing out bug report.

Thanks!