syncing large files to disk causes ~4min disk hangs with heavy `reconcile_btree` / `sectors_alloc` traffic

[scottjg]

Hi- This is a weird setup, so it's possible that it has something to do with my configuration or disks, but I'm just trying bcachefs for the first time and have run into this issue.

I have 2 older 4TB HDDs connected via USB, along with a 500GB usb ssd, plugged into an Intel N150 host. The host runs KVM (Proxmox) and passes through the HDDs as virtio-block devices and the ssd as virtio-scsi devices into a VM. The VM is running Fedora 44 (Linux 7.0.12-201), and I am running the latest bcachefs modules via dkms (1.38.6-1) in the VM.

The filesystem was formatted like this:

bcachefs format \
  --label=ssd.ssd1 /dev/sdb1 \
  --label=hdd.hdd1 /dev/vda1 \
  --label=hdd.hdd2 /dev/vdb1 \
  --data_replicas=1 --metadata_replicas=2 --foreground_target=ssd --promote_target=ssd --background_target=hdd

In general, this seems to work ok. I can run some sequential write tests with fio on the bcachefs filesystem, and performance is close-ish to saturating the SSD.

Unfortunately, when I try to sync large files (20GB+ for a total of ~3TB) via lftp, after a few files, the transfers begin to hang. I can see the process is stuck in the D state, and if i touch the filesystem, it also hangs. in bcachefs fs top, i see that reconcile_btree is writing 111M/s and sectors_alloc is running at 112M/s. CPU usage appears reasonable (various bcachefs kworkers consuming ~80% of a core) . After about 4 minutes, it eventually becomes unstuck, until it happens again after more disk activity.

I can see in the kernel logs that there are a bunch of warnings like this about the lock being too long:

[20610.957728] ------------[ cut here ]------------
[20610.957729]  nft_fib_ipv6 nft_fib nft_reject_inet nf_reject_ipv4 nf_reject_ipv6 nft_reject nft_ct nft_chain_nat nf_nat
[20610.957732] btree trans held srcu lock (delaying memory reclaim) for 233 seconds
               reconcile_btree:	0	113152	45056	203776	128000	81920	146432	134656	150528	202752	44544	186368	151552	29184	158720	144384	136192	95744	128000	158208
               bucket_discard_worker:	0	13	6	21	11	14	21	20	21	21	722	19	7	23	27	28	11	27	25
               bucket_alloc:	0	58	22	100	62	40	72	66	73	99	22	974	14	77	71	67	46	63	77
               sectors_alloc:	2048	118272	45056	203776	128512	81920	145920	135168	150016	202752	44544	186880	151552	28672	158720	144896	135680	96256	128000	159232
               btree_cache_cannibalize_lock:	2	226	88	398	251	160	285	264	293	396	87	365	296	56	310	284	265	188	255	318
               btree_cache_cannibalize_unlock:	2	226	88	398	251	160	285	264	293	396	87	365	296	56	310	284	265	188	255	318
               btree_node_write:	4	232	88	398	250	160	286	263	294	396	8365	296	58	310	284	268	187	250	311
               btree_node_merge:	2	2	0	0	0	0	0	0	0	0	00
               btree_node_merge_attempt:	5	15	0	0	0	0	0	0	0	00
               btree_node_split:	0	4	0	0	0	0	0	0	0	0	01
               btree_node_rewrite
