Loading...

Details

Type: Bug
Resolution: Fixed
Priority: Blocker
Fix Version/s: 6.6.2, 7.0.0
Affects Version/s: 6.5.1, Cheshire-Cat
Component/s: analytics
Labels:

Triage:
Untriaged
Story Points:
1
Is this a Regression?:
Unknown
Sprint:
CX Sprint 235

Description

Build: 7.0.0-4342

Test:
-test tests/integration/cheshirecat/test_cheshirecat_kv_gsi_coll_xdcr_backup_sgw_fts_itemct_txns.yml -scope tests/integration/cheshirecat/scope_cheshirecat_with_backup.yml
9th iteration

From .74 diag.log:

2021-01-31T19:51:35.317-08:00, ns_vbucket_mover:0:info:message(ns_1@172.23.97.74) - Bucket "default" rebalance appears to be swap rebalance

2021-02-01T02:11:01.374-08:00, ns_orchestrator:0:critical:message(ns_1@172.23.97.74) - Rebalance exited with reason {service_rebalance_failed,cbas,

                              {worker_died,

                               {'EXIT',<0.17438.301>,

                                {rebalance_failed,

                                 {service_error,

                                  <<"Rebalance 7c90f94577e58f0569bbcf1494b45b00 failed: see analytics_info.log for details">>}}}}}.

Rebalance Operation Id = ea8d372c7f79cf599761dbe5e7b01cf8

