Re: useradd question

[Steve Grubb <sgrubb@redhat.com>]

On Monday, May 20, 2019 11:39:09 AM EDT Lenny Bruzenak wrote:
> On 5/17/19 7:44 AM, Steve Grubb wrote:
> > On Thursday, May 16, 2019 7:00:38 PM EDT Lenny Bruzenak wrote:
> >> If I add a new user with the "useradd" utility, it submits a ADD_USER
> >> event, but the event itself has no interpretation for the new UID.
> > 
> > What exactly was typed in at the command line?
> 
> # useradd -c iam2 -G issm iam2
> 
> > This is caused by this line of
> > code:
> > 
> > https://github.com/linux-audit/audit-userspace/blob/master/lib/
> > audit_logging.c#L480
> > 
> > The idea is that we want to rely on the number rather than the name.
> > However, the log event is supposed to be created after passwd and shadow
> > have been updated. So, the audit daemon should be able to resolve the
> > event.
> > 
> > Maybe useradd needs to be straced to see if it does everything in one
> > shot or if it sends multiple events as it builds the user.
> 
> I think it is adding the events independently IIUC what the strace
> results say. Starting with the audit_open getting the netlink socket:
> 
> ...
> 
> socket(AF_NETLINK, SOCK_RAW, NETLINK_AUDIT) = 3
> sendto(3, "t\0\0\0\\\4\5\0\1\0\0\0\0\0\0\0op=add-group acc"..., 116, 0,
> {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 116
> recvfrom(3,
> "$\0\0\0\2\0\0\0\1\0\0\0006]\0\0\0\0\0\0t\0\0\0\\\4\5\0\1\0\0\0"...,
> 8988, MSG_PEEK|MSG_DONTWAIT, {sa_family=AF_NETLINK, pid=0,
> groups=00000000}, [12]) = 36
> recvfrom(3,
> "$\0\0\0\2\0\0\0\1\0\0\0006]\0\0\0\0\0\0t\0\0\0\\\4\5\0\1\0\0\0"...,
> 8988, MSG_DONTWAIT, {sa_family=AF_NETLINK, pid=0, groups=00000000},
> [12]) = 36
> sendto(3, "p\0\0\0Z\4\5\0\2\0\0\0\0\0\0\0op=add-user id=1"..., 112, 0,
> {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 112
> recvfrom(3,
> "$\0\0\0\2\0\0\0\2\0\0\0006]\0\0\0\0\0\0p\0\0\0Z\4\5\0\2\0\0\0"...,
> 8988, MSG_PEEK|MSG_DONTWAIT, {sa_family=AF_NETLINK, pid=0,
> groups=00000000}, [12]) = 36
> recvfrom(3,
> "$\0\0\0\2\0\0\0\2\0\0\0006]\0\0\0\0\0\0p\0\0\0Z\4\5\0\2\0\0\0"...,
> 8988, MSG_DONTWAIT, {sa_family=AF_NETLINK, pid=0, groups=00000000},
> [12]) = 36
> sendto(3, "\210\0\0\0N\4\5\0\3\0\0\0\0\0\0\0op=add-user-to-g"..., 136,
> 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 136
> recvfrom(3,
> "$\0\0\0\2\0\0\0\3\0\0\0006]\0\0\0\0\0\0\210\0\0\0N\4\5\0\3\0\0\0"...,
> 8988, MSG_PEEK|MSG_DONTWAIT, {sa_family=AF_NETLINK, pid=0,
> groups=00000000}, [12]) = 36
> recvfrom(3,
> "$\0\0\0\2\0\0\0\3\0\0\0006]\0\0\0\0\0\0\210\0\0\0N\4\5\0\3\0\0\0"...,
> 8988, MSG_DONTWAIT, {sa_family=AF_NETLINK, pid=0, groups=00000000},
> [12]) = 36
> sendto(3, "\210\0\0\0N\4\5\0\4\0\0\0\0\0\0\0op=add-to-shadow"..., 136,
> 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 136
> recvfrom(3,
> "$\0\0\0\2\0\0\0\4\0\0\0006]\0\0\0\0\0\0\210\0\0\0N\4\5\0\4\0\0\0"...,
> 8988, MSG_PEEK|MSG_DONTWAIT, {sa_family=AF_NETLINK, pid=0,
> groups=00000000}, [12]) = 36
> recvfrom(3,
> "$\0\0\0\2\0\0\0\4\0\0\0006]\0\0\0\0\0\0\210\0\0\0N\4\5\0\4\0\0\0"...,
> 8988, MSG_DONTWAIT, {sa_family=AF_NETLINK, pid=0, groups=00000000},
> [12]) = 36
> sendto(3, "t\0\0\0N\4\5\0\5\0\0\0\0\0\0\0op=add-home-dir "..., 116, 0,
> {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 116
> recvfrom(3,
> "$\0\0\0\2\0\0\0\5\0\0\0006]\0\0\0\0\0\0t\0\0\0N\4\5\0\5\0\0\0"...,
> 8988, MSG_PEEK|MSG_DONTWAIT, {sa_family=AF_NETLINK, pid=0,
> groups=00000000}, [12]) = 36
> recvfrom(3,
> "$\0\0\0\2\0\0\0\5\0\0\0006]\0\0\0\0\0\0t\0\0\0N\4\5\0\5\0\0\0"...,
> 8988, MSG_DONTWAIT, {sa_family=AF_NETLINK, pid=0, groups=00000000},
> [12]) = 36
> 
> That's all the FD 3 activity.
> 
> >> IOW, the "id" field is numeric and the translated data at the end of the
> >> raw record has "ID=unknown(number)".
> >> 
> >> I'm guessing it is because until the user data has been successfully
> >> entered, there is no translation. Perhaps the event submission should
> >> wait until that happens?
> > 
> > I'd say strace useradd will have the answer.
> 
> Let me know if the above isn't sufficient; I'll search again.

So...I went digging through the source code of useradd.c. In main is this 
comment:

        /*
         * Do the hard stuff:
         * - open the files,
         * - create the user entries,
         * - create the home directory,
         * - create user mail spool,
         * - flush nscd caches for passwd and group services,
         * - then close and update the files.
         */

If you dig around, you'll see in the above process it calls usr_update(). 
This is where the audit event is. The very next function call is close_files. 
This is where it actually writes to the files where it would be visible to 
auditd. So, it looks like auditing in shadow-utils is busted.

I also see where its calling pam_tally2 which is deprecated for years. It 
should be calling faillock. I'll chat with upstream maintainers.

-Steve


> >> I may be able to dig out the name from other related generated events,
> >> but that is kind of a pain.
> > 
> > Right. Let's see what the root cause is and then what we can do about it.
> 
> Thanks Steve.
> 
> I see plenty of audit events correlating to the above strace calls; e.g.:
> 
> node=audit type=ADD_GROUP msg=audit(05/15/2019 16:28:38.510:1684) :
> pid=25284 uid=root auid=iam1 ses=1
> subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023
> msg='op=add-group acct=iam2 exe=/usr/sbin/useradd hostname=audit addr=?
> terminal=pts/1 res=success'
> ...
> node=audit type=ADD_USER msg=audit(05/15/2019 16:28:38.516:1686) :
> pid=25284 uid=root auid=iam1 ses=1
> subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023
> msg='op=add-user id=iam2 exe=/usr/sbin/useradd hostname=audit addr=?
> terminal=pts/1 res=success'
> ...
> node=audit type=USER_MGMT msg=audit(05/15/2019 16:28:38.516:1687) :
> pid=25284 uid=root auid=iam1 ses=1
> subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023
> msg='op=add-user-to-group grp=issm acct=iam2 exe=/usr/sbin/useradd
> hostname=audit addr=? terminal=pts/1 res=success'
> ...
> node=audit type=USER_MGMT msg=audit(05/15/2019 16:28:38.516:1688) :
> pid=25284 uid=root auid=iam1 ses=1
> subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023
> msg='op=add-to-shadow-group grp=issm acct=iam2 exe=/usr/sbin/useradd
> hostname=audit addr=? terminal=pts/1 res=success'
> 
> ...
> 
> Then the user's home file setup events.
> 
> 
> 
> But wait, there's more and it isn't good at all. Here's what I did next,
> because I wanted to capture the events from an entirely new user.
> Previously, I was doing "useradd" as above followed by "userdel -rf
> iam2". Also iam3. Then I did:
> 
> [root@audit ~]# useradd -c iam10 -G issm iam10
> [root@audit ~]# ausearch -i -ts recent -m ADD_USER
> ----
> node=audit type=ADD_USER msg=audit(05/15/2019 16:43:28.456:1812) :
> pid=26210 uid=root auid=iam1 ses=1
> subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023
> msg='op=add-user id=iam3 exe=/usr/sbin/useradd hostname=audit addr=?
> terminal=pts/1 res=success'
> [root@audit ~]# ausearch -i -ts recent -m ADD_USER
> 
> Note that although the user id is filled in, it is wrong. I thought that
> must be from an earlier add, so I did:
> 
> [root@audit ~]# userdel iam10 -rf
> 
> [root@audit ~]# ausearch -i -ts recent -m ADD_USER
> ----
> node=audit type=ADD_USER msg=audit(05/15/2019 16:43:28.456:1812) :
> pid=26210 uid=root auid=iam1 ses=1
> subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023
> msg='op=add-user id=iam3 exe=/usr/sbin/useradd hostname=audit addr=?
> terminal=pts/1 res=success'
> [root@audit ~]# useradd -c iam10 -G issm iam10
> [root@audit ~]# ausearch -i -ts recent -m ADD_USER
> ----
> node=audit type=ADD_USER msg=audit(05/15/2019 16:43:28.456:1812) :
> pid=26210 uid=root auid=iam1 ses=1
> subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023
> msg='op=add-user id=iam3 exe=/usr/sbin/useradd hostname=audit addr=?
> terminal=pts/1 res=success'
> ----
> node=audit type=ADD_USER msg=audit(05/15/2019 16:48:58.746:1965) :
> pid=26555 uid=root auid=iam1 ses=1
> subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023
> msg='op=add-user id=iam3 exe=/usr/sbin/useradd hostname=audit addr=?
> terminal=pts/1 res=success'
> 
> So after sitting there in stunned silence a bit, I did:
> 
> [root@audit ~]# date
> Wed May 15 16:49:07 GMT 2019
> 
> [root@audit ~]# ausearch -r -a 1965  -ts recent
> node=audit type=ADD_USER msg=audit(1557938938.746:1965): pid=26555 uid=0
> auid=1000 ses=1
> subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023
> msg='op=add-user id=1003 exe="/usr/sbin/useradd" hostname=audit addr=?
> terminal=pts/1 res=success'UID="root" AUID="iam1" ID="iam3"
> 
> 
> [root@audit ~]# grep iam /etc/passwd
> iam1:x:1000:1000:iam1:/home/iam1:/bin/bash
> iam2:x:1002:1002:iam2:/home/iam2:/bin/bash
> iam10:x:1003:1003:iam10:/home/iam10:/bin/bash
> 
> 
> So now I'm truly confused about what is happening.
> 
> Thx,
> 
> LCB