[Bug] Can't connect to Kyuubi due to java.net.SocketTimeoutException: Read timed out
- Dominant language
- Scala
- Stars
- 2.4k
- Forks
- 1k
- PR merge metrics
- No merged PRs in 30d
Description
### 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.
### Describe the bug
Sometimes user report error saying job can't connect to Kyuubi server, error message shown as below, not sure if it's similar with #1624.
```
23/02/17 06:03:34 INFO zookeeper.ClientCnxn: Opening socket connection to server hadoopcbd008100/10.9.8.100:2181. Will not attempt to authenticate using SASL (unknown error)
23/02/17 06:03:34 INFO zookeeper.ClientCnxn: Socket connection established to hadoopcbd008100/10.9.8.100:2181, initiating session
23/02/17 06:03:34 INFO zookeeper.ClientCnxn: Session establishment complete on server hadoopcbd008100/10.9.8.100:2181, sessionid = 0xff801dbff55e25a3, negotiated timeout = 40000
23/02/17 06:03:34 INFO state.ConnectionStateManager: State change: CONNECTED
23/02/17 06:03:35 INFO jdbc.ZooKeeperHiveClientHelper: Selected HiveServer2 instance with uri: hadoopcbd009100.ppdgdsl.com:10009
23/02/17 06:03:35 INFO zookeeper.ZooKeeper: Session: 0xff801dbff55e25a3 closed
23/02/17 06:03:35 INFO jdbc.Utils: Resolved authority: hadoopcbd009100.ppdgdsl.com:10009
23/02/17 06:03:35 INFO zookeeper.ClientCnxn: EventThread shut down for session: 0xff801dbff55e25a3
23/02/17 06:03:35 INFO jdbc.HiveConnection: Will try to open client transport with JDBC Uri: jdbc:hive2://hadoopcbd009100.ppdgdsl.com:10009/;serviceDiscoveryMode=zooKeeper;zooKeeperNamespace=kyuubi
Error: Error opening session for hive client ip 10.9.9.172, due to org.apache.kyuubi.KyuubiSQLException: Error operating UNKNOWN_OPERATION: org.apache.thrift.transport.TTransportException: java.net.SocketTimeoutException: Read timed out
at org.apache.thrift.transport.TIOStreamTransport.read(TIOStreamTransport.java:129)
at org.apache.thrift.transport.TTransport.readAll(TTransport.java:86)
at org.apache.thrift.transport.TSaslTransport.readLength(TSaslTransport.java:376)
at org.apache.thrift.transport.TSaslTransport.readFrame(TSaslTransport.java:453)
at org.apache.thrift.transport.TSaslTransport.read(TSaslTransport.java:435)
at org.apache.thrift.transport.TSaslClientTransport.read(TSaslClientTransport.java:37)
at org.apache.thrift.transport.TTransport.readAll(TTransport.java:86)
at org.apache.thrift.protocol.TBinaryProtocol.readAll(TBinaryProtocol.java:429)
at org.apache.thrift.protocol.TBinaryProtocol.readI32(TBinaryProtocol.java:318)
at org.apache.thrift.protocol.TBinaryProtocol.readMessageBegin(TBinaryProtocol.java:219)
at org.apache.thrift.TServiceClient.receiveBase(TServiceClient.java:77)
at org.apache.hive.service.rpc.thrift.TCLIService$Client.recv_OpenSession(TCLIService.java:168)
at org.apache.hive.service.rpc.thrift.TCLIService$Client.OpenSession(TCLIService.java:155)
at org.apache.kyuubi.client.KyuubiSyncThriftClient.$anonfun$openSession$1(KyuubiSyncThriftClient.scala:65)
at org.apache.kyuubi.client.KyuubiSyncThriftClient.withLockAcquired(KyuubiSyncThriftClient.scala:49)
at org.apache.kyuubi.client.KyuubiSyncThriftClient.openSession(KyuubiSyncThriftClient.scala:65)
at org.apache.kyuubi.session.KyuubiSessionImpl.$anonfun$openEngineSession$1(KyuubiSessionImpl.scala:101)
at org.apache.kyuubi.session.KyuubiSessionImpl.$anonfun$openEngineSession$1$adapted(KyuubiSessionImpl.scala:87)
at org.apache.kyuubi.ha.client.ZooKeeperClientProvider$.withZkClient(ZooKeeperClientProvider.scala:81)
at org.apache.kyuubi.session.KyuubiSessionImpl.openEngineSession(KyuubiSessionImpl.scala:87)
at org.apache.kyuubi.operation.LaunchEngine.$anonfun$runInternal$1(LaunchEngine.scala:51)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:171)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
at java.io.BufferedInputStream.read1(BufferedInputStream.java:286)
at java.io.BufferedInputStream.read(BufferedInputStream.java:345)
at org.apache.thrift.transport.TIOStreamTransport.read(TIOStreamTransport.java:127)
... 25 more (state=,code=0)
0: jdbc:hive2://hadoopcbd008100:2181,hadoopcb (closed)> set mapreduce.job.name=tmp.d_cs_case_dddroolsparam on 2023-02-17;
23/02/17 06:13:35 INFO jdbc.Utils: Supplied authorities: hadoopcbd008100:2181,hadoopcbd008110:2181,hadoopcbd008120:2181
23/02/17 06:13:35 INFO imps.CuratorFrameworkImpl: Starting
23/02/17 06:13:35 INFO zookeeper.ZooKeeper: Initiating client connection, connectString=hadoopcbd008100:2181,hadoopcbd008110:2181,hadoopcbd008120:2181 sessionTimeout=60000 watcher=org.apache.curator.ConnectionState@2f4948e4
23/02/17 06:13:35 INFO zookeeper.ClientCnxn: Opening socket connection to server hadoopcbd008120/10.9.8.120:2181. Will not attempt to authenticate using SASL (unknown error)
23/02/17 06:13:35 INFO zookeeper.ClientCnxn: Socket connection established to hadoopcbd008120/10.9.8.120:2181, initiating session
23/02/17 06:13:35 INFO zookeeper.ClientCnxn: Session establishment complete on server hadoopcbd008120/10.9.8.120:2181, sessionid = 0x37ed9208c56f7e1, negotiated timeout = 40000
23/02/17 06:13:35 INFO state.ConnectionStateManager: State change: CONNECTED
23/02/17 06:13:35 INFO jdbc.ZooKeeperHiveClientHelper: Selected HiveServer2 instance with uri: hadoopcbd009100.ppdgdsl.com:10009
23/02/17 06:13:35 INFO zookeeper.ZooKeeper: Session: 0x37ed9208c56f7e1 closed
23/02/17 06:13:35 INFO zookeeper.ClientCnxn: EventThread shut down for session: 0x37ed9208c56f7e1
23/02/17 06:13:35 INFO jdbc.Utils: Resolved authority: hadoopcbd009100.ppdgdsl.com:10009
23/02/17 06:13:35 INFO jdbc.HiveConnection: Will try to open client transport with JDBC Uri: jdbc:hive2://hadoopcbd009100.ppdgdsl.com:10009/;serviceDiscoveryMode=zooKeeper;zooKeeperNamespace=kyuubi
No current connection
23/02/17 06:23:35 INFO jdbc.Utils: Supplied authorities: hadoopcbd008100:2181,hadoopcbd008110:2181,hadoopcbd008120:2181
23/02/17 06:23:35 INFO imps.CuratorFrameworkImpl: Starting
23/02/17 06:23:35 INFO zookeeper.ZooKeeper: Initiating client connection, connectString=hadoopcbd008100:2181,hadoopcbd008110:2181,hadoopcbd008120:2181 sessionTimeout=60000 watcher=org.apache.curator.ConnectionState@385c9627
23/02/17 06:23:35 INFO zookeeper.ClientCnxn: Opening socket connection to server hadoopcbd008120/10.9.8.120:2181. Will not attempt to authenticate using SASL (unknown error)
23/02/17 06:23:35 INFO zookeeper.ClientCnxn: Socket connection established to hadoopcbd008120/10.9.8.120:2181, initiating session
23/02/17 06:23:35 INFO zookeeper.ClientCnxn: Session establishment complete on server hadoopcbd008120/10.9.8.120:2181, sessionid = 0x37ed9208c56f7ef, negotiated timeout = 40000
23/02/17 06:23:35 INFO state.ConnectionStateManager: State change: CONNECTED
23/02/17 06:23:35 INFO jdbc.ZooKeeperHiveClientHelper: Selected HiveServer2 instance with uri: hadoopcbd009100.ppdgdsl.com:10009
23/02/17 06:23:35 INFO zookeeper.ZooKeeper: Session: 0x37ed9208c56f7ef closed
23/02/17 06:23:35 INFO jdbc.Utils: Resolved authority: hadoopcbd009100.ppdgdsl.com:10009
23/02/17 06:23:35 INFO zookeeper.ClientCnxn: EventThread shut down for session: 0x37ed9208c56f7ef
23/02/17 06:23:35 INFO jdbc.HiveConnection: Will try to open client transport with JDBC Uri: jdbc:hive2://hadoopcbd009100.ppdgdsl.com:10009/;serviceDiscoveryMode=zooKeeper;zooKeeperNamespace=kyuubi
Connected to: Apache Kyuubi (Incubating) (version 1.4.1-incubating)
Driver: Hive JDBC (version 1.2.1.spark2)
Transaction isolation: TRANSACTION_REPEATABLE_READ
Closing: 0: jdbc:hive2://hadoopcbd008100:2181,hadoopcbd008110:2181,hadoopcbd008120:2181/;serviceDiscoveryMode=zooKeeper;zooKeeperNamespace=kyuubi
```
### Affects Version(s)
1.4.1
### Kyuubi Server Log Output
_No response_
### Kyuubi Engine Log Output
_No response_
### Kyuubi Server Configurations
_No response_
### Kyuubi Engine Configurations
_No response_
### Additional context
_No response_
### Are you willing to submit PR?
- [ ] Yes. I would be willing to submit a PR with guidance from the Kyuubi community to fix.
- [X] No. I cannot submit a PR at this time.
Contributor guide
Research direction
Start with the connection flow named in the trace: KyuubiSyncThriftClient.scala, KyuubiSessionImpl.scala, ZooKeeperClientProvider.scala, and LaunchEngine.scala. Compare the reported timeout during OpenSession with the later successful connection; server, engine, and configuration logs are not provided. Done means the timeout cause is isolated and the connection behavior is covered by a verified fix.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- java, scala
- Domain
- backend, distributed-systems, networking
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Needs clarification
- Newbie friendliness
- 25/100