[Samba] No longer access to shares after upgrade to 4.17.3

Ingo Asche foren at asche-rz.de
Fri Nov 25 23:32:38 UTC 2022 

After updating from 4.17.3+dfsg-1 to dfsg-2 changed sadly nothing.

Before that a user miraculously was working again.

Here's a log (level 10) from accessing a share on my member server:
[2022/11/26 00:13:22.692897,  5, pid=40466, effective(10032, 30058), 
real(10032, 0)] 
../../libcli/security/security_token.c:51(security_token_debug)
   Security token SIDs (23):
     SID[  0]: S-1-5-21-2244708279-3181442824-414010930-1124
     SID[  1]: S-1-5-21-2244708279-3181442824-414010930-513
     SID[  2]: S-1-5-21-2244708279-3181442824-414010930-1177
     SID[  3]: S-1-5-21-2244708279-3181442824-414010930-1173
     SID[  4]: S-1-5-21-2244708279-3181442824-414010930-1165
     SID[  5]: S-1-5-21-2244708279-3181442824-414010930-16604
     SID[  6]: S-1-5-21-2244708279-3181442824-414010930-16616
     SID[  7]: S-1-18-1
     SID[  8]: S-1-1-0
     SID[  9]: S-1-5-2
     SID[ 10]: S-1-5-11
     SID[ 11]: S-1-5-32-545
     SID[ 12]: S-1-22-1-10025
     SID[ 13]: S-1-22-2-30058
     SID[ 14]: S-1-22-2-30004
     SID[ 15]: S-1-22-2-30060
     SID[ 16]: S-1-22-2-30073
     SID[ 17]: S-1-22-2-30046
     SID[ 18]: S-1-22-2-30097
     SID[ 19]: S-1-22-2-3003
     SID[ 20]: S-1-22-2-3004
     SID[ 21]: S-1-22-2-3006
     SID[ 22]: S-1-22-2-3001
    Privileges (0x               0):
    Rights (0x               0):
[2022/11/26 00:13:22.695227,  5, pid=40466, effective(10032, 30058), 
real(10032, 0)] ../../source3/auth/token_util.c:873(debug_unix_user_token)
   UNIX token of user 10025
   Primary group is 30058 and contains 10 supplementary groups
   Group[  0]: 30058
   Group[  1]: 30004
   Group[  2]: 30060
   Group[  3]: 30073
   Group[  4]: 30046
   Group[  5]: 30097
   Group[  6]: 3003
   Group[  7]: 3004
   Group[  8]: 3006
   Group[  9]: 3001
[2022/11/26 00:13:22.696402,  4, pid=40466, effective(10025, 30058), 
real(10025, 0), class=vfs] ../../source3/smbd/vfs.c:938(vfs_ChDir)
   vfs_ChDir to /srv/samba/data
[2022/11/26 00:13:22.696639,  0, pid=40466, effective(10025, 30058), 
real(10025, 0)] ../../source3/smbd/smb2_service.c:168(chdir_current_service)
   chdir_current_service: vfs_ChDir(/srv/samba/data) failed: Permission 
denied. Current token: uid=10025, gid=30058, 10 groups: 30058 30004 
30060 30073 30046 30097 3003 3004 3006 3001
[2022/11/26 00:13:22.697005,  3, pid=40466, effective(10025, 30058), 
real(10025, 0), class=smb2] 
../../source3/smbd/smb2_server.c:3955(smbd_smb2_request_error_ex)
   smbd_smb2_request_error_ex: smbd_smb2_request_error_ex: idx[1] 
status[NT_STATUS_ACCESS_DENIED] || at ../../source3/smbd/smb2_server.c:3247
[2022/11/26 00:13:22.697266, 10, pid=40466, effective(10025, 30058), 
real(10025, 0), class=smb2] 
../../source3/smbd/smb2_server.c:3841(smbd_smb2_request_done_ex)
   smbd_smb2_request_done_ex: mid [12918] idx[1] 
status[NT_STATUS_ACCESS_DENIED] body[8] dyn[yes:1] at 
../../source3/smbd/smb2_server.c:4005
[2022/11/26 00:13:22.697429, 10, pid=40466, effective(10025, 30058), 
real(10025, 0), class=smb2_credits] 
../../source3/smbd/smb2_server.c:969(smb2_set_operation_credit)
   smb2_set_operation_credit: smb2_set_operation_credit: requested 1, 
charge 1, granted 1, current possible/max 8074/8192, total 
granted/max/low/range 119/8192/12919/119
[2022/11/26 00:13:22.698385, 10, pid=40466, effective(10025, 30058), 
real(10025, 0), class=smb2] 
../../source3/smbd/smb2_server.c:4995(smbd_smb2_io_handler)
   smbd_smb2_request idx[1] of 5 vectors
