Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

periodic txg_sync zfs tasks blocked (from ret_from_fork) #9796

Closed
fermulator opened this issue Jan 1, 2020 · 11 comments
Closed

periodic txg_sync zfs tasks blocked (from ret_from_fork) #9796

fermulator opened this issue Jan 1, 2020 · 11 comments
Labels
Status: Stale No recent activity for issue

Comments

@fermulator
Copy link

fermulator commented Jan 1, 2020 •
edited
Loading

System information (SYSTEM A, VM host)

Type Version/Name
Distribution Name Ubuntu
Distribution Version 18.04.3 LTS
Linux Kernel 4.15.0-70-generic
Architecture x64
ZFS Version 0.7.5
SPL Version 0.7.5

This system is purely a KVM host, it runs nill applications itself, it has 2x mirrors one for root ZFS and another for storage.

System information (SYSTEM B, storage server)

Type Version/Name
Distribution Name Ubuntu
Distribution Version 18.04.3 LTS
Linux Kernel 4.15.0-70-generic
Architecture x64
ZFS Version 0.7.5
SPL Version 0.7.5

Describe the problem you're observing

Occasionally have seen "zfs task:##### blocked for more than 120 seconds" messages in system logs on two different zfsonlinux systems.

It happens infrequently, but in bursts. I cannot determine any "pattern" of events prior to these blocking zfs tasks.

Describe how to reproduce the problem

UNKNOWN

Given it has happened on TWO systems now, same software version(s), but different hardware, I am wondering if it is a common configuration or software component.

Include any warning/errors/backtraces from the system logs

System A

[Sun Dec 29 19:23:32 2019] INFO: task zfs:31092 blocked for more than 120 seconds.
[Sun Dec 29 19:23:32 2019]       Tainted: P          IO     4.15.0-70-generic #79-Ubuntu
[Sun Dec 29 19:23:32 2019] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Sun Dec 29 19:23:32 2019] zfs             D    0 31092  31074 0x00000000
[Sun Dec 29 19:23:32 2019] Call Trace:
[Sun Dec 29 19:23:32 2019]  __schedule+0x24e/0x880
[Sun Dec 29 19:23:32 2019]  schedule+0x2c/0x80
[Sun Dec 29 19:23:32 2019]  cv_wait_common+0x11e/0x140 [spl]
[Sun Dec 29 19:23:32 2019]  ? wait_woken+0x80/0x80
[Sun Dec 29 19:23:32 2019]  __cv_wait+0x15/0x20 [spl]
[Sun Dec 29 19:23:32 2019]  txg_wait_synced+0xdd/0x130 [zfs]
[Sun Dec 29 19:23:32 2019]  dsl_sync_task+0x17c/0x270 [zfs]
[Sun Dec 29 19:23:32 2019]  ? dsl_destroy_snapshot_check_impl+0x140/0x140 [zfs]
[Sun Dec 29 19:23:32 2019]  ? dsl_destroy_snapshot_sync_impl+0xba0/0xba0 [zfs]
[Sun Dec 29 19:23:32 2019]  ? dsl_destroy_snapshot_check_impl+0x140/0x140 [zfs]
[Sun Dec 29 19:23:32 2019]  ? dsl_destroy_snapshot_sync_impl+0xba0/0xba0 [zfs]
[Sun Dec 29 19:23:32 2019]  dsl_destroy_snapshots_nvl+0x8f/0x100 [zfs]
[Sun Dec 29 19:23:32 2019]  zfs_ioc_destroy_snaps+0x87/0xd0 [zfs]
[Sun Dec 29 19:23:32 2019]  zfsdev_ioctl+0x451/0x610 [zfs]
[Sun Dec 29 19:23:32 2019]  do_vfs_ioctl+0xa8/0x630
[Sun Dec 29 19:23:32 2019]  ? handle_mm_fault+0xb1/0x210
[Sun Dec 29 19:23:32 2019]  ? __do_page_fault+0x2a1/0x4b0
[Sun Dec 29 19:23:32 2019]  SyS_ioctl+0x79/0x90
[Sun Dec 29 19:23:32 2019]  do_syscall_64+0x73/0x130
[Sun Dec 29 19:23:32 2019]  entry_SYSCALL_64_after_hwframe+0x3d/0xa2
[Sun Dec 29 19:23:32 2019] RIP: 0033:0x7f8bf15655d7
[Sun Dec 29 19:23:32 2019] RSP: 002b:00007ffcd4091a28 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[Sun Dec 29 19:23:32 2019] RAX: ffffffffffffffda RBX: 0000000000005a3b RCX: 00007f8bf15655d7
[Sun Dec 29 19:23:32 2019] RDX: 00007ffcd4091a40 RSI: 0000000000005a3b RDI: 0000000000000005
[Sun Dec 29 19:23:32 2019] RBP: 00007ffcd4091a40 R08: 00007f8bf183b2d0 R09: 0000000000000000
[Sun Dec 29 19:23:32 2019] R10: 00005635716a9010 R11: 0000000000000246 R12: 00007ffcd4095178
[Sun Dec 29 19:23:32 2019] R13: 0000000000000005 R14: 00005635716b3450 R15: 000000000000000c
[Sun Dec 29 19:33:37 2019] INFO: task txg_sync:2935 blocked for more than 120 seconds.
[Sun Dec 29 19:33:37 2019]       Tainted: P          IO     4.15.0-70-generic #79-Ubuntu
[Sun Dec 29 19:33:37 2019] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Sun Dec 29 19:33:37 2019] txg_sync        D    0  2935      2 0x80000000
[Sun Dec 29 19:33:37 2019] Call Trace:
[Sun Dec 29 19:33:37 2019]  __schedule+0x24e/0x880
[Sun Dec 29 19:33:37 2019]  schedule+0x2c/0x80
[Sun Dec 29 19:33:37 2019]  io_schedule+0x16/0x40
[Sun Dec 29 19:33:37 2019]  cv_wait_common+0xb2/0x140 [spl]
[Sun Dec 29 19:33:37 2019]  ? wait_woken+0x80/0x80
[Sun Dec 29 19:33:37 2019]  __cv_wait_io+0x18/0x20 [spl]
[Sun Dec 29 19:33:37 2019]  zio_wait+0xf8/0x1b0 [zfs]
[Sun Dec 29 19:33:37 2019]  dsl_pool_sync+0x3e5/0x430 [zfs]
[Sun Dec 29 19:33:37 2019]  spa_sync+0x43e/0xd80 [zfs]
[Sun Dec 29 19:33:37 2019]  txg_sync_thread+0x2cd/0x4a0 [zfs]
[Sun Dec 29 19:33:37 2019]  ? __switch_to_asm+0x35/0x70
[Sun Dec 29 19:33:37 2019]  ? txg_quiesce_thread+0x3d0/0x3d0 [zfs]
[Sun Dec 29 19:33:37 2019]  thread_generic_wrapper+0x74/0x90 [spl]
[Sun Dec 29 19:33:37 2019]  kthread+0x121/0x140
[Sun Dec 29 19:33:37 2019]  ? __thread_exit+0x20/0x20 [spl]
[Sun Dec 29 19:33:37 2019]  ? kthread_create_worker_on_cpu+0x70/0x70
[Sun Dec 29 19:33:37 2019]  ret_from_fork+0x35/0x40

This repeats itself many times, then stopped.

