| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-Id: <1179879569.25500.74.camel@sx.thebigcorporation.com>
Date: Tue, 22 May 2007 17:19:29 -0700
From: Sven-Thorsten Dietrich <sven@...bigcorporation.com>
To: Ingo Molnar <mingo@...e.hu>
Cc: LKML <Linux-kernel@...r.kernel.org>
Subject: LOCKDEP: possible irq lock inversion dependency detected
Hi Ingo,
Below is a snippet from the bootup log, and attached .config
Let me know if there is anything else you need.
Enjoy,
Sven
lockdep says:
---------%<-----------
NET: Registered protocol family 2
IP route cache hash table entries: 131072 (order: 8, 1048576 bytes)
TCP established hash table entries: 16384 (order: 9, 3014656 bytes)
TCP bind hash table entries: 16384 (order: 9, 2883584 bytes)
TCP: Hash tables configured (established 16384 bind 16384)
TCP reno registered
checking if image is initramfs... it is
Freeing initrd memory: 7629k freed
stopped custom tracer.
=========================================================
[ INFO: possible irq lock inversion dependency detected ]
[ 2.6.21-rt6-smp-rt-debug #3
---------------------------------------------------------
swapper/1 just changed the state of lock:
(rtc_lock#2){-...}, at: [<ffffffff8085b185>] sbf_init+0x25/0xe0
but this lock was taken by another, hard-irq-safe lock in the past:
(xtime_lock){+...}
and interrupts could create inverse lock ordering between them.
other info that might help us debug this:
no locks held by swapper/1.
the first lock's dependencies:
-> (rtc_lock#2){-...} ops: 2 {
initial-use at:
[<ffffffff8025d383>] mark_lock+0xf3/0x5b0
[<ffffffff8025e6f4>] __lock_acquire+0x664/0xf80
[<ffffffff8025f098>] lock_acquire+0x88/0xc0
[<ffffffff8047e2c5>] rt_spin_lock+0x35/0x40
[<ffffffff8020e162>] read_persistent_clock+0x22/0x1b0
[<ffffffff80867e86>] timekeeping_init+0x86/0x100
[<ffffffff808537af>] start_kernel+0x1bf/0x350
[<ffffffff80853179>] _sinittext+0x179/0x180
[<ffffffffffffffff>] 0xffffffffffffffff
hardirq-on-W at:
[<ffffffff8025d383>] mark_lock+0xf3/0x5b0
[<ffffffff8025e6b4>] __lock_acquire+0x624/0xf80
[<ffffffff8025f098>] lock_acquire+0x88/0xc0
[<ffffffff8047e2c5>] rt_spin_lock+0x35/0x40
[<ffffffff8085b185>] sbf_init+0x25/0xe0
[<ffffffff80853b28>] init+0x1e8/0x490
[<ffffffff8020b248>] child_rip+0xa/0x12
[<ffffffffffffffff>] 0xffffffffffffffff
}
... key at: [<ffffffff8066b110>] rtc_lock+0x90/0x100
the second lock's dependencies:
-> (xtime_lock){+...} ops: 11343 {
initial-use at:
[<ffffffff8025d383>] mark_lock+0xf3/0x5b0
[<ffffffff8025e6f4>] __lock_acquire+0x664/0xf80
[<ffffffff8025f098>] lock_acquire+0x88/0xc0
[<ffffffff8047eb24>] __spin_lock+0x34/0x50
[<ffffffff80867e21>] timekeeping_init+0x21/0x100
[<ffffffff808537af>] start_kernel+0x1bf/0x350
[<ffffffff80853179>] _sinittext+0x179/0x180
[<ffffffffffffffff>] 0xffffffffffffffff
in-hardirq-W at:
[<ffffffff8025d383>] mark_lock+0xf3/0x5b0
[<ffffffff8025e631>] __lock_acquire+0x5a1/0xf80
[<ffffffff8025f098>] lock_acquire+0x88/0xc0
[<ffffffff8047eb24>] __spin_lock+0x34/0x50
[<ffffffff80259e2d>] tick_periodic+0x1d/0x80
[<ffffffff80259eb4>] tick_handle_periodic+0x24/0x80
[<ffffffff8020dee6>] timer_interrupt+0x16/0x20
[<ffffffff80288059>] handle_IRQ_event+0x69/0x110
[<ffffffff8028a52d>] handle_level_irq+0xed/0x150
[<ffffffff8020d139>] do_IRQ+0x149/0x1d0
[<ffffffff8020a8d6>] ret_from_intr+0x0/0xf
[<ffffffff80872fe0>] console_init+0x0/0x50
[<ffffffff808537e0>] start_kernel+0x1f0/0x350
[<ffffffff80853179>] _sinittext+0x179/0x180
[<ffffffffffffffff>] 0xffffffffffffffff
}
... key at: [<ffffffff806786a0>] xtime_lock+0x20/0x80
-> (clocksource_lock){....} ops: 5098 {
initial-use at:
[<ffffffff8025d383>] mark_lock+0xf3/0x5b0
[<ffffffff8025e6f4>] __lock_acquire+0x664/0xf80
[<ffffffff8025f098>] lock_acquire+0x88/0xc0
[<ffffffff8047eee5>] __spin_lock_irqsave+0x45/0x60
[<ffffffff802582a5>] clocksource_get_next+0x15/0x60
[<ffffffff80867e32>] timekeeping_init+0x32/0x100
[<ffffffff808537af>] start_kernel+0x1bf/0x350
[<ffffffff80853179>] _sinittext+0x179/0x180
[<ffffffffffffffff>] 0xffffffffffffffff
}
... key at: [<ffffffff80678b18>] clocksource_lock+0x18/0x80
... acquired at:
[<ffffffff8025bdc4>] add_lock_to_list+0xa4/0xe0
[<ffffffff8025ed67>] __lock_acquire+0xcd7/0xf80
[<ffffffff8025f098>] lock_acquire+0x88/0xc0
[<ffffffff8047eee5>] __spin_lock_irqsave+0x45/0x60
[<ffffffff802582a5>] clocksource_get_next+0x15/0x60
[<ffffffff80867e32>] timekeeping_init+0x32/0x100
[<ffffffff808537af>] start_kernel+0x1bf/0x350
[<ffffffff80853179>] _sinittext+0x179/0x180
[<ffffffffffffffff>] 0xffffffffffffffff
-> (rtc_lock){....} ops: 3 {
initial-use at:
[<ffffffff8025d383>] mark_lock+0xf3/0x5b0
[<ffffffff8025e6f4>] __lock_acquire+0x664/0xf80
[<ffffffff8025f098>] lock_acquire+0x88/0xc0
[<ffffffff8047eee5>] __spin_lock_irqsave+0x45/0x60
[<ffffffff8047d608>] rt_spin_lock_slowlock+0x38/0x210
[<ffffffff8047e2a6>] rt_spin_lock+0x16/0x40
[<ffffffff8020e162>] read_persistent_clock+0x22/0x1b0
[<ffffffff80867e86>] timekeeping_init+0x86/0x100
[<ffffffff808537af>] start_kernel+0x1bf/0x350
[<ffffffff80853179>] _sinittext+0x179/0x180
[<ffffffffffffffff>] 0xffffffffffffffff
}
... key at: [<ffffffff8066b098>] rtc_lock+0x18/0x100
... acquired at:
[<ffffffff8025bdc4>] add_lock_to_list+0xa4/0xe0
[<ffffffff8025ed67>] __lock_acquire+0xcd7/0xf80
[<ffffffff8025f098>] lock_acquire+0x88/0xc0
[<ffffffff8047eee5>] __spin_lock_irqsave+0x45/0x60
[<ffffffff8047d608>] rt_spin_lock_slowlock+0x38/0x210
[<ffffffff8047e2a6>] rt_spin_lock+0x16/0x40
[<ffffffff8020e162>] read_persistent_clock+0x22/0x1b0
[<ffffffff80867e86>] timekeeping_init+0x86/0x100
[<ffffffff808537af>] start_kernel+0x1bf/0x350
[<ffffffff80853179>] _sinittext+0x179/0x180
[<ffffffffffffffff>] 0xffffffffffffffff
-> (rtc_lock#2){-...} ops: 2 {
initial-use at:
[<ffffffff8025d383>] mark_lock+0xf3/0x5b0
[<ffffffff8025e6f4>] __lock_acquire+0x664/0xf80
[<ffffffff8025f098>] lock_acquire+0x88/0xc0
[<ffffffff8047e2c5>] rt_spin_lock+0x35/0x40
[<ffffffff8020e162>] read_persistent_clock+0x22/0x1b0
[<ffffffff80867e86>] timekeeping_init+0x86/0x100
[<ffffffff808537af>] start_kernel+0x1bf/0x350
[<ffffffff80853179>] _sinittext+0x179/0x180
[<ffffffffffffffff>] 0xffffffffffffffff
hardirq-on-W at:
[<ffffffff8025d383>] mark_lock+0xf3/0x5b0
[<ffffffff8025e6b4>] __lock_acquire+0x624/0xf80
[<ffffffff8025f098>] lock_acquire+0x88/0xc0
[<ffffffff8047e2c5>] rt_spin_lock+0x35/0x40
[<ffffffff8085b185>] sbf_init+0x25/0xe0
[<ffffffff80853b28>] init+0x1e8/0x490
[<ffffffff8020b248>] child_rip+0xa/0x12
[<ffffffffffffffff>] 0xffffffffffffffff
}
... key at: [<ffffffff8066b110>] rtc_lock+0x90/0x100
... acquired at:
[<ffffffff8025bdc4>] add_lock_to_list+0xa4/0xe0
[<ffffffff8025ed67>] __lock_acquire+0xcd7/0xf80
[<ffffffff8025f098>] lock_acquire+0x88/0xc0
[<ffffffff8047e2c5>] rt_spin_lock+0x35/0x40
[<ffffffff8020e162>] read_persistent_clock+0x22/0x1b0
[<ffffffff80867e86>] timekeeping_init+0x86/0x100
[<ffffffff808537af>] start_kernel+0x1bf/0x350
[<ffffffff80853179>] _sinittext+0x179/0x180
[<ffffffffffffffff>] 0xffffffffffffffff
-> (__vsyscall_gtod_data.lock){....} ops: 5093 {
initial-use at:
[<ffffffff8025d383>] mark_lock+0xf3/0x5b0
[<ffffffff8025e6f4>] __lock_acquire+0x664/0xf80
[<ffffffff8025f098>] lock_acquire+0x88/0xc0
[<ffffffff8047eb24>] __spin_lock+0x34/0x50
[<ffffffff8021108d>] update_vsyscall+0x2d/0x180
[<ffffffff80245fbb>] run_timer_softirq+0x43b/0x850
[<ffffffff80241ca2>] ksoftirqd+0x182/0x2a0
[<ffffffff802529f4>] kthread+0xf4/0x130
[<ffffffff8020b248>] child_rip+0xa/0x12
[<ffffffffffffffff>] 0xffffffffffffffff
}
... key at: [<ffffffff80849220>] sysctl_unix_max_dgram_qlen+0xbe0/0x19c0
... acquired at:
[<ffffffff8025bdc4>] add_lock_to_list+0xa4/0xe0
[<ffffffff8025ed67>] __lock_acquire+0xcd7/0xf80
[<ffffffff8025f098>] lock_acquire+0x88/0xc0
[<ffffffff8047eb24>] __spin_lock+0x34/0x50
[<ffffffff8021108d>] update_vsyscall+0x2d/0x180
[<ffffffff80245fbb>] run_timer_softirq+0x43b/0x850
[<ffffffff80241ca2>] ksoftirqd+0x182/0x2a0
[<ffffffff802529f4>] kthread+0xf4/0x130
[<ffffffff8020b248>] child_rip+0xa/0x12
[<ffffffffffffffff>] 0xffffffffffffffff
stack backtrace:
Call Trace:
[<ffffffff8020b936>] dump_trace+0xc6/0x380
[<ffffffff8020bc3d>] show_trace+0x4d/0x80
[<ffffffff8020bc8a>] dump_stack+0x1a/0x20
[<ffffffff8025ca71>] print_irq_inversion_bug+0x141/0x160
[<ffffffff8025d14f>] check_usage_backwards+0x4f/0x60
[<ffffffff8025d591>] mark_lock+0x301/0x5b0
[<ffffffff8025e6b4>] __lock_acquire+0x624/0xf80
[<ffffffff8025f098>] lock_acquire+0x88/0xc0
[<ffffffff8047e2c5>] rt_spin_lock+0x35/0x40
[<ffffffff8085b185>] sbf_init+0x25/0xe0
[<ffffffff80853b28>] init+0x1e8/0x490
[<ffffffff8020b248>] child_rip+0xa/0x12
INFO: lockdep is turned off.
---------------------------
| preempt count: 00000000 ]
| 0-level deep critical section nesting:
----------------------------------------
Simple Boot Flag at 0x7a set to 0x1
Registering sysdev class '<NULL>'
Registering sys device 'i82370'
------------%<-------------------
cat /proc/cpuinfo
processor : 0
vendor_id : GenuineIntel
cpu family : 6
model : 15
model name : Intel(R) Xeon(R) CPU 5130 @ 2.00GHz
stepping : 6
cpu MHz : 1995.000
cache size : 4096 KB
physical id : 0
siblings : 2
core id : 0
cpu cores : 2
fpu : yes
fpu_exception : yes
cpuid level : 10
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmovm
bogomips : 3993.06
clflush size : 64
cache_alignment : 64
address sizes : 36 bits physical, 48 bits virtual
power management:
processor : 1
vendor_id : GenuineIntel
cpu family : 6
model : 15
model name : Intel(R) Xeon(R) CPU 5130 @ 2.00GHz
stepping : 6
cpu MHz : 1995.000
cache size : 4096 KB
physical id : 3
siblings : 2
core id : 0
cpu cores : 2
fpu : yes
fpu_exception : yes
cpuid level : 10
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmovm
bogomips : 3990.04
clflush size : 64
cache_alignment : 64
address sizes : 36 bits physical, 48 bits virtual
power management:
processor : 2
vendor_id : GenuineIntel
cpu family : 6
model : 15
model name : Intel(R) Xeon(R) CPU 5130 @ 2.00GHz
stepping : 6
cpu MHz : 1995.000
cache size : 4096 KB
physical id : 0
siblings : 2
core id : 1
cpu cores : 2
fpu : yes
fpu_exception : yes
cpuid level : 10
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmovm
bogomips : 3990.04
clflush size : 64
cache_alignment : 64
address sizes : 36 bits physical, 48 bits virtual
power management:
processor : 3
vendor_id : GenuineIntel
cpu family : 6
model : 15
model name : Intel(R) Xeon(R) CPU 5130 @ 2.00GHz
stepping : 6
cpu MHz : 1995.000
cache size : 4096 KB
physical id : 3
siblings : 2
core id : 1
cpu cores : 2
fpu : yes
fpu_exception : yes
cpuid level : 10
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmovm
bogomips : 3990.04
clflush size : 64
cache_alignment : 64
address sizes : 36 bits physical, 48 bits virtual
power management:
View attachment "lockdep.config" of type "text/plain" (71903 bytes)
Powered by blists - more mailing lists