2021-02-01T02:16:15.375-08:00, ns_cluster:5:info:message(ns_1@172

2021-02-01T02:55:59.262-08:00, analytics:0:warning:message(ns_1@172.23.120.75) - Analytics Service unable to successfully rebalance 2b963730aa495c96edd982759024569f due to 'java.lang.IllegalStateException: timed out waiting for all nodes to join & cluster active (missing nodes: [], state: RECOVERING)'; see analytics_info.log for details

2021-02-01T02:55:59.525-08:00, ns_orchestrator:0:critical:message(ns_1@172.23.97.74) - Rebalance exited with reason {service_rebalance_failed,cbas,

                              {worker_died,

                               {'EXIT',<0.13028.502>,

                                {rebalance_failed,

                                 {service_error,

                                  <<"Rebalance 2b963730aa495c96edd982759024569f failed: timed out waiting for all nodes to join & cluster active (missing nodes: [], state: RECOVERING)">>}}}}}.

Rebalance Operation Id = 736962d5a219db32e386937ceaa3fbaa

From .81 analytics log:

021-02-01T02:11:03.340-08:00 DEBU CBAS.adapter.CouchbaseConnector [HttpExecutor(port:9110)-13] Getting stats and the client is disconnected or not yet established, skipping adding progress info

2021-02-01T02:11:03.340-08:00 DEBU CBAS.adapter.CouchbaseConnector [HttpExecutor(port:9110)-13] Getting stats and the client is disconnected or not yet established, skipping adding progress info

2021-02-01T02:11:03.340-08:00 DEBU CBAS.adapter.CouchbaseConnector [HttpExecutor(port:9110)-13] Getting stats and the client is disconnected or not yet established, skipping adding progress info

2021-02-01T02:11:04.277-08:00 DEBU CBAS.adapter.CouchbaseConnector [Executor-85:266fa65b24d536e4e15c9a24b30694a1:JID:1.15321:TAID:TID:ANID:ODID:4:0:3:0:SA:(Default.Local.NEW_ORDER(CB))[3]:BO] cbas:Default.Local:NEW_ORDER:266fa65b24d536e4e15c9a24b30694a1:3 closed...

2021-02-01T02:11:04.279-08:00 DEBU CBAS.nc.Task [o.a.h.a.r.runtime.SuperActivity:JID:1.15321:TAID:TID:ANID:ODID:4:0:3:0:0] Task failed with exception

org.apache.hyracks.api.exceptions.HyracksDataException: java.lang.InterruptedException

	at org.apache.hyracks.api.exceptions.HyracksDataException.create(HyracksDataException.java:51) ~[hyracks-api.jar:7.0.0-4342]

	at org.apache.hyracks.api.rewriter.runtime.SuperActivityOperatorNodePushable.runInParallel(SuperActivityOperatorNodePushable.java:251) ~[hyracks-api.jar:7.0.0-4342]

	at org.apache.hyracks.api.rewriter.runtime.SuperActivityOperatorNodePushable.initialize(SuperActivityOperatorNodePushable.java:92) ~[hyracks-api.jar:7.0.0-4342]

	at org.apache.hyracks.control.nc.Task.run(Task.java:320) [hyracks-control-nc.jar:7.0.0-4342]

	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [?:?]

	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [?:?]

	at java.lang.Thread.run(Unknown Source) [?:?]

	Suppressed: org.apache.hyracks.api.exceptions.HyracksDataException: java.lang.InterruptedException

		at org.apache.hyracks.api.exceptions.HyracksDataException.create(HyracksDataException.java:51) ~[hyracks-api.jar:7.0.0-4342]

		at org.apache.hyracks.api.rewriter.runtime.SuperActivityOperatorNodePushable.runInParallel(SuperActivityOperatorNodePushable.java:251) ~[hyracks-api.jar:7.0.0-4342]

		at org.apache.hyracks.api.rewriter.runtime.SuperActivityOperatorNodePushable.deinitialize(SuperActivityOperatorNodePushable.java:97) ~[hyracks-api.jar:7.0.0-4342]

		at org.apache.hyracks.control.nc.Task.run(Task.java:364) [hyracks-control-nc.jar:7.0.0-4342]

		at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [?:?]

		at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [?:?]

		at java.lang.Thread.run(Unknown Source) [?:?]

	Caused by: java.lang.InterruptedException

		at java.util.concurrent.FutureTask.awaitDone(Unknown Source) ~[?:?]

		at java.util.concurrent.FutureTask.get(Unknown Source) ~[?:?]

		at org.apache.hyracks.api.rewriter.runtime.SuperActivityOperatorNodePushable.runInParallel(SuperActivityOperatorNodePushable.java:240) ~[hyracks-api.jar:7.0.0-4342]

		... 5 more

Caused by: java.lang.InterruptedException

	at java.util.concurrent.FutureTask.awaitDone(Unknown Source) ~[?:?]

	at java.util.concurrent.FutureTask.get(Unknown Source) ~[?:?]

	at org.apache.hyracks.api.rewriter.runtime.SuperActivityOperatorNodePushable.runInParallel(SuperActivityOperatorNodePushable.java:240) ~[hyracks-api.jar:7.0.0-4342]

	... 5 more

	Suppressed: org.apache.hyracks.api.exceptions.HyracksDataException: Connection has been aborted

		at org.apache.hyracks.comm.channels.NetworkOutputChannel.nextFrame(NetworkOutputChannel.java:69) ~[hyracks-comm.jar:7.0.0-4342]

		at org.apache.hyracks.control.nc.partitions.PipelinedPartition.nextFrame(PipelinedPartition.java:82) ~[hyracks-control-nc.jar:7.0.0-4342]

		at com.couchbase.analytics.runtime.ProgressFrameTupleAppender.forward(ProgressFrameTupleAppender.java:184) ~[cbas-connector.jar:7.0.0-4342]

		at com.couchbase.analytics.runtime.ProgressFrameTupleAppender.write(ProgressFrameTupleAppender.java:162) ~[cbas-connector.jar:7.0.0-4342]

		at com.couchbase.analytics.runtime.ProgressFrameTupleAppender.flush(ProgressFrameTupleAppender.java:194) ~[cbas-connector.jar:7.0.0-4342]

		at org.apache.hyracks.dataflow.common.comm.io.AbstractFrameAppender.flush(AbstractFrameAppender.java:117) ~[hyracks-dataflow-common.jar:7.0.0-4342]

		at com.couchbase.analytics.runtime.ProgressPartitionDataWriter.flush(ProgressPartitionDataWriter.java:230) ~[cbas-connector.jar:7.0.0-4342]

		at org.apache.hyracks.dataflow.std.base.AbstractReplicateOperatorDescriptor$ReplicatorMaterializerActivityNode$1.flush(AbstractReplicateOperatorDescriptor.java:149) ~[hyracks-dataflow-std.jar:7.0.0-4342]

		at org.apache.hyracks.api.comm.IFrameAppender.flush(IFrameAppender.java:68) ~[hyracks-api.jar:7.0.0-4342]

		at org.apache.asterix.external.dataflow.TupleForwarder.flush(TupleForwarder.java:47) ~[asterix-external-data.jar:7.0.0-4342]

		at org.apache.asterix.external.dataflow.AbstractFeedDataFlowController.flush(AbstractFeedDataFlowController.java:48) ~[asterix-external-data.jar:7.0.0-4342]

		at com.couchbase.analytics.adapter.CouchbaseConnector.flushCurrentFrame(CouchbaseConnector.java:860) ~[cbas-connector.jar:7.0.0-4342]

		at com.couchbase.analytics.adapter.CouchbaseConnector.pollNextMessage(CouchbaseConnector.java:614) ~[cbas-connector.jar:7.0.0-4342]

		at com.couchbase.analytics.adapter.CouchbaseConnector.take(CouchbaseConnector.java:595) ~[cbas-connector.jar:7.0.0-4342]

		at com.couchbase.analytics.adapter.CouchbaseConnector.next(CouchbaseConnector.java:583) ~[cbas-connector.jar:7.0.0-4342]

		at org.apache.asterix.external.dataflow.FeedRecordDataFlowController.next(FeedRecordDataFlowController.java:139) ~[asterix-external-data.jar:7.0.0-4342]

		at org.apache.asterix.external.dataflow.FeedRecordDataFlowController.start(FeedRecordDataFlowController.java:87) ~[asterix-external-data.jar:7.0.0-4342]

		at org.apache.asterix.external.dataset.adapter.FeedAdapter.start(FeedAdapter.java:40) ~[asterix-external-data.jar:7.0.0-4342]

		at org.apache.asterix.common.external.IDataSourceAdapter.start(IDataSourceAdapter.java:75) ~[asterix-common.jar:7.0.0-4342]

		at com.couchbase.analytics.runtime.BucketOperatorNodePushable.start(BucketOperatorNodePushable.java:51) ~[cbas-connector.jar:7.0.0-4342]

		at org.apache.asterix.active.ActiveSourceOperatorNodePushable.initialize(ActiveSourceOperatorNodePushable.java:102) ~[asterix-active.jar:7.0.0-4342]

		at org.apache.hyracks.api.rewriter.runtime.SuperActivityOperatorNodePushable.lambda$runInParallel$0(SuperActivityOperatorNodePushable.java:228) ~[hyracks-api.jar:7.0.0-4342]

		at java.util.concurrent.FutureTask.run(Unknown Source) ~[?:?]

		at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [?:?]

		at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [?:?]

021-02-01T02:53:37.821-08:00 DEBU CBAS.bootstrap.DeadlockWatchdog [Timer-0] No deadlocked threads detected

2021-02-01T02:53:37.969-08:00 DEBU CBAS.work.WorkQueue [Worker:266fa65b24d536e4e15c9a24b30694a1] Executing: ApplicationMessage: nodeId: 266fa65b24d536e4e15c9a24b30694a1

2021-02-01T02:53:37.981-08:00 DEBU CBAS.bootstrap.PeriodicThreadDump [Timer-0] taking periodic thread dump

2021-02-01T02:53:38.607-08:00 DEBU CBAS.bootstrap.Auditor [Executor-9:266fa65b24d536e4e15c9a24b30694a1] ignoring stream w/o audit settings update

2021-02-01T02:53:38.607-08:00 DEBU CBAS.bootstrap.PeriodicThreadDump [Timer-0] periodic thread dump:

["main" prio=5 Id=1 WAITING on java.util.concurrent.Semaphore$NonfairSync@2681270a

	at java.base@11.0.10/jdk.internal.misc.Unsafe.park(Native Method)

	-  waiting on java.util.concurrent.Semaphore$NonfairSync@2681270a

	at java.base@11.0.10/java.util.concurrent.locks.LockSupport.park(Unknown Source)

	at java.base@11.0.10/java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(Unknown Source)

	at java.base@11.0.10/java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(Unknown Source)

	at java.base@11.0.10/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(Unknown Source)

	at java.base@11.0.10/java.util.concurrent.Semaphore.acquire(Unknown Source)

	at app//com.couchbase.analytics.control.AnalyticsDriver.main(AnalyticsDriver.java:112)

, "Reference Handler" daemon prio=10 Id=2 RUNNABLE

	at java.base@11.0.10/java.lang.ref.Reference.waitForReferencePendingList(Native Method)

	at java.base@11.0.10/java.lang.ref.Reference.processPendingReferences(Unknown Source)

	at java.base@11.0.10/java.lang.ref.Reference$ReferenceHandler.run(Unknown Source)

, "Finalizer" daemon prio=8 Id=3 WAITING on java.lang.ref.ReferenceQueue$Lock@c2cf597

	at java.base@11.0.10/java.lang.Object.wait(Native Method)

	-  waiting on java.lang.ref.ReferenceQueue$Lock@c2cf597

	at java.base@11.0.10/java.lang.ref.ReferenceQueue.remove(Unknown Source)

	at java.base@11.0.10/java.lang.ref.ReferenceQueue.remove(Unknown Source)

	at java.base@11.0.10/java.lang.ref.Finalizer$FinalizerThread.run(Unknown Source)

, "Signal Dispatcher" daemon prio=9 Id=4 RUNNABLE

, "Common-Cleaner" daemon prio=8 Id=11 TIMED_WAITING on java.lang.ref.ReferenceQueue$Lock@724bf25f

	at java.base@11.0.10/java.lang.Object.wait(Native Method)

	-  waiting on java.lang.ref.ReferenceQueue$Lock@724bf25f

	at java.base@11.0.10/java.lang.ref.ReferenceQueue.remove(Unknown Source)

	at java.base@11.0.10/jdk.internal.ref.CleanerImpl.run(Unknown Source)

	at java.base@11.0.10/java.lang.Thread.run(Unknown Source)

	at java.base@11.0.10/jdk.internal.misc.InnocuousThread.run(Unknown Source)

, "AsyncAppender-AsyncDcpDebugLog" daemon prio=5 Id=12 WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@2abafa97

	at java.base@11.0.10/jdk.internal.misc.Unsafe.park(Native Method)

	-  waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@2abafa97

	at java.base@11.0.10/java.util.concurrent.locks.LockSupport.park(Unknown Source)

	at java.base@11.0.10/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Unknown Source)

	at app//com.conversantmedia.util.concurrent.AbstractCondition.await(AbstractCondition.java:57)

	at app//com.conversantmedia.util.concurrent.DisruptorBlockingQueue.take(DisruptorBlockingQueue.java:240)

	at app//org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.run(AsyncAppender.java:398)

, "AsyncAppender-AsyncAccessLog" daemon prio=5 Id=13 WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@6f6cc7da

	at java.base@11.0.10/jdk.internal.misc.Unsafe.park(Native Method)

	-  waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@6f6cc7da

	at java.base@11.0.10/java.util.concurrent.locks.LockSupport.park(Unknown Source)

	at java.base@11.0.10/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(Unknown Source)

	at app//com.conversantmedia.util.concurrent.AbstractCondition.await(AbstractCondition.java:57)

	at app//com.conversantmedia.util.concurrent.DisruptorBlockingQueue.take(DisruptorBlockingQueue.java:240)

	at app//org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.run(AsyncAppender.java:398)

Attachments

Issue Links

links to

AsterixDB commit

Gerrit Reviews

- Issue Only
- Show All Reviews
- Show Open Reviews
- Show All Issues
- Show Open Issues

No reviews matched the request. Check your Options in the drop-down menu of this sections header.

[System Test][Analytics] Fatal error message with rebalance failure observed in longevity

Details

Description

Attachments

Issue Links

Gerrit Reviews

Activity

People

Dates

Gerrit Reviews

PagerDuty