7.0-RC1 - ZFS + UFS + io activity show a deadlock

From: Henri Hennebert <hlh_at_restart.be>
Date: Sun, 27 Jan 2008 14:47:02 +0100
Hello,

I encounter a deadlock while

1) cpio -p from a ZFS filesystem to a UFS filesystem

2) rsync from ZFS to ZFS

I was running with this patch:
http://people.freebsd.org/~pjd/patches/zgd_done.patch

Here are show alllocks + showpcpu + bt from serial console:

Henri

KDB: enter: Line break on console
[thread pid 259 tid 100064 ]
Stopped at      kdb_enter+0x32: leave
db> show alllocks
Process 7816 (java_vm) thread 0xa8b6bcc0 (100477)
exclusive sx so_rcv_sx r = 0 (0xa9e40e78) locked @ /usr/src/sys/kern/uipc_sockbuf.c:145
Process 7816 (java_vm) thread 0xa61ebcc0 (100380)
exclusive sx so_rcv_sx r = 0 (0xb1227e78) locked @ /usr/src/sys/kern/uipc_sockbuf.c:145
Process 81189 (java_vm) thread 0xa6652aa0 (100458)
exclusive sx so_rcv_sx r = 0 (0xa80993a4) locked @ /usr/src/sys/kern/uipc_sockbuf.c:145
Process 81189 (java_vm) thread 0xa5c55660 (100371)
exclusive sx so_rcv_sx r = 0 (0xa6138cec) locked @ /usr/src/sys/kern/uipc_sockbuf.c:145
Process 1406 (gnome-pty-helper) thread 0xa8259880 (100301)
exclusive sx so_rcv_sx r = 0 (0xa9e3f218) locked @ /usr/src/sys/kern/uipc_sockbuf.c:145
Process 48 (arc_reclaim_thread) thread 0xa56ab440 (100043)
exclusive sleep mutex vm object (kmem object) r = 0 (0xa08b1ec0) locked @ /usr/src/sys/vm/vm_map.c:2293
exclusive sleep mutex system map r = 0 (0xa186b0e8) locked @ /usr/src/sys/vm/vm_map.c:2412
exclusive sleep mutex UMA lock r = 0 (0xa08b1b2c) locked @ /usr/src/sys/vm/uma_core.c:1492
db> show allpcpu
Current CPU: 1

cpuid        = 0
curthread    = 0xa56ab440: pid 48 "arc_reclaim_thread"
curpcb       = 0xf7510d90
fpcurthread  = none
idlethread   = 0xa5529aa0: pid 12 "idle: cpu0"
APIC ID      = 0
currentldt   = 0x50
spin locks held:

cpuid        = 1
curthread    = 0xa5b36aa0: pid 259 "spa_zio_intr_1"
curpcb       = 0xf99bad90
fpcurthread  = none
idlethread   = 0xa5529880: pid 11 "idle: cpu1"
APIC ID      = 1
currentldt   = 0x50
spin locks held:

