Uploaded image for project: 'CDH (READ-ONLY)'
  1. CDH (READ-ONLY)
  2. DISTRO-711

Exception root cause null (during query execution error)

          Details

          • Type: Bug
          • Status: Open
          • Priority: Major
          • Resolution: Unresolved
          • Affects Version/s: CDH 5.3.0
          • Fix Version/s: None
          • Component/s: Hive
          • Labels:
            None
          • Environment:
            Java application with Gradle dependencies as below.
            compile 'org.apache.hive:hive-exec:0.13.1-cdh5.3.0'
            compile 'org.apache.hive:hive-jdbc:0.13.1-cdh5.3.0'

            Description

            Let's start Hive query that takes time. In the middle of processing stop metastore. Job fails, of course, but does not provide any meaningful information about root cause.

            Hive log clearly says what is root cause (connection lost to metastore).

            2015-04-23 11:07:28,443 ERROR org.apache.hadoop.hive.ql.exec.Task: Failed with exception Unable to fetch table job_779_item_temp
org.apache.hadoop.hive.ql.metadata.HiveException: Unable to fetch table job_779_item_temp
	at org.apache.hadoop.hive.ql.metadata.Hive.getTable(Hive.java:1008)
	at org.apache.hadoop.hive.ql.metadata.Hive.getTable(Hive.java:942)
	at org.apache.hadoop.hive.ql.exec.MoveTask.execute(MoveTask.java:246)
	at org.apache.hadoop.hive.ql.exec.Task.executeTask(Task.java:153)
	at org.apache.hadoop.hive.ql.exec.TaskRunner.runSequential(TaskRunner.java:85)
	at org.apache.hadoop.hive.ql.Driver.launchTask(Driver.java:1554)
	at org.apache.hadoop.hive.ql.Driver.execute(Driver.java:1321)
	at org.apache.hadoop.hive.ql.Driver.runInternal(Driver.java:1139)
	at org.apache.hadoop.hive.ql.Driver.run(Driver.java:962)
	at org.apache.hadoop.hive.ql.Driver.run(Driver.java:957)
	at org.apache.hive.service.cli.operation.SQLOperation.runInternal(SQLOperation.java:145)
	at org.apache.hive.service.cli.operation.SQLOperation.access$000(SQLOperation.java:69)
	at org.apache.hive.service.cli.operation.SQLOperation$1$1.run(SQLOperation.java:200)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:415)
	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1642)
	at org.apache.hadoop.hive.shims.HadoopShimsSecure.doAs(HadoopShimsSecure.java:502)
	at org.apache.hive.service.cli.operation.SQLOperation$1.run(SQLOperation.java:213)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)
Caused by: MetaException(message:Could not connect to meta store using any of the URIs provided. Most recent failure: org.apache.thrift.transport.TTransportException: java.net.ConnectException: Connection refused
	at org.apache.thrift.transport.TSocket.open(TSocket.java:185)
	at org.apache.hadoop.hive.metastore.HiveMetaStoreClient.open(HiveMetaStoreClient.java:347)
	at org.apache.hadoop.hive.metastore.HiveMetaStoreClient.reconnect(HiveMetaStoreClient.java:253)
	at org.apache.hadoop.hive.metastore.RetryingMetaStoreClient.invoke(RetryingMetaStoreClient.java:88)
	at com.sun.proxy.$Proxy10.getTable(Unknown Source)
	at org.apache.hadoop.hive.ql.metadata.Hive.getTable(Hive.java:1000)
	at org.apache.hadoop.hive.ql.metadata.Hive.getTable(Hive.java:942)
	at org.apache.hadoop.hive.ql.exec.MoveTask.execute(MoveTask.java:246)
	at org.apache.hadoop.hive.ql.exec.Task.executeTask(Task.java:153)
	at org.apache.hadoop.hive.ql.exec.TaskRunner.runSequential(TaskRunner.java:85)
	at org.apache.hadoop.hive.ql.Driver.launchTask(Driver.java:1554)
	at org.apache.hadoop.hive.ql.Driver.execute(Driver.java:1321)
	at org.apache.hadoop.hive.ql.Driver.runInternal(Driver.java:1139)
	at org.apache.hadoop.hive.ql.Driver.run(Driver.java:962)
	at org.apache.hadoop.hive.ql.Driver.run(Driver.java:957)
	at org.apache.hive.service.cli.operation.SQLOperation.runInternal(SQLOperation.java:145)
	at org.apache.hive.service.cli.operation.SQLOperation.access$000(SQLOperation.java:69)
	at org.apache.hive.service.cli.operation.SQLOperation$1$1.run(SQLOperation.java:200)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:415)
	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1642)
	at org.apache.hadoop.hive.shims.HadoopShimsSecure.doAs(HadoopShimsSecure.java:502)
	at org.apache.hive.service.cli.operation.SQLOperation$1.run(SQLOperation.java:213)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)
