[patch] Real-Time Preemption, -RT-2.6.9-mm1-V0.5

From: Ingo Molnar
Date: Thu Oct 28 2004 - 07:06:50 EST



* Michal Schmidt <xschmi00@xxxxxxxxxxxxxxxxxx> wrote:

> > i've uploaded -V0.4.1 with a fix that could fix this networking
> > deadlock. Does it work any better?
>
> Unfortunately, no. It's only slightly different:

ok. I've uploaded -RT-V0.5 which includes a different approach to
solving these netfilter related deadlocks. It can be downloaded from the
usual place:

http://redhat.com/~mingo/realtime-preempt/

there's a fair chance that you will still see a deadlock, so in -V0.5
i've improved the deadlock-detection infrastructure with a number of new
debugging features:

- track the code (by EIP) that acquired the semaphore

- track the place (by file:line) where the locking object got defined
or initialized. Print this symbolic info out when printing locking
objects - this is easier to read than the hexa address alone.

- added a global registry for all mutexes, rwsems, spinlocks and
rwlocks, which registry is printed during the deadlock-printout.
(including the current holder of the lock and the place where the
lock was acquired.)

- print out all the locks held by the task(s) involved in any deadlock
scenario.

- print out a summary of all tasks in the system, whether they are
blocked on a locking object, and if they are, on which lock.

- the 'all locks' and 'all tasks' printout can also be triggered via
sysrq-d or 'echo d > /proc/sysrq-trigger'.

- turn off deadlock tracing when the first deadlock has been detected.
This is to get a more robust printout of a stable locking state and
usually it's the first deadlock that matters so there's no point in
printing out more.

- cleaned up formatting of various existing printouts like the
preemption backtrace and messages from the deadlock detector.

all this info will greatly simplify the tracking down of deadlocks.
There is no additional configuration needed to active the above
features, other than to enable CONFIG_RWSEM_DEADLOCK_DETECT. Below i've
attached a sample printout.

Ingo


down()-ing unlocked semaphore. should succeed.
good. now down()ing locked semaphore. should deadlock.

===============================================
[ BUG: semaphore recursion deadlock detected! ]
-----------------------------------------------
already locked: [c065eee0] {r:0,a:-1,kernel/time.c:100}
.. held by: gettimeofday/ 3008 [f1b374c0]
... acquired at: sys_gettimeofday+0xfa/0x3f8

-{backtrace}--------------------------------->
[<c0241d47>] __rwsem_deadlock+0xf9/0x188 (12)
[<c011f1eb>] sys_gettimeofday+0xfa/0x3f8 (8)
[<c058f68e>] _down_write+0xe/0x325 (16)
[<c011f201>] sys_gettimeofday+0x110/0x3f8 (4)
[<c011f201>] sys_gettimeofday+0x110/0x3f8 (20)
[<c058f7e0>] _down_write+0x160/0x325 (8)
[<c0130903>] __mcount+0x1d/0x1f (16)
[<c0242561>] down+0x8/0x11 (4)
[<c011f201>] sys_gettimeofday+0x110/0x3f8 (4)
[<c011f201>] sys_gettimeofday+0x110/0x3f8 (36)
[<c014d641>] sys_munmap+0x42/0x4b (12)
[<c010601d>] sysenter_past_esp+0x52/0x71 (28)
---------------------------
| preempt count: 00000002 ]
| 2-level deep critical section nesting:
----------------------------------------
.. [<c058f8bd>] .... _down_write+0x23d/0x325
.....[<c011f201>] .. ( <= sys_gettimeofday+0x110/0x3f8)
.. [<c0131be1>] .... print_traces+0x1b/0x5a
.....[<c0106608>] .. ( <= dump_stack+0x23/0x25)


------------------------------
| showing all locks held by: | (gettimeofday/3008 [f1b374c0]):
------------------------------

#001: [c065eee0] {r:0,a:-1,kernel/time.c:100}
... acquired at: sys_gettimeofday+0xfa/0x3f8

