[ 6834.100567] run fstests btrfs/232 at 2023-03-15 22:47:24
[ 6834.579180] BTRFS: device fsid 13921637-4436-40f4-9cb4-e48f1103a380 devid 1 transid 1419312 /dev/mapper/vg0-lv0 scanned by mount (861199)
[ 6834.580339] BTRFS info (device dm-0): using crc32c (crc32c-intel) checksum algorithm
[ 6834.580346] BTRFS info (device dm-0): using free space tree
[ 6834.584083] BTRFS info (device dm-0): auto enabling async discard
[ 6834.951738] BTRFS: device fsid 9d546821-afb0-4068-a8f6-591c919570a8 devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (861254)
[ 6834.987152] BTRFS info (device dm-9): using crc32c (crc32c-intel) checksum algorithm
[ 6834.987162] BTRFS info (device dm-9): disk space caching is enabled
[ 6835.007854] BTRFS info (device dm-9): auto enabling async discard
[ 6835.008206] BTRFS info (device dm-9): checking UUID tree
[ 6843.782299] BTRFS warning (device dm-9): qgroup rescan is already in progress
[ 6843.856099] BTRFS info (device dm-9): qgroup scan completed (inconsistency flag cleared)
[ 6871.752225] ------------[ cut here ]------------
[ 6871.752416] WARNING: CPU: 0 PID: 861303 at fs/btrfs/space-info.h:199 btrfs_space_info_free_bytes_may_use+0xfd/0x190
[ 6871.752427] Modules linked in: dm_thin_pool dm_persistent_data dm_bio_prison dm_log_writes dm_dust dm_flakey nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nft_fib nft_reject_inet nf_reject_ipv4 nf_reject_ipv6 nft_reject nft_ct nft_chain_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 rfkill ip6_tables nft_compat ip_set nf_tables nfnetlink iTCO_wdt iTCO_vendor_support intel_rapl_msr snd_hda_codec_generic snd_hda_intel snd_intel_dspcfg snd_hda_codec joydev snd_hwdep snd_hda_core intel_rapl_common snd_pcm snd_timer i2c_i801 i2c_smbus snd virtio_balloon soundcore lpc_ich zram ip_tables xfs crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel serio_raw qemu_fw_cfg
[ 6871.752505] CPU: 0 PID: 861303 Comm: fsstress Not tainted 6.2.0-rc8+ #1116
[ 6871.752508] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[ 6871.752513] RIP: 0010:btrfs_space_info_free_bytes_may_use+0xfd/0x190
[ 6871.752516] Code: 4d 89 e0 48 89 ea 4c 89 ee e8 3f ff f2 ff 65 ff 0d e0 65 91 5b 0f 85 51 ff ff ff 0f 1f 44 00 00 e9 47 ff ff ff 48 39 c3 76 86 <0f> 0b 31 c0 eb 83 48 8d 7d 18 be ff ff ff ff e8 4f be 8d 00 85 c0
[ 6871.752519] RSP: 0000:ffff9fa3c566bd88 EFLAGS: 00010206
[ 6871.752523] RAX: 00000000000b5000 RBX: 00000000000f6000 RCX: 0000000000000001
[ 6871.752525] RDX: 0000000000000000 RSI: ffffffffa593f1e3 RDI: ffffffffa59e2bfe
[ 6871.752527] RBP: ffff8f54c0906c00 R08: 0000000000000000 R09: 0000000000000001
[ 6871.752529] R10: 00000000000582e9 R11: 0000000000000001 R12: fffffffffff0a000
[ 6871.752530] R13: ffff8f54c50a4000 R14: 00000000000f6000 R15: ffffffffffffff86
[ 6871.752533] FS:  00007f6088f54740(0000) GS:ffff8f553bc00000(0000) knlGS:0000000000000000
[ 6871.752535] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 6871.752537] CR2: 00007f6088f52000 CR3: 00000001053dc004 CR4: 0000000000370ef0
[ 6871.752541] Call Trace:
[ 6871.752543]  
[ 6871.752548]  btrfs_free_reserved_data_space+0x4f/0x70
[ 6871.752552]  btrfs_fallocate+0xc94/0x1120
[ 6871.752568]  ? lock_acquire+0xd2/0x2d0
[ 6871.752578]  vfs_fallocate+0x148/0x440
[ 6871.752584]  __x64_sys_fallocate+0x3e/0x70
[ 6871.752589]  do_syscall_64+0x38/0x90
[ 6871.752594]  entry_SYSCALL_64_after_hwframe+0x72/0xdc
[ 6871.752597] RIP: 0033:0x7f608904d50a
[ 6871.752601] Code: d8 64 89 02 b8 ff ff ff ff eb bd 0f 1f 44 00 00 f3 0f 1e fa 49 89 ca 64 8b 04 25 18 00 00 00 85 c0 75 15 b8 1d 01 00 00 0f 05 <48> 3d 00 f0 ff ff 77 5e c3 0f 1f 44 00 00 48 83 ec 28 48 89 54 24
[ 6871.752603] RSP: 002b:00007ffd6630b688 EFLAGS: 00000246 ORIG_RAX: 000000000000011d
[ 6871.752607] RAX: ffffffffffffffda RBX: 0000000000000010 RCX: 00007f608904d50a
[ 6871.752609] RDX: 000000000029f559 RSI: 0000000000000010 RDI: 0000000000000003
[ 6871.752611] RBP: 0000000000000003 R08: 000000000000004e R09: 00007ffd6630b6ac
[ 6871.752612] R10: 00000000000f4f1b R11: 0000000000000246 R12: 000000000000018d
[ 6871.752614] R13: 00000000000f4f1b R14: 000000000029f559 R15: 0000000000000010
[ 6871.752625]  
[ 6871.752630] irq event stamp: 378243
[ 6871.752632] hardirqs last  enabled at (378249): [] __up_console_sem+0x5e/0x70
[ 6871.752636] hardirqs last disabled at (378254): [] __up_console_sem+0x43/0x70
[ 6871.752639] softirqs last  enabled at (377700): [] __irq_exit_rcu+0xfd/0x150
[ 6871.752642] softirqs last disabled at (377693): [] __irq_exit_rcu+0xfd/0x150
[ 6871.752644] ---[ end trace 0000000000000000 ]---
[ 6871.778596] ------------[ cut here ]------------
[ 6871.778829] WARNING: CPU: 0 PID: 816153 at fs/btrfs/space-info.h:199 btrfs_space_info_free_bytes_may_use+0xfd/0x190
[ 6871.778837] Modules linked in: dm_thin_pool dm_persistent_data dm_bio_prison dm_log_writes dm_dust dm_flakey nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nft_fib nft_reject_inet nf_reject_ipv4 nf_reject_ipv6 nft_reject nft_ct nft_chain_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 rfkill ip6_tables nft_compat ip_set nf_tables nfnetlink iTCO_wdt iTCO_vendor_support intel_rapl_msr snd_hda_codec_generic snd_hda_intel snd_intel_dspcfg snd_hda_codec joydev snd_hwdep snd_hda_core intel_rapl_common snd_pcm snd_timer i2c_i801 i2c_smbus snd virtio_balloon soundcore lpc_ich zram ip_tables xfs crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel serio_raw qemu_fw_cfg
[ 6871.778911] CPU: 0 PID: 816153 Comm: kworker/u4:10 Tainted: G        W          6.2.0-rc8+ #1116
[ 6871.778914] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[ 6871.778922] Workqueue: btrfs-flush_delalloc btrfs_work_helper
[ 6871.778928] RIP: 0010:btrfs_space_info_free_bytes_may_use+0xfd/0x190
[ 6871.778932] Code: 4d 89 e0 48 89 ea 4c 89 ee e8 3f ff f2 ff 65 ff 0d e0 65 91 5b 0f 85 51 ff ff ff 0f 1f 44 00 00 e9 47 ff ff ff 48 39 c3 76 86 <0f> 0b 31 c0 eb 83 48 8d 7d 18 be ff ff ff ff e8 4f be 8d 00 85 c0
[ 6871.778935] RSP: 0018:ffff9fa3c694b800 EFLAGS: 00010206
[ 6871.778938] RAX: 0000000000001000 RBX: 0000000000002000 RCX: 0000000000000001
[ 6871.778940] RDX: 0000000000000000 RSI: ffffffffa593f1e3 RDI: ffffffffa59e2bfe
[ 6871.778942] RBP: ffff8f54c0906c00 R08: 0000000000000000 R09: 0000000000000001
[ 6871.778944] R10: 000000000007f790 R11: 0000000000000001 R12: ffffffffffffe000
[ 6871.778946] R13: ffff8f54c50a4000 R14: 0000000000002000 R15: ffff8f54d3dc6200
[ 6871.778948] FS:  0000000000000000(0000) GS:ffff8f553bc00000(0000) knlGS:0000000000000000
[ 6871.778950] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 6871.778952] CR2: 00007f6088f52000 CR3: 0000000105c3a005 CR4: 0000000000370ef0
[ 6871.778956] Call Trace:
[ 6871.778959]  
[ 6871.778965]  btrfs_clear_delalloc_extent+0x17c/0x370
[ 6871.778975]  clear_state_bit+0x30/0x140
[ 6871.778982]  __clear_extent_bit+0x268/0x530
[ 6871.778991]  extent_clear_unlock_delalloc+0x36/0x60
[ 6871.778997]  run_delalloc_nocow+0x489/0x650
[ 6871.779012]  btrfs_run_delalloc_range+0x67/0x5d0
[ 6871.779017]  ? find_lock_delalloc_range+0x1fe/0x220
[ 6871.779024]  writepage_delalloc+0xa7/0x170
[ 6871.779032]  __extent_writepage+0x15a/0x4a0
[ 6871.779038]  extent_write_cache_pages+0x128/0x4f0
[ 6871.779045]  ? lock_is_held_type+0xe2/0x140
[ 6871.779052]  ? __lock_acquire+0x374/0x1e20
[ 6871.779057]  ? cpuacct_charge+0x79/0x120
[ 6871.779062]  extent_writepages+0x72/0x130
[ 6871.779069]  do_writepages+0xbf/0x1c0
[ 6871.779075]  ? lock_release+0x137/0x2d0
[ 6871.779081]  ? _raw_spin_unlock+0x29/0x50
[ 6871.779087]  filemap_fdatawrite_wbc+0x66/0x90
[ 6871.779093]  __filemap_fdatawrite_range+0x46/0x50
[ 6871.779101]  btrfs_run_delalloc_work+0x17/0x40
[ 6871.779104]  btrfs_work_helper+0xf1/0x3e0
[ 6871.779107]  ? lock_is_held_type+0xe2/0x140
[ 6871.779113]  process_one_work+0x271/0x590
[ 6871.779122]  worker_thread+0x52/0x3b0
[ 6871.779127]  ? __pfx_worker_thread+0x10/0x10
[ 6871.779130]  kthread+0xf0/0x120
[ 6871.779134]  ? __pfx_kthread+0x10/0x10
[ 6871.779139]  ret_from_fork+0x29/0x50
[ 6871.779153]  
[ 6871.779154] irq event stamp: 3283207
[ 6871.779156] hardirqs last  enabled at (3283213): [] __up_console_sem+0x5e/0x70
[ 6871.779160] hardirqs last disabled at (3283218): [] __up_console_sem+0x43/0x70
[ 6871.779163] softirqs last  enabled at (3282248): [] __irq_exit_rcu+0xfd/0x150
[ 6871.779166] softirqs last disabled at (3282087): [] __irq_exit_rcu+0xfd/0x150
[ 6871.779168] ---[ end trace 0000000000000000 ]---
[ 6906.496400] ------------[ cut here ]------------
[ 6906.496654] WARNING: CPU: 0 PID: 861317 at fs/btrfs/space-info.h:199 btrfs_add_reserved_bytes+0x224/0x2f0
[ 6906.496662] Modules linked in: dm_thin_pool dm_persistent_data dm_bio_prison dm_log_writes dm_dust dm_flakey nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nft_fib nft_reject_inet nf_reject_ipv4 nf_reject_ipv6 nft_reject nft_ct nft_chain_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 rfkill ip6_tables nft_compat ip_set nf_tables nfnetlink iTCO_wdt iTCO_vendor_support intel_rapl_msr snd_hda_codec_generic snd_hda_intel snd_intel_dspcfg snd_hda_codec joydev snd_hwdep snd_hda_core intel_rapl_common snd_pcm snd_timer i2c_i801 i2c_smbus snd virtio_balloon soundcore lpc_ich zram ip_tables xfs crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel serio_raw qemu_fw_cfg
[ 6906.496742] CPU: 0 PID: 861317 Comm: kworker/u4:9 Tainted: G        W          6.2.0-rc8+ #1116
[ 6906.496745] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[ 6906.496748] Workqueue: btrfs-flush_delalloc btrfs_work_helper
[ 6906.496753] RIP: 0010:btrfs_add_reserved_bytes+0x224/0x2f0
[ 6906.496757] Code: 0d a9 fd 90 5b 0f 85 be fe ff ff 0f 1f 44 00 00 e9 b4 fe ff ff 89 83 40 04 00 00 e9 53 fe ff ff 48 39 04 24 0f 86 e9 fe ff ff <0f> 0b 31 c0 e9 e4 fe ff ff 49 8d 7c 24 18 be ff ff ff ff 4c 89 54
[ 6906.496762] RSP: 0018:ffff9fa3c56db7b8 EFLAGS: 00010206
[ 6906.496765] RAX: 000000000001f000 RBX: ffff8f54c4faa000 RCX: 0000000000000001
[ 6906.496768] RDX: 0000000000000000 RSI: ffffffffa593f1e3 RDI: ffffffffa59e2bfe
[ 6906.496770] RBP: 0000000000020000 R08: 0000000000000000 R09: 0000000000000001
[ 6906.496772] R10: 0000000000020000 R11: ffff8f54c50a4000 R12: ffff8f54c0906c00
[ 6906.496774] R13: 0000000000000001 R14: fffffffffffe0000 R15: ffff8f54c4faa010
[ 6906.496776] FS:  0000000000000000(0000) GS:ffff8f553bc00000(0000) knlGS:0000000000000000
[ 6906.496778] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 6906.496780] CR2: 00007f6089150000 CR3: 000000011724a004 CR4: 0000000000370ef0
[ 6906.496784] Call Trace:
[ 6906.496786]  
[ 6906.496795]  find_free_extent+0x5ff/0x1610
[ 6906.496802]  ? _raw_spin_unlock+0x29/0x50
[ 6906.496807]  ? btrfs_get_alloc_profile+0x11a/0x250
[ 6906.496813]  btrfs_reserve_extent+0x13a/0x260
[ 6906.496839]  cow_file_range+0x141/0x540
[ 6906.496856]  btrfs_run_delalloc_range+0x119/0x5d0
[ 6906.496868]  writepage_delalloc+0xa7/0x170
[ 6906.496877]  __extent_writepage+0x15a/0x4a0
[ 6906.496883]  extent_write_cache_pages+0x128/0x4f0
[ 6906.496899]  extent_writepages+0x72/0x130
[ 6906.496907]  do_writepages+0xbf/0x1c0
[ 6906.496912]  ? lock_release+0x137/0x2d0
[ 6906.496920]  ? _raw_spin_unlock+0x29/0x50
[ 6906.496925]  filemap_fdatawrite_wbc+0x66/0x90
[ 6906.496930]  __filemap_fdatawrite_range+0x46/0x50
[ 6906.496939]  btrfs_run_delalloc_work+0x17/0x40
[ 6906.496943]  btrfs_work_helper+0xf1/0x3e0
[ 6906.496946]  ? lock_is_held_type+0xe2/0x140
[ 6906.496953]  process_one_work+0x271/0x590
[ 6906.496962]  ? __pfx_worker_thread+0x10/0x10
[ 6906.496965]  worker_thread+0x52/0x3b0
[ 6906.496970]  ? __pfx_worker_thread+0x10/0x10
[ 6906.496973]  kthread+0xf0/0x120
[ 6906.496977]  ? __pfx_kthread+0x10/0x10
[ 6906.496982]  ret_from_fork+0x29/0x50
[ 6906.496996]  
[ 6906.496998] irq event stamp: 60843
[ 6906.497022] hardirqs last  enabled at (60857): [] asm_sysvec_apic_timer_interrupt+0x16/0x20
[ 6906.497027] hardirqs last disabled at (60862): [] __up_console_sem+0x43/0x70
[ 6906.497031] softirqs last  enabled at (60856): [] __irq_exit_rcu+0xfd/0x150
[ 6906.497034] softirqs last disabled at (60851): [] __irq_exit_rcu+0xfd/0x150
[ 6906.497036] ---[ end trace 0000000000000000 ]---
[ 6920.727798] ------------[ cut here ]------------
[ 6920.728072] WARNING: CPU: 1 PID: 861314 at fs/btrfs/space-info.h:199 btrfs_space_info_free_bytes_may_use+0xfd/0x190
[ 6920.728079] Modules linked in: dm_thin_pool dm_persistent_data dm_bio_prison dm_log_writes dm_dust dm_flakey nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nft_fib nft_reject_inet nf_reject_ipv4 nf_reject_ipv6 nft_reject nft_ct nft_chain_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 rfkill ip6_tables nft_compat ip_set nf_tables nfnetlink iTCO_wdt iTCO_vendor_support intel_rapl_msr snd_hda_codec_generic snd_hda_intel snd_intel_dspcfg snd_hda_codec joydev snd_hwdep snd_hda_core intel_rapl_common snd_pcm snd_timer i2c_i801 i2c_smbus snd virtio_balloon soundcore lpc_ich zram ip_tables xfs crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel serio_raw qemu_fw_cfg
[ 6920.728150] CPU: 1 PID: 861314 Comm: fsstress Tainted: G        W          6.2.0-rc8+ #1116
[ 6920.728153] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[ 6920.728155] RIP: 0010:btrfs_space_info_free_bytes_may_use+0xfd/0x190
[ 6920.728158] Code: 4d 89 e0 48 89 ea 4c 89 ee e8 3f ff f2 ff 65 ff 0d e0 65 91 5b 0f 85 51 ff ff ff 0f 1f 44 00 00 e9 47 ff ff ff 48 39 c3 76 86 <0f> 0b 31 c0 eb 83 48 8d 7d 18 be ff ff ff ff e8 4f be 8d 00 85 c0
[ 6920.728161] RSP: 0018:ffff9fa3c56c3a90 EFLAGS: 00010206
[ 6920.728164] RAX: 0000000000007000 RBX: 0000000000008000 RCX: 0000000000000001
[ 6920.728166] RDX: 0000000000000000 RSI: ffffffffa593f1e3 RDI: ffffffffa59e2bfe
[ 6920.728168] RBP: ffff8f54c0906c00 R08: 0000000000000000 R09: 0000000000000001
[ 6920.728170] R10: 0000000000007947 R11: 0000000000000001 R12: ffffffffffff8000
[ 6920.728171] R13: ffff8f54c50a4000 R14: 0000000000008000 R15: ffff8f54c4e97ac0
[ 6920.728173] FS:  00007f6088f54740(0000) GS:ffff8f553bd00000(0000) knlGS:0000000000000000
[ 6920.728176] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 6920.728177] CR2: 00007f6088f53000 CR3: 0000000161fbc004 CR4: 0000000000370ee0
[ 6920.728181] Call Trace:
[ 6920.728184]  
[ 6920.728190]  btrfs_check_data_free_space+0xa9/0xf0
[ 6920.728196]  btrfs_buffered_write+0x1ff/0x830
[ 6920.728202]  ? __lock_acquire+0x374/0x1e20
[ 6920.728213]  btrfs_do_write_iter+0x3cd/0x5f0
[ 6920.728217]  ? lock_is_held_type+0xe2/0x140
[ 6920.728225]  do_iter_readv_writev+0xc2/0x110
[ 6920.728233]  do_iter_write+0x80/0x1c0
[ 6920.728238]  iter_file_splice_write+0x272/0x410
[ 6920.728252]  direct_splice_actor+0x29/0x40
[ 6920.728255]  splice_direct_to_actor+0xd1/0x1f0
[ 6920.728259]  ? __pfx_direct_splice_actor+0x10/0x10
[ 6920.728266]  do_splice_direct+0x7b/0xb0
[ 6920.728273]  generic_copy_file_range+0x4b/0x80
[ 6920.728277]  vfs_copy_file_range+0x171/0x5c0
[ 6920.728286]  __do_sys_copy_file_range+0xc4/0x1f0
[ 6920.728292]  do_syscall_64+0x38/0x90
[ 6920.728297]  entry_SYSCALL_64_after_hwframe+0x72/0xdc
[ 6920.728300] RIP: 0033:0x7f608905211d
[ 6920.728304] Code: c5 0c 00 0f 05 eb a9 66 0f 1f 44 00 00 f3 0f 1e fa 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 23 7d 0c 00 f7 d8 64 89 01 48
[ 6920.728306] RSP: 002b:00007ffd6630b1c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000146
[ 6920.728309] RAX: ffffffffffffffda RBX: 00000000006a1000 RCX: 00007f608905211d
[ 6920.728311] RDX: 0000000000000004 RSI: 00007ffd6630b200 RDI: 0000000000000003
[ 6920.728313] RBP: 0000000000000003 R08: 00000000000100da R09: 0000000000000000
[ 6920.728315] R10: 00007ffd6630b208 R11: 0000000000000246 R12: 0000000000000275
[ 6920.728316] R13: 0000000000000004 R14: 00000000000100da R15: 00000000005b828d
[ 6920.728327]  
[ 6920.728329] irq event stamp: 928713
[ 6920.728331] hardirqs last  enabled at (928719): [] __up_console_sem+0x5e/0x70
[ 6920.728335] hardirqs last disabled at (928724): [] __up_console_sem+0x43/0x70
[ 6920.728338] softirqs last  enabled at (928110): [] __irq_exit_rcu+0xfd/0x150
[ 6920.728340] softirqs last disabled at (928103): [] __irq_exit_rcu+0xfd/0x150
[ 6920.728343] ---[ end trace 0000000000000000 ]---
[ 6983.637146] BTRFS: device fsid 9d546821-afb0-4068-a8f6-591c919570a8 devid 1 transid 5227 /dev/mapper/vg0-lv9 scanned by mount (861340)
[ 6983.638725] BTRFS info (device dm-9): using crc32c (crc32c-intel) checksum algorithm
[ 6983.638733] BTRFS info (device dm-9): disk space caching is enabled
[ 6983.642477] BTRFS info (device dm-9): auto enabling async discard