[20610.957736]  nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 nvidia_uvm(OE) nf_tables nfnetlink qrtr bcachefs(OE) sunrpc nvidia_drm(OE) nvidia_modeset(OE) intel_rapl_msr intel_rapl_common intel_pmc_core pmt_telemetry pmt_discovery pmt_class intel_pmc_ssram_telemetry intel_vsec nvidia(OE) kvm_intel snd_hda_codec_nvhdmi snd_hda_codec_hdmi iTCO_wdt kvm intel_pmc_bxt irqbypass rapl snd_hda_intel snd_hda_codec vfat fat i2c_i801 snd_hda_core i2c_smbus drm_ttm_helper lpc_ich virtio_net net_failover failover virtio_balloon ttm snd_intel_dspcfg video wmi snd_intel_sdw_acpi snd_hwdep snd_seq snd_seq_device snd_pcm snd_timer snd soundcore joydev dm_multipath zram lz4hc_compress lz4_compress vmw_vsock_virtio_transport vmw_vsock_virtio_transport_common vsock xfs ghash_clmulni_intel virtio_scsi virtio_gpu virtio_dma_buf serio_raw i2c_dev scsi_dh_rdac scsi_dh_emc scsi_dh_alua qemu_fw_cfg virtiofs fuse
[20610.957739] WARNING: src/fs/bcachefs/btree/locking.c:1243 at bch2_trans_unlock_long+0x251/0x270 [bcachefs], CPU#0: kworker/u16:6/97476
[20610.957795] CPU: 1 UID: 0 PID: 108370 Comm: kworker/u17:4 Tainted: G        W  OE       7.0.12-201.fc44.x86_64 #1 PREEMPT(lazy) 
[20610.957799] Tainted: [W]=WARN, [O]=OOT_MODULE, [E]=UNSIGNED_MODULE
[20610.957800] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 4.2025.05-2 11/13/2025
[20610.957849] Modules linked in: nf_conntrack_netlink xt_nat veth xt_conntrack xt_MASQUERADE bridge stp llc xt_set ip_set xt_addrtype nft_compat overlay rfkill nft_redir nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nft_fib nft_reject_inet nf_reject_ipv4 nf_reject_ipv6 nft_reject nft_ct nft_chain_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 nvidia_uvm(OE) nf_tables nfnetlink qrtr bcachefs(OE) sunrpc nvidia_drm(OE) nvidia_modeset(OE) intel_rapl_msr intel_rapl_common intel_pmc_core pmt_telemetry pmt_discovery pmt_class intel_pmc_ssram_telemetry intel_vsec nvidia(OE) kvm_intel snd_hda_codec_nvhdmi
[20610.957802] Workqueue: bcachefs bch2_write_point_do_index_updates [bcachefs]
[20610.957874]  snd_hda_codec_hdmi iTCO_wdt kvm intel_pmc_bxt irqbypass rapl snd_hda_intel snd_hda_codec vfat fat i2c_i801 snd_hda_core i2c_smbus drm_ttm_helper lpc_ich virtio_net net_failover failover virtio_balloon ttm snd_intel_dspcfg video wmi snd_intel_sdw_acpi snd_hwdep snd_seq snd_seq_device snd_pcm snd_timer snd soundcore joydev dm_multipath zram lz4hc_compress lz4_compress vmw_vsock_virtio_transport vmw_vsock_virtio_transport_common vsock xfs ghash_clmulni_intel virtio_scsi virtio_gpu virtio_dma_buf serio_raw i2c_dev scsi_dh_rdac scsi_dh_emc scsi_dh_alua qemu_fw_cfg virtiofs fuse
[20610.957901] CPU: 0 UID: 0 PID: 97476 Comm: kworker/u16:6 Tainted: G        W  OE       7.0.12-201.fc44.x86_64 #1 PREEMPT(lazy) 
[20610.957904] Tainted: [W]=WARN, [O]=OOT_MODULE, [E]=UNSIGNED_MODULE
[20610.957905] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 4.2025.05-2 11/13/2025
[20610.957906] Workqueue: writeback wb_workfn (flush-bcachefs-1)
[20610.957912] RIP: 0010:bch2_trans_unlock_long+0x256/0x270 [bcachefs]