Caused by: java.net.ConnectException: Connection refused
	at java.net.PlainSocketImpl.socketConnect(Native Method)
	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
	at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
	at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
	at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
	at java.net.Socket.connect(Socket.java:579)
	at org.apache.thrift.transport.TSocket.open(TSocket.java:180)
	... 27 more
)
	at org.apache.hadoop.hive.metastore.HiveMetaStoreClient.open(HiveMetaStoreClient.java:393)
	at org.apache.hadoop.hive.metastore.HiveMetaStoreClient.reconnect(HiveMetaStoreClient.java:253)
	at org.apache.hadoop.hive.metastore.RetryingMetaStoreClient.invoke(RetryingMetaStoreClient.java:88)
	at com.sun.proxy.$Proxy10.getTable(Unknown Source)
	at org.apache.hadoop.hive.ql.metadata.Hive.getTable(Hive.java:1000)
	... 22 more

2015-04-23 11:07:28,443 ERROR org.apache.hadoop.hive.ql.Driver: FAILED: Execution Error, return code 1 from org.apache.hadoop.hive.ql.exec.MoveTask
2015-04-23 11:07:28,443 INFO org.apache.hadoop.hive.ql.log.PerfLogger: </PERFLOG method=Driver.execute start=1429754786299 end=1429754848443 duration=62144 from=org.apache.hadoop.hive.ql.Driver>
2015-04-23 11:07:28,443 INFO org.apache.hadoop.hive.ql.Driver: MapReduce Jobs Launched: 
2015-04-23 11:07:28,443 INFO org.apache.hadoop.hive.ql.Driver: Stage-Stage-1: Map: 2  Reduce: 1   Cumulative CPU: 4.49 sec   HDFS Read: 875 HDFS Write: 496 SUCCESS
2015-04-23 11:07:28,443 INFO org.apache.hadoop.hive.ql.Driver: Stage-Stage-2: Map: 2  Reduce: 1   Cumulative CPU: 4.42 sec   HDFS Read: 7244 HDFS Write: 2869 SUCCESS
2015-04-23 11:07:28,444 INFO org.apache.hadoop.hive.ql.Driver: Total MapReduce CPU Time Spent: 8 seconds 910 msec
2015-04-23 11:07:28,444 INFO org.apache.hadoop.hive.ql.log.PerfLogger: <PERFLOG method=releaseLocks from=org.apache.hadoop.hive.ql.Driver>
2015-04-23 11:07:28,444 INFO org.apache.hadoop.hive.ql.log.PerfLogger: </PERFLOG method=releaseLocks start=1429754848444 end=1429754848444 duration=0 from=org.apache.hadoop.hive.ql.Driver>
2015-04-23 11:07:28,444 ERROR org.apache.hive.service.cli.operation.Operation: Error running hive query: 
org.apache.hive.service.cli.HiveSQLException: Error while processing statement: FAILED: Execution Error, return code 1 from org.apache.hadoop.hive.ql.exec.MoveTask
	at org.apache.hive.service.cli.operation.SQLOperation.runInternal(SQLOperation.java:147)
	at org.apache.hive.service.cli.operation.SQLOperation.access$000(SQLOperation.java:69)
	at org.apache.hive.service.cli.operation.SQLOperation$1$1.run(SQLOperation.java:200)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:415)
	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1642)
	at org.apache.hadoop.hive.shims.HadoopShimsSecure.doAs(HadoopShimsSecure.java:502)
	at org.apache.hive.service.cli.operation.SQLOperation$1.run(SQLOperation.java:213)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	at java.lang.Thread.run(Thread.java:745)

            Unfortunately only exception that is thrown is:

            java.sql.SQLException
- message: Error while processing statement: FAILED: Execution Error, return code 1 from org.apache.hadoop.hive.ql.exec.MoveTask
- cause: null

            Based on this exception you are unable to tell real cause, unless you check hive logs manually.

              Attachments

                Activity

                  People

                  • Assignee:
                    Unassigned
                    Reporter:
                    michalmichalak Michal Michalak
                  • Votes:
                    0 Vote for this issue
                    Watchers:
                    1 Start watching this issue

                    Dates

                    • Created:
                      Updated: