Kernel traces

For the (roughly) past 12 months, I've been experiencing the following (repeatable, nightly) kernel traces on btrfs filesystems which are under heavy (nightly backups) btrfs-receive traffic (over the network).

The problems intensify when the amount of data per second increases. If the amount of data per second is high enough, either the whole kernel locks up, or the btrfs filesystem hangs on all operations.
The oopses below were generated under moderate traffic levels and did not cause a full kernel lockup and did not make the btrfs filesystem permanently inaccessible (possibly temporarily unresponsive though).

My current way to mitigate this problem is by limiting the amount of network traffic to below 3MB/s (which is, ridiculously low, I think). Nonetheless, it should not be possible to lock up a system by increasing bandwidth to the btrfs filesystem with btrfs-receive.

Any ideas? I can apply custom patches to either test and get more output or to test possible fixes. It is on a production system, so dataloss is not an option, but I can reboot it several times a day, if necessary. I can increase the datarate to any desirable level to test if the problem reoccurs or not.

(The most recent ones are from v4.19.7):

Total devices 8 FS bytes used 8.98TiB
devid 1 size 5.46TiB used 2.49TiB path /dev/sdf
devid 2 size 5.46TiB used 2.49TiB path /dev/sdi
devid 3 size 5.46TiB used 2.49TiB path /dev/sdh
devid 4 size 5.46TiB used 2.49TiB path /dev/sdg
devid 5 size 5.46TiB used 2.49TiB path /dev/sdj
devid 6 size 5.46TiB used 2.49TiB path /dev/sdc
devid 7 size 5.46TiB used 2.49TiB path /dev/sda
devid 8 size 3.64TiB used 689.00GiB path /dev/sdb

[64389.127561] INFO: task btrfs:7518 blocked for more than 120 seconds.
[64389.132750]       Not tainted 94.19.7-srb-asrock-00001-g22c8f45edcaf #137
[64389.138421] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[64389.145126] btrfs           D    0  7518   7489 0x00000000
[64389.149481] Call Trace:
[64389.150755]  ? __schedule+0x4db/0x524
[64389.153220]  ? schedule+0x60/0x71
[64389.155342]  ? __rwsem_down_read_failed_common+0x180/0x1df
[64389.159679]  ? call_rwsem_down_read_failed+0x14/0x30
[64389.163541]  ? down_read+0x1c/0x2f
[64389.165755]  ? btrfs_ioctl_subvol_getflags+0x67/0xbb
[64389.169592]  ? btrfs_ioctl+0x2d8/0x2a51
[64389.172237]  ? current_time+0x67/0x88
[64389.174705]  ? pipe_write+0x356/0x369
[64389.177222]  ? vfs_ioctl+0x1e/0x2b
[64389.179439]  ? btrfs_ioctl_get_supported_features+0x22/0x22
[64389.183814]  ? vfs_ioctl+0x1e/0x2b
[64389.186048]  ? do_vfs_ioctl+0x523/0x54c
[64389.188742]  ? vfs_write+0xb2/0xdf
[64389.190958]  ? ksys_ioctl+0x3e/0x5d
[64389.193268]  ? __x64_sys_ioctl+0x16/0x19
[64389.196000]  ? do_syscall_64+0x4e/0x5b
[64389.198591]  ? entry_SYSCALL_64_after_hwframe+0x44/0xa9

[64512.019259] INFO: task btrfs:7828 blocked for more than 120 seconds.
[64512.024455]       Not tainted 94.19.7-srb-asrock-00001-g22c8f45edcaf #137
[64512.030109] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[64512.036781] btrfs           D    0  7828   7771 0x00000000
[64512.041123] Call Trace:
[64512.042397]  ? __schedule+0x4db/0x524
[64512.044865]  ? schedule+0x60/0x71
[64512.046988]  ? __rwsem_down_write_failed_common+0x2ff/0x382
[64512.051443]  ? update_cfs_rq_load_avg+0x124/0x150
[64512.054964]  ? check_preempt_wakeup+0xfd/0x146
[64512.058222]  ? call_rwsem_down_write_failed+0x13/0x20
[64512.062125]  ? down_write+0x29/0x38
[64512.064429]  ? _btrfs_ioctl_set_received_subvol+0x90/0x2ab
[64512.068725]  ? btrfs_ioctl+0x1572/0x2a51
[64512.071508]  ? current_time+0x67/0x88
[64512.073992]  ? __switch_to_asm+0x40/0x70
[64512.076723]  ? __switch_to_asm+0x34/0x70
[64512.079504]  ? __switch_to_asm+0x40/0x70
[64512.082235]  ? __switch_to_asm+0x34/0x70
[64512.084963]  ? __switch_to_asm+0x40/0x70
[64512.087687]  ? __switch_to_asm+0x34/0x70
[64512.090458]  ? __switch_to_asm+0x40/0x70
[64512.093202]  ? __switch_to_asm+0x34/0x70
[64512.095927]  ? __switch_to_asm+0x40/0x70
[64512.098650]  ? __switch_to_asm+0x34/0x70
[64512.101427]  ? __switch_to_asm+0x40/0x70
[64512.104164]  ? __switch_to_asm+0x34/0x70
[64512.106891]  ? __switch_to_asm+0x40/0x70
[64512.109668]  ? vfs_ioctl+0x1e/0x2b
[64512.111887]  ? btrfs_ioctl_get_supported_features+0x22/0x22
[64512.116274]  ? vfs_ioctl+0x1e/0x2b
[64512.118479]  ? do_vfs_ioctl+0x523/0x54c
[64512.121159]  ? __switch_to_asm+0x34/0x70
[64512.123905]  ? __switch_to_asm+0x40/0x70
[64512.126637]  ? __switch_to+0x1c8/0x37f
[64512.129237]  ? finish_task_switch+0x113/0x1e6
[64512.132413]  ? ksys_ioctl+0x3e/0x5d
[64512.134703]  ? __x64_sys_ioctl+0x16/0x19
[64512.137426]  ? do_syscall_64+0x4e/0x5b
[64512.140043]  ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
[64512.144084] INFO: task btrfs:7840 blocked for more than 120 seconds.
[64512.149282]       Not tainted 94.19.7-srb-asrock-00001-g22c8f45edcaf #137
[64512.154895] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[64512.161563] btrfs           D    0  7840   7691 0x00000000
[64512.165860] Call Trace:
[64512.167118]  ? __schedule+0x4db/0x524
[64512.169630]  ? schedule+0x60/0x71
[64512.171757]  ? __rwsem_down_read_failed_common+0x180/0x1df
[64512.176045]  ? call_rwsem_down_read_failed+0x14/0x30
[64512.179853]  ? down_read+0x1c/0x2f
[64512.182072]  ? btrfs_ioctl_subvol_getflags+0x67/0xbb
[64512.185858]  ? btrfs_ioctl+0x2d8/0x2a51
[64512.188503]  ? current_time+0x67/0x88
[64512.191026]  ? pipe_write+0x356/0x369
[64512.193505]  ? vfs_ioctl+0x1e/0x2b
[64512.195733]  ? btrfs_ioctl_get_supported_features+0x22/0x22
[64512.200162]  ? vfs_ioctl+0x1e/0x2b
[64512.202376]  ? do_vfs_ioctl+0x523/0x54c
[64512.205035]  ? vfs_write+0xb2/0xdf
[64512.207260]  ? ksys_ioctl+0x3e/0x5d
[64512.209600]  ? __x64_sys_ioctl+0x16/0x19
[64512.212353]  ? do_syscall_64+0x4e/0x5b
[64512.214936]  ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
[64512.219027] INFO: task btrfs:15145 blocked for more than 120 seconds.
[64512.224292]       Not tainted 94.19.7-srb-asrock-00001-g22c8f45edcaf #137
[64512.229923] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[64512.236564] btrfs           D    0 15145  15124 0x00000000
[64512.240886] Call Trace:
[64512.242157]  ? __schedule+0x4db/0x524
[64512.244638]  ? schedule+0x60/0x71
[64512.246769]  ? __rwsem_down_read_failed_common+0x180/0x1df
[64512.251116]  ? call_rwsem_down_read_failed+0x14/0x30
[64512.254907]  ? down_read+0x1c/0x2f
[64512.257144]  ? btrfs_mksubvol+0x110/0x453
[64512.259997]  ? btrfs_ioctl_snap_create_transid+0x165/0x199
[64512.264301]  ? btrfs_ioctl_snap_create_v2+0xf1/0x154
[64512.268069]  ? btrfs_ioctl+0x87f/0x2a51
[64512.270755]  ? do_filp_open+0x89/0xaf
[64512.273235]  ? get_page+0x5/0xa
[64512.275178]  ? vfs_ioctl+0x1e/0x2b
[64512.277388]  ? btrfs_ioctl_get_supported_features+0x22/0x22
[64512.281811]  ? vfs_ioctl+0x1e/0x2b
[64512.284020]  ? do_vfs_ioctl+0x523/0x54c
[64512.286677]  ? cache_from_obj+0x22/0x57
[64512.289373]  ? ksys_ioctl+0x3e/0x5d
[64512.291673]  ? __x64_sys_ioctl+0x16/0x19
[64512.294400]  ? do_syscall_64+0x4e/0x5b
[64512.296959]  ? entry_SYSCALL_64_after_hwframe+0x44/0xa9

[64634.890975] INFO: task btrfs:7823 blocked for more than 120 seconds.
[64634.896137]       Not tainted 94.19.7-srb-asrock-00001-g22c8f45edcaf #137
[64634.901800] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[64634.908461] btrfs           D    0  7823   7641 0x00000000
[64634.912806] Call Trace:
[64634.914070]  ? __schedule+0x4db/0x524
[64634.916540]  ? schedule+0x60/0x71
[64634.918656]  ? __rwsem_down_write_failed_common+0x2ff/0x382
[64634.923081]  ? apic_timer_interrupt+0xa/0x20
[64634.926193]  ? call_rwsem_down_write_failed+0x13/0x20
[64634.930053]  ? down_write+0x29/0x38
[64634.932398]  ? btrfs_ioctl_subvol_setflags+0xc5/0x1fb
[64634.936259]  ? btrfs_ioctl+0x13a/0x2a51
[64634.938943]  ? current_time+0x67/0x88
[64634.941467]  ? pipe_write+0x356/0x369
[64634.943937]  ? vfs_ioctl+0x1e/0x2b
[64634.946174]  ? btrfs_ioctl_get_supported_features+0x22/0x22
[64634.950597]  ? vfs_ioctl+0x1e/0x2b
[64634.952804]  ? do_vfs_ioctl+0x523/0x54c
[64634.965173]  ? vfs_write+0xb2/0xdf
[64634.967417]  ? ksys_ioctl+0x3e/0x5d
[64634.969712]  ? __x64_sys_ioctl+0x16/0x19
[64634.972482]  ? do_syscall_64+0x4e/0x5b
[64634.975043]  ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
[64634.979075] INFO: task btrfs:7831 blocked for more than 120 seconds.
[64634.984266]       Not tainted 94.19.7-srb-asrock-00001-g22c8f45edcaf #137
[64634.989885] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[64634.996560] btrfs           D    0  7831   7755 0x00000000
[64635.000865] Call Trace:
[64635.002126]  ? __schedule+0x4db/0x524
[64635.004608]  ? schedule+0x60/0x71
[64635.006757]  ? __rwsem_down_read_failed_common+0x180/0x1df
[64635.011092]  ? call_rwsem_down_read_failed+0x14/0x30
[64635.014876]  ? down_read+0x1c/0x2f
[64635.017087]  ? btrfs_ioctl_subvol_getflags+0x67/0xbb
[64635.020893]  ? btrfs_ioctl+0x2d8/0x2a51
[64635.023544]  ? current_time+0x67/0x88
[64635.026012]  ? __switch_to_asm+0x40/0x70
[64635.028770]  ? __switch_to_asm+0x34/0x70
[64635.031529]  ? __switch_to_asm+0x40/0x70
[64635.034261]  ? __switch_to_asm+0x34/0x70
[64635.036993]  ? __switch_to_asm+0x40/0x70
[64635.039720]  ? __switch_to_asm+0x34/0x70
[64635.042476]  ? __switch_to_asm+0x40/0x70
[64635.045210]  ? __switch_to_asm+0x34/0x70
[64635.047964]  ? __switch_to_asm+0x40/0x70
[64635.050731]  ? __switch_to_asm+0x34/0x70
[64635.053459]  ? __switch_to_asm+0x40/0x70
[64635.056188]  ? __switch_to_asm+0x34/0x70
[64635.058910]  ? __switch_to_asm+0x40/0x70
[64635.061670]  ? vfs_ioctl+0x1e/0x2b
[64635.063878]  ? btrfs_ioctl_get_supported_features+0x22/0x22
[64635.068281]  ? vfs_ioctl+0x1e/0x2b
[64635.070491]  ? do_vfs_ioctl+0x523/0x54c
[64635.073179]  ? __switch_to_asm+0x34/0x70
[64635.075913]  ? __switch_to_asm+0x40/0x70
[64635.078636]  ? __switch_to+0x1c8/0x37f
[64635.081219]  ? finish_task_switch+0x113/0x1e6
[64635.084384]  ? ksys_ioctl+0x3e/0x5d
[64635.086679]  ? __x64_sys_ioctl+0x16/0x19
[64635.089418]  ? do_syscall_64+0x4e/0x5b
[64635.092018]  ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
[64635.096062] INFO: task btrfs:7840 blocked for more than 120 seconds.
[64635.101255]       Not tainted 94.19.7-srb-asrock-00001-g22c8f45edcaf #137
[64635.106866] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[64635.113532] btrfs           D    0  7840   7691 0x00000000
[64635.117827] Call Trace:
[64635.119083]  ? __schedule+0x4db/0x524
[64635.121583]  ? schedule+0x60/0x71
[64635.123715]  ? __rwsem_down_read_failed_common+0x180/0x1df
[64635.128002]  ? call_rwsem_down_read_failed+0x14/0x30
[64635.131810]  ? down_read+0x1c/0x2f
[64635.134031]  ? btrfs_ioctl_subvol_getflags+0x67/0xbb
[64635.137815]  ? btrfs_ioctl+0x2d8/0x2a51
[64635.140457]  ? current_time+0x67/0x88
[64635.142965]  ? pipe_write+0x356/0x369
[64635.145433]  ? vfs_ioctl+0x1e/0x2b
[64635.147643]  ? btrfs_ioctl_get_supported_features+0x22/0x22
[64635.152051]  ? vfs_ioctl+0x1e/0x2b
[64635.154262]  ? do_vfs_ioctl+0x523/0x54c
[64635.156919]  ? vfs_write+0xb2/0xdf
[64635.159126]  ? ksys_ioctl+0x3e/0x5d
[64635.161448]  ? __x64_sys_ioctl+0x16/0x19
[64635.164180]  ? do_syscall_64+0x4e/0x5b
[64635.166736]  ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
[64635.170813] INFO: task btrfs:15145 blocked for more than 120 seconds.
[64635.176068]       Not tainted 94.19.7-srb-asrock-00001-g22c8f45edcaf #137
[64635.181703] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[64635.188354] btrfs           D    0 15145  15124 0x00000000
[64635.192676] Call Trace:
[64635.193939]  ? __schedule+0x4db/0x524
[64635.196410]  ? schedule+0x60/0x71
[64635.198527]  ? __rwsem_down_read_failed_common+0x180/0x1df
[64635.202854]  ? call_rwsem_down_read_failed+0x14/0x30
[64635.206651]  ? down_read+0x1c/0x2f
[64635.208858]  ? btrfs_mksubvol+0x110/0x453
[64635.211710]  ? btrfs_ioctl_snap_create_transid+0x165/0x199
[64635.216009]  ? btrfs_ioctl_snap_create_v2+0xf1/0x154
[64635.219792]  ? btrfs_ioctl+0x87f/0x2a51
[64635.222484]  ? do_filp_open+0x89/0xaf
[64635.224967]  ? get_page+0x5/0xa
[64635.226911]  ? vfs_ioctl+0x1e/0x2b
[64635.229121]  ? btrfs_ioctl_get_supported_features+0x22/0x22
[64635.233567]  ? vfs_ioctl+0x1e/0x2b
[64635.235778]  ? do_vfs_ioctl+0x523/0x54c
[64635.238443]  ? cache_from_obj+0x22/0x57
[64635.241132]  ? ksys_ioctl+0x3e/0x5d
[64635.243457]  ? __x64_sys_ioctl+0x16/0x19
[64635.246187]  ? do_syscall_64+0x4e/0x5b
[64635.248742]  ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
[64635.252813] INFO: task btrfs:16588 blocked for more than 120 seconds.
[64635.258065]       Not tainted 94.19.7-srb-asrock-00001-g22c8f45edcaf #137
[64635.263717] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[64635.270357] btrfs           D    0 16588  16585 0x00000000
[64635.274703] Call Trace:
[64635.275964]  ? __schedule+0x4db/0x524
[64635.278434]  ? mem_cgroup_commit_charge+0xb1/0xf3
[64635.281995]  ? schedule+0x60/0x71
[64635.284121]  ? __rwsem_down_write_failed_common+0x2ff/0x382
[64635.288496]  ? call_rwsem_down_write_failed+0x13/0x20
[64635.292393]  ? down_write+0x29/0x38
[64635.294696]  ? btrfs_delete_subvolume+0x9b/0x4d9
[64635.298116]  ? d_lookup+0x2d/0x3d
[64635.300239]  ? btrfs_ioctl_snap_destroy+0x245/0x2a3
[64635.303984]  ? btrfs_ioctl+0x8aa/0x2a51
[64635.306629]  ? __count_memcg_events+0x11/0x4e
[64635.309792]  ? mem_cgroup_commit_charge+0xb1/0xf3
[64635.313341]  ? get_page+0x5/0xa
[64635.315293]  ? __lru_cache_add+0x1e/0x4d
[64635.318015]  ? __handle_mm_fault+0x5f0/0x9cf
[64635.321123]  ? vfs_ioctl+0x1e/0x2b
[64635.323348]  ? btrfs_ioctl_get_supported_features+0x22/0x22
[64635.327731]  ? vfs_ioctl+0x1e/0x2b
[64635.329932]  ? do_vfs_ioctl+0x523/0x54c
[64635.332619]  ? handle_mm_fault+0x12f/0x17e
[64635.335523]  ? ksys_ioctl+0x3e/0x5d
[64635.337818]  ? __x64_sys_ioctl+0x16/0x19
[64635.340550]  ? do_syscall_64+0x4e/0x5b
[64635.343154]  ? entry_SYSCALL_64_after_hwframe+0x44/0xa9