# dmesg -T | grep zfs | grep "blocked for more than 120 seconds"
[Sun Dec 29 19:23:32 2019] INFO: task zfs:31092 blocked for more than 120 seconds.
[Sun Dec 29 19:33:37 2019] INFO: task zfs:32199 blocked for more than 120 seconds.
[Sun Dec 29 19:53:45 2019] INFO: task zfs:24759 blocked for more than 120 seconds.
[Sun Dec 29 19:57:47 2019] INFO: task zfs:29649 blocked for more than 120 seconds.
[Sun Dec 29 20:03:49 2019] INFO: task zfs:29496 blocked for more than 120 seconds.

System B

On another system I have running

[Sun Dec 29 19:24:48 2019] INFO: task zfs:31567 blocked for more than 120 seconds.
[Sun Dec 29 19:24:48 2019]       Tainted: P           O     4.15.0-73-generic #82-Ubuntu
[Sun Dec 29 19:24:48 2019] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Sun Dec 29 19:24:48 2019] zfs             D    0 31567  31565 0x80000080
[Sun Dec 29 19:24:48 2019] Call Trace:
[Sun Dec 29 19:24:48 2019]  __schedule+0x24e/0x880
[Sun Dec 29 19:24:48 2019]  ? vn_rdwr+0x97/0xc0 [spl]
[Sun Dec 29 19:24:48 2019]  schedule+0x2c/0x80
[Sun Dec 29 19:24:48 2019]  cv_wait_common+0x11e/0x140 [spl]
[Sun Dec 29 19:24:48 2019]  ? wait_woken+0x80/0x80
[Sun Dec 29 19:24:48 2019]  __cv_wait+0x15/0x20 [spl]
[Sun Dec 29 19:24:48 2019]  bqueue_enqueue+0x62/0xe0 [zfs]
[Sun Dec 29 19:24:48 2019]  dmu_recv_stream+0x548/0xef0 [zfs]
[Sun Dec 29 19:24:48 2019]  ? zfs_set_prop_nvlist+0x216/0x520 [zfs]
[Sun Dec 29 19:24:48 2019]  zfs_ioc_recv_impl+0x5d1/0x1100 [zfs]
[Sun Dec 29 19:24:48 2019]  ? nvlist_common.part.88+0xf1/0x210 [znvpair]
[Sun Dec 29 19:24:48 2019]  zfs_ioc_recv+0x1e9/0x330 [zfs]
[Sun Dec 29 19:24:48 2019]  ? avl_find+0x5f/0x90 [zavl]
[Sun Dec 29 19:24:48 2019]  ? security_capable+0x4e/0x70
[Sun Dec 29 19:24:48 2019]  ? ns_capable_common+0x68/0x80
[Sun Dec 29 19:24:48 2019]  ? capable+0x1c/0x20
[Sun Dec 29 19:24:48 2019]  ? priv_policy.isra.3.part.4+0x11/0x20 [zfs]
[Sun Dec 29 19:24:48 2019]  ? secpolicy_zinject+0x3a/0x40 [zfs]
[Sun Dec 29 19:24:48 2019]  ? _cond_resched+0x19/0x40
[Sun Dec 29 19:24:48 2019]  ? __kmalloc+0x18e/0x220
[Sun Dec 29 19:24:48 2019]  ? strdup+0x45/0x70 [spl]
[Sun Dec 29 19:24:48 2019]  zfsdev_ioctl+0x1e0/0x610 [zfs]
[Sun Dec 29 19:24:48 2019]  do_vfs_ioctl+0xa8/0x630
[Sun Dec 29 19:24:48 2019]  ? handle_mm_fault+0xb1/0x210
[Sun Dec 29 19:24:48 2019]  ? __audit_syscall_entry+0xbc/0x110
[Sun Dec 29 19:24:48 2019]  ? syscall_trace_enter+0x1da/0x2d0
[Sun Dec 29 19:24:48 2019]  SyS_ioctl+0x79/0x90
[Sun Dec 29 19:24:48 2019]  do_syscall_64+0x73/0x130
[Sun Dec 29 19:24:48 2019]  entry_SYSCALL_64_after_hwframe+0x3d/0xa2
[Sun Dec 29 19:24:48 2019] RIP: 0033:0x7f71479c65d7
[Sun Dec 29 19:24:48 2019] RSP: 002b:00007ffef6834fa8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[Sun Dec 29 19:24:48 2019] RAX: ffffffffffffffda RBX: 000055db99b45480 RCX: 00007f71479c65d7
[Sun Dec 29 19:24:48 2019] RDX: 00007ffef6835140 RSI: 0000000000005a1b RDI: 0000000000000005
[Sun Dec 29 19:24:48 2019] RBP: 00007ffef6835140 R08: 00007f7147c9bd20 R09: 0000000000000000
[Sun Dec 29 19:24:48 2019] R10: 000055db99b40010 R11: 0000000000000246 R12: 00007ffef68432e8
[Sun Dec 29 19:24:48 2019] R13: 00007ffef683f430 R14: 00007ffef683ce30 R15: 000055db99b43298
[Sun Dec 29 19:24:48 2019] INFO: task send_traverse:31656 blocked for more than 120 seconds.
[Sun Dec 29 19:24:48 2019]       Tainted: P           O     4.15.0-73-generic #82-Ubuntu
[Sun Dec 29 19:24:48 2019] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Sun Dec 29 19:24:48 2019] send_traverse   D    0 31656      2 0x80000080
[Sun Dec 29 19:24:48 2019] Call Trace:
[Sun Dec 29 19:24:48 2019]  __schedule+0x24e/0x880
[Sun Dec 29 19:24:48 2019]  schedule+0x2c/0x80
[Sun Dec 29 19:24:48 2019]  cv_wait_common+0x11e/0x140 [spl]
[Sun Dec 29 19:24:48 2019]  ? wait_woken+0x80/0x80
[Sun Dec 29 19:24:48 2019]  __cv_wait+0x15/0x20 [spl]
[Sun Dec 29 19:24:48 2019]  bqueue_enqueue+0x62/0xe0 [zfs]
[Sun Dec 29 19:24:48 2019]  send_cb+0x14a/0x190 [zfs]
[Sun Dec 29 19:24:48 2019]  traverse_visitbp+0x1c9/0x9a0 [zfs]
[Sun Dec 29 19:24:48 2019]  traverse_visitbp+0x350/0x9a0 [zfs]
[Sun Dec 29 19:24:48 2019]  traverse_dnode+0xf5/0x1c0 [zfs]
[Sun Dec 29 19:24:48 2019]  traverse_visitbp+0x731/0x9a0 [zfs]
[Sun Dec 29 19:24:48 2019]  traverse_visitbp+0x350/0x9a0 [zfs]
[Sun Dec 29 19:24:48 2019]  traverse_visitbp+0x350/0x9a0 [zfs]
[Sun Dec 29 19:24:48 2019]  traverse_visitbp+0x350/0x9a0 [zfs]
[Sun Dec 29 19:24:48 2019]  traverse_visitbp+0x350/0x9a0 [zfs]
[Sun Dec 29 19:24:48 2019]  traverse_visitbp+0x350/0x9a0 [zfs]
[Sun Dec 29 19:24:48 2019]  traverse_visitbp+0x350/0x9a0 [zfs]
[Sun Dec 29 19:24:48 2019]  traverse_dnode+0xf5/0x1c0 [zfs]
[Sun Dec 29 19:24:48 2019]  traverse_visitbp+0x7f8/0x9a0 [zfs]
[Sun Dec 29 19:24:48 2019]  traverse_impl+0x1e3/0x440 [zfs]
[Sun Dec 29 19:24:48 2019]  ? dmu_send_impl+0x14d0/0x14d0 [zfs]
[Sun Dec 29 19:24:48 2019]  ? byteswap_record+0x2d0/0x2d0 [zfs]
[Sun Dec 29 19:24:48 2019]  traverse_dataset_resume+0x46/0x50 [zfs]
[Sun Dec 29 19:24:48 2019]  ? dmu_send_impl+0x14d0/0x14d0 [zfs]
[Sun Dec 29 19:24:48 2019]  send_traverse_thread+0x59/0xb0 [zfs]
[Sun Dec 29 19:24:48 2019]  thread_generic_wrapper+0x74/0x90 [spl]
[Sun Dec 29 19:24:48 2019]  kthread+0x121/0x140
[Sun Dec 29 19:24:48 2019]  ? __thread_exit+0x20/0x20 [spl]
[Sun Dec 29 19:24:48 2019]  ? kthread_create_worker_on_cpu+0x70/0x70
[Sun Dec 29 19:24:48 2019]  ret_from_fork+0x22/0x40

