A log used to help report a bcachefs bug: <https://github.com/koverstreet/bcachefs/>

Log.txt

[32959.989201] Allocator stuck? Waited for 30 seconds
[32959.989203] Allocator debug:
[32959.989204]   capacity849891820
[32959.989205]   used                 833188184
[32959.989205]   reserved             73903636
[32959.989205]   hidden               7221557
[32959.989206]   btree                20343808
[32959.989206]   data                 811177914
[32959.989207]   cached               0
[32959.989207]   reserved             519032
[32959.989207]   online_reserved      1121792
[32959.989208]
[32959.989208]   freelist_wait        waiting
[32959.989209]   open buckets allocated2
[32959.989209]   open buckets total   1024
[32959.989209]   open_buckets_wait    empty
[32959.989210]   open_buckets_btree   0
[32959.989210]   open_buckets_user    1
[32959.989211]   btree reserve cache  0

[32959.989211] Dev 0:
[32959.989212]                      buckets         sectors      fragmented
[32959.989212]   free                    29               0               0
[32959.989213]   sb                       5            4104             301
[32959.989213]   journal               8192         7217152               0
[32959.989214]   btree                39734        20343808        14661846
[32959.989214] Allocator stuck? Waited for 30 seconds
[32959.989214]   user                926297       811177914         4889743
[32959.989215]   cached                   0               0               0
[32959.989215]   parity                   0               0               0
[32959.989215] Allocator debug:
[32959.989216]   stripe                   0               0               0
[32959.989216]   capacity849891820
[32959.989216]   need_gc_gens             0               0               0
[32959.989217]   used                 833188184
[32959.989217]   need_discard         74319               0               0
[32959.989218]   reserved             73903636
[32959.989218]   unstriped                0               0               0
[32959.989218]   hidden               7221557
[32959.989218]   capacity           1048576
[32959.989219]   btree                20343808
[32959.989219]
[32959.989219]   data                 811177914
[32959.989219]   reserves:
[32959.989220]   cached               0
[32959.989220]   stripe               32824
[32959.989220]   reserved             519032
[32959.989221]   normal               16440
[32959.989221]   online_reserved      1121792
[32959.989221]   copygc                  56
[32959.989222]
[32959.989222]   btree                   28
[32959.989222]   freelist_wait        waiting
[32959.989222]   btree_copygc             0
[32959.989223]   open buckets allocated2
[32959.989223]   reclaim                  0
[32959.989223]   open buckets total   1024
[32959.989223]   interior_updates         0
[32959.989224]   open_buckets_wait    empty
[32959.989224]
[32959.989224]   open_buckets_btree   0
[32959.989224]   open buckets             1
[32959.989225]   open_buckets_user    1
[32959.989225]   buckets to invalidate    0
[32959.989225]   btree reserve cache  0


[32959.989226] Copygc debug:
[32959.989226] Dev 0:
[32959.989226]   running: 1
[32959.989227]                      buckets         sectors      fragmented
[32959.989227]   copygc_wait:0
[32959.989227]   free                    29               0               0
[32959.989227]   copygc_wait_at:0
[32959.989228]   sb                       5            4104             301
[32959.989228]   Currently waiting for:0 B
[32959.989228]   journal               8192         7217152               0
[32959.989228]   Currently waiting since:25.1 TiB
[32959.989229]   btree                39734        20343808        14661846
[32959.989229]   Currently calculated wait:
[32959.989229]     vdb2:  0 B
[32959.989230]   user                926297       811177914         4889743

[32959.989230]   cached                   0               0               0
[32959.989230] Journal debug:
[32959.989231]   parity                   0               0               0
[32959.989231]   flags:                   replay_done,running,may_skip_flush
[32959.989231]   stripe                   0               0               0
[32959.989232]   dirty journal entries:   3271/32768
[32959.989232]   need_gc_gens             0               0               0
[32959.989232]   seq:                     4861841
[32959.989232]   need_discard         74319               0               0
[32959.989233]   seq_ondisk:              4861841
[32959.989233]   unstriped                0               0               0
[32959.989233]   last_seq:                4858571
[32959.989234]   capacity           1048576
[32959.989234]   last_seq_ondisk:         4858564
[32959.989234]
[32959.989234]   flushed_seq_ondisk:      4861841
[32959.989235]   reserves:
[32959.989235]   watermark:               stripe
[32959.989235]   stripe               32824
[32959.989235]   each entry reserved:     321
[32959.989236]   normal               16440
[32959.989236]   nr flush writes:         27472
[32959.989236]   copygc                  56
[32959.989236]   nr noflush writes:       14761
[32959.989236]   btree                   28
[32959.989237]   average write size:      272 KiB
[32959.989237]   btree_copygc             0
[32959.989237]   free buf:                524288
[32959.989238]   reclaim                  0
[32959.989238]   nr direct reclaim:       0
[32959.989238]   interior_updates         0
[32959.989239]   nr background reclaim:   1035427
[32959.989239]
[32959.989239]   reclaim kicked:          0
[32959.989239]   open buckets             1
[32959.989240]   reclaim runs in:         52 ms
[32959.989240]   buckets to invalidate    0
[32959.989240]   blocked:                 0

[32959.989241]   current entry sectors:   881
[32959.989241] Copygc debug:
[32959.989241]   current entry error:     (No error)
[32959.989241]   running: 1
[32959.989242]   current entry:           closed
[32959.989242]   copygc_wait:0
[32959.989242]   unwritten entries:
[32959.989242]   copygc_wait_at:0
[32959.989243]   last buf closed
[32959.989243]   Currently waiting for:0 B
[32959.989243]   space:
[32959.989243]   Currently waiting since:25.1 TiB
[32959.989244]     discarded              881:903025
[32959.989244]   Currently calculated wait:
[32959.989245]     clean ondisk           881:2847598
[32959.989245]     vdb2:  0 B
[32959.989245]     clean                  881:2847598

[32959.989246] Journal debug:
[32959.989246]     total                  881:2847598
[32959.989246]   flags:                   replay_done,running,may_skip_flush
[32959.989246]   dev 0:
[32959.989247]   durability 1:
[32959.989247]   dirty journal entries:   3271/32768
[32959.989247]     nr                     8192
[32959.989247]   seq:                     4861841
[32959.989248]     bucket size            881
[32959.989248]   seq_ondisk:              4861841
[32959.989248]     available              1025:288
[32959.989249]   last_seq:                4858571
[32959.989249]     discard_idx            7025
[32959.989249]   last_seq_ondisk:         4858564
[32959.989249]     dirty_ondisk           3136 (seq 4858564)
[32959.989249]   flushed_seq_ondisk:      4861841
[32959.989250]     dirty_idx              3143 (seq 4858571)
[32959.989250]   watermark:               stripe
[32959.989250]     cur_idx                5999 (seq 4861841)
[32959.989251]   each entry reserved:     321
[32959.989251]   replicas want 1 need 1
[32959.989251]   nr flush writes:         27472
[32959.989251]   nr noflush writes:       14761
[32959.989252]   average write size:      272 KiB
[32959.989252]   free buf:                524288
[32959.989555] Allocator stuck? Waited for 30 seconds
[32959.989557] Allocator debug:
[32959.989558]   capacity849891820
[32959.989559]   used                 833188184
[32959.989559]   reserved             73903636
[32959.989560]   hidden               7221557
[32959.989561]   btree                20343808
[32959.989561]   data                 811177914
[32959.989562]   cached               0
[32959.989562]   reserved             519032
[32959.989563]   online_reserved      1121792
[32959.989564]
[32959.989564]   freelist_wait        waiting
[32959.989565]   open buckets allocated2
[32959.989565]   open buckets total   1024
[32959.989566]   open_buckets_wait    empty
[32959.989566]   open_buckets_btree   0
[32959.989567]   open_buckets_user    1
[32959.989568]   btree reserve cache  0

[32959.989569] Dev 0:
[32959.989569]                      buckets         sectors      fragmented
[32959.989570]   free                    29               0               0
[32959.989571]   sb                       5            4104             301
[32959.989571]   journal               8192         7217152               0
[32959.989572]   btree                39734        20343808        14661846
[32959.989573]   user                926297       811177914         4889743
[32959.989574]   cached                   0               0               0
[32959.989574]   parity                   0               0               0
[32959.989575]   stripe                   0               0               0
[32959.989576]   need_gc_gens             0               0               0
[32959.989577]   need_discard         74319               0               0
[32959.989578]   unstriped                0               0               0
[32959.989578]   capacity           1048576
[32959.989579]
[32959.989579]   reserves:
[32959.989580]   stripe               32824
[32959.989580]   normal               16440
[32959.989581]   copygc                  56
[32959.989581]   btree                   28
[32959.989582]   btree_copygc             0
[32959.989583]   reclaim                  0
[32959.989583]   interior_updates         0
[32959.989584]
[32959.989584]   open buckets             1
[32959.989585]   buckets to invalidate    0

[32959.989586] Copygc debug:
[32959.989586]   running: 1
[32959.989587]   copygc_wait:0
[32959.989587]   copygc_wait_at:0
[32959.989588]   Currently waiting for:0 B
[32959.989589]   Currently waiting since:25.1 TiB
[32959.989590]   Currently calculated wait:
[32959.989590]     vdb2:  0 B
[32959.989591]   [<0>] bch2_copygc_wait_to_text+0x1ad/0x2c0 [bcachefs]
[32959.989592]   [<0>] bch2_print_allocator_stuck+0x11c/0x240 [bcachefs]
[32959.989593]   [<0>] __bch2_wait_on_allocator+0x9f/0xc0 [bcachefs]
[32959.989594]   [<0>] bch2_btree_update_start+0x74c/0xa40 [bcachefs]
[32959.989594]   [<0>] bch2_btree_node_rewrite+0x6f/0x4a0 [bcachefs]
[32959.989595]   [<0>] bch2_btree_node_rewrite_pos+0xa2/0xe0 [bcachefs]
[32959.989596]   [<0>] __bch2_move_data_phys+0x899/0xce0 [bcachefs]
[32959.989597]   [<0>] bch2_evacuate_bucket+0xcc/0x130 [bcachefs]
[32959.989597]   [<0>] bch2_copygc+0x113/0x350 [bcachefs]
[32959.989598]   [<0>] bch2_copygc_thread+0x309/0x560 [bcachefs]
[32959.989599]   [<0>] kthread+0xfb/0x250
[32959.989600]   [<0>] ret_from_fork+0x199/0x1d0
[32959.989600]   [<0>] ret_from_fork_asm+0x1a/0x30

[32959.989601] Journal debug:
[32959.989602]   flags:                   replay_done,running,may_skip_flush
[32959.989603]   dirty journal entries:   3271/32768
[32959.989603]   seq:                     4861841
[32959.989604]   seq_ondisk:              4861841
[32959.989604]   last_seq:                4858571
[32959.989605]   last_seq_ondisk:         4858564
[32959.989606]   flushed_seq_ondisk:      4861841
[32959.989606]   watermark:               stripe
[32959.989607]   each entry reserved:     321
[32959.989607]   nr flush writes:         27472
[32959.989608]   nr noflush writes:       14761
[32959.989608]   average write size:      272 KiB
[32959.989609]   free buf:                524288
[32959.989610]   nr direct reclaim:       0
[32959.989610]   nr background reclaim:   1035427
[32959.989611]   reclaim kicked:          0
[32959.989611]   reclaim runs in:         52 ms
[32959.989612]   blocked:                 0
[32959.989612]   current entry sectors:   881
[32959.989613]   current entry error:     (No error)
[32959.989613]   current entry:           closed
[32959.989614]   unwritten entries:
[32959.989614]   last buf closed
[32959.989615]   space:
[32959.989615]     discarded              881:903025
[32959.989616]     clean ondisk           881:2847598
[32959.989617]     clean                  881:2847598
[32959.989617]     total                  881:2847598
[32959.989618]   dev 0:
[32959.989618]   durability 1:
[32959.989619]     nr                     8192
[32959.989619]     bucket size            881
[32959.989620]     available              1025:288
[32959.989621]     discard_idx            7025
[32959.989621]     dirty_ondisk           3136 (seq 4858564)
[32959.989622]     dirty_idx              3143 (seq 4858571)
[32959.989623]     cur_idx                5999 (seq 4861841)
[32959.989623]   replicas want 1 need 1
[32960.096864]   nr direct reclaim:       0
[32960.097357]   nr background reclaim:   1035427
[32960.097844]   reclaim kicked:          0
[32960.098207]   reclaim runs in:         52 ms
[32960.098592]   blocked:                 0
[32960.098949]   current entry sectors:   881
[32960.099328]   current entry error:     (No error)
[32960.099789]   current entry:           closed
[32960.100203]   unwritten entries:
[32960.100504]   last buf closed
[32960.100786]   space:
[32960.101085]     discarded              881:903025
[32960.101485]     clean ondisk           881:2847598
[32960.102077]     clean                  881:2847598
[32960.102479]     total                  881:2847598
[32960.102875]   dev 0:
[32960.103074]   durability 1:
[32960.103317]     nr                     8192
[32960.103749]     bucket size            881
[32960.104092]     available              1025:288
[32960.104471]     discard_idx            7025
[32960.104817]     dirty_ondisk           3136 (seq 4858564)
[32960.105268]     dirty_idx              3143 (seq 4858571)
[32960.105778]     cur_idx                5999 (seq 4861841)
[32960.106233]   replicas want 1 need 1
[33089.878501] ------------[ cut here ]------------
[33089.878505] btree trans held srcu lock (delaying memory reclaim) for 4140 seconds
[33089.878519] WARNING: CPU: 2 PID: 445 at src/fs/bcachefs/btree_iter.c:3331 bch2_trans_srcu_unlock+0x11b/0x130 [bcachefs]
[33089.878582] Modules linked in: bcachefs(O) chacha_x86_64 libchacha libpoly1305 poly1305_x86_64 lz4hc_compress lz4_compress xor raid6_pq qrtr snd_seq_dummy snd_hrtimer snd_seq snd_seq_device af_packet rfkill nls_iso8859_1 nls_cp437 vfat fat snd_hda_codec_generic snd_hda_intel snd_intel_dspcfg intel_rapl_msr snd_intel_sdw_acpi iTCO_wdt intel_pmc_bxt watchdog xt_conntrack snd_hda_codec nf_conntrack snd_hda_core nf_defrag_ipv6 nf_defrag_ipv4 snd_hwdep edac_core snd_pcm intel_rapl_common polyval_clmulni ghash_clmulni_intel sha512_ssse3 sha1_ssse3 i2c_i801 psmouse aesni_intel i2c_smbus i2c_mux snd_timer ip6t_rpfilter ipt_rpfilter snd soundcore joydev lpc_ich mousedev rtc_cmos evdev xt_pkttype intel_agp tiny_power_button xt_LOG nf_log_syslog input_leds intel_gtt button led_class nft_compat mac_hid serio_raw nf_tables sch_fq_codel loop kvm_amd ccp kvm irqbypass fuse efi_pstore configfs nfnetlink efivarfs dmi_sysfs qemu_fw_cfg autofs4 ext4 crc16 mbcache jbd2 hid_generic usbhid hid sr_mod cdrom virtio_net net_failover failover
[33089.878630]  virtio_blk virtio_scsi ahci libahci libata atkbd libps2 vivaldi_fmap xhci_pci xhci_hcd scsi_mod scsi_common virtio_pci virtio_pci_legacy_dev virtio_pci_modern_dev i8042 serio virtio_rng rng_core virtio_gpu virtio_dma_buf virtio_console virtio_balloon virtio virtio_ring dm_mod dax
[33089.878645] CPU: 2 UID: 0 PID: 445 Comm: kworker/2:4 Tainted: G        W  O        6.16.9 #1-NixOS PREEMPT(voluntary)
[33089.878648] Tainted: [W]=WARN, [O]=OOT_MODULE
[33089.878649] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS edk2-stable202408-prebuilt.qemu.org 08/13/2024
[33089.878651] Workqueue: bcachefs_write_ref bch2_do_discards_work [bcachefs]
[33089.878699] RIP: 0010:bch2_trans_srcu_unlock+0x11b/0x130 [bcachefs]
[33089.878745] Code: bc d6 48 c7 c7 d8 0a 38 c1 48 b9 cf f7 53 e3 a5 9b c4 20 48 29 d0 48 c1 e8 03 48 f7 e1 48 89 d6 48 c1 ee 04 e8 56 2f ec d4 90 <0f> 0b 90 90 eb 9f 90 0f 0b 90 eb ab 66 0f 1f 84 00 00 00 00 00 90
[33089.878746] RSP: 0018:ffffcebc803a3c50 EFLAGS: 00010286
[33089.878748] RAX: 0000000000000000 RBX: ffff8d0d74c74000 RCX: 0000000000000027
[33089.878749] RDX: ffff8d0ef5d1e408 RSI: 0000000000000001 RDI: ffff8d0ef5d1e400
[33089.878750] RBP: ffff8d0d85e40000 R08: 0000000000000000 R09: ffffcebc803a3ae0
[33089.878751] R10: ffffffff98110a28 R11: 0000000000000003 R12: 0000000000008000
[33089.878752] R13: ffff8d0d05f7cc00 R14: ffff8d0d74c74000 R15: 0000000000000000
[33089.878754] FS:  0000000000000000(0000) GS:ffff8d0f5d24f000(0000) knlGS:0000000000000000
[33089.878756] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[33089.878757] CR2: 00007fbc68220000 CR3: 0000000103ebe000 CR4: 0000000000350ef0
[33089.878759] Call Trace:
[33089.878762]  <TASK>
[33089.878765]  ? bch2_trans_begin+0xc3/0x8e0 [bcachefs]
[33089.878809]  bch2_trans_begin+0x50a/0x8e0 [bcachefs]
[33089.878853]  __bch2_dev_do_discards+0xfc/0x310 [bcachefs]
[33089.878905]  bch2_do_discards_work+0x1d/0x60 [bcachefs]
[33089.878965]  process_one_work+0x18d/0x340
[33089.878970]  worker_thread+0x225/0x360
[33089.878972]  ? __pfx_worker_thread+0x10/0x10
[33089.878974]  kthread+0xfb/0x250
[33089.878976]  ? __pfx_kthread+0x10/0x10
[33089.878978]  ? _raw_spin_unlock+0xe/0x30
[33089.878980]  ? finish_task_switch.isra.0+0x99/0x2e0
[33089.878983]  ? __pfx_kthread+0x10/0x10
[33089.878984]  ? __pfx_kthread+0x10/0x10
[33089.878986]  ret_from_fork+0x199/0x1d0
[33089.878988]  ? __pfx_kthread+0x10/0x10
[33089.878990]  ret_from_fork_asm+0x1a/0x30
[33089.878993]  </TASK>
[33089.878994] ---[ end trace 0000000000000000 ]---
[33120.242691] Allocator stuck? Waited for 30 seconds
[33120.242693] Allocator debug:
[33120.242694]   capacity849891820
[33120.242694]   used                 833188184
[33120.242695]   reserved             73903636
[33120.242695]   hidden               7221557
[33120.242696]   btree                20343808
[33120.242696]   data                 811177914
[33120.242696]   cached               0
[33120.242697]   reserved             519032
[33120.242697]   online_reserved      1121792
[33120.242698]
[33120.242698]   freelist_wait        waiting
[33120.242698]   open buckets allocated2
[33120.242699]   open buckets total   1024
[33120.242699]   open_buckets_wait    empty
[33120.242700]   open_buckets_btree   0
[33120.242700]   open_buckets_user    1
[33120.242700]   btree reserve cache  0

[33120.242701] Dev 0:
[33120.242701]                      buckets         sectors      fragmented
[33120.242702]   free                    29               0               0
[33120.242702]   sb                       5            4104             301
[33120.242703]   journal               8192         7217152               0
[33120.242703]   btree                39734        20343808        14661846
[33120.242704]   user                926297       811177914         4889743
[33120.242704]   cached                   0               0               0
[33120.242705]   parity                   0               0               0
[33120.242705]   stripe                   0               0               0
[33120.242706]   need_gc_gens             0               0               0
[33120.242706]   need_discard         74319               0               0
[33120.242706]   unstriped                0               0               0
[33120.242707]   capacity           1048576
[33120.242707]
[33120.242718]   reserves:
[33120.242718]   stripe               32824
[33120.242719]   normal               16440
[33120.242719]   copygc                  56
[33120.242719]   btree                   28
[33120.242720]   btree_copygc             0
[33120.242720]   reclaim                  0
[33120.242720]   interior_updates         0
[33120.242721]
[33120.242721]   open buckets             1
[33120.242721]   buckets to invalidate    0

[33120.242722] Copygc debug:
[33120.242723]   running: 1
[33120.242723]   copygc_wait:0
[33120.242723]   copygc_wait_at:0
[33120.242724]   Currently waiting for:0 B
[33120.242724]   Currently waiting since:25.1 TiB
[33120.242725]   Currently calculated wait:
[33120.242725]     vdb2:  0 B

[33120.242726] Journal debug:
[33120.242726]   flags:                   replay_done,running,may_skip_flush
[33120.242727]   dirty journal entries:   3250/32768
[33120.242727]   seq:                     4861844
[33120.242727]   seq_ondisk:              4861844
[33120.242728]   last_seq:                4858595
[33120.242728]   last_seq_ondisk:         4858592
[33120.242752]   flushed_seq_ondisk:      4861844
[33120.242756]   watermark:               stripe
[33120.242757]   each entry reserved:     321
[33120.242757]   nr flush writes:         27475
[33120.242758]   nr noflush writes:       14761
[33120.242758]   average write size:      272 KiB
[33120.242759]   free buf:                524288
[33120.242760]   nr direct reclaim:       0
[33120.242760]   nr background reclaim:   1036968
[33120.242760]   reclaim kicked:          0
[33120.242761]   reclaim runs in:         60 ms
[33120.242761]   blocked:                 0
[33120.242762]   current entry sectors:   881
[33120.242762]   current entry error:     (No error)
[33120.242763]   current entry:           closed
[33120.242763]   unwritten entries:
[33120.242764]   last buf closed
[33120.242764]   space:
[33120.242765]     discarded              881:903025
[33120.242765]     clean ondisk           881:2865915
[33120.242766]     clean                  881:2865915
[33120.242766]     total                  881:2865915
[33120.242766]   dev 0:
[33120.242767]   durability 1:
[33120.242767]     nr                     8192
[33120.242767]     bucket size            881
[33120.242768]     available              1025:276
[33120.242768]     discard_idx            7025
[33120.242769]     dirty_ondisk           3162 (seq 4858592)
[33120.242769]     dirty_idx              3165 (seq 4858595)
[33120.242770]     cur_idx                5999 (seq 4861844)
[33120.242770]   replicas want 1 need 1
[33120.242797] Allocator stuck? Waited for 30 seconds
[33120.243008] Allocator stuck? Waited for 30 seconds
[33120.243009] Allocator debug:
[33120.243010]   capacity849891820
[33120.243011]   used                 833188184
[33120.243011]   reserved             73903636
[33120.243012]   hidden               7221557
[33120.243012]   btree                20343808
[33120.243013]   data                 811177914
[33120.243013]   cached               0
[33120.243014]   reserved             519032
[33120.243014]   online_reserved      1121792
[33120.243015]
[33120.243015]   freelist_wait        waiting
[33120.243016]   open buckets allocated2
[33120.243016]   open buckets total   1024
[33120.243017]   open_buckets_wait    empty
[33120.243017]   open_buckets_btree   0
[33120.243017]   open_buckets_user    1
[33120.243018]   btree reserve cache  0

[33120.243019] Dev 0:
[33120.243019]                      buckets         sectors      fragmented
[33120.243020]   free                    29               0               0
[33120.243020]   sb                       5            4104             301
[33120.243021]   journal               8192         7217152               0
[33120.243021]   btree                39734        20343808        14661846
[33120.243022]   user                926297       811177914         4889743
[33120.243023]   cached                   0               0               0
[33120.243023]   parity                   0               0               0
[33120.243024]   stripe                   0               0               0
[33120.243024]   need_gc_gens             0               0               0
[33120.243025]   need_discard         74319               0               0
[33120.243025]   unstriped                0               0               0
[33120.243026]   capacity           1048576
[33120.243026]
[33120.243027]   reserves:
[33120.243027]   stripe               32824
[33120.243027]   normal               16440
[33120.243028]   copygc                  56
[33120.243028]   btree                   28
[33120.243029]   btree_copygc             0
[33120.243029]   reclaim                  0
[33120.243030]   interior_updates         0
[33120.243030]
[33120.243030]   open buckets             1
[33120.243031]   buckets to invalidate    0

[33120.243031] Copygc debug:
[33120.243032]   running: 1
[33120.243032]   copygc_wait:0
[33120.243032]   copygc_wait_at:0
[33120.243033]   Currently waiting for:0 B
[33120.243033]   Currently waiting since:25.1 TiB
[33120.243034]   Currently calculated wait:
[33120.243034]     vdb2:  0 B
[33120.243035]   [<0>] bch2_copygc_wait_to_text+0x1ad/0x2c0 [bcachefs]
[33120.243035]   [<0>] bch2_print_allocator_stuck+0x11c/0x240 [bcachefs]
[33120.243036]   [<0>] __bch2_wait_on_allocator+0x9f/0xc0 [bcachefs]
[33120.243036]   [<0>] bch2_btree_update_start+0x74c/0xa40 [bcachefs]
[33120.243037]   [<0>] bch2_btree_node_rewrite+0x6f/0x4a0 [bcachefs]
[33120.243037]   [<0>] bch2_btree_node_rewrite_pos+0xa2/0xe0 [bcachefs]
[33120.243038]   [<0>] __bch2_move_data_phys+0x899/0xce0 [bcachefs]
[33120.243038]   [<0>] bch2_evacuate_bucket+0xcc/0x130 [bcachefs]
[33120.243038]   [<0>] bch2_copygc+0x113/0x350 [bcachefs]
[33120.243039]   [<0>] bch2_copygc_thread+0x309/0x560 [bcachefs]
[33120.243039]   [<0>] kthread+0xfb/0x250
[33120.243040]   [<0>] ret_from_fork+0x199/0x1d0
[33120.243040]   [<0>] ret_from_fork_asm+0x1a/0x30

[33120.243041] Journal debug:
[33120.243041]   flags:                   replay_done,running,may_skip_flush
[33120.243042]   dirty journal entries:   3250/32768
[33120.243042]   seq:                     4861844
[33120.243043]   seq_ondisk:              4861844
[33120.243043]   last_seq:                4858595
[33120.243044]   last_seq_ondisk:         4858592
[33120.243044]   flushed_seq_ondisk:      4861844
[33120.243044]   watermark:               stripe
[33120.243045]   each entry reserved:     321
[33120.243045]   nr flush writes:         27475
[33120.243046]   nr noflush writes:       14761
[33120.243046]   average write size:      272 KiB
[33120.243047]   free buf:                524288
[33120.243047]   nr direct reclaim:       0
[33120.243047]   nr background reclaim:   1036968
[33120.243048]   reclaim kicked:          0
[33120.243048]   reclaim runs in:         60 ms
[33120.243049]   blocked:                 0
[33120.243049]   current entry sectors:   881
[33120.243049]   current entry error:     (No error)
[33120.243050]   current entry:           closed
[33120.243050]   unwritten entries:
[33120.243051]   last buf closed
[33120.243051]   space:
[33120.243051]     discarded              881:903025
[33120.243052]     clean ondisk           881:2865915
[33120.243052]     clean                  881:2865915
[33120.243053]     total                  881:2865915
[33120.243053]   dev 0:
[33120.243054]   durability 1:
[33120.243054]     nr                     8192
[33120.243054]     bucket size            881
[33120.243055]     available              1025:276
[33120.243055]     discard_idx            7025
[33120.243056]     dirty_ondisk           3162 (seq 4858592)
[33120.243056]     dirty_idx              3165 (seq 4858595)
[33120.243057]     cur_idx                5999 (seq 4861844)
[33120.243057]   replicas want 1 need 1
[33120.321558] Allocator debug:
[33120.321841]   capacity849891820
[33120.322134]   used                 833188184
[33120.322540]   reserved             73903636
[33120.323020]   hidden               7221557
[33120.323401]   btree                20343808
[33120.323811]   data                 811177914
[33120.324214]   cached               0
[33120.324558]   reserved             519032
[33120.324980]   online_reserved      1121792
[33120.325363]
[33120.325539]   freelist_wait        waiting
[33120.325929]   open buckets allocated2
[33120.326279]   open buckets total   1024
[33120.326650]   open_buckets_wait    empty
[33120.327073]   open_buckets_btree   0
[33120.327371]   open_buckets_user    1
[33120.327677]   btree reserve cache  0

