Hung processes during copy operations

Ulrich Petri u.petri at gmail.com
Mon May 16 09:58:20 EDT 2011


(I already posted a similar message but it seems to have gotten lost
somewhere; But maybe that a good thing because I have made a few more
obersavtions and maybe that will help.)

Hi,

I have installed zfs-0.6.0-rc4 on a new server I'm setting up
(configuration see at the bottom). Compiling and creating the pool
worked without problems.

However I then started to copy over data from one of our other servers
(3.3 TB, about 98M files) which at first seemed to be going well but
after a few hours (< 10) the copying process (cp in the first run,
rsync afterwards) seems to enter longer and longer periods of
uninterruptible sleep (state D in ps) and messages like this "INFO:
task rsync:1637 blocked for more than 120 seconds." started to appear
in dmesg (full output see below).

At some point it seems to be either blocked permanently or at the
least longer than I was patient enough to wait.

After a reboot I continued the copying but it showed the same
behaviour again (I've so far have gone through this "cycle" 4 times
and it seems to be perfectly reproducible).

Today I have actively monitored the copying process and was able to
see the growing durations of rsync being in state D. At some point I
stopped rsync, unmounted the volume, rmmoded zfs, mounted it again and
resumed rsync. This seemd to - for the moment at least - restore the
system to full speed.

So do you have any ideas what could be causing this behaviour or what
I could do to fix it?

Thanks
Ulrich


Hardware: AMD Phenom II X6 (6x 3 GHz); 12 GB RAM; Storage disks: 4x
2TB Hitachi HDS5C3020ALA632
OS: Ubuntu 11.04 x64

# uname -a
Linux xfiles2 2.6.38-8-server #42-Ubuntu SMP Mon Apr 11 03:49:04 UTC
2011 x86_64 x86_64 x86_64 GNU/Linux

# zpool list
NAME   SIZE  ALLOC   FREE    CAP  DEDUP  HEALTH  ALTROOT
data  7.25T  1000G  6.27T    13%  1.87x  ONLINE  -

# zfs list
NAME   USED  AVAIL  REFER  MOUNTPOINT
data  1.36T  4.60T  1.36T  /data

# zpool status
  pool: data
 state: ONLINE
 scan: scrub canceled on Sat May 14 14:47:32 2011
config:

	NAME        STATE     READ WRITE CKSUM
	data        ONLINE       0     0     0
	  raidz1-0  ONLINE       0     0     0
	    sdc     ONLINE       0     0     0
	    sdd     ONLINE       0     0     0
	    sde     ONLINE       0     0     0
	    sdf     ONLINE       0     0     0

errors: No known data errors


# zfs get all | grep local
data  dedup                 on                     local

###############################################
dmesg:


