[ 5314.328398] run fstests btrfs/201 at 2022-04-03 22:19:58
[ 5315.162054] BTRFS: device fsid d3e2d283-afd7-4cc9-baf8-e22b520b59ee devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (961620)
[ 5315.230776] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 5315.231012] BTRFS info (device dm-11): turning on async discard
[ 5315.231191] BTRFS info (device dm-11): disk space caching is enabled
[ 5315.232080] BTRFS info (device dm-11): has skinny extents
[ 5315.234495] BTRFS info (device dm-11): checking UUID tree
[ 5315.633587] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (960742)
[ 5315.634476] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (960742)
[ 5315.687770] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 5315.688007] BTRFS info (device dm-11): turning on async discard
[ 5315.688187] BTRFS info (device dm-11): disk space caching is enabled
[ 5315.688386] BTRFS info (device dm-11): has skinny extents
[ 5315.690162] BTRFS info (device dm-11): start tree-log replay
[ 5316.025977] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[ 5316.026283] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 961735, name: (spawn)
[ 5316.026560] preempt_count: 101, expected: 0
[ 5316.026717] RCU nest depth: 0, expected: 0
[ 5316.026877] INFO: lockdep is turned off.
[ 5316.027046] Preemption disabled at:
[ 5316.027047] [<0000000000000000>] 0x0
[ 5316.027350] CPU: 1 PID: 961735 Comm: (spawn) Tainted: G        W         5.17.0+ #641
[ 5316.027615] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[ 5316.027889] Call Trace:
[ 5316.028040]  
[ 5316.028159]  dump_stack_lvl+0x56/0x6f
[ 5316.028310]  __might_resched.cold+0xff/0x13a
[ 5316.028474]  blk_release_queue+0x24/0x120
[ 5316.028625]  kobject_put+0x7c/0x1d0
[ 5316.028772]  ? rcu_do_batch+0x1ac/0x570
[ 5316.028922]  blkg_free.part.0+0x41/0x60
[ 5316.029071]  rcu_do_batch+0x1e1/0x570
[ 5316.029218]  ? rcu_do_batch+0x1ac/0x570
[ 5316.029375]  rcu_core+0x2cb/0x460
[ 5316.029516]  __do_softirq+0x178/0x517
[ 5316.029664]  __irq_exit_rcu+0xe3/0x160
[ 5316.029814]  irq_exit_rcu+0xa/0x20
[ 5316.029958]  sysvec_apic_timer_interrupt+0xa2/0xd0
[ 5316.030153]  
[ 5316.030270]  
[ 5316.030396]  asm_sysvec_apic_timer_interrupt+0x12/0x20
[ 5316.030566] RIP: 0010:_raw_spin_unlock_irqrestore+0x33/0x60
[ 5316.030810] 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 5d 85 c0 74 03 5b
[ 5316.031378] RSP: 0018:ffffb12641a1fe50 EFLAGS: 00000246
[ 5316.031613] RAX: 0000000080000001 RBX: 0000000000000296 RCX: 00000000000003f1
[ 5316.031857] RDX: 00000000000112ad RSI: ffffffffa24544bf RDI: ffffffffa2e651fd
[ 5316.032117] RBP: ffff9be28031bf30 R08: 0000000000000000 R09: 0000000000000000
[ 5316.032392] R10: 0000000000000002 R11: ffff9be29097b810 R12: ffff9be29097b800
[ 5316.032602] R13: ffff9be2abc34800 R14: 0000000000000000 R15: 0000000000000001
[ 5316.032814]  ? bprm_execve+0x17f/0x860
[ 5316.033016]  ? _raw_spin_unlock_irqrestore+0x2d/0x60
[ 5316.033220]  bprm_execve+0x17f/0x860
[ 5316.033377]  do_execveat_common+0x1b5/0x230
[ 5316.033532]  __x64_sys_execve+0x39/0x50
[ 5316.033683]  do_syscall_64+0x38/0x90
[ 5316.033832]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[ 5316.034001] RIP: 0033:0x7fe131f032fb
[ 5316.034145] Code: 48 3d 00 f0 ff ff 76 e7 f7 d8 64 41 89 00 eb df 0f 1f 80 00 00 00 00 f7 d8 64 41 89 00 eb dc f3 0f 1e fa b8 3b 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 4d 5b 0f 00 f7 d8 64 89 01 48
[ 5316.034648] RSP: 002b:00007ffd60e19048 EFLAGS: 00000202 ORIG_RAX: 000000000000003b
[ 5316.034901] RAX: ffffffffffffffda RBX: 000055a021e811b0 RCX: 00007fe131f032fb
[ 5316.035109] RDX: 000055a021ea6a00 RSI: 000055a021eb4dd0 RDI: 000055a021e83080
[ 5316.035315] RBP: 00007ffd60e19150 R08: 0000000000000000 R09: 0000000000000000
[ 5316.035527] R10: 00007ffd60e19020 R11: 0000000000000202 R12: 00007ffd60e191c0
[ 5316.035730] R13: 000055a021eb4dd0 R14: 0000000000000000 R15: 000000000aba9500
[ 5316.035940]  
[ 5316.452493] BTRFS: device fsid 3a0c9499-639d-4f6f-86a4-af4415c78023 devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (961734)
[ 5316.512860] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 5316.513095] BTRFS info (device dm-11): turning on async discard
[ 5316.513278] BTRFS info (device dm-11): disk space caching is enabled
[ 5316.513468] BTRFS info (device dm-11): has skinny extents
[ 5316.515464] BTRFS info (device dm-11): checking UUID tree
[ 5322.979535] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (965788)
[ 5322.980799] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (965788)
[ 5323.076207] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 5323.076440] BTRFS info (device dm-11): turning on async discard
[ 5323.076621] BTRFS info (device dm-11): disk space caching is enabled
[ 5323.076802] BTRFS info (device dm-11): has skinny extents
[ 5323.078824] BTRFS info (device dm-11): start tree-log replay
[ 5323.547905] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[ 5323.548281] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 0, name: swapper/0
[ 5323.548522] preempt_count: 101, expected: 0
[ 5323.548672] RCU nest depth: 0, expected: 0
[ 5323.548819] INFO: lockdep is turned off.
[ 5323.548971] Preemption disabled at:
[ 5323.548971] [] schedule_preempt_disabled+0x1e/0x20
[ 5323.549308] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G        W         5.17.0+ #641
[ 5323.549546] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[ 5323.549796] Call Trace:
[ 5323.549921]  
[ 5323.555695]  dump_stack_lvl+0x56/0x6f
[ 5323.555861]  __might_resched.cold+0xff/0x13a
[ 5323.556021]  blk_release_queue+0x24/0x120
[ 5323.556173]  kobject_put+0x7c/0x1d0
[ 5323.556322]  ? rcu_do_batch+0x1ac/0x570
[ 5323.556468]  blkg_free.part.0+0x41/0x60
[ 5323.556613]  rcu_do_batch+0x1e1/0x570
[ 5323.556759]  ? rcu_do_batch+0x1ac/0x570
[ 5323.556904]  rcu_core+0x2cb/0x460
[ 5323.557042]  __do_softirq+0x178/0x517
[ 5323.557189]  __irq_exit_rcu+0xe3/0x160
[ 5323.557342]  irq_exit_rcu+0xa/0x20
[ 5323.557480]  sysvec_apic_timer_interrupt+0xa2/0xd0
[ 5323.557643]  
[ 5323.557761]  
[ 5323.557875]  asm_sysvec_apic_timer_interrupt+0x12/0x20
[ 5323.558045] RIP: 0010:native_safe_halt+0xb/0x10
[ 5323.558205] Code: 5d 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
[ 5323.558691] RSP: 0018:ffffffffa3a03ea8 EFLAGS: 00000246
[ 5323.558855] RAX: ffffffffa2e64a80 RBX: ffffffffa3a30a00 RCX: 0000000000000000
[ 5323.559052] RDX: ffffffffa3a30a00 RSI: ffffffffa387e4d9 RDI: ffffffffa2e64bf6
[ 5323.559250] RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
[ 5323.559448] R10: 0000000000000000 R11: ffff9be2fbc20c88 R12: 0000000000000000
[ 5323.559669] R13: 0000000000000000 R14: ffffffffa3a30118 R15: 0000000000000065
[ 5323.559888]  ? mwait_idle+0x80/0x80
[ 5323.560029]  ? default_idle_call+0x26/0xa0
[ 5323.560177]  default_idle+0xa/0x10
[ 5323.560319]  default_idle_call+0x5e/0xa0
[ 5323.560464]  do_idle+0x1e9/0x240
[ 5323.560594]  cpu_startup_entry+0x19/0x20
[ 5323.560737]  start_kernel+0x98c/0x99e
[ 5323.560879]  ? copy_bootdata+0x18/0x55
[ 5323.561023]  secondary_startup_64_no_verify+0xd5/0xdb
[ 5323.561187]  
[ 5323.903462] BTRFS: device fsid c2fa9b36-0e91-40c6-b3ff-52750266b9d9 devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (965829)
[ 5323.985577] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 5323.985800] BTRFS info (device dm-11): turning on async discard
[ 5323.985997] BTRFS info (device dm-11): disk space caching is enabled
[ 5323.986181] BTRFS info (device dm-11): has skinny extents
[ 5323.987767] BTRFS info (device dm-11): checking UUID tree
[ 5330.052420] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (969885)
[ 5330.053298] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (969885)
[ 5330.145554] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 5330.145775] BTRFS info (device dm-11): turning on async discard
[ 5330.145974] BTRFS info (device dm-11): disk space caching is enabled
[ 5330.146162] BTRFS info (device dm-11): has skinny extents
[ 5330.148382] BTRFS info (device dm-11): start tree-log replay
[ 5330.782830] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[ 5330.783118] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 969927, name: mkfs.btrfs
[ 5330.783422] preempt_count: 100, expected: 0
[ 5330.783578] RCU nest depth: 0, expected: 0
[ 5330.783755] INFO: lockdep is turned off.
[ 5330.783932] Preemption disabled at:
[ 5330.783933] [] __do_softirq+0x5e/0x517
[ 5330.784277] CPU: 1 PID: 969927 Comm: mkfs.btrfs Tainted: G        W         5.17.0+ #641
[ 5330.784562] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[ 5330.784857] Call Trace:
[ 5330.785002]  
[ 5330.785127]  dump_stack_lvl+0x56/0x6f
[ 5330.785291]  __might_resched.cold+0xff/0x13a
[ 5330.785449]  blk_release_queue+0x24/0x120
[ 5330.785614]  kobject_put+0x7c/0x1d0
[ 5330.785765]  ? rcu_do_batch+0x1ac/0x570
[ 5330.785921]  blkg_free.part.0+0x41/0x60
[ 5330.786073]  rcu_do_batch+0x1e1/0x570
[ 5330.786230]  ? rcu_do_batch+0x1ac/0x570
[ 5330.786403]  rcu_core+0x2cb/0x460
[ 5330.786551]  __do_softirq+0x178/0x517
[ 5330.786710]  __irq_exit_rcu+0xe3/0x160
[ 5330.786858]  irq_exit_rcu+0xa/0x20
[ 5330.787006]  sysvec_apic_timer_interrupt+0xa2/0xd0
[ 5330.787191]  
[ 5330.787318]  
[ 5330.787448]  asm_sysvec_apic_timer_interrupt+0x12/0x20
[ 5330.787717] RIP: 0010:get_page_from_freelist+0x9cd/0x16d0
[ 5330.788004] Code: 48 c7 45 28 00 00 00 00 48 c7 c6 93 e9 3c a2 48 89 ef e8 86 83 e1 ff 48 83 7c 24 20 00 74 0b e8 99 d8 ed ff fb 0f 1f 44 00 00 <4d> 85 ed 0f 84 a3 02 00 00 49 8b 45 00 48 c1 e8 33 83 e0 07 65 48
[ 5330.788597] RSP: 0000:ffffb12641edfc18 EFLAGS: 00000246
[ 5330.788790] RAX: 0000000080000000 RBX: ffff9be2fbd3a460 RCX: 0000000000000000
[ 5330.789045] RDX: 0017ffffc0000000 RSI: ffffffffa23ce993 RDI: ffffffffa23ce9b7
[ 5330.789299] RBP: ffff9be2fbd2f200 R08: 0000000000000000 R09: 0000000000000000
[ 5330.789548] R10: 0000000000000000 R11: 0000000000000000 R12: ffff9be2fbd3a480
[ 5330.789769] R13: ffffed300492c780 R14: 0000000000000000 R15: ffff9be2fffd3e00
[ 5330.789971]  ? get_page_from_freelist+0x9a3/0x16d0
[ 5330.790135]  ? get_page_from_freelist+0x9c7/0x16d0
[ 5330.790411]  ? get_page_from_freelist+0x9c7/0x16d0
[ 5330.790574]  ? rcu_read_lock_sched_held+0x12/0x60
[ 5330.790798]  ? prepare_alloc_pages+0xbc/0x1b0
[ 5330.790955]  __alloc_pages+0xd6/0x290
[ 5330.791095]  alloc_pages_vma+0x8f/0x2e0
[ 5330.791242]  __handle_mm_fault+0xb31/0x1460
[ 5330.791393]  ? mmap_region+0x2da/0x620
[ 5330.791539]  handle_mm_fault+0x11e/0x3a0
[ 5330.791680]  do_user_addr_fault+0x1e9/0x6b0
[ 5330.791843]  exc_page_fault+0x78/0x280
[ 5330.792002]  ? asm_exc_page_fault+0x8/0x30
[ 5330.792152]  asm_exc_page_fault+0x1e/0x30
[ 5330.792304] RIP: 0033:0x7fa3c83dd411
[ 5330.792456] 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
[ 5330.792914] RSP: 002b:00007ffd7f29e248 EFLAGS: 00010206
[ 5330.793107] RAX: 0000000000000000 RBX: 00007fa3c8057010 RCX: 0000000000047010
[ 5330.793321] RDX: 00007fa3c8057010 RSI: 0000000000000000 RDI: 00007fa3c8210000
[ 5330.793518] RBP: 0000000000200000 R08: 00007fa3c8057010 R09: 0000000000000000
[ 5330.793727] R10: fffffffffffffb0c R11: 00007fa3c83dd430 R12: 0000000000000000
[ 5330.793941] R13: 0000000000000003 R14: 0000000000000000 R15: 0000000000000000
[ 5330.794149]  
[ 5330.882248] BTRFS: device fsid ab310f59-46d8-4615-8d17-c2d93b17be3e devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (969927)
[ 5330.947298] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 5330.947521] BTRFS info (device dm-11): turning on async discard
[ 5330.947702] BTRFS info (device dm-11): disk space caching is enabled
[ 5330.947930] BTRFS info (device dm-11): has skinny extents
[ 5330.949640] BTRFS info (device dm-11): checking UUID tree
[ 5337.281659] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (973983)
[ 5337.282857] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (973983)
[ 5337.398684] BTRFS info (device dm-11): flagging fs with big metadata feature
[ 5337.399074] BTRFS info (device dm-11): turning on async discard
[ 5337.399340] BTRFS info (device dm-11): disk space caching is enabled
[ 5337.399606] BTRFS info (device dm-11): has skinny extents
[ 5337.402397] BTRFS info (device dm-11): start tree-log replay
[ 5337.789752] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[ 5337.790021] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 0, name: swapper/1
[ 5337.790300] preempt_count: 101, expected: 0
[ 5337.790511] RCU nest depth: 0, expected: 0
[ 5337.790669] INFO: lockdep is turned off.
[ 5337.790862] Preemption disabled at:
[ 5337.790863] [] ___slab_alloc+0x961/0xf50
[ 5337.791381] CPU: 1 PID: 0 Comm: swapper/1 Tainted: G        W         5.17.0+ #641
[ 5337.791832] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[ 5337.792224] Call Trace:
[ 5337.792395]  
[ 5337.792558]  dump_stack_lvl+0x56/0x6f
[ 5337.792762]  __might_resched.cold+0xff/0x13a
[ 5337.792985]  blk_release_queue+0x24/0x120
[ 5337.793881]  kobject_put+0x7c/0x1d0
[ 5337.794082]  ? rcu_do_batch+0x1ac/0x570
[ 5337.794294]  blkg_free.part.0+0x41/0x60
[ 5337.794496]  rcu_do_batch+0x1e1/0x570
[ 5337.794693]  ? rcu_do_batch+0x1ac/0x570
[ 5337.794897]  rcu_core+0x2cb/0x460
[ 5337.795099]  __do_softirq+0x178/0x517
[ 5337.795307]  __irq_exit_rcu+0xe3/0x160
[ 5337.795509]  irq_exit_rcu+0xa/0x20
[ 5337.795707]  sysvec_apic_timer_interrupt+0xa2/0xd0
[ 5337.795864]  
[ 5337.795975]  
[ 5337.796094]  asm_sysvec_apic_timer_interrupt+0x12/0x20
[ 5337.796257] RIP: 0010:native_safe_halt+0xb/0x10
[ 5337.796425] Code: 5d 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
[ 5337.797126] RSP: 0018:ffffb12640093ef8 EFLAGS: 00000246
[ 5337.797372] RAX: ffffffffa2e64a80 RBX: ffff9be280378000 RCX: 0000000000000000
[ 5337.797657] RDX: ffff9be280378000 RSI: ffffffffa387e4d9 RDI: ffffffffa2e64bf6
[ 5337.797941] RBP: 0000000000000001 R08: 0000000000000000 R09: 0000000000000000
[ 5337.798265] R10: 0000000000000002 R11: ffff9be2fbd20c88 R12: 0000000000000000
[ 5337.798547] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[ 5337.798753]  ? mwait_idle+0x80/0x80
[ 5337.798889]  ? default_idle_call+0x26/0xa0
[ 5337.799038]  default_idle+0xa/0x10
[ 5337.799214]  default_idle_call+0x5e/0xa0
[ 5337.799355]  do_idle+0x1e9/0x240
[ 5337.805271]  cpu_startup_entry+0x19/0x20
[ 5337.805414]  secondary_startup_64_no_verify+0xd5/0xdb
[ 5337.805581]