[2022/11/26 00:13:22.698607, 10, pid=40466, effective(10025, 30058), 
real(10025, 0), class=smb2_credits] 
../../source3/smbd/smb2_server.c:712(smb2_validate_sequence_number)
   smb2_validate_sequence_number: smb2_validate_sequence_number: 
clearing id 12919 (position 4727) from bitmap
[2022/11/26 00:13:22.698764, 10, pid=40466, effective(10025, 30058), 
real(10025, 0), class=smb2] 
../../source3/smbd/smb2_server.c:2980(smbd_smb2_request_dispatch)
   smbd_smb2_request_dispatch: opcode[SMB2_OP_LOGOFF] mid = 12919
[2022/11/26 00:13:22.698917,  4, pid=40466, effective(10025, 30058), 
real(10025, 0)] ../../source3/smbd/sec_ctx.c:317(set_sec_ctx_internal)
   setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2022/11/26 00:13:22.699048,  5, pid=40466, effective(10025, 30058), 
real(10025, 0)] 
../../libcli/security/security_token.c:47(security_token_debug)
   Security token: (NULL)
[2022/11/26 00:13:22.699280,  5, pid=40466, effective(10025, 30058), 
real(10025, 0)] ../../source3/auth/token_util.c:873(debug_unix_user_token)
   UNIX token of user 0
   Primary group is 0 and contains 0 supplementary groups
[2022/11/26 00:13:22.699996,  5, pid=40466, effective(0, 0), real(0, 0)] 
../../source3/smbd/uid.c:494(smbd_change_to_root_user)
   change_to_root_user: now uid=(0,0) gid=(0,0)
[2022/11/26 00:13:22.700379,  4, pid=40466, effective(0, 0), real(0, 0)] 
../../source3/smbd/sec_ctx.c:206(push_sec_ctx)
   push_sec_ctx(0, 0) : sec_ctx_stack_ndx = 1
[2022/11/26 00:13:22.700527,  4, pid=40466, effective(0, 0), real(0, 0)] 
../../source3/smbd/uid.c:566(push_conn_ctx)
   push_conn_ctx(0) : conn_ctx_stack_ndx = 0
[2022/11/26 00:13:22.700654,  4, pid=40466, effective(0, 0), real(0, 0)] 
../../source3/smbd/sec_ctx.c:317(set_sec_ctx_internal)
   setting sec ctx (0, 0) - sec_ctx_stack_ndx = 1
[2022/11/26 00:13:22.700788,  5, pid=40466, effective(0, 0), real(0, 0)] 
../../libcli/security/security_token.c:47(security_token_debug)
   Security token: (NULL)
[2022/11/26 00:13:22.700911,  5, pid=40466, effective(0, 0), real(0, 0)] 
../../source3/auth/token_util.c:873(debug_unix_user_token)
   UNIX token of user 0
   Primary group is 0 and contains 0 supplementary groups
[2022/11/26 00:13:22.701168, 10, pid=40466, effective(0, 0), real(0, 0), 
class=tdb] ../../source3/lib/gencache.c:333(gencache_del)
   Deleting cache entry (key=[RA/d548a3c6-696a-11ed-8dd4-00012e588206])
[2022/11/26 00:13:22.701401,  4, pid=40466, effective(0, 0), real(0, 0)] 
../../source3/smbd/sec_ctx.c:443(pop_sec_ctx)
   pop_sec_ctx (0, 0) - sec_ctx_stack_ndx = 0
[2022/11/26 00:13:22.701547, 10, pid=40466, effective(0, 0), real(0, 0), 
class=smb2] 
../../source3/smbd/smb2_sesssetup.c:1342(smbd_smb2_logoff_shutdown_done)
   smbd_smb2_logoff_shutdown_done: Deletion from remote arch cache failed
[2022/11/26 00:13:22.701676,  4, pid=40466, effective(0, 0), real(0, 0)] 
../../source3/smbd/sec_ctx.c:317(set_sec_ctx_internal)
   setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2022/11/26 00:13:22.701811,  5, pid=40466, effective(0, 0), real(0, 0)] 
../../libcli/security/security_token.c:47(security_token_debug)
   Security token: (NULL)
[2022/11/26 00:13:22.701932,  5, pid=40466, effective(0, 0), real(0, 0)] 
../../source3/auth/token_util.c:873(debug_unix_user_token)
   UNIX token of user 0
   Primary group is 0 and contains 0 supplementary groups
[2022/11/26 00:13:22.702245,  5, pid=40466, effective(0, 0), real(0, 0)] 
../../source3/smbd/uid.c:494(smbd_change_to_root_user)
   change_to_root_user: now uid=(0,0) gid=(0,0)
