[ 3933.179883] run fstests btrfs/159 at 2022-04-03 21:56:57
[ 3933.389630] BTRFS info (device dm-0): flagging fs with big metadata feature
[ 3933.389855] BTRFS info (device dm-0): using free space tree
[ 3933.390046] BTRFS info (device dm-0): has skinny extents
[ 3933.602176] BTRFS: device fsid 2ba2c509-a725-4a00-9da1-599c317938b3 devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (601156)
[ 3933.670048] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 3933.670279] BTRFS info (device dm-11): turning on async discard
[ 3933.670456] BTRFS info (device dm-11): disk space caching is enabled
[ 3933.670637] BTRFS info (device dm-11): has skinny extents
[ 3933.672871] BTRFS info (device dm-11): checking UUID tree
[ 3937.820134] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (602868)
[ 3937.821007] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (602868)
[ 3937.923106] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 3937.923329] BTRFS info (device dm-11): turning on async discard
[ 3937.923536] BTRFS info (device dm-11): disk space caching is enabled
[ 3937.923730] BTRFS info (device dm-11): has skinny extents
[ 3937.925871] BTRFS info (device dm-11): start tree-log replay
[ 3939.585039] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[ 3939.585421] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 602868, name: systemd-udevd
[ 3939.585781] preempt_count: 101, expected: 0
[ 3939.585933] RCU nest depth: 1, expected: 0
[ 3939.586148] INFO: lockdep is turned off.
[ 3939.586366] Preemption disabled at:
[ 3939.586367] [<0000000000000000>] 0x0
[ 3939.586761] CPU: 0 PID: 602868 Comm: systemd-udevd Tainted: G W 5.17.0+ #641
[ 3939.587063] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[ 3939.587411] Call Trace:
[ 3939.587593]
[ 3939.587758] dump_stack_lvl+0x56/0x6f
[ 3939.587968] __might_resched.cold+0xff/0x13a
[ 3939.588172] blk_release_queue+0x24/0x120
[ 3939.588326] kobject_put+0x7c/0x1d0
[ 3939.588526] ? rcu_do_batch+0x1ac/0x570
[ 3939.588741] blkg_free.part.0+0x41/0x60
[ 3939.589010] rcu_do_batch+0x1e1/0x570
[ 3939.589246] ? rcu_do_batch+0x1ac/0x570
[ 3939.589451] rcu_core+0x2cb/0x460
[ 3939.589591] __do_softirq+0x178/0x517
[ 3939.589775] __irq_exit_rcu+0xe3/0x160
[ 3939.589988] irq_exit_rcu+0xa/0x20
[ 3939.590227] sysvec_apic_timer_interrupt+0xa2/0xd0
[ 3939.590548]
[ 3939.590750]
[ 3939.590955] asm_sysvec_apic_timer_interrupt+0x12/0x20
[ 3939.591253] RIP: 0010:rcu_is_watching+0x20/0x40
[ 3939.591500] Code: e2 5d 0f be c0 c3 0f 1f 40 00 53 65 ff 05 78 69 e1 5d e8 e3 ad c4 00 48 c7 c3 90 41 03 00 89 c0 48 03 1c c5 20 5b 93 a3 8b 03 <83> e0 01 65 ff 0d 56 69 e1 5d 74 02 5b c3 0f 1f 44 00 00 5b c3 66
[ 3939.592031] RSP: 0018:ffffb12642d9fa20 EFLAGS: 00000286
[ 3939.592245] RAX: 0000000000bf200d RBX: ffff9be2fbc34190 RCX: ffffffffa2402386
[ 3939.592470] RDX: 0000000000000000 RSI: ffffffffa387e4d9 RDI: ffffffffa383354b
[ 3939.592709] RBP: ffff9be2801e7700 R08: 0000000000000000 R09: 0000000000000000
[ 3939.593031] R10: 0000000000000000 R11: 0000000000000000 R12: ffff9be28e6b99c0
[ 3939.593274] R13: 0000000000000001 R14: ffffb12642d9fa78 R15: ffffed300445c2c0
[ 3939.593470] ? memcg_slab_post_alloc_hook+0x1b6/0x440
[ 3939.593635] memcg_slab_post_alloc_hook+0x1fe/0x440
[ 3939.593794] kmem_cache_alloc+0x1d1/0x3f0
[ 3939.593953] vm_area_dup+0x21/0xa0
[ 3939.594100] ? rcu_read_lock_sched_held+0x12/0x60
[ 3939.594258] ? lock_acquire+0x176/0x2d0
[ 3939.594399] ? rcu_read_lock_sched_held+0x12/0x60
[ 3939.594558] ? lock_release+0x1ed/0x2c0
[ 3939.594712] dup_mm+0x1d8/0x610
[ 3939.594876] copy_process+0x134f/0x1e90
[ 3939.595065] kernel_clone+0x8b/0x3c0
[ 3939.595274] ? rcu_read_lock_sched_held+0x12/0x60
[ 3939.595498] ? rcu_read_lock_sched_held+0x12/0x60
[ 3939.595654] ? rcu_read_lock_sched_held+0x12/0x60
[ 3939.595812] ? lock_acquire+0x176/0x2d0
[ 3939.595971] ? __seccomp_filter+0x38b/0x5d0
[ 3939.596120] __do_sys_clone+0x52/0x60
[ 3939.596260] do_syscall_64+0x38/0x90
[ 3939.596400] entry_SYSCALL_64_after_hwframe+0x44/0xae
[ 3939.596563] RIP: 0033:0x7fe131f030df
[ 3939.596701] Code: ed 0f 85 f4 00 00 00 64 4c 8b 0c 25 10 00 00 00 45 31 c0 4d 8d 91 d0 02 00 00 31 d2 31 f6 bf 11 00 20 01 b8 38 00 00 00 0f 05 <48> 3d 00 f0 ff ff 0f 87 8d 00 00 00 41 89 c5 85 c0 0f 85 9a 00 00
[ 3939.597230] RSP: 002b:00007ffd60e18eb0 EFLAGS: 00000246 ORIG_RAX: 0000000000000038
[ 3939.597577] RAX: ffffffffffffffda RBX: 0000000000000045 RCX: 00007fe131f030df
[ 3939.597772] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000001200011
[ 3939.597980] RBP: 0000000000000000 R08: 0000000000000000 R09: 00007fe131010380
[ 3939.598176] R10: 00007fe131010650 R11: 0000000000000246 R12: 0000000000000000
[ 3939.598373] R13: 00007ffd60e18f80 R14: 0000000000000040 R15: 00007ffd60e18f00
[ 3939.598571]
[ 3939.781215] BTRFS: device fsid c2545709-3edf-4ea7-b066-9b20ce3c8a64 devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (602910)
[ 3939.844342] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 3939.844583] BTRFS info (device dm-11): turning on async discard
[ 3939.844759] BTRFS info (device dm-11): disk space caching is enabled
[ 3939.844943] BTRFS info (device dm-11): has skinny extents
[ 3939.847116] BTRFS info (device dm-11): checking UUID tree
[ 3943.944073] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (604622)
[ 3943.945174] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (604622)
[ 3944.053518] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 3944.053762] BTRFS info (device dm-11): turning on async discard
[ 3944.053968] BTRFS info (device dm-11): disk space caching is enabled
[ 3944.054189] BTRFS info (device dm-11): has skinny extents
[ 3944.056255] BTRFS info (device dm-11): start tree-log replay
[ 3945.123987] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[ 3945.124293] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 0, name: swapper/1
[ 3945.124568] preempt_count: 101, expected: 0
[ 3945.124732] RCU nest depth: 0, expected: 0
[ 3945.124911] INFO: lockdep is turned off.
[ 3945.125086] Preemption disabled at:
[ 3945.125087] [] ___slab_alloc+0x961/0xf50
[ 3945.125431] CPU: 1 PID: 0 Comm: swapper/1 Tainted: G W 5.17.0+ #641
[ 3945.125698] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[ 3945.126027] Call Trace:
[ 3945.126195]
[ 3945.126372] dump_stack_lvl+0x56/0x6f
[ 3945.126599] __might_resched.cold+0xff/0x13a
[ 3945.126782] blk_release_queue+0x24/0x120
[ 3945.126977] kobject_put+0x7c/0x1d0
[ 3945.127129] ? rcu_do_batch+0x1ac/0x570
[ 3945.127288] blkg_free.part.0+0x41/0x60
[ 3945.127447] rcu_do_batch+0x1e1/0x570
[ 3945.127601] ? rcu_do_batch+0x1ac/0x570
[ 3945.127761] rcu_core+0x2cb/0x460
[ 3945.127929] __do_softirq+0x178/0x517
[ 3945.128085] __irq_exit_rcu+0xe3/0x160
[ 3945.128241] irq_exit_rcu+0xa/0x20
[ 3945.128399] sysvec_apic_timer_interrupt+0xa2/0xd0
[ 3945.128599]
[ 3945.128768]
[ 3945.128959] asm_sysvec_apic_timer_interrupt+0x12/0x20
[ 3945.129179] RIP: 0010:native_safe_halt+0xb/0x10
[ 3945.129350] Code: 5d ff ff ff 7f 5b c3 65 48 8b 04 25 c0 fe 01 00 f0 80 48 02 20 48 8b 00 a8 08 75 c3 eb 80 cc eb 07 0f 00 2d 79 b7 5b 00 fb f4 0f 1f 40 00 eb 07 0f 00 2d 69 b7 5b 00 f4 c3 cc cc cc cc cc 0f
[ 3945.129880] RSP: 0018:ffffb12640093ef8 EFLAGS: 00000246
[ 3945.130064] RAX: ffffffffa2e64a80 RBX: ffff9be280378000 RCX: 0000000000000000
[ 3945.130279] RDX: ffff9be280378000 RSI: ffffffffa387e4d9 RDI: ffffffffa2e64bf6
[ 3945.130495] RBP: 0000000000000001 R08: 0000000000000000 R09: 0000000000000000
[ 3945.130712] R10: 0000000000000000 R11: ffff9be2fbd20c88 R12: 0000000000000000
[ 3945.130967] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[ 3945.131249] ? mwait_idle+0x80/0x80
[ 3945.131467] ? default_idle_call+0x26/0xa0
[ 3945.131684] default_idle+0xa/0x10
[ 3945.131855] default_idle_call+0x5e/0xa0
[ 3945.132014] do_idle+0x1e9/0x240
[ 3945.132166] cpu_startup_entry+0x19/0x20
[ 3945.132327] secondary_startup_64_no_verify+0xd5/0xdb
[ 3945.132506]