Appendix

on system A, the pools and datasets and ZVOLs:

zpool status  | grep -v scsi
  pool: bpool
 state: ONLINE
status: Some supported features are not enabled on the pool. The pool can
	still be used, but some features are unavailable.
action: Enable all features using 'zpool upgrade'. Once this is done,
	the pool may no longer be accessible by software that does not support
	the features. See zpool-features(5) for details.
  scan: none requested
config:

	NAME                                                       STATE     READ WRITE CKSUM
	bpool                                                      ONLINE       0     0     0
	  mirror-0                                                 ONLINE       0     0     0

errors: No known data errors

  pool: rpool
 state: ONLINE
  scan: none requested
config:

	NAME                                                       STATE     READ WRITE CKSUM
	rpool                                                      ONLINE       0     0     0
	  mirror-0                                                 ONLINE       0     0     0

errors: No known data errors

  pool: zstorage
 state: ONLINE
  scan: scrub repaired 0B in 8h54m with 0 errors on Sun Dec  8 09:18:34 2019
config:

	NAME                        STATE     READ WRITE CKSUM
	zstorage                    ONLINE       0     0     0
	  mirror-0                  ONLINE       0     0     0

errors: No known data errors


zfs list -t filesystem,volume
NAME                                USED  AVAIL  REFER  MOUNTPOINT
bpool                              57.2M   823M    96K  /
bpool/BOOT                         56.5M   823M    96K  none
bpool/BOOT/ubuntu                  56.4M   823M  56.3M  legacy
rpool                              3.48G  60.9G    96K  /
rpool/ROOT                         1.21G  60.9G    96K  none
rpool/ROOT/ubuntu                  1.21G  60.9G  1.18G  /
rpool/home                          121M  60.9G    96K  /home
rpool/home/fermulator               121M  60.9G   121M  /home/fermulator
rpool/home/root                     144K  60.9G   144K  /root
rpool/tmp                            96K  60.9G    96K  legacy
rpool/usr                           200K  60.9G    96K  /usr
rpool/usr/local                     104K  60.9G   104K  /usr/local
rpool/var                          2.15G  60.9G    96K  /var
rpool/var/lib                        96K  60.9G    96K  /var/lib
rpool/var/log                      2.15G  60.9G  2.15G  legacy
rpool/var/spool                     132K  60.9G   132K  legacy
zstorage                            409G   501G    24K  /zstorage
zstorage/ROOT_BACKUP               13.2G   501G    24K  /zstorage/ROOT_BACKUP
zstorage/ROOT_BACKUP/fedora        9.22G   501G  9.22G  /mnt/fermmy-vms_fedora
zstorage/ROOT_BACKUP/ubuntu        4.02G   501G  3.84G  /mnt/fermmy-vms_home_recovery
zstorage/nfs                       16.0G   501G    23K  /zstorage/nfs
zstorage/nfs/fermmy-boinc0         16.0G   501G    23K  /zstorage/nfs/fermmy-boinc0
zstorage/nfs/fermmy-boinc0/disk0   16.0G   510G  7.71G  -
zstorage/vms                        373G   501G   129G  /zstorage/vms
zstorage/vms/archived              7.15G   501G  7.15G  /zstorage/vms/archived
zstorage/vms/git                   24.6G   501G    23K  /zstorage/vms/git
zstorage/vms/git/disk0             24.2G   501G  19.5G  -
zstorage/vms/git/disk1              449M   501G   446M  -
zstorage/vms/home-assistant        40.1G   501G    24K  /zstorage/vms/home-assistant
zstorage/vms/home-assistant/disk0  40.1G   501G  37.7G  -
zstorage/vms/house                 23.2G   501G    23K  /zstorage/vms/house
zstorage/vms/house/disk0           23.2G   501G  20.1G  -
zstorage/vms/nextcloud             30.2G   501G    23K  /zstorage/vms/nextcloud
zstorage/vms/nextcloud/disk0       30.2G   501G  29.6G  -
zstorage/vms/services              58.1G   501G    23K  /zstorage/vms/services
zstorage/vms/services/disk0        40.7G   501G  38.9G  -
zstorage/vms/services/disk1        17.5G   501G  17.5G  -
(snip ...)

on system B, the pools are a pool of mirrors, nothing fancy really

$ sudo zpool status  | grep -v ata
  pool: zfsmain
 state: ONLINE
status: Some supported features are not enabled on the pool. The pool can
	still be used, but some features are unavailable.
action: Enable all features using 'zpool upgrade'. Once this is done,
	the pool may no longer be accessible by software that does not support
	the features. See zpool-features(5) for details.
  scan: scrub repaired 0B in 1h55m with 0 errors on Sun Dec  8 02:19:22 2019
config:

	NAME                                                STATE     READ WRITE CKSUM
	zfsmain                                             ONLINE       0     0     0
	  mirror-0                                          ONLINE       0     0     0


  pool: zstuff
 state: ONLINE
  scan: resilvered 2.09T in 5h32m with 0 errors on Sat Dec 14 22:10:26 2019
config:

	NAME                                            STATE     READ WRITE CKSUM
	zstuff                                          ONLINE       0     0     0
	  mirror-0                                      ONLINE       0     0     0
	  mirror-1                                      ONLINE       0     0     0
	  mirror-2                                      ONLINE       0     0     0
	  mirror-3                                      ONLINE       0     0     0
	  mirror-4                                      ONLINE       0     0     0


  pool: zstorage
 state: ONLINE
  scan: scrub repaired 0B in 14h21m with 0 errors on Sun Dec  8 14:45:22 2019
config:

	NAME                                   STATE     READ WRITE CKSUM
	zstorage                               ONLINE       0     0     0
	  mirror-0                             ONLINE       0     0     0


  pool: ztank
 state: ONLINE
  scan: scrub repaired 0B in 6h22m with 0 errors on Sat Dec 21 08:52:32 2019
config:

	NAME                                          STATE     READ WRITE CKSUM
	ztank                                         ONLINE       0     0     0
	  mirror-0                                    ONLINE       0     0     0

$ zfs list -t filesystem | wc -l
27

on system B, we aren't using root boot on zfs (it is MDADM)

it is worth noting I saw #7659 and #7734

On system A (the VM one) when the ZVOLs were on the same pool as the root boot, these locks were FREQUENT, and in fact I may have been hit by #7734 directly (but since I isolated the VM ZVOLs on a different hardware pool, ... haven't had the issue as prominantly)

I don't think #7659 applies as I'm not using LXD.

