[CBG-4462] High Amount of 409 Conflicts for Replication Status And Checkpoint Documents Due to Status Reporter Leak in ISGR

Product: Sync Gateway
Component: sync-gateway
Issue Link: CBG-4462
Affects Version: 3.2.x
Fix Versions: 3.2.4, 3.3.0

Summary

• This is a Sync Gateway issue where replication processes experience high volumes of HTTP 409 Document update conflict while updating the internal documents used to store replication status.
• This can lead to increased CPU and memory usage, potential goroutine leaks, and replication freezes or stalls.
• The problem may persist even after earlier attempts to address similar replication-related defects, and often correlates with status document update loops during replication reconnects for ISGR (Inter-Sync Gateway Replication) replications.
• It is pertinent to ensure that these conflicts are not actual conflicts happening for use case-related documents, i.e., troubleshooting must confirm that the observed 409s pertain only to replication status or checkpoint documents, not business or application data, so as not to overlook genuine document conflicts requiring proper handling.

Symptoms 

• Hundreds of thousands of 409 warnings in sg_warn.log in a short time, often linked to a specific active replication.
• Spikes in CPU and memory usage on Sync Gateway clusters correlate with periods of high 409 activity.
• Replications appear Running in status, but do not pull the latest remote sequence, consequently causing a freeze or stall.
• Frequent Revision mismatch in setCheckpoint - ... will retry and Couldn't set status for replication: 409 Document update conflict log entries.

Triggers

• Replication reconnection scenarios, especially after networking interruptions or cluster issues.
• Repeated checkpoint updates during conflicts, especially if a checkpointed sequence resets to 0.

Verification

• Review Sync Gateway logs for bursts of 409 Document update conflicts on replication status and checkpoint documents. Note where the conflict is logged (db.(*activeReplicatorCommon)._publishStatus(), db.(*Checkpointer).setLastCheckpointSeq()) For example:

2024-12-02T10:22:48.605Z [WRN] c:replication-pull-pull Couldn't set status for replication: 409 Document update conflict -- db.(*activeReplicatorCommon)._publishStatus() at active_replicator_common.go:369
2024-12-02T16:19:06.568Z [WRN] c:replication-pull-pull Couldn't set status for replication: 409 Document update conflict -- db.(*activeReplicatorCommon)._publishStatus() at active_replicator_common.go:369
2024-12-02T16:19:06.719Z [WRN] c:replication-pull-pull Unable to roll back remote checkpoint: 409 Document update conflict -- db.(*Checkpointer).setLastCheckpointSeq() at active_replicator_checkpointer.go:450
2024-12-02T16:19:08.695Z [WRN] c:replication-pull-pull Unable to roll back remote checkpoint: 409 Document update conflict -- db.(*Checkpointer).setLastCheckpointSeq() at active_replicator_checkpointer.go:450

• On following the impacted ISGR replications (through context c:replication-pull-pull), we observe repeated Revision mismatch in setCheckpoint messages:

2024-12-04T12:00:46.821Z [INF] Replicate: c:replication-pull-pull Revision mismatch in setCheckpoint - updated from "0-139978" to "0-140011" based on existing checkpoint, will retry
2024-12-04T12:00:46.896Z [INF] Replicate: c:replication-pull-pull Revision mismatch in setCheckpoint - updated from "0-215197" to "0-215229" based on existing checkpoint, will retry
2024-12-04T12:00:47.162Z [INF] Replicate: c:replication-pull-pull Revision mismatch in setCheckpoint - updated from "0-215229" to "0-215230" based on existing checkpoint, will retry
2024-12-06T17:00:39.337Z [INF] Replicate: c:replication-pull-pull Revision mismatch in setCheckpoint - updated from "0-141475" to "0-141476" based on existing checkpoint, will retry
2024-12-06T17:00:39.535Z [INF] Replicate: c:replication-pull-pull Revision mismatch in setCheckpoint - updated from "0-141476" to "0-141477" based on existing checkpoint, will retry

• Before conflicts, recurring using checkpointed seq: 0 messages may appear:

2024-12-02T16:19:06.564Z [INF] Replicate: c:replication-pull-pull using checkpointed seq: "0"
2024-12-02T16:19:06.564Z [INF] Replicate: c:replication-pull-pull using checkpointed seq: "0"
2024-12-02T16:19:06.568Z [WRN] c:replication-pull-pull Couldn't set status for replication: 409 Document update conflict -- db.(*activeReplicatorCommon)._publishStatus() at active_replicator_common.go:369

• Track CPU and memory metrics alongside log timestamps. High resource utilization would align with the burst of conflicts.

• Growth in replication stats (sgw_replication_sgr_num_connect_attempts_pull) correlates with growth in the following stats:
  • sgw_resource_utilization_go_memstats_stackinuse
  • sgw_resource_utilization_go_memstats_stacksys
  • sgw_resource_utilization_process_memory_resident
  • sgw_resource_utilization_process_cpu_percent_utilization

Note: Always verify that conflicts reported in logs do not affect use case-related (business/application) documents. User document conflicts suggest a separate data integrity concern and require individualized resolution.

Workarounds

• Short-term: Restart impacted replications. CPU and memory usage should drop, and replications should resume catching up.
• Long-term: Upgrade Sync Gateway to a version with a fix to this issue: 3.2.4 or 3.3.0.