[33120.328123] Dev 0:
[33120.328301]                      buckets         sectors      fragmented
[33120.328859]   free                    29               0               0
[33120.329406]   sb                       5            4104             301
[33120.329960]   journal               8192         7217152               0
[33120.330515]   btree                39734        20343808        14661846
[33120.331112]   user                926297       811177914         4889743
[33120.331667]   cached                   0               0               0
[33120.332226]   parity                   0               0               0
[33120.332795]   stripe                   0               0               0
[33120.333342]   need_gc_gens             0               0               0
[33120.333900]   need_discard         74319               0               0
[33120.334458]   unstriped                0               0               0
[33120.335193]   capacity           1048576
[33120.335570]
[33120.335750]   reserves:
[33120.335985]   stripe               32824
[33120.336359]   normal               16440
[33120.336743]   copygc                  56
[33120.337110]   btree                   28
[33120.337485]   btree_copygc             0
[33120.337858]   reclaim                  0
[33120.338229]   interior_updates         0
[33120.338609]
[33120.338840]   open buckets             1
[33120.339212]   buckets to invalidate    0

[33120.339749] Copygc debug:
[33120.339999]   running: 1
[33120.340242]   copygc_wait:0
[33120.340516]   copygc_wait_at:0
[33120.340815]   Currently waiting for:0 B
[33120.341173]   Currently waiting since:25.1 TiB
[33120.341596]   Currently calculated wait:
[33120.341969]     vdb2:  0 B
[33120.342228]   [<0>] __bch2_closure_sync_timeout+0x3c/0x5d0 [bcachefs]
[33120.342839]   [<0>] __bch2_wait_on_allocator+0x85/0xc0 [bcachefs]
[33120.343463]   [<0>] bch2_btree_update_start+0x74c/0xa40 [bcachefs]
[33120.344046]   [<0>] bch2_btree_node_rewrite+0x6f/0x4a0 [bcachefs]
[33120.344617]   [<0>] bch2_btree_node_rewrite_pos+0xa2/0xe0 [bcachefs]
[33120.345208]   [<0>] __bch2_move_data_phys+0x899/0xce0 [bcachefs]
[33120.345778]   [<0>] bch2_evacuate_bucket+0xcc/0x130 [bcachefs]
[33120.346320]   [<0>] bch2_copygc+0x113/0x350 [bcachefs]
[33120.346818]   [<0>] bch2_copygc_thread+0x309/0x560 [bcachefs]
[33120.347389]   [<0>] kthread+0xfb/0x250
[33120.347723]   [<0>] ret_from_fork+0x199/0x1d0
[33120.348088]   [<0>] ret_from_fork_asm+0x1a/0x30

[33120.348612] Journal debug:
[33120.348848]   flags:                   replay_done,running,may_skip_flush
[33120.349400]   dirty journal entries:   3250/32768
[33120.349797]   seq:                     4861844
[33120.350166]   seq_ondisk:              4861844
[33120.350544]   last_seq:                4858595
[33120.350959]   last_seq_ondisk:         4858592
[33120.351333]   flushed_seq_ondisk:      4861844
[33120.351715]   watermark:               stripe
[33120.352079]   each entry reserved:     321
[33120.352420]   nr flush writes:         27475
[33120.352786]   nr noflush writes:       14761
[33120.353142]   average write size:      272 KiB
[33120.353515]   free buf:                524288
[33120.353881]   nr direct reclaim:       0
[33120.354213]   nr background reclaim:   1036968
[33120.354591]   reclaim kicked:          0
[33120.355003]   reclaim runs in:         60 ms
[33120.355363]   blocked:                 0
[33120.355699]   current entry sectors:   881
[33120.356045]   current entry error:     (No error)
[33120.356437]   current entry:           closed
[33120.356811]   unwritten entries:
[33120.357084]   last buf closed
[33120.357336]   space:
[33120.357532]     discarded              881:903025
[33120.357925]     clean ondisk           881:2865915
[33120.358324]     clean                  881:2865915
[33120.358732]     total                  881:2865915
[33120.359189]   dev 0:
[33120.359381]   durability 1:
[33120.359625]     nr                     8192
[33120.359981]     bucket size            881
[33120.360321]     available              1025:276
[33120.360700]     discard_idx            7025
[33120.361052]     dirty_ondisk           3162 (seq 4858592)
[33120.361504]     dirty_idx              3165 (seq 4858595)
[33120.361953]     cur_idx                5999 (seq 4861844)
[33120.362393]   replicas want 1 need 1
[33427.437362] Allocator stuck? Waited for 30 seconds
[33427.437364] Allocator debug:
[33427.437365]   capacity849891820
[33427.437366]   used                 833188184
[33427.437366]   reserved             73903636
[33427.437366]   hidden               7221557
[33427.437367]   btree                20343808
[33427.437367]   data                 811177914
[33427.437368]   cached               0
[33427.437368]   reserved             519032
[33427.437368]   online_reserved      1121792
[33427.437369]
[33427.437369]   freelist_wait        waiting
[33427.437369]   open buckets allocated2
[33427.437370]   open buckets total   1024
[33427.437370]   open_buckets_wait    empty
[33427.437370]   open_buckets_btree   0
[33427.437371]   open_buckets_user    1
[33427.437371]   btree reserve cache  0

[33427.437372] Dev 0:
[33427.437372]                      buckets         sectors      fragmented
[33427.437373]   free                    29               0               0
[33427.437373]   sb                       5            4104             301
[33427.437374]   journal               8192         7217152               0
[33427.437374]   btree                39734        20343808        14661846
[33427.437374]   user                926297       811177914         4889743
[33427.437375]   cached                   0               0               0
[33427.437375]   parity                   0               0               0
[33427.437376]   stripe                   0               0               0
[33427.437376]   need_gc_gens             0               0               0
[33427.437377]   need_discard         74319               0               0
[33427.437377]   unstriped                0               0               0
[33427.437377]   capacity           1048576
[33427.437377] Allocator stuck? Waited for 30 seconds
[33427.437378]
[33427.437378]   reserves:
[33427.437379]   stripe               32824
[33427.437379]   normal               16440
[33427.437379] Allocator debug:
[33427.437380]   copygc                  56
[33427.437380]   btree                   28
[33427.437380]   btree_copygc             0
[33427.437381]   capacity849891820
[33427.437381]   reclaim                  0
[33427.437382]   interior_updates         0
[33427.437382]   used                 833188184
[33427.437382]
[33427.437383]   open buckets             1
[33427.437383]   reserved             73903636
[33427.437383]   buckets to invalidate    0

[33427.437384]   hidden               7221557
[33427.437384] Copygc debug:
[33427.437385]   running: 1
[33427.437385]   btree                20343808
[33427.437385]   copygc_wait:0
[33427.437386]   copygc_wait_at:0
[33427.437386]   data                 811177914
[33427.437386]   Currently waiting for:0 B
[33427.437387]   Currently waiting since:25.1 TiB
[33427.437387]   cached               0
[33427.437387]   Currently calculated wait:
[33427.437388]     vdb2:  0 B
[33427.437388]   reserved             519032

[33427.437388]   online_reserved      1121792
[33427.437389] Journal debug:
[33427.437389]   flags:                   replay_done,running,may_skip_flush
[33427.437389]
[33427.437390]   dirty journal entries:   3217/32768
[33427.437390]   seq:                     4861846
[33427.437390]   freelist_wait        waiting
[33427.437391]   seq_ondisk:              4861846
[33427.437391]   open buckets allocated2
[33427.437391]   last_seq:                4858630
[33427.437392]   last_seq_ondisk:         4858626
[33427.437392]   open buckets total   1024
[33427.437392]   flushed_seq_ondisk:      4861846
[33427.437393]   watermark:               stripe
[33427.437393]   open_buckets_wait    empty
[33427.437393]   each entry reserved:     321
[33427.437393]   open_buckets_btree   0
[33427.437393]   nr flush writes:         27477
[33427.437394]   nr noflush writes:       14761
[33427.437394]   open_buckets_user    1
[33427.437394]   average write size:      272 KiB
[33427.437395]   free buf:                524288
[33427.437395]   btree reserve cache  0
[33427.437395]   nr direct reclaim:       0

[33427.437396]   nr background reclaim:   1039922
[33427.437396]   reclaim kicked:          0
[33427.437396] Dev 0:
[33427.437397]   reclaim runs in:         76 ms
[33427.437397]   blocked:                 0
[33427.437397]                      buckets         sectors      fragmented
[33427.437398]   current entry sectors:   881
[33427.437398]   current entry error:     (No error)
[33427.437398]   free                    29               0               0
[33427.437399]   current entry:           closed
[33427.437399]   unwritten entries:
[33427.437399]   sb                       5            4104             301
[33427.437400]   last buf closed
[33427.437400]   space:
[33427.437400]   journal               8192         7217152               0
[33427.437400]     discarded              881:903025
[33427.437401]     clean ondisk           881:2889312
[33427.437401]   btree                39734        20343808        14661846
[33427.437402]     clean                  881:2889312
[33427.437402]   user                926297       811177914         4889743
[33427.437402]     total                  881:2889312
[33427.437403]   dev 0:
[33427.437403]   durability 1:
[33427.437403]   cached                   0               0               0
[33427.437403]     nr                     8192
[33427.437404]     bucket size            881
[33427.437404]   parity                   0               0               0
[33427.437404]     available              1025:267
[33427.437405]     discard_idx            7025
[33427.437405]   stripe                   0               0               0
[33427.437405]     dirty_ondisk           3195 (seq 4858626)
[33427.437405]   need_gc_gens             0               0               0
[33427.437406]     dirty_idx              3198 (seq 4858630)
[33427.437406]     cur_idx                5999 (seq 4861846)
[33427.437407]   replicas want 1 need 1
[33427.437406]   need_discard         74319               0               0
[33427.437407]   unstriped                0               0               0
[33427.437408]   capacity           1048576
[33427.437702] Allocator stuck? Waited for 30 seconds
[33427.437704] Allocator debug:
[33427.437705]   capacity849891820
[33427.437705]   used                 833188184
[33427.437706]   reserved             73903636
[33427.437706]   hidden               7221557
[33427.437707]   btree                20343808
[33427.437707]   data                 811177914
[33427.437708]   cached               0
[33427.437708]   reserved             519032
[33427.437709]   online_reserved      1121792
[33427.437709]
[33427.437709]   freelist_wait        waiting
[33427.437710]   open buckets allocated2
[33427.437710]   open buckets total   1024
[33427.437711]   open_buckets_wait    empty
[33427.437711]   open_buckets_btree   0
[33427.437712]   open_buckets_user    1
[33427.437712]   btree reserve cache  0

[33427.437713] Dev 0:
[33427.437714]                      buckets         sectors      fragmented
[33427.437714]   free                    29               0               0
[33427.437715]   sb                       5            4104             301
[33427.437715]   journal               8192         7217152               0
[33427.437716]   btree                39734        20343808        14661846
[33427.437717]   user                926297       811177914         4889743
[33427.437717]   cached                   0               0               0
[33427.437718]   parity                   0               0               0
[33427.437718]   stripe                   0               0               0
[33427.437719]   need_gc_gens             0               0               0
[33427.437719]   need_discard         74319               0               0
[33427.437720]   unstriped                0               0               0
[33427.437721]   capacity           1048576
[33427.437721]
[33427.437721]   reserves:
[33427.437722]   stripe               32824
[33427.437722]   normal               16440
[33427.437723]   copygc                  56
[33427.437723]   btree                   28
[33427.437724]   btree_copygc             0
[33427.437724]   reclaim                  0
[33427.437725]   interior_updates         0
[33427.437725]
[33427.437725]   open buckets             1
[33427.437726]   buckets to invalidate    0

[33427.437727] Copygc debug:
[33427.437727]   running: 1
[33427.437728]   copygc_wait:0
[33427.437728]   copygc_wait_at:0
[33427.437728]   Currently waiting for:0 B
[33427.437729]   Currently waiting since:25.1 TiB
[33427.437730]   Currently calculated wait:
[33427.437730]     vdb2:  0 B
[33427.437730]   [<0>] bch2_copygc_wait_to_text+0x1ad/0x2c0 [bcachefs]
[33427.437731]   [<0>] bch2_print_allocator_stuck+0x11c/0x240 [bcachefs]
[33427.437732]   [<0>] __bch2_wait_on_allocator+0x9f/0xc0 [bcachefs]
[33427.437732]   [<0>] bch2_btree_update_start+0x74c/0xa40 [bcachefs]
[33427.437733]   [<0>] bch2_btree_node_rewrite+0x6f/0x4a0 [bcachefs]
[33427.437733]   [<0>] bch2_btree_node_rewrite_pos+0xa2/0xe0 [bcachefs]
[33427.437734]   [<0>] __bch2_move_data_phys+0x899/0xce0 [bcachefs]
[33427.437734]   [<0>] bch2_evacuate_bucket+0xcc/0x130 [bcachefs]
[33427.437735]   [<0>] bch2_copygc+0x113/0x350 [bcachefs]
[33427.437736]   [<0>] bch2_copygc_thread+0x309/0x560 [bcachefs]
[33427.437736]   [<0>] kthread+0xfb/0x250
[33427.437737]   [<0>] ret_from_fork+0x199/0x1d0
[33427.437737]   [<0>] ret_from_fork_asm+0x1a/0x30

[33427.437738] Journal debug:
[33427.437738]   flags:                   replay_done,running,may_skip_flush
[33427.437739]   dirty journal entries:   3217/32768
[33427.437739]   seq:                     4861846
[33427.437740]   seq_ondisk:              4861846
[33427.437740]   last_seq:                4858630
[33427.437741]   last_seq_ondisk:         4858626
[33427.437741]   flushed_seq_ondisk:      4861846
[33427.437742]   watermark:               stripe
[33427.437742]   each entry reserved:     321
[33427.437743]   nr flush writes:         27477
[33427.437743]   nr noflush writes:       14761
[33427.437744]   average write size:      272 KiB
[33427.437744]   free buf:                524288
[33427.437745]   nr direct reclaim:       0
[33427.437745]   nr background reclaim:   1039922
[33427.437746]   reclaim kicked:          0
[33427.437746]   reclaim runs in:         76 ms
[33427.437747]   blocked:                 0
[33427.437747]   current entry sectors:   881
[33427.437748]   current entry error:     (No error)
[33427.437748]   current entry:           closed
[33427.437749]   unwritten entries:
[33427.437749]   last buf closed
[33427.437750]   space:
[33427.437750]     discarded              881:903025
[33427.437751]     clean ondisk           881:2889312
[33427.437751]     clean                  881:2889312
[33427.437752]     total                  881:2889312
[33427.437752]   dev 0:
[33427.437753]   durability 1:
[33427.437753]     nr                     8192
[33427.437753]     bucket size            881
[33427.437754]     available              1025:267
[33427.437754]     discard_idx            7025
[33427.437755]     dirty_ondisk           3195 (seq 4858626)
[33427.437755]     dirty_idx              3198 (seq 4858630)
[33427.437756]     cur_idx                5999 (seq 4861846)
[33427.437757]   replicas want 1 need 1
[33427.532062]
[33427.532207]   reserves:
[33427.532534]   stripe               32824
[33427.532942]   normal               16440
[33427.533368]   copygc                  56
[33427.533774]   btree                   28
[33427.534180]   btree_copygc             0
[33427.534563]   reclaim                  0
[33427.534894]   interior_updates         0
[33427.535211]
[33427.535389]   open buckets             1
[33427.535709]   buckets to invalidate    0

[33427.536159] Copygc debug:
[33427.536398]   running: 1
[33427.536611]   copygc_wait:0
[33427.536842]   copygc_wait_at:0
[33427.537118]   Currently waiting for:0 B
[33427.537495]   Currently waiting since:25.1 TiB
[33427.537916]   Currently calculated wait:
[33427.538289]     vdb2:  0 B

[33427.538743] Journal debug:
[33427.538952]   flags:                   replay_done,running,may_skip_flush
[33427.539531]   dirty journal entries:   3217/32768
[33427.539985]   seq:                     4861846
[33427.540449]   seq_ondisk:              4861846
[33427.540888]   last_seq:                4858630
[33427.541343]   last_seq_ondisk:         4858626
[33427.541781]   flushed_seq_ondisk:      4861846
[33427.542219]   watermark:               stripe
[33427.542666]   each entry reserved:     321
[33427.543072]   nr flush writes:         27477
[33427.543514]   nr noflush writes:       14761
[33427.543940]   average write size:      272 KiB
[33427.544391]   free buf:                524288
[33427.544825]   nr direct reclaim:       0
[33427.545212]   nr background reclaim:   1039922
[33427.545967]   reclaim kicked:          0
[33427.546561]   reclaim runs in:         76 ms
[33427.546946]   blocked:                 0
[33427.547313]   current entry sectors:   881
[33427.547652]   current entry error:     (No error)
[33427.548038]   current entry:           closed
[33427.548415]   unwritten entries:
[33427.548687]   last buf closed
[33427.548937]   space:
[33427.549126]     discarded              881:903025
[33427.549531]     clean ondisk           881:2889312
[33427.549926]     clean                  881:2889312
[33427.550453]     total                  881:2889312
[33427.550948]   dev 0:
[33427.551181]   durability 1:
[33427.551446]     nr                     8192
[33427.551789]     bucket size            881
[33427.552125]     available              1025:267
[33427.552612]     discard_idx            7025
[33427.553042]     dirty_ondisk           3195 (seq 4858626)
[33427.553540]     dirty_idx              3198 (seq 4858630)
[33427.553980]     cur_idx                5999 (seq 4861846)
[33427.554434]   replicas want 1 need 1
[33696.744864] Allocator stuck? Waited for 30 seconds
[33696.744866] Allocator debug:
[33696.744867]   capacity849891820
[33696.744867]   used                 833188184
[33696.744868]   reserved             73903636
[33696.744868]   hidden               7221557
[33696.744869]   btree                20343808
[33696.744869]   data                 811177914
[33696.744870]   cached               0
[33696.744870]   reserved             519032
[33696.744870]   online_reserved      1121792
[33696.744871]
[33696.744871]   freelist_wait        waiting
[33696.744872]   open buckets allocated2
[33696.744872]   open buckets total   1024
[33696.744872]   open_buckets_wait    empty
[33696.744873]   open_buckets_btree   0
[33696.744873]   open_buckets_user    1
[33696.744873]   btree reserve cache  0

[33696.744874] Allocator stuck? Waited for 30 seconds
[33696.744874] Dev 0:
[33696.744875]                      buckets         sectors      fragmented
[33696.744875]   free                    29               0               0
[33696.744875] Allocator debug:
[33696.744876]   sb                       5            4104             301
[33696.744876]   capacity849891820
[33696.744877]   journal               8192         7217152               0
[33696.744877]   used                 833188184
[33696.744877]   btree                39734        20343808        14661846
[33696.744877]   reserved             73903636
[33696.744878]   user                926297       811177914         4889743
[33696.744878]   hidden               7221557
[33696.744879]   cached                   0               0               0
[33696.744879]   btree                20343808
[33696.744879]   parity                   0               0               0
[33696.744879]   data                 811177914
[33696.744880]   stripe                   0               0               0
[33696.744880]   cached               0
[33696.744880]   need_gc_gens             0               0               0
[33696.744880]   reserved             519032
[33696.744881]   need_discard         74319               0               0
[33696.744881]   online_reserved      1121792
[33696.744881]   unstriped                0               0               0
[33696.744881]
[33696.744882]   capacity           1048576
[33696.744882]   freelist_wait        waiting
[33696.744882]
[33696.744883]   open buckets allocated2
[33696.744883]   reserves:
[33696.744883]   open buckets total   1024
[33696.744883]   stripe               32824
[33696.744884]   open_buckets_wait    empty
[33696.744884]   normal               16440
[33696.744884]   open_buckets_btree   0
[33696.744884]   copygc                  56
[33696.744884]   open_buckets_user    1
[33696.744885]   btree                   28
[33696.744885]   btree reserve cache  0
[33696.744885]   btree_copygc             0

[33696.744886]   reclaim                  0
[33696.744886] Dev 0:
[33696.744886]   interior_updates         0
[33696.744886]                      buckets         sectors      fragmented
[33696.744887]
[33696.744887]   free                    29               0               0
[33696.744887]   open buckets             1
[33696.744888]   sb                       5            4104             301
[33696.744888]   buckets to invalidate    0
[33696.744888]   journal               8192         7217152               0

[33696.744889]   btree                39734        20343808        14661846
[33696.744889] Copygc debug:
[33696.744890]   user                926297       811177914         4889743
[33696.744890]   running: 1
[33696.744890]   cached                   0               0               0
[33696.744890]   copygc_wait:0
[33696.744891]   parity                   0               0               0
[33696.744891]   copygc_wait_at:0
[33696.744891]   stripe                   0               0               0
[33696.744892]   Currently waiting for:0 B
[33696.744892]   need_gc_gens             0               0               0
[33696.744892]   Currently waiting since:25.1 TiB
[33696.744893]   need_discard         74319               0               0
[33696.744893]   Currently calculated wait:
[33696.744893]   unstriped                0               0               0
[33696.744893]     vdb2:  0 B
[33696.744894]   capacity           1048576

[33696.744894]
[33696.744894] Journal debug:
[33696.744895]   reserves:
[33696.744895]   flags:                   replay_done,running,may_skip_flush
[33696.744895]   stripe               32824
[33696.744896]   dirty journal entries:   3194/32768
[33696.744896]   normal               16440
[33696.744896]   seq:                     4861853
[33696.744896]   copygc                  56
[33696.744897]   seq_ondisk:              4861853
[33696.744897]   btree                   28
[33696.744897]   last_seq:                4858660
[33696.744897]   btree_copygc             0
[33696.744898]   last_seq_ondisk:         4858658
[33696.744898]   reclaim                  0
[33696.744898]   flushed_seq_ondisk:      4861853
[33696.744898]   interior_updates         0
[33696.744899]   watermark:               stripe
[33696.744899]
[33696.744899]   each entry reserved:     321
[33696.744899]   open buckets             1
[33696.744900]   nr flush writes:         27484
[33696.744900]   buckets to invalidate    0
[33696.744900]   nr noflush writes:       14761

[33696.744901] Copygc debug:
[33696.744901]   average write size:      272 KiB
[33696.744901]   running: 1
[33696.744901]   free buf:                524288
[33696.744902]   copygc_wait:0
[33696.744902]   nr direct reclaim:       0
[33696.744902]   copygc_wait_at:0
[33696.744902]   nr background reclaim:   1042511
[33696.744903]   Currently waiting for:0 B
[33696.744903]   reclaim kicked:          0
[33696.744903]   Currently waiting since:25.1 TiB
[33696.744903]   reclaim runs in:         20 ms
[33696.744904]   Currently calculated wait:
[33696.744904]   blocked:                 0
[33696.744904]     vdb2:  0 B
[33696.744905]   current entry sectors:   881

[33696.744905]   current entry error:     (No error)
[33696.744905] Journal debug:
[33696.744906]   current entry:           closed
[33696.744906]   flags:                   replay_done,running,may_skip_flush
[33696.744906]   unwritten entries:
[33696.744907]   dirty journal entries:   3194/32768
[33696.744907]   last buf closed
[33696.744907]   seq:                     4861853
[33696.744907]   space:
[33696.744908]   seq_ondisk:              4861853
[33696.744908]     discarded              881:903025
[33696.744908]   last_seq:                4858660
[33696.744908]     clean ondisk           881:2911140
[33696.744909]   last_seq_ondisk:         4858658
[33696.744909]     clean                  881:2911140
[33696.744909]   flushed_seq_ondisk:      4861853
[33696.744910]     total                  881:2911140
[33696.744910]   watermark:               stripe
[33696.744910]   dev 0:
[33696.744910]   each entry reserved:     321
[33696.744911]   durability 1:
[33696.744911]   nr flush writes:         27484
[33696.744911]     nr                     8192
[33696.744911]   nr noflush writes:       14761
[33696.744912]     bucket size            881
[33696.744912]   average write size:      272 KiB
[33696.744912]     available              1025:214
[33696.744912]   free buf:                524288
[33696.744913]     discard_idx            7025
[33696.744913]   nr direct reclaim:       0
[33696.744913]     dirty_ondisk           3224 (seq 4858658)
[33696.744913]   nr background reclaim:   1042511
[33696.744914]     dirty_idx              3226 (seq 4858660)
[33696.744914]   reclaim kicked:          0
[33696.744914]     cur_idx                5999 (seq 4861853)
[33696.744914]   reclaim runs in:         20 ms
[33696.744915]   replicas want 1 need 1
[33696.744915]   blocked:                 0
[33696.744916]   current entry sectors:   881
[33696.744916]   current entry error:     (No error)
[33696.744917]   current entry:           closed
[33696.745210] Allocator stuck? Waited for 30 seconds
[33696.745211] Allocator debug:
[33696.745212]   capacity849891820
[33696.745212]   used                 833188184
[33696.745213]   reserved             73903636
[33696.745213]   hidden               7221557
[33696.745214]   btree                20343808
[33696.745214]   data                 811177914
[33696.745215]   cached               0
[33696.745215]   reserved             519032
[33696.745216]   online_reserved      1121792
[33696.745216]
[33696.745217]   freelist_wait        waiting
[33696.745217]   open buckets allocated2
[33696.745218]   open buckets total   1024
[33696.745218]   open_buckets_wait    empty
[33696.745219]   open_buckets_btree   0
[33696.745219]   open_buckets_user    1
[33696.745219]   btree reserve cache  0

[33696.745220] Dev 0:
[33696.745221]                      buckets         sectors      fragmented
[33696.745221]   free                    29               0               0
[33696.745222]   sb                       5            4104             301
[33696.745222]   journal               8192         7217152               0
[33696.745223]   btree                39734        20343808        14661846
[33696.745223]   user                926297       811177914         4889743
[33696.745224]   cached                   0               0               0
[33696.745224]   parity                   0               0               0
[33696.745225]   stripe                   0               0               0
[33696.745225]   need_gc_gens             0               0               0
[33696.745226]   need_discard         74319               0               0
[33696.745226]   unstriped                0               0               0
[33696.745227]   capacity           1048576
[33696.745227]
[33696.745228]   reserves:
[33696.745228]   stripe               32824
[33696.745229]   normal               16440
[33696.745229]   copygc                  56
[33696.745230]   btree                   28
[33696.745230]   btree_copygc             0
[33696.745230]   reclaim                  0
[33696.745231]   interior_updates         0
[33696.745231]
[33696.745232]   open buckets             1
[33696.745232]   buckets to invalidate    0