Only a few datasets have dedup on fwiw (systemB); systemA doesn't have dedup on at all.
@jspuij
Copy link

jspuij commented Jan 1, 2020

I have exactly the same issue. Strack trace:

[ 4592.540832] INFO: task txg_sync:1216 blocked for more than 120 seconds.
[ 4592.540840]       Tainted: P        W  O      5.3.13-1-pve #1
[ 4592.540843] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 4592.540847] txg_sync        D    0  1216      2 0x80004000
[ 4592.540851] Call Trace:
[ 4592.540860]  __schedule+0x2bb/0x660
[ 4592.540936]  ? zio_taskq_member.isra.12.constprop.17+0x70/0x70 [zfs]
[ 4592.540939]  schedule+0x33/0xa0
[ 4592.540942]  schedule_timeout+0x152/0x300
[ 4592.540946]  ? __next_timer_interrupt+0xd0/0xd0
[ 4592.540949]  io_schedule_timeout+0x1e/0x50
[ 4592.540956]  __cv_timedwait_common+0x12f/0x170 [spl]
[ 4592.540960]  ? wait_woken+0x80/0x80
[ 4592.540966]  __cv_timedwait_io+0x19/0x20 [spl]
[ 4592.541036]  zio_wait+0x13a/0x280 [zfs]
[ 4592.541038]  ? _cond_resched+0x19/0x30
[ 4592.541101]  dsl_pool_sync+0xdc/0x4f0 [zfs]
[ 4592.541171]  spa_sync+0x5b2/0xfc0 [zfs]
[ 4592.541242]  ? spa_txg_history_init_io+0x106/0x110 [zfs]
[ 4592.541313]  txg_sync_thread+0x2d9/0x4c0 [zfs]
[ 4592.541384]  ? txg_thread_exit.isra.12+0x60/0x60 [zfs]
[ 4592.541395]  thread_generic_wrapper+0x74/0x90 [spl]
[ 4592.541398]  kthread+0x120/0x140
[ 4592.541407]  ? __thread_exit+0x20/0x20 [spl]
[ 4592.541409]  ? __kthread_parkme+0x70/0x70
[ 4592.541412]  ret_from_fork+0x22/0x40

root@pve:~# uname -a
Linux pve 5.3.13-1-pve #1 SMP PVE 5.3.13-1 (Thu, 05 Dec 2019 07:18:14 +0100) x86_64 GNU/Linux

@PrivatePuffin
Copy link
Contributor

PrivatePuffin commented Jan 1, 2020 •
edited
Loading

@jspuij Having the same error (and hang) does not mean it has the same cause...
periodic txg_sync zfs tasks blocked can be caused by a multitude of issues.

I cant find much of your stacktrace besides ret_from_fork to be the same as OP...

@fermulator Do you have the same running 0.8.*?

@AgeManning
Copy link

AgeManning commented Jan 2, 2020 •
edited
Loading

I have the same issue, originally caused #9747.
I've posted my logs which match others found in this thread.

For me, I'm using:
linux kernel: 5.4.6
zfs: 0.8.2-1
spl: 0.8.2-1

This seems to occur when performing large writes to the pool.

[ 2826.471870]       Tainted: P           OE     5.4.6-arch3-1 #1
[ 2826.473297] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 2826.474804] txg_sync        D    0  1248      2 0x80004080
[ 2826.474808] Call Trace:
[ 2826.474822]  ? __schedule+0x2f3/0x770
[ 2826.474825]  schedule+0x43/0xd0
[ 2826.474828]  schedule_timeout+0x173/0x310
[ 2826.474833]  ? __next_timer_interrupt+0xd0/0xd0
[ 2826.474836]  io_schedule_timeout+0x19/0x40
[ 2826.474846]  __cv_timedwait_common+0x123/0x160 [spl]
[ 2826.474850]  ? wait_woken+0x70/0x70
[ 2826.474932]  zio_wait+0x13a/0x280 [zfs]
[ 2826.474993]  dsl_pool_sync+0xd4/0x4d0 [zfs]
[ 2826.475063]  spa_sync+0x57d/0xf70 [zfs]
[ 2826.475067]  ? _raw_spin_unlock+0x16/0x30
[ 2826.475132]  ? spa_txg_history_init_io+0x112/0x120 [zfs]
[ 2826.475197]  txg_sync_thread+0x2d3/0x4b0 [zfs]
[ 2826.475202]  ? finish_task_switch+0x80/0x270
[ 2826.475268]  ? txg_thread_exit.isra.0+0x60/0x60 [zfs]
[ 2826.475277]  thread_generic_wrapper+0x6f/0x80 [spl]
[ 2826.475282]  kthread+0xfb/0x130
[ 2826.475290]  ? __thread_exit+0x20/0x20 [spl]
[ 2826.475292]  ? kthread_park+0x90/0x90
[ 2826.475294]  ret_from_fork+0x35/0x40

@jspuij
Copy link

jspuij commented Jan 2, 2020 •
edited
Loading

@Ornias1993 See: #9800

Kernel version and zfs version in the issue. But it definitely happens on 0.8.2 too.

@PrivatePuffin
Copy link
Contributor

@jspuij thanks for the 0.8.* confirmation

@behlendorf we are slowly more and more getting flooded on those errors...

@PrivatePuffin
Copy link
Contributor

@fixyourcodeplease222 Welcome to the ZFSonLinux repository.
like you can see, it's not only an issue with kernel > 5.0.

4.15.0-70

@fermulator
Copy link
Author

@fermulator Do you have the same running 0.8.*?

@Ornias1993 no, I'm afraid I'm not quite ready to upgrade to 0.8.* - both my systems are sticking on Ubuntu 18.04 LTS stable channels, which currently puts me at 0.7.5

@yifan-gu
Copy link

yifan-gu commented Feb 15, 2020 •
edited
Loading

Confirming the similar issue on Ubuntu 18.04 LTS with ZFS 0.7.5. It happens quite frequently for us, like once / day.

Feb  9 14:14:51 backup kernel: [49127.094629] INFO: task zfs:25510 blocked for more than 120 seconds.
Feb  9 14:14:51 backup kernel: [49127.097527]       Tainted: P           O     4.15.0-1052-aws #54-Ubuntu
Feb  9 14:14:51 backup kernel: [49127.100535] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Feb  9 14:14:51 backup kernel: [49127.104089] zfs             D    0 25510  25498 0x80000000
Feb  9 14:14:51 backup kernel: [49127.104092] Call Trace:
Feb  9 14:14:51 backup kernel: [49127.104099]  __schedule+0x24e/0x880
Feb  9 14:14:51 backup kernel: [49127.104100]  schedule+0x2c/0x80
Feb  9 14:14:51 backup kernel: [49127.104107]  cv_wait_common+0x11e/0x140 [spl]
Feb  9 14:14:51 backup kernel: [49127.104111]  ? wait_woken+0x80/0x80
Feb  9 14:14:51 backup kernel: [49127.104115]  __cv_wait+0x15/0x20 [spl]
Feb  9 14:14:51 backup kernel: [49127.104155]  bqueue_enqueue+0x62/0xe0 [zfs]
Feb  9 14:14:51 backup kernel: [49127.104183]  dmu_recv_stream+0x548/0xef0 [zfs]
Feb  9 14:14:51 backup kernel: [49127.104214]  zfs_ioc_recv_impl+0x306/0x1100 [zfs]
Feb  9 14:14:51 backup kernel: [49127.104236]  ? dmu_zfetch+0x49a/0x500 [zfs]
Feb  9 14:14:51 backup kernel: [49127.104238]  ? mutex_lock+0x12/0x40
Feb  9 14:14:51 backup kernel: [49127.104266]  zfs_ioc_recv+0x1e9/0x330 [zfs]
Feb  9 14:14:51 backup kernel: [49127.104270]  ? security_capable+0x4e/0x70
Feb  9 14:14:51 backup kernel: [49127.104272]  ? ns_capable_common+0x68/0x80
Feb  9 14:14:51 backup kernel: [49127.104273]  ? capable+0x1c/0x20
Feb  9 14:14:51 backup kernel: [49127.104299]  ? priv_policy.isra.3.part.4+0x11/0x20 [zfs]
Feb  9 14:14:51 backup kernel: [49127.104324]  ? secpolicy_zinject+0x3a/0x40 [zfs]
Feb  9 14:14:51 backup kernel: [49127.104326]  ? _cond_resched+0x19/0x40
Feb  9 14:14:51 backup kernel: [49127.104328]  ? __kmalloc+0x19b/0x220
Feb  9 14:14:51 backup kernel: [49127.104331]  ? strdup+0x45/0x70 [spl]
Feb  9 14:14:51 backup kernel: [49127.104358]  zfsdev_ioctl+0x1e0/0x610 [zfs]
Feb  9 14:14:51 backup kernel: [49127.104361]  do_vfs_ioctl+0xa8/0x630
Feb  9 14:14:51 backup kernel: [49127.104363]  ? __do_page_fault+0x2a1/0x4b0
Feb  9 14:14:51 backup kernel: [49127.104365]  SyS_ioctl+0x79/0x90
Feb  9 14:14:51 backup kernel: [49127.104367]  do_syscall_64+0x73/0x130
Feb  9 14:14:51 backup kernel: [49127.104369]  entry_SYSCALL_64_after_hwframe+0x3d/0xa2

Feb 11 21:21:37 backup kernel: [247533.418511] INFO: task txg_sync:18222 blocked for more than 120 seconds.
Feb 11 21:21:37 backup kernel: [247533.423012]       Tainted: P           O     4.15.0-1052-aws #54-Ubuntu
Feb 11 21:21:37 backup kernel: [247533.427464] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Feb 11 21:21:37 backup kernel: [247533.433838] txg_sync        D    0 18222      2 0x80000000
Feb 11 21:21:37 backup kernel: [247533.433840] Call Trace:
Feb 11 21:21:37 backup kernel: [247533.433843]  __schedule+0x24e/0x880
Feb 11 21:21:37 backup kernel: [247533.433845]  schedule+0x2c/0x80
Feb 11 21:21:37 backup kernel: [247533.433854]  cv_wait_common+0x11e/0x140 [spl]
Feb 11 21:21:37 backup kernel: [247533.433857]  ? wait_woken+0x80/0x80
Feb 11 21:21:37 backup kernel: [247533.433861]  __cv_wait+0x15/0x20 [spl]
Feb 11 21:21:37 backup kernel: [247533.433894]  rrw_enter_write+0x3c/0xa0 [zfs]
Feb 11 21:21:37 backup kernel: [247533.433920]  rrw_enter+0x13/0x20 [zfs]
Feb 11 21:21:37 backup kernel: [247533.433946]  spa_sync+0x7c9/0xd80 [zfs]
Feb 11 21:21:37 backup kernel: [247533.433974]  txg_sync_thread+0x2cd/0x4a0 [zfs]
Feb 11 21:21:37 backup kernel: [247533.433976]  ? __switch_to_asm+0x35/0x70
Feb 11 21:21:37 backup kernel: [247533.434002]  ? txg_quiesce_thread+0x3d0/0x3d0 [zfs]
Feb 11 21:21:37 backup kernel: [247533.434005]  thread_generic_wrapper+0x74/0x90 [spl]
Feb 11 21:21:37 backup kernel: [247533.434007]  kthread+0x121/0x140
Feb 11 21:21:37 backup kernel: [247533.434009]  ? __thread_exit+0x20/0x20 [spl]
Feb 11 21:21:37 backup kernel: [247533.434010]  ? kthread_create_worker_on_cpu+0x70/0x70
Feb 11 21:21:37 backup kernel: [247533.434011]  ret_from_fork+0x35/0x40

Feb 12 13:46:51 backup kernel: [56857.873486] INFO: task txg_sync:4209 blocked for more than 120 seconds.
Feb 12 13:46:51 backup kernel: [56857.876444]       Tainted: P           O     4.15.0-1052-aws #54-Ubuntu
Feb 12 13:46:51 backup kernel: [56857.879393] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Feb 12 13:46:51 backup kernel: [56857.882822] txg_sync        D    0  4209      2 0x80000000
Feb 12 13:46:51 backup kernel: [56857.882824] Call Trace:
Feb 12 13:46:51 backup kernel: [56857.882829]  __schedule+0x24e/0x880
Feb 12 13:46:51 backup kernel: [56857.882832]  schedule+0x2c/0x80
Feb 12 13:46:51 backup kernel: [56857.882839]  cv_wait_common+0x11e/0x140 [spl]
Feb 12 13:46:51 backup kernel: [56857.882844]  ? wait_woken+0x80/0x80
Feb 12 13:46:51 backup kernel: [56857.882851]  __cv_wait+0x15/0x20 [spl]
Feb 12 13:46:51 backup kernel: [56857.882889]  rrw_enter_write+0x3c/0xa0 [zfs]
Feb 12 13:46:51 backup kernel: [56857.882919]  rrw_enter+0x13/0x20 [zfs]
Feb 12 13:46:51 backup kernel: [56857.882954]  spa_sync+0x7c9/0xd80 [zfs]
Feb 12 13:46:51 backup kernel: [56857.882985]  txg_sync_thread+0x2cd/0x4a0 [zfs]
Feb 12 13:46:51 backup kernel: [56857.882987]  ? __switch_to_asm+0x35/0x70
Feb 12 13:46:51 backup kernel: [56857.883023]  ? txg_quiesce_thread+0x3d0/0x3d0 [zfs]
Feb 12 13:46:51 backup kernel: [56857.883027]  thread_generic_wrapper+0x74/0x90 [spl]
Feb 12 13:46:51 backup kernel: [56857.883029]  kthread+0x121/0x140
Feb 12 13:46:51 backup kernel: [56857.883032]  ? __thread_exit+0x20/0x20 [spl]
Feb 12 13:46:51 backup kernel: [56857.883033]  ? kthread_create_worker_on_cpu+0x70/0x70
Feb 12 13:46:51 backup kernel: [56857.883034]  ret_from_fork+0x35/0x40

@gattytto
Copy link

gattytto commented May 18, 2020 •
edited
Loading 

zfs-0.8.4-pve1
zfs-kmod-0.8.4-pve1
kernel 5.4.41-1-pve

steps to reproduce in my case: copy big file from host in rpool to vm within raid0 pool using jumbo frames.

