Uploaded image for project: 'Couchbase Server'
  1. Couchbase Server
  2. MB-36126

[System Test] : Seeing error on Analytics nodes - ASX0023: 60.0s passed before getting back the responses from NCs

    XMLWordPrintable

Details

    Description

      Build : 6.0.3-2880
      Test : -test tests/integration/test_allFeatures_alice_timers.yml -scope tests/integration/scope_Xattrs_Alice.yml
      Scale : 3
      Day : 3rd

      Seeing the following on 172.23.96.212

      2019-09-21T05:41:33.988-07:00 ERRO CBAS.active.ActiveEntityEventsListener [Executor-100:ClusterController] Failed to start the entity Default.Local.default(CouchbaseMetadataExtension)
      org.apache.asterix.common.exceptions.RuntimeDataException: ASX0023: 60.0s passed before getting back the responses from NCs
              at org.apache.asterix.messaging.CCMessageBroker.sendSyncRequestToNCs(CCMessageBroker.java:117) ~[asterix-app.jar:6.0.3-2880]
              at com.couchbase.analytics.util.DcpUtil.requestShadowStates(DcpUtil.java:171) ~[cbas-connector.jar:6.0.3-2880]
              at com.couchbase.analytics.util.DcpUtil.aggregateDcpState(DcpUtil.java:132) ~[cbas-connector.jar:6.0.3-2880]
              at com.couchbase.analytics.adapter.CouchbaseConnectorFactory.coordinate(CouchbaseConnectorFactory.java:281) ~[cbas-connector.jar:6.0.3-2880]
              at com.couchbase.analytics.adapter.CouchbaseConnectorFactory.calculateStartingPoint(CouchbaseConnectorFactory.java:275) ~[cbas-connector.jar:6.0.3-2880]
              at com.couchbase.analytics.runtime.BucketOperatorDescriptor.calculateStartingPoint(BucketOperatorDescriptor.java:75) ~[cbas-connector.jar:6.0.3-2880]
              at com.couchbase.analytics.lang.ConnectLinkStatement.combine(ConnectLinkStatement.java:154) ~[cbas-connector.jar:6.0.3-2880]
              at com.couchbase.analytics.lang.ConnectLinkStatement.doConnect(ConnectLinkStatement.java:515) ~[cbas-connector.jar:6.0.3-2880]
              at com.couchbase.analytics.metadata.BucketEventsListener.doConnect(BucketEventsListener.java:199) ~[cbas-connector.jar:6.0.3-2880]
              at com.couchbase.analytics.metadata.BucketEventsListener.compileAndStartJob(BucketEventsListener.java:177) ~[cbas-connector.jar:6.0.3-2880]
              at org.apache.asterix.app.active.ActiveEntityEventsListener.doStart(ActiveEntityEventsListener.java:396) ~[asterix-app.jar:6.0.3-2880]
              at org.apache.asterix.app.active.ActiveEntityEventsListener.start(ActiveEntityEventsListener.java:383) [asterix-app.jar:6.0.3-2880]
              at com.couchbase.analytics.lang.ConnectLinkStatement.connect(ConnectLinkStatement.java:428) [cbas-connector.jar:6.0.3-2880]
              at com.couchbase.analytics.metadata.BucketEventsListener.fix(BucketEventsListener.java:123) [cbas-connector.jar:6.0.3-2880]
              at com.couchbase.analytics.metadata.BucketEventsListener.lambda$handle$0(BucketEventsListener.java:85) [cbas-connector.jar:6.0.3-2880]
              at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
              at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
              at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
              at java.lang.Thread.run(Thread.java:834) [?:?]
      2019-09-21T05:41:33.989-07:00 ERRO CBAS.metadata.BucketEventsListener [Executor-100:ClusterController] Failed to connect bucket Default.Local.default(CouchbaseMetadataExtension)
      org.apache.asterix.common.exceptions.RuntimeDataException: ASX0023: 60.0s passed before getting back the responses from NCs
              at org.apache.asterix.messaging.CCMessageBroker.sendSyncRequestToNCs(CCMessageBroker.java:117) ~[asterix-app.jar:6.0.3-2880]
              at com.couchbase.analytics.util.DcpUtil.requestShadowStates(DcpUtil.java:171) ~[cbas-connector.jar:6.0.3-2880]
              at com.couchbase.analytics.util.DcpUtil.aggregateDcpState(DcpUtil.java:132) ~[cbas-connector.jar:6.0.3-2880]
              at com.couchbase.analytics.adapter.CouchbaseConnectorFactory.coordinate(CouchbaseConnectorFactory.java:281) ~[cbas-connector.jar:6.0.3-2880]
              at com.couchbase.analytics.adapter.CouchbaseConnectorFactory.calculateStartingPoint(CouchbaseConnectorFactory.java:275) ~[cbas-connector.jar:6.0.3-2880]
              at com.couchbase.analytics.runtime.BucketOperatorDescriptor.calculateStartingPoint(BucketOperatorDescriptor.java:75) ~[cbas-connector.jar:6.0.3-2880]
              at com.couchbase.analytics.lang.ConnectLinkStatement.combine(ConnectLinkStatement.java:154) ~[cbas-connector.jar:6.0.3-2880]
              at com.couchbase.analytics.lang.ConnectLinkStatement.doConnect(ConnectLinkStatement.java:515) ~[cbas-connector.jar:6.0.3-2880]
              at com.couchbase.analytics.metadata.BucketEventsListener.doConnect(BucketEventsListener.java:199) ~[cbas-connector.jar:6.0.3-2880]
              at com.couchbase.analytics.metadata.BucketEventsListener.compileAndStartJob(BucketEventsListener.java:177) ~[cbas-connector.jar:6.0.3-2880]
              at org.apache.asterix.app.active.ActiveEntityEventsListener.doStart(ActiveEntityEventsListener.java:396) ~[asterix-app.jar:6.0.3-2880]
              at org.apache.asterix.app.active.ActiveEntityEventsListener.start(ActiveEntityEventsListener.java:383) ~[asterix-app.jar:6.0.3-2880]
              at com.couchbase.analytics.lang.ConnectLinkStatement.connect(ConnectLinkStatement.java:428) ~[cbas-connector.jar:6.0.3-2880]
              at com.couchbase.analytics.metadata.BucketEventsListener.fix(BucketEventsListener.java:123) [cbas-connector.jar:6.0.3-2880]
              at com.couchbase.analytics.metadata.BucketEventsListener.lambda$handle$0(BucketEventsListener.java:85) [cbas-connector.jar:6.0.3-2880]
              at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
              at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
              at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
              at java.lang.Thread.run(Thread.java:834) [?:?]
      2019-09-21T05:41:45.536-07:00 ERRO CBAS.adapter.ShadowStatesRequest [Executor-1837:0939d8c415a60f7e8bff52fbaacee6db] Exception while getting the dcp state on nc
      java.lang.IllegalStateException: Active Runtime (Default.Local.default(CouchbaseMetadataExtension))[-1]:StateRequest is already registered
              at org.apache.asterix.active.ActiveManager.registerRuntime(ActiveManager.java:79) ~[asterix-active.jar:6.0.3-2880]
              at com.couchbase.analytics.adapter.ShadowStatesRequest.handle(ShadowStatesRequest.java:89) [cbas-connector.jar:6.0.3-2880]
              at org.apache.asterix.messaging.NCMessageBroker.lambda$receivedMessage$0(NCMessageBroker.java:100) [asterix-app.jar:6.0.3-2880]
              at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
      at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
              at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
              at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
              at java.lang.Thread.run(Thread.java:834) [?:?]
      2019-09-21T05:41:54.252-07:00 ERRO CBAS.adapter.ShadowStatesRequest [Executor-1837:0939d8c415a60f7e8bff52fbaacee6db] Exception while getting the dcp state on nc
      java.lang.IllegalStateException: Active Runtime (Default.Local.default(CouchbaseMetadataExtension))[-1]:StateRequest is already registered
              at org.apache.asterix.active.ActiveManager.registerRuntime(ActiveManager.java:79) ~[asterix-active.jar:6.0.3-2880]
              at com.couchbase.analytics.adapter.ShadowStatesRequest.handle(ShadowStatesRequest.java:89) [cbas-connector.jar:6.0.3-2880]
              at org.apache.asterix.messaging.NCMessageBroker.lambda$receivedMessage$0(NCMessageBroker.java:100) [asterix-app.jar:6.0.3-2880]
              at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
              at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
              at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
              at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
              at java.lang.Thread.run(Thread.java:834) [?:?]
      

      Similar issues have been fixed in the past releases (MB-33508, MB-30718, MB-35510). The root cause for this one might not be exactly the same as the other bugs listed above.

      The test was doing a rebalance out of a failed over KV node at the time of this error.

      Attachments

        Issue Links

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

          Activity

            People

              michael.blow Michael Blow
              mihir.kamdar Mihir Kamdar (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Gerrit Reviews

                  There are no open Gerrit changes

                  PagerDuty