[ 4773.624196] run fstests btrfs/190 at 2022-04-03 22:10:57
[ 4774.169589] BTRFS: device fsid 7a06b137-237c-4d2a-a56b-1dd367460a8f devid 1 transid 6 /dev/mapper/logwrites-test scanned by mkfs.btrfs (948274)
[ 4774.177035] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 4774.177272] BTRFS info (device dm-11): turning on async discard
[ 4774.177455] BTRFS info (device dm-11): disk space caching is enabled
[ 4774.177672] BTRFS info (device dm-11): has skinny extents
[ 4774.179024] BTRFS info (device dm-11): checking UUID tree
[ 4774.228742] BTRFS warning (device dm-11): qgroup rescan is already in progress
[ 4774.241581] BTRFS info (device dm-11): qgroup scan completed (inconsistency flag cleared)
[ 4775.527361] BTRFS info (device dm-11): balance: start -f -m -s
[ 4775.527869] BTRFS info (device dm-11): relocating block group 30408704 flags metadata|dup
[ 4775.652553] BTRFS info (device dm-11): found 82 extents, stage: move data extents
[ 4775.745453] BTRFS info (device dm-11): relocating block group 22020096 flags system|dup
[ 4775.794016] BTRFS info (device dm-11): found 1 extents, stage: move data extents
[ 4775.837220] BTRFS info (device dm-11): balance: ended with status: 0
[ 4775.928519] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[ 4775.928787] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 949336, name: replay-log
[ 4775.929039] preempt_count: 101, expected: 0
[ 4775.929195] RCU nest depth: 0, expected: 0
[ 4775.929341] INFO: lockdep is turned off.
[ 4775.929484] Preemption disabled at:
[ 4775.929485] [] folio_add_lru+0x40/0x220
[ 4775.936026] CPU: 1 PID: 949336 Comm: replay-log Tainted: G        W         5.17.0+ #641
[ 4775.936339] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[ 4775.936601] Call Trace:
[ 4775.936727]  
[ 4775.936846]  dump_stack_lvl+0x56/0x6f
[ 4775.936988]  __might_resched.cold+0xff/0x13a
[ 4775.937141]  blk_release_queue+0x24/0x120
[ 4775.937296]  kobject_put+0x7c/0x1d0
[ 4775.937434]  ? rcu_do_batch+0x1ac/0x570
[ 4775.937574]  blkg_free.part.0+0x41/0x60
[ 4775.937719]  rcu_do_batch+0x1e1/0x570
[ 4775.937857]  ? rcu_do_batch+0x1ac/0x570
[ 4775.937998]  rcu_core+0x2cb/0x460
[ 4775.938135]  __do_softirq+0x178/0x517
[ 4775.938281]  __irq_exit_rcu+0xe3/0x160
[ 4775.938423]  irq_exit_rcu+0xa/0x20
[ 4775.938578]  sysvec_apic_timer_interrupt+0xa2/0xd0
[ 4775.938741]  
[ 4775.938852]  
[ 4775.938963]  asm_sysvec_apic_timer_interrupt+0x12/0x20
[ 4775.939129] RIP: 0010:lock_release+0x1f8/0x2c0
[ 4775.939285] Code: ff 0f 85 56 ff ff ff e9 82 6a bf 00 65 ff 05 6f 8f e3 5d 48 8b 05 c8 91 c4 01 e8 43 ec 01 00 85 c0 74 5f 65 ff 0d 58 8f e3 5d <0f> 85 31 fe ff ff 0f 1f 44 00 00 e9 27 fe ff ff 44 2b 7c 24 08 45
[ 4775.939740] RSP: 0018:ffffb1264733fb78 EFLAGS: 00000282
[ 4775.939906] RAX: 0000000000000001 RBX: 000000000002e740 RCX: 0000000000000000
[ 4775.940103] RDX: 0000000000000000 RSI: ffffffffa236c8b4 RDI: ffff9be2fbd2e740
[ 4775.940303] RBP: ffff9be2fbd2e740 R08: 0000000000000001 R09: 0000000000000000
[ 4775.940498] R10: ffff9be28385e088 R11: ffffffffa23cd75c R12: ffff9be2fbd2e770
[ 4775.940693] R13: 0000000000112cc0 R14: ffffffffa236c8b4 R15: ffffed30041307c0
[ 4775.940904]  ? folio_add_lru+0x104/0x220
[ 4775.941048]  ? free_unref_page_list+0x12c/0x560
[ 4775.941207]  ? folio_add_lru+0x104/0x220
[ 4775.941353]  ? lock_release+0x1ed/0x2c0
[ 4775.941496]  folio_add_lru+0x11b/0x220
[ 4775.941637]  filemap_add_folio+0x54/0x80
[ 4775.941784]  page_cache_ra_unbounded+0x14d/0x1f0
[ 4775.941944]  filemap_get_pages+0x523/0x740
[ 4775.942091]  ? atime_needs_update+0xf0/0x160
[ 4775.942248]  filemap_read+0xbe/0x340
[ 4775.942391]  ? rcu_read_lock_sched_held+0x12/0x60
[ 4775.942554]  blkdev_read_iter+0xac/0x1c0
[ 4775.942702]  new_sync_read+0xf3/0x160
[ 4775.942845]  vfs_read+0x15f/0x1b0
[ 4775.943007]  ksys_read+0x55/0xd0
[ 4775.943149]  do_syscall_64+0x38/0x90
[ 4775.943289]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[ 4775.943454] RIP: 0033:0x7fcb2a0ce4f2
[ 4775.943601] Code: c0 e9 b2 fe ff ff 50 48 8d 3d b2 39 0a 00 e8 95 f0 01 00 0f 1f 44 00 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 0f 05 <48> 3d 00 f0 ff ff 77 56 c3 0f 1f 44 00 00 48 83 ec 28 48 89 54 24
[ 4775.944057] RSP: 002b:00007ffe04c957f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
[ 4775.944298] RAX: ffffffffffffffda RBX: 00000000013142c0 RCX: 00007fcb2a0ce4f2
[ 4775.944491] RDX: 0000000000000200 RSI: 0000000001314310 RDI: 0000000000000003
[ 4775.944686] RBP: 0000000001314310 R08: 0000000000000080 R09: 00007ffe04c95800
[ 4775.944878] R10: 000000000000001f R11: 0000000000000246 R12: 0000000000000200
[ 4775.945072] R13: 0000000000000000 R14: 000000000000041b R15: 0000000001314310
[ 4775.945284]  
[ 4776.037177] BTRFS info (device dm-9): flagging fs with big metadata feature
[ 4776.037395] BTRFS info (device dm-9): turning on async discard
[ 4776.037594] BTRFS info (device dm-9): disk space caching is enabled
[ 4776.037780] BTRFS info (device dm-9): has skinny extents
[ 4776.153697] BTRFS info (device dm-9): flagging fs with big metadata feature
[ 4776.153918] BTRFS info (device dm-9): turning on async discard
[ 4776.154093] BTRFS info (device dm-9): disk space caching is enabled
[ 4776.154279] BTRFS info (device dm-9): has skinny extents
[ 4776.177671] BTRFS info (device dm-9): qgroup scan completed (inconsistency flag cleared)
[ 4776.395479] BTRFS info (device dm-9): flagging fs with big metadata feature
[ 4776.395717] BTRFS info (device dm-9): turning on async discard
[ 4776.395899] BTRFS info (device dm-9): disk space caching is enabled
[ 4776.396097] BTRFS info (device dm-9): has skinny extents
[ 4776.551811] BTRFS info (device dm-9): flagging fs with big metadata feature
[ 4776.552032] BTRFS info (device dm-9): turning on async discard
[ 4776.552219] BTRFS info (device dm-9): disk space caching is enabled
[ 4776.552426] BTRFS info (device dm-9): has skinny extents
[ 4776.598205] BTRFS info (device dm-9): balance: resume -f -musage=90 -susage=90
[ 4776.598472] BTRFS info (device dm-9): balance: paused
[ 4776.707761] BTRFS info (device dm-9): flagging fs with big metadata feature
[ 4776.708072] BTRFS info (device dm-9): turning on async discard
[ 4776.708336] BTRFS info (device dm-9): disk space caching is enabled
[ 4776.708623] BTRFS info (device dm-9): has skinny extents
[ 4776.710506] BTRFS info (device dm-9): checking UUID tree
[ 4776.725691] BTRFS info (device dm-9): balance: resume -f -musage=90 -susage=90
[ 4776.743637] BTRFS info (device dm-9): relocating block group 298844160 flags metadata|dup
[ 4776.844564] BTRFS info (device dm-9): balance: paused
[ 4777.065833] BTRFS info (device dm-9): flagging fs with big metadata feature
[ 4777.066055] BTRFS info (device dm-9): turning on async discard
[ 4777.066233] BTRFS info (device dm-9): disk space caching is enabled
[ 4777.066412] BTRFS info (device dm-9): has skinny extents
[ 4777.139460] BTRFS info (device dm-9): checking UUID tree
[ 4777.156306] BTRFS info (device dm-9): balance: resume -f -musage=90 -susage=90
[ 4777.156700] BTRFS info (device dm-9): balance: paused
[ 4777.386623] BTRFS info (device dm-9): flagging fs with big metadata feature
[ 4777.386847] BTRFS info (device dm-9): turning on async discard
[ 4777.387026] BTRFS info (device dm-9): disk space caching is enabled
[ 4777.387235] BTRFS info (device dm-9): has skinny extents
[ 4777.425426] BTRFS info (device dm-9): checking UUID tree
[ 4777.447282] BTRFS info (device dm-9): balance: resume -f -musage=90 -susage=90
[ 4777.447586] BTRFS info (device dm-9): balance: paused
[ 4777.595780] BTRFS info (device dm-9): flagging fs with big metadata feature
[ 4777.596085] BTRFS info (device dm-9): turning on async discard
[ 4777.596348] BTRFS info (device dm-9): disk space caching is enabled
[ 4777.596634] BTRFS info (device dm-9): has skinny extents
[ 4777.598758] BTRFS info (device dm-9): checking UUID tree
[ 4777.618209] BTRFS info (device dm-9): balance: resume -f -musage=90 -susage=90
[ 4777.618822] BTRFS info (device dm-9): relocating block group 298844160 flags metadata|dup
[ 4777.689591] BTRFS info (device dm-9): found 82 extents, stage: move data extents
[ 4777.751277] BTRFS info (device dm-9): balance: paused
[ 4777.918288] BTRFS info (device dm-9): flagging fs with big metadata feature
[ 4777.918533] BTRFS info (device dm-9): turning on async discard
[ 4777.918713] BTRFS info (device dm-9): disk space caching is enabled
[ 4777.918892] BTRFS info (device dm-9): has skinny extents
[ 4777.920852] BTRFS info (device dm-9): checking UUID tree
[ 4777.941511] BTRFS info (device dm-9): balance: resume -f -musage=90 -susage=90
[ 4777.941811] BTRFS info (device dm-9): balance: canceled
[ 4778.107683] BTRFS info (device dm-9): flagging fs with big metadata feature
[ 4778.107899] BTRFS info (device dm-9): turning on async discard
[ 4778.108077] BTRFS info (device dm-9): disk space caching is enabled
[ 4778.108270] BTRFS info (device dm-9): has skinny extents
[ 4778.110214] BTRFS info (device dm-9): checking UUID tree
[ 4778.148207] BTRFS info (device dm-9): balance: resume -f -musage=90 -susage=90
[ 4778.148514] BTRFS info (device dm-9): balance: canceled
[ 4778.292392] BTRFS info (device dm-9): flagging fs with big metadata feature
[ 4778.292637] BTRFS info (device dm-9): turning on async discard
[ 4778.292817] BTRFS info (device dm-9): disk space caching is enabled
[ 4778.293000] BTRFS info (device dm-9): has skinny extents
[ 4778.295081] BTRFS info (device dm-9): checking UUID tree
[ 4778.319932] BTRFS info (device dm-9): balance: resume -f -musage=90 -susage=90
[ 4778.320221] BTRFS info (device dm-9): balance: paused
[ 4778.469436] BTRFS info (device dm-9): flagging fs with big metadata feature
[ 4778.469765] BTRFS info (device dm-9): turning on async discard
[ 4778.470053] BTRFS info (device dm-9): disk space caching is enabled
[ 4778.470286] BTRFS info (device dm-9): has skinny extents
[ 4778.472857] BTRFS info (device dm-9): checking UUID tree
[ 4778.496566] BTRFS info (device dm-9): balance: resume -f -musage=90 -susage=90
[ 4778.497280] BTRFS info (device dm-9): relocating block group 567279616 flags system|dup
[ 4778.576143] BTRFS info (device dm-9): found 1 extents, stage: move data extents
[ 4778.615717] BTRFS info (device dm-9): balance: paused
[ 4778.806122] BTRFS info (device dm-9): flagging fs with big metadata feature
[ 4778.806353] BTRFS info (device dm-9): turning on async discard
[ 4778.806551] BTRFS info (device dm-9): disk space caching is enabled
[ 4778.806735] BTRFS info (device dm-9): has skinny extents
[ 4778.808846] BTRFS info (device dm-9): checking UUID tree
[ 4778.827663] BTRFS info (device dm-9): balance: resume -f -musage=90 -susage=90
[ 4778.827966] BTRFS info (device dm-9): relocating block group 567279616 flags system|dup
[ 4778.875812] BTRFS info (device dm-9): found 1 extents, stage: move data extents
[ 4778.913523] BTRFS info (device dm-9): balance: paused
[ 4779.089721] BTRFS info (device dm-9): flagging fs with big metadata feature
[ 4779.089935] BTRFS info (device dm-9): turning on async discard
[ 4779.090118] BTRFS info (device dm-9): disk space caching is enabled
[ 4779.090300] BTRFS info (device dm-9): has skinny extents
[ 4779.091852] BTRFS info (device dm-9): checking UUID tree
[ 4779.118449] BTRFS info (device dm-9): balance: resume -f -musage=90 -susage=90
[ 4779.119286] BTRFS info (device dm-9): relocating block group 567279616 flags system|dup
[ 4779.372805] BTRFS info (device dm-9): found 1 extents, stage: move data extents
[ 4779.480634] BTRFS info (device dm-9): balance: paused
[ 4779.630079] BTRFS info (device dm-9): flagging fs with big metadata feature