[20610.958022] Code: 50 48 8b 44 24 30 48 89 44 24 58 e8 14 3f 12 00 4c 8b 04 24 e9 6b fe ff ff e8 06 fb 0d ea 48 8d 3d cf 1a d8 ff 48 8b 74 24 10 <67> 48 0f b9 3a 4c 8b 04 24 eb 9b 0f 1f 40 00 66 66 2e 0f 1f 84 00
[20610.958025] RSP: 0018:ffffd43362eff980 EFLAGS: 00010202
[20610.958027] RAX: 0000000000000001 RBX: ffff8eba7dc64000 RCX: 0000000000001388
[20610.958029] RDX: 000000010135ecfa RSI: ffff8eb9890c1000 RDI: ffffffffc2402ad0
[20610.958030] RBP: ffff8eba7dc64000 R08: ffff8eb84f500000 R09: 00000000ffffffff
[20610.958031] R10: 0000000000000008 R11: 0000000000000000 R12: ffff8eb84f500000
[20610.958033] R13: ffff8eb8241a38e0 R14: ffff8eb84f500000 R15: 0000000000000000
[20610.958034] FS:  0000000000000000(0000) GS:ffff8ebb8129a000(0000) knlGS:0000000000000000
[20610.958036] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[20610.958037] CR2: 00007f2b7d39ef30 CR3: 00000001299ec006 CR4: 0000000000f72ef0
[20610.958041] PKRU: 55555554
[20610.958042] Call Trace:
[20610.958045]  <TASK>
[20610.958022] RIP: 0010:bch2_trans_unlock_long+0x256/0x270 [bcachefs]
[20610.958049]  bch2_trans_put+0x34/0x220 [bcachefs]
[20610.958121] Code: 50 48 8b 44 24 30 48 89 44 24 58 e8 14 3f 12 00 4c 8b 04 24 e9 6b fe ff ff e8 06 fb 0d ea 48 8d 3d cf 1a d8 ff 48 8b 74 24 10 <67> 48 0f b9 3a 4c 8b 04 24 eb 9b 0f 1f 40 00 66 66 2e 0f 1f 84 00
[20610.958123] RSP: 0018:ffffd4334589ba50 EFLAGS: 00010202
[20610.958125] RAX: 0000000000000001 RBX: ffff8eb8e9440000 RCX: fffffffffffb6515
[20610.958127] RDX: 0000000000000000 RSI: ffff8eba9f2de000 RDI: ffffffffc2402ad0
[20610.958128] RBP: 0000000000000023 R08: ffff8eb84f500000 R09: 00000000ffffffff
[20610.958129] R10: 0000000000000008 R11: 0000000000000000 R12: ffff8eb8e9440000
[20610.958130] R13: 000012886281d089 R14: ffff8eb84f500000 R15: ffff8eb8d3409708
[20610.958131] FS:  0000000000000000(0000) GS:ffff8ebb8131a000(0000) knlGS:0000000000000000
[20610.958132] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[20610.958133] CR2: 00007f2b7d457ff0 CR3: 00000001ec91d005 CR4: 0000000000f72ef0
[20610.958137] PKRU: 55555554
[20610.958138] Call Trace:
[20610.958139]  <TASK>
[20610.958141]  bch2_trans_begin+0x50c/0x630 [bcachefs]
[20610.958147]  ? __pfx_inode_update_times_fn+0x10/0x10 [bcachefs]
[20610.958229]  bch2_write_inode+0x9e/0x190 [bcachefs]
[20610.958227]  bch2_write_index_default+0x136/0x740 [bcachefs]
[20610.958326]  ? psi_group_change+0x186/0x430
[20610.958307]  bch2_vfs_write_inode+0x44/0x80 [bcachefs]
[20610.958377]  write_inode+0x5d/0x130
[20610.958380]  __writeback_single_inode+0x211/0x280
[20610.958383]  ? _raw_spin_unlock+0xe/0x30
[20610.958386]  writeback_sb_inodes+0x270/0x550
[20610.958391]  __writeback_inodes_wb+0x5d/0x100
[20610.958333]  ? __bch2_write_index+0x23d/0x790 [bcachefs]
[20610.958394]  wb_writeback+0x2f7/0x390
[20610.958396]  wb_workfn+0x316/0x550
[20610.958399]  ? __schedule+0x2c8/0x630
[20610.958401]  process_one_work+0x19e/0x3a0
[20610.958404]  worker_thread+0x1a6/0x310
[20610.958407]  ? __pfx_worker_thread+0x10/0x10
[20610.958409]  kthread+0xe4/0x120
[20610.958412]  ? __pfx_kthread+0x10/0x10
[20610.958414]  ret_from_fork+0x1a1/0x270
[20610.958417]  ? __pfx_kthread+0x10/0x10
[20610.958419]  ret_from_fork_asm+0x1a/0x30
[20610.958423]  </TASK>
[20610.958423] ---[ end trace 0000000000000000 ]---
[20610.958487]  __bch2_write_index+0x23d/0x790 [bcachefs]
[20610.958597]  ? dequeue_entity+0xf3/0x710
[20610.958601]  ? psi_group_change+0x186/0x430
[20610.958605]  bch2_write_point_do_index_updates+0xca/0x250 [bcachefs]
[20610.958770]  ? __schedule+0x2c8/0x630
[20610.958773]  process_one_work+0x19e/0x3a0
[20610.958777]  worker_thread+0x1a6/0x310
[20610.958779]  ? __pfx_worker_thread+0x10/0x10
[20610.958782]  kthread+0xe4/0x120
[20610.958785]  ? __pfx_kthread+0x10/0x10
[20610.958787]  ret_from_fork+0x1a1/0x270
[20610.958790]  ? __pfx_kthread+0x10/0x10
[20610.958791]  ret_from_fork_asm+0x1a/0x30
[20610.958795]  </TASK>
[20610.958796] ---[ end trace 0000000000000000 ]---

let me know if there's any additional data you would like me to collect.

[scottjg]

if i only do one metadata replica (so presumably, the metadata lives on the ssd only). it works great. so maybe having 1 ssd and one 1 hdd metadata replica is just not a good configuration.

[ilo1971]

Hi!
I see a similar problem with a different configuration: 2 SSD (u.2) + 4 НDD (sata), metadata_replicas=3, data_replicas=3, erasure_code=1. Reconcile is running after writing a lot of files to the bcachefs:

# bcache reconcile status
Scan pending:     0
                   data  metadata  
  replicas:           0         0  
  checksum:           0         0  
  erasure_code:   2.26T         0  
  compression:     351G         0  
  target:          702G     31.2G  
  high_priority:      0         0  
  pending:            0         0  
  stripes:            0         0  

processing normal btree: 2:130207211:0

# bcache fs top
  reconcile_btree                             116391936/s     3557818368 30677785640960
  sectors_alloc                               131334144/s     5724962816 39981711368192
  transaction_begin                               82867/s        5259682    71183450483
  error_throw                                       772/s          75160     5784395387

  [counters]  [devices]

                                                 read/s           read        write/s          write
► nvme2n1p18/btree                                      0     8832679936          24576  2581308755968
  nvme2n1p18/journal                                    0              0        1138688   453616898048
  nvme2n1p18/parity                                     0     8166309888              0    17838374912
  nvme2n1p18/sb                                         0       39370752              0      310044672
  nvme2n1p18/user                                       0   413485645824              0   693755097088
  nvme3n1p18/btree                                      0    10305142784          24576  1813101637632
  nvme3n1p18/journal                                    0              0        1138688   443031588864
  nvme3n1p18/parity                                     0     6557794304              0    14776532992
  nvme3n1p18/sb                                         0       39370752              0      310044672
  nvme3n1p18/user                                       0   384976240640              0   594961756160
  sdaw1/btree                                           0        8388608       35221504 13474864242688
  sdaw1/journal                                         0              0              0   274278080512
  sdaw1/parity                                          0    30169628672              0   372821196800
  sdaw1/sb                                              0       39370752              0      310044672
  sdaw1/user                                            0   732478488576              0  3190294085632
  sdax1/btree                                           0       12845056       35348480 13432313536512
  sdax1/journal                                         0              0              0   266335305728
  sdax1/parity                                          0    32841400320              0   378720485376
  sdax1/sb                                              0       39370752              0      310044672
  sdax1/user                                            0   696774168576              0  3150993170432
  sday1/btree                                           0       11796480       35221504 13150400430080
  sday1/journal                                         0              0              0   254255640576
  sday1/parity                                          0    32837206016              0   381400645632
  sday1/sb                                              0       39370752              0      310044672
  sday1/user                                            0   642136662016              0  3053523636224
  sdaz1/btree                                           0       14155776          24576  1797410226176
  sdaz1/journal                                         0              0              0   252714369024
  sdaz1/parity                                          0    36058431488              0   398551154688
  sdaz1/sb                                              0       39370752              0      310044672
  sdaz1/user                                            0   528822247424              0  1065690316800
  sdbb1/btree                                           0       14417920              0  1382415048704
  sdbb1/journal                                         0              0        1138688   248940240896
  sdbb1/parity                                          0    38025560064              0   403431227392
  sdbb1/sb                                              0       39370752              0      310044672
  sdbb1/user                                            0   527357927424              0   759251054592

counter runs, process seems to go, but user operations hangs:
3756691 pts/3 D+ 0:00 rm results/.search_N1_05_2018.tar.xa5F5U
since yesterday.

 bch-reconcile/8-3288745 [207] .l..1 498382.508840: error_throw: 8a179f33-cc5b-4879-921c-c107cec0c6b6: freelist_empty
 bch-reconcile/8-3288745 [207] .l..1 498382.508858: error_throw: 8a179f33-cc5b-4879-921c-c107cec0c6b6: freelist_empty
 bch-reconcile/8-3288745 [207] .l..1 498382.509162: error_throw: 8a179f33-cc5b-4879-921c-c107cec0c6b6: freelist_empty
 bch-reconcile/8-3288745 [207] .l..1 498382.509180: error_throw: 8a179f33-cc5b-4879-921c-c107cec0c6b6: freelist_empty
 bch-reconcile/8-3288745 [207] .l..1 498382.509592: error_throw: 8a179f33-cc5b-4879-921c-c107cec0c6b6: freelist_empty
 bch-reconcile/8-3288745 [207] .l..1 498382.509610: error_throw: 8a179f33-cc5b-4879-921c-c107cec0c6b6: freelist_empty
 bch-reconcile/8-3288745 [207] .l..1 498382.510202: error_throw: 8a179f33-cc5b-4879-921c-c107cec0c6b6: freelist_empty
 bch-reconcile/8-3288745 [207] .l..1 498382.510219: error_throw: 8a179f33-cc5b-4879-921c-c107cec0c6b6: freelist_empty
 bch-reconcile/8-3288745 [207] .l..1 498382.510504: error_throw: 8a179f33-cc5b-4879-921c-c107cec0c6b6: freelist_empty

------------[ cut here ]------------
------------[ cut here ]------------
btree trans held srcu lock (delaying memory reclaim) for 31117 seconds
reconcile_btree:        7168    60416   43520   150528  163328  97792   116224  147968  57344   129024  88576   118784  96256   141312  164352  123392  101888  123392  136704  140800
bucket_discard_worker:  13      71      47      201     204     114     154     233     106     63      103     136     122     207     231     169     114     178     194     206
bucket_discard: 221     0       148     0       176     0       192     0       180     0       186     0       159     0       166     0       176     0       198     0
bucket_alloc:   4       47      31      112     120     72      84      108     42      96      66      87      72      104     121     92      74      90      102     102
sectors_alloc:  7680    61952   44032   151040  164352  97280   116736  147968  57344   131072  89088   119296  97280   142848  164352  124928  102400  123904  137728  140800
btree_cache_cannibalize_lock:   15      119     85      294     320     190     228     289     112     254     173     232     188     277     321     242     200     242     268     276
btree_cache_cannibalize_unlock: 15      119     85      294     320     190     228     289     112     254     173     232     188     277     321     242     200     242     268     276
btree_node_write:       65      146     90      324     352     211     254     317     125     277     194     252     212     306     352     271     213     270     291     295
btree_node_compact:     0       1       1       0       1       0       0       0       0       0       1       1       2       1       0       0       0       0       1       1
btree_node_merge:       0       0       0       1       0
btree trans held srcu lock (delaying memory reclaim) for 31117 seconds
reconcile_btree:        7168    60416   43520   150528  163328  97792   116224  147968  57344   129024  88576   118784  96256   141312  164352  123392  101888  123392  136704  140800
bucket_discard_worker:  13      71      47      201     204     114     154     233     106     63      103     136     122     207     231     169     114     178     194     206
bucket_discard: 221     0       148     0       176     0       192     0       180     0       186     0       159     0       166     0       176     0       198     0
bucket_alloc:   4       47      31      112     120     72      84      108     42      96      66      87      72      104     121     92      74      90      102     102
sectors_alloc:  7680    61952   44032   151040  164352  97280   116736  147968  57344   131072  89088   119296  97280   142848  164352  124928  102400  123904  137728  140800
btree_cache_cannibalize_lock:   15      119     85      294     320     190     228     289     112     254     173     232     188     277     321     242     200     242     268     276
btree_cache_cannibalize_unlock: 15      119     85      294     320     190     228     289     112     254     173     232     188     277     321     242     200     242     268     276
btree_node_write:       65      146     90      324     352     211     254     317     125     277     194     252     212     306     352     271     213     270     291     295
btree_node_compact:     0       1       1       0       1       0       0       0       0       0       1       1       2       1       0       0       0       0       1       1
btree_node_merge:       0       0       0       1       0
WARNING: src/fs/bcachefs/btree/locking.c:1243 at bch2_trans_unlock_long+0x23c/0x250 [bcachefs], CPU#230: bch-copygc/8a17/3288744
WARNING: src/fs/bcachefs/btree/locking.c:1243 at bch2_trans_unlock_long+0x23c/0x250 [bcachefs], CPU#131: kworker/u1027:2/3609505
. . .
CPU: 230 UID: 0 PID: 3288744 Comm: bch-copygc/8a17 Tainted: P        W  OE       7.0.10+deb13-amd64 #1 PREEMPT(lazy)  Debian 7.0.10-1~bpo13+1 
 amd_atl
Tainted: [P]=PROPRIETARY_MODULE, [W]=WARN, [O]=OOT_MODULE, [E]=UNSIGNED_MODULE
 intel_rapl_msr
Hardware name: AMD Corporation Default string/Default string, BIOS 5.14 02/22/2021
 intel_rapl_common
RIP: 0010:bch2_trans_unlock_long+0x241/0x250 [bcachefs]
 nvidia_modeset(POE)
Code: 48 89 44 24 48 48 8b 44 24 28 48 89 44 24 50 e8 f5 87 11 00 e9 79 fe ff ff e8 cb ca 4b ce 48 8d 3d c4 40 e1 ff 48 8b 74 24 08 <67> 48 0f b9 3a eb a7 0f 1f 84 00 00 00 00 00 90 90 90 90 90 90 90
 amd64_edac
RSP: 0018:ffffd50083ef39d8 EFLAGS: 00010202
 ses

 sd_mod edac_mce_amd
RAX: 0000000000000001 RBX: ffff9000d73cc000 RCX: 0000000000000a2b
 enclosure
RDX: 0000000000000000 RSI: ffff906fd17de000 RDI: ffffffffc628faa0
 kvm_amd
RBP: ffff9008dd800000 R08: ffffffffc6724a68 R09: 00000000ffffffff
 sg
R10: 0000000000000008 R11: 0000000000000000 R12: ffff9000d73cc000
 video jc42
