minyk opened a new issue, #5451: URL: https://github.com/apache/kyuubi/issues/5451
### Code of Conduct - [X] I agree to follow this project's [Code of Conduct](https://www.apache.org/foundation/policies/conduct) ### Search before asking - [X] I have searched in the [issues](https://github.com/apache/kyuubi/issues?q=is%3Aissue) and found no similar issues. ### What would you like to be improved? `OperationLog.close()` try to close BufferedReader, but it says file is missing(NoSuchFileException). https://github.com/apache/kyuubi/blob/4bb67bdf3bcabd135102bd85c8992e9b52ba9356/kyuubi-common/src/main/scala/org/apache/kyuubi/operation/log/OperationLog.scala#L242 This happened after restarting kyuubi-server and PV is not set for `kyuubi.operation.log.dir.root`. Errors are very similar like https://github.com/apache/kyuubi/pull/4986, but happens when reader.close() not delete: ``` 2023-10-18 04:16:34.296 ERROR KyuubiTBinaryFrontendHandler-Pool: Thread-113 org.apache.kyuubi.operation.LaunchEngine: Failed to remove corresponding log file of operation: /opt/kyuubi/work/server_operation_logs/26434238-5615-456a-aa7b-fad4dde8da27/43a9bfd4-6795-422c-8031-5409d7fe3732 java.io.IOException: Failed to remove corresponding log file of operation: /opt/kyuubi/work/server_operation_logs/26434238-5615-456a-aa7b-fad4dde8da27/43a9bfd4-6795-422c-8031-5409d7fe3732 at org.apache.kyuubi.operation.log.OperationLog.trySafely(OperationLog.scala:230) ~[kyuubi-common_2.12-1.6.1-incubating.jar:1.6.1-incubating] at org.apache.kyuubi.operation.log.OperationLog.close(OperationLog.scala:201) ~[kyuubi-common_2.12-1.6.1-incubating.jar:1.6.1-incubating] at org.apache.kyuubi.operation.KyuubiOperation.$anonfun$close$2(KyuubiOperation.scala:119) ~[kyuubi-server_2.12-1.6.1-incubating.jar:1.6.1-incubating] at org.apache.kyuubi.operation.KyuubiOperation.$anonfun$close$2$adapted(KyuubiOperation.scala:119) ~[kyuubi-server_2.12-1.6.1-incubating.jar:1.6.1-incubating] at scala.Option.foreach(Option.scala:407) ~[scala-library-2.12.15.jar:?] at org.apache.kyuubi.operation.KyuubiOperation.liftedTree2$1(KyuubiOperation.scala:119) ~[kyuubi-server_2.12-1.6.1-incubating.jar:1.6.1-incubating] at org.apache.kyuubi.operation.KyuubiOperation.close(KyuubiOperation.scala:116) ~[kyuubi-server_2.12-1.6.1-incubating.jar:1.6.1-incubating] at org.apache.kyuubi.operation.OperationManager.closeOperation(OperationManager.scala:126) ~[kyuubi-common_2.12-1.6.1-incubating.jar:1.6.1-incubating] at org.apache.kyuubi.session.AbstractSession.$anonfun$close$2(AbstractSession.scala:89) ~[kyuubi-common_2.12-1.6.1-incubating.jar:1.6.1-incubating] at java.lang.Iterable.forEach(Iterable.java:75) ~[?:1.8.0_342] at org.apache.kyuubi.session.AbstractSession.$anonfun$close$1(AbstractSession.scala:87) ~[kyuubi-common_2.12-1.6.1-incubating.jar:1.6.1-incubating] at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:23) ~[scala-library-2.12.15.jar:?] at org.apache.kyuubi.session.AbstractSession.withAcquireRelease(AbstractSession.scala:82) ~[kyuubi-common_2.12-1.6.1-incubating.jar:1.6.1-incubating] at org.apache.kyuubi.session.AbstractSession.close(AbstractSession.scala:87) ~[kyuubi-common_2.12-1.6.1-incubating.jar:1.6.1-incubating] at org.apache.kyuubi.session.KyuubiSessionImpl.close(KyuubiSessionImpl.scala:190) ~[kyuubi-server_2.12-1.6.1-incubating.jar:1.6.1-incubating] at org.apache.kyuubi.session.SessionManager.closeSession(SessionManager.scala:127) ~[kyuubi-common_2.12-1.6.1-incubating.jar:1.6.1-incubating] at org.apache.kyuubi.session.KyuubiSessionManager.closeSession(KyuubiSessionManager.scala:111) ~[kyuubi-server_2.12-1.6.1-incubating.jar:1.6.1-incubating] at org.apache.kyuubi.service.AbstractBackendService.closeSession(AbstractBackendService.scala:49) ~[kyuubi-common_2.12-1.6.1-incubating.jar:1.6.1-incubating] at org.apache.kyuubi.server.KyuubiServer$$anon$1.org$apache$kyuubi$server$BackendServiceMetric$$super$closeSession(KyuubiServer.scala:111) ~[kyuubi-server_2.12-1.6.1-incubating.jar:1.6.1-incubating] at org.apache.kyuubi.server.BackendServiceMetric.$anonfun$closeSession$1(BackendServiceMetric.scala:43) ~[kyuubi-server_2.12-1.6.1-incubating.jar:1.6.1-incubating] at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:23) ~[scala-library-2.12.15.jar:?] ``` Also, when this happened, all other server logs are muted. ### How should we improve? We can ignore `NoSuchFileException` in the `trySafely()`: ```scala private def trySafely(f: => Unit): Unit = { try { f } catch { case _: NoSuchFileException => case e: IOException => // Printing log here may cause a deadlock. The lock order of OperationLog.write // is RootLogger -> LogDivertAppender -> OperationLog. If printing log here, the // lock order is OperationLog -> RootLogger. So the exception is thrown and // processing at the invocations throw new IOException( s"Failed to remove corresponding log file of operation: ${path.toAbsolutePath}", e) } } ``` this `trySafely()` is called only during `OperationLog.close()`, so I think we'll be safe here. ### Are you willing to submit PR? - [X] Yes. I would be willing to submit a PR with guidance from the Kyuubi community to improve. - [ ] No. I cannot submit a PR at this time. -- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. To unsubscribe, e-mail: [email protected] For queries about this service, please contact Infrastructure at: [email protected] --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