showing all tasks:
s init/ 1 [c2a77080] (not blocked)
s ksoftirqd/0/ 2 [c2a76850] (not blocked)
s desched/0/ 3 [c2a76020] (not blocked)
s events/0/ 4 [c2a950c0] (not blocked)
s khelper/ 5 [c2a94890] (not blocked)
s kthread/ 10 [c2a94060] (not blocked)
s kacpid/ 18 [c2ab1100] (not blocked)
s IRQ 9/ 19 [c2ab08d0] (not blocked)
s kblockd/0/ 94 [c2ab00a0] (not blocked)
s khubd/ 107 [f7cf1140] (not blocked)
s pdflush/ 330 [f7cf0910] (not blocked)
s pdflush/ 331 [f7cf00e0] (not blocked)
s aio/0/ 333 [f7d56950] (not blocked)
s kswapd0/ 332 [f7d57180] (not blocked)
s IRQ 8/ 918 [f7d56120] (not blocked)
s IRQ 12/ 931 [f7eca990] (not blocked)
s kseriod/ 925 [f7ecb1c0] (not blocked)
s IRQ 6/ 946 [f7eca160] (not blocked)
s IRQ 5/ 978 [f7f01200] (not blocked)
s IRQ 14/ 997 [f7f009d0] (not blocked)
s IRQ 15/ 999 [f7f001a0] (not blocked)
s khpsbpkt/ 1013 [f7f51240] (not blocked)
s IRQ 11/ 1024 [f7f50a10] (not blocked)
s knodemgrd_0/ 1025 [f7f501e0] (not blocked)
s IRQ 1/ 1131 [f7f91280] (not blocked)
s IRQ 10/ 1169 [f7f90a50] (not blocked)
D kjournald/ 1180 [f7f90220] (not blocked)
s udevd/ 1242 [f5ec76c0] (not blocked)
s IRQ 4/ 1615 [f610c2e0] (not blocked)
s IRQ 3/ 1616 [f59f0a50] (not blocked)
D syslogd/ 2503 [f5d6ad90] (not blocked)
s klogd/ 2507 [f610d340] (not blocked)
s portmap/ 2526 [f5ae0120] (not blocked)
s mDNSResponder/ 2559 [f63aa420] (not blocked)
s mDNSResponder/ 2560 [f2bc6b90] (not blocked)
s acpid/ 2580 [f2af9340] (not blocked)
s sshd/ 2590 [f2af82e0] (not blocked)
s distccd/ 2619 [f610cb10] (not blocked)
s distccd/ 2620 [f59f0220] (not blocked)
s gpm/ 2630 [f2b6cb50] (not blocked)
s crond/ 2640 [f2af8b10] (not blocked)
s sshd/ 2653 [f5a59100] (not blocked)
s distccd/ 2656 [f5ae0950] (not blocked)
s sshd/ 2667 [f5a580a0] (not blocked)
s xfs/ 2670 [f5ec6660] (not blocked)
s bash/ 2672 [f2bc73c0] (not blocked)
s anacron/ 2704 [f5ec6e90] (not blocked)
s distccd/ 2706 [f2b6c320] (not blocked)
s atd/ 2714 [f59f1280] (not blocked)
s dbus-daemon-1/ 2724 [f2bc6360] (not blocked)
s cups-config-dae/ 2734 [f63aac50] (not blocked)
s agetty/ 2748 [f5a588d0] (not blocked)
s mingetty/ 2749 [f5d6b5c0] (not blocked)
s mingetty/ 2750 [f63ab480] (not blocked)
s mingetty/ 2751 [f1a73400] (not blocked)
s mingetty/ 2752 [f1a72bd0] (not blocked)
s mingetty/ 2753 [f2b6d380] (not blocked)
s mingetty/ 2754 [f1a723a0] (not blocked)
s hotplug/ 2839 [f1b36460] (not blocked)
s hotplug/ 2856 [f14e6d90] (not blocked)
s hotplug/ 2857 [f155d600] (not blocked)
s 10-udev.hotplug/ 2916 [f1b36c90] (not blocked)
s 10-udev.hotplug/ 2917 [f14e75c0] (not blocked)
s 10-udev.hotplug/ 2918 [f14e6560] (not blocked)
s udev/ 2959 [f1629680] (not blocked)
s udev/ 2965 [f1702ed0] (not blocked)
s udev/ 2981 [f17d5780] (not blocked)
s udev/ 2987 [f11240a0] (not blocked)
D gettimeofday/ 3008 [f1b374c0] (not blocked)

---------------------------
| showing all locks held: |
---------------------------

#001: [c07f809c] {r:0,a:-1,drivers/ide/ide.c:228}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x8b/0x15c

#002: [c07f7bb4] {r:0,a:-1,drivers/ide/ide.c:252}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x14b/0x15c

#003: [c07f7e0c] {r:0,a:-1,drivers/ide/ide.c:252}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x14b/0x15c

#004: [c07f8890] {r:0,a:-1,drivers/ide/ide.c:228}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x8b/0x15c

#005: [c07f83a8] {r:0,a:-1,drivers/ide/ide.c:252}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x14b/0x15c

#006: [c07f8600] {r:0,a:-1,drivers/ide/ide.c:252}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x14b/0x15c

#007: [c07f9084] {r:0,a:-1,drivers/ide/ide.c:228}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x8b/0x15c

#008: [c07f8b9c] {r:0,a:-1,drivers/ide/ide.c:252}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x14b/0x15c

#009: [c07f8df4] {r:0,a:-1,drivers/ide/ide.c:252}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x14b/0x15c