[64757.782746] INFO: task btrfs:7823 blocked for more than 120 seconds.
[64757.788007]       Not tainted 94.19.7-srb-asrock-00001-g22c8f45edcaf #137
[64757.793652] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[64757.800296] btrfs           D    0  7823   7641 0x00000000
[64757.804628] Call Trace:
[64757.805897]  ? __schedule+0x4db/0x524
[64757.808366]  ? schedule+0x60/0x71
[64757.810491]  ? __rwsem_down_write_failed_common+0x2ff/0x382
[64757.814892]  ? apic_timer_interrupt+0xa/0x20
[64757.817971]  ? call_rwsem_down_write_failed+0x13/0x20
[64757.821825]  ? down_write+0x29/0x38
[64757.824139]  ? btrfs_ioctl_subvol_setflags+0xc5/0x1fb
[64757.827999]  ? btrfs_ioctl+0x13a/0x2a51
[64757.830641]  ? current_time+0x67/0x88
[64757.833142]  ? pipe_write+0x356/0x369
[64757.835607]  ? vfs_ioctl+0x1e/0x2b
[64757.837819]  ? btrfs_ioctl_get_supported_features+0x22/0x22
[64757.842202]  ? vfs_ioctl+0x1e/0x2b
[64757.844437]  ? do_vfs_ioctl+0x523/0x54c
[64757.847084]  ? vfs_write+0xb2/0xdf
[64757.849293]  ? ksys_ioctl+0x3e/0x5d
[64757.851590]  ? __x64_sys_ioctl+0x16/0x19
[64757.854346]  ? do_syscall_64+0x4e/0x5b
[64757.856902]  ? entry_SYSCALL_64_after_hwframe+0x44/0xa9

The following ones are from the sister system, starting at an older date, the older ones are from v4.19.1 and the newer ones from v4.19.7:

Total devices 5 FS bytes used 2.48TiB
devid 1 size 5.46TiB used 1.41TiB path /dev/sdb
devid 2 size 5.46TiB used 1.41TiB path /dev/sdg
devid 3 size 5.46TiB used 1.41TiB path /dev/sdf
devid 4 size 5.46TiB used 1.41TiB path /dev/sde
devid 5 size 3.64TiB used 0.00B path /dev/sda

Nov 11 07:43:15 argos kernel: INFO: task btrfs-transacti:1235 blocked for more than 120 seconds.
Nov 11 07:43:15 argos kernel:      Not tainted 94.19.1-srb-asrock-00001-gdffa15601442 #132
Nov 11 07:43:15 argos kernel: btrfs-transacti D    0  1235      2 0x80000000
Nov 11 07:43:15 argos kernel: Call Trace:
Nov 11 07:43:15 argos kernel: ? __schedule+0x4db/0x524
Nov 11 07:43:15 argos kernel: ? schedule+0x60/0x71
Nov 11 07:45:18 argos kernel: ? btrfs_start_ordered_extent+0xd3/0x105
Nov 11 07:45:18 argos kernel: ? finish_wait+0x60/0x60
Nov 11 07:45:18 argos kernel: ? btrfs_wait_ordered_range+0xa4/0x100
Nov 11 07:45:18 argos kernel: ? __btrfs_wait_cache_io+0x47/0x16d
Nov 11 07:45:18 argos kernel: ? btrfs_start_dirty_block_groups+0x111/0x390
Nov 11 07:45:18 argos kernel: ? btrfs_commit_transaction+0xd3/0x73b
Nov 11 07:47:21 argos kernel: ? kthread+0xeb/0xf0
Nov 11 07:47:21 argos kernel: ? __kthread_cancel_work+0x68/0x68
Nov 11 07:47:21 argos kernel: ? ret_from_fork+0x35/0x40
Nov 11 07:49:23 argos kernel: ? __btrfs_wait_cache_io+0x47/0x16d
Nov 11 07:49:23 argos kernel: ? btrfs_start_dirty_block_groups+0x111/0x390
Nov 11 07:49:23 argos kernel: ? start_transaction+0x2b8/0x329
Nov 11 07:49:23 argos kernel: ? transaction_kthread+0xc6/0x132
Nov 11 07:49:23 argos kernel: ? btrfs_cleanup_transaction+0x3ca/0x3ca
Nov 11 07:51:26 argos kernel: btrfs-transacti D    0  1235      2 0x80000000
Nov 11 07:51:26 argos kernel: Call Trace:
Nov 11 07:51:26 argos kernel: ? __schedule+0x4db/0x524
Nov 11 07:51:26 argos kernel: ? schedule+0x60/0x71
Nov 11 07:51:26 argos kernel: ? __btrfs_wait_cache_io+0x47/0x16d
Nov 11 07:51:26 argos kernel: ? btrfs_start_dirty_block_groups+0x111/0x390
Nov 11 07:51:26 argos kernel: ? btrfs_commit_transaction+0xd3/0x73b
Nov 11 07:51:26 argos kernel: ? kthread+0xeb/0xf0
Nov 11 07:51:26 argos kernel: ? __kthread_cancel_work+0x68/0x68
Nov 11 07:51:26 argos kernel: ? ret_from_fork+0x35/0x40
Nov 11 07:53:29 argos kernel: INFO: task btrfs-transacti:1235 blocked for more than 120 seconds.
Nov 11 07:53:29 argos kernel:      Not tainted 94.19.1-srb-asrock-00001-gdffa15601442 #132
Nov 11 07:53:29 argos kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 11 07:57:35 argos kernel: ? btrfs_start_ordered_extent+0xd3/0x105
Nov 11 07:57:35 argos kernel: ? finish_wait+0x60/0x60
Nov 11 07:57:35 argos kernel: ? btrfs_wait_ordered_range+0xa4/0x100

Nov 13 12:02:01 argos kernel: ? btrfs_start_ordered_extent+0xd3/0x105
Nov 13 12:06:07 argos kernel: INFO: task btrfs:26969 blocked for more than 120 seconds.
Nov 13 12:06:07 argos kernel:      Not tainted 94.19.1-srb-asrock-00001-gdffa15601442 #135
Nov 13 12:08:10 argos kernel: Call Trace:
Nov 13 12:30:06 argos kernel: perf: interrupt took too long (2506 > 2500), lowering kernel.perf_event_max_sample_rate to 79800
Nov 13 14:29:19 argos kernel: perf: interrupt took too long (3144 > 3132), lowering kernel.perf_event_max_sample_rate to 63600

Nov 14 07:41:40 argos kernel: ? btrfs_wait_ordered_range+0xa4/0x100
Nov 14 07:47:49 argos kernel: ? ret_from_fork+0x35/0x40

Nov 14 13:34:18 argos kernel: INFO: task btrfs:6654 blocked for more than 120 seconds.
Nov 14 13:34:18 argos kernel:      Not tainted 94.19.1-srb-asrock-00001-gdffa15601442 #135
Nov 14 13:34:18 argos kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 14 13:34:19 argos kernel: btrfs           D    0  6654   6649 0x00000000
Nov 14 13:34:19 argos kernel: Call Trace:
Nov 14 13:34:19 argos kernel: ? do_truncate+0x82/0xb6
Nov 14 13:34:19 argos kernel: ? kmem_cache_alloc+0x9a/0x100
Nov 14 13:34:19 argos kernel: ? vfs_truncate+0xbc/0xda
Nov 14 13:34:19 argos kernel: ? do_sys_truncate+0x60/0xa9
Nov 14 13:34:19 argos kernel: ? do_syscall_64+0x4e/0x5b
Nov 14 13:34:19 argos kernel: ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
Nov 14 13:36:21 argos kernel: ? btrfs_wait_ordered_range+0xa4/0x100
Nov 14 13:36:21 argos kernel: ? unmap_mapping_pages+0x64/0x113
Nov 14 13:36:21 argos kernel: ? btrfs_setattr+0x20b/0x499

Nov 18 09:48:00 argos kernel: btrfs           D    0 26152  26147 0x00000000
Nov 18 09:48:00 argos kernel: ? __schedule+0x4db/0x524
Nov 18 09:48:00 argos kernel: ? finish_wait+0x60/0x60
Nov 18 09:48:00 argos kernel: ? notify_change+0x268/0x347
Nov 18 09:48:00 argos kernel: ? do_truncate+0x82/0xb6
Nov 18 09:48:00 argos kernel: ? kmem_cache_alloc+0x9a/0x100
Nov 18 09:48:00 argos kernel: ? vfs_truncate+0xbc/0xda
Nov 19 10:02:05 argos kernel: ? do_sys_truncate+0x60/0xa9
Nov 19 10:02:05 argos kernel: ? do_syscall_64+0x4e/0x5b
Nov 19 10:02:05 argos kernel: ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
Nov 19 10:04:08 argos kernel: ? vfs_truncate+0xbc/0xda

Nov 22 12:22:53 argos kernel: INFO: task btrfs:19688 blocked for more than 120 seconds.
Nov 22 12:22:53 argos kernel:      Not tainted 94.19.1-srb-asrock-00001-gdffa15601442 #135
Nov 22 12:22:53 argos kernel: btrfs           D    0 19688  19683 0x00000000
Nov 22 12:22:53 argos kernel: Call Trace:
Nov 22 12:22:53 argos kernel: ? btrfs_wait_ordered_range+0xa4/0x100
Nov 22 12:22:53 argos kernel: ? unmap_mapping_pages+0x64/0x113

Nov 23 07:46:09 argos kernel: INFO: task btrfs-transacti:1234 blocked for more than 120 seconds.
Nov 23 07:46:09 argos kernel:      Not tainted 94.19.1-srb-asrock-00001-gdffa15601442 #135
Nov 23 07:46:09 argos kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 23 07:46:09 argos kernel: btrfs-transacti D    0  1234      2 0x80000000
Nov 23 07:46:09 argos kernel: ? btrfs_start_ordered_extent+0xd3/0x105
Nov 23 07:46:09 argos kernel: ? finish_wait+0x60/0x60
Nov 23 07:46:09 argos kernel: ? btrfs_wait_ordered_range+0xa4/0x100
Nov 23 07:46:09 argos kernel: ? __kthread_cancel_work+0x68/0x68
Nov 23 07:48:12 argos kernel: INFO: task btrfs-transacti:1234 blocked for more than 120 seconds.
Nov 23 07:48:12 argos kernel:      Not tainted 94.19.1-srb-asrock-00001-gdffa15601442 #135
Nov 23 07:48:12 argos kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 23 07:48:12 argos kernel: btrfs-transacti D    0  1234      2 0x80000000
Nov 23 07:48:12 argos kernel: ? btrfs_start_dirty_block_groups+0x111/0x390
Nov 23 07:48:12 argos kernel: ? btrfs_commit_transaction+0xd3/0x73b
Nov 23 07:50:15 argos kernel: ? btrfs_clean_one_deleted_snapshot+0xa8/0xb2
Nov 23 07:50:15 argos kernel: INFO: task btrfs-transacti:1234 blocked for more than 120 seconds.
Nov 23 07:50:15 argos kernel:      Not tainted 94.19.1-srb-asrock-00001-gdffa15601442 #135
Nov 23 07:52:18 argos kernel: ? finish_wait+0x60/0x60

