search

namhnguyen / asterixdb

Automatically exported from code.google.com/p/asterixdb
0 stars 0 forks source link

java.lang.ArrayIndexOutOfBoundsException #879

Open GoogleCodeExporter opened 9 years ago

GoogleCodeExporter commented 9 years ago 
Hi,

I get java.lang.ArrayIndexOutOfBoundsException: 7 in the web console output 
while executing the following query:

for $i in dataset xyz where $i.stt-point.value=0 return $i;

I had the same problem a few weeks ago. When I restarted the instance, hoping 
that it will get fixed, the instance moved to UNUSABLE state.
I had to clean up and reinstall AsterixDB.

The same query was running successfully a few days ago in the new installation.
However it's throwing up the exception now.

The log file says:

java.lang.ArrayIndexOutOfBoundsException: 7
    at edu.uci.ics.asterix.optimizer.rules.am.AbstractIntroduceAccessMethodRule.getFieldNameFromSubTree(AbstractIntroduceAccessMethodRule.java:402)
    at edu.uci.ics.asterix.optimizer.rules.am.AbstractIntroduceAccessMethodRule.fillAllIndexExprs(AbstractIntroduceAccessMethodRule.java:294)
    at edu.uci.ics.asterix.optimizer.rules.am.AbstractIntroduceAccessMethodRule.fillSubTreeIndexExprs(AbstractIntroduceAccessMethodRule.java:92)
    at edu.uci.ics.asterix.optimizer.rules.am.IntroduceSelectAccessMethodRule.rewritePost(IntroduceSelectAccessMethodRule.java:101)
    at edu.uci.ics.hyracks.algebricks.core.rewriter.base.AbstractRuleController.rewriteOperatorRef(AbstractRuleController.java:122)
    at edu.uci.ics.hyracks.algebricks.core.rewriter.base.AbstractRuleController.rewriteOperatorRef(AbstractRuleController.java:96)
    at edu.uci.ics.hyracks.algebricks.core.rewriter.base.AbstractRuleController.rewriteOperatorRef(AbstractRuleController.java:96)
    at edu.uci.ics.hyracks.algebricks.compiler.rewriter.rulecontrollers.SequentialFixpointRuleController.rewriteWithRuleCollection(SequentialFixpointRuleController.java:49)
    at edu.uci.ics.hyracks.algebricks.core.rewriter.base.HeuristicOptimizer.runOptimizationSets(HeuristicOptimizer.java:91)
    at edu.uci.ics.hyracks.algebricks.core.rewriter.base.HeuristicOptimizer.optimize(HeuristicOptimizer.java:78)
    at edu.uci.ics.hyracks.algebricks.compiler.api.HeuristicCompilerFactoryBuilder$1$1.optimize(HeuristicCompilerFactoryBuilder.java:83)
    at edu.uci.ics.asterix.api.common.APIFramework.compileQuery(APIFramework.java:287)
    at edu.uci.ics.asterix.aql.translator.AqlTranslator.rewriteCompileQuery(AqlTranslator.java:1699)
    at edu.uci.ics.asterix.aql.translator.AqlTranslator.handleQuery(AqlTranslator.java:2007)
    at edu.uci.ics.asterix.aql.translator.AqlTranslator.compileAndExecute(AqlTranslator.java:318)
    at edu.uci.ics.asterix.api.http.servlet.APIServlet.doPost(APIServlet.java:97)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:754)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:847)
    at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:546)
    at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:483)
    at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:231)
    at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:970)
    at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:411)
    at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:192)
    at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:904)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:110)
    at org.eclipse.jetty.server.Server.handle(Server.java:347)
    at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:439)
    at org.eclipse.jetty.server.HttpConnection$RequestHandler.content(HttpConnection.java:924)
    at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:781)
    at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:220)
    at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:43)
    at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:545)
    at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:43)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:529)
    at java.lang.Thread.run(Thread.java:745)
May 11, 2015 11:51:03 AM edu.uci.ics.asterix.api.http.servlet.APIServlet doPost
SEVERE: 7

Is there a way to fix this?

Regards,
Sanjana

Original issue reported on code.google.com by dssa...@gmail.com on 11 May 2015 at 1:31

GoogleCodeExporter commented 9 years ago 
Hi Sanjana,

