drill-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Chun Chang (JIRA)" <j...@apache.org>
Subject [jira] [Created] (DRILL-4311) Unexpected exception during fragment initialization: Internal error: Error while applying rule DrillTableRule, args [rel#6431439:EnumerableTableScan.ENUMERABLE.ANY([]).[](table=[hive, lineitem_text_partitioned_hive_hier_intstring])]
Date Tue, 26 Jan 2016 18:55:39 GMT
Chun Chang created DRILL-4311:
---------------------------------

             Summary: Unexpected exception during fragment initialization: Internal error:
Error while applying rule DrillTableRule, args [rel#6431439:EnumerableTableScan.ENUMERABLE.ANY([]).[](table=[hive,
lineitem_text_partitioned_hive_hier_intstring])]
                 Key: DRILL-4311
                 URL: https://issues.apache.org/jira/browse/DRILL-4311
             Project: Apache Drill
          Issue Type: Bug
          Components: Execution - Flow
    Affects Versions: 1.5.0
            Reporter: Chun Chang


1.5.0-SNAPSHOT	3d0b4b02521f12e3871d6060c8f9bfce73b218a0

Hit the following exception while running Functional automation. It's not specific to a query.
The same query passed in other runs. So looks random. And feels the current master is less
stable than a few days ago.

