I have an issue which has me scratching my head, and I dont know where I need to enable deeper logging to find the source of the issue.
We have a third party appliance, where we do have root ssh access to for management.
We have been running on a backup server for a while but now we have switched back to this storage server to start setting up good storage practice with a clean slate.
AD:
Windows Server 2016 running AD and DNS
Domain: vfx.int
User: freezer
UID: 100000005
GID: 100000024
Appliance linux version:
Linux elementsone 3.10.0-1062.el7.x86_64 #1 SMP Wed Aug 7 18:08:02 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux
I believe that is CentOS7
smb.conf LDAP configuration:
workgroup=VFX
server string=ELEMENTS SMB
log file=/var/log/samba/log.%m
max log size=5000
realm=VFX.INT
security=ads
lanman auth=yes
domain master=no
local master=no
prefered master=no
idmap config * : backend=tdb2
idmap config * : range=1000000-99999999
idmap config VFX : backend=ad
idmap config VFX : unix_primary_group=yes
idmap config VFX : schema_mode=rfc2307
idmap config VFX : range=100000005-1999999999
template shell=/bin/bash
winbind offline logon=false
winbind separator=+
winbind enum users=yes
winbind enum groups=yes
winbind use default domain=no
winbind nested groups=yes
winbind expand groups=5
winbind refresh tickets=yes
allow trusted domains=yes
passdb backend=tdbsam
load printers=no
printing=bsd
printcap name=/dev/null
map to guest=bad user
enable core files=no
ntlm auth=yes
server signing=disabled
client signing=disabled
min protocol=smb2_10
max protocol=smb3
nt acl support=no
max xmit=1048576
block size=4096
aio read size=1
aio write size=1
map system=no
map archive=no
map read only=no
dns proxy=no
wins proxy=no
hide dot files=yes
case sensitive=yes
Affected User in AD has UID 100000005
The issue was visible on the system before:
root ~ $ getent passwd
VFX+freezer:*:10000000:100000024:Freezer:/home/VFX/freezer:/bin/bash
root ~ $ id vfx+freezer
uid=10000000(VFX+freezer) gid=100000024(VFX+freezers) groups=100000024(VFX+freezers)
root ~ $ getent passwd 100000005
VFX+freezer:*:10000000:100000024:Freezer:/home/VFX/freezer:/bin/bash
trying to umode it, to change it to the correct UID:
root ~ $ usermod -u 100000005 VFX+Freezer usermod: UID '100000005' already exists
so what did I do after we found this out:
remove the user from the webui ( the system has a webui) Removing the user from command line using userdel did not work, there were always processes in use.
I ran the following sequence:
systemctl stop sernet-samba-smbd;
systemctl stop sernet-samba-winbindd;
systemctl stop nscd
rm /var/lib/samba/*.tdb;
net cache flush;
systemctl start nscd
systemctl start sernet-samba-smbd;
systemctl start sernet-samba-winbindd;
after this, i did a UID check:
root ~ $ getent passwd vfx+Freezer VFX+freezer:*:100000005:100000024:Freezer:/home/VFX/freezer:/bin/bash
root ~ $ id vfx+freezer uid=100000005(VFX+freezer) gid=100000024(VFX+freezers) groups=100000024(VFX+freezers)
root ~ $ getent passwd 100000005 VFX+freezer:*:100000005:100000024:Freezer:/home/VFX/freezer:/bin/bash
Yesterday morning my colleague did a check and came up with this:
root~ $ id vfx+freezerelementsone
uid=10000000(VFX+freezer) gid=100000024(VFX+freezers) groups=100000024(VFX+freezers)
back to square one?
I checked the following logs:
Messages
audit log
smb log
and only these references i can find:
Jan 30 21:00:43 elementsone elements-webui[15894]: [INFO] [audit] Deleted user [email protected] ip=10.212.134.105 http_fingerprint=d834046e33502e6892901f86004a4401fab5969372ebb1a965a8e6e404b5d7527ac9af5764bd049bd6e36cf0a0f455c537664ac04301d3c741bf8aea0d9528e0 username=root user_id=1 session=24f8c1e7f50d718fa5d808643e3ce9c6463cf3f0535606664e7ac62bde52a120a45c8e1a227c9d19dbada7e44fffaa2de29775f678871c07ac8183ac8978b834 api=deleteUser url=/api/2/users/7
Jan 30 21:00:44 elementsone nscd: 30580 monitored file `/etc/passwd` was moved into place, adding watch
Jan 30 21:00:44 elementsone nscd: 30580 monitored file `/etc/group` was moved into place, adding watch
Jan 30 21:00:44 elementsone systemd: Reloading Samba SMB Daemon.
Jan 30 21:00:44 elementsone systemd: Reloaded Samba SMB Daemon.
this is me removing the user
and:
Jan 31 09:34:05 elementsone elements-webui[23682]: [INFO] [audit] Auth result: authenticated as root ip=192.168.29.49 http_fingerprint=b636a21951c20d515693b271313ecb7d0d45972c27f16d77134ed3ead003034855cedec2bc941929f2c575f7a6431160500875603d86d8cc456aa8964ed924b2 session=40cf833271af24b469de123f839d092604167f81f087c7a5356f833f545a6fb8ef389afe1e781cc985c337f28d4ca67d7f313b214e80b62364e3b37d7a0492f9 api=login url=/api/2/auth/login
Jan 31 09:34:05 elementsone elements-webui[23682]: [INFO] [audit] Starting task: private.apply_user_password(user_id=1, _context={'name': '', 'initiator_user_id': None, 'initiator_workstation_id': None, 'initiator_subtask_id': None, 'initiator_schedule_id': None, 'initiator_event_id': None, 'job_instance_id': None, 'security_context_user_id': None, 'timeout': None, 'dont_save': False, 'noop_dont_save': False, 'success_dont_save': True, 'no_concurrency': False, 'log_variable': False, 'queue': None, 'enqueue_at_front': False, 'vars': {}}) ip=192.168.29.49 http_fingerprint=b636a21951c20d515693b271313ecb7d0d45972c27f16d77134ed3ead003034855cedec2bc941929f2c575f7a6431160500875603d86d8cc456aa8964ed924b2 session=40cf833271af24b469de123f839d092604167f81f087c7a5356f833f545a6fb8ef389afe1e781cc985c337f28d4ca67d7f313b214e80b62364e3b37d7a0492f9 api=login url=/api/2/auth/login
Jan 31 09:34:51 elementsone elements-webui[12241]: [INFO] [audit] LDAP sync adds a new user [email protected] to [email protected] ip=192.168.29.49 http_fingerprint=b636a21951c20d515693b271313ecb7d0d45972c27f16d77134ed3ead003034855cedec2bc941929f2c575f7a6431160500875603d86d8cc456aa8964ed924b2 username=root user_id=1 session=f18696c407fb8c58318a61011c8cd81a6cc25410b6e1a01a8ab866b215dacc65dd403fe26ed47684fbf278fbffea6dac19e0ec32d172cf2bc494c760ecb2b8f8 api=syncLDAPGroup url=/api/2/groups/23/ldap-sync
Jan 31 09:34:51 elementsone elements-webui[12241]: [INFO] [audit] Added permission for [email protected]: client:access ip=192.168.29.49 http_fingerprint=b636a21951c20d515693b271313ecb7d0d45972c27f16d77134ed3ead003034855cedec2bc941929f2c575f7a6431160500875603d86d8cc456aa8964ed924b2 username=root user_id=1 session=f18696c407fb8c58318a61011c8cd81a6cc25410b6e1a01a8ab866b215dacc65dd403fe26ed47684fbf278fbffea6dac19e0ec32d172cf2bc494c760ecb2b8f8 api=syncLDAPGroup url=/api/2/groups/23/ldap-sync
Jan 31 09:34:51 elementsone elements-webui[12241]: [INFO] [audit] Created user [email protected] ip=192.168.29.49 http_fingerprint=b636a21951c20d515693b271313ecb7d0d45972c27f16d77134ed3ead003034855cedec2bc941929f2c575f7a6431160500875603d86d8cc456aa8964ed924b2 username=root user_id=1 session=f18696c407fb8c58318a61011c8cd81a6cc25410b6e1a01a8ab866b215dacc65dd403fe26ed47684fbf278fbffea6dac19e0ec32d172cf2bc494c760ecb2b8f8 api=syncLDAPGroup url=/api/2/groups/23/ldap-sync
Jan 31 09:34:52 elementsone nscd: 28546 monitored file `/etc/passwd` was moved into place, adding watch
Jan 31 09:34:52 elementsone nscd: 28546 monitored file `/etc/group` was moved into place, adding watch
Jan 31 09:34:53 elementsone systemd: Reloading Samba SMB Daemon.
Jan 31 09:34:53 elementsone systemd: Reloaded Samba SMB Daemon.
this is after my colleague had run the check on the UID, so this should not be relevant to our changing of the UID once more.
It looks like somehow it is applying the user as a non domain user? I did not explicitly add the user post my cleanup, could that cause it? even then still the system was happy with its checking the UID after cleanup, if a user gets added, it should get the correct UID pulled from AD.
That the system finds another UID already in use on that number as well baffles me.
Anyone know what kind of log I can enable to dig deeper into who has setup that user with UID 10000000 instead of 100000005 ? Or anyone have seen such an issue and know a resolution?
UPDATE 06-20-2023 UID /GID change example:
root ~ $ elementsone is VFX+freezeri VFX+freezer id VFX+freezer
uid=10000000(VFX+freezer) gid=100000024(VFX+freezers) groups=100000024(VFX+freezers)
root ~ $ elementsone net cache flush
root ~ $ elementsone id VFX+freezer
uid=100000005(VFX+freezer) gid=100000024(VFX+freezers) groups=100000024(VFX+freezers)
root ~ $ elementsone id VFX+freezer
uid=10000000(VFX+freezer) gid=100000024(VFX+freezers) groups=100000024(VFX+freezers)
root ~ $ elementsone id VFX+freezer
uid=10000000(VFX+freezer) gid=100000024(VFX+freezers) groups=100000024(VFX+freezers)
root ~ $ elementsone
This example shows after a flush, it gets identified correctly but after a few seconds somehow the wrong one gets pushed into the cache.
Comparing the correct and the 'saved' UID it shows that somehow the user gets pushed in the idmap * group, in place of the domain. Is there a setting which might be wrong or missing?
Additional information in the net cache log which shows the mixup, anyone know how to trace this to a source?
Key: IDMAP/UID2SID/10000000 Timeout: Thu Feb 9 21:26:52 2023 Value: S-1-5-21-3125647252-293200167-3195640431-1607
Key: IDMAP/GID2SID/60051 Timeout: Thu Feb 2 21:28:51 2023 Value: - (expired)
Key: IDMAP/SID2XID/S-1-5-21-3125647252-293200167-3195640431-1632 Timeout: Thu Feb 9 21:26:48 2023 Value: 100000015:U
Key: SAF/DOMAIN/VFX.INT Timeout: 14:09:24 Value: dc2.vfx.int (expired)
Key: SID2NAME/S-1-5-21-3125647252-293200167-3195640431-1632 Timeout: 05:07:12 Value: VFX\president (1) (expired)
Key: RA/fa506325-a3ca-11ed-9831-78e7d1f9d7fc Timeout: Fri Feb 10 16:06:45 2023 Value: Vista
Key: IDMAP/SID2XID/S-1-5-21-3125647252-293200167-3195640431-1779 Timeout: 13:56:24 Value: -1:N (expired)
Key: RA/f5e7d180-2234-9456-b2f6-86348565d8bd Timeout: Mon Feb 13 10:55:38 2023 Value: OSX
Key: IDMAP/UID2SID/100000005 Timeout: Thu Feb 9 21:26:45 2023 Value: S-1-5-21-3125647252-293200167-3195640431-1607
I hope all relevant information and testing is in here, otherwise ask please! (and yes I am working with the appliance manufacturer as well but I have a feeling they are out of their depth on this issue as well, queue, you guys ;)