Nov 25 09:53:44 argos kernel:      Not tainted 94.19.1-srb-asrock-00001-gdffa15601442 #135
Nov 25 09:53:44 argos kernel: btrfs           D    0  7623   7618 0x00000000
Nov 25 09:53:44 argos kernel: ? btrfs_wait_ordered_range+0xa4/0x100
Nov 25 09:53:44 argos kernel: ? unmap_mapping_pages+0x64/0x113
Nov 25 09:53:44 argos kernel: ? btrfs_setattr+0x20b/0x499

Nov 26 10:26:14 argos kernel: INFO: task btrfs:18234 blocked for more than 120 seconds.

Nov 27 10:22:54 argos kernel: ? __schedule+0x4db/0x524
Nov 27 10:22:54 argos kernel: ? schedule+0x60/0x71
Nov 27 10:22:54 argos kernel: ? btrfs_start_ordered_extent+0xd3/0x105
Nov 27 10:22:54 argos kernel: ? notify_change+0x268/0x347
Nov 27 10:22:54 argos kernel: ? do_truncate+0x82/0xb6
Nov 27 10:22:54 argos kernel: ? kmem_cache_alloc+0x9a/0x100
Nov 27 10:22:54 argos kernel: ? vfs_truncate+0xbc/0xda
Nov 27 10:22:54 argos kernel: ? do_sys_truncate+0x60/0xa9
Nov 27 10:22:54 argos kernel: ? do_syscall_64+0x4e/0x5b
Nov 27 10:22:54 argos kernel: ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
Nov 27 10:24:57 argos kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 28 10:04:13 argos kernel: ? __schedule+0x4db/0x524
Nov 28 10:04:13 argos kernel: ? schedule+0x60/0x71
Nov 28 10:04:13 argos kernel: ? btrfs_start_ordered_extent+0xd3/0x105
Nov 28 10:04:13 argos kernel: ? finish_wait+0x60/0x60
Nov 28 10:06:16 argos kernel: ? btrfs_start_ordered_extent+0xd3/0x105
Nov 28 10:06:16 argos kernel: ? finish_wait+0x60/0x60
Nov 28 10:06:16 argos kernel: ? btrfs_setattr+0x20b/0x499
Nov 28 10:08:18 argos kernel: ? vfs_truncate+0xbc/0xda
Nov 29 10:24:26 argos kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 29 10:24:26 argos kernel: ? do_sys_truncate+0x60/0xa9
Nov 29 10:24:26 argos kernel: ? do_syscall_64+0x4e/0x5b
Nov 29 10:24:26 argos kernel: ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
Nov 29 10:26:29 argos kernel: ? btrfs_wait_ordered_range+0xa4/0x100
Nov 29 10:26:29 argos kernel: ? unmap_mapping_pages+0x64/0x113
Nov 29 10:26:29 argos kernel: ? btrfs_setattr+0x20b/0x499
Nov 29 10:28:32 argos kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Nov 29 10:28:32 argos kernel: btrfs           D    0 24965  24960 0x00000000
Nov 29 10:28:32 argos kernel: Call Trace:
Nov 29 13:08:31 argos kernel: Code: 1f 80 00 00 00 00 e9 7b ff ff ff 66 2e 0f 1f 84 00 00 00 00 00 90 48 81 ec f8 ff 00 00 8b 05 8f 2e 00 00 48 8d 35 40 0e 00 00 <48> 89 3c 24 48 8b 3d 81 2e 00 00 8d 90 00 00 01 00 31 c0 89 15 6f
Nov 30 10:13:56 argos kernel: ? btrfs_setattr+0x20b/0x499
Nov 30 10:13:56 argos kernel: ? vfs_truncate+0xbc/0xda
Dec  3 17:08:40 argos kernel: Code: 1f 80 00 00 00 00 e9 7b ff ff ff 66 2e 0f 1f 84 00 00 00 00 00 90 48 81 ec f8 ff 00 00 8b 05 8f 2e 00 00 48 8d 35 40 0e 00 00 <48> 89 3c 24 48 8b 3d 81 2e 00 00 8d 90 00 00 01 00 31 c0 89 15 6f

Dec  6 11:41:13 argos kernel: perf: interrupt took too long (2514 > 2500), lowering kernel.perf_event_max_sample_rate to 79500
Dec  6 22:42:18 argos kernel: ? btrfs_wait_ordered_range+0xa4/0x100
Dec  6 22:42:18 argos kernel: ? unmap_mapping_pages+0x64/0x113
Dec  6 22:42:18 argos kernel: ? btrfs_setattr+0x20b/0x499
Dec  6 22:42:18 argos kernel: ? notify_change+0x268/0x347
Dec  6 22:42:18 argos kernel: ? do_truncate+0x82/0xb6
Dec  6 22:42:18 argos kernel: ? kmem_cache_alloc+0x9a/0x100
Dec  6 22:42:18 argos kernel: ? vfs_truncate+0xbc/0xda
Dec  6 22:58:41 argos kernel:      Not tainted 94.19.7-srb-asrock-00001-g22c8f45edcaf #137
Dec  6 22:58:41 argos kernel: Call Trace:
Dec  6 22:58:41 argos kernel: ? btrfs_setattr+0x20b/0x499

Dec  7 00:26:26 argos kernel: Linux version 94.19.7-srb-asrock-00001-g22c8f45edcaf (root@devel2) (gcc version 8.2.0 (Debian 8.2.0-9)) #137 SMP Thu Dec 6 09:36:50 CET 2018
Dec  7 03:49:45 argos kernel: perf: interrupt took too long (3958 > 3937), lowering kernel.perf_event_max_sample_rate to 50500
Dec  7 11:35:20 argos kernel: ? finish_wait+0x60/0x60
Dec  7 11:39:26 argos kernel: ? notify_change+0x268/0x347
Dec  7 11:39:26 argos kernel: ? do_truncate+0x82/0xb6
Dec  7 11:39:26 argos kernel: ? kmem_cache_alloc+0x9a/0x100
Dec  7 11:39:26 argos kernel: ? vfs_truncate+0xbc/0xda
Dec  7 14:37:55 argos kernel: in libxul.so[7f3f410b2000+3dd6000]
Dec  7 14:37:55 argos kernel: Code: 15 7a 84 a3 04 48 89 10 c7 04 25 00 00 00 00 e0 09 00 00 e8 47 57 ff ff 90 48 8b 05 c7 75 ec 05 48 8d 0d c0 84 a3 04 48 89 08 <c7> 04 25 00 00 00 00 66 0a 00 00 e8 25 57 ff ff e8 2a f3 ff ff 48
Dec  7 14:49:20 argos kernel: Code: 15 7a 84 a3 04 48 89 10 c7 04 25 00 00 00 00 e0 09 00 00 e8 47 57 ff ff 90 48 8b 05 c7 75 ec 05 48 8d 0d c0 84 a3 04 48 89 08 <c7> 04 25 00 00 00 00 66 0a 00 00 e8 25 57 ff ff e8 2a f3 ff ff 48
Dec  8 12:03:45 argos kernel: ? unmap_mapping_pages+0x64/0x113
Dec  8 12:05:48 argos kernel: ? __schedule+0x4db/0x524
Dec  8 12:05:48 argos kernel: ? schedule+0x60/0x71
Dec  8 12:05:48 argos kernel: ? btrfs_start_ordered_extent+0xd3/0x105
Dec  8 12:05:48 argos kernel: ? finish_wait+0x60/0x60
Dec  8 12:07:51 argos kernel: btrfs           D    0 17853  17848 0x00000000
Dec  8 12:07:51 argos kernel: Call Trace:
Dec  8 12:07:51 argos kernel: ? vfs_truncate+0xbc/0xda

Dec  9 10:37:29 argos kernel:      Not tainted 94.19.7-srb-asrock-00001-g22c8f45edcaf #137
Dec  9 10:37:29 argos kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec  9 10:37:29 argos kernel: btrfs           D    0   409    404 0x00000000
Dec  9 10:37:29 argos kernel: Call Trace:
Dec  9 10:37:29 argos kernel: ? vfs_truncate+0xbc/0xda
Dec  9 10:39:32 argos kernel: btrfs           D    0   409    404 0x00000000
Dec  9 10:39:32 argos kernel: Call Trace:
Dec  9 10:39:32 argos kernel: ? btrfs_wait_ordered_range+0xa4/0x100
Dec  9 10:39:32 argos kernel: ? unmap_mapping_pages+0x64/0x113
Dec  9 10:39:32 argos kernel: ? btrfs_setattr+0x20b/0x499
Dec  9 10:39:32 argos kernel: ? notify_change+0x268/0x347
Dec  9 10:39:32 argos kernel: ? do_truncate+0x82/0xb6
Dec  9 10:41:34 argos kernel: ? __schedule+0x4db/0x524
Dec  9 10:41:34 argos kernel: ? schedule+0x60/0x71
Dec  9 10:41:34 argos kernel: ? btrfs_start_ordered_extent+0xd3/0x105
Dec  9 10:41:34 argos kernel: ? finish_wait+0x60/0x60
Dec  9 10:43:37 argos kernel: INFO: task btrfs:409 blocked for more than 120 seconds.
Dec  9 10:43:37 argos kernel:      Not tainted 94.19.7-srb-asrock-00001-g22c8f45edcaf #137
Dec  9 10:43:37 argos kernel: ? finish_wait+0x60/0x60
Dec  9 12:08:42 argos kernel: Code: 1f 80 00 00 00 00 e9 7b ff ff ff 66 2e 0f 1f 84 00 00 00 00 00 90 48 81 ec f8 ff 00 00 8b 05 8f 2e 00 00 48 8d 35 40 0e 00 00 <48> 89 3c 24 48 8b 3d 81 2e 00 00 8d 90 00 00 01 00 31 c0 89 15 6f

Stephen.

I suggest reproducing the problem and issuing sysrq+w and then post the entire resulting output for a developer to evaluate. I find it's best to have the sysrq setup in a shell before hand so all you have to do is hit return, and of course you can test the before the problem happens. It dumps to dmesg and can sometimes overflow the default size buffer, so either increase the buffer, or get it from 'journalctl -k' redirected to a file. The entire kernel message might be helpful, but I also note the kernel isn't tainted so what you're getting is mostly info noise about the hang.

I see this is btrfs-receive workload, so I wouldn't guess it's suvolume lock contention unless the contention is happening with a single shared parent subvolume into which all the receive subvolumes are going (e.g. subvol id 5). I'm not sure how to alleviate it.

Chris Murphy

Chris Murphy

I'll give that a try.

Well, machine A has 32GB RAM and is running
multiple simultaneous btrfs-receive instances, but the machine rarely locks up unless I increase the total reception rate beyond 5MB/s.

Machine B has 8GB RAM and is running at most a single btrfs-receive instance, but it is much more susceptible to hangups. The maximum reception rate here is 3MB/s.

In both cases all received subvolumes are created inside the same master parent (subvol id 5). The only difference is that machine A receives multiple subvolumes simultaneously, and machine B serialises reception (it basically receives subvolumes from a single source (machine A)), but the subvolumes here *are* created back to back (so maybe the previous btrfs-receive is still late flushing buffers to disk when the new btrfs-receive already starts).

Stephen.

Also, what scheduler are you using? And do you get different results with a different one (better or worse)?

Chris Murphy

I'm using CFQ, and I don't think I ever tried a different one. But, btrfs should be compatible with all schedulers.

Stephen.

Sure but there are some workloads we know where CFQ can cause or exacerbate problems with some storage stacks, and other schedulers exist to deal with those workloads better. So the question is whether the problem is made worse or better by trying another scheduler. It might have no effect. And it might just flat out be a Btrfs bug, but I'm doing send and receive on far more meager hardware with much less RAM and haven't run into problems.

But yeah, one of the developers might have more to say about it once sysrq+w output is available, which should expose what's stuck or busy.

Chris Murphy

Ok. Finally have a sysrq+w output of 4.19.8.
The uptime of this system has been a few days. It has already received quite some btrfs-sends in that time (every night). When the sysrq+w output was taken, the system started to get more and more processes in a D kernel state bordering on becoming unusable. I had to hard-reset the system after this to get it going again.

sysrq: SysRq : Show Blocked State
task PC stack pid father
btrfs-cleaner D 0 276 2 0x80000000

Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? btrfs_tree_read_lock+0xc1/0xf8
 ? finish_wait+0x60/0x60
 ? find_parent_nodes+0x89d/0x11df
 ? __schedule+0x4ff/0x524
 ? page_cache_tree_insert+0xc6/0xc6
 ? btrfs_find_all_roots_safe+0x9e/0x10f
 ? btrfs_find_all_roots_safe+0x9e/0x10f
 ? btrfs_find_all_roots+0x58/0x77
 ? btrfs_qgroup_trace_extent_post+0x38/0x7e
 ? btrfs_qgroup_trace_subtree+0x21e/0x362
 ? do_walk_down+0x3f5/0x495
 ? walk_down_tree+0x99/0xd4
 ? btrfs_drop_snapshot+0x2c4/0x5de
 ? btrfs_kill_all_delayed_nodes+0x5a/0xd1
 ? btrfs_need_cleaner_sleep+0x27/0x27
 ? btrfs_clean_one_deleted_snapshot+0xa8/0xb2
 ? cleaner_kthread+0x7a/0x138
 ? kthread+0xeb/0xf0
 ? __kthread_cancel_work+0x68/0x68
 ? ret_from_fork+0x35/0x40
btrfs-transacti D    0   277      2 0x80000000
Call Trace:
 ? __schedule+0x4db/0x524
 ? __switch_to_asm+0x40/0x70
 ? schedule+0x60/0x71
 ? wait_current_trans+0xa1/0xdf
 ? finish_wait+0x60/0x60
 ? start_transaction+0x1ce/0x329
 ? transaction_kthread+0xa7/0x132
 ? btrfs_cleanup_transaction+0x3ca/0x3ca
 ? kthread+0xeb/0xf0
 ? __kthread_cancel_work+0x68/0x68
 ? ret_from_fork+0x35/0x40