{noformat}
2016-01-26 05:22:05,991 [29588d02-6fc1-3e49-4e4b-de4cc6205538:foreman] INFO  o.a.drill.exec.work.foreman.Foreman
- Query text for query id 29588d02-6fc1-3e49-4e4b-de4cc6205538: select l_orderkey, l_partkey,
l_quantity, l_shipdate, l_shipinstruct from hive.lineitem_text_partitioned_hive_hier_intstring
where `year`=1993 and l_orderkey > 29600 and `month`='nov'
2016-01-26 05:22:05,990 [29588d02-7206-dac7-a1dd-bb4a99fed1b9:foreman] INFO  o.a.d.exec.store.parquet.Metadata
- Fetch parquet metadata: Executed 85 out of 85 using 16 threads. Time: 13ms total, 2.287035ms
avg, 3ms max.
2016-01-26 05:22:05,982 [29588d01-bfc1-49db-caa3-baabb0b9ff30:foreman] INFO  o.a.drill.exec.work.foreman.Foreman
- Query text for query id 29588d01-bfc1-49db-caa3-baabb0b9ff30: select distinct count(distinct
c_row) from data group by c_int order by 1
2016-01-26 05:22:05,995 [29588d02-7206-dac7-a1dd-bb4a99fed1b9:foreman] INFO  o.a.d.exec.store.parquet.Metadata
- Fetch parquet metadata: Executed 85 out of 85 using 16 threads. Earliest start: 400.204000
μs, Latest start: 12264.460000 μs, Average start: 5804.976765 μs .
2016-01-26 05:22:05,995 [29588d02-0b3c-0b0f-fbac-c219dd631d92:frag:0:0] INFO  o.a.d.e.w.f.FragmentStatusReporter
- 29588d02-0b3c-0b0f-fbac-c219dd631d92:0:0: State to report: RUNNING
2016-01-26 05:22:05,997 [29588d02-0b3c-0b0f-fbac-c219dd631d92:frag:0:0] INFO  o.a.d.e.w.fragment.FragmentExecutor
- 29588d02-0b3c-0b0f-fbac-c219dd631d92:0:0: State change requested RUNNING --> FINISHED
2016-01-26 05:22:05,997 [29588d02-0b3c-0b0f-fbac-c219dd631d92:frag:0:0] INFO  o.a.d.e.w.f.FragmentStatusReporter
- 29588d02-0b3c-0b0f-fbac-c219dd631d92:0:0: State to report: FINISHED
2016-01-26 05:22:05,997 [29588d02-7206-dac7-a1dd-bb4a99fed1b9:foreman] INFO  o.a.d.e.p.l.partition.PruneScanRule
- Total pruning elapsed time: 128 ms
2016-01-26 05:22:06,016 [29588d01-51bd-c95b-a4ef-692ababd0a05:foreman] INFO  o.a.drill.exec.work.foreman.Foreman
- Query text for query id 29588d01-51bd-c95b-a4ef-692ababd0a05: use `dfs`
2016-01-26 05:22:06,137 [29588d01-c725-8642-b99d-e902fd4e7f93:foreman] INFO  o.a.d.e.s.schedule.BlockMapBuilder
- Get block maps: Executed 1 out of 1 using 1 threads. Time: 0ms total, 0.945990ms avg, 0ms
max.
2016-01-26 05:22:06,137 [29588d01-c725-8642-b99d-e902fd4e7f93:foreman] INFO  o.a.d.e.s.schedule.BlockMapBuilder
- Get block maps: Executed 1 out of 1 using 1 threads. Earliest start: 0.219000 μs, Latest
start: 0.219000 μs, Average start: 0.219000 μs .
2016-01-26 05:22:06,138 [29588d01-bfc1-49db-caa3-baabb0b9ff30:foreman] INFO  o.a.d.exec.store.parquet.Metadata
- Took 0 ms to get file statuses
2016-01-26 05:22:06,139 [29588d01-bfc1-49db-caa3-baabb0b9ff30:foreman] INFO  o.a.d.exec.store.parquet.Metadata
- Fetch parquet metadata: Executed 1 out of 1 using 1 threads. Time: 1ms total, 1.486007ms
avg, 1ms max.
2016-01-26 05:22:06,140 [29588d01-bfc1-49db-caa3-baabb0b9ff30:foreman] INFO  o.a.d.exec.store.parquet.Metadata
- Fetch parquet metadata: Executed 1 out of 1 using 1 threads. Earliest start: 0.390000 μs,
Latest start: 0.390000 μs, Average start: 0.390000 μs .
2016-01-26 05:22:06,140 [29588d01-bfc1-49db-caa3-baabb0b9ff30:foreman] INFO  o.a.d.exec.store.parquet.Metadata
- Took 1 ms to read file metadata
2016-01-26 05:22:06,169 [29588d01-c725-8642-b99d-e902fd4e7f93:frag:0:0] INFO  o.a.d.e.w.fragment.FragmentExecutor
- 29588d01-c725-8642-b99d-e902fd4e7f93:0:0: State change requested AWAITING_ALLOCATION -->
RUNNING
2016-01-26 05:22:06,169 [29588d01-c725-8642-b99d-e902fd4e7f93:frag:0:0] INFO  o.a.d.e.w.f.FragmentStatusReporter
- 29588d01-c725-8642-b99d-e902fd4e7f93:0:0: State to report: RUNNING
2016-01-26 05:22:06,175 [29588d02-7206-dac7-a1dd-bb4a99fed1b9:frag:0:0] INFO  o.a.d.e.w.fragment.FragmentExecutor
- 29588d02-7206-dac7-a1dd-bb4a99fed1b9:0:0: State change requested AWAITING_ALLOCATION -->
RUNNING
2016-01-26 05:22:06,175 [29588d02-7206-dac7-a1dd-bb4a99fed1b9:frag:0:0] INFO  o.a.d.e.w.f.FragmentStatusReporter
- 29588d02-7206-dac7-a1dd-bb4a99fed1b9:0:0: State to report: RUNNING
2016-01-26 05:22:06,247 [29588d01-c725-8642-b99d-e902fd4e7f93:frag:0:0] INFO  o.a.d.e.w.fragment.FragmentExecutor
- 29588d01-c725-8642-b99d-e902fd4e7f93:0:0: State change requested RUNNING --> FINISHED
2016-01-26 05:22:06,248 [29588d01-c725-8642-b99d-e902fd4e7f93:frag:0:0] INFO  o.a.d.e.w.f.FragmentStatusReporter
- 29588d01-c725-8642-b99d-e902fd4e7f93:0:0: State to report: FINISHED
2016-01-26 05:22:06,248 [29588d01-51bd-c95b-a4ef-692ababd0a05:frag:0:0] INFO  o.a.d.e.w.fragment.FragmentExecutor
- 29588d01-51bd-c95b-a4ef-692ababd0a05:0:0: State change requested AWAITING_ALLOCATION -->
RUNNING
2016-01-26 05:22:06,248 [29588d01-51bd-c95b-a4ef-692ababd0a05:frag:0:0] INFO  o.a.d.e.w.f.FragmentStatusReporter
- 29588d01-51bd-c95b-a4ef-692ababd0a05:0:0: State to report: RUNNING
2016-01-26 05:22:06,249 [29588d01-51bd-c95b-a4ef-692ababd0a05:frag:0:0] INFO  o.a.d.e.w.fragment.FragmentExecutor
- 29588d01-51bd-c95b-a4ef-692ababd0a05:0:0: State change requested RUNNING --> FINISHED
2016-01-26 05:22:06,249 [29588d01-51bd-c95b-a4ef-692ababd0a05:frag:0:0] INFO  o.a.d.e.w.f.FragmentStatusReporter
- 29588d01-51bd-c95b-a4ef-692ababd0a05:0:0: State to report: FINISHED
2016-01-26 05:22:06,292 [29588d02-6fc1-3e49-4e4b-de4cc6205538:foreman] ERROR o.a.drill.exec.work.foreman.Foreman
- SYSTEM ERROR: NullPointerException


