apache / apache/kyuubi

[Bug] Can't connect to Kyuubi due to java.net.SocketTimeoutException: Read timed out

Open
#4,350 0 comments 0 reactions 0 assignees View on GitHub
kind:bug priority:major
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

Open the contributing 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

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.