[ 4581.613536] run fstests btrfs/201 at 2022-04-02 22:18:48
[ 4582.072922] BTRFS: device fsid 9cf2a61f-53f4-44c4-8cc5-ff57a463c06b devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (900573)
[ 4582.134055] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 4582.134495] BTRFS info (device dm-11): disk space caching is enabled
[ 4582.134870] BTRFS info (device dm-11): has skinny extents
[ 4582.137292] BTRFS info (device dm-11): checking UUID tree
[ 4582.327400] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (899789)
[ 4582.328558] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (899789)
[ 4582.386749] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 4582.387202] BTRFS info (device dm-11): disk space caching is enabled
[ 4582.387592] BTRFS info (device dm-11): has skinny extents
[ 4582.389736] BTRFS info (device dm-11): start tree-log replay
[ 4582.468985] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[ 4582.469473] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 900687, name: mkfs.btrfs
[ 4582.469957] preempt_count: 101, expected: 0
[ 4582.470218] RCU nest depth: 1, expected: 0
[ 4582.470467] INFO: lockdep is turned off.
[ 4582.470771] Preemption disabled at:
[ 4582.470772] [<0000000000000000>] 0x0
[ 4582.471324] CPU: 0 PID: 900687 Comm: mkfs.btrfs Tainted: G        W         5.17.0+ #640
[ 4582.471834] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[ 4582.472329] Call Trace:
[ 4582.472488]  
[ 4582.472614]  dump_stack_lvl+0x56/0x6f
[ 4582.472837]  __might_resched.cold+0xff/0x13a
[ 4582.473095]  blk_release_queue+0x24/0x120
[ 4582.473337]  kobject_put+0x7c/0x1d0
[ 4582.473554]  ? rcu_do_batch+0x1ac/0x570
[ 4582.473787]  blkg_free.part.0+0x41/0x60
[ 4582.474018]  rcu_do_batch+0x1e1/0x570
[ 4582.474238]  ? rcu_do_batch+0x1ac/0x570
[ 4582.474475]  rcu_core+0x2cb/0x460
[ 4582.474677]  __do_softirq+0x178/0x517
[ 4582.474902]  __irq_exit_rcu+0xe3/0x160
[ 4582.475129]  irq_exit_rcu+0xa/0x20
[ 4582.475334]  sysvec_apic_timer_interrupt+0xa2/0xd0
[ 4582.475627]  
[ 4582.475758]  
[ 4582.475888]  asm_sysvec_apic_timer_interrupt+0x12/0x20
[ 4582.476196] RIP: 0010:cgroup_rstat_updated+0xb/0xd0
[ 4582.476491] Code: ff ff ff ff 48 c7 c7 f8 08 c5 ac e8 0f 81 bf 00 85 c0 0f 85 71 fc ff ff 0f 0b e9 6a fc ff ff 0f 1f 44 00 00 41 54 55 48 63 ee <48> 8b 14 ed 20 5b 93 ac 53 48 89 fb 48 c7 c7 40 4a 02 00 48 8b 83
[ 4582.477602] RSP: 0000:ffffa8c181f87d48 EFLAGS: 00000292
[ 4582.477911] RAX: 0000000000000000 RBX: 00002b200402d920 RCX: 0000000000000011
[ 4582.478325] RDX: 0000000000000001 RSI: 0000000000000000 RDI: ffff9da10d58f000
[ 4582.478746] RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
[ 4582.479160] R10: 0000000000000000 R11: 0000000000000000 R12: ffff9da105be6000
[ 4582.479581] R13: ffff9da10ee77800 R14: 0000000000000001 R15: ffff9da1051b4080
[ 4582.480000]  __mod_memcg_lruvec_state+0x8d/0x110
[ 4582.480279]  __mod_lruvec_page_state+0xd5/0x220
[ 4582.480557]  page_add_new_anon_rmap+0xb7/0x210
[ 4582.480827]  __handle_mm_fault+0x127d/0x1460
[ 4582.481083]  ? mmap_region+0x2da/0x620
[ 4582.481310]  handle_mm_fault+0x11e/0x3a0
[ 4582.481550]  do_user_addr_fault+0x1e9/0x6b0
[ 4582.481816]  exc_page_fault+0x78/0x280
[ 4582.482042]  ? asm_exc_page_fault+0x8/0x30
[ 4582.482290]  asm_exc_page_fault+0x1e/0x30
[ 4582.482537] RIP: 0033:0x7f0425bf5e71
[ 4582.482767] Code: 01 00 00 48 83 fa 40 77 77 c5 fe 7f 44 17 e0 c5 fe 7f 07 c5 f8 77 c3 66 90 f3 0f 1e fa c5 f8 77 48 89 d1 40 0f b6 c6 48 89 fa  aa 48 89 d0 c3 66 0f 1f 84 00 00 00 00 00 f3 0f 1e fa 48 39 d1
[ 4582.483865] RSP: 002b:00007ffd78f81548 EFLAGS: 00010206
[ 4582.484177] RAX: 0000000000000000 RBX: 00007f0425871010 RCX: 0000000000015010
[ 4582.484601] RDX: 00007f0425871010 RSI: 0000000000000000 RDI: 00007f0425a5c000
[ 4582.485022] RBP: 0000000000200000 R08: 00007f0425871010 R09: 0000000000000000
[ 4582.485440] R10: 00007f0425a9ec70 R11: 00007f0425bf5e90 R12: 0000000000000000
[ 4582.485863] R13: 0000000000000003 R14: 0000000000000000 R15: 0000000000000000
[ 4582.486284]  
[ 4582.653717] BTRFS: device fsid efe42d93-6d53-4d07-8c77-6078276562fb devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (900687)
[ 4582.744359] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 4582.745632] BTRFS info (device dm-11): disk space caching is enabled
[ 4582.746753] BTRFS info (device dm-11): has skinny extents
[ 4582.752200] BTRFS info (device dm-11): checking UUID tree
[ 4588.837376] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (904741)
[ 4588.838644] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (904741)
[ 4588.927021] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 4588.927459] BTRFS info (device dm-11): disk space caching is enabled
[ 4588.927835] BTRFS info (device dm-11): has skinny extents
[ 4588.930067] BTRFS info (device dm-11): start tree-log replay
[ 4590.642916] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[ 4590.643467] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 20, name: ksoftirqd/1
[ 4590.644009] preempt_count: 100, expected: 0
[ 4590.644289] RCU nest depth: 0, expected: 0
[ 4590.644566] INFO: lockdep is turned off.
[ 4590.644826] Preemption disabled at:
[ 4590.644827] [] __do_softirq+0x5e/0x517
[ 4590.645437] CPU: 1 PID: 20 Comm: ksoftirqd/1 Tainted: G        W         5.17.0+ #640
[ 4590.645949] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[ 4590.646505] Call Trace:
[ 4590.646673]  
[ 4590.646819]  dump_stack_lvl+0x56/0x6f
[ 4590.647067]  __might_resched.cold+0xff/0x13a
[ 4590.647353]  blk_release_queue+0x24/0x120
[ 4590.647627]  kobject_put+0x7c/0x1d0
[ 4590.647864]  ? rcu_do_batch+0x1ac/0x570
[ 4590.648122]  blkg_free.part.0+0x41/0x60
[ 4590.648459]  rcu_do_batch+0x1e1/0x570
[ 4590.648899]  ? rcu_do_batch+0x1ac/0x570
[ 4590.649218]  rcu_core+0x2cb/0x460
[ 4590.649486]  __do_softirq+0x178/0x517
[ 4590.649788]  ? smpboot_thread_fn+0x2c/0x270
[ 4590.650098]  run_ksoftirqd+0x43/0x70
[ 4590.650416]  smpboot_thread_fn+0x1c1/0x270
[ 4590.650726]  ? sort_range+0x20/0x20
[ 4590.650973]  kthread+0xf0/0x120
[ 4590.651305]  ? kthread_complete_and_exit+0x20/0x20
[ 4590.651639]  ret_from_fork+0x1f/0x30
[ 4590.651889]  
[ 4591.394941] BTRFS: device fsid fd4832be-a1e3-43b2-b1d2-d8a4f96ecca8 devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (904783)
[ 4591.464158] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 4591.464623] BTRFS info (device dm-11): disk space caching is enabled
[ 4591.465040] BTRFS info (device dm-11): has skinny extents
[ 4591.467083] BTRFS info (device dm-11): checking UUID tree
[ 4596.860539] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (908838)
[ 4596.861766] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (908838)
[ 4596.950235] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 4596.950660] BTRFS info (device dm-11): disk space caching is enabled
[ 4596.951039] BTRFS info (device dm-11): has skinny extents
[ 4596.953312] BTRFS info (device dm-11): start tree-log replay
[ 4597.723831] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[ 4597.724385] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 908880, name: mkfs.btrfs
[ 4597.725015] preempt_count: 101, expected: 0
[ 4597.725368] RCU nest depth: 1, expected: 0
[ 4597.725701] INFO: lockdep is turned off.
[ 4597.726031] Preemption disabled at:
[ 4597.726033] [<0000000000000000>] 0x0
[ 4597.726566] CPU: 0 PID: 908880 Comm: mkfs.btrfs Tainted: G        W         5.17.0+ #640
[ 4597.727134] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[ 4597.727687] Call Trace:
[ 4597.727853]  
[ 4597.727992]  dump_stack_lvl+0x56/0x6f
[ 4597.728238]  __might_resched.cold+0xff/0x13a
[ 4597.728526]  blk_release_queue+0x24/0x120
[ 4597.728794]  kobject_put+0x7c/0x1d0
[ 4597.729029]  ? rcu_do_batch+0x1ac/0x570
[ 4597.729284]  blkg_free.part.0+0x41/0x60
[ 4597.729541]  rcu_do_batch+0x1e1/0x570
[ 4597.729786]  ? rcu_do_batch+0x1ac/0x570
[ 4597.730041]  rcu_core+0x2cb/0x460
[ 4597.730263]  __do_softirq+0x178/0x517
[ 4597.730512]  __irq_exit_rcu+0xe3/0x160
[ 4597.730773]  irq_exit_rcu+0xa/0x20
[ 4597.730991]  sysvec_apic_timer_interrupt+0xa2/0xd0
[ 4597.731296]  
[ 4597.731437]  
[ 4597.731577]  asm_sysvec_apic_timer_interrupt+0x12/0x20
[ 4597.731904] RIP: 0010:_raw_spin_unlock_irqrestore+0x33/0x60
[ 4597.732256] 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
[ 4597.733408] RSP: 0018:ffffa8c1822d7c80 EFLAGS: 00000246
[ 4597.733728] RAX: 0000000080000001 RBX: 0000000000000286 RCX: 0000000000000000
[ 4597.734163] RDX: 0000000002000021 RSI: ffffffffab49e718 RDI: ffffffffabe651fd
[ 4597.734614] RBP: ffff9da102399390 R08: 0000000000000000 R09: 0000000000000000
[ 4597.735036] R10: ffff9da10dbfd540 R11: ffffffffab3cd75c R12: 0000000000000000
[ 4597.735461] R13: 0000000000001000 R14: 0000000000000000 R15: ffff9da10dbfd540
[ 4597.735885]  ? free_unref_page_list+0x12c/0x560
[ 4597.736160]  ? mark_buffer_dirty+0x178/0x1d0
[ 4597.736464]  ? _raw_spin_unlock_irqrestore+0x2d/0x60
[ 4597.736763]  mark_buffer_dirty+0x178/0x1d0
[ 4597.737020]  __block_commit_write.constprop.0.isra.0+0x51/0xb0
[ 4597.737374]  block_write_end+0x30/0xb0
[ 4597.737616]  ? blkdev_llseek+0x60/0x60
[ 4597.737838]  blkdev_write_end+0x14/0xb0
[ 4597.738065]  generic_perform_write+0xf7/0x1d0
[ 4597.738327]  __generic_file_write_iter+0xdb/0x1a0
[ 4597.738602]  blkdev_write_iter+0xc1/0x150
[ 4597.738840]  new_sync_write+0xf6/0x160
[ 4597.739062]  vfs_write+0x290/0x390
[ 4597.739265]  __x64_sys_pwrite64+0x6f/0xb0
[ 4597.739506]  do_syscall_64+0x38/0x90
[ 4597.739720]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[ 4597.740014] RIP: 0033:0x7f62ca0ce19a
[ 4597.740228] 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
[ 4597.741287] RSP: 002b:00007ffea142d648 EFLAGS: 00000246 ORIG_RAX: 0000000000000012
[ 4597.741722] RAX: ffffffffffffffda RBX: 00007f62c9ccb010 RCX: 00007f62ca0ce19a
[ 4597.742120] RDX: 0000000000200000 RSI: 00007f62c9ccb010 RDI: 0000000000000003
[ 4597.742521] RBP: 0000000000200000 R08: 00007f62c9ccb010 R09: 0000000000000000
[ 4597.742919] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
[ 4597.743319] R13: 0000000000000003 R14: 0000000000000000 R15: 0000000000000000
[ 4597.743719]  
[ 4598.820625] BTRFS: device fsid 4c79404e-b076-48ab-9a43-216eadf6c7d9 devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (908880)
[ 4598.883949] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 4598.884389] BTRFS info (device dm-11): disk space caching is enabled
[ 4598.884763] BTRFS info (device dm-11): has skinny extents
[ 4598.887202] BTRFS info (device dm-11): checking UUID tree
[ 4604.752928] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (912935)
[ 4604.754172] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (912935)
[ 4604.843139] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 4604.843567] BTRFS info (device dm-11): disk space caching is enabled
[ 4604.843944] BTRFS info (device dm-11): has skinny extents
[ 4604.846312] BTRFS info (device dm-11): start tree-log replay
[ 4605.541749] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[ 4605.542302] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 912977, name: 201
[ 4605.542831] preempt_count: 100, expected: 0
[ 4605.543115] RCU nest depth: 1, expected: 0
[ 4605.543396] INFO: lockdep is turned off.
[ 4605.543675] Preemption disabled at:
[ 4605.543676] [] __do_softirq+0x5e/0x517
[ 4605.544271] CPU: 0 PID: 912977 Comm: 201 Tainted: G        W         5.17.0+ #640
[ 4605.544751] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[ 4605.545298] Call Trace:
[ 4605.545463]  
[ 4605.545602]  dump_stack_lvl+0x56/0x6f
[ 4605.545846]  __might_resched.cold+0xff/0x13a
[ 4605.546128]  blk_release_queue+0x24/0x120
[ 4605.546396]  kobject_put+0x7c/0x1d0
[ 4605.546645]  ? rcu_do_batch+0x1ac/0x570
[ 4605.546892]  blkg_free.part.0+0x41/0x60
[ 4605.547136]  rcu_do_batch+0x1e1/0x570
[ 4605.547375]  ? rcu_do_batch+0x1ac/0x570
[ 4605.547621]  rcu_core+0x2cb/0x460
[ 4605.547837]  __do_softirq+0x178/0x517
[ 4605.548072]  __irq_exit_rcu+0xe3/0x160
[ 4605.548317]  irq_exit_rcu+0xa/0x20
[ 4605.548535]  sysvec_apic_timer_interrupt+0xa2/0xd0
[ 4605.548839]  
[ 4605.548976]  
[ 4605.549115]  asm_sysvec_apic_timer_interrupt+0x12/0x20
[ 4605.549442] RIP: 0010:count_memcg_events.constprop.0+0x4a/0x50
[ 4605.549818] Code: 00 00 00 41 5c e9 e6 a1 08 00 e8 41 bb f0 ff ba 01 00 00 00 44 89 e6 48 89 ef e8 d1 a1 08 00 e8 ac bd f0 ff fb 0f 1f 44 00 00 <5d> 41 5c c3 66 90 41 54 41 89 f4 55 48 89 fd 9c 58 0f 1f 40 00 48
[ 4605.550937] RSP: 0000:ffffa8c1824d7e90 EFLAGS: 00000246
[ 4605.551259] RAX: 0000000080000000 RBX: 0000000000000354 RCX: 0000000000000000
[ 4605.551704] RDX: 0000000000000019 RSI: ffffffffac7f78ef RDI: ffffffffab3a04a4
[ 4605.552125] RBP: ffff9da105be6000 R08: 0000000000000000 R09: 0000000000000000
[ 4605.552547] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000014
[ 4605.552968] R13: 00007f78c26650d9 R14: ffffa8c1824d7f58 R15: ffff9da100d83b38
[ 4605.553392]  ? count_memcg_events.constprop.0+0x44/0x50
[ 4605.553713]  handle_mm_fault+0xa8/0x3a0
[ 4605.553947]  do_user_addr_fault+0x1e9/0x6b0
[ 4605.554200]  ? rcu_read_lock_sched_held+0x12/0x60
[ 4605.554488]  exc_page_fault+0x78/0x280
[ 4605.554717]  ? asm_exc_page_fault+0x8/0x30
[ 4605.554965]  asm_exc_page_fault+0x1e/0x30
[ 4605.555209] RIP: 0033:0x7f78c26650d9
[ 4605.555431] Code: Unable to access opcode bytes at RIP 0x7f78c26650af.
[ 4605.555819] RSP: 002b:00007fff5c703e90 EFLAGS: 00010246
[ 4605.556134] RAX: 0000000000000000 RBX: 0000000000000001 RCX: 00007f78c26650d9
[ 4605.556558] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000001200011
[ 4605.556981] RBP: 0000000000000000 R08: 0000000000000000 R09: 000000000000005f
[ 4605.557406] R10: 00007f78c2595a10 R11: 0000000000000246 R12: 0000000000000000
[ 4605.557831] R13: 00007fff5c703f80 R14: 0000557b066d4ad0 R15: 0000557b043dbd31
[ 4605.558259]