May 18 01:09:41 pc kernel: [93504.616531] perf: interrupt took too long (2501 > 2500), lowering kernel.perf_event_max_sample_rate to 79750
May 18 06:14:06 pc kernel: [111769.934928] zvol            D    0   351      2 0x80004000
May 18 06:14:06 pc kernel: [111769.934930] Call Trace:
May 18 06:14:06 pc kernel: [111769.934934]  __schedule+0x2e6/0x6f0
May 18 06:14:06 pc kernel: [111769.934936]  schedule+0x33/0xa0
May 18 06:14:06 pc kernel: [111769.934941]  cv_wait_common+0x104/0x130 [spl]
May 18 06:14:06 pc kernel: [111769.934943]  ? wait_woken+0x80/0x80
May 18 06:14:06 pc kernel: [111769.934946]  __cv_wait+0x15/0x20 [spl]
May 18 06:14:06 pc kernel: [111769.934973]  dmu_buf_hold_array_by_dnode+0x1c4/0x480 [zfs]
May 18 06:14:06 pc kernel: [111769.934991]  dmu_read_uio_dnode+0x49/0xf0 [zfs]
May 18 06:14:06 pc kernel: [111769.934994]  ? generic_start_io_acct+0x101/0x120
May 18 06:14:06 pc kernel: [111769.935020]  zvol_read+0x101/0x2d0 [zfs]
May 18 06:14:06 pc kernel: [111769.935024]  taskq_thread+0x2ec/0x4d0 [spl]
May 18 06:14:06 pc kernel: [111769.935026]  ? wake_up_q+0x80/0x80
May 18 06:14:06 pc kernel: [111769.935029]  kthread+0x120/0x140
May 18 06:14:06 pc kernel: [111769.935032]  ? task_done+0xb0/0xb0 [spl]
May 18 06:14:06 pc kernel: [111769.935034]  ? kthread_park+0x90/0x90
May 18 06:14:06 pc kernel: [111769.935035]  ret_from_fork+0x35/0x40
May 18 06:14:06 pc kernel: [111769.935041] l2arc_feed      D    0   358      2 0x80004000
May 18 06:14:06 pc kernel: [111769.935043] Call Trace:
May 18 06:14:06 pc kernel: [111769.935045]  __schedule+0x2e6/0x6f0
May 18 06:14:06 pc kernel: [111769.935047]  schedule+0x33/0xa0
May 18 06:14:06 pc kernel: [111769.935048]  schedule_timeout+0x152/0x300
May 18 06:14:06 pc kernel: [111769.935050]  ? __next_timer_interrupt+0xd0/0xd0
May 18 06:14:06 pc kernel: [111769.935052]  io_schedule_timeout+0x1e/0x50
May 18 06:14:06 pc kernel: [111769.935054]  __cv_timedwait_common+0x12f/0x170 [spl]
May 18 06:14:06 pc kernel: [111769.935056]  ? wait_woken+0x80/0x80
May 18 06:14:06 pc kernel: [111769.935059]  __cv_timedwait_io+0x19/0x20 [spl]
May 18 06:14:06 pc kernel: [111769.935085]  zio_wait+0x130/0x270 [zfs]
May 18 06:14:06 pc kernel: [111769.935110]  ? zio_issue_async+0x12/0x20 [zfs]
May 18 06:14:06 pc kernel: [111769.935124]  l2arc_feed_thread+0x9a8/0x1090 [zfs]
May 18 06:14:06 pc kernel: [111769.935126]  ? __switch_to_asm+0x34/0x70
May 18 06:14:06 pc kernel: [111769.935127]  ? __switch_to_asm+0x40/0x70
May 18 06:14:06 pc kernel: [111769.935129]  ? syscall_return_via_sysret+0x19/0x7f
May 18 06:14:06 pc kernel: [111769.935143]  ? l2arc_evict+0x2b0/0x2b0 [zfs]
May 18 06:14:06 pc kernel: [111769.935146]  thread_generic_wrapper+0x74/0x90 [spl]
May 18 06:14:06 pc kernel: [111769.935148]  kthread+0x120/0x140
May 18 06:14:06 pc kernel: [111769.935151]  ? __thread_exit+0x20/0x20 [spl]
May 18 06:14:06 pc kernel: [111769.935153]  ? kthread_park+0x90/0x90
May 18 06:14:06 pc kernel: [111769.935155]  ret_from_fork+0x35/0x40
May 18 06:14:06 pc kernel: [111769.935172] txg_sync        D    0  1714      2 0x80004000
May 18 06:14:06 pc kernel: [111769.935174] Call Trace:
May 18 06:14:06 pc kernel: [111769.935175]  __schedule+0x2e6/0x6f0
May 18 06:14:06 pc kernel: [111769.935177]  schedule+0x33/0xa0
May 18 06:14:06 pc kernel: [111769.935178]  schedule_timeout+0x152/0x300
May 18 06:14:06 pc kernel: [111769.935180]  ? __next_timer_interrupt+0xd0/0xd0
May 18 06:14:06 pc kernel: [111769.935182]  io_schedule_timeout+0x1e/0x50
May 18 06:14:06 pc kernel: [111769.935184]  __cv_timedwait_common+0x12f/0x170 [spl]
May 18 06:14:06 pc kernel: [111769.935186]  ? wait_woken+0x80/0x80
May 18 06:14:06 pc kernel: [111769.935189]  __cv_timedwait_io+0x19/0x20 [spl]
May 18 06:14:06 pc kernel: [111769.935214]  zio_wait+0x130/0x270 [zfs]
May 18 06:14:06 pc kernel: [111769.935229]  dbuf_read+0x4e1/0xb80 [zfs]
May 18 06:14:06 pc kernel: [111769.935244]  dbuf_hold_impl_arg+0x4ca/0x640 [zfs]
May 18 06:14:06 pc kernel: [111769.935259]  dbuf_hold_impl+0x9a/0xc0 [zfs]
May 18 06:14:06 pc kernel: [111769.935273]  dbuf_hold+0x33/0x60 [zfs]
May 18 06:14:06 pc kernel: [111769.935289]  dmu_buf_hold_array_by_dnode+0xe1/0x480 [zfs]
May 18 06:14:06 pc kernel: [111769.935305]  dmu_write.part.10+0x6a/0x100 [zfs]
May 18 06:14:06 pc kernel: [111769.935307]  ? mutex_lock+0x12/0x30
May 18 06:14:06 pc kernel: [111769.935322]  dmu_write+0x14/0x20 [zfs]
May 18 06:14:06 pc kernel: [111769.935347]  space_map_write+0x152/0x600 [zfs]
May 18 06:14:06 pc kernel: [111769.935349]  ? ktime_get_raw_ts64+0x38/0xd0
May 18 06:14:06 pc kernel: [111769.935351]  ? mutex_lock+0x12/0x30
May 18 06:14:06 pc kernel: [111769.935373]  metaslab_sync+0x473/0xc50 [zfs]
May 18 06:14:06 pc kernel: [111769.935375]  ? _cond_resched+0x19/0x30
May 18 06:14:06 pc kernel: [111769.935377]  ? mutex_lock+0x12/0x30
May 18 06:14:06 pc kernel: [111769.935401]  vdev_sync+0x6f/0x1e0 [zfs]
May 18 06:14:06 pc kernel: [111769.935425]  spa_sync+0x62f/0xfa0 [zfs]
May 18 06:14:06 pc kernel: [111769.935449]  ? spa_txg_history_init_io+0x104/0x110 [zfs]
May 18 06:14:06 pc kernel: [111769.935474]  txg_sync_thread+0x2d9/0x4c0 [zfs]
May 18 06:14:06 pc kernel: [111769.935498]  ? txg_thread_exit.isra.12+0x60/0x60 [zfs]
May 18 06:14:06 pc kernel: [111769.935502]  thread_generic_wrapper+0x74/0x90 [spl]
May 18 06:14:06 pc kernel: [111769.935504]  kthread+0x120/0x140
May 18 06:14:06 pc kernel: [111769.935507]  ? __thread_exit+0x20/0x20 [spl]
May 18 06:14:06 pc kernel: [111769.935509]  ? kthread_park+0x90/0x90
May 18 06:14:06 pc kernel: [111769.935510]  ret_from_fork+0x35/0x40
May 18 06:14:06 pc kernel: [111769.935525] zvol            D    0 21457      2 0x80004000
May 18 06:14:06 pc kernel: [111769.935527] Call Trace:
May 18 06:14:06 pc kernel: [111769.935529]  __schedule+0x2e6/0x6f0
May 18 06:14:06 pc kernel: [111769.935531]  schedule+0x33/0xa0
May 18 06:14:06 pc kernel: [111769.935532]  schedule_timeout+0x152/0x300
May 18 06:14:06 pc kernel: [111769.935533]  ? __next_timer_interrupt+0xd0/0xd0
May 18 06:14:06 pc kernel: [111769.935535]  io_schedule_timeout+0x1e/0x50
May 18 06:14:06 pc kernel: [111769.935538]  __cv_timedwait_common+0x12f/0x170 [spl]
May 18 06:14:06 pc kernel: [111769.935540]  ? wait_woken+0x80/0x80
May 18 06:14:06 pc kernel: [111769.935542]  __cv_timedwait_io+0x19/0x20 [spl]
May 18 06:14:06 pc kernel: [111769.935568]  zio_wait+0x130/0x270 [zfs]
May 18 06:14:06 pc kernel: [111769.935584]  dmu_buf_hold_array_by_dnode+0x15a/0x480 [zfs]
May 18 06:14:06 pc kernel: [111769.935601]  dmu_read_uio_dnode+0x49/0xf0 [zfs]
May 18 06:14:06 pc kernel: [111769.935603]  ? generic_start_io_acct+0x101/0x120
May 18 06:14:06 pc kernel: [111769.935628]  zvol_read+0x101/0x2d0 [zfs]
May 18 06:14:06 pc kernel: [111769.935632]  taskq_thread+0x2ec/0x4d0 [spl]
May 18 06:14:06 pc kernel: [111769.935634]  ? wake_up_q+0x80/0x80
May 18 06:14:06 pc kernel: [111769.935636]  kthread+0x120/0x140
May 18 06:14:06 pc kernel: [111769.935639]  ? task_done+0xb0/0xb0 [spl]
May 18 06:14:06 pc kernel: [111769.935641]  ? kthread_park+0x90/0x90
May 18 06:14:06 pc kernel: [111769.935642]  ret_from_fork+0x35/0x40
May 18 06:14:06 pc kernel: [111769.935647] zvol            D    0 21459      2 0x80004000
May 18 06:14:06 pc kernel: [111769.935648] Call Trace:
May 18 06:14:06 pc kernel: [111769.935650]  __schedule+0x2e6/0x6f0
May 18 06:14:06 pc kernel: [111769.935652]  schedule+0x33/0xa0
May 18 06:14:06 pc kernel: [111769.935654]  cv_wait_common+0x104/0x130 [spl]
May 18 06:14:06 pc kernel: [111769.935656]  ? wait_woken+0x80/0x80
May 18 06:14:06 pc kernel: [111769.935658]  __cv_wait+0x15/0x20 [spl]
May 18 06:14:06 pc kernel: [111769.935674]  dmu_buf_hold_array_by_dnode+0x1c4/0x480 [zfs]
May 18 06:14:06 pc kernel: [111769.935690]  dmu_read_uio_dnode+0x49/0xf0 [zfs]
May 18 06:14:06 pc kernel: [111769.935692]  ? generic_start_io_acct+0x101/0x120
May 18 06:14:06 pc kernel: [111769.935717]  zvol_read+0x101/0x2d0 [zfs]
May 18 06:14:06 pc kernel: [111769.935721]  taskq_thread+0x2ec/0x4d0 [spl]
May 18 06:14:06 pc kernel: [111769.935723]  ? wake_up_q+0x80/0x80
May 18 06:14:06 pc kernel: [111769.935725]  kthread+0x120/0x140
May 18 06:14:06 pc kernel: [111769.935728]  ? task_done+0xb0/0xb0 [spl]
May 18 06:14:06 pc kernel: [111769.935730]  ? kthread_park+0x90/0x90
May 18 06:14:06 pc kernel: [111769.935731]  ret_from_fork+0x35/0x40
May 18 06:14:06 pc kernel: [111769.935736] zvol            D    0 21460      2 0x80004000
May 18 06:14:06 pc kernel: [111769.935737] Call Trace:
May 18 06:14:06 pc kernel: [111769.935739]  __schedule+0x2e6/0x6f0
May 18 06:14:06 pc kernel: [111769.935741]  schedule+0x33/0xa0
May 18 06:14:06 pc kernel: [111769.935743]  cv_wait_common+0x104/0x130 [spl]
May 18 06:14:06 pc kernel: [111769.935745]  ? wait_woken+0x80/0x80
May 18 06:14:06 pc kernel: [111769.935747]  __cv_wait+0x15/0x20 [spl]
May 18 06:14:06 pc kernel: [111769.935763]  dmu_buf_hold_array_by_dnode+0x1c4/0x480 [zfs]
May 18 06:14:06 pc kernel: [111769.935779]  dmu_read_uio_dnode+0x49/0xf0 [zfs]
May 18 06:14:06 pc kernel: [111769.935782]  ? generic_start_io_acct+0x101/0x120
May 18 06:14:06 pc kernel: [111769.935806]  zvol_read+0x101/0x2d0 [zfs]
May 18 06:14:06 pc kernel: [111769.935810]  taskq_thread+0x2ec/0x4d0 [spl]
May 18 06:14:06 pc kernel: [111769.935812]  ? wake_up_q+0x80/0x80
May 18 06:14:06 pc kernel: [111769.935814]  kthread+0x120/0x140
May 18 06:14:06 pc kernel: [111769.935817]  ? task_done+0xb0/0xb0 [spl]
May 18 06:14:06 pc kernel: [111769.935819]  ? kthread_park+0x90/0x90
May 18 06:14:06 pc kernel: [111769.935820]  ret_from_fork+0x35/0x40
May 18 06:14:06 pc kernel: [111769.935825] zvol            D    0 21461      2 0x80004000
May 18 06:14:06 pc kernel: [111769.935826] Call Trace:
May 18 06:14:06 pc kernel: [111769.935828]  __schedule+0x2e6/0x6f0
May 18 06:14:06 pc kernel: [111769.935830]  schedule+0x33/0xa0
May 18 06:14:06 pc kernel: [111769.935832]  cv_wait_common+0x104/0x130 [spl]
May 18 06:14:06 pc kernel: [111769.935834]  ? wait_woken+0x80/0x80
May 18 06:14:06 pc kernel: [111769.935837]  __cv_wait+0x15/0x20 [spl]
May 18 06:14:06 pc kernel: [111769.935852]  dmu_buf_hold_array_by_dnode+0x1c4/0x480 [zfs]
May 18 06:14:06 pc kernel: [111769.935868]  dmu_read_uio_dnode+0x49/0xf0 [zfs]
May 18 06:14:06 pc kernel: [111769.935870]  ? generic_start_io_acct+0x101/0x120
May 18 06:14:06 pc kernel: [111769.935895]  zvol_read+0x101/0x2d0 [zfs]
May 18 06:14:06 pc kernel: [111769.935899]  taskq_thread+0x2ec/0x4d0 [spl]
May 18 06:14:06 pc kernel: [111769.935901]  ? wake_up_q+0x80/0x80
May 18 06:14:06 pc kernel: [111769.935903]  kthread+0x120/0x140
May 18 06:14:06 pc kernel: [111769.935906]  ? task_done+0xb0/0xb0 [spl]
May 18 06:14:06 pc kernel: [111769.935908]  ? kthread_park+0x90/0x90
May 18 06:14:06 pc kernel: [111769.935909]  ret_from_fork+0x35/0x40
May 18 06:14:06 pc kernel: [111769.935914] zvol            D    0 21462      2 0x80004000
May 18 06:14:06 pc kernel: [111769.935915] Call Trace:
May 18 06:14:06 pc kernel: [111769.935917]  __schedule+0x2e6/0x6f0
May 18 06:14:06 pc kernel: [111769.935919]  schedule+0x33/0xa0
May 18 06:14:06 pc kernel: [111769.935920]  schedule_timeout+0x152/0x300
May 18 06:14:06 pc kernel: [111769.935922]  ? __next_timer_interrupt+0xd0/0xd0
May 18 06:14:06 pc kernel: [111769.935923]  io_schedule_timeout+0x1e/0x50
May 18 06:14:06 pc kernel: [111769.935926]  __cv_timedwait_common+0x12f/0x170 [spl]
May 18 06:14:06 pc kernel: [111769.935928]  ? wait_woken+0x80/0x80
May 18 06:14:06 pc kernel: [111769.935930]  __cv_timedwait_io+0x19/0x20 [spl]
May 18 06:14:06 pc kernel: [111769.935955]  zio_wait+0x130/0x270 [zfs]
May 18 06:14:06 pc kernel: [111769.935972]  dmu_buf_hold_array_by_dnode+0x15a/0x480 [zfs]
May 18 06:14:06 pc kernel: [111769.935988]  dmu_read_uio_dnode+0x49/0xf0 [zfs]
May 18 06:14:06 pc kernel: [111769.935990]  ? generic_start_io_acct+0x101/0x120
May 18 06:14:06 pc kernel: [111769.936015]  zvol_read+0x101/0x2d0 [zfs]
May 18 06:14:06 pc kernel: [111769.936019]  taskq_thread+0x2ec/0x4d0 [spl]
May 18 06:14:06 pc kernel: [111769.936021]  ? wake_up_q+0x80/0x80
May 18 06:14:06 pc kernel: [111769.936023]  kthread+0x120/0x140
May 18 06:14:06 pc kernel: [111769.936026]  ? task_done+0xb0/0xb0 [spl]
May 18 06:14:06 pc kernel: [111769.936028]  ? kthread_park+0x90/0x90
May 18 06:14:06 pc kernel: [111769.936029]  ret_from_fork+0x35/0x40
May 18 06:14:06 pc kernel: [111769.936034] zvol            D    0 21471      2 0x80004000
May 18 06:14:06 pc kernel: [111769.936035] Call Trace:
May 18 06:14:06 pc kernel: [111769.936037]  __schedule+0x2e6/0x6f0
May 18 06:14:06 pc kernel: [111769.936039]  schedule+0x33/0xa0
May 18 06:14:06 pc kernel: [111769.936041]  cv_wait_common+0x104/0x130 [spl]
May 18 06:14:06 pc kernel: [111769.936043]  ? wait_woken+0x80/0x80
May 18 06:14:06 pc kernel: [111769.936045]  __cv_wait+0x15/0x20 [spl]
May 18 06:14:06 pc kernel: [111769.936061]  dmu_buf_hold_array_by_dnode+0x1c4/0x480 [zfs]
May 18 06:14:06 pc kernel: [111769.936077]  dmu_read_uio_dnode+0x49/0xf0 [zfs]
May 18 06:14:06 pc kernel: [111769.936080]  ? spl_kmem_alloc+0xec/0x140 [spl]
May 18 06:14:06 pc kernel: [111769.936082]  ? generic_start_io_acct+0x101/0x120
May 18 06:14:06 pc kernel: [111769.936107]  zvol_read+0x101/0x2d0 [zfs]
May 18 06:14:06 pc kernel: [111769.936111]  taskq_thread+0x2ec/0x4d0 [spl]
May 18 06:14:06 pc kernel: [111769.936112]  ? __switch_to_asm+0x40/0x70
May 18 06:14:06 pc kernel: [111769.936114]  ? wake_up_q+0x80/0x80
May 18 06:14:06 pc kernel: [111769.936116]  kthread+0x120/0x140
May 18 06:14:06 pc kernel: [111769.936119]  ? task_done+0xb0/0xb0 [spl]
May 18 06:14:06 pc kernel: [111769.936121]  ? kthread_park+0x90/0x90
May 18 06:14:06 pc kernel: [111769.936122]  ret_from_fork+0x35/0x40
May 18 06:14:06 pc kernel: [111769.936127] zvol            D    0 21472      2 0x80004000
May 18 06:14:06 pc kernel: [111769.936128] Call Trace:
May 18 06:14:06 pc kernel: [111769.936130]  __schedule+0x2e6/0x6f0
May 18 06:14:06 pc kernel: [111769.936132]  schedule+0x33/0xa0
May 18 06:14:06 pc kernel: [111769.936134]  cv_wait_common+0x104/0x130 [spl]
May 18 06:14:06 pc kernel: [111769.936136]  ? wait_woken+0x80/0x80
May 18 06:14:06 pc kernel: [111769.936138]  __cv_wait+0x15/0x20 [spl]
May 18 06:14:06 pc kernel: [111769.936154]  dmu_buf_hold_array_by_dnode+0x1c4/0x480 [zfs]
May 18 06:14:06 pc kernel: [111769.936170]  dmu_read_uio_dnode+0x49/0xf0 [zfs]
May 18 06:14:06 pc kernel: [111769.936173]  ? spl_kmem_alloc+0xec/0x140 [spl]
May 18 06:14:06 pc kernel: [111769.936175]  ? generic_start_io_acct+0x101/0x120
May 18 06:14:06 pc kernel: [111769.936200]  zvol_read+0x101/0x2d0 [zfs]
May 18 06:14:06 pc kernel: [111769.936204]  taskq_thread+0x2ec/0x4d0 [spl]
May 18 06:14:06 pc kernel: [111769.936205]  ? __switch_to_asm+0x40/0x70
May 18 06:14:06 pc kernel: [111769.936207]  ? wake_up_q+0x80/0x80
May 18 06:14:06 pc kernel: [111769.936209]  kthread+0x120/0x140
May 18 06:14:06 pc kernel: [111769.936212]  ? task_done+0xb0/0xb0 [spl]
May 18 06:14:06 pc kernel: [111769.936214]  ? kthread_park+0x90/0x90
May 18 06:14:06 pc kernel: [111769.936215]  ret_from_fork+0x35/0x40

@jspuij
Copy link

jspuij commented May 18, 2020 •
edited
Loading

I'll repost here, not only in my own issue, but my issue was caused by my drives being SMR (Shingled Magnetic Recording) while I was unaware as the manufacturer had not specified it in the disk specs.
see #9800.

@stale
Copy link

stale bot commented May 19, 2021

This issue has been automatically marked as "stale" because it has not had any activity for a while. It will be closed in 90 days if no further activity occurs. Thank you for your contributions.

@stale stale bot added the Status: Stale No recent activity for issue label May 19, 2021
@stale stale bot closed this as completed Aug 17, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
Status: Stale No recent activity for issue
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
7 participants
@gattytto @jspuij @yifan-gu @fermulator @AgeManning @PrivatePuffin and others