search

apache / kyuubi

Apache Kyuubi is a distributed and multi-tenant gateway to provide serverless SQL on data warehouses and lakehouses.
https://kyuubi.apache.org/
Apache License 2.0
2.11k stars 917 forks source link

[Bug] TRINO Error operating EXECUTE_STATEMENT, broken pipe(Write failed) #4930

Open A-little-bit-of-data opened 1 year ago

A-little-bit-of-data commented 1 year ago

Code of Conduct

Search before asking

Describe the bug

I am using kyuubi to connect to trino, but show tables will report an error only after using the use schema

Affects Version(s)

1.7.0

Kyuubi Server Log Output

2023-06-07 13:47:27.401 INFO org.apache.kyuubi.engine.ProcBuilder: Logging to /opt/kyuubi/work/admin/kyuubi-trino-engine.log.0

 2023-06-07 13:47:28.811 INFO org.apache.zookeeper.server.NIOServerCnxnFactory: Accepted socket connection from /XXXXXXXXX:40580

 2023-06-07 13:47:28.813 INFO org.apache.zookeeper.server.ZooKeeperServer: Client attempting to establish new session at /XXXXXXXXX:40580

 2023-06-07 13:47:28.813 INFO org.apache.zookeeper.server.ZooKeeperServer: Established session 0x10240e15f740002 with negotiated timeout 60000 for client /XXXXXX:40580

 2023-06-07 13:47:29.233 INFO org.apache.zookeeper.server.PrepRequestProcessor: Got user-level KeeperException when processing sessionid:0x10240e15f740002 type:create cxid:0x1 zxid:0x10 txntype:-1 reqpath:n/a Error Path:/kyuubi_1.7.0_USER_TRINO/admin Error:KeeperErrorCode = NoNode for /kyuubi_1.7.0_USER_TRINO/admin

 2023-06-07 13:47:29.417 INFO org.apache.kyuubi.ha.client.zookeeper.ZookeeperDiscoveryClient: Get service instance:kyuubi-86c95975c7-nx59s:46789 and version:1.7.0 under /kyuubi_1.7.0_USER_TRINO/admin/default

 2023-06-07 13:47:29.624 INFO org.apache.kyuubi.session.KyuubiSessionImpl: [admin:XXXXXX] SessionHandle [1a38d5b0-2f1d-486f-bca2-da78371d63cc] - Connected to engine [kyuubi-86c95975c7-nx59s:46789]/[] with SessionHandle [78a28437-ff95-45b8-979a-97732bc04faa]]

 2023-06-07 13:47:29.625 INFO org.apache.curator.framework.imps.CuratorFrameworkImpl: backgroundOperationsLoop exiting

 2023-06-07 13:47:29.650 INFO org.apache.zookeeper.server.PrepRequestProcessor: Processed session termination for sessionid: 0x10240e15f740001

 2023-06-07 13:47:29.651 INFO org.apache.zookeeper.ZooKeeper: Session: 0x10240e15f740001 closed

 2023-06-07 13:47:29.651 INFO org.apache.zookeeper.ClientCnxn: EventThread shut down for session: 0x10240e15f740001

 2023-06-07 13:47:29.651 INFO org.apache.zookeeper.server.NIOServerCnxn: Closed socket connection for client /XXXX:40574 which had sessionid 0x10240e15f740001

 2023-06-07 13:47:29.652 INFO org.apache.kyuubi.operation.LaunchEngine: Processing admin's query[ffca0373-e9fd-49bd-803a-8ced71814928]: RUNNING_STATE -> FINISHED_STATE, time taken: 2.333 seconds

 2023-06-07 13:47:29.653 INFO org.apache.kyuubi.session.KyuubiSessionImpl: [admin:XXXX] SessionHandle [1a38d5b0-2f1d-486f-bca2-da78371d63cc] - Engine has been launched, elapsed time: 2 s

 2023-06-07 13:47:32.826 INFO org.apache.kyuubi.operation.log.OperationLog: Creating operation log file /opt/kyuubi/work/server_operation_logs/1a38d5b0-2f1d-486f-bca2-da78371d63cc/61da0ccf-0583-4392-b95e-abbcf3216d39

 2023-06-07 13:47:32.875 INFO org.apache.kyuubi.operation.ExecuteStatement: Processing admin's query[61da0ccf-0583-4392-b95e-abbcf3216d39]: PENDING_STATE -> RUNNING_STATE, statement:

 use default

 2023-06-07 13:47:32.952 INFO org.apache.kyuubi.operation.ExecuteStatement: Query[61da0ccf-0583-4392-b95e-abbcf3216d39] in FINISHED_STATE

 2023-06-07 13:47:32.952 INFO org.apache.kyuubi.operation.ExecuteStatement: Processing admin's query[61da0ccf-0583-4392-b95e-abbcf3216d39]: RUNNING_STATE -> FINISHED_STATE, time taken: 0.077 seconds

 2023-06-07 13:47:32.990 ERROR org.apache.kyuubi.server.KyuubiTBinaryFrontendService: Error getting result set metadata: 

 org.apache.thrift.transport.TTransportException: null

    at org.apache.thrift.transport.TIOStreamTransport.read(TIOStreamTransport.java:132) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.transport.TTransport.readAll(TTransport.java:86) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.transport.TSaslTransport.readLength(TSaslTransport.java:376) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.transport.TSaslTransport.readFrame(TSaslTransport.java:453) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.transport.TSaslTransport.read(TSaslTransport.java:435) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.transport.TSaslClientTransport.read(TSaslClientTransport.java:37) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.transport.TTransport.readAll(TTransport.java:86) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.protocol.TBinaryProtocol.readAll(TBinaryProtocol.java:429) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.protocol.TBinaryProtocol.readI32(TBinaryProtocol.java:318) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.protocol.TBinaryProtocol.readMessageBegin(TBinaryProtocol.java:219) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.TServiceClient.receiveBase(TServiceClient.java:77) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.hive.service.rpc.thrift.TCLIService$Client.recv_GetResultSetMetadata(TCLIService.java:544) ~[hive-service-rpc-3.1.3.jar:3.1.3]

    at org.apache.hive.service.rpc.thrift.TCLIService$Client.GetResultSetMetadata(TCLIService.java:531) ~[hive-service-rpc-3.1.3.jar:3.1.3]

    at org.apache.kyuubi.client.KyuubiSyncThriftClient.$anonfun$getResultSetMetadata$1(KyuubiSyncThriftClient.scala:395) ~[kyuubi-server_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.client.KyuubiSyncThriftClient.$anonfun$withLockAcquiredAsyncRequest$2(KyuubiSyncThriftClient.scala:142) ~[kyuubi-server_2.12-1.7.0.jar:1.7.0]

    at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_362]

    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_362]

    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) ~[?:1.8.0_362]

    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_362]

    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_362]

    at java.lang.Thread.run(Thread.java:750) ~[?:1.8.0_362]

 2023-06-07 13:47:33.070 WARN org.apache.kyuubi.operation.ExecuteStatement: Error closing THandleIdentifier(guid:0D 3C B8 2B FC DD 49 FA 9A 50 BB 8D 10 78 00 06, secret:C2 EE 5B 97 3E A0 41 FC AC 16 9B D7 08 ED 8F 38): null

 org.apache.thrift.transport.TTransportException: null

    at org.apache.thrift.transport.TIOStreamTransport.read(TIOStreamTransport.java:132) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.transport.TTransport.readAll(TTransport.java:86) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.transport.TSaslTransport.readLength(TSaslTransport.java:376) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.transport.TSaslTransport.readFrame(TSaslTransport.java:453) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.transport.TSaslTransport.read(TSaslTransport.java:435) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.transport.TSaslClientTransport.read(TSaslClientTransport.java:37) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.transport.TTransport.readAll(TTransport.java:86) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.protocol.TBinaryProtocol.readAll(TBinaryProtocol.java:429) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.protocol.TBinaryProtocol.readI32(TBinaryProtocol.java:318) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.protocol.TBinaryProtocol.readMessageBegin(TBinaryProtocol.java:219) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.TServiceClient.receiveBase(TServiceClient.java:77) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.hive.service.rpc.thrift.TCLIService$Client.recv_CloseOperation(TCLIService.java:521) ~[hive-service-rpc-3.1.3.jar:3.1.3]

    at org.apache.hive.service.rpc.thrift.TCLIService$Client.CloseOperation(TCLIService.java:508) ~[hive-service-rpc-3.1.3.jar:3.1.3]

    at org.apache.kyuubi.client.KyuubiSyncThriftClient.$anonfun$closeOperation$1(KyuubiSyncThriftClient.scala:385) ~[kyuubi-server_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.client.KyuubiSyncThriftClient.$anonfun$withLockAcquiredAsyncRequest$2(KyuubiSyncThriftClient.scala:142) ~[kyuubi-server_2.12-1.7.0.jar:1.7.0]

    at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_362]

    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_362]

    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) ~[?:1.8.0_362]

    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_362]

    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_362]

    at java.lang.Thread.run(Thread.java:750) ~[?:1.8.0_362]

 2023-06-07 13:47:35.593 INFO org.apache.kyuubi.operation.log.OperationLog: Creating operation log file /opt/kyuubi/work/server_operation_logs/1a38d5b0-2f1d-486f-bca2-da78371d63cc/ba2509b3-28e8-4cd5-9c6d-e4ebb945de54

 2023-06-07 13:47:35.599 INFO org.apache.kyuubi.operation.ExecuteStatement: Processing admin's query[ba2509b3-28e8-4cd5-9c6d-e4ebb945de54]: PENDING_STATE -> ERROR_STATE, time taken: 1.686116855599E9 seconds

 2023-06-07 13:47:35.600 ERROR org.apache.kyuubi.server.KyuubiTBinaryFrontendService: Error executing statement: 

 org.apache.kyuubi.KyuubiSQLException: Error operating ExecuteStatement: org.apache.thrift.transport.TTransportException: java.net.SocketException: Broken pipe (Write failed)

    at org.apache.thrift.transport.TIOStreamTransport.flush(TIOStreamTransport.java:161)

    at org.apache.thrift.transport.TSaslTransport.flush(TSaslTransport.java:501)

    at org.apache.thrift.transport.TSaslClientTransport.flush(TSaslClientTransport.java:37)

    at org.apache.thrift.TServiceClient.sendBase(TServiceClient.java:73)

    at org.apache.thrift.TServiceClient.sendBase(TServiceClient.java:62)

    at org.apache.hive.service.rpc.thrift.TCLIService$Client.send_ExecuteStatement(TCLIService.java:239)

    at org.apache.hive.service.rpc.thrift.TCLIService$Client.ExecuteStatement(TCLIService.java:231)

    at org.apache.kyuubi.client.KyuubiSyncThriftClient.$anonfun$executeStatement$1(KyuubiSyncThriftClient.scala:241)

    at org.apache.kyuubi.client.KyuubiSyncThriftClient.$anonfun$withLockAcquiredAsyncRequest$2(KyuubiSyncThriftClient.scala:142)

    at java.util.concurrent.FutureTask.run(FutureTask.java:266)

    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

    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:750)

 Caused by: java.net.SocketException: Broken pipe (Write failed)

    at java.net.SocketOutputStream.socketWrite0(Native Method)

    at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:111)

    at java.net.SocketOutputStream.write(SocketOutputStream.java:155)

    at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)

    at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)

    at org.apache.thrift.transport.TIOStreamTransport.flush(TIOStreamTransport.java:159)

    ... 14 more

    at org.apache.kyuubi.KyuubiSQLException$.apply(KyuubiSQLException.scala:69) ~[kyuubi-common_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.operation.KyuubiOperation$$anonfun$onError$1.applyOrElse(KyuubiOperation.scala:76) ~[kyuubi-server_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.operation.KyuubiOperation$$anonfun$onError$1.applyOrElse(KyuubiOperation.scala:57) ~[kyuubi-server_2.12-1.7.0.jar:1.7.0]

    at scala.runtime.AbstractPartialFunction.apply(AbstractPartialFunction.scala:38) ~[scala-library-2.12.17.jar:?]

    at org.apache.kyuubi.operation.ExecuteStatement.executeStatement(ExecuteStatement.scala:68) ~[kyuubi-server_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.operation.ExecuteStatement.runInternal(ExecuteStatement.scala:159) ~[kyuubi-server_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.operation.AbstractOperation.run(AbstractOperation.scala:166) ~[kyuubi-common_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.session.AbstractSession.runOperation(AbstractSession.scala:101) ~[kyuubi-common_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.session.KyuubiSessionImpl.runOperation(KyuubiSessionImpl.scala:211) ~[kyuubi-server_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.session.AbstractSession.$anonfun$executeStatement$1(AbstractSession.scala:131) ~[kyuubi-common_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.session.AbstractSession.withAcquireRelease(AbstractSession.scala:82) ~[kyuubi-common_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.session.AbstractSession.executeStatement(AbstractSession.scala:128) ~[kyuubi-common_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.session.KyuubiSessionImpl.super$executeStatement(KyuubiSessionImpl.scala:285) ~[kyuubi-server_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.session.KyuubiSessionImpl.$anonfun$executeStatement$1(KyuubiSessionImpl.scala:285) ~[kyuubi-server_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.session.AbstractSession.withAcquireRelease(AbstractSession.scala:82) ~[kyuubi-common_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.session.KyuubiSessionImpl.executeStatement(KyuubiSessionImpl.scala:276) ~[kyuubi-server_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.service.AbstractBackendService.executeStatement(AbstractBackendService.scala:66) ~[kyuubi-common_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.server.KyuubiServer$$anon$1.org$apache$kyuubi$server$BackendServiceMetric$$super$executeStatement(KyuubiServer.scala:147) ~[kyuubi-server_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.server.BackendServiceMetric.$anonfun$executeStatement$1(BackendServiceMetric.scala:62) ~[kyuubi-server_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.metrics.MetricsSystem$.timerTracing(MetricsSystem.scala:111) ~[kyuubi-metrics_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.server.BackendServiceMetric.executeStatement(BackendServiceMetric.scala:62) ~[kyuubi-server_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.server.BackendServiceMetric.executeStatement$(BackendServiceMetric.scala:55) ~[kyuubi-server_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.server.KyuubiServer$$anon$1.executeStatement(KyuubiServer.scala:147) ~[kyuubi-server_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.service.TFrontendService.ExecuteStatement(TFrontendService.scala:252) ~[kyuubi-common_2.12-1.7.0.jar:1.7.0]

    at org.apache.hive.service.rpc.thrift.TCLIService$Processor$ExecuteStatement.getResult(TCLIService.java:1557) ~[hive-service-rpc-3.1.3.jar:3.1.3]

    at org.apache.hive.service.rpc.thrift.TCLIService$Processor$ExecuteStatement.getResult(TCLIService.java:1542) ~[hive-service-rpc-3.1.3.jar:3.1.3]

    at org.apache.thrift.ProcessFunction.process(ProcessFunction.java:39) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.TBaseProcessor.process(TBaseProcessor.java:39) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.kyuubi.service.authentication.TSetIpAddressProcessor.process(TSetIpAddressProcessor.scala:36) ~[kyuubi-common_2.12-1.7.0.jar:1.7.0]

    at org.apache.thrift.server.TThreadPoolServer$WorkerProcess.run(TThreadPoolServer.java:286) ~[libthrift-0.9.3.jar:0.9.3]

    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_362]

    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_362]

    at java.lang.Thread.run(Thread.java:750) ~[?:1.8.0_362]

 Caused by: org.apache.thrift.transport.TTransportException: java.net.SocketException: Broken pipe (Write failed)

    at org.apache.thrift.transport.TIOStreamTransport.flush(TIOStreamTransport.java:161) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.transport.TSaslTransport.flush(TSaslTransport.java:501) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.transport.TSaslClientTransport.flush(TSaslClientTransport.java:37) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.TServiceClient.sendBase(TServiceClient.java:73) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.TServiceClient.sendBase(TServiceClient.java:62) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.hive.service.rpc.thrift.TCLIService$Client.send_ExecuteStatement(TCLIService.java:239) ~[hive-service-rpc-3.1.3.jar:3.1.3]

    at org.apache.hive.service.rpc.thrift.TCLIService$Client.ExecuteStatement(TCLIService.java:231) ~[hive-service-rpc-3.1.3.jar:3.1.3]

    at org.apache.kyuubi.client.KyuubiSyncThriftClient.$anonfun$executeStatement$1(KyuubiSyncThriftClient.scala:241) ~[kyuubi-server_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.client.KyuubiSyncThriftClient.$anonfun$withLockAcquiredAsyncRequest$2(KyuubiSyncThriftClient.scala:142) ~[kyuubi-server_2.12-1.7.0.jar:1.7.0]

    at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_362]

    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_362]

    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) ~[?:1.8.0_362]

    ... 3 more

 Caused by: java.net.SocketException: Broken pipe (Write failed)

    at java.net.SocketOutputStream.socketWrite0(Native Method) ~[?:1.8.0_362]

    at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:111) ~[?:1.8.0_362]

    at java.net.SocketOutputStream.write(SocketOutputStream.java:155) ~[?:1.8.0_362]

    at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82) ~[?:1.8.0_362]

    at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140) ~[?:1.8.0_362]

    at org.apache.thrift.transport.TIOStreamTransport.flush(TIOStreamTransport.java:159) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.transport.TSaslTransport.flush(TSaslTransport.java:501) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.transport.TSaslClientTransport.flush(TSaslClientTransport.java:37) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.TServiceClient.sendBase(TServiceClient.java:73) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.thrift.TServiceClient.sendBase(TServiceClient.java:62) ~[libthrift-0.9.3.jar:0.9.3]

    at org.apache.hive.service.rpc.thrift.TCLIService$Client.send_ExecuteStatement(TCLIService.java:239) ~[hive-service-rpc-3.1.3.jar:3.1.3]

    at org.apache.hive.service.rpc.thrift.TCLIService$Client.ExecuteStatement(TCLIService.java:231) ~[hive-service-rpc-3.1.3.jar:3.1.3]

    at org.apache.kyuubi.client.KyuubiSyncThriftClient.$anonfun$executeStatement$1(KyuubiSyncThriftClient.scala:241) ~[kyuubi-server_2.12-1.7.0.jar:1.7.0]

    at org.apache.kyuubi.client.KyuubiSyncThriftClient.$anonfun$withLockAcquiredAsyncRequest$2(KyuubiSyncThriftClient.scala:142) ~[kyuubi-server_2.12-1.7.0.jar:1.7.0]

    at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_362]

    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) ~[?:1.8.0_362]

    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) ~[?:1.8.0_362]

    ... 3 more

Kyuubi Engine Log Output

Connected to: Trino (version 418)
Driver: Hive JDBC (version 2.3.9)
Transaction isolation: TRANSACTION_REPEATABLE_READ
Beeline version 2.3.9 by Apache Hive
0: jdbc:hive2://XXXX:XXXX/s3test> use default;
2023-06-07 13:47:32.875 INFO org.apache.kyuubi.operation.ExecuteStatement: Processing admin's query[61da0ccf-0583-4392-b95e-abbcf3216d39]: PENDING_STATE -> RUNNING_STATE, statement:
use default
2023-06-07 13:47:32.870 INFO org.apache.kyuubi.engine.trino.operation.ExecuteStatement: Processing admin's query[0d3cb82b-fcdd-49fa-9a50-bb8d10780006]: PENDING_STATE -> RUNNING_STATE, statement:
use default
2023-06-07 13:47:32.894 INFO org.apache.kyuubi.engine.trino.TrinoStatement: Execute with Trino query id: 20230607_054732_00021_gvgri
2023-06-07 13:47:32.894 INFO org.apache.kyuubi.engine.trino.operation.ExecuteStatement: Execute in full collect mode
2023-06-07 13:47:32.899 INFO org.apache.kyuubi.engine.trino.operation.ExecuteStatement: Processing admin's query[0d3cb82b-fcdd-49fa-9a50-bb8d10780006]: RUNNING_STATE -> FINISHED_STATE, time taken: 0.028 seconds
2023-06-07 13:47:32.952 INFO org.apache.kyuubi.operation.ExecuteStatement: Query[61da0ccf-0583-4392-b95e-abbcf3216d39] in FINISHED_STATE
2023-06-07 13:47:32.952 INFO org.apache.kyuubi.operation.ExecuteStatement: Processing admin's query[61da0ccf-0583-4392-b95e-abbcf3216d39]: RUNNING_STATE -> FINISHED_STATE, time taken: 0.077 seconds
Unknown HS2 problem when communicating with Thrift server.
Error:  (state=,code=0)
0: jdbc:hive2://XXXX:XXXX/s3test> show tables;
Error: Error operating ExecuteStatement: org.apache.thrift.transport.TTransportException: java.net.SocketException: Broken pipe (Write failed)
        at org.apache.thrift.transport.TIOStreamTransport.flush(TIOStreamTransport.java:161)
        at org.apache.thrift.transport.TSaslTransport.flush(TSaslTransport.java:501)
        at org.apache.thrift.transport.TSaslClientTransport.flush(TSaslClientTransport.java:37)
        at org.apache.thrift.TServiceClient.sendBase(TServiceClient.java:73)
        at org.apache.thrift.TServiceClient.sendBase(TServiceClient.java:62)
        at org.apache.hive.service.rpc.thrift.TCLIService$Client.send_ExecuteStatement(TCLIService.java:239)
        at org.apache.hive.service.rpc.thrift.TCLIService$Client.ExecuteStatement(TCLIService.java:231)
        at org.apache.kyuubi.client.KyuubiSyncThriftClient.$anonfun$executeStatement$1(KyuubiSyncThriftClient.scala:241)
        at org.apache.kyuubi.client.KyuubiSyncThriftClient.$anonfun$withLockAcquiredAsyncRequest$2(KyuubiSyncThriftClient.scala:142)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
        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:750)
Caused by: java.net.SocketException: Broken pipe (Write failed)
        at java.net.SocketOutputStream.socketWrite0(Native Method)
        at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:111)
        at java.net.SocketOutputStream.write(SocketOutputStream.java:155)
        at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
        at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
        at org.apache.thrift.transport.TIOStreamTransport.flush(TIOStreamTransport.java:159)
        ... 14 more (state=,code=0)

Kyuubi Server Configurations

No response

Kyuubi Engine Configurations

No response

Additional context

No response

Are you willing to submit PR?

github-actions[bot] commented 1 year ago

Hello @A-little-bit-of-data, Thanks for finding the time to report the issue! We really appreciate the community's efforts to improve Apache Kyuubi.

pan3793 commented 1 year ago

What you pasted in "Kyuubi Engine Log Output" is actually the client log, the real engine log is located at

org.apache.kyuubi.engine.ProcBuilder: Logging to /opt/kyuubi/work/admin/kyuubi-trino-engine.log.0
A-little-bit-of-data commented 1 year ago

/opt/kyuubi/work/admin

the log :

2023-06-07 13:47:28.314 INFO org.apache.kyuubi.util.SignalRegister: Registering signal handler for TERM
2023-06-07 13:47:28.317 INFO org.apache.kyuubi.util.SignalRegister: Registering signal handler for HUP
2023-06-07 13:47:28.317 INFO org.apache.kyuubi.util.SignalRegister: Registering signal handler for INT
2023-06-07 13:47:28.455 WARN org.apache.hadoop.util.NativeCodeLoader: Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2023-06-07 13:47:28.678 INFO org.apache.kyuubi.Utils: Loading Kyuubi properties from /opt/kyuubi/conf/kyuubi-defaults.conf
2023-06-07 13:47:28.706 INFO org.apache.kyuubi.util.ThreadUtils: TrinoSessionManager-exec-pool: pool size: 100, wait queue size: 100, thread keepalive time: 60000 ms
2023-06-07 13:47:28.713 INFO org.apache.kyuubi.engine.trino.operation.TrinoOperationManager: Service[TrinoOperationManager] is initialized.
2023-06-07 13:47:28.714 INFO org.apache.kyuubi.engine.trino.session.TrinoSessionManager: Service[TrinoSessionManager] is initialized.
2023-06-07 13:47:28.714 INFO org.apache.kyuubi.engine.trino.TrinoBackendService: Service[TrinoBackendService] is initialized.
2023-06-07 13:47:28.750 INFO org.apache.kyuubi.engine.trino.TrinoTBinaryFrontendService: Initializing TrinoTBinaryFrontend on kyuubi-86c95975c7-nx59s:46789 with [500, 999] worker threads
2023-06-07 13:47:28.790 INFO org.apache.curator.framework.imps.CuratorFrameworkImpl: Starting
2023-06-07 13:47:28.794 INFO org.apache.zookeeper.ZooKeeper: Client environment:zookeeper.version=3.4.14-4c25d480e66aadd371de8bd2fd8da255ac140bcf, built on 03/06/2019 16:18 GMT
2023-06-07 13:47:28.795 INFO org.apache.zookeeper.ZooKeeper: Client environment:host.name=kyuubi-86c95975c7-nx59s
2023-06-07 13:47:28.795 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.version=1.8.0_362
2023-06-07 13:47:28.795 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.vendor=Temurin
2023-06-07 13:47:28.795 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.home=/opt/java/openjdk/jre
2023-06-07 13:47:28.795 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.class.path=/opt/kyuubi/externals/engines/trino/kyuubi-trino-engine_2.12-1.7.0.jar:/opt/kyuubi/externals/engines/trino/HikariCP-4.0.3.jar:/opt/kyuubi/externals/engines/trino/ST4-4.3.4.jar:/opt/kyuubi/externals/engines/trino/animal-sniffer-annotations-1.21.jar:/opt/kyuubi/externals/engines/trino/annotations-4.1.1.4.jar:/opt/kyuubi/externals/engines/trino/antlr-runtime-3.5.3.jar:/opt/kyuubi/externals/engines/trino/commons-lang3-3.12.0.jar:/opt/kyuubi/externals/engines/trino/commons-logging-1.1.3.jar:/opt/kyuubi/externals/engines/trino/curator-client-2.12.0.jar:/opt/kyuubi/externals/engines/trino/curator-framework-2.12.0.jar:/opt/kyuubi/externals/engines/trino/curator-recipes-2.12.0.jar:/opt/kyuubi/externals/engines/trino/error_prone_annotations-2.14.0.jar:/opt/kyuubi/externals/engines/trino/failsafe-2.4.4.jar:/opt/kyuubi/externals/engines/trino/failureaccess-1.0.1.jar:/opt/kyuubi/externals/engines/trino/grpc-api-1.48.0.jar:/opt/kyuubi/externals/engines/trino/grpc-context-1.48.0.jar:/opt/kyuubi/externals/engines/trino/grpc-core-1.48.0.jar:/opt/kyuubi/externals/engines/trino/grpc-grpclb-1.48.0.jar:/opt/kyuubi/externals/engines/trino/grpc-netty-1.48.0.jar:/opt/kyuubi/externals/engines/trino/grpc-protobuf-1.48.0.jar:/opt/kyuubi/externals/engines/trino/grpc-protobuf-lite-1.48.0.jar:/opt/kyuubi/externals/engines/trino/grpc-stub-1.48.0.jar:/opt/kyuubi/externals/engines/trino/gson-2.9.0.jar:/opt/kyuubi/externals/engines/trino/guava-31.1-jre.jar:/opt/kyuubi/externals/engines/trino/hadoop-client-api-3.3.4.jar:/opt/kyuubi/externals/engines/trino/hadoop-client-runtime-3.3.4.jar:/opt/kyuubi/externals/engines/trino/hive-service-rpc-3.1.3.jar:/opt/kyuubi/externals/engines/trino/j2objc-annotations-1.3.jar:/opt/kyuubi/externals/engines/trino/jackson-annotations-2.14.2.jar:/opt/kyuubi/externals/engines/trino/jackson-core-2.14.2.jar:/opt/kyuubi/externals/engines/trino/jackson-databind-2.14.2.jar:/opt/kyuubi/externals/engines/trino/jackson-datatype-jdk8-2.14.2.jar:/opt/kyuubi/externals/engines/trino/jackson-module-scala_2.12-2.14.2.jar:/opt/kyuubi/externals/engines/trino/jcl-over-slf4j-1.7.36.jar:/opt/kyuubi/externals/engines/trino/jetcd-api-0.7.3.jar:/opt/kyuubi/externals/engines/trino/jetcd-common-0.7.3.jar:/opt/kyuubi/externals/engines/trino/jetcd-core-0.7.3.jar:/opt/kyuubi/externals/engines/trino/jetcd-grpc-0.7.3.jar:/opt/kyuubi/externals/engines/trino/jsr305-3.0.2.jar:/opt/kyuubi/externals/engines/trino/jul-to-slf4j-1.7.36.jar:/opt/kyuubi/externals/engines/trino/kyuubi-common_2.12-1.7.0.jar:/opt/kyuubi/externals/engines/trino/kyuubi-events_2.12-1.7.0.jar:/opt/kyuubi/externals/engines/trino/kyuubi-ha_2.12-1.7.0.jar:/opt/kyuubi/externals/engines/trino/kyuubi-trino-engine_2.12-1.7.0.jar:/opt/kyuubi/externals/engines/trino/libfb303-0.9.3.jar:/opt/kyuubi/externals/engines/trino/libthrift-0.9.3.jar:/opt/kyuubi/externals/engines/trino/log4j-1.2-api-2.19.0.jar:/opt/kyuubi/externals/engines/trino/log4j-api-2.19.0.jar:/opt/kyuubi/externals/engines/trino/log4j-core-2.19.0.jar:/opt/kyuubi/externals/engines/trino/log4j-slf4j-impl-2.19.0.jar:/opt/kyuubi/externals/engines/trino/netty-buffer-4.1.87.Final.jar:/opt/kyuubi/externals/engines/trino/netty-codec-4.1.87.Final.jar:/opt/kyuubi/externals/engines/trino/netty-codec-dns-4.1.87.Final.jar:/opt/kyuubi/externals/engines/trino/netty-codec-http-4.1.87.Final.jar:/opt/kyuubi/externals/engines/trino/netty-codec-http2-4.1.87.Final.jar:/opt/kyuubi/externals/engines/trino/netty-codec-socks-4.1.87.Final.jar:/opt/kyuubi/externals/engines/trino/netty-common-4.1.87.Final.jar:/opt/kyuubi/externals/engines/trino/netty-handler-4.1.87.Final.jar:/opt/kyuubi/externals/engines/trino/netty-handler-proxy-4.1.87.Final.jar:/opt/kyuubi/externals/engines/trino/netty-resolver-4.1.87.Final.jar:/opt/kyuubi/externals/engines/trino/netty-resolver-dns-4.1.87.Final.jar:/opt/kyuubi/externals/engines/trino/netty-transport-4.1.87.Final.jar:/opt/kyuubi/externals/engines/trino/netty-transport-classes-epoll-4.1.87.Final.jar:/opt/kyuubi/externals/engines/trino/netty-transport-native-epoll-4.1.87.Final-linux-aarch_64.jar:/opt/kyuubi/externals/engines/trino/netty-transport-native-epoll-4.1.87.Final-linux-x86_64.jar:/opt/kyuubi/externals/engines/trino/netty-transport-native-unix-common-4.1.87.Final.jar:/opt/kyuubi/externals/engines/trino/okhttp-3.14.9.jar:/opt/kyuubi/externals/engines/trino/okhttp-urlconnection-3.14.9.jar:/opt/kyuubi/externals/engines/trino/okio-1.17.2.jar:/opt/kyuubi/externals/engines/trino/paranamer-2.8.jar:/opt/kyuubi/externals/engines/trino/perfmark-api-0.25.0.jar:/opt/kyuubi/externals/engines/trino/proto-google-common-protos-2.9.0.jar:/opt/kyuubi/externals/engines/trino/protobuf-java-3.21.7.jar:/opt/kyuubi/externals/engines/trino/protobuf-java-util-3.21.7.jar:/opt/kyuubi/externals/engines/trino/scala-library-2.12.17.jar:/opt/kyuubi/externals/engines/trino/slf4j-api-1.7.36.jar:/opt/kyuubi/externals/engines/trino/trino-client-363.jar:/opt/kyuubi/externals/engines/trino/units-1.6.jar:/opt/kyuubi/externals/engines/trino/vertx-core-4.3.2.jar:/opt/kyuubi/externals/engines/trino/vertx-grpc-4.3.2.jar:/opt/kyuubi/externals/engines/trino/zookeeper-3.4.14.jar
2023-06-07 13:47:28.795 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib
2023-06-07 13:47:28.795 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.io.tmpdir=/tmp
2023-06-07 13:47:28.795 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.compiler=<NA>
2023-06-07 13:47:28.795 INFO org.apache.zookeeper.ZooKeeper: Client environment:os.name=Linux
2023-06-07 13:47:28.795 INFO org.apache.zookeeper.ZooKeeper: Client environment:os.arch=amd64
2023-06-07 13:47:28.795 INFO org.apache.zookeeper.ZooKeeper: Client environment:os.version=5.4.17-2136.307.3.1.el8uek.x86_64
2023-06-07 13:47:28.795 INFO org.apache.zookeeper.ZooKeeper: Client environment:user.name=root
2023-06-07 13:47:28.795 INFO org.apache.zookeeper.ZooKeeper: Client environment:user.home=/root
2023-06-07 13:47:28.795 INFO org.apache.zookeeper.ZooKeeper: Client environment:user.dir=/opt/kyuubi/work/admin
2023-06-07 13:47:28.796 INFO org.apache.zookeeper.ZooKeeper: Initiating client connection, connectString=kyuubi-86c95975c7-nx59s:2181 sessionTimeout=60000 watcher=org.apache.curator.ConnectionState@201b6b6f
2023-06-07 13:47:28.806 INFO org.apache.kyuubi.ha.client.EngineServiceDiscovery: Service[EngineServiceDiscovery] is initialized.
2023-06-07 13:47:28.806 INFO org.apache.kyuubi.engine.trino.TrinoTBinaryFrontendService: Service[TrinoTBinaryFrontend] is initialized.
2023-06-07 13:47:28.806 INFO org.apache.kyuubi.engine.trino.TrinoSqlEngine: Service[TrinoSQLEngine] is initialized.
2023-06-07 13:47:28.807 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server kyuubi-86c95975c7-nx59s/XXXXX:2181. Will not attempt to authenticate using SASL (unknown error)
2023-06-07 13:47:28.811 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to kyuubi-86c95975c7-nx59s/XXXXX:2181, initiating session
2023-06-07 13:47:28.814 INFO org.apache.zookeeper.ClientCnxn: Session establishment complete on server kyuubi-86c95975c7-nx59s/XXXXX:2181, sessionid = 0x10240e15f740002, negotiated timeout = 60000
2023-06-07 13:47:28.818 INFO org.apache.curator.framework.state.ConnectionStateManager: State change: CONNECTED
2023-06-07 13:47:28.820 INFO org.apache.kyuubi.ha.client.zookeeper.ZookeeperDiscoveryClient: Zookeeper client connection state changed to: CONNECTED
2023-06-07 13:47:28.857 INFO org.apache.kyuubi.engine.trino.event.handler.TrinoJsonLoggingEventHandler: Logging kyuubi events to file:/tmp/kyuubi/events/trino_engine/day=20230607/Trino-kyuubi-86c95975c7-nx59s.json
2023-06-07 13:47:29.172 INFO org.apache.kyuubi.engine.trino.operation.TrinoOperationManager: Service[TrinoOperationManager] is started.
2023-06-07 13:47:29.172 INFO org.apache.kyuubi.engine.trino.session.TrinoSessionManager: Service[TrinoSessionManager] is started.
2023-06-07 13:47:29.172 INFO org.apache.kyuubi.engine.trino.TrinoBackendService: Service[TrinoBackendService] is started.
2023-06-07 13:47:29.245 INFO org.apache.kyuubi.ha.client.zookeeper.ZookeeperDiscoveryClient: Created a /kyuubi_1.7.0_USER_TRINO/admin/default/serviceUri=kyuubi-86c95975c7-nx59s:46789;version=1.7.0;refId=1a38d5b0-2f1d-486f-bca2-da78371d63cc;sequence=0000000000 on ZooKeeper for KyuubiServer uri: kyuubi-86c95975c7-nx59s:46789
2023-06-07 13:47:29.246 INFO org.apache.kyuubi.ha.client.EngineServiceDiscovery: Service[EngineServiceDiscovery] is started.
2023-06-07 13:47:29.246 INFO org.apache.kyuubi.engine.trino.TrinoTBinaryFrontendService: Service[TrinoTBinaryFrontend] is started.
2023-06-07 13:47:29.246 INFO org.apache.kyuubi.engine.trino.TrinoSqlEngine: Service[TrinoSQLEngine] is started.
2023-06-07 13:47:29.448 INFO org.apache.kyuubi.engine.trino.TrinoTBinaryFrontendService: Client protocol version:HIVE_CLI_SERVICE_PROTOCOL_V10
2023-06-07 13:47:29.454 INFO org.apache.kyuubi.engine.trino.session.TrinoSessionManager: Opening session for admin@XXXX
2023-06-07 13:47:29.599 INFO org.apache.kyuubi.engine.trino.event.handler.TrinoJsonLoggingEventHandler: Logging kyuubi events to file:/tmp/kyuubi/events/trino_session/day=20230607/Trino-kyuubi-86c95975c7-nx59s.json
2023-06-07 13:47:29.613 INFO org.apache.kyuubi.engine.trino.session.TrinoSessionManager: admin's session with SessionHandle [78a28437-ff95-45b8-979a-97732bc04faa] is opened, current opening sessions 1
2023-06-07 13:47:32.841 INFO org.apache.kyuubi.operation.log.OperationLog: Creating operation log file /opt/kyuubi/work/engine_operation_logs/78a28437-ff95-45b8-979a-97732bc04faa/0d3cb82b-fcdd-49fa-9a50-bb8d10780006
2023-06-07 13:47:32.850 INFO org.apache.kyuubi.engine.trino.event.handler.TrinoJsonLoggingEventHandler: Logging kyuubi events to file:/tmp/kyuubi/events/trino_operation/day=20230607/Trino-kyuubi-86c95975c7-nx59s.json
2023-06-07 13:47:32.870 INFO org.apache.kyuubi.engine.trino.operation.ExecuteStatement: Processing admin's query[0d3cb82b-fcdd-49fa-9a50-bb8d10780006]: PENDING_STATE -> RUNNING_STATE, statement:
use default
2023-06-07 13:47:32.894 INFO org.apache.kyuubi.engine.trino.TrinoStatement: Execute with Trino query id: 20230607_054732_00021_gvgri
2023-06-07 13:47:32.894 INFO org.apache.kyuubi.engine.trino.operation.ExecuteStatement: Execute in full collect mode
2023-06-07 13:47:32.899 INFO org.apache.kyuubi.engine.trino.operation.ExecuteStatement: Processing admin's query[0d3cb82b-fcdd-49fa-9a50-bb8d10780006]: RUNNING_STATE -> FINISHED_STATE, time taken: 0.028 seconds
2023-06-07 13:47:32.984 INFO org.apache.kyuubi.engine.trino.TrinoTBinaryFrontendService: Session [SessionHandle [78a28437-ff95-45b8-979a-97732bc04faa]] disconnected without closing properly, close it now
2023-06-07 13:47:32.984 INFO org.apache.kyuubi.engine.trino.session.TrinoSessionManager: admin's session with SessionHandle [78a28437-ff95-45b8-979a-97732bc04faa] is closed, current opening sessions 0

It can be seen from the log that after the statement is executed, it will display Session [SessionHandle [78a28437-ff95-45b8-979a-97732bc04faa]] disconnected without closing properly. I don’t know why this is, it should also be the reason for the error

haoranchuixue commented 1 year ago

I also encountered this problem.

After using other engines, everything is normal.

When using the trino engine and using the use schema, this error will be reported in the query.

pan3793 commented 1 year ago

cc @hddong