[32245.921066] run fstests btrfs/201 at 2022-04-04 05:48:19
[32246.326983] BTRFS: device fsid 96311be5-da41-43e2-95b6-325a9989d1f4 devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (3174940)
[32246.387520] BTRFS info (device dm-11): flagging fs with big metadata feature
[32246.387967] BTRFS info (device dm-11): using free space tree
[32246.388320] BTRFS info (device dm-11): has skinny extents
[32246.390621] BTRFS info (device dm-11): checking UUID tree
[32246.538882] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (3174162)
[32246.540763] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (3174162)
[32246.602775] BTRFS info (device dm-11): flagging fs with big metadata feature
[32246.603203] BTRFS info (device dm-11): using free space tree
[32246.603549] BTRFS info (device dm-11): has skinny extents
[32246.605724] BTRFS info (device dm-11): start tree-log replay
[32246.681279] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[32246.681768] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 3175055, name: mkfs.btrfs
[32246.682256] preempt_count: 101, expected: 0
[32246.682496] RCU nest depth: 1, expected: 0
[32246.682741] INFO: lockdep is turned off.
[32246.682968] Preemption disabled at:
[32246.682969] [<0000000000000000>] 0x0
[32246.683391] CPU: 1 PID: 3175055 Comm: mkfs.btrfs Tainted: G W 5.17.0+ #641
[32246.683855] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[32246.684336] Call Trace:
[32246.684482]
[32246.684606] dump_stack_lvl+0x56/0x6f
[32246.684821] __might_resched.cold+0xff/0x13a
[32246.685070] blk_release_queue+0x24/0x120
[32246.685304] kobject_put+0x7c/0x1d0
[32246.685508] ? rcu_do_batch+0x1ac/0x570
[32246.685733] blkg_free.part.0+0x41/0x60
[32246.685955] rcu_do_batch+0x1e1/0x570
[32246.686169] ? rcu_do_batch+0x1ac/0x570
[32246.686393] rcu_core+0x2cb/0x460
[32246.686590] __do_softirq+0x178/0x517
[32246.686804] __irq_exit_rcu+0xe3/0x160
[32246.687023] irq_exit_rcu+0xa/0x20
[32246.687222] sysvec_call_function_single+0xa2/0xd0
[32246.687497]
[32246.687625]
[32246.687753] asm_sysvec_call_function_single+0x12/0x20
[32246.688048] RIP: 0010:_raw_spin_unlock_irqrestore+0x33/0x60
[32246.688365] Code: 48 83 c7 18 53 48 89 f3 48 8b 74 24 10 e8 45 1b 38 ff 48 89 ef e8 dd 44 38 ff 80 e7 02 74 0b e8 53 70 44 ff fb 0f 1f 44 00 00 01 00 00 00 e8 93 d8 33 ff 65 8b 05 6c ac 1b 56 85 c0 74 03 5b
[32246.689413] RSP: 0018:ffffa284471fbb78 EFLAGS: 00000246
[32246.689713] RAX: 0000000080000001 RBX: 0000000000000246 RCX: ffff94fc45332000
[32246.690116] RDX: 0000000000000002 RSI: ffffffffa9363f5f RDI: ffffffffa9e651fd
[32246.690517] RBP: ffff94fc43826b90 R08: 0000000000000000 R09: 0000000000000000
[32246.690925] R10: ffff94fc43826960 R11: 000000000003a420 R12: ffffa284471fbe00
[32246.691327] R13: 0000000000000001 R14: ffff94fc43826b88 R15: ffffc95d051dec40
[32246.691733] ? __folio_start_writeback+0x1af/0x340
[32246.692008] ? _raw_spin_unlock_irqrestore+0x2d/0x60
[32246.692292] ? _raw_spin_unlock_irqrestore+0x2d/0x60
[32246.692580] __folio_start_writeback+0x1af/0x340
[32246.692847] __block_write_full_page+0x20e/0x550
[32246.693114] ? bh_uptodate_or_lock+0xa0/0xa0
[32246.693360] ? blkdev_llseek+0x60/0x60
[32246.693581] __writepage+0x17/0x70
[32246.693779] write_cache_pages+0x17d/0x560
[32246.694016] ? writeout_period+0x80/0x80
[32246.694244] generic_writepages+0x41/0x60
[32246.694477] do_writepages+0xbf/0x1b0
[32246.694692] ? rcu_read_lock_sched_held+0x12/0x60
[32246.694963] ? lock_release+0x1ed/0x2c0
[32246.695185] ? lock_release+0x1ed/0x2c0
[32246.695407] ? _raw_spin_unlock+0x29/0x40
[32246.695732] filemap_fdatawrite_wbc+0x62/0x90
[32246.695984] file_write_and_wait_range+0x78/0xc0
[32246.696250] blkdev_fsync+0x14/0x40
[32246.696450] __x64_sys_fsync+0x34/0x60
[32246.696674] do_syscall_64+0x38/0x90
[32246.696880] entry_SYSCALL_64_after_hwframe+0x44/0xae
[32246.697168] RIP: 0033:0x7f0347cb9dd7
[32246.697374] Code: c7 c0 ff ff ff ff eb b7 66 2e 0f 1f 84 00 00 00 00 00 90 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 b8 4a 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 41 c3 48 83 ec 18 89 7c 24 0c e8 53 f7 ff ff
[32246.698409] RSP: 002b:00007ffcb086c268 EFLAGS: 00000246 ORIG_RAX: 000000000000004a
[32246.698839] RAX: ffffffffffffffda RBX: 0000000001e17c70 RCX: 00007f0347cb9dd7
[32246.699237] RDX: 0000000000001000 RSI: 0000000001e17ce8 RDI: 0000000000000003
[32246.699640] RBP: 0000000000000000 R08: 0000000000000001 R09: 0000000000000100
[32246.700038] R10: 00007f0347ca9e48 R11: 0000000000000246 R12: 0000000000000000
[32246.700437] R13: 0000000000170000 R14: 0000000000400000 R15: 0000000001e17ce8
[32246.700841]
[32246.787464] BTRFS: device fsid 185c10ae-2aba-4768-9483-dcad57ce53aa devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (3175055)
[32246.855386] BTRFS info (device dm-11): flagging fs with big metadata feature
[32246.855825] BTRFS info (device dm-11): using free space tree
[32246.856158] BTRFS info (device dm-11): has skinny extents
[32246.858293] BTRFS info (device dm-11): checking UUID tree
[32252.263725] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (3179109)
[32252.264970] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (3179109)
[32252.355209] BTRFS info (device dm-11): flagging fs with big metadata feature
[32252.355654] BTRFS info (device dm-11): using free space tree
[32252.355991] BTRFS info (device dm-11): has skinny extents
[32252.358432] BTRFS info (device dm-11): start tree-log replay
[32252.729186] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[32252.729685] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 3179109, name: systemd-udevd
[32252.730213] preempt_count: 101, expected: 0
[32252.730465] RCU nest depth: 1, expected: 0
[32252.730713] INFO: lockdep is turned off.
[32252.730949] Preemption disabled at:
[32252.730949] [<0000000000000000>] 0x0
[32252.731394] CPU: 0 PID: 3179109 Comm: systemd-udevd Tainted: G W 5.17.0+ #641
[32252.731892] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[32252.732398] Call Trace:
[32252.732554]
[32252.732681] dump_stack_lvl+0x56/0x6f
[32252.732903] __might_resched.cold+0xff/0x13a
[32252.733160] blk_release_queue+0x24/0x120
[32252.733401] kobject_put+0x7c/0x1d0
[32252.733617] ? rcu_do_batch+0x1ac/0x570
[32252.733850] blkg_free.part.0+0x41/0x60
[32252.734082] rcu_do_batch+0x1e1/0x570
[32252.734303] ? rcu_do_batch+0x1ac/0x570
[32252.734540] rcu_core+0x2cb/0x460
[32252.734746] __do_softirq+0x178/0x517
[32252.734969] __irq_exit_rcu+0xe3/0x160
[32252.735201] irq_exit_rcu+0xa/0x20
[32252.735408] sysvec_apic_timer_interrupt+0xa2/0xd0
[32252.735972]
[32252.736213]
[32252.736464] asm_sysvec_apic_timer_interrupt+0x12/0x20
[32252.736995] RIP: 0010:check_preemption_disabled+0x2/0xe0
[32252.737394] Code: a3 7e aa be 30 00 00 00 48 c7 c7 60 73 83 aa c6 05 31 54 fd 00 01 e8 d9 88 f8 ff e9 79 ff ff ff cc cc cc cc cc cc cc cc 41 54 <55> 53 48 83 ec 08 65 44 8b 25 b0 57 1c 56 65 8b 05 59 bc 1c 56 a9
[32252.738491] RSP: 0018:ffffa2844584bca0 EFLAGS: 00000282
[32252.738805] RAX: 0000000000000001 RBX: 0000000000008000 RCX: 0000000000000000
[32252.739224] RDX: 0000000000000000 RSI: ffffffffaa87e4d9 RDI: ffffffffaa83354b
[32252.739647] RBP: ffff94fc401eb600 R08: 0000000000000000 R09: 0000000000000000
[32252.740066] R10: 0000000000000010 R11: 0000000000000040 R12: 0000000000000000
[32252.740492] R13: 0000000000000dc0 R14: ffffffffa944d393 R15: 0000000000000dc0
[32252.740914] ? __alloc_file+0x23/0x100
[32252.741146] rcu_is_watching+0xd/0x40
[32252.741370] get_obj_cgroup_from_current+0x80/0x310
[32252.741665] ? get_obj_cgroup_from_current+0x56/0x310
[32252.741966] kmem_cache_alloc+0x75/0x3f0
[32252.742203] __alloc_file+0x23/0x100
[32252.742422] alloc_empty_file+0x41/0xb0
[32252.742657] path_openat+0x39/0xab0
[32252.742870] ? _raw_spin_unlock+0x29/0x40
[32252.743112] ? wp_page_reuse+0x60/0x70
[32252.743340] do_filp_open+0x96/0x120
[32252.743562] ? lock_acquire+0x176/0x2d0
[32252.743794] ? lock_release+0x1ed/0x2c0
[32252.744025] ? _raw_spin_unlock+0x29/0x40
[32252.744266] ? alloc_fd+0x130/0x1f0
[32252.744481] do_sys_openat2+0x7b/0x140
[32252.744710] __x64_sys_openat+0x46/0x70
[32252.744944] do_syscall_64+0x38/0x90
[32252.745160] entry_SYSCALL_64_after_hwframe+0x44/0xae
[32252.745463] RIP: 0033:0x7f114b8ae41b
[32252.745683] Code: 25 00 00 41 00 3d 00 00 41 00 74 4b 64 8b 04 25 18 00 00 00 85 c0 75 67 44 89 e2 48 89 ee bf 9c ff ff ff b8 01 01 00 00 0f 05 <48> 3d 00 f0 ff ff 0f 87 91 00 00 00 48 8b 54 24 28 64 48 2b 14 25
[32252.746805] RSP: 002b:00007ffe2f13e2b0 EFLAGS: 00000246 ORIG_RAX: 0000000000000101
[32252.747253] RAX: ffffffffffffffda RBX: 0000562aabdc67e0 RCX: 00007f114b8ae41b
[32252.747675] RDX: 0000000000080000 RSI: 0000562aabdc7820 RDI: 00000000ffffff9c
[32252.748096] RBP: 0000562aabdc7820 R08: 0000562aabdc7820 R09: 0000000000000000
[32252.748518] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000080000
[32252.748938] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[32252.749361]
[32252.835581] BTRFS: device fsid 6bb5ef7e-534a-4cb2-b878-695b4d3e2226 devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (3179150)
[32252.899248] BTRFS info (device dm-11): flagging fs with big metadata feature
[32252.899679] BTRFS info (device dm-11): using free space tree
[32252.900001] BTRFS info (device dm-11): has skinny extents
[32252.902060] BTRFS info (device dm-11): checking UUID tree
[32258.487368] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (3183205)
[32258.488643] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (3183205)
[32258.580205] BTRFS info (device dm-11): flagging fs with big metadata feature
[32258.580646] BTRFS info (device dm-11): using free space tree
[32258.580982] BTRFS info (device dm-11): has skinny extents
[32258.583363] BTRFS info (device dm-11): start tree-log replay
[32258.956130] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[32258.956807] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 3183246, name: mkfs.btrfs
[32258.957500] preempt_count: 101, expected: 0
[32258.957864] RCU nest depth: 0, expected: 0
[32258.958186] INFO: lockdep is turned off.
[32258.958504] Preemption disabled at:
[32258.958505] [<0000000000000000>] 0x0
[32258.959052] CPU: 0 PID: 3183246 Comm: mkfs.btrfs Tainted: G W 5.17.0+ #641
[32258.959585] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[32258.960085] Call Trace:
[32258.960240]
[32258.960368] dump_stack_lvl+0x56/0x6f
[32258.960597] __might_resched.cold+0xff/0x13a
[32258.960854] blk_release_queue+0x24/0x120
[32258.961096] kobject_put+0x7c/0x1d0
[32258.961314] ? rcu_do_batch+0x1ac/0x570
[32258.961549] blkg_free.part.0+0x41/0x60
[32258.961781] rcu_do_batch+0x1e1/0x570
[32258.962002] ? rcu_do_batch+0x1ac/0x570
[32258.962238] rcu_core+0x2cb/0x460
[32258.962444] __do_softirq+0x178/0x517
[32258.962668] __irq_exit_rcu+0xe3/0x160
[32258.962895] irq_exit_rcu+0xa/0x20
[32258.963100] sysvec_apic_timer_interrupt+0xa2/0xd0
[32258.963390]
[32258.963523]
[32258.963653] asm_sysvec_apic_timer_interrupt+0x12/0x20
[32258.963959] RIP: 0010:_raw_spin_unlock_irqrestore+0x33/0x60
[32258.964297] Code: 48 83 c7 18 53 48 89 f3 48 8b 74 24 10 e8 45 1b 38 ff 48 89 ef e8 dd 44 38 ff 80 e7 02 74 0b e8 53 70 44 ff fb 0f 1f 44 00 00 01 00 00 00 e8 93 d8 33 ff 65 8b 05 6c ac 1b 56 85 c0 74 03 5b
[32258.965384] RSP: 0018:ffffa2844776bb60 EFLAGS: 00000246
[32258.965738] RAX: 0000000080000001 RBX: 0000000000000202 RCX: 0000000000000000
[32258.966160] RDX: 0000000000000002 RSI: ffffffffa942f1ee RDI: ffffffffa9e651fd
[32258.966583] RBP: ffffffffaaca5940 R08: 0000000000000000 R09: 0000000000000000
[32258.967001] R10: 0000000000000002 R11: 0000000000000000 R12: ffffa2844776bc08
[32258.967422] R13: ffffa2844776bc18 R14: ffffa2844776bca8 R15: 0000000000000237
[32258.967845] ? mem_cgroup_wb_stats+0xee/0x100
[32258.968104] ? _raw_spin_unlock_irqrestore+0x2d/0x60
[32258.968405] mem_cgroup_wb_stats+0xee/0x100
[32258.968661] ? rcu_read_lock_sched_held+0x12/0x60
[32258.968943] balance_dirty_pages+0x47c/0xeb0
[32258.969208] ? xas_set_mark+0x59/0xc0
[32258.969434] ? __xa_set_mark+0x53/0x60
[32258.969663] balance_dirty_pages_ratelimited+0x507/0xa50
[32258.969978] generic_perform_write+0x141/0x1d0
[32258.970252] __generic_file_write_iter+0xdb/0x1a0
[32258.970537] blkdev_write_iter+0xc1/0x150
[32258.970779] new_sync_write+0xf6/0x160
[32258.971007] vfs_write+0x290/0x390
[32258.971218] __x64_sys_pwrite64+0x6f/0xb0
[32258.971464] do_syscall_64+0x38/0x90
[32258.971679] entry_SYSCALL_64_after_hwframe+0x44/0xae
[32258.971980] RIP: 0033:0x7fc2c4ada19a
[32258.972201] 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
[32258.973292] RSP: 002b:00007fff0ef56068 EFLAGS: 00000246 ORIG_RAX: 0000000000000012
[32258.973740] RAX: ffffffffffffffda RBX: 00007fc2c46d7010 RCX: 00007fc2c4ada19a
[32258.974164] RDX: 0000000000200000 RSI: 00007fc2c46d7010 RDI: 0000000000000003
[32258.974586] RBP: 0000000000200000 R08: 00007fc2c46d7010 R09: 0000000000000000
[32258.975004] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
[32258.975425] R13: 0000000000000003 R14: 0000000000000000 R15: 0000000000000000
[32258.975850]
[32259.070371] BTRFS: device fsid b278186e-f2b0-4054-8891-c59e807c2f3e devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (3183246)
[32259.134058] BTRFS info (device dm-11): flagging fs with big metadata feature
[32259.134516] BTRFS info (device dm-11): using free space tree
[32259.134853] BTRFS info (device dm-11): has skinny extents
[32259.137312] BTRFS info (device dm-11): checking UUID tree
[32264.760982] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (3187302)
[32264.762290] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (3187302)
[32264.851544] BTRFS info (device dm-11): flagging fs with big metadata feature
[32264.851982] BTRFS info (device dm-11): using free space tree
[32264.852339] BTRFS info (device dm-11): has skinny extents
[32264.854649] BTRFS info (device dm-11): start tree-log replay
[32265.221058] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[32265.221561] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 0, name: swapper/1
[32265.222022] preempt_count: 101, expected: 0
[32265.222285] RCU nest depth: 0, expected: 0
[32265.222537] INFO: lockdep is turned off.
[32265.222773] Preemption disabled at:
[32265.222774] [] ___slab_alloc+0x961/0xf50
[32265.223323] CPU: 1 PID: 0 Comm: swapper/1 Tainted: G W 5.17.0+ #641
[32265.223777] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[32265.224281] Call Trace:
[32265.224438]
[32265.224567] dump_stack_lvl+0x56/0x6f
[32265.224792] __might_resched.cold+0xff/0x13a
[32265.225055] blk_release_queue+0x24/0x120
[32265.225301] kobject_put+0x7c/0x1d0
[32265.225522] ? rcu_do_batch+0x1ac/0x570
[32265.225756] blkg_free.part.0+0x41/0x60
[32265.225989] rcu_do_batch+0x1e1/0x570
[32265.226213] ? rcu_do_batch+0x1ac/0x570
[32265.226450] rcu_core+0x2cb/0x460
[32265.226653] __do_softirq+0x178/0x517
[32265.226878] __irq_exit_rcu+0xe3/0x160
[32265.227107] irq_exit_rcu+0xa/0x20
[32265.227315] sysvec_apic_timer_interrupt+0xa2/0xd0
[32265.227607]
[32265.227737]
[32265.227871] asm_sysvec_apic_timer_interrupt+0x12/0x20
[32265.228179] RIP: 0010:native_safe_halt+0xb/0x10
[32265.228458] Code: 56 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
[32265.229542] RSP: 0018:ffffa28440093ef8 EFLAGS: 00000246
[32265.229853] RAX: ffffffffa9e64a80 RBX: ffff94fc40340000 RCX: 0000000000000000
[32265.230272] RDX: ffff94fc40340000 RSI: ffffffffaa87e4d9 RDI: ffffffffa9e64bf6
[32265.230696] RBP: 0000000000000001 R08: 0000000000000000 R09: 0000000000000000
[32265.231116] R10: 0000000000000000 R11: ffff94fcbbd20c88 R12: 0000000000000000
[32265.231538] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[32265.231961] ? mwait_idle+0x80/0x80
[32265.232173] ? default_idle_call+0x26/0xa0
[32265.232424] default_idle+0xa/0x10
[32265.232630] default_idle_call+0x5e/0xa0
[32265.232866] do_idle+0x1e9/0x240
[32265.233064] cpu_startup_entry+0x19/0x20
[32265.233300] secondary_startup_64_no_verify+0xd5/0xdb
[32265.233607]