Skip to main content
Docs Developer Videos Webinars Academy Blog Forum Contact

[MB-65069] Catch-up ingestion should be prevented when they are predestined to rollback

Callum 
Product: Couchbase Server
Component: Analytics-Service
Issue Link: MB-65069
Affects Versions: 7.2.x, 7.6.x, 8.0.x
Fix Version: totoro

Summary

Analytics Service catch-up ingestion is repeatedly re-started in some scenarios where it is guaranteed to rollback. This can occur when disk bottlenecks cause recurring timeouts during ingestion.

Symptoms 

  • Analytics Service ingestion is continuously restarted.
  • Repeated rollbacks are observed.

Triggers

  • Disk bottlenecks, exacerbated by the following conditions:
    • A large number of CBAS indexes present (70+).
    • Analytics replicas configured (2+).
    • Slowness from underlying disk subsystem.

In one observed case of this issue, a large number of CBAS indexes were created. Since each link is automatically connected upon creation, this triggered numerous rollbacks from KV.

  • As data ingestion between CBAS and KV begins, the links quickly become disconnected, preventing ingestion from making significant progress. When a link reconnects, it attempts to synchronise the new index with the current state. However, because the existing state lags behind the purge sequence number, a rollback is required.

The reason the rollbacks keep happening is because the replicas involved diverge due to hitting a timeout and as a result, the Analytics Service disconnect the DCP streams to make sure they are in-sync again. This keeps happening before we stream past the Data Service purge point which leads to full rollback once we connect again. In the observed case, the Analytics Service continuously hit a timeout, which is 120 seconds by default, in order to wait for some information to be sent from a partition's active node to the replica and persisted on disk.

Verification

Look for the following log message in ns_server.analytics_warn.log which indicates that ingestion is slow:

2025-01-24T10:05:33.277+00:00 WARN CBAS.messaging.MarkComponentValidTask [Replication Worker-1488779(/10.0.20.10:40150)] 120 seconds passed without receiving flush lsn 281852198 from master for component storage/partition_13/Default/<dataset1>/0/javaClassIdx/998_998_b

Look for the presence of a thread dump in ns_server.analytics_debug.log which indicates a timeout while waiting for information to be persisted:

, "Replication Worker-1488476(/10.0.20.10:44014)" daemon prio=5 Id=3602396 TIMED_WAITING on org.apache.asterix.app.nc.IndexCheckpointManager@5c7213b4 owned by "RemoteLogsNotifier:465bfc2e575534568801454a4e484adb" Id=94
	at java.base@17.0.11/java.lang.Object.wait(Native Method)
	-  waiting on org.apache.asterix.app.nc.IndexCheckpointManager@5c7213b4
	at app//org.apache.asterix.replication.messaging.MarkComponentValidTask.ensureComponentLsnFlushed(MarkComponentValidTask.java:103)
	at app//org.apache.asterix.replication.messaging.MarkComponentValidTask.perform(MarkComponentValidTask.java:68)
	at app//org.apache.asterix.replication.management.ReplicationChannel$ReplicationWorker.handle(ReplicationChannel.java:174)
	at app//org.apache.asterix.replication.management.ReplicationChannel$ReplicationWorker.run(ReplicationChannel.java:140)
	at java.base@17.0.11/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base@17.0.11/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at java.base@17.0.11/java.lang.Thread.run(Thread.java:840)

	Number of locked synchronizers = 1
	- java.util.concurrent.ThreadPoolExecutor$Worker@1877560a

, "RemoteLogsNotifier:465bfc2e575534568801454a4e484adb" daemon prio=5 Id=94 RUNNABLE
	at java.base@17.0.11/sun.nio.ch.FileDispatcherImpl.force0(Native Method)
	at java.base@17.0.11/sun.nio.ch.FileDispatcherImpl.force(FileDispatcherImpl.java:82)
	at java.base@17.0.11/sun.nio.ch.FileChannelImpl.force(FileChannelImpl.java:468)
	at app//org.apache.hyracks.util.file.FileUtil.writeAndForce(FileUtil.java:105)
	at app//org.apache.asterix.app.nc.IndexCheckpointManager.persist(IndexCheckpointManager.java:213)
	at app//org.apache.asterix.app.nc.IndexCheckpointManager.masterFlush(IndexCheckpointManager.java:108)
	-  locked org.apache.asterix.app.nc.IndexCheckpointManager@5c7213b4
	at app//org.apache.asterix.replication.logging.RemoteLogsNotifier.checkpointReplicaIndexes(RemoteLogsNotifier.java:100)
	-  locked org.apache.asterix.app.nc.IndexCheckpointManager@5c7213b4
	at app//org.apache.asterix.replication.logging.RemoteLogsNotifier.run(RemoteLogsNotifier.java:73)

	Number of locked synchronizers = 1
	- java.util.concurrent.ThreadPoolExecutor$Worker@334ebcaa

Look for signs of rollbacks in ns_server.analytics_info.log as below:

// resuming ingestion and trying to reconnect
2025-01-24T09:37:57.674+00:00 INFO CBAS.rebalance.ReplicasRecoveryAttempt [ReplicasSynchronizer] active events handler resumed

// notified that a rollback is needed upon reconnect
2025-01-24T09:37:57.770+00:00 INFO CBAS.adapter.CouchbaseConnector [SAO:JID:2.2202:TAID:TID:ANID:ODID:174:0:41:0:(Local/<dataset1>)[41]:BO] notifying CC of the following required rollbacks: [{"sid":1,"vbucket":298,"open-stream-response":"Rollback required (0x23)","rollback-seq":0},

// rollback performed
2025-01-24T09:38:51.142+00:00 INFO CBAS.runtime.FullRollbackOperatorDescriptor [SAO:JID:2.2203:TAID:TID:ANID:ODID:0:0:1:0] Fully rolledback dataset

// reconnecting and starting ingestion
2025-01-24T09:38:51.143+00:00 INFO CBAS.metadata.BucketEventsListener [Executor-2062:ClusterController] Reconnecting the bucket Default/Local/<dataset1> after performing full rollback(s)

Workarounds

Adjust Analytics Service timeouts to allow ingestion to continue:

  1. SSH to any analytics node.
  2. Run the following curl with a user that has at least analytics_admin role:
curl -v -u Administrator:password -X PUT \
     -d replicaInactivityTimeoutSeconds=3600 \
     -d replicaRecoveryWaitIntervalSeconds=3600 \
     -d replicaReportIntervalSeconds=60 \
     -d replicationTimeout=900 \
     http://localhost:8095/analytics/config/service
  1. Call the Analytics Restart API https://docs.couchbase.com/server/current/analytics-rest-admin/index.html#restart_cluster for the change to take effect:
curl -v -u Administrator:password -X POST http://localhost:8095/analytics/cluster/restart

After the restart, ingestion will most likely reset again, and if we don't run into other unexpected issues, ingestion should continue.

Reduce number of Analytics replicas from 2 to 1 (if applicable):

Reducing the number of Analytics replicas will reduce the load on the disk which can help mitigate the issue scenario. The worst case scenario for Analytics if all replicas are lost is that we will stream the data back from the Data Service, meaning reducing the number of replicas can be acceptable in many scenarios.

To change the number of Analytics replicas from 2 to 1:

  1. Run the following curl command:
curl -v -u Administrator:password --request POST \
  --url http://localhost:8091/settings/analytics \
  --header 'Content-Type: application/x-www-form-urlencoded' \
  --data numReplicas=1
  1. Trigger a rebalance.

Related articles

Comments

0 comments

Article is closed for comments.