Bug 241535 - selinux/audit causing soft lockup
Summary: selinux/audit causing soft lockup
Keywords:
Status: CLOSED INSUFFICIENT_DATA
Alias: None
Product: Fedora
Classification: Fedora
Component: kernel
Version: 6
Hardware: All
OS: Linux
medium
medium
Target Milestone: ---
Assignee: Kernel Maintainer List
QA Contact: Brian Brock
URL:
Whiteboard:
Depends On: 230191
Blocks:
TreeView+ depends on / blocked
 
Reported: 2007-05-27 15:20 UTC by Jonathan Underwood
Modified: 2007-11-30 22:12 UTC (History)
0 users

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2007-06-22 21:04:11 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)

Description Jonathan Underwood 2007-05-27 15:20:12 UTC
Description of problem:
Today I noticed that an avc denied event seemed to cause a soft lockup of the
kernel. I am not sure if this should be filed against selinux or the kernel.

Version-Release number of selected component (if applicable):
kernel-2.6.20-1.2948.fc6
selinux-policy-2.4.6-69.fc6
libselinux-1.33.4-2.fc6
libselinux-1.33.4-2.fc6
selinux-policy-targeted-2.4.6-69.fc6

How reproducible:
Unsure.

Steps to Reproduce:
1.Install fail2ban
2.Wait for an event which triggers fail2ban to try to write a log message
3.
  