lldpad          D    0  2165      1 0x00000000
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? wait_current_trans+0xa1/0xdf
 ? finish_wait+0x60/0x60
 ? start_transaction+0x1b2/0x329
 ? btrfs_setattr+0x234/0x499
 ? notify_change+0x268/0x347
 ? do_truncate+0x82/0xb6
 ? path_openat+0x95a/0xa5b
 ? do_filp_open+0x52/0xaf
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
ntpd            D    0  2396      1 0x00000004
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? wait_current_trans+0xa1/0xdf
 ? finish_wait+0x60/0x60
 ? start_transaction+0x1b2/0x329
 ? btrfs_create+0x5a/0x1bd
 ? path_openat+0x643/0xa5b
 ? recalc_sigpending+0x17/0x3f
 ? dequeue_signal+0x169/0x19a
 ? do_filp_open+0x52/0xaf
 ? __set_current_blocked+0x3d/0x55
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
smartd          D    0  2424      1 0x00000000
Call Trace:
 ? __schedule+0x4db/0x524
 ? unlock_new_inode+0x4a/0x54
 ? schedule+0x60/0x71
 ? wait_current_trans+0xa1/0xdf
 ? finish_wait+0x60/0x60
 ? start_transaction+0x1b2/0x329
 ? btrfs_start_transaction_fallback_global_rsv+0x32/0xbc
 ? btrfs_unlink+0x30/0xc0
 ? vfs_unlink+0x81/0xc7
 ? do_unlinkat+0x111/0x1e3
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
rs:main Q:Reg   D    0  7824   3086 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? __accumulate_pelt_segments+0x29/0x3a
 ? schedule+0x60/0x71
 ? btrfs_tree_read_lock+0xc1/0xf8
 ? finish_wait+0x60/0x60
 ? btrfs_read_lock_root_node+0x1d/0x3b
 ? btrfs_search_slot+0x181/0x71d
 ? find_busiest_group+0x108/0x5ef
 ? btrfs_lookup_file_extent+0x4b/0x66
 ? btrfs_get_extent+0x176/0x6fb
 ? _cond_resched+0x20/0x23
 ? kmem_cache_free+0x25/0xc4
 ? __do_readpage+0x214/0x564
 ? start_delalloc_inodes+0x2b8/0x2b8
 ? mem_cgroup_commit_charge+0xb1/0xf3
 ? __extent_read_full_page+0xcb/0xdb
 ? start_delalloc_inodes+0x2b8/0x2b8
 ? extent_read_full_page+0x42/0x75
 ? prepare_uptodate_page+0x33/0x8c
 ? prepare_pages+0xb6/0x15d
 ? btrfs_buffered_write+0x29d/0x5cf
 ? btrfs_file_write_iter+0x3a8/0x485
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
cron            D    0  7826   3086 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? btrfs_tree_read_lock+0xc1/0xf8
 ? finish_wait+0x60/0x60
 ? btrfs_read_lock_root_node+0x1d/0x3b
 ? btrfs_search_slot+0x181/0x71d
 ? crc32c+0x66/0x90
 ? btrfs_lookup_dir_item+0x7d/0xc6
 ? btrfs_lookup_dentry+0x9d/0x40c
 ? d_alloc_parallel+0x28a/0x2cb
 ? btrfs_lookup+0xe/0x2c
 ? __lookup_slow+0xd4/0x117
 ? lookup_slow+0x3a/0x52
 ? walk_component+0x84/0x112
 ? path_lookupat.isra.55+0x107/0x1c3
 ? load_balance+0x150/0x6ed
 ? __switch_to_asm+0x40/0x70
 ? __switch_to_asm+0x34/0x70
 ? __switch_to_asm+0x40/0x70
 ? filename_lookup.part.71+0x6f/0xd2
 ? __switch_to_asm+0x40/0x70
 ? __switch_to_asm+0x34/0x70
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? kmem_cache_alloc+0x9a/0x100
 ? getname_flags+0x49/0x156
 ? vfs_statx+0x71/0xce
 ? hrtimer_cancel+0x11/0x1b
 ? do_nanosleep+0xc0/0x168
 ? __do_sys_newstat+0x3a/0x6d
 ? hrtimer_nanosleep+0x9f/0x100
 ? syscall_trace_enter+0x103/0x19c
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
hiawatha        D    0  7885   3086 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? btrfs_tree_read_lock+0xc1/0xf8
 ? finish_wait+0x60/0x60
 ? btrfs_read_lock_root_node+0x1d/0x3b
 ? btrfs_search_slot+0x181/0x71d
 ? crc32c+0x66/0x90
 ? btrfs_lookup_dir_item+0x7d/0xc6
 ? btrfs_lookup_dentry+0x9d/0x40c
 ? d_alloc_parallel+0x28a/0x2cb
 ? __switch_to_asm+0x34/0x70
 ? __switch_to_asm+0x40/0x70
 ? __switch_to_asm+0x34/0x70
 ? __switch_to_asm+0x40/0x70
 ? btrfs_lookup+0xe/0x2c
 ? __lookup_slow+0xd4/0x117
 ? lookup_slow+0x3a/0x52
 ? walk_component+0x84/0x112
 ? inode_permission+0x7c/0x115
 ? link_path_walk.part.53+0x112/0x420
 ? path_openat+0x164/0xa5b
 ? __bpf_prog_run32+0x34/0x52
 ? futex_wake+0x11e/0x145
 ? do_filp_open+0x52/0xaf
 ? inet_recvmsg+0x6c/0x98
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
hiawatha        D    0  7889   3086 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? d_alloc_parallel+0x1d1/0x2cb
 ? __switch_to_asm+0x34/0x70
 ? wake_up_q+0x45/0x45
 ? __lookup_slow+0x73/0x117
 ? lookup_slow+0x3a/0x52
 ? walk_component+0x84/0x112
 ? inode_permission+0x7c/0x115
 ? link_path_walk.part.53+0x112/0x420
 ? path_openat+0x164/0xa5b
 ? __bpf_prog_run32+0x34/0x52
 ? futex_wake+0x11e/0x145
 ? do_filp_open+0x52/0xaf
 ? inet_recvmsg+0x6c/0x98
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
hiawatha        D    0  3974   3086 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? d_alloc_parallel+0x1d1/0x2cb
 ? wake_up_q+0x45/0x45
 ? __lookup_slow+0x73/0x117
 ? lookup_slow+0x3a/0x52
 ? walk_component+0x84/0x112
 ? inode_permission+0x7c/0x115
 ? link_path_walk.part.53+0x112/0x420
 ? path_openat+0x164/0xa5b
 ? __bpf_prog_run32+0x34/0x52
 ? do_filp_open+0x52/0xaf
 ? inet_recvmsg+0x6c/0x98
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
hiawatha        D    0  4048   3086 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? d_alloc_parallel+0x1d1/0x2cb
 ? wake_up_q+0x45/0x45
 ? __lookup_slow+0x73/0x117
 ? lookup_slow+0x3a/0x52
 ? walk_component+0x84/0x112
 ? inode_permission+0x7c/0x115
 ? link_path_walk.part.53+0x112/0x420
 ? path_openat+0x164/0xa5b
 ? __bpf_prog_run32+0x34/0x52
 ? do_filp_open+0x52/0xaf
 ? inet_recvmsg+0x6c/0x98
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
hiawatha        D    0  4269   3086 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? d_alloc_parallel+0x1d1/0x2cb
 ? wake_up_q+0x45/0x45
 ? __lookup_slow+0x73/0x117
 ? lookup_slow+0x3a/0x52
 ? walk_component+0x84/0x112
 ? inode_permission+0x7c/0x115
 ? link_path_walk.part.53+0x112/0x420
 ? path_openat+0x164/0xa5b
 ? __bpf_prog_run32+0x34/0x52
 ? __count_memcg_events+0x11/0x4e
 ? do_filp_open+0x52/0xaf
 ? inet_recvmsg+0x6c/0x98
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
hiawatha        D    0  4273   3086 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? d_alloc_parallel+0x1d1/0x2cb
 ? wake_up_q+0x45/0x45
 ? __lookup_slow+0x73/0x117
 ? lookup_slow+0x3a/0x52
 ? walk_component+0x84/0x112
 ? inode_permission+0x7c/0x115
 ? link_path_walk.part.53+0x112/0x420
 ? path_openat+0x164/0xa5b
 ? __bpf_prog_run32+0x34/0x52
 ? do_filp_open+0x52/0xaf
 ? inet_recvmsg+0x6c/0x98
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
hiawatha        D    0  4439   3086 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? d_alloc_parallel+0x1d1/0x2cb
 ? wake_up_q+0x45/0x45
 ? __lookup_slow+0x73/0x117
 ? lookup_slow+0x3a/0x52
 ? walk_component+0x84/0x112
 ? inode_permission+0x7c/0x115
 ? link_path_walk.part.53+0x112/0x420
 ? path_openat+0x164/0xa5b
 ? __bpf_prog_run32+0x34/0x52
 ? __count_memcg_events+0x11/0x4e
 ? do_filp_open+0x52/0xaf
 ? inet_recvmsg+0x6c/0x98
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
postgres        D    0  8067   3086 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? btrfs_tree_read_lock+0xc1/0xf8
 ? finish_wait+0x60/0x60
 ? btrfs_read_lock_root_node+0x1d/0x3b
 ? btrfs_search_slot+0x181/0x71d
 ? crc32c+0x66/0x90
 ? btrfs_lookup_dir_item+0x7d/0xc6
 ? btrfs_lookup_dentry+0x9d/0x40c
 ? d_alloc_parallel+0x28a/0x2cb
 ? unlazy_walk+0x45/0x94
 ? btrfs_lookup+0xe/0x2c
 ? path_openat+0x5d1/0xa5b
 ? do_filp_open+0x52/0xaf
 ? kernel_wait4+0xca/0x113
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
postgres        D    0  8531   8067 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? btrfs_tree_read_lock+0xc1/0xf8
 ? finish_wait+0x60/0x60
 ? btrfs_read_lock_root_node+0x1d/0x3b
 ? btrfs_search_slot+0x181/0x71d
 ? crc32c+0x66/0x90
 ? btrfs_lookup_dir_item+0x7d/0xc6
 ? btrfs_lookup_dentry+0x9d/0x40c
 ? d_alloc_parallel+0x28a/0x2cb
 ? btrfs_lookup+0xe/0x2c
 ? __lookup_slow+0xd4/0x117
 ? lookup_slow+0x3a/0x52
 ? walk_component+0x84/0x112
 ? inode_permission+0x7c/0x115
 ? link_path_walk.part.53+0x112/0x420
 ? path_openat+0x164/0xa5b
 ? __bpf_prog_run32+0x34/0x52
 ? __switch_to_asm+0x40/0x70
 ? __switch_to_asm+0x34/0x70
 ? __switch_to_asm+0x40/0x70
 ? __switch_to+0x1c8/0x37f
 ? do_filp_open+0x52/0xaf
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
postgres        D    0  8694   3086 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? btrfs_tree_read_lock+0xc1/0xf8
 ? finish_wait+0x60/0x60
 ? btrfs_read_lock_root_node+0x1d/0x3b
 ? btrfs_search_slot+0x181/0x71d
 ? crc32c+0x66/0x90
 ? btrfs_lookup_dir_item+0x7d/0xc6
 ? btrfs_lookup_dentry+0x9d/0x40c
 ? d_alloc_parallel+0x28a/0x2cb
 ? unlazy_walk+0x45/0x94
 ? btrfs_lookup+0xe/0x2c
 ? path_openat+0x5d1/0xa5b
 ? do_filp_open+0x52/0xaf
 ? kernel_wait4+0xca/0x113
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
postgres        D    0  8716   8694 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? d_alloc_parallel+0x1d1/0x2cb
 ? wake_up_q+0x45/0x45
 ? __lookup_slow+0x73/0x117
 ? lookup_slow+0x3a/0x52
 ? walk_component+0x84/0x112
 ? inode_permission+0x7c/0x115
 ? link_path_walk.part.53+0x112/0x420
 ? path_openat+0x164/0xa5b
 ? __bpf_prog_run32+0x34/0x52
 ? __switch_to_asm+0x40/0x70
 ? __switch_to_asm+0x34/0x70
 ? __switch_to_asm+0x40/0x70
 ? __switch_to+0x1c8/0x37f
 ? do_filp_open+0x52/0xaf
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
unbound         D    0  9532   3421 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? wait_current_trans+0xa1/0xdf
 ? finish_wait+0x60/0x60
 ? start_transaction+0x1b2/0x329
 ? btrfs_create+0x5a/0x1bd
 ? path_openat+0x643/0xa5b
 ? unix_dgram_sendmsg+0x4b8/0x523
 ? do_filp_open+0x52/0xaf
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
pdns_server     D    0 10415   9913 0x20020104
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? wait_current_trans+0xa1/0xdf
 ? finish_wait+0x60/0x60
 ? start_transaction+0x1b2/0x329
 ? btrfs_create+0x5a/0x1bd
 ? path_openat+0x643/0xa5b
 ? do_filp_open+0x52/0xaf
 ? vfs_statx+0x96/0xce
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_int80_syscall_32+0x50/0x5d
 ? entry_INT80_compat+0x7d/0x90
pdns_server     D    0 10422   9913 0x20020104
Call Trace:
 ? __schedule+0x4db/0x524
 ? __switch_to_asm+0x40/0x70
 ? schedule+0x60/0x71
 ? __rwsem_down_read_failed_common+0x180/0x1df
 ? call_rwsem_down_read_failed+0x14/0x30
 ? down_read+0x1c/0x2f
 ? lookup_slow+0x2a/0x52
 ? walk_component+0x84/0x112
 ? path_lookupat.isra.55+0x107/0x1c3
 ? filename_lookup.part.71+0x6f/0xd2
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? kmem_cache_alloc+0x9a/0x100
 ? getname_flags+0x49/0x156
 ? do_faccessat+0xce/0x1c4
 ? do_int80_syscall_32+0x50/0x5d
 ? entry_INT80_compat+0x7d/0x90
pdns_server     D    0 10423   9913 0x20020104
Call Trace:
 ? __schedule+0x4db/0x524
 ? __switch_to_asm+0x40/0x70
 ? schedule+0x60/0x71
 ? __rwsem_down_read_failed_common+0x180/0x1df
 ? call_rwsem_down_read_failed+0x14/0x30
 ? down_read+0x1c/0x2f
 ? lookup_slow+0x2a/0x52
 ? walk_component+0x84/0x112
 ? path_lookupat.isra.55+0x107/0x1c3
 ? filename_lookup.part.71+0x6f/0xd2
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? kmem_cache_alloc+0x9a/0x100
 ? getname_flags+0x49/0x156
 ? do_faccessat+0xce/0x1c4
 ? do_int80_syscall_32+0x50/0x5d
 ? entry_INT80_compat+0x7d/0x90
pdns_server     D    0 10434   9913 0x20020104
Call Trace:
 ? __schedule+0x4db/0x524
 ? __switch_to_asm+0x40/0x70
 ? schedule+0x60/0x71
 ? __rwsem_down_read_failed_common+0x180/0x1df
 ? call_rwsem_down_read_failed+0x14/0x30
 ? down_read+0x1c/0x2f
 ? lookup_slow+0x2a/0x52
 ? walk_component+0x84/0x112
 ? path_lookupat.isra.55+0x107/0x1c3
 ? filename_lookup.part.71+0x6f/0xd2
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? kmem_cache_alloc+0x9a/0x100
 ? getname_flags+0x49/0x156
 ? do_faccessat+0xce/0x1c4
 ? do_int80_syscall_32+0x50/0x5d
 ? entry_INT80_compat+0x7d/0x90
