[teiid-issues] [JBoss JIRA] (TEIID-5185) JDBC client intermittently hangs when processing multi-batch result sets from server

[ https://issues.jboss.org/browse/TEIID-5185?page=com.atlassian.jira.plugin... ] Krum Bakalsky updated TEIID-5185: --------------------------------- Description: We have a server-side application that is powered by Teiid version 9.3.4, and that exposes a Teiid JDBC endpoint to its clients. A couple of app instances are configured to sit behind a VIP load balancer, that works on the TCP level. We have been experiencing intermittently following problem, when we run Teiid 9.3.4 client to execute multi-batch queries to the server: * client successfully fetches few batches from server; * client hangs and its thread blocks on waiting for the next batch to be delivered on the network; * after 1 hour client throws exceptions that Socket is closed. When building up the JDBC connection URL the client refers directly to the server's VIP, and does not list particular service hosts: jdbc:teiid:<Application>@mm://<VIP's DNS name>:<port> Client thread's call stack: {code} "Thread Group 1-1" #41 prio=6 os_prio=0 tid=0x000000005e03a800 nid=0x17bc runnable [0x00000000623ae000] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.socketRead(Unknown Source) at java.net.SocketInputStream.read(Unknown Source) at java.net.SocketInputStream.read(Unknown Source) at java.io.BufferedInputStream.fill(Unknown Source) at java.io.BufferedInputStream.read(Unknown Source) - locked <0x00000000f5f32420> (a org.teiid.core.util.AccessibleBufferedInputStream) at java.io.DataInputStream.readInt(Unknown Source) at org.teiid.netty.handler.codec.serialization.ObjectDecoderInputStream.readObjectOverride(ObjectDecoderInputStream.java:97) at java.io.ObjectInputStream.readObject(Unknown Source) at org.teiid.net.socket.OioOjbectChannelFactory$OioObjectChannel.read(OioOjbectChannelFactory.java:117) at org.teiid.net.socket.SocketServerInstanceImpl.read(SocketServerInstanceImpl.java:324) at sun.reflect.GeneratedMethodAccessor22.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) at java.lang.reflect.Method.invoke(Unknown Source) at org.teiid.net.socket.SocketServerConnectionFactory$ShutdownHandler.invoke(SocketServerConnectionFactory.java:98) at com.sun.proxy.$Proxy21.read(Unknown Source) at org.teiid.net.socket.SocketServerInstanceImpl$RemoteInvocationHandler$1.get(SocketServerInstanceImpl.java:427) at org.teiid.jdbc.ResultSetImpl.getResults(ResultSetImpl.java:449) at org.teiid.jdbc.ResultSetImpl.requestBatch(ResultSetImpl.java:382) at org.teiid.jdbc.BatchResults.requestBatchAndWait(BatchResults.java:227) at org.teiid.jdbc.BatchResults.requestNextBatch(BatchResults.java:142) at org.teiid.jdbc.BatchResults.hasNext(BatchResults.java:253) at org.teiid.jdbc.ResultSetImpl.hasNext(ResultSetImpl.java:510) at org.teiid.jdbc.ResultSetImpl.next(ResultSetImpl.java:259) at org.apache.commons.dbcp2.DelegatingResultSet.next(DelegatingResultSet.java:191) at org.apache.commons.dbcp2.DelegatingResultSet.next(DelegatingResultSet.java:191) at org.apache.jmeter.protocol.jdbc.AbstractJDBCTestElement.getStringFromResultSet(AbstractJDBCTestElement.java:535) at org.apache.jmeter.protocol.jdbc.AbstractJDBCTestElement.execute(AbstractJDBCTestElement.java:174) at org.apache.jmeter.protocol.jdbc.sampler.JDBCSampler.sample(JDBCSampler.java:84) at org.apache.jmeter.threads.JMeterThread.executeSamplePackage(JMeterThread.java:491) at org.apache.jmeter.threads.JMeterThread.processSampler(JMeterThread.java:425) at org.apache.jmeter.threads.JMeterThread.run(JMeterThread.java:254) at java.lang.Thread.run(Unknown Source) Locked ownable synchronizers: - None {code} Client side exception after 1 hour: {code} 2017-12-19 13:17:07,160 WARN o.a.j.p.j.AbstractJDBCTestElement: Error closing ResultSet org.teiid.jdbc.TeiidSQLException: TEIID20013 java.net.SocketException: Socket closed at org.teiid.jdbc.TeiidSQLException.create(TeiidSQLException.java:135) ~[teiid-9.3.4-jdbc.jar:9.3.4] at org.teiid.jdbc.TeiidSQLException.create(TeiidSQLException.java:71) ~[teiid-9.3.4-jdbc.jar:9.3.4] at org.teiid.jdbc.ResultSetImpl.close(ResultSetImpl.java:168) ~[teiid-9.3.4-jdbc.jar:9.3.4] at org.apache.commons.dbcp2.DelegatingResultSet.close(DelegatingResultSet.java:170) ~[commons-dbcp2-2.1.1.jar:2.1.1] at org.apache.commons.dbcp2.DelegatingResultSet.close(DelegatingResultSet.java:170) ~[commons-dbcp2-2.1.1.jar:2.1.1] at org.apache.jmeter.protocol.jdbc.AbstractJDBCTestElement.close(AbstractJDBCTestElement.java:607) [ApacheJMeter_jdbc.jar:3.2 r1790748] at org.apache.jmeter.protocol.jdbc.AbstractJDBCTestElement.execute(AbstractJDBCTestElement.java:176) [ApacheJMeter_jdbc.jar:3.2 r1790748] at org.apache.jmeter.protocol.jdbc.sampler.JDBCSampler.sample(JDBCSampler.java:84) [ApacheJMeter_jdbc.jar:3.2 r1790748] at org.apache.jmeter.threads.JMeterThread.executeSamplePackage(JMeterThread.java:491) [ApacheJMeter_core.jar:3.2 r1790748] at org.apache.jmeter.threads.JMeterThread.processSampler(JMeterThread.java:425) [ApacheJMeter_core.jar:3.2 r1790748] at org.apache.jmeter.threads.JMeterThread.run(JMeterThread.java:254) [ApacheJMeter_core.jar:3.2 r1790748] at java.lang.Thread.run(Unknown Source) [?:1.8.0_121] Caused by: org.teiid.core.TeiidComponentException: TEIID20013 java.net.SocketException: Socket closed at org.teiid.client.util.ExceptionUtil.convertException(ExceptionUtil.java:65) ~[teiid-9.3.4-jdbc.jar:9.3.4] at org.teiid.net.socket.SocketServerInstanceImpl$RemoteInvocationHandler.invoke(SocketServerInstanceImpl.java:445) ~[teiid-9.3.4-jdbc.jar:9.3.4] at org.teiid.net.socket.SocketServerConnection$1.invoke(SocketServerConnection.java:293) ~[teiid-9.3.4-jdbc.jar:9.3.4] at com.sun.proxy.$Proxy24.closeRequest(Unknown Source) ~[?:?] at org.teiid.jdbc.ResultSetImpl.close(ResultSetImpl.java:164) ~[teiid-9.3.4-jdbc.jar:9.3.4] ... 9 more Caused by: org.teiid.net.socket.SingleInstanceCommunicationException: TEIID20013 java.net.SocketException: Socket closed at org.teiid.net.socket.SocketServerInstanceImpl.send(SocketServerInstanceImpl.java:217) ~[teiid-9.3.4-jdbc.jar:9.3.4] at sun.reflect.GeneratedMethodAccessor24.invoke(Unknown Source) ~[?:?] at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_121] at java.lang.reflect.Method.invoke(Unknown Source) ~[?:1.8.0_121] at org.teiid.net.socket.SocketServerConnectionFactory$ShutdownHandler.invoke(SocketServerConnectionFactory.java:98) ~[teiid-9.3.4-jdbc.jar:9.3.4] at com.sun.proxy.$Proxy21.send(Unknown Source) ~[?:?] at org.teiid.net.socket.SocketServerInstanceImpl$RemoteInvocationHandler.invoke(SocketServerInstanceImpl.java:433) ~[teiid-9.3.4-jdbc.jar:9.3.4] at org.teiid.net.socket.SocketServerConnection$1.invoke(SocketServerConnection.java:293) ~[teiid-9.3.4-jdbc.jar:9.3.4] at com.sun.proxy.$Proxy24.closeRequest(Unknown Source) ~[?:?] at org.teiid.jdbc.ResultSetImpl.close(ResultSetImpl.java:164) ~[teiid-9.3.4-jdbc.jar:9.3.4] ... 9 more Caused by: java.util.concurrent.ExecutionException: java.net.SocketException: Socket closed at org.teiid.client.util.ResultsFuture.convertResult(ResultsFuture.java:104) ~[teiid-9.3.4-jdbc.jar:9.3.4] at org.teiid.client.util.ResultsFuture.get(ResultsFuture.java:99) ~[teiid-9.3.4-jdbc.jar:9.3.4] at org.teiid.net.socket.SocketServerInstanceImpl.send(SocketServerInstanceImpl.java:214) ~[teiid-9.3.4-jdbc.jar:9.3.4] at sun.reflect.GeneratedMethodAccessor24.invoke(Unknown Source) ~[?:?] at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_121] at java.lang.reflect.Method.invoke(Unknown Source) ~[?:1.8.0_121] at org.teiid.net.socket.SocketServerConnectionFactory$ShutdownHandler.invoke(SocketServerConnectionFactory.java:98) ~[teiid-9.3.4-jdbc.jar:9.3.4] at com.sun.proxy.$Proxy21.send(Unknown Source) ~[?:?] at org.teiid.net.socket.SocketServerInstanceImpl$RemoteInvocationHandler.invoke(SocketServerInstanceImpl.java:433) ~[teiid-9.3.4-jdbc.jar:9.3.4] at org.teiid.net.socket.SocketServerConnection$1.invoke(SocketServerConnection.java:293) ~[teiid-9.3.4-jdbc.jar:9.3.4] at com.sun.proxy.$Proxy24.closeRequest(Unknown Source) ~[?:?] at org.teiid.jdbc.ResultSetImpl.close(ResultSetImpl.java:164) ~[teiid-9.3.4-jdbc.jar:9.3.4] ... 9 more Caused by: java.net.SocketException: Socket closed at java.net.SocketOutputStream.socketWrite(Unknown Source) ~[?:1.8.0_121] at java.net.SocketOutputStream.write(Unknown Source) ~[?:1.8.0_121] at java.io.DataOutputStream.write(Unknown Source) ~[?:1.8.0_121] at org.teiid.core.util.MultiArrayOutputStream.writeTo(MultiArrayOutputStream.java:94) ~[teiid-9.3.4-jdbc.jar:9.3.4] at org.teiid.netty.handler.codec.serialization.ObjectEncoderOutputStream.writeObjectOverride(ObjectEncoderOutputStream.java:70) ~[teiid-9.3.4-jdbc.jar:9.3.4] at java.io.ObjectOutputStream.writeObject(Unknown Source) ~[?:1.8.0_121] at org.teiid.net.socket.OioOjbectChannelFactory$OioObjectChannel.write(OioOjbectChannelFactory.java:136) ~[teiid-9.3.4-jdbc.jar:9.3.4] at org.teiid.net.socket.SocketServerInstanceImpl.send(SocketServerInstanceImpl.java:213) ~[teiid-9.3.4-jdbc.jar:9.3.4] at sun.reflect.GeneratedMethodAccessor24.invoke(Unknown Source) ~[?:?] at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_121] at java.lang.reflect.Method.invoke(Unknown Source) ~[?:1.8.0_121] at org.teiid.net.socket.SocketServerConnectionFactory$ShutdownHandler.invoke(SocketServerConnectionFactory.java:98) ~[teiid-9.3.4-jdbc.jar:9.3.4] at com.sun.proxy.$Proxy21.send(Unknown Source) ~[?:?] at org.teiid.net.socket.SocketServerInstanceImpl$RemoteInvocationHandler.invoke(SocketServerInstanceImpl.java:433) ~[teiid-9.3.4-jdbc.jar:9.3.4] at org.teiid.net.socket.SocketServerConnection$1.invoke(SocketServerConnection.java:293) ~[teiid-9.3.4-jdbc.jar:9.3.4] at com.sun.proxy.$Proxy24.closeRequest(Unknown Source) ~[?:?] at org.teiid.jdbc.ResultSetImpl.close(ResultSetImpl.java:164) ~[teiid-9.3.4-jdbc.jar:9.3.4] ... 9 more {code} Server-side log excerpt, after raising logger levels to Debug: {code} 2017-12-15 12:00:45.625 [NIO36 ] DEBUG - processing message:MessageHolder: key=550774 contents=Invoke interface org.teiid.client.DQP.executeRequest 2017-12-15 12:00:47.730 [ocessorQueue14017479] DEBUG - send message: MessageHolder: key=550774 contents=ResultsMessage rowCount=256 finalRow=-1 2017-12-15 12:00:47.737 [NIO36 ] DEBUG - processing message:MessageHolder: key=550776 contents=Invoke interface org.teiid.client.DQP.processCursorRequest 2017-12-15 12:00:47.738 [ocessorQueue14017553] DEBUG - send message: MessageHolder: key=550776 contents=ResultsMessage rowCount=2048 finalRow=-1 2017-12-15 12:00:47.755 [NIO36 ] DEBUG - processing message:MessageHolder: key=550777 contents=Invoke interface org.teiid.client.DQP.processCursorRequest 2017-12-15 12:00:47.756 [ocessorQueue14017554] DEBUG - send message: MessageHolder: key=550777 contents=ResultsMessage rowCount=2048 finalRow=-1 2017-12-15 12:00:48.389 [NIO36 ] DEBUG - processing message:MessageHolder: key=550778 contents=Invoke interface org.teiid.client.DQP.processCursorRequest 2017-12-15 12:00:48.389 [ocessorQueue14017556] DEBUG - send message: MessageHolder: key=550778 contents=ResultsMessage rowCount=2048 finalRow=-1 2017-12-15 12:00:48.825 [NIO36 ] DEBUG - processing message:MessageHolder: key=550779 contents=Invoke interface org.teiid.client.DQP.processCursorRequest 2017-12-15 12:00:48.826 [ocessorQueue14017557] DEBUG - send message: MessageHolder: key=550779 contents=ResultsMessage rowCount=2048 finalRow=-1 2017-12-15 12:00:48.932 [NIO36 ] DEBUG - processing message:MessageHolder: key=550780 contents=Invoke interface org.teiid.client.DQP.processCursorRequest 2017-12-15 12:00:48.933 [ocessorQueue14017558] DEBUG - send message: MessageHolder: key=550780 contents=ResultsMessage rowCount=2048 finalRow=-1 2017-12-15 12:02:18.386 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:05:55.327 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:09:29.545 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:13:08.903 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:16:41.864 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:20:16.875 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:23:57.860 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:27:30.273 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:31:07.795 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:34:46.439 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:38:23.325 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:41:59.227 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:45:35.526 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:49:14.088 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:52:46.177 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:56:24.407 [NIO36 ] DEBUG - Channel closed 2017-12-15 13:00:03.109 [NIO36 ] DEBUG - Channel closed 2017-12-15 13:00:52.143 [NIO36 ] DEBUG - TEIID40114 Unhandled exception, closing client instance: Connection reset by peer java.io.IOException: Connection reset by peer at sun.nio.ch.FileDispatcherImpl.read0(Native Method) at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39) at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223) at sun.nio.ch.IOUtil.read(IOUtil.java:192) at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:380) at io.netty.buffer.UnpooledUnsafeDirectByteBuf.setBytes(UnpooledUnsafeDirectByteBuf.java:447) at io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:880) at io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:242) at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:119) at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:511) at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:468) at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:382) at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:354) at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) 2017-12-15 13:00:52.143 [NIO36 ] DEBUG - Channel closed 2017-12-15 13:03:34.811 [NIO36 ] DEBUG - Channel closed {code} Legend: * 'Channel closed' is logged from org.teiid.transport.SSLAwareChannelHandler class, and its channelInactive method; * 'MessageHolder' logs are from org.teiid.net.socket.Message; * the log lines that contain rowCount, finalRow, etc. are coming from org.teiid.transport.SocketClientInstance. The problem is rarely reproducible, but it happens a few times every day, while running the JMeter tests full day. W was: We have a server-side application that is powered by Teiid version 9.3.4, and that exposes a Teiid JDBC endpoint to its clients. A couple of app instances are configured to sit behind a VIP load balancer, that works on the TCP level. We have been experiencing intermittently following problem, when we run Teiid 9.3.4 client to execute multi-batch queries to the server: * client successfully fetches few batches from server; * client hangs and its thread blocks on waiting for the next batch to be delivered on the network; * after 1 hour client throws exceptions that Socket is closed. Client thread's call stack: {code} "Thread Group 1-1" #41 prio=6 os_prio=0 tid=0x000000005e03a800 nid=0x17bc runnable [0x00000000623ae000] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.socketRead(Unknown Source) at java.net.SocketInputStream.read(Unknown Source) at java.net.SocketInputStream.read(Unknown Source) at java.io.BufferedInputStream.fill(Unknown Source) at java.io.BufferedInputStream.read(Unknown Source) - locked <0x00000000f5f32420> (a org.teiid.core.util.AccessibleBufferedInputStream) at java.io.DataInputStream.readInt(Unknown Source) at org.teiid.netty.handler.codec.serialization.ObjectDecoderInputStream.readObjectOverride(ObjectDecoderInputStream.java:97) at java.io.ObjectInputStream.readObject(Unknown Source) at org.teiid.net.socket.OioOjbectChannelFactory$OioObjectChannel.read(OioOjbectChannelFactory.java:117) at org.teiid.net.socket.SocketServerInstanceImpl.read(SocketServerInstanceImpl.java:324) at sun.reflect.GeneratedMethodAccessor22.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) at java.lang.reflect.Method.invoke(Unknown Source) at org.teiid.net.socket.SocketServerConnectionFactory$ShutdownHandler.invoke(SocketServerConnectionFactory.java:98) at com.sun.proxy.$Proxy21.read(Unknown Source) at org.teiid.net.socket.SocketServerInstanceImpl$RemoteInvocationHandler$1.get(SocketServerInstanceImpl.java:427) at org.teiid.jdbc.ResultSetImpl.getResults(ResultSetImpl.java:449) at org.teiid.jdbc.ResultSetImpl.requestBatch(ResultSetImpl.java:382) at org.teiid.jdbc.BatchResults.requestBatchAndWait(BatchResults.java:227) at org.teiid.jdbc.BatchResults.requestNextBatch(BatchResults.java:142) at org.teiid.jdbc.BatchResults.hasNext(BatchResults.java:253) at org.teiid.jdbc.ResultSetImpl.hasNext(ResultSetImpl.java:510) at org.teiid.jdbc.ResultSetImpl.next(ResultSetImpl.java:259) at org.apache.commons.dbcp2.DelegatingResultSet.next(DelegatingResultSet.java:191) at org.apache.commons.dbcp2.DelegatingResultSet.next(DelegatingResultSet.java:191) at org.apache.jmeter.protocol.jdbc.AbstractJDBCTestElement.getStringFromResultSet(AbstractJDBCTestElement.java:535) at org.apache.jmeter.protocol.jdbc.AbstractJDBCTestElement.execute(AbstractJDBCTestElement.java:174) at org.apache.jmeter.protocol.jdbc.sampler.JDBCSampler.sample(JDBCSampler.java:84) at org.apache.jmeter.threads.JMeterThread.executeSamplePackage(JMeterThread.java:491) at org.apache.jmeter.threads.JMeterThread.processSampler(JMeterThread.java:425) at org.apache.jmeter.threads.JMeterThread.run(JMeterThread.java:254) at java.lang.Thread.run(Unknown Source) Locked ownable synchronizers: - None {code} Client side exception after 1 hour: {code} 2017-12-19 13:17:07,160 WARN o.a.j.p.j.AbstractJDBCTestElement: Error closing ResultSet org.teiid.jdbc.TeiidSQLException: TEIID20013 java.net.SocketException: Socket closed at org.teiid.jdbc.TeiidSQLException.create(TeiidSQLException.java:135) ~[teiid-9.3.4-jdbc.jar:9.3.4] at org.teiid.jdbc.TeiidSQLException.create(TeiidSQLException.java:71) ~[teiid-9.3.4-jdbc.jar:9.3.4] at org.teiid.jdbc.ResultSetImpl.close(ResultSetImpl.java:168) ~[teiid-9.3.4-jdbc.jar:9.3.4] at org.apache.commons.dbcp2.DelegatingResultSet.close(DelegatingResultSet.java:170) ~[commons-dbcp2-2.1.1.jar:2.1.1] at org.apache.commons.dbcp2.DelegatingResultSet.close(DelegatingResultSet.java:170) ~[commons-dbcp2-2.1.1.jar:2.1.1] at org.apache.jmeter.protocol.jdbc.AbstractJDBCTestElement.close(AbstractJDBCTestElement.java:607) [ApacheJMeter_jdbc.jar:3.2 r1790748] at org.apache.jmeter.protocol.jdbc.AbstractJDBCTestElement.execute(AbstractJDBCTestElement.java:176) [ApacheJMeter_jdbc.jar:3.2 r1790748] at org.apache.jmeter.protocol.jdbc.sampler.JDBCSampler.sample(JDBCSampler.java:84) [ApacheJMeter_jdbc.jar:3.2 r1790748] at org.apache.jmeter.threads.JMeterThread.executeSamplePackage(JMeterThread.java:491) [ApacheJMeter_core.jar:3.2 r1790748] at org.apache.jmeter.threads.JMeterThread.processSampler(JMeterThread.java:425) [ApacheJMeter_core.jar:3.2 r1790748] at org.apache.jmeter.threads.JMeterThread.run(JMeterThread.java:254) [ApacheJMeter_core.jar:3.2 r1790748] at java.lang.Thread.run(Unknown Source) [?:1.8.0_121] Caused by: org.teiid.core.TeiidComponentException: TEIID20013 java.net.SocketException: Socket closed at org.teiid.client.util.ExceptionUtil.convertException(ExceptionUtil.java:65) ~[teiid-9.3.4-jdbc.jar:9.3.4] at org.teiid.net.socket.SocketServerInstanceImpl$RemoteInvocationHandler.invoke(SocketServerInstanceImpl.java:445) ~[teiid-9.3.4-jdbc.jar:9.3.4] at org.teiid.net.socket.SocketServerConnection$1.invoke(SocketServerConnection.java:293) ~[teiid-9.3.4-jdbc.jar:9.3.4] at com.sun.proxy.$Proxy24.closeRequest(Unknown Source) ~[?:?] at org.teiid.jdbc.ResultSetImpl.close(ResultSetImpl.java:164) ~[teiid-9.3.4-jdbc.jar:9.3.4] ... 9 more Caused by: org.teiid.net.socket.SingleInstanceCommunicationException: TEIID20013 java.net.SocketException: Socket closed at org.teiid.net.socket.SocketServerInstanceImpl.send(SocketServerInstanceImpl.java:217) ~[teiid-9.3.4-jdbc.jar:9.3.4] at sun.reflect.GeneratedMethodAccessor24.invoke(Unknown Source) ~[?:?] at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_121] at java.lang.reflect.Method.invoke(Unknown Source) ~[?:1.8.0_121] at org.teiid.net.socket.SocketServerConnectionFactory$ShutdownHandler.invoke(SocketServerConnectionFactory.java:98) ~[teiid-9.3.4-jdbc.jar:9.3.4] at com.sun.proxy.$Proxy21.send(Unknown Source) ~[?:?] at org.teiid.net.socket.SocketServerInstanceImpl$RemoteInvocationHandler.invoke(SocketServerInstanceImpl.java:433) ~[teiid-9.3.4-jdbc.jar:9.3.4] at org.teiid.net.socket.SocketServerConnection$1.invoke(SocketServerConnection.java:293) ~[teiid-9.3.4-jdbc.jar:9.3.4] at com.sun.proxy.$Proxy24.closeRequest(Unknown Source) ~[?:?] at org.teiid.jdbc.ResultSetImpl.close(ResultSetImpl.java:164) ~[teiid-9.3.4-jdbc.jar:9.3.4] ... 9 more Caused by: java.util.concurrent.ExecutionException: java.net.SocketException: Socket closed at org.teiid.client.util.ResultsFuture.convertResult(ResultsFuture.java:104) ~[teiid-9.3.4-jdbc.jar:9.3.4] at org.teiid.client.util.ResultsFuture.get(ResultsFuture.java:99) ~[teiid-9.3.4-jdbc.jar:9.3.4] at org.teiid.net.socket.SocketServerInstanceImpl.send(SocketServerInstanceImpl.java:214) ~[teiid-9.3.4-jdbc.jar:9.3.4] at sun.reflect.GeneratedMethodAccessor24.invoke(Unknown Source) ~[?:?] at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_121] at java.lang.reflect.Method.invoke(Unknown Source) ~[?:1.8.0_121] at org.teiid.net.socket.SocketServerConnectionFactory$ShutdownHandler.invoke(SocketServerConnectionFactory.java:98) ~[teiid-9.3.4-jdbc.jar:9.3.4] at com.sun.proxy.$Proxy21.send(Unknown Source) ~[?:?] at org.teiid.net.socket.SocketServerInstanceImpl$RemoteInvocationHandler.invoke(SocketServerInstanceImpl.java:433) ~[teiid-9.3.4-jdbc.jar:9.3.4] at org.teiid.net.socket.SocketServerConnection$1.invoke(SocketServerConnection.java:293) ~[teiid-9.3.4-jdbc.jar:9.3.4] at com.sun.proxy.$Proxy24.closeRequest(Unknown Source) ~[?:?] at org.teiid.jdbc.ResultSetImpl.close(ResultSetImpl.java:164) ~[teiid-9.3.4-jdbc.jar:9.3.4] ... 9 more Caused by: java.net.SocketException: Socket closed at java.net.SocketOutputStream.socketWrite(Unknown Source) ~[?:1.8.0_121] at java.net.SocketOutputStream.write(Unknown Source) ~[?:1.8.0_121] at java.io.DataOutputStream.write(Unknown Source) ~[?:1.8.0_121] at org.teiid.core.util.MultiArrayOutputStream.writeTo(MultiArrayOutputStream.java:94) ~[teiid-9.3.4-jdbc.jar:9.3.4] at org.teiid.netty.handler.codec.serialization.ObjectEncoderOutputStream.writeObjectOverride(ObjectEncoderOutputStream.java:70) ~[teiid-9.3.4-jdbc.jar:9.3.4] at java.io.ObjectOutputStream.writeObject(Unknown Source) ~[?:1.8.0_121] at org.teiid.net.socket.OioOjbectChannelFactory$OioObjectChannel.write(OioOjbectChannelFactory.java:136) ~[teiid-9.3.4-jdbc.jar:9.3.4] at org.teiid.net.socket.SocketServerInstanceImpl.send(SocketServerInstanceImpl.java:213) ~[teiid-9.3.4-jdbc.jar:9.3.4] at sun.reflect.GeneratedMethodAccessor24.invoke(Unknown Source) ~[?:?] at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_121] at java.lang.reflect.Method.invoke(Unknown Source) ~[?:1.8.0_121] at org.teiid.net.socket.SocketServerConnectionFactory$ShutdownHandler.invoke(SocketServerConnectionFactory.java:98) ~[teiid-9.3.4-jdbc.jar:9.3.4] at com.sun.proxy.$Proxy21.send(Unknown Source) ~[?:?] at org.teiid.net.socket.SocketServerInstanceImpl$RemoteInvocationHandler.invoke(SocketServerInstanceImpl.java:433) ~[teiid-9.3.4-jdbc.jar:9.3.4] at org.teiid.net.socket.SocketServerConnection$1.invoke(SocketServerConnection.java:293) ~[teiid-9.3.4-jdbc.jar:9.3.4] at com.sun.proxy.$Proxy24.closeRequest(Unknown Source) ~[?:?] at org.teiid.jdbc.ResultSetImpl.close(ResultSetImpl.java:164) ~[teiid-9.3.4-jdbc.jar:9.3.4] ... 9 more {code} Server-side log excerpt, after raising logger levels to Debug: {code} 2017-12-15 12:00:45.625 [NIO36 ] DEBUG - processing message:MessageHolder: key=550774 contents=Invoke interface org.teiid.client.DQP.executeRequest 2017-12-15 12:00:47.730 [ocessorQueue14017479] DEBUG - send message: MessageHolder: key=550774 contents=ResultsMessage rowCount=256 finalRow=-1 2017-12-15 12:00:47.737 [NIO36 ] DEBUG - processing message:MessageHolder: key=550776 contents=Invoke interface org.teiid.client.DQP.processCursorRequest 2017-12-15 12:00:47.738 [ocessorQueue14017553] DEBUG - send message: MessageHolder: key=550776 contents=ResultsMessage rowCount=2048 finalRow=-1 2017-12-15 12:00:47.755 [NIO36 ] DEBUG - processing message:MessageHolder: key=550777 contents=Invoke interface org.teiid.client.DQP.processCursorRequest 2017-12-15 12:00:47.756 [ocessorQueue14017554] DEBUG - send message: MessageHolder: key=550777 contents=ResultsMessage rowCount=2048 finalRow=-1 2017-12-15 12:00:48.389 [NIO36 ] DEBUG - processing message:MessageHolder: key=550778 contents=Invoke interface org.teiid.client.DQP.processCursorRequest 2017-12-15 12:00:48.389 [ocessorQueue14017556] DEBUG - send message: MessageHolder: key=550778 contents=ResultsMessage rowCount=2048 finalRow=-1 2017-12-15 12:00:48.825 [NIO36 ] DEBUG - processing message:MessageHolder: key=550779 contents=Invoke interface org.teiid.client.DQP.processCursorRequest 2017-12-15 12:00:48.826 [ocessorQueue14017557] DEBUG - send message: MessageHolder: key=550779 contents=ResultsMessage rowCount=2048 finalRow=-1 2017-12-15 12:00:48.932 [NIO36 ] DEBUG - processing message:MessageHolder: key=550780 contents=Invoke interface org.teiid.client.DQP.processCursorRequest 2017-12-15 12:00:48.933 [ocessorQueue14017558] DEBUG - send message: MessageHolder: key=550780 contents=ResultsMessage rowCount=2048 finalRow=-1 2017-12-15 12:02:18.386 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:05:55.327 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:09:29.545 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:13:08.903 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:16:41.864 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:20:16.875 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:23:57.860 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:27:30.273 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:31:07.795 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:34:46.439 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:38:23.325 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:41:59.227 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:45:35.526 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:49:14.088 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:52:46.177 [NIO36 ] DEBUG - Channel closed 2017-12-15 12:56:24.407 [NIO36 ] DEBUG - Channel closed 2017-12-15 13:00:03.109 [NIO36 ] DEBUG - Channel closed 2017-12-15 13:00:52.143 [NIO36 ] DEBUG - TEIID40114 Unhandled exception, closing client instance: Connection reset by peer java.io.IOException: Connection reset by peer at sun.nio.ch.FileDispatcherImpl.read0(Native Method) at sun.nio.ch.SocketDispatcher.read(SocketDispatcher.java:39) at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:223) at sun.nio.ch.IOUtil.read(IOUtil.java:192) at sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:380) at io.netty.buffer.UnpooledUnsafeDirectByteBuf.setBytes(UnpooledUnsafeDirectByteBuf.java:447) at io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:880) at io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:242) at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:119) at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:511) at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:468) at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:382) at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:354) at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) at java.lang.Thread.run(Thread.java:745) 2017-12-15 13:00:52.143 [NIO36 ] DEBUG - Channel closed 2017-12-15 13:03:34.811 [NIO36 ] DEBUG - Channel closed {code} Legend: * 'Channel closed' is logged from org.teiid.transport.SSLAwareChannelHandler class, and its channelInactive method; * 'MessageHolder' logs are from org.teiid.net.socket.Message; * the log lines that contain rowCount, finalRow, etc. are coming from org.teiid.transport.SocketClientInstance. -- This message was sent by Atlassian JIRA (v7.5.0#75005)