[33696.745233] Copygc debug:
[33696.745233]   running: 1
[33696.745234]   copygc_wait:0
[33696.745234]   copygc_wait_at:0
[33696.745234]   Currently waiting for:0 B
[33696.745235]   Currently waiting since:25.1 TiB
[33696.745235]   Currently calculated wait:
[33696.745236]     vdb2:  0 B
[33696.745236]   [<0>] bch2_copygc_wait_to_text+0x1ad/0x2c0 [bcachefs]
[33696.745237]   [<0>] bch2_print_allocator_stuck+0x11c/0x240 [bcachefs]
[33696.745238]   [<0>] __bch2_wait_on_allocator+0x9f/0xc0 [bcachefs]
[33696.745238]   [<0>] bch2_btree_update_start+0x74c/0xa40 [bcachefs]
[33696.745239]   [<0>] bch2_btree_node_rewrite+0x6f/0x4a0 [bcachefs]
[33696.745239]   [<0>] bch2_btree_node_rewrite_pos+0xa2/0xe0 [bcachefs]
[33696.745240]   [<0>] __bch2_move_data_phys+0x899/0xce0 [bcachefs]
[33696.745240]   [<0>] bch2_evacuate_bucket+0xcc/0x130 [bcachefs]
[33696.745241]   [<0>] bch2_copygc+0x113/0x350 [bcachefs]
[33696.745241]   [<0>] bch2_copygc_thread+0x309/0x560 [bcachefs]
[33696.745242]   [<0>] kthread+0xfb/0x250
[33696.745242]   [<0>] ret_from_fork+0x199/0x1d0
[33696.745243]   [<0>] ret_from_fork_asm+0x1a/0x30

[33696.745244] Journal debug:
[33696.745244]   flags:                   replay_done,running,may_skip_flush
[33696.745245]   dirty journal entries:   3194/32768
[33696.745245]   seq:                     4861853
[33696.745245]   seq_ondisk:              4861853
[33696.745246]   last_seq:                4858660
[33696.745246]   last_seq_ondisk:         4858658
[33696.745247]   flushed_seq_ondisk:      4861853
[33696.745247]   watermark:               stripe
[33696.745248]   each entry reserved:     321
[33696.745248]   nr flush writes:         27484
[33696.745249]   nr noflush writes:       14761
[33696.745249]   average write size:      272 KiB
[33696.745250]   free buf:                524288
[33696.745250]   nr direct reclaim:       0
[33696.745251]   nr background reclaim:   1042511
[33696.745251]   reclaim kicked:          0
[33696.745251]   reclaim runs in:         20 ms
[33696.745252]   blocked:                 0
[33696.745252]   current entry sectors:   881
[33696.745253]   current entry error:     (No error)
[33696.745253]   current entry:           closed
[33696.745254]   unwritten entries:
[33696.745254]   last buf closed
[33696.745255]   space:
[33696.745255]     discarded              881:903025
[33696.745256]     clean ondisk           881:2911140
[33696.745256]     clean                  881:2911140
[33696.745257]     total                  881:2911140
[33696.745257]   dev 0:
[33696.745258]   durability 1:
[33696.745258]     nr                     8192
[33696.745259]     bucket size            881
[33696.745259]     available              1025:214
[33696.745260]     discard_idx            7025
[33696.745260]     dirty_ondisk           3224 (seq 4858658)
[33696.745261]     dirty_idx              3226 (seq 4858660)
[33696.745261]     cur_idx                5999 (seq 4861853)
[33696.745262]   replicas want 1 need 1
[33696.856067]   unwritten entries:
[33696.856393]   last buf closed
[33696.856642]   space:
[33696.856845]     discarded              881:903025
[33696.857387]     clean ondisk           881:2911140
[33696.857836]     clean                  881:2911140
[33696.858286]     total                  881:2911140
[33696.858724]   dev 0:
[33696.858944]   durability 1:
[33696.859267]     nr                     8192
[33696.859650]     bucket size            881
[33696.860033]     available              1025:214
[33696.860411]     discard_idx            7025
[33696.860752]     dirty_ondisk           3224 (seq 4858658)
[33696.861207]     dirty_idx              3226 (seq 4858660)
[33696.861744]     cur_idx                5999 (seq 4861853)
[33696.862251]   replicas want 1 need 1
[33927.141001] Allocator stuck? Waited for 30 seconds
[33927.141004] Allocator debug:
[33927.141005]   capacity849891820
[33927.141005]   used                 833188184
[33927.141006]   reserved             73903636
[33927.141006]   hidden               7221557
[33927.141007]   btree                20343808
[33927.141007]   data                 811177914
[33927.141007]   cached               0
[33927.141008]   reserved             519032
[33927.141008]   online_reserved      1121792
[33927.141009]
[33927.141009]   freelist_wait        waiting
[33927.141009]   open buckets allocated2
[33927.141010]   open buckets total   1024
[33927.141010]   open_buckets_wait    empty
[33927.141011]   open_buckets_btree   0
[33927.141011]   open_buckets_user    1
[33927.141011]   btree reserve cache  0

[33927.141012] Dev 0:
[33927.141012]                      buckets         sectors      fragmented
[33927.141013]   free                    29               0               0
[33927.141013]   sb                       5            4104             301
[33927.141014]   journal               8192         7217152               0
[33927.141014] Allocator stuck? Waited for 30 seconds
[33927.141015]   btree                39734        20343808        14661846
[33927.141015]   user                926297       811177914         4889743
[33927.141015] Allocator debug:
[33927.141016]   cached                   0               0               0
[33927.141016]   parity                   0               0               0
[33927.141016]   capacity849891820
[33927.141017]   stripe                   0               0               0
[33927.141017]   used                 833188184
[33927.141017]   need_gc_gens             0               0               0
[33927.141018]   reserved             73903636
[33927.141018]   need_discard         74319               0               0
[33927.141018]   hidden               7221557
[33927.141019]   unstriped                0               0               0
[33927.141019]   btree                20343808
[33927.141019]   capacity           1048576
[33927.141019]   data                 811177914
[33927.141020]
[33927.141020]   cached               0
[33927.141020]   reserves:
[33927.141020]   reserved             519032
[33927.141021]   stripe               32824
[33927.141021]   online_reserved      1121792
[33927.141021]   normal               16440
[33927.141021]
[33927.141022]   copygc                  56
[33927.141022]   freelist_wait        waiting
[33927.141022]   btree                   28
[33927.141022]   open buckets allocated2
[33927.141023]   btree_copygc             0
[33927.141023]   open buckets total   1024
[33927.141023]   reclaim                  0
[33927.141023]   open_buckets_wait    empty
[33927.141024]   interior_updates         0
[33927.141024]   open_buckets_btree   0
[33927.141024]
[33927.141024]   open_buckets_user    1
[33927.141024]   open buckets             1
[33927.141025]   btree reserve cache  0
[33927.141025]   buckets to invalidate    0


[33927.141026] Dev 0:
[33927.141026] Copygc debug:
[33927.141026]                      buckets         sectors      fragmented
[33927.141026]   running: 1
[33927.141027]   copygc_wait:0
[33927.141027]   free                    29               0               0
[33927.141027]   copygc_wait_at:0
[33927.141028]   sb                       5            4104             301
[33927.141028]   Currently waiting for:0 B
[33927.141028]   journal               8192         7217152               0
[33927.141028]   Currently waiting since:25.1 TiB
[33927.141029]   btree                39734        20343808        14661846
[33927.141029]   Currently calculated wait:
[33927.141029]   user                926297       811177914         4889743
[33927.141029]     vdb2:  0 B
[33927.141030]   cached                   0               0               0

[33927.141030]   parity                   0               0               0
[33927.141031] Journal debug:
[33927.141031]   flags:                   replay_done,running,may_skip_flush
[33927.141031]   stripe                   0               0               0
[33927.141032]   dirty journal entries:   3173/32768
[33927.141032]   need_gc_gens             0               0               0
[33927.141032]   seq:                     4861854
[33927.141032]   need_discard         74319               0               0
[33927.141033]   seq_ondisk:              4861854
[33927.141033]   unstriped                0               0               0
[33927.141033]   last_seq:                4858682
[33927.141033]   capacity           1048576
[33927.141034]   last_seq_ondisk:         4858679
[33927.141034]
[33927.141034]   flushed_seq_ondisk:      4861854
[33927.141034]   reserves:
[33927.141035]   watermark:               stripe
[33927.141035]   stripe               32824
[33927.141035]   each entry reserved:     321
[33927.141036]   normal               16440
[33927.141036]   nr flush writes:         27485
[33927.141036]   copygc                  56
[33927.141037]   nr noflush writes:       14761
[33927.141037]   btree                   28
[33927.141037]   average write size:      272 KiB
[33927.141037]   btree_copygc             0
[33927.141038]   free buf:                524288
[33927.141038]   reclaim                  0
[33927.141038]   nr direct reclaim:       0
[33927.141038]   interior_updates         0
[33927.141039]   nr background reclaim:   1044727
[33927.141039]
[33927.141039]   reclaim kicked:          0
[33927.141039]   open buckets             1
[33927.141040]   reclaim runs in:         84 ms
[33927.141040]   buckets to invalidate    0
[33927.141040]   blocked:                 0

[33927.141041]   current entry sectors:   881
[33927.141041] Copygc debug:
[33927.141041]   current entry error:     (No error)
[33927.141041]   running: 1
[33927.141042]   current entry:           closed
[33927.141042]   copygc_wait:0
[33927.141042]   unwritten entries:
[33927.141042]   copygc_wait_at:0
[33927.141043]   last buf closed
[33927.141043]   Currently waiting for:0 B
[33927.141043]   space:
[33927.141043]   Currently waiting since:25.1 TiB
[33927.141044]     discarded              881:903025
[33927.141044]   Currently calculated wait:
[33927.141044]     clean ondisk           881:2927283
[33927.141044]     vdb2:  0 B
[33927.141045]     clean                  881:2927283

[33927.141045]     total                  881:2927283
[33927.141045] Journal debug:
[33927.141046]   dev 0:
[33927.141046]   flags:                   replay_done,running,may_skip_flush
[33927.141046]   durability 1:
[33927.141047]   dirty journal entries:   3173/32768
[33927.141047]     nr                     8192
[33927.141047]   seq:                     4861854
[33927.141047]     bucket size            881
[33927.141048]   seq_ondisk:              4861854
[33927.141048]     available              1025:210
[33927.141048]   last_seq:                4858682
[33927.141048]     discard_idx            7025
[33927.141049]   last_seq_ondisk:         4858679
[33927.141049]     dirty_ondisk           3244 (seq 4858679)
[33927.141049]   flushed_seq_ondisk:      4861854
[33927.141050]     dirty_idx              3247 (seq 4858682)
[33927.141050]   watermark:               stripe
[33927.141050]     cur_idx                5999 (seq 4861854)
[33927.141050]   each entry reserved:     321
[33927.141051]   replicas want 1 need 1
[33927.141051]   nr flush writes:         27485
[33927.141051]   nr noflush writes:       14761
[33927.141052]   average write size:      272 KiB
[33927.141052]   free buf:                524288
[33927.141363] Allocator stuck? Waited for 30 seconds
[33927.141365] Allocator debug:
[33927.141366]   capacity849891820
[33927.141366]   used                 833188184
[33927.141367]   reserved             73903636
[33927.141367]   hidden               7221557
[33927.141368]   btree                20343808
[33927.141368]   data                 811177914
[33927.141369]   cached               0
[33927.141369]   reserved             519032
[33927.141370]   online_reserved      1121792
[33927.141370]
[33927.141371]   freelist_wait        waiting
[33927.141371]   open buckets allocated2
[33927.141372]   open buckets total   1024
[33927.141372]   open_buckets_wait    empty
[33927.141373]   open_buckets_btree   0
[33927.141373]   open_buckets_user    1
[33927.141374]   btree reserve cache  0

[33927.141375] Dev 0:
[33927.141375]                      buckets         sectors      fragmented
[33927.141376]   free                    29               0               0
[33927.141377]   sb                       5            4104             301
[33927.141377]   journal               8192         7217152               0
[33927.141378]   btree                39734        20343808        14661846
[33927.141378]   user                926297       811177914         4889743
[33927.141379]   cached                   0               0               0
[33927.141379]   parity                   0               0               0
[33927.141380]   stripe                   0               0               0
[33927.141381]   need_gc_gens             0               0               0
[33927.141381]   need_discard         74319               0               0
[33927.141382]   unstriped                0               0               0
[33927.141382]   capacity           1048576
[33927.141383]
[33927.141383]   reserves:
[33927.141384]   stripe               32824
[33927.141384]   normal               16440
[33927.141385]   copygc                  56
[33927.141385]   btree                   28
[33927.141386]   btree_copygc             0
[33927.141386]   reclaim                  0
[33927.141387]   interior_updates         0
[33927.141387]
[33927.141388]   open buckets             1
[33927.141388]   buckets to invalidate    0

[33927.141389] Copygc debug:
[33927.141390]   running: 1
[33927.141390]   copygc_wait:0
[33927.141391]   copygc_wait_at:0
[33927.141391]   Currently waiting for:0 B
[33927.141392]   Currently waiting since:25.1 TiB
[33927.141392]   Currently calculated wait:
[33927.141393]     vdb2:  0 B
[33927.141393]   [<0>] bch2_copygc_wait_to_text+0x1ad/0x2c0 [bcachefs]
[33927.141394]   [<0>] bch2_print_allocator_stuck+0x11c/0x240 [bcachefs]
[33927.141395]   [<0>] __bch2_wait_on_allocator+0x9f/0xc0 [bcachefs]
[33927.141395]   [<0>] bch2_btree_update_start+0x74c/0xa40 [bcachefs]
[33927.141396]   [<0>] bch2_btree_node_rewrite+0x6f/0x4a0 [bcachefs]
[33927.141397]   [<0>] bch2_btree_node_rewrite_pos+0xa2/0xe0 [bcachefs]
[33927.141397]   [<0>] __bch2_move_data_phys+0x899/0xce0 [bcachefs]
[33927.141398]   [<0>] bch2_evacuate_bucket+0xcc/0x130 [bcachefs]
[33927.141398]   [<0>] bch2_copygc+0x113/0x350 [bcachefs]
[33927.141399]   [<0>] bch2_copygc_thread+0x309/0x560 [bcachefs]
[33927.141399]   [<0>] kthread+0xfb/0x250
[33927.141400]   [<0>] ret_from_fork+0x199/0x1d0
[33927.141401]   [<0>] ret_from_fork_asm+0x1a/0x30

[33927.141402] Journal debug:
[33927.141402]   flags:                   replay_done,running,may_skip_flush
[33927.141403]   dirty journal entries:   3173/32768
[33927.141404]   seq:                     4861854
[33927.141404]   seq_ondisk:              4861854
[33927.141405]   last_seq:                4858682
[33927.141405]   last_seq_ondisk:         4858679
[33927.141406]   flushed_seq_ondisk:      4861854
[33927.141406]   watermark:               stripe
[33927.141407]   each entry reserved:     321
[33927.141407]   nr flush writes:         27485
[33927.141408]   nr noflush writes:       14761
[33927.141408]   average write size:      272 KiB
[33927.141409]   free buf:                524288
[33927.141409]   nr direct reclaim:       0
[33927.141410]   nr background reclaim:   1044727
[33927.141410]   reclaim kicked:          0
[33927.141411]   reclaim runs in:         84 ms
[33927.141411]   blocked:                 0
[33927.141412]   current entry sectors:   881
[33927.141412]   current entry error:     (No error)
[33927.141413]   current entry:           closed
[33927.141413]   unwritten entries:
[33927.141414]   last buf closed
[33927.141414]   space:
[33927.141415]     discarded              881:903025
[33927.141416]     clean ondisk           881:2927283
[33927.141416]     clean                  881:2927283
[33927.141417]     total                  881:2927283
[33927.141417]   dev 0:
[33927.141418]   durability 1:
[33927.141418]     nr                     8192
[33927.141419]     bucket size            881
[33927.141419]     available              1025:210
[33927.141420]     discard_idx            7025
[33927.141420]     dirty_ondisk           3244 (seq 4858679)
[33927.141421]     dirty_idx              3247 (seq 4858682)
[33927.141421]     cur_idx                5999 (seq 4861854)
[33927.141422]   replicas want 1 need 1
[33927.246798]   nr direct reclaim:       0
[33927.247134]   nr background reclaim:   1044727
[33927.247511]   reclaim kicked:          0
[33927.247842]   reclaim runs in:         84 ms
[33927.248205]   blocked:                 0
[33927.248533]   current entry sectors:   881
[33927.248875]   current entry error:     (No error)
[33927.249268]   current entry:           closed
[33927.249686]   unwritten entries:
[33927.249962]   last buf closed
[33927.250211]   space:
[33927.250402]     discarded              881:903025
[33927.250793]     clean ondisk           881:2927283
[33927.251188]     clean                  881:2927283
[33927.251577]     total                  881:2927283
[33927.251980]   dev 0:
[33927.252167]   durability 1:
[33927.252398]     nr                     8192
[33927.252748]     bucket size            881
[33927.253089]     available              1025:210
[33927.253464]     discard_idx            7025
[33927.253868]     dirty_ondisk           3244 (seq 4858679)
[33927.254314]     dirty_idx              3247 (seq 4858682)
[33927.254794]     cur_idx                5999 (seq 4861854)
[33927.255240]   replicas want 1 need 1
[33960.770688] ------------[ cut here ]------------
[33960.770691] btree trans held srcu lock (delaying memory reclaim) for 5000 seconds
[33960.770706] WARNING: CPU: 0 PID: 1819 at src/fs/bcachefs/btree_iter.c:3331 bch2_trans_srcu_unlock+0x11b/0x130 [bcachefs]
[33960.770774] Modules linked in: bcachefs(O) chacha_x86_64 libchacha libpoly1305 poly1305_x86_64 lz4hc_compress lz4_compress xor raid6_pq qrtr snd_seq_dummy snd_hrtimer snd_seq snd_seq_device af_packet rfkill nls_iso8859_1 nls_cp437 vfat fat snd_hda_codec_generic snd_hda_intel snd_intel_dspcfg intel_rapl_msr snd_intel_sdw_acpi iTCO_wdt intel_pmc_bxt watchdog xt_conntrack snd_hda_codec nf_conntrack snd_hda_core nf_defrag_ipv6 nf_defrag_ipv4 snd_hwdep edac_core snd_pcm intel_rapl_common polyval_clmulni ghash_clmulni_intel sha512_ssse3 sha1_ssse3 i2c_i801 psmouse aesni_intel i2c_smbus i2c_mux snd_timer ip6t_rpfilter ipt_rpfilter snd soundcore joydev lpc_ich mousedev rtc_cmos evdev xt_pkttype intel_agp tiny_power_button xt_LOG nf_log_syslog input_leds intel_gtt button led_class nft_compat mac_hid serio_raw nf_tables sch_fq_codel loop kvm_amd ccp kvm irqbypass fuse efi_pstore configfs nfnetlink efivarfs dmi_sysfs qemu_fw_cfg autofs4 ext4 crc16 mbcache jbd2 hid_generic usbhid hid sr_mod cdrom virtio_net net_failover failover
[33960.770825]  virtio_blk virtio_scsi ahci libahci libata atkbd libps2 vivaldi_fmap xhci_pci xhci_hcd scsi_mod scsi_common virtio_pci virtio_pci_legacy_dev virtio_pci_modern_dev i8042 serio virtio_rng rng_core virtio_gpu virtio_dma_buf virtio_console virtio_balloon virtio virtio_ring dm_mod dax
[33960.770842] CPU: 0 UID: 0 PID: 1819 Comm: bch-copygc/vdb2 Tainted: G        W  O        6.16.9 #1-NixOS PREEMPT(voluntary)
[33960.770845] Tainted: [W]=WARN, [O]=OOT_MODULE
[33960.770846] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS edk2-stable202408-prebuilt.qemu.org 08/13/2024
[33960.770847] RIP: 0010:bch2_trans_srcu_unlock+0x11b/0x130 [bcachefs]
[33960.770899] Code: bc d6 48 c7 c7 d8 0a 38 c1 48 b9 cf f7 53 e3 a5 9b c4 20 48 29 d0 48 c1 e8 03 48 f7 e1 48 89 d6 48 c1 ee 04 e8 56 2f ec d4 90 <0f> 0b 90 90 eb 9f 90 0f 0b 90 eb ab 66 0f 1f 84 00 00 00 00 00 90
[33960.770900] RSP: 0018:ffffcebc83e437e8 EFLAGS: 00010282
[33960.770902] RAX: 0000000000000000 RBX: ffff8d0d08ba8000 RCX: 0000000000000027
[33960.770903] RDX: ffff8d0ef5c1e408 RSI: 0000000000000001 RDI: ffff8d0ef5c1e400
[33960.770904] RBP: ffff8d0d85e40000 R08: 0000000000000000 R09: ffffcebc83e43678
[33960.770905] R10: ffffffff98110a28 R11: 0000000000000003 R12: 0000000000008000
[33960.770906] R13: ffff8d0d54e69300 R14: ffff8d0d08ba8000 R15: 0000000000000000
[33960.770909] FS:  0000000000000000(0000) GS:ffff8d0f5d14f000(0000) knlGS:0000000000000000
[33960.770911] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[33960.770912] CR2: 00007fbe15420000 CR3: 000000010fcb8000 CR4: 0000000000350ef0
[33960.770915] Call Trace:
[33960.770916]  <TASK>
[33960.770918]  ? bch2_trans_begin+0xc3/0x8e0 [bcachefs]
[33960.770966]  bch2_trans_begin+0x50a/0x8e0 [bcachefs]
[33960.771013]  ? bch2_move_ratelimit+0x29f/0x560 [bcachefs]
[33960.771077]  __bch2_move_data_phys+0x2bf/0xce0 [bcachefs]
[33960.771139]  ? __pfx_evacuate_bucket_pred+0x10/0x10 [bcachefs]
[33960.771196]  ? bch2_evacuate_bucket+0xcc/0x130 [bcachefs]
[33960.771243]  bch2_evacuate_bucket+0xcc/0x130 [bcachefs]
[33960.771290]  ? __pfx_evacuate_bucket_pred+0x10/0x10 [bcachefs]
[33960.771337]  bch2_copygc+0x113/0x350 [bcachefs]
[33960.771399]  bch2_copygc_thread+0x309/0x560 [bcachefs]
[33960.771454]  ? bch2_copygc_thread+0x28f/0x560 [bcachefs]
[33960.771502]  ? __pfx_bch2_copygc_thread+0x10/0x10 [bcachefs]
[33960.771547]  kthread+0xfb/0x250
[33960.771550]  ? __pfx_kthread+0x10/0x10
[33960.771552]  ret_from_fork+0x199/0x1d0
[33960.771555]  ? __pfx_kthread+0x10/0x10
[33960.771556]  ret_from_fork_asm+0x1a/0x30
[33960.771560]  </TASK>
[33960.771561] ---[ end trace 0000000000000000 ]---
[34130.913634] Allocator stuck? Waited for 30 seconds
[34130.913636] Allocator debug:
[34130.913637]   capacity849891820
[34130.913637]   used                 833188184
[34130.913638]   reserved             73903636
[34130.913638]   hidden               7221557
[34130.913638]   btree                20343808
[34130.913639]   data                 811177914
[34130.913639]   cached               0
[34130.913639]   reserved             519032
[34130.913640]   online_reserved      1121792
[34130.913640]
[34130.913641]   freelist_wait        waiting
[34130.913641]   open buckets allocated2
[34130.913641]   open buckets total   1024
[34130.913642]   open_buckets_wait    empty
[34130.913642]   open_buckets_btree   0
[34130.913642]   open_buckets_user    1
[34130.913643]   btree reserve cache  0

[34130.913643] Allocator stuck? Waited for 30 seconds
[34130.913643] Dev 0:
[34130.913644]                      buckets         sectors      fragmented
[34130.913644]   free                    29               0               0
[34130.913644] Allocator debug:
[34130.913645]   sb                       5            4104             301
[34130.913645]   capacity849891820
[34130.913646]   journal               8192         7217152               0
[34130.913646]   used                 833188184
[34130.913646]   btree                39734        20343808        14661846
[34130.913646]   reserved             73903636
[34130.913647]   user                926297       811177914         4889743
[34130.913647]   hidden               7221557
[34130.913647]   cached                   0               0               0
[34130.913647]   btree                20343808
[34130.913648]   parity                   0               0               0
[34130.913648]   data                 811177914
[34130.913648]   stripe                   0               0               0
[34130.913648]   cached               0
[34130.913649]   need_gc_gens             0               0               0
[34130.913649]   reserved             519032
[34130.913649]   need_discard         74319               0               0
[34130.913649]   online_reserved      1121792
[34130.913650]   unstriped                0               0               0
[34130.913650]
[34130.913650]   capacity           1048576
[34130.913651]   freelist_wait        waiting
[34130.913651]
[34130.913651]   open buckets allocated2
[34130.913651]   reserves:
[34130.913652]   open buckets total   1024
[34130.913652]   stripe               32824
[34130.913652]   open_buckets_wait    empty
[34130.913652]   normal               16440
[34130.913653]   open_buckets_btree   0
[34130.913653]   copygc                  56
[34130.913653]   open_buckets_user    1
[34130.913653]   btree                   28
[34130.913654]   btree reserve cache  0
[34130.913654]   btree_copygc             0

[34130.913654]   reclaim                  0
[34130.913654] Dev 0:
[34130.913655]   interior_updates         0
[34130.913655]
[34130.913655]                      buckets         sectors      fragmented
[34130.913655]   open buckets             1
[34130.913656]   free                    29               0               0
[34130.913656]   buckets to invalidate    0
[34130.913656]   sb                       5            4104             301

[34130.913657] Copygc debug:
[34130.913657]   journal               8192         7217152               0
[34130.913657]   running: 1
[34130.913657]   btree                39734        20343808        14661846
[34130.913658]   copygc_wait:0
[34130.913658]   user                926297       811177914         4889743
[34130.913658]   copygc_wait_at:0
[34130.913658]   cached                   0               0               0
[34130.913658]   Currently waiting for:0 B
[34130.913659]   parity                   0               0               0
[34130.913659]   Currently waiting since:25.1 TiB
[34130.913659]   stripe                   0               0               0
[34130.913660]   Currently calculated wait:
[34130.913660]   need_gc_gens             0               0               0
[34130.913660]     vdb2:  0 B
[34130.913661]   need_discard         74319               0               0

[34130.913661]   unstriped                0               0               0
[34130.913661] Journal debug:
[34130.913662]   capacity           1048576
[34130.913662]   flags:                   replay_done,running,may_skip_flush
[34130.913662]
[34130.913663]   dirty journal entries:   3159/32768
[34130.913663]   reserves:
[34130.913663]   seq:                     4861861
[34130.913663]   stripe               32824
[34130.913664]   seq_ondisk:              4861861
[34130.913664]   normal               16440
[34130.913664]   last_seq:                4858703
[34130.913664]   copygc                  56
[34130.913664]   last_seq_ondisk:         4858701
[34130.913665]   btree                   28
[34130.913665]   flushed_seq_ondisk:      4861861
[34130.913665]   btree_copygc             0
[34130.913665]   watermark:               stripe
[34130.913666]   reclaim                  0
[34130.913666]   each entry reserved:     321
[34130.913666]   interior_updates         0
[34130.913666]   nr flush writes:         27492
[34130.913667]
[34130.913667]   nr noflush writes:       14761
[34130.913667]   open buckets             1
[34130.913667]   average write size:      272 KiB
[34130.913667]   buckets to invalidate    0
[34130.913668]   free buf:                524288

[34130.913668]   nr direct reclaim:       0
[34130.913668] Copygc debug:
[34130.913669]   nr background reclaim:   1046686
[34130.913669]   running: 1
[34130.913669]   reclaim kicked:          0
[34130.913669]   copygc_wait:0
[34130.913670]   reclaim runs in:         44 ms
[34130.913670]   copygc_wait_at:0
[34130.913670]   blocked:                 0
[34130.913670]   Currently waiting for:0 B
[34130.913670]   current entry sectors:   881
[34130.913671]   Currently waiting since:25.1 TiB
[34130.913671]   current entry error:     (No error)
[34130.913671]   Currently calculated wait:
[34130.913672]   current entry:           closed
[34130.913672]     vdb2:  0 B
[34130.913672]   unwritten entries:

[34130.913672]   last buf closed
[34130.913672] Journal debug:
[34130.913673]   space:
[34130.913673]   flags:                   replay_done,running,may_skip_flush
[34130.913673]     discarded              881:903025
[34130.913674]   dirty journal entries:   3159/32768
[34130.913674]     clean ondisk           881:2941423
[34130.913674]   seq:                     4861861
[34130.913674]     clean                  881:2941423
[34130.913675]   seq_ondisk:              4861861
[34130.913675]     total                  881:2941423
[34130.913675]   last_seq:                4858703
[34130.913675]   dev 0:
[34130.913676]   last_seq_ondisk:         4858701
[34130.913676]   durability 1:
[34130.913676]   flushed_seq_ondisk:      4861861
[34130.913676]     nr                     8192
[34130.913677]   watermark:               stripe
[34130.913677]     bucket size            881
[34130.913677]   each entry reserved:     321
[34130.913677]     available              1025:164
[34130.913678]   nr flush writes:         27492
[34130.913678]     discard_idx            7025
[34130.913678]   nr noflush writes:       14761
[34130.913678]     dirty_ondisk           3265 (seq 4858701)
[34130.913679]   average write size:      272 KiB
[34130.913679]     dirty_idx              3267 (seq 4858703)
[34130.913679]   free buf:                524288
[34130.913680]     cur_idx                5999 (seq 4861861)
[34130.913680]   nr direct reclaim:       0
[34130.913680]   replicas want 1 need 1
[34130.913680]   nr background reclaim:   1046686
[34130.913681]   reclaim kicked:          0
[34130.913681]   reclaim runs in:         44 ms
[34130.913682]   blocked:                 0
[34130.913977] Allocator stuck? Waited for 30 seconds
[34130.913979] Allocator debug:
[34130.913980]   capacity849891820
[34130.913981]   used                 833188184
[34130.913982]   reserved             73903636
[34130.913982]   hidden               7221557
[34130.913983]   btree                20343808
[34130.913984]   data                 811177914
[34130.913984]   cached               0
[34130.913985]   reserved             519032
[34130.913985]   online_reserved      1121792
[34130.913986]
[34130.913987]   freelist_wait        waiting
[34130.913987]   open buckets allocated2
[34130.913988]   open buckets total   1024
[34130.913988]   open_buckets_wait    empty
[34130.913989]   open_buckets_btree   0
[34130.913989]   open_buckets_user    1
[34130.913990]   btree reserve cache  0

[34130.913991] Dev 0:
[34130.913991]                      buckets         sectors      fragmented
[34130.913992]   free                    29               0               0
[34130.913993]   sb                       5            4104             301
[34130.913994]   journal               8192         7217152               0
[34130.913994]   btree                39734        20343808        14661846
[34130.913995]   user                926297       811177914         4889743
[34130.913995]   cached                   0               0               0
[34130.913996]   parity                   0               0               0
[34130.913997]   stripe                   0               0               0
[34130.913997]   need_gc_gens             0               0               0
[34130.913998]   need_discard         74319               0               0
[34130.913999]   unstriped                0               0               0
[34130.913999]   capacity           1048576
[34130.914000]
[34130.914000]   reserves:
[34130.914001]   stripe               32824
[34130.914001]   normal               16440
[34130.914002]   copygc                  56
[34130.914003]   btree                   28
[34130.914003]   btree_copygc             0
[34130.914004]   reclaim                  0
[34130.914004]   interior_updates         0
[34130.914005]
[34130.914005]   open buckets             1
[34130.914006]   buckets to invalidate    0

[34130.914007] Copygc debug:
[34130.914007]   running: 1
[34130.914008]   copygc_wait:0
[34130.914008]   copygc_wait_at:0
[34130.914009]   Currently waiting for:0 B
[34130.914009]   Currently waiting since:25.1 TiB
[34130.914010]   Currently calculated wait:
[34130.914011]     vdb2:  0 B
[34130.914011]   [<0>] bch2_copygc_wait_to_text+0x1ad/0x2c0 [bcachefs]
[34130.914012]   [<0>] bch2_print_allocator_stuck+0x11c/0x240 [bcachefs]
[34130.914012]   [<0>] __bch2_wait_on_allocator+0x9f/0xc0 [bcachefs]
[34130.914013]   [<0>] bch2_btree_update_start+0x74c/0xa40 [bcachefs]
[34130.914014]   [<0>] bch2_btree_node_rewrite+0x6f/0x4a0 [bcachefs]
[34130.914015]   [<0>] bch2_btree_node_rewrite_pos+0xa2/0xe0 [bcachefs]
[34130.914015]   [<0>] __bch2_move_data_phys+0x899/0xce0 [bcachefs]
[34130.914016]   [<0>] bch2_evacuate_bucket+0xcc/0x130 [bcachefs]
[34130.914016]   [<0>] bch2_copygc+0x113/0x350 [bcachefs]
[34130.914017]   [<0>] bch2_copygc_thread+0x309/0x560 [bcachefs]
[34130.914018]   [<0>] kthread+0xfb/0x250
[34130.914018]   [<0>] ret_from_fork+0x199/0x1d0
[34130.914019]   [<0>] ret_from_fork_asm+0x1a/0x30

[34130.914020] Journal debug:
[34130.914020]   flags:                   replay_done,running,may_skip_flush
[34130.914021]   dirty journal entries:   3159/32768
[34130.914021]   seq:                     4861861
[34130.914022]   seq_ondisk:              4861861
[34130.914023]   last_seq:                4858703
[34130.914023]   last_seq_ondisk:         4858701
[34130.914024]   flushed_seq_ondisk:      4861861
[34130.914024]   watermark:               stripe
[34130.914025]   each entry reserved:     321
[34130.914026]   nr flush writes:         27492
[34130.914026]   nr noflush writes:       14761
[34130.914027]   average write size:      272 KiB
[34130.914027]   free buf:                524288
[34130.914028]   nr direct reclaim:       0
[34130.914028]   nr background reclaim:   1046686
[34130.914029]   reclaim kicked:          0
[34130.914029]   reclaim runs in:         44 ms
[34130.914030]   blocked:                 0
[34130.914031]   current entry sectors:   881
[34130.914031]   current entry error:     (No error)
[34130.914032]   current entry:           closed
[34130.914032]   unwritten entries:
[34130.914033]   last buf closed
[34130.914033]   space:
[34130.914034]     discarded              881:903025
[34130.914035]     clean ondisk           881:2941423
[34130.914035]     clean                  881:2941423
[34130.914036]     total                  881:2941423
[34130.914036]   dev 0:
[34130.914037]   durability 1:
[34130.914037]     nr                     8192
[34130.914038]     bucket size            881
[34130.914039]     available              1025:164
[34130.914039]     discard_idx            7025
[34130.914040]     dirty_ondisk           3265 (seq 4858701)
[34130.914040]     dirty_idx              3267 (seq 4858703)
[34130.914041]     cur_idx                5999 (seq 4861861)
[34130.914042]   replicas want 1 need 1
[34131.029580]   current entry sectors:   881
[34131.029917]   current entry error:     (No error)
[34131.030306]   current entry:           closed
[34131.030682]   unwritten entries:
[34131.030951]   last buf closed
[34131.031200]   space:
[34131.031392]     discarded              881:903025
[34131.031841]     clean ondisk           881:2941423
[34131.032232]     clean                  881:2941423
[34131.032678]     total                  881:2941423
[34131.033090]   dev 0:
[34131.033280]   durability 1:
[34131.033526]     nr                     8192
[34131.033875]     bucket size            881
[34131.034210]     available              1025:164
[34131.034598]     discard_idx            7025
[34131.035010]     dirty_ondisk           3265 (seq 4858701)
[34131.035452]     dirty_idx              3267 (seq 4858703)
[34131.035911]     cur_idx                5999 (seq 4861861)
[34131.036354]   replicas want 1 need 1
[34388.445834] Allocator stuck? Waited for 30 seconds
[34388.445836] Allocator debug:
[34388.445837]   capacity849891820
[34388.445838]   used                 833188184
[34388.445838]   reserved             73903636
[34388.445839]   hidden               7221557
[34388.445839]   btree                20343808
[34388.445840]   data                 811177914
[34388.445840]   cached               0
[34388.445840]   reserved             519032
[34388.445841]   online_reserved      1121792
[34388.445841]
[34388.445841]   freelist_wait        waiting
[34388.445842]   open buckets allocated2
[34388.445842]   open buckets total   1024
[34388.445843]   open_buckets_wait    empty
[34388.445843]   open_buckets_btree   0
[34388.445843]   open_buckets_user    1
[34388.445844]   btree reserve cache  0

[34388.445844] Dev 0:
[34388.445845]                      buckets         sectors      fragmented
[34388.445845]   free                    29               0               0
[34388.445846]   sb                       5            4104             301
[34388.445846]   journal               8192         7217152               0
[34388.445847]   btree                39734        20343808        14661846
[34388.445847]   user                926297       811177914         4889743
[34388.445848]   cached                   0               0               0
[34388.445848]   parity                   0               0               0
[34388.445848] Allocator stuck? Waited for 30 seconds
[34388.445849]   stripe                   0               0               0
[34388.445849]   need_gc_gens             0               0               0
[34388.445850]   need_discard         74319               0               0
[34388.445850] Allocator debug:
[34388.445851]   unstriped                0               0               0
[34388.445851]   capacity           1048576
[34388.445852]   capacity849891820
[34388.445852]
[34388.445853]   reserves:
[34388.445853]   used                 833188184
[34388.445853]   stripe               32824
[34388.445854]   normal               16440
[34388.445854]   reserved             73903636
[34388.445855]   copygc                  56
[34388.445855]   hidden               7221557
[34388.445855]   btree                   28
[34388.445856]   btree_copygc             0
[34388.445857]   btree                20343808
[34388.445857]   reclaim                  0
[34388.445857]   interior_updates         0
[34388.445858]
[34388.445858]   data                 811177914
[34388.445859]   open buckets             1
[34388.445859]   cached               0
[34388.445859]   buckets to invalidate    0

[34388.445860]   reserved             519032
[34388.445860] Copygc debug:
[34388.445861]   running: 1
[34388.445861]   online_reserved      1121792
[34388.445861]   copygc_wait:0
[34388.445862]   copygc_wait_at:0
[34388.445862]
[34388.445862]   Currently waiting for:0 B
[34388.445863]   Currently waiting since:25.1 TiB
[34388.445863]   freelist_wait        waiting
[34388.445864]   Currently calculated wait:
[34388.445864]     vdb2:  0 B
[34388.445864]   open buckets allocated2

[34388.445865] Journal debug:
[34388.445865]   open buckets total   1024
[34388.445866]   flags:                   replay_done,running,may_skip_flush
[34388.445866]   open_buckets_wait    empty
[34388.445866]   dirty journal entries:   3135/32768
[34388.445867]   open_buckets_btree   0
[34388.445867]   seq:                     4861863
[34388.445868]   seq_ondisk:              4861863
[34388.445868]   open_buckets_user    1
[34388.445868]   last_seq:                4858729
[34388.445869]   last_seq_ondisk:         4858726
[34388.445869]   btree reserve cache  0
[34388.445869]   flushed_seq_ondisk:      4861863

[34388.445870]   watermark:               stripe
[34388.445871]   each entry reserved:     321
[34388.445871] Dev 0:
[34388.445872]   nr flush writes:         27494
[34388.445872]                      buckets         sectors      fragmented
[34388.445872]   nr noflush writes:       14761
[34388.445873]   average write size:      272 KiB
[34388.445874]   free                    29               0               0
[34388.445874]   free buf:                524288
[34388.445874]   nr direct reclaim:       0
[34388.445875]   nr background reclaim:   1049162
[34388.445875]   sb                       5            4104             301
[34388.445876]   reclaim kicked:          0
[34388.445876]   reclaim runs in:         12 ms
[34388.445876]   journal               8192         7217152               0
[34388.445877]   blocked:                 0
[34388.445878]   current entry sectors:   881
[34388.445878]   btree                39734        20343808        14661846
[34388.445879]   current entry error:     (No error)
[34388.445879]   current entry:           closed
[34388.445879]   user                926297       811177914         4889743
[34388.445880]   unwritten entries:
[34388.445881]   last buf closed
[34388.445881]   cached                   0               0               0
[34388.445881]   space:
[34388.445882]     discarded              881:903025
[34388.445882]   parity                   0               0               0
[34388.445882]     clean ondisk           881:2961037
[34388.445883]     clean                  881:2961037
[34388.445883]   stripe                   0               0               0
[34388.445883]     total                  881:2961037
[34388.445884]   dev 0:
[34388.445884]   need_gc_gens             0               0               0
[34388.445884]   durability 1:
[34388.445885]     nr                     8192
[34388.445885]   need_discard         74319               0               0
[34388.445885]     bucket size            881
[34388.445886]     available              1025:156
[34388.445886]   unstriped                0               0               0
[34388.445886]     discard_idx            7025
[34388.445887]   capacity           1048576
[34388.445887]     dirty_ondisk           3288 (seq 4858727)
[34388.445888]
[34388.445888]     dirty_idx              3290 (seq 4858729)
[34388.445889]     cur_idx                5999 (seq 4861863)
[34388.445889]   reserves:
[34388.445889]   replicas want 1 need 1
[34388.445890]   stripe               32824
[34388.445891]   normal               16440
[34388.445891]   copygc                  56
[34388.446212] Allocator stuck? Waited for 30 seconds
[34388.446214] Allocator debug:
[34388.446215]   capacity849891820
[34388.446215]   used                 833188184
[34388.446216]   reserved             73903636
[34388.446216]   hidden               7221557
[34388.446217]   btree                20343808
[34388.446218]   data                 811177914
[34388.446218]   cached               0
[34388.446219]   reserved             519032
[34388.446219]   online_reserved      1121792
[34388.446220]
[34388.446220]   freelist_wait        waiting
[34388.446221]   open buckets allocated2
[34388.446221]   open buckets total   1024
[34388.446222]   open_buckets_wait    empty
[34388.446222]   open_buckets_btree   0
[34388.446223]   open_buckets_user    1
[34388.446223]   btree reserve cache  0

[34388.446224] Dev 0:
[34388.446225]                      buckets         sectors      fragmented
[34388.446226]   free                    29               0               0
[34388.446226]   sb                       5            4104             301
[34388.446227]   journal               8192         7217152               0
[34388.446228]   btree                39734        20343808        14661846
[34388.446228]   user                926297       811177914         4889743
[34388.446229]   cached                   0               0               0
[34388.446230]   parity                   0               0               0
[34388.446230]   stripe                   0               0               0
[34388.446231]   need_gc_gens             0               0               0
[34388.446231]   need_discard         74319               0               0
[34388.446232]   unstriped                0               0               0
[34388.446233]   capacity           1048576
[34388.446233]
[34388.446234]   reserves:
[34388.446234]   stripe               32824
[34388.446235]   normal               16440
[34388.446235]   copygc                  56
[34388.446236]   btree                   28
[34388.446236]   btree_copygc             0
[34388.446237]   reclaim                  0
[34388.446237]   interior_updates         0
[34388.446238]
[34388.446238]   open buckets             1
[34388.446239]   buckets to invalidate    0

[34388.446240] Copygc debug:
[34388.446240]   running: 1
[34388.446241]   copygc_wait:0
[34388.446241]   copygc_wait_at:0
[34388.446242]   Currently waiting for:0 B
[34388.446242]   Currently waiting since:25.1 TiB
[34388.446243]   Currently calculated wait:
[34388.446243]     vdb2:  0 B
[34388.446244]   [<0>] bch2_copygc_wait_to_text+0x1ad/0x2c0 [bcachefs]
[34388.446244]   [<0>] bch2_print_allocator_stuck+0x11c/0x240 [bcachefs]
[34388.446245]   [<0>] __bch2_wait_on_allocator+0x9f/0xc0 [bcachefs]
[34388.446246]   [<0>] bch2_btree_update_start+0x74c/0xa40 [bcachefs]
[34388.446246]   [<0>] bch2_btree_node_rewrite+0x6f/0x4a0 [bcachefs]
[34388.446247]   [<0>] bch2_btree_node_rewrite_pos+0xa2/0xe0 [bcachefs]
[34388.446248]   [<0>] __bch2_move_data_phys+0x899/0xce0 [bcachefs]
[34388.446248]   [<0>] bch2_evacuate_bucket+0xcc/0x130 [bcachefs]
[34388.446249]   [<0>] bch2_copygc+0x113/0x350 [bcachefs]
[34388.446249]   [<0>] bch2_copygc_thread+0x309/0x560 [bcachefs]
[34388.446250]   [<0>] kthread+0xfb/0x250
[34388.446251]   [<0>] ret_from_fork+0x199/0x1d0
[34388.446251]   [<0>] ret_from_fork_asm+0x1a/0x30

[34388.446252] Journal debug:
[34388.446253]   flags:                   replay_done,running,may_skip_flush
[34388.446253]   dirty journal entries:   3135/32768
[34388.446254]   seq:                     4861863
[34388.446254]   seq_ondisk:              4861863
[34388.446255]   last_seq:                4858729
[34388.446256]   last_seq_ondisk:         4858726
[34388.446256]   flushed_seq_ondisk:      4861863
[34388.446257]   watermark:               stripe
[34388.446257]   each entry reserved:     321
[34388.446258]   nr flush writes:         27494
[34388.446258]   nr noflush writes:       14761
[34388.446259]   average write size:      272 KiB
[34388.446259]   free buf:                524288
[34388.446260]   nr direct reclaim:       0
[34388.446260]   nr background reclaim:   1049162
[34388.446261]   reclaim kicked:          0
[34388.446262]   reclaim runs in:         12 ms
[34388.446262]   blocked:                 0
[34388.446263]   current entry sectors:   881
[34388.446263]   current entry error:     (No error)
[34388.446264]   current entry:           closed
[34388.446264]   unwritten entries:
[34388.446265]   last buf closed
[34388.446265]   space:
[34388.446266]     discarded              881:903025
[34388.446266]     clean ondisk           881:2961037
[34388.446267]     clean                  881:2961037
[34388.446267]     total                  881:2961037
[34388.446268]   dev 0:
[34388.446269]   durability 1:
[34388.446269]     nr                     8192
[34388.446270]     bucket size            881
[34388.446270]     available              1025:156
[34388.446271]     discard_idx            7025
[34388.446271]     dirty_ondisk           3288 (seq 4858727)
[34388.446272]     dirty_idx              3290 (seq 4858729)
[34388.446272]     cur_idx                5999 (seq 4861863)
[34388.446273]   replicas want 1 need 1
[34388.541771]   btree                   28
[34388.542209]   btree_copygc             0
[34388.542596]   reclaim                  0
[34388.543007]   interior_updates         0
[34388.543395]
[34388.543572]   open buckets             1
[34388.543976]   buckets to invalidate    0

[34388.544569] Copygc debug:
[34388.544850]   running: 1
[34388.545108]   copygc_wait:0
[34388.545389]   copygc_wait_at:0
[34388.545702]   Currently waiting for:0 B
[34388.546098]   Currently waiting since:25.1 TiB
[34388.546582]   Currently calculated wait:
[34388.546989]     vdb2:  0 B

[34388.547423] Journal debug:
[34388.547701]   flags:                   replay_done,running,may_skip_flush
[34388.548372]   dirty journal entries:   3135/32768
[34388.548916]   seq:                     4861863
[34388.549357]   seq_ondisk:              4861863
[34388.549812]   last_seq:                4858729
[34388.550328]   last_seq_ondisk:         4858726
[34388.550786]   flushed_seq_ondisk:      4861863
[34388.551225]   watermark:               stripe
[34388.551657]   each entry reserved:     321
[34388.552079]   nr flush writes:         27494
[34388.552582]   nr noflush writes:       14761
[34388.553022]   average write size:      272 KiB
[34388.553461]   free buf:                524288
[34388.553907]   nr direct reclaim:       0
[34388.554371]   nr background reclaim:   1049162
[34388.554827]   reclaim kicked:          0
[34388.555214]   reclaim runs in:         12 ms
[34388.555635]   blocked:                 0
[34388.556039]   current entry sectors:   881
[34388.556485]   current entry error:     (No error)
[34388.557010]   current entry:           closed
[34388.557441]   unwritten entries:
[34388.557785]   last buf closed
[34388.558134]   space:
[34388.558358]     discarded              881:903025
[34388.558837]     clean ondisk           881:2961037
[34388.559312]     clean                  881:2961037
[34388.559794]     total                  881:2961037
[34388.560303]   dev 0:
[34388.560528]   durability 1:
[34388.560825]     nr                     8192
[34388.561237]     bucket size            881
[34388.561640]     available              1025:156
[34388.562110]     discard_idx            7025
[34388.562555]     dirty_ondisk           3288 (seq 4858727)
[34388.563008]     dirty_idx              3290 (seq 4858729)
[34388.563441]     cur_idx                5999 (seq 4861863)
[34388.563887]   replicas want 1 need 1
[34987.988409] Allocator stuck? Waited for 30 seconds
[34987.988412] Allocator debug:
[34987.988413]   capacity849891820
[34987.988414]   used                 833188184
[34987.988414]   reserved             73903636
[34987.988415]   hidden               7221557
[34987.988416]   btree                20343808
[34987.988416]   data                 811177914
[34987.988417]   cached               0
[34987.988418]   reserved             519032
[34987.988418]   online_reserved      1121792
[34987.988419]
[34987.988419] Allocator stuck? Waited for 30 seconds
[34987.988419]   freelist_wait        waiting
[34987.988420]   open buckets allocated2
[34987.988421] Allocator debug:
[34987.988421]   open buckets total   1024
[34987.988421]   capacity849891820
[34987.988421]   open_buckets_wait    empty
[34987.988422]   used                 833188184
[34987.988422]   open_buckets_btree   0
[34987.988423]   reserved             73903636
[34987.988423]   open_buckets_user    1
[34987.988423]   hidden               7221557
[34987.988423]   btree reserve cache  0
[34987.988424]   btree                20343808

[34987.988425] Dev 0:
[34987.988425]   data                 811177914
[34987.988425]                      buckets         sectors      fragmented
[34987.988425]   cached               0
[34987.988426]   free                    29               0               0
[34987.988426]   reserved             519032
[34987.988427]   sb                       5            4104             301
[34987.988427]   online_reserved      1121792
[34987.988428]
[34987.988428]   journal               8192         7217152               0
[34987.988428]   freelist_wait        waiting
[34987.988428]   btree                39734        20343808        14661846
[34987.988429]   open buckets allocated2
[34987.988429]   user                926297       811177914         4889743
[34987.988430]   open buckets total   1024
[34987.988430]   cached                   0               0               0
[34987.988430]   open_buckets_wait    empty
[34987.988431]   parity                   0               0               0
[34987.988431]   open_buckets_btree   0
[34987.988432]   stripe                   0               0               0
[34987.988432]   open_buckets_user    1
[34987.988432]   btree reserve cache  0
[34987.988432]   need_gc_gens             0               0               0

[34987.988433]   need_discard         74319               0               0
[34987.988434] Dev 0:
[34987.988434]   unstriped                0               0               0
[34987.988434]                      buckets         sectors      fragmented
[34987.988435]   capacity           1048576
[34987.988435]   free                    29               0               0
[34987.988435]
[34987.988436]   sb                       5            4104             301
[34987.988436]   reserves:
[34987.988436]   journal               8192         7217152               0
[34987.988437]   stripe               32824
[34987.988437]   normal               16440
[34987.988437]   btree                39734        20343808        14661846
[34987.988438]   copygc                  56
[34987.988438]   user                926297       811177914         4889743
[34987.988438]   btree                   28
[34987.988439]   cached                   0               0               0
[34987.988439]   btree_copygc             0
[34987.988440]   parity                   0               0               0
[34987.988440]   reclaim                  0
[34987.988440]   stripe                   0               0               0
[34987.988441]   interior_updates         0
[34987.988441]
[34987.988441]   need_gc_gens             0               0               0
[34987.988442]   open buckets             1
[34987.988442]   need_discard         74319               0               0
[34987.988442]   buckets to invalidate    0
[34987.988443]   unstriped                0               0               0

[34987.988444]   capacity           1048576
[34987.988444] Copygc debug:
[34987.988444]
[34987.988444]   running: 1
[34987.988445]   reserves:
[34987.988445]   copygc_wait:0
[34987.988445]   stripe               32824
[34987.988446]   copygc_wait_at:0
[34987.988446]   normal               16440
[34987.988446]   Currently waiting for:0 B
[34987.988447]   copygc                  56
[34987.988447]   Currently waiting since:25.1 TiB
[34987.988447]   btree                   28
[34987.988447]   Currently calculated wait:
[34987.988448]   btree_copygc             0
[34987.988448]     vdb2:  0 B
[34987.988448]   reclaim                  0

[34987.988449]   interior_updates         0
[34987.988449] Journal debug:
[34987.988450]
[34987.988450]   flags:                   replay_done,running,may_skip_flush
[34987.988450]   open buckets             1
[34987.988451]   dirty journal entries:   3076/32768
[34987.988451]   buckets to invalidate    0

[34987.988451]   seq:                     4861864
[34987.988452] Copygc debug:
[34987.988452]   seq_ondisk:              4861864
[34987.988453]   running: 1
[34987.988453]   last_seq:                4858789
[34987.988453]   copygc_wait:0
[34987.988453]   last_seq_ondisk:         4858787
[34987.988454]   copygc_wait_at:0
[34987.988454]   flushed_seq_ondisk:      4861864
[34987.988454]   Currently waiting for:0 B
[34987.988455]   watermark:               stripe
[34987.988455]   Currently waiting since:25.1 TiB
[34987.988455]   each entry reserved:     321
[34987.988456]   Currently calculated wait:
[34987.988456]   nr flush writes:         27495
[34987.988456]     vdb2:  0 B
[34987.988457]   nr noflush writes:       14761

