[ 4833.137489] run fstests btrfs/201 at 2022-04-01 22:11:59
[ 4833.546495] BTRFS: device fsid 1d322dbc-7d39-436d-b440-edf3e179ba20 devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (853734)
[ 4833.614320] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 4833.614557] BTRFS info (device dm-11): turning on async discard
[ 4833.614747] BTRFS info (device dm-11): disk space caching is enabled
[ 4833.614929] BTRFS info (device dm-11): has skinny extents
[ 4833.618335] BTRFS info (device dm-11): checking UUID tree
[ 4833.786212] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (852943)
[ 4833.787006] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (852943)
[ 4833.836732] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 4833.836961] BTRFS info (device dm-11): turning on async discard
[ 4833.837143] BTRFS info (device dm-11): disk space caching is enabled
[ 4833.837329] BTRFS info (device dm-11): has skinny extents
[ 4833.839231] BTRFS info (device dm-11): start tree-log replay
[ 4833.921468] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[ 4833.921742] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 853848, name: mkfs.btrfs
[ 4833.921999] preempt_count: 100, expected: 0
[ 4833.922170] RCU nest depth: 0, expected: 0
[ 4833.922322] INFO: lockdep is turned off.
[ 4833.922482] Preemption disabled at:
[ 4833.922483] [] __do_softirq+0x5e/0x517
[ 4833.922807] CPU: 1 PID: 853848 Comm: mkfs.btrfs Tainted: G        W         5.17.0+ #639
[ 4833.923069] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[ 4833.923322] Call Trace:
[ 4833.923490]  
[ 4833.923606]  dump_stack_lvl+0x56/0x6f
[ 4833.923815]  __might_resched.cold+0xff/0x13a
[ 4833.924075]  blk_release_queue+0x24/0x120
[ 4833.924242]  kobject_put+0x7c/0x1d0
[ 4833.924409]  ? rcu_do_batch+0x1ac/0x570
[ 4833.924568]  blkg_free.part.0+0x41/0x60
[ 4833.924734]  rcu_do_batch+0x1e1/0x570
[ 4833.924892]  ? rcu_do_batch+0x1ac/0x570
[ 4833.925052]  rcu_core+0x2cb/0x460
[ 4833.925189]  __do_softirq+0x178/0x517
[ 4833.925429]  __irq_exit_rcu+0xe3/0x160
[ 4833.925574]  irq_exit_rcu+0xa/0x20
[ 4833.925806]  sysvec_apic_timer_interrupt+0xa2/0xd0
[ 4833.925968]  
[ 4833.926080]  
[ 4833.926194]  asm_sysvec_apic_timer_interrupt+0x12/0x20
[ 4833.926361] RIP: 0010:__block_commit_write.constprop.0.isra.0+0x49/0xb0
[ 4833.926568] Code: f6 c4 20 74 7e 48 8b 44 24 08 41 89 f4 31 ed 45 31 f6 4c 8b 78 28 45 8b 6f 20 4c 89 fb eb 27 48 8b 03 a8 01 75 04 f0 80 0b 01 <48> 89 df e8 8f f8 ff ff 48 8b 03 a8 20 74 04 f0 80 23 df 48 8b 5b
[ 4833.927048] RSP: 0018:ffffb835c1e6fcb0 EFLAGS: 00000206
[ 4833.927214] RAX: 0000000000000010 RBX: ffff9418439f99d8 RCX: 0000000000001000
[ 4833.927408] RDX: 0000000000001000 RSI: 0000000000000000 RDI: ffffddd1840c7600
[ 4833.927612] RBP: 0000000000001000 R08: 0000000000001000 R09: ffffddd1840c7600
[ 4833.927808] R10: ffff9418439f99d8 R11: 0000000000000000 R12: 0000000000000000
[ 4833.928003] R13: 0000000000001000 R14: 0000000000000000 R15: ffff9418439f99d8
[ 4833.928198]  block_write_end+0x30/0xb0
[ 4833.928338]  ? blkdev_llseek+0x60/0x60
[ 4833.928477]  blkdev_write_end+0x14/0xb0
[ 4833.928627]  generic_perform_write+0xf7/0x1d0
[ 4833.928786]  __generic_file_write_iter+0xdb/0x1a0
[ 4833.928942]  blkdev_write_iter+0xc1/0x150
[ 4833.929086]  new_sync_write+0xf6/0x160
[ 4833.929229]  vfs_write+0x290/0x390
[ 4833.929378]  __x64_sys_pwrite64+0x6f/0xb0
[ 4833.929541]  do_syscall_64+0x38/0x90
[ 4833.929695]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[ 4833.929858] RIP: 0033:0x7f3dd75c453a
[ 4833.929994] Code: d8 64 89 02 48 c7 c0 ff ff ff ff eb ba 0f 1f 00 f3 0f 1e fa 49 89 ca 64 8b 04 25 18 00 00 00 85 c0 75 15 b8 12 00 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
[ 4833.930448] RSP: 002b:00007ffd447b3f78 EFLAGS: 00000246 ORIG_RAX: 0000000000000012
[ 4833.930691] RAX: ffffffffffffffda RBX: 00007f3dd71c5010 RCX: 00007f3dd75c453a
[ 4833.930883] RDX: 0000000000200000 RSI: 00007f3dd71c5010 RDI: 0000000000000003
[ 4833.931074] RBP: 0000000000200000 R08: 00007f3dd71c5010 R09: 0000000000000000
[ 4833.931265] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
[ 4833.931458] R13: 0000000000000003 R14: 0000000000000000 R15: 0000000000000000
[ 4833.931657]  
[ 4834.036806] BTRFS: device fsid 8378c307-9374-4279-850f-a40b591f5141 devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (853848)
[ 4834.102652] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 4834.102876] BTRFS info (device dm-11): turning on async discard
[ 4834.103051] BTRFS info (device dm-11): disk space caching is enabled
[ 4834.103233] BTRFS info (device dm-11): has skinny extents
[ 4834.105353] BTRFS info (device dm-11): checking UUID tree
[ 4839.572409] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (857902)
[ 4839.573227] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (857902)
[ 4839.660253] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 4839.660489] BTRFS info (device dm-11): turning on async discard
[ 4839.660674] BTRFS info (device dm-11): disk space caching is enabled
[ 4839.660861] BTRFS info (device dm-11): has skinny extents
[ 4839.663137] BTRFS info (device dm-11): start tree-log replay
[ 4840.035422] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[ 4840.035787] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 20, name: ksoftirqd/1
[ 4840.036123] preempt_count: 100, expected: 0
[ 4840.036311] RCU nest depth: 0, expected: 0
[ 4840.036496] INFO: lockdep is turned off.
[ 4840.036676] Preemption disabled at:
[ 4840.036677] [] __do_softirq+0x5e/0x517
[ 4840.037017] CPU: 1 PID: 20 Comm: ksoftirqd/1 Tainted: G        W         5.17.0+ #639
[ 4840.037274] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[ 4840.037529] Call Trace:
[ 4840.037655]  
[ 4840.043943]  dump_stack_lvl+0x56/0x6f
[ 4840.044091]  __might_resched.cold+0xff/0x13a
[ 4840.044241]  blk_release_queue+0x24/0x120
[ 4840.044386]  kobject_put+0x7c/0x1d0
[ 4840.044526]  ? rcu_do_batch+0x1ac/0x570
[ 4840.044676]  blkg_free.part.0+0x41/0x60
[ 4840.044819]  rcu_do_batch+0x1e1/0x570
[ 4840.044960]  ? rcu_do_batch+0x1ac/0x570
[ 4840.045106]  rcu_core+0x2cb/0x460
[ 4840.045238]  __do_softirq+0x178/0x517
[ 4840.045378]  ? smpboot_thread_fn+0x2c/0x270
[ 4840.045531]  run_ksoftirqd+0x43/0x70
[ 4840.045701]  smpboot_thread_fn+0x1c1/0x270
[ 4840.045878]  ? sort_range+0x20/0x20
[ 4840.046018]  kthread+0xf0/0x120
[ 4840.046151]  ? kthread_complete_and_exit+0x20/0x20
[ 4840.046308]  ret_from_fork+0x1f/0x30
[ 4840.046448]  
[ 4840.103069] BTRFS: device fsid dc72f20b-3933-41c8-ab08-6320a7d977f9 devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (857943)
[ 4840.163133] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 4840.163353] BTRFS info (device dm-11): turning on async discard
[ 4840.163552] BTRFS info (device dm-11): disk space caching is enabled
[ 4840.163741] BTRFS info (device dm-11): has skinny extents
[ 4840.165555] BTRFS info (device dm-11): checking UUID tree
[ 4845.655469] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (861998)
[ 4845.656290] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (861998)
[ 4845.743012] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 4845.743235] BTRFS info (device dm-11): turning on async discard
[ 4845.743433] BTRFS info (device dm-11): disk space caching is enabled
[ 4845.743630] BTRFS info (device dm-11): has skinny extents
[ 4845.745993] BTRFS info (device dm-11): start tree-log replay
[ 4846.140355] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[ 4846.140798] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 861998, name: systemd-udevd
[ 4846.141225] preempt_count: 100, expected: 0
[ 4846.141486] RCU nest depth: 0, expected: 0
[ 4846.141738] INFO: lockdep is turned off.
[ 4846.141974] Preemption disabled at:
[ 4846.141976] [] __do_softirq+0x5e/0x517
[ 4846.142492] CPU: 1 PID: 861998 Comm: systemd-udevd Tainted: G        W         5.17.0+ #639
[ 4846.142914] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[ 4846.143321] Call Trace:
[ 4846.143543]  
[ 4846.143744]  dump_stack_lvl+0x56/0x6f
[ 4846.143978]  __might_resched.cold+0xff/0x13a
[ 4846.144228]  blk_release_queue+0x24/0x120
[ 4846.144463]  kobject_put+0x7c/0x1d0
[ 4846.144698]  ? rcu_do_batch+0x1ac/0x570
[ 4846.144932]  blkg_free.part.0+0x41/0x60
[ 4846.145167]  rcu_do_batch+0x1e1/0x570
[ 4846.145392]  ? rcu_do_batch+0x1ac/0x570
[ 4846.145644]  rcu_core+0x2cb/0x460
[ 4846.145868]  __do_softirq+0x178/0x517
[ 4846.146094]  __irq_exit_rcu+0xe3/0x160
[ 4846.146322]  irq_exit_rcu+0xa/0x20
[ 4846.146549]  sysvec_apic_timer_interrupt+0x54/0xd0
[ 4846.146878]  ? asm_sysvec_apic_timer_interrupt+0xa/0x20
[ 4846.147146]  asm_sysvec_apic_timer_interrupt+0x12/0x20
[ 4846.147420] RIP: 0033:0x7fb218d92d00
[ 4846.147665] Code: 29 c8 c5 f8 77 c3 0f 1f 40 00 48 01 d7 48 01 d6 49 29 d3 f3 0f bc d1 4c 39 da 73 ce 0f b6 04 17 0f b6 14 16 29 d0 c5 f8 77 c3 <3d> e0 0f 00 00 7f 2c c5 fe 6f 0c 17 c5 f5 74 04 16 c5 fd da c1 c5
[ 4846.148353] RSP: 002b:00007fff194a1d78 EFLAGS: 00000202
[ 4846.148680] RAX: 0000000000000fff RBX: 000055a1abc2787b RCX: 00007fff194a2060
[ 4846.148967] RDX: 0000000000000000 RSI: 000055a1ab237fee RDI: 000055a1abc2787b
[ 4846.149301] RBP: 000055a1ab249270 R08: 0000000000000000 R09: 0000000000000000
[ 4846.149632] R10: 9b6433ea965fbe3f R11: 0000000000000007 R12: 00007fff194a1e40
[ 4846.149924] R13: 0000000000000000 R14: 000055a1ab237fee R15: 0000000000000007
[ 4846.150202]  
[ 4846.245196] BTRFS: device fsid 89bf4ecf-e6c3-434d-8bdb-17f83aff8db5 devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (862039)
[ 4846.314034] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 4846.314253] BTRFS info (device dm-11): turning on async discard
[ 4846.314453] BTRFS info (device dm-11): disk space caching is enabled
[ 4846.314644] BTRFS info (device dm-11): has skinny extents
[ 4846.316630] BTRFS info (device dm-11): checking UUID tree
[ 4851.839725] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (866094)
[ 4851.840594] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (866094)
[ 4851.928618] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 4851.928841] BTRFS info (device dm-11): turning on async discard
[ 4851.929018] BTRFS info (device dm-11): disk space caching is enabled
[ 4851.929203] BTRFS info (device dm-11): has skinny extents
[ 4851.931231] BTRFS info (device dm-11): start tree-log replay
[ 4852.316299] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[ 4852.316577] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 20, name: ksoftirqd/1
[ 4852.316824] preempt_count: 100, expected: 0
[ 4852.316983] RCU nest depth: 0, expected: 0
[ 4852.317130] INFO: lockdep is turned off.
[ 4852.317287] Preemption disabled at:
[ 4852.317288] [] __do_softirq+0x5e/0x517
[ 4852.317597] CPU: 1 PID: 20 Comm: ksoftirqd/1 Tainted: G        W         5.17.0+ #639
[ 4852.317843] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[ 4852.318110] Call Trace:
[ 4852.318231]  
[ 4852.318345]  dump_stack_lvl+0x56/0x6f
[ 4852.318492]  __might_resched.cold+0xff/0x13a
[ 4852.318642]  blk_release_queue+0x24/0x120
[ 4852.318788]  kobject_put+0x7c/0x1d0
[ 4852.318923]  ? rcu_do_batch+0x1ac/0x570
[ 4852.319067]  blkg_free.part.0+0x41/0x60
[ 4852.319209]  rcu_do_batch+0x1e1/0x570
[ 4852.319347]  ? rcu_do_batch+0x1ac/0x570
[ 4852.319496]  rcu_core+0x2cb/0x460
[ 4852.319630]  __do_softirq+0x178/0x517
[ 4852.319799]  ? smpboot_thread_fn+0x2c/0x270
[ 4852.319950]  run_ksoftirqd+0x43/0x70
[ 4852.320089]  smpboot_thread_fn+0x1c1/0x270
[ 4852.320235]  ? sort_range+0x20/0x20
[ 4852.320369]  kthread+0xf0/0x120
[ 4852.320504]  ? kthread_complete_and_exit+0x20/0x20
[ 4852.320664]  ret_from_fork+0x1f/0x30
[ 4852.320803]