SOLVED Service SMB can not start after upgrade from FreeNAS11.2-U1 to FreeNAS11.2-U2

tobiasbp

Patron
Joined
Dec 2, 2015
Messages
238
Hello there...

I just updated a FreeNAS server from 11.2-U1 to 11.2-U2.

I can no longer start the SMB service. My users are in LDAP.

EDIT:
The problem was fixed by adding Adding winbind nested groups = no in section auxiliary parameter under Services->SMB. Thank you @anodos.

Something is going wrong with the mapping of user IDs as far as I can tell? Any thoughts?

This is what I get in /var/log/samb4/log.smbd:
Code:
[2019/02/25 12:25:47.765122,  3] ../source3/smbd/server.c:1842(main)
  Becoming a daemon.
[2019/02/25 12:25:47.767435,  2] ../source3/passdb/pdb_ldap_util.c:281(smbldap_search_domain_info)
  smbldap_search_domain_info: Searching for:[(&(objectClass=sambaDomain)(sambaDomainName=ZFS_ULTRAMAN))]
[2019/02/25 12:25:47.817732,  3] ../source3/lib/smbldap.c:632(smbldap_start_tls)
  StartTLS issued: using a TLS connection
[2019/02/25 12:25:47.817788,  2] ../source3/lib/smbldap.c:847(smbldap_open_connection)
  smbldap_open_connection: connection opened
[2019/02/25 12:25:47.827892,  3] ../source3/lib/smbldap.c:1069(smbldap_connect_system)
  ldap_connect_system: successful connection to the LDAP server
[2019/02/25 12:25:47.979475,  3] ../source3/lib/util_procid.c:54(pid_to_procid)
  pid_to_procid: messaging_dgm_get_unique failed: No such file or directory
[2019/02/25 12:25:47.982172,  2] ../source3/passdb/pdb_ldap_util.c:281(smbldap_search_domain_info)
  smbldap_search_domain_info: Searching for:[(&(objectClass=sambaDomain)(sambaDomainName=ZFS_ULTRAMAN))]
[2019/02/25 12:25:47.990562,  3] ../source3/lib/smbldap.c:632(smbldap_start_tls)
  StartTLS issued: using a TLS connection
[2019/02/25 12:25:47.990626,  2] ../source3/lib/smbldap.c:847(smbldap_open_connection)
  smbldap_open_connection: connection opened
[2019/02/25 12:25:47.996891,  2] ../source3/passdb/pdb_ldap_util.c:281(smbldap_search_domain_info)
  smbldap_search_domain_info: Searching for:[(&(objectClass=sambaDomain)(sambaDomainName=ZFS_ULTRAMAN))]
[2019/02/25 12:25:48.005126,  3] ../source3/lib/smbldap.c:632(smbldap_start_tls)
  StartTLS issued: using a TLS connection
[2019/02/25 12:25:48.005218,  2] ../source3/lib/smbldap.c:847(smbldap_open_connection)
  smbldap_open_connection: connection opened
[2019/02/25 12:25:48.005653,  3] ../source3/lib/smbldap.c:1069(smbldap_connect_system)
  ldap_connect_system: successful connection to the LDAP server
[2019/02/25 12:25:48.021043,  3] ../source3/lib/smbldap.c:1069(smbldap_connect_system)
  ldap_connect_system: successful connection to the LDAP server
[2019/02/25 12:25:48.036973,  3] ../source3/lib/smbldap.c:632(smbldap_start_tls)
  StartTLS issued: using a TLS connection
[2019/02/25 12:25:48.037043,  2] ../source3/lib/smbldap.c:847(smbldap_open_connection)
  smbldap_open_connection: connection opened
[2019/02/25 12:25:48.051993,  3] ../source3/lib/smbldap.c:1069(smbldap_connect_system)
  ldap_connect_system: successful connection to the LDAP server
[2019/02/25 12:25:48.052787,  2] ../source3/passdb/pdb_ldap.c:2386(init_group_from_ldap)
  init_group_from_ldap: Entry found for group: 90000005
[2019/02/25 12:25:48.053792,  2] ../source3/passdb/pdb_ldap.c:2386(init_group_from_ldap)
  init_group_from_ldap: Entry found for group: 90000006
[2019/02/25 12:25:48.107401,  3] ../source3/passdb/pdb_ldap.c:5210(ldapsam_gid_to_sid)
  ERROR: Got 0 entries for gid 90000016, expected one
[2019/02/25 12:25:48.108434,  0] ../source3/groupdb/mapping.c:863(pdb_create_builtin_alias)
  pdb_create_builtin_alias: Could not add group mapping entry for alias 546 (NT_STATUS_ACCESS_DENIED)
