You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@drill.apache.org by "Khurram Faraaz (JIRA)" <ji...@apache.org> on 2016/09/07 11:41:20 UTC

[jira] [Commented] (DRILL-4856) stop foreman Drillbit results in DATA_READ_ERROR - NPE

    [ https://issues.apache.org/jira/browse/DRILL-4856?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15470370#comment-15470370 ] 

Khurram Faraaz commented on DRILL-4856:
---------------------------------------

Was this fixed recently, that is because we do not see the DATA_READ_ERROR on apache Drill 1.9.0

{noformat}
0: jdbc:drill:schema=dfs.tmp> select * from sys.version;
+-----------------+-------------------------------------------+------------------------------------+----------------------------+-----------------------+----------------------------+
|     version     |                 commit_id                 |           commit_message           |        commit_time         |      build_email      |         build_time         |
+-----------------+-------------------------------------------+------------------------------------+----------------------------+-----------------------+----------------------------+
| 1.9.0-SNAPSHOT  | 28d315bbb1b9145488a886179aa3e6683b338556  | Update version to 1.9.0-SNAPSHOT.  | 30.08.2016 @ 17:56:03 UTC  | kfaraaz@maprtech.com  | 01.09.2016 @ 09:29:55 UTC  |
+-----------------+-------------------------------------------+------------------------------------+----------------------------+-----------------------+----------------------------+
1 row selected (0.319 seconds)
0: jdbc:drill:schema=dfs.tmp> select count(*) from `twoKeyJsn.json`;
Error: CONNECTION ERROR: Connection /10.10.100.201:35153 <--> /10.10.100.201:31010 (user client) closed unexpectedly. Drillbit down?


[Error Id: c451f355-7562-4b95-a5ff-6fc2a0a3328c ] (state=,code=0)
{noformat}

> stop foreman Drillbit results in DATA_READ_ERROR - NPE
> ------------------------------------------------------
>
>                 Key: DRILL-4856
>                 URL: https://issues.apache.org/jira/browse/DRILL-4856
>             Project: Apache Drill
>          Issue Type: Bug
>          Components: Execution - Flow
>    Affects Versions: 1.8.0
>         Environment: 4 node cluster CentOS
>            Reporter: Khurram Faraaz
>
> Steps to reproduce the problem
> {noformat}
> 1. start 4 Drillbits on 4 different nodes using /opt/mapr/drill/drill-1.8.0/bin/drillbit.sh start
> 2. execute query from sqlline => select count(*) from `twoKeyJsn.json`;
> 3. Stop the foreman Drillbit while the above query still under execution, /opt/mapr/drill/drill-1.8.0/bin/drillbit.sh stop
> 4. You will see DATA_READ ERROR on sqlline prompt
> {noformat}
> apache Drill version 1.8.0-SNAPSHOT git commit ID: 57dc9f43
> On doing a kill -9 <PID> (PID being that of Foreman Drillbit) while the long running query was under execution, we would see the below message on sqlline prompt, when I used MapR Drill RPM.
> [root@centos-01 drill]# find . -name *.java -print | xargs grep -i "Drillbit down"
> ./exec/java-exec/src/main/java/org/apache/drill/exec/rpc/user/QueryResultHandler.java:                    .message("Connection %s closed unexpectedly. Drillbit down?",
> However on apache Drill master I did not see the same behavior, instead we see DATA_READ ERROR caused due to an NPE
> {noformat}
> /* Input JSON file is large, it has 26M key value pairs*/
> 0: jdbc:drill:schema=dfs.tmp> select count(*) from `twoKeyJsn.json`;
> Error: DATA_READ ERROR: Error parsing JSON - null
> File  /tmp/twoKeyJsn.json
> Record  1508271
> Fragment 0:0
> [Error Id: 044924dd-12f5-41b2-8ec1-2c7e6ef04123 on centos-01.qa.lab:31010] (state=,code=0)
> {noformat}
> Stack trace from drillbit.log
> {noformat}
> 2016-08-19 06:05:39,740 [28495e4b-a163-cd09-9b99-27e7f02f3e18:foreman] INFO  o.a.drill.exec.work.foreman.Foreman - Query text for query id 28495e4b-a163-cd09-9b99-27e7f02f3e18: select count(*) from `twoKeyJsn.json`
> 2016-08-19 06:05:39,764 [28495e4b-a163-cd09-9b99-27e7f02f3e18:foreman] INFO  o.a.d.exec.store.dfs.FileSelection - FileSelection.getStatuses() took 0 ms, numFiles: 1
> 2016-08-19 06:05:39,764 [28495e4b-a163-cd09-9b99-27e7f02f3e18:foreman] INFO  o.a.d.exec.store.dfs.FileSelection - FileSelection.getStatuses() took 0 ms, numFiles: 1
> 2016-08-19 06:05:39,765 [28495e4b-a163-cd09-9b99-27e7f02f3e18:foreman] INFO  o.a.d.exec.store.dfs.FileSelection - FileSelection.getStatuses() took 0 ms, numFiles: 1
> 2016-08-19 06:05:39,765 [28495e4b-a163-cd09-9b99-27e7f02f3e18:foreman] INFO  o.a.d.exec.store.dfs.FileSelection - FileSelection.getStatuses() took 0 ms, numFiles: 1
> 2016-08-19 06:05:39,765 [28495e4b-a163-cd09-9b99-27e7f02f3e18:foreman] INFO  o.a.d.exec.store.dfs.FileSelection - FileSelection.getStatuses() took 0 ms, numFiles: 1
> 2016-08-19 06:05:39,765 [28495e4b-a163-cd09-9b99-27e7f02f3e18:foreman] INFO  o.a.d.exec.store.dfs.FileSelection - FileSelection.getStatuses() took 0 ms, numFiles: 1
> 2016-08-19 06:05:39,775 [28495e4b-a163-cd09-9b99-27e7f02f3e18:foreman] INFO  o.a.d.exec.store.dfs.FileSelection - FileSelection.getStatuses() took 0 ms, numFiles: 1
> 2016-08-19 06:05:39,779 [28495e4b-a163-cd09-9b99-27e7f02f3e18:foreman] INFO  o.a.d.e.s.schedule.BlockMapBuilder - Get block maps: Executed 1 out of 1 using 1 threads. Time: 3ms total, 3.595731ms avg, 3ms max.
> 2016-08-19 06:05:39,780 [28495e4b-a163-cd09-9b99-27e7f02f3e18:foreman] INFO  o.a.d.e.s.schedule.BlockMapBuilder - Get block maps: Executed 1 out of 1 using 1 threads. Earliest start: 1.348000 μs, Latest start: 1.348000 μs, Average start: 1.348000 μs .
> 2016-08-19 06:05:39,849 [28495e4b-a163-cd09-9b99-27e7f02f3e18:frag:0:0] INFO  o.a.d.e.w.fragment.FragmentExecutor - 28495e4b-a163-cd09-9b99-27e7f02f3e18:0:0: State change requested AWAITING_ALLOCATION --> RUNNING
> 2016-08-19 06:05:39,849 [28495e4b-a163-cd09-9b99-27e7f02f3e18:frag:0:0] INFO  o.a.d.e.w.f.FragmentStatusReporter - 28495e4b-a163-cd09-9b99-27e7f02f3e18:0:0: State to report: RUNNING
> Fri Aug 19 06:05:41 UTC 2016 Terminating drillbit pid 18812
> 2016-08-19 06:05:41,592 [Drillbit-ShutdownHook#0] INFO  o.apache.drill.exec.server.Drillbit - Received shutdown request.
> 2016-08-19 06:05:41,605 [28495e4b-a163-cd09-9b99-27e7f02f3e18:frag:0:0] INFO  o.a.d.e.s.easy.json.JSONRecordReader - User Error Occurred
> org.apache.drill.common.exceptions.UserException: DATA_READ ERROR: Error parsing JSON - null
> File  /tmp/twoKeyJsn.json
> Record  1508271
> [Error Id: 044924dd-12f5-41b2-8ec1-2c7e6ef04123 ]
>         at org.apache.drill.common.exceptions.UserException$Builder.build(UserException.java:543) ~[drill-common-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.store.easy.json.JSONRecordReader.handleAndRaise(JSONRecordReader.java:181) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.store.easy.json.JSONRecordReader.next(JSONRecordReader.java:221) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.physical.impl.ScanBatch.next(ScanBatch.java:178) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.record.AbstractRecordBatch.next(AbstractRecordBatch.java:119) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.record.AbstractRecordBatch.next(AbstractRecordBatch.java:109) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.record.AbstractSingleRecordBatch.innerNext(AbstractSingleRecordBatch.java:51) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.physical.impl.project.ProjectRecordBatch.innerNext(ProjectRecordBatch.java:135) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.record.AbstractRecordBatch.next(AbstractRecordBatch.java:162) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.record.AbstractRecordBatch.next(AbstractRecordBatch.java:119) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.test.generated.StreamingAggregatorGen3.doWork(StreamingAggTemplate.java:173) [na:na]
>         at org.apache.drill.exec.physical.impl.aggregate.StreamingAggBatch.innerNext(StreamingAggBatch.java:167) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.record.AbstractRecordBatch.next(AbstractRecordBatch.java:162) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.record.AbstractRecordBatch.next(AbstractRecordBatch.java:119) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.record.AbstractRecordBatch.next(AbstractRecordBatch.java:109) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.physical.impl.aggregate.StreamingAggBatch.innerNext(StreamingAggBatch.java:137) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.record.AbstractRecordBatch.next(AbstractRecordBatch.java:162) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.record.AbstractRecordBatch.next(AbstractRecordBatch.java:119) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.record.AbstractRecordBatch.next(AbstractRecordBatch.java:109) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.record.AbstractSingleRecordBatch.innerNext(AbstractSingleRecordBatch.java:51) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.physical.impl.project.ProjectRecordBatch.innerNext(ProjectRecordBatch.java:135) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.record.AbstractRecordBatch.next(AbstractRecordBatch.java:162) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.physical.impl.BaseRootExec.next(BaseRootExec.java:104) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.physical.impl.ScreenCreator$ScreenRoot.innerNext(ScreenCreator.java:81) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.physical.impl.BaseRootExec.next(BaseRootExec.java:94) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.work.fragment.FragmentExecutor$1.run(FragmentExecutor.java:232) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.work.fragment.FragmentExecutor$1.run(FragmentExecutor.java:226) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at java.security.AccessController.doPrivileged(Native Method) [na:1.8.0_91]
>         at javax.security.auth.Subject.doAs(Subject.java:422) [na:1.8.0_91]
>         at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1595) [hadoop-common-2.7.0-mapr-1607.jar:na]
>         at org.apache.drill.exec.work.fragment.FragmentExecutor.run(FragmentExecutor.java:226) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.common.SelfCleaningRunnable.run(SelfCleaningRunnable.java:38) [drill-common-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_91]
>         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_91]
>         at java.lang.Thread.run(Thread.java:745) [na:1.8.0_91]
> Caused by: java.lang.NullPointerException: null
>         at com.mapr.fs.MapRFsInStream.read(MapRFsInStream.java:276) ~[maprfs-5.2.0-mapr.jar:5.2.0-mapr]
>         at java.io.DataInputStream.read(DataInputStream.java:149) ~[na:1.8.0_91]
>         at org.apache.drill.exec.store.dfs.DrillFSDataInputStream$WrappedInputStream.read(DrillFSDataInputStream.java:216) ~[drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at java.io.DataInputStream.read(DataInputStream.java:149) ~[na:1.8.0_91]
>         at com.fasterxml.jackson.core.json.UTF8StreamJsonParser.loadMore(UTF8StreamJsonParser.java:207) ~[jackson-core-2.7.1.jar:2.7.1]
>         at com.fasterxml.jackson.core.json.UTF8StreamJsonParser.parseEscapedName(UTF8StreamJsonParser.java:1983) ~[jackson-core-2.7.1.jar:2.7.1]
>         at com.fasterxml.jackson.core.json.UTF8StreamJsonParser.slowParseName(UTF8StreamJsonParser.java:1885) ~[jackson-core-2.7.1.jar:2.7.1]
>         at com.fasterxml.jackson.core.json.UTF8StreamJsonParser._parseName(UTF8StreamJsonParser.java:1669) ~[jackson-core-2.7.1.jar:2.7.1]
>         at com.fasterxml.jackson.core.json.UTF8StreamJsonParser.nextToken(UTF8StreamJsonParser.java:752) ~[jackson-core-2.7.1.jar:2.7.1]
>         at org.apache.drill.exec.vector.complex.fn.JsonReader.writeData(JsonReader.java:320) ~[drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.vector.complex.fn.JsonReader.writeDataSwitch(JsonReader.java:277) ~[drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.vector.complex.fn.JsonReader.writeToVector(JsonReader.java:215) ~[drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.vector.complex.fn.JsonReader.write(JsonReader.java:181) ~[drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         at org.apache.drill.exec.store.easy.json.JSONRecordReader.next(JSONRecordReader.java:199) [drill-java-exec-1.8.0-SNAPSHOT.jar:1.8.0-SNAPSHOT]
>         ... 32 common frames omitted
> {noformat}



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