[ 3645.162598] run fstests btrfs/159 at 2022-04-01 21:52:11
[ 3645.343566] BTRFS info (device dm-0): flagging fs with big metadata feature
[ 3645.343794] BTRFS info (device dm-0): using free space tree
[ 3645.343984] BTRFS info (device dm-0): has skinny extents
[ 3645.531231] BTRFS: device fsid 6ab013dc-f424-4d58-9b29-b564c3e287f0 devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (487549)
[ 3645.591095] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 3645.591315] BTRFS info (device dm-11): turning on async discard
[ 3645.591494] BTRFS info (device dm-11): disk space caching is enabled
[ 3645.591683] BTRFS info (device dm-11): has skinny extents
[ 3645.593461] BTRFS info (device dm-11): checking UUID tree
[ 3649.427925] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (489262)
[ 3649.428931] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (489262)
[ 3649.526302] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 3649.526523] BTRFS info (device dm-11): turning on async discard
[ 3649.526710] BTRFS info (device dm-11): disk space caching is enabled
[ 3649.526911] BTRFS info (device dm-11): has skinny extents
[ 3649.529148] BTRFS info (device dm-11): start tree-log replay
[ 3650.504764] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[ 3650.505089] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 489303, name: mkfs.btrfs
[ 3650.505388] preempt_count: 101, expected: 0
[ 3650.505553] RCU nest depth: 2, expected: 0
[ 3650.505711] INFO: lockdep is turned off.
[ 3650.505866] Preemption disabled at:
[ 3650.505867] [] folio_add_lru+0x40/0x220
[ 3650.506175] CPU: 1 PID: 489303 Comm: mkfs.btrfs Tainted: G W 5.17.0+ #639
[ 3650.506552] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[ 3650.506889] Call Trace:
[ 3650.507010]
[ 3650.507123] dump_stack_lvl+0x56/0x6f
[ 3650.507266] __might_resched.cold+0xff/0x13a
[ 3650.507416] blk_release_queue+0x24/0x120
[ 3650.507561] kobject_put+0x7c/0x1d0
[ 3650.507705] ? rcu_do_batch+0x1ac/0x570
[ 3650.507849] blkg_free.part.0+0x41/0x60
[ 3650.507990] rcu_do_batch+0x1e1/0x570
[ 3650.508127] ? rcu_do_batch+0x1ac/0x570
[ 3650.508272] rcu_core+0x2cb/0x460
[ 3650.508409] __do_softirq+0x178/0x517
[ 3650.508551] __irq_exit_rcu+0xe3/0x160
[ 3650.508703] irq_exit_rcu+0xa/0x20
[ 3650.508841] sysvec_apic_timer_interrupt+0xa2/0xd0
[ 3650.508999]
[ 3650.509110]
[ 3650.509224] asm_sysvec_apic_timer_interrupt+0x12/0x20
[ 3650.509387] RIP: 0010:rcu_is_watching+0x23/0x40
[ 3650.509541] Code: be c0 c3 0f 1f 40 00 53 65 ff 05 78 69 e1 47 e8 e3 ad c4 00 48 c7 c3 90 41 03 00 89 c0 48 03 1c c5 20 5b 93 b9 8b 03 83 e0 01 <65> ff 0d 56 69 e1 47 74 02 5b c3 0f 1f 44 00 00 5b c3 66 66 2e 0f
[ 3650.510009] RSP: 0018:ffffb835c2f47ba0 EFLAGS: 00000202
[ 3650.510172] RAX: 0000000000000001 RBX: ffff9418bbd34190 RCX: 0000000000000000
[ 3650.510367] RDX: ffffffffb842dcf4 RSI: ffffffffb987e4d9 RDI: ffffffffb983354b
[ 3650.510558] RBP: 0000000000000001 R08: 0000000000000000 R09: 0000000000000000
[ 3650.510756] R10: 0000000000000000 R11: 0000000000000000 R12: ffff9418441f6b00
[ 3650.510949] R13: 0000000000408d40 R14: ffffffffb849aabb R15: 0000000000408d40
[ 3650.511144] ? alloc_buffer_head+0x1b/0xc0
[ 3650.511295] ? get_obj_cgroup_from_current+0xd4/0x310
[ 3650.511461] get_obj_cgroup_from_current+0x121/0x310
[ 3650.511626] kmem_cache_alloc+0x75/0x3f0
[ 3650.511770] alloc_buffer_head+0x1b/0xc0
[ 3650.511912] alloc_page_buffers+0xc4/0x1e0
[ 3650.512060] ? blkdev_llseek+0x60/0x60
[ 3650.512200] create_empty_buffers+0x19/0x250
[ 3650.512351] create_page_buffers+0x75/0x90
[ 3650.518010] __block_write_begin_int+0x70/0x500
[ 3650.518166] ? blkdev_llseek+0x60/0x60
[ 3650.518306] ? blkdev_llseek+0x60/0x60
[ 3650.518448] ? blkdev_llseek+0x60/0x60
[ 3650.518590] block_write_begin+0x50/0x130
[ 3650.518734] generic_perform_write+0xa9/0x1d0
[ 3650.518890] __generic_file_write_iter+0xdb/0x1a0
[ 3650.519050] blkdev_write_iter+0xc1/0x150
[ 3650.519195] new_sync_write+0xf6/0x160
[ 3650.519337] vfs_write+0x290/0x390
[ 3650.519476] __x64_sys_pwrite64+0x6f/0xb0
[ 3650.519626] do_syscall_64+0x38/0x90
[ 3650.519764] entry_SYSCALL_64_after_hwframe+0x44/0xae
[ 3650.519928] RIP: 0033:0x7fc7eb0ec53a
[ 3650.520069] 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
[ 3650.520526] RSP: 002b:00007fff321694f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000012
[ 3650.520768] RAX: ffffffffffffffda RBX: 0000000001033c70 RCX: 00007fc7eb0ec53a
[ 3650.520964] RDX: 0000000000200000 RSI: 0000000001033c70 RDI: 0000000000000003
[ 3650.521158] RBP: 0000000000200000 R08: 0000000001033c70 R09: 00007fc7eb0d2a60
[ 3650.521352] R10: 000000027fe00000 R11: 0000000000000246 R12: 0000000000000000
[ 3650.521544] R13: 0000000000000003 R14: 000000027fe00000 R15: 0000000000010000
[ 3650.521744]
[ 3650.607228] BTRFS: device fsid 1139ad35-56cb-488f-bd97-0d5c2e9d4e5e devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (489303)
[ 3650.674807] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 3650.675033] BTRFS info (device dm-11): turning on async discard
[ 3650.675211] BTRFS info (device dm-11): disk space caching is enabled
[ 3650.675392] BTRFS info (device dm-11): has skinny extents
[ 3650.677263] BTRFS info (device dm-11): checking UUID tree
[ 3654.420468] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (491016)
[ 3654.421307] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (491016)
[ 3654.517788] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 3654.518008] BTRFS info (device dm-11): turning on async discard
[ 3654.518184] BTRFS info (device dm-11): disk space caching is enabled
[ 3654.518364] BTRFS info (device dm-11): has skinny extents
[ 3654.520072] BTRFS info (device dm-11): start tree-log replay
[ 3655.490714] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[ 3655.490990] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 0, name: swapper/0
[ 3655.491231] preempt_count: 101, expected: 0
[ 3655.491380] RCU nest depth: 0, expected: 0
[ 3655.491525] INFO: lockdep is turned off.
[ 3655.491671] Preemption disabled at:
[ 3655.491672] [] schedule_preempt_disabled+0x1e/0x20
[ 3655.492008] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G W 5.17.0+ #639
[ 3655.492247] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[ 3655.492508] Call Trace:
[ 3655.492631]
[ 3655.492749] dump_stack_lvl+0x56/0x6f
[ 3655.492890] __might_resched.cold+0xff/0x13a
[ 3655.493039] blk_release_queue+0x24/0x120
[ 3655.493186] kobject_put+0x7c/0x1d0
[ 3655.493328] ? rcu_do_batch+0x1ac/0x570
[ 3655.493470] blkg_free.part.0+0x41/0x60
[ 3655.493614] rcu_do_batch+0x1e1/0x570
[ 3655.493754] ? rcu_do_batch+0x1ac/0x570
[ 3655.493894] rcu_core+0x2cb/0x460
[ 3655.494029] __do_softirq+0x178/0x517
[ 3655.494170] __irq_exit_rcu+0xe3/0x160
[ 3655.494313] irq_exit_rcu+0xa/0x20
[ 3655.494448] sysvec_apic_timer_interrupt+0xa2/0xd0
[ 3655.494612]
[ 3655.494727]
[ 3655.494838] asm_sysvec_apic_timer_interrupt+0x12/0x20
[ 3655.495003] RIP: 0010:native_safe_halt+0xb/0x10
[ 3655.495158] Code: 47 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
[ 3655.495613] RSP: 0018:ffffffffb9a03ea8 EFLAGS: 00000246
[ 3655.495776] RAX: ffffffffb8e64a80 RBX: ffffffffb9a30a00 RCX: 0000000000000000
[ 3655.495974] RDX: ffffffffb9a30a00 RSI: ffffffffb987e4d9 RDI: ffffffffb8e64bf6
[ 3655.496168] RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
[ 3655.496364] R10: 0000000000000000 R11: ffff9418bbc20c88 R12: 0000000000000000
[ 3655.496560] R13: 0000000000000000 R14: ffffffffb9a30118 R15: 0000000000000065
[ 3655.496758] ? mwait_idle+0x80/0x80
[ 3655.496897] ? default_idle_call+0x26/0xa0
[ 3655.497044] default_idle+0xa/0x10
[ 3655.497176] default_idle_call+0x5e/0xa0
[ 3655.497321] do_idle+0x1e9/0x240
[ 3655.497452] cpu_startup_entry+0x19/0x20
[ 3655.497598] start_kernel+0x98c/0x99e
[ 3655.497741] ? copy_bootdata+0x18/0x55
[ 3655.497886] secondary_startup_64_no_verify+0xd5/0xdb
[ 3655.498050]