[26557.305394] run fstests btrfs/201 at 2022-04-03 04:25:04
[26557.666401] BTRFS: device fsid 1054b62c-739e-4d30-9073-3c7cf4b171ee devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (3051923)
[26557.726246] BTRFS info (device dm-11): flagging fs with big metadata feature
[26557.726724] BTRFS info (device dm-11): using free space tree
[26557.727064] BTRFS info (device dm-11): has skinny extents
[26557.729119] BTRFS info (device dm-11): checking UUID tree
[26557.866470] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (3051127)
[26557.867613] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (3051127)
[26557.917765] BTRFS info (device dm-11): flagging fs with big metadata feature
[26557.918200] BTRFS info (device dm-11): using free space tree
[26557.918534] BTRFS info (device dm-11): has skinny extents
[26557.920775] BTRFS info (device dm-11): start tree-log replay
[26557.978650] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[26557.979154] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 3052037, name: mkfs.btrfs
[26557.979680] preempt_count: 102, expected: 0
[26557.979937] RCU nest depth: 0, expected: 0
[26557.980263] INFO: lockdep is turned off.
[26557.980535] Preemption disabled at:
[26557.980536] [] folio_add_lru+0x40/0x220
[26557.981279] CPU: 0 PID: 3052037 Comm: mkfs.btrfs Tainted: G        W         5.17.0+ #640
[26557.981799] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[26557.982300] Call Trace:
[26557.982452]  
[26557.982585]  dump_stack_lvl+0x56/0x6f
[26557.982810]  __might_resched.cold+0xff/0x13a
[26557.983072]  blk_release_queue+0x24/0x120
[26557.983316]  kobject_put+0x7c/0x1d0
[26557.983530]  ? rcu_do_batch+0x1ac/0x570
[26557.983768]  blkg_free.part.0+0x41/0x60
[26557.984002]  rcu_do_batch+0x1e1/0x570
[26557.984226]  ? rcu_do_batch+0x1ac/0x570
[26557.984460]  rcu_core+0x2cb/0x460
[26557.984667]  __do_softirq+0x178/0x517
[26557.984892]  __irq_exit_rcu+0xe3/0x160
[26557.985125]  irq_exit_rcu+0xa/0x20
[26557.985332]  sysvec_apic_timer_interrupt+0xa2/0xd0
[26557.985625]  
[26557.985757]  
[26557.985890]  asm_sysvec_apic_timer_interrupt+0x12/0x20
[26557.986203] RIP: 0010:_raw_spin_unlock_irqrestore+0x33/0x60
[26557.986543] 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 54 85 c0 74 03 5b
[26557.987649] RSP: 0018:ffffa8c181a9fb98 EFLAGS: 00000246
[26557.987966] RAX: 0000000080000002 RBX: 0000000000000246 RCX: 0000000000000088
[26557.988391] RDX: ffff9da1043eb020 RSI: ffffffffab36c46f RDI: ffffffffabe651fd
[26557.988819] RBP: ffff9da1043eb050 R08: 0000000000000000 R09: 0000000000000000
[26557.989243] R10: 0000000000000000 R11: 0000000000000000 R12: 000000000000000f
[26557.989668] R13: ffffeeb204221b80 R14: ffffeeb204bb4a08 R15: ffff9da1043eb020
[26557.990095]  ? __pagevec_lru_add+0x28f/0x5d0
[26557.990355]  ? _raw_spin_unlock_irqrestore+0x2d/0x60
[26557.990664]  ? _raw_spin_unlock_irqrestore+0x2d/0x60
[26557.990964]  __pagevec_lru_add+0x28f/0x5d0
[26557.991214]  folio_add_lru+0xd5/0x220
[26557.991440]  filemap_add_folio+0x54/0x80
[26557.991695]  __filemap_get_folio+0x1ac/0x4d0
[26557.991959]  ? blkdev_llseek+0x60/0x60
[26557.992190]  pagecache_get_page+0x15/0x90
[26557.992435]  block_write_begin+0x24/0x130
[26557.992685]  generic_perform_write+0xa9/0x1d0
[26557.992952]  __generic_file_write_iter+0xdb/0x1a0
[26557.993238]  blkdev_write_iter+0xc1/0x150
[26557.993482]  new_sync_write+0xf6/0x160
[26557.993716]  vfs_write+0x290/0x390
[26557.993924]  __x64_sys_pwrite64+0x6f/0xb0
[26557.994168]  do_syscall_64+0x38/0x90
[26557.994387]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[26557.994696] RIP: 0033:0x7f4cf01c519a
[26557.994915] 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
[26557.996016] RSP: 002b:00007ffe827cfa48 EFLAGS: 00000246 ORIG_RAX: 0000000000000012
[26557.996468] RAX: ffffffffffffffda RBX: 00007f4cefdc2010 RCX: 00007f4cf01c519a
[26557.996895] RDX: 0000000000200000 RSI: 00007f4cefdc2010 RDI: 0000000000000003
[26557.997319] RBP: 0000000000200000 R08: 00007f4cefdc2010 R09: 0000000000000000
[26557.997744] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
[26557.998166] R13: 0000000000000003 R14: 0000000000000000 R15: 0000000000000000
[26557.998595]  
[26558.060209] BTRFS: device fsid 8eb6b23c-1af5-4d60-ab97-4086edf44537 devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (3052037)
[26558.116253] BTRFS info (device dm-11): flagging fs with big metadata feature
[26558.116733] BTRFS info (device dm-11): using free space tree
[26558.117068] BTRFS info (device dm-11): has skinny extents
[26558.119230] BTRFS info (device dm-11): checking UUID tree
[26563.681858] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (3056092)
[26563.683238] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (3056092)
[26563.774157] BTRFS info (device dm-11): flagging fs with big metadata feature
[26563.774615] BTRFS info (device dm-11): using free space tree
[26563.774956] BTRFS info (device dm-11): has skinny extents
[26563.777408] BTRFS info (device dm-11): start tree-log replay
[26564.142578] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[26564.143142] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 3056133, name: mkfs.btrfs
[26564.143653] preempt_count: 101, expected: 0
[26564.143909] RCU nest depth: 0, expected: 0
[26564.144153] INFO: lockdep is turned off.
[26564.144388] Preemption disabled at:
[26564.144388] [] __slab_alloc.constprop.0+0x23/0x80
[26564.144988] CPU: 0 PID: 3056133 Comm: mkfs.btrfs Tainted: G        W         5.17.0+ #640
[26564.145467] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[26564.145968] Call Trace:
[26564.146120]  
[26564.146247]  dump_stack_lvl+0x56/0x6f
[26564.146469]  __might_resched.cold+0xff/0x13a
[26564.146728]  blk_release_queue+0x24/0x120
[26564.146969]  kobject_put+0x7c/0x1d0
[26564.147182]  ? rcu_do_batch+0x1ac/0x570
[26564.147413]  blkg_free.part.0+0x41/0x60
[26564.147648]  rcu_do_batch+0x1e1/0x570
[26564.147868]  ? rcu_do_batch+0x1ac/0x570
[26564.148101]  rcu_core+0x2cb/0x460
[26564.148303]  __do_softirq+0x178/0x517
[26564.148527]  __irq_exit_rcu+0xe3/0x160
[26564.148755]  irq_exit_rcu+0xa/0x20
[26564.148960]  sysvec_apic_timer_interrupt+0xa2/0xd0
[26564.149246]  
[26564.149378]  
[26564.149512]  asm_sysvec_apic_timer_interrupt+0x12/0x20
[26564.149818] RIP: 0010:___slab_alloc+0x7ed/0xf50
[26564.150089] Code: c7 43 28 00 00 00 00 48 c7 c6 e2 5c 40 ab 48 89 df e8 37 10 de ff 41 f7 c5 00 02 00 00 74 0b e8 49 65 ea ff fb 0f 1f 44 00 00 <48> 81 c4 88 00 00 00 4c 89 f0 5b 5d 41 5c 41 5d 41 5e 41 5f c3 65
[26564.151182] RSP: 0018:ffffa8c181ab7a18 EFLAGS: 00000246
[26564.151494] RAX: 0000000080000001 RBX: ffff9da17bc3d310 RCX: c05f4e10a19dffff
[26564.152008] RDX: ffff9da1104e5fc0 RSI: ffffffffab405ce2 RDI: ffffffffab405d07
[26564.152426] RBP: ffff9da100c24500 R08: 0000000000000000 R09: 0000000000000000
[26564.152849] R10: ffff9da17ffd5e00 R11: 000000000003a420 R12: 0000000000092800
[26564.153294] R13: 0000000000000246 R14: ffff9da1104e5f00 R15: ffff9da1104e5f00
[26564.153719]  ? ___slab_alloc+0x7c2/0xf50
[26564.153955]  ? ___slab_alloc+0x7e7/0xf50
[26564.154192]  ? ___slab_alloc+0x7e7/0xf50
[26564.154428]  ? mempool_alloc+0x58/0x190
[26564.154663]  ? lock_acquire+0x176/0x2d0
[26564.154895]  ? rcu_read_lock_sched_held+0x12/0x60
[26564.155177]  ? lock_release+0x1ed/0x2c0
[26564.155409]  ? mempool_alloc+0x58/0x190
[26564.155643]  __slab_alloc.constprop.0+0x4a/0x80
[26564.155916]  ? mempool_alloc+0x58/0x190
[26564.156147]  kmem_cache_alloc+0x343/0x3f0
[26564.156390]  mempool_alloc+0x58/0x190
[26564.156614]  ? lock_release+0x1ed/0x2c0
[26564.156845]  ? trace_hardirqs_on+0x1b/0xe0
[26564.157092]  bio_alloc_bioset+0x9e/0x3c0
[26564.157330]  submit_bh_wbc+0x98/0x140
[26564.157561]  __block_write_full_page+0x236/0x550
[26564.157837]  ? bh_uptodate_or_lock+0xa0/0xa0
[26564.158095]  ? blkdev_llseek+0x60/0x60
[26564.158326]  __writepage+0x17/0x70
[26564.158539]  write_cache_pages+0x17d/0x560
[26564.158785]  ? writeout_period+0x80/0x80
[26564.159027]  generic_writepages+0x41/0x60
[26564.159272]  do_writepages+0xbf/0x1b0
[26564.159498]  ? rcu_read_lock_sched_held+0x12/0x60
[26564.159789]  ? lock_release+0x1ed/0x2c0
[26564.160024]  ? lock_release+0x1ed/0x2c0
[26564.160257]  ? _raw_spin_unlock+0x29/0x40
[26564.160506]  filemap_fdatawrite_wbc+0x62/0x90
[26564.160773]  file_write_and_wait_range+0x78/0xc0
[26564.161056]  blkdev_fsync+0x14/0x40
[26564.161269]  __x64_sys_fsync+0x34/0x60
[26564.161501]  do_syscall_64+0x38/0x90
[26564.161722]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[26564.162026] RIP: 0033:0x7f0a4a868dd7
[26564.162244] 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
[26564.163338] RSP: 002b:00007fffd694ce18 EFLAGS: 00000246 ORIG_RAX: 000000000000004a
[26564.163788] RAX: ffffffffffffffda RBX: 00000000018afc70 RCX: 00007f0a4a868dd7
[26564.164208] RDX: 0000000000001000 RSI: 00000000018afce8 RDI: 0000000000000003
[26564.164631] RBP: 0000000000000000 R08: 0000000000000001 R09: 0000000000000100
[26564.165051] R10: 00007f0a4a858e48 R11: 0000000000000246 R12: 0000000000000000
[26564.165473] R13: 0000000000170000 R14: 0000000000400000 R15: 00000000018afce8
[26564.165901]  
[26564.223511] BTRFS: device fsid 113d9d20-d9c7-4e5d-bca6-a4b49d6723c0 devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (3056133)
[26564.284355] BTRFS info (device dm-11): flagging fs with big metadata feature
[26564.284835] BTRFS info (device dm-11): using free space tree
[26564.285173] BTRFS info (device dm-11): has skinny extents
[26564.287929] BTRFS info (device dm-11): checking UUID tree
[26569.875402] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (3060188)
[26569.876846] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (3060188)
[26569.968485] BTRFS info (device dm-11): flagging fs with big metadata feature
[26569.968935] BTRFS info (device dm-11): using free space tree
[26569.969273] BTRFS info (device dm-11): has skinny extents
[26569.971785] BTRFS info (device dm-11): start tree-log replay
[26570.332543] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[26570.333125] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 3060188, name: systemd-udevd
[26570.333663] preempt_count: 100, expected: 0
[26570.333919] RCU nest depth: 0, expected: 0
[26570.334167] INFO: lockdep is turned off.
[26570.334406] Preemption disabled at:
[26570.334407] [] __do_softirq+0x5e/0x517
[26570.334955] CPU: 0 PID: 3060188 Comm: systemd-udevd Tainted: G        W         5.17.0+ #640
[26570.335461] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[26570.335967] Call Trace:
[26570.336122]  
[26570.336251]  dump_stack_lvl+0x56/0x6f
[26570.336482]  __might_resched.cold+0xff/0x13a
[26570.336745]  blk_release_queue+0x24/0x120
[26570.336990]  kobject_put+0x7c/0x1d0
[26570.337210]  ? rcu_do_batch+0x1ac/0x570
[26570.337451]  blkg_free.part.0+0x41/0x60
[26570.337688]  rcu_do_batch+0x1e1/0x570
[26570.337914]  ? rcu_do_batch+0x1ac/0x570
[26570.338153]  rcu_core+0x2cb/0x460
[26570.338361]  __do_softirq+0x178/0x517
[26570.338591]  __irq_exit_rcu+0xe3/0x160
[26570.338822]  irq_exit_rcu+0xa/0x20
[26570.339032]  sysvec_apic_timer_interrupt+0xa2/0xd0
[26570.339322]  
[26570.339459]  
[26570.339594]  asm_sysvec_apic_timer_interrupt+0x12/0x20
[26570.339906] RIP: 0010:force_page_cache_ra+0xe4/0x100
[26570.340210] Code: 48 0f 43 f3 31 d2 e8 4b fd ff ff 48 89 da 4c 89 eb eb a9 48 83 7a 20 00 0f 85 5d ff ff ff 48 83 7a 28 00 0f 85 52 ff ff ff 5b <5d> 41 5c 41 5d 41 5e c3 49 89 dd bb 00 02 00 00 eb b7 66 2e 0f 1f
[26570.341314] RSP: 0018:ffffa8c181d1fc58 EFLAGS: 00000246
[26570.341635] RAX: 0000000000400140 RBX: ffffa8c181d1fd70 RCX: 0000000000000000
[26570.342088] RDX: 0000000000000001 RSI: ffffffffab366f0e RDI: ffff9da1023993e0
[26570.342516] RBP: 0000000000280000 R08: 0000000000000000 R09: 0000000000000000
[26570.342938] R10: 0000000000000920 R11: 0000000000000002 R12: ffffa8c181d1fcd8
[26570.343362] R13: 0000000000000000 R14: ffff9da11a372178 R15: ffffa8c181d1fe90
[26570.343791]  ? page_cache_ra_unbounded+0x1ae/0x1f0
[26570.344088]  filemap_get_pages+0xca/0x740
[26570.344334]  ? atime_needs_update+0xf0/0x160
[26570.344601]  filemap_read+0xbe/0x340
[26570.344822]  ? _raw_spin_unlock+0x29/0x40
[26570.345067]  ? wp_page_reuse+0x60/0x70
[26570.345300]  ? do_wp_page+0x184/0x3c0
[26570.345527]  ? __handle_mm_fault+0xba9/0x1460
[26570.345791]  blkdev_read_iter+0xac/0x1c0
[26570.346033]  new_sync_read+0xf3/0x160
[26570.346259]  vfs_read+0x15f/0x1b0
[26570.346466]  ksys_read+0x55/0xd0
[26570.346668]  do_syscall_64+0x38/0x90
[26570.346890]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[26570.347195] RIP: 0033:0x7f87d37226c2
[26570.347417] Code: c0 e9 b2 fe ff ff 50 48 8d 3d 0a 2b 0a 00 e8 b5 e8 01 00 0f 1f 44 00 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 0f 05 <48> 3d 00 f0 ff ff 77 56 c3 0f 1f 44 00 00 48 83 ec 28 48 89 54 24
[26570.348526] RSP: 002b:00007fff44081318 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
[26570.348979] RAX: ffffffffffffffda RBX: 000055cc060615f8 RCX: 00007f87d37226c2
[26570.349407] RDX: 0000000000000200 RSI: 000055cc06061608 RDI: 0000000000000006
[26570.349836] RBP: 000055cc0608b8f0 R08: 000055cc060615e0 R09: 00007f87d37f4a00
[26570.350263] R10: 0000000000000007 R11: 0000000000000246 R12: 000000027ffffe00
[26570.350693] R13: 0000000000000200 R14: 000055cc060615e0 R15: 000055cc0608b940
[26570.351124]  
[26570.408583] BTRFS: device fsid 2c4b1665-f315-44c8-a8a4-caa9aa23e29b devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (3060229)
[26570.472229] BTRFS info (device dm-11): flagging fs with big metadata feature
[26570.472712] BTRFS info (device dm-11): using free space tree
[26570.473055] BTRFS info (device dm-11): has skinny extents
[26570.475083] BTRFS info (device dm-11): checking UUID tree
[26576.017872] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (3064284)
[26576.019151] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (3064284)
[26576.110050] BTRFS info (device dm-11): flagging fs with big metadata feature
[26576.110508] BTRFS info (device dm-11): using free space tree
[26576.110848] BTRFS info (device dm-11): has skinny extents
[26576.113405] BTRFS info (device dm-11): start tree-log replay
[26576.461452] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[26576.461946] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 0, name: swapper/1
[26576.462412] preempt_count: 101, expected: 0
[26576.462681] RCU nest depth: 0, expected: 0
[26576.462929] INFO: lockdep is turned off.
[26576.463167] Preemption disabled at:
[26576.463167] [] ___slab_alloc+0x961/0xf50
[26576.463725] CPU: 1 PID: 0 Comm: swapper/1 Tainted: G        W         5.17.0+ #640
[26576.464175] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[26576.464685] Call Trace:
[26576.464840]  
[26576.464968]  dump_stack_lvl+0x56/0x6f
[26576.465195]  __might_resched.cold+0xff/0x13a
[26576.465459]  blk_release_queue+0x24/0x120
[26576.465706]  kobject_put+0x7c/0x1d0
[26576.465922]  ? rcu_do_batch+0x1ac/0x570
[26576.466158]  blkg_free.part.0+0x41/0x60
[26576.466396]  rcu_do_batch+0x1e1/0x570
[26576.466620]  ? rcu_do_batch+0x1ac/0x570
[26576.466855]  rcu_core+0x2cb/0x460
[26576.467060]  __do_softirq+0x178/0x517
[26576.467289]  __irq_exit_rcu+0xe3/0x160
[26576.467520]  irq_exit_rcu+0xa/0x20
[26576.467730]  sysvec_apic_timer_interrupt+0xa2/0xd0
[26576.468021]  
[26576.468153]  
[26576.468285]  asm_sysvec_apic_timer_interrupt+0x12/0x20
[26576.468598] RIP: 0010:native_safe_halt+0xb/0x10
[26576.468872] Code: 54 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
[26576.469976] RSP: 0018:ffffa8c180093ef8 EFLAGS: 00000246
[26576.470289] RAX: ffffffffabe64a80 RBX: ffff9da100340000 RCX: 0000000000000000
[26576.470718] RDX: ffff9da100340000 RSI: ffffffffac87e4d9 RDI: ffffffffabe64bf6
[26576.471169] RBP: 0000000000000001 R08: 0000000000000000 R09: 0000000000000000
[26576.471602] R10: 0000000000000000 R11: ffff9da17bd20c88 R12: 0000000000000000
[26576.472025] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[26576.472453]  ? mwait_idle+0x80/0x80
[26576.472668]  ? default_idle_call+0x26/0xa0
[26576.472918]  default_idle+0xa/0x10
[26576.473129]  default_idle_call+0x5e/0xa0
[26576.473367]  do_idle+0x1e9/0x240
[26576.473571]  cpu_startup_entry+0x19/0x20
[26576.473811]  secondary_startup_64_no_verify+0xd5/0xdb
[26576.474118]