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:
BZ #230191 is the bug that details the problem with fail2ban and selinux policy.
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?
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.
[Just to clarify - I don't see these soft lockups on F7 on the same machines]
Closing due to lack of further info. Fixed in F7 anyway.