hive-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "ASF GitHub Bot (Jira)" <j...@apache.org>
Subject [jira] [Work logged] (HIVE-24569) LLAP daemon leaks file descriptors/log4j appenders
Date Tue, 12 Jan 2021 14:22:00 GMT

     [ https://issues.apache.org/jira/browse/HIVE-24569?focusedWorklogId=534871&page=com.atlassian.jira.plugin.system.issuetabpanels:worklog-tabpanel#worklog-534871
]

ASF GitHub Bot logged work on HIVE-24569:
-----------------------------------------

                Author: ASF GitHub Bot
            Created on: 12/Jan/21 14:21
            Start Date: 12/Jan/21 14:21
    Worklog Time Spent: 10m 
      Work Description: zabetak opened a new pull request #1858:
URL: https://github.com/apache/hive/pull/1858


   ### What changes were proposed in this pull request?
   1. Add Jupiter extension for using mock TCP servers in tests
   2. Add Jupiter extension proving LLAP daemons for unit tests
   3. Add unit test reproducing the file descriptor leak with LLAP
   4. Replace `LlapRoutingAppenderPurgePolicy` with `IdlePurgePolicy`
   
   ### Why are the changes needed?
   1. Solve the descriptor leak problem.
   2. Delegate the burden of managing appenders to the Log4j2 framework
   3. Simplify code
   4 New extensions are needed for making the unit test reproducer more readable
   
   ### Does this PR introduce _any_ user-facing change?
   No
   
   ### How was this patch tested?
   
   `mvn -pl llap-server test -Dtest=TestLlapDaemonLogging`, fails on f49bbc0dd9a270e7fc6472c43989f6e8f1590e50
   `mvn -pl llap-server test -Dtest=TestLlapDaemonLogging`, passes on 458ac1467247f2a7c8275a5ab79a339c63b37e3c
   
   Tests exclusively for the Jupiter extension:
   `mvn -pl testutils test -Dtest=TestDoNothingTCPServerExtension`


----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


Issue Time Tracking
-------------------

            Worklog Id:     (was: 534871)
    Remaining Estimate: 0h
            Time Spent: 10m

> LLAP daemon leaks file descriptors/log4j appenders
> --------------------------------------------------
>
>                 Key: HIVE-24569
>                 URL: https://issues.apache.org/jira/browse/HIVE-24569
>             Project: Hive
>          Issue Type: Bug
>          Components: llap
>    Affects Versions: 2.2.0
>            Reporter: Stamatis Zampetakis
>            Assignee: Stamatis Zampetakis
>            Priority: Major
>             Fix For: 4.0.0
>
>         Attachments: llap-appender-gc-roots.png
>
>          Time Spent: 10m
>  Remaining Estimate: 0h
>
> With HIVE-9756 query logs in LLAP are directed to different files (file per query) using
a Log4j2 routing appender. Without a purge policy in place, appenders are created dynamically
by the routing appender, one for each query, and remain in memory forever. The dynamic appenders
write to files so each appender holds to a file descriptor. 
> Further work HIVE-14224 has mitigated the issue by introducing a custom purging policy
(LlapRoutingAppenderPurgePolicy) which deletes the dynamic appenders (and closes the respective
files) when the query is completed (org.apache.hadoop.hive.llap.daemon.impl.QueryTracker#handleLogOnQueryCompletion).

> However, in the presence of multiple threads appending to the logs there are race conditions.
In an internal Hive cluster the number of file descriptors started going up approx one descriptor
leaking per query. After some debugging it turns out that one thread (running the QueryTracker#handleLogOnQueryCompletion)
signals that the query has finished and thus the purge policy should get rid of the respective
appender (and close the file) while another (Task-Executor-0) attempts to append another log
message for the same query. The initial appender is closed after the request from the query
tracker but a new one is created to accomodate the message from the task executor and the
latter is never removed thus creating a leak. 
> Similar leaks have been identified and fixed for HS2 with the most similar one being
that described [here|https://issues.apache.org/jira/browse/HIVE-22753?focusedCommentId=17021041&page=com.atlassian.jira.plugin.system.issuetabpanels%3Acomment-tabpanel#comment-17021041].

> The problem relies on the timing of threads so it may not manifestate in all versions
between 2.2.0 and 4.0.0. Usually the leak can be seen either via lsof (or other similar command)
with the following output:
> {noformat}
> # 1494391 is the PID of the LLAP daemon process
> ls -ltr /proc/1494391/fd
> ...
> lrwx------ 1 hive hadoop 64 Dec 24 12:08 978 -> /hadoop/yarn/log/application_1608659125567_0006/container_e04_1608659125567_0006_01_000002/hive_20201224121724_66ce273d-54a9-4dcd-a9fb-20cb5691cef7-dag_1608659125567_0008_194.log
> lrwx------ 1 hive hadoop 64 Dec 24 12:08 977 -> /hadoop/yarn/log/application_1608659125567_0006/container_e04_1608659125567_0006_01_000002/hive_20201224121804_ce53eeb5-c73f-4999-b7a4-b4dd04d4e4de-dag_1608659125567_0008_197.log
> lrwx------ 1 hive hadoop 64 Dec 24 12:08 974 -> /hadoop/yarn/log/application_1608659125567_0006/container_e04_1608659125567_0006_01_000002/hive_20201224122002_1693bd7d-2f0e-4673-a8d1-b7cb14a02204-dag_1608659125567_0008_204.log
> lrwx------ 1 hive hadoop 64 Dec 24 12:08 989 -> /hadoop/yarn/log/application_1608659125567_0006/container_e04_1608659125567_0006_01_000002/hive_20201224121909_6a56218f-06c7-4906-9907-4b6dd824b100-dag_1608659125567_0008_201.log
> lrwx------ 1 hive hadoop 64 Dec 24 12:08 984 -> /hadoop/yarn/log/application_1608659125567_0006/container_e04_1608659125567_0006_01_000002/hive_20201224121754_78ef49a0-bc23-478f-9a16-87fa25e7a287-dag_1608659125567_0008_196.log
> lrwx------ 1 hive hadoop 64 Dec 24 12:08 983 -> /hadoop/yarn/log/application_1608659125567_0006/container_e04_1608659125567_0006_01_000002/hive_20201224121855_e65b9ebf-b2ec-4159-9570-1904442b7048-dag_1608659125567_0008_200.log
> lrwx------ 1 hive hadoop 64 Dec 24 12:08 981 -> /hadoop/yarn/log/application_1608659125567_0006/container_e04_1608659125567_0006_01_000002/hive_20201224121818_e9051ae3-1316-46af-aabb-22c53ed2fda7-dag_1608659125567_0008_198.log
> lrwx------ 1 hive hadoop 64 Dec 24 12:08 980 -> /hadoop/yarn/log/application_1608659125567_0006/container_e04_1608659125567_0006_01_000002/hive_20201224121744_fcf37921-4351-4368-95ee-b5be2592d89a-dag_1608659125567_0008_195.log
> lrwx------ 1 hive hadoop 64 Dec 24 12:08 979 -> /hadoop/yarn/log/application_1608659125567_0006/container_e04_1608659125567_0006_01_000002/hive_20201224121837_e80c0024-f6bc-4b3c-85ed-5c0c85c55787-dag_1608659125567_0008_199.log
> {noformat}
> or in the heap dump with many appenders (in my case {{LlapWrappedAppender}}) holding
indirectly open file descriptors:
> !llap-appender-gc-roots.png! 



--
This message was sent by Atlassian Jira
(v8.3.4#803005)

Mime
View raw message