[Bugme-new] [Bug 6274] New: audit_log_exit calls sleeping function in invalid context

[Andrew Morton]

bugme-daemon at bugzilla.kernel.org wrote:
>
> http://bugzilla.kernel.org/show_bug.cgi?id=6274
> 
>            Summary: audit_log_exit calls sleeping function in invalid
>                     context
>     Kernel Version: 2.6.16
>             Status: NEW
>           Severity: normal
>              Owner: process_other at kernel-bugs.osdl.org
>          Submitter: vladimir.kondratiev at intel.com
> 
> 
> Most recent kernel where this bug did not occur:
> did not tested this in earlier kernels
> 
> Distribution:
> Fedora Core 5
> 
> Hardware Environment:
> Software Environment: 
> Vanilla 2.6.16 kernel
> [root at vkondra-mobl ~]# cat /proc/version
> Linux version 2.6.16 (root at vkondra-mobl) (gcc version 4.1.0 20060304 (Red Hat
> 4.1.0-3)) #1 PREEMPT Mon Mar 20 13:43:30 IST 2006
> 
> Problem Description:
> sleeping function called in invalid context.
> 
> Steps to reproduce:
> 
> Enable audit rule to track all "exit" syscalls:
> auditctl -a exit,always -S exit
> 
> run anything, 'ls' is OK. This will trigger the following error:
> 
> Mar 23 16:15:10 vkondra-mobl kernel: Debug: sleeping function called from
> invalid context at include/linux/rwsem.h:43
> Mar 23 16:15:10 vkondra-mobl kernel: in_atomic():1, irqs_disabled():0
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c0104084>] show_trace+0xd/0xf
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c01040d0>] dump_stack+0x17/0x19
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c0114685>] __might_sleep+0x86/0x90
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c01345e5>] audit_log_exit+0x136/0x36b
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c013560a>] audit_free+0x101/0x20e
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c0117368>] __put_task_struct_cb+0x8f/0xdc
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c012624d>]
> __rcu_process_callbacks+0xf6/0x14b
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c01262b4>] rcu_process_callbacks+0x12/0x23
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c011c5c8>] tasklet_action+0x3a/0x60
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c011c513>] __do_softirq+0x43/0x8f
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c011c589>] do_softirq+0x2a/0x2f
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c011c662>] irq_exit+0x30/0x3c
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c0104c02>] do_IRQ+0x4a/0x58
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c01036fe>] common_interrupt+0x1a/0x20
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c014d41a>]
> cache_alloc_debugcheck_after+0x25/0xf4
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c014d565>] kmem_cache_alloc+0x7c/0x88
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c0239690>] __alloc_skb+0x29/0xf4
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c02366f3>] sock_alloc_send_skb+0x62/0x19a
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c028afed>] unix_stream_sendmsg+0x131/0x2fd
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c023415d>] do_sock_write+0xb5/0xbe
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c0234f84>] sock_aio_write+0x56/0x64
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c0150684>] do_sync_write+0xb1/0xe6
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c0150f41>] vfs_write+0xbc/0x154
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c01514a5>] sys_write+0x3b/0x60
> Mar 23 16:15:10 vkondra-mobl kernel:  [<c0102cb9>] syscall_call+0x7/0xb

Yes, bad. We cannot perform sleeping things in an RCU callback.

I don't think that audit_log_exit() call is in the correct place anyway. 
It's not actually logging an "exit" - it's currently logging the free of a
task_struct, which can happen an arbitrary time later and can be performed
by a different task (or by none at all, as in this case).

IOW: shouldn't we be calling audit_log_exit() from within do_exit()??

A backportable-to-2.6.16.1 fix is needed, I'd suggest.