N1QL Analytics got Internal Error - 2500

Dear Couchbase team,

I am testing to run query on N1QL analytics. Below are the steps I’ve done:

  1. Create new dataset analytics, copying all data from my bucket. The data contains arround 60 millions document
  2. Execute below n1ql on analytics node:

SELECT count(1)
FROM analytics d
WHERE d.type_ = ‘SALES_DETAIL’
AND STR_TO_MILLIS(runningTranDate) BETWEEN STR_TO_MILLIS(DATE_TRUNC_STR(‘2021-01-14’, ‘month’)) AND STR_TO_MILLIS(DATE_TRUNC_STR(‘2021-01-14’, ‘day’))
limit 10;

When i run above query, I got this error:

[
{
“code”: 25000,
“msg”: “Internal error”,
“query_from_user”: “SELECT count(1)\nFROM analytics d\nWHERE d.type_ = ‘SALES_DETAIL’\n AND STR_TO_MILLIS(runningTranDate) BETWEEN STR_TO_MILLIS(DATE_TRUNC_STR(‘2021-01-14’, ‘month’)) AND STR_TO_MILLIS(DATE_TRUNC_STR(‘2021-01-14’, ‘day’))\n limit 10;”
}
]

Anyone can help what cause the internal error?

There should be an exception in the log file (analytics_info.log) at the time of this query execution. Could you provide that exception’s error message and its stack trace?

Hi @dmitry.lychagin,

I found this in the log file (analytics_info.log) upon executing the queery

2021-01-18T17:02:31.627+07:00 INFO CBAS.server.QueryServiceServlet [HttpExecutor(port:8095)-2] handleRequest: {“host”:“10.171.88.11:8091”,“path”:“/query/service”,“statement”:“SELECT count(1)\nFROM analytics d\nWHERE d.type_ = ‘SALES_DETAIL’\n AND STR_TO_MILLIS(runningTranDate) BETWEEN STR_TO_MILLIS(DATE_TRUNC_STR(‘2021-01-14’, ‘month’)) AND STR_TO_MILLIS(DATE_TRUNC_STR(‘2021-01-14’, ‘day’))\n limit 10;”,“pretty”:false,“mode”:“immediate”,“clientContextID”:“51806972-5846-48f8-8438-29c8bd6fdaef”,“format”:“CLEAN_JSON”,“timeout”:9223372036854775807,“maxResultReads”:1,“planFormat”:“JSON”,“expressionTree”:false,“rewrittenExpressionTree”:false,“logicalPlan”:false,“optimizedLogicalPlan”:true,“job”:false,“profile”:“counts”,“signature”:true,“multiStatement”:true,“parseOnly”:false,“readOnly”:false,“maxWarnings”:10,“scanConsistency”:“not_bounded”,“scanWait”:null}
2021-01-18T17:02:31.629+07:00 INFO CBAS.messaging.CCMessageBroker [Executor-28:ClusterController] Received message: ExecuteStatementRequestMessage(id=853, from=32f29731362341d3b94a2077b9f3aa6e): SELECT count(1)
FROM analytics d
WHERE d.type_ = ‘SALES_DETAIL’
AND STR_TO_MILLIS(runningTranDate) BETWEEN STR_TO_MILLIS(DATE_TRUNC_STR(‘2021-01-14’, ‘month’)) AND STR_TO_MILLIS(DATE_TRUNC_STR(‘2021-01-14’, ‘day’))
limit 10;;
2021-01-18T17:03:01.778+07:00 INFO CBAS.messaging.NCMessageBroker [Worker:32f29731362341d3b94a2077b9f3aa6e] Received message: ActiveManagerMessage
2021-01-18T17:03:01.778+07:00 INFO CBAS.active.ActiveManager [Executor-1287:32f29731362341d3b94a2077b9f3aa6e] Message of type REQUEST_STATS received in 32f29731362341d3b94a2077b9f3aa6e
2021-01-18T17:03:01.778+07:00 INFO CBAS.active.ActiveManager [Executor-1284:32f29731362341d3b94a2077b9f3aa6e] Message of type REQUEST_STATS received in 32f29731362341d3b94a2077b9f3aa6e
2021-01-18T17:03:07.401+07:00 WARN CBAS.collectors.NonDeterministicChannelReader [org.apache.hyracks.api.rewriter.runtime.SuperActivity:JID:0.45:TAID:TID:ANID:ODID:2:0:0:0:0] Sender failed… returning silently
2021-01-18T17:03:07.401+07:00 WARN CBAS.nc.Task [org.apache.hyracks.api.rewriter.runtime.SuperActivity:JID:0.45:TAID:TID:ANID:ODID:3:0:3:0:0] Task failed with exception
org.apache.hyracks.api.exceptions.HyracksDataException: java.lang.ArrayIndexOutOfBoundsException
at org.apache.hyracks.api.exceptions.HyracksDataException.create(HyracksDataException.java:51) ~[hyracks-api.jar:6.5.1-6299]
at org.apache.hyracks.storage.am.common.dataflow.IndexSearchOperatorNodePushable.nextFrame(IndexSearchOperatorNodePushable.java:284) ~[hyracks-storage-am-common.jar:6.5.1-6299]
at org.apache.hyracks.dataflow.common.comm.io.AbstractFrameAppender.write(AbstractFrameAppender.java:94) ~[hyracks-dataflow-common.jar:6.5.1-6299]
at org.apache.hyracks.algebricks.runtime.operators.std.EmptyTupleSourceRuntimeFactory$1.open(EmptyTupleSourceRuntimeFactory.java:55) ~[algebricks-runtime.jar:6.5.1-6299]
at org.apache.hyracks.algebricks.runtime.operators.meta.AlgebricksMetaOperatorDescriptor$SourcePushRuntime.initialize(AlgebricksMetaOperatorDescriptor.java:105) ~[algebricks-runtime.jar:6.5.1-6299]
at org.apache.hyracks.api.rewriter.runtime.SuperActivityOperatorNodePushable.lambda$runInParallel$0(SuperActivityOperatorNodePushable.java:228) ~[hyracks-api.jar:6.5.1-6299]
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) [?:?]
at java.lang.Thread.run(Unknown Source) [?:?]
Caused by: java.lang.ArrayIndexOutOfBoundsException