[22321.570141] INFO: task rsync:1637 blocked for more than 120
seconds.
[22321.570237] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[22321.570346] rsync           D 0000000000000001     0  1637   1635
0x00000000
[22321.570356]  ffff8802fe537b88 0000000000000082 ffff8802fe537fd8
ffff8802fe536000
[22321.570364]  0000000000013d00 ffff88030229b178 ffff8802fe537fd8
0000000000013d00
[22321.570373]  ffff880307940000 ffff88030229adc0 ffff8802fe537ba8
ffff880305f0f330
[22321.570380] Call Trace:
[22321.570406]  [<ffffffffa0418ce7>] cv_wait_common+0x77/0xd0 [spl]
[22321.570417]  [<ffffffff81087f30>] ? autoremove_wake_function
+0x0/0x40
[22321.570435]  [<ffffffffa0418d73>] __cv_wait+0x13/0x20 [spl]
[22321.570504]  [<ffffffffa04feb13>] txg_wait_open+0x73/0xb0 [zfs]
[22321.570552]  [<ffffffffa04c538d>] dmu_tx_wait+0xed/0xf0 [zfs]
[22321.570609]  [<ffffffffa0531823>] zfs_write+0x363/0xbf0 [zfs]
[22321.570665]  [<ffffffffa0543572>] zpl_write_common+0x52/0x80 [zfs]
[22321.570719]  [<ffffffffa0543608>] zpl_write+0x68/0xa0 [zfs]
[22321.570727]  [<ffffffff81164df6>] vfs_write+0xc6/0x180
[22321.570734]  [<ffffffff81165111>] sys_write+0x51/0x90
[22321.570740]  [<ffffffff8100c002>] system_call_fastpath+0x16/0x1b
[25441.580166] INFO: task rsync:1637 blocked for more than 120
seconds.
[25441.580264] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[25441.580372] rsync           D 0000000000000001     0  1637   1635
0x00000000
[25441.580382]  ffff8802fe537ae8 0000000000000082 ffff8802fe537fd8
ffff8802fe536000
[25441.580391]  0000000000013d00 ffff88030229b178 ffff8802fe537fd8
0000000000013d00
[25441.580399]  ffff8802fc4dc4a0 ffff88030229adc0 ffff8802fe537b08
ffff880305f0f330
[25441.580407] Call Trace:
[25441.580433]  [<ffffffffa0418ce7>] cv_wait_common+0x77/0xd0 [spl]
[25441.580443]  [<ffffffff81087f30>] ? autoremove_wake_function
+0x0/0x40
[25441.580461]  [<ffffffffa0418d73>] __cv_wait+0x13/0x20 [spl]
[25441.580531]  [<ffffffffa04feb13>] txg_wait_open+0x73/0xb0 [zfs]
[25441.580579]  [<ffffffffa04c538d>] dmu_tx_wait+0xed/0xf0 [zfs]
[25441.580637]  [<ffffffffa052e9b8>] zfs_setattr+0x1478/0x1750 [zfs]
[25441.580681]  [<ffffffffa04b8f99>] ? dmu_object_size_from_db
+0x69/0xa0 [zfs]
[25441.580690]  [<ffffffff81171483>] ? do_lookup+0x113/0x2e0
[25441.580699]  [<ffffffff812ae501>] ? apparmor_capable+0x31/0x90
[25441.580707]  [<ffffffff815c2cbe>] ? _raw_spin_lock+0xe/0x20
[25441.580713]  [<ffffffff8117bbae>] ? dput+0x12e/0x1d0
[25441.580720]  [<ffffffff81171e3d>] ? link_path_walk+0x7ed/0xc40
[25441.580727]  [<ffffffff81155dd7>] ? __kmalloc+0x117/0x160
[25441.580741]  [<ffffffffa041333b>] ? kmem_alloc_debug+0xbb/0x130
[spl]
[25441.580755]  [<ffffffffa041333b>] ? kmem_alloc_debug+0xbb/0x130
[spl]
[25441.580809]  [<ffffffffa0543b4c>] zpl_setattr+0xdc/0x110 [zfs]
[25441.580817]  [<ffffffff8117fc19>] notify_change+0x189/0x370
[25441.580825]  [<ffffffff8119022e>] utimes_common+0xce/0x1d0
[25441.580832]  [<ffffffff8119041c>] do_utimes+0xec/0x100
[25441.580839]  [<ffffffff81190584>] sys_futimesat+0x34/0xc0
[25441.580847]  [<ffffffff81190629>] sys_utimes+0x19/0x20
[25441.580853]  [<ffffffff8100c002>] system_call_fastpath+0x16/0x1b
[25561.580166] INFO: task rsync:1637 blocked for more than 120
seconds.
[25561.580263] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[25561.580371] rsync           D 0000000000000001     0  1637   1635
0x00000000
[25561.580380]  ffff8802fe537ae8 0000000000000082 ffff8802fe537fd8
ffff8802fe536000
[25561.580388]  0000000000013d00 ffff88030229b178 ffff8802fe537fd8
0000000000013d00
[25561.580395]  ffff8802fc4dc4a0 ffff88030229adc0 ffff8802fe537b08
ffff880305f0f330
[25561.580403] Call Trace:
[25561.580428]  [<ffffffffa0418ce7>] cv_wait_common+0x77/0xd0 [spl]
[25561.580437]  [<ffffffff81087f30>] ? autoremove_wake_function
+0x0/0x40
[25561.580454]  [<ffffffffa0418d73>] __cv_wait+0x13/0x20 [spl]
[25561.580522]  [<ffffffffa04feb13>] txg_wait_open+0x73/0xb0 [zfs]
[25561.580570]  [<ffffffffa04c538d>] dmu_tx_wait+0xed/0xf0 [zfs]
[25561.580627]  [<ffffffffa052e9b8>] zfs_setattr+0x1478/0x1750 [zfs]
[25561.580674]  [<ffffffffa04b8f99>] ? dmu_object_size_from_db
+0x69/0xa0 [zfs]
[25561.580683]  [<ffffffff81171483>] ? do_lookup+0x113/0x2e0
[25561.580691]  [<ffffffff812ae501>] ? apparmor_capable+0x31/0x90
[25561.580704]  [<ffffffff815c2cbe>] ? _raw_spin_lock+0xe/0x20
[25561.580710]  [<ffffffff8117bbae>] ? dput+0x12e/0x1d0
[25561.580716]  [<ffffffff81171e3d>] ? link_path_walk+0x7ed/0xc40
[25561.580726]  [<ffffffff81155dd7>] ? __kmalloc+0x117/0x160
[25561.580741]  [<ffffffffa041333b>] ? kmem_alloc_debug+0xbb/0x130
[spl]
[25561.580755]  [<ffffffffa041333b>] ? kmem_alloc_debug+0xbb/0x130
[spl]
[25561.580809]  [<ffffffffa0543b4c>] zpl_setattr+0xdc/0x110 [zfs]
[25561.580817]  [<ffffffff8117fc19>] notify_change+0x189/0x370
[25561.580825]  [<ffffffff8119022e>] utimes_common+0xce/0x1d0
[25561.580832]  [<ffffffff8119041c>] do_utimes+0xec/0x100
[25561.580839]  [<ffffffff81190584>] sys_futimesat+0x34/0xc0
[25561.580846]  [<ffffffff81190629>] sys_utimes+0x19/0x20
[25561.580853]  [<ffffffff8100c002>] system_call_fastpath+0x16/0x1b
[25681.580170] INFO: task rsync:1637 blocked for more than 120
seconds.
[25681.580267] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[25681.580374] rsync           D 0000000000000001     0  1637   1635
0x00000000
[25681.580383]  ffff8802fe537ae8 0000000000000082 ffff8802fe537fd8
ffff8802fe536000
[25681.580391]  0000000000013d00 ffff88030229b178 ffff8802fe537fd8
0000000000013d00
[25681.580398]  ffff8802fc4dc4a0 ffff88030229adc0 ffff8802fe537b08
ffff880305f0f330
[25681.580406] Call Trace:
[25681.580431]  [<ffffffffa0418ce7>] cv_wait_common+0x77/0xd0 [spl]
[25681.580440]  [<ffffffff81087f30>] ? autoremove_wake_function
+0x0/0x40
[25681.580458]  [<ffffffffa0418d73>] __cv_wait+0x13/0x20 [spl]
[25681.580526]  [<ffffffffa04feb13>] txg_wait_open+0x73/0xb0 [zfs]
[25681.580574]  [<ffffffffa04c538d>] dmu_tx_wait+0xed/0xf0 [zfs]
[25681.580631]  [<ffffffffa052e9b8>] zfs_setattr+0x1478/0x1750 [zfs]
[25681.580675]  [<ffffffffa04b8f99>] ? dmu_object_size_from_db
+0x69/0xa0 [zfs]
[25681.580684]  [<ffffffff81171483>] ? do_lookup+0x113/0x2e0
[25681.580693]  [<ffffffff812ae501>] ? apparmor_capable+0x31/0x90
[25681.580701]  [<ffffffff815c2cbe>] ? _raw_spin_lock+0xe/0x20
[25681.580707]  [<ffffffff8117bbae>] ? dput+0x12e/0x1d0
[25681.580713]  [<ffffffff81171e3d>] ? link_path_walk+0x7ed/0xc40
[25681.580720]  [<ffffffff81155dd7>] ? __kmalloc+0x117/0x160
[25681.580734]  [<ffffffffa041333b>] ? kmem_alloc_debug+0xbb/0x130
[spl]
[25681.580748]  [<ffffffffa041333b>] ? kmem_alloc_debug+0xbb/0x130
[spl]
[25681.580802]  [<ffffffffa0543b4c>] zpl_setattr+0xdc/0x110 [zfs]
[25681.580810]  [<ffffffff8117fc19>] notify_change+0x189/0x370
[25681.580818]  [<ffffffff8119022e>] utimes_common+0xce/0x1d0
[25681.580825]  [<ffffffff8119041c>] do_utimes+0xec/0x100
[25681.580832]  [<ffffffff81190584>] sys_futimesat+0x34/0xc0
[25681.580839]  [<ffffffff81190629>] sys_utimes+0x19/0x20
[25681.580846]  [<ffffffff8100c002>] system_call_fastpath+0x16/0x1b
[25801.580173] INFO: task rsync:1637 blocked for more than 120
seconds.
[25801.580271] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[25801.580379] rsync           D 0000000000000001     0  1637   1635
0x00000000
[25801.580389]  ffff8802fe537ae8 0000000000000082 ffff8802fe537fd8
ffff8802fe536000
[25801.580398]  0000000000013d00 ffff88030229b178 ffff8802fe537fd8
0000000000013d00
[25801.580406]  ffff8802fc4dc4a0 ffff88030229adc0 ffff8802fe537b08
ffff880305f0f330
[25801.580414] Call Trace:
[25801.580441]  [<ffffffffa0418ce7>] cv_wait_common+0x77/0xd0 [spl]
[25801.580451]  [<ffffffff81087f30>] ? autoremove_wake_function
+0x0/0x40
[25801.580470]  [<ffffffffa0418d73>] __cv_wait+0x13/0x20 [spl]
[25801.580538]  [<ffffffffa04feb13>] txg_wait_open+0x73/0xb0 [zfs]
[25801.580586]  [<ffffffffa04c538d>] dmu_tx_wait+0xed/0xf0 [zfs]
[25801.580644]  [<ffffffffa052e9b8>] zfs_setattr+0x1478/0x1750 [zfs]
[25801.580688]  [<ffffffffa04b8f99>] ? dmu_object_size_from_db
+0x69/0xa0 [zfs]
[25801.580698]  [<ffffffff81171483>] ? do_lookup+0x113/0x2e0
[25801.580706]  [<ffffffff812ae501>] ? apparmor_capable+0x31/0x90
[25801.580715]  [<ffffffff815c2cbe>] ? _raw_spin_lock+0xe/0x20
[25801.580721]  [<ffffffff8117bbae>] ? dput+0x12e/0x1d0
[25801.580727]  [<ffffffff81171e3d>] ? link_path_walk+0x7ed/0xc40
[25801.580734]  [<ffffffff81155dd7>] ? __kmalloc+0x117/0x160
[25801.580748]  [<ffffffffa041333b>] ? kmem_alloc_debug+0xbb/0x130
[spl]
[25801.580763]  [<ffffffffa041333b>] ? kmem_alloc_debug+0xbb/0x130
[spl]
[25801.580817]  [<ffffffffa0543b4c>] zpl_setattr+0xdc/0x110 [zfs]
[25801.580830]  [<ffffffff8117fc19>] notify_change+0x189/0x370
[25801.580839]  [<ffffffff8119022e>] utimes_common+0xce/0x1d0
[25801.580846]  [<ffffffff8119041c>] do_utimes+0xec/0x100
[25801.580853]  [<ffffffff81190584>] sys_futimesat+0x34/0xc0
[25801.580861]  [<ffffffff81190629>] sys_utimes+0x19/0x20
[25801.580867]  [<ffffffff8100c002>] system_call_fastpath+0x16/0x1b
[25921.580142] INFO: task rsync:1637 blocked for more than 120
seconds.
[25921.580242] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[25921.580350] rsync           D 0000000000000001     0  1637   1635
0x00000000
[25921.580360]  ffff8802fe537ae8 0000000000000082 ffff8802fe537fd8
ffff8802fe536000
[25921.580368]  0000000000013d00 ffff88030229b178 ffff8802fe537fd8
0000000000013d00
[25921.580376]  ffff8802fc4dc4a0 ffff88030229adc0 ffff8802fe537b08
ffff880305f0f330
[25921.580384] Call Trace:
[25921.580410]  [<ffffffffa0418ce7>] cv_wait_common+0x77/0xd0 [spl]
[25921.580419]  [<ffffffff81087f30>] ? autoremove_wake_function
+0x0/0x40
[25921.580437]  [<ffffffffa0418d73>] __cv_wait+0x13/0x20 [spl]
[25921.580505]  [<ffffffffa04feb13>] txg_wait_open+0x73/0xb0 [zfs]
[25921.580554]  [<ffffffffa04c538d>] dmu_tx_wait+0xed/0xf0 [zfs]
[25921.580612]  [<ffffffffa052e9b8>] zfs_setattr+0x1478/0x1750 [zfs]
[25921.580656]  [<ffffffffa04b8f99>] ? dmu_object_size_from_db
+0x69/0xa0 [zfs]
[25921.580665]  [<ffffffff81171483>] ? do_lookup+0x113/0x2e0
[25921.580674]  [<ffffffff812ae501>] ? apparmor_capable+0x31/0x90
[25921.580682]  [<ffffffff815c2cbe>] ? _raw_spin_lock+0xe/0x20
[25921.580688]  [<ffffffff8117bbae>] ? dput+0x12e/0x1d0
[25921.580694]  [<ffffffff81171e3d>] ? link_path_walk+0x7ed/0xc40
[25921.580701]  [<ffffffff81155dd7>] ? __kmalloc+0x117/0x160
[25921.580715]  [<ffffffffa041333b>] ? kmem_alloc_debug+0xbb/0x130
[spl]
[25921.580729]  [<ffffffffa041333b>] ? kmem_alloc_debug+0xbb/0x130
[spl]
[25921.580784]  [<ffffffffa0543b4c>] zpl_setattr+0xdc/0x110 [zfs]
[25921.580791]  [<ffffffff8117fc19>] notify_change+0x189/0x370
[25921.580799]  [<ffffffff8119022e>] utimes_common+0xce/0x1d0
[25921.580807]  [<ffffffff8119041c>] do_utimes+0xec/0x100
[25921.580813]  [<ffffffff81190584>] sys_futimesat+0x34/0xc0
[25921.580821]  [<ffffffff81190629>] sys_utimes+0x19/0x20
[25921.580827]  [<ffffffff8100c002>] system_call_fastpath+0x16/0x1b
[26041.580145] INFO: task rsync:1637 blocked for more than 120
seconds.
[26041.580244] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[26041.580352] rsync           D 0000000000000001     0  1637   1635
0x00000000
[26041.580361]  ffff8802fe537ae8 0000000000000082 ffff8802fe537fd8
ffff8802fe536000
[26041.580369]  0000000000013d00 ffff88030229b178 ffff8802fe537fd8
0000000000013d00
[26041.580377]  ffff8802fc4dc4a0 ffff88030229adc0 ffff8802fe537b08
ffff880305f0f330
[26041.580384] Call Trace:
[26041.580409]  [<ffffffffa0418ce7>] cv_wait_common+0x77/0xd0 [spl]
[26041.580419]  [<ffffffff81087f30>] ? autoremove_wake_function
+0x0/0x40
[26041.580436]  [<ffffffffa0418d73>] __cv_wait+0x13/0x20 [spl]
[26041.580503]  [<ffffffffa04feb13>] txg_wait_open+0x73/0xb0 [zfs]
[26041.580551]  [<ffffffffa04c538d>] dmu_tx_wait+0xed/0xf0 [zfs]
[26041.580609]  [<ffffffffa052e9b8>] zfs_setattr+0x1478/0x1750 [zfs]
[26041.580653]  [<ffffffffa04b8f99>] ? dmu_object_size_from_db
+0x69/0xa0 [zfs]
[26041.580662]  [<ffffffff81171483>] ? do_lookup+0x113/0x2e0
[26041.580670]  [<ffffffff812ae501>] ? apparmor_capable+0x31/0x90
[26041.580679]  [<ffffffff815c2cbe>] ? _raw_spin_lock+0xe/0x20
[26041.580684]  [<ffffffff8117bbae>] ? dput+0x12e/0x1d0
[26041.580691]  [<ffffffff81171e3d>] ? link_path_walk+0x7ed/0xc40
[26041.580697]  [<ffffffff81155dd7>] ? __kmalloc+0x117/0x160
[26041.580712]  [<ffffffffa041333b>] ? kmem_alloc_debug+0xbb/0x130
[spl]
[26041.580726]  [<ffffffffa041333b>] ? kmem_alloc_debug+0xbb/0x130
[spl]
[26041.580780]  [<ffffffffa0543b4c>] zpl_setattr+0xdc/0x110 [zfs]
[26041.580788]  [<ffffffff8117fc19>] notify_change+0x189/0x370
[26041.580796]  [<ffffffff8119022e>] utimes_common+0xce/0x1d0
[26041.580803]  [<ffffffff8119041c>] do_utimes+0xec/0x100
[26041.580810]  [<ffffffff81190584>] sys_futimesat+0x34/0xc0
[26041.580817]  [<ffffffff81190629>] sys_utimes+0x19/0x20
[26041.580823]  [<ffffffff8100c002>] system_call_fastpath+0x16/0x1b
[26161.580147] INFO: task rsync:1637 blocked for more than 120
seconds.
[26161.580245] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[26161.580352] rsync           D 0000000000000001     0  1637   1635
0x00000000
[26161.580362]  ffff8802fe537ae8 0000000000000082 ffff8802fe537fd8
ffff8802fe536000
[26161.580370]  0000000000013d00 ffff88030229b178 ffff8802fe537fd8
0000000000013d00
[26161.580378]  ffff8802fc4dc4a0 ffff88030229adc0 ffff8802fe537b08
ffff880305f0f330
[26161.580385] Call Trace:
[26161.580410]  [<ffffffffa0418ce7>] cv_wait_common+0x77/0xd0 [spl]
[26161.580420]  [<ffffffff81087f30>] ? autoremove_wake_function
+0x0/0x40
[26161.580438]  [<ffffffffa0418d73>] __cv_wait+0x13/0x20 [spl]
[26161.580505]  [<ffffffffa04feb13>] txg_wait_open+0x73/0xb0 [zfs]
[26161.580553]  [<ffffffffa04c538d>] dmu_tx_wait+0xed/0xf0 [zfs]
[26161.580611]  [<ffffffffa052e9b8>] zfs_setattr+0x1478/0x1750 [zfs]
[26161.580655]  [<ffffffffa04b8f99>] ? dmu_object_size_from_db
+0x69/0xa0 [zfs]
[26161.580664]  [<ffffffff81171483>] ? do_lookup+0x113/0x2e0
[26161.580673]  [<ffffffff812ae501>] ? apparmor_capable+0x31/0x90
[26161.580681]  [<ffffffff815c2cbe>] ? _raw_spin_lock+0xe/0x20
[26161.580687]  [<ffffffff8117bbae>] ? dput+0x12e/0x1d0
[26161.580693]  [<ffffffff81171e3d>] ? link_path_walk+0x7ed/0xc40
[26161.580700]  [<ffffffff81155dd7>] ? __kmalloc+0x117/0x160
[26161.580714]  [<ffffffffa041333b>] ? kmem_alloc_debug+0xbb/0x130
[spl]
[26161.580729]  [<ffffffffa041333b>] ? kmem_alloc_debug+0xbb/0x130
[spl]
[26161.580783]  [<ffffffffa0543b4c>] zpl_setattr+0xdc/0x110 [zfs]
[26161.580790]  [<ffffffff8117fc19>] notify_change+0x189/0x370
[26161.580799]  [<ffffffff8119022e>] utimes_common+0xce/0x1d0
[26161.580806]  [<ffffffff8119041c>] do_utimes+0xec/0x100
[26161.580813]  [<ffffffff81190584>] sys_futimesat+0x34/0xc0
[26161.580820]  [<ffffffff81190629>] sys_utimes+0x19/0x20
[26161.580826]  [<ffffffff8100c002>] system_call_fastpath+0x16/0x1b
[26401.580146] INFO: task rsync:1637 blocked for more than 120
seconds.
[26401.580245] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[26401.580353] rsync           D 0000000000000001     0  1637   1635
0x00000000
[26401.580363]  ffff8802fe537b88 0000000000000082 ffff8802fe537fd8
ffff8802fe536000
[26401.580372]  0000000000013d00 ffff88030229b178 ffff8802fe537fd8
0000000000013d00
[26401.580380]  ffff880307940000 ffff88030229adc0 ffff8802fe537ba8
ffff880305f0f330
[26401.580387] Call Trace:
[26401.580414]  [<ffffffffa0418ce7>] cv_wait_common+0x77/0xd0 [spl]
[26401.580424]  [<ffffffff81087f30>] ? autoremove_wake_function
+0x0/0x40
[26401.580442]  [<ffffffffa0418d73>] __cv_wait+0x13/0x20 [spl]
[26401.580509]  [<ffffffffa04feb13>] txg_wait_open+0x73/0xb0 [zfs]
[26401.580557]  [<ffffffffa04c538d>] dmu_tx_wait+0xed/0xf0 [zfs]
[26401.580614]  [<ffffffffa0531823>] zfs_write+0x363/0xbf0 [zfs]
[26401.580625]  [<ffffffff81164792>] ? do_sync_read+0xd2/0x110
[26401.580679]  [<ffffffffa0543572>] zpl_write_common+0x52/0x80 [zfs]
[26401.580732]  [<ffffffffa0543608>] zpl_write+0x68/0xa0 [zfs]
[26401.580740]  [<ffffffff81164df6>] vfs_write+0xc6/0x180
[26401.580746]  [<ffffffff81165111>] sys_write+0x51/0x90
[26401.580753]  [<ffffffff8100c002>] system_call_fastpath+0x16/0x1b
[26521.580141] INFO: task rsync:1637 blocked for more than 120
seconds.
[26521.580238] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[26521.580346] rsync           D 0000000000000001     0  1637   1635
0x00000000
[26521.580355]  ffff8802fe537b88 0000000000000082 ffff8802fe537fd8
ffff8802fe536000
[26521.580364]  0000000000013d00 ffff88030229b178 ffff8802fe537fd8
0000000000013d00
[26521.580372]  ffff880307940000 ffff88030229adc0 ffff8802fe537ba8
ffff880305f0f330
[26521.580379] Call Trace:
[26521.580405]  [<ffffffffa0418ce7>] cv_wait_common+0x77/0xd0 [spl]
[26521.580415]  [<ffffffff81087f30>] ? autoremove_wake_function
+0x0/0x40
[26521.580433]  [<ffffffffa0418d73>] __cv_wait+0x13/0x20 [spl]
[26521.580501]  [<ffffffffa04feb13>] txg_wait_open+0x73/0xb0 [zfs]
[26521.580549]  [<ffffffffa04c538d>] dmu_tx_wait+0xed/0xf0 [zfs]
[26521.580606]  [<ffffffffa0531823>] zfs_write+0x363/0xbf0 [zfs]
[26521.580616]  [<ffffffff81164792>] ? do_sync_read+0xd2/0x110
[26521.580669]  [<ffffffffa0543572>] zpl_write_common+0x52/0x80 [zfs]
[26521.580723]  [<ffffffffa0543608>] zpl_write+0x68/0xa0 [zfs]
[26521.580730]  [<ffffffff81164df6>] vfs_write+0xc6/0x180
[26521.580736]  [<ffffffff81165111>] sys_write+0x51/0x90
[26521.580743]  [<ffffffff8100c002>] system_call_fastpath+0x16/0x1b



More information about the zfs-discuss mailing list