[2019/02/25 12:25:48.108496,  2] ../source3/auth/token_util.c:774(finalize_local_nt_token)
  Failed to create BUILTIN\Guests group NT_STATUS_ACCESS_DENIED!  Can Winbind allocate gids?
[2019/02/25 12:25:48.108529,  3] ../source3/auth/token_util.c:412(create_local_nt_token_from_info3)
  Failed to finalize nt token
[2019/02/25 12:25:48.108557,  0] ../source3/auth/auth_util.c:1382(make_new_session_info_guest)
  create_local_token failed: NT_STATUS_ACCESS_DENIED
[2019/02/25 12:25:48.108590,  0] ../source3/smbd/server.c:2000(main)
  ERROR: failed to setup guest info.


This is mu SAMBA config (I have no shares as I deleted them to simplify the setup):
Code:
testparm -s

Registered MSG_REQ_POOL_USAGE
Registered MSG_REQ_DMALLOC_MARK and LOG_CHANGED
Load smb config files from /usr/local/etc/smb4.conf
Loaded services file OK.
Server role: ROLE_DOMAIN_PDC

# Global parameters
[global]
    deadtime = 15
    disable spoolss = Yes
    dns proxy = No
    domain logons = Yes
    dos charset = CP437
    hostname lookups = Yes
    kernel change notify = No
    ldap admin dn = *****
    ldap passwd sync = yes
    ldap suffix = ***
    lm announce = Yes
    load printers = No
    local master = No
    logging = file
    max log size = 51200
    max open files = 6603833
    nsupdate command = /usr/local/bin/samba-nsupdate -g
    obey pam restrictions = Yes
    panic action = /usr/local/libexec/samba/samba-backtrace
    passdb backend = ldapsam:ldap://ldap.example.com
    printcap name = /dev/null
    security = USER
    server min protocol = SMB2_02
    server role = member server
    server string = FreeNAS Server
    workgroup = ZFS_ULTRAMAN
    idmap config zfs_ultraman: range = 10000-90000000
    idmap config zfs_ultraman: backend = ldap
    ldapsam:trusted = yes
    idmap config *: range = 90000001-100000000
    idmap config * : backend = tdb
    acl allow execute always = Yes
    create mask = 0666
    directory mask = 0777
    directory name cache size = 0
    dos filemode = Yes
    strict locking = No
 
Last edited:

anodos

Sambassador
iXsystems
Joined
Mar 6, 2014
Messages
9,544
Hello there...

I just updated a FreeNAS server from 11.2-U1 to 11.2-U2.

I can no longer start the SMB service. My users are in LDAP.

Something is going wrong with the mapping of user IDs as far as I can tell? Any thoughts?

This is what I get in /var/log/samb4/log.smbd:
Code:
[2019/02/25 12:25:47.765122,  3] ../source3/smbd/server.c:1842(main)
  Becoming a daemon.
[2019/02/25 12:25:47.767435,  2] ../source3/passdb/pdb_ldap_util.c:281(smbldap_search_domain_info)
  smbldap_search_domain_info: Searching for:[(&(objectClass=sambaDomain)(sambaDomainName=ZFS_ULTRAMAN))]
[2019/02/25 12:25:47.817732,  3] ../source3/lib/smbldap.c:632(smbldap_start_tls)
  StartTLS issued: using a TLS connection
[2019/02/25 12:25:47.817788,  2] ../source3/lib/smbldap.c:847(smbldap_open_connection)
  smbldap_open_connection: connection opened
[2019/02/25 12:25:47.827892,  3] ../source3/lib/smbldap.c:1069(smbldap_connect_system)
  ldap_connect_system: successful connection to the LDAP server
[2019/02/25 12:25:47.979475,  3] ../source3/lib/util_procid.c:54(pid_to_procid)
  pid_to_procid: messaging_dgm_get_unique failed: No such file or directory
[2019/02/25 12:25:47.982172,  2] ../source3/passdb/pdb_ldap_util.c:281(smbldap_search_domain_info)
  smbldap_search_domain_info: Searching for:[(&(objectClass=sambaDomain)(sambaDomainName=ZFS_ULTRAMAN))]
[2019/02/25 12:25:47.990562,  3] ../source3/lib/smbldap.c:632(smbldap_start_tls)
  StartTLS issued: using a TLS connection
[2019/02/25 12:25:47.990626,  2] ../source3/lib/smbldap.c:847(smbldap_open_connection)
  smbldap_open_connection: connection opened
[2019/02/25 12:25:47.996891,  2] ../source3/passdb/pdb_ldap_util.c:281(smbldap_search_domain_info)
  smbldap_search_domain_info: Searching for:[(&(objectClass=sambaDomain)(sambaDomainName=ZFS_ULTRAMAN))]
[2019/02/25 12:25:48.005126,  3] ../source3/lib/smbldap.c:632(smbldap_start_tls)
  StartTLS issued: using a TLS connection