#010: [c07f9878] {r:0,a:-1,drivers/ide/ide.c:228}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x8b/0x15c

#011: [c07f9390] {r:0,a:-1,drivers/ide/ide.c:252}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x14b/0x15c

#012: [c07f95e8] {r:0,a:-1,drivers/ide/ide.c:252}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x14b/0x15c

#013: [c07fa06c] {r:0,a:-1,drivers/ide/ide.c:228}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x8b/0x15c

#014: [c07f9b84] {r:0,a:-1,drivers/ide/ide.c:252}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x14b/0x15c

#015: [c07f9ddc] {r:0,a:-1,drivers/ide/ide.c:252}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x14b/0x15c

#016: [c07fa860] {r:0,a:-1,drivers/ide/ide.c:228}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x8b/0x15c

#017: [c07fa378] {r:0,a:-1,drivers/ide/ide.c:252}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x14b/0x15c

#018: [c07fa5d0] {r:0,a:-1,drivers/ide/ide.c:252}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x14b/0x15c

#019: [c07fb054] {r:0,a:-1,drivers/ide/ide.c:228}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x8b/0x15c

#020: [c07fab6c] {r:0,a:-1,drivers/ide/ide.c:252}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x14b/0x15c

#021: [c07fadc4] {r:0,a:-1,drivers/ide/ide.c:252}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x14b/0x15c

#022: [c07fb848] {r:0,a:-1,drivers/ide/ide.c:228}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x8b/0x15c

#023: [c07fb360] {r:0,a:-1,drivers/ide/ide.c:252}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x14b/0x15c

#024: [c07fb5b8] {r:0,a:-1,drivers/ide/ide.c:252}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x14b/0x15c

#025: [c07fc03c] {r:0,a:-1,drivers/ide/ide.c:228}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x8b/0x15c

#026: [c07fbb54] {r:0,a:-1,drivers/ide/ide.c:252}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x14b/0x15c

#027: [c07fbdac] {r:0,a:-1,drivers/ide/ide.c:252}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x14b/0x15c

#028: [c07fc830] {r:0,a:-1,drivers/ide/ide.c:228}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x8b/0x15c

#029: [c07fc348] {r:0,a:-1,drivers/ide/ide.c:252}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x14b/0x15c

#030: [c07fc5a0] {r:0,a:-1,drivers/ide/ide.c:252}
.. held by: init/ 1 [c2a77080]
... acquired at: init_hwif_data+0x14b/0x15c

#031: [c06a8f40] {r:0,a:-1,drivers/ieee1394/nodemgr.c:111}
.. held by: knodemgrd_0/ 1025 [f7f501e0]
... acquired at: nodemgr_host_thread+0x89/0x186

#032: [f2b7cfcc] {r:0,a:-1,drivers/char/tty_io.c:2641}
.. held by: mingetty/ 2749 [f5d6b5c0]
... acquired at: read_chan+0x471/0x7a2

#033: [f1ba4fcc] {r:0,a:-1,drivers/char/tty_io.c:2641}
.. held by: mingetty/ 2751 [f1a73400]
... acquired at: read_chan+0x471/0x7a2

#034: [f157efcc] {r:0,a:-1,drivers/char/tty_io.c:2641}
.. held by: mingetty/ 2754 [f1a723a0]
... acquired at: read_chan+0x471/0x7a2

#035: [f1722fcc] {r:0,a:-1,drivers/char/tty_io.c:2641}
.. held by: mingetty/ 2752 [f1a72bd0]
... acquired at: read_chan+0x471/0x7a2

#036: [f10dafcc] {r:0,a:-1,drivers/char/tty_io.c:2641}
.. held by: mingetty/ 2753 [f2b6d380]
... acquired at: read_chan+0x471/0x7a2

#037: [f150efcc] {r:0,a:-1,drivers/char/tty_io.c:2641}
.. held by: mingetty/ 2750 [f63ab480]
... acquired at: read_chan+0x471/0x7a2

#038: [f1a92fcc] {r:0,a:-1,drivers/char/tty_io.c:2641}
.. held by: agetty/ 2748 [f5a588d0]
... acquired at: read_chan+0x471/0x7a2

#039: [f2a11ba4] {r:0,a:-1,fs/inode.c:198}
.. held by: syslogd/ 2503 [f5d6ad90]
... acquired at: sys_fsync+0x56/0xb7

#040: [c065eee0] {r:0,a:-1,kernel/time.c:100}
.. held by: gettimeofday/ 3008 [f1b374c0]
... acquired at: sys_gettimeofday+0xfa/0x3f8

#041: [c0748a00] {r:0,a:-1,kernel/fork.c:64}
.. held by: gettimeofday/ 3008 [f1b374c0]
... acquired at: show_all_locks+0x30/0x148
=============================================

-
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/