Sorry you're running into troubles. It's surprising that doing a stop, and then 
start doesn't cause something like this to go away. 
Would it be possible for us to get log files and perhaps the data or a subset, 
so we can try reproducing this?

Original comment by ima...@uci.edu on 11 May 2015 at 4:36

GoogleCodeExporter commented 9 years ago 
[deleted comment]
GoogleCodeExporter commented 9 years ago 
Hi,

Please find attached a text file containing a subset of the data and a zip file 
containing logs.

Thanks,
Sanjana

Original comment by dssa...@gmail.com on 11 May 2015 at 4:57

Attachments:

GoogleCodeExporter commented 9 years ago 
Also, the error is apparent when I add about a thousand records. It was fine 
when it had < 100 records

Regards,
Sanjana

Original comment by dssa...@gmail.com on 11 May 2015 at 4:59

GoogleCodeExporter commented 9 years ago 
Interesting, thanks for the data. This should help investigating the source of 
this. Any chance we could get the ~1000 records you mentioned will reproduce 
this easily? This looks like the relevant portion of the CC log:
May 11, 2015 12:16:13 PM 
edu.uci.ics.hyracks.algebricks.core.rewriter.base.HeuristicOptimizer optimize
INFO: Optimized Plan:
distribute result [%0->$$0]
-- DISTRIBUTE_RESULT  |PARTITIONED|
  exchange 
  -- ONE_TO_ONE_EXCHANGE  |PARTITIONED|
    project ([$$0])
    -- STREAM_PROJECT  |PARTITIONED|
      select (function-call: algebricks:neq, Args:[function-call: asterix:field-access-by-index, Args:[%0->$$7, AInt32: {7}], AInt32: {0}])
      -- STREAM_SELECT  |PARTITIONED|
        assign [$$7] <- [function-call: asterix:field-access-by-index, Args:[%0->$$0, AInt32: {1}]]
        -- ASSIGN  |PARTITIONED|
          project ([$$0])
          -- STREAM_PROJECT  |PARTITIONED|
            exchange 
            -- ONE_TO_ONE_EXCHANGE  |PARTITIONED|
              data-scan []<-[$$5, $$0] <- eventshop:STTStream_allergy_san
              -- DATASOURCE_SCAN  |PARTITIONED|
                exchange 
                -- ONE_TO_ONE_EXCHANGE  |PARTITIONED|
                  empty-tuple-source
                  -- EMPTY_TUPLE_SOURCE  |PARTITIONED|

