[15476.909651] run fstests btrfs/159 at 2022-04-02 01:09:22
[15477.108649] BTRFS info (device dm-0): flagging fs with big metadata feature
[15477.108902] BTRFS info (device dm-0): using free space tree
[15477.109100] BTRFS info (device dm-0): has skinny extents
[15477.307025] BTRFS: device fsid f7564b78-b728-4f12-a695-87dc16a25897 devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (3031836)
[15477.368234] BTRFS info (device dm-11): flagging fs with big metadata feature
[15477.368458] BTRFS info (device dm-11): setting incompat feature flag for COMPRESS_ZSTD (0x10)
[15477.368722] BTRFS info (device dm-11): use zstd compression, level 3
[15477.368942] BTRFS info (device dm-11): turning on async discard
[15477.369133] BTRFS info (device dm-11): disk space caching is enabled
[15477.369323] BTRFS info (device dm-11): has skinny extents
[15477.371228] BTRFS info (device dm-11): checking UUID tree
[15481.469209] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (3033548)
[15481.470137] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (3033548)
[15481.573396] BTRFS info (device dm-11): flagging fs with big metadata feature
[15481.573616] BTRFS info (device dm-11): use zstd compression, level 3
[15481.573824] BTRFS info (device dm-11): turning on async discard
[15481.574048] BTRFS info (device dm-11): disk space caching is enabled
[15481.574233] BTRFS info (device dm-11): has skinny extents
[15481.576488] BTRFS info (device dm-11): start tree-log replay
[15482.564787] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[15482.565068] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 3033589, name: mkfs.btrfs
[15482.565329] preempt_count: 102, expected: 0
[15482.565475] RCU nest depth: 1, expected: 0
[15482.565620] INFO: lockdep is turned off.
[15482.565765] Preemption disabled at:
[15482.565766] [] percpu_counter_add_batch+0x1b/0xb0
[15482.566113] CPU: 1 PID: 3033589 Comm: mkfs.btrfs Tainted: G        W         5.17.0+ #639
[15482.566360] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[15482.566624] Call Trace:
[15482.566743]  
[15482.566861]  dump_stack_lvl+0x56/0x6f
[15482.567005]  __might_resched.cold+0xff/0x13a
[15482.567155]  blk_release_queue+0x24/0x120
[15482.567303]  kobject_put+0x7c/0x1d0
[15482.567444]  ? rcu_do_batch+0x1ac/0x570
[15482.567587]  blkg_free.part.0+0x41/0x60
[15482.567733]  rcu_do_batch+0x1e1/0x570
[15482.567875]  ? rcu_do_batch+0x1ac/0x570
[15482.568020]  rcu_core+0x2cb/0x460
[15482.568154]  __do_softirq+0x178/0x517
[15482.568297]  __irq_exit_rcu+0xe3/0x160
[15482.568439]  irq_exit_rcu+0xa/0x20
[15482.568574]  sysvec_apic_timer_interrupt+0xa2/0xd0
[15482.568735]  
[15482.568850]  
[15482.568964]  asm_sysvec_apic_timer_interrupt+0x12/0x20
[15482.569132] RIP: 0010:_raw_spin_unlock_irqrestore+0x33/0x60
[15482.569313] 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 47 85 c0 74 03 5b
[15482.569789] RSP: 0018:ffffb835c2dbfc10 EFLAGS: 00000246
[15482.569973] RAX: 0000000080000002 RBX: 0000000000000217 RCX: 0000000000000000
[15482.570171] RDX: 0000000000000001 RSI: ffffffffb880a0fd RDI: ffffffffb8e651fd
[15482.570368] RBP: ffff941842d480a0 R08: 0000000000000000 R09: 0000000000000000
[15482.570569] R10: ffff9418bffd3e00 R11: 000000000003a420 R12: 0000000000000217
[15482.570767] R13: ffff941842d480a0 R14: 000000000000000f R15: 0000000000000000
[15482.570971]  ? percpu_counter_add_batch+0x9d/0xb0
[15482.571129]  ? _raw_spin_unlock_irqrestore+0x2d/0x60
[15482.571293]  percpu_counter_add_batch+0x9d/0xb0
[15482.571448]  folio_clear_dirty_for_io+0x1dd/0x290
[15482.571608]  write_cache_pages+0x13f/0x560
[15482.571757]  ? writeout_period+0x80/0x80
[15482.571914]  generic_writepages+0x41/0x60
[15482.572060]  do_writepages+0xbf/0x1b0
[15482.572201]  ? rcu_read_lock_sched_held+0x12/0x60
[15482.572363]  ? lock_release+0x1ed/0x2c0
[15482.572503]  ? lock_release+0x1ed/0x2c0
[15482.572644]  ? _raw_spin_unlock+0x29/0x40
[15482.572792]  filemap_fdatawrite_wbc+0x62/0x90
[15482.572954]  file_write_and_wait_range+0x78/0xc0
[15482.573109]  blkdev_fsync+0x14/0x40
[15482.573245]  __x64_sys_fsync+0x34/0x60
[15482.573391]  do_syscall_64+0x38/0x90
[15482.573530]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[15482.573692] RIP: 0033:0x7f08256db177
[15482.573834] 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 a3 f6 ff ff
[15482.575275] RSP: 002b:00007ffc534d0488 EFLAGS: 00000246 ORIG_RAX: 000000000000004a
[15482.575519] RAX: ffffffffffffffda RBX: 0000000002393c70 RCX: 00007f08256db177
[15482.575720] RDX: 0000000000001000 RSI: 0000000002393ce8 RDI: 0000000000000003
[15482.576006] RBP: 0000000000000000 R08: 0000000000000001 R09: 0000000000000100
[15482.576245] R10: 0000000000406251 R11: 0000000000000246 R12: 0000000000000000
[15482.576460] R13: 0000000000100000 R14: 0000000000000003 R15: 0000000002393ce8
[15482.576670]  
[15482.655706] BTRFS: device fsid de2133b2-a141-4b20-867d-ba155c343510 devid 1 transid 6 /dev/mapper/vg0-lv9 scanned by mkfs.btrfs (3033589)
[15482.717284] BTRFS info (device dm-11): flagging fs with big metadata feature
[15482.717504] BTRFS info (device dm-11): setting incompat feature flag for COMPRESS_ZSTD (0x10)
[15482.717764] BTRFS info (device dm-11): use zstd compression, level 3
[15482.717995] BTRFS info (device dm-11): turning on async discard
[15482.718174] BTRFS info (device dm-11): disk space caching is enabled
[15482.718360] BTRFS info (device dm-11): has skinny extents
[15482.720264] BTRFS info (device dm-11): checking UUID tree
[15488.114656] BTRFS info: devid 1 device path /dev/mapper/flakey-test changed to /dev/dm-11 scanned by systemd-udevd (3035301)
[15488.115505] BTRFS info: devid 1 device path /dev/dm-11 changed to /dev/mapper/flakey-test scanned by systemd-udevd (3035301)
[15488.219025] BTRFS info (device dm-11): flagging fs with big metadata feature
[15488.219306] BTRFS info (device dm-11): use zstd compression, level 3
[15488.219508] BTRFS info (device dm-11): turning on async discard
[15488.219765] BTRFS info (device dm-11): disk space caching is enabled
[15488.219980] BTRFS info (device dm-11): has skinny extents
[15488.222269] BTRFS info (device dm-11): start tree-log replay
[15489.225718] BUG: sleeping function called from invalid context at block/blk-sysfs.c:766
[15489.226021] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 3035344, name: udevadm
[15489.226273] preempt_count: 100, expected: 0
[15489.226423] RCU nest depth: 0, expected: 0
[15489.226587] INFO: lockdep is turned off.
[15489.226760] Preemption disabled at:
[15489.226761] [] __do_softirq+0x5e/0x517
[15489.227074] CPU: 0 PID: 3035344 Comm: udevadm Tainted: G        W         5.17.0+ #639
[15489.227355] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
[15489.227617] Call Trace:
[15489.227741]  
[15489.227859]  dump_stack_lvl+0x56/0x6f
[15489.228031]  __might_resched.cold+0xff/0x13a
[15489.228185]  blk_release_queue+0x24/0x120
[15489.228331]  kobject_put+0x7c/0x1d0
[15489.228487]  ? rcu_do_batch+0x1ac/0x570
[15489.228644]  blkg_free.part.0+0x41/0x60
[15489.228796]  rcu_do_batch+0x1e1/0x570
[15489.228979]  ? rcu_do_batch+0x1ac/0x570
[15489.229126]  rcu_core+0x2cb/0x460
[15489.229264]  __do_softirq+0x178/0x517
[15489.229404]  __irq_exit_rcu+0xe3/0x160
[15489.229552]  irq_exit_rcu+0xa/0x20
[15489.229691]  sysvec_apic_timer_interrupt+0xa2/0xd0
[15489.229854]  
[15489.229973]  
[15489.230100]  asm_sysvec_apic_timer_interrupt+0x12/0x20
[15489.230265] RIP: 0010:copy_user_enhanced_fast_string+0xe/0x40
[15489.230468] Code: 89 d1 c1 e9 03 83 e2 07 f3 48 a5 89 d1 f3 a4 31 c0 0f 01 ca c3 8d 0c ca 89 ca eb 20 0f 01 cb 83 fa 40 0f 82 60 ff ff ff 89 d1  a4 31 c0 0f 01 ca c3 89 ca eb 06 66 0f 1f 44 00 00 83 f8 12 74
[15489.230985] RSP: 0018:ffffb835c2ea7cc8 EFLAGS: 00050206
[15489.231171] RAX: 00007fffffffecc0 RBX: 0000000000000340 RCX: 0000000000000080
[15489.231410] RDX: 0000000000000340 RSI: ffff94188acc82c0 RDI: 00007fffe8ebc1c8
[15489.231618] RBP: ffffb835c2ea7e68 R08: 0000000000000001 R09: ffffb835c2ea7e58
[15489.231826] R10: 00007fffe8ebbf08 R11: 0000000000000000 R12: 0000000000000340
[15489.232046] R13: 0000000000000340 R14: 0000000000000000 R15: 0000000000000000
[15489.232252]  copyout+0x3d/0x50
[15489.232396]  copy_page_to_iter+0x104/0x4a0
[15489.232566]  filemap_read+0x18c/0x340
[15489.232717]  ? terminate_walk+0x130/0x140
[15489.232915]  ? register_handler_proc+0xe1/0x130
[15489.233112]  ? lock_acquire+0x176/0x2d0
[15489.233262]  xfs_file_buffered_read+0x6b/0x140 [xfs]
[15489.233506]  xfs_file_read_iter+0x70/0xd0 [xfs]
[15489.233723]  new_sync_read+0xf3/0x160
[15489.240365]  vfs_read+0x15f/0x1b0
[15489.240502]  ksys_read+0x55/0xd0
[15489.240640]  do_syscall_64+0x38/0x90
[15489.240782]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[15489.240948] RIP: 0033:0x7fe1b4425018
[15489.241087] Code: c0 48 8d 44 24 d0 48 89 44 24 c8 eb bb 0f 1f 44 00 00 f7 d8 89 05 60 11 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 38 11
[15489.241560] RSP: 002b:00007fffe8ebbe28 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
[15489.241803] RAX: ffffffffffffffda RBX: 0000000000000340 RCX: 00007fe1b4425018
[15489.242045] RDX: 0000000000000340 RSI: 00007fffe8ebbf08 RDI: 0000000000000003
[15489.242244] RBP: 00007fffe8ebbe90 R08: 0000000000080000 R09: 00007fe1b438a4d0
[15489.242461] R10: 0000000000000000 R11: 0000000000000246 R12: 00007fffe8ebbeef
[15489.242670] R13: 00007fe1b438a4d0 R14: 0000000000000003 R15: 00007fffe8ebbf00
[15489.242895]