[2022/11/26 00:13:22.702423,  4, pid=40466, effective(0, 0), real(0, 0), 
class=vfs] ../../source3/smbd/vfs.c:938(vfs_ChDir)
   vfs_ChDir to /srv/samba/data
[2022/11/26 00:13:22.702684,  5, pid=40466, effective(0, 0), real(0, 0), 
class=vfs] ../../source3/smbd/vfs.c:1000(vfs_ChDir)
   vfs_ChDir: vfs_ChDir got /srv/samba/data
[2022/11/26 00:13:22.702837,  4, pid=40466, effective(0, 0), real(0, 0)] 
../../source3/smbd/sec_ctx.c:317(set_sec_ctx_internal)
   setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2022/11/26 00:13:22.702963,  5, pid=40466, effective(0, 0), real(0, 0)] 
../../libcli/security/security_token.c:47(security_token_debug)
   Security token: (NULL)
[2022/11/26 00:13:22.703095,  5, pid=40466, effective(0, 0), real(0, 0)] 
../../source3/auth/token_util.c:873(debug_unix_user_token)
   UNIX token of user 0
   Primary group is 0 and contains 0 supplementary groups
[2022/11/26 00:13:22.703341,  5, pid=40466, effective(0, 0), real(0, 0)] 
../../source3/smbd/uid.c:494(smbd_change_to_root_user)
   change_to_root_user: now uid=(0,0) gid=(0,0)
[2022/11/26 00:13:22.703489,  2, pid=40466, effective(0, 0), real(0, 0)] 
../../source3/smbd/smb2_service.c:948(close_cnum)
   192.168.181.99 (ipv4:192.168.181.99:49676) closed connection to 
service Data
[2022/11/26 00:13:22.703655,  4, pid=40466, effective(0, 0), real(0, 0), 
class=vfs] ../../source3/smbd/vfs.c:938(vfs_ChDir)
   vfs_ChDir to /
[2022/11/26 00:13:22.703921,  5, pid=40466, effective(0, 0), real(0, 0), 
class=vfs] ../../source3/smbd/vfs.c:1000(vfs_ChDir)
   vfs_ChDir: vfs_ChDir got /
[2022/11/26 00:13:22.704103,  4, pid=40466, effective(0, 0), real(0, 0)] 
../../source3/smbd/sec_ctx.c:317(set_sec_ctx_internal)
   setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
[2022/11/26 00:13:22.704229,  5, pid=40466, effective(0, 0), real(0, 0)] 
../../libcli/security/security_token.c:47(security_token_debug)
   Security token: (NULL)
[2022/11/26 00:13:22.704349,  5, pid=40466, effective(0, 0), real(0, 0)] 
../../source3/auth/token_util.c:873(debug_unix_user_token)
   UNIX token of user 0
   Primary group is 0 and contains 0 supplementary groups
[2022/11/26 00:13:22.704609,  5, pid=40466, effective(0, 0), real(0, 0)] 
../../source3/smbd/uid.c:494(smbd_change_to_root_user)
   change_to_root_user: now uid=(0,0) gid=(0,0)
[2022/11/26 00:13:22.704812,  5, pid=40466, effective(0, 0), real(0, 0)] 
../../lib/dbwrap/dbwrap.c:143(dbwrap_lock_order_lock)
   dbwrap_lock_order_lock: check lock order 1 for 
/run/samba/smbXsrv_tcon_global.tdb
[2022/11/26 00:13:22.704944, 10, pid=40466, effective(0, 0), real(0, 0)] 
../../lib/dbwrap/dbwrap.c:128(debug_lock_order)
   lock order:  1:/run/samba/smbXsrv_tcon_global.tdb 2:<none> 3:<none> 
4:<none>
[2022/11/26 00:13:22.705104, 10, pid=40466, effective(0, 0), real(0, 0)] 
../../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
   db_tdb_log_key: Locking key DD0078AA
[2022/11/26 00:13:22.705250, 10, pid=40466, effective(0, 0), real(0, 0)] 
../../lib/dbwrap/dbwrap_tdb.c:153(db_tdb_fetch_locked_internal)
   db_tdb_fetch_locked_internal: Allocated locked data 0x55b4ee1d40
[2022/11/26 00:13:22.705451, 10, pid=40466, effective(0, 0), real(0, 0)] 
../../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
   db_tdb_log_key: Unlocking key DD0078AA
[2022/11/26 00:13:22.705592,  5, pid=40466, effective(0, 0), real(0, 0)] 
../../lib/dbwrap/dbwrap.c:175(dbwrap_lock_order_unlock)
   dbwrap_lock_order_unlock: release lock order 1 for 
/run/samba/smbXsrv_tcon_global.tdb
[2022/11/26 00:13:22.705748,  5, pid=40466, effective(0, 0), real(0, 0)] 
../../lib/dbwrap/dbwrap.c:143(dbwrap_lock_order_lock)
   dbwrap_lock_order_lock: check lock order 1 for 
