[ 2492.961093] run fstests btrfs/056 at 2022-04-03 21:32:26
[ 2493.149591] BTRFS info (device dm-0): flagging fs with big metadata feature
[ 2493.150034] BTRFS info (device dm-0): using free space tree
[ 2493.150372] BTRFS info (device dm-0): has skinny extents
[ 2493.280008] BTRFS: device fsid e807b992-431e-4514-83a6-b15a077d3099 devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (369079)
[ 2493.347989] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 2493.348437] BTRFS info (device dm-11): disk space caching is enabled
[ 2493.348822] BTRFS info (device dm-11): has skinny extents
[ 2493.351054] BTRFS info (device dm-11): checking UUID tree
[ 2493.424726] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (365523)
[ 2493.425901] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (365523)
[ 2493.490372] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 2493.490879] BTRFS info (device dm-11): disk space caching is enabled
[ 2493.491256] BTRFS info (device dm-11): has skinny extents
[ 2493.493341] BTRFS info (device dm-11): start tree-log replay
[ 2493.498792] BTRFS info (device dm-11): checking UUID tree
[ 2493.569843] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[ 2493.570411] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 369216, name: mkfs.btrfs
[ 2493.570928] preempt_count: 100, expected: 0
[ 2493.571227] RCU nest depth: 1, expected: 0
[ 2493.571476] INFO: lockdep is turned off.
[ 2493.571709] Preemption disabled at:
[ 2493.571709] [] __do_softirq+0x5e/0x517
[ 2493.572307] CPU: 0 PID: 369216 Comm: mkfs.btrfs Not tainted 5.17.0+ #641
[ 2493.572705] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[ 2493.573208] Call Trace:
[ 2493.573359]  
[ 2493.573491]  dump_stack_lvl+0x56/0x6f
[ 2493.573714]  __might_resched.cold+0xff/0x13a
[ 2493.573981]  blk_release_queue+0x24/0x120
[ 2493.574223]  kobject_put+0x7c/0x1d0
[ 2493.574440]  ? rcu_do_batch+0x1ac/0x570
[ 2493.574670]  blkg_free.part.0+0x41/0x60
[ 2493.574907]  rcu_do_batch+0x1e1/0x570
[ 2493.575126]  ? rcu_do_batch+0x1ac/0x570
[ 2493.575355]  rcu_core+0x2cb/0x460
[ 2493.575561]  __do_softirq+0x178/0x517
[ 2493.575784]  __irq_exit_rcu+0xe3/0x160
[ 2493.576018]  irq_exit_rcu+0xa/0x20
[ 2493.576223]  sysvec_apic_timer_interrupt+0xa2/0xd0
[ 2493.576511]  
[ 2493.576640]  
[ 2493.576769]  asm_sysvec_apic_timer_interrupt+0x12/0x20
[ 2493.577078] RIP: 0010:lock_acquire+0x37/0x2d0
[ 2493.577338] Code: 54 41 89 cc 55 48 89 fd 53 44 89 c3 48 83 ec 30 4c 89 0c 24 0f 1f 44 00 00 65 8b 05 b3 29 e3 56 89 c0 48 0f a3 05 39 48 c9 01 <0f> 82 26 01 00 00 8b 0d 19 b5 c9 01 85 c9 0f 84 a8 00 00 00 65 8b
[ 2493.578430] RSP: 0018:ffffa2844141baf8 EFLAGS: 00000283
[ 2493.578751] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000002
[ 2493.579173] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffffaab9ce40
[ 2493.579594] RBP: ffffffffaab9ce40 R08: 0000000000000000 R09: 0000000000000000
[ 2493.580015] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000002
[ 2493.580430] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[ 2493.580865]  ? rcu_read_lock_sched_held+0x12/0x60
[ 2493.581148]  get_mem_cgroup_from_mm+0x3f/0x410
[ 2493.581413]  ? get_mem_cgroup_from_mm+0x1a/0x410
[ 2493.581692]  __mem_cgroup_charge+0x1c/0x60
[ 2493.581943]  __filemap_add_folio+0x375/0x6a0
[ 2493.582197]  ? mod_lruvec_state+0x60/0x60
[ 2493.582441]  filemap_add_folio+0x27/0x80
[ 2493.582676]  __filemap_get_folio+0x1ac/0x4d0
[ 2493.582938]  ? blkdev_llseek+0x60/0x60
[ 2493.583164]  pagecache_get_page+0x15/0x90
[ 2493.583405]  block_write_begin+0x24/0x130
[ 2493.583650]  generic_perform_write+0xa9/0x1d0
[ 2493.583915]  __generic_file_write_iter+0xdb/0x1a0
[ 2493.584195]  blkdev_write_iter+0xc1/0x150
[ 2493.584442]  new_sync_write+0xf6/0x160
[ 2493.584671]  vfs_write+0x290/0x390
[ 2493.584882]  __x64_sys_pwrite64+0x6f/0xb0
[ 2493.585135]  do_syscall_64+0x38/0x90
[ 2493.585351]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[ 2493.585655] RIP: 0033:0x7f643076019a
[ 2493.585881] 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
[ 2493.586968] RSP: 002b:00007fff96e9afd8 EFLAGS: 00000246 ORIG_RAX: 0000000000000012
[ 2493.587409] RAX: ffffffffffffffda RBX: 00007f643035d010 RCX: 00007f643076019a
[ 2493.587826] RDX: 0000000000200000 RSI: 00007f643035d010 RDI: 0000000000000003
[ 2493.588255] RBP: 0000000000200000 R08: 00007f643035d010 R09: 0000000000000000
[ 2493.588674] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
[ 2493.589096] R13: 0000000000000003 R14: 0000000000000000 R15: 0000000000000000
[ 2493.589518]  
[ 2493.657567] BTRFS: device fsid 46a47473-b411-4588-8dd5-27823e996384 devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (369216)
[ 2493.719064] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 2493.719508] BTRFS info (device dm-11): setting incompat feature flag for COMPRESS_LZO (0x8)
[ 2493.720004] BTRFS info (device dm-11): force lzo compression, level 0
[ 2493.720397] BTRFS info (device dm-11): disk space caching is enabled
[ 2493.720786] BTRFS info (device dm-11): has skinny extents
[ 2493.722868] BTRFS info (device dm-11): checking UUID tree
[ 2493.792025] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (365523)
[ 2493.793202] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (365523)
[ 2493.858445] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 2493.858960] BTRFS info (device dm-11): setting incompat feature flag for COMPRESS_LZO (0x8)
[ 2493.859504] BTRFS info (device dm-11): force lzo compression, level 0
[ 2493.859936] BTRFS info (device dm-11): disk space caching is enabled
[ 2493.860365] BTRFS info (device dm-11): has skinny extents
[ 2493.862019] BTRFS info (device dm-11): start tree-log replay
[ 2493.867470] BTRFS info (device dm-11): checking UUID tree
[ 2494.009997] BTRFS: device fsid 5d3f32cd-fc05-4a4e-817a-2c114892516e devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (369353)
[ 2494.079936] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 2494.080370] BTRFS info (device dm-11): disk space caching is enabled
[ 2494.080748] BTRFS info (device dm-11): has skinny extents
[ 2494.082596] BTRFS info (device dm-11): checking UUID tree
[ 2494.180573] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (365523)
[ 2494.181722] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (365523)
[ 2494.247672] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 2494.248284] BTRFS info (device dm-11): disk space caching is enabled
[ 2494.248807] BTRFS info (device dm-11): has skinny extents
[ 2494.250666] BTRFS info (device dm-11): start tree-log replay
[ 2494.258107] BTRFS info (device dm-11): checking UUID tree
[ 2494.399204] BTRFS: device fsid b4faedd7-b221-4370-bc5f-ec5e166e0daa devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (369490)
[ 2494.465886] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 2494.466328] BTRFS info (device dm-11): setting incompat feature flag for COMPRESS_LZO (0x8)
[ 2494.466848] BTRFS info (device dm-11): force lzo compression, level 0
[ 2494.467234] BTRFS info (device dm-11): disk space caching is enabled
[ 2494.467614] BTRFS info (device dm-11): has skinny extents
[ 2494.469300] BTRFS info (device dm-11): checking UUID tree
[ 2494.586881] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (365523)
[ 2494.588170] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (365523)
[ 2494.656155] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 2494.656643] BTRFS info (device dm-11): setting incompat feature flag for COMPRESS_LZO (0x8)
[ 2494.657170] BTRFS info (device dm-11): force lzo compression, level 0
[ 2494.657566] BTRFS info (device dm-11): disk space caching is enabled
[ 2494.657960] BTRFS info (device dm-11): has skinny extents
[ 2494.659695] BTRFS info (device dm-11): start tree-log replay
[ 2494.665846] BTRFS info (device dm-11): checking UUID tree
[ 2494.733833] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[ 2494.734353] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 369628, name: udevadm
[ 2494.734851] preempt_count: 100, expected: 0
[ 2494.735147] RCU nest depth: 1, expected: 0
[ 2494.735391] INFO: lockdep is turned off.
[ 2494.735670] Preemption disabled at:
[ 2494.735672] [] __do_softirq+0x5e/0x517
[ 2494.736274] CPU: 1 PID: 369628 Comm: udevadm Tainted: G        W         5.17.0+ #641
[ 2494.736736] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[ 2494.737391] Call Trace:
[ 2494.737547]  
[ 2494.737674]  dump_stack_lvl+0x56/0x6f
[ 2494.737904]  __might_resched.cold+0xff/0x13a
[ 2494.738162]  blk_release_queue+0x24/0x120
[ 2494.738404]  kobject_put+0x7c/0x1d0
[ 2494.738622]  ? rcu_do_batch+0x1ac/0x570
[ 2494.738857]  blkg_free.part.0+0x41/0x60
[ 2494.739088]  rcu_do_batch+0x1e1/0x570
[ 2494.739309]  ? rcu_do_batch+0x1ac/0x570
[ 2494.739557]  rcu_core+0x2cb/0x460
[ 2494.739783]  __do_softirq+0x178/0x517
[ 2494.740054]  __irq_exit_rcu+0xe3/0x160
[ 2494.740281]  irq_exit_rcu+0xa/0x20
[ 2494.740517]  sysvec_apic_timer_interrupt+0xa2/0xd0
[ 2494.740869]  
[ 2494.740999]  
[ 2494.741152]  asm_sysvec_apic_timer_interrupt+0x12/0x20
[ 2494.741544] RIP: 0010:xas_start+0x80/0x260
[ 2494.741808] Code: 77 22 48 85 c0 75 2c 48 c7 43 18 00 00 00 00 4c 89 e0 5b 5d 41 5c c3 48 c1 fd 02 85 ed 74 b1 45 31 e4 eb eb 41 0f b6 4c 24 fe <48> d3 e8 48 83 f8 3f 76 d4 45 31 e4 48 c7 43 18 01 00 00 00 5b 4c
[ 2494.743087] RSP: 0018:ffffa28441a43be8 EFLAGS: 00000286
[ 2494.743487] RAX: 0000000000000000 RBX: ffffa28441a43c20 RCX: 0000000000000006
[ 2494.743963] RDX: 0000000000000002 RSI: 00000000ffffffff RDI: ffff94fc422de5f8
[ 2494.744415] RBP: 0000000000000003 R08: 0000000000000000 R09: 0000000000000000
[ 2494.744889] R10: 0000000000020000 R11: 0000000000000000 R12: ffff94fc42359daa
[ 2494.745382] R13: 0000000000000001 R14: 0000000000000000 R15: ffffa28441a43e90
[ 2494.745891]  ? xas_start+0x3b/0x260
[ 2494.746137]  xas_load+0xa/0x50
[ 2494.746335]  filemap_get_read_batch+0x89/0x330
[ 2494.746636]  filemap_get_pages+0x80/0x740
[ 2494.746947]  ? lock_acquire+0x176/0x2d0
[ 2494.747219]  ? rcu_read_lock_sched_held+0x12/0x60
[ 2494.747579]  ? lock_release+0x1ed/0x2c0
[ 2494.747891]  filemap_read+0xbe/0x340
[ 2494.748199]  ? terminate_walk+0x130/0x140
[ 2494.748496]  ? path_openat+0x3e3/0xab0
[ 2494.748757]  ? register_handler_proc+0xe0/0x130
[ 2494.749061]  ? lock_acquire+0x176/0x2d0
[ 2494.749332]  xfs_file_buffered_read+0x6b/0x140 [xfs]
[ 2494.750067]  xfs_file_read_iter+0x70/0xd0 [xfs]
[ 2494.750514]  new_sync_read+0xf3/0x160
[ 2494.750749]  vfs_read+0x15f/0x1b0
[ 2494.750962]  ksys_read+0x55/0xd0
[ 2494.751212]  do_syscall_64+0x38/0x90
[ 2494.751504]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[ 2494.751900] RIP: 0033:0x7f43d2aed278
[ 2494.752130] Code: c0 48 8d 44 24 d0 48 89 44 24 c8 eb bb 0f 1f 44 00 00 f7 d8 89 05 40 0f 01 00 b8 ff ff ff ff c3 66 90 f3 0f 1e fa 31 c0 0f 05 <48> 3d 00 f0 ff ff 77 08 c3 0f 1f 80 00 00 00 00 f7 d8 89 05 18 0f
[ 2494.753286] RSP: 002b:00007ffc3753e1f8 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
[ 2494.753744] RAX: ffffffffffffffda RBX: 00007ffc3753e2bf RCX: 00007f43d2aed278
[ 2494.754193] RDX: 0000000000000340 RSI: 00007ffc3753e2d8 RDI: 0000000000000003
[ 2494.754653] RBP: 00007ffc3753e260 R08: 0000000000080000 R09: 00007f43d22f1af0
[ 2494.755092] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000340
[ 2494.755552] R13: 00007ffc3753e2d0 R14: 00007f43d22f1af0 R15: 0000000000000003
[ 2494.755985]