pdns_server     D    0 11724   9913 0x20020104
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_read_failed_common+0x180/0x1df
 ? call_rwsem_down_read_failed+0x14/0x30
 ? down_read+0x1c/0x2f
 ? lookup_slow+0x2a/0x52
 ? walk_component+0x84/0x112
 ? path_lookupat.isra.55+0x107/0x1c3
 ? filename_lookup.part.71+0x6f/0xd2
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? kmem_cache_alloc+0x9a/0x100
 ? getname_flags+0x49/0x156
 ? do_faccessat+0xce/0x1c4
 ? do_int80_syscall_32+0x50/0x5d
 ? entry_INT80_compat+0x7d/0x90
mysqld          D    0  7366  12050 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? wait_current_trans+0xa1/0xdf
 ? finish_wait+0x60/0x60
 ? start_transaction+0x1b2/0x329
 ? btrfs_sync_file+0x247/0x321
 ? do_fsync+0x2e/0x47
 ? __x64_sys_fsync+0x10/0x13
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
qmgr            D    0 12580  12570 0x00000104
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_read_failed_common+0x180/0x1df
 ? call_rwsem_down_read_failed_killable+0x14/0x30
 ? down_read_killable+0x1c/0x40
 ? iterate_dir+0x59/0x131
 ? __do_sys_getdents+0x91/0xf6
 ? filldir64+0xd0/0xd0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
kworker/u16:4   D    0 29942      2 0x80000000
Workqueue: btrfs-endio-write btrfs_endio_write_helper
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? btrfs_tree_read_lock+0xc1/0xf8
 ? finish_wait+0x60/0x60
 ? find_parent_nodes+0x89d/0x11df
 ? btrfs_find_all_roots_safe+0x9e/0x10f
 ? btrfs_find_all_roots_safe+0x9e/0x10f
 ? btrfs_find_all_roots+0x58/0x77
 ? btrfs_qgroup_trace_extent_post+0x38/0x7e
 ? btrfs_add_delayed_tree_ref+0x2d9/0x300
 ? add_pinned_bytes+0x38/0x38
 ? btrfs_inc_extent_ref+0x74/0xe3
 ? __btrfs_mod_ref+0x1bc/0x1eb
 ? update_ref_for_cow+0x153/0x260
 ? __btrfs_cow_block+0x205/0x457
 ? btrfs_cow_block+0xc6/0x129
 ? btrfs_search_slot+0x296/0x71d
 ? __switch_to_asm+0x34/0x70
 ? btrfs_lookup_file_extent+0x4b/0x66
 ? __btrfs_drop_extents+0x158/0x9d6
 ? kmem_cache_free+0x25/0xc4
 ? __set_extent_bit+0x3d0/0x3f8
 ? insert_reserved_file_extent.constprop.58+0x9d/0x2b8
 ? btrfs_finish_ordered_io+0x2e1/0x5ac
 ? normal_work_helper+0xfe/0x243
 ? process_one_work+0x18d/0x271
 ? rescuer_thread+0x278/0x278
 ? worker_thread+0x194/0x23f
 ? kthread+0xeb/0xf0
 ? __kthread_cancel_work+0x68/0x68
 ? ret_from_fork+0x35/0x40
kworker/u16:3   D    0  9685      2 0x80000000
Workqueue: btrfs-endio-write btrfs_endio_write_helper
Call Trace:
 ? __schedule+0x4db/0x524
 ? __switch_to_asm+0x34/0x70
 ? schedule+0x60/0x71
 ? btrfs_tree_read_lock+0xc1/0xf8
 ? finish_wait+0x60/0x60
 ? btrfs_read_lock_root_node+0x1d/0x3b
 ? btrfs_search_slot+0x181/0x71d
 ? kmem_cache_alloc_trace+0xaf/0xbd
 ? btrfs_lookup_file_extent+0x4b/0x66
 ? __btrfs_drop_extents+0x158/0x9d6
 ? test_clear_page_writeback+0x151/0x164
 ? kmem_cache_free+0x25/0xc4
 ? __set_extent_bit+0x3d0/0x3f8
 ? insert_reserved_file_extent.constprop.58+0x9d/0x2b8
 ? btrfs_finish_ordered_io+0x2e1/0x5ac
 ? normal_work_helper+0xfe/0x243
 ? process_one_work+0x18d/0x271
 ? rescuer_thread+0x278/0x278
 ? worker_thread+0x194/0x23f
 ? kthread+0xeb/0xf0
 ? __kthread_cancel_work+0x68/0x68
 ? ret_from_fork+0x35/0x40
btrfs           D    0  9998   9896 0x00000000
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? btrfs_commit_transaction+0x21c/0x711
 ? finish_wait+0x60/0x60
 ? btrfs_ioctl_send+0x579/0xc54
 ? _btrfs_ioctl_send+0xaf/0xf2
 ? _btrfs_ioctl_send+0xc7/0xf2
 ? node_tag_clear+0x2a/0x69
 ? idr_alloc_u32+0xa5/0xc8
 ? __radix_tree_lookup+0x6b/0xa5
 ? btrfs_ioctl+0x16e3/0x2a51
 ? task_rq_unlock.isra.43+0xd/0x1f
 ? cpu_cgroup_fork+0x4a/0x67
 ? freezer_css_free+0xa/0xa
 ? select_task_rq_fair+0x6da/0xb52
 ? __accumulate_pelt_segments+0x29/0x3a
 ? update_cfs_rq_load_avg+0x124/0x150
 ? vfs_ioctl+0x1e/0x2b
 ? btrfs_ioctl_get_supported_features+0x22/0x22
 ? vfs_ioctl+0x1e/0x2b
 ? do_vfs_ioctl+0x523/0x54c
 ? task_rq_unlock.isra.43+0xd/0x1f
 ? wake_up_new_task+0x110/0x12f
 ? ksys_ioctl+0x3e/0x5d
 ? __x64_sys_ioctl+0x16/0x19
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
scp             D    0 14456  14452 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? wait_current_trans+0xa1/0xdf
 ? finish_wait+0x60/0x60
 ? start_transaction+0x1b2/0x329
 ? btrfs_setattr+0x234/0x499
 ? notify_change+0x268/0x347
 ? do_truncate+0x82/0xb6
 ? do_sys_ftruncate+0xc6/0xf9
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
scp             D    0 19976  19974 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
default.script  D    0 22674  11529 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? wait_current_trans+0xa1/0xdf
 ? finish_wait+0x60/0x60
 ? start_transaction+0x1b2/0x329
 ? btrfs_setattr+0x234/0x499
 ? notify_change+0x268/0x347
 ? do_truncate+0x82/0xb6
 ? path_openat+0x95a/0xa5b
 ? do_filp_open+0x52/0xaf
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
scp             D    0 25502  25500 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
cron            D    0 27719  10299 0x20020100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? wait_current_trans+0xa1/0xdf
 ? finish_wait+0x60/0x60
 ? start_transaction+0x1b2/0x329
 ? btrfs_create+0x5a/0x1bd
 ? path_openat+0x643/0xa5b
 ? swap_free+0x53/0x6d
 ? do_filp_open+0x52/0xaf
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_int80_syscall_32+0x50/0x5d
 ? entry_INT80_compat+0x7d/0x90
scp             D    0 31033  31029 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
scp             D    0  4039   4037 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
scp             D    0  9821   9819 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
scp             D    0 15307  15305 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
scp             D    0 20769  20767 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
scp             D    0 26250  26248 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
cron            D    0 28466  10299 0x20020100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? step_into+0x58/0x1a8
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? path_openat+0x293/0xa5b
 ? swap_free+0x53/0x6d
 ? unlock_page+0xa/0x1b
 ? do_filp_open+0x52/0xaf
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_int80_syscall_32+0x50/0x5d
 ? entry_INT80_compat+0x7d/0x90
scp             D    0 31805  31803 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
apt.systemd.dai D    0   418    417 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? wait_current_trans+0xa1/0xdf
 ? finish_wait+0x60/0x60
 ? start_transaction+0x1b2/0x329
 ? btrfs_setattr+0x234/0x499
 ? notify_change+0x268/0x347
 ? do_truncate+0x82/0xb6
 ? path_openat+0x95a/0xa5b
 ? do_filp_open+0x52/0xaf
 ? kernel_wait4+0xe0/0x113
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
apt.systemd.dai D    0   436    435 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? wait_current_trans+0xa1/0xdf
 ? finish_wait+0x60/0x60
 ? start_transaction+0x1b2/0x329
 ? btrfs_setattr+0x234/0x499
 ? notify_change+0x268/0x347
 ? do_truncate+0x82/0xb6
 ? path_openat+0x95a/0xa5b
 ? do_filp_open+0x52/0xaf
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
cron            D    0   439  10299 0x20020100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? step_into+0x58/0x1a8
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? path_openat+0x293/0xa5b
 ? swap_free+0x53/0x6d
 ? unlock_page+0xa/0x1b
 ? do_filp_open+0x52/0xaf
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_int80_syscall_32+0x50/0x5d
 ? entry_INT80_compat+0x7d/0x90
apt.systemd.dai D    0   452    451 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? wait_current_trans+0xa1/0xdf
 ? finish_wait+0x60/0x60
 ? start_transaction+0x1b2/0x329
 ? btrfs_setattr+0x234/0x499
 ? notify_change+0x268/0x347
 ? do_truncate+0x82/0xb6
 ? path_openat+0x95a/0xa5b
 ? do_filp_open+0x52/0xaf
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
apt.systemd.dai D    0   465    463 0x00000000
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? wait_current_trans+0xa1/0xdf
 ? finish_wait+0x60/0x60
 ? start_transaction+0x1b2/0x329
 ? btrfs_setattr+0x234/0x499
 ? notify_change+0x268/0x347
 ? do_truncate+0x82/0xb6
 ? path_openat+0x95a/0xa5b
 ? do_filp_open+0x52/0xaf
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
apt.systemd.dai D    0   491    489 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? wait_current_trans+0xa1/0xdf
 ? finish_wait+0x60/0x60
 ? start_transaction+0x1b2/0x329
 ? btrfs_setattr+0x234/0x499
 ? notify_change+0x268/0x347
 ? do_truncate+0x82/0xb6
 ? path_openat+0x95a/0xa5b
 ? do_filp_open+0x52/0xaf
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
apt.systemd.dai D    0   510    505 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? wait_current_trans+0xa1/0xdf
 ? finish_wait+0x60/0x60
 ? start_transaction+0x1b2/0x329
 ? btrfs_setattr+0x234/0x499
 ? notify_change+0x268/0x347
 ? do_truncate+0x82/0xb6
 ? path_openat+0x95a/0xa5b
 ? do_filp_open+0x52/0xaf
 ? kernel_wait4+0xe0/0x113
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
apt.systemd.dai D    0   523    522 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? wait_current_trans+0xa1/0xdf
 ? finish_wait+0x60/0x60
 ? start_transaction+0x1b2/0x329
 ? btrfs_setattr+0x234/0x499
 ? notify_change+0x268/0x347
 ? do_truncate+0x82/0xb6
 ? path_openat+0x95a/0xa5b
 ? do_filp_open+0x52/0xaf
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
apt.systemd.dai D    0   535    534 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? wait_current_trans+0xa1/0xdf
 ? finish_wait+0x60/0x60
 ? start_transaction+0x1b2/0x329
 ? btrfs_setattr+0x234/0x499
 ? notify_change+0x268/0x347
 ? do_truncate+0x82/0xb6
 ? path_openat+0x95a/0xa5b
 ? do_filp_open+0x52/0xaf
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
cp              D    0  3321   3320 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? wait_current_trans+0xa1/0xdf
 ? finish_wait+0x60/0x60
 ? start_transaction+0x1b2/0x329
 ? btrfs_setattr+0x234/0x499
 ? notify_change+0x268/0x347
 ? do_truncate+0x82/0xb6
 ? path_openat+0x95a/0xa5b
 ? _cond_resched+0x20/0x23
 ? do_filp_open+0x52/0xaf
 ? _copy_to_user+0x22/0x28
 ? cp_new_stat+0x151/0x181
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
scp             D    0  4985   4981 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
scp             D    0 10762  10760 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
cp              D    0 10911  10909 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? __d_lookup_rcu+0xdb/0x109
 ? schedule+0x60/0x71
 ? wait_current_trans+0xa1/0xdf
 ? finish_wait+0x60/0x60
 ? start_transaction+0x1b2/0x329
 ? btrfs_create+0x5a/0x1bd
 ? path_openat+0x643/0xa5b
 ? do_filp_open+0x52/0xaf
 ? _copy_to_user+0x22/0x28
 ? cp_new_stat+0x151/0x181
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
scp             D    0 16301  16296 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
scp             D    0 22063  22059 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
scp             D    0 28266  28264 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
cron            D    0 30615  10299 0x20020100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? step_into+0x58/0x1a8
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? path_openat+0x293/0xa5b
 ? swap_free+0x53/0x6d
 ? unlock_page+0xa/0x1b
 ? do_filp_open+0x52/0xaf
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_int80_syscall_32+0x50/0x5d
 ? entry_INT80_compat+0x7d/0x90
scp             D    0  1758   1754 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
scp             D    0  7952   7950 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
scp             D    0 14337  14330 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
scp             D    0 20292  20290 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
scp             D    0 26358  26354 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
scp             D    0 32592  32589 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
cron            D    0  2698  10299 0x20020100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? step_into+0x58/0x1a8
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? path_openat+0x293/0xa5b
 ? swap_free+0x53/0x6d
 ? unlock_page+0xa/0x1b
 ? do_filp_open+0x52/0xaf
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_int80_syscall_32+0x50/0x5d
 ? entry_INT80_compat+0x7d/0x90
scp             D    0  6570   6568 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
scp             D    0 13064  13061 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
scp             D    0 19322  19320 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
scp             D    0 25998  25996 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
kworker/u16:5   D    0 30954      2 0x80000000
Workqueue: writeback wb_workfn (flush-btrfs-1)
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? btrfs_tree_lock+0xb1/0x1a8
 ? finish_wait+0x60/0x60
 ? lock_extent_buffer_for_io+0x3b/0x166
 ? btree_write_cache_pages+0x1cb/0x29b
 ? do_writepages+0x2d/0x56
 ? __writeback_single_inode+0x84/0x2d3
 ? writeback_sb_inodes+0x220/0x3ad
 ? wb_writeback+0x157/0x281
 ? wb_workfn+0x134/0x2e5
 ? __switch_to_asm+0x34/0x70
 ? __switch_to_asm+0x40/0x70
 ? __switch_to_asm+0x34/0x70
 ? __switch_to_asm+0x40/0x70
 ? __switch_to_asm+0x34/0x70
 ? __switch_to_asm+0x40/0x70
 ? finish_task_switch+0x113/0x1e6
 ? process_one_work+0x18d/0x271
 ? rescuer_thread+0x278/0x278
 ? worker_thread+0x194/0x23f
 ? kthread+0xeb/0xf0
 ? __kthread_cancel_work+0x68/0x68
 ? ret_from_fork+0x35/0x40
