[ 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)