[34987.988457]   average write size:      272 KiB
[34987.988457] Journal debug:
[34987.988458]   free buf:                524288
[34987.988458]   flags:                   replay_done,running,may_skip_flush
[34987.988459]   nr direct reclaim:       0
[34987.988459]   dirty journal entries:   3076/32768
[34987.988459]   nr background reclaim:   1054927
[34987.988460]   seq:                     4861864
[34987.988460]   reclaim kicked:          0
[34987.988460]   seq_ondisk:              4861864
[34987.988461]   reclaim runs in:         20 ms
[34987.988461]   last_seq:                4858789
[34987.988461]   blocked:                 0
[34987.988462]   last_seq_ondisk:         4858787
[34987.988462]   current entry sectors:   881
[34987.988462]   flushed_seq_ondisk:      4861864
[34987.988463]   current entry error:     (No error)
[34987.988463]   watermark:               stripe
[34987.988463]   current entry:           closed
[34987.988464]   each entry reserved:     321
[34987.988464]   unwritten entries:
[34987.988464]   nr flush writes:         27495
[34987.988465]   last buf closed
[34987.988465]   nr noflush writes:       14761
[34987.988465]   space:
[34987.988466]   average write size:      272 KiB
[34987.988466]     discarded              881:903025
[34987.988466]   free buf:                524288
[34987.988467]     clean ondisk           881:3001076
[34987.988467]   nr direct reclaim:       0
[34987.988467]     clean                  881:3001076
[34987.988467]   nr background reclaim:   1054927
[34987.988468]     total                  881:3001076
[34987.988468]   reclaim kicked:          0
[34987.988469]   dev 0:
[34987.988469]   reclaim runs in:         20 ms
[34987.988469]   durability 1:
[34987.988469]   blocked:                 0
[34987.988470]     nr                     8192
[34987.988470]   current entry sectors:   881
[34987.988470]     bucket size            881
[34987.988471]   current entry error:     (No error)
[34987.988471]     available              1025:152
[34987.988471]   current entry:           closed
[34987.988472]     discard_idx            7025
[34987.988472]   unwritten entries:
[34987.988472]     dirty_ondisk           3344 (seq 4858787)
[34987.988473]   last buf closed
[34987.988473]     dirty_idx              3346 (seq 4858789)
[34987.988473]   space:
[34987.988474]     discarded              881:903025
[34987.988474]     cur_idx                5999 (seq 4861864)
[34987.988474]     clean ondisk           881:3001076
[34987.988475]   replicas want 1 need 1
[34987.988475]     clean                  881:3001076
[34987.988476]     total                  881:3001076
[34987.988476]   dev 0:
[34987.988477]   durability 1:
[34987.988789] Allocator stuck? Waited for 30 seconds
[34987.988791] Allocator debug:
[34987.988792]   capacity849891820
[34987.988792]   used                 833188184
[34987.988793]   reserved             73903636
[34987.988793]   hidden               7221557
[34987.988794]   btree                20343808
[34987.988794]   data                 811177914
[34987.988795]   cached               0
[34987.988795]   reserved             519032
[34987.988796]   online_reserved      1121792
[34987.988796]
[34987.988797]   freelist_wait        waiting
[34987.988797]   open buckets allocated2
[34987.988797]   open buckets total   1024
[34987.988798]   open_buckets_wait    empty
[34987.988798]   open_buckets_btree   0
[34987.988799]   open_buckets_user    1
[34987.988799]   btree reserve cache  0

[34987.988800] Dev 0:
[34987.988801]                      buckets         sectors      fragmented
[34987.988801]   free                    29               0               0
[34987.988802]   sb                       5            4104             301
[34987.988802]   journal               8192         7217152               0
[34987.988803]   btree                39734        20343808        14661846
[34987.988803]   user                926297       811177914         4889743
[34987.988804]   cached                   0               0               0
[34987.988804]   parity                   0               0               0
[34987.988805]   stripe                   0               0               0
[34987.988805]   need_gc_gens             0               0               0
[34987.988806]   need_discard         74319               0               0
[34987.988806]   unstriped                0               0               0
[34987.988807]   capacity           1048576
[34987.988807]
[34987.988808]   reserves:
[34987.988808]   stripe               32824
[34987.988808]   normal               16440
[34987.988809]   copygc                  56
[34987.988809]   btree                   28
[34987.988810]   btree_copygc             0
[34987.988810]   reclaim                  0
[34987.988811]   interior_updates         0
[34987.988811]
[34987.988812]   open buckets             1
[34987.988812]   buckets to invalidate    0

[34987.988813] Copygc debug:
[34987.988813]   running: 1
[34987.988814]   copygc_wait:0
[34987.988814]   copygc_wait_at:0
[34987.988814]   Currently waiting for:0 B
[34987.988815]   Currently waiting since:25.1 TiB
[34987.988815]   Currently calculated wait:
[34987.988816]     vdb2:  0 B
[34987.988816]   [<0>] bch2_copygc_wait_to_text+0x1ad/0x2c0 [bcachefs]
[34987.988817]   [<0>] bch2_print_allocator_stuck+0x11c/0x240 [bcachefs]
[34987.988817]   [<0>] __bch2_wait_on_allocator+0x9f/0xc0 [bcachefs]
[34987.988818]   [<0>] bch2_btree_update_start+0x74c/0xa40 [bcachefs]
[34987.988819]   [<0>] bch2_btree_node_rewrite+0x6f/0x4a0 [bcachefs]
[34987.988819]   [<0>] bch2_btree_node_rewrite_pos+0xa2/0xe0 [bcachefs]
[34987.988820]   [<0>] __bch2_move_data_phys+0x899/0xce0 [bcachefs]
[34987.988820]   [<0>] bch2_evacuate_bucket+0xcc/0x130 [bcachefs]
[34987.988821]   [<0>] bch2_copygc+0x113/0x350 [bcachefs]
[34987.988821]   [<0>] bch2_copygc_thread+0x309/0x560 [bcachefs]
[34987.988822]   [<0>] kthread+0xfb/0x250
[34987.988822]   [<0>] ret_from_fork+0x199/0x1d0
[34987.988823]   [<0>] ret_from_fork_asm+0x1a/0x30

[34987.988824] Journal debug:
[34987.988824]   flags:                   replay_done,running,may_skip_flush
[34987.988825]   dirty journal entries:   3076/32768
[34987.988825]   seq:                     4861864
[34987.988826]   seq_ondisk:              4861864
[34987.988826]   last_seq:                4858789
[34987.988827]   last_seq_ondisk:         4858787
[34987.988827]   flushed_seq_ondisk:      4861864
[34987.988828]   watermark:               stripe
[34987.988828]   each entry reserved:     321
[34987.988829]   nr flush writes:         27495
[34987.988829]   nr noflush writes:       14761
[34987.988830]   average write size:      272 KiB
[34987.988830]   free buf:                524288
[34987.988831]   nr direct reclaim:       0
[34987.988831]   nr background reclaim:   1054927
[34987.988831]   reclaim kicked:          0
[34987.988832]   reclaim runs in:         20 ms
[34987.988832]   blocked:                 0
[34987.988833]   current entry sectors:   881
[34987.988833]   current entry error:     (No error)
[34987.988834]   current entry:           closed
[34987.988834]   unwritten entries:
[34987.988835]   last buf closed
[34987.988836]   space:
[34987.988836]     discarded              881:903025
[34987.988837]     clean ondisk           881:3001076
[34987.988837]     clean                  881:3001076
[34987.988838]     total                  881:3001076
[34987.988838]   dev 0:
[34987.988839]   durability 1:
[34987.988839]     nr                     8192
[34987.988840]     bucket size            881
[34987.988840]     available              1025:152
[34987.988841]     discard_idx            7025
[34987.988841]     dirty_ondisk           3344 (seq 4858787)
[34987.988842]     dirty_idx              3346 (seq 4858789)
[34987.988842]     cur_idx                5999 (seq 4861864)
[34987.988843]   replicas want 1 need 1
[34988.101174]     nr                     8192
[34988.101578]     bucket size            881
[34988.102022]     available              1025:152
[34988.102447]     discard_idx            7025
[34988.102804]     dirty_ondisk           3344 (seq 4858787)
[34988.103238]     dirty_idx              3346 (seq 4858789)
[34988.103688]     cur_idx                5999 (seq 4861864)
[34988.104211]   replicas want 1 need 1
[35164.512582] ------------[ cut here ]------------
[35164.512586] btree trans held srcu lock (delaying memory reclaim) for 1203 seconds
[35164.512603] WARNING: CPU: 0 PID: 1819 at src/fs/bcachefs/btree_iter.c:3331 bch2_trans_srcu_unlock+0x11b/0x130 [bcachefs]
[35164.512672] Modules linked in: bcachefs(O) chacha_x86_64 libchacha libpoly1305 poly1305_x86_64 lz4hc_compress lz4_compress xor raid6_pq qrtr snd_seq_dummy snd_hrtimer snd_seq snd_seq_device af_packet rfkill nls_iso8859_1 nls_cp437 vfat fat snd_hda_codec_generic snd_hda_intel snd_intel_dspcfg intel_rapl_msr snd_intel_sdw_acpi iTCO_wdt intel_pmc_bxt watchdog xt_conntrack snd_hda_codec nf_conntrack snd_hda_core nf_defrag_ipv6 nf_defrag_ipv4 snd_hwdep edac_core snd_pcm intel_rapl_common polyval_clmulni ghash_clmulni_intel sha512_ssse3 sha1_ssse3 i2c_i801 psmouse aesni_intel i2c_smbus i2c_mux snd_timer ip6t_rpfilter ipt_rpfilter snd soundcore joydev lpc_ich mousedev rtc_cmos evdev xt_pkttype intel_agp tiny_power_button xt_LOG nf_log_syslog input_leds intel_gtt button led_class nft_compat mac_hid serio_raw nf_tables sch_fq_codel loop kvm_amd ccp kvm irqbypass fuse efi_pstore configfs nfnetlink efivarfs dmi_sysfs qemu_fw_cfg autofs4 ext4 crc16 mbcache jbd2 hid_generic usbhid hid sr_mod cdrom virtio_net net_failover failover
[35164.512721]  virtio_blk virtio_scsi ahci libahci libata atkbd libps2 vivaldi_fmap xhci_pci xhci_hcd scsi_mod scsi_common virtio_pci virtio_pci_legacy_dev virtio_pci_modern_dev i8042 serio virtio_rng rng_core virtio_gpu virtio_dma_buf virtio_console virtio_balloon virtio virtio_ring dm_mod dax
[35164.512736] CPU: 0 UID: 0 PID: 1819 Comm: bch-copygc/vdb2 Tainted: G        W  O        6.16.9 #1-NixOS PREEMPT(voluntary)
[35164.512740] Tainted: [W]=WARN, [O]=OOT_MODULE
[35164.512740] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS edk2-stable202408-prebuilt.qemu.org 08/13/2024
[35164.512742] RIP: 0010:bch2_trans_srcu_unlock+0x11b/0x130 [bcachefs]
[35164.512799] Code: bc d6 48 c7 c7 d8 0a 38 c1 48 b9 cf f7 53 e3 a5 9b c4 20 48 29 d0 48 c1 e8 03 48 f7 e1 48 89 d6 48 c1 ee 04 e8 56 2f ec d4 90 <0f> 0b 90 90 eb 9f 90 0f 0b 90 eb ab 66 0f 1f 84 00 00 00 00 00 90
[35164.512801] RSP: 0018:ffffcebc83e437e8 EFLAGS: 00010282
[35164.512803] RAX: 0000000000000000 RBX: ffff8d0d08ba8000 RCX: 0000000000000027
[35164.512804] RDX: ffff8d0ef5c1e408 RSI: 0000000000000001 RDI: ffff8d0ef5c1e400
[35164.512805] RBP: ffff8d0d85e40000 R08: 0000000000000000 R09: ffffcebc83e43678
[35164.512806] R10: ffffffff98110a28 R11: 0000000000000003 R12: 0000000000000000
[35164.512807] R13: ffff8d0d075f0800 R14: ffff8d0d08ba8000 R15: ffff8d0d08ba8000
[35164.512809] FS:  0000000000000000(0000) GS:ffff8d0f5d14f000(0000) knlGS:0000000000000000
[35164.512811] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[35164.512812] CR2: 00007f3104a20000 CR3: 00000001240ac000 CR4: 0000000000350ef0
[35164.512815] Call Trace:
[35164.512817]  <TASK>
[35164.512820]  ? bch2_trans_begin+0xc3/0x8e0 [bcachefs]
[35164.512865]  bch2_trans_begin+0x50a/0x8e0 [bcachefs]
[35164.512910]  ? bch2_move_ratelimit+0x29f/0x560 [bcachefs]
[35164.512969]  __bch2_move_data_phys+0x2bf/0xce0 [bcachefs]
[35164.513019]  ? __pfx_evacuate_bucket_pred+0x10/0x10 [bcachefs]
[35164.513072]  ? bch2_evacuate_bucket+0xcc/0x130 [bcachefs]
[35164.513117]  bch2_evacuate_bucket+0xcc/0x130 [bcachefs]
[35164.513161]  ? __pfx_evacuate_bucket_pred+0x10/0x10 [bcachefs]
[35164.513205]  bch2_copygc+0x113/0x350 [bcachefs]
[35164.513250]  bch2_copygc_thread+0x309/0x560 [bcachefs]
[35164.513294]  ? bch2_copygc_thread+0x28f/0x560 [bcachefs]
[35164.513339]  ? __pfx_bch2_copygc_thread+0x10/0x10 [bcachefs]
[35164.513380]  kthread+0xfb/0x250
[35164.513384]  ? __pfx_kthread+0x10/0x10
[35164.513386]  ret_from_fork+0x199/0x1d0
[35164.513388]  ? __pfx_kthread+0x10/0x10
[35164.513389]  ret_from_fork_asm+0x1a/0x30
[35164.513393]  </TASK>
[35164.513394] ---[ end trace 0000000000000000 ]---
[35167.735106] ------------[ cut here ]------------
[35167.735109] btree trans held srcu lock (delaying memory reclaim) for 2077 seconds
[35167.735124] WARNING: CPU: 2 PID: 445 at src/fs/bcachefs/btree_iter.c:3331 bch2_trans_srcu_unlock+0x11b/0x130 [bcachefs]
[35167.735186] Modules linked in: bcachefs(O) chacha_x86_64 libchacha libpoly1305 poly1305_x86_64 lz4hc_compress lz4_compress xor raid6_pq qrtr snd_seq_dummy snd_hrtimer snd_seq snd_seq_device af_packet rfkill nls_iso8859_1 nls_cp437 vfat fat snd_hda_codec_generic snd_hda_intel snd_intel_dspcfg intel_rapl_msr snd_intel_sdw_acpi iTCO_wdt intel_pmc_bxt watchdog xt_conntrack snd_hda_codec nf_conntrack snd_hda_core nf_defrag_ipv6 nf_defrag_ipv4 snd_hwdep edac_core snd_pcm intel_rapl_common polyval_clmulni ghash_clmulni_intel sha512_ssse3 sha1_ssse3 i2c_i801 psmouse aesni_intel i2c_smbus i2c_mux snd_timer ip6t_rpfilter ipt_rpfilter snd soundcore joydev lpc_ich mousedev rtc_cmos evdev xt_pkttype intel_agp tiny_power_button xt_LOG nf_log_syslog input_leds intel_gtt button led_class nft_compat mac_hid serio_raw nf_tables sch_fq_codel loop kvm_amd ccp kvm irqbypass fuse efi_pstore configfs nfnetlink efivarfs dmi_sysfs qemu_fw_cfg autofs4 ext4 crc16 mbcache jbd2 hid_generic usbhid hid sr_mod cdrom virtio_net net_failover failover
[35167.735234]  virtio_blk virtio_scsi ahci libahci libata atkbd libps2 vivaldi_fmap xhci_pci xhci_hcd scsi_mod scsi_common virtio_pci virtio_pci_legacy_dev virtio_pci_modern_dev i8042 serio virtio_rng rng_core virtio_gpu virtio_dma_buf virtio_console virtio_balloon virtio virtio_ring dm_mod dax
[35167.735250] CPU: 2 UID: 0 PID: 445 Comm: kworker/2:4 Tainted: G        W  O        6.16.9 #1-NixOS PREEMPT(voluntary)
[35167.735253] Tainted: [W]=WARN, [O]=OOT_MODULE
[35167.735254] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS edk2-stable202408-prebuilt.qemu.org 08/13/2024
[35167.735255] Workqueue: bcachefs_write_ref bch2_do_discards_work [bcachefs]
[35167.735303] RIP: 0010:bch2_trans_srcu_unlock+0x11b/0x130 [bcachefs]
[35167.735349] Code: bc d6 48 c7 c7 d8 0a 38 c1 48 b9 cf f7 53 e3 a5 9b c4 20 48 29 d0 48 c1 e8 03 48 f7 e1 48 89 d6 48 c1 ee 04 e8 56 2f ec d4 90 <0f> 0b 90 90 eb 9f 90 0f 0b 90 eb ab 66 0f 1f 84 00 00 00 00 00 90
[35167.735350] RSP: 0018:ffffcebc803a3c50 EFLAGS: 00010286
[35167.735352] RAX: 0000000000000000 RBX: ffff8d0d74c74000 RCX: 0000000000000027
[35167.735353] RDX: ffff8d0ef5d1e408 RSI: 0000000000000001 RDI: ffff8d0ef5d1e400
[35167.735354] RBP: ffff8d0d85e40000 R08: 0000000000000000 R09: ffffcebc803a3ae0
[35167.735355] R10: ffffffff98110a28 R11: 0000000000000003 R12: ffff8d0d74c74000
[35167.735356] R13: ffffcebc803a3d78 R14: ffff8d0d74c74000 R15: 00000000fffff778
[35167.735359] FS:  0000000000000000(0000) GS:ffff8d0f5d24f000(0000) knlGS:0000000000000000
[35167.735360] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[35167.735361] CR2: 00007f3104a20000 CR3: 000000010625a000 CR4: 0000000000350ef0
[35167.735363] Call Trace:
[35167.735365]  <TASK>
[35167.735367]  ? bch2_trans_begin+0xc3/0x8e0 [bcachefs]
[35167.735411]  bch2_trans_begin+0x50a/0x8e0 [bcachefs]
[35167.735468]  __bch2_dev_do_discards+0xfc/0x310 [bcachefs]
[35167.735515]  bch2_do_discards_work+0x1d/0x60 [bcachefs]
[35167.735557]  process_one_work+0x18d/0x340
[35167.735561]  worker_thread+0x225/0x360
[35167.735563]  ? __pfx_worker_thread+0x10/0x10
[35167.735565]  kthread+0xfb/0x250
[35167.735567]  ? __pfx_kthread+0x10/0x10
[35167.735569]  ? _raw_spin_unlock+0xe/0x30
[35167.735571]  ? finish_task_switch.isra.0+0x99/0x2e0
[35167.735574]  ? __pfx_kthread+0x10/0x10
[35167.735575]  ? __pfx_kthread+0x10/0x10
[35167.735577]  ret_from_fork+0x199/0x1d0
[35167.735579]  ? __pfx_kthread+0x10/0x10
[35167.735581]  ret_from_fork_asm+0x1a/0x30
[35167.735584]  </TASK>
[35167.735585] ---[ end trace 0000000000000000 ]---
[35244.496257] Allocator stuck? Waited for 30 seconds
[35244.496260] Allocator debug:
[35244.496261]   capacity849891820
[35244.496261]   used                 833188184
[35244.496262]   reserved             73903636
[35244.496262]   hidden               7221557
[35244.496263]   btree                20343808
[35244.496263]   data                 811177914
[35244.496263]   cached               0
[35244.496264]   reserved             519032
[35244.496264]   online_reserved      1121792
[35244.496265]
[35244.496265]   freelist_wait        waiting
[35244.496265]   open buckets allocated2
[35244.496266]   open buckets total   1024
[35244.496266]   open_buckets_wait    empty
[35244.496266]   open_buckets_btree   0
[35244.496267]   open_buckets_user    1
[35244.496267] Allocator stuck? Waited for 30 seconds
[35244.496267]   btree reserve cache  0

[35244.496268] Dev 0:
[35244.496269]                      buckets         sectors      fragmented
[35244.496269] Allocator debug:
[35244.496270]   free                    29               0               0
[35244.496270]   capacity849891820
[35244.496270]   sb                       5            4104             301
[35244.496270]   used                 833188184
[35244.496271]   journal               8192         7217152               0
[35244.496271]   reserved             73903636
[35244.496271]   btree                39734        20343808        14661846
[35244.496271]   hidden               7221557
[35244.496272]   user                926297       811177914         4889743
[35244.496272]   btree                20343808
[35244.496272]   cached                   0               0               0
[35244.496272]   data                 811177914
[35244.496273]   parity                   0               0               0
[35244.496273]   cached               0
[35244.496274]   reserved             519032
[35244.496274]   stripe                   0               0               0
[35244.496274]   online_reserved      1121792
[35244.496274]   need_gc_gens             0               0               0
[35244.496275]
[35244.496275]   need_discard         74319               0               0
[35244.496275]   freelist_wait        waiting
[35244.496275]   unstriped                0               0               0
[35244.496275]   open buckets allocated2
[35244.496276]   capacity           1048576
[35244.496276]   open buckets total   1024
[35244.496276]
[35244.496277]   open_buckets_wait    empty
[35244.496277]   reserves:
[35244.496277]   open_buckets_btree   0
[35244.496277]   stripe               32824
[35244.496278]   open_buckets_user    1
[35244.496278]   normal               16440
[35244.496278]   btree reserve cache  0
[35244.496278]   copygc                  56

[35244.496279]   btree                   28
[35244.496279] Dev 0:
[35244.496280]   btree_copygc             0
[35244.496280]                      buckets         sectors      fragmented
[35244.496280]   reclaim                  0
[35244.496280]   free                    29               0               0
[35244.496281]   interior_updates         0
[35244.496281]
[35244.496281]   sb                       5            4104             301
[35244.496281]   open buckets             1
[35244.496282]   journal               8192         7217152               0
[35244.496282]   buckets to invalidate    0

[35244.496282]   btree                39734        20343808        14661846
[35244.496283] Copygc debug:
[35244.496283]   user                926297       811177914         4889743
[35244.496283]   running: 1
[35244.496284]   cached                   0               0               0
[35244.496284]   copygc_wait:0
[35244.496284]   copygc_wait_at:0
[35244.496284]   parity                   0               0               0
[35244.496285]   stripe                   0               0               0
[35244.496285]   Currently waiting for:0 B
[35244.496286]   Currently waiting since:25.1 TiB
[35244.496286]   need_gc_gens             0               0               0
[35244.496287]   Currently calculated wait:
[35244.496287]   need_discard         74319               0               0
[35244.496287]     vdb2:  0 B
[35244.496287]   unstriped                0               0               0

[35244.496288]   capacity           1048576
[35244.496288] Journal debug:
[35244.496288]
[35244.496289]   flags:                   replay_done,running,may_skip_flush
[35244.496289]   reserves:
[35244.496289]   dirty journal entries:   2419/32768
[35244.496289]   stripe               32824
[35244.496290]   seq:                     4861874
[35244.496290]   normal               16440
[35244.496290]   seq_ondisk:              4861874
[35244.496290]   copygc                  56
[35244.496291]   last_seq:                4859456
[35244.496291]   btree                   28
[35244.496291]   last_seq_ondisk:         4859437
[35244.496291]   btree_copygc             0
[35244.496292]   flushed_seq_ondisk:      4861874
[35244.496292]   reclaim                  0
[35244.496292]   watermark:               stripe
[35244.496292]   interior_updates         0
[35244.496293]   each entry reserved:     321
[35244.496293]
[35244.496293]   nr flush writes:         27505
[35244.496293]   open buckets             1
[35244.496294]   buckets to invalidate    0
[35244.496294]   nr noflush writes:       14761

[35244.496294]   average write size:      272 KiB
[35244.496295] Copygc debug:
[35244.496295]   free buf:                524288
[35244.496295]   running: 1
[35244.496296]   nr direct reclaim:       0
[35244.496296]   copygc_wait:0
[35244.496296]   nr background reclaim:   1057394
[35244.496296]   copygc_wait_at:0
[35244.496297]   reclaim kicked:          0
[35244.496297]   Currently waiting for:0 B
[35244.496297]   reclaim runs in:         76 ms
[35244.496297]   Currently waiting since:25.1 TiB
[35244.496298]   blocked:                 0
[35244.496298]   Currently calculated wait:
[35244.496298]   current entry sectors:   881
[35244.496298]     vdb2:  0 B
[35244.496299]   current entry error:     (No error)

[35244.496299]   current entry:           closed
[35244.496299] Journal debug:
[35244.496300]   unwritten entries:
[35244.496300]   flags:                   replay_done,running,may_skip_flush
[35244.496300]   last buf closed
[35244.496300]   dirty journal entries:   2419/32768
[35244.496300]   space:
[35244.496301]   seq:                     4861874
[35244.496301]     discarded              881:903025
[35244.496301]   seq_ondisk:              4861874
[35244.496302]     clean ondisk           881:3458037
[35244.496302]   last_seq:                4859456
[35244.496302]     clean                  881:3458037
[35244.496302]   last_seq_ondisk:         4859437
[35244.496303]     total                  881:3458037
[35244.496303]   flushed_seq_ondisk:      4861874
[35244.496303]   dev 0:
[35244.496303]   watermark:               stripe
[35244.496304]   durability 1:
[35244.496304]   each entry reserved:     321
[35244.496304]     nr                     8192
[35244.496305]   nr flush writes:         27505
[35244.496305]     bucket size            881
[35244.496305]   nr noflush writes:       14761
[35244.496305]     available              1025:96
[35244.496305]   average write size:      272 KiB
[35244.496306]     discard_idx            7025
[35244.496306]   free buf:                524288
[35244.496306]     dirty_ondisk           3896 (seq 4859437)
[35244.496306]   nr direct reclaim:       0
[35244.496307]     dirty_idx              3914 (seq 4859456)
[35244.496307]   nr background reclaim:   1057394
[35244.496307]     cur_idx                5999 (seq 4861874)
[35244.496308]   reclaim kicked:          0
[35244.496308]   replicas want 1 need 1
[35244.496308]   reclaim runs in:         76 ms
[35244.496308]   blocked:                 0
[35244.496309]   current entry sectors:   881
[35244.496309]   current entry error:     (No error)
[35244.496637] Allocator stuck? Waited for 30 seconds
[35244.496639] Allocator debug:
[35244.496640]   capacity849891820
[35244.496641]   used                 833188184
[35244.496642]   reserved             73903636
[35244.496642]   hidden               7221557
[35244.496643]   btree                20343808
[35244.496644]   data                 811177914
[35244.496644]   cached               0
[35244.496645]   reserved             519032
[35244.496646]   online_reserved      1121792
[35244.496646]
[35244.496647]   freelist_wait        waiting
[35244.496648]   open buckets allocated2
[35244.496648]   open buckets total   1024
[35244.496649]   open_buckets_wait    empty
[35244.496649]   open_buckets_btree   0
[35244.496650]   open_buckets_user    1
[35244.496651]   btree reserve cache  0

[35244.496652] Dev 0:
[35244.496652]                      buckets         sectors      fragmented
[35244.496653]   free                    29               0               0
[35244.496654]   sb                       5            4104             301
[35244.496655]   journal               8192         7217152               0
[35244.496655]   btree                39734        20343808        14661846
[35244.496656]   user                926297       811177914         4889743
[35244.496657]   cached                   0               0               0
[35244.496658]   parity                   0               0               0
[35244.496658]   stripe                   0               0               0
[35244.496659]   need_gc_gens             0               0               0
[35244.496660]   need_discard         74319               0               0
[35244.496660]   unstriped                0               0               0
[35244.496661]   capacity           1048576
[35244.496661]
[35244.496662]   reserves:
[35244.496663]   stripe               32824
[35244.496663]   normal               16440
[35244.496664]   copygc                  56
[35244.496664]   btree                   28
[35244.496665]   btree_copygc             0
[35244.496666]   reclaim                  0
[35244.496666]   interior_updates         0
[35244.496667]
[35244.496667]   open buckets             1
[35244.496668]   buckets to invalidate    0

[35244.496669] Copygc debug:
[35244.496670]   running: 1
[35244.496670]   copygc_wait:0
[35244.496671]   copygc_wait_at:0
[35244.496671]   Currently waiting for:0 B
[35244.496672]   Currently waiting since:25.1 TiB
[35244.496673]   Currently calculated wait:
[35244.496673]     vdb2:  0 B
[35244.496674]   [<0>] bch2_copygc_wait_to_text+0x1ad/0x2c0 [bcachefs]
[35244.496675]   [<0>] bch2_print_allocator_stuck+0x11c/0x240 [bcachefs]
[35244.496675]   [<0>] __bch2_wait_on_allocator+0x9f/0xc0 [bcachefs]
[35244.496676]   [<0>] bch2_btree_update_start+0x74c/0xa40 [bcachefs]
[35244.496677]   [<0>] bch2_btree_node_rewrite+0x6f/0x4a0 [bcachefs]
[35244.496677]   [<0>] bch2_btree_node_rewrite_pos+0xa2/0xe0 [bcachefs]
[35244.496678]   [<0>] __bch2_move_data_phys+0x899/0xce0 [bcachefs]
[35244.496679]   [<0>] bch2_evacuate_bucket+0xcc/0x130 [bcachefs]
[35244.496679]   [<0>] bch2_copygc+0x113/0x350 [bcachefs]
[35244.496680]   [<0>] bch2_copygc_thread+0x309/0x560 [bcachefs]
[35244.496681]   [<0>] kthread+0xfb/0x250
[35244.496681]   [<0>] ret_from_fork+0x199/0x1d0
[35244.496682]   [<0>] ret_from_fork_asm+0x1a/0x30