[2019/02/25 12:25:48.005218,  2] ../source3/lib/smbldap.c:847(smbldap_open_connection)
  smbldap_open_connection: connection opened
[2019/02/25 12:25:48.005653,  3] ../source3/lib/smbldap.c:1069(smbldap_connect_system)
  ldap_connect_system: successful connection to the LDAP server
[2019/02/25 12:25:48.021043,  3] ../source3/lib/smbldap.c:1069(smbldap_connect_system)
  ldap_connect_system: successful connection to the LDAP server
[2019/02/25 12:25:48.036973,  3] ../source3/lib/smbldap.c:632(smbldap_start_tls)
  StartTLS issued: using a TLS connection
[2019/02/25 12:25:48.037043,  2] ../source3/lib/smbldap.c:847(smbldap_open_connection)
  smbldap_open_connection: connection opened
[2019/02/25 12:25:48.051993,  3] ../source3/lib/smbldap.c:1069(smbldap_connect_system)
  ldap_connect_system: successful connection to the LDAP server
[2019/02/25 12:25:48.052787,  2] ../source3/passdb/pdb_ldap.c:2386(init_group_from_ldap)
  init_group_from_ldap: Entry found for group: 90000005
[2019/02/25 12:25:48.053792,  2] ../source3/passdb/pdb_ldap.c:2386(init_group_from_ldap)
  init_group_from_ldap: Entry found for group: 90000006
[2019/02/25 12:25:48.107401,  3] ../source3/passdb/pdb_ldap.c:5210(ldapsam_gid_to_sid)
  ERROR: Got 0 entries for gid 90000016, expected one
[2019/02/25 12:25:48.108434,  0] ../source3/groupdb/mapping.c:863(pdb_create_builtin_alias)
  pdb_create_builtin_alias: Could not add group mapping entry for alias 546 (NT_STATUS_ACCESS_DENIED)
[2019/02/25 12:25:48.108496,  2] ../source3/auth/token_util.c:774(finalize_local_nt_token)
  Failed to create BUILTIN\Guests group NT_STATUS_ACCESS_DENIED!  Can Winbind allocate gids?
[2019/02/25 12:25:48.108529,  3] ../source3/auth/token_util.c:412(create_local_nt_token_from_info3)
  Failed to finalize nt token
[2019/02/25 12:25:48.108557,  0] ../source3/auth/auth_util.c:1382(make_new_session_info_guest)
  create_local_token failed: NT_STATUS_ACCESS_DENIED
[2019/02/25 12:25:48.108590,  0] ../source3/smbd/server.c:2000(main)
  ERROR: failed to setup guest info.


This is mu SAMBA config (I have no shares as I deleted them to simplify the setup):
Code:
testparm -s

Registered MSG_REQ_POOL_USAGE
Registered MSG_REQ_DMALLOC_MARK and LOG_CHANGED
Load smb config files from /usr/local/etc/smb4.conf
Loaded services file OK.
Server role: ROLE_DOMAIN_PDC

# Global parameters
[global]
    deadtime = 15
    disable spoolss = Yes
    dns proxy = No
    domain logons = Yes
    dos charset = CP437
    hostname lookups = Yes
    kernel change notify = No
    ldap admin dn = *****
    ldap passwd sync = yes
    ldap suffix = ***
    lm announce = Yes
    load printers = No
    local master = No
    logging = file
    max log size = 51200
    max open files = 6603833
    nsupdate command = /usr/local/bin/samba-nsupdate -g
    obey pam restrictions = Yes
    panic action = /usr/local/libexec/samba/samba-backtrace
    passdb backend = ldapsam:ldap://ldap.example.com
    printcap name = /dev/null
    security = USER
    server min protocol = SMB2_02
    server role = member server
    server string = FreeNAS Server
    workgroup = ZFS_ULTRAMAN
    idmap config zfs_ultraman: range = 10000-90000000
    idmap config zfs_ultraman: backend = ldap
    ldapsam:trusted = yes
    idmap config *: range = 90000001-100000000
    idmap config * : backend = tdb
    acl allow execute always = Yes
    create mask = 0666
    directory mask = 0777
    directory name cache size = 0
    dos filemode = Yes
    strict locking = No
This is due to a change in how smbd starts in 4.9.4, failure to intialize the guest account is considered a fatal error and results in the samba server failing to start. See here: https://redmine.ixsystems.com/issues/76269 The user in the redmine ticket posted a workaround.

I have been unable to reproduce in my own LDAP environment. Out of curiousity, can you send me a debug before you fix the problem? Also, can you perhaps try changing the server role to "standalone" (using nano/vi/whatever), then run service samba_server restart
 

tobiasbp

