Mike, the behavior appears to be consistent. I am running against an iRODS Server 3.2. I thought that perhaps is was a change in the behavior of the IRODSFileSystem.closeAndEatExceptions() method I was using to close connections after each getOperation in my multithreaded application. However, commenting out that line only resulted in a delay of the ClosedChannelExceptions, which were then followed by IOExceptions and SocketExceptions:
73263 [pool-4-thread-2] WARN org.irods.jargon.core.connection.IRODSSimpleProtocolManager returnConnectionWithIoException 88- connection returned with IOException, will forcefully close and remove from session cache
73263 [pool-4-thread-2] WARN org.irods.jargon.core.connection.IRODSSession discardSessionForErrors 460- discarding irods session for: irods://********@********:1247
73263 [pool-4-thread-2] ERROR org.irods.jargon.core.connection.IRODSConnection read 863- io exception reading
java.io.IOException: Stream closed.
at java.net.AbstractPlainSocketImpl.available(AbstractPlainSocketImpl.java:435)
at java.net.SocketInputStream.available(SocketInputStream.java:234)
at java.io.BufferedInputStream.read(BufferedInputStream.java:342)
at org.irods.jargon.core.connection.IRODSConnection.read(IRODSConnection.java:926)
at org.irods.jargon.core.connection.IRODSConnection.read(IRODSConnection.java:841)
at org.irods.jargon.core.connection.IRODSCommands.read(IRODSCommands.java:670)
at org.irods.jargon.core.pub.DataAOHelper.processNormalGetTransfer(DataAOHelper.java:390)
at org.irods.jargon.core.pub.DataObjectAOImpl.processGetAfterResourceDetermined(DataObjectAOImpl.java:1317)
at org.irods.jargon.core.pub.DataObjectAOImpl.getDataObjectFromIrods(DataObjectAOImpl.java:1052)
at org.irods.jargon.core.pub.TransferOperationsHelper.processGetOfSingleFile(TransferOperationsHelper.java:255)
at org.irods.jargon.core.pub.DataTransferOperationsImpl.processGetOfSingleFile(DataTransferOperationsImpl.java:756)
at org.irods.jargon.core.pub.DataTransferOperationsImpl.processGetAfterAnyConnectionRerouting(DataTransferOperationsImpl.java:544)
at org.irods.jargon.core.pub.DataTransferOperationsImpl.getOperation(DataTransferOperationsImpl.java:369)
at edu.stsci.irods.util2.StsciDataObject.copyFromIRODS(StsciDataObject.java:193)
at edu.stsci.irods.util2.StsciIrodsUtilities.readIRODSFile(StsciIrodsUtilities.java:182)
at edu.stsci.irods.performance.ReadTestConfiguration.runAsJargon(ReadTestConfiguration.java:88)
at edu.stsci.irods.performance.AbstractTestConfiguration$2.run(AbstractTestConfiguration.java:131)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:679)
and.....
77486 [pool-4-thread-4] ERROR org.irods.jargon.core.connection.IRODSCommands irodsFunction 347- ioexception
java.net.SocketException: Socket closed
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:116)
at java.net.SocketOutputStream.write(SocketOutputStream.java:153)
at org.irods.jargon.core.connection.IRODSConnection.send(IRODSConnection.java:540)
at org.irods.jargon.core.connection.IRODSCommands.irodsFunction(IRODSCommands.java:328)
at org.irods.jargon.core.connection.IRODSCommands.irodsFunction(IRODSCommands.java:270)
at org.irods.jargon.core.query.GenQueryProcessor.sendGenQueryAndReturnResponse(GenQueryProcessor.java:140)
at org.irods.jargon.core.query.GenQueryProcessor.executeTranslatedIRODSQuery(GenQueryProcessor.java:84)
at org.irods.jargon.core.pub.IRODSGenQueryExecutorImpl.executeIRODSQueryAndCloseResultInZone(IRODSGenQueryExecutorImpl.java:159)
at org.irods.jargon.core.pub.DataObjectAOImpl.findGivenObjStat(DataObjectAOImpl.java:252)
at org.irods.jargon.core.pub.DataObjectAOImpl.findByCollectionNameAndDataName(DataObjectAOImpl.java:150)
at org.irods.jargon.core.pub.DataObjectAOImpl.findByAbsolutePath(DataObjectAOImpl.java:174)
at edu.stsci.irods.util2.StsciDataObject.<init>(StsciDataObject.java:33)
at edu.stsci.irods.util2.StsciIrodsUtilities.readIRODSFile(StsciIrodsUtilities.java:174)
at edu.stsci.irods.performance.ReadTestConfiguration.runAsJargon(ReadTestConfiguration.java:88)
at edu.stsci.irods.performance.AbstractTestConfiguration$2.run(AbstractTestConfiguration.java:131)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:679)
Without that line commented out, I only get the ClosedChannelExceptions. With it commented out, there is some information in the log. There are a lot of intermittent blocks such as this:
Nov 16 15:41:01 pid:69264 ERROR: readMsgHeader:header read- read 0 bytes, expect 4, status = -4002
Nov 16 15:41:01 pid:69264 NOTICE: Agent exiting with status = -4002
Nov 16 15:41:01 pid:69260 ERROR: readMsgHeader:header read- read 0 bytes, expect 4, status = -4002
Nov 16 15:41:01 pid:69260 NOTICE: Agent exiting with status = -4002
Nov 16 15:41:01 pid:12877 NOTICE: Agent process 69260 exited with status 256
Nov 16 15:41:01 pid:12877 NOTICE: Agent process 69264 exited with status 256
Followed by a ton of blocks like this one:
Nov 16 15:41:05 pid:69608 NOTICE: chlOpen cmlOpen failure -803000
Nov 16 15:41:05 pid:69608 NOTICE: connectRcat: chlOpen Error. Status = -803000
Nov 16 15:41:05 pid:69608 SYSTEM FATAL: initServerInfo: no rcatHost error, status = -803000
Nov 16 15:41:05 pid:69608 ERROR: initAgent: initServerInfo error, status = -803000
Nov 16 15:41:05 pid:69608 NOTICE: Agent exiting with status = -803000
Nov 16 15:41:05 pid:12877 NOTICE: Agent process 69609 started for puser=******** and cuser=******** from 130.167.252.40
Nov 16 15:41:05 pid:12877 NOTICE: Agent process 69608 exited with status 256
Nov 16 15:41:05 pid:12877 NOTICE: Agent process 69611 started for puser=******** and cuser=******** from 130.167.252.40
Nov 16 15:41:05 pid:69609 ERROR: cllConnect: SQLConnect failed: -1
Nov 16 15:41:05 pid:69609 ERROR: cllConnect: SQLConnect failed:odbcEntry=PostgreSQL,user=*******,pass=********
Nov 16 15:41:05 pid:69609 ERROR: cllConnect: SQLSTATE: 28000
Nov 16 15:41:05 pid:69609 ERROR: cllConnect: Native Error Code: 210
Nov 16 15:41:05 pid:69609 ERROR: cllConnect: [unixODBC]FATAL: sorry, too many clients already
I was previously running the same multithreaded application (closeAndEatExceptions() not commented out) with Jargon-Core 3.0.0.1 w/out these issues. I can roll back to that or 3.1.3 to see if I still have the same problems if you think that would be useful. There were some API changes between 3.0.0.1 and 3.1.3 I believe.