/run/samba/smbXsrv_session_global.tdb
[2022/11/26 00:13:22.705876, 10, pid=40466, effective(0, 0), real(0, 0)] 
../../lib/dbwrap/dbwrap.c:128(debug_lock_order)
   lock order:  1:/run/samba/smbXsrv_session_global.tdb 2:<none> 
3:<none> 4:<none>
[2022/11/26 00:13:22.706020, 10, pid=40466, effective(0, 0), real(0, 0)] 
../../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
   db_tdb_log_key: Locking key 85AF9D66
[2022/11/26 00:13:22.706258, 10, pid=40466, effective(0, 0), real(0, 0)] 
../../lib/dbwrap/dbwrap_tdb.c:153(db_tdb_fetch_locked_internal)
   db_tdb_fetch_locked_internal: Allocated locked data 0x55b4edc740
[2022/11/26 00:13:22.706392, 10, pid=40466, effective(0, 0), real(0, 0)] 
../../source3/lib/dbwrap/dbwrap_watch.c:507(dbwrap_watched_record_prepare_wakeup)
   dbwrap_watched_record_prepare_wakeup: No watchers
[2022/11/26 00:13:22.706572,  5, pid=40466, effective(0, 0), real(0, 0)] 
../../lib/dbwrap/dbwrap.c:175(dbwrap_lock_order_unlock)
   dbwrap_lock_order_unlock: release lock order 1 for 
/run/samba/smbXsrv_session_global.tdb
[2022/11/26 00:13:22.706711, 10, pid=40466, effective(0, 0), real(0, 0)] 
../../lib/dbwrap/dbwrap_tdb.c:60(db_tdb_log_key)
   db_tdb_log_key: Unlocking key 85AF9D66
[2022/11/26 00:13:22.706838, 10, pid=40466, effective(0, 0), real(0, 0)] 
../../source3/lib/dbwrap/dbwrap_watch.c:550(dbwrap_watched_trigger_wakeup)
   dbwrap_watched_trigger_wakeup: No one to wakeup
[2022/11/26 00:13:22.706986, 10, pid=40466, effective(0, 0), real(0, 0), 
class=smb2] ../../source3/smbd/smb2_server.c:3841(smbd_smb2_request_done_ex)
   smbd_smb2_request_done_ex: mid [12919] idx[1] status[NT_STATUS_OK] 
body[4] dyn[no:0] at ../../source3/smbd/smb2_sesssetup.c:1281
[2022/11/26 00:13:22.707141, 10, pid=40466, effective(0, 0), real(0, 0), 
class=smb2_credits] 
../../source3/smbd/smb2_server.c:969(smb2_set_operation_credit)
   smb2_set_operation_credit: smb2_set_operation_credit: requested 1, 
charge 1, granted 1, current possible/max 8074/8192, total 
granted/max/low/range 119/8192/12920/119
[2022/11/26 00:13:22.707572, 10, pid=40466, effective(0, 0), real(0, 0)] 
../../source3/smbd/smbXsrv_session.c:1271(smbXsrv_session_destructor)
   smbXsrv_session_destructor: destructing session(2242878822)
[2022/11/26 00:13:33.440556, 10, pid=40466, effective(0, 0), real(0, 0), 
class=smb2] ../../source3/smbd/smb2_server.c:4995(smbd_smb2_io_handler)
   smbd_smb2_request idx[1] of 5 vectors
[2022/11/26 00:13:33.440891, 10, pid=40466, effective(0, 0), real(0, 0), 
class=smb2_credits] 
../../source3/smbd/smb2_server.c:712(smb2_validate_sequence_number)
   smb2_validate_sequence_number: smb2_validate_sequence_number: 
clearing id 12920 (position 4728) from bitmap
[2022/11/26 00:13:33.441039, 10, pid=40466, effective(0, 0), real(0, 0), 
class=smb2] 
../../source3/smbd/smb2_server.c:2980(smbd_smb2_request_dispatch)
   smbd_smb2_request_dispatch: opcode[SMB2_OP_TDIS] mid = 12920
[2022/11/26 00:13:33.441235,  4, pid=40466, effective(0, 0), real(0, 0)] 
../../source3/smbd/sec_ctx.c:317(set_sec_ctx_internal)
   setting sec ctx (10032, 30058) - sec_ctx_stack_ndx = 0
[2022/11/26 00:13:33.441369,  5, pid=40466, effective(0, 0), real(0, 0)] 
../../libcli/security/security_token.c:51(security_token_debug)

If I check the effective rights over Windows, I get the thumbs up, the 
user read and write rights to this share. Rights are set over a security 
group.

Regards
Ingo
https://github.com/WAdama

More information about the samba mailing list