Re: Deadlock with option FULL_PREEMPTION

From: Peter Holm <peter_at_holm.cc>
Date: Tue, 8 Feb 2005 20:08:36 +0100
On Tue, Feb 08, 2005 at 01:17:40PM -0500, John Baldwin wrote:
> On Sunday 06 February 2005 08:41 am, Peter Holm wrote:
> > With GENERIC HEAD from Feb 5 09:19 UTC + FULL_PREEMPTION +
> > mpsafe_vfs = 1 I ran into what appears to be the same deadlock
> > twice. This is the first one:
> > http://www.holm.cc/stress/log/cons114.html
> 
> What is the deadlock exactly?

top froze, console login froze after giving login name, but I
could ping the box.

> It looks like lots of threads banging on fork() 
> and that they are all waiting on an exclusive lock of allproc_lock while 
> holding a shared lock of proctree_lock (except for the 1 thread currently 
> doing a fork that is on a run queue because it was preempted by IRQ 0 which 
> kicked off softclock).  Can you get 'ps' output?
> 

Yes:

$ ps -alx -o flags -N kernel.debug -M /var/crash/vmcore.167
  UID   PID  PPID CPU PRI NI   VSZ  RSS MWCHAN STAT  TT       TIME COMMAND                F
    0     0     0   0 -16  0     0    0 allpro DLs   ??    0:00,11 [swapper]            200
    0     1     0 287   8  0   720    0 wait   DLs   ??    0:00,38 [init]              4200
    0     2     0 140  -8  0     0    0 -      DL    ??    0:02,95 [g_event]            204
    0     3     0 273  -8  0     0    0 -      DL    ??    4:00,96 [g_up]               204
    0     4     0  91  -8  0     0    0 -      DL    ??    1:02,45 [g_down]             204
    0     5     0   0   8  0     0    0 -      DL    ??    0:00,00 [kqueue taskq]       204
    0     6     0   0   8  0     0    0 -      RL    ??    0:00,00 [thread taskq]       204
    0     7     0   0 -84  0     0    0 actask DL    ??    0:00,00 [acpi_task0]         204
    0     8     0   0 -84  0     0    0 actask DL    ??    0:00,00 [acpi_task1]         204
    0     9     0   0 -84  0     0    0 actask DL    ??    0:00,00 [acpi_task2]         204
    0    10     0   0 -16  0     0    0 ktrace DL    ??    0:00,00 [ktrace]             204
    0    11     0 219 171  0     0    0 -      RL    ??   10:22,62 [idle: cpu0]         20c
    0    12     0   2 -60  0     0    0 -      WL    ??    0:00,04 [irq1: atkbd0]       204
    0    13     0   0 -21  0     0    0 -      WL    ??    0:00,00 [irq3:]              204
    0    14     0   0 -60  0     0    0 -      WL    ??    0:00,00 [irq4: sio0]         204
    0    15     0   0 -21  0     0    0 -      WL    ??    0:00,00 [irq5:]              204
    0    16     0   0 -64  0     0    0 -      WL    ??    0:00,00 [irq6: fdc0]         204
    0    17     0   0 -60  0     0    0 -      WL    ??    0:00,00 [irq7: ppc0]         204
    0    18     0   0 -84  0     0    0 -      WL    ??    0:00,00 [irq8: rtc]          204
    0    19     0   0 -52  0     0    0 -      WL    ??    0:00,00 [irq9: acpi0]        204
    0    20     0   0 -21  0     0    0 -      WL    ??    0:00,00 [irq10:]             204
    0    21     0   0 -21  0     0    0 -      WL    ??    0:00,00 [irq11:]             204
    0    22     0   0 -60  0     0    0 -      WL    ??    0:00,00 [irq12: psm0]        204
    0    23     0   0 -21  0     0    0 -      WL    ??    0:00,00 [irq13:]             204
    0    24     0   0 -64  0     0    0 -      WL    ??    0:25,54 [irq14: ata0]        204
    0    25     0   0 -64  0     0    0 -      WL    ??    0:00,00 [irq15: ata1]        204
    0    26     0   0 -64  0     0    0 -      WL    ??    0:00,00 [irq16: uhci0 uh     204
    0    27     0   0 -80  0     0    0 -      WL    ??    0:00,00 [irq17: pcm0]        204
    0    28     0   0 -64  0     0    0 -      WL    ??    0:00,00 [irq18: uhci2]       204
    0    29     0   0 -64  0     0    0 -      WL    ??    0:00,00 [irq19: uhci1]       204
    0    30     0   0 -21  0     0    0 -      WL    ??    0:00,00 [irq20:]             204
    0    31     0   0 -21  0     0    0 -      WL    ??    0:00,00 [irq21:]             204
    0    32     0  24 -68  0     0    0 -      WL    ??    0:56,13 [irq22: rl0]         204
    0    33     0   0 -21  0     0    0 -      WL    ??    0:00,00 [irq23:]             204
    0    34     0   0 -84  0     0    0 -      WL    ??    0:00,00 [irq0: clk]          204
    0    35     0 227 -44  0     0    0 -      WL    ??    2:15,59 [swi1: net]          204
    0    36     0 295 -32  0     0    0 -      WL    ??    1:20,97 [swi4: clock sio     20c
    0    37     0   0 -36  0     0    0 -      WL    ??    0:00,00 [swi3: vm]           204
    0    38     0  42 -16  0     0    0 -      DL    ??    0:03,48 [yarrow]             204
    0    39     0   0 -24  0     0    0 -      WL    ??    0:00,00 [swi6: task queu     204
    0    40     0   0 -24  0     0    0 -      WL    ??    0:00,00 [swi6:+]             204
    0    41     0   0 -24  0     0    0 -      WL    ??    0:00,00 [swi6: acpitaskq     204
    0    42     0   0 -28  0     0    0 -      WL    ??    0:00,00 [swi5:+]             204
    0    43     0   0 -40  0     0    0 -      WL    ??    0:00,00 [swi2: cambio]       204
    0    44     0   0   8  0     0    0 usbevt DL    ??    0:00,00 [usb0]               204
    0    45     0   0   8  0     0    0 usbtsk DL    ??    0:00,00 [usbtask]            204
    0    46     0   0   8  0     0    0 usbevt DL    ??    0:00,00 [usb1]               204
    0    47     0   0   8  0     0    0 usbevt DL    ??    0:00,00 [usb2]               204
    0    48     0   1   8  0     0    0 usbevt DL    ??    0:00,00 [usb3]               204
    0    49     0   0 -48  0     0    0 -      WL    ??    0:00,00 [swi0: sio]          204
    0    50     0   6  -8  0     0    0 -      DL    ??    0:00,14 [fdc0]               204
    0    51     0 239 -16  0     0    0 psleep DL    ??    3:59,81 [pagedaemon]         204
    0    52     0  36  20  0     0    0 psleep DL    ??    0:12,59 [vmdaemon]           204
    0    53     0  20 171  0     0    0 -      RL    ??    0:13,25 [pagezero]           20c
    0    54     0 139 -16  0     0    0 psleep DL    ??   20:59,10 [bufdaemon]          204
    0    55     0  13  -4  0     0    0 vlruwt DL    ??    0:00,28 [vnlru]              204
    0    56     0 283  -4  0     0    0 ufs    DL    ??    5:52,85 [syncer]             204
    0    57     0  27   8  0     0    0 -      DL    ??    0:00,00 [nfsiod 0]           204
    0    58     0  27   8  0     0    0 -      DL    ??    0:00,00 [nfsiod 1]           204
    0    59     0  28   8  0     0    0 -      DL    ??    0:00,00 [nfsiod 2]           204
    0    60     0  28   8  0     0    0 -      DL    ??    0:00,00 [nfsiod 3]           204
    0    61     0   0 -32  0     0    0 allpro DL    ??    0:01,64 [schedcpu]           204
    0   249     1 120 111  0   488    0 select Ds    ??    0:00,00 [devd]                 0
    0   274     1   6  96  0  1328  120 select Ds    ??    0:00,54 [syslogd]              0
    0   288     1   4  96  0  1472    0 select Ds    ??    0:00,18 [rpcbind]              0
    0   357     1 120 111  0  1352    0 select Ds    ??    0:00,02 [mountd]               0
    0   359     1  77 105  0  1296    0 select Ds    ??    0:00,09 [nfsd]                 0
    0   360   359 120   4  0  1236    0 -      D     ??    0:00,00 [nfsd]                 0
    0   361   359 120   4  0  1236    0 -      D     ??    0:00,00 [nfsd]                 0
    0   362   359 120   4  0  1236    0 -      D     ??    0:00,00 [nfsd]                 0
    0   363   359 120   4  0  1236    0 -      D     ??    0:00,00 [nfsd]                 0
    0   384     1   4  96  0  1244    0 select Ds    ??    0:00,14 [usbd]                 0
    0   410     1 110 109  0  2828    0 select Ds    ??    0:01,66 [ntpd]                 0
    0   426     1   0  96  0  3348    0 select Ds    ??    0:00,02 [sshd]               100
    0   432     1   0  96  0  3440  208 sysctl Ds    ??    0:00,96 [sendmail]           100
   25   436     1   0  96  0  3320    0 sysctl Ds    ??    0:00,05 [sendmail]           100
    0   448     1   1  96  0  1356    0 allpro Ds    ??    0:00,26 [cron]                 0
    0   499     1 112 110  0  1244    0 select Ds    ??    0:00,00 [moused]               0
    0   542   426  66   4  0  6092    0 sbwait Ds    ??    0:00,22 [sshd]              4100
 1001   544   542   0  96  0  6088  344 select D     ??    0:01,81 [sshd]               100
    0   552   426  13   4  0  6092    0 sbwait Ds    ??    0:00,22 [sshd]              4100
 1001   554   552   0  96  0  6248    0 select D     ??    0:02,62 [sshd]               100
 1001   545   544  38   8  0  2520    0 wait   Ds    p0    0:00,10 [bash]              4002
 1001   551   545  70 104  0  2452  624 allpro D+    p0    0:51,24 [top]               4002
 1001   555   554 162   8  0  2520    0 wait   Ds    p1    0:00,21 [bash]              4002
 1001  2120   555 247   8  0  1664    0 wait   D+    p1    0:00,03 [sh]                4002
 1001  2125  2120  22   8  0  1228    0 nanslp D+    p1    0:00,44 [run]               4002
 1001  2126  2125 247   8  0  1228    0 wait   D+    p1    0:00,00 [run]                  2
 1001  2127  2126 285   8  0  1232    0 wait   D+    p1    0:01,12 [run]                  2
 1001 10334  2127 281 131  0  1224    0 allpro D+    p1    0:00,02 [swap]              4002
 1001 10335  2127 280 131  0  1224    0 allpro D+    p1    0:00,02 [creat]             4002
 1001 10336  2127 280 131  0  1228    0 allpro D+    p1    0:00,02 [mkdir]             4002
 1001 10337  2127   0 -84  0     0    0 -      ZW    p1    0:00,00 <defunct>              0
 1001 10338  2127   0 -84  0     0    0 -      ZW    p1    0:00,00 <defunct>              0
 1001 10339  2127   0 -84  0     0    0 -      ZW    p1    0:00,00 <defunct>              0
 1001 10340  2127 280 131  0  1228    0 allpro D+    p1    0:00,02 [sysctl]            4002
 1001 10341  2127 280 131  0  1232    0 allpro D+    p1    0:00,02 [tcp]               4002
 1001 10342  2127 281 131  0  1228    0 allpro D+    p1    0:00,02 [udp]               4002
 1001 10343 10335 285   8  0  1224    0 wait   D+    p1    0:00,01 [creat]                2
 1001 10344 10340 285   8  0  1228    0 wait   D+    p1    0:00,00 [sysctl]               2
 1001 10345 10334 285   8  0  1224    0 wait   D+    p1    0:00,01 [swap]                 2
 1001 10346 10344 285 131  0  1228    0 allpro D+    p1    0:00,00 [sysctl]               2
 1001 10347 10345 285 131  0  1224    0 sysctl D+    p1    0:00,00 [swap]                 2
 1001 10348 10345 295 131  0 30684    0 -      R+    p1   88:53,23 [swap]                 2
 1001 10349 10345 285 131  0  1224    0 sysctl D+    p1    0:00,00 [swap]                 2
 1001 10350 10343 285  -4  0  1224    0 ufs    D+    p1    0:00,00 [creat]                2
 1001 10351 10343 290 132  0  1224    0 -      R+    p1    0:00,11 [creat]                2
 1001 10352 10343 285  -4  0  1224    0 ufs    D+    p1    0:00,00 [creat]                2
 1001 10353 10343 285  -4  0  1224    0 ufs    D+    p1    0:00,00 [creat]                2
 1001 10354 10343 289 132  0  1224    0 -      R+    p1    0:00,07 [creat]                2
 1001 10355 10343 285  -4  0  1224    0 ufs    D+    p1    0:00,00 [creat]                2
 1001 10356 10345 285 131  0  1224    0 sysctl D+    p1    0:00,00 [swap]                 2
 1001 10357 10345 285 131  0  1224    0 sysctl D+    p1    0:00,00 [swap]                 2
 1001 10358 10345 285 131  0  1224    0 sysctl D+    p1    0:00,00 [swap]                 2
 1001 10359 10345 285  -8  0  1232    0 piperd D+    p1    0:00,00 [swap]                 2
 1001 10360 10336 285   8  0  1228    0 wait   D+    p1    0:00,00 [mkdir]                2
 1001 10361 10341 285   8  0  1232    0 wait   D+    p1    0:00,02 [tcp]                  2
 1001 10362 10360 285 131  0  1228    0 sysctl D+    p1    0:00,00 [mkdir]                2
 1001 10363 10360 285  -4  0  1228    0 getblk D+    p1    0:00,00 [mkdir]                2
 1001 10364 10361 285   4  0  1236    0 sbwait D+    p1    0:00,04 [tcp]                  2
 1001 10365 10361 285 131  0  1232    0 allpro D+    p1    0:00,00 [tcp]                  2
 1001 10366 10361 285 131  0  1232    0 allpro D+    p1    0:00,00 [tcp]                  2
 1001 10367 10361 285 131  0  1232    0 allpro D+    p1    0:00,00 [tcp]                  2
 1001 10368 10361 285 131  0  1232    0 allpro D+    p1    0:00,00 [tcp]                  2
 1001 10369 10361 285 131  0  1232    0 allpro D+    p1    0:00,00 [tcp]                  2
 1001 10370 10361 285 131  0  1232    0 allpro D+    p1    0:00,00 [tcp]                  2
 1001 10371 10361 281   4  0  1232    0 sbwait D+    p1    0:00,03 [tcp]                  2
 1001 10372 10361 285 131  0  1232    0 allpro D+    p1    0:00,00 [tcp]                  2
 1001 10373 10361 284   4  0  1236    0 sbwait D+    p1    0:00,05 [tcp]                  2
 1001 10374 10342 285   8  0  1228    0 wait   D+    p1    0:00,01 [udp]                  2
 1001 10375 10374 290 132  0  1252    0 -      R+    p1    0:00,67 [udp]                  2
 1001 10376 10374 288 132  0  1252    0 -      R+    p1    0:00,03 [udp]                  2
 1001 10377 10374 288 132  0  1252    0 -      R+    p1    0:00,03 [udp]                  2
 1001 10378 10371 288 132  0  1320    0 -      R+    p1    0:00,05 [tcp]                  2
 1001 10382 10364 288 132  0  1320    0 -      R+    p1    0:00,07 [tcp]                  2
 1001 10383 10373 291 132  0  1320    0 -      R+    p1    0:00,08 [tcp]                  2
 1001 10385 10359 288 132  0  1664    0 -      R+    p1    0:00,02 [sh]                4002
 1001 10386 10385 288 132  0  1220    0 -      R+    p1    0:00,01 [swapinfo]          4002
 1001 10387 10385 288 132  0   288    0 -      R+    p1    0:00,00 [tail]              4002
    0   534     1   1  96  0   288    0 sysctl Ds+   v0    0:00,03 [login]             4002
    0   535     1 112   5  0  1300    0 ttyin  Ds+   v1    0:00,02 [getty]             4002
    0   536     1 112   5  0  1300    0 ttyin  Ds+   v2    0:00,02 [getty]             4002
    0   537     1 112   5  0  1300    0 ttyin  Ds+   v3    0:00,02 [getty]             4002
    0   538     1 112   5  0  1300    0 ttyin  Ds+   v4    0:00,02 [getty]             4002
    0   539     1 112   5  0  1300    0 ttyin  Ds+   v5    0:00,02 [getty]             4002
    0   540     1 112   5  0  1300    0 ttyin  Ds+   v6    0:00,02 [getty]             4002
    0   541     1 112   5  0  1300    0 ttyin  Ds+   v7    0:00,02 [getty]             4002

I have uploaded the other freeze, that has a "show witness", to
http://www.holm.cc/stress/log/cons114a.html.

Hope this helps.

- Peter

> -- 
> John Baldwin <jhb_at_FreeBSD.org>  <><  http://www.FreeBSD.org/~jhb/
> "Power Users Use the Power to Serve"  =  http://www.FreeBSD.org

-- 
Peter Holm
Received on Tue Feb 08 2005 - 18:08:40 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:38:27 UTC