[35244.496683] Journal debug:
[35244.496684]   flags:                   replay_done,running,may_skip_flush
[35244.496684]   dirty journal entries:   2419/32768
[35244.496685]   seq:                     4861874
[35244.496686]   seq_ondisk:              4861874
[35244.496686]   last_seq:                4859456
[35244.496687]   last_seq_ondisk:         4859437
[35244.496687]   flushed_seq_ondisk:      4861874
[35244.496688]   watermark:               stripe
[35244.496689]   each entry reserved:     321
[35244.496689]   nr flush writes:         27505
[35244.496690]   nr noflush writes:       14761
[35244.496690]   average write size:      272 KiB
[35244.496691]   free buf:                524288
[35244.496692]   nr direct reclaim:       0
[35244.496692]   nr background reclaim:   1057394
[35244.496693]   reclaim kicked:          0
[35244.496693]   reclaim runs in:         76 ms
[35244.496694]   blocked:                 0
[35244.496695]   current entry sectors:   881
[35244.496695]   current entry error:     (No error)
[35244.496696]   current entry:           closed
[35244.496697]   unwritten entries:
[35244.496697]   last buf closed
[35244.496698]   space:
[35244.496698]     discarded              881:903025
[35244.496699]     clean ondisk           881:3458037
[35244.496700]     clean                  881:3458037
[35244.496700]     total                  881:3458037
[35244.496701]   dev 0:
[35244.496702]   durability 1:
[35244.496702]     nr                     8192
[35244.496703]     bucket size            881
[35244.496704]     available              1025:96
[35244.496704]     discard_idx            7025
[35244.496705]     dirty_ondisk           3896 (seq 4859437)
[35244.496705]     dirty_idx              3914 (seq 4859456)
[35244.496706]     cur_idx                5999 (seq 4861874)
[35244.496707]   replicas want 1 need 1
[35244.614207]   current entry:           closed
[35244.614743]   unwritten entries:
[35244.615099]   last buf closed
[35244.615441]   space:
[35244.615695]     discarded              881:903025
[35244.616214]     clean ondisk           881:3458037
[35244.616786]     clean                  881:3458037
[35244.617311]     total                  881:3458037
[35244.617831]   dev 0:
[35244.618078]   durability 1:
[35244.618402]     nr                     8192
[35244.618916]     bucket size            881
[35244.619367]     available              1025:96
[35244.619790]     discard_idx            7025
[35244.620117]     dirty_ondisk           3896 (seq 4859437)
[35244.620561]     dirty_idx              3914 (seq 4859456)
[35244.621076]     cur_idx                5999 (seq 4861874)
[35244.621517]   replicas want 1 need 1
[35412.429535] Allocator stuck? Waited for 30 seconds
[35412.429538] Allocator debug:
[35412.429539]   capacity849891820
[35412.429539]   used                 833188184
[35412.429539]   reserved             73903636
[35412.429540]   hidden               7221557
[35412.429540]   btree                20343808
[35412.429541]   data                 811177914
[35412.429541]   cached               0
[35412.429542]   reserved             519032
[35412.429542]   online_reserved      1121792
[35412.429542]
[35412.429543]   freelist_wait        waiting
[35412.429543]   open buckets allocated2
[35412.429543]   open buckets total   1024
[35412.429544]   open_buckets_wait    empty
[35412.429544]   open_buckets_btree   0
[35412.429545]   open_buckets_user    1
[35412.429545]   btree reserve cache  0

[35412.429546] Dev 0:
[35412.429546]                      buckets         sectors      fragmented
[35412.429547]   free                    29               0               0
[35412.429547]   sb                       5            4104             301
[35412.429547]   journal               8192         7217152               0
[35412.429548]   btree                39734        20343808        14661846
[35412.429548]   user                926297       811177914         4889743
[35412.429549]   cached                   0               0               0
[35412.429549]   parity                   0               0               0
[35412.429550]   stripe                   0               0               0
[35412.429550]   need_gc_gens             0               0               0
[35412.429550] Allocator stuck? Waited for 30 seconds
[35412.429551]   need_discard         74319               0               0
[35412.429551]   unstriped                0               0               0
[35412.429552]   capacity           1048576
[35412.429552]
[35412.429552] Allocator debug:
[35412.429553]   reserves:
[35412.429553]   stripe               32824
[35412.429553]   capacity849891820
[35412.429554]   normal               16440
[35412.429554]   copygc                  56
[35412.429554]   used                 833188184
[35412.429555]   btree                   28
[35412.429555]   btree_copygc             0
[35412.429555]   reserved             73903636
[35412.429556]   reclaim                  0
[35412.429556]   interior_updates         0
[35412.429557]   hidden               7221557
[35412.429557]
[35412.429557]   open buckets             1
[35412.429557]   btree                20343808
[35412.429558]   buckets to invalidate    0

[35412.429559]   data                 811177914
[35412.429559] Copygc debug:
[35412.429559]   running: 1
[35412.429560]   cached               0
[35412.429560]   copygc_wait:0
[35412.429560]   copygc_wait_at:0
[35412.429560]   reserved             519032
[35412.429561]   Currently waiting for:0 B
[35412.429561]   online_reserved      1121792
[35412.429561]   Currently waiting since:25.1 TiB
[35412.429562]   Currently calculated wait:
[35412.429562]
[35412.429562]     vdb2:  0 B
[35412.429563]   freelist_wait        waiting

[35412.429563] Journal debug:
[35412.429564]   open buckets allocated2
[35412.429564]   flags:                   replay_done,running,may_skip_flush
[35412.429564]   open buckets total   1024
[35412.429564]   dirty journal entries:   2303/32768
[35412.429565]   seq:                     4861951
[35412.429565]   open_buckets_wait    empty
[35412.429565]   seq_ondisk:              4861951
[35412.429566]   open_buckets_btree   0
[35412.429566]   last_seq:                4859649
[35412.429566]   last_seq_ondisk:         4859636
[35412.429567]   open_buckets_user    1
[35412.429567]   flushed_seq_ondisk:      4861951
[35412.429568]   watermark:               stripe
[35412.429568]   btree reserve cache  0
[35412.429568]   each entry reserved:     321

[35412.429568]   nr flush writes:         27582
[35412.429569] Dev 0:
[35412.429569]   nr noflush writes:       14761
[35412.429569]   average write size:      271 KiB
[35412.429570]                      buckets         sectors      fragmented
[35412.429570]   free buf:                524288
[35412.429570]   nr direct reclaim:       0
[35412.429571]   free                    29               0               0
[35412.429571]   nr background reclaim:   1059008
[35412.429571]   reclaim kicked:          0
[35412.429572]   sb                       5            4104             301
[35412.429572]   reclaim runs in:         0 ms
[35412.429572]   blocked:                 0
[35412.429573]   journal               8192         7217152               0
[35412.429573]   current entry sectors:   881
[35412.429573]   current entry error:     (No error)
[35412.429573]   btree                39734        20343808        14661846
[35412.429574]   current entry:           closed
[35412.429574]   unwritten entries:
[35412.429574]   user                926297       811177914         4889743
[35412.429575]   last buf closed
[35412.429575]   space:
[35412.429576]     discarded              881:903025
[35412.429576]   cached                   0               0               0
[35412.429576]     clean ondisk           881:3598799
[35412.429577]   parity                   0               0               0
[35412.429577]     clean                  881:3598799
[35412.429578]     total                  881:3598799
[35412.429578]   stripe                   0               0               0
[35412.429578]   dev 0:
[35412.429578]   durability 1:
[35412.429579]   need_gc_gens             0               0               0
[35412.429579]     nr                     8192
[35412.429580]     bucket size            881
[35412.429580]   need_discard         74319               0               0
[35412.429580]     available              1025:393
[35412.429581]     discard_idx            7026
[35412.429581]   unstriped                0               0               0
[35412.429581]     dirty_ondisk           4086 (seq 4859636)
[35412.429582]     dirty_idx              4098 (seq 4859649)
[35412.429582]   capacity           1048576
[35412.429582]     cur_idx                6000 (seq 4861951)
[35412.429582]
[35412.429583]   replicas want 1 need 1
[35412.429583]   reserves:
[35412.429584]   stripe               32824
[35412.429585]   normal               16440
[35412.429872] Allocator stuck? Waited for 30 seconds
[35412.429873] Allocator debug:
[35412.429874]   capacity849891820
[35412.429874]   used                 833188184
[35412.429875]   reserved             73903636
[35412.429875]   hidden               7221557
[35412.429876]   btree                20343808
[35412.429887]   data                 811177914
[35412.429888]   cached               0
[35412.429889]   reserved             519032
[35412.429889]   online_reserved      1121792
[35412.429890]
[35412.429890]   freelist_wait        waiting
[35412.429891]   open buckets allocated2
[35412.429891]   open buckets total   1024
[35412.429891]   open_buckets_wait    empty
[35412.429892]   open_buckets_btree   0
[35412.429892]   open_buckets_user    1
[35412.429893]   btree reserve cache  0

[35412.429894] Dev 0:
[35412.429894]                      buckets         sectors      fragmented
[35412.429895]   free                    29               0               0
[35412.429896]   sb                       5            4104             301
[35412.429896]   journal               8192         7217152               0
[35412.429897]   btree                39734        20343808        14661846
[35412.429897]   user                926297       811177914         4889743
[35412.429898]   cached                   0               0               0
[35412.429898]   parity                   0               0               0
[35412.429899]   stripe                   0               0               0
[35412.429900]   need_gc_gens             0               0               0
[35412.429900]   need_discard         74319               0               0
[35412.429901]   unstriped                0               0               0
[35412.429901]   capacity           1048576
[35412.429902]
[35412.429902]   reserves:
[35412.429903]   stripe               32824
[35412.429903]   normal               16440
[35412.429904]   copygc                  56
[35412.429904]   btree                   28
[35412.429905]   btree_copygc             0
[35412.429905]   reclaim                  0
[35412.429905]   interior_updates         0
[35412.429906]
[35412.429906]   open buckets             1
[35412.429907]   buckets to invalidate    0

[35412.429908] Copygc debug:
[35412.429908]   running: 1
[35412.429909]   copygc_wait:0
[35412.429909]   copygc_wait_at:0
[35412.429910]   Currently waiting for:0 B
[35412.429910]   Currently waiting since:25.1 TiB
[35412.429911]   Currently calculated wait:
[35412.429911]     vdb2:  0 B
[35412.429912]   [<0>] bch2_copygc_wait_to_text+0x1ad/0x2c0 [bcachefs]
[35412.429912]   [<0>] bch2_print_allocator_stuck+0x11c/0x240 [bcachefs]
[35412.429913]   [<0>] __bch2_wait_on_allocator+0x9f/0xc0 [bcachefs]
[35412.429913]   [<0>] bch2_btree_update_start+0x74c/0xa40 [bcachefs]
[35412.429914]   [<0>] bch2_btree_node_rewrite+0x6f/0x4a0 [bcachefs]
[35412.429914]   [<0>] bch2_btree_node_rewrite_pos+0xa2/0xe0 [bcachefs]
[35412.429915]   [<0>] __bch2_move_data_phys+0x899/0xce0 [bcachefs]
[35412.429916]   [<0>] bch2_evacuate_bucket+0xcc/0x130 [bcachefs]
[35412.429916]   [<0>] bch2_copygc+0x113/0x350 [bcachefs]
[35412.429917]   [<0>] bch2_copygc_thread+0x309/0x560 [bcachefs]
[35412.429917]   [<0>] kthread+0xfb/0x250
[35412.429918]   [<0>] ret_from_fork+0x199/0x1d0
[35412.429918]   [<0>] ret_from_fork_asm+0x1a/0x30

[35412.429919] Journal debug:
[35412.429920]   flags:                   replay_done,running,may_skip_flush
[35412.429920]   dirty journal entries:   2303/32768
[35412.429921]   seq:                     4861951
[35412.429921]   seq_ondisk:              4861951
[35412.429922]   last_seq:                4859649
[35412.429922]   last_seq_ondisk:         4859636
[35412.429923]   flushed_seq_ondisk:      4861951
[35412.429923]   watermark:               stripe
[35412.429924]   each entry reserved:     321
[35412.429924]   nr flush writes:         27582
[35412.429925]   nr noflush writes:       14761
[35412.429925]   average write size:      271 KiB
[35412.429926]   free buf:                524288
[35412.429926]   nr direct reclaim:       0
[35412.429926]   nr background reclaim:   1059008
[35412.429927]   reclaim kicked:          0
[35412.429927]   reclaim runs in:         0 ms
[35412.429928]   blocked:                 0
[35412.429928]   current entry sectors:   881
[35412.429929]   current entry error:     (No error)
[35412.429929]   current entry:           closed
[35412.429930]   unwritten entries:
[35412.429930]   last buf closed
[35412.429931]   space:
[35412.429931]     discarded              881:903025
[35412.429932]     clean ondisk           881:3598799
[35412.429932]     clean                  881:3598799
[35412.429933]     total                  881:3598799
[35412.429933]   dev 0:
[35412.429934]   durability 1:
[35412.429934]     nr                     8192
[35412.429935]     bucket size            881
[35412.429935]     available              1025:393
[35412.429936]     discard_idx            7026
[35412.429936]     dirty_ondisk           4086 (seq 4859636)
[35412.429937]     dirty_idx              4098 (seq 4859649)
[35412.429937]     cur_idx                6000 (seq 4861951)
[35412.429938]   replicas want 1 need 1
[35412.529925]   copygc                  56
[35412.530351]   btree                   28
[35412.530794]   btree_copygc             0
[35412.531301]   reclaim                  0
[35412.531714]   interior_updates         0
[35412.532135]
[35412.532329]   open buckets             1
[35412.532773]   buckets to invalidate    0

[35412.533484] Copygc debug:
[35412.533777]   running: 1
[35412.534069]   copygc_wait:0
[35412.534379]   copygc_wait_at:0
[35412.534733]   Currently waiting for:0 B
[35412.535167]   Currently waiting since:25.1 TiB
[35412.535741]   Currently calculated wait:
[35412.536180]     vdb2:  0 B

[35412.536722] Journal debug:
[35412.537048]   flags:                   replay_done,running,may_skip_flush
[35412.537785]   dirty journal entries:   2303/32768
[35412.538305]   seq:                     4861951
[35412.538802]   seq_ondisk:              4861951
[35412.539373]   last_seq:                4859649
[35412.539867]   last_seq_ondisk:         4859636
[35412.540355]   flushed_seq_ondisk:      4861951
[35412.540851]   watermark:               stripe
[35412.541401]   each entry reserved:     321
[35412.541839]   nr flush writes:         27582
[35412.542296]   nr noflush writes:       14761
[35412.542753]   average write size:      271 KiB
[35412.543267]   free buf:                524288
[35412.543731]   nr direct reclaim:       0
[35412.544154]   nr background reclaim:   1059008
[35412.544631]   reclaim kicked:          0
[35412.545085]   reclaim runs in:         0 ms
[35412.545533]   blocked:                 0
[35412.545945]   current entry sectors:   881
[35412.546369]   current entry error:     (No error)
[35412.546870]   current entry:           closed
[35412.547370]   unwritten entries:
[35412.547722]   last buf closed
[35412.548046]   space:
[35412.548281]     discarded              881:903025
[35412.548781]     clean ondisk           881:3598799
[35412.549270]     clean                  881:3598799
[35412.549682]     total                  881:3598799
[35412.550090]   dev 0:
[35412.550282]   durability 1:
[35412.550529]     nr                     8192
[35412.550924]     bucket size            881
[35412.551265]     available              1025:393
[35412.551648]     discard_idx            7026
[35412.552000]     dirty_ondisk           4086 (seq 4859636)
[35412.552449]     dirty_idx              4098 (seq 4859649)
[35412.552907]     cur_idx                6000 (seq 4861951)
[35412.553388]   replicas want 1 need 1
[35448.117858] ------------[ cut here ]------------
[35448.117861] btree trans held srcu lock (delaying memory reclaim) for 280 seconds
[35448.117888] WARNING: CPU: 2 PID: 445 at src/fs/bcachefs/btree_iter.c:3331 bch2_trans_srcu_unlock+0x11b/0x130 [bcachefs]
[35448.117955] Modules linked in: bcachefs(O) chacha_x86_64 libchacha libpoly1305 poly1305_x86_64 lz4hc_compress lz4_compress xor raid6_pq qrtr snd_seq_dummy snd_hrtimer snd_seq snd_seq_device af_packet rfkill nls_iso8859_1 nls_cp437 vfat fat snd_hda_codec_generic snd_hda_intel snd_intel_dspcfg intel_rapl_msr snd_intel_sdw_acpi iTCO_wdt intel_pmc_bxt watchdog xt_conntrack snd_hda_codec nf_conntrack snd_hda_core nf_defrag_ipv6 nf_defrag_ipv4 snd_hwdep edac_core snd_pcm intel_rapl_common polyval_clmulni ghash_clmulni_intel sha512_ssse3 sha1_ssse3 i2c_i801 psmouse aesni_intel i2c_smbus i2c_mux snd_timer ip6t_rpfilter ipt_rpfilter snd soundcore joydev lpc_ich mousedev rtc_cmos evdev xt_pkttype intel_agp tiny_power_button xt_LOG nf_log_syslog input_leds intel_gtt button led_class nft_compat mac_hid serio_raw nf_tables sch_fq_codel loop kvm_amd ccp kvm irqbypass fuse efi_pstore configfs nfnetlink efivarfs dmi_sysfs qemu_fw_cfg autofs4 ext4 crc16 mbcache jbd2 hid_generic usbhid hid sr_mod cdrom virtio_net net_failover failover
[35448.118006]  virtio_blk virtio_scsi ahci libahci libata atkbd libps2 vivaldi_fmap xhci_pci xhci_hcd scsi_mod scsi_common virtio_pci virtio_pci_legacy_dev virtio_pci_modern_dev i8042 serio virtio_rng rng_core virtio_gpu virtio_dma_buf virtio_console virtio_balloon virtio virtio_ring dm_mod dax
[35448.118022] CPU: 2 UID: 0 PID: 445 Comm: kworker/2:4 Tainted: G        W  O        6.16.9 #1-NixOS PREEMPT(voluntary)
[35448.118026] Tainted: [W]=WARN, [O]=OOT_MODULE
[35448.118027] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS edk2-stable202408-prebuilt.qemu.org 08/13/2024
[35448.118028] Workqueue: bcachefs_write_ref bch2_do_discards_work [bcachefs]
[35448.118080] RIP: 0010:bch2_trans_srcu_unlock+0x11b/0x130 [bcachefs]
[35448.118129] Code: bc d6 48 c7 c7 d8 0a 38 c1 48 b9 cf f7 53 e3 a5 9b c4 20 48 29 d0 48 c1 e8 03 48 f7 e1 48 89 d6 48 c1 ee 04 e8 56 2f ec d4 90 <0f> 0b 90 90 eb 9f 90 0f 0b 90 eb ab 66 0f 1f 84 00 00 00 00 00 90
[35448.118131] RSP: 0018:ffffcebc803a3c50 EFLAGS: 00010286
[35448.118133] RAX: 0000000000000000 RBX: ffff8d0d74c74000 RCX: 0000000000000027
[35448.118134] RDX: ffff8d0ef5d1e408 RSI: 0000000000000001 RDI: ffff8d0ef5d1e400
[35448.118135] RBP: ffff8d0d85e40000 R08: 0000000000000000 R09: ffffcebc803a3ae0
[35448.118136] R10: ffffffff98110a28 R11: 0000000000000003 R12: 0000000000010000
[35448.118137] R13: ffff8d0d05f7cc00 R14: ffff8d0d74c74000 R15: 0000000000000000
[35448.118140] FS:  0000000000000000(0000) GS:ffff8d0f5d24f000(0000) knlGS:0000000000000000
[35448.118141] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[35448.118142] CR2: 00007f6451420000 CR3: 00000001240ac000 CR4: 0000000000350ef0
[35448.118145] Call Trace:
[35448.118147]  <TASK>
[35448.118149]  ? bch2_trans_begin+0xc3/0x8e0 [bcachefs]
[35448.118196]  bch2_trans_begin+0x50a/0x8e0 [bcachefs]
[35448.118244]  __bch2_dev_do_discards+0xfc/0x310 [bcachefs]
[35448.118294]  bch2_do_discards_work+0x1d/0x60 [bcachefs]
[35448.118351]  process_one_work+0x18d/0x340
[35448.118355]  worker_thread+0x225/0x360
[35448.118358]  ? __pfx_worker_thread+0x10/0x10
[35448.118360]  kthread+0xfb/0x250
[35448.118362]  ? __pfx_kthread+0x10/0x10
[35448.118364]  ? _raw_spin_unlock+0xe/0x30
[35448.118366]  ? finish_task_switch.isra.0+0x99/0x2e0
[35448.118369]  ? __pfx_kthread+0x10/0x10
[35448.118370]  ? __pfx_kthread+0x10/0x10
[35448.118372]  ret_from_fork+0x199/0x1d0
[35448.118375]  ? __pfx_kthread+0x10/0x10
[35448.118376]  ret_from_fork_asm+0x1a/0x30
[35448.118380]  </TASK>
[35448.118380] ---[ end trace 0000000000000000 ]---
[35567.076514] ------------[ cut here ]------------
[35567.076517] btree trans held srcu lock (delaying memory reclaim) for 401 seconds
[35567.076531] WARNING: CPU: 0 PID: 1819 at src/fs/bcachefs/btree_iter.c:3331 bch2_trans_srcu_unlock+0x11b/0x130 [bcachefs]
[35567.076598] Modules linked in: bcachefs(O) chacha_x86_64 libchacha libpoly1305 poly1305_x86_64 lz4hc_compress lz4_compress xor raid6_pq qrtr snd_seq_dummy snd_hrtimer snd_seq snd_seq_device af_packet rfkill nls_iso8859_1 nls_cp437 vfat fat snd_hda_codec_generic snd_hda_intel snd_intel_dspcfg intel_rapl_msr snd_intel_sdw_acpi iTCO_wdt intel_pmc_bxt watchdog xt_conntrack snd_hda_codec nf_conntrack snd_hda_core nf_defrag_ipv6 nf_defrag_ipv4 snd_hwdep edac_core snd_pcm intel_rapl_common polyval_clmulni ghash_clmulni_intel sha512_ssse3 sha1_ssse3 i2c_i801 psmouse aesni_intel i2c_smbus i2c_mux snd_timer ip6t_rpfilter ipt_rpfilter snd soundcore joydev lpc_ich mousedev rtc_cmos evdev xt_pkttype intel_agp tiny_power_button xt_LOG nf_log_syslog input_leds intel_gtt button led_class nft_compat mac_hid serio_raw nf_tables sch_fq_codel loop kvm_amd ccp kvm irqbypass fuse efi_pstore configfs nfnetlink efivarfs dmi_sysfs qemu_fw_cfg autofs4 ext4 crc16 mbcache jbd2 hid_generic usbhid hid sr_mod cdrom virtio_net net_failover failover
[35567.076650]  virtio_blk virtio_scsi ahci libahci libata atkbd libps2 vivaldi_fmap xhci_pci xhci_hcd scsi_mod scsi_common virtio_pci virtio_pci_legacy_dev virtio_pci_modern_dev i8042 serio virtio_rng rng_core virtio_gpu virtio_dma_buf virtio_console virtio_balloon virtio virtio_ring dm_mod dax
[35567.076669] CPU: 0 UID: 0 PID: 1819 Comm: bch-copygc/vdb2 Tainted: G        W  O        6.16.9 #1-NixOS PREEMPT(voluntary)
[35567.076672] Tainted: [W]=WARN, [O]=OOT_MODULE
[35567.076673] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS edk2-stable202408-prebuilt.qemu.org 08/13/2024
[35567.076674] RIP: 0010:bch2_trans_srcu_unlock+0x11b/0x130 [bcachefs]
[35567.076722] Code: bc d6 48 c7 c7 d8 0a 38 c1 48 b9 cf f7 53 e3 a5 9b c4 20 48 29 d0 48 c1 e8 03 48 f7 e1 48 89 d6 48 c1 ee 04 e8 56 2f ec d4 90 <0f> 0b 90 90 eb 9f 90 0f 0b 90 eb ab 66 0f 1f 84 00 00 00 00 00 90
[35567.076723] RSP: 0018:ffffcebc83e437e8 EFLAGS: 00010282
[35567.076725] RAX: 0000000000000000 RBX: ffff8d0d08ba8000 RCX: 0000000000000027
[35567.076726] RDX: ffff8d0ef5c1e408 RSI: 0000000000000001 RDI: ffff8d0ef5c1e400
[35567.076727] RBP: ffff8d0d85e40000 R08: 0000000000000000 R09: ffffcebc83e43678
[35567.076728] R10: ffffffff98110a28 R11: 0000000000000003 R12: 0000000000010000
[35567.076729] R13: ffff8d0d54e69300 R14: ffff8d0d08ba8000 R15: 0000000000000000
[35567.076731] FS:  0000000000000000(0000) GS:ffff8d0f5d14f000(0000) knlGS:0000000000000000
[35567.076733] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[35567.076734] CR2: 00007fd9d6220000 CR3: 00000001240ac000 CR4: 0000000000350ef0
[35567.076736] Call Trace:
[35567.076738]  <TASK>
[35567.076739]  ? bch2_trans_begin+0xc3/0x8e0 [bcachefs]
[35567.076784]  bch2_trans_begin+0x50a/0x8e0 [bcachefs]
[35567.076828]  ? bch2_move_ratelimit+0x29f/0x560 [bcachefs]
[35567.076894]  __bch2_move_data_phys+0x2bf/0xce0 [bcachefs]
[35567.076959]  ? __pfx_evacuate_bucket_pred+0x10/0x10 [bcachefs]
[35567.077013]  ? bch2_evacuate_bucket+0xcc/0x130 [bcachefs]
[35567.077058]  bch2_evacuate_bucket+0xcc/0x130 [bcachefs]
[35567.077101]  ? __pfx_evacuate_bucket_pred+0x10/0x10 [bcachefs]
[35567.077145]  bch2_copygc+0x113/0x350 [bcachefs]
[35567.077190]  bch2_copygc_thread+0x309/0x560 [bcachefs]
[35567.077233]  ? bch2_copygc_thread+0x28f/0x560 [bcachefs]
[35567.077278]  ? __pfx_bch2_copygc_thread+0x10/0x10 [bcachefs]
[35567.077320]  kthread+0xfb/0x250
[35567.077323]  ? __pfx_kthread+0x10/0x10
[35567.077325]  ret_from_fork+0x199/0x1d0
[35567.077328]  ? __pfx_kthread+0x10/0x10
[35567.077329]  ret_from_fork_asm+0x1a/0x30
[35567.077333]  </TASK>
[35567.077334] ---[ end trace 0000000000000000 ]---
[35597.258525] Allocator stuck? Waited for 30 seconds
[35597.258528] Allocator debug:
[35597.258529]   capacity849891820
[35597.258529]   used                 833188184
[35597.258530]   reserved             73903636
[35597.258530]   hidden               7221557
[35597.258531]   btree                20343808
[35597.258531]   data                 811177914
[35597.258532]   cached               0
[35597.258532]   reserved             519032
[35597.258533]   online_reserved      1121792
[35597.258533]
[35597.258534]   freelist_wait        waiting
[35597.258534]   open buckets allocated2
[35597.258534]   open buckets total   1024
[35597.258535]   open_buckets_wait    empty
[35597.258535]   open_buckets_btree   0
[35597.258536]   open_buckets_user    1
[35597.258536]   btree reserve cache  0

[35597.258537] Dev 0:
[35597.258537]                      buckets         sectors      fragmented
[35597.258538]   free                    29               0               0
[35597.258538]   sb                       5            4104             301
[35597.258539]   journal               8192         7217152               0
[35597.258539]   btree                39734        20343808        14661846
[35597.258540]   user                926297       811177914         4889743
[35597.258540] Allocator stuck? Waited for 30 seconds
[35597.258541]   cached                   0               0               0
[35597.258541]   parity                   0               0               0
[35597.258542]   stripe                   0               0               0
[35597.258542] Allocator debug:
[35597.258543]   need_gc_gens             0               0               0
[35597.258543]   capacity849891820
[35597.258543]   need_discard         74319               0               0
[35597.258544]   unstriped                0               0               0
[35597.258544]   used                 833188184
[35597.258545]   capacity           1048576
[35597.258545]
[35597.258545]   reserved             73903636
[35597.258546]   reserves:
[35597.258546]   stripe               32824
[35597.258547]   hidden               7221557
[35597.258547]   normal               16440
[35597.258547]   copygc                  56
[35597.258548]   btree                20343808
[35597.258548]   btree                   28
[35597.258549]   btree_copygc             0
[35597.258549]   data                 811177914
[35597.258549]   reclaim                  0
[35597.258550]   cached               0
[35597.258550]   interior_updates         0
[35597.258550]
[35597.258550]   reserved             519032
[35597.258551]   open buckets             1
[35597.258551]   buckets to invalidate    0
[35597.258551]   online_reserved      1121792

[35597.258552] Copygc debug:
[35597.258552]
[35597.258553]   running: 1
[35597.258553]   freelist_wait        waiting
[35597.258554]   copygc_wait:0
[35597.258554]   open buckets allocated2
[35597.258554]   copygc_wait_at:0
[35597.258555]   Currently waiting for:0 B
[35597.258555]   open buckets total   1024
[35597.258555]   Currently waiting since:25.1 TiB
[35597.258556]   Currently calculated wait:
[35597.258556]   open_buckets_wait    empty
[35597.258556]     vdb2:  0 B
[35597.258557]   open_buckets_btree   0

[35597.258557] Journal debug:
[35597.258558]   open_buckets_user    1
[35597.258558]   flags:                   replay_done,running,may_skip_flush
[35597.258559]   btree reserve cache  0
[35597.258559]   dirty journal entries:   2289/32768

[35597.258560]   seq:                     4861953
[35597.258560]   seq_ondisk:              4861953
[35597.258560] Dev 0:
[35597.258561]   last_seq:                4859665
[35597.258561]   last_seq_ondisk:         4859663
[35597.258561]                      buckets         sectors      fragmented
[35597.258562]   flushed_seq_ondisk:      4861953
[35597.258562]   watermark:               stripe
[35597.258562]   free                    29               0               0
[35597.258563]   each entry reserved:     321
[35597.258563]   nr flush writes:         27584
[35597.258563]   sb                       5            4104             301
[35597.258564]   nr noflush writes:       14761
[35597.258564]   average write size:      271 KiB
[35597.258564]   journal               8192         7217152               0
[35597.258565]   free buf:                524288
[35597.258565]   nr direct reclaim:       0
[35597.258565]   btree                39734        20343808        14661846
[35597.258566]   nr background reclaim:   1060786
[35597.258566]   reclaim kicked:          0
[35597.258566]   user                926297       811177914         4889743
[35597.258567]   reclaim runs in:         76 ms
[35597.258567]   blocked:                 0
[35597.258567]   cached                   0               0               0
[35597.258568]   current entry sectors:   881
[35597.258568]   current entry error:     (No error)
[35597.258568]   parity                   0               0               0
[35597.258569]   current entry:           closed
[35597.258569]   unwritten entries:
[35597.258570]   stripe                   0               0               0
[35597.258570]   last buf closed
[35597.258570]   space:
[35597.258571]   need_gc_gens             0               0               0
[35597.258571]     discarded              881:903025
[35597.258572]     clean ondisk           881:3610717
[35597.258572]   need_discard         74319               0               0
[35597.258572]     clean                  881:3610717
[35597.258573]     total                  881:3610717
[35597.258574]   dev 0:
[35597.258574]   unstriped                0               0               0
[35597.258574]   durability 1:
[35597.258575]     nr                     8192
[35597.258575]   capacity           1048576
[35597.258575]     bucket size            881
[35597.258576]
[35597.258576]     available              1025:385
[35597.258577]   reserves:
[35597.258577]     discard_idx            7026
[35597.258578]   stripe               32824
[35597.258578]     dirty_ondisk           4111 (seq 4859663)
[35597.258579]     dirty_idx              4113 (seq 4859665)
[35597.258579]   normal               16440
[35597.258579]     cur_idx                6000 (seq 4861953)
[35597.258580]   copygc                  56
[35597.258580]   replicas want 1 need 1
[35597.258580]   btree                   28
[35597.258581]   btree_copygc             0
[35597.258582]   reclaim                  0
[35597.258896] Allocator stuck? Waited for 30 seconds
[35597.258898] Allocator debug:
[35597.258899]   capacity849891820
[35597.258899]   used                 833188184
[35597.258900]   reserved             73903636
[35597.258900]   hidden               7221557
[35597.258901]   btree                20343808
[35597.258901]   data                 811177914
[35597.258902]   cached               0
[35597.258902]   reserved             519032
[35597.258903]   online_reserved      1121792
[35597.258904]
[35597.258904]   freelist_wait        waiting
[35597.258905]   open buckets allocated2
[35597.258905]   open buckets total   1024
[35597.258906]   open_buckets_wait    empty
[35597.258906]   open_buckets_btree   0
[35597.258907]   open_buckets_user    1
[35597.258907]   btree reserve cache  0

[35597.258908] Dev 0:
[35597.258909]                      buckets         sectors      fragmented
[35597.258909]   free                    29               0               0
[35597.258910]   sb                       5            4104             301
[35597.258911]   journal               8192         7217152               0
[35597.258911]   btree                39734        20343808        14661846
[35597.258912]   user                926297       811177914         4889743
[35597.258912]   cached                   0               0               0
[35597.258913]   parity                   0               0               0
[35597.258914]   stripe                   0               0               0
[35597.258914]   need_gc_gens             0               0               0
[35597.258915]   need_discard         74319               0               0
[35597.258915]   unstriped                0               0               0
[35597.258916]   capacity           1048576
[35597.258917]
[35597.258917]   reserves:
[35597.258917]   stripe               32824
[35597.258918]   normal               16440
[35597.258918]   copygc                  56
[35597.258919]   btree                   28
[35597.258920]   btree_copygc             0
[35597.258920]   reclaim                  0
[35597.258921]   interior_updates         0
[35597.258921]
[35597.258921]   open buckets             1
[35597.258922]   buckets to invalidate    0

[35597.258923] Copygc debug:
[35597.258923]   running: 1
[35597.258924]   copygc_wait:0
[35597.258924]   copygc_wait_at:0
[35597.258925]   Currently waiting for:0 B
[35597.258925]   Currently waiting since:25.1 TiB
[35597.258926]   Currently calculated wait:
[35597.258926]     vdb2:  0 B
[35597.258927]   [<0>] bch2_copygc_wait_to_text+0x1ad/0x2c0 [bcachefs]
[35597.258928]   [<0>] bch2_print_allocator_stuck+0x11c/0x240 [bcachefs]
[35597.258928]   [<0>] __bch2_wait_on_allocator+0x9f/0xc0 [bcachefs]
[35597.258929]   [<0>] bch2_btree_update_start+0x74c/0xa40 [bcachefs]
[35597.258929]   [<0>] bch2_btree_node_rewrite+0x6f/0x4a0 [bcachefs]
[35597.258930]   [<0>] bch2_btree_node_rewrite_pos+0xa2/0xe0 [bcachefs]
[35597.258931]   [<0>] __bch2_move_data_phys+0x899/0xce0 [bcachefs]
[35597.258931]   [<0>] bch2_evacuate_bucket+0xcc/0x130 [bcachefs]
[35597.258932]   [<0>] bch2_copygc+0x113/0x350 [bcachefs]
[35597.258932]   [<0>] bch2_copygc_thread+0x309/0x560 [bcachefs]
[35597.258933]   [<0>] kthread+0xfb/0x250
[35597.258933]   [<0>] ret_from_fork+0x199/0x1d0
[35597.258934]   [<0>] ret_from_fork_asm+0x1a/0x30

[35597.258935] Journal debug:
[35597.258935]   flags:                   replay_done,running,may_skip_flush
[35597.258936]   dirty journal entries:   2289/32768
[35597.258937]   seq:                     4861953
[35597.258937]   seq_ondisk:              4861953
[35597.258938]   last_seq:                4859665
[35597.258938]   last_seq_ondisk:         4859663
[35597.258939]   flushed_seq_ondisk:      4861953
[35597.258939]   watermark:               stripe
[35597.258940]   each entry reserved:     321
[35597.258940]   nr flush writes:         27584
[35597.258941]   nr noflush writes:       14761
[35597.258941]   average write size:      271 KiB
[35597.258942]   free buf:                524288
[35597.258942]   nr direct reclaim:       0
[35597.258943]   nr background reclaim:   1060786
[35597.258943]   reclaim kicked:          0
[35597.258944]   reclaim runs in:         76 ms
[35597.258944]   blocked:                 0
[35597.258945]   current entry sectors:   881
[35597.258945]   current entry error:     (No error)
[35597.258946]   current entry:           closed
[35597.258946]   unwritten entries:
[35597.258947]   last buf closed
[35597.258948]   space:
[35597.258948]     discarded              881:903025
[35597.258949]     clean ondisk           881:3610717
[35597.258949]     clean                  881:3610717
[35597.258950]     total                  881:3610717
[35597.258950]   dev 0:
[35597.258951]   durability 1:
[35597.258951]     nr                     8192
[35597.258952]     bucket size            881
[35597.258952]     available              1025:385
[35597.258953]     discard_idx            7026
[35597.258953]     dirty_ondisk           4111 (seq 4859663)
[35597.258954]     dirty_idx              4113 (seq 4859665)
[35597.258955]     cur_idx                6000 (seq 4861953)
[35597.258955]   replicas want 1 need 1
[35597.356202]   interior_updates         0
[35597.356543]
[35597.356690]   open buckets             1
[35597.357023]   buckets to invalidate    0

[35597.357497] Copygc debug:
[35597.357844]   running: 1
[35597.358150]   copygc_wait:0
[35597.358417]   copygc_wait_at:0
[35597.358697]   Currently waiting for:0 B
[35597.359023]   Currently waiting since:25.1 TiB
[35597.359388]   Currently calculated wait:
[35597.359724]     vdb2:  0 B

[35597.360093] Journal debug:
[35597.360321]   flags:                   replay_done,running,may_skip_flush
[35597.360885]   dirty journal entries:   2289/32768
[35597.361408]   seq:                     4861953
[35597.361796]   seq_ondisk:              4861953
[35597.362169]   last_seq:                4859665
[35597.362543]   last_seq_ondisk:         4859663
[35597.362905]   flushed_seq_ondisk:      4861953
[35597.363273]   watermark:               stripe
[35597.363646]   each entry reserved:     321
[35597.364080]   nr flush writes:         27584
[35597.364430]   nr noflush writes:       14761
[35597.364792]   average write size:      271 KiB
[35597.365164]   free buf:                524288
[35597.365536]   nr direct reclaim:       0
[35597.365870]   nr background reclaim:   1060786
[35597.366266]   reclaim kicked:          0
[35597.366611]   reclaim runs in:         76 ms
[35597.367084]   blocked:                 0
[35597.367456]   current entry sectors:   881
[35597.367832]   current entry error:     (No error)
[35597.368278]   current entry:           closed
[35597.368687]   unwritten entries:
[35597.368993]   last buf closed
[35597.369271]   space:
[35597.369495]     discarded              881:903025
[35597.369988]     clean ondisk           881:3610717
[35597.370377]     clean                  881:3610717
[35597.370774]     total                  881:3610717
[35597.371226]   dev 0:
[35597.371436]   durability 1:
[35597.371706]     nr                     8192
[35597.372102]     bucket size            881
[35597.372490]     available              1025:385
[35597.372956]     discard_idx            7026
[35597.373306]     dirty_ondisk           4111 (seq 4859663)
[35597.373752]     dirty_idx              4113 (seq 4859665)
[35597.374196]     cur_idx                6000 (seq 4861953)
[35597.374634]   replicas want 1 need 1
[35850.694373] Allocator stuck? Waited for 30 seconds
[35850.694376] Allocator debug:
[35850.694377]   capacity849891820
[35850.694377]   used                 833188184
[35850.694378]   reserved             73903636
[35850.694379]   hidden               7221557
[35850.694380]   btree                20343808
[35850.694380]   data                 811177914
[35850.694381]   cached               0
[35850.694382]   reserved             519032
[35850.694382]   online_reserved      1121792
[35850.694383]
[35850.694383] Allocator stuck? Waited for 30 seconds
[35850.694384]   freelist_wait        waiting
[35850.694384]   open buckets allocated2
[35850.694385]   open buckets total   1024
[35850.694385] Allocator debug:
[35850.694386]   open_buckets_wait    empty
[35850.694386]   capacity849891820
[35850.694386]   open_buckets_btree   0
[35850.694387]   used                 833188184
[35850.694387]   open_buckets_user    1
[35850.694387]   reserved             73903636
[35850.694388]   btree reserve cache  0
[35850.694388]   hidden               7221557

[35850.694389]   btree                20343808
[35850.694389] Dev 0:
[35850.694390]   data                 811177914
[35850.694390]                      buckets         sectors      fragmented
[35850.694390]   cached               0
[35850.694391]   free                    29               0               0
[35850.694391]   reserved             519032
[35850.694392]   sb                       5            4104             301
[35850.694392]   online_reserved      1121792
[35850.694392]   journal               8192         7217152               0
[35850.694393]
[35850.694393]   freelist_wait        waiting
[35850.694393]   btree                39734        20343808        14661846
[35850.694394]   open buckets allocated2
[35850.694394]   user                926297       811177914         4889743
[35850.694395]   open buckets total   1024
[35850.694395]   cached                   0               0               0
[35850.694395]   open_buckets_wait    empty
[35850.694396]   parity                   0               0               0
[35850.694396]   open_buckets_btree   0
[35850.694397]   open_buckets_user    1
[35850.694397]   stripe                   0               0               0
[35850.694397]   btree reserve cache  0
[35850.694397]   need_gc_gens             0               0               0

[35850.694398]   need_discard         74319               0               0
[35850.694399] Dev 0:
[35850.694399]   unstriped                0               0               0
[35850.694399]                      buckets         sectors      fragmented
[35850.694400]   capacity           1048576
[35850.694400]   free                    29               0               0
[35850.694401]
[35850.694401]   sb                       5            4104             301
[35850.694401]   reserves:
[35850.694402]   journal               8192         7217152               0
[35850.694402]   stripe               32824
[35850.694402]   btree                39734        20343808        14661846
[35850.694403]   normal               16440
[35850.694403]   user                926297       811177914         4889743
[35850.694403]   copygc                  56
[35850.694404]   btree                   28
[35850.694404]   cached                   0               0               0
[35850.694405]   btree_copygc             0
[35850.694405]   parity                   0               0               0
[35850.694405]   reclaim                  0
[35850.694406]   stripe                   0               0               0
[35850.694406]   interior_updates         0
[35850.694407]   need_gc_gens             0               0               0
[35850.694407]
[35850.694407]   open buckets             1
[35850.694407]   need_discard         74319               0               0
[35850.694408]   buckets to invalidate    0
[35850.694408]   unstriped                0               0               0

[35850.694409]   capacity           1048576
[35850.694409] Copygc debug:
[35850.694410]
[35850.694410]   running: 1
[35850.694410]   reserves:
[35850.694411]   copygc_wait:0
[35850.694411]   stripe               32824
[35850.694411]   copygc_wait_at:0
[35850.694411]   normal               16440
[35850.694412]   Currently waiting for:0 B
[35850.694412]   copygc                  56
[35850.694412]   Currently waiting since:25.1 TiB
[35850.694413]   btree                   28
[35850.694413]   Currently calculated wait:
[35850.694413]   btree_copygc             0
[35850.694414]     vdb2:  0 B
[35850.694414]   reclaim                  0

[35850.694415]   interior_updates         0
[35850.694415] Journal debug:
[35850.694415]
[35850.694416]   flags:                   replay_done,running,may_skip_flush
[35850.694416]   open buckets             1
[35850.694417]   dirty journal entries:   2268/32768
[35850.694417]   buckets to invalidate    0

[35850.694417]   seq:                     4861954
[35850.694418] Copygc debug:
[35850.694418]   seq_ondisk:              4861954
[35850.694419]   running: 1
[35850.694419]   last_seq:                4859687
[35850.694419]   copygc_wait:0
[35850.694420]   last_seq_ondisk:         4859685
[35850.694420]   copygc_wait_at:0
[35850.694420]   flushed_seq_ondisk:      4861954
[35850.694420]   Currently waiting for:0 B
[35850.694421]   watermark:               stripe
[35850.694421]   Currently waiting since:25.1 TiB
[35850.694422]   each entry reserved:     321
[35850.694422]   Currently calculated wait:
[35850.694422]   nr flush writes:         27585
[35850.694423]     vdb2:  0 B
[35850.694423]   nr noflush writes:       14761

[35850.694424] Journal debug:
[35850.694424]   average write size:      271 KiB
[35850.694425]   flags:                   replay_done,running,may_skip_flush
[35850.694425]   free buf:                524288
[35850.694426]   nr direct reclaim:       0
[35850.694426]   dirty journal entries:   2268/32768
[35850.694426]   nr background reclaim:   1063223
[35850.694426]   seq:                     4861954
[35850.694427]   reclaim kicked:          0
[35850.694427]   seq_ondisk:              4861954
[35850.694428]   reclaim runs in:         84 ms
[35850.694428]   last_seq:                4859687
[35850.694428]   blocked:                 0
[35850.694429]   last_seq_ondisk:         4859685
[35850.694429]   current entry sectors:   881
[35850.694429]   flushed_seq_ondisk:      4861954
[35850.694430]   current entry error:     (No error)
[35850.694430]   watermark:               stripe
[35850.694430]   current entry:           closed
[35850.694431]   each entry reserved:     321
[35850.694431]   unwritten entries:
[35850.694431]   nr flush writes:         27585
[35850.694432]   last buf closed
[35850.694432]   nr noflush writes:       14761
[35850.694432]   space:
[35850.694433]   average write size:      271 KiB
[35850.694433]     discarded              881:903025
[35850.694433]   free buf:                524288
[35850.694434]     clean ondisk           881:3628268
[35850.694434]   nr direct reclaim:       0
[35850.694435]     clean                  881:3628268
[35850.694435]   nr background reclaim:   1063223
[35850.694435]     total                  881:3628268
[35850.694435]   reclaim kicked:          0
[35850.694436]   dev 0:
[35850.694436]   reclaim runs in:         84 ms
[35850.694437]   durability 1:
[35850.694437]   blocked:                 0
[35850.694437]     nr                     8192
[35850.694437]   current entry sectors:   881
[35850.694438]     bucket size            881
[35850.694438]   current entry error:     (No error)
[35850.694439]     available              1025:381
[35850.694439]   current entry:           closed
[35850.694439]     discard_idx            7026
[35850.694440]   unwritten entries:
[35850.694440]     dirty_ondisk           4132 (seq 4859685)
[35850.694440]   last buf closed
[35850.694441]   space:
[35850.694441]     dirty_idx              4134 (seq 4859687)
[35850.694441]     discarded              881:903025
[35850.694442]     cur_idx                6000 (seq 4861954)
[35850.694442]     clean ondisk           881:3628268
[35850.694443]   replicas want 1 need 1
[35850.694443]     clean                  881:3628268
[35850.694444]     total                  881:3628268
[35850.694444]   dev 0:
[35850.694445]   durability 1:
[35850.694672] Allocator stuck? Waited for 30 seconds
[35850.694674] Allocator debug:
[35850.694675]   capacity849891820
[35850.694676]   used                 833188184
[35850.694676]   reserved             73903636
[35850.694677]   hidden               7221557
[35850.694677]   btree                20343808
[35850.694678]   data                 811177914
[35850.694679]   cached               0
[35850.694679]   reserved             519032
[35850.694680]   online_reserved      1121792
[35850.694681]
[35850.694681]   freelist_wait        waiting
[35850.694682]   open buckets allocated2
[35850.694682]   open buckets total   1024
[35850.694683]   open_buckets_wait    empty
[35850.694683]   open_buckets_btree   0
[35850.694684]   open_buckets_user    1
[35850.694684]   btree reserve cache  0

[35850.694685] Dev 0:
[35850.694686]                      buckets         sectors      fragmented
[35850.694687]   free                    29               0               0
[35850.694687]   sb                       5            4104             301
[35850.694688]   journal               8192         7217152               0
[35850.694689]   btree                39734        20343808        14661846
[35850.694689]   user                926297       811177914         4889743
[35850.694690]   cached                   0               0               0
[35850.694691]   parity                   0               0               0
[35850.694692]   stripe                   0               0               0
[35850.694692]   need_gc_gens             0               0               0
[35850.694693]   need_discard         74319               0               0
[35850.694694]   unstriped                0               0               0
[35850.694694]   capacity           1048576
[35850.694695]
[35850.694696]   reserves:
[35850.694696]   stripe               32824
[35850.694697]   normal               16440
[35850.694697]   copygc                  56
[35850.694698]   btree                   28
[35850.694698]   btree_copygc             0
[35850.694699]   reclaim                  0
[35850.694699]   interior_updates         0
[35850.694700]
[35850.694700]   open buckets             1
[35850.694701]   buckets to invalidate    0

[35850.694702] Copygc debug:
[35850.694702]   running: 1
[35850.694703]   copygc_wait:0
[35850.694704]   copygc_wait_at:0
[35850.694704]   Currently waiting for:0 B
[35850.694705]   Currently waiting since:25.1 TiB
[35850.694705]   Currently calculated wait:
[35850.694706]     vdb2:  0 B
[35850.694706]   [<0>] bch2_copygc_wait_to_text+0x1ad/0x2c0 [bcachefs]
[35850.694707]   [<0>] bch2_print_allocator_stuck+0x11c/0x240 [bcachefs]
[35850.694708]   [<0>] __bch2_wait_on_allocator+0x9f/0xc0 [bcachefs]
[35850.694709]   [<0>] bch2_btree_update_start+0x74c/0xa40 [bcachefs]
[35850.694709]   [<0>] bch2_btree_node_rewrite+0x6f/0x4a0 [bcachefs]
[35850.694710]   [<0>] bch2_btree_node_rewrite_pos+0xa2/0xe0 [bcachefs]
[35850.694711]   [<0>] __bch2_move_data_phys+0x899/0xce0 [bcachefs]
[35850.694711]   [<0>] bch2_evacuate_bucket+0xcc/0x130 [bcachefs]
[35850.694712]   [<0>] bch2_copygc+0x113/0x350 [bcachefs]
[35850.694713]   [<0>] bch2_copygc_thread+0x309/0x560 [bcachefs]
[35850.694713]   [<0>] kthread+0xfb/0x250
[35850.694714]   [<0>] ret_from_fork+0x199/0x1d0
[35850.694714]   [<0>] ret_from_fork_asm+0x1a/0x30

[35850.694715] Journal debug:
[35850.694716]   flags:                   replay_done,running,may_skip_flush
[35850.694717]   dirty journal entries:   2268/32768
[35850.694717]   seq:                     4861954
[35850.694718]   seq_ondisk:              4861954
[35850.694718]   last_seq:                4859687
[35850.694719]   last_seq_ondisk:         4859685
[35850.694719]   flushed_seq_ondisk:      4861954
[35850.694720]   watermark:               stripe
[35850.694721]   each entry reserved:     321
[35850.694721]   nr flush writes:         27585
[35850.694722]   nr noflush writes:       14761
[35850.694723]   average write size:      271 KiB
[35850.694723]   free buf:                524288
[35850.694724]   nr direct reclaim:       0
[35850.694724]   nr background reclaim:   1063223
[35850.694725]   reclaim kicked:          0
[35850.694726]   reclaim runs in:         84 ms
[35850.694726]   blocked:                 0
[35850.694727]   current entry sectors:   881
[35850.694727]   current entry error:     (No error)
[35850.694728]   current entry:           closed
[35850.694728]   unwritten entries:
[35850.694729]   last buf closed
[35850.694729]   space:
[35850.694730]     discarded              881:903025
[35850.694730]     clean ondisk           881:3628268
[35850.694731]     clean                  881:3628268
[35850.694732]     total                  881:3628268
[35850.694732]   dev 0:
[35850.694732]   durability 1:
[35850.694733]     nr                     8192
[35850.694733]     bucket size            881
[35850.694734]     available              1025:381
[35850.694734]     discard_idx            7026
[35850.694735]     dirty_ondisk           4132 (seq 4859685)
[35850.694735]     dirty_idx              4134 (seq 4859687)
[35850.694736]     cur_idx                6000 (seq 4861954)
[35850.694736]   replicas want 1 need 1
[35850.806616]     nr                     8192
[35850.806966]     bucket size            881
[35850.807322]     available              1025:381
[35850.807756]     discard_idx            7026
[35850.808109]     dirty_ondisk           4132 (seq 4859685)
[35850.808560]     dirty_idx              4134 (seq 4859687)
[35850.809008]     cur_idx                6000 (seq 4861954)
[35850.809565]   replicas want 1 need 1
[36179.905001] Allocator stuck? Waited for 30 seconds
[36179.905004] Allocator debug:
[36179.905005]   capacity849891820
[36179.905006]   used                 833188184
[36179.905007]   reserved             73903636
[36179.905008]   hidden               7221557
[36179.905008]   btree                20343808
[36179.905009]   data                 811177914
[36179.905010]   cached               0
[36179.905010]   reserved             519032
[36179.905011]   online_reserved      1121792
[36179.905011] Allocator stuck? Waited for 30 seconds
[36179.905012]
[36179.905012]   freelist_wait        waiting
[36179.905013] Allocator debug:
[36179.905013]   open buckets allocated2
[36179.905014]   capacity849891820
[36179.905014]   open buckets total   1024
[36179.905015]   used                 833188184
[36179.905015]   open_buckets_wait    empty
[36179.905015]   reserved             73903636
[36179.905015]   open_buckets_btree   0
[36179.905016]   hidden               7221557
[36179.905016]   open_buckets_user    1
[36179.905017]   btree                20343808
[36179.905017]   btree reserve cache  0
[36179.905017]   data                 811177914

[36179.905018]   cached               0
[36179.905018] Dev 0:
[36179.905019]   reserved             519032
[36179.905019]                      buckets         sectors      fragmented
[36179.905020]   online_reserved      1121792
[36179.905020]   free                    29               0               0
[36179.905020]
[36179.905021]   sb                       5            4104             301
[36179.905021]   freelist_wait        waiting
[36179.905022]   open buckets allocated2
[36179.905022]   journal               8192         7217152               0
[36179.905022]   open buckets total   1024
[36179.905023]   btree                39734        20343808        14661846
[36179.905023]   open_buckets_wait    empty
[36179.905024]   user                926297       811177914         4889743
[36179.905024]   open_buckets_btree   0
[36179.905024]   open_buckets_user    1
[36179.905024]   cached                   0               0               0
[36179.905025]   btree reserve cache  0
[36179.905025]   parity                   0               0               0

