[
https://issues.apache.org/jira/browse/HIVE-24590?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17261235#comment-17261235
]
Eugene Chung edited comment on HIVE-24590 at 1/8/21, 11:29 AM:
---------------------------------------------------------------
I've been digging it for days, and have found that MDC is not cleared.
Even I call MDC.clear() at
org.apache.hive.service.cli.session.HiveSessionImpl.close(), the MDC context
set by LogUtils.registerLoggingContext() still exists at
org.apache.hadoop.hive.ql.log.HushableRandomAccessFileAppender.createAppender().
While following the codes related to slf4j MDC, it actually calls
Log4jMDCAdapter and finally accesses log4j ThreadContext. It is basically
stack-based. I don't know how log4j ThreadContext works exactly right now, but
the log4j MDC stacks at the point of HiveSessionImpl.close() and
HushableRandomAccessFileAppender.createAppender() seems to be different.
When I call log4j ThreadContext.clearAll() instead of
MDC.clear()(=ThreadContext.clearMap()),
HushableRandomAccessFileAppender.createAppender() is not called anymore at the
time of closing session.
was (Author: euigeun_chung):
I've been digging it for days, and have found that MDC is not cleared.
Even I call MDC.clear() at
org.apache.hive.service.cli.session.HiveSessionImpl.close(), the MDC context
set by LogUtils.registerLoggingContext() still exists at
org.apache.hadoop.hive.ql.log.HushableRandomAccessFileAppender.createAppender().
While following the codes related to slf4j MDC, I know that it actually calls
Log4jMDCAdapter and it finally uses log4j ThreadContext. It is basically
stack-based. I don't know how log4j ThreadContext works exactly right now, but
the log4j MDC stacks at the point of HiveSessionImpl.close() and
HushableRandomAccessFileAppender.createAppender() seems to be different.
When I call log4j ThreadContext.clearAll() instead of
MDC.clear()(=ThreadContext.clearMap()),
HushableRandomAccessFileAppender.createAppender() is not called anymore at the
time of closing session.
> Operation Logging still leaks the log4j Appenders
> -------------------------------------------------
>
> Key: HIVE-24590
> URL: https://issues.apache.org/jira/browse/HIVE-24590
> Project: Hive
> Issue Type: Bug
> Components: Logging
> Reporter: Eugene Chung
> Assignee: Stamatis Zampetakis
> Priority: Major
> Attachments: Screen Shot 2021-01-06 at 18.42.05.png, Screen Shot
> 2021-01-06 at 18.42.24.png, Screen Shot 2021-01-06 at 18.42.55.png, Screen
> Shot 2021-01-06 at 21.38.32.png, Screen Shot 2021-01-06 at 21.47.28.png,
> add_debug_log_and_trace.patch
>
>
> I'm using Hive 3.1.2 with options below.
> * hive.server2.logging.operation.enabled=true
> * hive.server2.logging.operation.level=VERBOSE
> * hive.async.log.enabled=false
> I already know the ticket, https://issues.apache.org/jira/browse/HIVE-17128
> but HS2 still leaks log4j RandomAccessFileManager.
> !Screen Shot 2021-01-06 at 18.42.05.png|width=756,height=197!
> I checked the operation log file which is not closed/deleted properly.
> !Screen Shot 2021-01-06 at 18.42.24.png|width=603,height=272!
> Then there's the log,
> {code:java}
> client.TezClient: Shutting down Tez Session, sessionName= ....{code}
> !Screen Shot 2021-01-06 at 18.42.55.png|width=1372,height=26!
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
