How to find the process that logs to /var/log/audit.log?

Hi,

On a SLES 11 SP2 server I see a lot of entries in /var/log/messages like these:

Jan 2 12:59:13 phire su: (to papercut) root on none
Jan 2 13:00:24 phire su: (to papercut) root on none
Jan 2 13:01:35 phire su: (to papercut) root on none
Jan 2 13:02:45 phire su: (to papercut) root on none
Jan 2 13:03:56 phire su: (to papercut) root on none
Jan 2 13:05:06 phire su: (to papercut) root on none
Jan 2 13:06:17 phire su: (to papercut) root on none
Jan 2 13:07:27 phire su: (to papercut) root on none

which correspond to the audit.log entries for example:

type=USER_AUTH msg=audit(1357150683.081:96790): user pid=3227 uid=0 auid=4294967295 ses=4294967295 msg=‘op=PAM:authentication acct=“papercut” exe="/bin/su" (hostname=?, addr=?, terminal=? res=success)’
type=USER_ACCT msg=audit(1357150683.081:96791): user pid=3227 uid=0 auid=4294967295 ses=4294967295 msg=‘op=PAM:accounting acct=“papercut” exe="/bin/su" (hostname=?, addr=?, terminal=? res=success)’
type=CRED_ACQ msg=audit(1357150683.125:96792): user pid=3227 uid=0 auid=4294967295 ses=4294967295 msg=‘op=PAM:setcred acct=“papercut” exe="/bin/su" (hostname=?, addr=?, terminal=? res=success)’
type=USER_START msg=audit(1357150683.125:96793): user pid=3227 uid=0 auid=4294967295 ses=4294967295 msg=‘op=PAM:session_open acct=“papercut” exe="/bin/su" (hostname=?, addr=?, terminal=? res=success)’
type=USER_END msg=audit(1357150683.177:96794): user pid=3227 uid=0 auid=4294967295 ses=4294967295 msg=‘op=PAM:session_close acct=“papercut” exe="/bin/su" (hostname=?, addr=?, terminal=? res=success)’
type=CRED_DISP msg=audit(1357150683.177:96795): user pid=3227 uid=0 auid=4294967295 ses=4294967295 msg=‘op=PAM:setcred acct=“papercut” exe="/bin/su" (hostname=?, addr=?, terminal=? res=success)’

Is there a way to find out which process run by root creates these log entries?

I have tried using “acct” package but it does not log the PID in the process history (lastcomm). The process exits too fast to see it in top or ps…
There is nothing in crontab that could be causing these logs. BTW, user papercut is used by an application, but even after stopping it the logs are being created.

lsof /var/log/audit.log

But I think you meant /var/log/audit/audit.log?

Should be the Linux Audit demon

Tom

Sorry, yes, I meant /var/log/audit/audit.log file.

But actually I am trying to find out what process is causing these messages to be logged by the audit daemon in the audit.log, I see now that my question is a bit confusing. :slight_smile:

Am 03.01.2013 15:44, schrieb ablovatskia:[color=blue]

Sorry, yes, I meant /var/log/audit/audit.log file.

But actually I am trying to find out what process is causing these
messages to be logged by the audit daemon in the audit.log, I see now
that my question is a bit confusing. :-)[/color]

Or I should read more then just the headline…

Assuming that there are just a few processes started by the user
papercut and the pid is everytime changing try this

watch -n1 ‘ps -U papercut -o pid|tail -n +2|xargs -n1 ps -p’

This will show a condensed view of processes started by papercut,
updated every second. You may want to pipe the result in a logfile, so
add >>/var/log/my.log before the ’ at the end.

watch -n1 'ps -U papercut -o pid|tail -n +2|xargs -n1 ps -p[color=blue][color=green]

/var/log/mylog’[/color][/color]

After a while the log should contain what you want to know.

Tom

Thanks for the help here!
I have been running the watch command for about 5 hours now and it still did not log any interesting PIDs listed in the audit.log. The process seems to be exiting too fast to catch with the 1s refresh interval…

I don’t believe that. Maybe it’s the ‘su’ hiding the user papercut at
the process list. The problem seems to be a process running for a very
short period, right?

Either you have to snip all pids from the ps command

watch -n1 ‘ps aux >> mylog’

and compare with the pid shown in the audit.log

or you have to do some tricky awk/sed scripting to grep the pid at
runtime from audit.log. That’s a hard task because tailf and piping is
an ugly couple.

Personally I would use ‘either’, but your log will grow fast doing so.

Good luck

Tom

First hack^Widea which pops in my mind, is a hook in the ‘su’ pam module.

http://stackoverflow.com/questions/5284624/hook-into-linux-authentication-to-run-script-or-program-when-certain-conditions

You could write a small script which logs information about the parent process ( e. g.: ps -ocommand= -p $PPID | awk -F/ ‘{print $NF}’ | awk ‘{print $1}’ )

thanks for the suggestions!

I should have looked at the auditd man in the first place, though! I was able to trace back the [P]PIDs of the offending process by adding a auditd rule to log all processes started by root:

auditctl -a exit,always -S execve -F uid=0

auditctl -l

LIST_RULES: exit,always uid=0 syscall=execve

this logs a lot of data to the /var/log/audit/audit.log file, so to remove the rul, use:

auditctl -D

No rules