[36179.905026]   stripe                   0               0               0
[36179.905026] Dev 0:
[36179.905027]   need_gc_gens             0               0               0
[36179.905027]                      buckets         sectors      fragmented
[36179.905028]   need_discard         74319               0               0
[36179.905028]   free                    29               0               0
[36179.905029]   unstriped                0               0               0
[36179.905029]   sb                       5            4104             301
[36179.905029]   capacity           1048576
[36179.905030]   journal               8192         7217152               0
[36179.905030]
[36179.905030]   btree                39734        20343808        14661846
[36179.905031]   reserves:
[36179.905031]   user                926297       811177914         4889743
[36179.905031]   stripe               32824
[36179.905032]   normal               16440
[36179.905032]   cached                   0               0               0
[36179.905033]   copygc                  56
[36179.905033]   parity                   0               0               0
[36179.905033]   btree                   28
[36179.905034]   stripe                   0               0               0
[36179.905034]   btree_copygc             0
[36179.905035]   need_gc_gens             0               0               0
[36179.905035]   reclaim                  0
[36179.905036]   need_discard         74319               0               0
[36179.905036]   interior_updates         0
[36179.905036]
[36179.905036]   unstriped                0               0               0
[36179.905037]   open buckets             1
[36179.905037]   capacity           1048576
[36179.905038]   buckets to invalidate    0
[36179.905038]

[36179.905038]   reserves:
[36179.905039] Copygc debug:
[36179.905039]   stripe               32824
[36179.905040]   running: 1
[36179.905040]   normal               16440
[36179.905040]   copygc_wait:0
[36179.905040]   copygc                  56
[36179.905041]   copygc_wait_at:0
[36179.905041]   btree                   28
[36179.905042]   Currently waiting for:0 B
[36179.905042]   btree_copygc             0
[36179.905042]   Currently waiting since:25.1 TiB
[36179.905042]   reclaim                  0
[36179.905043]   Currently calculated wait:
[36179.905043]   interior_updates         0
[36179.905044]     vdb2:  0 B
[36179.905044]

[36179.905045]   open buckets             1
[36179.905045] Journal debug:
[36179.905045]   buckets to invalidate    0
[36179.905046]   flags:                   replay_done,running,may_skip_flush

[36179.905046] Copygc debug:
[36179.905047]   dirty journal entries:   1477/32768
[36179.905047]   running: 1
[36179.905047]   seq:                     4861995
[36179.905048]   copygc_wait:0
[36179.905048]   seq_ondisk:              4861995
[36179.905048]   copygc_wait_at:0
[36179.905049]   last_seq:                4860519
[36179.905049]   Currently waiting for:0 B
[36179.905050]   last_seq_ondisk:         4860500
[36179.905050]   Currently waiting since:25.1 TiB
[36179.905050]   flushed_seq_ondisk:      4861995
[36179.905050]   Currently calculated wait:
[36179.905051]   watermark:               stripe
[36179.905051]     vdb2:  0 B

[36179.905052]   each entry reserved:     321
[36179.905052] Journal debug:
[36179.905053]   nr flush writes:         27626
[36179.905053]   flags:                   replay_done,running,may_skip_flush
[36179.905053]   nr noflush writes:       14761
[36179.905054]   dirty journal entries:   1477/32768
[36179.905054]   average write size:      271 KiB
[36179.905055]   seq:                     4861995
[36179.905055]   free buf:                524288
[36179.905055]   seq_ondisk:              4861995
[36179.905056]   nr direct reclaim:       0
[36179.905056]   last_seq:                4860519
[36179.905056]   nr background reclaim:   1066388
[36179.905057]   last_seq_ondisk:         4860500
[36179.905057]   reclaim kicked:          0
[36179.905057]   flushed_seq_ondisk:      4861995
[36179.905058]   reclaim runs in:         28 ms
[36179.905058]   watermark:               stripe
[36179.905058]   blocked:                 0
[36179.905059]   each entry reserved:     321
[36179.905059]   current entry sectors:   881
[36179.905060]   nr flush writes:         27626
[36179.905060]   current entry error:     (No error)
[36179.905060]   nr noflush writes:       14761
[36179.905060]   current entry:           closed
[36179.905061]   average write size:      271 KiB
[36179.905061]   unwritten entries:
[36179.905062]   free buf:                524288
[36179.905062]   last buf closed
[36179.905063]   nr direct reclaim:       0
[36179.905063]   space:
[36179.905063]   nr background reclaim:   1066388
[36179.905063]     discarded              881:903025
[36179.905064]   reclaim kicked:          0
[36179.905064]     clean ondisk           881:4197431
[36179.905065]   reclaim runs in:         28 ms
[36179.905065]     clean                  881:4197431
[36179.905065]   blocked:                 0
[36179.905066]     total                  881:4197431
[36179.905066]   current entry sectors:   881
[36179.905066]   dev 0:
[36179.905067]   current entry error:     (No error)
[36179.905067]   durability 1:
[36179.905067]   current entry:           closed
[36179.905068]     nr                     8192
[36179.905068]   unwritten entries:
[36179.905068]     bucket size            881
[36179.905069]   last buf closed
[36179.905069]     available              1025:137
[36179.905069]   space:
[36179.905070]     discard_idx            7026
[36179.905070]     discarded              881:903025
[36179.905071]     dirty_ondisk           4838 (seq 4860500)
[36179.905071]     clean ondisk           881:4197431
[36179.905071]     dirty_idx              4856 (seq 4860519)
[36179.905072]     clean                  881:4197431
[36179.905072]     cur_idx                6000 (seq 4861995)
[36179.905072]     total                  881:4197431
[36179.905073]   replicas want 1 need 1
[36179.905073]   dev 0:
[36179.905074]   durability 1:
[36179.905074]     nr                     8192
[36179.905075]     bucket size            881
[36179.905358] Allocator stuck? Waited for 30 seconds
[36179.905360] Allocator debug:
[36179.905360]   capacity849891820
[36179.905361]   used                 833188184
[36179.905362]   reserved             73903636
[36179.905362]   hidden               7221557
[36179.905363]   btree                20343808
[36179.905363]   data                 811177914
[36179.905364]   cached               0
[36179.905364]   reserved             519032
[36179.905365]   online_reserved      1121792
[36179.905365]
[36179.905366]   freelist_wait        waiting
[36179.905366]   open buckets allocated2
[36179.905367]   open buckets total   1024
[36179.905367]   open_buckets_wait    empty
[36179.905368]   open_buckets_btree   0
[36179.905368]   open_buckets_user    1
[36179.905369]   btree reserve cache  0

[36179.905370] Dev 0:
[36179.905370]                      buckets         sectors      fragmented
[36179.905371]   free                    29               0               0
[36179.905372]   sb                       5            4104             301
[36179.905372]   journal               8192         7217152               0
[36179.905373]   btree                39734        20343808        14661846
[36179.905373]   user                926297       811177914         4889743
[36179.905374]   cached                   0               0               0
[36179.905374]   parity                   0               0               0
[36179.905375]   stripe                   0               0               0
[36179.905376]   need_gc_gens             0               0               0
[36179.905376]   need_discard         74319               0               0
[36179.905377]   unstriped                0               0               0
[36179.905377]   capacity           1048576
[36179.905378]
[36179.905378]   reserves:
[36179.905379]   stripe               32824
[36179.905379]   normal               16440
[36179.905380]   copygc                  56
[36179.905380]   btree                   28
[36179.905381]   btree_copygc             0
[36179.905381]   reclaim                  0
[36179.905382]   interior_updates         0
[36179.905382]
[36179.905382]   open buckets             1
[36179.905383]   buckets to invalidate    0

[36179.905384] Copygc debug:
[36179.905384]   running: 1
[36179.905385]   copygc_wait:0
[36179.905386]   copygc_wait_at:0
[36179.905386]   Currently waiting for:0 B
[36179.905387]   Currently waiting since:25.1 TiB
[36179.905387]   Currently calculated wait:
[36179.905388]     vdb2:  0 B
[36179.905389]   [<0>] bch2_copygc_wait_to_text+0x1ad/0x2c0 [bcachefs]
[36179.905389]   [<0>] bch2_print_allocator_stuck+0x11c/0x240 [bcachefs]
[36179.905390]   [<0>] __bch2_wait_on_allocator+0x9f/0xc0 [bcachefs]
[36179.905391]   [<0>] bch2_btree_update_start+0x74c/0xa40 [bcachefs]
[36179.905391]   [<0>] bch2_btree_node_rewrite+0x6f/0x4a0 [bcachefs]
[36179.905392]   [<0>] bch2_btree_node_rewrite_pos+0xa2/0xe0 [bcachefs]
[36179.905393]   [<0>] __bch2_move_data_phys+0x899/0xce0 [bcachefs]
[36179.905393]   [<0>] bch2_evacuate_bucket+0xcc/0x130 [bcachefs]
[36179.905394]   [<0>] bch2_copygc+0x113/0x350 [bcachefs]
[36179.905394]   [<0>] bch2_copygc_thread+0x309/0x560 [bcachefs]
[36179.905395]   [<0>] kthread+0xfb/0x250
[36179.905395]   [<0>] ret_from_fork+0x199/0x1d0
[36179.905396]   [<0>] ret_from_fork_asm+0x1a/0x30

[36179.905397] Journal debug:
[36179.905397]   flags:                   replay_done,running,may_skip_flush
[36179.905398]   dirty journal entries:   1477/32768
[36179.905398]   seq:                     4861995
[36179.905399]   seq_ondisk:              4861995
[36179.905400]   last_seq:                4860519
[36179.905400]   last_seq_ondisk:         4860500
[36179.905401]   flushed_seq_ondisk:      4861995
[36179.905401]   watermark:               stripe
[36179.905402]   each entry reserved:     321
[36179.905402]   nr flush writes:         27626
[36179.905403]   nr noflush writes:       14761
[36179.905403]   average write size:      271 KiB
[36179.905404]   free buf:                524288
[36179.905404]   nr direct reclaim:       0
[36179.905405]   nr background reclaim:   1066388
[36179.905405]   reclaim kicked:          0
[36179.905406]   reclaim runs in:         28 ms
[36179.905406]   blocked:                 0
[36179.905407]   current entry sectors:   881
[36179.905407]   current entry error:     (No error)
[36179.905408]   current entry:           closed
[36179.905409]   unwritten entries:
[36179.905409]   last buf closed
[36179.905410]   space:
[36179.905410]     discarded              881:903025
[36179.905411]     clean ondisk           881:4197431
[36179.905411]     clean                  881:4197431
[36179.905412]     total                  881:4197431
[36179.905412]   dev 0:
[36179.905413]   durability 1:
[36179.905413]     nr                     8192
[36179.905414]     bucket size            881
[36179.905414]     available              1025:137
[36179.905415]     discard_idx            7026
[36179.905415]     dirty_ondisk           4838 (seq 4860500)
[36179.905416]     dirty_idx              4856 (seq 4860519)
[36179.905417]     cur_idx                6000 (seq 4861995)
[36179.905417]   replicas want 1 need 1
[36180.018675]     available              1025:137
[36180.019110]     discard_idx            7026
[36180.019491]     dirty_ondisk           4838 (seq 4860500)
[36180.019950]     dirty_idx              4856 (seq 4860519)
[36180.020477]     cur_idx                6000 (seq 4861995)
[36180.020932]   replicas want 1 need 1
[36726.863482] ------------[ cut here ]------------
[36726.863486] btree trans held srcu lock (delaying memory reclaim) for 1278 seconds
[36726.863505] WARNING: CPU: 2 PID: 445 at src/fs/bcachefs/btree_iter.c:3331 bch2_trans_srcu_unlock+0x11b/0x130 [bcachefs]
[36726.863574] Modules linked in: bcachefs(O) chacha_x86_64 libchacha libpoly1305 poly1305_x86_64 lz4hc_compress lz4_compress xor raid6_pq qrtr snd_seq_dummy snd_hrtimer snd_seq snd_seq_device af_packet rfkill nls_iso8859_1 nls_cp437 vfat fat snd_hda_codec_generic snd_hda_intel snd_intel_dspcfg intel_rapl_msr snd_intel_sdw_acpi iTCO_wdt intel_pmc_bxt watchdog xt_conntrack snd_hda_codec nf_conntrack snd_hda_core nf_defrag_ipv6 nf_defrag_ipv4 snd_hwdep edac_core snd_pcm intel_rapl_common polyval_clmulni ghash_clmulni_intel sha512_ssse3 sha1_ssse3 i2c_i801 psmouse aesni_intel i2c_smbus i2c_mux snd_timer ip6t_rpfilter ipt_rpfilter snd soundcore joydev lpc_ich mousedev rtc_cmos evdev xt_pkttype intel_agp tiny_power_button xt_LOG nf_log_syslog input_leds intel_gtt button led_class nft_compat mac_hid serio_raw nf_tables sch_fq_codel loop kvm_amd ccp kvm irqbypass fuse efi_pstore configfs nfnetlink efivarfs dmi_sysfs qemu_fw_cfg autofs4 ext4 crc16 mbcache jbd2 hid_generic usbhid hid sr_mod cdrom virtio_net net_failover failover
[36726.863625]  virtio_blk virtio_scsi ahci libahci libata atkbd libps2 vivaldi_fmap xhci_pci xhci_hcd scsi_mod scsi_common virtio_pci virtio_pci_legacy_dev virtio_pci_modern_dev i8042 serio virtio_rng rng_core virtio_gpu virtio_dma_buf virtio_console virtio_balloon virtio virtio_ring dm_mod dax
[36726.863641] CPU: 2 UID: 0 PID: 445 Comm: kworker/2:4 Tainted: G        W  O        6.16.9 #1-NixOS PREEMPT(voluntary)
[36726.863644] Tainted: [W]=WARN, [O]=OOT_MODULE
[36726.863645] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS edk2-stable202408-prebuilt.qemu.org 08/13/2024
[36726.863647] Workqueue: bcachefs_write_ref bch2_do_discards_work [bcachefs]
[36726.863698] RIP: 0010:bch2_trans_srcu_unlock+0x11b/0x130 [bcachefs]
[36726.863748] Code: bc d6 48 c7 c7 d8 0a 38 c1 48 b9 cf f7 53 e3 a5 9b c4 20 48 29 d0 48 c1 e8 03 48 f7 e1 48 89 d6 48 c1 ee 04 e8 56 2f ec d4 90 <0f> 0b 90 90 eb 9f 90 0f 0b 90 eb ab 66 0f 1f 84 00 00 00 00 00 90
[36726.863749] RSP: 0018:ffffcebc803a3c50 EFLAGS: 00010286
[36726.863751] RAX: 0000000000000000 RBX: ffff8d0d74c74000 RCX: 0000000000000027
[36726.863752] RDX: ffff8d0ef5d1e408 RSI: 0000000000000001 RDI: ffff8d0ef5d1e400
[36726.863753] RBP: ffff8d0d85e40000 R08: 0000000000000000 R09: ffffcebc803a3ae0
[36726.863754] R10: ffffffff98110a28 R11: 0000000000000003 R12: ffff8d0d74c74000
[36726.863755] R13: ffffcebc803a3d78 R14: ffff8d0d74c74000 R15: 00000000fffff778
[36726.863758] FS:  0000000000000000(0000) GS:ffff8d0f5d24f000(0000) knlGS:0000000000000000
[36726.863760] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[36726.863761] CR2: 00007f1add020000 CR3: 00000001240ac000 CR4: 0000000000350ef0
[36726.863764] Call Trace:
[36726.863765]  <TASK>
[36726.863768]  ? bch2_trans_begin+0xc3/0x8e0 [bcachefs]
[36726.863815]  bch2_trans_begin+0x50a/0x8e0 [bcachefs]
[36726.863870]  __bch2_dev_do_discards+0xfc/0x310 [bcachefs]
[36726.863920]  bch2_do_discards_work+0x1d/0x60 [bcachefs]
[36726.863965]  process_one_work+0x18d/0x340
[36726.863969]  worker_thread+0x225/0x360
[36726.863972]  ? __pfx_worker_thread+0x10/0x10
[36726.863974]  kthread+0xfb/0x250
[36726.863976]  ? __pfx_kthread+0x10/0x10
[36726.863978]  ? _raw_spin_unlock+0xe/0x30
[36726.863980]  ? finish_task_switch.isra.0+0x99/0x2e0
[36726.863983]  ? __pfx_kthread+0x10/0x10
[36726.863984]  ? __pfx_kthread+0x10/0x10
[36726.863986]  ret_from_fork+0x199/0x1d0
[36726.863988]  ? __pfx_kthread+0x10/0x10
[36726.863990]  ret_from_fork_asm+0x1a/0x30
[36726.863994]  </TASK>
[36726.863994] ---[ end trace 0000000000000000 ]---
[36804.242221] ------------[ cut here ]------------
[36804.242224] btree trans held srcu lock (delaying memory reclaim) for 77 seconds
[36804.242239] WARNING: CPU: 2 PID: 445 at src/fs/bcachefs/btree_iter.c:3331 bch2_trans_srcu_unlock+0x11b/0x130 [bcachefs]
[36804.242324] Modules linked in: bcachefs(O) chacha_x86_64 libchacha libpoly1305 poly1305_x86_64 lz4hc_compress lz4_compress xor raid6_pq qrtr snd_seq_dummy snd_hrtimer snd_seq snd_seq_device af_packet rfkill nls_iso8859_1 nls_cp437 vfat fat snd_hda_codec_generic snd_hda_intel snd_intel_dspcfg intel_rapl_msr snd_intel_sdw_acpi iTCO_wdt intel_pmc_bxt watchdog xt_conntrack snd_hda_codec nf_conntrack snd_hda_core nf_defrag_ipv6 nf_defrag_ipv4 snd_hwdep edac_core snd_pcm intel_rapl_common polyval_clmulni ghash_clmulni_intel sha512_ssse3 sha1_ssse3 i2c_i801 psmouse aesni_intel i2c_smbus i2c_mux snd_timer ip6t_rpfilter ipt_rpfilter snd soundcore joydev lpc_ich mousedev rtc_cmos evdev xt_pkttype intel_agp tiny_power_button xt_LOG nf_log_syslog input_leds intel_gtt button led_class nft_compat mac_hid serio_raw nf_tables sch_fq_codel loop kvm_amd ccp kvm irqbypass fuse efi_pstore configfs nfnetlink efivarfs dmi_sysfs qemu_fw_cfg autofs4 ext4 crc16 mbcache jbd2 hid_generic usbhid hid sr_mod cdrom virtio_net net_failover failover
[36804.242374]  virtio_blk virtio_scsi ahci libahci libata atkbd libps2 vivaldi_fmap xhci_pci xhci_hcd scsi_mod scsi_common virtio_pci virtio_pci_legacy_dev virtio_pci_modern_dev i8042 serio virtio_rng rng_core virtio_gpu virtio_dma_buf virtio_console virtio_balloon virtio virtio_ring dm_mod dax
[36804.242390] CPU: 2 UID: 0 PID: 445 Comm: kworker/2:4 Tainted: G        W  O        6.16.9 #1-NixOS PREEMPT(voluntary)
[36804.242394] Tainted: [W]=WARN, [O]=OOT_MODULE
[36804.242395] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS edk2-stable202408-prebuilt.qemu.org 08/13/2024
[36804.242396] Workqueue: bcachefs_write_ref bch2_do_discards_work [bcachefs]
[36804.242448] RIP: 0010:bch2_trans_srcu_unlock+0x11b/0x130 [bcachefs]
[36804.242498] Code: bc d6 48 c7 c7 d8 0a 38 c1 48 b9 cf f7 53 e3 a5 9b c4 20 48 29 d0 48 c1 e8 03 48 f7 e1 48 89 d6 48 c1 ee 04 e8 56 2f ec d4 90 <0f> 0b 90 90 eb 9f 90 0f 0b 90 eb ab 66 0f 1f 84 00 00 00 00 00 90
[36804.242499] RSP: 0018:ffffcebc803a3c50 EFLAGS: 00010286
[36804.242501] RAX: 0000000000000000 RBX: ffff8d0d74c74000 RCX: 0000000000000027
[36804.242503] RDX: ffff8d0ef5d1e408 RSI: 0000000000000001 RDI: ffff8d0ef5d1e400
[36804.242504] RBP: ffff8d0d85e40000 R08: 0000000000000000 R09: ffffcebc803a3ae0
[36804.242505] R10: ffffffff98110a28 R11: 0000000000000003 R12: ffff8d0d74c74000
[36804.242505] R13: ffffcebc803a3d78 R14: ffff8d0d74c74000 R15: 00000000fffff778
[36804.242508] FS:  0000000000000000(0000) GS:ffff8d0f5d24f000(0000) knlGS:0000000000000000
[36804.242510] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[36804.242511] CR2: 00007f9a8b442f00 CR3: 00000001240ac000 CR4: 0000000000350ef0
[36804.242514] Call Trace:
[36804.242516]  <TASK>
[36804.242517]  ? bch2_trans_begin+0xc3/0x8e0 [bcachefs]
[36804.242565]  bch2_trans_begin+0x50a/0x8e0 [bcachefs]
[36804.242612]  __bch2_dev_do_discards+0xfc/0x310 [bcachefs]
[36804.242662]  bch2_do_discards_work+0x1d/0x60 [bcachefs]
[36804.242719]  process_one_work+0x18d/0x340
[36804.242724]  worker_thread+0x225/0x360
[36804.242726]  ? __pfx_worker_thread+0x10/0x10
[36804.242729]  kthread+0xfb/0x250
[36804.242731]  ? __pfx_kthread+0x10/0x10
[36804.242733]  ? _raw_spin_unlock+0xe/0x30
[36804.242735]  ? finish_task_switch.isra.0+0x99/0x2e0
[36804.242738]  ? __pfx_kthread+0x10/0x10
[36804.242739]  ? __pfx_kthread+0x10/0x10
[36804.242741]  ret_from_fork+0x199/0x1d0
[36804.242743]  ? __pfx_kthread+0x10/0x10
[36804.242745]  ret_from_fork_asm+0x1a/0x30
[36804.242749]  </TASK>
[36804.242749] ---[ end trace 0000000000000000 ]---
[36804.244785] ------------[ cut here ]------------
[36804.244787] btree trans held srcu lock (delaying memory reclaim) for 1237 seconds
[36804.244800] WARNING: CPU: 0 PID: 1819 at src/fs/bcachefs/btree_iter.c:3331 bch2_trans_srcu_unlock+0x11b/0x130 [bcachefs]
[36804.244878] Modules linked in: bcachefs(O) chacha_x86_64 libchacha libpoly1305 poly1305_x86_64 lz4hc_compress lz4_compress xor raid6_pq qrtr snd_seq_dummy snd_hrtimer snd_seq snd_seq_device af_packet rfkill nls_iso8859_1 nls_cp437 vfat fat snd_hda_codec_generic snd_hda_intel snd_intel_dspcfg intel_rapl_msr snd_intel_sdw_acpi iTCO_wdt intel_pmc_bxt watchdog xt_conntrack snd_hda_codec nf_conntrack snd_hda_core nf_defrag_ipv6 nf_defrag_ipv4 snd_hwdep edac_core snd_pcm intel_rapl_common polyval_clmulni ghash_clmulni_intel sha512_ssse3 sha1_ssse3 i2c_i801 psmouse aesni_intel i2c_smbus i2c_mux snd_timer ip6t_rpfilter ipt_rpfilter snd soundcore joydev lpc_ich mousedev rtc_cmos evdev xt_pkttype intel_agp tiny_power_button xt_LOG nf_log_syslog input_leds intel_gtt button led_class nft_compat mac_hid serio_raw nf_tables sch_fq_codel loop kvm_amd ccp kvm irqbypass fuse efi_pstore configfs nfnetlink efivarfs dmi_sysfs qemu_fw_cfg autofs4 ext4 crc16 mbcache jbd2 hid_generic usbhid hid sr_mod cdrom virtio_net net_failover failover
[36804.244931]  virtio_blk virtio_scsi ahci libahci libata atkbd libps2 vivaldi_fmap xhci_pci xhci_hcd scsi_mod scsi_common virtio_pci virtio_pci_legacy_dev virtio_pci_modern_dev i8042 serio virtio_rng rng_core virtio_gpu virtio_dma_buf virtio_console virtio_balloon virtio virtio_ring dm_mod dax
[36804.244948] CPU: 0 UID: 0 PID: 1819 Comm: bch-copygc/vdb2 Tainted: G        W  O        6.16.9 #1-NixOS PREEMPT(voluntary)
[36804.244952] Tainted: [W]=WARN, [O]=OOT_MODULE
[36804.244953] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS edk2-stable202408-prebuilt.qemu.org 08/13/2024
[36804.244954] RIP: 0010:bch2_trans_srcu_unlock+0x11b/0x130 [bcachefs]
[36804.245024] Code: bc d6 48 c7 c7 d8 0a 38 c1 48 b9 cf f7 53 e3 a5 9b c4 20 48 29 d0 48 c1 e8 03 48 f7 e1 48 89 d6 48 c1 ee 04 e8 56 2f ec d4 90 <0f> 0b 90 90 eb 9f 90 0f 0b 90 eb ab 66 0f 1f 84 00 00 00 00 00 90
[36804.245026] RSP: 0018:ffffcebc83e437e8 EFLAGS: 00010282
[36804.245028] RAX: 0000000000000000 RBX: ffff8d0d08ba8000 RCX: 0000000000000027
[36804.245030] RDX: ffff8d0ef5c1e408 RSI: 0000000000000001 RDI: ffff8d0ef5c1e400
[36804.245031] RBP: ffff8d0d85e40000 R08: 0000000000000000 R09: ffffcebc83e43678
[36804.245033] R10: ffffffff98110a28 R11: 0000000000000003 R12: ffff8d0d08ba83e0
[36804.245034] R13: ffff8d0d08ba83e0 R14: ffff8d0d08ba8000 R15: 0000000000000000
[36804.245038] FS:  0000000000000000(0000) GS:ffff8d0f5d14f000(0000) knlGS:0000000000000000
[36804.245040] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[36804.245041] CR2: 00007f9a8b442d00 CR3: 0000000103ebe000 CR4: 0000000000350ef0
[36804.245045] Call Trace:
[36804.245046]  <TASK>
[36804.245048]  ? bch2_trans_begin+0xc3/0x8e0 [bcachefs]
[36804.245112]  bch2_trans_begin+0x50a/0x8e0 [bcachefs]
[36804.245189]  __bch2_move_data_phys+0x2bf/0xce0 [bcachefs]
[36804.245276]  ? __pfx_evacuate_bucket_pred+0x10/0x10 [bcachefs]
[36804.245353]  ? bch2_evacuate_bucket+0xcc/0x130 [bcachefs]
[36804.245419]  bch2_evacuate_bucket+0xcc/0x130 [bcachefs]
[36804.245483]  ? __pfx_evacuate_bucket_pred+0x10/0x10 [bcachefs]
[36804.245547]  bch2_copygc+0x113/0x350 [bcachefs]
[36804.245612]  bch2_copygc_thread+0x309/0x560 [bcachefs]
[36804.245675]  ? bch2_copygc_thread+0x28f/0x560 [bcachefs]
[36804.245740]  ? __pfx_bch2_copygc_thread+0x10/0x10 [bcachefs]
[36804.245801]  kthread+0xfb/0x250
[36804.245804]  ? __pfx_kthread+0x10/0x10
[36804.245806]  ret_from_fork+0x199/0x1d0
[36804.245809]  ? __pfx_kthread+0x10/0x10
[36804.245811]  ret_from_fork_asm+0x1a/0x30
[36804.245814]  </TASK>
[36804.245815] ---[ end trace 0000000000000000 ]---