Re: rcu: INFO: rcu_preempt detected stalls on CPUs/tasks on v3.6

From: Michael Wang
Date: Thu Jul 26 2012 - 01:10:10 EST

Next message: Xiao Guangrong: "[PATCH v2] KVM: x86: simplify read_emulated"
Previous message: James Bottomley: "Re: [git patches] libata updates"
In reply to: Sasha Levin: "Re: rcu: INFO: rcu_preempt detected stalls on CPUs/tasks on v3.6"
Next in thread: Michael Wang: "Re: rcu: INFO: rcu_preempt detected stalls on CPUs/tasks on v3.6"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

On 07/26/2012 05:16 AM, Sasha Levin wrote:
> On 07/25/2012 10:36 AM, Michael Wang wrote:
>> On 07/25/2012 01:10 AM, Sasha Levin wrote:
>>> Hi all,
>>>
>>> I was fuzzing with trinity inside a KVM tools guest, on the current 3.6, and stumbled on the following:
>>
>> Hi, Sasha
>>
>> I'm currently trying to reproduce this issue on my machine but keep
>> failing, it's really make me think the issue has been solved...
>
> I see this happening on both with -next and current Linus' master.
>
>> Could you please provide more info about you environment? like the
>> .config and is there some plugin devices which is rarely.
>
> I've attached the .config. The only device attached to the guest is a virtio-9p device which provides the filesystem, but I don't think it's related to the issue.
>
>> It will be better if you can make your test environment as clean as
>> possible (remove the devices which could be remove) and then see whether
>> the issue still exist.
>
> I can't remove the filesystem device, other that that nothing else is attached to the guest.
>
> On 07/25/2012 11:06 AM, Michael Wang wrote:
>> And is this a host dmesg or from the guest?
>
> guest dmesg, nothing appeared in the host.

Then the situation will be more complicated...

If you are running on a X86 platform, the interrupt bit in
eflag should be 0x200, so according to the dmesg, this bit
is not set and the interrupt is disabled.

But then how to explain the timer interrupt in cpu 1's trace?
that makes me doubt there are some issues while simulating
the timer interrupt for guest.

>
>> Could you please provide more details about your testing environment?
>
> The guest is running a -next/3.6 kernel built with the attached .config. In that guest I run an instance of the trinity fuzzer.

Could you provide the option you have used with trinity
(the full command)?
Are you running it as a root or a normal user?

I've test again with a 3.5.0 guest(fedora 16) according
to your .config, running trinity with out any option as
a normal user, the rcu stall warning doesn't appear, but
got some different warning which I have attached below.

I'm not sure whether those info also appear on your machine?

--Michael Wang

