You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@hive.apache.org by "Ashutosh Bapat (Jira)" <ji...@apache.org> on 2019/11/20 06:30:00 UTC
[jira] [Commented] (HIVE-22428) Remove superfluous "Failed to get
database" WARN Logging in ObjectStore
[ https://issues.apache.org/jira/browse/HIVE-22428?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16978105#comment-16978105 ]
Ashutosh Bapat commented on HIVE-22428:
---------------------------------------
[~belugabehr], [~mgergely],
In this commit, you have modified debugLog() and pass (new Exception()) to LOG.debug() instead of earlier getStackTrace(). (new Exception()) prints the whole stack trace which can be misled as some error condition/exception. But getStackTrace() printed just a few frames rationalising the output, which was easy not to mistake for an actual exception.
I was looking at the debug output of one of my tests and had this confusion. It took me a bit of time to know that it wasn't a real exception. Here's how it looked. I thought it was NullPointer exception or something like that.
{code:java}
2019-11-19T08:13:31,392 DEBUG [PrivilegeSynchronizer] metastore.ObjectStore: Commit transaction: count = 1, isactive true
java.lang.Exception: null
at org.apache.hadoop.hive.metastore.ObjectStore.debugLog(ObjectStore.java:9671) [hive-exec-4.0.0-SNAPSHOT.jar:4.0.0-SNAPSHOT]
at org.apache.hadoop.hive.metastore.ObjectStore.commitTransaction(ObjectStore.java:475) [hive-exec-4.0.0-SNAPSHOT.jar:4.0.0-SNAPSHOT]
at org.apache.hadoop.hive.metastore.ObjectStore$GetHelper.commit(ObjectStore.java:3707) [hive-exec-4.0.0-SNAPSHOT.jar:4.0.0-SNAPSHOT]
at org.apache.hadoop.hive.metastore.ObjectStore$GetHelper.run(ObjectStore.java:3608) [hive-exec-4.0.0-SNAPSHOT.jar:4.0.0-SNAPSHOT]
at org.apache.hadoop.hive.metastore.ObjectStore.getTableAllColumnGrants(ObjectStore.java:6521) [hive-exec-4.0.0-SNAPSHOT.jar:4.0.0-SNAPSHOT]
at org.apache.hadoop.hive.metastore.ObjectStore.refreshPrivileges(ObjectStore.java:6455) [hive-exec-4.0.0-SNAPSHOT.jar:4.0.0-SNAPSHOT]
at sun.reflect.GeneratedMethodAccessor27.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_222]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_222]
at org.apache.hadoop.hive.metastore.RawStoreProxy.invoke(RawStoreProxy.java:97) [hive-exec-4.0.0-SNAPSHOT.jar:4.0.0-SNAPSHOT]
at com.sun.proxy.$Proxy40.refreshPrivileges(Unknown Source) [?:?]
at org.apache.hadoop.hive.metastore.HiveMetaStore$HMSHandler.refresh_privileges(HiveMetaStore.java:7136) [hive-exec-4.0.0-SNAPSHOT.jar:4.0.0-SNAPSHOT]
at sun.reflect.GeneratedMethodAccessor26.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_222]{code}
Is it possible to revert back to the old method or at least sanitize the output so that it doesn't look like a real exception?
> Remove superfluous "Failed to get database" WARN Logging in ObjectStore
> -----------------------------------------------------------------------
>
> Key: HIVE-22428
> URL: https://issues.apache.org/jira/browse/HIVE-22428
> Project: Hive
> Issue Type: Improvement
> Components: Standalone Metastore
> Affects Versions: 3.2.0
> Reporter: David Mollitor
> Assignee: David Mollitor
> Priority: Major
> Fix For: 4.0.0
>
> Attachments: HIVE-22428.1.patch
>
>
> In my testing, I get lots of logs like this:
> {code:none}
> Line 26319: 2019-10-28T21:09:52,134 WARN [pool-6-thread-5] metastore.ObjectStore: Failed to get database hive.compdb, returning NoSuchObjectException
> Line 26327: 2019-10-28T21:09:52,135 WARN [pool-6-thread-5] metastore.ObjectStore: Failed to get database hive.compdb, returning NoSuchObjectException
> Line 26504: 2019-10-28T21:09:52,600 WARN [pool-6-thread-5] metastore.ObjectStore: Failed to get database hive.tstatsfast, returning NoSuchObjectException
> Line 26519: 2019-10-28T21:09:52,606 WARN [pool-6-thread-5] metastore.ObjectStore: Failed to get database hive.tstatsfast, returning NoSuchObjectException
> Line 26695: 2019-10-28T21:09:52,922 WARN [pool-6-thread-5] metastore.ObjectStore: Failed to get database hive.createDb, returning NoSuchObjectException
> Line 26703: 2019-10-28T21:09:52,923 WARN [pool-6-thread-5] metastore.ObjectStore: Failed to get database hive.createDb, returning NoSuchObjectException
> Line 26763: 2019-10-28T21:09:52,936 WARN [pool-6-thread-5] metastore.ObjectStore: Failed to get database hive.compdb, returning NoSuchObjectException
> Line 26778: 2019-10-28T21:09:52,939 WARN [pool-6-thread-5] metastore.ObjectStore: Failed to get database hive.compdb, returning NoSuchObjectException
> Line 26963: 2019-10-28T21:09:53,273 WARN [pool-6-thread-5] metastore.ObjectStore: Failed to get database hive.db1, returning NoSuchObjectException
> Line 26978: 2019-10-28T21:09:53,276 WARN [pool-6-thread-5] metastore.ObjectStore: Failed to get database hive.db2, returning NoSuchObjectException
> Line 26986: 2019-10-28T21:09:53,277 WARN [pool-6-thread-5] metastore.ObjectStore: Failed to get database hive.db1, returning NoSuchObjectException
> Line 27018: 2019-10-28T21:09:53,300 WARN [pool-6-thread-5] metastore.ObjectStore: Failed to get database hive.db2, returning NoSuchObjectException
> {code}
> This is a superfluous log message. It might be pretty common for a database to not exists if, for example, a user fat-fingers the name of the database. The code also has the bad habit of log-and-throw. Just log or throw, not both.
> Since I'm looking at this class, touch up some of the other logging as well.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)