R13: 00018829732e334e R14: ffff9008dd800000 R15: ffff9000d73cc338
 wmi
FS:  0000000000000000(0000) GS:ffff90fb78ea0000(0000) knlGS:0000000000000000
 kvm
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
 ixgbe
CR2: 00007fc8842f641c CR3: 00000103029d7000 CR4: 0000000000350ef0
 ast
Call Trace:
 nls_ascii
 <TASK>
 ahci
 bch2_trans_begin+0x6f6/0x910 [bcachefs]
 libie_fwlog
 __bch2_write+0x17e/0x15a0 [bcachefs]
 ee1004
 ? bch2_moving_ctxt_do_pending_writes+0xe2/0x120 [bcachefs]
 mpt3sas
 bch2_moving_ctxt_do_pending_writes+0xe2/0x120 [bcachefs]
 nls_cp437
 move_buckets_wait+0x99/0x170 [bcachefs]
 drm_client_lib
 ? __pfx_autoremove_wake_function+0x10/0x10
 libahci
 bch2_copygc_thread+0x49c/0x4c0 [bcachefs]
 irqbypass raid_class
 ? bch2_copygc_thread+0x1d9/0x4c0 [bcachefs]
 vfat ghash_clmulni_intel
 ? __pfx_bch2_copygc_thread+0x10/0x10 [bcachefs]
 sp5100_tco
 kthread+0xe3/0x120
 xfrm_algo
 ? __pfx_kthread+0x10/0x10
 libata
 ret_from_fork+0x2cf/0x360
 drm_shmem_helper
 ? __pfx_kthread+0x10/0x10
 ipmi_ssif
 ret_from_fork_asm+0x1a/0x30
 megaraid_sas
 </TASK>
 scsi_transport_sas
---[ end trace 0000000000000000 ]---
 nvidia(POE) fat aesni_intel acpi_ipmi watchdog igb mdio zfs(POE) mlx4_core ipmi_si rapl drm_kms_helper dca scsi_mod i2c_piix4 i2c_algo_bit ccp acpi_cpufreq ipmi_devintf pcspkr scsi_common i2c_smbus ipmi_msghandler k10temp spl(OE) button evdev joydev ib_umad ib_ipoib ib_cm ib_core nvme_fabrics drm efi_pstore configfs nfnetlink efivarfs ip_tables x_tables autofs4 hid_generic usbhid hid ext4 crc16 mbcache jbd2 crc32c_cryptoapi xhci_pci xhci_hcd nvme nvme_core usbcore nvme_keyring nvme_auth hkdf usb_common [last unloaded: bfq]
CPU: 131 UID: 0 PID: 3609505 Comm: kworker/u1027:2 Tainted: P        W  OE       7.0.10+deb13-amd64 #1 PREEMPT(lazy)  Debian 7.0.10-1~bpo13+1 
Tainted: [P]=PROPRIETARY_MODULE, [W]=WARN, [O]=OOT_MODULE, [E]=UNSIGNED_MODULE
Hardware name: AMD Corporation Default string/Default string, BIOS 5.14 02/22/2021
Workqueue: writeback wb_workfn (flush-bcachefs-13)
RIP: 0010:bch2_trans_unlock_long+0x241/0x250 [bcachefs]
Code: 48 89 44 24 48 48 8b 44 24 28 48 89 44 24 50 e8 f5 87 11 00 e9 79 fe ff ff e8 cb ca 4b ce 48 8d 3d c4 40 e1 ff 48 8b 74 24 08 <67> 48 0f b9 3a eb a7 0f 1f 84 00 00 00 00 00 90 90 90 90 90 90 90
RSP: 0018:ffffd500860cb998 EFLAGS: 00010202
RAX: 0000000000000001 RBX: ffff8f27216ec000 RCX: 0000000000000a2b
RDX: 0000000106e2839d RSI: ffff8f8f67eb5000 RDI: ffffffffc628faa0
RBP: ffff9008dd800000 R08: ffffffffc6724a68 R09: 00000000ffffffff
R10: 0000000000000008 R11: 0000000000000000 R12: ffff9008dd800000
R13: ffff9013b65e56e0 R14: ffff9008dd800000 R15: 0000000000000070
FS:  0000000000000000(0000) GS:ffff8fff779e0000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00005570a6aa92e4 CR3: 00000103029d7000 CR4: 0000000000350ef0
Call Trace:
 <TASK>
 bch2_trans_put+0x27/0x1e0 [bcachefs]
 bch2_write_inode+0x9e/0x190 [bcachefs]
 ? __pfx_inode_update_times_fn+0x10/0x10 [bcachefs]
 bch2_vfs_write_inode+0x44/0x80 [bcachefs]
 __writeback_single_inode+0x26e/0x330
 writeback_sb_inodes+0x231/0x570
 __writeback_inodes_wb+0x4c/0xf0
 wb_writeback+0x1a1/0x350
 wb_workfn+0x36d/0x460
 process_one_work+0x198/0x390
 worker_thread+0x1af/0x320
 ? __pfx_worker_thread+0x10/0x10
 kthread+0xe3/0x120
 ? __pfx_kthread+0x10/0x10
 ret_from_fork+0x2cf/0x360
 ? __pfx_kthread+0x10/0x10
 ret_from_fork_asm+0x1a/0x30
 </TASK>
---[ end trace 0000000000000000 ]---

[scottjg]

your setup is a little different than mine since i'm not using compression or erasure coding. i also discovered that my setup had other problems. the usb hdd enclosure that i was using had a bad cable, and after about an hour i was seeing speeds on the hdd drop to usb2 (480mbps), which probably was making everything worse.

[Komzpa]

This looks closely related to the SRCU/blocking-operation class tracked in #1069, even if it may not be the whole story for every setup here.

The matching signals are:

• the report is dominated by reconcile_btree / sectors_alloc traffic while user I/O is stuck;
• the warning is btree trans held srcu lock (delaying memory reclaim) and fires in/around bch2_trans_unlock_long();
• bcachefs: don't hold srcu lock across blocking operations #1069 specifically audits long-blocking sites where a transaction had dropped btree locks but was still holding SRCU, including data/update.c, data/write.c, data/ec/io.c, and data/migrate.c paths that line up with large writes, reconcile, EC/copygc, and metadata/data movement.

Caveat: #1069 is still open and currently has a dirty merge state, and Kent pushed back on the blanket unlock_long() approach there. So I would not call this fixed from that PR as-is. But this issue is a good reproducer/evidence thread for that lock class, especially because the second report has a 31k-second SRCU hold from copygc/writeback while reconcile is active.

For anyone still able to reproduce: the most useful next split is probably testing a build with the current #1069-equivalent SRCU/drop-lock changes (or the narrower accepted replacement if that PR is respun) while keeping the same tiered SSD/HDD workload. If the stall disappears, this is likely the SRCU/blocking boundary bug. If it persists, the remaining evidence points at reconcile/backpressure behavior under slow HDD targets, and the freelist_empty trace spam from the second report should be treated as a separate allocator/reconcile symptom.

[Komzpa]

Opened a narrow bcachefs-tools companion for one of the remaining data-update allocation sites in this SRCU/blocking-operation class:

koverstreet/bcachefs-tools#730

This does not claim the whole reconcile/copygc stall class is fixed. It targets the bch2_data_update_init() path called out by #1069: after btree locks are dropped, data-update bio/bounce-buffer allocation now tries GFP_NOWAIT first and only drops transaction SRCU with bch2_trans_unlock_long() before falling back to GFP_KERNEL.

Local validation for head 01aa5755918408711bdc1091609a95cd8f2d961f:

• git diff --check
• BINDGEN=/home/kom/.cargo/bin/bindgen make -j32 build/fs/data/update.o
• BINDGEN=/home/kom/.cargo/bin/bindgen make -j32 bcachefs