[
https://issues.apache.org/jira/browse/HIVE-25203?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17358014#comment-17358014
]
László Bodor commented on HIVE-25203:
-------------------------------------
FYI: this was a debug logging while we investigated:
{code}
1 row selected (14.303 seconds)
21/06/04 04:55:04 [main]: INFO jdbc.HiveConnection: HiveQueryResultSet.close():
org.apache.hive.jdbc.HiveStatement@523424b5
java.lang.RuntimeException
at
org.apache.hive.jdbc.HiveQueryResultSet.close(HiveQueryResultSet.java:310)
at org.apache.hive.beeline.Commands.executeInternal(Commands.java:1041)
at org.apache.hive.beeline.Commands.execute(Commands.java:1217)
at org.apache.hive.beeline.Commands.sql(Commands.java:1146)
at org.apache.hive.beeline.BeeLine.dispatch(BeeLine.java:1497)
at org.apache.hive.beeline.BeeLine.execute(BeeLine.java:1355)
at org.apache.hive.beeline.BeeLine.begin(BeeLine.java:1134)
at org.apache.hive.beeline.BeeLine.begin(BeeLine.java:1082)
at
org.apache.hive.beeline.BeeLine.mainWithInputRedirection(BeeLine.java:546)
at org.apache.hive.beeline.BeeLine.main(BeeLine.java:528)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.apache.hadoop.util.RunJar.run(RunJar.java:318)
at org.apache.hadoop.util.RunJar.main(RunJar.java:232)
21/06/04 04:55:04 [main]: INFO jdbc.HiveConnection: HiveStatement
closeClientOperation()
21/06/04 04:55:04 [main]: INFO jdbc.HiveConnection: HiveStatement
closeStatementIfNeeded() stmtHandle:
TOperationHandle(operationId:THandleIdentifier(guid:46 7F D7 60 2F 38 4C F5 AC
6F 08 C3 AC FA 13 A2, secret:A8 C7 B8 FF C4 88 4B C0 84 27 57 C1 C5 8C 44 F3),
operationType:EXECUTE_STATEMENT, hasResultSet:true)
21/06/04 04:55:04 [main]: INFO jdbc.HiveConnection: HiveStatement
CloseOperation returned: TStatus(statusCode:SUCCESS_STATUS)
21/06/04 04:55:04 [main]: INFO jdbc.HiveConnection: HiveStatement close()
isClosed: false
21/06/04 04:55:04 [main]: INFO jdbc.HiveConnection: HiveStatement
closeClientOperation()
21/06/04 04:55:04 [main]: INFO jdbc.HiveConnection: HiveStatement
closeStatementIfNeeded() stmtHandle: null
21/06/04 04:55:04 [main]: INFO jdbc.HiveConnection: HiveQueryResultSet.close():
org.apache.hive.jdbc.HiveStatement@523424b5
java.lang.RuntimeException
at
org.apache.hive.jdbc.HiveQueryResultSet.close(HiveQueryResultSet.java:310)
at org.apache.hive.jdbc.HiveStatement.close(HiveStatement.java:252)
at org.apache.hive.beeline.Commands.executeInternal(Commands.java:1067)
at org.apache.hive.beeline.Commands.execute(Commands.java:1217)
at org.apache.hive.beeline.Commands.sql(Commands.java:1146)
at org.apache.hive.beeline.BeeLine.dispatch(BeeLine.java:1497)
at org.apache.hive.beeline.BeeLine.execute(BeeLine.java:1355)
at org.apache.hive.beeline.BeeLine.begin(BeeLine.java:1134)
at org.apache.hive.beeline.BeeLine.begin(BeeLine.java:1082)
at
org.apache.hive.beeline.BeeLine.mainWithInputRedirection(BeeLine.java:546)
at org.apache.hive.beeline.BeeLine.main(BeeLine.java:528)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.apache.hadoop.util.RunJar.run(RunJar.java:318)
at org.apache.hadoop.util.RunJar.main(RunJar.java:232)
{code}
> HiveQueryResultSet and client operation are not expected to be closed twice
> ---------------------------------------------------------------------------
>
> Key: HIVE-25203
> URL: https://issues.apache.org/jira/browse/HIVE-25203
> Project: Hive
> Issue Type: Bug
> Reporter: László Bodor
> Assignee: László Bodor
> Priority: Major
> Labels: pull-request-available
> Time Spent: 10m
> Remaining Estimate: 0h
>
> While testing retry scenarios of HIVE-24786, we found that
> HiveQueryResultSet.close() is called twice, which is not expected. There are
> 2 different issues here:
> 1. ResultSet should not handle Statement as in HiveQueryResultSet:
> {code}
> if (this.statement != null && (this.statement instanceof HiveStatement)) {
> HiveStatement s = (HiveStatement) this.statement;
> s.closeClientOperation();
> {code}
> The hiearchy of Connection(HiveConnection) -> Statement(HiveStatement) ->
> ResultSet(HiveQueryResultSet) should be respected in a sense that the parent
> can handle child but not the opposite way, only except a single case, where
> the state of the result set has an effect on statement's state, which is
> [Statement.closeOnCompletion|https://docs.oracle.com/javase/7/docs/api/java/sql/Statement.html#closeOnCompletion()],
> which was introduced by HIVE-22698.
> The above logic was introduced by
> [HIVE-4974|https://github.com/apache/hive/blame/master/jdbc/src/java/org/apache/hive/jdbc/HiveQueryResultSet.java#L276].
> Its intention was to make children able to return their parents, but that
> doesn't mean they should handle their parents' lifecycle.
> 2. Also, HiveStatement should close HiveQueryResultSet only if it's not
> already closed, so it would make sense to check ResultSet.isClosed() before
> closing. This is for the very same reason as another change above, to avoid
> duplicated close logic.
> Background: under normal circumstances, a close operation is idempotent, we
> should not worry about any side effects of calling it twice, but while
> testing HIVE-24786, we found strange issues where in case of a
> SocketTimeoutException, such code path was hit in the jdbc client, that made
> HiveStatement.closeClientOperation() to be called twice, and it led to a
> WARNING on HS2 side. This is not expected as the operation close is protected
> by stmtHandle != null check, but yet it ran twice. To avoid situations like
> this, cleaning up duplicated close calls would help.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
