[16742.896172] run fstests btrfs/201 at 2022-04-03 01:30:30
[16743.302376] BTRFS: device fsid f223cb8c-1136-4e52-af38-b3e45776b5ee devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (3336774)
[16743.364177] BTRFS info (device dm-11): flagging fs with big metadata feature
[16743.364405] BTRFS info (device dm-11): setting incompat feature flag for COMPRESS_ZSTD (0x10)
[16743.364663] BTRFS info (device dm-11): use zstd compression, level 3
[16743.364842] BTRFS info (device dm-11): turning on async discard
[16743.365012] BTRFS info (device dm-11): disk space caching is enabled
[16743.365208] BTRFS info (device dm-11): has skinny extents
[16743.367502] BTRFS info (device dm-11): checking UUID tree
[16743.536493] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (3335982)
[16743.537487] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (3335982)
[16743.589200] BTRFS info (device dm-11): flagging fs with big metadata feature
[16743.589518] BTRFS info (device dm-11): use zstd compression, level 3
[16743.589787] BTRFS info (device dm-11): turning on async discard
[16743.590046] BTRFS info (device dm-11): disk space caching is enabled
[16743.590334] BTRFS info (device dm-11): has skinny extents
[16743.593471] BTRFS info (device dm-11): start tree-log replay
[16743.673123] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[16743.673518] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 3336888, name: mkfs.btrfs
[16743.673892] preempt_count: 100, expected: 0
[16743.674123] RCU nest depth: 1, expected: 0
[16743.674340] INFO: lockdep is turned off.
[16743.674551] Preemption disabled at:
[16743.674553] [] __do_softirq+0x5e/0x517
[16743.674988] CPU: 0 PID: 3336888 Comm: mkfs.btrfs Tainted: G W 5.17.0+ #640
[16743.675369] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[16743.675740] Call Trace:
[16743.675919]
[16743.676079] dump_stack_lvl+0x56/0x6f
[16743.676279] __might_resched.cold+0xff/0x13a
[16743.676499] blk_release_queue+0x24/0x120
[16743.676709] kobject_put+0x7c/0x1d0
[16743.676911] ? rcu_do_batch+0x1ac/0x570
[16743.677124] blkg_free.part.0+0x41/0x60
[16743.677344] rcu_do_batch+0x1e1/0x570
[16743.677545] ? rcu_do_batch+0x1ac/0x570
[16743.677754] rcu_core+0x2cb/0x460
[16743.677953] __do_softirq+0x178/0x517
[16743.678160] __irq_exit_rcu+0xe3/0x160
[16743.678371] irq_exit_rcu+0xa/0x20
[16743.678574] sysvec_apic_timer_interrupt+0xa2/0xd0
[16743.678809]
[16743.678971]
[16743.679141] asm_sysvec_apic_timer_interrupt+0x12/0x20
[16743.679391] RIP: 0010:__xas_prev+0x15/0x1a0
[16743.679605] Code: 00 75 cc 5b 5d c3 66 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 41 54 55 48 89 fd 53 48 8b 5f 18 f6 c3 02 75 05 48 83 6f 08 01 <48> 85 db 0f 84 bd 00 00 00 f6 c3 03 74 09 5b 48 89 ef 5d 41 5c eb
[16743.680272] RSP: 0018:ffffb18fc3e1bbc0 EFLAGS: 00000202
[16743.681235] RAX: 000000000000000f RBX: 0000000000000003 RCX: 0000000000000000
[16743.681538] RDX: 0000000000000003 RSI: 000000000000000f RDI: ffffb18fc3e1bbe0
[16743.681823] RBP: ffffb18fc3e1bbe0 R08: 0000000000000000 R09: 0000000000000000
[16743.682107] R10: 0000000000000000 R11: ffff9e59c0077000 R12: ffff9e59c3e53978
[16743.682398] R13: 0000000000000001 R14: 0000000000000000 R15: 0000000000000020
[16743.682690] page_cache_prev_miss+0x51/0x140
[16743.682917] ondemand_readahead+0x3d1/0x550
[16743.683144] filemap_get_pages+0xca/0x740
[16743.683368] ? rcu_read_lock_sched_held+0x12/0x60
[16743.683600] filemap_read+0xbe/0x340
[16743.683804] ? rcu_read_lock_sched_held+0x12/0x60
[16743.684042] ? lock_acquire+0x176/0x2d0
[16743.684260] ? rcu_read_lock_sched_held+0x12/0x60
[16743.684495] ? lock_release+0x1ed/0x2c0
[16743.684647] blkdev_read_iter+0xac/0x1c0
[16743.684802] new_sync_read+0xf3/0x160
[16743.684947] vfs_read+0x15f/0x1b0
[16743.685079] __x64_sys_pread64+0x6f/0xb0
[16743.685226] do_syscall_64+0x38/0x90
[16743.685373] entry_SYSCALL_64_after_hwframe+0x44/0xae
[16743.685535] RIP: 0033:0x7fa27d41448a
[16743.685673] Code: d8 64 89 02 b8 ff ff ff ff eb bf 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 11 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
[16743.686139] RSP: 002b:00007ffcfac9fd28 EFLAGS: 00000246 ORIG_RAX: 0000000000000011
[16743.686383] RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007fa27d41448a
[16743.686580] RDX: 0000000000001000 RSI: 00007ffcfac9fe30 RDI: 0000000000000003
[16743.686778] RBP: 0000000000000000 R08: 0000000000000001 R09: 0000000000000000
[16743.686974] R10: 0000000000010000 R11: 0000000000000246 R12: 00007ffcfac9fe30
[16743.687171] R13: 0000000000000000 R14: 0000000000010000 R15: 0000000000010000
[16743.687373]
[16743.774736] BTRFS: device fsid 4e4e80b3-74f5-4d70-839c-f9962216ee2f devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (3336888)
[16743.837270] BTRFS info (device dm-11): flagging fs with big metadata feature
[16743.837510] BTRFS info (device dm-11): setting incompat feature flag for COMPRESS_ZSTD (0x10)
[16743.837775] BTRFS info (device dm-11): use zstd compression, level 3
[16743.837958] BTRFS info (device dm-11): turning on async discard
[16743.838153] BTRFS info (device dm-11): disk space caching is enabled
[16743.844018] BTRFS info (device dm-11): has skinny extents
[16743.845891] BTRFS info (device dm-11): checking UUID tree
[16749.604782] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (3340942)
[16749.605712] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (3340942)
[16749.695766] BTRFS info (device dm-11): flagging fs with big metadata feature
[16749.695997] BTRFS info (device dm-11): use zstd compression, level 3
[16749.696202] BTRFS info (device dm-11): turning on async discard
[16749.696382] BTRFS info (device dm-11): disk space caching is enabled
[16749.696561] BTRFS info (device dm-11): has skinny extents
[16749.698836] BTRFS info (device dm-11): start tree-log replay
[16750.087046] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[16750.087354] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 3340942, name: systemd-udevd
[16750.087633] preempt_count: 100, expected: 0
[16750.087783] RCU nest depth: 0, expected: 0
[16750.087934] INFO: lockdep is turned off.
[16750.088095] Preemption disabled at:
[16750.088096] [] __do_softirq+0x5e/0x517
[16750.088412] CPU: 1 PID: 3340942 Comm: systemd-udevd Tainted: G W 5.17.0+ #640
[16750.088759] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[16750.089104] Call Trace:
[16750.089227]
[16750.089457] dump_stack_lvl+0x56/0x6f
[16750.089684] __might_resched.cold+0xff/0x13a
[16750.089840] blk_release_queue+0x24/0x120
[16750.090060] kobject_put+0x7c/0x1d0
[16750.090214] ? rcu_do_batch+0x1ac/0x570
[16750.090381] blkg_free.part.0+0x41/0x60
[16750.090566] rcu_do_batch+0x1e1/0x570
[16750.090744] ? rcu_do_batch+0x1ac/0x570
[16750.090939] rcu_core+0x2cb/0x460
[16750.091097] __do_softirq+0x178/0x517
[16750.091268] __irq_exit_rcu+0xe3/0x160
[16750.091430] irq_exit_rcu+0xa/0x20
[16750.091569] sysvec_apic_timer_interrupt+0xa2/0xd0
[16750.091727]
[16750.091839]
[16750.091955] asm_sysvec_apic_timer_interrupt+0x12/0x20
[16750.092120] RIP: 0010:lock_acquire+0xfb/0x2d0
[16750.092277] Code: 00 b8 ff ff ff ff 65 0f c1 05 f9 9c e3 48 83 f8 01 0f 85 bf 01 00 00 4d 85 ff 74 06 fb 0f 1f 44 00 00 48 83 c4 30 5b 5d 41 5c <41> 5d 41 5e 41 5f c3 65 8b 05 d7 28 e3 48 89 c0 48 0f a3 05 5d 47
[16750.092750] RSP: 0018:ffffb18fc3f3bcb0 EFLAGS: 00000282
[16750.092914] RAX: 0000000000000001 RBX: 0000000000008000 RCX: 0000000000000000
[16750.093111] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffffb8c897a0
[16750.093313] RBP: ffffb18fc3f3bcd8 R08: 0000000000000001 R09: 0000000000000000
[16750.093507] R10: 0000000000000011 R11: 0000000000000040 R12: 0000000000008000
[16750.093705] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000dc0
[16750.093907] ? __alloc_file+0x23/0x100
[16750.094229] fs_reclaim_acquire+0xa1/0xd0
[16750.094385] ? kmem_cache_alloc+0x30/0x3f0
[16750.094534] kmem_cache_alloc+0x30/0x3f0
[16750.094679] __alloc_file+0x23/0x100
[16750.094820] alloc_empty_file+0x41/0xb0
[16750.094991] path_openat+0x39/0xab0
[16750.095181] ? _raw_spin_unlock+0x29/0x40
[16750.095395] ? wp_page_reuse+0x60/0x70
[16750.095594] do_filp_open+0x96/0x120
[16750.095755] ? lock_acquire+0x176/0x2d0
[16750.095941] ? lock_release+0x1ed/0x2c0
[16750.096088] ? _raw_spin_unlock+0x29/0x40
[16750.096236] ? alloc_fd+0x130/0x1f0
[16750.096421] do_sys_openat2+0x7b/0x140
[16750.096740] __x64_sys_openat+0x46/0x70
[16750.096888] do_syscall_64+0x38/0x90
[16750.097027] entry_SYSCALL_64_after_hwframe+0x44/0xae
[16750.097190] RIP: 0033:0x7f31a71273c6
[16750.097337] Code: c0 f6 c2 40 75 4e 89 d0 45 31 d2 25 00 00 41 00 3d 00 00 41 00 74 3d 64 8b 04 25 18 00 00 00 85 c0 75 61 b8 01 01 00 00 0f 05 <48> 3d 00 f0 ff ff 0f 87 9e 00 00 00 48 8b 4c 24 38 64 48 2b 0c 25
[16750.097809] RSP: 002b:00007ffd27b216d0 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
[16750.098050] RAX: ffffffffffffffda RBX: 0000557dd168a380 RCX: 00007f31a71273c6
[16750.098255] RDX: 0000000000080000 RSI: 00007f31a75726a3 RDI: 0000000000000010
[16750.098457] RBP: 00007f31a75726a3 R08: 0000000000000000 R09: 00007f31a71f9a60
[16750.098656] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000010
[16750.098856] R13: 0000000000080000 R14: 0000557dd168a380 R15: 00007f31a757c240
[16750.099056]
[16750.168964] BTRFS: device fsid 7d33532c-5ad7-4b68-9320-bc492d74f9fd devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (3340983)
[16750.231622] BTRFS info (device dm-11): flagging fs with big metadata feature
[16750.231849] BTRFS info (device dm-11): setting incompat feature flag for COMPRESS_ZSTD (0x10)
[16750.232135] BTRFS info (device dm-11): use zstd compression, level 3
[16750.232328] BTRFS info (device dm-11): turning on async discard
[16750.232506] BTRFS info (device dm-11): disk space caching is enabled
[16750.232692] BTRFS info (device dm-11): has skinny extents
[16750.234772] BTRFS info (device dm-11): checking UUID tree
[16756.247566] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (3345038)
[16756.248528] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (3345038)
[16756.339986] BTRFS info (device dm-11): flagging fs with big metadata feature
[16756.340322] BTRFS info (device dm-11): use zstd compression, level 3
[16756.340511] BTRFS info (device dm-11): turning on async discard
[16756.340689] BTRFS info (device dm-11): disk space caching is enabled
[16756.340871] BTRFS info (device dm-11): has skinny extents
[16756.343053] BTRFS info (device dm-11): start tree-log replay
[16756.719990] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[16756.720281] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 20, name: ksoftirqd/1
[16756.720531] preempt_count: 100, expected: 0
[16756.720679] RCU nest depth: 0, expected: 0
[16756.720826] INFO: lockdep is turned off.
[16756.720982] Preemption disabled at:
[16756.720983] [] __do_softirq+0x5e/0x517
[16756.721306] CPU: 1 PID: 20 Comm: ksoftirqd/1 Tainted: G W 5.17.0+ #640
[16756.721579] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[16756.721861] Call Trace:
[16756.721996]
[16756.722129] dump_stack_lvl+0x56/0x6f
[16756.722352] __might_resched.cold+0xff/0x13a
[16756.722506] blk_release_queue+0x24/0x120
[16756.722652] kobject_put+0x7c/0x1d0
[16756.722929] ? rcu_do_batch+0x1ac/0x570
[16756.723077] blkg_free.part.0+0x41/0x60
[16756.723228] rcu_do_batch+0x1e1/0x570
[16756.723445] ? rcu_do_batch+0x1ac/0x570
[16756.723592] rcu_core+0x2cb/0x460
[16756.723727] __do_softirq+0x178/0x517
[16756.723867] ? smpboot_thread_fn+0x2c/0x270
[16756.724018] run_ksoftirqd+0x43/0x70
[16756.724163] smpboot_thread_fn+0x1c1/0x270
[16756.724316] ? sort_range+0x20/0x20
[16756.724452] kthread+0xf0/0x120
[16756.724587] ? kthread_complete_and_exit+0x20/0x20
[16756.724746] ret_from_fork+0x1f/0x30
[16756.724887]
[16756.859870] BTRFS: device fsid 4f7b9027-77c6-44ad-8547-7218f3ff26ff devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (3345080)
[16756.931060] BTRFS info (device dm-11): flagging fs with big metadata feature
[16756.931297] BTRFS info (device dm-11): setting incompat feature flag for COMPRESS_ZSTD (0x10)
[16756.931554] BTRFS info (device dm-11): use zstd compression, level 3
[16756.931742] BTRFS info (device dm-11): turning on async discard
[16756.931920] BTRFS info (device dm-11): disk space caching is enabled
[16756.932117] BTRFS info (device dm-11): has skinny extents
[16756.934003] BTRFS info (device dm-11): checking UUID tree
[16762.808993] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (3349134)
[16762.810179] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (3349134)
[16762.897275] BTRFS info (device dm-11): flagging fs with big metadata feature
[16762.897501] BTRFS info (device dm-11): use zstd compression, level 3
[16762.897687] BTRFS info (device dm-11): turning on async discard
[16762.897861] BTRFS info (device dm-11): disk space caching is enabled
[16762.898070] BTRFS info (device dm-11): has skinny extents
[16762.900374] BTRFS info (device dm-11): start tree-log replay
[16763.319896] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[16763.320178] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 0, name: swapper/0
[16763.320428] preempt_count: 101, expected: 0
[16763.320572] RCU nest depth: 0, expected: 0
[16763.320716] INFO: lockdep is turned off.
[16763.320861] Preemption disabled at:
[16763.320862] [] schedule_preempt_disabled+0x1e/0x20
[16763.321208] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G W 5.17.0+ #640
[16763.321446] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[16763.321707] Call Trace:
[16763.321826]
[16763.321944] dump_stack_lvl+0x56/0x6f
[16763.322083] __might_resched.cold+0xff/0x13a
[16763.322239] blk_release_queue+0x24/0x120
[16763.322390] kobject_put+0x7c/0x1d0
[16763.322529] ? rcu_do_batch+0x1ac/0x570
[16763.322671] blkg_free.part.0+0x41/0x60
[16763.322815] rcu_do_batch+0x1e1/0x570
[16763.322957] ? rcu_do_batch+0x1ac/0x570
[16763.323099] rcu_core+0x2cb/0x460
[16763.329216] __do_softirq+0x178/0x517
[16763.329361] __irq_exit_rcu+0xe3/0x160
[16763.329502] irq_exit_rcu+0xa/0x20
[16763.329638] sysvec_apic_timer_interrupt+0xa2/0xd0
[16763.329795]
[16763.329907]
[16763.330022] asm_sysvec_apic_timer_interrupt+0x12/0x20
[16763.330905] RIP: 0010:native_safe_halt+0xb/0x10
[16763.331062] Code: 48 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
[16763.331549] RSP: 0018:ffffffffb8a03ea8 EFLAGS: 00000246
[16763.331719] RAX: ffffffffb7e64a80 RBX: ffffffffb8a30a00 RCX: 0000000000000000
[16763.331923] RDX: ffffffffb8a30a00 RSI: ffffffffb887e4d9 RDI: ffffffffb7e64bf6
[16763.332116] RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
[16763.332316] R10: 0000000000000000 R11: ffff9e5a3bc20c88 R12: 0000000000000000
[16763.332509] R13: 0000000000000000 R14: ffffffffb8a30118 R15: 0000000000000065
[16763.332703] ? mwait_idle+0x80/0x80
[16763.332839] ? default_idle_call+0x26/0xa0
[16763.332990] default_idle+0xa/0x10
[16763.333130] default_idle_call+0x5e/0xa0
[16763.333272] do_idle+0x1e9/0x240
[16763.333408] cpu_startup_entry+0x19/0x20
[16763.333553] start_kernel+0x98c/0x99e
[16763.333692] ? copy_bootdata+0x18/0x55
[16763.333833] secondary_startup_64_no_verify+0xd5/0xdb
[16763.333999]