hive-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Sahil Takiar (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (HIVE-14090) JDOException's thrown by the Metastore have their full stack trace returned to clients
Date Fri, 24 Jun 2016 16:17:16 GMT

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

Sahil Takiar commented on HIVE-14090:
-------------------------------------

The root cause of this issue is in {{RetryingHMSHandler.invokeInternal}} method, specifically
the following lines:

{code}
if (retryCount >= retryLimit) {
    LOG.error("HMSHandler Fatal error: " + ExceptionUtils.getStackTrace(caughtException));
    // Since returning exceptions with a nested "cause" can be a problem in
    // Thrift, we are stuffing the stack trace into the message itself.
    throw new MetaException(ExceptionUtils.getStackTrace(caughtException));
}
{code}

Some context: this code is run on the Hive Metastore server (clients communicate with the
remote Hive Metastore instance via a Thrift API).

The {{caughtException}} variable is a {{JDOFatalUserException}}. So the entire stack-trace
of {{JDOFatalUserException}} gets stuffed into the message of a {{MetaException}}, which then
gets returned to the client (HiveServer2 usually), via the Hive Metastore Thrift API. This
only happens for {{JDOException}}s due to some other logic in the class, which is why it is
not a very common complaint. So when HiveServer2 sees an exception is thrown by the Metastore,
it displays the exception message to the user, which in this case contains the full stack-trace
of the exception.

Note that the comments in the code mention that the stack-trace is stuffed into the message
due to some problems with Thrift not sending the entire stack-trace back to the client. This
comment was added in https://issues.apache.org/jira/browse/HIVE-3400 - there is a Phabricator
review linked to the Hive JIRA (https://reviews.facebook.net/D4791) which contains a relevant
conversation about this choice, I copied it below:

{code}
Actually the RetryingHMSHandler is currently putting the stacktrace into the "message" of
the MetaException and not its "cause". In the Thrift generated MetaException.java, there is
no constructor taking the cause so I stuffed it into the message. Now that I think of it,
I can call initCause(jdoexception) after constructing the MetaException. Then I can make the
change you suggested. Do you want me to do that?
...
Yes, please do that. Type comparison is much better than regex matching.
...
Unfortunately, things break with that change. In direct db mode things are fine. But when
we go through Thrift, the MetaException received by Hive client from the Thrift server has
null as its cause. Even though the cause is being set properly on the Thrift side. This might
be happening because Thrift does not "know" about JDOExceptions. Or it may even be a limitation
of Thrift exception handling. Not sure. I'm satisfied with the way it was. The two key requirements
of letting the client know about the JDOException and shipping the entire stack trace back
were being met. What do you think?
...
Yeah, lets keep it this way then. If, thrift can't transport exception trace correctly. I
will suggest to leave a comment there saying why we have to do regex matching of exception
message instead of checking type of exception.
{code}

I modified the code to stop stuffing the stack-trace into the exception message, and I tested
the change locally. The change works. The full exception is still shipped to the client (HiveServer2),
who prints the full exception stack trace in its log files, and only the exception message
is displayed to the user. I was sure to run the Hive Metastore as a Thrift Server in order
to check if Thrift had any issues transporting the stack trace of the exception, and I saw
no issues.

> JDOException's thrown by the Metastore have their full stack trace returned to clients
> --------------------------------------------------------------------------------------
>
>                 Key: HIVE-14090
>                 URL: https://issues.apache.org/jira/browse/HIVE-14090
>             Project: Hive
>          Issue Type: Bug
>    Affects Versions: 1.1.0, 2.1.0
>            Reporter: Sahil Takiar
>            Assignee: Sahil Takiar
>
> When user try to create any database or table with a name longer than 128 characters:
> {code}
> create database test_longname_looooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooongNametableFAIL;
> {code}
> It dumps the full exception stack-trace in a non-user-friendly message. The lends to
relatively negative user-experience for Beeline users who hit this exception, they are generally
not interested in the full stack-trace.
> The formatted stack-trace is below:
> {code}
> Error while processing statement: FAILED: Execution Error, return code 1 from org.apache.hadoop.hive.ql.exec.DDLTask.
MetaException(message:javax.jdo.JDOFatalUserException: Attempt to store value "test_longname_looooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooongnametablefail2"
in column "`NAME`" that has maximum length of 128. Please correct your data!
> at org.datanucleus.api.jdo.NucleusJDOHelper.getJDOExceptionForNucleusException(NucleusJDOHelper.java:528)
> at org.datanucleus.api.jdo.JDOPersistenceManager.jdoMakePersistent(JDOPersistenceManager.java:732)
> at org.datanucleus.api.jdo.JDOPersistenceManager.makePersistent(JDOPersistenceManager.java:752)
> at org.apache.hadoop.hive.metastore.ObjectStore.createDatabase(ObjectStore.java:569)
> at sun.reflect.GeneratedMethodAccessor31.invoke(Unknown Source)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at org.apache.hadoop.hive.metastore.RawStoreProxy.invoke(RawStoreProxy.java:114)
> at com.sun.proxy.$Proxy10.createDatabase(Unknown Source)
> at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.create_database_core(HiveMetaStore.java:923)
> at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.create_database(HiveMetaStore.java:962)
> at sun.reflect.GeneratedMethodAccessor30.invoke(Unknown Source)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at org.apache.hadoop.hive.metastore.RetryingHMSHandler.invokeInternal(RetryingHMSHandler.java:138)
> at org.apache.hadoop.hive.metastore.RetryingHMSHandler.invoke(RetryingHMSHandler.java:99)
> at com.sun.proxy.$Proxy12.create_database(Unknown Source)
> at org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$Processor$create_database.getResult(ThriftHiveMetastore.java:8863)
> at org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$Processor$create_database.getResult(ThriftHiveMetastore.java:8847)
> at org.apache.thrift.ProcessFunction.process(ProcessFunction.java:39)
> at org.apache.thrift.TBaseProcessor.process(TBaseProcessor.java:39)
> at org.apache.hadoop.hive.thrift.HadoopThriftAuthBridge$Server$TUGIAssumingProcessor$1.run(HadoopThriftAuthBridge.java:707)
> at org.apache.hadoop.hive.thrift.HadoopThriftAuthBridge$Server$TUGIAssumingProcessor$1.run(HadoopThriftAuthBridge.java:702)
> 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:1693)
> at org.apache.hadoop.hive.thrift.HadoopThriftAuthBridge$Server$TUGIAssumingProcessor.process(HadoopThriftAuthBridge.java:702)
> at org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:286)
> 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) NestedThrowablesStackTrace: Attempt to store
value "test_longname_looooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooongnametablefail2"
in column "`NAME`" that has maximum length of 128. Please correct your data! org.datanucleus.exceptions.NucleusUserException:
Attempt to store value "test_longname_looooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooongnametablefail2"
in column "`NAME`" that has maximum length of 128. Please correct your data!
> at org.datanucleus.store.rdbms.mapping.datastore.CharRDBMSMapping.setString(CharRDBMSMapping.java:263)
> at org.datanucleus.store.rdbms.mapping.java.SingleFieldMapping.setString(SingleFieldMapping.java:201)
> at org.datanucleus.store.rdbms.fieldmanager.ParameterSetter.storeStringField(ParameterSetter.java:159)
> at org.datanucleus.state.JDOStateManager.providedStringField(JDOStateManager.java:1256)
> at org.apache.hadoop.hive.metastore.model.MDatabase.jdoProvideField(MDatabase.java)
> at org.apache.hadoop.hive.metastore.model.MDatabase.jdoProvideFields(MDatabase.java)
> at org.datanucleus.state.JDOStateManager.provideFields(JDOStateManager.java:1346)
> at org.datanucleus.store.rdbms.request.InsertRequest.execute(InsertRequest.java:289)
> at org.datanucleus.store.rdbms.RDBMSPersistenceHandler.insertTable(RDBMSPersistenceHandler.java:167)
> at org.datanucleus.store.rdbms.RDBMSPersistenceHandler.insertObject(RDBMSPersistenceHandler.java:143)
> at org.datanucleus.state.JDOStateManager.internalMakePersistent(JDOStateManager.java:3784)
> at org.datanucleus.state.JDOStateManager.makePersistent(JDOStateManager.java:3760)
> at org.datanucleus.ExecutionContextImpl.persistObjectInternal(ExecutionContextImpl.java:2219)
> at org.datanucleus.ExecutionContextImpl.persistObjectWork(ExecutionContextImpl.java:2065)
> at org.datanucleus.ExecutionContextImpl.persistObject(ExecutionContextImpl.java:1913)
> at org.datanucleus.ExecutionContextThreadedImpl.persistObject(ExecutionContextThreadedImpl.java:217)
> at org.datanucleus.api.jdo.JDOPersistenceManager.jdoMakePersistent(JDOPersistenceManager.java:727)
> at org.datanucleus.api.jdo.JDOPersistenceManager.makePersistent(JDOPersistenceManager.java:752)
> at org.apache.hadoop.hive.metastore.ObjectStore.createDatabase(ObjectStore.java:569)
> at sun.reflect.GeneratedMethodAccessor31.invoke(Unknown Source)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at org.apache.hadoop.hive.metastore.RawStoreProxy.invoke(RawStoreProxy.java:114)
> at com.sun.proxy.$Proxy10.createDatabase(Unknown Source)
> at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.create_database_core(HiveMetaStore.java:923)
> at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.create_database(HiveMetaStore.java:962)
> at sun.reflect.GeneratedMethodAccessor30.invoke(Unknown Source)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:606)
> at org.apache.hadoop.hive.metastore.RetryingHMSHandler.invokeInternal(RetryingHMSHandler.java:138)
> at org.apache.hadoop.hive.metastore.RetryingHMSHandler.invoke(RetryingHMSHandler.java:99)
> at com.sun.proxy.$Proxy12.create_database(Unknown Source)
> at org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$Processor$create_database.getResult(ThriftHiveMetastore.java:8863)
> at org.apache.hadoop.hive.metastore.api.ThriftHiveMetastore$Processor$create_database.getResult(ThriftHiveMetastore.java:8847)
> at org.apache.thrift.ProcessFunction.process(ProcessFunction.java:39)
> at org.apache.thrift.TBaseProcessor.process(TBaseProcessor.java:39)
> at org.apache.hadoop.hive.thrift.HadoopThriftAuthBridge$Server$TUGIAssumingProcessor$1.run(HadoopThriftAuthBridge.java:707)
> at org.apache.hadoop.hive.thrift.HadoopThriftAuthBridge$Server$TUGIAssumingProcessor$1.run(HadoopThriftAuthBridge.java:702)
> 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:1693)
> at org.apache.hadoop.hive.thrift.HadoopThriftAuthBridge$Server$TUGIAssumingProcessor.process(HadoopThriftAuthBridge.java:702)
> at org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:286)
> 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) )
> {code}
> The ideal situation would be to just return the following message to Beeline users:
> {code}
> Error while processing statement: FAILED: Execution Error, return code 1 from org.apache.hadoop.hive.ql.exec.DDLTask.
MetaException(message:javax.jdo.JDOFatalUserException: Attempt to store value "test_longname_looooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooonglooooooongnametablefail2"
in column "`NAME`" that has maximum length of 128. Please correct your data!)
> {code}
> And have the full stack trace should up in the HiveServer2 logs.



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

Mime
View raw message