scp             D    0 32252  32250 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
scp             D    0  6528   6526 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
verify          D    0  6825  12570 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? wait_current_trans+0xa1/0xdf
 ? finish_wait+0x60/0x60
 ? start_transaction+0x1b2/0x329
 ? btrfs_sync_file+0x247/0x321
 ? do_fsync+0x2e/0x47
 ? __x64_sys_fdatasync+0x13/0x16
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
cleanup         D    0  6826  12570 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? wait_current_trans+0xa1/0xdf
 ? finish_wait+0x60/0x60
 ? start_transaction+0x1b2/0x329
 ? btrfs_create+0x5a/0x1bd
 ? path_openat+0x643/0xa5b
 ? do_filp_open+0x52/0xaf
 ? pipe_read+0x21c/0x22f
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
cron            D    0  9378  10299 0x20020100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? step_into+0x58/0x1a8
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? path_openat+0x293/0xa5b
 ? swap_free+0x53/0x6d
 ? unlock_page+0xa/0x1b
 ? do_filp_open+0x52/0xaf
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_int80_syscall_32+0x50/0x5d
 ? entry_INT80_compat+0x7d/0x90
scp             D    0 13410  13406 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
scp             D    0 19990  19988 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
scp             D    0 26896  26894 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? __rwsem_down_write_failed_common+0x2ff/0x382
 ? call_rwsem_down_write_failed+0x13/0x20
 ? down_write+0x29/0x38
 ? btrfs_file_write_iter+0xd6/0x485
 ? pipe_read+0x21c/0x22f
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_write+0x5e/0xa0
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
bash            D    0 30962  30930 0x00000100
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? wait_current_trans+0xa1/0xdf
 ? finish_wait+0x60/0x60
 ? start_transaction+0x1b2/0x329
 ? btrfs_create+0x5a/0x1bd
 ? path_openat+0x643/0xa5b
 ? path_lookupat.isra.55+0x19c/0x1c3
 ? do_filp_open+0x52/0xaf
 ? _cond_resched+0x20/0x23
 ? slab_pre_alloc_hook+0x2b/0x4d
 ? slab_post_alloc_hook.isra.66+0xa/0x1a
 ? __alloc_fd+0x136/0x149
 ? do_sys_open+0x7c/0x119
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
sync            D    0 32082  31611 0x00000000
Call Trace:
 ? __schedule+0x4db/0x524
 ? bdi_split_work_to_wbs+0xfa/0x186
 ? default_file_splice_write+0x1f/0x1f
 ? schedule+0x60/0x71
 ? wb_wait_for_completion+0x5e/0x88
 ? finish_wait+0x60/0x60
 ? sync_inodes_sb+0xa7/0x226
 ? __queue_work+0x244/0x257
 ? default_file_splice_write+0x1f/0x1f
 ? iterate_supers+0x73/0xb4
 ? ksys_sync+0x41/0xa6
 ? __ia32_sys_sync+0xa/0xd
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9

Stephen.

It's caused by qgroup, and a dead lock on btrfs_drop_snapshot().

This is one of the easiest way to trigger an ABBA deadlock.

Please either disable qgroup or apply this patch to solve it:
https://patchwork.kernel.org/patch/10725371/

Thanks,
Qu

Any idea in which kernel version this patch is/will be included?

Stephen.

If we're lucky enough, it would be v5.0 or v4.21.
It may be more likely for v5.1 or v4.22, as there are tons of pending qgroup related patches for v5.0/v4.21.

Thanks,
Qu

Ok, booting the system in v4.20 with this patch. I'll report back if it does not resolve the problem.

Stephen.

I now have a stuck btrfs receive again:

[    0.000000] INFO: task btrfs:1850 blocked for more than 120 seconds.
[    0.000000]       Not tainted 94.20.0-srb-asrock-00002-gfb1bd063cc72 #141
[    0.000000] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[    0.000000] btrfs           D    0  1850   1845 0x00000000
[    0.000000] Call Trace:
[    0.000000]  ? __schedule+0x4db/0x524
[    0.000000]  ? schedule+0x60/0x71
[    0.000000]  ? btrfs_start_ordered_extent+0xd3/0x105
[    0.000000]  ? finish_wait+0x60/0x60
[    0.000000]  ? btrfs_wait_ordered_range+0xa4/0x100
[    0.000000]  ? unmap_mapping_pages+0x64/0x113
[    0.000000]  ? btrfs_setattr+0x20b/0x499
[    0.000000]  ? notify_change+0x268/0x347
[    0.000000]  ? do_truncate+0x82/0xb6
[    0.000000]  ? kmem_cache_alloc+0x9a/0x100
[    0.000000]  ? vfs_truncate+0xbc/0xda
[    0.000000]  ? do_sys_truncate+0x60/0xa9
[    0.000000]  ? do_syscall_64+0x4e/0x5b
[    0.000000]  ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
[    0.000000] INFO: task btrfs:1850 blocked for more than 120 seconds.
[    0.000000]       Not tainted 94.20.0-srb-asrock-00002-gfb1bd063cc72 #141
[    0.000000] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[    0.000000] btrfs           D    0  1850   1845 0x00000000
[    0.000000] Call Trace:
[    0.000000]  ? __schedule+0x4db/0x524
[    0.000000]  ? schedule+0x60/0x71
[    0.000000]  ? btrfs_start_ordered_extent+0xd3/0x105
[    0.000000]  ? finish_wait+0x60/0x60
[    0.000000]  ? btrfs_wait_ordered_range+0xa4/0x100
[    0.000000]  ? unmap_mapping_pages+0x64/0x113
[    0.000000]  ? btrfs_setattr+0x20b/0x499
[    0.000000]  ? notify_change+0x268/0x347
[    0.000000]  ? do_truncate+0x82/0xb6
[    0.000000]  ? kmem_cache_alloc+0x9a/0x100
[    0.000000]  ? vfs_truncate+0xbc/0xda
[    0.000000]  ? do_sys_truncate+0x60/0xa9
[    0.000000]  ? do_syscall_64+0x4e/0x5b
[    0.000000]  ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
[    0.000000] conftest[24422]: segfault at 7ffe21547e90 ip 000055ebaef881c4 sp 00007ffe21547e90 error 6 in conftest[55ebaef88000+1000]
[    0.000000] Code: 1f 80 00 00 00 00 e9 7b ff ff ff 66 2e 0f 1f 84 00 00 00 00 00 90 48 81 ec f8 ff 00 00 8b 05 8f 2e 00 00 48 8d 35 40 0e 00 00 <48> 89 3c 24 48 8b 3d 81 2e 00 00 8d 90 00 00 01 00 31 c0 89 15 6f
[    0.000000] perf: interrupt took too long (3977 > 3961), lowering kernel.perf_event_max_sample_rate to 50200
[    0.000000] perf: interrupt took too long (4975 > 4971), lowering kernel.perf_event_max_sample_rate to 40200
[    0.000000] conftest[4747]: segfault at 7ffd0e0fb540 ip 00005567d53c61c4 sp 00007ffd0e0fb540 error 6 in conftest[5567d53c6000+1000]
[    0.000000] Code: 1f 80 00 00 00 00 e9 7b ff ff ff 66 2e 0f 1f 84 00 00 00 00 00 90 48 81 ec f8 ff 00 00 8b 05 8f 2e 00 00 48 8d 35 40 0e 00 00 <48> 89 3c 24 48 8b 3d 81 2e 00 00 8d 90 00 00 01 00 31 c0 89 15 6f
[    0.000000] perf: interrupt took too long (6222 > 6218), lowering kernel.perf_event_max_sample_rate to 32100
[    0.000000] INFO: task btrfs:16752 blocked for more than 120 seconds.
[    0.000000]       Not tainted 94.20.0-srb-asrock-00002-gfb1bd063cc72 #141
[    0.000000] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[    0.000000] btrfs           D    0 16752  16745 0x00000000
[    0.000000] Call Trace:
[    0.000000]  ? __schedule+0x4db/0x524
[    0.000000]  ? schedule+0x60/0x71
[    0.000000]  ? btrfs_start_ordered_extent+0xd3/0x105
[    0.000000]  ? finish_wait+0x60/0x60
[    0.000000]  ? btrfs_wait_ordered_range+0xa4/0x100
[    0.000000]  ? unmap_mapping_pages+0x64/0x113
[    0.000000]  ? btrfs_setattr+0x20b/0x499
[    0.000000]  ? notify_change+0x268/0x347
[    0.000000]  ? do_truncate+0x82/0xb6
[    0.000000]  ? kmem_cache_alloc+0x9a/0x100
[    0.000000]  ? vfs_truncate+0xbc/0xda
[    0.000000]  ? do_sys_truncate+0x60/0xa9
[    0.000000]  ? do_syscall_64+0x4e/0x5b
[    0.000000]  ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
[    0.000000] INFO: task btrfs:16752 blocked for more than 120 seconds.
[    0.000000]       Not tainted 94.20.0-srb-asrock-00002-gfb1bd063cc72 #141
[    0.000000] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[    0.000000] btrfs           D    0 16752  16745 0x00000000
[    0.000000] Call Trace:
[    0.000000]  ? __schedule+0x4db/0x524
[    0.000000]  ? schedule+0x60/0x71
[    0.000000]  ? btrfs_start_ordered_extent+0xd3/0x105
[    0.000000]  ? finish_wait+0x60/0x60
[    0.000000]  ? btrfs_wait_ordered_range+0xa4/0x100
[    0.000000]  ? unmap_mapping_pages+0x64/0x113
[    0.000000]  ? btrfs_setattr+0x20b/0x499
[    0.000000]  ? notify_change+0x268/0x347
[    0.000000]  ? do_truncate+0x82/0xb6
[    0.000000]  ? kmem_cache_alloc+0x9a/0x100
[    0.000000]  ? vfs_truncate+0xbc/0xda
[    0.000000]  ? do_sys_truncate+0x60/0xa9
[    0.000000]  ? do_syscall_64+0x4e/0x5b
[    0.000000]  ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
[    0.000000] INFO: task btrfs:16752 blocked for more than 120 seconds.
[    0.000000]       Not tainted 94.20.0-srb-asrock-00002-gfb1bd063cc72 #141
[    0.000000] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[    0.000000] btrfs           D    0 16752  16745 0x00000000
[    0.000000] Call Trace:
[    0.000000]  ? __schedule+0x4db/0x524
[    0.000000]  ? schedule+0x60/0x71
[    0.000000]  ? btrfs_start_ordered_extent+0xd3/0x105
[    0.000000]  ? finish_wait+0x60/0x60
[    0.000000]  ? btrfs_wait_ordered_range+0xa4/0x100
[    0.000000]  ? unmap_mapping_pages+0x64/0x113
[    0.000000]  ? btrfs_setattr+0x20b/0x499
[    0.000000]  ? notify_change+0x268/0x347
[    0.000000]  ? do_truncate+0x82/0xb6
[    0.000000]  ? kmem_cache_alloc+0x9a/0x100
[    0.000000]  ? vfs_truncate+0xbc/0xda
[    0.000000]  ? do_sys_truncate+0x60/0xa9
[    0.000000]  ? do_syscall_64+0x4e/0x5b
[    0.000000]  ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
[    0.000000] INFO: task btrfs:16752 blocked for more than 120 seconds.
[    0.000000]       Not tainted 94.20.0-srb-asrock-00002-gfb1bd063cc72 #141
[    0.000000] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[    0.000000] btrfs           D    0 16752  16745 0x00000000
[    0.000000] Call Trace:
[    0.000000]  ? __schedule+0x4db/0x524
[    0.000000]  ? schedule+0x60/0x71
[    0.000000]  ? btrfs_start_ordered_extent+0xd3/0x105
[    0.000000]  ? finish_wait+0x60/0x60
[    0.000000]  ? btrfs_wait_ordered_range+0xa4/0x100
[    0.000000]  ? unmap_mapping_pages+0x64/0x113
[    0.000000]  ? btrfs_setattr+0x20b/0x499
[    0.000000]  ? notify_change+0x268/0x347
[    0.000000]  ? do_truncate+0x82/0xb6
[    0.000000]  ? kmem_cache_alloc+0x9a/0x100
[    0.000000]  ? vfs_truncate+0xbc/0xda
[    0.000000]  ? do_sys_truncate+0x60/0xa9
[    0.000000]  ? do_syscall_64+0x4e/0x5b
[    0.000000]  ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
[    0.000000] INFO: task btrfs:16752 blocked for more than 120 seconds.
[    0.000000]       Not tainted 94.20.0-srb-asrock-00002-gfb1bd063cc72 #141
[    0.000000] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[    0.000000] btrfs           D    0 16752  16745 0x00000000
[    0.000000] Call Trace:
[    0.000000]  ? __schedule+0x4db/0x524
[    0.000000]  ? schedule+0x60/0x71
[    0.000000]  ? btrfs_start_ordered_extent+0xd3/0x105
[    0.000000]  ? finish_wait+0x60/0x60
[    0.000000]  ? btrfs_wait_ordered_range+0xa4/0x100
[    0.000000]  ? unmap_mapping_pages+0x64/0x113
[    0.000000]  ? btrfs_setattr+0x20b/0x499
[    0.000000]  ? notify_change+0x268/0x347
[    0.000000]  ? do_truncate+0x82/0xb6
[    0.000000]  ? kmem_cache_alloc+0x9a/0x100
[    0.000000]  ? vfs_truncate+0xbc/0xda
[    0.000000]  ? do_sys_truncate+0x60/0xa9
[    0.000000]  ? do_syscall_64+0x4e/0x5b
[    0.000000]  ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
[    0.000000] INFO: task btrfs:16752 blocked for more than 120 seconds.
[    0.000000]       Not tainted 94.20.0-srb-asrock-00002-gfb1bd063cc72 #141
[    0.000000] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[    0.000000] btrfs           D    0 16752  16745 0x00000000
[    0.000000] Call Trace:
[    0.000000]  ? __schedule+0x4db/0x524
[    0.000000]  ? schedule+0x60/0x71
[    0.000000]  ? btrfs_start_ordered_extent+0xd3/0x105
[    0.000000]  ? finish_wait+0x60/0x60
[    0.000000]  ? btrfs_wait_ordered_range+0xa4/0x100
[    0.000000]  ? unmap_mapping_pages+0x64/0x113
[    0.000000]  ? btrfs_setattr+0x20b/0x499
[    0.000000]  ? notify_change+0x268/0x347
[    0.000000]  ? do_truncate+0x82/0xb6
[    0.000000]  ? kmem_cache_alloc+0x9a/0x100
[    0.000000]  ? vfs_truncate+0xbc/0xda
[    0.000000]  ? do_sys_truncate+0x60/0xa9
[    0.000000]  ? do_syscall_64+0x4e/0x5b
[    0.000000]  ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
[    0.000000] INFO: task btrfs:16752 blocked for more than 120 seconds.
[    0.000000]       Not tainted 94.20.0-srb-asrock-00002-gfb1bd063cc72 #141
[    0.000000] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[    0.000000] btrfs           D    0 16752  16745 0x00000000
[    0.000000] Call Trace:
[    0.000000]  ? __schedule+0x4db/0x524
[    0.000000]  ? schedule+0x60/0x71
[    0.000000]  ? btrfs_start_ordered_extent+0xd3/0x105
[    0.000000]  ? finish_wait+0x60/0x60
[    0.000000]  ? btrfs_wait_ordered_range+0xa4/0x100
[    0.000000]  ? unmap_mapping_pages+0x64/0x113
[    0.000000]  ? btrfs_setattr+0x20b/0x499
[    0.000000]  ? notify_change+0x268/0x347
[    0.000000]  ? do_truncate+0x82/0xb6
[    0.000000]  ? kmem_cache_alloc+0x9a/0x100
[    0.000000]  ? vfs_truncate+0xbc/0xda
[    0.000000]  ? do_sys_truncate+0x60/0xa9
[    0.000000]  ? do_syscall_64+0x4e/0x5b
[    0.000000]  ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
[    0.000000] INFO: task btrfs:16752 blocked for more than 120 seconds.
[    0.000000]       Not tainted 94.20.0-srb-asrock-00002-gfb1bd063cc72 #141
[    0.000000] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[    0.000000] btrfs           D    0 16752  16745 0x00000000
[    0.000000] Call Trace:
[    0.000000]  ? __schedule+0x4db/0x524
[    0.000000]  ? schedule+0x60/0x71
[    0.000000]  ? btrfs_start_ordered_extent+0xd3/0x105
[    0.000000]  ? finish_wait+0x60/0x60
[    0.000000]  ? btrfs_wait_ordered_range+0xa4/0x100
[    0.000000]  ? unmap_mapping_pages+0x64/0x113
[    0.000000]  ? btrfs_setattr+0x20b/0x499
[    0.000000]  ? notify_change+0x268/0x347
[    0.000000]  ? do_truncate+0x82/0xb6
[    0.000000]  ? kmem_cache_alloc+0x9a/0x100
[    0.000000]  ? vfs_truncate+0xbc/0xda
[    0.000000]  ? do_sys_truncate+0x60/0xa9
[    0.000000]  ? do_syscall_64+0x4e/0x5b
[    0.000000]  ? entry_SYSCALL_64_after_hwframe+0x44/0xa9

Running 4.20.0 including the special patch mentioned earlier in this thread.

Stephen.

Ok, I now have a sysreq+w output again (attached at the bottom). In userspace I see the following (ps xfa):

 1282 ?        D      5:57  \_ [btrfs-cleaner]
 1283 ?        D     26:09  \_ [btrfs-transacti]

18526 ? D 0:09 | \_ btrfs receive --max-errors 1 -vv /data/lxc/somecontainer/rootfs

The btrfs receive hangs and does not proceed.

The dmesg output prior to running the sysreq+w:

[11651.269729] perf: interrupt took too long (3154 > 3136), lowering kernel.perf_event_max_sample_rate to 63400
[14867.617253] INFO: task btrfs:24867 blocked for more than 120 seconds.
[14867.622513]       Not tainted 94.20.0-srb-asrock-00002-gfb1bd063cc72 #141
[14867.628202] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[14867.634845] btrfs           D    0 24867  24862 0x00000000
[14867.639173] Call Trace:
[14867.640436]  ? __schedule+0x4db/0x524
[14867.642904]  ? schedule+0x60/0x71
[14867.645029]  ? btrfs_start_ordered_extent+0xd3/0x105
[14867.648818]  ? finish_wait+0x60/0x60
[14867.651198]  ? btrfs_wait_ordered_range+0xa4/0x100
[14867.654795]  ? unmap_mapping_pages+0x64/0x113
[14867.657979]  ? btrfs_setattr+0x20b/0x499
[14867.660707]  ? notify_change+0x268/0x347
[14867.663435]  ? do_truncate+0x82/0xb6
[14867.665810]  ? kmem_cache_alloc+0x9a/0x100
[14867.668726]  ? vfs_truncate+0xbc/0xda
[14867.671194]  ? do_sys_truncate+0x60/0xa9
[14867.673926]  ? do_syscall_64+0x4e/0x5b
[14867.676479]  ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
[20498.479174] perf: interrupt took too long (3952 > 3942), lowering kernel.perf_event_max_sample_rate to 50600
[53253.444439] perf: interrupt took too long (4953 > 4940), lowering kernel.perf_event_max_sample_rate to 40300
[64758.167022] INFO: task btrfs:21633 blocked for more than 120 seconds.
[64758.172267]       Not tainted 94.20.0-srb-asrock-00002-gfb1bd063cc72 #141
[64758.177906] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[64758.184541] btrfs           D    0 21633  21626 0x00000000
[64758.188854] Call Trace:
[64758.190114]  ? __schedule+0x4db/0x524
[64758.192582]  ? schedule+0x60/0x71
[64758.194698]  ? btrfs_commit_transaction+0x21c/0x711
[64758.198401]  ? finish_wait+0x60/0x60
[64758.200791]  ? _btrfs_ioctl_set_received_subvol+0x27e/0x2ab
[64758.205167]  ? btrfs_ioctl+0x1572/0x2a51
[64758.207902]  ? current_time+0x67/0x88
[64758.210369]  ? pipe_write+0x356/0x369
[64758.212830]  ? vfs_ioctl+0x1e/0x2b
[64758.215030]  ? btrfs_ioctl_get_supported_features+0x22/0x22
[64758.219422]  ? vfs_ioctl+0x1e/0x2b
[64758.221626]  ? do_vfs_ioctl+0x523/0x54c
[64758.224261]  ? ksys_ioctl+0x3e/0x5d
[64758.226548]  ? __x64_sys_ioctl+0x16/0x19
[64758.229281]  ? do_syscall_64+0x4e/0x5b
[64758.231837]  ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
[87012.380856] conftest[12985]: segfault at 7ffe28de8aa0 ip 0000557f11bc31c4 sp 00007ffe28de8aa0 error 6 in conftest[557f11bc3000+1000]
[87012.391632] Code: 1f 80 00 00 00 00 e9 7b ff ff ff 66 2e 0f 1f 84 00 00 00 00 00 90 48 81 ec f8 ff 00 00 8b 05 8f 2e 00 00 48 8d 35 40 0e 00 00 <48> 89 3c 24 48 8b 3d 81 2e 00 00 8d 90 00 00 01 00 31 c0 89 15 6f
[89521.271437] perf: interrupt took too long (6193 > 6191), lowering kernel.perf_event_max_sample_rate to 32200
[139102.477242] INFO: task btrfs-cleaner:1282 blocked for more than 120 seconds.
[139102.483103]       Not tainted 94.20.0-srb-asrock-00002-gfb1bd063cc72 #141
[139102.488730] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[139102.495364] btrfs-cleaner   D    0  1282      2 0x80000000
[139102.499687] Call Trace:
[139102.500957]  ? __schedule+0x4db/0x524
[139102.503418]  ? __wait_for_common+0xda/0x160
[139102.506399]  ? schedule+0x60/0x71
[139102.508536]  ? wait_current_trans+0xa1/0xdf
[139102.511522]  ? finish_wait+0x60/0x60
[139102.513896]  ? start_transaction+0x1b2/0x329
[139102.516964]  ? btrfs_drop_snapshot+0x3d2/0x5de
[139102.520239]  ? btrfs_kill_all_delayed_nodes+0x5a/0xd1
[139102.524097]  ? btrfs_delete_unused_bgs+0x39/0x39e
[139102.527619]  ? btrfs_need_cleaner_sleep+0x27/0x27
[139102.531127]  ? btrfs_clean_one_deleted_snapshot+0xa8/0xb2
[139102.535329]  ? cleaner_kthread+0x80/0xf6
[139102.538066]  ? kthread+0xeb/0xf0
[139102.540097]  ? kthread_associate_blkcg+0x86/0x86
[139102.543520]  ? ret_from_fork+0x35/0x40
[139102.546070] INFO: task btrfs-transacti:1283 blocked for more than 120 seconds.
[139102.552115]       Not tainted 94.20.0-srb-asrock-00002-gfb1bd063cc72 #141
[139102.557713] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[139102.564344] btrfs-transacti D    0  1283      2 0x80000000
[139102.568659] Call Trace:
[139102.569917]  ? __schedule+0x4db/0x524
[139102.572383]  ? schedule+0x60/0x71
[139102.574495]  ? btrfs_start_ordered_extent+0xd3/0x105
[139102.578283]  ? finish_wait+0x60/0x60
[139102.580660]  ? btrfs_wait_ordered_range+0xa4/0x100
[139102.584254]  ? btrfs_get_token_32+0x8e/0xf4
[139102.587258]  ? __btrfs_wait_cache_io+0x47/0x16d
[139102.590594]  ? btrfs_write_dirty_block_groups+0xc7/0x2d3
[139102.594707]  ? btrfs_run_delayed_refs+0xdf/0x12d
[139102.598149]  ? commit_cowonly_roots+0x1f3/0x2a8
[139102.601493]  ? btrfs_commit_transaction+0x397/0x711
[139102.605178]  ? finish_wait+0x60/0x60
[139102.607568]  ? transaction_kthread+0xc6/0x132
[139102.610732]  ? btrfs_cleanup_transaction+0x3ca/0x3ca
[139102.614495]  ? kthread+0xeb/0xf0
[139102.616522]  ? kthread_associate_blkcg+0x86/0x86
[139102.619961]  ? ret_from_fork+0x35/0x40
[139471.126602] INFO: task btrfs-cleaner:1282 blocked for more than 120 seconds.
[139471.132462]       Not tainted 94.20.0-srb-asrock-00002-gfb1bd063cc72 #141
[139471.138099] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[139471.144733] btrfs-cleaner   D    0  1282      2 0x80000000
[139471.149046] Call Trace:
[139471.150306]  ? __schedule+0x4db/0x524
[139471.152775]  ? __wait_for_common+0xda/0x160
[139471.155758]  ? schedule+0x60/0x71
[139471.157896]  ? wait_current_trans+0xa1/0xdf
[139471.160885]  ? finish_wait+0x60/0x60
[139471.163265]  ? start_transaction+0x1b2/0x329
[139471.166334]  ? btrfs_drop_snapshot+0x3d2/0x5de
[139471.169609]  ? btrfs_kill_all_delayed_nodes+0x5a/0xd1
[139471.173467]  ? btrfs_delete_unused_bgs+0x39/0x39e
[139471.176996]  ? btrfs_need_cleaner_sleep+0x27/0x27
[139471.180504]  ? btrfs_clean_one_deleted_snapshot+0xa8/0xb2
[139471.184707]  ? cleaner_kthread+0x80/0xf6
[139471.187453]  ? kthread+0xeb/0xf0
[139471.189483]  ? kthread_associate_blkcg+0x86/0x86
[139471.192907]  ? ret_from_fork+0x35/0x40
[139471.195456] INFO: task btrfs-transacti:1283 blocked for more than 120 seconds.
[139471.201495]       Not tainted 94.20.0-srb-asrock-00002-gfb1bd063cc72 #141
[139471.207088] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[139471.213723] btrfs-transacti D    0  1283      2 0x80000000
[139471.218033] Call Trace:
[139471.219282]  ? __schedule+0x4db/0x524
[139471.221748]  ? schedule+0x60/0x71
[139471.223862]  ? btrfs_start_ordered_extent+0xd3/0x105
[139471.227660]  ? finish_wait+0x60/0x60
[139471.230035]  ? btrfs_wait_ordered_range+0xa4/0x100
[139471.233629]  ? btrfs_get_token_32+0x8e/0xf4
[139471.236636]  ? __btrfs_wait_cache_io+0x47/0x16d
[139471.249343]  ? btrfs_start_dirty_block_groups+0x111/0x390
[139471.253542]  ? btrfs_commit_transaction+0xc9/0x711
[139471.257164]  ? start_transaction+0x2b8/0x329
[139471.260241]  ? transaction_kthread+0xc6/0x132
[139471.263402]  ? btrfs_cleanup_transaction+0x3ca/0x3ca
[139471.267184]  ? kthread+0xeb/0xf0
[139471.269219]  ? kthread_associate_blkcg+0x86/0x86
[139471.272640]  ? ret_from_fork+0x35/0x40
[139594.009727] INFO: task btrfs-cleaner:1282 blocked for more than 120 seconds.
[139594.015604]       Not tainted 94.20.0-srb-asrock-00002-gfb1bd063cc72 #141
[139594.021226] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[139594.027860] btrfs-cleaner   D    0  1282      2 0x80000000
[139594.032188] Call Trace:
[139594.033450]  ? __schedule+0x4db/0x524
[139594.035913]  ? __wait_for_common+0xda/0x160
[139594.038914]  ? schedule+0x60/0x71
[139594.041057]  ? wait_current_trans+0xa1/0xdf
[139594.044046]  ? finish_wait+0x60/0x60
[139594.046426]  ? start_transaction+0x1b2/0x329
[139594.049503]  ? btrfs_drop_snapshot+0x3d2/0x5de
[139594.052772]  ? btrfs_kill_all_delayed_nodes+0x5a/0xd1
[139594.056627]  ? btrfs_delete_unused_bgs+0x39/0x39e
[139594.060162]  ? btrfs_need_cleaner_sleep+0x27/0x27
[139594.063672]  ? btrfs_clean_one_deleted_snapshot+0xa8/0xb2
[139594.067875]  ? cleaner_kthread+0x80/0xf6
[139594.070620]  ? kthread+0xeb/0xf0
[139594.072650]  ? kthread_associate_blkcg+0x86/0x86
[139594.076075]  ? ret_from_fork+0x35/0x40
[139594.078622] INFO: task btrfs-transacti:1283 blocked for more than 120 seconds.
[139594.084668]       Not tainted 94.20.0-srb-asrock-00002-gfb1bd063cc72 #141
[139594.090271] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[139594.096908] btrfs-transacti D    0  1283      2 0x80000000
[139594.101225] Call Trace:
[139594.102481]  ? __schedule+0x4db/0x524
[139594.104942]  ? schedule+0x60/0x71
[139594.107059]  ? btrfs_start_ordered_extent+0xd3/0x105
[139594.110853]  ? finish_wait+0x60/0x60
[139594.113238]  ? btrfs_wait_ordered_range+0xa4/0x100
[139594.116832]  ? btrfs_get_token_32+0x8e/0xf4
[139594.119840]  ? __btrfs_wait_cache_io+0x47/0x16d
[139594.123181]  ? btrfs_start_dirty_block_groups+0x111/0x390
[139594.127382]  ? btrfs_commit_transaction+0xc9/0x711
[139594.131004]  ? start_transaction+0x2b8/0x329
[139594.134083]  ? transaction_kthread+0xc6/0x132
[139594.137244]  ? btrfs_cleanup_transaction+0x3ca/0x3ca
[139594.141032]  ? kthread+0xeb/0xf0
[139594.143060]  ? kthread_associate_blkcg+0x86/0x86
[139594.146475]  ? ret_from_fork+0x35/0x40
[139716.892803] INFO: task btrfs-cleaner:1282 blocked for more than 120 seconds.
[139716.898664]       Not tainted 94.20.0-srb-asrock-00002-gfb1bd063cc72 #141
[139716.904287] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[139716.910955] btrfs-cleaner   D    0  1282      2 0x80000000
[139716.915275] Call Trace:
[139716.916532]  ? __schedule+0x4db/0x524
[139716.918993]  ? __wait_for_common+0xda/0x160
[139716.921974]  ? schedule+0x60/0x71
[139716.924126]  ? wait_current_trans+0xa1/0xdf
[139716.927115]  ? finish_wait+0x60/0x60
[139716.929488]  ? start_transaction+0x1b2/0x329
[139716.932558]  ? btrfs_drop_snapshot+0x3d2/0x5de
[139716.935834]  ? btrfs_kill_all_delayed_nodes+0x5a/0xd1
[139716.939689]  ? btrfs_delete_unused_bgs+0x39/0x39e
[139716.943216]  ? btrfs_need_cleaner_sleep+0x27/0x27
[139716.946729]  ? btrfs_clean_one_deleted_snapshot+0xa8/0xb2
[139716.950931]  ? cleaner_kthread+0x80/0xf6
[139716.953679]  ? kthread+0xeb/0xf0
[139716.955706]  ? kthread_associate_blkcg+0x86/0x86
[139716.959120]  ? ret_from_fork+0x35/0x40
[139716.961672] INFO: task btrfs-transacti:1283 blocked for more than 120 seconds.
[139716.967715]       Not tainted 94.20.0-srb-asrock-00002-gfb1bd063cc72 #141
[139716.973313] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[139716.979946] btrfs-transacti D    0  1283      2 0x80000000
[139716.984257] Call Trace:
[139716.985506]  ? __schedule+0x4db/0x524
[139716.987975]  ? schedule+0x60/0x71
[139716.990088]  ? btrfs_start_ordered_extent+0xd3/0x105
[139716.993872]  ? finish_wait+0x60/0x60
[139716.996251]  ? btrfs_wait_ordered_range+0xa4/0x100
[139716.999848]  ? btrfs_get_token_32+0x8e/0xf4
[139717.002853]  ? __btrfs_wait_cache_io+0x47/0x16d
[139717.006192]  ? btrfs_start_dirty_block_groups+0x111/0x390
[139717.010397]  ? btrfs_commit_transaction+0xc9/0x711
[139717.014016]  ? start_transaction+0x2b8/0x329
[139717.017094]  ? transaction_kthread+0xc6/0x132
[139717.020248]  ? btrfs_cleanup_transaction+0x3ca/0x3ca
[139717.024033]  ? kthread+0xeb/0xf0
[139717.026065]  ? kthread_associate_blkcg+0x86/0x86
[139717.029489]  ? ret_from_fork+0x35/0x40

