Re: Audit not recording the correct syscall return value in Fedora 10?

[Tony Jones <tonyj@suse.de>]

On Tue, Apr 07, 2009 at 11:34:35AM -0400, Paul Moore wrote:
> While doing some testing on Fedora 10 using the 2.6.27.5-117.fc10.x86_64 
> kernel I stumbled across a rather odd problem: somewhere between the end of 
> sys_sendto() and audit_syscall_exit() the syscall's return value was changing 
> resulting in incorrect audit records (similar problems with sys_sendmsg()).  
> After some head scratching and debugging I determined that the %rax register 
> was being altered at some point and if we reloaded the syscall's return value 
> from the stack before calling audit_syscall_exit() we could avoid the problem 
> (see patch below).
> 
> I also tried to reproduce the problem with a vanilla 2.6.29.1 kernel and after 
> several hours of testing I have yet to see the problem using the newer, 
> upstream kernel.  Taking a look at the entry_64.S files of the two kernels 
> there appear to be a number of changes, the most significant are the tracing 
> changes but I'm not familiar enough with this chunk of code to identify the 
> definitive root cause (although, tracing changes does sound reasonable).
> 
> Does anyone have any thoughts?

I have seen a similar issue with the init_module syscall on x86_64.  I have an 
open bug on it.

for i in `seq 1 100`; do cat /dev/null > /var/log/audit/audit.log ; rmmod dummy
; rcauditd restart ; auditctl -a entry,always -S init_module ; modprobe dummy ;
ausearch -c modprobe; done

Randomly you'll get a bogus return code in audit, on a DL375 needed 1000 iter
to reproduce.

type=SYSCALL msg=audit(1235061247.598:22697): arch=c000003e syscall=175
success=no exit=1490771928 a0=7fe11dc61000 a1=1e08 a2=61a1e0 a3=61a1e0 items=0
ppid=31342 pid=8313 auid=1001 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0
fsgid=0 tty=pts3 ses=2 comm="modprobe" exe="/sbin/modprobe" key=(null)

I keep meaning to get back to debugging it.

Tony