db> bt 48
Tracing pid 48 tid 100043 td 0xa56ab440
cpustop_handler(1,f7510bb4,a07876dd,0,0,...) at cpustop_handler+0x32
ipi_nmi_handler(0,0,a05a23d8,b04d509c,a56d5804,...) at ipi_nmi_handler+0x2f
trap(f7510bc0) at trap+0x2d
calltrap() at calltrap+0x6
--- trap 0x13, eip = 0xa058d066, esp = 0xf7510c00, ebp = 0xf7510c1c ---
_mtx_unlock_flags(a185d688,0,a07e8e0b,2e0,0,f7510c60,a058d3d3,a08b1b2c,8,a07e8e0b,5d4,f7510c94) at _mtx_unlock_flags+0x56
zone_drain(a18575a0,0,a07e8e0b,5d4,342a0554,...) at zone_drain+0x26e
zone_foreach(4000000,342a0554,f7510cf8,a099a89f,f7510ce4,...) at zone_foreach+0x45
uma_reclaim(f7510ce4,a0a0ce14,1f4,0,0,...) at uma_reclaim+0x16
arc_reclaim_thread(0,f7510d38,a07cdfc5,2ea,a56d5804,...) at arc_reclaim_thread+0x3ef
fork_exit(a099a4b0,0,f7510d38) at fork_exit+0x94
fork_trampoline() at fork_trampoline+0x8
--- trap 0, eip = 0, esp = 0xf7510d70, ebp = 0 ---
db> bt 259
Tracing pid 259 tid 100064 td 0xa5b36aa0
kdb_enter(a07c0400,a08b4928,8,7ec647,a56fb48c,...) at kdb_enter+0x32
siointr1(a08b4928,0,a07ec647,56f,f99babd8,...) at siointr1+0xdf
siointr(a56fb400,f99babe8,0,a5b36aa0,a5525280,...) at siointr+0x32
intr_execute_handlers(a5519cd0,f99babf8,f99bac3c,a076fa14,3a,...) at intr_execute_handlers+0xec
lapic_handle_intr(3a,f99babf8) at lapic_handle_intr+0x3f
Xapic_isr1() at Xapic_isr1+0x34
--- interrupt, eip = 0xa077a99b, esp = 0xf99bac38, ebp = 0xf99bac3c ---
spinlock_exit(a085a414,8,a07d329d,108) at spinlock_exit+0x2b
_mtx_unlock_spin_flags(a085a414,0,a07d329d,108,f99bac8c,...) at _mtx_unlock_spin_flags+0x4d
sleepq_release(a558a454,2,27af18f4,a558a3fc) at sleepq_release+0x37
cv_broadcastpri(a558a454,ffffffff,a0a02fb3,347,92388953,...) at cv_broadcastpri+0x48
taskq_thread(a558a3fc,f99bad38,a07cdfc5,2ea,a5b34ab0,...) at taskq_thread+0x31c
fork_exit(a098ddd0,a558a3fc,f99bad38) at fork_exit+0x94
fork_trampoline() at fork_trampoline+0x8
--- trap 0, eip = 0, esp = 0xf99bad70, ebp = 0 ---
db> c
KDB: enter: Line break on console
[thread pid 259 tid 100064 ]
Stopped at      kdb_enter+0x32: leave
db> show alllocks
Process 7816 (java_vm) thread 0xa8b6bcc0 (100477)
exclusive sx so_rcv_sx r = 0 (0xa9e40e78) locked @ /usr/src/sys/kern/uipc_sockbuf.c:145
Process 7816 (java_vm) thread 0xa61ebcc0 (100380)
exclusive sx so_rcv_sx r = 0 (0xb1227e78) locked @ /usr/src/sys/kern/uipc_sockbuf.c:145
Process 81189 (java_vm) thread 0xa6652aa0 (100458)
exclusive sx so_rcv_sx r = 0 (0xa80993a4) locked @ /usr/src/sys/kern/uipc_sockbuf.c:145
Process 81189 (java_vm) thread 0xa5c55660 (100371)
exclusive sx so_rcv_sx r = 0 (0xa6138cec) locked @ /usr/src/sys/kern/uipc_sockbuf.c:145
Process 1406 (gnome-pty-helper) thread 0xa8259880 (100301)
exclusive sx so_rcv_sx r = 0 (0xa9e3f218) locked @ /usr/src/sys/kern/uipc_sockbuf.c:145
Process 48 (arc_reclaim_thread) thread 0xa56ab440 (100043)
exclusive sleep mutex vm object (kmem object) r = 0 (0xa08b1ec0) locked @ /usr/src/sys/vm/vm_map.c:2293
exclusive sleep mutex system map r = 0 (0xa186b0e8) locked @ /usr/src/sys/vm/vm_map.c:2412
exclusive sleep mutex UMA lock r = 0 (0xa08b1b2c) locked @ /usr/src/sys/vm/uma_core.c:1492
db> show allpcpu
Current CPU: 1

cpuid        = 0
curthread    = 0xa56ab440: pid 48 "arc_reclaim_thread"
curpcb       = 0xf7510d90
fpcurthread  = none
idlethread   = 0xa5529aa0: pid 12 "idle: cpu0"
APIC ID      = 0
currentldt   = 0x50
spin locks held:

cpuid        = 1
curthread    = 0xa5b36aa0: pid 259 "spa_zio_intr_1"
curpcb       = 0xf99bad90
fpcurthread  = none
idlethread   = 0xa5529880: pid 11 "idle: cpu1"
APIC ID      = 1
currentldt   = 0x50
spin locks held:

