Page MenuHomePhabricator

Beeline does not print full stack traces when a query fails
Closed, ResolvedPublic1 Estimated Story Points

Description

The Hive cli - when there's an error prints a detailed stacktrace, but beeline does not - need to look into if there's a configuration switch that can be flipped to make this happen.

Event Timeline

Milimetric triaged this task as Medium priority.Jun 6 2016, 4:35 PM
Milimetric moved this task from Incoming to Dashiki on the Analytics board.
Nuria renamed this task from Beeline does not print full stack traces when a query fails {hawk} to Beeline does not print full stack traces when a query fails.Nov 29 2017, 1:59 AM
Nuria removed Milimetric as the assignee of this task.
Nuria moved this task from Next Up to In Progress on the Analytics-Kanban board.
Nuria added a subscriber: Milimetric.

showNestedErrs=true does not work:

beeline --showNestedErrs=true --debug=true -e "invalid syntax;"

does not return a stack trace

From my brief research I think beeline (given that is a "remote" client to hiveServer via JDBC) does not do stacktraces until this patch which is added to Hive 14

https://issues.apache.org/jira/browse/HIVE-7379?page=com.atlassian.jira.plugin.system.issuetabpanels%3Aall-tabpanel

Once we upgrade we will get it but there is not command line argument that works for version hive12 and 13

Nuria set the point value for this task to 1.Mar 3 2018, 12:06 AM
Nuria moved this task from Paused to Done on the Analytics-Kanban board.

We currently are running Hive 1.1.0 (that should be 0.15 IIUC) and I can see this:

elukey@stat1007:~$ beeline --verbose -e "invalid"
Picked up JAVA_TOOL_OPTIONS: -Dfile.encoding=UTF-8
Picked up JAVA_TOOL_OPTIONS: -Dfile.encoding=UTF-8
Picked up JAVA_TOOL_OPTIONS: -Dfile.encoding=UTF-8
Picked up JAVA_TOOL_OPTIONS: -Dfile.encoding=UTF-8
Setting property: [outputformat, tsv2]
issuing: !connect jdbc:hive2://an-coord1001.eqiad.wmnet:10000 elukey [passwd stripped]
scan complete in 2ms
Connecting to jdbc:hive2://an-coord1001.eqiad.wmnet:10000
Connected to: Apache Hive (version 1.1.0-cdh5.16.1)
Driver: Hive JDBC (version 1.1.0-cdh5.16.1)
Transaction isolation: TRANSACTION_REPEATABLE_READ
Executing command: invalid

going to print operations logs
printed operations logs
Getting log thread is interrupted, since query is done!
Error: Error while compiling statement: FAILED: ParseException line 1:0 cannot recognize input near 'invalid' '<EOF>' '<EOF>' (state=42000,code=40000)
org.apache.hive.service.cli.HiveSQLException: Error while compiling statement: FAILED: ParseException line 1:0 cannot recognize input near 'invalid' '<EOF>' '<EOF>'
	at org.apache.hive.jdbc.Utils.verifySuccess(Utils.java:241)
	at org.apache.hive.jdbc.Utils.verifySuccessWithInfo(Utils.java:227)
	at org.apache.hive.jdbc.HiveStatement.execute(HiveStatement.java:255)
	at org.apache.hive.beeline.Commands.executeInternal(Commands.java:989)
	at org.apache.hive.beeline.Commands.execute(Commands.java:1180)
	at org.apache.hive.beeline.Commands.sql(Commands.java:1094)
	at org.apache.hive.beeline.BeeLine.dispatch(BeeLine.java:1180)
	at org.apache.hive.beeline.BeeLine.initArgs(BeeLine.java:840)
	at org.apache.hive.beeline.BeeLine.begin(BeeLine.java:898)
	at org.apache.hive.beeline.BeeLine.mainWithInputRedirection(BeeLine.java:518)
	at org.apache.hive.beeline.BeeLine.main(BeeLine.java:501)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.apache.hadoop.util.RunJar.run(RunJar.java:226)
	at org.apache.hadoop.util.RunJar.main(RunJar.java:141)
Caused by: org.apache.hive.service.cli.HiveSQLException: Error while compiling statement: FAILED: ParseException line 1:0 cannot recognize input near 'invalid' '<EOF>' '<EOF>'
	at org.apache.hive.service.cli.operation.Operation.toSQLException(Operation.java:400)
	at org.apache.hive.service.cli.operation.SQLOperation.prepare(SQLOperation.java:187)
	at org.apache.hive.service.cli.operation.SQLOperation.runInternal(SQLOperation.java:271)
	at org.apache.hive.service.cli.operation.Operation.run(Operation.java:337)
	at org.apache.hive.service.cli.session.HiveSessionImpl.executeStatementInternal(HiveSessionImpl.java:439)
	at org.apache.hive.service.cli.session.HiveSessionImpl.executeStatementAsync(HiveSessionImpl.java:416)
	at sun.reflect.GeneratedMethodAccessor72.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.apache.hive.service.cli.session.HiveSessionProxy.invoke(HiveSessionProxy.java:78)
	at org.apache.hive.service.cli.session.HiveSessionProxy.access$000(HiveSessionProxy.java:36)
	at org.apache.hive.service.cli.session.HiveSessionProxy$1.run(HiveSessionProxy.java:63)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAs(Subject.java:422)
	at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1924)
	at org.apache.hive.service.cli.session.HiveSessionProxy.invoke(HiveSessionProxy.java:59)
	at com.sun.proxy.$Proxy21.executeStatementAsync(Unknown Source)
	at org.apache.hive.service.cli.CLIService.executeStatementAsync(CLIService.java:282)
	at org.apache.hive.service.cli.thrift.ThriftCLIService.ExecuteStatement(ThriftCLIService.java:503)
	at org.apache.hive.service.cli.thrift.TCLIService$Processor$ExecuteStatement.getResult(TCLIService.java:1313)
	at org.apache.hive.service.cli.thrift.TCLIService$Processor$ExecuteStatement.getResult(TCLIService.java:1298)
	at org.apache.thrift.ProcessFunction.process(ProcessFunction.java:39)
	at org.apache.thrift.TBaseProcessor.process(TBaseProcessor.java:39)
	at org.apache.hive.service.auth.TSetIpAddressProcessor.process(TSetIpAddressProcessor.java:56)
	at org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:286)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.RuntimeException: org.apache.hadoop.hive.ql.parse.ParseException:line 1:0 cannot recognize input near 'invalid' '<EOF>' '<EOF>'
	at org.apache.hadoop.hive.ql.parse.ParseDriver.parse(ParseDriver.java:208)
	at org.apache.hadoop.hive.ql.parse.ParseDriver.parse(ParseDriver.java:170)
	at org.apache.hadoop.hive.ql.Driver.compile(Driver.java:524)
	at org.apache.hadoop.hive.ql.Driver.compileInternal(Driver.java:1358)
	at org.apache.hadoop.hive.ql.Driver.compileAndRespond(Driver.java:1345)
	at org.apache.hive.service.cli.operation.SQLOperation.prepare(SQLOperation.java:185)
	... 26 more
Closing: 0: jdbc:hive2://an-coord1001.eqiad.wmnet:10000

Is it the kind of stack tracing that we'd need? (seems so from https://issues.apache.org/jira/browse/HIVE-7127)

@Nuria can you check whenever you have time?

Tested that with beeline --verbose -f select.hql > out.txt stack trace is like the one hive would provide so closing!

I tested too and it seems a lot better. There's one issue and a minor nit:

  • beeline fails for me on stat1004 (with or without sudo and with or without the wrapper). It says "Unable to determine Hadoop version information." and exits, but it works fine on stat1007
  • the prompt doesn't show the database you're on, which can cause accidents. According to https://issues.apache.org/jira/browse/HIVE-13899 we can just pass --showDbInPrompt via our wrapper

Error on stat1004 was due to an experiment that I was doing to nail down why the --verbose option leads to:

java.io.FileNotFoundException: /usr/lib/hadoop/logs/hdfs-audit.log (No such file or directory)
	at java.io.FileOutputStream.open0(Native Method)
	at java.io.FileOutputStream.open(FileOutputStream.java:270)
	at java.io.FileOutputStream.<init>(FileOutputStream.java:213)

I think that one of the hadoop commands for some reason picks up the wrong log4j conf, need to investigate more (not happening on other hosts afaics).

I tried to use --showDbInPrompt but it doesn't seem to work for me..

EDIT: support for it was added in https://issues.apache.org/jira/browse/HIVE-14123, fixed version is 2.3.0 (we have 1.1.0)

The hdfs-audit log error comes from this bit in /usr/lib/hive/bin/hive:

# Make sure we're using a compatible version of Hadoop
if [ "x$HADOOP_VERSION" == "x" ]; then
    HADOOP_VERSION=$($HADOOP version | awk '{if (NR == 1) {print $2;}}');
fi

If I execute $HADOOP version in my shell I don't get any logging error, so I tried to dump the beeline's env when executing:

HIVE_HOME=/usr/lib/hive
JAVA_HOME=/usr/lib/jvm/java-8-openjdk-amd64/jre
JAVA_TOOL_OPTIONS=-Dfile.encoding=UTF-8
HADOOP_CLIENT_OPTS=-Djava.util.logging.config.file=/etc/hive/conf.analytics-hadoop/java-logging.properties
HBASE_THRIFT_MODE=-nonblocking
XDG_SESSION_ID=100306
USER=elukey
HADOOP_HEAPSIZE=256
MYSQL_PS1=mysql:\u@\h [\d]>
HIVE_AUX_JARS_PATH=
PWD=/home/elukey
HADOOP_CLASSPATH=/usr/lib/hive/conf:/usr/lib/hive/lib/accumulo-core-1.6.0.jar:/usr/lib/hive/lib/accumulo-fate-1.6.0.jar:/usr/lib/hive/lib/accumulo-start-1.6.0.jar:/usr/lib/hive/lib/accumulo-trace-1.6.0.jar:/usr/lib/hive/lib/activation-1.1.jar:/usr/lib/hive/lib/ant-1.9.1.jar:/usr/lib/hive/lib/ant-launcher-1.9.1.jar:/usr/lib/hive/lib/antlr-2.7.7.jar:/usr/lib/hive/lib/antlr-runtime-3.4.jar:/usr/lib/hive/lib/apache-log4j-extras-1.2.17.jar:/usr/lib/hive/lib/asm-3.2.jar:/usr/lib/hive/lib/asm-commons-3.1.jar:/usr/lib/hive/lib/asm-tree-3.1.jar:/usr/lib/hive/lib/avro.jar:/usr/lib/hive/lib/bonecp-0.8.0.RELEASE.jar:/usr/lib/hive/lib/calcite-avatica-1.0.0-incubating.jar:/usr/lib/hive/lib/calcite-core-1.0.0-incubating.jar:/usr/lib/hive/lib/calcite-linq4j-1.0.0-incubating.jar:/usr/lib/hive/lib/commons-beanutils-1.9.2.jar:/usr/lib/hive/lib/commons-beanutils-core-1.8.0.jar:/usr/lib/hive/lib/commons-cli-1.2.jar:/usr/lib/hive/lib/commons-codec-1.4.jar:/usr/lib/hive/lib/commons-collections-3.2.2.jar:/usr/lib/hive/lib/commons-compiler-2.7.6.jar:/usr/lib/hive/lib/commons-compress-1.4.1.jar:/usr/lib/hive/lib/commons-configuration-1.6.jar:/usr/lib/hive/lib/commons-dbcp-1.4.jar:/usr/lib/hive/lib/commons-digester-1.8.jar:/usr/lib/hive/lib/commons-el-1.0.jar:/usr/lib/hive/lib/commons-httpclient-3.0.1.jar:/usr/lib/hive/lib/commons-io-2.4.jar:/usr/lib/hive/lib/commons-lang-2.6.jar:/usr/lib/hive/lib/commons-lang3-3.1.jar:/usr/lib/hive/lib/commons-logging-1.1.3.jar:/usr/lib/hive/lib/commons-math-2.1.jar:/usr/lib/hive/lib/commons-pool-1.5.4.jar:/usr/lib/hive/lib/commons-vfs2-2.0.jar:/usr/lib/hive/lib/curator-client-2.6.0.jar:/usr/lib/hive/lib/curator-framework-2.6.0.jar:/usr/lib/hive/lib/curator-recipes-2.6.0.jar:/usr/lib/hive/lib/datanucleus-api-jdo-3.2.6.jar:/usr/lib/hive/lib/datanucleus-core-3.2.10.jar:/usr/lib/hive/lib/datanucleus-rdbms-3.2.9.jar:/usr/lib/hive/lib/derby-10.11.1.1.jar:/usr/lib/hive/lib/eigenbase-properties-1.1.4.jar:/usr/lib/hive/lib/findbugs-annotations-1.3.9-1.jar:/usr/lib/hive/lib/geronimo-annotation_1.0_spec-1.1.1.jar:/usr/lib/hive/lib/geronimo-jaspic_1.0_spec-1.0.jar:/usr/lib/hive/lib/geronimo-jta_1.1_spec-1.1.1.jar:/usr/lib/hive/lib/groovy-all-2.4.4.jar:/usr/lib/hive/lib/gson-2.2.4.jar:/usr/lib/hive/lib/guava-14.0.1.jar:/usr/lib/hive/lib/hamcrest-core-1.1.jar:/usr/lib/hive/lib/hbase-annotations.jar:/usr/lib/hive/lib/high-scale-lib-1.1.1.jar:/usr/lib/hive/lib/hive-accumulo-handler-1.1.0-cdh5.16.1.jar:/usr/lib/hive/lib/hive-accumulo-handler.jar:/usr/lib/hive/lib/hive-ant-1.1.0-cdh5.16.1.jar:/usr/lib/hive/lib/hive-ant.jar:/usr/lib/hive/lib/hive-beeline-1.1.0-cdh5.16.1.jar:/usr/lib/hive/lib/hive-beeline.jar:/usr/lib/hive/lib/hive-classification-1.1.0-cdh5.16.1.jar:/usr/lib/hive/lib/hive-classification.jar:/usr/lib/hive/lib/hive-cli-1.1.0-cdh5.16.1.jar:/usr/lib/hive/lib/hive-cli.jar:/usr/lib/hive/lib/hive-common-1.1.0-cdh5.16.1.jar:/usr/lib/hive/lib/hive-common.jar:/usr/lib/hive/lib/hive-contrib-1.1.0-cdh5.16.1.jar:/usr/lib/hive/lib/hive-contrib.jar:/usr/lib/hive/lib/hive-exec-1.1.0-cdh5.16.1.jar:/usr/lib/hive/lib/hive-exec.jar:/usr/lib/hive/lib/hive-hbase-handler-1.1.0-cdh5.16.1.jar:/usr/lib/hive/lib/hive-hbase-handler.jar:/usr/lib/hive/lib/hive-hwi-1.1.0-cdh5.16.1.jar:/usr/lib/hive/lib/hive-hwi.jar:/usr/lib/hive/lib/hive-jdbc-1.1.0-cdh5.16.1.jar:/usr/lib/hive/lib/hive-jdbc-1.1.0-cdh5.16.1-standalone.jar:/usr/lib/hive/lib/hive-jdbc.jar:/usr/lib/hive/lib/hive-jdbc-standalone.jar:/usr/lib/hive/lib/hive-metastore-1.1.0-cdh5.16.1.jar:/usr/lib/hive/lib/hive-metastore.jar:/usr/lib/hive/lib/hive-serde-1.1.0-cdh5.16.1.jar:/usr/lib/hive/lib/hive-serde.jar:/usr/lib/hive/lib/hive-service-1.1.0-cdh5.16.1.jar:/usr/lib/hive/lib/hive-service.jar:/usr/lib/hive/lib/hive-shims-0.23-1.1.0-cdh5.16.1.jar:/usr/lib/hive/lib/hive-shims-0.23.jar:/usr/lib/hive/lib/hive-shims-1.1.0-cdh5.16.1.jar:/usr/lib/hive/lib/hive-shims-common-1.1.0-cdh5.16.1.jar:/usr/lib/hive/lib/hive-shims-common.jar:/usr/lib/hive/lib/hive-shims.jar:/usr/lib/hive/lib/hive-shims-scheduler-1.1.0-cdh5.16.1.jar:/usr/lib/hive/lib/hive-shims-scheduler.jar:/usr/lib/hive/lib/hive-testutils-1.1.0-cdh5.16.1.jar:/usr/lib/hive/lib/hive-testutils.jar:/usr/lib/hive/lib/httpclient-4.2.5.jar:/usr/lib/hive/lib/httpcore-4.2.5.jar:/usr/lib/hive/lib/ivy-2.0.0-rc2.jar:/usr/lib/hive/lib/jackson-annotations-2.2.3.jar:/usr/lib/hive/lib/jackson-core-2.2.3.jar:/usr/lib/hive/lib/jackson-databind-2.2.3-cloudera.1.jar:/usr/lib/hive/lib/jackson-jaxrs-1.9.13.jar:/usr/lib/hive/lib/jackson-xc-1.9.13.jar:/usr/lib/hive/lib/jamon-runtime-2.3.1.jar:/usr/lib/hive/lib/janino-2.7.6.jar:/usr/lib/hive/lib/jasper-compiler-5.5.23.jar:/usr/lib/hive/lib/jasper-runtime-5.5.23.jar:/usr/lib/hive/lib/jcommander-1.32.jar:/usr/lib/hive/lib/jdo-api-3.0.1.jar:/usr/lib/hive/lib/jersey-server-1.14.jar:/usr/lib/hive/lib/jersey-servlet-1.14.jar:/usr/lib/hive/lib/jetty-all-7.6.0.v20120127.jar:/usr/lib/hive/lib/jetty-all-server-7.6.0.v20120127.jar:/usr/lib/hive/lib/jline-2.12.jar:/usr/lib/hive/lib/joda-time-1.6.jar:/usr/lib/hive/lib/jpam-1.1.jar:/usr/lib/hive/lib/jsp-api-2.1.jar:/usr/lib/hive/lib/jsr305-3.0.0.jar:/usr/lib/hive/lib/jta-1.1.jar:/usr/lib/hive/lib/junit-4.11.jar:/usr/lib/hive/lib/libfb303-0.9.3.jar:/usr/lib/hive/lib/libthrift-0.9.3.jar:/usr/lib/hive/lib/log4j-1.2.16.jar:/usr/lib/hive/lib/logredactor-1.0.3.jar:/usr/lib/hive/lib/mail-1.4.1.jar:/usr/lib/hive/lib/maven-scm-api-1.4.jar:/usr/lib/hive/lib/maven-scm-provider-svn-commons-1.4.jar:/usr/lib/hive/lib/maven-scm-provider-svnexe-1.4.jar:/usr/lib/hive/lib/metrics-core-3.0.2.jar:/usr/lib/hive/lib/metrics-json-3.0.2.jar:/usr/lib/hive/lib/metrics-jvm-3.0.2.jar:/usr/lib/hive/lib/opencsv-2.3.jar:/usr/lib/hive/lib/oro-2.0.8.jar:/usr/lib/hive/lib/paranamer-2.3.jar:/usr/lib/hive/lib/parquet-hadoop-bundle.jar:/usr/lib/hive/lib/pentaho-aggdesigner-algorithm-5.1.5-jhyde.jar:/usr/lib/hive/lib/plexus-utils-1.5.6.jar:/usr/lib/hive/lib/regexp-1.3.jar:/usr/lib/hive/lib/servlet-api-2.5.jar:/usr/lib/hive/lib/snappy-java-1.0.4.1.jar:/usr/lib/hive/lib/ST4-4.0.4.jar:/usr/lib/hive/lib/stax-api-1.0.1.jar:/usr/lib/hive/lib/stringtemplate-3.2.1.jar:/usr/lib/hive/lib/super-csv-2.2.0.jar:/usr/lib/hive/lib/tempus-fugit-1.1.jar:/usr/lib/hive/lib/velocity-1.5.jar:/usr/lib/hive/lib/xz-1.0.jar:/usr/lib/hive/lib/zookeeper.jar::/usr/lib/hive/auxlib/hive-exec-1.1.0-cdh5.16.1-core.jar:/usr/lib/hive/auxlib/hive-exec-core.jar
HOME=/home/elukey
HADOOP_USER_CLASSPATH_FIRST=true
SSH_TTY=/dev/pts/0
MAIL=/var/mail/elukey
HBASE_PID_DIR=/var/run/hbase
TERM=xterm-256color
SHELL=/bin/bash
OOZIE_URL=http://an-coord1001.eqiad.wmnet:11000/oozie
HADOOP_HOME_WARN_SUPPRESS=true
TMOUT=432000
HIVE_SKIP_SPARK_ASSEMBLY=true
SHLVL=2
PYTHONPATH=:/srv/deployment/analytics/refinery/python
HIVE_CONF_DIR=/usr/lib/hive/conf
LOGNAME=elukey
XDG_RUNTIME_DIR=/run/user/13926
PATH=/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
HBASE_LOG_DIR=/var/log/hbase
HBASE_IDENT_STRING=hbase
_=/usr/bin/env

Tried to do the same on stat1007, compared the diffs, nothing.

No users were logged so I have also done apt-get purge hive; puppet agent -tv, to get a clean version of hive. Issue persists.

Also tried to comment out all the log4j configs related to hdfs-audit to see if anything changed, but nothing (/etc/hadoop/conf, /etc/hadoop/conf.empty, /etc/hadoop/conf/hadoop-env.sh)

Ok turns out this is only a problem that I have, Fran seems to get no errors.. Now I am really confused :D

EDIT: I had a log4j.conf file in my home directory, that was picked up causing the issue.

This bit seems not easily solvable, since the new option has been introduced in 2.3.0 (https://issues.apache.org/jira/browse/HIVE-14123). We have the beeline version packaged with the CDH Hive, that is 1.1.0. Beeline is part of https://github.com/apache/hive/tree/master/beeline, so not sure if we could easily package a new version and use it in isolation from the hive-server/cli version that we have. It seems a very annoying issue, especially if when we'll ask to people already familiar with the hive cli to migrate.

This bit seems not easily solvable, since the new option has been introduced in 2.3.0 (https://issues.apache.org/jira/browse/HIVE-14123). We have the beeline version packaged with the CDH Hive, that is 1.1.0. Beeline is part of https://github.com/apache/hive/tree/master/beeline, so not sure if we could easily package a new version and use it in isolation from the hive-server/cli version that we have. It seems a very annoying issue, especially if when we'll ask to people already familiar with the hive cli to migrate.

I'm sorry, I thought I checked the version and it said it was available in 0.15 but I don't see that now, must've been mistaken.

Yeah, I'm not sure what the right approach is, but if we need to leave Hive behind due to Kerberos, we'll just have to get used to this until we can upgrade. Hops supports up to Hive 3.x... just saying :)

Change 524168 had a related patch set uploaded (by Elukey; owner: Elukey):
[operations/puppet@production] profile::hive::client: add --verbose=true to default parameters

https://gerrit.wikimedia.org/r/524168

Change 524168 merged by Elukey:
[operations/puppet@production] profile::hive::client: add --verbose=true to default parameters

https://gerrit.wikimedia.org/r/524168