neon: Gc failed, retrying: could not find data for key 010000000000000000000000000000000000

https://neondb.slack.com/archives/C03H1K0PGKH/p1671039692717009

It is not clear why GC tries to look so far in the past, when previous GC iteration for this timeline takes place

One theoretical reason could be remote storage restoration: we only update metadata on S3 when some layer gets uploaded, so latest_gc_cutoff_lsn in metadata could go quite late on local disk without any updates to reflect that on S3, then something removes local disk data and very early latest_gc_cutoff_lsn gets downloaded from S3 along with the layers.

latest_gc_cutoff_lsn just determines boundary of PITR (prohibiting requests with smaller LSN). Also it is used to check whether it is time to start new GC iterations. The rule is the following:

1. Choose new gc cutoff. It is calculated as min(last_record_lsn - gc_horizon, find_lsn_for_timestamp(current_time - pitr_interval))
2. Compare new gc cutoff with old gc cutoff: GC is performed only if it is larger.

So doesn’t matter which value of latest_gc_cutoff_lsn is stored in metadata. It doesn’t affect new gc cutoff.

The problem is that GC code tries to get from storage some value which has to be reconstructed. Whiles colleting data for reconstruction we goo too far in the past. We know key: it is SlruDir. It is used in:

1. get_slru_segment_exists
2. list_slru_segments
3. collect_keyspace
4. put_slru_segment_creation
5. drop_slru_segment

3 is used by compaction, 4-5 - by wal receiver, 1-2 - by basebackup, wal receiver and … is_latest_commit_timestamp_ge_than ! The last one is called by find_lsn_for_timestamp which is used to determine cutoff boundary based on pitr_interval.

So looks like the source of the problem is now clear (thanks to @SomeoneToIgnore)! find_lsn_for_timestamp is using binary search in boundaries latest_gc_cutoff..last_record_lsn If value of latest_gc_cutoff is actually too small and precedes actually performed GC, then we may try to access already removed record.