[
https://issues.apache.org/jira/browse/HIVE-14296?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15388046#comment-15388046
]
Naveen Gangam commented on HIVE-14296:
--------------------------------------
[~mohitsabharwal] Using the getOpenSessionCount() to record the open sessions
is very timing-sensitive and causes non-linear/inconsistent results. There are
different actions been perfomed between when this message gets logged and the
session handle is removed from the map. For example, (when this message is
printed before the closeSession() is called) I have a single beeline instance
that creates 5 sessions and killing this instance produces the following.
{code}
2016-07-21T11:20:46,976 INFO [HiveServer2-Handler-Pool: Thread-40]
thrift.ThriftCLIService: Session disconnected without closing properly.
2016-07-21T11:20:46,976 INFO [HiveServer2-Handler-Pool: Thread-60]
thrift.ThriftCLIService: Session disconnected without closing properly.
2016-07-21T11:20:46,976 INFO [HiveServer2-Handler-Pool: Thread-55]
thrift.ThriftCLIService: Session disconnected without closing properly.
2016-07-21T11:20:46,976 INFO [HiveServer2-Handler-Pool: Thread-45]
thrift.ThriftCLIService: Session disconnected without closing properly.
2016-07-21T11:20:46,976 INFO [HiveServer2-Handler-Pool: Thread-50]
thrift.ThriftCLIService: Session disconnected without closing properly.
2016-07-21T11:20:46,977 INFO [HiveServer2-Handler-Pool: Thread-55]
thrift.ThriftCLIService: Session closed: SessionHandle
[a83ef567-c283-4630-8608-fa2ce122f105], current sessions:5
2016-07-21T11:20:46,977 INFO [HiveServer2-Handler-Pool: Thread-50]
thrift.ThriftCLIService: Session closed: SessionHandle
[5732986a-5a39-48e7-8ff0-a0144ba3f1e5], current sessions:5
2016-07-21T11:20:46,977 INFO [HiveServer2-Handler-Pool: Thread-60]
thrift.ThriftCLIService: Session closed: SessionHandle
[10de27d4-eb46-40b5-b960-8a5bb42406b1], current sessions:5
2016-07-21T11:20:46,977 INFO [HiveServer2-Handler-Pool: Thread-45]
thrift.ThriftCLIService: Session closed: SessionHandle
[3c5b1f31-20e5-4587-8501-c0291b230ff6], current sessions:5
2016-07-21T11:20:46,977 INFO [HiveServer2-Handler-Pool: Thread-40]
thrift.ThriftCLIService: Session closed: SessionHandle
[60a10fc0-1882-49a7-b046-eff2fd66c88b], current sessions:3
{code}
I have seen other variations of this output. The output swings to the other
extreme when I have the log statement after the closeSession() call. The count
is near zero most times.
The end result should be accurate though. If I create another session at the
end, it will log the correct number of sessions. Thoughts?
> Session count is not decremented when HS2 clients do not shutdown cleanly.
> --------------------------------------------------------------------------
>
> Key: HIVE-14296
> URL: https://issues.apache.org/jira/browse/HIVE-14296
> Project: Hive
> Issue Type: Bug
> Components: HiveServer2
> Affects Versions: 2.0.0
> Reporter: Naveen Gangam
> Assignee: Naveen Gangam
> Attachments: HIVE-14296.patch
>
>
> When a JDBC client like beeline abruptly disconnects from HS2, the session
> gets closed on the serverside but the session count reported in the logs is
> incorrect. It never gets decremented.
> For example, I created 6 connections from the same instance of beeline to HS2.
> {code}
> 2016-07-20T15:05:17,987 INFO [HiveServer2-Handler-Pool: Thread-40]
> thrift.ThriftCLIService: Opened a session SessionHandle
> [28b225ee-204f-4b3e-b4fd-0039ef8e276e], current sessions: 1
> .....
> 2016-07-20T15:05:24,239 INFO [HiveServer2-Handler-Pool: Thread-45]
> thrift.ThriftCLIService: Opened a session SessionHandle
> [1d267de8-ff9a-4e76-ac5c-e82c871588e7], current sessions: 2
> .....
> 2016-07-20T15:05:25,710 INFO [HiveServer2-Handler-Pool: Thread-50]
> thrift.ThriftCLIService: Opened a session SessionHandle
> [04d53deb-8965-464b-aa3f-7042304cfb54], current sessions: 3
> .....
> 2016-07-20T15:05:26,795 INFO [HiveServer2-Handler-Pool: Thread-55]
> thrift.ThriftCLIService: Opened a session SessionHandle
> [b4bb8b86-74e1-4e3c-babb-674d34ad1caf], current sessions: 4
> 2016-07-20T15:05:28,160 INFO [HiveServer2-Handler-Pool: Thread-60]
> thrift.ThriftCLIService: Opened a session SessionHandle
> [6d3c3ed9-fadb-4673-8c15-3315b7e2995d], current sessions: 5
> .....
> 2016-07-20T15:05:29,136 INFO [HiveServer2-Handler-Pool: Thread-65]
> thrift.ThriftCLIService: Opened a session SessionHandle
> [88b630c0-f272-427d-8263-febfe2222f8d], current sessions: 6
> {code}
> When I CNTRL-C the beeline process, in the HS2 logs I see
> {code}
> 2016-07-20T15:11:37,858 INFO [HiveServer2-Handler-Pool: Thread-55]
> thrift.ThriftCLIService: Session disconnected without closing properly.
> 2016-07-20T15:11:37,858 INFO [HiveServer2-Handler-Pool: Thread-40]
> thrift.ThriftCLIService: Session disconnected without closing properly.
> 2016-07-20T15:11:37,858 INFO [HiveServer2-Handler-Pool: Thread-65]
> thrift.ThriftCLIService: Session disconnected without closing properly.
> 2016-07-20T15:11:37,858 INFO [HiveServer2-Handler-Pool: Thread-60]
> thrift.ThriftCLIService: Session disconnected without closing properly.
> 2016-07-20T15:11:37,859 INFO [HiveServer2-Handler-Pool: Thread-50]
> thrift.ThriftCLIService: Session disconnected without closing properly.
> 2016-07-20T15:11:37,859 INFO [HiveServer2-Handler-Pool: Thread-45]
> thrift.ThriftCLIService: Session disconnected without closing properly.
> 2016-07-20T15:11:37,859 INFO [HiveServer2-Handler-Pool: Thread-55]
> thrift.ThriftCLIService: Closing the session: SessionHandle
> [b4bb8b86-74e1-4e3c-babb-674d34ad1caf]
> 2016-07-20T15:11:37,859 INFO [HiveServer2-Handler-Pool: Thread-40]
> thrift.ThriftCLIService: Closing the session: SessionHandle
> [28b225ee-204f-4b3e-b4fd-0039ef8e276e]
> 2016-07-20T15:11:37,859 INFO [HiveServer2-Handler-Pool: Thread-65]
> thrift.ThriftCLIService: Closing the session: SessionHandle
> [88b630c0-f272-427d-8263-febfe2222f8d]
> 2016-07-20T15:11:37,859 INFO [HiveServer2-Handler-Pool: Thread-60]
> thrift.ThriftCLIService: Closing the session: SessionHandle
> [6d3c3ed9-fadb-4673-8c15-3315b7e2995d]
> 2016-07-20T15:11:37,859 INFO [HiveServer2-Handler-Pool: Thread-45]
> thrift.ThriftCLIService: Closing the session: SessionHandle
> [1d267de8-ff9a-4e76-ac5c-e82c871588e7]
> 2016-07-20T15:11:37,859 INFO [HiveServer2-Handler-Pool: Thread-50]
> thrift.ThriftCLIService: Closing the session: SessionHandle
> [04d53deb-8965-464b-aa3f-7042304cfb54]
> {code}
> The next time I connect to HS2 via beeline, I see
> {code}
> 2016-07-20T15:14:33,679 INFO [HiveServer2-Handler-Pool: Thread-50]
> thrift.ThriftCLIService: Client protocol version: HIVE_CLI_SERVICE_PROTOCOL_V8
> 2016-07-20T15:14:33,710 INFO [HiveServer2-Handler-Pool: Thread-50]
> session.SessionState: Created HDFS directory:
> /tmp/hive/hive/d47759e8-df3a-4504-9f28-99ff5247352c
> 2016-07-20T15:14:33,725 INFO [HiveServer2-Handler-Pool: Thread-50]
> session.SessionState: Created local directory:
> /var/folders/_3/0w477k4j5bjd6h967rw4vflw0000gp/T/ngangam/d47759e8-df3a-4504-9f28-99ff5247352c
> 2016-07-20T15:14:33,735 INFO [HiveServer2-Handler-Pool: Thread-50]
> session.SessionState: Created HDFS directory:
> /tmp/hive/hive/d47759e8-df3a-4504-9f28-99ff5247352c/_tmp_space.db
> 2016-07-20T15:14:33,737 INFO [HiveServer2-Handler-Pool: Thread-50]
> session.HiveSessionImpl: Operation log session directory is created:
> /var/folders/_3/0w477k4j5bjd6h967rw4vflw0000gp/T/ngangam/operation_logs/d47759e8-df3a-4504-9f28-99ff5247352c
> 2016-07-20T15:14:33,737 INFO [HiveServer2-Handler-Pool: Thread-50]
> thrift.ThriftCLIService: Opened a session SessionHandle
> [d47759e8-df3a-4504-9f28-99ff5247352c], current sessions: 7
> {code}
> So while the sessions itself are closed and cleaned up, the session count
> reported is not accurate.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
