racey behaviour with tail determination between node components and go-header

[renaynay]

Newly initialised light node on arabica on v0.28.0-arabica and started for the first time:

2025-10-12T13:43:53.108+0200    INFO    header/sync     sync/syncer_head.go:142 empty store, initializing...
2025-10-12T13:43:53.208+0200    INFO    header/sync     sync/syncer_head.go:168 subjective initialization finished      {"height": 8502576}
2025-10-12T13:43:53.271+0200    INFO    header/sync     sync/syncer_head.go:214 new network head        {"height": 8502576, "hash": "BC7A8BFF8111E1FC6E0A5ADECE87CBFB6DB74EE18BCA590EB12DBECE4FCFBB4F"}
2025-10-12T13:43:53.271+0200    INFO    header/sync     sync/syncer.go:259      syncing headers {"from": 8401777, "to": 8502576}
2025-10-12T13:43:53.371+0200    INFO    pruner/service  pruner/checkpoint.go:90 reset checkpoint        {"last_pruned_height": 8401776}

arabica-11/header-ex/v0.0.3"}
2025-10-12T13:43:53.371+0200    INFO    pruner/service  pruner/service.go:170   pruning round finished  {"done": 0, "failed": 0, "took": 0.000028209}
2025-10-12T13:43:53.371+0200    WARN    das     das/daser.go:121        checkpoint not found, initializing with Tail (8401776) and Head (8401776)
2025-10-12T13:43:53.371+0200    INFO    das     das/daser.go:160        starting DASer from checkpoint: SampleFrom: 8401776, NetworkHead: 8401776

Starts to hit issues with pruning headers because it tries to prune a range that only partially exists in the header store as the node hasn't had time to sync the full range yet:

2025-10-12T13:43:54.671+0200    INFO    header/store    store/store.go:614      new head        {"height": 8401840, "hash": "16412079759FEE645FB56C782B569904FCC6C87DE2B16DA7FF6F15FDF9355F99"}
2025-10-12T13:43:55.781+0200    INFO    header/store    store/store.go:614      new head        {"height": 8401904, "hash": "E852D63FBA5484C33941EF1B8B4564CC82DB19F2EC030C8BE44E5467FA79C549"}
2025-10-12T13:43:55.817+0200    INFO    header/sync     sync/syncer_head.go:214 new network head        {"height": 8502577, "hash": "ACF761B6915BDC6736E8F629FF696E871E88D94F5F315D82618B1012FB190985"}
2025-10-12T13:43:55.842+0200    INFO    header/sync     sync/syncer_tail.go:132 move tail up from 8401776 to 8485534, pruning the diff...
2025-10-12T13:43:55.842+0200    INFO    header/store    store/store_delete.go:246       deleting range parallel {"from_height": 8401776, "to_height": 8485534, "worker_num": 24}
2025-10-12T13:43:55.904+0200    ERROR   header/store    store/store_delete.go:119       partial delete with error       {"from_height": 8401776, "expected_to_height": 8485534, "actual_to_height": 8485386, "hdrs_not_found": 0, "took(s)": 0.06217325, "err": "hash by height 8485386: datastore: key not found"}
2025-10-12T13:43:55.905+0200    ERROR   header/sync     sync/syncer.go:129      subjective tail {"head": 8502577, "err": "moving tail from 8401776 to 8485534: deleting headers up to newly configured tail(8485534): header/store: delete to height 8485534: hash by height 8485386: datastore: key not found\nsetting tail to 8485386: getting tail: height 8485386: header: not found"}

Immediately hits issues with retrieving headers from store in DASer during catch-up sampling:

2025-10-12T13:43:55.905+0200    INFO    das     das/worker.go:164       sampled header  {"type": "recent", "height": 8502577, "hash": "ACF761B6915BDC6736E8F629FF696E871E88D94F5F315D82618B1012FB190985", "EDS square width": 2, "data root": "3D96B7D238E7E0456F6AF8E7CDF0A67BD6CF9C2089ECB559C659DCAA1F880353", "finished (s)": 0.000004042}
2025-10-12T13:43:55.905+0200    ERROR   das     das/worker.go:186       failed to get header from header store  {"height": 8401877, "finished (s)": 0.000006375}
2025-10-12T13:43:55.905+0200    ERROR   das     das/worker.go:186       failed to get header from header store  {"height": 8401777, "finished (s)": 0.0000085}
2025-10-12T13:43:55.905+0200    ERROR   das     das/worker.go:186       failed to get header from header store  {"height": 8401878, "finished (s)": 0.000003125}
2025-10-12T13:43:55.905+0200    ERROR   das     das/worker.go:186       failed to get header from header store  {"height": 8401778, "finished (s)": 0.000002792}

[renaynay]

Also annoyingly causes DASer to think heights are failed that are just not part of the header chain at the given time

Ref from Josh: https://gist.github.com/jcstein/c858ec774515fafe5e47ed0913c24433

[renaynay]

And this sometimes happens on a fresh start (arabica):

Error: node: failed to start: error getting latest head during Start: subjective tail for head 8516087: moving tail from 8329571 to 8414687: deleting headers up to newly configured tail(8414687): header/store: delete to height 8414687: hash by height 8414556: datastore: key not found
setting tail to 8414556: getting tail: height 8414556: header: not found

A re-start can fix it though, but the problem is still hit sometimes on subsequent restarts:

Error: node: failed to start: error getting latest head during Start: subjective tail for head 8516087: moving tail from 8415287 to 8512752: deleting headers up to newly configured tail(8512752): header/store: delete to height 8512752: hash by height 8512482: datastore: key not found
setting tail to 8512482: getting tail: height 8512482: header: not found

[Wondertan]

The restart problem is orthogonal and is a timing one with the time.Sleep

[renaynay]

This problem only occurs on arabica where block production time was unstable for several days. Syncer estimates a range based on block time, leading to a situation where originally estimated tail was set using avg block time of 6s and once tail was attempted to be renewed based on pruning window, its timestamp was evaluated as outdated and a new tail was estimated.

This causes all other services relying on originally-set tail to experience issue where

• they try to load headers in between outdatedTail --> head and
• all headers between outdatedTail --> newlySetTail fail with header not found as they are pruned from header store before being able to be retrieved

While pruner/service is okay bc of the OnDelete callback (where pruning logic occurs before the header is deleted, ensuring any data downloaded associated with that header will be deleted), DASer will register those failures as sampling failures. This isn't necessarily an issue, but it is 1. confusing for node runner as DASer will report large amount of errors, 2. DASer will store + log those enormous amount of heights.=

There are 2 solutions:

1. just ignore header not found errors in DASer, assuming that if header is not found, there is nothing to sample
2. use header not found error as a queue to recalibrate state of DASer using newly calculated tail (as DASer has access to header store)

[renaynay]

@Wondertan Also proposed exploring an OnDelete option for DASer, which I will look into today.

[renaynay]

OnDelete much better option than the ones I suggested - also makes use of what's available there. Will take that approach