db> bt 48
Tracing pid 48 tid 100043 td 0xa56ab440
cpustop_handler(1,f7510bb4,a07876dd,680085a4,0,...) at cpustop_handler+0x32
ipi_nmi_handler(680085a4,0,a0811ae0,a0811aa0,a56d5804,...) at ipi_nmi_handler+0x2f
trap(f7510bc0) at trap+0x2d
calltrap() at calltrap+0x6
--- trap 0x13, eip = 0xa058d066, esp = 0xf7510c00, ebp = 0xf7510c1c ---
_mtx_unlock_flags(a186e908,0,a07e8e0b,2e0,0,f7510c60,a058d3d3,a08b1b2c,8,a07e8e0b,5d4,f7510c94) at _mtx_unlock_flags+0x56
zone_drain(a18671e0,0,a07e8e0b,5d4,2087f152,...) at zone_drain+0x26e
zone_foreach(4000000,2087f152,f7510cf8,a099a89f,f7510ce4,...) at zone_foreach+0x45
uma_reclaim(f7510ce4,a0a0ce14,1f4,0,0,...) at uma_reclaim+0x16
arc_reclaim_thread(0,f7510d38,a07cdfc5,2ea,a56d5804,...) at arc_reclaim_thread+0x3ef
fork_exit(a099a4b0,0,f7510d38) at fork_exit+0x94
fork_trampoline() at fork_trampoline+0x8
--- trap 0, eip = 0, esp = 0xf7510d70, ebp = 0 ---
db> bt 259
Tracing pid 259 tid 100064 td 0xa5b36aa0
kdb_enter(a07c0400,a08b4928,8,7ec647,a56fb48c,...) at kdb_enter+0x32
siointr1(a08b4928,0,a07ec647,56f,f99babd8,...) at siointr1+0xdf
siointr(a56fb400,0,0,a5b36aa0,a5525280,...) at siointr+0x32
intr_execute_handlers(a5519cd0,f99babf8,f99bac3c,a076fa14,3a,...) at intr_execute_handlers+0xec
lapic_handle_intr(3a,f99babf8) at lapic_handle_intr+0x3f
Xapic_isr1() at Xapic_isr1+0x34
--- interrupt, eip = 0xa077a99b, esp = 0xf99bac38, ebp = 0xf99bac3c ---
spinlock_exit(a085a414,8,a07d329d,108) at spinlock_exit+0x2b
_mtx_unlock_spin_flags(a085a414,0,a07d329d,108,f99bac8c,...) at _mtx_unlock_spin_flags+0x4d
sleepq_release(a558a454,0,27af18f4,a558a3fc) at sleepq_release+0x37
cv_broadcastpri(a558a454,ffffffff,a0a02fb3,347,92388953,...) at cv_broadcastpri+0x48
taskq_thread(a558a3fc,f99bad38,a07cdfc5,2ea,a5b34ab0,...) at taskq_thread+0x31c
fork_exit(a098ddd0,a558a3fc,f99bad38) at fork_exit+0x94
fork_trampoline() at fork_trampoline+0x8
--- trap 0, eip = 0, esp = 0xf99bad70, ebp = 0 ---
db> c
KDB: enter: Line break on console
[thread pid 259 tid 100064 ]
Stopped at      kdb_enter+0x32: leave
db> show alllocks
Process 7816 (java_vm) thread 0xa8b6bcc0 (100477)
exclusive sx so_rcv_sx r = 0 (0xa9e40e78) locked @ /usr/src/sys/kern/uipc_sockbuf.c:145
Process 7816 (java_vm) thread 0xa61ebcc0 (100380)
exclusive sx so_rcv_sx r = 0 (0xb1227e78) locked _at_ /usr/src/sys/kern/uipc_sockbuf.c:145
Process 81189 (java_vm) thread 0xa6652aa0 (100458)
exclusive sx so_rcv_sx r = 0 (0xa80993a4) locked @ /usr/src/sys/kern/uipc_sockbuf.c:145
Process 81189 (java_vm) thread 0xa5c55660 (100371)
exclusive sx so_rcv_sx r = 0 (0xa6138cec) locked @ /usr/src/sys/kern/uipc_sockbuf.c:145
Process 1406 (gnome-pty-helper) thread 0xa8259880 (100301)
exclusive sx so_rcv_sx r = 0 (0xa9e3f218) locked @ /usr/src/sys/kern/uipc_sockbuf.c:145
Process 48 (arc_reclaim_thread) thread 0xa56ab440 (100043)
exclusive sleep mutex vm object (kmem object) r = 0 (0xa08b1ec0) locked @ /usr/src/sys/vm/vm_map.c:2293
exclusive sleep mutex system map r = 0 (0xa186b0e8) locked @ /usr/src/sys/vm/vm_map.c:2412
exclusive sleep mutex UMA lock r = 0 (0xa08b1b2c) locked @ /usr/src/sys/vm/uma_core.c:1492
db> show allpcpu
Current CPU: 1

