btrfs_rename2 and hangs with 5.2.1

btrfs_rename2 and hangs with 5.2.1

[Russell Coker]

[-- Attachment #1: Type: text/plain, Size: 863 bytes --]

The file log.txt has one of many kernel message logs (logged via syslog) about 
btrfs_rename2 that happened while the laptop in question was apparently 
working OK.

The file dm.txt has part of the output of dmesg after the system got into a 
state where all disk access was going to D state, that wasn't logged via 
syslog because writing to files was impossible.

Any suggestions on what to do to further debug this?  The problem of all 
processes going to D state happens periodically, so presumably it will happen 
again soon enough.  I've got the commonly used utilities like cat, dmesg, ssh, 
etc locked in RAM so I can run them without disk access.  It appears that the 
BTRFS filesystem (which is used for all storage on the laptop) works fine as 
long there is only reads from cache.

I've tried kernel 5.2.11 but that one hangs on resume.

[-- Attachment #2: log.txt --]
[-- Type: text/plain, Size: 6113 bytes --]

Sep 10 10:47:13 neuromancer kernel: [31562.243971] WARNING: CPU: 0 PID: 6003 at fs/btrfs/inode.c:9773 btrfs_rename2+0x6d9/0x1d30 [btrfs]
Sep 10 10:47:13 neuromancer kernel: [31562.243974] Modules linked in: fuse(E) ufs(E) qnx4(E) hfsplus(E) hfs(E) minix(E) ntfs(E) vfat(E) msdos(E) fat(E) jfs(E) xfs(E) cpuid(E) ctr(E) ccm(E) loop(E) sd_mod(E) sg(E) nft_counter(E) xt_MASQUERADE(E) nft_compat(E) nft_chain_nat(E) nf_nat(E) nf_conntrack(E) nf_defrag_ipv6(E) nf_defrag_ipv4(E) uas(E) usb_storage(E) nf_tables(E) scsi_mod(E) nfnetlink(E) uvcvideo(E) bridge(E) stp(E) llc(E) videobuf2_vmalloc(E) videobuf2_memops(E) videobuf2_v4l2(E) videobuf2_common(E) videodev(E) media(E) snd_hda_codec_realtek(E) snd_hda_codec_generic(E) arc4(E) snd_soc_skl(E) snd_soc_skl_ipc(E) snd_soc_sst_ipc(E) snd_soc_sst_dsp(E) snd_hda_ext_core(E) iwlmvm(E) snd_soc_acpi_intel_match(E) intel_rapl(E) x86_pkg_temp_thermal(E) intel_powerclamp(E) coretemp(E) snd_soc_acpi(E) mac80211(E) kvm_intel(E) snd_soc_core(E) i915(E) kvm(E) irqbypass(E) snd_compress(E) iwlwifi(E) iTCO_wdt(E) iTCO_vendor_support(E) snd_hda_intel(E) xhci_pci(E) crct10dif_pclmul(E) crc32_pclmul(E) wmi_bmof(E) snd_hda_codec(E)
Sep 10 10:47:13 neuromancer kernel: [31562.244013]  drm_kms_helper(E) xhci_hcd(E) drm(E) snd_hda_core(E) ghash_clmulni_intel(E) tpm_crb(E) snd_hwdep(E) cfg80211(E) intel_cstate(E) pcspkr(E) idma64(E) usbcore(E) thinkpad_acpi(E) snd_pcm(E) nvram(E) tpm_tis(E) mei_me(E) tpm_tis_core(E) int3403_thermal(E) snd_timer(E) intel_uncore(E) i2c_i801(E) ucsi_acpi(E) intel_lpss_pci(E) ledtrig_audio(E) typec_ucsi(E) intel_rapl_perf(E) snd(E) tpm(E) processor_thermal_device(E) e1000e(E) i2c_algo_bit(E) intel_lpss(E) intel_soc_dts_iosf(E) intel_pch_thermal(E) int340x_thermal_zone(E) battery(E) ac(E) rng_core(E) mei(E) soundcore(E) rfkill(E) typec(E) wmi(E) video(E) int3400_thermal(E) acpi_thermal_rel(E) acpi_pad(E) button(E) pcc_cpufreq(E) ip_tables(E) x_tables(E) autofs4(E) btrfs(E) libcrc32c(E) xor(E) zstd_decompress(E) zstd_compress(E) raid6_pq(E) algif_skcipher(E) af_alg(E) dm_crypt(E) dm_mod(E) virtio_pci(E) virtio_blk(E) virtio_ring(E) virtio(E) ext4(E) crc32c_generic(E) crc16(E) mbcache(E) jbd2(E) crc32c_intel(E) aesni_intel(E) nvme(E)
Sep 10 10:47:13 neuromancer kernel: [31562.244054]  aes_x86_64(E) glue_helper(E) crypto_simd(E) evdev(E) cryptd(E) psmouse(E) serio_raw(E) nvme_core(E) thermal(E)
Sep 10 10:47:13 neuromancer kernel: [31562.244065] CPU: 0 PID: 6003 Comm: ThreadPoolForeg Tainted: G        W   E     5.2.1 #1
Sep 10 10:47:13 neuromancer kernel: [31562.244067] Hardware name: LENOVO 20KHS0L900/20KHS0L900, BIOS N23ET56W (1.31 ) 09/17/2018
Sep 10 10:47:13 neuromancer kernel: [31562.244111] RIP: 0010:btrfs_rename2+0x6d9/0x1d30 [btrfs]
Sep 10 10:47:13 neuromancer kernel: [31562.244114] Code: 74 24 40 48 8b bd 48 ff ff ff e8 d2 26 fe ff 89 85 50 ff ff ff 85 c0 0f 84 e5 fa ff ff 83 bd 50 ff ff ff ef 0f 85 dc fd ff ff <0f> 0b e9 d5 fd ff ff 89 85 50 ff ff ff e9 34 ff ff ff 4d 8b 4c 24
Sep 10 10:47:13 neuromancer kernel: [31562.244116] RSP: 0018:ffffab7a03ddfc80 EFLAGS: 00010246
Sep 10 10:47:13 neuromancer kernel: [31562.244118] RAX: 00000000ffffffef RBX: ffff9eeb0aa837d0 RCX: 0000000000000000
Sep 10 10:47:13 neuromancer kernel: [31562.244120] RDX: 000000000047c556 RSI: ffff9eec2a634800 RDI: fffff6d14012b980
Sep 10 10:47:13 neuromancer kernel: [31562.244121] RBP: ffffab7a03ddfd90 R08: 0000000000034800 R09: ffffffffc0481049
Sep 10 10:47:13 neuromancer kernel: [31562.244122] R10: 0000000000003000 R11: 0000000000000003 R12: ffff9eeb591cc9b0
Sep 10 10:47:13 neuromancer kernel: [31562.244124] R13: ffff9eeb9c39cb40 R14: 000000000065ce98 R15: 0000000000000000
Sep 10 10:47:13 neuromancer kernel: [31562.244126] FS:  00007ff8adb50700(0000) GS:ffff9eec2a600000(0000) knlGS:0000000000000000
Sep 10 10:47:13 neuromancer kernel: [31562.244128] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Sep 10 10:47:13 neuromancer kernel: [31562.244129] CR2: 00001956959b5020 CR3: 00000001a045e006 CR4: 00000000003606f0
Sep 10 10:47:13 neuromancer kernel: [31562.244131] Call Trace:
Sep 10 10:47:13 neuromancer kernel: [31562.244142]  ? _cond_resched+0x15/0x30
Sep 10 10:47:13 neuromancer kernel: [31562.244148]  ? selinux_inode_rename+0x193/0x250
Sep 10 10:47:13 neuromancer kernel: [31562.244153]  ? vfs_rename+0x303/0x9b0
Sep 10 10:47:13 neuromancer kernel: [31562.244194]  ? btrfs_create+0x1f0/0x1f0 [btrfs]
Sep 10 10:47:13 neuromancer kernel: [31562.244197]  vfs_rename+0x303/0x9b0
Sep 10 10:47:13 neuromancer kernel: [31562.244200]  ? __d_lookup+0x5e/0x140
Sep 10 10:47:13 neuromancer kernel: [31562.244204]  ? __lookup_hash+0x1f/0xa0
Sep 10 10:47:13 neuromancer kernel: [31562.244206]  do_renameat2+0x3bc/0x560
Sep 10 10:47:13 neuromancer kernel: [31562.244211]  __x64_sys_rename+0x1c/0x20
Sep 10 10:47:13 neuromancer kernel: [31562.244216]  do_syscall_64+0x55/0x110
Sep 10 10:47:13 neuromancer kernel: [31562.244221]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
Sep 10 10:47:13 neuromancer kernel: [31562.244225] RIP: 0033:0x7ff8bb47d6d7
Sep 10 10:47:13 neuromancer kernel: [31562.244228] Code: e8 6e e9 07 00 85 c0 0f 95 c0 0f b6 c0 f7 d8 5b c3 66 90 b8 ff ff ff ff 5b c3 66 0f 1f 84 00 00 00 00 00 b8 52 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 01 c3 48 8b 15 89 d7 14 00 f7 d8 64 89 02 b8
Sep 10 10:47:13 neuromancer kernel: [31562.244229] RSP: 002b:00007ff8adb4ed48 EFLAGS: 00000246 ORIG_RAX: 0000000000000052
Sep 10 10:47:13 neuromancer kernel: [31562.244232] RAX: ffffffffffffffda RBX: 00007ff8adb4ed50 RCX: 00007ff8bb47d6d7
Sep 10 10:47:13 neuromancer kernel: [31562.244233] RDX: 0000000000000000 RSI: 0000557ab15e09f0 RDI: 00007ff898005f30
Sep 10 10:47:13 neuromancer kernel: [31562.244234] RBP: 00007ff8adb4edc0 R08: 0000000000000000 R09: 00007fffd32690b0
Sep 10 10:47:13 neuromancer kernel: [31562.244236] R10: 00007fffd3269080 R11: 0000000000000246 R12: 0000000000000001
Sep 10 10:47:13 neuromancer kernel: [31562.244237] R13: 00007ff8adb4edfc R14: 00007ff8adb4ee00 R15: 00007ff8a01f99f0
Sep 10 10:47:13 neuromancer kernel: [31562.244241] ---[ end trace 800a03a8710007af ]---

[-- Attachment #3: dm.txt --]
[-- Type: text/plain, Size: 14868 bytes --]

[39320.063233] WARNING: CPU: 1 PID: 26818 at fs/btrfs/inode.c:9773 btrfs_rename2+0x6d9/0x1d30 [btrfs]
[39320.063236] Modules linked in: fuse(E) ufs(E) qnx4(E) hfsplus(E) hfs(E) minix(E) ntfs(E) vfat(E) msdos(E) fat(E) jfs(E) xfs(E) cpuid(E) ctr(E) ccm(E) loop(E) sd_mod(E) sg(E) nft_counter(E) xt_MASQUERADE(E) nft_compat(E) nft_chain_nat(E) nf_nat(E) nf_conntrack(E) nf_defrag_ipv6(E) nf_defrag_ipv4(E) uas(E) usb_storage(E) nf_tables(E) scsi_mod(E) nfnetlink(E) uvcvideo(E) bridge(E) stp(E) llc(E) videobuf2_vmalloc(E) videobuf2_memops(E) videobuf2_v4l2(E) videobuf2_common(E) videodev(E) media(E) snd_hda_codec_realtek(E) snd_hda_codec_generic(E) arc4(E) snd_soc_skl(E) snd_soc_skl_ipc(E) snd_soc_sst_ipc(E) snd_soc_sst_dsp(E) snd_hda_ext_core(E) iwlmvm(E) snd_soc_acpi_intel_match(E) intel_rapl(E) x86_pkg_temp_thermal(E) intel_powerclamp(E) coretemp(E) snd_soc_acpi(E) mac80211(E) kvm_intel(E) snd_soc_core(E) i915(E) kvm(E) irqbypass(E) snd_compress(E) iwlwifi(E) iTCO_wdt(E) iTCO_vendor_support(E) snd_hda_intel(E) xhci_pci(E) crct10dif_pclmul(E) crc32_pclmul(E) wmi_bmof(E) snd_hda_codec(E)
[39320.063283]  drm_kms_helper(E) xhci_hcd(E) drm(E) snd_hda_core(E) ghash_clmulni_intel(E) tpm_crb(E) snd_hwdep(E) cfg80211(E) intel_cstate(E) pcspkr(E) idma64(E) usbcore(E) thinkpad_acpi(E) snd_pcm(E) nvram(E) tpm_tis(E) mei_me(E) tpm_tis_core(E) int3403_thermal(E) snd_timer(E) intel_uncore(E) i2c_i801(E) ucsi_acpi(E) intel_lpss_pci(E) ledtrig_audio(E) typec_ucsi(E) intel_rapl_perf(E) snd(E) tpm(E) processor_thermal_device(E) e1000e(E) i2c_algo_bit(E) intel_lpss(E) intel_soc_dts_iosf(E) intel_pch_thermal(E) int340x_thermal_zone(E) battery(E) ac(E) rng_core(E) mei(E) soundcore(E) rfkill(E) typec(E) wmi(E) video(E) int3400_thermal(E) acpi_thermal_rel(E) acpi_pad(E) button(E) pcc_cpufreq(E) ip_tables(E) x_tables(E) autofs4(E) btrfs(E) libcrc32c(E) xor(E) zstd_decompress(E) zstd_compress(E) raid6_pq(E) algif_skcipher(E) af_alg(E) dm_crypt(E) dm_mod(E) virtio_pci(E) virtio_blk(E) virtio_ring(E) virtio(E) ext4(E) crc32c_generic(E) crc16(E) mbcache(E) jbd2(E) crc32c_intel(E) aesni_intel(E) nvme(E)
[39320.063332]  aes_x86_64(E) glue_helper(E) crypto_simd(E) evdev(E) cryptd(E) psmouse(E) serio_raw(E) nvme_core(E) thermal(E)
[39320.063344] CPU: 1 PID: 26818 Comm: ThreadPoolForeg Tainted: G        W   E     5.2.1 #1
[39320.063346] Hardware name: LENOVO 20KHS0L900/20KHS0L900, BIOS N23ET56W (1.31 ) 09/17/2018
[39320.063400] RIP: 0010:btrfs_rename2+0x6d9/0x1d30 [btrfs]
[39320.063405] Code: 74 24 40 48 8b bd 48 ff ff ff e8 d2 26 fe ff 89 85 50 ff ff ff 85 c0 0f 84 e5 fa ff ff 83 bd 50 ff ff ff ef 0f 85 dc fd ff ff <0f> 0b e9 d5 fd ff ff 89 85 50 ff ff ff e9 34 ff ff ff 4d 8b 4c 24
[39320.063407] RSP: 0018:ffffab7a051efc80 EFLAGS: 00010246
[39320.063410] RAX: 00000000ffffffef RBX: ffff9eebc5e0ed70 RCX: 0000000000000000
[39320.063412] RDX: 00000000005a0fad RSI: ffff9eec2a6b4800 RDI: fffff6d1445acc80
[39320.063413] RBP: ffffab7a051efd90 R08: 0000000000034800 R09: ffffffffc0481049
[39320.063415] R10: 0000000000003000 R11: 0000000000000003 R12: ffff9eeb591cc9b0
[39320.063417] R13: ffff9eeb2fb9e0c0 R14: 000000000065dd64 R15: 0000000000000000
[39320.063420] FS:  00007ff84ffff700(0000) GS:ffff9eec2a680000(0000) knlGS:0000000000000000
[39320.063422] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[39320.063423] CR2: 00002f3f8dbae000 CR3: 00000001a045e002 CR4: 00000000003606e0
[39320.063425] Call Trace:
[39320.063439]  ? _cond_resched+0x15/0x30
[39320.063446]  ? selinux_inode_rename+0x193/0x250
[39320.063452]  ? vfs_rename+0x303/0x9b0
[39320.063504]  ? btrfs_create+0x1f0/0x1f0 [btrfs]
[39320.063507]  vfs_rename+0x303/0x9b0
[39320.063511]  ? __d_lookup+0x5e/0x140
[39320.063515]  ? __lookup_hash+0x1f/0xa0
[39320.063519]  do_renameat2+0x3bc/0x560
[39320.063524]  __x64_sys_rename+0x1c/0x20
[39320.063530]  do_syscall_64+0x55/0x110
[39320.063537]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[39320.063541] RIP: 0033:0x7ff8bb47d6d7
[39320.063544] Code: e8 6e e9 07 00 85 c0 0f 95 c0 0f b6 c0 f7 d8 5b c3 66 90 b8 ff ff ff ff 5b c3 66 0f 1f 84 00 00 00 00 00 b8 52 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 01 c3 48 8b 15 89 d7 14 00 f7 d8 64 89 02 b8
[39320.063546] RSP: 002b:00007ff84fffdd48 EFLAGS: 00000246 ORIG_RAX: 0000000000000052
[39320.063549] RAX: ffffffffffffffda RBX: 00007ff84fffdd50 RCX: 00007ff8bb47d6d7
[39320.063551] RDX: 0000000000000000 RSI: 00007ff8a029b180 RDI: 00007ff898011710
[39320.063552] RBP: 00007ff84fffddc0 R08: 0000000000000000 R09: 00007fffd32690b0
[39320.063554] R10: 00007fffd3269080 R11: 0000000000000246 R12: 0000000000000001
[39320.063556] R13: 00007ff84fffddfc R14: 00007ff84fffde00 R15: 00007ff8a031fec0
[39320.063560] ---[ end trace 800a03a8710007b1 ]---
[42774.436060] INFO: task kcompactd0:35 blocked for more than 120 seconds.
[42774.436072]       Tainted: G        W   E     5.2.1 #1
[42774.436075] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[42774.436079] kcompactd0      D    0    35      2 0x80004000
[42774.436085] Call Trace:
[42774.436103]  ? __schedule+0x2bb/0x690
[42774.436108]  schedule+0x29/0x90
[42774.436113]  io_schedule+0x12/0x40
[42774.436118]  __lock_page+0x141/0x210
[42774.436127]  ? file_fdatawait_range+0x20/0x20
[42774.436134]  migrate_pages+0x754/0xb70
[42774.436139]  ? isolate_freepages_block+0x390/0x390
[42774.436147]  ? __bpf_trace_mm_compaction_kcompactd_sleep+0x10/0x10
[42774.436151]  compact_zone+0x6d8/0xcb0
[42774.436158]  ? syscall_return_via_sysret+0xf/0x7f
[42774.436163]  kcompactd_do_work+0x131/0x2d0
[42774.436168]  ? __switch_to_asm+0x40/0x70
[42774.436172]  ? __switch_to_asm+0x34/0x70
[42774.436178]  ? kcompactd_do_work+0x2d0/0x2d0
[42774.436180]  kcompactd+0x83/0x1c0
[42774.436185]  ? finish_wait+0x80/0x80
[42774.436190]  kthread+0x112/0x130
[42774.436194]  ? __kthread_parkme+0x70/0x70
[42774.436200]  ret_from_fork+0x35/0x40
[42774.436217] INFO: task btrfs-transacti:306 blocked for more than 120 seconds.
[42774.436221]       Tainted: G        W   E     5.2.1 #1
[42774.436223] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[42774.436226] btrfs-transacti D    0   306      2 0x80004000
[42774.436230] Call Trace:
[42774.436235]  ? __schedule+0x2bb/0x690
[42774.436239]  schedule+0x29/0x90
[42774.436308]  wait_current_trans+0xc3/0xf0 [btrfs]
[42774.436316]  ? finish_wait+0x80/0x80
[42774.436376]  start_transaction+0x2cc/0x470 [btrfs]
[42774.436433]  transaction_kthread+0xab/0x170 [btrfs]
[42774.436489]  ? btrfs_cleanup_transaction+0x530/0x530 [btrfs]
[42774.436494]  kthread+0x112/0x130
[42774.436499]  ? __kthread_parkme+0x70/0x70
[42774.436507]  ret_from_fork+0x35/0x40
[42774.436613] INFO: task ThreadPoolForeg:27827 blocked for more than 120 seconds.
[42774.436619]       Tainted: G        W   E     5.2.1 #1
[42774.436622] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[42774.436625] ThreadPoolForeg D    0 27827   1388 0x00000080
[42774.436629] Call Trace:
[42774.436637]  ? __schedule+0x2bb/0x690
[42774.436642]  schedule+0x29/0x90
[42774.436710]  wait_current_trans+0xc3/0xf0 [btrfs]
[42774.436720]  ? finish_wait+0x80/0x80
[42774.436780]  start_transaction+0x3a2/0x470 [btrfs]
[42774.436842]  btrfs_create+0x58/0x1f0 [btrfs]
[42774.436851]  path_openat+0x11da/0x15c0
[42774.436858]  do_filp_open+0x93/0x100
[42774.436865]  ? __check_object_size+0x15d/0x189
[42774.436871]  do_sys_open+0x186/0x220
[42774.436879]  do_syscall_64+0x55/0x110
[42774.436887]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[42774.436893] RIP: 0033:0x7fc035f14d0e
[42774.436905] Code: Bad RIP value.
[42774.436907] RSP: 002b:00007fc002506630 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
[42774.436912] RAX: ffffffffffffffda RBX: 00007fc0025066a8 RCX: 00007fc035f14d0e
[42774.436914] RDX: 0000000000000241 RSI: 00000bdaf1390f50 RDI: 00000000ffffff9c
[42774.436916] RBP: 00007fc002506710 R08: 0000000000000000 R09: 00007fff111fa0b0
[42774.436918] R10: 0000000000000180 R11: 0000000000000293 R12: 0000000000000241
[42774.436919] R13: 00007fc002506760 R14: 00007fc0025067f8 R15: 0000000000000048
[42774.436934] INFO: task ThreadPoolForeg:26001 blocked for more than 120 seconds.
[42774.436938]       Tainted: G        W   E     5.2.1 #1
[42774.436941] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[42774.436943] ThreadPoolForeg D    0 26001   2943 0x00000080
[42774.436946] Call Trace:
[42774.436952]  ? __schedule+0x2bb/0x690
[42774.436956]  schedule+0x29/0x90
[42774.437014]  wait_current_trans+0xc3/0xf0 [btrfs]
[42774.437020]  ? finish_wait+0x80/0x80
[42774.437080]  start_transaction+0x3a2/0x470 [btrfs]
[42774.437145]  btrfs_create+0x58/0x1f0 [btrfs]
[42774.437152]  path_openat+0x11da/0x15c0
[42774.437158]  ? __fprop_inc_percpu_max+0xa1/0xb0
[42774.437163]  do_filp_open+0x93/0x100
[42774.437169]  ? __check_object_size+0x15d/0x189
[42774.437176]  do_sys_open+0x186/0x220
[42774.437182]  do_syscall_64+0x55/0x110
[42774.437189]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[42774.437193] RIP: 0033:0x7f2f8cf5b239
[42774.437198] Code: Bad RIP value.
[42774.437200] RSP: 002b:00007f2f83e32fa0 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
[42774.437203] RAX: ffffffffffffffda RBX: 000000000003a2f8 RCX: 00007f2f8cf5b239
[42774.437206] RDX: 00000000000000c2 RSI: 00000835a479b4e0 RDI: 00000000ffffff9c
[42774.437208] RBP: 0000000000000000 R08: 0000000000000000 R09: 00000835a51ff390
[42774.437210] R10: 0000000000000180 R11: 0000000000000293 R12: 00007f2f8cffa560
[42774.437212] R13: 00000000000000c2 R14: 00000835a479b51b R15: 8421084210842109
[42774.437218] INFO: task ThreadPoolForeg:28383 blocked for more than 120 seconds.
[42774.437222]       Tainted: G        W   E     5.2.1 #1
[42774.437224] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[42774.437226] ThreadPoolForeg D    0 28383   2943 0x00004080
[42774.437230] Call Trace:
[42774.437236]  ? __schedule+0x2bb/0x690
[42774.437241]  ? bit_wait_timeout+0x90/0x90
[42774.437245]  ? bit_wait_timeout+0x90/0x90
[42774.437249]  schedule+0x29/0x90
[42774.437253]  io_schedule+0x12/0x40
[42774.437258]  bit_wait_io+0xd/0x50
[42774.437262]  __wait_on_bit+0x73/0x90
[42774.437267]  out_of_line_wait_on_bit+0x91/0xb0
[42774.437273]  ? init_wait_var_entry+0x40/0x40
[42774.437349]  lock_extent_buffer_for_io+0xc4/0x2d0 [btrfs]
[42774.437427]  btree_write_cache_pages+0x149/0x350 [btrfs]
[42774.437438]  ? recalibrate_cpu_khz+0x10/0x10
[42774.437446]  ? ktime_get+0x36/0xa0
[42774.437453]  do_writepages+0x41/0xd0
[42774.437555]  ? clear_state_bit+0xe6/0x1a0 [btrfs]
[42774.437564]  __filemap_fdatawrite_range+0xbe/0xf0
[42774.437626]  btrfs_write_marked_extents+0x68/0x150 [btrfs]
[42774.437687]  btrfs_write_and_wait_transaction.isra.24+0x4d/0xa0 [btrfs]
[42774.437749]  btrfs_commit_transaction+0x72d/0x9a0 [btrfs]
[42774.437759]  ? dput.part.32+0xa1/0x130
[42774.437828]  ? btrfs_log_dentry_safe+0x54/0x70 [btrfs]
[42774.437899]  btrfs_sync_file+0x3af/0x3f0 [btrfs]
[42774.437910]  do_fsync+0x38/0x70
[42774.437917]  __x64_sys_fdatasync+0x13/0x20
[42774.437925]  do_syscall_64+0x55/0x110
[42774.437934]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[42774.437939] RIP: 0033:0x7f2f8cf622e7
[42774.437946] Code: Bad RIP value.
[42774.437948] RSP: 002b:00007f2f84e48d00 EFLAGS: 00000293 ORIG_RAX: 000000000000004b
[42774.437952] RAX: ffffffffffffffda RBX: 000000000000001f RCX: 00007f2f8cf622e7
[42774.437954] RDX: 0000000000000000 RSI: 0000000000000002 RDI: 000000000000001f
[42774.437956] RBP: 00007f2f84e48d50 R08: 0000000000000000 R09: 0000560fbb4191c8
[42774.437958] R10: 000000000001b400 R11: 0000000000000293 R12: 0000000000000000
[42774.437960] R13: d763a120f905d5d9 R14: 0000000000000000 R15: 0000000000001000
[42774.437966] INFO: task ThreadPoolForeg:28470 blocked for more than 120 seconds.
[42774.437970]       Tainted: G        W   E     5.2.1 #1
[42774.437973] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[42774.437975] ThreadPoolForeg D    0 28470   2943 0x00000080
[42774.437978] Call Trace:
[42774.437984]  ? __schedule+0x2bb/0x690
[42774.437988]  schedule+0x29/0x90
[42774.438048]  wait_current_trans+0xc3/0xf0 [btrfs]
[42774.438056]  ? finish_wait+0x80/0x80
[42774.438114]  start_transaction+0x3a2/0x470 [btrfs]
[42774.438174]  btrfs_create+0x58/0x1f0 [btrfs]
[42774.438182]  path_openat+0x11da/0x15c0
[42774.438188]  ? __hrtimer_init+0x11/0xb0
[42774.438194]  ? futex_wake+0x90/0x170
[42774.438198]  do_filp_open+0x93/0x100
[42774.438204]  ? __check_object_size+0x15d/0x189
[42774.438210]  do_sys_open+0x186/0x220
[42774.438216]  do_syscall_64+0x55/0x110
[42774.438222]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[42774.438225] RIP: 0033:0x7f2f8f333d0e
[42774.438230] Code: Bad RIP value.
[42774.438232] RSP: 002b:00007f2f85649fd0 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
[42774.438235] RAX: ffffffffffffffda RBX: 00007f2f8564a048 RCX: 00007f2f8f333d0e
[42774.438237] RDX: 00000000000000c2 RSI: 00000835a61d7600 RDI: 00000000ffffff9c
[42774.438238] RBP: 00007f2f8564a0b0 R08: 0000000000000000 R09: 00007ffe3ef090b0
[42774.438240] R10: 0000000000000180 R11: 0000000000000293 R12: 00000000000000c2
[42774.438242] R13: 00007f2f8564a100 R14: 00000835a61f5980 R15: 0000000000008062
[42774.438312] INFO: task ThreadPoolForeg:22033 blocked for more than 120 seconds.
[42774.438315]       Tainted: G        W   E     5.2.1 #1
[42774.438317] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[42774.438320] ThreadPoolForeg D    0 22033  21592 0x00004080
[42774.438323] Call Trace:
[42774.438328]  ? __schedule+0x2bb/0x690
[42774.438332]  schedule+0x29/0x90
[42774.438383]  wait_for_commit+0x58/0x80 [btrfs]
[42774.438389]  ? finish_wait+0x80/0x80
[42774.438439]  btrfs_commit_transaction+0x144/0x9a0 [btrfs]
[42774.438446]  ? dput.part.32+0xa1/0x130
[42774.438507]  ? btrfs_log_dentry_safe+0x54/0x70 [btrfs]
[42774.438563]  btrfs_sync_file+0x3af/0x3f0 [btrfs]
[42774.438571]  do_fsync+0x38/0x70
[42774.438576]  __x64_sys_fdatasync+0x13/0x20
[42774.438581]  do_syscall_64+0x55/0x110
[42774.438587]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[42774.438589] RIP: 0033:0x7fd089b172e7
[42774.438594] Code: Bad RIP value.
[42774.438596] RSP: 002b:00007fd080abd960 EFLAGS: 00000293 ORIG_RAX: 000000000000004b
[42774.438599] RAX: ffffffffffffffda RBX: 00000000000000cb RCX: 00007fd089b172e7
[42774.438600] RDX: 0000000000000000 RSI: 0000000000000002 RDI: 00000000000000cb
[42774.438602] RBP: 00007fd080abd9a0 R08: 0000000000000008 R09: 0000000000000038
[42774.438604] R10: 0000000000009400 R11: 0000000000000293 R12: 0000000000000000
[42774.438606] R13: 0000000000000000 R14: 0000000000009400 R15: 0000000000000000