Any idea how that could happen and how to fix the issue?

Hi @hartono.mochtar,
Did you create any secondary indexes on the analytics dataset?

Hi @hartono.mochtar,

Could you also paste the remaining stack trace below this line? Seems like that is the cause of the error.

Hi @mhubail, I didn’t create any secondary index on analytics dataset. Should I create any index for the dataset?

Hi @dmitry.lychagin, here is the full log that i got for the error:

2021-01-18T17:02:31.627+07:00 INFO CBAS.server.QueryServiceServlet [HttpExecutor(port:8095)-2] handleRequest: {“host”:“10.171.88.11:8091”,“path”:“/query/service”,“statement”:“SELECT count(1)\nFROM analytics d\nWHERE d.type_ = ‘SALES_DETAIL’\n AND STR_TO_MILLIS(runningTranDate) BETWEEN STR_TO_MILLIS(DATE_TRUNC_STR(‘2021-01-14’, ‘month’)) AND STR_TO_MILLIS(DATE_TRUNC_STR(‘2021-01-14’, ‘day’))\n limit 10;”,“pretty”:false,“mode”:“immediate”,“clientContextID”:“51806972-5846-48f8-8438-29c8bd6fdaef”,“format”:“CLEAN_JSON”,“timeout”:9223372036854775807,“maxResultReads”:1,“planFormat”:“JSON”,“expressionTree”:false,“rewrittenExpressionTree”:false,“logicalPlan”:false,“optimizedLogicalPlan”:true,“job”:false,“profile”:“counts”,“signature”:true,“multiStatement”:true,“parseOnly”:false,“readOnly”:false,“maxWarnings”:10,“scanConsistency”:“not_bounded”,“scanWait”:null}
2021-01-18T17:02:31.629+07:00 INFO CBAS.messaging.CCMessageBroker [Executor-28:ClusterController] Received message: ExecuteStatementRequestMessage(id=853, from=32f29731362341d3b94a2077b9f3aa6e): SELECT count(1)
FROM analytics d
WHERE d.type_ = ‘SALES_DETAIL’
AND STR_TO_MILLIS(runningTranDate) BETWEEN STR_TO_MILLIS(DATE_TRUNC_STR(‘2021-01-14’, ‘month’)) AND STR_TO_MILLIS(DATE_TRUNC_STR(‘2021-01-14’, ‘day’))
limit 10;;
2021-01-18T17:03:01.778+07:00 INFO CBAS.messaging.NCMessageBroker [Worker:32f29731362341d3b94a2077b9f3aa6e] Received message: ActiveManagerMessage
2021-01-18T17:03:01.778+07:00 INFO CBAS.active.ActiveManager [Executor-1287:32f29731362341d3b94a2077b9f3aa6e] Message of type REQUEST_STATS received in 32f29731362341d3b94a2077b9f3aa6e
2021-01-18T17:03:01.778+07:00 INFO CBAS.active.ActiveManager [Executor-1284:32f29731362341d3b94a2077b9f3aa6e] Message of type REQUEST_STATS received in 32f29731362341d3b94a2077b9f3aa6e
2021-01-18T17:03:07.401+07:00 WARN CBAS.collectors.NonDeterministicChannelReader [org.apache.hyracks.api.rewriter.runtime.SuperActivity:JID:0.45:TAID:TID:ANID:ODID:2:0:0:0:0] Sender failed… returning silently
2021-01-18T17:03:07.401+07:00 WARN CBAS.nc.Task [org.apache.hyracks.api.rewriter.runtime.SuperActivity:JID:0.45:TAID:TID:ANID:ODID:3:0:3:0:0] Task failed with exception
org.apache.hyracks.api.exceptions.HyracksDataException: java.lang.ArrayIndexOutOfBoundsException
at org.apache.hyracks.api.exceptions.HyracksDataException.create(HyracksDataException.java:51) ~[hyracks-api.jar:6.5.1-6299]
at org.apache.hyracks.storage.am.common.dataflow.IndexSearchOperatorNodePushable.nextFrame(IndexSearchOperatorNodePushable.java:284) ~[hyracks-storage-am-common.jar:6.5.1-6299]
at org.apache.hyracks.dataflow.common.comm.io.AbstractFrameAppender.write(AbstractFrameAppender.java:94) ~[hyracks-dataflow-common.jar:6.5.1-6299]
at org.apache.hyracks.algebricks.runtime.operators.std.EmptyTupleSourceRuntimeFactory$1.open(EmptyTupleSourceRuntimeFactory.java:55) ~[algebricks-runtime.jar:6.5.1-6299]
at org.apache.hyracks.algebricks.runtime.operators.meta.AlgebricksMetaOperatorDescriptor$SourcePushRuntime.initialize(AlgebricksMetaOperatorDescriptor.java:105) ~[algebricks-runtime.jar:6.5.1-6299]
at org.apache.hyracks.api.rewriter.runtime.SuperActivityOperatorNodePushable.lambda$runInParallel$0(SuperActivityOperatorNodePushable.java:228) ~[hyracks-api.jar:6.5.1-6299]
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) [?:?]
at java.lang.Thread.run(Unknown Source) [?:?]
Caused by: java.lang.ArrayIndexOutOfBoundsException
2021-01-18T17:03:07.401+07:00 WARN CBAS.work.NotifyTaskFailureWork [Worker:32f29731362341d3b94a2077b9f3aa6e] task TAID:TID:ANID:ODID:3:0:3:0 has failed
org.apache.hyracks.api.exceptions.HyracksDataException: java.lang.ArrayIndexOutOfBoundsException
at org.apache.hyracks.api.exceptions.HyracksDataException.create(HyracksDataException.java:51) ~[hyracks-api.jar:6.5.1-6299]
at org.apache.hyracks.storage.am.common.dataflow.IndexSearchOperatorNodePushable.nextFrame(IndexSearchOperatorNodePushable.java:284) ~[hyracks-storage-am-common.jar:6.5.1-6299]
at org.apache.hyracks.dataflow.common.comm.io.AbstractFrameAppender.write(AbstractFrameAppender.java:94) ~[hyracks-dataflow-common.jar:6.5.1-6299]
at org.apache.hyracks.algebricks.runtime.operators.std.EmptyTupleSourceRuntimeFactory$1.open(EmptyTupleSourceRuntimeFactory.java:55) ~[algebricks-runtime.jar:6.5.1-6299]
at org.apache.hyracks.algebricks.runtime.operators.meta.AlgebricksMetaOperatorDescriptor$SourcePushRuntime.initialize(AlgebricksMetaOperatorDescriptor.java:105) ~[algebricks-runtime.jar:6.5.1-6299]
at org.apache.hyracks.api.rewriter.runtime.SuperActivityOperatorNodePushable.lambda$runInParallel$0(SuperActivityOperatorNodePushable.java:228) ~[hyracks-api.jar:6.5.1-6299]
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) ~[?:?]
at java.lang.Thread.run(Unknown Source) ~[?:?]
Caused by: java.lang.ArrayIndexOutOfBoundsException
2021-01-18T17:03:07.408+07:00 WARN CBAS.work.TaskFailureWork [Worker:ClusterController] Executing task failure work for TaskFailure: [JID:0.45:TAID:TID:ANID:ODID:3:0:3:0:32f29731362341d3b94a2077b9f3aa6e]
org.apache.hyracks.api.exceptions.HyracksDataException: java.lang.ArrayIndexOutOfBoundsException
at org.apache.hyracks.api.exceptions.HyracksDataException.create(HyracksDataException.java:51) ~[hyracks-api.jar:6.5.1-6299]
at org.apache.hyracks.storage.am.common.dataflow.IndexSearchOperatorNodePushable.nextFrame(IndexSearchOperatorNodePushable.java:284) ~[hyracks-storage-am-common.jar:6.5.1-6299]
at org.apache.hyracks.dataflow.common.comm.io.AbstractFrameAppender.write(AbstractFrameAppender.java:94) ~[hyracks-dataflow-common.jar:6.5.1-6299]
at org.apache.hyracks.algebricks.runtime.operators.std.EmptyTupleSourceRuntimeFactory$1.open(EmptyTupleSourceRuntimeFactory.java:55) ~[algebricks-runtime.jar:6.5.1-6299]
at org.apache.hyracks.algebricks.runtime.operators.meta.AlgebricksMetaOperatorDescriptor$SourcePushRuntime.initialize(AlgebricksMetaOperatorDescriptor.java:105) ~[algebricks-runtime.jar:6.5.1-6299]
at org.apache.hyracks.api.rewriter.runtime.SuperActivityOperatorNodePushable.lambda$runInParallel$0(SuperActivityOperatorNodePushable.java:228) ~[hyracks-api.jar:6.5.1-6299]
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) ~[?:?]
at java.lang.Thread.run(Unknown Source) ~[?:?]
Caused by: java.lang.ArrayIndexOutOfBoundsException
2021-01-18T17:03:07.409+07:00 WARN CBAS.executor.JobExecutor [Worker:ClusterController] Spurious task complete notification: TAID:TID:ANID:ODID:2:0:0:0 Current state = ABORTED
2021-01-18T17:03:07.409+07:00 INFO CBAS.work.JobCleanupWork [Worker:ClusterController] Cleanup for job: JID:0.45
2021-01-18T17:03:07.410+07:00 INFO CBAS.work.AbortTasksWork [Worker:32f29731362341d3b94a2077b9f3aa6e] Aborting Tasks: JID:0.45:[TAID:TID:ANID:ODID:2:0:0:0, TAID:TID:ANID:ODID:3:0:0:0, TAID:TID:ANID:ODID:3:0:1:0, TAID:TID:ANID:ODID:3:0:2:0, TAID:TID:ANID:ODID:3:0:4:0, TAID:TID:ANID:ODID:3:0:5:0, TAID:TID:ANID:ODID:3:0:6:0, TAID:TID:ANID:ODID:3:0:7:0, TAID:TID:ANID:ODID:3:0:8:0, TAID:TID:ANID:ODID:3:0:9:0]
2021-01-18T17:03:07.413+07:00 INFO CBAS.work.JobCleanupWork [Worker:ClusterController] Cleanup for job: JID:0.45
2021-01-18T17:03:07.413+07:00 WARN CBAS.job.JobManager [Worker:ClusterController] Ignoring duplicate cleanup for JobRun with id: JID:0.45
2021-01-18T17:03:07.413+07:00 INFO CBAS.work.JobCleanupWork [Worker:ClusterController] Cleanup for job: JID:0.45
2021-01-18T17:03:07.413+07:00 WARN CBAS.job.JobManager [Worker:ClusterController] Ignoring duplicate cleanup for JobRun with id: JID:0.45
2021-01-18T17:03:07.414+07:00 INFO CBAS.work.JobCleanupWork [Worker:ClusterController] Cleanup for job: JID:0.45
2021-01-18T17:03:07.414+07:00 WARN CBAS.job.JobManager [Worker:ClusterController] Ignoring duplicate cleanup for JobRun with id: JID:0.45
2021-01-18T17:03:07.414+07:00 INFO CBAS.work.JobCleanupWork [Worker:ClusterController] Cleanup for job: JID:0.45
2021-01-18T17:03:07.414+07:00 WARN CBAS.job.JobManager [Worker:ClusterController] Ignoring duplicate cleanup for JobRun with id: JID:0.45
2021-01-18T17:03:07.415+07:00 INFO CBAS.work.JobCleanupWork [Worker:ClusterController] Cleanup for job: JID:0.45
2021-01-18T17:03:07.415+07:00 WARN CBAS.job.JobManager [Worker:ClusterController] Ignoring duplicate cleanup for JobRun with id: JID:0.45
2021-01-18T17:03:07.416+07:00 INFO CBAS.work.JobCleanupWork [Worker:ClusterController] Cleanup for job: JID:0.45
2021-01-18T17:03:07.416+07:00 INFO CBAS.impl.IPCSystem [IPC Network Listener Thread [/0.0.0.0:44724]] Exception in message
org.apache.hyracks.api.exceptions.HyracksDataException: java.lang.ArrayIndexOutOfBoundsException
at org.apache.hyracks.api.exceptions.HyracksDataException.create(HyracksDataException.java:51) ~[hyracks-api.jar:6.5.1-6299]
at org.apache.hyracks.storage.am.common.dataflow.IndexSearchOperatorNodePushable.nextFrame(IndexSearchOperatorNodePushable.java:284) ~[hyracks-storage-am-common.jar:6.5.1-6299]
at org.apache.hyracks.dataflow.common.comm.io.AbstractFrameAppender.write(AbstractFrameAppender.java:94) ~[hyracks-dataflow-common.jar:6.5.1-6299]
at org.apache.hyracks.algebricks.runtime.operators.std.EmptyTupleSourceRuntimeFactory$1.open(EmptyTupleSourceRuntimeFactory.java:55) ~[algebricks-runtime.jar:6.5.1-6299]
at org.apache.hyracks.algebricks.runtime.operators.meta.AlgebricksMetaOperatorDescriptor$SourcePushRuntime.initialize(AlgebricksMetaOperatorDescriptor.java:105) ~[algebricks-runtime.jar:6.5.1-6299]
at org.apache.hyracks.api.rewriter.runtime.SuperActivityOperatorNodePushable.lambda$runInParallel$0(SuperActivityOperatorNodePushable.java:228) ~[hyracks-api.jar:6.5.1-6299]
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) ~[?:?]
at java.lang.Thread.run(Unknown Source) ~[?:?]
Caused by: java.lang.ArrayIndexOutOfBoundsException
2021-01-18T17:03:07.416+07:00 WARN CBAS.apache.asterix [Executor-28:ClusterController] java.lang.ArrayIndexOutOfBoundsException
org.apache.hyracks.api.exceptions.HyracksDataException: java.lang.ArrayIndexOutOfBoundsException
at org.apache.hyracks.api.exceptions.HyracksDataException.create(HyracksDataException.java:51) ~[hyracks-api.jar:6.5.1-6299]
at org.apache.hyracks.storage.am.common.dataflow.IndexSearchOperatorNodePushable.nextFrame(IndexSearchOperatorNodePushable.java:284) ~[hyracks-storage-am-common.jar:6.5.1-6299]
at org.apache.hyracks.dataflow.common.comm.io.AbstractFrameAppender.write(AbstractFrameAppender.java:94) ~[hyracks-dataflow-common.jar:6.5.1-6299]
at org.apache.hyracks.algebricks.runtime.operators.std.EmptyTupleSourceRuntimeFactory$1.open(EmptyTupleSourceRuntimeFactory.java:55) ~[algebricks-runtime.jar:6.5.1-6299]
at org.apache.hyracks.algebricks.runtime.operators.meta.AlgebricksMetaOperatorDescriptor$SourcePushRuntime.initialize(AlgebricksMetaOperatorDescriptor.java:105) ~[algebricks-runtime.jar:6.5.1-6299]
at org.apache.hyracks.api.rewriter.runtime.SuperActivityOperatorNodePushable.lambda$runInParallel$0(SuperActivityOperatorNodePushable.java:228) ~[hyracks-api.jar:6.5.1-6299]
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) [?:?]
at java.lang.Thread.run(Unknown Source) [?:?]
Caused by: java.lang.ArrayIndexOutOfBoundsException
2021-01-18T17:03:07.416+07:00 INFO CBAS.work.JobCleanupWork [Worker:ClusterController] Cleanup for job: JID:0.45
2021-01-18T17:03:07.417+07:00 INFO CBAS.work.JobCleanupWork [Worker:ClusterController] Cleanup for job: JID:0.45
2021-01-18T17:03:07.417+07:00 INFO CBAS.messaging.NCMessageBroker [Worker:32f29731362341d3b94a2077b9f3aa6e] Received message: ExecuteStatementResponseMessage(id=853): 0 characters
2021-01-18T17:03:07.417+07:00 INFO CBAS.work.JobCleanupWork [Worker:ClusterController] Cleanup for job: JID:0.45

Hi @hartono.mochtar,

Looks like we need more logs from the server to diagnose this problem. Can you open a support request and upload output of cbcollect_info there?