cpuid        = 0
curthread    = 0xa56ab440: pid 48 "arc_reclaim_thread"
curpcb       = 0xf7510d90
fpcurthread  = none
idlethread   = 0xa5529aa0: pid 12 "idle: cpu0"
APIC ID      = 0
currentldt   = 0x50
spin locks held:

cpuid        = 1
curthread    = 0xa5b36aa0: pid 259 "spa_zio_intr_1"
curpcb       = 0xf99bad90
fpcurthread  = none
idlethread   = 0xa5529880: pid 11 "idle: cpu1"
APIC ID      = 1
currentldt   = 0x50
spin locks held:

db> bt 48
Tracing pid 48 tid 100043 td 0xa56ab440
cpustop_handler(1,f7510bb4,a07876dd,0,0,...) at cpustop_handler+0x32
ipi_nmi_handler(0,0,0,a05a23d8,a56d5804,...) at ipi_nmi_handler+0x2f
trap(f7510bc0) at trap+0x2d
calltrap() at calltrap+0x6
--- trap 0x13, eip = 0xa058d066, esp = 0xf7510c00, ebp = 0xf7510c1c ---
_mtx_unlock_flags(a184ec08,0,a07e8e0b,2e0,0,f7510c60,a058d3d3,a08b1b2c,8,a07e8e0b,5d4,f7510c94) at _mtx_unlock_flags+0x56
zone_drain(a184b780,0,a07e8e0b,5d4,290e2107,...) at zone_drain+0x26e
zone_foreach(4000000,290e2107,f7510cf8,a099a89f,f7510ce4,...) at zone_foreach+0x45
uma_reclaim(f7510ce4,a0a0ce14,1f4,0,0,...) at uma_reclaim+0x16
arc_reclaim_thread(0,f7510d38,a07cdfc5,2ea,a56d5804,...) at arc_reclaim_thread+0x3ef
fork_exit(a099a4b0,0,f7510d38) at fork_exit+0x94
fork_trampoline() at fork_trampoline+0x8
--- trap 0, eip = 0, esp = 0xf7510d70, ebp = 0 ---
db> bt 259
Tracing pid 259 tid 100064 td 0xa5b36aa0
kdb_enter(a07c0400,a08b4928,8,7ec647,a56fb48c,...) at kdb_enter+0x32
siointr1(a08b4928,0,a07ec647,56f,f99babd8,...) at siointr1+0xdf
siointr(a56fb400,0,0,a5b36aa0,a5525280,...) at siointr+0x32
intr_execute_handlers(a5519cd0,f99babf8,f99bac3c,a076fa14,3a,...) at intr_execute_handlers+0xec
lapic_handle_intr(3a,f99babf8) at lapic_handle_intr+0x3f
Xapic_isr1() at Xapic_isr1+0x34
--- interrupt, eip = 0xa077a99b, esp = 0xf99bac38, ebp = 0xf99bac3c ---
spinlock_exit(a085a414,8,a07d329d,108) at spinlock_exit+0x2b
_mtx_unlock_spin_flags(a085a414,0,a07d329d,108,f99bac8c,...) at _mtx_unlock_spin_flags+0x4d
sleepq_release(a558a454,0,27af18f4,a558a3fc) at sleepq_release+0x37
cv_broadcastpri(a558a454,ffffffff,a0a02fb3,347,92388953,...) at cv_broadcastpri+0x48
taskq_thread(a558a3fc,f99bad38,a07cdfc5,2ea,a5b34ab0,...) at taskq_thread+0x31c
fork_exit(a098ddd0,a558a3fc,f99bad38) at fork_exit+0x94
fork_trampoline() at fork_trampoline+0x8
--- trap 0, eip = 0, esp = 0xf99bad70, ebp = 0 ---
db> 
Received on Sun Jan 27 2008 - 12:47:09 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:39:26 UTC