Jul 26 12:50:10 localhost kernel: [ 585.900620] ------------[ cut here ]------------
Jul 26 12:50:10 localhost kernel: [ 585.900652] WARNING: at kernel/futex.c:2452 sys_get_robust_list+0x4f/0xe5()
Jul 26 12:50:10 localhost kernel: [ 585.900658] Hardware name: Bochs
Jul 26 12:50:10 localhost kernel: [ 585.900660] deprecated: get_robust_list will be deleted in 2013.
Jul 26 12:50:10 localhost kernel: [ 585.900661] Modules linked in: binfmt_misc bnep can_raw hidp af_802154 phonet bluetooth rfkill can pppoe pppox ppp_generic slhc irda crc_ccitt rds af_key rose ax25 appletalk ipx p8022 psnap llc p8023 atm tcp_lp nls_utf8 fuse lockd ip6t_REJECT nf_conntrack_ipv6 nf_defrag_ipv6 nf_conntrack_ipv4 nf_defrag_ipv4 xt_state nf_conntrack ip6table_filter ip6_tables ppdev parport_pc microcode parport 8139too i2c_piix4 8139cp i2c_core pcspkr mii uinput sunrpc floppy [last unloaded: scsi_wait_scan]
Jul 26 12:50:10 localhost kernel: [ 585.900737] Pid: 6627, comm: trinity-child11 Not tainted 3.5.0+ #16
Jul 26 12:50:10 localhost kernel: [ 585.900739] Call Trace:
Jul 26 12:50:10 localhost kernel: [ 585.900755] [<ffffffff8104c58d>] warn_slowpath_common+0x83/0x9b
Jul 26 12:50:10 localhost kernel: [ 585.900760] [<ffffffff8104c648>] warn_slowpath_fmt+0x46/0x48
Jul 26 12:50:10 localhost kernel: [ 585.900771] [<ffffffff810bdc81>] ? __audit_syscall_entry+0x11f/0x14b
Jul 26 12:50:10 localhost kernel: [ 585.900777] [<ffffffff810a15f9>] sys_get_robust_list+0x4f/0xe5
Jul 26 12:50:10 localhost kernel: [ 585.900796] [<ffffffff81533569>] system_call_fastpath+0x16/0x1b
Jul 26 12:50:10 localhost kernel: [ 585.900799] ---[ end trace d35e4e89c7922e91 ]---
Jul 26 12:50:10 localhost kernel: [ 585.968401] trinity-child11 (6627): Using mlock ulimits for SHM_HUGETLB is deprecated
Jul 26 12:50:10 localhost kernel: [ 586.002344] warning: process `trinity-child7' used the deprecated sysctl system call with
Jul 26 12:50:11 localhost dbus[919]: [system] Successfully activated service 'org.fedoraproject.Setroubleshootd'
Jul 26 12:50:11 localhost dbus-daemon[919]: dbus[919]: [system] Successfully activated service 'org.fedoraproject.Setroubleshootd'
Jul 26 12:50:11 localhost abrtd: Directory 'oops-2012-07-26-12:50:11-868-0' creation detected
Jul 26 12:50:11 localhost abrt-dump-oops: Reported 1 kernel oopses to Abrt
Jul 26 12:50:11 localhost abrtd: Can't open file '/var/spool/abrt/oops-2012-07-26-12:50:11-868-0/uid': No such file or directory
Jul 26 12:50:11 localhost abrtd: DUP_OF_DIR: /var/spool/abrt/oops-2012-07-26-10:59:11-864-0
Jul 26 12:50:11 localhost abrtd: Dump directory is a duplicate of /var/spool/abrt/oops-2012-07-26-10:59:11-864-0
Jul 26 12:50:11 localhost abrtd: Deleting dump directory oops-2012-07-26-12:50:11-868-0 (dup of oops-2012-07-26-10:59:11-864-0), sending dbus signal

Jul 26 12:52:58 localhost kernel: [ 753.298689]
Jul 26 12:52:58 localhost kernel: [ 753.298693] ======================================================
Jul 26 12:52:58 localhost kernel: [ 753.298696] [ INFO: HARDIRQ-READ-safe -> HARDIRQ-READ-unsafe lock order detected ]
Jul 26 12:52:58 localhost kernel: [ 753.298699] 3.5.0+ #16 Tainted: G W
Jul 26 12:52:58 localhost kernel: [ 753.298701] ------------------------------------------------------
Jul 26 12:52:58 localhost kernel: [ 753.298704] trinity-child2/6740 [HC0[0]:SC0[0]:HE0:SE1] is trying to acquire:
Jul 26 12:52:58 localhost kernel: [ 753.298706] (&(&p->alloc_lock)->rlock){+.+...}, at: [<ffffffff81218a11>] keyctl_session_to_parent+0x107/0x329
Jul 26 12:52:58 localhost kernel: [ 753.298731]
Jul 26 12:52:58 localhost kernel: [ 753.298731] and this task is already holding:
Jul 26 12:52:58 localhost kernel: [ 753.298734] (tasklist_lock){.?.?..}, at: [<ffffffff812189f5>] keyctl_session_to_parent+0xeb/0x329
Jul 26 12:52:58 localhost kernel: [ 753.298740] which would create a new lock dependency:
Jul 26 12:52:58 localhost kernel: [ 753.298741] (tasklist_lock){.?.?..} -> (&(&p->alloc_lock)->rlock){+.+...}
Jul 26 12:52:58 localhost kernel: [ 753.298748]
Jul 26 12:52:58 localhost kernel: [ 753.298748] but this new dependency connects a HARDIRQ-READ-irq-safe lock:
Jul 26 12:52:58 localhost kernel: [ 753.298750] (tasklist_lock){.?.?..}
Jul 26 12:52:58 localhost kernel: [ 753.298750] ... which became HARDIRQ-READ-irq-safe at:
Jul 26 12:52:58 localhost kernel: [ 753.298754] [<ffffffff8109d14c>] __lock_acquire+0x27b/0xcf0
Jul 26 12:52:58 localhost kernel: [ 753.298765] [<ffffffff8109e0a0>] lock_acquire+0xfa/0x14f
Jul 26 12:52:58 localhost kernel: [ 753.298769] [<ffffffff8152ce8b>] _raw_read_lock+0x3e/0x4d
Jul 26 12:52:58 localhost kernel: [ 753.298780] [<ffffffff8116403f>] send_sigio+0x56/0xde
Jul 26 12:52:58 localhost kernel: [ 753.298796] [<ffffffff8116417f>] kill_fasync+0xb8/0x118
Jul 26 12:52:58 localhost kernel: [ 753.298800] [<ffffffff813c919e>] evdev_pass_event+0xc3/0xd4
Jul 26 12:52:58 localhost kernel: [ 753.298817] [<ffffffff813c9c23>] evdev_event+0x154/0x210
Jul 26 12:52:58 localhost kernel: [ 753.298820] [<ffffffff813c5149>] input_pass_event+0xe5/0x141
Jul 26 12:52:58 localhost kernel: [ 753.298824] [<ffffffff813c5ab6>] input_handle_event+0x480/0x48f
Jul 26 12:52:58 localhost kernel: [ 753.298827] [<ffffffff813c5c01>] input_event+0x69/0x88
Jul 26 12:52:58 localhost kernel: [ 753.298830] [<ffffffff813cc4d5>] psmouse_process_byte+0x258/0x262
Jul 26 12:52:58 localhost kernel: [ 753.298835] [<ffffffff813cc9df>] psmouse_handle_byte+0x15/0x138
Jul 26 12:52:58 localhost kernel: [ 753.298838] [<ffffffff813ccdcb>] psmouse_interrupt+0x2b2/0x2d2
Jul 26 12:52:58 localhost kernel: [ 753.298842] [<ffffffff813c069a>] serio_interrupt+0x45/0x7f
Jul 26 12:52:58 localhost kernel: [ 753.298852] [<ffffffff813c1498>] i8042_interrupt+0x299/0x2ab
Jul 26 12:52:58 localhost kernel: [ 753.298856] [<ffffffff810cb162>] handle_irq_event_percpu+0xa5/0x266
Jul 26 12:52:58 localhost kernel: [ 753.298871] [<ffffffff810cb367>] handle_irq_event+0x44/0x65
Jul 26 12:52:58 localhost kernel: [ 753.298875] [<ffffffff810cdbc8>] handle_edge_irq+0xaa/0xd2
Jul 26 12:52:58 localhost kernel: [ 753.298879] [<ffffffff81011d08>] handle_irq+0x15f/0x170
Jul 26 12:52:58 localhost kernel: [ 753.298894] [<ffffffff8153532d>] do_IRQ+0x4d/0xa4
Jul 26 12:52:58 localhost kernel: [ 753.298898] [<ffffffff8152d5af>] ret_from_intr+0x0/0x1a
Jul 26 12:52:58 localhost kernel: [ 753.298902] [<ffffffff81017829>] default_idle+0x51/0x8c
Jul 26 12:52:58 localhost kernel: [ 753.298908] [<ffffffff810181e6>] cpu_idle+0xaf/0x103
Jul 26 12:52:58 localhost kernel: [ 753.298911] [<ffffffff81506441>] rest_init+0x135/0x13c
Jul 26 12:52:58 localhost kernel: [ 753.298920] [<ffffffff81b0cbb3>] start_kernel+0x3d9/0x3e6
Jul 26 12:52:58 localhost kernel: [ 753.298938] [<ffffffff81b0c2d3>] x86_64_start_reservations+0xae/0xb2
Jul 26 12:52:58 localhost kernel: [ 753.298942] [<ffffffff81b0c3d9>] x86_64_start_kernel+0x102/0x111
Jul 26 12:52:58 localhost kernel: [ 753.298949]
Jul 26 12:52:58 localhost kernel: [ 753.298949] to a HARDIRQ-READ-irq-unsafe lock:
Jul 26 12:52:58 localhost kernel: [ 753.298951] (&(&p->alloc_lock)->rlock){+.+...}
Jul 26 12:52:58 localhost kernel: [ 753.298951] ... which became HARDIRQ-READ-irq-unsafe at:
Jul 26 12:52:58 localhost kernel: [ 753.298955] ... [<ffffffff8109d1f4>] __lock_acquire+0x323/0xcf0
Jul 26 12:52:58 localhost kernel: [ 753.298964] [<ffffffff8109e0a0>] lock_acquire+0xfa/0x14f
Jul 26 12:52:58 localhost kernel: [ 753.298967] [<ffffffff8152ca10>] _raw_spin_lock+0x3b/0x4a
Jul 26 12:52:58 localhost kernel: [ 753.298971] [<ffffffff8115b87a>] set_task_comm+0x25/0xe5
Jul 26 12:52:58 localhost kernel: [ 753.298979] [<ffffffff8106eb2c>] kthreadd+0x35/0x151
Jul 26 12:52:58 localhost kernel: [ 753.298989] [<ffffffff815349b4>] kernel_thread_helper+0x4/0x10
Jul 26 12:52:58 localhost kernel: [ 753.298993]
Jul 26 12:52:58 localhost kernel: [ 753.298993] other info that might help us debug this:
Jul 26 12:52:58 localhost kernel: [ 753.298993]
Jul 26 12:52:58 localhost kernel: [ 753.298996] Possible interrupt unsafe locking scenario:
Jul 26 12:52:58 localhost kernel: [ 753.298996]
Jul 26 12:52:58 localhost kernel: [ 753.298998] CPU0 CPU1
Jul 26 12:52:58 localhost kernel: [ 753.298999] ---- ----
Jul 26 12:52:58 localhost kernel: [ 753.299000] lock(&(&p->alloc_lock)->rlock);
Jul 26 12:52:58 localhost kernel: [ 753.299008] local_irq_disable();
Jul 26 12:52:58 localhost kernel: [ 753.299010] lock(tasklist_lock);
Jul 26 12:52:58 localhost kernel: [ 753.299013] lock(&(&p->alloc_lock)->rlock);
Jul 26 12:52:58 localhost kernel: [ 753.299015] <Interrupt>
Jul 26 12:52:58 localhost kernel: [ 753.299016] lock(tasklist_lock);
Jul 26 12:52:58 localhost kernel: [ 753.299016]
Jul 26 12:52:58 localhost kernel: [ 753.299016] *** DEADLOCK ***
Jul 26 12:52:58 localhost kernel: [ 753.299016]
Jul 26 12:52:58 localhost kernel: [ 753.299016] 2 locks held by trinity-child2/6740:
Jul 26 12:52:58 localhost kernel: [ 753.299016] #0: (rcu_read_lock){.+.+..}, at: [<ffffffff81218952>] keyctl_session_to_parent+0x48/0x329
Jul 26 12:52:58 localhost kernel: [ 753.299016] #1: (tasklist_lock){.?.?..}, at: [<ffffffff812189f5>] keyctl_session_to_parent+0xeb/0x329
Jul 26 12:52:58 localhost kernel: [ 753.299016]
Jul 26 12:52:58 localhost kernel: [ 753.299016] the dependencies between HARDIRQ-READ-irq-safe lock and the holding lock:
Jul 26 12:52:58 localhost kernel: [ 753.299016] -> (tasklist_lock){.?.?..} ops: 41961 {
Jul 26 12:52:58 localhost kernel: [ 753.299016] IN-HARDIRQ-R at:
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109d14c>] __lock_acquire+0x27b/0xcf0
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109e0a0>] lock_acquire+0xfa/0x14f
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8152ce8b>] _raw_read_lock+0x3e/0x4d
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8116403f>] send_sigio+0x56/0xde
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8116417f>] kill_fasync+0xb8/0x118
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff813c919e>] evdev_pass_event+0xc3/0xd4
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff813c9c23>] evdev_event+0x154/0x210
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff813c5149>] input_pass_event+0xe5/0x141
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff813c5ab6>] input_handle_event+0x480/0x48f
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff813c5c01>] input_event+0x69/0x88
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff813cc4d5>] psmouse_process_byte+0x258/0x262
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff813cc9df>] psmouse_handle_byte+0x15/0x138
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff813ccdcb>] psmouse_interrupt+0x2b2/0x2d2
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff813c069a>] serio_interrupt+0x45/0x7f
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff813c1498>] i8042_interrupt+0x299/0x2ab
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff810cb162>] handle_irq_event_percpu+0xa5/0x266
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff810cb367>] handle_irq_event+0x44/0x65
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff810cdbc8>] handle_edge_irq+0xaa/0xd2
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81011d08>] handle_irq+0x15f/0x170
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8153532d>] do_IRQ+0x4d/0xa4
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8152d5af>] ret_from_intr+0x0/0x1a
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81017829>] default_idle+0x51/0x8c
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff810181e6>] cpu_idle+0xaf/0x103
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81506441>] rest_init+0x135/0x13c
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81b0cbb3>] start_kernel+0x3d9/0x3e6
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81b0c2d3>] x86_64_start_reservations+0xae/0xb2
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81b0c3d9>] x86_64_start_kernel+0x102/0x111
Jul 26 12:52:58 localhost kernel: [ 753.299016] HARDIRQ-ON-R at:
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109d1c9>] __lock_acquire+0x2f8/0xcf0
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109e0a0>] lock_acquire+0xfa/0x14f
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8152ce8b>] _raw_read_lock+0x3e/0x4d
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81051111>] do_wait+0xff/0x259
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81052577>] sys_wait4+0x9e/0xc1
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81533569>] system_call_fastpath+0x16/0x1b
Jul 26 12:52:58 localhost kernel: [ 753.299016] IN-SOFTIRQ-R at:
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109d1a4>] __lock_acquire+0x2d3/0xcf0
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109e0a0>] lock_acquire+0xfa/0x14f
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8152ce8b>] _raw_read_lock+0x3e/0x4d
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8116403f>] send_sigio+0x56/0xde
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8116417f>] kill_fasync+0xb8/0x118
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff813c919e>] evdev_pass_event+0xc3/0xd4
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff813c9c23>] evdev_event+0x154/0x210
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff813c5149>] input_pass_event+0xe5/0x141
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff813c5ab6>] input_handle_event+0x480/0x48f
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff813c5c01>] input_event+0x69/0x88
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff813cc4d5>] psmouse_process_byte+0x258/0x262
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff813cc9df>] psmouse_handle_byte+0x15/0x138
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff813ccdcb>] psmouse_interrupt+0x2b2/0x2d2
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff813c069a>] serio_interrupt+0x45/0x7f
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff813c1498>] i8042_interrupt+0x299/0x2ab
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff810cb162>] handle_irq_event_percpu+0xa5/0x266
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff810cb367>] handle_irq_event+0x44/0x65
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff810cdbc8>] handle_edge_irq+0xaa/0xd2
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81011d08>] handle_irq+0x15f/0x170
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8153532d>] do_IRQ+0x4d/0xa4
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8152d5af>] ret_from_intr+0x0/0x1a
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff810542cb>] __do_softirq+0x80/0x265
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81534aac>] call_softirq+0x1c/0x30
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81011d64>] do_softirq+0x4b/0x9f
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81054725>] irq_exit+0x5d/0xcc
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff815353ff>] smp_apic_timer_interrupt+0x7b/0x89
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff815340af>] apic_timer_interrupt+0x6f/0x80
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81017829>] default_idle+0x51/0x8c
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff810181e6>] cpu_idle+0xaf/0x103
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81506441>] rest_init+0x135/0x13c
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81b0cbb3>] start_kernel+0x3d9/0x3e6
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81b0c2d3>] x86_64_start_reservations+0xae/0xb2
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81b0c3d9>] x86_64_start_kernel+0x102/0x111
Jul 26 12:52:58 localhost kernel: [ 753.299016] SOFTIRQ-ON-R at:
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109d218>] __lock_acquire+0x347/0xcf0
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109e0a0>] lock_acquire+0xfa/0x14f
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8152ce8b>] _raw_read_lock+0x3e/0x4d
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81051111>] do_wait+0xff/0x259
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81052577>] sys_wait4+0x9e/0xc1
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81533569>] system_call_fastpath+0x16/0x1b
Jul 26 12:52:58 localhost kernel: [ 753.299016] INITIAL USE at:
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109d269>] __lock_acquire+0x398/0xcf0
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109e0a0>] lock_acquire+0xfa/0x14f
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8152cc51>] _raw_write_lock_irq+0x45/0x54
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8104b3ca>] copy_process+0xea0/0x1452
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8104bac7>] do_fork+0x110/0x2fe
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8101757d>] kernel_thread+0x75/0x77
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81506332>] rest_init+0x26/0x13c
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81b0cbb3>] start_kernel+0x3d9/0x3e6
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81b0c2d3>] x86_64_start_reservations+0xae/0xb2
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81b0c3d9>] x86_64_start_kernel+0x102/0x111
Jul 26 12:52:58 localhost kernel: [ 753.299016] }
Jul 26 12:52:58 localhost kernel: [ 753.299016] ... key at: [<ffffffff81a04058>] tasklist_lock+0x18/0x40
Jul 26 12:52:58 localhost kernel: [ 753.299016] ... acquired at:
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109cbda>] check_irq_usage+0x76/0x88
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109d907>] __lock_acquire+0xa36/0xcf0
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109e0a0>] lock_acquire+0xfa/0x14f
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8152ca10>] _raw_spin_lock+0x3b/0x4a
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81218a11>] keyctl_session_to_parent+0x107/0x329
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81218cf2>] sys_keyctl+0xbf/0xd9
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81533569>] system_call_fastpath+0x16/0x1b
Jul 26 12:52:58 localhost kernel: [ 753.299016]
Jul 26 12:52:58 localhost kernel: [ 753.299016]
Jul 26 12:52:58 localhost kernel: [ 753.299016] the dependencies between the lock to be acquired and HARDIRQ-READ-irq-unsafe lock:
Jul 26 12:52:58 localhost kernel: [ 753.299016] -> (&(&p->alloc_lock)->rlock){+.+...} ops: 230916 {
Jul 26 12:52:58 localhost kernel: [ 753.299016] HARDIRQ-ON-W at:
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109d1f4>] __lock_acquire+0x323/0xcf0
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109e0a0>] lock_acquire+0xfa/0x14f
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8152ca10>] _raw_spin_lock+0x3b/0x4a
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8115b87a>] set_task_comm+0x25/0xe5
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8106eb2c>] kthreadd+0x35/0x151
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff815349b4>] kernel_thread_helper+0x4/0x10
Jul 26 12:52:58 localhost kernel: [ 753.299016] SOFTIRQ-ON-W at:
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109d218>] __lock_acquire+0x347/0xcf0
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109e0a0>] lock_acquire+0xfa/0x14f
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8152ca10>] _raw_spin_lock+0x3b/0x4a
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8115b87a>] set_task_comm+0x25/0xe5
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8106eb2c>] kthreadd+0x35/0x151
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff815349b4>] kernel_thread_helper+0x4/0x10
Jul 26 12:52:58 localhost kernel: [ 753.299016] INITIAL USE at:
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109d269>] __lock_acquire+0x398/0xcf0
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109e0a0>] lock_acquire+0xfa/0x14f
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8152ca10>] _raw_spin_lock+0x3b/0x4a
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8115b87a>] set_task_comm+0x25/0xe5
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8106eb2c>] kthreadd+0x35/0x151
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff815349b4>] kernel_thread_helper+0x4/0x10
Jul 26 12:52:58 localhost kernel: [ 753.299016] }
Jul 26 12:52:58 localhost kernel: [ 753.299016] ... key at: [<ffffffff81c438a8>] __key.45376+0x0/0x8
Jul 26 12:52:58 localhost kernel: [ 753.299016] ... acquired at:
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109cbda>] check_irq_usage+0x76/0x88
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109d907>] __lock_acquire+0xa36/0xcf0
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109e0a0>] lock_acquire+0xfa/0x14f
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8152ca10>] _raw_spin_lock+0x3b/0x4a
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81218a11>] keyctl_session_to_parent+0x107/0x329
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81218cf2>] sys_keyctl+0xbf/0xd9
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81533569>] system_call_fastpath+0x16/0x1b
Jul 26 12:52:58 localhost kernel: [ 753.299016]
Jul 26 12:52:58 localhost kernel: [ 753.299016]
Jul 26 12:52:58 localhost kernel: [ 753.299016] stack backtrace:
Jul 26 12:52:58 localhost kernel: [ 753.299016] Pid: 6740, comm: trinity-child2 Tainted: G W 3.5.0+ #16
Jul 26 12:52:58 localhost kernel: [ 753.299016] Call Trace:
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109cb4f>] check_usage+0x38d/0x3a2
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109e0bc>] ? lock_acquire+0x116/0x14f
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109cbda>] check_irq_usage+0x76/0x88
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109d907>] __lock_acquire+0xa36/0xcf0
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8121f78e>] ? kzalloc+0xf/0x11
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81218a11>] ? keyctl_session_to_parent+0x107/0x329
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109e0a0>] lock_acquire+0xfa/0x14f
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81218a11>] ? keyctl_session_to_parent+0x107/0x329
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8152ca10>] _raw_spin_lock+0x3b/0x4a
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81218a11>] ? keyctl_session_to_parent+0x107/0x329
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff810d3f77>] ? rcu_is_cpu_idle+0x53/0x62
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81218a11>] keyctl_session_to_parent+0x107/0x329
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81218952>] ? keyctl_session_to_parent+0x48/0x329
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff8109e4f2>] ? trace_hardirqs_on_caller+0x121/0x158
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81218cf2>] sys_keyctl+0xbf/0xd9
Jul 26 12:52:58 localhost kernel: [ 753.299016] [<ffffffff81533569>] system_call_fastpath+0x16/0x1b

Jul 26 12:54:14 localhost kernel: [ 830.136969] BUG: unable to handle kernel paging request at ffffffffffffffff
Jul 26 12:54:14 localhost kernel: [ 830.136975] IP: [<ffffffff81223f57>] selinux_inode_setxattr+0xdc/0x1a8
Jul 26 12:54:14 localhost kernel: [ 830.136982] PGD 1a0d067 PUD 1a0e067 PMD 0
Jul 26 12:54:14 localhost kernel: [ 830.136986] Oops: 0000 [#1] PREEMPT SMP
Jul 26 12:54:14 localhost kernel: [ 830.136989] Modules linked in: scsi_transport_iscsi ipt_ULOG nfnetlink binfmt_misc bnep can_raw hidp af_802154 phonet bluetooth rfkill can pppoe pppox ppp_generic slhc irda crc_ccitt rds af_key rose ax25 appletalk ipx p8022 psnap llc p8023 atm tcp_lp nls_utf8 fuse lockd ip6t_REJECT nf_conntrack_ipv6 nf_defrag_ipv6 nf_conntrack_ipv4 nf_defrag_ipv4 xt_state nf_conntrack ip6table_filter ip6_tables ppdev parport_pc microcode parport 8139too i2c_piix4 8139cp i2c_core pcspkr mii uinput sunrpc floppy [last unloaded: scsi_wait_scan]
Jul 26 12:54:14 localhost kernel: [ 830.137031] CPU 1
Jul 26 12:54:14 localhost kernel: [ 830.137033] Pid: 7662, comm: trinity-child1 Tainted: G W 3.5.0+ #16 Bochs Bochs
Jul 26 12:54:14 localhost kernel: [ 830.137035] RIP: 0010:[<ffffffff81223f57>] [<ffffffff81223f57>] selinux_inode_setxattr+0xdc/0x1a8
Jul 26 12:54:14 localhost kernel: [ 830.137039] RSP: 0018:ffff8801e6ac7ce8 EFLAGS: 00010246
Jul 26 12:54:14 localhost kernel: [ 830.137040] RAX: 00000000ffffff00 RBX: ffff8801ed866d10 RCX: 0000000000000021
Jul 26 12:54:14 localhost kernel: [ 830.137042] RDX: 0000000000000000 RSI: ffffffff81a286b0 RDI: ffff8801f314b9c0
Jul 26 12:54:14 localhost kernel: [ 830.137043] RBP: ffff8801e6ac7d58 R08: ffff8801e6ac7c50 R09: 0000000000000000
Jul 26 12:54:14 localhost kernel: [ 830.137044] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
Jul 26 12:54:14 localhost kernel: [ 830.137046] R13: 0000000000000000 R14: ffff8802039ca0f8 R15: ffff880213f5ea00
Jul 26 12:54:14 localhost kernel: [ 830.137048] FS: 00007f7922686700(0000) GS:ffff88021fc20000(0000) knlGS:0000000000000000
Jul 26 12:54:14 localhost kernel: [ 830.137049] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Jul 26 12:54:14 localhost kernel: [ 830.137051] CR2: ffffffffffffffff CR3: 00000001e6b69000 CR4: 00000000000006e0
Jul 26 12:54:14 localhost kernel: [ 830.137056] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Jul 26 12:54:14 localhost kernel: [ 830.137059] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Jul 26 12:54:14 localhost kernel: [ 830.137065] Process trinity-child1 (pid: 7662, threadinfo ffff8801e6ac6000, task ffff880214110000)
Jul 26 12:54:14 localhost kernel: [ 830.137066] Stack:
Jul 26 12:54:14 localhost kernel: [ 830.137068] ffff8802ffffffea 0000074a811727b9 ffff880203ba3f40 ffff880203ba3f0a
Jul 26 12:54:14 localhost kernel: [ 830.137072] ffff8802039ca0f8 2222222222222222 2222222222222222 0000000022222222
Jul 26 12:54:14 localhost kernel: [ 830.137076] ffff8801e6ac7d68 ffff8802039ca0f8 ffff8801e6ac7de0 0000000000000002
Jul 26 12:54:14 localhost kernel: [ 830.137080] Call Trace:
Jul 26 12:54:14 localhost kernel: [ 830.137089] [<ffffffff8121cf1e>] security_inode_setxattr+0x23/0x25
Jul 26 12:54:14 localhost kernel: [ 830.137094] [<ffffffff811727cd>] vfs_setxattr+0x6b/0xa1
Jul 26 12:54:14 localhost kernel: [ 830.137097] [<ffffffff81172906>] setxattr+0x103/0x146
Jul 26 12:54:14 localhost kernel: [ 830.137102] [<ffffffff8152d093>] ? _raw_spin_unlock_irqrestore+0x6c/0x7a
Jul 26 12:54:14 localhost kernel: [ 830.137109] [<ffffffff81072743>] ? __hrtimer_start_range_ns+0x27c/0x28e
Jul 26 12:54:14 localhost kernel: [ 830.137114] [<ffffffff8109df70>] ? lock_release+0x19c/0x1d2
Jul 26 12:54:14 localhost kernel: [ 830.137117] [<ffffffff8109e536>] ? trace_hardirqs_on+0xd/0xf
Jul 26 12:54:14 localhost kernel: [ 830.137120] [<ffffffff8152d0f2>] ? _raw_spin_unlock_irq+0x51/0x5e
Jul 26 12:54:14 localhost kernel: [ 830.137125] [<ffffffff81052d0f>] ? do_setitimer+0x1d8/0x208
Jul 26 12:54:14 localhost kernel: [ 830.137129] [<ffffffff811567d6>] ? fcheck_files+0x87/0xe7
Jul 26 12:54:14 localhost kernel: [ 830.137131] [<ffffffff81172c23>] sys_fsetxattr+0x68/0x9b
Jul 26 12:54:14 localhost kernel: [ 830.137135] [<ffffffff81533569>] system_call_fastpath+0x16/0x1b
Jul 26 12:54:14 localhost kernel: [ 830.137137] Code: e2 00 00 00 48 8d 55 cc 44 89 e6 4c 89 ef e8 7c c2 00 00 83 f8 ea 89 c1 75 7a bf 21 00 00 00 89 45 90 e8 ef 33 e3 ff 84 c0 75 58 <43> 80 7c 25 ff 01 ba 79 05 00 00 be 20 00 00 00 49 83 dc 00 65
Jul 26 12:54:14 localhost kernel: [ 830.137168] RIP [<ffffffff81223f57>] selinux_inode_setxattr+0xdc/0x1a8
Jul 26 12:54:14 localhost kernel: [ 830.137171] RSP <ffff8801e6ac7ce8>
Jul 26 12:54:14 localhost kernel: [ 830.137172] CR2: ffffffffffffffff
Jul 26 12:54:14 localhost kernel: [ 830.137177] ---[ end trace d35e4e89c7922e92 ]---

> Nothing else is attached to the guest.
> The host is running a 3.5 kernel, and running the guest within KVM tools.
>
> If you need more specific info about anything let me know.
>

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

Next message: Xiao Guangrong: "[PATCH v2] KVM: x86: simplify read_emulated"
Previous message: James Bottomley: "Re: [git patches] libata updates"
In reply to: Sasha Levin: "Re: rcu: INFO: rcu_preempt detected stalls on CPUs/tasks on v3.6"
Next in thread: Michael Wang: "Re: rcu: INFO: rcu_preempt detected stalls on CPUs/tasks on v3.6"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]