Actual results:
May 27 12:37:19 withnail kernel: audit(1180265839.698:170): avc:  denied  { read
write } for  pid=22600 comm="iptables" nam
e="[544036]" dev=sockfs ino=544036 scontext=user_u:system_r:iptables_t:s0
tcontext=user_u:system_r:initrc_t:s0 tclass=unix_
stream_socket
May 27 12:37:19 withnail kernel: audit(1180265839.698:171): avc:  denied  {
append } for  pid=22600 comm="iptables" name="f
ail2ban.log" dev=sda2 ino=1404512 scontext=user_u:system_r:iptables_t:s0
tcontext=system_u:object_r:fail2ban_log_t:s0 tclas
s=file
May 27 12:37:19 withnail kernel: audit(1180265839.717:172): avc:  denied  { read
write } for  pid=22603 comm="iptables" nam
e="[544036]" dev=sockfs ino=544036 scontext=user_u:system_r:iptables_t:s0
tcontext=user_u:system_r:initrc_t:s0 tclass=unix_
stream_socket
May 27 12:37:19 withnail kernel: audit(1180265839.717:173): avc:  denied  {
append } for  pid=22603 comm="iptables" name="f
ail2ban.log" dev=sda2 ino=1404512 scontext=user_u:system_r:iptables_t:s0
tcontext=system_u:object_r:fail2ban_log_t:s0 tclas
s=file
May 27 12:37:19 withnail kernel: BUG: soft lockup detected on CPU#0!
May 27 12:37:19 withnail kernel: 
May 27 12:37:19 withnail kernel: Call Trace:
May 27 12:37:19 withnail kernel:  <IRQ>  [<ffffffff802b0bc6>]
softlockup_tick+0xdb/0xf6
May 27 12:37:19 withnail kernel:  [<ffffffff8042a113>] rt_check_expire+0x0/0x159
May 27 12:37:19 withnail kernel:  [<ffffffff8028f5d3>]
update_process_times+0x42/0x68
May 27 12:37:19 withnail kernel:  [<ffffffff80271f0c>]
smp_local_timer_interrupt+0x34/0x55
May 27 12:37:19 withnail kernel:  [<ffffffff80284b4f>] enqueue_task+0x41/0x56
May 27 12:37:19 withnail kernel:  [<ffffffff802725e8>]
smp_apic_timer_interrupt+0x51/0x69
May 27 12:37:19 withnail kernel:  [<ffffffff8025ace6>]
apic_timer_interrupt+0x66/0x70
May 27 12:37:19 withnail kernel:  [<ffffffff8042a19f>] rt_check_expire+0x8c/0x159
May 27 12:37:19 withnail kernel:  [<ffffffff8042a113>] rt_check_expire+0x0/0x159
May 27 12:37:19 withnail kernel:  [<ffffffff8028f002>] run_timer_softirq+0x138/0x1ac
May 27 12:37:19 withnail kernel:  [<ffffffff80211ffb>] __do_softirq+0x55/0xc3
May 27 12:37:19 withnail kernel:  [<ffffffff8025b23c>] call_softirq+0x1c/0x28
May 27 12:37:19 withnail kernel:  [<ffffffff802684d2>] do_softirq+0x2c/0x85
May 27 12:37:19 withnail kernel:  [<ffffffff802725ed>]
smp_apic_timer_interrupt+0x56/0x69
May 27 12:37:19 withnail kernel:  [<ffffffff8025ace6>]
apic_timer_interrupt+0x66/0x70
May 27 12:37:19 withnail kernel:  <EOI>  [<ffffffff80289c4a>] vprintk+0x2af/0x2ef
May 27 12:37:19 withnail kernel:  [<ffffffff802ab43b>] audit_log_vformat+0xb1/0x17c
May 27 12:37:19 withnail kernel:  [<ffffffff80289cdc>] printk+0x52/0xbd
May 27 12:37:19 withnail kernel:  [<ffffffff802ab554>] audit_log_format+0x4e/0x56
May 27 12:37:19 withnail kernel:  [<ffffffff802ab0ef>] audit_log_end+0xdf/0x104
May 27 12:37:19 withnail kernel:  [<ffffffff803190ec>] avc_audit+0xb3f/0xb4e
May 27 12:37:19 withnail kernel:  [<ffffffff8020f282>] __alloc_pages+0x72/0x2d4
May 27 12:37:19 withnail kernel:  [<ffffffff80319141>] avc_has_perm+0x46/0x58
May 27 12:37:19 withnail kernel:  [<ffffffff80319d22>] inode_has_perm+0x56/0x63
May 27 12:37:19 withnail kernel:  [<ffffffff80319141>] avc_has_perm+0x46/0x58
May 27 12:37:19 withnail kernel:  [<ffffffff80262af4>] do_page_fault+0x48b/0x7ca
May 27 12:37:19 withnail kernel:  [<ffffffff8021670d>] prio_tree_insert+0x181/0x22a
May 27 12:37:19 withnail kernel:  [<ffffffff80319dc3>] file_has_perm+0x94/0xa3
May 27 12:37:19 withnail kernel:  [<ffffffff8031c339>]
selinux_bprm_post_apply_creds+0x193/0x3f5
May 27 12:37:19 withnail kernel:  [<ffffffff8031e3b9>]
selinux_bprm_apply_creds+0x19/0xc3
May 27 12:37:19 withnail kernel:  [<ffffffff80218cb8>] load_elf_binary+0x10a1/0x17e5
May 27 12:37:19 withnail kernel:  [<ffffffff80217c17>] load_elf_binary+0x0/0x17e5
May 27 12:37:19 withnail kernel:  [<ffffffff8023e35d>]
search_binary_handler+0xc7/0x25e
May 27 12:37:19 withnail kernel:  [<ffffffff8023d890>] do_execve+0x18c/0x242
May 27 12:37:19 withnail kernel:  [<ffffffff80250e14>] sys_execve+0x36/0x4c
May 27 12:37:19 withnail kernel:  [<ffffffff8025a4e7>] stub_execve+0x67/0xb0
May 27 12:37:19 withnail kernel: 
May 27 12:37:19 withnail kernel: BUG: soft lockup detected on CPU#1!
May 27 12:37:19 withnail kernel: 
May 27 12:37:19 withnail kernel: Call Trace:
May 27 12:37:19 withnail kernel:  <IRQ>  [<ffffffff802b0bc6>]
softlockup_tick+0xdb/0xf6
May 27 12:37:19 withnail kernel:  [<ffffffff8028f1e9>] process_timeout+0x0/0x5
May 27 12:37:19 withnail kernel:  [<ffffffff8028f5d3>]
update_process_times+0x42/0x68
May 27 12:37:19 withnail kernel:  [<ffffffff80271f0c>]
smp_local_timer_interrupt+0x34/0x55
May 27 12:37:19 withnail kernel:  [<ffffffff80284b4f>] enqueue_task+0x41/0x56
May 27 12:37:19 withnail kernel:  [<ffffffff802725e8>]
smp_apic_timer_interrupt+0x51/0x69
May 27 12:37:19 withnail kernel:  [<ffffffff8025ace6>]
apic_timer_interrupt+0x66/0x70
May 27 12:37:19 withnail kernel:  [<ffffffff80260aab>] _spin_unlock_irq+0xb/0xc
May 27 12:37:19 withnail kernel:  [<ffffffff8028efec>] run_timer_softirq+0x122/0x1ac
May 27 12:37:19 withnail kernel:  [<ffffffff80211ffb>] __do_softirq+0x55/0xc3
May 27 12:37:19 withnail kernel:  [<ffffffff8025b23c>] call_softirq+0x1c/0x28
May 27 12:37:19 withnail kernel:  [<ffffffff802684d2>] do_softirq+0x2c/0x85
May 27 12:37:19 withnail kernel:  [<ffffffff802725ed>]
smp_apic_timer_interrupt+0x56/0x69
May 27 12:37:19 withnail kernel:  [<ffffffff8025ace6>]
apic_timer_interrupt+0x66/0x70
May 27 12:37:19 withnail kernel:  <EOI>  [<ffffffff80260aab>]
_spin_unlock_irq+0xb/0xc
May 27 12:37:19 withnail kernel:  [<ffffffff80289fab>] do_syslog+0x16c/0x3b2
May 27 12:37:19 withnail kernel:  [<ffffffff80297bb7>]
autoremove_wake_function+0x0/0x2e
May 27 12:37:19 withnail kernel:  [<ffffffff8025ef4a>] thread_return+0x5e/0xf9
May 27 12:37:19 withnail kernel:  [<ffffffff802f87c5>] kmsg_read+0x3a/0x44
May 27 12:37:19 withnail kernel:  [<ffffffff8020b14e>] vfs_read+0xcb/0x173
May 27 12:37:19 withnail kernel:  [<ffffffff80211847>] sys_read+0x45/0x6e
May 27 12:37:19 withnail kernel:  [<ffffffff8025a11e>] system_call+0x7e/0x83
May 27 12:37:19 withnail kernel: 
May 27 12:37:19 withnail kernel: audit(1180265839.759:174): avc:  denied  { read
write } for  pid=22604 comm="iptables" nam
e="[544036]" dev=sockfs ino=544036 scontext=user_u:system_r:iptables_t:s0
tcontext=user_u:system_r:initrc_t:s0 tclass=unix_
stream_socket
May 27 12:37:19 withnail kernel: audit(1180265839.759:175): avc:  denied  {
append } for  pid=22604 comm="iptables" name="f
ail2ban.log" dev=sda2 ino=1404512 scontext=user_u:system_r:iptables_t:s0
tcontext=system_u:object_r:fail2ban_log_t:s0 tclas
s=file
May 27 12:37:19 withnail kernel: audit(1180265839.760:176): avc:  denied  { read
write } for  pid=22605 comm="iptables" nam
e="[544036]" dev=sockfs ino=544036 scontext=user_u:system_r:iptables_t:s0
tcontext=user_u:system_r:initrc_t:s0 tclass=unix_
stream_socket
May 27 12:37:19 withnail kernel: audit(1180265839.760:177): avc:  denied  {
append } for  pid=22605 comm="iptables" name="f
ail2ban.log" dev=sda2 ino=1404512 scontext=user_u:system_r:iptables_t:s0
tcontext=system_u:object_r:fail2ban_log_t:s0 tclas
s=file
May 27 12:37:19 withnail kernel: audit(1180265839.766:178): avc:  denied  { read
write } for  pid=22606 comm="iptables" nam
e="[544036]" dev=sockfs ino=544036 scontext=user_u:system_r:iptables_t:s0
tcontext=user_u:system_r:initrc_t:s0 tclass=unix_
stream_socket
May 27 12:37:19 withnail kernel: audit(1180265839.766:179): avc:  denied  {
append } for  pid=22606 comm="iptables" name="f
ail2ban.log" dev=sda2 ino=1404512 scontext=user_u:system_r:iptables_t:s0
tcontext=system_u:object_r:fail2ban_log_t:s0 tclas
s=file
May 27 12:37:19 withnail kernel: audit(1180265839.767:180): avc:  denied  { read
write } for  pid=22607 comm="iptables" nam
e="[544036]" dev=sockfs ino=544036 scontext=user_u:system_r:iptables_t:s0
tcontext=user_u:system_r:initrc_t:s0 tclass=unix_
stream_socket
May 27 12:37:19 withnail kernel: audit(1180265839.767:181): avc:  denied  {
append } for  pid=22607 comm="iptables" name="f
ail2ban.log" dev=sda2 ino=1404512 scontext=user_u:system_r:iptables_t:s0
tcontext=system_u:object_r:fail2ban_log_t:s0 tclas
s=file


Expected results:


Additional info:

Comment 1 Jonathan Underwood 2007-05-27 15:21:32 UTC
BZ #230191 is the bug that details the problem with fail2ban and selinux policy.

Comment 2 Chuck Ebbert 2007-06-22 19:28:26 UTC
It looks like the log is being flooded -- this will cause softlockups.
How many messages end up in the logs around the time of the softlockup?


Comment 3 Jonathan Underwood 2007-06-22 21:00:12 UTC
Hi Chuck,

I'm afraid that I've now moved all machines to F7, so can't go back and check
this to provide more info. IIRC there would be bursts of on the order of 10
messages, but recollection is hazy.

Comment 4 Jonathan Underwood 2007-06-22 21:01:10 UTC
[Just to clarify - I don't see these soft lockups on F7 on the same machines]

Comment 5 Chuck Ebbert 2007-06-22 21:04:11 UTC
Closing due to lack of further info. Fixed in F7 anyway.


Note You need to log in before you can comment on or make changes to this bug.