May 11, 2015 12:16:13 PM edu.uci.ics.asterix.aql.translator.AqlTranslator 
handleQuery
INFO: {
 "connectors": [
  {
   "connector": {
    "display-name": "edu.uci.ics.hyracks.dataflow.std.connectors.OneToOneConnectorDescriptor[CDID:0]",
    "id": "CDID:0",
    "java-class": "edu.uci.ics.hyracks.dataflow.std.connectors.OneToOneConnectorDescriptor"
   },
   "in-operator-id": "ODID:3",
   "in-operator-port": 0,
   "out-operator-id": "ODID:0",
   "out-operator-port": 0
  },
  {
   "connector": {
    "display-name": "edu.uci.ics.hyracks.dataflow.std.connectors.OneToOneConnectorDescriptor[CDID:1]",
    "id": "CDID:1",
    "java-class": "edu.uci.ics.hyracks.dataflow.std.connectors.OneToOneConnectorDescriptor"
   },
   "in-operator-id": "ODID:0",
   "in-operator-port": 0,
   "out-operator-id": "ODID:2",
   "out-operator-port": 0
  },
  {
   "connector": {
    "display-name": "edu.uci.ics.hyracks.dataflow.std.connectors.OneToOneConnectorDescriptor[CDID:2]",
    "id": "CDID:2",
    "java-class": "edu.uci.ics.hyracks.dataflow.std.connectors.OneToOneConnectorDescriptor"
   },
   "in-operator-id": "ODID:2",
   "in-operator-port": 0,
   "out-operator-id": "ODID:1",
   "out-operator-port": 0
  }
 ],
 "operators": [
  {
   "display-name": "edu.uci.ics.hyracks.storage.am.btree.dataflow.BTreeSearchOperatorDescriptor[ODID:0]",
   "id": "ODID:0",
   "in-arity": 1,
   "java-class": "edu.uci.ics.hyracks.storage.am.btree.dataflow.BTreeSearchOperatorDescriptor",
   "out-arity": 1,
   "partition-constraints": {
    "count": "1",
    "location": {"0": "my_asterix_node1"}
   }
  },
  {
   "display-name": "edu.uci.ics.hyracks.dataflow.std.result.ResultWriterOperatorDescriptor[ODID:1]",
   "id": "ODID:1",
   "in-arity": 1,
   "java-class": "edu.uci.ics.hyracks.dataflow.std.result.ResultWriterOperatorDescriptor",
   "out-arity": 0,
   "partition-constraints": {
    "count": "1",
    "location": {"0": "my_asterix_node1"}
   }
  },
  {
   "display-name": "edu.uci.ics.hyracks.algebricks.runtime.operators.meta.AlgebricksMetaOperatorDescriptor[ODID:2]",
   "id": "ODID:2",
   "in-arity": 1,
   "java-class": "edu.uci.ics.hyracks.algebricks.runtime.operators.meta.AlgebricksMetaOperatorDescriptor",
   "micro-operators": [
    "stream-project [1]",
    "assign [1] := [edu.uci.ics.hyracks.algebricks.core.algebra.expressions.LogicalExpressionJobGenToExpressionRuntimeProviderAdapter$ScalarEvaluatorFactoryAdapter@5dfa0125]",
    "stream-select edu.uci.ics.hyracks.algebricks.core.algebra.expressions.LogicalExpressionJobGenToExpressionRuntimeProviderAdapter$ScalarEvaluatorFactoryAdapter@48615456",
    "stream-project [0]"
   ],
   "out-arity": 1,
   "partition-constraints": {
    "count": "1",
    "location": {"0": "my_asterix_node1"}
   }
  },
  {
   "display-name": "edu.uci.ics.hyracks.algebricks.runtime.operators.meta.AlgebricksMetaOperatorDescriptor[ODID:3]",
   "id": "ODID:3",
   "in-arity": 0,
   "java-class": "edu.uci.ics.hyracks.algebricks.runtime.operators.meta.AlgebricksMetaOperatorDescriptor",
   "micro-operators": ["ets"],
   "out-arity": 1,
   "partition-constraints": {
    "count": "1",
    "location": {"0": "my_asterix_node1"}
   }
  }
 ]
}
May 11, 2015 12:16:13 PM 
edu.uci.ics.hyracks.control.common.work.WorkQueue$WorkerThread run
INFO: Executing: JobStart
May 11, 2015 12:16:13 PM 
edu.uci.ics.hyracks.control.cc.scheduler.ActivityClusterPlanner 
planActivityCluster
INFO: Plan for edu.uci.ics.hyracks.api.job.ActivityCluster@398816dc
May 11, 2015 12:16:13 PM 
edu.uci.ics.hyracks.control.cc.scheduler.ActivityClusterPlanner 
planActivityCluster
INFO: Built 1 Task Clusters
May 11, 2015 12:16:13 PM 
edu.uci.ics.hyracks.control.cc.scheduler.ActivityClusterPlanner 
planActivityCluster
INFO: Tasks: [TID:ANID:ODID:3:0:0]
May 11, 2015 12:16:13 PM 
edu.uci.ics.hyracks.control.common.work.WorkQueue$WorkerThread run
INFO: Executing: GetResultPartitionLocations: JobId@JID:12191 
ResultSetId@RSID:0 Known@null
May 11, 2015 12:16:13 PM 
edu.uci.ics.hyracks.control.common.work.WorkQueue$WorkerThread run
INFO: Executing: RegisterResultPartitionLocation: JobId@JID:12191 
ResultSetId@RSID:0 Partition@0 NPartitions@1 ResultPartitionLocation@[127, 0, 
0, 1]:59559 OrderedResult@true EmptyResult@false
May 11, 2015 12:16:13 PM 
edu.uci.ics.hyracks.control.common.work.WorkQueue$WorkerThread run
INFO: Executing: ReportResultPartitionWriteCompletion: JobId@JID:12191 
ResultSetId@RSID:0 Partition@0
May 11, 2015 12:16:13 PM 
edu.uci.ics.hyracks.control.common.work.WorkQueue$WorkerThread run
INFO: Executing: TaskComplete: 
[my_asterix_node1[JID:12191:TAID:TID:ANID:ODID:3:0:0:0]
May 11, 2015 12:16:13 PM 
edu.uci.ics.hyracks.control.common.work.WorkQueue$WorkerThread run
INFO: Executing: JobCleanup: JobId@JID:12191 Status@TERMINATED
May 11, 2015 12:16:13 PM edu.uci.ics.hyracks.control.cc.work.JobCleanupWork run
INFO: Cleanup for JobRun with id: JID:12191
May 11, 2015 12:16:13 PM 
edu.uci.ics.hyracks.control.common.work.WorkQueue$WorkerThread run
INFO: Executing: JobletCleanupNotification
May 11, 2015 12:16:13 PM 
edu.uci.ics.hyracks.control.common.work.WorkQueue$WorkerThread run
INFO: Executing: WaitForJobCompletion
java.lang.ArrayIndexOutOfBoundsException: 7
    at edu.uci.ics.asterix.optimizer.rules.am.AbstractIntroduceAccessMethodRule.getFieldNameFromSubTree(AbstractIntroduceAccessMethodRule.java:402)
    at edu.uci.ics.asterix.optimizer.rules.am.AbstractIntroduceAccessMethodRule.fillAllIndexExprs(AbstractIntroduceAccessMethodRule.java:294)
    at edu.uci.ics.asterix.optimizer.rules.am.AbstractIntroduceAccessMethodRule.fillSubTreeIndexExprs(AbstractIntroduceAccessMethodRule.java:92)
    at edu.uci.ics.asterix.optimizer.rules.am.IntroduceSelectAccessMethodRule.rewritePost(IntroduceSelectAccessMethodRule.java:101)
    at edu.uci.ics.hyracks.algebricks.core.rewriter.base.AbstractRuleController.rewriteOperatorRef(AbstractRuleController.java:122)
    at edu.uci.ics.hyracks.algebricks.core.rewriter.base.AbstractRuleController.rewriteOperatorRef(AbstractRuleController.java:96)
    at edu.uci.ics.hyracks.algebricks.core.rewriter.base.AbstractRuleController.rewriteOperatorRef(AbstractRuleController.java:96)
    at edu.uci.ics.hyracks.algebricks.compiler.rewriter.rulecontrollers.SequentialFixpointRuleController.rewriteWithRuleCollection(SequentialFixpointRuleController.java:49)
    at edu.uci.ics.hyracks.algebricks.core.rewriter.base.HeuristicOptimizer.runOptimizationSets(HeuristicOptimizer.java:91)
    at edu.uci.ics.hyracks.algebricks.core.rewriter.base.HeuristicOptimizer.optimize(HeuristicOptimizer.java:78)
    at edu.uci.ics.hyracks.algebricks.compiler.api.HeuristicCompilerFactoryBuilder$1$1.optimize(HeuristicCompilerFactoryBuilder.java:83)
    at edu.uci.ics.asterix.api.common.APIFramework.compileQuery(APIFramework.java:287)
    at edu.uci.ics.asterix.aql.translator.AqlTranslator.rewriteCompileQuery(AqlTranslator.java:1699)
    at edu.uci.ics.asterix.aql.translator.AqlTranslator.handleQuery(AqlTranslator.java:2007)
    at edu.uci.ics.asterix.aql.translator.AqlTranslator.compileAndExecute(AqlTranslator.java:318)
    at edu.uci.ics.asterix.api.http.servlet.APIServlet.doPost(APIServlet.java:97)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:754)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:847)
    at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:546)
    at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:483)
    at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:231)
    at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:970)
    at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:411)
    at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:192)
    at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:904)
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:110)
    at org.eclipse.jetty.server.Server.handle(Server.java:347)
    at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:439)
    at org.eclipse.jetty.server.HttpConnection$RequestHandler.content(HttpConnection.java:924)
    at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:781)
    at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:220)
    at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:43)
    at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:545)
    at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:43)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:529)
    at java.lang.Thread.run(Thread.java:745)

Original comment by ima...@uci.edu on 11 May 2015 at 6:32

GoogleCodeExporter commented 9 years ago 
Hey,

Please find attached the data file containing about 1500 records. This should 
help reproducing the problem.

Thanks,
Sanjana

Original comment by dssa...@gmail.com on 14 May 2015 at 2:32

Attachments: