Issue with SSSD and NSS user/group resolution, sort of

[Lawrence Kearney]

I hope someone can help. I have an odd issue I haven't seen before. I've
done a lot of checking under the hood, but I'm stuck.

We have hundreds of systems using the v2.9+ of the daemon (AD and LDAP
providers). We're deploying a new HPC cluster using Rocky Linux 9
containers (all other systems are RHEL 8/9) as stateless compute nodes.
These nodes are ephemeral so we use the LDAP providers.

The observed issue is the daemons load and run as expected. The nodes mount
NFS file systems but do not resolve file and directory ownerships for LDAP
users until I manually run a "getent" or "id" on any user or group. It
doesn't even have to be a user or group that owns files. So any type of
NSS lookup seems to kick start the process. From there the node is fine.

libnfs, libnss, sssd-nfs-idmap, libsss_nss_idmap, etc are all the same
on nodes that don't do this.

DNS works, there's no difference in daemon configurations from working
ones. systemd unit files are identical, etc. I cannot figure out why these
nodes need to be poked by NSS to start using NSS. Very peculiar.

Any insight would be appreciated,

-- lawrence

[Alexey Tikhonov]

Hi,
> The nodes mount NFS file systems but do not resolve file and directory ownerships for LDAP users

Could you please run `strace ls file_on_nfs` and `ltrace ls
file_on_nfs` (when uid:gid aren't resolved) and share logs?

On Fri, Feb 14, 2025 at 8:45 PM Lawrence Kearney via sssd-users
 wrote:
> I hope someone can help. I have an odd issue I haven't seen before. I've done a lot of checking under the hood, but I'm stuck.
>
> We have hundreds of systems using the v2.9+ of the daemon (AD and LDAP providers). We're deploying a new HPC cluster using Rocky Linux 9 containers (all other systems are RHEL 8/9) as stateless compute nodes. These nodes are ephemeral so we use the LDAP providers.
>
> The observed issue is the daemons load and run as expected. The nodes mount NFS file systems but do not resolve file and directory ownerships for LDAP users until I manually run a "getent" or "id" on any user or group. It doesn't even have to be a user or group that owns files. So any type of NSS lookup seems to kick start the process. From there the node is fine.
>
> libnfs, libnss, sssd-nfs-idmap, libsss_nss_idmap, etc are all the same on nodes that don't do this.
>
> DNS works, there's no difference in daemon configurations from working ones. systemd unit files are identical, etc. I cannot figure out why these nodes need to be poked by NSS to start using NSS. Very peculiar.
>
> Any insight would be appreciated,
>
> -- lawrence
>
> --
> _______________________________________________
> sssd-users mailing list -- [e-mail]
> To unsubscribe send an email to [e-mail]
> Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/
> List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
> List Archives: https://lists.fedorahosted.org/archives/list/[e-mail].o...
> Do not reply to spam, report it: https://pagure.io/fedora-infrastructure/new_issue

[Alexey Tikhonov]

On Fri, Feb 14, 2025 at 9:33 PM Alexey Tikhonov  wrote:
> Hi,
> > The nodes mount NFS file systems but do not resolve file and directory ownerships for LDAP users
>
> Could you please run `strace ls file_on_nfs` and `ltrace ls
> file_on_nfs` (when uid:gid aren't resolved) and share logs?

* 'ls -l'
> On Fri, Feb 14, 2025 at 8:45 PM Lawrence Kearney via sssd-users
>  wrote:
> > I hope someone can help. I have an odd issue I haven't seen before. I've done a lot of checking under the hood, but I'm stuck.
> >
> > We have hundreds of systems using the v2.9+ of the daemon (AD and LDAP providers). We're deploying a new HPC cluster using Rocky Linux 9 containers (all other systems are RHEL 8/9) as stateless compute nodes. These nodes are ephemeral so we use the LDAP providers.
> >
> > The observed issue is the daemons load and run as expected. The nodes mount NFS file systems but do not resolve file and directory ownerships for LDAP users until I manually run a "getent" or "id" on any user or group. It doesn't even have to be a user or group that owns files. So any type of NSS lookup seems to kick start the process. From there the node is fine.
> >
> > libnfs, libnss, sssd-nfs-idmap, libsss_nss_idmap, etc are all the same on nodes that don't do this.
> >
> > DNS works, there's no difference in daemon configurations from working ones. systemd unit files are identical, etc. I cannot figure out why these nodes need to be poked by NSS to start using NSS. Very peculiar.
> >
> > Any insight would be appreciated,
> >
> > -- lawrence
> >
> > --
> > _______________________________________________
> > sssd-users mailing list -- [e-mail]
> > To unsubscribe send an email to [e-mail]
> > Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/
> > List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
> > List Archives: https://lists.fedorahosted.org/archives/list/[e-mail].o...
> > Do not reply to spam, report it: https://pagure.io/fedora-infrastructure/new_issue

[Lawrence Kearney]

Alex,
Sure. As a base, the daemon status and original call:

[root@acad-cnode006 ~]# systemctl status sssd
● sssd.service - System Security Services Daemon
     Loaded: loaded (/usr/lib/systemd/system/sssd.service; enabled; preset:
enabled)
     Active: active (running) since Wed 2025-01-29 16:24:29 UTC; 2 weeks 2
days ago
   Main PID: 758 (sssd)
      Tasks: 4 (limit: 1230849)
     Memory: 48.1M
        CPU: 41.021s
     CGroup: /system.slice/sssd.service
             ├─758 /usr/sbin/sssd -i --logger=files
             ├─770 /usr/libexec/sssd/sssd_be --domain adldap1.augusta.edu
--uid 0 --gid 0 --logger=files
             ├─779 /usr/libexec/sssd/sssd_nss --uid 0 --gid 0 --logger=files
             └─780 /usr/libexec/sssd/sssd_pam --uid 0 --gid 0 --logger=files

Jan 29 16:24:29 acad-cnode006 systemd[1]: Starting System Security Services
Daemon...
Jan 29 16:24:29 acad-cnode006 sssd[758]: Starting up
Jan 29 16:24:29 acad-cnode006 sssd_be[770]: Starting up
Jan 29 16:24:29 acad-cnode006 sssd_nss[779]: Starting up
Jan 29 16:24:29 acad-cnode006 sssd_pam[780]: Starting up
Jan 29 16:24:29 acad-cnode006 systemd[1]: Started System Security Services
Daemon.
Jan 29 16:24:30 acad-cnode006 sssd_nss[779]: Enumeration requested but not
enabled
Jan 29 16:24:30 acad-cnode006 sssd_be[770]: Backend is offline
Jan 29 16:24:36 acad-cnode006 sssd_be[770]: Backend is online

----------

[root@acad-cnode006 ~]# ll /home
total 8
drwx------  9 28449524 28433522 4096 Jan 29 18:49 dsb
drwx------ 12 28244723 28433522 4096 Feb 12 16:25 lck

----------

[root@acad-cnode006 ~]# strace ls /home/lck
execve("/usr/bin/ls", ["ls", "/home/lck"], 0x7ffe31ae8cf8 /* 38 vars */) = 0
brk(NULL)                               = 0x55985add7000
arch_prctl(0x3001 /* ARCH_??? */, 0x7ffd3c0e0910) = -1 EINVAL (Invalid
argument)
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or
directory)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=23979, ...}) = 0
mmap(NULL, 23979, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fb9e00c4000
close(3)                                = 0
openat(AT_FDCWD, "/lib64/libselinux.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0pp\0\0\0\0\0\0"...,
832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=175760, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0x7fb9e00c2000
mmap(NULL, 181896, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) =
0x7fb9e0095000
mmap(0x7fb9e009b000, 110592, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x6000) = 0x7fb9e009b000
mmap(0x7fb9e00b6000, 32768, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE,
3, 0x21000) = 0x7fb9e00b6000
mmap(0x7fb9e00be000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x28000) = 0x7fb9e00be000
mmap(0x7fb9e00c0000, 5768, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fb9e00c0000
close(3)                                = 0
openat(AT_FDCWD, "/lib64/libcap.so.2", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P'\0\0\0\0\0\0"...,
832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=36304, ...}) = 0
mmap(NULL, 36920, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) =
0x7fb9e008b000
mmap(0x7fb9e008d000, 16384, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7fb9e008d000
mmap(0x7fb9e0091000, 8192, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE,
3, 0x6000) = 0x7fb9e0091000
mmap(0x7fb9e0093000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x7000) = 0x7fb9e0093000
close(3)                                = 0
openat(AT_FDCWD, "/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3,
"\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\220\227\2\0\0\0\0\0"...,
832) = 832
pread64(3, "\6\0\0\0\4\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0"...,
784, 64) = 784
pread64(3, "\4\0\0\0
\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0"..., 48, 848) = 48
pread64(3, "\4\0\0\0\24\0\0\0\3\0\0\0GNU\0\327\212D\256\224\361\323
4.\17\366\3021[+"..., 68, 896) = 68
fstat(3, {st_mode=S_IFREG|0755, st_size=2543976, ...}) = 0
pread64(3, "\6\0\0\0\4\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0"...,
784, 64) = 784
mmap(NULL, 2129840, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) =
0x7fb9dfe83000
mmap(0x7fb9dfeab000, 1527808, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x28000) = 0x7fb9dfeab000
mmap(0x7fb9e0020000, 360448, PROT_READ,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x19d000) = 0x7fb9e0020000
mmap(0x7fb9e0078000, 24576, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1f5000) = 0x7fb9e0078000
mmap(0x7fb9e007e000, 53168, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fb9e007e000
close(3)                                = 0
openat(AT_FDCWD, "/lib64/libpcre2-8.so.0", O_RDONLY|O_CLOEXEC) = 3
read(3,
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\220$\0\0\0\0\0\0"..., 832)
= 832
fstat(3, {st_mode=S_IFREG|0755, st_size=636840, ...}) = 0
mmap(NULL, 635440, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) =
0x7fb9dfde7000
mmap(0x7fb9dfde9000, 446464, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7fb9dfde9000
mmap(0x7fb9dfe56000, 176128, PROT_READ,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x6f000) = 0x7fb9dfe56000
mmap(0x7fb9dfe81000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x99000) = 0x7fb9dfe81000
close(3)                                = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0x7fb9dfde5000
arch_prctl(ARCH_SET_FS, 0x7fb9dfde5c40) = 0
set_tid_address(0x7fb9dfde5f10)         = 80338
set_robust_list(0x7fb9dfde5f20, 24)     = 0
rseq(0x7fb9dfde65e0, 0x20, 0, 0x53053053) = 0
mprotect(0x7fb9e0078000, 16384, PROT_READ) = 0
mprotect(0x7fb9dfe81000, 4096, PROT_READ) = 0
mprotect(0x7fb9e0093000, 4096, PROT_READ) = 0
mprotect(0x7fb9e00be000, 4096, PROT_READ) = 0
mprotect(0x55985a665000, 8192, PROT_READ) = 0
mprotect(0x7fb9e00fe000, 8192, PROT_READ) = 0
prlimit64(0, RLIMIT_STACK, NULL, {rlim_cur=8192*1024,
rlim_max=RLIM64_INFINITY}) = 0
munmap(0x7fb9e00c4000, 23979)           = 0
prctl(PR_CAPBSET_READ, CAP_MAC_OVERRIDE) = 1
prctl(PR_CAPBSET_READ, 0x30 /* CAP_??? */) = -1 EINVAL (Invalid argument)
prctl(PR_CAPBSET_READ, CAP_CHECKPOINT_RESTORE) = 1
prctl(PR_CAPBSET_READ, 0x2c /* CAP_??? */) = -1 EINVAL (Invalid argument)
prctl(PR_CAPBSET_READ, 0x2a /* CAP_??? */) = -1 EINVAL (Invalid argument)
prctl(PR_CAPBSET_READ, 0x29 /* CAP_??? */) = -1 EINVAL (Invalid argument)
statfs("/sys/fs/selinux", {f_type=SYSFS_MAGIC, f_bsize=4096, f_blocks=0,
f_bfree=0, f_bavail=0, f_files=0, f_ffree=0, f_fsid={val=[0, 0]},
f_namelen=255, f_frsize=4096, f_flags=ST_VALID|ST_RELATIME}) = 0
statfs("/selinux", 0x7ffd3c0e08a0)      = -1 ENOENT (No such file or
directory)
getrandom("\x87\x15\x1a\xc4\x7b\x82\xc0\xe0", 8, GRND_NONBLOCK) = 8
brk(NULL)                               = 0x55985add7000
brk(0x55985adf8000)                     = 0x55985adf8000
openat(AT_FDCWD, "/proc/filesystems", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
read(3, "nodev\tsysfs\nnodev\ttmpfs\nnodev\tbd"..., 1024) = 397
close(3)                                = 0
openat(AT_FDCWD, "/proc/mounts", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
read(3, "rootfs / rootfs rw,size=98468024"..., 1024) = 1024
read(3, "/tracing tracefs rw,nosuid,nodev"..., 1024) = 1024
read(3, "05:/cluster_data/cluster_apps/so"..., 1024) = 262
read(3, "", 1024)                       = 0
close(3)                                = 0
access("/etc/selinux/config", F_OK)     = 0
openat(AT_FDCWD, "/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = -1
ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/locale/locale.alias", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=2998, ...}) = 0
read(3, "# Locale name alias data base.\n#"..., 4096) = 2998
read(3, "", 4096)                       = 0
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/C.UTF-8/LC_IDENTIFICATION",
O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_IDENTIFICATION",
O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=258, ...}) = 0
mmap(NULL, 258, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fb9e00c9000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib64/gconv/gconv-modules.cache", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=2218, ...}) = 0
mmap(NULL, 2218, PROT_READ, MAP_SHARED, 3, 0) = 0x7fb9e00c8000
close(3)                                = 0
futex(0x7fb9e007da6c, FUTEX_WAKE_PRIVATE, 2147483647) = 0
openat(AT_FDCWD, "/usr/lib/locale/C.UTF-8/LC_MEASUREMENT",
O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_MEASUREMENT",
O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=23, ...}) = 0
mmap(NULL, 23, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fb9e00c7000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/C.UTF-8/LC_TELEPHONE",
O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_TELEPHONE", O_RDONLY|O_CLOEXEC)
= 3
fstat(3, {st_mode=S_IFREG|0644, st_size=47, ...}) = 0
mmap(NULL, 47, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fb9e00c6000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/C.UTF-8/LC_ADDRESS", O_RDONLY|O_CLOEXEC)
= -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_ADDRESS", O_RDONLY|O_CLOEXEC) =
3
fstat(3, {st_mode=S_IFREG|0644, st_size=127, ...}) = 0
mmap(NULL, 127, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fb9e00c5000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/C.UTF-8/LC_NAME", O_RDONLY|O_CLOEXEC) =
-1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_NAME", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=62, ...}) = 0
mmap(NULL, 62, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fb9e00c4000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/C.UTF-8/LC_PAPER", O_RDONLY|O_CLOEXEC) =
-1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_PAPER", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=34, ...}) = 0
mmap(NULL, 34, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fb9dfde4000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/C.UTF-8/LC_MESSAGES", O_RDONLY|O_CLOEXEC)
= -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_MESSAGES", O_RDONLY|O_CLOEXEC)
= 3
fstat(3, {st_mode=S_IFDIR|0755, st_size=60, ...}) = 0
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_MESSAGES/SYS_LC_MESSAGES",
O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=48, ...}) = 0
mmap(NULL, 48, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fb9dfde3000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/C.UTF-8/LC_MONETARY", O_RDONLY|O_CLOEXEC)
= -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_MONETARY", O_RDONLY|O_CLOEXEC)
= 3
fstat(3, {st_mode=S_IFREG|0644, st_size=270, ...}) = 0
mmap(NULL, 270, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fb9dfde2000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/C.UTF-8/LC_COLLATE", O_RDONLY|O_CLOEXEC)
= -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_COLLATE", O_RDONLY|O_CLOEXEC) =
3
fstat(3, {st_mode=S_IFREG|0644, st_size=1406, ...}) = 0
mmap(NULL, 1406, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fb9dfde1000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/C.UTF-8/LC_TIME", O_RDONLY|O_CLOEXEC) =
-1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_TIME", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=3360, ...}) = 0
mmap(NULL, 3360, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fb9dfde0000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/C.UTF-8/LC_NUMERIC", O_RDONLY|O_CLOEXEC)
= -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_NUMERIC", O_RDONLY|O_CLOEXEC) =
3
fstat(3, {st_mode=S_IFREG|0644, st_size=50, ...}) = 0
mmap(NULL, 50, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fb9dfddf000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/C.UTF-8/LC_CTYPE", O_RDONLY|O_CLOEXEC) =
-1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_CTYPE", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=346132, ...}) = 0
mmap(NULL, 346132, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fb9dfd8a000
close(3)                                = 0
ioctl(1, TCGETS, {B38400 opost isig icanon echo ...}) = 0
ioctl(1, TIOCGWINSZ, {ws_row=57, ws_col=208, ws_xpixel=0, ws_ypixel=0}) = 0
statx(AT_FDCWD, "/home/lck", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT,
STATX_MODE, {stx_mask=STATX_BASIC_STATS|STATX_MNT_ID, stx_attributes=0,
stx_mode=S_IFDIR|0700, stx_size=4096, ...}) = 0
openat(AT_FDCWD, "/home/lck", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 3
fstat(3, {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
getdents64(3, 0x55985ade0190 /* 19 entries */, 32768) = 592
getdents64(3, 0x55985ade0190 /* 0 entries */, 32768) = 0
close(3)                                = 0
fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(0x88, 0), ...}) = 0
write(1, "Documents  apps  scripts\n", 25Documents  apps  scripts
) = 25
close(1)                                = 0
close(2)                                = 0
exit_group(0)                           = ?
+++ exited with 0 +++

----------

[root@acad-cnode006 ~]# strace ls -l /home/lck
execve("/usr/bin/ls", ["ls", "-l", "/home/lck"], 0x7fff20169bd0 /* 38 vars
*/) = 0
brk(NULL)                               = 0x55db02b5b000
arch_prctl(0x3001 /* ARCH_??? */, 0x7ffdc0738860) = -1 EINVAL (Invalid
argument)
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or
directory)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=23979, ...}) = 0
mmap(NULL, 23979, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f65cdff2000
close(3)                                = 0
openat(AT_FDCWD, "/lib64/libselinux.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0pp\0\0\0\0\0\0"...,
832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=175760, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0x7f65cdff0000
mmap(NULL, 181896, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) =
0x7f65cdfc3000
mmap(0x7f65cdfc9000, 110592, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x6000) = 0x7f65cdfc9000
mmap(0x7f65cdfe4000, 32768, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE,
3, 0x21000) = 0x7f65cdfe4000
mmap(0x7f65cdfec000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x28000) = 0x7f65cdfec000
mmap(0x7f65cdfee000, 5768, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f65cdfee000
close(3)                                = 0
openat(AT_FDCWD, "/lib64/libcap.so.2", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P'\0\0\0\0\0\0"...,
832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=36304, ...}) = 0
mmap(NULL, 36920, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) =
0x7f65cdfb9000
mmap(0x7f65cdfbb000, 16384, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7f65cdfbb000
mmap(0x7f65cdfbf000, 8192, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE,
3, 0x6000) = 0x7f65cdfbf000
mmap(0x7f65cdfc1000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x7000) = 0x7f65cdfc1000
close(3)                                = 0
openat(AT_FDCWD, "/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3,
"\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\220\227\2\0\0\0\0\0"...,
832) = 832
pread64(3, "\6\0\0\0\4\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0"...,
784, 64) = 784
pread64(3, "\4\0\0\0
\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0"..., 48, 848) = 48
pread64(3, "\4\0\0\0\24\0\0\0\3\0\0\0GNU\0\327\212D\256\224\361\323
4.\17\366\3021[+"..., 68, 896) = 68
fstat(3, {st_mode=S_IFREG|0755, st_size=2543976, ...}) = 0
pread64(3, "\6\0\0\0\4\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0"...,
784, 64) = 784
mmap(NULL, 2129840, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) =
0x7f65cddb1000
mmap(0x7f65cddd9000, 1527808, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x28000) = 0x7f65cddd9000
mmap(0x7f65cdf4e000, 360448, PROT_READ,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x19d000) = 0x7f65cdf4e000
mmap(0x7f65cdfa6000, 24576, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1f5000) = 0x7f65cdfa6000
mmap(0x7f65cdfac000, 53168, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f65cdfac000
close(3)                                = 0
openat(AT_FDCWD, "/lib64/libpcre2-8.so.0", O_RDONLY|O_CLOEXEC) = 3
read(3,
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\220$\0\0\0\0\0\0"..., 832)
= 832
fstat(3, {st_mode=S_IFREG|0755, st_size=636840, ...}) = 0
mmap(NULL, 635440, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) =
0x7f65cdd15000
mmap(0x7f65cdd17000, 446464, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7f65cdd17000
mmap(0x7f65cdd84000, 176128, PROT_READ,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x6f000) = 0x7f65cdd84000
mmap(0x7f65cddaf000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x99000) = 0x7f65cddaf000
close(3)                                = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0x7f65cdd13000
arch_prctl(ARCH_SET_FS, 0x7f65cdd13c40) = 0
set_tid_address(0x7f65cdd13f10)         = 80345
set_robust_list(0x7f65cdd13f20, 24)     = 0
rseq(0x7f65cdd145e0, 0x20, 0, 0x53053053) = 0
mprotect(0x7f65cdfa6000, 16384, PROT_READ) = 0
mprotect(0x7f65cddaf000, 4096, PROT_READ) = 0
mprotect(0x7f65cdfc1000, 4096, PROT_READ) = 0
mprotect(0x7f65cdfec000, 4096, PROT_READ) = 0
mprotect(0x55db027ab000, 8192, PROT_READ) = 0
mprotect(0x7f65ce02c000, 8192, PROT_READ) = 0
prlimit64(0, RLIMIT_STACK, NULL, {rlim_cur=8192*1024,
rlim_max=RLIM64_INFINITY}) = 0
munmap(0x7f65cdff2000, 23979)           = 0
prctl(PR_CAPBSET_READ, CAP_MAC_OVERRIDE) = 1
prctl(PR_CAPBSET_READ, 0x30 /* CAP_??? */) = -1 EINVAL (Invalid argument)
prctl(PR_CAPBSET_READ, CAP_CHECKPOINT_RESTORE) = 1
prctl(PR_CAPBSET_READ, 0x2c /* CAP_??? */) = -1 EINVAL (Invalid argument)
prctl(PR_CAPBSET_READ, 0x2a /* CAP_??? */) = -1 EINVAL (Invalid argument)
prctl(PR_CAPBSET_READ, 0x29 /* CAP_??? */) = -1 EINVAL (Invalid argument)
statfs("/sys/fs/selinux", {f_type=SYSFS_MAGIC, f_bsize=4096, f_blocks=0,
f_bfree=0, f_bavail=0, f_files=0, f_ffree=0, f_fsid={val=[0, 0]},
f_namelen=255, f_frsize=4096, f_flags=ST_VALID|ST_RELATIME}) = 0
statfs("/selinux", 0x7ffdc07387f0)      = -1 ENOENT (No such file or
directory)
getrandom("\x1c\x1a\x63\x04\xaf\x3a\x96\x41", 8, GRND_NONBLOCK) = 8
brk(NULL)                               = 0x55db02b5b000
brk(0x55db02b7c000)                     = 0x55db02b7c000
openat(AT_FDCWD, "/proc/filesystems", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
read(3, "nodev\tsysfs\nnodev\ttmpfs\nnodev\tbd"..., 1024) = 397
close(3)                                = 0
openat(AT_FDCWD, "/proc/mounts", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
read(3, "rootfs / rootfs rw,size=98468024"..., 1024) = 1024
read(3, "/tracing tracefs rw,nosuid,nodev"..., 1024) = 1024
read(3, "05:/cluster_data/cluster_apps/so"..., 1024) = 262
read(3, "", 1024)                       = 0
close(3)                                = 0
access("/etc/selinux/config", F_OK)     = 0
openat(AT_FDCWD, "/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = -1
ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/locale/locale.alias", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=2998, ...}) = 0
read(3, "# Locale name alias data base.\n#"..., 4096) = 2998
read(3, "", 4096)                       = 0
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/C.UTF-8/LC_IDENTIFICATION",
O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_IDENTIFICATION",
O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=258, ...}) = 0
mmap(NULL, 258, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f65cdff7000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib64/gconv/gconv-modules.cache", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=2218, ...}) = 0
mmap(NULL, 2218, PROT_READ, MAP_SHARED, 3, 0) = 0x7f65cdff6000
close(3)                                = 0
futex(0x7f65cdfaba6c, FUTEX_WAKE_PRIVATE, 2147483647) = 0
openat(AT_FDCWD, "/usr/lib/locale/C.UTF-8/LC_MEASUREMENT",
O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_MEASUREMENT",
O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=23, ...}) = 0
mmap(NULL, 23, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f65cdff5000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/C.UTF-8/LC_TELEPHONE",
O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_TELEPHONE", O_RDONLY|O_CLOEXEC)
= 3
fstat(3, {st_mode=S_IFREG|0644, st_size=47, ...}) = 0
mmap(NULL, 47, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f65cdff4000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/C.UTF-8/LC_ADDRESS", O_RDONLY|O_CLOEXEC)
= -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_ADDRESS", O_RDONLY|O_CLOEXEC) =
3
fstat(3, {st_mode=S_IFREG|0644, st_size=127, ...}) = 0
mmap(NULL, 127, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f65cdff3000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/C.UTF-8/LC_NAME", O_RDONLY|O_CLOEXEC) =
-1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_NAME", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=62, ...}) = 0
mmap(NULL, 62, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f65cdff2000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/C.UTF-8/LC_PAPER", O_RDONLY|O_CLOEXEC) =
-1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_PAPER", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=34, ...}) = 0
mmap(NULL, 34, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f65cdd12000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/C.UTF-8/LC_MESSAGES", O_RDONLY|O_CLOEXEC)
= -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_MESSAGES", O_RDONLY|O_CLOEXEC)
= 3
fstat(3, {st_mode=S_IFDIR|0755, st_size=60, ...}) = 0
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_MESSAGES/SYS_LC_MESSAGES",
O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=48, ...}) = 0
mmap(NULL, 48, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f65cdd11000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/C.UTF-8/LC_MONETARY", O_RDONLY|O_CLOEXEC)
= -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_MONETARY", O_RDONLY|O_CLOEXEC)
= 3
fstat(3, {st_mode=S_IFREG|0644, st_size=270, ...}) = 0
mmap(NULL, 270, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f65cdd10000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/C.UTF-8/LC_COLLATE", O_RDONLY|O_CLOEXEC)
= -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_COLLATE", O_RDONLY|O_CLOEXEC) =
3
fstat(3, {st_mode=S_IFREG|0644, st_size=1406, ...}) = 0
mmap(NULL, 1406, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f65cdd0f000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/C.UTF-8/LC_TIME", O_RDONLY|O_CLOEXEC) =
-1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_TIME", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=3360, ...}) = 0
mmap(NULL, 3360, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f65cdd0e000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/C.UTF-8/LC_NUMERIC", O_RDONLY|O_CLOEXEC)
= -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_NUMERIC", O_RDONLY|O_CLOEXEC) =
3
fstat(3, {st_mode=S_IFREG|0644, st_size=50, ...}) = 0
mmap(NULL, 50, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f65cdd0d000
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/C.UTF-8/LC_CTYPE", O_RDONLY|O_CLOEXEC) =
-1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/C.utf8/LC_CTYPE", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=346132, ...}) = 0
mmap(NULL, 346132, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f65cdcb8000
close(3)                                = 0
ioctl(1, TCGETS, {B38400 opost isig icanon echo ...}) = 0
ioctl(1, TIOCGWINSZ, {ws_row=57, ws_col=208, ws_xpixel=0, ws_ypixel=0}) = 0
openat(AT_FDCWD, "/usr/share/locale/C.UTF-8/LC_TIME/coreutils.mo",
O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/locale/C.utf8/LC_TIME/coreutils.mo", O_RDONLY)
= -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/locale/C/LC_TIME/coreutils.mo", O_RDONLY) = -1
ENOENT (No such file or directory)
statx(AT_FDCWD, "/home/lck",
AT_STATX_SYNC_AS_STAT|AT_SYMLINK_NOFOLLOW|AT_NO_AUTOMOUNT,
STATX_MODE|STATX_NLINK|STATX_UID|STATX_GID|STATX_MTIME|STATX_SIZE,
{stx_mask=STATX_BASIC_STATS|STATX_MNT_ID, stx_attributes=0,
stx_mode=S_IFDIR|0700, stx_size=4096, ...}) = 0
lgetxattr("/home/lck", "security.selinux", 0x55db02b64530, 255) = -1
EOPNOTSUPP (Operation not supported)
getxattr("/home/lck", "system.posix_acl_access", NULL, 0) = -1 EOPNOTSUPP
(Operation not supported)
getxattr("/home/lck", "system.nfs4_acl", 0x7ffdc07384e0, 152) = -1
EOPNOTSUPP (Operation not supported)
socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
connect(3, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = -1
ENOENT (No such file or directory)
close(3)                                = 0
socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
connect(3, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = -1
ENOENT (No such file or directory)
close(3)                                = 0
newfstatat(AT_FDCWD, "/etc/nsswitch.conf", {st_mode=S_IFREG|0644,
st_size=2980, ...}, 0) = 0
newfstatat(AT_FDCWD, "/", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=560, ...},
0) = 0
openat(AT_FDCWD, "/etc/nsswitch.conf", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=2980, ...}) = 0
read(3, "# Generated by authselect on Mon"..., 4096) = 2980
read(3, "", 4096)                       = 0
fstat(3, {st_mode=S_IFREG|0644, st_size=2980, ...}) = 0
close(3)                                = 0
openat(AT_FDCWD, "/etc/passwd", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=1589, ...}) = 0
lseek(3, 0, SEEK_SET)                   = 0
read(3, "# Uncomment the following line t"..., 4096) = 1589
read(3, "", 4096)                       = 0
close(3)                                = 0
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=23979, ...}) = 0
mmap(NULL, 23979, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f65cdcb2000
close(3)                                = 0
openat(AT_FDCWD, "/lib64/libnss_sss.so.2", O_RDONLY|O_CLOEXEC) = 3
read(3,
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\260%\0\0\0\0\0\0"..., 832)
= 832
fstat(3, {st_mode=S_IFREG|0755, st_size=53480, ...}) = 0
mmap(NULL, 53856, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) =
0x7f65cdca4000
mmap(0x7f65cdca6000, 32768, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7f65cdca6000
mmap(0x7f65cdcae000, 8192, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE,
3, 0xa000) = 0x7f65cdcae000
mmap(0x7f65cdcb0000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xb000) = 0x7f65cdcb0000
close(3)                                = 0
mprotect(0x7f65cdcb0000, 4096, PROT_READ) = 0
munmap(0x7f65cdcb2000, 23979)           = 0
openat(AT_FDCWD, "/var/lib/sss/mc/passwd", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0664, st_size=9253600, ...}) = 0
mmap(NULL, 9253600, PROT_READ, MAP_SHARED, 3, 0) = 0x7f65cd3d0000
fstat(3, {st_mode=S_IFREG|0664, st_size=9253600, ...}) = 0
futex(0x7f65cdcb1214, FUTEX_WAKE_PRIVATE, 2147483647) = 0
fstat(3, {st_mode=S_IFREG|0664, st_size=9253600, ...}) = 0
futex(0x7f65cdcb1250, FUTEX_WAKE_PRIVATE, 2147483647) = 0
newfstatat(AT_FDCWD, "/proc/self/", {st_mode=S_IFDIR|0555, st_size=0, ...},
AT_SYMLINK_NOFOLLOW) = 0
getpid()                                = 80345
fstat(-1, 0x7ffdc0738100)               = -1 EBADF (Bad file descriptor)
socket(AF_UNIX, SOCK_STREAM, 0)         = 4
fcntl(4, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(4, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
fcntl(4, F_GETFD)                       = 0
fcntl(4, F_SETFD, FD_CLOEXEC)           = 0
connect(4, {sa_family=AF_UNIX, sun_path="/var/lib/sss/pipes/nss"}, 110) = 0
fstat(4, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0
poll([{fd=4, events=POLLOUT}], 1, 300000) = 1 ([{fd=4, revents=POLLOUT}])
sendto(4, "\24\0\0\0\1\0\0\0\0\0\0\0\0\0\0\0", 16, MSG_NOSIGNAL, NULL, 0) =
16
poll([{fd=4, events=POLLOUT}], 1, 300000) = 1 ([{fd=4, revents=POLLOUT}])
sendto(4, "\1\0\0\0", 4, MSG_NOSIGNAL, NULL, 0) = 4
poll([{fd=4, events=POLLIN}], 1, 300000) = 1 ([{fd=4, revents=POLLIN}])
read(4, "\24\0\0\0\1\0\0\0\0\0\0\0\0\0\0\0", 16) = 16
poll([{fd=4, events=POLLIN}], 1, 300000) = 1 ([{fd=4, revents=POLLIN}])
read(4, "\1\0\0\0", 4)                  = 4
poll([{fd=4, events=POLLOUT}], 1, 300000) = 1 ([{fd=4, revents=POLLOUT}])
sendto(4, "\24\0\0\0\22\0\0\0\0\0\0\0\0\0\0\0", 16, MSG_NOSIGNAL, NULL, 0)
= 16
poll([{fd=4, events=POLLOUT}], 1, 300000) = 1 ([{fd=4, revents=POLLOUT}])
sendto(4, "\363\372\256\1", 4, MSG_NOSIGNAL, NULL, 0) = 4
poll([{fd=4, events=POLLIN}], 1, 300000) = 1 ([{fd=4, revents=POLLIN}])
read(4, "\30\0\0\0\22\0\0\0\0\0\0\0\0\0\0\0", 16) = 16
poll([{fd=4, events=POLLIN}], 1, 300000) = 1 ([{fd=4, revents=POLLIN}])
read(4, "\0\0\0\0\0\0\0\0", 8)          = 8
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 5
fstat(5, {st_mode=S_IFREG|0644, st_size=23979, ...}) = 0
mmap(NULL, 23979, PROT_READ, MAP_PRIVATE, 5, 0) = 0x7f65cdcb2000
close(5)                                = 0
openat(AT_FDCWD, "/lib64/libnss_systemd.so.2", O_RDONLY|O_CLOEXEC) = 5
read(5,
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\260\203\0\0\0\0\0\0"...,
832) = 832
fstat(5, {st_mode=S_IFREG|0755, st_size=353400, ...}) = 0
mmap(NULL, 350752, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 5, 0) =
0x7f65cd37a000
mmap(0x7f65cd381000, 229376, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 5, 0x7000) = 0x7f65cd381000
mmap(0x7f65cd3b9000, 73728, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE,
5, 0x3f000) = 0x7f65cd3b9000
mmap(0x7f65cd3cb000, 20480, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 5, 0x50000) = 0x7f65cd3cb000
close(5)                                = 0
openat(AT_FDCWD, "/lib64/libm.so.6", O_RDONLY|O_CLOEXEC) = 5
read(5,
"\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\220\323\0\0\0\0\0\0"...,
832) = 832
fstat(5, {st_mode=S_IFREG|0755, st_size=912440, ...}) = 0
mmap(NULL, 893184, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 5, 0) =
0x7f65cd29f000
mmap(0x7f65cd2ac000, 458752, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 5, 0xd000) = 0x7f65cd2ac000
mmap(0x7f65cd31c000, 376832, PROT_READ,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 5, 0x7d000) = 0x7f65cd31c000
mmap(0x7f65cd378000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 5, 0xd8000) = 0x7f65cd378000
close(5)                                = 0
openat(AT_FDCWD, "/lib64/libcrypt.so.2", O_RDONLY|O_CLOEXEC) = 5
read(5, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P \0\0\0\0\0\0"...,
832) = 832
fstat(5, {st_mode=S_IFREG|0755, st_size=201832, ...}) = 0
mmap(NULL, 233728, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 5, 0) =
0x7f65cd265000
mprotect(0x7f65cd267000, 188416, PROT_NONE) = 0
mmap(0x7f65cd267000, 81920, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 5, 0x2000) = 0x7f65cd267000
mmap(0x7f65cd27b000, 102400, PROT_READ,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 5, 0x16000) = 0x7f65cd27b000
mmap(0x7f65cd295000, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 5, 0x2f000) = 0x7f65cd295000
mmap(0x7f65cd296000, 33024, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f65cd296000
close(5)                                = 0
openat(AT_FDCWD, "/lib64/libcrypto.so.3", O_RDONLY|O_CLOEXEC) = 5
read(5, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0`\v\0\0\0\0\0"...,
832) = 832
fstat(5, {st_mode=S_IFREG|0755, st_size=5435408, ...}) = 0
mmap(NULL, 5344208, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 5, 0) =
0x7f65ccd4c000
mmap(0x7f65cce00000, 3334144, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 5, 0xb4000) = 0x7f65cce00000
mmap(0x7f65cd12e000, 876544, PROT_READ,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 5, 0x3e2000) = 0x7f65cd12e000
mmap(0x7f65cd204000, 385024, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 5, 0x4b7000) = 0x7f65cd204000
mmap(0x7f65cd262000, 11216, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f65cd262000
close(5)                                = 0
openat(AT_FDCWD, "/lib64/libp11-kit.so.0", O_RDONLY|O_CLOEXEC) = 5
read(5,
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\20b\3\0\0\0\0\0"..., 832) =
832
fstat(5, {st_mode=S_IFREG|0755, st_size=1714240, ...}) = 0
mmap(NULL, 1664200, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 5, 0) =
0x7f65ccbb5000
mmap(0x7f65ccbea000, 864256, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 5, 0x35000) = 0x7f65ccbea000
mmap(0x7f65cccbd000, 479232, PROT_READ,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 5, 0x108000) = 0x7f65cccbd000
mmap(0x7f65ccd32000, 102400, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 5, 0x17c000) = 0x7f65ccd32000
mmap(0x7f65ccd4b000, 1224, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f65ccd4b000
close(5)                                = 0
openat(AT_FDCWD, "/lib64/libgcc_s.so.1", O_RDONLY|O_CLOEXEC) = 5
read(5,
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\3605\0\0\0\0\0\0"..., 832)
= 832
fstat(5, {st_mode=S_IFREG|0755, st_size=108136, ...}) = 0
mmap(NULL, 107208, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 5, 0) =
0x7f65ccb9a000
mprotect(0x7f65ccb9d000, 90112, PROT_NONE) = 0
mmap(0x7f65ccb9d000, 73728, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 5, 0x3000) = 0x7f65ccb9d000
mmap(0x7f65ccbaf000, 12288, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE,
5, 0x15000) = 0x7f65ccbaf000
mmap(0x7f65ccbb3000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 5, 0x18000) = 0x7f65ccbb3000
close(5)                                = 0
openat(AT_FDCWD, "/lib64/libz.so.1", O_RDONLY|O_CLOEXEC) = 5
read(5,
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\3605\0\0\0\0\0\0"..., 832)
= 832
fstat(5, {st_mode=S_IFREG|0755, st_size=102552, ...}) = 0
mmap(NULL, 102408, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 5, 0) =
0x7f65ccb80000
mprotect(0x7f65ccb83000, 86016, PROT_NONE) = 0
mmap(0x7f65ccb83000, 57344, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 5, 0x3000) = 0x7f65ccb83000
mmap(0x7f65ccb91000, 24576, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE,
5, 0x11000) = 0x7f65ccb91000
mmap(0x7f65ccb98000, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 5, 0x17000) = 0x7f65ccb98000
mmap(0x7f65ccb99000, 8, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f65ccb99000
close(5)                                = 0
openat(AT_FDCWD, "/lib64/libffi.so.8", O_RDONLY|O_CLOEXEC) = 5
read(5,
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\220%\0\0\0\0\0\0"..., 832)
= 832
fstat(5, {st_mode=S_IFREG|0755, st_size=44784, ...}) = 0
mmap(NULL, 46320, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 5, 0) =
0x7f65ccb74000
mprotect(0x7f65ccb76000, 32768, PROT_NONE) = 0
mmap(0x7f65ccb76000, 24576, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 5, 0x2000) = 0x7f65ccb76000
mmap(0x7f65ccb7c000, 4096, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE,
5, 0x8000) = 0x7f65ccb7c000
mmap(0x7f65ccb7e000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 5, 0x9000) = 0x7f65ccb7e000
close(5)                                = 0
mprotect(0x7f65ccb7e000, 4096, PROT_READ) = 0
mprotect(0x7f65ccb98000, 4096, PROT_READ) = 0
mprotect(0x7f65ccbb3000, 4096, PROT_READ) = 0
mprotect(0x7f65ccd32000, 49152, PROT_READ) = 0
mprotect(0x7f65cd204000, 372736, PROT_READ) = 0
mprotect(0x7f65cd295000, 4096, PROT_READ) = 0
mprotect(0x7f65cd378000, 4096, PROT_READ) = 0
mprotect(0x7f65cd3cb000, 16384, PROT_READ) = 0
munmap(0x7f65cdcb2000, 23979)           = 0
rt_sigprocmask(SIG_BLOCK, [HUP USR1 USR2 PIPE ALRM CHLD TSTP URG VTALRM
PROF WINCH IO], [], 8) = 0
futex(0x7f65cd3cf9f8, FUTEX_WAKE_PRIVATE, 2147483647) = 0
openat(AT_FDCWD, "/run/systemd/userdb/",
O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 5
fstat(5, {st_mode=S_IFDIR|0755, st_size=60, ...}) = 0
getdents64(5, 0x55db02b699a0 /* 3 entries */, 32768) = 96
socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 6
connect(6, {sa_family=AF_UNIX,
sun_path="/run/systemd/userdb/io.systemd.DynamicUser"}, 45) = 0
getpid()                                = 80345
epoll_create1(EPOLL_CLOEXEC)            = 7
timerfd_create(CLOCK_MONOTONIC, TFD_CLOEXEC|TFD_NONBLOCK) = 8
epoll_ctl(7, EPOLL_CTL_ADD, 8, {events=EPOLLIN, data={u32=45554736,
u64=94399131753520}}) = 0
epoll_ctl(7, EPOLL_CTL_ADD, 6, {events=0, data={u32=45556656,
u64=94399131755440}}) = 0
getrandom("\xce\x08\xdf\xa4\x68\x03\x32\x43\xff\x10\x9e\x2d\x30\x84\x84\x3c",
16, GRND_INSECURE) = 16
futex(0x7f65cd3cf0c0, FUTEX_WAKE_PRIVATE, 2147483647) = 0
getdents64(5, 0x55db02b699a0 /* 0 entries */, 32768) = 0
close(5)                                = 0
epoll_ctl(7, EPOLL_CTL_MOD, 6, {events=EPOLLIN|EPOLLOUT,
data={u32=45556656, u64=94399131755440}}) = 0
openat(AT_FDCWD, "/proc/sys/kernel/random/boot_id",
O_RDONLY|O_NOCTTY|O_CLOEXEC) = 5
read(5, "a5db6380-3d63-4be2-8039-350ae5a9"..., 38) = 37
read(5, "", 1)                          = 0
close(5)                                = 0
timerfd_settime(8, TFD_TIMER_ABSTIME, {it_interval={tv_sec=0, tv_nsec=0},
it_value={tv_sec=1402937, tv_nsec=562741000}}, NULL) = 0
epoll_wait(7, [{events=EPOLLOUT, data={u32=45556656, u64=94399131755440}}],
8, 0) = 1
sendto(6, "{"method":"io.systemd.UserDataba"..., 116,
MSG_DONTWAIT|MSG_NOSIGNAL, NULL, 0) = 116
epoll_ctl(7, EPOLL_CTL_MOD, 6, {events=EPOLLIN, data={u32=45556656,
u64=94399131755440}}) = 0
epoll_wait(7, [], 8, 0)                 = 0
mmap(NULL, 135168, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0)
= 0x7f65ccb53000
recvfrom(6, "{"error":"io.systemd.UserDatabas"..., 135152, MSG_DONTWAIT,
NULL, NULL) = 66
epoll_ctl(7, EPOLL_CTL_MOD, 6, {events=0, data={u32=45556656,
u64=94399131755440}}) = 0
epoll_wait(7, [], 8, 0)                 = 0
epoll_wait(7, [], 8, 0)                 = 0
epoll_ctl(7, EPOLL_CTL_DEL, 6, NULL)    = 0
close(6)                                = 0
munmap(0x7f65ccb53000, 135168)          = 0
openat(AT_FDCWD, "/", O_RDONLY|O_CLOEXEC|O_PATH|O_DIRECTORY) = 5
openat(5, "etc", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = 6
fstat(6, {st_mode=S_IFDIR|0755, st_size=3760, ...}) = 0
close(5)                                = 0
openat(6, "userdb", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = -1 ENOENT (No
such file or directory)
close(6)                                = 0
openat(AT_FDCWD, "/", O_RDONLY|O_CLOEXEC|O_PATH|O_DIRECTORY) = 5
openat(5, "run", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = 6
fstat(6, {st_mode=S_IFDIR|S_ISVTX|0777, st_size=800, ...}) = 0
close(5)                                = 0
openat(6, "userdb", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = -1 ENOENT (No
such file or directory)
close(6)                                = 0
openat(AT_FDCWD, "/", O_RDONLY|O_CLOEXEC|O_PATH|O_DIRECTORY) = 5
openat(5, "run", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = 6
fstat(6, {st_mode=S_IFDIR|S_ISVTX|0777, st_size=800, ...}) = 0
close(5)                                = 0
openat(6, "host", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = -1 ENOENT (No
such file or directory)
close(6)                                = 0
openat(AT_FDCWD, "/", O_RDONLY|O_CLOEXEC|O_PATH|O_DIRECTORY) = 5
openat(5, "usr", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = 6
fstat(6, {st_mode=S_IFDIR|0755, st_size=260, ...}) = 0
close(5)                                = 0
openat(6, "local", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = 5
fstat(5, {st_mode=S_IFDIR|0755, st_size=240, ...}) = 0
close(6)                                = 0
openat(5, "lib", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = 6
fstat(6, {st_mode=S_IFDIR|0755, st_size=40, ...}) = 0
close(5)                                = 0
openat(6, "userdb", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = -1 ENOENT (No
such file or directory)
close(6)                                = 0
openat(AT_FDCWD, "/", O_RDONLY|O_CLOEXEC|O_PATH|O_DIRECTORY) = 5
openat(5, "usr", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = 6
fstat(6, {st_mode=S_IFDIR|0755, st_size=260, ...}) = 0
close(5)                                = 0
openat(6, "lib", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = 5
fstat(5, {st_mode=S_IFDIR|0555, st_size=680, ...}) = 0
close(6)                                = 0
openat(5, "userdb", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = -1 ENOENT (No
such file or directory)
close(5)                                = 0
openat(AT_FDCWD, "/etc/userdb/28244723.user", O_RDONLY|O_CLOEXEC) = -1
ENOENT (No such file or directory)
openat(AT_FDCWD, "/run/userdb/28244723.user", O_RDONLY|O_CLOEXEC) = -1
ENOENT (No such file or directory)
openat(AT_FDCWD, "/run/host/userdb/28244723.user", O_RDONLY|O_CLOEXEC) = -1
ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/local/lib/userdb/28244723.user", O_RDONLY|O_CLOEXEC)
= -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/userdb/28244723.user", O_RDONLY|O_CLOEXEC) = -1
ENOENT (No such file or directory)
close(7)                                = 0
close(8)                                = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 5
connect(5, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = -1
ENOENT (No such file or directory)
close(5)                                = 0
socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 5
connect(5, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = -1
ENOENT (No such file or directory)
close(5)                                = 0
newfstatat(AT_FDCWD, "/etc/nsswitch.conf", {st_mode=S_IFREG|0644,
st_size=2980, ...}, 0) = 0
openat(AT_FDCWD, "/etc/group", O_RDONLY|O_CLOEXEC) = 5
fstat(5, {st_mode=S_IFREG|0644, st_size=615, ...}) = 0
lseek(5, 0, SEEK_SET)                   = 0
read(5, "root:x:0:\nbin:x:1:\ndaemon:x:2:\ns"..., 4096) = 615
read(5, "", 4096)                       = 0
close(5)                                = 0
openat(AT_FDCWD, "/var/lib/sss/mc/group", O_RDONLY|O_CLOEXEC) = 5
fstat(5, {st_mode=S_IFREG|0664, st_size=6940392, ...}) = 0
mmap(NULL, 6940392, PROT_READ, MAP_SHARED, 5, 0) = 0x7f65cc4d5000
fstat(5, {st_mode=S_IFREG|0664, st_size=6940392, ...}) = 0
fstat(5, {st_mode=S_IFREG|0664, st_size=6940392, ...}) = 0
newfstatat(AT_FDCWD, "/proc/self/", {st_mode=S_IFDIR|0555, st_size=0, ...},
AT_SYMLINK_NOFOLLOW) = 0
getpid()                                = 80345
fstat(4, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0
poll([{fd=4, events=POLLIN|POLLOUT}], 1, 300000) = 1 ([{fd=4,
revents=POLLOUT}])
poll([{fd=4, events=POLLOUT}], 1, 300000) = 1 ([{fd=4, revents=POLLOUT}])
sendto(4, "\24\0\0\0"\0\0\0\0\0\0\0\0\0\0\0", 16, MSG_NOSIGNAL, NULL, 0) =
16
poll([{fd=4, events=POLLOUT}], 1, 300000) = 1 ([{fd=4, revents=POLLOUT}])
sendto(4, "r\334\261\1", 4, MSG_NOSIGNAL, NULL, 0) = 4
poll([{fd=4, events=POLLIN}], 1, 300000) = 1 ([{fd=4, revents=POLLIN}])
read(4, "\30\0\0\0"\0\0\0\0\0\0\0\0\0\0\0", 16) = 16
poll([{fd=4, events=POLLIN}], 1, 300000) = 1 ([{fd=4, revents=POLLIN}])
read(4, "\0\0\0\0\0\0\0\0", 8)          = 8
rt_sigprocmask(SIG_BLOCK, [HUP USR1 USR2 PIPE ALRM CHLD TSTP URG VTALRM
PROF WINCH IO], [], 8) = 0
openat(AT_FDCWD, "/run/systemd/userdb/",
O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 6
fstat(6, {st_mode=S_IFDIR|0755, st_size=60, ...}) = 0
getdents64(6, 0x55db02b72da0 /* 3 entries */, 32768) = 96
socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 7
connect(7, {sa_family=AF_UNIX,
sun_path="/run/systemd/userdb/io.systemd.DynamicUser"}, 45) = 0
epoll_create1(EPOLL_CLOEXEC)            = 8
timerfd_create(CLOCK_MONOTONIC, TFD_CLOEXEC|TFD_NONBLOCK) = 9
epoll_ctl(8, EPOLL_CTL_ADD, 9, {events=EPOLLIN, data={u32=45554736,
u64=94399131753520}}) = 0
epoll_ctl(8, EPOLL_CTL_ADD, 7, {events=0, data={u32=45555408,
u64=94399131754192}}) = 0
getdents64(6, 0x55db02b72da0 /* 0 entries */, 32768) = 0
close(6)                                = 0
epoll_ctl(8, EPOLL_CTL_MOD, 7, {events=EPOLLIN|EPOLLOUT,
data={u32=45555408, u64=94399131754192}}) = 0
timerfd_settime(9, TFD_TIMER_ABSTIME, {it_interval={tv_sec=0, tv_nsec=0},
it_value={tv_sec=1402937, tv_nsec=562741000}}, NULL) = 0
epoll_wait(8, [{events=EPOLLOUT, data={u32=45555408, u64=94399131754192}}],
8, 0) = 1
sendto(7, "{"method":"io.systemd.UserDataba"..., 117,
MSG_DONTWAIT|MSG_NOSIGNAL, NULL, 0) = 117
epoll_ctl(8, EPOLL_CTL_MOD, 7, {events=EPOLLIN, data={u32=45555408,
u64=94399131754192}}) = 0
epoll_wait(8, [], 8, 0)                 = 0
brk(0x55db02bb3000)                     = 0x55db02bb3000
recvfrom(7, "{"error":"io.systemd.UserDatabas"..., 131080, MSG_DONTWAIT,
NULL, NULL) = 66
epoll_ctl(8, EPOLL_CTL_MOD, 7, {events=0, data={u32=45555408,
u64=94399131754192}}) = 0
epoll_wait(8, [], 8, 0)                 = 0
epoll_wait(8, [], 8, 0)                 = 0
epoll_ctl(8, EPOLL_CTL_DEL, 7, NULL)    = 0
close(7)                                = 0
openat(AT_FDCWD, "/", O_RDONLY|O_CLOEXEC|O_PATH|O_DIRECTORY) = 6
openat(6, "etc", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = 7
fstat(7, {st_mode=S_IFDIR|0755, st_size=3760, ...}) = 0
close(6)                                = 0
openat(7, "userdb", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = -1 ENOENT (No
such file or directory)
close(7)                                = 0
openat(AT_FDCWD, "/", O_RDONLY|O_CLOEXEC|O_PATH|O_DIRECTORY) = 6
openat(6, "run", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = 7
fstat(7, {st_mode=S_IFDIR|S_ISVTX|0777, st_size=800, ...}) = 0
close(6)                                = 0
openat(7, "userdb", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = -1 ENOENT (No
such file or directory)
close(7)                                = 0
openat(AT_FDCWD, "/", O_RDONLY|O_CLOEXEC|O_PATH|O_DIRECTORY) = 6
openat(6, "run", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = 7
fstat(7, {st_mode=S_IFDIR|S_ISVTX|0777, st_size=800, ...}) = 0
close(6)                                = 0
openat(7, "host", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = -1 ENOENT (No
such file or directory)
close(7)                                = 0
openat(AT_FDCWD, "/", O_RDONLY|O_CLOEXEC|O_PATH|O_DIRECTORY) = 6
openat(6, "usr", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = 7
fstat(7, {st_mode=S_IFDIR|0755, st_size=260, ...}) = 0
close(6)                                = 0
openat(7, "local", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = 6
fstat(6, {st_mode=S_IFDIR|0755, st_size=240, ...}) = 0
close(7)                                = 0
openat(6, "lib", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = 7
fstat(7, {st_mode=S_IFDIR|0755, st_size=40, ...}) = 0
close(6)                                = 0
openat(7, "userdb", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = -1 ENOENT (No
such file or directory)
close(7)                                = 0
openat(AT_FDCWD, "/", O_RDONLY|O_CLOEXEC|O_PATH|O_DIRECTORY) = 6
openat(6, "usr", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = 7
fstat(7, {st_mode=S_IFDIR|0755, st_size=260, ...}) = 0
close(6)                                = 0
openat(7, "lib", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = 6
fstat(6, {st_mode=S_IFDIR|0555, st_size=680, ...}) = 0
close(7)                                = 0
openat(6, "userdb", O_RDONLY|O_NOFOLLOW|O_CLOEXEC|O_PATH) = -1 ENOENT (No
such file or directory)
close(6)                                = 0
openat(AT_FDCWD, "/etc/userdb/28433522.group", O_RDONLY|O_CLOEXEC) = -1
ENOENT (No such file or directory)
openat(AT_FDCWD, "/run/userdb/28433522.group", O_RDONLY|O_CLOEXEC) = -1
ENOENT (No such file or directory)
openat(AT_FDCWD, "/run/host/userdb/28433522.group", O_RDONLY|O_CLOEXEC) =
-1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/local/lib/userdb/28433522.group",
O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/userdb/28433522.group", O_RDONLY|O_CLOEXEC) = -1
ENOENT (No such file or directory)
close(8)                                = 0
close(9)                                = 0
newfstatat(AT_FDCWD, "/etc/nsswitch.conf", {st_mode=S_IFREG|0644,
st_size=2980, ...}, 0) = 0
openat(AT_FDCWD, "/etc/group", O_RDONLY|O_CLOEXEC) = 6
fstat(6, {st_mode=S_IFREG|0644, st_size=615, ...}) = 0
lseek(6, 0, SEEK_SET)                   = 0
read(6, "root:x:0:\nbin:x:1:\ndaemon:x:2:\ns"..., 4096) = 615
read(6, "", 4096)                       = 0
close(6)                                = 0
fstat(5, {st_mode=S_IFREG|0664, st_size=6940392, ...}) = 0
fstat(5, {st_mode=S_IFREG|0664, st_size=6940392, ...}) = 0
newfstatat(AT_FDCWD, "/proc/self/", {st_mode=S_IFDIR|0555, st_size=0, ...},
AT_SYMLINK_NOFOLLOW) = 0
getpid()                                = 80345
fstat(4, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0
poll([{fd=4, events=POLLIN|POLLOUT}], 1, 300000) = 1 ([{fd=4,
revents=POLLOUT}])
poll([{fd=4, events=POLLOUT}], 1, 300000) = 1 ([{fd=4, revents=POLLOUT}])
sendto(4, "\24\0\0\0"\0\0\0\0\0\0\0\0\0\0\0", 16, MSG_NOSIGNAL, NULL, 0) =
16
poll([{fd=4, events=POLLOUT}], 1, 300000) = 1 ([{fd=4, revents=POLLOUT}])
sendto(4, "r\334\261\1", 4, MSG_NOSIGNAL, NULL, 0) = 4
poll([{fd=4, events=POLLIN}], 1, 300000) = 1 ([{fd=4, revents=POLLIN}])
read(4, "\30\0\0\0"\0\0\0\0\0\0\0\0\0\0\0", 16) = 16
poll([{fd=4, events=POLLIN}], 1, 300000) = 1 ([{fd=4, revents=POLLIN}])
read(4, "\0\0\0\0\0\0\0\0", 8)          = 8
rt_sigprocmask(SIG_BLOCK, [HUP USR1 USR2 PIPE ALRM CHLD TSTP URG VTALRM
PROF WINCH IO], [HUP USR1 USR2 PIPE ALRM CHLD TSTP URG VTALRM PROF WINCH
IO], 8) = 0
rt_sigprocmask(SIG_SETMASK, [HUP USR1 USR2 PIPE ALRM CHLD TSTP URG VTALRM
PROF WINCH IO], NULL, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
openat(AT_FDCWD, "/home/lck", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 6
fstat(6, {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
getdents64(6, 0x55db02b72d60 /* 19 entries */, 32768) = 592
statx(AT_FDCWD, "/home/lck/scripts",
AT_STATX_SYNC_AS_STAT|AT_SYMLINK_NOFOLLOW|AT_NO_AUTOMOUNT,
STATX_MODE|STATX_NLINK|STATX_UID|STATX_GID|STATX_MTIME|STATX_SIZE,
{stx_mask=STATX_BASIC_STATS|STATX_MNT_ID, stx_attributes=0,
stx_mode=S_IFDIR|0755, stx_size=4096, ...}) = 0
statx(AT_FDCWD, "/home/lck/Documents",
AT_STATX_SYNC_AS_STAT|AT_SYMLINK_NOFOLLOW|AT_NO_AUTOMOUNT,
STATX_MODE|STATX_NLINK|STATX_UID|STATX_GID|STATX_MTIME|STATX_SIZE,
{stx_mask=STATX_BASIC_STATS|STATX_MNT_ID, stx_attributes=0,
stx_mode=S_IFDIR|0755, stx_size=4096, ...}) = 0
statx(AT_FDCWD, "/home/lck/apps",
AT_STATX_SYNC_AS_STAT|AT_SYMLINK_NOFOLLOW|AT_NO_AUTOMOUNT,
STATX_MODE|STATX_NLINK|STATX_UID|STATX_GID|STATX_MTIME|STATX_SIZE,
{stx_mask=STATX_BASIC_STATS|STATX_MNT_ID, stx_attributes=0,
stx_mode=S_IFDIR|0755, stx_size=4096, ...}) = 0
getdents64(6, 0x55db02b72d60 /* 0 entries */, 32768) = 0
close(6)                                = 0
openat(AT_FDCWD, "/usr/share/locale/C.UTF-8/LC_MESSAGES/coreutils.mo",
O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/locale/C.utf8/LC_MESSAGES/coreutils.mo",
O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/locale/C/LC_MESSAGES/coreutils.mo", O_RDONLY)
= -1 ENOENT (No such file or directory)
fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(0x88, 0), ...}) = 0
write(1, "total 12\n", 9total 12
)               = 9
openat(AT_FDCWD, "/etc/localtime", O_RDONLY|O_CLOEXEC) = 6
fstat(6, {st_mode=S_IFREG|0644, st_size=114, ...}) = 0
fstat(6, {st_mode=S_IFREG|0644, st_size=114, ...}) = 0
read(6, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
4096) = 114
lseek(6, -60, SEEK_CUR)                 = 54
read(6, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
4096) = 60
close(6)                                = 0
write(1, "drwxr-xr-x 3 28244723 28433522 4"..., 59drwxr-xr-x 3 28244723
28433522 4096 Jan 28 14:19 Documents
) = 59
write(1, "drwxr-xr-x 8 28244723 28433522 4"..., 54drwxr-xr-x 8 28244723
28433522 4096 Feb  6 12:25 apps
) = 54
write(1, "drwxr-xr-x 4 28244723 28433522 4"..., 57drwxr-xr-x 4 28244723
28433522 4096 Feb 12 15:36 scripts
) = 57
close(1)                                = 0
close(2)                                = 0
close(4)                                = 0
exit_group(0)                           = ?
+++ exited with 0 +++

-----------

Following:

[root@acad-cnode006 ~]# ls -l /home/lck
total 12
drwxr-xr-x 3 28244723 28433522 4096 Jan 28 14:19 Documents
drwxr-xr-x 8 28244723 28433522 4096 Feb  6 12:25 apps
drwxr-xr-x 4 28244723 28433522 4096 Feb 12 15:36 scripts

----------

-- lawrence

On Fri, Feb 14, 2025 at 3:40 PM Alexey Tikhonov via sssd-users <
[e-mail]> wrote:
> On Fri, Feb 14, 2025 at 9:33 PM Alexey Tikhonov 
> wrote:
> > Hi,
> > > The nodes mount NFS file systems but do not resolve file and directory
>
> ownerships for LDAP users
> > Could you please run `strace ls file_on_nfs` and `ltrace ls
> > file_on_nfs` (when uid:gid aren't resolved) and share logs?
> 'ls -l'
> > On Fri, Feb 14, 2025 at 8:45 PM Lawrence Kearney via sssd-users
> >  wrote:
> > > I hope someone can help. I have an odd issue I haven't seen before.
>
> I've done a lot of checking under the hood, but I'm stuck.
> > > We have hundreds of systems using the v2.9+ of the daemon (AD and LDAP
>
> providers). We're deploying a new HPC cluster using Rocky Linux 9
> containers (all other systems are RHEL 8/9) as stateless compute nodes.
> These nodes are ephemeral so we use the LDAP providers.
> > > The observed issue is the daemons load and run as expected. The nodes
>
> mount NFS file systems but do not resolve file and directory ownerships for
> LDAP users until I manually run a "getent" or "id" on any user or group. It
> doesn't even have to be a user or group that owns files. So any type of NSS
> lookup seems to kick start the process. From there the node is fine.
> > > libnfs, libnss, sssd-nfs-idmap, libsss_nss_idmap, etc are all the same
>
> on nodes that don't do this.
> > > DNS works, there's no difference in daemon configurations from working
>
> ones. systemd unit files are identical, etc. I cannot figure out why these
> nodes need to be poked by NSS to start using NSS. Very peculiar.
> > > Any insight would be appreciated,
> > >
> > > -- lawrence
> > >
> > > --
> > > _______________________________________________
> > > sssd-users mailing list -- [e-mail]
> > > To unsubscribe send an email to
>
> [e-mail]
> > > Fedora Code of Conduct:
>
> https://docs.fedoraproject.org/en-US/project/code-of-conduct/
> > > List Guidelines:
>
> https://fedoraproject.org/wiki/Mailing_list_guidelines
> > > List Archives:
>
> https://lists.fedorahosted.org/archives/list/[e-mail].o...
> > > Do not reply to spam, report it:
>
> https://pagure.io/fedora-infrastructure/new_issue
>
> --
> _______________________________________________
> sssd-users mailing list -- [e-mail]
> To unsubscribe send an email to [e-mail]
> Fedora Code of Conduct:
> https://docs.fedoraproject.org/en-US/project/code-of-conduct/
> List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
> List Archives:
> https://lists.fedorahosted.org/archives/list/[e-mail].o...
> Do not reply to spam, report it:
> https://pagure.io/fedora-infrastructure/new_issue

[Alexey Tikhonov]

On Fri, Feb 14, 2025 at 11:10 PM Lawrence Kearney via sssd-users <
[e-mail]> wrote:
> Alex,
> Sure. As a base, the daemon status and original call:

Thanks. At least, it does talk to SSSD:
```
connect(4, {sa_family=AF_UNIX, sun_path="/var/lib/sss/pipes/nss"}, 110) = 0
...
sendto(4, "\24\0\0\0\22\0\0\0\0\0\0\0\0\0\0\0", 16, MSG_NOSIGNAL, NULL, 0)
= 16  --  SSS_NSS_GETPWUID
sendto(4, "\363\372\256\1", 4, MSG_NOSIGNAL, NULL, 0) = 4  --  UID being
looked up, but if I parse this correctly, this is not 28244723, but
179959027
read(4, "\30\0\0\0\22\0\0\0\0\0\0\0\0\0\0\0", 16) = 16  --
 response(SSS_NSS_GETPWUID), no server error
read(4, "\0\0\0\0\0\0\0\0", 8)         = 8  --  NSS_STATUS_NOTFOUND
```
  --  if I parse strace correctly, it looks up a wrong id... sure thing
SSSD replies NOTFOUND
Next it continues with the next provider from nsswitch.conf - systemd - but
payload is cut so we can't say it it looks up the same (wrong?) id there:
```
connect(6, {sa_family=AF_UNIX,
sun_path="/run/systemd/userdb/io.systemd.DynamicUser"}, 45) = 0
...
sendto(6, "{"method":"io.systemd.UserDataba"..., 116,
MSG_DONTWAIT|MSG_NOSIGNAL, NULL, 0) = 116
```

The same with SSS_NSS_GETGRGID: it looks up "r\334\261\1" == 180729970, not
28433522...

I've also asked for 'ltrace' of the same command. Have you got it?

[Alexey Tikhonov]

On Sat, Feb 15, 2025 at 10:46 AM Alexey Tikhonov 
wrote:
> On Fri, Feb 14, 2025 at 11:10 PM Lawrence Kearney via sssd-users <
> [e-mail]> wrote:
> > Alex,
> > Sure. As a base, the daemon status and original call:
>
> Thanks. At least, it does talk to SSSD:
> connect(4, {sa_family=AF_UNIX, sun_path="/var/lib/sss/pipes/nss"}, 110) = 0
> ...
> sendto(4, "\24\0\0\0\22\0\0\0\0\0\0\0\0\0\0\0", 16, MSG_NOSIGNAL, NULL, 0)
> = 16  --  SSS_NSS_GETPWUID
> sendto(4, "\363\372\256\1", 4, MSG_NOSIGNAL, NULL, 0) = 4  --  UID being
> looked up, but if I parse this correctly, this is not 28244723, but
> 179959027
> read(4, "\30\0\0\0\22\0\0\0\0\0\0\0\0\0\0\0", 16) = 16  --
>  response(SSS_NSS_GETPWUID), no server error
> read(4, "\0\0\0\0\0\0\0\0", 8)         = 8  --  NSS_STATUS_NOTFOUND
>
> --  if I parse strace correctly, it looks up a wrong id... sure thing
> SSSD replies NOTFOUND
> Next it continues with the next provider from nsswitch.conf - systemd -
> but payload is cut so we can't say it it looks up the same (wrong?) id
> there:
> connect(6, {sa_family=AF_UNIX,
> sun_path="/run/systemd/userdb/io.systemd.DynamicUser"}, 45) = 0
> ...
> sendto(6, "{\"method\":\"io.systemd.UserDataba"..., 116,
> MSG_DONTWAIT|MSG_NOSIGNAL, NULL, 0) = 116
>
> The same with SSS_NSS_GETGRGID: it looks up "r\334\261\1" == 180729970,
> not 28433522...
>
> I've also asked for 'ltrace' of the same command. Have you got it?

`ltrace ls -l /home/lck`

[Alexey Tikhonov]

ltrace shows:
```
getpwuid(0x1aefaf3, 0, 0x7ffe281653b6, 0)
```
0x1aefaf3  ==  28244723, correct UID.

At this moment I'm unsure if I misread `strace` output or how the value
gets changed by the moment the request is sent to 'sssd_nss'...

Could you please set 'debug_level = 9' in the '[nss]' section of
'sssd.conf' and get /var/log/sssd_nss.log covering this 1st malfunction
lookup?

On Sat, Feb 15, 2025 at 10:48 AM Alexey Tikhonov 
wrote:
> On Sat, Feb 15, 2025 at 10:46 AM Alexey Tikhonov 
> wrote:
> > On Fri, Feb 14, 2025 at 11:10 PM Lawrence Kearney via sssd-users <
> > [e-mail]> wrote:
> > > Alex,
> > > Sure. As a base, the daemon status and original call:
> >
> > Thanks. At least, it does talk to SSSD:
> > connect(4, {sa_family=AF_UNIX, sun_path="/var/lib/sss/pipes/nss"}, 110) =
> > 0
> > ...
> > sendto(4, "\24\0\0\0\22\0\0\0\0\0\0\0\0\0\0\0", 16, MSG_NOSIGNAL, NULL,
> > 0) = 16  --  SSS_NSS_GETPWUID
> > sendto(4, "\363\372\256\1", 4, MSG_NOSIGNAL, NULL, 0) = 4  --  UID being
> > looked up, but if I parse this correctly, this is not 28244723, but
> > 179959027
> > read(4, "\30\0\0\0\22\0\0\0\0\0\0\0\0\0\0\0", 16) = 16  --
> >  response(SSS_NSS_GETPWUID), no server error
> > read(4, "\0\0\0\0\0\0\0\0", 8)         = 8  --  NSS_STATUS_NOTFOUND
> >
> > --  if I parse strace correctly, it looks up a wrong id... sure thing
> > SSSD replies NOTFOUND
> > Next it continues with the next provider from nsswitch.conf - systemd -
> > but payload is cut so we can't say it it looks up the same (wrong?) id
> > there:
> > connect(6, {sa_family=AF_UNIX,
> > sun_path="/run/systemd/userdb/io.systemd.DynamicUser"}, 45) = 0
> > ...
> > sendto(6, "{\"method\":\"io.systemd.UserDataba"..., 116,
> > MSG_DONTWAIT|MSG_NOSIGNAL, NULL, 0) = 116
> >
> > The same with SSS_NSS_GETGRGID: it looks up "r\334\261\1" == 180729970,
> > not 28433522...
> >
> > I've also asked for 'ltrace' of the same command. Have you got it?
>
> `ltrace ls -l /home/lck`

[Alexey Tikhonov]

Hi.

The reason is that 'id_provider = ldap' is used against AD.

Normally 'subdomain_provider' reads required data and sets up id-mapping at
startup, but ldap provider doesn't have 'subdomain_provider', so when first
lookup is by-id it can't convert id to SID:
```
[users_get_send] (0x0080): [RID#79] [28244723] did not match any configured
ID mapping domain
```
and can't handle a request.

You wrote: "until I manually run a "getent" or "id" on any user or group" -
I guess those lookups are by-name?
I guess this triggers a connection to AD, rootDSE is read and id-mapping is
set up.

You can try to set `ldap_idmap_default_domain_sid` and
`ldap_idmap_default_domain` to the SID and name of your domain. Hopefully
this will create a static mapping at startup.

But in general it's recommended to use 'id_provider = ad' against AD.

[Lawrence Kearney]

Alexey,
Of course. Added below.

-- lawrence

-----

[root@acad-cnode006 ~]# sssctl logs-remove

Truncating log files...

-----

[root@acad-cnode006 ~]# sssctl debug-level

sssd                      0x0070
nss                       0x0070
pam                       0x0070
domain/adldap1.augusta.edu 0x0070

[root@acad-cnode006 ~]# sssctl debug-level 9

[root@acad-cnode006 ~]# sssctl debug-level

sssd                      0x2f7f0
nss                       0x2f7f0
pam                       0x2f7f0
domain/adldap1.augusta.edu 0x2f7f0

-----

[root@acad-cnode006 ~]# ll /home/lck

total 12
drwxr-xr-x 3 28244723 28433522 4096 Jan 28 14:19 Documents
drwxr-xr-x 8 28244723 28433522 4096 Feb  6 12:25 apps
drwxr-xr-x 4 28244723 28433522 4096 Feb 12 15:36 scripts

-----

[root@acad-cnode006 ~]# cat /var/log/sssd/sssd_nss.log

(2025-02-15 19:29:55): [nss] [sbus_dispatch] (0x4000): Dispatching.
(2025-02-15 19:29:55): [nss] [sbus_signal_handler] (0x2000): Received D-Bus
signal org.freedesktop.DBus.NameOwnerChanged on /org/freedesktop/DBus
(2025-02-15 19:29:55): [nss] [sbus_name_owner_changed] (0x4000): Name of
owner :1.8 has changed from [] to [:1.8]
(2025-02-15 19:29:55): [nss] [sbus_issue_request_done] (0x0400):
org.freedesktop.DBus.NameOwnerChanged: Success
(2025-02-15 19:29:55): [nss] [sbus_dispatch] (0x4000): Dispatching.
(2025-02-15 19:29:55): [nss] [sbus_method_handler] (0x2000): Received D-Bus
method org.freedesktop.DBus.Properties.Get on /sssd
(2025-02-15 19:29:55): [nss] [sbus_senders_lookup] (0x2000): Looking for
identity of sender [:1.8]
(2025-02-15 19:29:55): [nss] [sbus_dispatch] (0x4000): Dispatching.
(2025-02-15 19:29:55): [nss] [sbus_senders_lookup] (0x2000): Looking for
identity of sender [:1.8]
(2025-02-15 19:29:55): [nss] [sbus_senders_add] (0x2000): Inserting
identity of sender [:1.8]: 0
(2025-02-15 19:29:55): [nss] [sbus_properties_get_send] (0x4000):
Requesting property: sssd.service.debug_level of /sssd
(2025-02-15 19:29:55): [nss] [sbus_issue_request_done] (0x0400):
org.freedesktop.DBus.Properties.Get: Success
(2025-02-15 19:29:55): [nss] [sbus_dispatch] (0x4000): Dispatching.
(2025-02-15 19:29:55): [nss] [sbus_signal_handler] (0x2000): Received D-Bus
signal org.freedesktop.DBus.NameOwnerChanged on /org/freedesktop/DBus
(2025-02-15 19:29:55): [nss] [sbus_name_owner_changed] (0x4000): Name of
owner :1.8 has changed from [:1.8] to []
(2025-02-15 19:29:55): [nss] [sbus_senders_delete] (0x2000): Removing
identity of sender [:1.8]
(2025-02-15 19:29:55): [nss] [sbus_issue_request_done] (0x0400):
org.freedesktop.DBus.NameOwnerChanged: Success
(2025-02-15 19:30:29): [nss] [get_client_cred] (0x4000): Client
[0x55cf53509b00][22] creds: euid[0] egid[0] pid[84709] cmd_line['ls'].
(2025-02-15 19:30:29): [nss] [setup_client_idle_timer] (0x4000): Idle timer
re-set for client [0x55cf53509b00][22]
(2025-02-15 19:30:29): [nss] [accept_fd_handler] (0x0400): [CID#451] Client
[cmd ls][uid 0][0x55cf53509b00][22] connected!
(2025-02-15 19:30:29): [nss] [sss_cmd_get_version] (0x0200): [CID#451]
Received client version [1].
(2025-02-15 19:30:29): [nss] [sss_cmd_get_version] (0x0200): [CID#451]
Offered version [1].
(2025-02-15 19:30:29): [nss] [sss_nss_getby_id] (0x0400): [CID#451] Input
ID: 28244723 (looking up 'POSIX data')
(2025-02-15 19:30:29): [nss] [cache_req_set_plugin] (0x2000): [CID#451] CR
#969: Setting "User by ID" plugin
(2025-02-15 19:30:29): [nss] [cache_req_send] (0x0400): [CID#451] CR #969:
REQ_TRACE: New request [CID #451] 'User by ID'
(2025-02-15 19:30:29): [nss] [cache_req_select_domains] (0x0400): [CID#451]
CR #969: Performing a multi-domain search
(2025-02-15 19:30:29): [nss] [cache_req_search_domains] (0x0400): [CID#451]
CR #969: Search will check the cache and check the data provider
(2025-02-15 19:30:29): [nss] [cache_req_validate_domain_type] (0x2000):
[CID#451] Request type POSIX-only for domain adldap1.augusta.edu type POSIX
is valid
(2025-02-15 19:30:29): [nss] [cache_req_set_domain] (0x0400): [CID#451] CR
#969: Using domain [adldap1.augusta.edu]
(2025-02-15 19:30:29): [nss] [cache_req_search_send] (0x0400): [CID#451] CR
#969: Looking up UID:[e-mail]
(2025-02-15 19:30:29): [nss] [cache_req_search_ncache] (0x0400): [CID#451]
CR #969: Checking negative cache for [UID:[e-mail]]
(2025-02-15 19:30:29): [nss] [sss_ncache_check_str] (0x2000): [CID#451]
Checking negative cache for [NCE/UID/adldap1.augusta.edu/28244723]
(2025-02-15 19:30:29): [nss] [sss_ncache_check_str] (0x2000): [CID#451]
Checking negative cache for [NCE/UID/28244723]
(2025-02-15 19:30:29): [nss] [cache_req_search_ncache] (0x0400): [CID#451]
CR #969: [UID:[e-mail]] is not present in negative cache
(2025-02-15 19:30:29): [nss] [cache_req_search_cache] (0x0400): [CID#451]
CR #969: Looking up [UID:[e-mail]] in cache
(2025-02-15 19:30:29): [nss] [cache_req_search_cache] (0x0400): [CID#451]
CR #969: Object [UID:[e-mail]] was not found in cache
(2025-02-15 19:30:29): [nss] [cache_req_search_dp] (0x0400): [CID#451] CR
#969: Looking up [UID:[e-mail]] in data provider
(2025-02-15 19:30:29): [nss] [sss_dp_get_account_send] (0x0400): [CID#451]
Creating request for [adldap1.augusta.edu
][0x1][BE_REQ_USER][idnumber=28244723:-]
(2025-02-15 19:30:29): [nss] [sss_nss_get_object_send] (0x0400): [CID#451]
Client [0x55cf53509b00][22]: sent cache request #969
(2025-02-15 19:30:29): [nss] [sbus_dispatch] (0x4000): Dispatching.
(2025-02-15 19:30:29): [nss] [cache_req_common_process_dp_reply] (0x3f7c0):
[CID#451] CR #969: Data Provider Error: 3, 0, Success
(2025-02-15 19:30:29): [nss] [cache_req_common_process_dp_reply] (0x0400):
[CID#451] CR #969: Due to an error we will return cached data
(2025-02-15 19:30:29): [nss] [sss_domain_get_state] (0x1000): [CID#451]
Domain adldap1.augusta.edu is Active
(2025-02-15 19:30:29): [nss] [cache_req_search_cache] (0x0400): [CID#451]
CR #969: Looking up [UID:[e-mail]] in cache
(2025-02-15 19:30:29): [nss] [cache_req_search_cache] (0x0400): [CID#451]
CR #969: Object [UID:[e-mail]] was not found in cache
(2025-02-15 19:30:29): [nss] [cache_req_process_result] (0x0400): [CID#451]
CR #969: Finished: Not found
(2025-02-15 19:30:29): [nss] [sss_nss_protocol_done] (0x4000): [CID#451]
Sending reply: not found
(2025-02-15 19:30:29): [nss] [sss_nss_getby_id] (0x0400): [CID#451] Input
ID: 28433522 (looking up 'POSIX data')
(2025-02-15 19:30:29): [nss] [cache_req_set_plugin] (0x2000): [CID#451] CR
#970: Setting "Group by ID" plugin
(2025-02-15 19:30:29): [nss] [cache_req_send] (0x0400): [CID#451] CR #970:
REQ_TRACE: New request [CID #451] 'Group by ID'
(2025-02-15 19:30:29): [nss] [cache_req_select_domains] (0x0400): [CID#451]
CR #970: Performing a multi-domain search
(2025-02-15 19:30:29): [nss] [cache_req_search_domains] (0x0400): [CID#451]
CR #970: Search will check the cache and check the data provider
(2025-02-15 19:30:29): [nss] [cache_req_validate_domain_type] (0x2000):
[CID#451] Request type POSIX-only for domain adldap1.augusta.edu type POSIX
is valid
(2025-02-15 19:30:29): [nss] [cache_req_set_domain] (0x0400): [CID#451] CR
#970: Using domain [adldap1.augusta.edu]
(2025-02-15 19:30:29): [nss] [cache_req_search_send] (0x0400): [CID#451] CR
#970: Looking up GID:[e-mail]
(2025-02-15 19:30:29): [nss] [cache_req_search_ncache] (0x0400): [CID#451]
CR #970: Checking negative cache for [GID:[e-mail]]
(2025-02-15 19:30:29): [nss] [sss_ncache_check_str] (0x2000): [CID#451]
Checking negative cache for [NCE/GID/adldap1.augusta.edu/28433522]
(2025-02-15 19:30:29): [nss] [sss_ncache_check_str] (0x2000): [CID#451]
Checking negative cache for [NCE/GID/28433522]
(2025-02-15 19:30:29): [nss] [cache_req_search_ncache] (0x0400): [CID#451]
CR #970: [GID:[e-mail]] is not present in negative cache
(2025-02-15 19:30:29): [nss] [cache_req_search_cache] (0x0400): [CID#451]
CR #970: Looking up [GID:[e-mail]] in cache
(2025-02-15 19:30:29): [nss] [cache_req_search_cache] (0x0400): [CID#451]
CR #970: Object [GID:[e-mail]] was not found in cache
(2025-02-15 19:30:29): [nss] [cache_req_search_dp] (0x0400): [CID#451] CR
#970: Looking up [GID:[e-mail]] in data provider
(2025-02-15 19:30:29): [nss] [sss_dp_get_account_send] (0x0400): [CID#451]
Creating request for [adldap1.augusta.edu
][0x2][BE_REQ_GROUP][idnumber=28433522:-]
(2025-02-15 19:30:29): [nss] [sss_nss_get_object_send] (0x0400): [CID#451]
Client [0x55cf53509b00][22]: sent cache request #970
(2025-02-15 19:30:29): [nss] [sbus_dispatch] (0x4000): Dispatching.
(2025-02-15 19:30:29): [nss] [cache_req_common_process_dp_reply] (0x3f7c0):
[CID#451] CR #970: Data Provider Error: 3, 0, Success
(2025-02-15 19:30:29): [nss] [cache_req_common_process_dp_reply] (0x0400):
[CID#451] CR #970: Due to an error we will return cached data
(2025-02-15 19:30:29): [nss] [sss_domain_get_state] (0x1000): [CID#451]
Domain adldap1.augusta.edu is Active
(2025-02-15 19:30:29): [nss] [cache_req_search_cache] (0x0400): [CID#451]
CR #970: Looking up [GID:[e-mail]] in cache
(2025-02-15 19:30:29): [nss] [cache_req_search_cache] (0x0400): [CID#451]
CR #970: Object [GID:[e-mail]] was not found in cache
(2025-02-15 19:30:29): [nss] [cache_req_process_result] (0x0400): [CID#451]
CR #970: Finished: Not found
(2025-02-15 19:30:29): [nss] [sss_nss_protocol_done] (0x4000): [CID#451]
Sending reply: not found
(2025-02-15 19:30:29): [nss] [sss_nss_getby_id] (0x0400): [CID#451] Input
ID: 28433522 (looking up 'POSIX data')
(2025-02-15 19:30:29): [nss] [cache_req_set_plugin] (0x2000): [CID#451] CR
#971: Setting "Group by ID" plugin
(2025-02-15 19:30:29): [nss] [cache_req_send] (0x0400): [CID#451] CR #971:
REQ_TRACE: New request [CID #451] 'Group by ID'
(2025-02-15 19:30:29): [nss] [cache_req_select_domains] (0x0400): [CID#451]
CR #971: Performing a multi-domain search
(2025-02-15 19:30:29): [nss] [cache_req_search_domains] (0x0400): [CID#451]
CR #971: Search will check the cache and check the data provider
(2025-02-15 19:30:29): [nss] [cache_req_validate_domain_type] (0x2000):
[CID#451] Request type POSIX-only for domain adldap1.augusta.edu type POSIX
is valid
(2025-02-15 19:30:29): [nss] [cache_req_set_domain] (0x0400): [CID#451] CR
#971: Using domain [adldap1.augusta.edu]
(2025-02-15 19:30:29): [nss] [cache_req_search_send] (0x0400): [CID#451] CR
#971: Looking up GID:[e-mail]
(2025-02-15 19:30:29): [nss] [cache_req_search_ncache] (0x0400): [CID#451]
CR #971: Checking negative cache for [GID:[e-mail]]
(2025-02-15 19:30:29): [nss] [sss_ncache_check_str] (0x2000): [CID#451]
Checking negative cache for [NCE/GID/adldap1.augusta.edu/28433522]
(2025-02-15 19:30:29): [nss] [sss_ncache_check_str] (0x2000): [CID#451]
Checking negative cache for [NCE/GID/28433522]
(2025-02-15 19:30:29): [nss] [cache_req_search_ncache] (0x0400): [CID#451]
CR #971: [GID:[e-mail]] is not present in negative cache
(2025-02-15 19:30:29): [nss] [cache_req_search_cache] (0x0400): [CID#451]
CR #971: Looking up [GID:[e-mail]] in cache
(2025-02-15 19:30:29): [nss] [cache_req_search_cache] (0x0400): [CID#451]
CR #971: Object [GID:[e-mail]] was not found in cache
(2025-02-15 19:30:29): [nss] [cache_req_search_dp] (0x0400): [CID#451] CR
#971: Looking up [GID:[e-mail]] in data provider
(2025-02-15 19:30:29): [nss] [sss_dp_get_account_send] (0x0400): [CID#451]
Creating request for [adldap1.augusta.edu
][0x2][BE_REQ_GROUP][idnumber=28433522:-]
(2025-02-15 19:30:29): [nss] [sss_nss_get_object_send] (0x0400): [CID#451]
Client [0x55cf53509b00][22]: sent cache request #971
(2025-02-15 19:30:29): [nss] [sbus_dispatch] (0x4000): Dispatching.
(2025-02-15 19:30:29): [nss] [cache_req_common_process_dp_reply] (0x3f7c0):
[CID#451] CR #971: Data Provider Error: 3, 0, Success
(2025-02-15 19:30:29): [nss] [cache_req_common_process_dp_reply] (0x0400):
[CID#451] CR #971: Due to an error we will return cached data
(2025-02-15 19:30:29): [nss] [sss_domain_get_state] (0x1000): [CID#451]
Domain adldap1.augusta.edu is Active
(2025-02-15 19:30:29): [nss] [cache_req_search_cache] (0x0400): [CID#451]
CR #971: Looking up [GID:[e-mail]] in cache
(2025-02-15 19:30:29): [nss] [cache_req_search_cache] (0x0400): [CID#451]
CR #971: Object [GID:[e-mail]] was not found in cache
(2025-02-15 19:30:29): [nss] [cache_req_process_result] (0x0400): [CID#451]
CR #971: Finished: Not found
(2025-02-15 19:30:29): [nss] [sss_nss_protocol_done] (0x4000): [CID#451]
Sending reply: not found
(2025-02-15 19:30:29): [nss] [client_recv] (0x0200): [CID#451] Client
disconnected!
(2025-02-15 19:30:29): [nss] [client_close_fn] (0x2000): [CID#451]
Terminated client [0x55cf53509b00][22]

----------

From Alexey:

Huh... apparently I parsed strace wrongly because sssd_nss.log says a
correct UID is being looked up:
```
(2025-02-15 19:30:29): [nss] [cache_req_search_send] (0x0400): [CID#451] CR
#969: Looking up UID:[e-mail]
(2025-02-15 19:30:29): [nss] [sss_dp_get_account_send] (0x0400): [CID#451]
Creating request for [adldap1.augusta.edu
][0x1][BE_REQ_USER][idnumber=28244723:-]
(2025-02-15 19:30:29): [nss] [cache_req_common_process_dp_reply] (0x3f7c0):
[CID#451] CR #969: Data Provider Error: 3, 0, Success
```
Well, that's good, no mystery on the sss_client library side.
Then the next thing we need to check 'sssd_$domain.log' with debug_level=9
that covers processing of this request, that results in "Data Provider
Error"

----------

Alexey,

Thank you again, included below:

[root@acad-cnode006 ~]# sssctl debug-level 9

[root@acad-cnode006 ~]# sssctl debug-level

sssd                      0x2f7f0
nss                       0x2f7f0
pam                       0x2f7f0
domain/adldap1.augusta.edu 0x2f7f0

[root@acad-cnode006 ~]# sssctl logs-remove

Truncating log files...

[root@acad-cnode006 ~]# ll /home/lck

-----

total 12
drwxr-xr-x 3 28244723 28433522 4096 Jan 28 14:19 Documents
drwxr-xr-x 8 28244723 28433522 4096 Feb  6 12:25 apps
drwxr-xr-x 4 28244723 28433522 4096 Feb 12 15:36 scripts

-----

[root@acad-cnode006 ~]# cat /var/log/sssd/sssd_adldap1.augusta.edu.log

(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_dir_event]
(0x4000): inotify name: chrony.conf
(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_dir_event]
(0x0400): Not interested in chrony.conf
(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_dir_event]
(0x4000): inotify name: group
(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_dir_event]
(0x0400): Not interested in group
(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_dir_event]
(0x4000): inotify name: hosts
(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_dir_event]
(0x0400): Not interested in hosts
(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [snotify_internal_cb]
(0x2000): All inotify events processed
(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_dir_event]
(0x4000): inotify name: passwd
(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_dir_event]
(0x0400): Not interested in passwd
(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_file_event]
(0x0400): received notification for watched file /etc/resolv.conf
(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [create_dispatcher]
(0x0400): Running a timer with delay 1.0
(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [dispatch_event] (0x0400):
Dispatched an event with combined flags 0x400
(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_file_event]
(0x0400): Will reopen moved or deleted file /etc/resolv.conf
(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_dir_event]
(0x4000): inotify name: resolv.conf
(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_dir_event]
(0x0400): received notification for watched file [resolv.conf] under /etc
(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [get_dispatcher] (0x2000):
Reusing existing dispatcher
(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [dispatch_event] (0x0400):
Dispatched an event with combined flags 0x500
(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_dir_event]
(0x4000): inotify name: shadow
(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [process_dir_event]
(0x0400): Not interested in shadow
(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [snotify_internal_cb]
(0x2000): All inotify events processed
(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [watch_ctx_destructor]
(0x2000): Closing inotify fd 20
(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [snotify_watch] (0x2000):
Opened inotify fd 20
(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [snotify_watch] (0x2000):
Opened file watch 1
(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [snotify_watch] (0x2000):
Opened directory watch 2
(2025-02-17 13:32:14): [be[adldap1.augusta.edu]] [snotify_rewatch]
(0x0400): Recreated watch
(2025-02-17 13:32:15): [be[adldap1.augusta.edu]] [watched_file_inotify_cb]
(0x1000): Received inotify notification for /etc/resolv.conf
(2025-02-17 13:32:15): [be[adldap1.augusta.edu]] [watch_update_resolv]
(0x0400): Reloading /etc/resolv.conf.
(2025-02-17 13:32:15): [be[adldap1.augusta.edu]] [recreate_ares_channel]
(0x0100): Initializing new c-ares channel
(2025-02-17 13:32:15): [be[adldap1.augusta.edu]] [recreate_ares_channel]
(0x0100): Destroying the old c-ares channel
(2025-02-17 13:32:15): [be[adldap1.augusta.edu]] [check_if_online]
(0x2000): Schedule check_if_online_delayed in 1s.
(2025-02-17 13:32:16): [be[adldap1.augusta.edu]]
[be_run_unconditional_online_cb] (0x4000): List of unconditional online
callbacks is empty, nothing to do.
(2025-02-17 13:32:16): [be[adldap1.augusta.edu]] [check_if_online_delayed]
(0x2000): Backend is already online, nothing to do.
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_dispatch] (0x4000):
Dispatching.
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_dispatch] (0x4000):
Dispatching.
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_method_handler]
(0x2000): Received D-Bus method sssd.dataprovider.getAccountInfo on /sssd
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_senders_lookup]
(0x2000): Looking for identity of sender [sssd.nss]
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_get_account_info_send]
(0x0200): Got request for [0x1][BE_REQ_USER][idnumber=28244723]
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_attach_req] (0x0400):
[RID#79] DP Request [Account #79]: REQ_TRACE: New request. [sssd.nss CID
#496] Flags [0x0001].
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_attach_req] (0x0400):
[RID#79] Number of active DP request: 1
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sss_domain_get_state]
(0x1000): [RID#79] Domain adldap1.augusta.edu is Active
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [users_get_send] (0x0080):
[RID#79] [28244723] did not match any configured ID mapping domain
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sysdb_search_user_by_uid]
(0x0400): [RID#79] No such entry
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sysdb_delete_user]
(0x0400): [RID#79] Error: 2 (No such file or directory)
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_done] (0x0400):
[RID#79] DP Request [Account #79]: Request handler finished [0]: Success
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_done] (0x20000):
[RID#79] DP Request [Account #79]: Handling request took [0.142]
milliseconds.
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [_dp_req_recv] (0x0400):
[RID#79] DP Request [Account #79]: Receiving request data.
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_destructor]
(0x0400): [RID#79] DP Request [Account #79]: Request removed.
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_destructor]
(0x0400): [RID#79] Number of active DP request: 0
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_reply_std]
(0x1000): [RID#79] DP Request [Account #79]: Returning [Internal Error]:
3,0,Success
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_issue_request_done]
(0x0400): sssd.dataprovider.getAccountInfo: Success
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_dispatch] (0x4000):
Dispatching.
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_dispatch] (0x4000):
Dispatching.
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_dispatch] (0x4000):
Dispatching.
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_method_handler]
(0x2000): Received D-Bus method sssd.dataprovider.getAccountInfo on /sssd
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_senders_lookup]
(0x2000): Looking for identity of sender [sssd.nss]
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_get_account_info_send]
(0x0200): Got request for [0x2][BE_REQ_GROUP][idnumber=28433522]
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_attach_req] (0x0400):
[RID#80] DP Request [Account #80]: REQ_TRACE: New request. [sssd.nss CID
#496] Flags [0x0001].
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_attach_req] (0x0400):
[RID#80] Number of active DP request: 1
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sss_domain_get_state]
(0x1000): [RID#80] Domain adldap1.augusta.edu is Active
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [groups_get_send]
(0x0080): [RID#80] [28433522] did not match any configured ID mapping domain
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sysdb_search_group_by_id]
(0x0400): [RID#80] No such entry
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sysdb_delete_group]
(0x0400): [RID#80] Error: 2 (No such file or directory)
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_done] (0x0400):
[RID#80] DP Request [Account #80]: Request handler finished [0]: Success
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_done] (0x20000):
[RID#80] DP Request [Account #80]: Handling request took [0.142]
milliseconds.
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [_dp_req_recv] (0x0400):
[RID#80] DP Request [Account #80]: Receiving request data.
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_destructor]
(0x0400): [RID#80] DP Request [Account #80]: Request removed.
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_destructor]
(0x0400): [RID#80] Number of active DP request: 0
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_reply_std]
(0x1000): [RID#80] DP Request [Account #80]: Returning [Internal Error]:
3,0,Success
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_issue_request_done]
(0x0400): sssd.dataprovider.getAccountInfo: Success
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_dispatch] (0x4000):
Dispatching.
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_dispatch] (0x4000):
Dispatching.
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_dispatch] (0x4000):
Dispatching.
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_method_handler]
(0x2000): Received D-Bus method sssd.dataprovider.getAccountInfo on /sssd
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_senders_lookup]
(0x2000): Looking for identity of sender [sssd.nss]
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_get_account_info_send]
(0x0200): Got request for [0x2][BE_REQ_GROUP][idnumber=28433522]
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_attach_req] (0x0400):
[RID#81] DP Request [Account #81]: REQ_TRACE: New request. [sssd.nss CID
#496] Flags [0x0001].
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_attach_req] (0x0400):
[RID#81] Number of active DP request: 1
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sss_domain_get_state]
(0x1000): [RID#81] Domain adldap1.augusta.edu is Active
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [groups_get_send]
(0x0080): [RID#81] [28433522] did not match any configured ID mapping domain
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sysdb_search_group_by_id]
(0x0400): [RID#81] No such entry
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sysdb_delete_group]
(0x0400): [RID#81] Error: 2 (No such file or directory)
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_done] (0x0400):
[RID#81] DP Request [Account #81]: Request handler finished [0]: Success
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_done] (0x20000):
[RID#81] DP Request [Account #81]: Handling request took [0.158]
milliseconds.
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [_dp_req_recv] (0x0400):
[RID#81] DP Request [Account #81]: Receiving request data.
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_destructor]
(0x0400): [RID#81] DP Request [Account #81]: Request removed.
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_destructor]
(0x0400): [RID#81] Number of active DP request: 0
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [dp_req_reply_std]
(0x1000): [RID#81] DP Request [Account #81]: Returning [Internal Error]:
3,0,Success
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_issue_request_done]
(0x0400): sssd.dataprovider.getAccountInfo: Success
(2025-02-17 13:32:22): [be[adldap1.augusta.edu]] [sbus_dispatch] (0x4000):
Dispatching.sssd                      0x2f7f0

---------

From Alexey:

Ok, we are getting closer to the root cause:
```
(13:32:22): [dp_get_account_info_send] (0x0200): Got request for
[0x1][BE_REQ_USER][idnumber=28244723]
(13:32:22): [sss_domain_get_state] (0x1000): [RID#79] Domain
adldap1.augusta.edu is Active
(13:32:22): [users_get_send] (0x0080): [RID#79] [28244723] did not match
any configured ID mapping domain
```

What are:
1) actual backend - AD?
2) id_provider user in sssd.conf?
3) value of 'ldap_id_mapping' sssd.conf::domain option?

----------

Alexey,
Good morning! sanitized conf file included below:

- Yes, back end is native AD
- Included sanitized conf file details other settings (group names, certs,
dn's, modified, password omitted)

-----

[sssd]
config_file_version = 2
services = nss,pam
domains = adldap1.example.edu

[nss]
filter_users = root
filter_groups = root

[pam]

[domain/adldap1.example.edu]
id_provider = ldap

enumerate = False
cache_credentials = True
case_sensitive = false

ignore_group_members = True

ldap_schema = ad
ldap_uri = ldaps://root.example.edu
ldap_backup_uri = ldaps://root2.example.edu

ldap_user_search_base = dc=example,dc=edu
ldap_referrals = False

ldap_tls_cacert = /etc/openldap/certs/root.crt
ldap_tls_reqcert = never

ldap_use_tokengroups = True
ldap_id_mapping = True
ldap_idmap_range_size = 2000000

override_homedir = /home/%u
default_shell = /bin/bash
override_gid = 28433520

ldap_access_order = filter,expire
ldap_account_expire_policy = ad
ldap_access_filter =
(|(memberOf=cn=prod_admins_group,ou=hpc,dc=example,dc=edu)(memberOf=cn=prod_users_group,ou=hpc,dc=example,dc=edu))

ldap_default_bind_dn = CN="Service,
LDAP_Auth",OU=ServiceAccounts,DC=example,DC=edu
ldap_default_authtok_type = password

----------

Alexey,
Thank you for the effort thus far and the feedback, but I'd like to offer a
few points.

- As referenced, these systems are ephemeral, so joining them to AD to use
the AD provider isn't sustainable.
- We have other systems configured exactly the same way, across many
different versions of the daemon and RHEL OS's, and have never seen this
issue.
- Correct, as soon as I do a lookup by name, any valid name, everything
resolves as expected.

Being able to use the LDAP ID provider and the AD schema, provided by an
SSSD configuration directive, suggests we're not doing anything radical.

What is different is these OS instances are Rocky 9.5 Linux containers
deployed as stateless systems.

So, given that my question becomes what is different? Is there something
the daemon is missing in a stateless configuration? I know that's pretty
open ended, I've done this quite a bit, but I don't have the developer
insight or experience of where else to look next.

I'll test with the recommendations given and perhaps the results may
provide additional breadcrumbs.

Stay tuned and thank you,

-- Lawrence

----------

Alexey,

I tried using both the `ldap_idmap_default_domain_sid` and
`ldap_idmap_default_domain` directives, but the same result.

-- lawrence

On Mon, Feb 17, 2025 at 12:39 PM Alexey Tikhonov 
wrote:
> Hi.
>
> The reason is that 'id_provider = ldap' is used against AD.
>
> Normally 'subdomain_provider' reads required data and sets up id-mapping
> at startup, but ldap provider doesn't have 'subdomain_provider', so when
> first lookup is by-id it can't convert id to SID:
> [users_get_send] (0x0080): [RID#79] [28244723] did not match any
> configured ID mapping domain
>
> and can't handle a request.
>
> You wrote: "until I manually run a "getent" or "id" on any user or group"
> I guess those lookups are by-name?
>
> I guess this triggers a connection to AD, rootDSE is read and id-mapping
> is set up.
>
> You can try to set `ldap_idmap_default_domain_sid` and
> `ldap_idmap_default_domain` to the SID and name of your domain. Hopefully
> this will create a static mapping at startup.
>
> But in general it's recommended to use 'id_provider = ad' against AD.

[Alexey Tikhonov]

> Alexey,
> Thank you for the effort thus far and the feedback, but I'd like to offer a few points.
> As referenced, these systems are ephemeral, so joining them to AD to use the AD provider isn't sustainable.

Out of curiosity: did you consider a pool of pre-enrolled hosts whose
identity (host principal key) ephemeral systems could assume?
> What is different is these OS instances are Rocky 9.5 Linux containers deployed as stateless systems.
> So, given that my question becomes what is different? Is there something the daemon is missing in a stateless configuration?

Required domain information (SID/name) is cached.
I bet if you "stop sssd; rm -rf /var/lib/sss/db/*; start sssd" on a
"stateful" system you will face the same issue.
> I'll test with the recommendations given and perhaps the results may provide additional breadcrumbs.

Keep in mind that those settings should be consistent over the entire
fleet of client hosts.
Otherwise you'll end up with a different ID for a given SID on different hosts.

Another workaround could be: to forcefully trigger 'getent -s sss
passwd name' at node startup.

[Alexey Tikhonov]

> What is different is these OS instances are Rocky 9.5 Linux containers deployed as stateless systems.

Also out of curiosity: how do you use SSSD in those containers?
What is the use case?

[Lawrence Kearney]

Alexey,
Please forgive the delay in response. I'm heavily involved with a PS
engagement/deployment for the next couple of weeks (this one included) and
free time is sparse. This is important though so I will be working on it so
again please forgive any delays in response.

We use the daemon for AD user/group resolution, access control, and
authentication for cluster users at the edge (AD joined job submission
nodes, data transfer nodes, etc.) and internally (compute nodes using
LDAP). Users are permitted to authenticate to compute nodes if they have
active jobs on. The SLURM "pam_slurm_adopt.so" module controls that access,
where AD groups do so on the cluster edge systems. Those same AD groups
will be used for SLURM based quality of service settings as well in an
internal database. The enterprise provides the AD environment and we have
no appetite to implement a shadow AD or LDAP service for the research
compute side of things.

As mentioned, I've deployed hundreds of these configurations and this
stateless configurations are the only one to behave this way. Very curious
but as ephemeral systems are expectantly redeployed as a matter of
operations, this nuance could certainly get annoying :-) .

-- lawrence

On Tue, Feb 18, 2025 at 3:14 AM Alexey Tikhonov  wrote:
> > What is different is these OS instances are Rocky 9.5 Linux containers
>
> deployed as stateless systems.
>
> Also out of curiosity: how do you use SSSD in those containers?
> What is the use case?

[Lawrence Kearney]

Alexey,
Good evening. I have finally made the time to circle back to this and do
some testing.

I found this, which was interesting (I think you were assisting)
https://blog.rook.io/prototyping-an-nfs-connection-to-ldap-using-sssd-7c27f6...

It seemed to share some parallels so I decided to test swapping the order
of lookup in the nsswitch.conf for a test stateless instance.

passwd sss files
group sss files

After 15 minutes (exactly) a poll of the mounted NFS file systems reflected
resolved users and groups as normal. Without requiring a lookup operation
(for any valid user) as before.

I'm having trouble tracking this to the likely sssd timer that may help
explain more.

Thoughts?

-- lawrence

On Wed, Feb 19, 2025 at 8:50 AM Lawrence Kearney 
wrote:
> Alexey,
> Please forgive the delay in response. I'm heavily involved with a PS
> engagement/deployment for the next couple of weeks (this one included) and
> free time is sparse. This is important though so I will be working on it so
> again please forgive any delays in response.
>
> We use the daemon for AD user/group resolution, access control, and
> authentication for cluster users at the edge (AD joined job submission
> nodes, data transfer nodes, etc.) and internally (compute nodes using
> LDAP). Users are permitted to authenticate to compute nodes if they have
> active jobs on. The SLURM "pam_slurm_adopt.so" module controls that access,
> where AD groups do so on the cluster edge systems. Those same AD groups
> will be used for SLURM based quality of service settings as well in an
> internal database. The enterprise provides the AD environment and we have
> no appetite to implement a shadow AD or LDAP service for the research
> compute side of things.
>
> As mentioned, I've deployed hundreds of these configurations and this
> stateless configurations are the only one to behave this way. Very curious
> but as ephemeral systems are expectantly redeployed as a matter of
> operations, this nuance could certainly get annoying :-) .
>
> -- lawrence
>
> On Tue, Feb 18, 2025 at 3:14 AM Alexey Tikhonov 
> wrote:
> > > What is different is these OS instances are Rocky 9.5 Linux containers
> >
> > deployed as stateless systems.
> >
> > Also out of curiosity: how do you use SSSD in those containers?
> > What is the use case?

[Alexey Tikhonov]

On Sun, Mar 9, 2025 at 8:32 PM Lawrence Kearney  wrote:
> Alexey,
> Good evening. I have finally made the time to circle back to this and do some testing.
>
> I found this, which was interesting (I think you were assisting) https://blog.rook.io/prototyping-an-nfs-connection-to-ldap-using-sssd-7c27f6...
>
> It seemed to share some parallels so I decided to test swapping the order of lookup in the nsswitch.conf for a test stateless instance.
>
> passwd sss files
> group sss files
>
> After 15 minutes (exactly) a poll of the mounted NFS file systems reflected resolved users and groups as normal. Without requiring a lookup operation (for any valid user) as before.
>
> I'm having trouble tracking this to the likely sssd timer that may help explain more.

Maybe ldap_connection_expire_timeout/ldap_connection_idle_timeout.