The latest sysreq+w output:

sysrq: SysRq : Show Blocked State
task PC stack pid father
btrfs-cleaner D 0 1282 2 0x80000000

Call Trace:
 ? __schedule+0x4db/0x524
 ? __wait_for_common+0xda/0x160
 ? schedule+0x60/0x71
 ? wait_current_trans+0xa1/0xdf
 ? finish_wait+0x60/0x60
 ? start_transaction+0x1b2/0x329
 ? btrfs_drop_snapshot+0x3d2/0x5de
 ? btrfs_kill_all_delayed_nodes+0x5a/0xd1
 ? btrfs_delete_unused_bgs+0x39/0x39e
 ? btrfs_need_cleaner_sleep+0x27/0x27
 ? btrfs_clean_one_deleted_snapshot+0xa8/0xb2
 ? cleaner_kthread+0x80/0xf6
 ? kthread+0xeb/0xf0
 ? kthread_associate_blkcg+0x86/0x86
 ? ret_from_fork+0x35/0x40
btrfs-transacti D    0  1283      2 0x80000000
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? btrfs_start_ordered_extent+0xd3/0x105
 ? finish_wait+0x60/0x60
 ? btrfs_wait_ordered_range+0xa4/0x100
 ? btrfs_get_token_32+0x8e/0xf4
 ? __btrfs_wait_cache_io+0x47/0x16d
 ? btrfs_start_dirty_block_groups+0x111/0x390
 ? btrfs_commit_transaction+0xc9/0x711
 ? start_transaction+0x2b8/0x329
 ? transaction_kthread+0xc6/0x132
 ? btrfs_cleanup_transaction+0x3ca/0x3ca
 ? kthread+0xeb/0xf0
 ? kthread_associate_blkcg+0x86/0x86
 ? ret_from_fork+0x35/0x40
kworker/u16:1   D    0 19178      2 0x80000000
Workqueue: btrfs-endio-write btrfs_endio_write_helper
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? schedule_timeout+0xb2/0xec
 ? __next_timer_interrupt+0xae/0xae
 ? io_schedule_timeout+0x1b/0x3d
 ? balance_dirty_pages+0x7a7/0x861
 ? usleep_range+0x7e/0x7e
 ? schedule+0x60/0x71
 ? schedule_timeout+0x32/0xec
 ? balance_dirty_pages_ratelimited+0x204/0x225
 ? btrfs_finish_ordered_io+0x584/0x5ac
 ? normal_work_helper+0xfe/0x243
 ? process_one_work+0x18d/0x271
 ? rescuer_thread+0x278/0x278
 ? worker_thread+0x194/0x23f
 ? kthread+0xeb/0xf0
 ? kthread_associate_blkcg+0x86/0x86
 ? ret_from_fork+0x35/0x40
kworker/u16:3   D    0  3778      2 0x80000000
Workqueue: btrfs-endio-write btrfs_endio_write_helper
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? schedule_timeout+0xb2/0xec
 ? __next_timer_interrupt+0xae/0xae
 ? io_schedule_timeout+0x1b/0x3d
 ? balance_dirty_pages+0x7a7/0x861
 ? usleep_range+0x7e/0x7e
 ? schedule+0x60/0x71
 ? schedule_timeout+0x32/0xec
 ? balance_dirty_pages_ratelimited+0x204/0x225
 ? btrfs_finish_ordered_io+0x584/0x5ac
 ? normal_work_helper+0xfe/0x243
 ? process_one_work+0x18d/0x271
 ? rescuer_thread+0x278/0x278
 ? worker_thread+0x194/0x23f
 ? kthread+0xeb/0xf0
 ? kthread_associate_blkcg+0x86/0x86
 ? ret_from_fork+0x35/0x40
kworker/u16:14  D    0  4078      2 0x80000000
Workqueue: btrfs-endio-write btrfs_endio_write_helper
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? schedule_timeout+0xb2/0xec
 ? __next_timer_interrupt+0xae/0xae
 ? io_schedule_timeout+0x1b/0x3d
 ? balance_dirty_pages+0x7a7/0x861
 ? usleep_range+0x7e/0x7e
 ? schedule+0x60/0x71
 ? schedule_timeout+0x32/0xec
 ? balance_dirty_pages_ratelimited+0x204/0x225
 ? btrfs_finish_ordered_io+0x584/0x5ac
 ? normal_work_helper+0xfe/0x243
 ? process_one_work+0x18d/0x271
 ? rescuer_thread+0x278/0x278
 ? worker_thread+0x194/0x23f
 ? kthread+0xeb/0xf0
 ? kthread_associate_blkcg+0x86/0x86
 ? ret_from_fork+0x35/0x40
kworker/u16:17  D    0  4084      2 0x80000000
Workqueue: btrfs-freespace-write btrfs_freespace_write_helper
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? schedule_timeout+0xb2/0xec
 ? __next_timer_interrupt+0xae/0xae
 ? io_schedule_timeout+0x1b/0x3d
 ? balance_dirty_pages+0x7a7/0x861
 ? sched_clock_cpu+0x10/0x9c
 ? try_to_wake_up+0x202/0x229
 ? balance_dirty_pages_ratelimited+0x204/0x225
 ? btrfs_finish_ordered_io+0x584/0x5ac
 ? __switch_to_asm+0x34/0x70
 ? __switch_to_asm+0x40/0x70
 ? normal_work_helper+0xfe/0x243
 ? process_one_work+0x18d/0x271
 ? rescuer_thread+0x278/0x278
 ? worker_thread+0x194/0x23f
 ? kthread+0xeb/0xf0
 ? kthread_associate_blkcg+0x86/0x86
 ? ret_from_fork+0x35/0x40
btrfs           D    0 18526  18521 0x00000000
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? schedule_timeout+0xb2/0xec
 ? __next_timer_interrupt+0xae/0xae
 ? io_schedule_timeout+0x1b/0x3d
 ? balance_dirty_pages+0x7a7/0x861
 ? __set_extent_bit+0xff/0x3f8
 ? __set_extent_bit+0x3c0/0x3f8
 ? balance_dirty_pages_ratelimited+0x204/0x225
 ? btrfs_buffered_write+0x4fd/0x5cf
 ? btrfs_file_write_iter+0x3a8/0x485
 ? __vfs_write+0x9b/0xd9
 ? vfs_write+0xa2/0xdf
 ? ksys_pwrite64+0x63/0x7f
 ? do_syscall_64+0x4e/0x5b
 ? entry_SYSCALL_64_after_hwframe+0x44/0xa9
kworker/u16:12  D    0 24060      2 0x80000000
Workqueue: btrfs-endio-write btrfs_endio_write_helper
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? schedule_timeout+0xb2/0xec
 ? __next_timer_interrupt+0xae/0xae
 ? io_schedule_timeout+0x1b/0x3d
 ? balance_dirty_pages+0x7a7/0x861
 ? usleep_range+0x7e/0x7e
 ? __slab_free.isra.72+0x89/0x1ba
 ? balance_dirty_pages_ratelimited+0x204/0x225
 ? btrfs_finish_ordered_io+0x584/0x5ac
 ? normal_work_helper+0xfe/0x243
 ? process_one_work+0x18d/0x271
 ? rescuer_thread+0x278/0x278
 ? worker_thread+0x194/0x23f
 ? kthread+0xeb/0xf0
 ? kthread_associate_blkcg+0x86/0x86
 ? ret_from_fork+0x35/0x40
kworker/u16:8   D    0 19152      2 0x80000000
Workqueue: btrfs-endio-write btrfs_endio_write_helper
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? schedule_timeout+0xb2/0xec
 ? __next_timer_interrupt+0xae/0xae
 ? io_schedule_timeout+0x1b/0x3d
 ? balance_dirty_pages+0x7a7/0x861
 ? usleep_range+0x7e/0x7e
 ? schedule+0x60/0x71
 ? schedule_timeout+0x32/0xec
 ? balance_dirty_pages_ratelimited+0x204/0x225
 ? btrfs_finish_ordered_io+0x584/0x5ac
 ? normal_work_helper+0xfe/0x243
 ? process_one_work+0x18d/0x271
 ? rescuer_thread+0x278/0x278
 ? worker_thread+0x194/0x23f
 ? kthread+0xeb/0xf0
 ? kthread_associate_blkcg+0x86/0x86
 ? ret_from_fork+0x35/0x40
kworker/u16:7   D    0 27825      2 0x80000000
Workqueue: btrfs-endio-write btrfs_endio_write_helper
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? schedule_timeout+0xb2/0xec
 ? __next_timer_interrupt+0xae/0xae
 ? io_schedule_timeout+0x1b/0x3d
 ? balance_dirty_pages+0x7a7/0x861
 ? usleep_range+0x7e/0x7e
 ? schedule+0x60/0x71
 ? schedule_timeout+0x32/0xec
 ? balance_dirty_pages_ratelimited+0x204/0x225
 ? btrfs_finish_ordered_io+0x584/0x5ac
 ? normal_work_helper+0xfe/0x243
 ? process_one_work+0x18d/0x271
 ? rescuer_thread+0x278/0x278
 ? worker_thread+0x194/0x23f
 ? kthread+0xeb/0xf0
 ? kthread_associate_blkcg+0x86/0x86
 ? ret_from_fork+0x35/0x40
kworker/u16:11  D    0 31266      2 0x80000000
Workqueue: btrfs-endio-write btrfs_endio_write_helper
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? schedule_timeout+0xb2/0xec
 ? __next_timer_interrupt+0xae/0xae
 ? io_schedule_timeout+0x1b/0x3d
 ? balance_dirty_pages+0x7a7/0x861
 ? usleep_range+0x7e/0x7e
 ? schedule+0x60/0x71
 ? schedule_timeout+0x32/0xec
 ? balance_dirty_pages_ratelimited+0x204/0x225
 ? btrfs_finish_ordered_io+0x584/0x5ac
 ? normal_work_helper+0xfe/0x243
 ? process_one_work+0x18d/0x271
 ? rescuer_thread+0x278/0x278
 ? worker_thread+0x194/0x23f
 ? kthread+0xeb/0xf0
 ? kthread_associate_blkcg+0x86/0x86
 ? ret_from_fork+0x35/0x40

Stephen.

I'm running v4.20.0 with this patch on this system, BTW.

Stephen.

Are these Sysreq+w dumps not usable?

Stephen.

Sorry for the late reply.

The hang looks pretty strange, and doesn't really look like previous deadlock caused by tree block locking.
But some strange behavior about metadata dirty pages:

This looks like to be the cause of the problem.

kworker/u16:1 D 0 19178 2 0x80000000

Workqueue: btrfs-endio-write btrfs_endio_write_helper
Call Trace:
 ? __schedule+0x4db/0x524
 ? schedule+0x60/0x71
 ? schedule_timeout+0xb2/0xec
 ? __next_timer_interrupt+0xae/0xae
 ? io_schedule_timeout+0x1b/0x3d
 ? balance_dirty_pages+0x7a7/0x861
 ? usleep_range+0x7e/0x7e
 ? schedule+0x60/0x71
 ? schedule_timeout+0x32/0xec
 ? balance_dirty_pages_ratelimited+0x204/0x225
 ? btrfs_finish_ordered_io+0x584/0x5ac
 ? normal_work_helper+0xfe/0x243
 ? process_one_work+0x18d/0x271
 ? rescuer_thread+0x278/0x278
 ? worker_thread+0x194/0x23f
 ? kthread+0xeb/0xf0
 ? kthread_associate_blkcg+0x86/0x86
 ? ret_from_fork+0x35/0x40

But I'm not familiar with balance_dirty_pages part, thus can't provide much details about this.

Thanks,
Qu

That balance_dirty_pages call was removed with the latest stable kernels (
https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux.git/commit/fs/btrfs?h=linux-4.20.y&id=480c6fb23eb80e88eba7e4603304710ee7a9416f
).

Can anyone confirm that patch https://patchwork.kernel.org/patch/10725371/
(qgroup: Don't trigger backref walk at delayed ref insert time) is present in mainline Linux kernel v5.2.2 ?

I seem to be getting a conflict on merging that patch with this kernel.

Stephen.

Upstream goes with a better solution:

Thanks,
Qu