[Error Id: ac0f28f9-b569-4eac-af54-bedbce33278a on atsqa6c61.qa.lab:31010]
org.apache.drill.common.exceptions.UserException: SYSTEM ERROR: NullPointerException


[Error Id: ac0f28f9-b569-4eac-af54-bedbce33278a on atsqa6c61.qa.lab:31010]
        at org.apache.drill.common.exceptions.UserException$Builder.build(UserException.java:543)
~[drill-common-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        at org.apache.drill.exec.work.foreman.Foreman$ForemanResult.close(Foreman.java:746)
[drill-java-exec-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        at org.apache.drill.exec.work.foreman.Foreman$StateSwitch.processEvent(Foreman.java:858)
[drill-java-exec-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        at org.apache.drill.exec.work.foreman.Foreman$StateSwitch.processEvent(Foreman.java:790)
[drill-java-exec-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        at org.apache.drill.common.EventProcessor.sendEvent(EventProcessor.java:73) [drill-common-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        at org.apache.drill.exec.work.foreman.Foreman$StateSwitch.moveToState(Foreman.java:792)
[drill-java-exec-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        at org.apache.drill.exec.work.foreman.Foreman.moveToState(Foreman.java:909) [drill-java-exec-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        at org.apache.drill.exec.work.foreman.Foreman.run(Foreman.java:261) [drill-java-exec-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[na:1.7.0_45]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[na:1.7.0_45]
        at java.lang.Thread.run(Thread.java:744) [na:1.7.0_45]
Caused by: org.apache.drill.exec.work.foreman.ForemanException: Unexpected exception during
fragment initialization: Internal error: Error while applying rule DrillTableRule, args [rel#6431439:EnumerableTableScan.ENUMERABLE.ANY([]).[](table=[hive,
lineitem_text_partitioned_hive_hier_intstring])]
        ... 4 common frames omitted
Caused by: java.lang.AssertionError: Internal error: Error while applying rule DrillTableRule,
args [rel#6431439:EnumerableTableScan.ENUMERABLE.ANY([]).[](table=[hive, lineitem_text_partitioned_hive_hier_intstring])]
        at org.apache.calcite.util.Util.newInternal(Util.java:792) ~[calcite-core-1.4.0-drill-r10.jar:1.4.0-drill-r10]
        at org.apache.calcite.plan.volcano.VolcanoRuleCall.onMatch(VolcanoRuleCall.java:251)
~[calcite-core-1.4.0-drill-r10.jar:1.4.0-drill-r10]
        at org.apache.calcite.plan.volcano.VolcanoPlanner.findBestExp(VolcanoPlanner.java:808)
~[calcite-core-1.4.0-drill-r10.jar:1.4.0-drill-r10]
        at org.apache.calcite.tools.Programs$RuleSetProgram.run(Programs.java:303) ~[calcite-core-1.4.0-drill-r10.jar:1.4.0-drill-r10]
        at org.apache.calcite.prepare.PlannerImpl.transform(PlannerImpl.java:313) ~[calcite-core-1.4.0-drill-r10.jar:1.4.0-drill-r10]
        at org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler.doLogicalPlanning(DefaultSqlHandler.java:542)
~[drill-java-exec-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        at org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler.convertToDrel(DefaultSqlHandler.java:218)
~[drill-java-exec-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        at org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler.convertToDrel(DefaultSqlHandler.java:252)
~[drill-java-exec-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        at org.apache.drill.exec.planner.sql.handlers.DefaultSqlHandler.getPlan(DefaultSqlHandler.java:172)
~[drill-java-exec-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        at org.apache.drill.exec.planner.sql.DrillSqlWorker.getPlan(DrillSqlWorker.java:199)
~[drill-java-exec-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        at org.apache.drill.exec.work.foreman.Foreman.runSQL(Foreman.java:924) [drill-java-exec-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        at org.apache.drill.exec.work.foreman.Foreman.run(Foreman.java:250) [drill-java-exec-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        ... 3 common frames omitted
Caused by: java.lang.AssertionError: Internal error: Error occurred while applying rule DrillTableRule
        at org.apache.calcite.util.Util.newInternal(Util.java:792) ~[calcite-core-1.4.0-drill-r10.jar:1.4.0-drill-r10]
        at org.apache.calcite.plan.volcano.VolcanoRuleCall.transformTo(VolcanoRuleCall.java:150)
~[calcite-core-1.4.0-drill-r10.jar:1.4.0-drill-r10]
        at org.apache.calcite.plan.RelOptRuleCall.transformTo(RelOptRuleCall.java:213) ~[calcite-core-1.4.0-drill-r10.jar:1.4.0-drill-r10]
        at org.apache.drill.exec.planner.logical.DrillScanRule.onMatch(DrillScanRule.java:37)
~[drill-java-exec-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        at org.apache.calcite.plan.volcano.VolcanoRuleCall.onMatch(VolcanoRuleCall.java:228)
~[calcite-core-1.4.0-drill-r10.jar:1.4.0-drill-r10]
        ... 13 common frames omitted
Caused by: java.lang.reflect.UndeclaredThrowableException: null
        at com.sun.proxy.$Proxy69.getNonCumulativeCost(Unknown Source) ~[na:na]
        at org.apache.calcite.rel.metadata.RelMetadataQuery.getNonCumulativeCost(RelMetadataQuery.java:115)
~[calcite-core-1.4.0-drill-r10.jar:1.4.0-drill-r10]
        at org.apache.calcite.plan.volcano.VolcanoPlanner.getCost(VolcanoPlanner.java:1112)
~[calcite-core-1.4.0-drill-r10.jar:1.4.0-drill-r10]
        at org.apache.calcite.plan.volcano.RelSubset.propagateCostImprovements0(RelSubset.java:363)
~[calcite-core-1.4.0-drill-r10.jar:1.4.0-drill-r10]
        at org.apache.calcite.plan.volcano.RelSubset.propagateCostImprovements(RelSubset.java:344)
~[calcite-core-1.4.0-drill-r10.jar:1.4.0-drill-r10]
        at org.apache.calcite.plan.volcano.VolcanoPlanner.addRelToSet(VolcanoPlanner.java:1827)
~[calcite-core-1.4.0-drill-r10.jar:1.4.0-drill-r10]
        at org.apache.calcite.plan.volcano.VolcanoPlanner.registerImpl(VolcanoPlanner.java:1760)
~[calcite-core-1.4.0-drill-r10.jar:1.4.0-drill-r10]
        at org.apache.calcite.plan.volcano.VolcanoPlanner.register(VolcanoPlanner.java:1017)
~[calcite-core-1.4.0-drill-r10.jar:1.4.0-drill-r10]
        at org.apache.calcite.plan.volcano.VolcanoPlanner.ensureRegistered(VolcanoPlanner.java:1037)
~[calcite-core-1.4.0-drill-r10.jar:1.4.0-drill-r10]
        at org.apache.calcite.plan.volcano.VolcanoPlanner.ensureRegistered(VolcanoPlanner.java:1940)
~[calcite-core-1.4.0-drill-r10.jar:1.4.0-drill-r10]
        at org.apache.calcite.plan.volcano.VolcanoRuleCall.transformTo(VolcanoRuleCall.java:138)
~[calcite-core-1.4.0-drill-r10.jar:1.4.0-drill-r10]
        ... 16 common frames omitted
Caused by: java.lang.reflect.InvocationTargetException: null
        at sun.reflect.GeneratedMethodAccessor34.invoke(Unknown Source) ~[na:na]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
~[na:1.7.0_45]
        at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_45]
        at org.apache.calcite.rel.metadata.ReflectiveRelMetadataProvider$1$1.invoke(ReflectiveRelMetadataProvider.java:182)
~[calcite-core-1.4.0-drill-r10.jar:1.4.0-drill-r10]
        ... 27 common frames omitted
Caused by: org.apache.drill.common.exceptions.DrillRuntimeException: java.io.IOException:
Failed to get numRows from HiveTable
        at org.apache.drill.exec.store.hive.HiveScan.getScanStats(HiveScan.java:233) ~[drill-storage-hive-core-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        at org.apache.drill.exec.physical.base.AbstractGroupScan.getScanStats(AbstractGroupScan.java:76)
~[drill-java-exec-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        at org.apache.drill.exec.planner.logical.DrillScanRel.computeSelfCost(DrillScanRel.java:164)
~[drill-java-exec-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        at org.apache.calcite.rel.metadata.RelMdPercentageOriginalRows.getNonCumulativeCost(RelMdPercentageOriginalRows.java:165)
~[calcite-core-1.4.0-drill-r10.jar:1.4.0-drill-r10]
        ... 31 common frames omitted
Caused by: java.io.IOException: Failed to get numRows from HiveTable
        at org.apache.drill.exec.store.hive.HiveMetadataProvider.getStats(HiveMetadataProvider.java:113)
~[drill-storage-hive-core-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        at org.apache.drill.exec.store.hive.HiveScan.getScanStats(HiveScan.java:224) ~[drill-storage-hive-core-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        ... 34 common frames omitted
Caused by: java.lang.NullPointerException: null
        at com.mapr.fs.MapRFileSystem.globStatus(MapRFileSystem.java:1241) ~[maprfs-4.1.0-mapr.jar:4.1.0-mapr]
        at org.apache.hadoop.mapred.FileInputFormat.singleThreadedListStatus(FileInputFormat.java:259)
~[hadoop-mapreduce-client-core-2.7.0-mapr-1506.jar:na]
        at org.apache.hadoop.mapred.FileInputFormat.listStatus(FileInputFormat.java:229) ~[hadoop-mapreduce-client-core-2.7.0-mapr-1506.jar:na]
        at org.apache.hadoop.mapred.FileInputFormat.getSplits(FileInputFormat.java:317) ~[hadoop-mapreduce-client-core-2.7.0-mapr-1506.jar:na]
        at org.apache.drill.exec.store.hive.HiveMetadataProvider$1.run(HiveMetadataProvider.java:253)
~[drill-storage-hive-core-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        at org.apache.drill.exec.store.hive.HiveMetadataProvider$1.run(HiveMetadataProvider.java:241)
~[drill-storage-hive-core-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        at java.security.AccessController.doPrivileged(Native Method) ~[na:1.7.0_45]
        at javax.security.auth.Subject.doAs(Subject.java:415) ~[na:1.7.0_45]
        at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1595)
~[hadoop-common-2.7.0-mapr-1506.jar:na]
        at org.apache.drill.exec.store.hive.HiveMetadataProvider.splitInputWithUGI(HiveMetadataProvider.java:241)
~[drill-storage-hive-core-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        at org.apache.drill.exec.store.hive.HiveMetadataProvider.getPartitionInputSplits(HiveMetadataProvider.java:142)
~[drill-storage-hive-core-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        at org.apache.drill.exec.store.hive.HiveMetadataProvider.getStats(HiveMetadataProvider.java:105)
~[drill-storage-hive-core-1.5.0-SNAPSHOT.jar:1.5.0-SNAPSHOT]
        ... 35 common frames omitted
{noformat}




--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Mime
View raw message