[jira] [Commented] (HIVE-12790) Metastore connection leaks in HiveServer2
[
https://issues.apache.org/jira/browse/HIVE-12790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=16007341#comment-16007341
]
Wei Zheng commented on HIVE-12790:
--
Once you get new logs/configs from customer, please remove the outdated
attachments to avoid confusion
> Metastore connection leaks in HiveServer2
> -
>
> Key: HIVE-12790
> URL: https://issues.apache.org/jira/browse/HIVE-12790
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 1.1.0
>Reporter: Naveen Gangam
>Assignee: Naveen Gangam
> Fix For: 2.0.0
>
> Attachments: HIVE-12790.2.patch, HIVE-12790.3.patch,
> HIVE-12790.patch, snippedLog.txt
>
>
> HiveServer2 keeps opening new connections to HMS each time it launches a
> task. These connections do not appear to be closed when the task completes
> thus causing a HMS connection leak. "lsof" for the HS2 process shows
> connections to port 9083.
> {code}
> 2015-12-03 04:20:56,352 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 11 out of 41
> 2015-12-03 04:20:56,354 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14824
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
>
> 2015-12-03 04:21:06,355 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 12 out of 41
> 2015-12-03 04:21:06,357 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14825
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> 2015-12-03 04:21:08,357 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 13 out of 41
> 2015-12-03 04:21:08,360 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:08,364 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14826
> 2015-12-03 04:21:08,365 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> {code}
> The TaskRunner thread starts a new SessionState each time, which creates a
> new connection to the HMS (via Hive.get(conf).getMSC()) that is never closed.
> Even SessionState.close(), currently not being called by the TaskRunner
> thread, does not close this connection.
> Attaching a anonymized log snippet where the number of HMS connections
> reaches north of 25000+ connections.
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)
[jira] [Commented] (HIVE-12790) Metastore connection leaks in HiveServer2
[
https://issues.apache.org/jira/browse/HIVE-12790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15137498#comment-15137498
]
Sergey Shelukhin commented on HIVE-12790:
-
Assuming the current RC passes, this will not make it into 2.0 as it was
committed after the RC was cut.
> Metastore connection leaks in HiveServer2
> -
>
> Key: HIVE-12790
> URL: https://issues.apache.org/jira/browse/HIVE-12790
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 1.1.0
>Reporter: Naveen Gangam
>Assignee: Naveen Gangam
> Fix For: 1.3.0, 2.1.0
>
> Attachments: HIVE-12790.2.patch, HIVE-12790.3.patch,
> HIVE-12790.patch, snippedLog.txt
>
>
> HiveServer2 keeps opening new connections to HMS each time it launches a
> task. These connections do not appear to be closed when the task completes
> thus causing a HMS connection leak. "lsof" for the HS2 process shows
> connections to port 9083.
> {code}
> 2015-12-03 04:20:56,352 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 11 out of 41
> 2015-12-03 04:20:56,354 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14824
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
>
> 2015-12-03 04:21:06,355 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 12 out of 41
> 2015-12-03 04:21:06,357 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14825
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> 2015-12-03 04:21:08,357 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 13 out of 41
> 2015-12-03 04:21:08,360 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:08,364 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14826
> 2015-12-03 04:21:08,365 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> {code}
> The TaskRunner thread starts a new SessionState each time, which creates a
> new connection to the HMS (via Hive.get(conf).getMSC()) that is never closed.
> Even SessionState.close(), currently not being called by the TaskRunner
> thread, does not close this connection.
> Attaching a anonymized log snippet where the number of HMS connections
> reaches north of 25000+ connections.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Commented] (HIVE-12790) Metastore connection leaks in HiveServer2
[
https://issues.apache.org/jira/browse/HIVE-12790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15134217#comment-15134217
]
Naveen Gangam commented on HIVE-12790:
--
The test failures are not related to the patch. The failing qtest works fine
locally.
> Metastore connection leaks in HiveServer2
> -
>
> Key: HIVE-12790
> URL: https://issues.apache.org/jira/browse/HIVE-12790
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 1.1.0
>Reporter: Naveen Gangam
>Assignee: Naveen Gangam
> Attachments: HIVE-12790.2.patch, HIVE-12790.3.patch,
> HIVE-12790.patch, snippedLog.txt
>
>
> HiveServer2 keeps opening new connections to HMS each time it launches a
> task. These connections do not appear to be closed when the task completes
> thus causing a HMS connection leak. "lsof" for the HS2 process shows
> connections to port 9083.
> {code}
> 2015-12-03 04:20:56,352 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 11 out of 41
> 2015-12-03 04:20:56,354 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14824
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
>
> 2015-12-03 04:21:06,355 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 12 out of 41
> 2015-12-03 04:21:06,357 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14825
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> 2015-12-03 04:21:08,357 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 13 out of 41
> 2015-12-03 04:21:08,360 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:08,364 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14826
> 2015-12-03 04:21:08,365 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> {code}
> The TaskRunner thread starts a new SessionState each time, which creates a
> new connection to the HMS (via Hive.get(conf).getMSC()) that is never closed.
> Even SessionState.close(), currently not being called by the TaskRunner
> thread, does not close this connection.
> Attaching a anonymized log snippet where the number of HMS connections
> reaches north of 25000+ connections.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Commented] (HIVE-12790) Metastore connection leaks in HiveServer2
[
https://issues.apache.org/jira/browse/HIVE-12790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15134238#comment-15134238
]
Naveen Gangam commented on HIVE-12790:
--
Thanks for reviewing and pushing this thru [~aihuaxu] and [~thejas].
> Metastore connection leaks in HiveServer2
> -
>
> Key: HIVE-12790
> URL: https://issues.apache.org/jira/browse/HIVE-12790
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 1.1.0
>Reporter: Naveen Gangam
>Assignee: Naveen Gangam
> Fix For: 2.1.0
>
> Attachments: HIVE-12790.2.patch, HIVE-12790.3.patch,
> HIVE-12790.patch, snippedLog.txt
>
>
> HiveServer2 keeps opening new connections to HMS each time it launches a
> task. These connections do not appear to be closed when the task completes
> thus causing a HMS connection leak. "lsof" for the HS2 process shows
> connections to port 9083.
> {code}
> 2015-12-03 04:20:56,352 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 11 out of 41
> 2015-12-03 04:20:56,354 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14824
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
>
> 2015-12-03 04:21:06,355 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 12 out of 41
> 2015-12-03 04:21:06,357 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14825
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> 2015-12-03 04:21:08,357 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 13 out of 41
> 2015-12-03 04:21:08,360 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:08,364 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14826
> 2015-12-03 04:21:08,365 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> {code}
> The TaskRunner thread starts a new SessionState each time, which creates a
> new connection to the HMS (via Hive.get(conf).getMSC()) that is never closed.
> Even SessionState.close(), currently not being called by the TaskRunner
> thread, does not close this connection.
> Attaching a anonymized log snippet where the number of HMS connections
> reaches north of 25000+ connections.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Commented] (HIVE-12790) Metastore connection leaks in HiveServer2
[
https://issues.apache.org/jira/browse/HIVE-12790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15134240#comment-15134240
]
Aihua Xu commented on HIVE-12790:
-
Pushed to branch-1 and branch-2.0 as well.
> Metastore connection leaks in HiveServer2
> -
>
> Key: HIVE-12790
> URL: https://issues.apache.org/jira/browse/HIVE-12790
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 1.1.0
>Reporter: Naveen Gangam
>Assignee: Naveen Gangam
> Fix For: 1.3.0, 2.0.0, 2.1.0
>
> Attachments: HIVE-12790.2.patch, HIVE-12790.3.patch,
> HIVE-12790.patch, snippedLog.txt
>
>
> HiveServer2 keeps opening new connections to HMS each time it launches a
> task. These connections do not appear to be closed when the task completes
> thus causing a HMS connection leak. "lsof" for the HS2 process shows
> connections to port 9083.
> {code}
> 2015-12-03 04:20:56,352 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 11 out of 41
> 2015-12-03 04:20:56,354 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14824
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
>
> 2015-12-03 04:21:06,355 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 12 out of 41
> 2015-12-03 04:21:06,357 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14825
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> 2015-12-03 04:21:08,357 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 13 out of 41
> 2015-12-03 04:21:08,360 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:08,364 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14826
> 2015-12-03 04:21:08,365 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> {code}
> The TaskRunner thread starts a new SessionState each time, which creates a
> new connection to the HMS (via Hive.get(conf).getMSC()) that is never closed.
> Even SessionState.close(), currently not being called by the TaskRunner
> thread, does not close this connection.
> Attaching a anonymized log snippet where the number of HMS connections
> reaches north of 25000+ connections.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Commented] (HIVE-12790) Metastore connection leaks in HiveServer2
[
https://issues.apache.org/jira/browse/HIVE-12790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15133279#comment-15133279
]
Hive QA commented on HIVE-12790:
Here are the results of testing the latest attachment:
https://issues.apache.org/jira/secure/attachment/12786030/HIVE-12790.3.patch
{color:red}ERROR:{color} -1 due to no test(s) being added or modified.
{color:red}ERROR:{color} -1 due to 2 failed/errored test(s), 10051 tests
executed
*Failed tests:*
{noformat}
org.apache.hadoop.hive.cli.TestNegativeCliDriver.testNegativeCliDriver_authorization_uri_import
org.apache.hive.jdbc.TestSSL.testSSLVersion
{noformat}
Test results:
http://ec2-174-129-184-35.compute-1.amazonaws.com/jenkins/job/PreCommit-HIVE-TRUNK-Build/6865/testReport
Console output:
http://ec2-174-129-184-35.compute-1.amazonaws.com/jenkins/job/PreCommit-HIVE-TRUNK-Build/6865/console
Test logs:
http://ec2-174-129-184-35.compute-1.amazonaws.com/logs/PreCommit-HIVE-TRUNK-Build-6865/
Messages:
{noformat}
Executing org.apache.hive.ptest.execution.TestCheckPhase
Executing org.apache.hive.ptest.execution.PrepPhase
Executing org.apache.hive.ptest.execution.ExecutionPhase
Executing org.apache.hive.ptest.execution.ReportingPhase
Tests exited with: TestsFailedException: 2 tests failed
{noformat}
This message is automatically generated.
ATTACHMENT ID: 12786030 - PreCommit-HIVE-TRUNK-Build
> Metastore connection leaks in HiveServer2
> -
>
> Key: HIVE-12790
> URL: https://issues.apache.org/jira/browse/HIVE-12790
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 1.1.0
>Reporter: Naveen Gangam
>Assignee: Naveen Gangam
> Attachments: HIVE-12790.2.patch, HIVE-12790.3.patch,
> HIVE-12790.patch, snippedLog.txt
>
>
> HiveServer2 keeps opening new connections to HMS each time it launches a
> task. These connections do not appear to be closed when the task completes
> thus causing a HMS connection leak. "lsof" for the HS2 process shows
> connections to port 9083.
> {code}
> 2015-12-03 04:20:56,352 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 11 out of 41
> 2015-12-03 04:20:56,354 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14824
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
>
> 2015-12-03 04:21:06,355 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 12 out of 41
> 2015-12-03 04:21:06,357 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14825
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> 2015-12-03 04:21:08,357 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 13 out of 41
> 2015-12-03 04:21:08,360 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:08,364 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14826
> 2015-12-03 04:21:08,365 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> {code}
> The TaskRunner thread starts a new SessionState each time, which creates a
> new connection to the HMS (via Hive.get(conf).getMSC()) that is never closed.
> Even SessionState.close(), currently not being called by the TaskRunner
> thread, does not close this connection.
> Attaching a anonymized log snippet where the number of HMS connections
> reaches north of 25000+ connections.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Commented] (HIVE-12790) Metastore connection leaks in HiveServer2
[
https://issues.apache.org/jira/browse/HIVE-12790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15131442#comment-15131442
]
Thejas M Nair commented on HIVE-12790:
--
+1
> Metastore connection leaks in HiveServer2
> -
>
> Key: HIVE-12790
> URL: https://issues.apache.org/jira/browse/HIVE-12790
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 1.1.0
>Reporter: Naveen Gangam
>Assignee: Naveen Gangam
> Attachments: HIVE-12790.2.patch, HIVE-12790.3.patch,
> HIVE-12790.patch, snippedLog.txt
>
>
> HiveServer2 keeps opening new connections to HMS each time it launches a
> task. These connections do not appear to be closed when the task completes
> thus causing a HMS connection leak. "lsof" for the HS2 process shows
> connections to port 9083.
> {code}
> 2015-12-03 04:20:56,352 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 11 out of 41
> 2015-12-03 04:20:56,354 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14824
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
>
> 2015-12-03 04:21:06,355 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 12 out of 41
> 2015-12-03 04:21:06,357 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14825
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> 2015-12-03 04:21:08,357 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 13 out of 41
> 2015-12-03 04:21:08,360 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:08,364 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14826
> 2015-12-03 04:21:08,365 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> {code}
> The TaskRunner thread starts a new SessionState each time, which creates a
> new connection to the HMS (via Hive.get(conf).getMSC()) that is never closed.
> Even SessionState.close(), currently not being called by the TaskRunner
> thread, does not close this connection.
> Attaching a anonymized log snippet where the number of HMS connections
> reaches north of 25000+ connections.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Commented] (HIVE-12790) Metastore connection leaks in HiveServer2
[
https://issues.apache.org/jira/browse/HIVE-12790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15128959#comment-15128959
]
Thejas M Nair commented on HIVE-12790:
--
[~ngangam] Thanks for checking with me. Added some comments in review board.
I don't think the SessionState.close calling Hive.close is necessary to deal
with the issue of connection leak when hive.exec.parallel=true. However, it can
help with case when the thread pool in HS2 expands and contracts, at least in
case of binary transport mode, where a thread is associated with a
session/connection.
> Metastore connection leaks in HiveServer2
> -
>
> Key: HIVE-12790
> URL: https://issues.apache.org/jira/browse/HIVE-12790
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 1.1.0
>Reporter: Naveen Gangam
>Assignee: Naveen Gangam
> Attachments: HIVE-12790.2.patch, HIVE-12790.patch, snippedLog.txt
>
>
> HiveServer2 keeps opening new connections to HMS each time it launches a
> task. These connections do not appear to be closed when the task completes
> thus causing a HMS connection leak. "lsof" for the HS2 process shows
> connections to port 9083.
> {code}
> 2015-12-03 04:20:56,352 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 11 out of 41
> 2015-12-03 04:20:56,354 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14824
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
>
> 2015-12-03 04:21:06,355 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 12 out of 41
> 2015-12-03 04:21:06,357 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14825
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> 2015-12-03 04:21:08,357 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 13 out of 41
> 2015-12-03 04:21:08,360 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:08,364 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14826
> 2015-12-03 04:21:08,365 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> {code}
> The TaskRunner thread starts a new SessionState each time, which creates a
> new connection to the HMS (via Hive.get(conf).getMSC()) that is never closed.
> Even SessionState.close(), currently not being called by the TaskRunner
> thread, does not close this connection.
> Attaching a anonymized log snippet where the number of HMS connections
> reaches north of 25000+ connections.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Commented] (HIVE-12790) Metastore connection leaks in HiveServer2
[
https://issues.apache.org/jira/browse/HIVE-12790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15129244#comment-15129244
]
Naveen Gangam commented on HIVE-12790:
--
[~thejas] Agreed, the fix in SS.close() was not specifically for this issue. It
was meant as a general cleanup fix.
> Metastore connection leaks in HiveServer2
> -
>
> Key: HIVE-12790
> URL: https://issues.apache.org/jira/browse/HIVE-12790
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 1.1.0
>Reporter: Naveen Gangam
>Assignee: Naveen Gangam
> Attachments: HIVE-12790.2.patch, HIVE-12790.patch, snippedLog.txt
>
>
> HiveServer2 keeps opening new connections to HMS each time it launches a
> task. These connections do not appear to be closed when the task completes
> thus causing a HMS connection leak. "lsof" for the HS2 process shows
> connections to port 9083.
> {code}
> 2015-12-03 04:20:56,352 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 11 out of 41
> 2015-12-03 04:20:56,354 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14824
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
>
> 2015-12-03 04:21:06,355 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 12 out of 41
> 2015-12-03 04:21:06,357 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14825
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> 2015-12-03 04:21:08,357 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 13 out of 41
> 2015-12-03 04:21:08,360 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:08,364 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14826
> 2015-12-03 04:21:08,365 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> {code}
> The TaskRunner thread starts a new SessionState each time, which creates a
> new connection to the HMS (via Hive.get(conf).getMSC()) that is never closed.
> Even SessionState.close(), currently not being called by the TaskRunner
> thread, does not close this connection.
> Attaching a anonymized log snippet where the number of HMS connections
> reaches north of 25000+ connections.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Commented] (HIVE-12790) Metastore connection leaks in HiveServer2
[
https://issues.apache.org/jira/browse/HIVE-12790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15128417#comment-15128417
]
Naveen Gangam commented on HIVE-12790:
--
[~thejas] Could you please review the fix when you have a moment? Thank you in
advance.
> Metastore connection leaks in HiveServer2
> -
>
> Key: HIVE-12790
> URL: https://issues.apache.org/jira/browse/HIVE-12790
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 1.1.0
>Reporter: Naveen Gangam
>Assignee: Naveen Gangam
> Attachments: HIVE-12790.2.patch, HIVE-12790.patch, snippedLog.txt
>
>
> HiveServer2 keeps opening new connections to HMS each time it launches a
> task. These connections do not appear to be closed when the task completes
> thus causing a HMS connection leak. "lsof" for the HS2 process shows
> connections to port 9083.
> {code}
> 2015-12-03 04:20:56,352 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 11 out of 41
> 2015-12-03 04:20:56,354 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14824
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
>
> 2015-12-03 04:21:06,355 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 12 out of 41
> 2015-12-03 04:21:06,357 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14825
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> 2015-12-03 04:21:08,357 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 13 out of 41
> 2015-12-03 04:21:08,360 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:08,364 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14826
> 2015-12-03 04:21:08,365 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> {code}
> The TaskRunner thread starts a new SessionState each time, which creates a
> new connection to the HMS (via Hive.get(conf).getMSC()) that is never closed.
> Even SessionState.close(), currently not being called by the TaskRunner
> thread, does not close this connection.
> Attaching a anonymized log snippet where the number of HMS connections
> reaches north of 25000+ connections.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Commented] (HIVE-12790) Metastore connection leaks in HiveServer2
[
https://issues.apache.org/jira/browse/HIVE-12790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15125197#comment-15125197
]
Hive QA commented on HIVE-12790:
Here are the results of testing the latest attachment:
https://issues.apache.org/jira/secure/attachment/12785008/HIVE-12790.2.patch
{color:red}ERROR:{color} -1 due to no test(s) being added or modified.
{color:red}ERROR:{color} -1 due to 6 failed/errored test(s), 10047 tests
executed
*Failed tests:*
{noformat}
org.apache.hadoop.hive.cli.TestMiniTezCliDriver.org.apache.hadoop.hive.cli.TestMiniTezCliDriver
org.apache.hadoop.hive.cli.TestMiniTezCliDriver.testCliDriver_insert_into1
org.apache.hadoop.hive.cli.TestMiniTezCliDriver.testCliDriver_vector_aggregate_without_gby
org.apache.hadoop.hive.cli.TestNegativeCliDriver.testNegativeCliDriver_authorization_uri_import
org.apache.hive.jdbc.TestSSL.testSSLVersion
org.apache.hive.service.cli.TestEmbeddedThriftBinaryCLIService.testExecuteStatementAsync
{noformat}
Test results:
http://ec2-174-129-184-35.compute-1.amazonaws.com/jenkins/job/PreCommit-HIVE-TRUNK-Build/6805/testReport
Console output:
http://ec2-174-129-184-35.compute-1.amazonaws.com/jenkins/job/PreCommit-HIVE-TRUNK-Build/6805/console
Test logs:
http://ec2-174-129-184-35.compute-1.amazonaws.com/logs/PreCommit-HIVE-TRUNK-Build-6805/
Messages:
{noformat}
Executing org.apache.hive.ptest.execution.TestCheckPhase
Executing org.apache.hive.ptest.execution.PrepPhase
Executing org.apache.hive.ptest.execution.ExecutionPhase
Executing org.apache.hive.ptest.execution.ReportingPhase
Tests exited with: TestsFailedException: 6 tests failed
{noformat}
This message is automatically generated.
ATTACHMENT ID: 12785008 - PreCommit-HIVE-TRUNK-Build
> Metastore connection leaks in HiveServer2
> -
>
> Key: HIVE-12790
> URL: https://issues.apache.org/jira/browse/HIVE-12790
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 1.1.0
>Reporter: Naveen Gangam
>Assignee: Naveen Gangam
> Attachments: HIVE-12790.2.patch, HIVE-12790.patch, snippedLog.txt
>
>
> HiveServer2 keeps opening new connections to HMS each time it launches a
> task. These connections do not appear to be closed when the task completes
> thus causing a HMS connection leak. "lsof" for the HS2 process shows
> connections to port 9083.
> {code}
> 2015-12-03 04:20:56,352 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 11 out of 41
> 2015-12-03 04:20:56,354 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14824
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
>
> 2015-12-03 04:21:06,355 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 12 out of 41
> 2015-12-03 04:21:06,357 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14825
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> 2015-12-03 04:21:08,357 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 13 out of 41
> 2015-12-03 04:21:08,360 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:08,364 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14826
> 2015-12-03 04:21:08,365 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> {code}
> The TaskRunner thread starts a new SessionState each time, which creates a
> new connection to the HMS (via Hive.get(conf).getMSC()) that is never closed.
> Even SessionState.close(), currently not being called by the TaskRunner
> thread, does not close this connection.
> Attaching a anonymized log snippet where the number of HMS connections
> reaches north of 25000+ connections.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Commented] (HIVE-12790) Metastore connection leaks in HiveServer2
[
https://issues.apache.org/jira/browse/HIVE-12790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15123659#comment-15123659
]
Aihua Xu commented on HIVE-12790:
-
[~ngangam] I had a minor issue regarding the comment in text. Otherwise, looks
good to me. +1
[~thejas] Can you also take a look? Thanks.
> Metastore connection leaks in HiveServer2
> -
>
> Key: HIVE-12790
> URL: https://issues.apache.org/jira/browse/HIVE-12790
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 1.1.0
>Reporter: Naveen Gangam
>Assignee: Naveen Gangam
> Attachments: HIVE-12790.2.patch, HIVE-12790.patch, snippedLog.txt
>
>
> HiveServer2 keeps opening new connections to HMS each time it launches a
> task. These connections do not appear to be closed when the task completes
> thus causing a HMS connection leak. "lsof" for the HS2 process shows
> connections to port 9083.
> {code}
> 2015-12-03 04:20:56,352 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 11 out of 41
> 2015-12-03 04:20:56,354 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14824
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
>
> 2015-12-03 04:21:06,355 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 12 out of 41
> 2015-12-03 04:21:06,357 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14825
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> 2015-12-03 04:21:08,357 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 13 out of 41
> 2015-12-03 04:21:08,360 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:08,364 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14826
> 2015-12-03 04:21:08,365 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> {code}
> The TaskRunner thread starts a new SessionState each time, which creates a
> new connection to the HMS (via Hive.get(conf).getMSC()) that is never closed.
> Even SessionState.close(), currently not being called by the TaskRunner
> thread, does not close this connection.
> Attaching a anonymized log snippet where the number of HMS connections
> reaches north of 25000+ connections.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Commented] (HIVE-12790) Metastore connection leaks in HiveServer2
[
https://issues.apache.org/jira/browse/HIVE-12790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15088083#comment-15088083
]
Thejas M Nair commented on HIVE-12790:
--
bq. The proposed fix calls SessionState.close() from its run() method, so it
should only close it when executing in a new thread.
SeesionState is needed beyond the lifetime of the current query execution, as
it represents a session.
bq. But shouldn't the thread local variables be cleaned up when a session is
closed?
We don't maintain a session to threads/threadlocal mapping. It should ideally
be closed when the thread is being released.
Also, Hive.get() is called from many places outside of SessionState as well.
You can call Hive.closeCurrent() in the place where you added the call to
ss.close to fix this.
> Metastore connection leaks in HiveServer2
> -
>
> Key: HIVE-12790
> URL: https://issues.apache.org/jira/browse/HIVE-12790
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 1.1.0
>Reporter: Naveen Gangam
>Assignee: Naveen Gangam
> Attachments: HIVE-12790.patch, snippedLog.txt
>
>
> HiveServer2 keeps opening new connections to HMS each time it launches a
> task. These connections do not appear to be closed when the task completes
> thus causing a HMS connection leak. "lsof" for the HS2 process shows
> connections to port 9083.
> {code}
> 2015-12-03 04:20:56,352 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 11 out of 41
> 2015-12-03 04:20:56,354 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14824
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
>
> 2015-12-03 04:21:06,355 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 12 out of 41
> 2015-12-03 04:21:06,357 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14825
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> 2015-12-03 04:21:08,357 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 13 out of 41
> 2015-12-03 04:21:08,360 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:08,364 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14826
> 2015-12-03 04:21:08,365 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> {code}
> The TaskRunner thread starts a new SessionState each time, which creates a
> new connection to the HMS (via Hive.get(conf).getMSC()) that is never closed.
> Even SessionState.close(), currently not being called by the TaskRunner
> thread, does not close this connection.
> Attaching a anonymized log snippet where the number of HMS connections
> reaches north of 25000+ connections.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Commented] (HIVE-12790) Metastore connection leaks in HiveServer2
[
https://issues.apache.org/jira/browse/HIVE-12790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15088185#comment-15088185
]
Naveen Gangam commented on HIVE-12790:
--
Review was posted to RB yesterday at https://reviews.apache.org/r/41990/
It currently has the patch from yesterday. I will refresh it when I have a new
version.
> Metastore connection leaks in HiveServer2
> -
>
> Key: HIVE-12790
> URL: https://issues.apache.org/jira/browse/HIVE-12790
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 1.1.0
>Reporter: Naveen Gangam
>Assignee: Naveen Gangam
> Attachments: HIVE-12790.patch, snippedLog.txt
>
>
> HiveServer2 keeps opening new connections to HMS each time it launches a
> task. These connections do not appear to be closed when the task completes
> thus causing a HMS connection leak. "lsof" for the HS2 process shows
> connections to port 9083.
> {code}
> 2015-12-03 04:20:56,352 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 11 out of 41
> 2015-12-03 04:20:56,354 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14824
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
>
> 2015-12-03 04:21:06,355 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 12 out of 41
> 2015-12-03 04:21:06,357 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14825
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> 2015-12-03 04:21:08,357 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 13 out of 41
> 2015-12-03 04:21:08,360 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:08,364 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14826
> 2015-12-03 04:21:08,365 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> {code}
> The TaskRunner thread starts a new SessionState each time, which creates a
> new connection to the HMS (via Hive.get(conf).getMSC()) that is never closed.
> Even SessionState.close(), currently not being called by the TaskRunner
> thread, does not close this connection.
> Attaching a anonymized log snippet where the number of HMS connections
> reaches north of 25000+ connections.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Commented] (HIVE-12790) Metastore connection leaks in HiveServer2
[
https://issues.apache.org/jira/browse/HIVE-12790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15088169#comment-15088169
]
Naveen Gangam commented on HIVE-12790:
--
[~thejas] [~aihuaxu] and I just discussed exactly what you just mentioned. I
think we agree that SessionState.close() should not be called as it is shared
across threads within a session. I will take another look to confirm that Hive
instance is not being shared across threads as well before I upload another
patch.
Appreciate your input on this. Thanks much.
> Metastore connection leaks in HiveServer2
> -
>
> Key: HIVE-12790
> URL: https://issues.apache.org/jira/browse/HIVE-12790
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 1.1.0
>Reporter: Naveen Gangam
>Assignee: Naveen Gangam
> Attachments: HIVE-12790.patch, snippedLog.txt
>
>
> HiveServer2 keeps opening new connections to HMS each time it launches a
> task. These connections do not appear to be closed when the task completes
> thus causing a HMS connection leak. "lsof" for the HS2 process shows
> connections to port 9083.
> {code}
> 2015-12-03 04:20:56,352 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 11 out of 41
> 2015-12-03 04:20:56,354 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14824
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
>
> 2015-12-03 04:21:06,355 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 12 out of 41
> 2015-12-03 04:21:06,357 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14825
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> 2015-12-03 04:21:08,357 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 13 out of 41
> 2015-12-03 04:21:08,360 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:08,364 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14826
> 2015-12-03 04:21:08,365 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> {code}
> The TaskRunner thread starts a new SessionState each time, which creates a
> new connection to the HMS (via Hive.get(conf).getMSC()) that is never closed.
> Even SessionState.close(), currently not being called by the TaskRunner
> thread, does not close this connection.
> Attaching a anonymized log snippet where the number of HMS connections
> reaches north of 25000+ connections.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Commented] (HIVE-12790) Metastore connection leaks in HiveServer2
[
https://issues.apache.org/jira/browse/HIVE-12790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15086001#comment-15086001
]
Thejas M Nair commented on HIVE-12790:
--
TaskRunner should not be creating a new SessionState object. The SessionState
object is expected to be used for the entire hive session. The right fix would
be to not create additional SessionState in TaskRunner (assuming thats
happening).
> Metastore connection leaks in HiveServer2
> -
>
> Key: HIVE-12790
> URL: https://issues.apache.org/jira/browse/HIVE-12790
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 1.1.0
>Reporter: Naveen Gangam
>Assignee: Naveen Gangam
> Attachments: HIVE-12790.patch, snippedLog.txt
>
>
> HiveServer2 keeps opening new connections to HMS each time it launches a
> task. These connections do not appear to be closed when the task completes
> thus causing a HMS connection leak. "lsof" for the HS2 process shows
> connections to port 9083.
> {code}
> 2015-12-03 04:20:56,352 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 11 out of 41
> 2015-12-03 04:20:56,354 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14824
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
>
> 2015-12-03 04:21:06,355 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 12 out of 41
> 2015-12-03 04:21:06,357 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14825
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> 2015-12-03 04:21:08,357 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 13 out of 41
> 2015-12-03 04:21:08,360 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:08,364 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14826
> 2015-12-03 04:21:08,365 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> {code}
> The TaskRunner thread starts a new SessionState each time, which creates a
> new connection to the HMS (via Hive.get(conf).getMSC()) that is never closed.
> Even SessionState.close(), currently not being called by the TaskRunner
> thread, does not close this connection.
> Attaching a anonymized log snippet where the number of HMS connections
> reaches north of 25000+ connections.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Commented] (HIVE-12790) Metastore connection leaks in HiveServer2
[
https://issues.apache.org/jira/browse/HIVE-12790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15086014#comment-15086014
]
Thejas M Nair commented on HIVE-12790:
--
Also, there is no association of Hive object to SessionState right now. Doing a
close within SessionState.close does not seem right.
Are you sure that the TaskRunner actually creates a new SessionState ?
Is this something that happens only when hive.exec.parallel=true ?
> Metastore connection leaks in HiveServer2
> -
>
> Key: HIVE-12790
> URL: https://issues.apache.org/jira/browse/HIVE-12790
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 1.1.0
>Reporter: Naveen Gangam
>Assignee: Naveen Gangam
> Attachments: HIVE-12790.patch, snippedLog.txt
>
>
> HiveServer2 keeps opening new connections to HMS each time it launches a
> task. These connections do not appear to be closed when the task completes
> thus causing a HMS connection leak. "lsof" for the HS2 process shows
> connections to port 9083.
> {code}
> 2015-12-03 04:20:56,352 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 11 out of 41
> 2015-12-03 04:20:56,354 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14824
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
>
> 2015-12-03 04:21:06,355 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 12 out of 41
> 2015-12-03 04:21:06,357 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14825
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> 2015-12-03 04:21:08,357 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 13 out of 41
> 2015-12-03 04:21:08,360 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:08,364 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14826
> 2015-12-03 04:21:08,365 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> {code}
> The TaskRunner thread starts a new SessionState each time, which creates a
> new connection to the HMS (via Hive.get(conf).getMSC()) that is never closed.
> Even SessionState.close(), currently not being called by the TaskRunner
> thread, does not close this connection.
> Attaching a anonymized log snippet where the number of HMS connections
> reaches north of 25000+ connections.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Commented] (HIVE-12790) Metastore connection leaks in HiveServer2
[
https://issues.apache.org/jira/browse/HIVE-12790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15086232#comment-15086232
]
Naveen Gangam commented on HIVE-12790:
--
[~thejas] These logs are based on Hive 0.13 and I just realized the Hive object
and SessionState are no longer associated in the latest release. Regardless,
given that a new connection to the HMS is established every time right after
the log message "Launching Job" is printed, it points to the the following code
in Driver.launchTask()
{code}
console.printInfo("Launching Job " + cxt.getCurJobNo() + " out of " +
jobs);
}
tsk.initialize(conf, plan, cxt);
TaskResult tskRes = new TaskResult();
TaskRunner tskRun = new TaskRunner(tsk, tskRes);
{code}
The last line above launches a new thread and the first message from that new
thread is
{code}
2015-12-03 04:21:08,360 INFO [Thread-405782()]: hive.metastore
(HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with URI
thrift://:9083
{code}
So it appeared that the following codepath was creating new HMS connections
TaskRunner.run()-->SessionState.start()-->Hive.get().getMSC()
Hive.get() should return a shared instance but for some reason, is it possible
that it is closing the current and returning a new instance?
> Metastore connection leaks in HiveServer2
> -
>
> Key: HIVE-12790
> URL: https://issues.apache.org/jira/browse/HIVE-12790
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 1.1.0
>Reporter: Naveen Gangam
>Assignee: Naveen Gangam
> Attachments: HIVE-12790.patch, snippedLog.txt
>
>
> HiveServer2 keeps opening new connections to HMS each time it launches a
> task. These connections do not appear to be closed when the task completes
> thus causing a HMS connection leak. "lsof" for the HS2 process shows
> connections to port 9083.
> {code}
> 2015-12-03 04:20:56,352 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 11 out of 41
> 2015-12-03 04:20:56,354 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14824
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
>
> 2015-12-03 04:21:06,355 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 12 out of 41
> 2015-12-03 04:21:06,357 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14825
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> 2015-12-03 04:21:08,357 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 13 out of 41
> 2015-12-03 04:21:08,360 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:08,364 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14826
> 2015-12-03 04:21:08,365 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> {code}
> The TaskRunner thread starts a new SessionState each time, which creates a
> new connection to the HMS (via Hive.get(conf).getMSC()) that is never closed.
> Even SessionState.close(), currently not being called by the TaskRunner
> thread, does not close this connection.
> Attaching a anonymized log snippet where the number of HMS connections
> reaches north of 25000+ connections.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Commented] (HIVE-12790) Metastore connection leaks in HiveServer2
[
https://issues.apache.org/jira/browse/HIVE-12790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15086265#comment-15086265
]
Thejas M Nair commented on HIVE-12790:
--
bq. The last line above launches a new thread and the first message from that
new thread is
That is not what i expect. I expect new thread to be launched later at -
tskRun.start(); (that gets called when hive.exec.parallel=true).
bq. Hive.get() should return a shared instance
That returns a thread local instance if it already exists. In this case this is
a new thread, so new instances gets created.
You can close that one if a separate thread was used for task execution
> Metastore connection leaks in HiveServer2
> -
>
> Key: HIVE-12790
> URL: https://issues.apache.org/jira/browse/HIVE-12790
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 1.1.0
>Reporter: Naveen Gangam
>Assignee: Naveen Gangam
> Attachments: HIVE-12790.patch, snippedLog.txt
>
>
> HiveServer2 keeps opening new connections to HMS each time it launches a
> task. These connections do not appear to be closed when the task completes
> thus causing a HMS connection leak. "lsof" for the HS2 process shows
> connections to port 9083.
> {code}
> 2015-12-03 04:20:56,352 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 11 out of 41
> 2015-12-03 04:20:56,354 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14824
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
>
> 2015-12-03 04:21:06,355 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 12 out of 41
> 2015-12-03 04:21:06,357 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14825
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> 2015-12-03 04:21:08,357 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 13 out of 41
> 2015-12-03 04:21:08,360 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:08,364 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14826
> 2015-12-03 04:21:08,365 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> {code}
> The TaskRunner thread starts a new SessionState each time, which creates a
> new connection to the HMS (via Hive.get(conf).getMSC()) that is never closed.
> Even SessionState.close(), currently not being called by the TaskRunner
> thread, does not close this connection.
> Attaching a anonymized log snippet where the number of HMS connections
> reaches north of 25000+ connections.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Commented] (HIVE-12790) Metastore connection leaks in HiveServer2
[
https://issues.apache.org/jira/browse/HIVE-12790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15086269#comment-15086269
]
Naveen Gangam commented on HIVE-12790:
--
Just to add a bit more context, the logs are from an environment where HS2 is
running Talend generated hive queries via JDBC. I dont know much about Talend
other than treating it as a JDBC app connecting to HS2. I would imagine it is
capable of launching parallel jobs (I have seen tasks from different queries
get launched one after the other in a different log file).
So Beeline is not in the picture.
> Metastore connection leaks in HiveServer2
> -
>
> Key: HIVE-12790
> URL: https://issues.apache.org/jira/browse/HIVE-12790
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 1.1.0
>Reporter: Naveen Gangam
>Assignee: Naveen Gangam
> Attachments: HIVE-12790.patch, snippedLog.txt
>
>
> HiveServer2 keeps opening new connections to HMS each time it launches a
> task. These connections do not appear to be closed when the task completes
> thus causing a HMS connection leak. "lsof" for the HS2 process shows
> connections to port 9083.
> {code}
> 2015-12-03 04:20:56,352 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 11 out of 41
> 2015-12-03 04:20:56,354 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14824
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
>
> 2015-12-03 04:21:06,355 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 12 out of 41
> 2015-12-03 04:21:06,357 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14825
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> 2015-12-03 04:21:08,357 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 13 out of 41
> 2015-12-03 04:21:08,360 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:08,364 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14826
> 2015-12-03 04:21:08,365 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> {code}
> The TaskRunner thread starts a new SessionState each time, which creates a
> new connection to the HMS (via Hive.get(conf).getMSC()) that is never closed.
> Even SessionState.close(), currently not being called by the TaskRunner
> thread, does not close this connection.
> Attaching a anonymized log snippet where the number of HMS connections
> reaches north of 25000+ connections.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
[jira] [Commented] (HIVE-12790) Metastore connection leaks in HiveServer2
[
https://issues.apache.org/jira/browse/HIVE-12790?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15086324#comment-15086324
]
Naveen Gangam commented on HIVE-12790:
--
Yes, you are right. I meant whenever start() is called on that thread because
no other log messages appears to be logged between these 2 events.
The proposed fix calls SessionState.close() from its run() method, so it should
only close it when executing in a new thread.
Since Hive and SessionState are no longer associated, I can move the
Hive.closeCurrent() cleanup to the TaskRunner itself, right before the
SS.close(). But shouldnt the thread local variables be cleaned up when a
session is closed? (we still do Hive.get() in SessionState).
Thoughts? Thank you in advance.
> Metastore connection leaks in HiveServer2
> -
>
> Key: HIVE-12790
> URL: https://issues.apache.org/jira/browse/HIVE-12790
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
>Affects Versions: 1.1.0
>Reporter: Naveen Gangam
>Assignee: Naveen Gangam
> Attachments: HIVE-12790.patch, snippedLog.txt
>
>
> HiveServer2 keeps opening new connections to HMS each time it launches a
> task. These connections do not appear to be closed when the task completes
> thus causing a HMS connection leak. "lsof" for the HS2 process shows
> connections to port 9083.
> {code}
> 2015-12-03 04:20:56,352 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 11 out of 41
> 2015-12-03 04:20:56,354 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14824
> 2015-12-03 04:20:56,360 INFO [Thread-405728()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
>
> 2015-12-03 04:21:06,355 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 12 out of 41
> 2015-12-03 04:21:06,357 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14825
> 2015-12-03 04:21:06,362 INFO [Thread-405756()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> 2015-12-03 04:21:08,357 INFO [HiveServer2-Background-Pool: Thread-424756()]:
> ql.Driver (SessionState.java:printInfo(558)) - Launching Job 13 out of 41
> 2015-12-03 04:21:08,360 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(311)) - Trying to connect to metastore with
> URI thrift://:9083
> 2015-12-03 04:21:08,364 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(351)) - Opened a connection to metastore,
> current connections: 14826
> 2015-12-03 04:21:08,365 INFO [Thread-405782()]: hive.metastore
> (HiveMetaStoreClient.java:open(400)) - Connected to metastore.
> ...
> {code}
> The TaskRunner thread starts a new SessionState each time, which creates a
> new connection to the HMS (via Hive.get(conf).getMSC()) that is never closed.
> Even SessionState.close(), currently not being called by the TaskRunner
> thread, does not close this connection.
> Attaching a anonymized log snippet where the number of HMS connections
> reaches north of 25000+ connections.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