Patron
Joined
Dec 2, 2015
Messages
238
Apologies, apparently that's still a private bug. The workaround is

Thank you for the suggestion, but I really don't wan't my FreeNAS to (potentially) write to my LDAP server. I guess I must roll back to 11.2-U1. This is a rather severe regression in our setup.

It sound like the problem is, that the guest account is not in LDAP, and the fix allows FreeNAS to create it? Do you think I could fix the problem by adding the account to LDAP myself? I tried to configure the guest account as one of my LDAP users, but that did not fix the problem (Same error).
 
Last edited:

anodos

Sambassador
iXsystems
Joined
Mar 6, 2014
Messages
9,544
Do you still want these before I roll back?
Yes please. You are the second user that has pinged me about issues regarding this. I will switch to devoting significant time to reproducing internally. I understand that it's not acceptable. Did you try switching to "standalone"? What happens if you switch the guest account to an LDAP user (under services->SMB)?

Hopefully I can have a fix in by U3.
 

tobiasbp

Patron
Joined
Dec 2, 2015
Messages
238
What happens if you switch the guest account to an LDAP user (under services->SMB)?

Changing the guest account to an LDAP user, does not fix the problem. However, there is an interesting (?) chnage in the log:

With the LDAP user as the guest account, I get errors for all the LDAP users:
Code:
...
...
[2019/02/25 13:56:47.746591,  3] ../source3/passdb/pdb_ldap.c:5210(ldapsam_gid_to_sid)
  ERROR: Got 0 entries for gid 1105, expected one
[2019/02/25 13:56:47.747707,  3] ../source3/passdb/pdb_ldap.c:5210(ldapsam_gid_to_sid)
  ERROR: Got 0 entries for gid 1312, expected one
[2019/02/25 13:56:47.748779,  3] ../source3/passdb/pdb_ldap.c:5210(ldapsam_gid_to_sid)
  ERROR: Got 0 entries for gid 1101, expected one
[2019/02/25 13:56:47.749699,  3] ../source3/passdb/pdb_ldap.c:5210(ldapsam_gid_to_sid)
  ERROR: Got 0 entries for gid 1112, expected one
...
...


This is the full log when trying to start the service with the guest account as 'nobody' (in the GUI):
Code:
[2019/02/25 14:03:05.914047,  3] ../source3/param/loadparm.c:3876(lp_load_ex)
  lp_load_ex: refreshing parameters
[2019/02/25 14:03:05.914168,  3] ../source3/param/loadparm.c:548(init_globals)
  Initialising global parameters
[2019/02/25 14:03:05.914331,  3] ../source3/param/loadparm.c:2790(lp_do_section)
  Processing section "[global]"
[2019/02/25 14:03:05.915213,  3] ../source3/param/loadparm.c:1625(lp_add_ipc)
  adding IPC service
[2019/02/25 14:03:05.915491,  2] ../source3/lib/interface.c:345(add_interface)
  added interface igb0 ip=172.22.33.17 bcast=172.22.33.255 netmask=255.255.255.0
[2019/02/25 14:03:05.915572,  2] ../source3/lib/interface.c:345(add_interface)
  added interface igb0 ip=172.22.33.34 bcast=172.22.33.255 netmask=255.255.255.0
[2019/02/25 14:03:05.915648,  3] ../source3/smbd/server.c:1810(main)
  loaded services
[2019/02/25 14:03:05.915793,  1] ../source3/profile/profile_dummy.c:30(set_profile_level)
  INFO: Profiling support unavailable in this build.
[2019/02/25 14:03:05.915840,  3] ../source3/smbd/server.c:1842(main)
  Becoming a daemon.
[2019/02/25 14:03:05.918508,  2] ../source3/passdb/pdb_ldap_util.c:281(smbldap_search_domain_info)
  smbldap_search_domain_info: Searching for:[(&(objectClass=sambaDomain)(sambaDomainName=ZFS_ULTRAMAN))]
[2019/02/25 14:03:05.968444,  3] ../source3/lib/smbldap.c:632(smbldap_start_tls)
  StartTLS issued: using a TLS connection
[2019/02/25 14:03:05.968525,  2] ../source3/lib/smbldap.c:847(smbldap_open_connection)
  smbldap_open_connection: connection opened
[2019/02/25 14:03:05.978412,  3] ../source3/lib/smbldap.c:1069(smbldap_connect_system)
  ldap_connect_system: successful connection to the LDAP server
[2019/02/25 14:03:06.134148,  3] ../source3/lib/util_procid.c:54(pid_to_procid)
  pid_to_procid: messaging_dgm_get_unique failed: No such file or directory
[2019/02/25 14:03:06.137193,  2] ../source3/passdb/pdb_ldap_util.c:281(smbldap_search_domain_info)
  smbldap_search_domain_info: Searching for:[(&(objectClass=sambaDomain)(sambaDomainName=ZFS_ULTRAMAN))]
[2019/02/25 14:03:06.143556,  3] ../source3/lib/smbldap.c:632(smbldap_start_tls)
  StartTLS issued: using a TLS connection
[2019/02/25 14:03:06.143629,  2] ../source3/lib/smbldap.c:847(smbldap_open_connection)
  smbldap_open_connection: connection opened
[2019/02/25 14:03:06.151097,  2] ../source3/passdb/pdb_ldap_util.c:281(smbldap_search_domain_info)
  smbldap_search_domain_info: Searching for:[(&(objectClass=sambaDomain)(sambaDomainName=ZFS_ULTRAMAN))]
[2019/02/25 14:03:06.153430,  3] ../source3/lib/smbldap.c:1069(smbldap_connect_system)
  ldap_connect_system: successful connection to the LDAP server
[2019/02/25 14:03:06.157710,  3] ../source3/lib/smbldap.c:632(smbldap_start_tls)
  StartTLS issued: using a TLS connection
[2019/02/25 14:03:06.157803,  2] ../source3/lib/smbldap.c:847(smbldap_open_connection)
  smbldap_open_connection: connection opened
[2019/02/25 14:03:06.167416,  3] ../source3/lib/smbldap.c:1069(smbldap_connect_system)
  ldap_connect_system: successful connection to the LDAP server
[2019/02/25 14:03:06.183178,  3] ../source3/lib/smbldap.c:632(smbldap_start_tls)
  StartTLS issued: using a TLS connection
[2019/02/25 14:03:06.183260,  2] ../source3/lib/smbldap.c:847(smbldap_open_connection)
  smbldap_open_connection: connection opened
[2019/02/25 14:03:06.193163,  3] ../source3/lib/smbldap.c:1069(smbldap_connect_system)
  ldap_connect_system: successful connection to the LDAP server
[2019/02/25 14:03:06.194163,  2] ../source3/passdb/pdb_ldap.c:2386(init_group_from_ldap)
  init_group_from_ldap: Entry found for group: 90000005
[2019/02/25 14:03:06.195058,  2] ../source3/passdb/pdb_ldap.c:2386(init_group_from_ldap)
  init_group_from_ldap: Entry found for group: 90000006
[2019/02/25 14:03:06.243154,  3] ../source3/passdb/pdb_ldap.c:5210(ldapsam_gid_to_sid)
  ERROR: Got 0 entries for gid 90000022, expected one
[2019/02/25 14:03:06.243931,  0] ../source3/groupdb/mapping.c:863(pdb_create_builtin_alias)
  pdb_create_builtin_alias: Could not add group mapping entry for alias 546 (NT_STATUS_ACCESS_DENIED)
[2019/02/25 14:03:06.244016,  2] ../source3/auth/token_util.c:774(finalize_local_nt_token)
  Failed to create BUILTIN\Guests group NT_STATUS_ACCESS_DENIED!  Can Winbind allocate gids?
[2019/02/25 14:03:06.244057,  3] ../source3/auth/token_util.c:412(create_local_nt_token_from_info3)
  Failed to finalize nt token
[2019/02/25 14:03:06.244103,  0] ../source3/auth/auth_util.c:1382(make_new_session_info_guest)
  create_local_token failed: NT_STATUS_ACCESS_DENIED
[2019/02/25 14:03:06.244165,  0] ../source3/smbd/server.c:2000(main)
  ERROR: failed to setup guest info.
 

tobiasbp

Patron
Joined
Dec 2, 2015
Messages
238
This is what I get in /var/log/samba4/log.smbd when trying to launch the service. Logging is set to level DEBUG.
 

Attachments

  • samba_can_not_start_with_users_from_ldap_freenas_11.2-U2.txt
    50.1 KB · Views: 575

tobiasbp

Patron
Joined
Dec 2, 2015
Messages
238
Also, can you perhaps try changing the server role to "standalone" (using nano/vi/whatever), then run service samba_server restart

Using a text editor, I edited the file /usr/local/etc/smb4.conf

I changed the line "server role = member server" to "server role = standalone server" and restartet the service from the CLI using "service samba_server restart". This do not fix the error. End of log below:
Code:
...
...
  smbldap_make_mod: adding attribute |sambaSid| value |S-1-5-32-546|
[2019/02/25 14:29:36.947774, 10, pid=64089, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:521(smbldap_make_mod_internal)
  smbldap_make_mod: adding attribute |sambaGroupType| value |4|
[2019/02/25 14:29:36.947813, 10, pid=64089, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:521(smbldap_make_mod_internal)
  smbldap_make_mod: adding attribute |displayName| value |Guests|
[2019/02/25 14:29:36.947850, 10, pid=64089, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:521(smbldap_make_mod_internal)
  smbldap_make_mod: adding attribute |gidNumber| value |90000029|
[2019/02/25 14:29:36.947887,  5, pid=64089, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:1546(smbldap_add)
  smbldap_add: dn => [sambaSid=S-1-5-32-546,dc=example,dc=com]
[2019/02/25 14:29:36.948510, 10, pid=64089, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:1573(smbldap_add)
  Failed to add dn: sambaSid=S-1-5-32-546,dc=example,dc=com, error: 53 (Server is unwilling to perform) (shadow context; no update referral)
[2019/02/25 14:29:36.948564,  0, pid=64089, effective(0, 0), real(0, 0)] ../source3/groupdb/mapping.c:863(pdb_create_builtin_alias)
  pdb_create_builtin_alias: Could not add group mapping entry for alias 546 (NT_STATUS_ACCESS_DENIED)
[2019/02/25 14:29:36.948602,  5, pid=64089, effective(0, 0), real(0, 0)] ../source3/passdb/pdb_util.c:201(create_builtin_guests)
  create_builtin_guests: Failed to create Guests
[2019/02/25 14:29:36.948654,  4, pid=64089, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:438(pop_sec_ctx)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2019/02/25 14:29:36.948690,  2, pid=64089, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:774(finalize_local_nt_token)
  Failed to create BUILTIN\Guests group NT_STATUS_ACCESS_DENIED!  Can Winbind allocate gids?
[2019/02/25 14:29:36.948725,  3, pid=64089, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:412(create_local_nt_token_from_info3)
  Failed to finalize nt token
[2019/02/25 14:29:36.948757,  0, pid=64089, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth_util.c:1382(make_new_session_info_guest)
  create_local_token failed: NT_STATUS_ACCESS_DENIED
[2019/02/25 14:29:36.948801,  0, pid=64089, effective(0, 0), real(0, 0)] ../source3/smbd/server.c:2000(main)
  ERROR: failed to setup guest info.
 

tobiasbp

Patron
Joined
Dec 2, 2015
Messages
238
Can you provide output of tdbdump /var/db/samba4/winbindd_idmap.tdb

Code:
tdbdump /var/db/samba4/winbindd_idmap.tdb

{
key(13) = "GID 90000002\00"
data(8) = "S-1-5-2\00"
}
{
key(9) = "USER HWM\00"
data(4) = "\81J]\05"
}
{
key(8) = "S-1-1-0\00"
data(13) = "GID 90000001\00"
}
{
key(8) = "S-1-5-2\00"
data(13) = "GID 90000002\00"
}
{
key(10) = "GROUP HWM\00"
data(4) = "\9FJ]\05"
}
{
key(14) = "IDMAP_VERSION\00"
data(4) = "\02\00\00\00"
}
{
key(13) = "GID 90000001\00"
data(8) = "S-1-1-0\00"
}
 

tobiasbp

Patron
Joined
Dec 2, 2015
Messages
238
What is the output of net groupmap list?

Code:
# net groupmap list

wifi-cph (S-1-5-21-2270781224-3932256268-732302752-3209) -> wifi-cph
xxxx-wifi-cph-guest (S-1-5-21-2270781224-3932256268-732302752-3211) -> xxxxt-wifi-cph-guest
clients-write (S-1-5-21-2270781224-3932256268-732302752-513) -> clients-write
Administrators (S-1-5-32-544) -> 90000005
Users (S-1-5-32-545) -> 90000006
clients-access (S-1-5-21-2270781224-3932256268-732302752-3017) -> clients-access
another-access (S-1-5-21-2270781224-3932256268-732302752-3253) -> another-access
another-write (S-1-5-21-2270781224-3932256268-732302752-3255) -> another-write
another-wifi-cph (S-1-5-21-2270781224-3932256268-732302752-3269) -> another-wifi-cph
another-wifi-cph-guest (S-1-5-21-2270781224-3932256268-732302752-3257) -> another-wifi-cph-guest
kp-dir-amo (S-1-5-21-2270781224-3932256268-732302752-3259) -> kp-dir-amo
kp-dir-finance (S-1-5-21-2270781224-3932256268-732302752-3261) -> kp-dir-finance
kp-dir-it (S-1-5-21-2270781224-3932256268-732302752-3263) -> kp-dir-it
kp-dir-reports (S-1-5-21-2270781224-3932256268-732302752-3131) -> kp-dir-reports
kp-resources-access (S-1-5-21-2270781224-3932256268-732302752-3265) -> kp-resources-access
kp-resources-fonts (S-1-5-21-2270781224-3932256268-732302752-3057) -> kp-resources-fonts
kp-resources-logos (S-1-5-21-2270781224-3932256268-732302752-3059) -> kp-resources-logos
kp-resources-software (S-1-5-21-2270781224-3932256268-732302752-3177) -> kp-resources-software
kp-resources-templates (S-1-5-21-2270781224-3932256268-732302752-3267) -> kp-resources-templates
kp-resources-colours (S-1-5-21-2270781224-3932256268-732302752-3179) -> kp-resources-colours
workbook-upload (S-1-5-21-2270781224-3932256268-732302752-3271) -> workbook-upload
kp-dir-xxxx (S-1-5-21-2270781224-3932256268-732302752-3273) -> kp-dir-xxxx
 

anodos

Sambassador
iXsystems
Joined
Mar 6, 2014
Messages
9,544
I'm curious what will happen if you temporarily turn off LDAP and start samba. This will cause winbind to allocate GIDs for BUILTIN\Guests. Then stop samba, and re-enable LDAP.
 

tobiasbp

Patron
Joined
Dec 2, 2015
Messages
238
I'm curious what will happen if you temporarily turn off LDAP and start samba. This will cause winbind to allocate GIDs for BUILTIN\Guests. Then stop samba, and re-enable LDAP.

A: Directory Services -> LDAP -> Remove checkmark from box "Enable"
B: Services -> SMB -> Start (smbd IS running now)
C: Services -> SMB -> Stop
D: Directory Services -> LDAP -> Add checkmark to box "Enable"
B: Services -> SMB -> Start (smbd NOT running now)

So, it did not fix the problem. Log seen below:

Code:
...
...
[2019/02/25 15:00:53.582959,  4, pid=79169, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_ldap.c:2513(ldapsam_getgroup)
  ldapsam_getgroup: Did not find group, filter was (&(objectClass=sambaGroupMapping)(sambaSID=S-1-5-32-546))
[2019/02/25 15:00:53.583017,  4, pid=79169, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:216(push_sec_ctx)
  push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2019/02/25 15:00:53.583059,  4, pid=79169, effective(0, 0), real(0, 0)] ../source3/smbd/uid.c:527(push_conn_ctx)
  push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2019/02/25 15:00:53.583104,  4, pid=79169, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:320(set_sec_ctx_internal)
  setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2019/02/25 15:00:53.583150,  5, pid=79169, effective(0, 0), real(0, 0)] ../libcli/security/security_token.c:53(security_token_debug)
  Security token: (NULL)
[2019/02/25 15:00:53.583195,  5, pid=79169, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:850(debug_unix_user_token)
  UNIX token of user 0
  Primary group is 0 and contains 0 supplementary groups
[2019/02/25 15:00:53.583297,  5, pid=79169, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:1308(smbldap_search_ext)
  smbldap_search_ext: base => [dc=kontrapunkt,dc=com], filter => [(&(sambaSid=S-1-5-32-546)(|(objectClass=sambaGroupMapping)(objectClass=sambaSamAccount)))], scope => [2]
[2019/02/25 15:00:53.584563, 10, pid=79169, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_ldap.c:5056(ldapsam_sid_to_id)
  Got 0 entries, expected one
[2019/02/25 15:00:53.585123, 10, pid=79169, effective(0, 0), real(0, 0)] ../source3/groupdb/mapping.c:814(pdb_create_builtin_alias)
  Trying to create builtin alias 546
[2019/02/25 15:00:53.585204, 10, pid=79169, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1061(lookup_sid)
  lookup_sid called for SID 'S-1-5-32-546'
[2019/02/25 15:00:53.585273, 10, pid=79169, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:813(check_dom_sid_to_level)
  Accepting SID S-1-5-32 in level 1
[2019/02/25 15:00:53.585326, 10, pid=79169, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:574(lookup_rids)
  lookup_rids called for domain sid 'S-1-5-32'
[2019/02/25 15:00:53.585389, 10, pid=79169, effective(0, 0), real(0, 0)] ../source3/passdb/lookup_sid.c:1096(lookup_sid)
  Sid S-1-5-32-546 -> BUILTIN\Guests(4)
[2019/02/25 15:00:53.602971, 10, pid=79169, effective(0, 0), real(0, 0)] ../source3/groupdb/mapping.c:843(pdb_create_builtin_alias)
  Creating alias Guests with gid 90000034
[2019/02/25 15:00:53.603067,  5, pid=79169, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:1308(smbldap_search_ext)
  smbldap_search_ext: base => [dc=kontrapunkt,dc=com], filter => [(sambaSid=S-1-5-32-546)], scope => [2]
[2019/02/25 15:00:53.605038,  5, pid=79169, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:1308(smbldap_search_ext)
  smbldap_search_ext: base => [dc=kontrapunkt,dc=com], filter => [(&(gidNumber=90000034)(objectClass=sambaGroupMapping))], scope => [2]
[2019/02/25 15:00:53.606107,  3, pid=79169, effective(0, 0), real(0, 0), class=passdb] ../source3/passdb/pdb_ldap.c:5210(ldapsam_gid_to_sid)
  ERROR: Got 0 entries for gid 90000034, expected one
[2019/02/25 15:00:53.606171, 10, pid=79169, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:521(smbldap_make_mod_internal)
  smbldap_make_mod: adding attribute |objectClass| value |sambaSidEntry|
[2019/02/25 15:00:53.606221, 10, pid=79169, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:521(smbldap_make_mod_internal)
  smbldap_make_mod: adding attribute |objectClass| value |sambaGroupMapping|
[2019/02/25 15:00:53.606283, 10, pid=79169, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:521(smbldap_make_mod_internal)
  smbldap_make_mod: adding attribute |sambaSid| value |S-1-5-32-546|
[2019/02/25 15:00:53.606343, 10, pid=79169, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:521(smbldap_make_mod_internal)
  smbldap_make_mod: adding attribute |sambaGroupType| value |4|
[2019/02/25 15:00:53.606406, 10, pid=79169, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:521(smbldap_make_mod_internal)
  smbldap_make_mod: adding attribute |displayName| value |Guests|
[2019/02/25 15:00:53.606463, 10, pid=79169, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:521(smbldap_make_mod_internal)
  smbldap_make_mod: adding attribute |gidNumber| value |90000034|
[2019/02/25 15:00:53.606523,  5, pid=79169, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:1546(smbldap_add)
  smbldap_add: dn => [sambaSid=S-1-5-32-546,dc=kontrapunkt,dc=com]
[2019/02/25 15:00:53.607297, 10, pid=79169, effective(0, 0), real(0, 0)] ../source3/lib/smbldap.c:1573(smbldap_add)
  Failed to add dn: sambaSid=S-1-5-32-546,dc=kontrapunkt,dc=com, error: 53 (Server is unwilling to perform) (shadow context; no update referral)
[2019/02/25 15:00:53.607373,  0, pid=79169, effective(0, 0), real(0, 0)] ../source3/groupdb/mapping.c:863(pdb_create_builtin_alias)
  pdb_create_builtin_alias: Could not add group mapping entry for alias 546 (NT_STATUS_ACCESS_DENIED)
[2019/02/25 15:00:53.607434,  5, pid=79169, effective(0, 0), real(0, 0)] ../source3/passdb/pdb_util.c:201(create_builtin_guests)
  create_builtin_guests: Failed to create Guests
[2019/02/25 15:00:53.607510,  4, pid=79169, effective(0, 0), real(0, 0)] ../source3/smbd/sec_ctx.c:438(pop_sec_ctx)
  pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2019/02/25 15:00:53.607558,  2, pid=79169, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:774(finalize_local_nt_token)
  Failed to create BUILTIN\Guests group NT_STATUS_ACCESS_DENIED!  Can Winbind allocate gids?
[2019/02/25 15:00:53.607611,  3, pid=79169, effective(0, 0), real(0, 0)] ../source3/auth/token_util.c:412(create_local_nt_token_from_info3)
  Failed to finalize nt token
[2019/02/25 15:00:53.607668,  0, pid=79169, effective(0, 0), real(0, 0), class=auth] ../source3/auth/auth_util.c:1382(make_new_session_info_guest)
  create_local_token failed: NT_STATUS_ACCESS_DENIED
[2019/02/25 15:00:53.607723,  0, pid=79169, effective(0, 0), real(0, 0)] ../source3/smbd/server.c:2000(main)
  ERROR: failed to setup guest info.
 

tobiasbp

Patron
Joined
Dec 2, 2015
Messages
238
Are you able to for testing purposes create a guest group in your LDAP environment with a SID value of S-1-5-32-546?

I can not set he sambaSID on my groups in LDAP through the GUI (FusionDirectory) I'm using. I can make the group, but can't set the sambaSID myself. I don't feel comfortable poking around in the LDAP database with the cli tools.
 

anodos

Sambassador
iXsystems
Joined
Mar 6, 2014
Messages
9,544
I think this behavior really doesn't make sense in an LDAP environment.
I can not set he sambaSID on my groups in LDAP through the GUI (FusionDirectory) I'm using. I can make the group, but can't set the sambaSID myself. I don't feel comfortable poking around in the LDAP database with the cli tools.
No problem. I have something to work with now. Thank you.
 

anodos

Sambassador
iXsystems
Joined
Mar 6, 2014
Messages
9,544
I'm wondering what behaviour you are referring to? Mine?
I've been hopping between computers. That was a partially written reply, that I then wrote a response on top of without realizing. The weird behavior is trying to write to LDAP when initializing the local guest account.
 
Top