sys len read error parallel transfer 4.0.3 iRODS / PAM, remote storage resource

michael-conway commented 9 years ago

PAM enabled iRODS 4.0.3 server.

ICAT and remote 1

transfer 49 MB file from jargon to iCAT, Portal Opr indicates remote1

iRODS log


Jun 27 21:31:21 pid:28906 ERROR: [-]    iRODS/server/core/src/rsApiHandler.cpp:484:readAndProcClientMsg :  status [SYS_HEADER_READ_LEN_ERR]  errno [] -- message []
    [-]    iRODS/lib/core/src/sockComm.cpp:195:readMsgHeader :  status [SYS_HEADER_READ_LEN_ERR]  errno [] -- message [failed to call 'read header']
        [-]    libtcp.cpp:240:tcp_read_msg_header :  status [SYS_HEADER_READ_LEN_ERR]  errno [] -- message [read 0 expected 4]

Jargon logs show failure in thread7 of parallel with socket, but back channel error might indicate server to server communication in background impacting agent

2022 [main] INFO  org.irods.jargon.core.pub.DataObjectAOImpl  - getting ready to initiate parallel file transfer strategy:ParallelPutFileTransferStrategy
   host:xxxxxxxx
   port:20199
   numberOfThreads:8
   localFile:C:\Programs\_install\xxxx-win64-3.8.3.msi
   transferLength:49853441
2023 [main] INFO  org.irods.jargon.core.transfer.ParallelPutFileTransferStrategy  - initiating transfer for: ParallelPutFileTransferStrategy
   host:xxxxxx
   port:20199
   numberOfThreads:8
   localFile:xxxx.msi
   transferLength:49853441
015 [main] DEBUG org.irods.jargon.core.pub.DataObjectAOImpl  - fd for file:3
2015 [main] INFO  org.irods.jargon.core.pub.DataObjectAOImpl  - retrieveRestartInfoIfAvailable()
2015 [main] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - retrieveRestartAndBuildIfNotStored()
2016 [main] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - retrieveRestart()
2016 [main] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - no restart saved, create and store a new one
2019 [main] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - storeRestart()
2019 [main] INFO  org.irods.jargon.core.pub.DataObjectAOImpl  - transfer will be done using 8 threads
2019 [main] DEBUG org.irods.jargon.core.pub.IRODSAccessObjectFactoryImpl  - creating access object factory
2022 [main] INFO  org.irods.jargon.core.pub.DataObjectAOImpl  - getting ready to initiate parallel file transfer strategy:ParallelPutFileTransferStrategy
   host:xxxxxx
   port:20199
   numberOfThreads:8
   localFile:C:\Programs\_install\xxxxx-win64-3.8.3.msi
   transferLength:49853441
2023 [main] INFO  org.irods.jargon.core.transfer.ParallelPutFileTransferStrategy  - initiating transfer for: ParallelPutFileTransferStrategy
   host:10.205.115.41
   port:20199
   numberOfThreads:8
   localFile:C:\Programs\_install\charles-proxy-win64-3.8.3.msi
   transferLength:49853441
2023 [main] DEBUG org.irods.jargon.core.connection.IRODSSession  - getting the ParallelTransferThreadPool
2023 [main] DEBUG org.irods.jargon.core.connection.IRODSSession  - I am not using the parallel transfer threads pool, return null
2023 [main] INFO  org.irods.jargon.core.transfer.ParallelPutFileTransferStrategy  - no pool available, transfer using single executor
2027 [main] INFO  org.irods.jargon.core.transfer.ParallelPutFileTransferStrategy  - initiating transfer for: ParallelPutFileTransferStrategy
   host:xxxxxx
   port:20199
   numberOfThreads:8
   localFile:C:\Programs\_install\xxxxx-win64-3.8.3.msi
   transferLength:49853441 without executor
2031 [main] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - opening socket to parallel transfer (high) port at port:20199
2052 [main] INFO  org.irods.jargon.core.transfer.ParallelPutFileTransferStrategy  - created transfer thread:org.irods.jargon.core.transfer.ParallelPutTransferThread@5103c628
2052 [main] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - opening socket to parallel transfer (high) port at port:20199
2055 [main] INFO  org.irods.jargon.core.transfer.ParallelPutFileTransferStrategy  - created transfer thread:org.irods.jargon.core.transfer.ParallelPutTransferThread@4ec695a5
2055 [main] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - opening socket to parallel transfer (high) port at port:20199
2057 [main] INFO  org.irods.jargon.core.transfer.ParallelPutFileTransferStrategy  - created transfer thread:org.irods.jargon.core.transfer.ParallelPutTransferThread@4f8aac0a
2057 [main] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - opening socket to parallel transfer (high) port at port:20199
2060 [main] INFO  org.irods.jargon.core.transfer.ParallelPutFileTransferStrategy  - created transfer thread:org.irods.jargon.core.transfer.ParallelPutTransferThread@1924ed52
2060 [main] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - opening socket to parallel transfer (high) port at port:20199
2063 [main] INFO  org.irods.jargon.core.transfer.ParallelPutFileTransferStrategy  - created transfer thread:org.irods.jargon.core.transfer.ParallelPutTransferThread@4758af63
2063 [main] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - opening socket to parallel transfer (high) port at port:20199
2066 [main] INFO  org.irods.jargon.core.transfer.ParallelPutFileTransferStrategy  - created transfer thread:org.irods.jargon.core.transfer.ParallelPutTransferThread@f62b12d
2066 [main] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - opening socket to parallel transfer (high) port at port:20199
2069 [main] INFO  org.irods.jargon.core.transfer.ParallelPutFileTransferStrategy  - created transfer thread:org.irods.jargon.core.transfer.ParallelPutTransferThread@185e093f
2069 [main] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - opening socket to parallel transfer (high) port at port:20199
2072 [main] INFO  org.irods.jargon.core.transfer.ParallelPutFileTransferStrategy  - created transfer thread:org.irods.jargon.core.transfer.ParallelPutTransferThread@45b11398
2072 [main] INFO  org.irods.jargon.core.transfer.ParallelPutFileTransferStrategy  - invoking executor threads for put
2074 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - getting random access file for local file
2074 [pool-1-thread-2] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - getting random access file for local file
2074 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - getting random access file for local file
2074 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - getting random access file for local file
2074 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - getting random access file for local file
2075 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - getting random access file for local file
2075 [pool-1-thread-7] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - getting random access file for local file
2090 [pool-1-thread-8] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - getting random access file for local file
2090 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - writing the cookie (password) for the output thread
2090 [pool-1-thread-6] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - cookie written for output thread...calling put() to start read/write loop
2090 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - put()..
2090 [pool-1-thread-2] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - writing the cookie (password) for the output thread
2091 [pool-1-thread-2] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - cookie written for output thread...calling put() to start read/write loop
2091 [pool-1-thread-2] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - put()..
2091 [pool-1-thread-2] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - in main put() loop, reading header data
2092 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - writing the cookie (password) for the output thread
2092 [pool-1-thread-5] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - cookie written for output thread...calling put() to start read/write loop
2092 [pool-1-thread-7] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - writing the cookie (password) for the output thread
2092 [pool-1-thread-6] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - in main put() loop, reading header data
2092 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - put()..
2092 [pool-1-thread-7] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - cookie written for output thread...calling put() to start read/write loop
2092 [pool-1-thread-7] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - put()..
2092 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - writing the cookie (password) for the output thread
2093 [pool-1-thread-1] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - cookie written for output thread...calling put() to start read/write loop
2093 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - put()..
2093 [pool-1-thread-5] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - in main put() loop, reading header data
2093 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - writing the cookie (password) for the output thread
2093 [pool-1-thread-4] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - cookie written for output thread...calling put() to start read/write loop
2093 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - put()..
2093 [pool-1-thread-7] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - in main put() loop, reading header data
2093 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - writing the cookie (password) for the output thread
2093 [pool-1-thread-1] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - in main put() loop, reading header data
2093 [pool-1-thread-3] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - cookie written for output thread...calling put() to start read/write loop
2094 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - put()..
2111 [pool-1-thread-4] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - in main put() loop, reading header data
2111 [pool-1-thread-8] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - writing the cookie (password) for the output thread
2111 [pool-1-thread-8] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - cookie written for output thread...calling put() to start read/write loop
2111 [pool-1-thread-8] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - put()..
2112 [pool-1-thread-3] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - in main put() loop, reading header data
2112 [pool-1-thread-8] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - in main put() loop, reading header data
2120 [pool-1-thread-2] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    operation:1
2120 [pool-1-thread-2] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - put operation
2120 [pool-1-thread-2] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    flags:0
2120 [pool-1-thread-2] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    offset:6231680
2120 [pool-1-thread-2] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - updateLenghtForSegment()
2120 [pool-1-thread-2] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - retrieveRestart()
2120 [pool-1-thread-2] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - storeRestart()
2120 [pool-1-thread-2] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    length:6231680
2120 [pool-1-thread-2] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - buffer length for put is: 4194304
2120 [pool-1-thread-2] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - readWriteLoopForCurrentHeaderDirective()
2120 [pool-1-thread-2] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - read/write loop at top
2121 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    operation:1
2121 [pool-1-thread-3] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - put operation
2121 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    flags:0
2121 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    offset:12463360
2121 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - updateLenghtForSegment()
2121 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - retrieveRestart()
2121 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - storeRestart()
2121 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    length:6231680
2121 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - buffer length for put is: 4194304
2121 [pool-1-thread-3] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - readWriteLoopForCurrentHeaderDirective()
2121 [pool-1-thread-3] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - read/write loop at top
2124 [pool-1-thread-2] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - bytes read: 4194304
2124 [pool-1-thread-2] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - getting ready to write to iRODS, new txfr length:2037376
2125 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    operation:1
2125 [pool-1-thread-4] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - put operation
2125 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    flags:0
2125 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    offset:18695040
2125 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - updateLenghtForSegment()
2125 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - retrieveRestart()
2125 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - storeRestart()
2125 [pool-1-thread-7] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    operation:1
2125 [pool-1-thread-7] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - put operation
2125 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    length:6231680
2125 [pool-1-thread-7] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    flags:0
2125 [pool-1-thread-7] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    offset:37390080
2125 [pool-1-thread-7] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - updateLenghtForSegment()
2125 [pool-1-thread-7] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - retrieveRestart()
2125 [pool-1-thread-7] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - storeRestart()
2125 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    operation:1
2125 [pool-1-thread-6] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - put operation
2125 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    flags:0
2125 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    offset:31158400
2125 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - updateLenghtForSegment()
2125 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - retrieveRestart()
2125 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - storeRestart()
2125 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    length:6231680
2125 [pool-1-thread-7] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    length:6231680
2125 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    operation:1
2125 [pool-1-thread-5] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - put operation
2125 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    flags:0
2125 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    offset:24926720
2125 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - updateLenghtForSegment()
2125 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - retrieveRestart()
2125 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - buffer length for put is: 4194304
2125 [pool-1-thread-4] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - readWriteLoopForCurrentHeaderDirective()
2125 [pool-1-thread-4] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - read/write loop at top
2125 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - storeRestart()
2126 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    length:6231680
2125 [pool-1-thread-7] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - buffer length for put is: 4194304
2126 [pool-1-thread-7] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - readWriteLoopForCurrentHeaderDirective()
2126 [pool-1-thread-7] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - read/write loop at top
2126 [pool-1-thread-3] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - bytes read: 4194304
2126 [pool-1-thread-3] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - getting ready to write to iRODS, new txfr length:2037376
2125 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - buffer length for put is: 4194304
2127 [pool-1-thread-6] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - readWriteLoopForCurrentHeaderDirective()
2127 [pool-1-thread-6] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - read/write loop at top
2126 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - buffer length for put is: 4194304
2127 [pool-1-thread-5] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - readWriteLoopForCurrentHeaderDirective()
2127 [pool-1-thread-5] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - read/write loop at top
2131 [pool-1-thread-7] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - bytes read: 4194304
2131 [pool-1-thread-7] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - getting ready to write to iRODS, new txfr length:2037376
2133 [pool-1-thread-4] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - bytes read: 4194304
2133 [pool-1-thread-4] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - getting ready to write to iRODS, new txfr length:2037376
2137 [pool-1-thread-5] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - bytes read: 4194304
2137 [pool-1-thread-5] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - getting ready to write to iRODS, new txfr length:2037376
2142 [pool-1-thread-2] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - wrote data to the buffer
2142 [pool-1-thread-2] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - checking total written for this thread
2142 [pool-1-thread-2] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - updateLengthForSegment()
2142 [pool-1-thread-2] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - retrieveRestart()
2142 [pool-1-thread-2] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - storeRestart()
2142 [pool-1-thread-2] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - signal storage of new info
2145 [pool-1-thread-3] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - wrote data to the buffer
2145 [pool-1-thread-3] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - checking total written for this thread
2146 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - updateLengthForSegment()
2146 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - retrieveRestart()
2146 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - storeRestart()
2146 [pool-1-thread-3] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - signal storage of new info
2146 [pool-1-thread-3] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - read/write loop at top
2145 [pool-1-thread-6] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - bytes read: 4194304
2146 [pool-1-thread-6] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - getting ready to write to iRODS, new txfr length:2037376
2147 [pool-1-thread-3] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - bytes read: 2037376
2148 [pool-1-thread-3] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - getting ready to write to iRODS, new txfr length:0
2165 [pool-1-thread-5] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - wrote data to the buffer
2165 [pool-1-thread-5] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - checking total written for this thread
2165 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - updateLengthForSegment()
2165 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - retrieveRestart()
2165 [pool-1-thread-8] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    operation:1
2165 [pool-1-thread-8] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - put operation
2166 [pool-1-thread-8] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    flags:0
2166 [pool-1-thread-8] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    offset:43621760
2166 [pool-1-thread-8] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - updateLenghtForSegment()
2166 [pool-1-thread-7] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - wrote data to the buffer
2166 [pool-1-thread-7] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - checking total written for this thread
2166 [pool-1-thread-7] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - updateLengthForSegment()
2167 [pool-1-thread-3] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - wrote data to the buffer
2167 [pool-1-thread-3] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - checking total written for this thread
2167 [pool-1-thread-2] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - read/write loop at top
2167 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    operation:1
2167 [pool-1-thread-1] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - put operation
2165 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - storeRestart()
2167 [pool-1-thread-5] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - signal storage of new info
2167 [pool-1-thread-5] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - read/write loop at top
2170 [pool-1-thread-7] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - retrieveRestart()
2170 [pool-1-thread-7] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - storeRestart()
2170 [pool-1-thread-7] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - signal storage of new info
2170 [pool-1-thread-7] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - read/write loop at top
2167 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    flags:0
2170 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    offset:0
2170 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - updateLenghtForSegment()
2167 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - updateLengthForSegment()
2170 [pool-1-thread-8] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - retrieveRestart()
2171 [pool-1-thread-8] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - storeRestart()
2171 [pool-1-thread-8] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    length:6231681
2171 [pool-1-thread-8] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - buffer length for put is: 4194304
2171 [pool-1-thread-8] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - readWriteLoopForCurrentHeaderDirective()
2171 [pool-1-thread-8] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - read/write loop at top
2171 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - retrieveRestart()
2171 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - storeRestart()
2171 [pool-1-thread-3] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - signal storage of new info
2171 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - final flush of output buffer
2171 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - for thread, total read: 6231680
2171 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    total written: 6231680
2171 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    transferLength: 0
2171 [pool-1-thread-3] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - checking total written for this thread
2171 [pool-1-thread-3] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - in main put() loop, reading header data
2171 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    operation:9999
2171 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - done received
2171 [pool-1-thread-3] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - put operation completed
2172 [pool-1-thread-6] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - wrote data to the buffer
2172 [pool-1-thread-6] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - checking total written for this thread
2172 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - updateLengthForSegment()
2172 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - retrieveRestart()
2173 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - storeRestart()
2173 [pool-1-thread-6] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - signal storage of new info
2170 [pool-1-thread-2] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - bytes read: 2037376
2173 [pool-1-thread-2] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - getting ready to write to iRODS, new txfr length:0
2174 [pool-1-thread-4] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - wrote data to the buffer
2175 [pool-1-thread-4] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - checking total written for this thread
2175 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - updateLengthForSegment()
2175 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - retrieveRestart()
2175 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - storeRestart()
2175 [pool-1-thread-4] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - signal storage of new info
2175 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - retrieveRestart()
2176 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - storeRestart()
2176 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    length:6231680
2176 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - buffer length for put is: 4194304
2176 [pool-1-thread-1] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - readWriteLoopForCurrentHeaderDirective()
2176 [pool-1-thread-1] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - read/write loop at top
2177 [pool-1-thread-7] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - bytes read: 2037376
2178 [pool-1-thread-7] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - getting ready to write to iRODS, new txfr length:0
2178 [pool-1-thread-8] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - bytes read: 4194304
2178 [pool-1-thread-8] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - getting ready to write to iRODS, new txfr length:2037377
2178 [pool-1-thread-2] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - wrote data to the buffer
2179 [pool-1-thread-2] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - checking total written for this thread
2179 [pool-1-thread-2] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - updateLengthForSegment()
2179 [pool-1-thread-2] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - retrieveRestart()
2179 [pool-1-thread-2] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - storeRestart()
2179 [pool-1-thread-2] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - signal storage of new info
2170 [pool-1-thread-5] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - bytes read: 2037376
2179 [pool-1-thread-5] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - getting ready to write to iRODS, new txfr length:0
2181 [pool-1-thread-7] ERROR org.irods.jargon.core.transfer.ParallelPutTransferThread  - error writing to iRODS parallel transfer socket
java.net.SocketException: Software caused connection abort: socket write error
    at java.net.SocketOutputStream.socketWrite0(Native Method)
    at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
    at java.net.SocketOutputStream.write(SocketOutputStream.java:159)
    at java.io.BufferedOutputStream.write(BufferedOutputStream.java:122)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.readWriteLoopForCurrentHeaderDirective(ParallelPutTransferThread.java:341)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.put(ParallelPutTransferThread.java:290)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.call(ParallelPutTransferThread.java:169)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.call(ParallelPutTransferThread.java:1)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)
2185 [pool-1-thread-7] ERROR org.irods.jargon.core.transfer.ParallelPutTransferThread  - An IO exception occurred during a parallel file put operation
org.irods.jargon.core.exception.JargonException: java.net.SocketException: Software caused connection abort: socket write error
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.readWriteLoopForCurrentHeaderDirective(ParallelPutTransferThread.java:417)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.put(ParallelPutTransferThread.java:290)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.call(ParallelPutTransferThread.java:169)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.call(ParallelPutTransferThread.java:1)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)
Caused by: java.net.SocketException: Software caused connection abort: socket write error
    at java.net.SocketOutputStream.socketWrite0(Native Method)
    at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
    at java.net.SocketOutputStream.write(SocketOutputStream.java:159)
    at java.io.BufferedOutputStream.write(BufferedOutputStream.java:122)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.readWriteLoopForCurrentHeaderDirective(ParallelPutTransferThread.java:341)
    ... 7 more
2185 [pool-1-thread-7] ERROR org.irods.jargon.core.transfer.ParallelPutTransferThread  - An exception occurred during a parallel file put operation
org.irods.jargon.core.exception.JargonException: IOException during parallel file put
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.put(ParallelPutTransferThread.java:299)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.call(ParallelPutTransferThread.java:169)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.call(ParallelPutTransferThread.java:1)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)
Caused by: org.irods.jargon.core.exception.JargonException: java.net.SocketException: Software caused connection abort: socket write error
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.readWriteLoopForCurrentHeaderDirective(ParallelPutTransferThread.java:417)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.put(ParallelPutTransferThread.java:290)
    ... 6 more
Caused by: java.net.SocketException: Software caused connection abort: socket write error
    at java.net.SocketOutputStream.socketWrite0(Native Method)
    at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
    at java.net.SocketOutputStream.write(SocketOutputStream.java:159)
    at java.io.BufferedOutputStream.write(BufferedOutputStream.java:122)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.readWriteLoopForCurrentHeaderDirective(ParallelPutTransferThread.java:341)
    ... 7 more
2185 [pool-1-thread-7] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - closing sockets, this eats any exceptions
2175 [pool-1-thread-6] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - read/write loop at top
2185 [pool-1-thread-7] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - socket conns for parallel transfer closed, now close the file stream
2186 [pool-1-thread-7] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - streams and files closed
2175 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - closing sockets, this eats any exceptions
2186 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - socket conns for parallel transfer closed, now close the file stream
2175 [pool-1-thread-4] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - read/write loop at top
2181 [pool-1-thread-1] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - bytes read: 4194304
2186 [pool-1-thread-1] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - getting ready to write to iRODS, new txfr length:2037376
2186 [pool-1-thread-3] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - streams and files closed
2187 [pool-1-thread-6] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - bytes read: 2037376
2187 [pool-1-thread-6] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - getting ready to write to iRODS, new txfr length:0
2188 [pool-1-thread-5] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - wrote data to the buffer
2188 [pool-1-thread-5] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - checking total written for this thread
2188 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - updateLengthForSegment()
2188 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - retrieveRestart()
2188 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - storeRestart()
2188 [pool-1-thread-5] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - signal storage of new info
2181 [pool-1-thread-2] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - final flush of output buffer
2188 [pool-1-thread-2] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - for thread, total read: 6231680
2188 [pool-1-thread-2] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    total written: 6231680
2188 [pool-1-thread-2] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    transferLength: 0
2188 [pool-1-thread-2] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - checking total written for this thread
2188 [pool-1-thread-2] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - in main put() loop, reading header data
2188 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - final flush of output buffer
2188 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - for thread, total read: 6231680
2189 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    total written: 6231680
2189 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    transferLength: 0
2189 [pool-1-thread-5] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - checking total written for this thread
2189 [pool-1-thread-5] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - in main put() loop, reading header data
2189 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    operation:9999
2189 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - done received
2189 [pool-1-thread-5] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - put operation completed
2189 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - closing sockets, this eats any exceptions
2189 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - socket conns for parallel transfer closed, now close the file stream
2189 [pool-1-thread-5] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - streams and files closed
2191 [pool-1-thread-4] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - bytes read: 2037376
2191 [pool-1-thread-4] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - getting ready to write to iRODS, new txfr length:0
2198 [pool-1-thread-6] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - wrote data to the buffer
2198 [pool-1-thread-6] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - checking total written for this thread
2198 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - updateLengthForSegment()
2198 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - retrieveRestart()
2198 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - storeRestart()
2198 [pool-1-thread-6] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - signal storage of new info
2198 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - final flush of output buffer
2198 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - for thread, total read: 6231680
2198 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    total written: 6231680
2198 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    transferLength: 0
2198 [pool-1-thread-6] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - checking total written for this thread
2198 [pool-1-thread-6] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - in main put() loop, reading header data
2198 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    operation:9999
2198 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - done received
2198 [pool-1-thread-6] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - put operation completed
2198 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - closing sockets, this eats any exceptions
2198 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - socket conns for parallel transfer closed, now close the file stream
2198 [pool-1-thread-6] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - streams and files closed
2199 [pool-1-thread-8] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - wrote data to the buffer
2199 [pool-1-thread-8] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - checking total written for this thread
2199 [pool-1-thread-8] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - updateLengthForSegment()
2200 [pool-1-thread-8] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - retrieveRestart()
2200 [pool-1-thread-8] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - storeRestart()
2200 [pool-1-thread-8] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - signal storage of new info
2200 [pool-1-thread-8] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - read/write loop at top
2201 [pool-1-thread-8] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - bytes read: 2037377
2202 [pool-1-thread-8] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - getting ready to write to iRODS, new txfr length:0
2205 [pool-1-thread-4] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - wrote data to the buffer
2205 [pool-1-thread-4] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - checking total written for this thread
2205 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - updateLengthForSegment()
2205 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - retrieveRestart()
2205 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - storeRestart()
2205 [pool-1-thread-4] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - signal storage of new info
2205 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - final flush of output buffer
2206 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - for thread, total read: 6231680
2206 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    total written: 6231680
2206 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    transferLength: 0
2206 [pool-1-thread-4] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - checking total written for this thread
2206 [pool-1-thread-4] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - in main put() loop, reading header data
2206 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    operation:9999
2206 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - done received
2206 [pool-1-thread-4] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - put operation completed
2206 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - closing sockets, this eats any exceptions
2206 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - socket conns for parallel transfer closed, now close the file stream
2206 [pool-1-thread-4] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - streams and files closed
2209 [pool-1-thread-8] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - wrote data to the buffer
2209 [pool-1-thread-8] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - checking total written for this thread
2209 [pool-1-thread-8] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - updateLengthForSegment()
2209 [pool-1-thread-8] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - retrieveRestart()
2209 [pool-1-thread-8] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - storeRestart()
2209 [pool-1-thread-8] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - signal storage of new info
2209 [pool-1-thread-8] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - final flush of output buffer
2209 [pool-1-thread-8] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - for thread, total read: 6231681
2209 [pool-1-thread-8] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    total written: 6231681
2209 [pool-1-thread-8] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    transferLength: 0
2209 [pool-1-thread-8] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - checking total written for this thread
2209 [pool-1-thread-8] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - in main put() loop, reading header data
2209 [pool-1-thread-1] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - wrote data to the buffer
2209 [pool-1-thread-1] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - checking total written for this thread
2209 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - updateLengthForSegment()
2209 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - retrieveRestart()
2209 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - storeRestart()
2209 [pool-1-thread-1] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - signal storage of new info
2209 [pool-1-thread-1] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - read/write loop at top
2211 [pool-1-thread-1] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - bytes read: 2037376
2211 [pool-1-thread-1] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - getting ready to write to iRODS, new txfr length:0
2216 [pool-1-thread-1] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - wrote data to the buffer
2216 [pool-1-thread-1] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - checking total written for this thread
2216 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.AbstractRestartManager  - updateLengthForSegment()
2216 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - retrieveRestart()
2216 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.MemoryBasedTransferRestartManager  - storeRestart()
2216 [pool-1-thread-1] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - signal storage of new info
2216 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - final flush of output buffer
2216 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - for thread, total read: 6231680
2216 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    total written: 6231680
2216 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    transferLength: 0
2216 [pool-1-thread-1] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - checking total written for this thread
2216 [pool-1-thread-1] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - in main put() loop, reading header data
2275 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  -    operation:9999
2275 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - done received
2276 [pool-1-thread-1] DEBUG org.irods.jargon.core.transfer.ParallelPutTransferThread  - put operation completed
2276 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - closing sockets, this eats any exceptions
2276 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - socket conns for parallel transfer closed, now close the file stream
2276 [pool-1-thread-1] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - streams and files closed
122194 [pool-1-thread-2] ERROR org.irods.jargon.core.transfer.AbstractParallelTransferThread  - IOExeption in parallel transfer
java.net.SocketTimeoutException: Read timed out
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.read(SocketInputStream.java:152)
    at java.net.SocketInputStream.read(SocketInputStream.java:122)
    at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
    at java.io.BufferedInputStream.read1(BufferedInputStream.java:275)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:334)
    at java.io.FilterInputStream.read(FilterInputStream.java:107)
    at org.irods.jargon.core.transfer.AbstractParallelTransferThread.readInt(AbstractParallelTransferThread.java:47)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.put(ParallelPutTransferThread.java:231)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.call(ParallelPutTransferThread.java:169)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.call(ParallelPutTransferThread.java:1)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)
122195 [pool-1-thread-2] ERROR org.irods.jargon.core.transfer.ParallelPutTransferThread  - An IO exception occurred during a parallel file put operation
org.irods.jargon.core.exception.JargonException: IOException occurred during parallel file transfer
    at org.irods.jargon.core.transfer.AbstractParallelTransferThread.readInt(AbstractParallelTransferThread.java:50)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.put(ParallelPutTransferThread.java:231)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.call(ParallelPutTransferThread.java:169)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.call(ParallelPutTransferThread.java:1)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)
Caused by: java.net.SocketTimeoutException: Read timed out
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.read(SocketInputStream.java:152)
    at java.net.SocketInputStream.read(SocketInputStream.java:122)
    at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
    at java.io.BufferedInputStream.read1(BufferedInputStream.java:275)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:334)
    at java.io.FilterInputStream.read(FilterInputStream.java:107)
    at org.irods.jargon.core.transfer.AbstractParallelTransferThread.readInt(AbstractParallelTransferThread.java:47)
    ... 7 more
122196 [pool-1-thread-2] ERROR org.irods.jargon.core.transfer.ParallelPutTransferThread  - An exception occurred during a parallel file put operation
org.irods.jargon.core.exception.JargonException: IOException during parallel file put
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.put(ParallelPutTransferThread.java:299)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.call(ParallelPutTransferThread.java:169)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.call(ParallelPutTransferThread.java:1)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)
Caused by: org.irods.jargon.core.exception.JargonException: IOException occurred during parallel file transfer
    at org.irods.jargon.core.transfer.AbstractParallelTransferThread.readInt(AbstractParallelTransferThread.java:50)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.put(ParallelPutTransferThread.java:231)
    ... 6 more
Caused by: java.net.SocketTimeoutException: Read timed out
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.read(SocketInputStream.java:152)
    at java.net.SocketInputStream.read(SocketInputStream.java:122)
    at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
    at java.io.BufferedInputStream.read1(BufferedInputStream.java:275)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:334)
    at java.io.FilterInputStream.read(FilterInputStream.java:107)
    at org.irods.jargon.core.transfer.AbstractParallelTransferThread.readInt(AbstractParallelTransferThread.java:47)
    ... 7 more
122197 [pool-1-thread-2] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - closing sockets, this eats any exceptions
122197 [pool-1-thread-2] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - socket conns for parallel transfer closed, now close the file stream
122197 [pool-1-thread-2] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - streams and files closed
122215 [pool-1-thread-8] ERROR org.irods.jargon.core.transfer.AbstractParallelTransferThread  - IOExeption in parallel transfer
java.net.SocketTimeoutException: Read timed out
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.read(SocketInputStream.java:152)
    at java.net.SocketInputStream.read(SocketInputStream.java:122)
    at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
    at java.io.BufferedInputStream.read1(BufferedInputStream.java:275)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:334)
    at java.io.FilterInputStream.read(FilterInputStream.java:107)
    at org.irods.jargon.core.transfer.AbstractParallelTransferThread.readInt(AbstractParallelTransferThread.java:47)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.put(ParallelPutTransferThread.java:231)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.call(ParallelPutTransferThread.java:169)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.call(ParallelPutTransferThread.java:1)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)
122215 [pool-1-thread-8] ERROR org.irods.jargon.core.transfer.ParallelPutTransferThread  - An IO exception occurred during a parallel file put operation
org.irods.jargon.core.exception.JargonException: IOException occurred during parallel file transfer
    at org.irods.jargon.core.transfer.AbstractParallelTransferThread.readInt(AbstractParallelTransferThread.java:50)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.put(ParallelPutTransferThread.java:231)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.call(ParallelPutTransferThread.java:169)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.call(ParallelPutTransferThread.java:1)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)
Caused by: java.net.SocketTimeoutException: Read timed out
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.read(SocketInputStream.java:152)
    at java.net.SocketInputStream.read(SocketInputStream.java:122)
    at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
    at java.io.BufferedInputStream.read1(BufferedInputStream.java:275)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:334)
    at java.io.FilterInputStream.read(FilterInputStream.java:107)
    at org.irods.jargon.core.transfer.AbstractParallelTransferThread.readInt(AbstractParallelTransferThread.java:47)
    ... 7 more
122216 [pool-1-thread-8] ERROR org.irods.jargon.core.transfer.ParallelPutTransferThread  - An exception occurred during a parallel file put operation
org.irods.jargon.core.exception.JargonException: IOException during parallel file put
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.put(ParallelPutTransferThread.java:299)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.call(ParallelPutTransferThread.java:169)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.call(ParallelPutTransferThread.java:1)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)
Caused by: org.irods.jargon.core.exception.JargonException: IOException occurred during parallel file transfer
    at org.irods.jargon.core.transfer.AbstractParallelTransferThread.readInt(AbstractParallelTransferThread.java:50)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.put(ParallelPutTransferThread.java:231)
    ... 6 more
Caused by: java.net.SocketTimeoutException: Read timed out
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.read(SocketInputStream.java:152)
    at java.net.SocketInputStream.read(SocketInputStream.java:122)
    at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
    at java.io.BufferedInputStream.read1(BufferedInputStream.java:275)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:334)
    at java.io.FilterInputStream.read(FilterInputStream.java:107)
    at org.irods.jargon.core.transfer.AbstractParallelTransferThread.readInt(AbstractParallelTransferThread.java:47)
    ... 7 more
122217 [pool-1-thread-8] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - closing sockets, this eats any exceptions
122217 [pool-1-thread-8] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - socket conns for parallel transfer closed, now close the file stream
122218 [pool-1-thread-8] INFO  org.irods.jargon.core.transfer.ParallelPutTransferThread  - streams and files closed
122218 [main] ERROR org.irods.jargon.core.transfer.ParallelPutFileTransferStrategy  - an error occurred in a parallel put
org.irods.jargon.core.exception.JargonException: org.irods.jargon.core.exception.JargonException: error during parallel file put
    at org.irods.jargon.core.transfer.ParallelPutFileTransferStrategy.transferWithExecutor(ParallelPutFileTransferStrategy.java:179)
    at org.irods.jargon.core.transfer.ParallelPutFileTransferStrategy.transfer(ParallelPutFileTransferStrategy.java:142)
    at org.irods.jargon.core.pub.DataObjectAOImpl.parallelPutTransfer(DataObjectAOImpl.java:983)
    at org.irods.jargon.core.pub.DataObjectAOImpl.processAsAParallelPutOperationIfMoreThanZeroThreads(DataObjectAOImpl.java:896)
    at org.irods.jargon.core.pub.DataObjectAOImpl.putCommonProcessing(DataObjectAOImpl.java:643)
    at org.irods.jargon.core.pub.DataObjectAOImpl.putLocalDataObjectToIRODS(DataObjectAOImpl.java:413)
    at org.irods.jargon.core.pub.TransferOperationsHelper.processPutOfSingleFile(TransferOperationsHelper.java:966)
    at org.irods.jargon.core.pub.DataTransferOperationsImpl.processPutAfterAnyConnectionRerouting(DataTransferOperationsImpl.java:949)
    at org.irods.jargon.core.pub.DataTransferOperationsImpl.putOperation(DataTransferOperationsImpl.java:798)
    at org.irods.jargon.core.pub.DataTransferOperationsImpl.putOperation(DataTransferOperationsImpl.java:1052)
    at com.bayer.irods.IrodsMain.main(IrodsMain.java:44)
Caused by: org.irods.jargon.core.exception.JargonException: error during parallel file put
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.call(ParallelPutTransferThread.java:178)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.call(ParallelPutTransferThread.java:1)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)
Caused by: org.irods.jargon.core.exception.JargonException: IOException during parallel file put
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.put(ParallelPutTransferThread.java:299)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.call(ParallelPutTransferThread.java:169)
    ... 5 more
Caused by: org.irods.jargon.core.exception.JargonException: IOException occurred during parallel file transfer
    at org.irods.jargon.core.transfer.AbstractParallelTransferThread.readInt(AbstractParallelTransferThread.java:50)
    at org.irods.jargon.core.transfer.ParallelPutTransferThread.put(ParallelPutTransferThread.java:231)
    ... 6 more
Caused by: java.net.SocketTimeoutException: Read timed out
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.read(SocketInputStream.java:152)
    at java.net.SocketInputStream.read(SocketInputStream.java:122)
    at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
    at java.io.BufferedInputStream.read1(BufferedInputStream.java:275)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:334)
    at java.io.FilterInputStream.read(FilterInputStream.java:107)
    at org.irods.jargon.core.transfer.AbstractParallelTransferThread.readInt(AbstractParallelTransferThread.java:47)
    ... 7 more

michael-conway commented 9 years ago

Interesting in initial testing

I have a long-standing vm I've run on a local VM that runs 403 and an iCat server (fedzone1-403.irods.org). This morning I added a new VM as a resource server (fedzone1-403-r3.irods.org)

I noted that unit tests were running much slower, I was seeing occasional sys len read errors in the icat log, simply by having a resource server attached, this felt a lot like the indicated issues. I found that I had a misconfiguration in my etc/hosts file on the iCat server where the fqdn for the resource server had not been entered. I could thus ping the iCat from my resource server, but couldn't ping the resource server from the iCat.

Fixing the host name config on my test rig seems to have resolved that. I am going to proceed next to develop an exact functional test of our scenario in the Jargon unit tests, but this is an interesting data point and might make a review of the host configuration and ping-ability by fqdn from icat to resource and vice versa?

A second question...is there a limiting factor to running the tests on iRODS 4.1.3? If we find it is an pam/ssl flush issue or the like, is an upgrade possible?

michael-conway commented 9 years ago

NB unit testTestParallelTransferToIcatRerouteRemoteBug132

Shows that deliberate network misconfiguration causes a

Jun 18 01:28:35 pid:14820 ERROR: [-]    iRODS/server/core/src/rsApiHandler.cpp:484:readAndProcClientMsg :  status [SYS_HEADER_READ_LEN_ERR]  errno [Broken pipe] -- message []
    [-] iRODS/lib/core/src/sockComm.cpp:195:readMsgHeader :  status [SYS_HEADER_READ_LEN_ERR]  errno [Broken pipe] -- message [failed to call 'read header']
        [-] libtcp.cpp:240:tcp_read_msg_header :  status [SYS_HEADER_READ_LEN_ERR]  errno [Broken pipe] -- message [read 0 expected 4]

which is different than reported. Working on adding PAM to the mix. With proper network config the test works as expected under std auth.

carsten-jahn commented 9 years ago

We observe this issue only if we are writing to the secondary resource server. If we're writing to the resource that is served together with the icat process, there is no issue. It does not make a difference if we connect using the rods user (no PAM) or a regular user (with PAM authentication).

"iadmin lr" shows resources on both the icat and separate resource server. It's the same output on both servers. The hostnames stated in its output can be used in "ping" on all servers, and include the full domain.

We have no 4.1.x running right now and don't plan to upgrade this year. Even if its not so difficult to upgrade, we'd have to execute a couple of tests, which takes time. It's not impossible, but requires time and budget, and I'd have to get this approved first...

michael-conway commented 9 years ago

a working unit test with pam is now available with the previous commit


@Test
    public void testBugCasePam() throws Exception {

        if (!testingPropertiesHelper
                .isTestDistributedResources(testingProperties)) {
            return;
        }

        if (!testingPropertiesHelper.isTestPAM(testingProperties)) {
            return;
        }

        String testFileName = "testBugCasePam.txt";
        long testFileLength = 49 * 1024 * 2014;

        String absPath = scratchFileUtils
                .createAndReturnAbsoluteScratchPath(IRODS_TEST_SUBDIR_PATH);
        String localFileName = FileGenerator
                .generateFileOfFixedLengthGivenName(absPath, testFileName,
                        testFileLength);

        String targetIrodsColl = testingPropertiesHelper
                .buildIRODSCollectionAbsolutePathFromPamTestProperties(
                        testingProperties, IRODS_TEST_SUBDIR_PATH);

        String targetIrodsFile = targetIrodsColl + '/' + testFileName;

        IRODSAccount irodsAccount = testingPropertiesHelper
                .buildPamIrodsAccountFromTestProperties(testingProperties);
        IRODSFileFactory irodsFileFactory = irodsFileSystem
                .getIRODSFileFactory(irodsAccount);
        IRODSFile destFile = irodsFileFactory
                .instanceIRODSFile(targetIrodsFile);
        destFile.deleteWithForceOption();
        irodsAccount
                .setDefaultStorageResource(testingProperties
                        .getProperty(TestingPropertiesHelper.IRODS_TERTIARY_RESOURCE_KEY));

        SettableJargonProperties jargonProperties = new SettableJargonProperties();
        jargonProperties.setUseTransferThreadsPool(false);
        jargonProperties.setLongTransferRestart(false);
        jargonProperties.setComputeAndVerifyChecksumAfterTransfer(true);
        irodsFileSystem.getIrodsSession().setJargonProperties(jargonProperties);
        IRODSFile coll = irodsFileFactory.instanceIRODSFile(targetIrodsColl);
        coll.mkdirs();

        DataTransferOperations dataTransferOperationsAO = irodsFileSystem
                .getIRODSAccessObjectFactory().getDataTransferOperations(
                        irodsAccount);

        File localSourceFile = new File(localFileName);

        destFile.setResource(testingProperties
                .getProperty(TestingPropertiesHelper.IRODS_TERTIARY_RESOURCE_KEY));

        dataTransferOperationsAO.putOperation(localSourceFile, destFile, null,
                null);

        Assert.assertTrue(destFile.exists());
        Assert.assertEquals(testFileLength, destFile.length());

    }

michael-conway commented 9 years ago

Current status, after review with some of the RENCI folks

the Pam and non-pam tests work on a local, VM based grid of two servers (fedzone1-403.irods.org is icat, fedzone1-403-r3.renci.org is remote resource). These run iRODS 4.0.3 servers
we suspect it is less an organic issue in code, the general feeling is that an intervening firewall or other network issue is at play. It looks like the parallel transfer communications to the 'portal' are interrupted somewhere in mid-flight, that is, some number of buffers do make it over.
we suspect that the sys len read errors in the icat log reflect the jargon client breaking communication with the agent on the icat

Proposed next step

I will prepare the above test as a stand-alone jar, would it be possible to eliminate the remote client, and only involve the iCat and resource servers? That would mean configuring and running a little app on the icat server box with the same scenario (connect to icat server, specify the secondary resource server as the target of the transfer?

The tests have been committed to master in TestParallelTransferToIcatRerouteRemoteBug132 in the jargon-core junit test suite, in the org.irods.jargon.core.unittest.functionaltest package

michael-conway commented 9 years ago

further up in the qa2 log is this

Jun 26 11:10:19 pid:32378 NOTICE: _partialDataPut: toread 4194304 bytes, 8388604 bytes read, errno = 14
*** glibc detected *** irodsAgent: munmap_chunk(): invalid pointer: 0x00007f1ba923b010 ***
======= Backtrace: =========
/lib64/libc.so.6[0x3c46e75e66]
irodsAgent(_Z14partialDataPutP17PortalTransferInp+0x4c0)[0x519370]
irodsAgent[0x72b543]
/lib64/libpthread.so.0[0x3c472079d1]
/lib64/libc.so.6(clone+0x6d)[0x3c46ee88fd]
======= Memory map: ========
00400000-00824000 r-xp 00000000 fd:05 2483                               /var/lib/irods/iRODS/server/bin/irodsAgent
00a24000-00a39000 rw-p 00424000 fd:05 2483                               /var/lib/irods/iRODS/server/bin/irodsAgent
00a39000-00c8b000 rw-p 00000000 00:00 0 
02157000-028fc000 rw-p 00000000 00:00 0                                  [heap]
3347200000-3347249000 r-xp 00000000 fd:00 159390                         /lib64/libldap-2.4.so.2.5.6
3347249000-3347449000 ---p 00049000 fd:00 159390                         /lib64/libldap-2.4.so.2.5.6
3347449000-334744b000 r--p 00049000 fd:00 159390                         /lib64/libldap-2.4.so.2.5.6
334744b000-334744d000 rw-p 0004b000 fd:00 159390                         /lib64/libldap-2.4.so.2.5.6
3347600000-334760e000 r-xp 00000000 fd:00 163931                         /lib64/liblber-2.4.so.2.5.6
334760e000-334780d000 ---p 0000e000 fd:00 163931                         /lib64/liblber-2.4.so.2.5.6
334780d000-334780e000 r--p 0000d000 fd:00 163931                         /lib64/liblber-2.4.so.2.5.6
334780e000-334780f000 rw-p 0000e000 fd:00 163931                         /lib64/liblber-2.4.so.2.5.6
3347a00000-3347a52000 r-xp 00000000 fd:00 163933                         /usr/lib64/libcurl.so.4.1.1
3347a52000-3347c51000 ---p 00052000 fd:00 163933                         /usr/lib64/libcurl.so.4.1.1
3347c51000-3347c54000 rw-p 00051000 fd:00 163933                         /usr/lib64/libcurl.so.4.1.1
3347e00000-3347e3a000 r-xp 00000000 fd:00 163929                         /usr/lib64/libssl3.so
3347e3a000-334803a000 ---p 0003a000 fd:00 163929                         /usr/lib64/libssl3.so
334803a000-334803d000 r--p 0003a000 fd:00 163929                         /usr/lib64/libssl3.so
334803d000-334803e000 rw-p 0003d000 fd:00 163929                         /usr/lib64/libssl3.so
334803e000-334803f000 rw-p 00000000 00:00 0 
3348200000-3348336000 r-xp 00000000 fd:00 159516                         /usr/lib64/libnss3.so
3348336000-3348536000 ---p 00136000 fd:00 159516                         /usr/lib64/libnss3.so
3348536000-334853b000 r--p 00136000 fd:00 159516                         /usr/lib64/libnss3.so
334853b000-334853d000 rw-p 0013b000 fd:00 159516                         /usr/lib64/libnss3.so
334853d000-334853f000 rw-p 00000000 00:00 0 
3348600000-3348628000 r-xp 00000000 fd:00 163930                         /usr/lib64/libsmime3.so
3348628000-3348827000 ---p 00028000 fd:00 163930                         /usr/lib64/libsmime3.so
3348827000-334882b000 r--p 00027000 fd:00 163930                         /usr/lib64/libsmime3.so
334882b000-334882c000 rw-p 0002b000 fd:00 163930                         /usr/lib64/libsmime3.so
3c46a00000-3c46a20000 r-xp 00000000 fd:00 153299                         /lib64/ld-2.12.so
3c46c1f000-3c46c20000 r--p 0001f000 fd:00 153299                         /lib64/ld-2.12.so
3c46c20000-3c46c21000 rw-p 00020000 fd:00 153299                         /lib64/ld-2.12.so
3c46c21000-3c46c22000 rw-p 00000000 00:00 0 
3c46e00000-3c46f8a000 r-xp 00000000 fd:00 156616                         /lib64/libc-2.12.so
3c46f8a000-3c4718a000 ---p 0018a000 fd:00 156616                         /lib64/libc-2.12.so
3c4718a000-3c4718e000 r--p 0018a000 fd:00 156616                         /lib64/libc-2.12.so
3c4718e000-3c4718f000 rw-p 0018e000 fd:00 156616                         /lib64/libc-2.12.so
3c4718f000-3c47194000 rw-p 00000000 00:00 0 
3c47200000-3c47217000 r-xp 00000000 fd:00 156656                         /lib64/libpthread-2.12.so
3c47217000-3c47417000 ---p 00017000 fd:00 156656                         /lib64/libpthread-2.12.so
3c47417000-3c47418000 r--p 00017000 fd:00 156656                         /lib64/libpthread-2.12.so
3c47418000-3c47419000 rw-p 00018000 fd:00 156656                         /lib64/libpthread-2.12.so
3c47419000-3c4741d000 rw-p 00000000 00:00 0 
3c47600000-3c47602000 r-xp 00000000 fd:00 156665                         /lib64/libdl-2.12.so
3c47602000-3c47802000 ---p 00002000 fd:00 156665                         /lib64/libdl-2.12.so
3c47802000-3c47803000 r--p 00002000 fd:00 156665                         /lib64/libdl-2.12.so
3c47803000-3c47804000 rw-p 00003000 fd:00 156665                         /lib64/libdl-2.12.so
3c47a00000-3c47a07000 r-xp 00000000 fd:00 142863                         /lib64/librt-2.12.so
3c47a07000-3c47c06000 ---p 00007000 fd:00 142863                         /lib64/librt-2.12.so
3c47c06000-3c47c07000 r--p 00006000 fd:00 142863                         /lib64/librt-2.12.so
3c47c07000-3c47c08000 rw-p 00007000 fd:00 142863                         /lib64/librt-2.12.so
3c47e00000-3c47e83000 r-xp 00000000 fd:00 146734                         /lib64/libm-2.12.so
3c47e83000-3c48082000 ---p 00083000 fd:00 146734                         /lib64/libm-2.12.so
3c48082000-3c48083000 r--p 00082000 fd:00 146734                         /lib64/libm-2.12.so
3c48083000-3c48084000 rw-p 00083000 fd:00 146734                         /lib64/libm-2.12.so
3c48200000-3c48215000 r-xp 00000000 fd:00 156667                         /lib64/libz.so.1.2.3
3c48215000-3c48414000 ---p 00015000 fd:00 156667                         /lib64/libz.so.1.2.3
3c48414000-3c48415000 r--p 00014000 fd:00 156667                         /lib64/libz.so.1.2.3
3c48415000-3c48416000 rw-p 00015000 fd:00 156667                         /lib64/libz.so.1.2.3
3c48a00000-3c48a1d000 r-xp 00000000 fd:00 156668                         /lib64/libselinux.so.1
3c48a1d000-3c48c1c000 ---p 0001d000 fd:00 156668                         /lib64/libselinux.so.1
3c48c1c000-3c48c1d000 r--p 0001c000 fd:00 156668                         /lib64/libselinux.so.1
3c48c1d000-3c48c1e000 rw-p 0001d000 fd:00 156668                         /lib64/libselinux.so.1
3c48c1e000-3c48c1f000 rw-p 00000000 00:00 0 
3c48e00000-3c48e19000 r-xp 00000000 fd:00 148385                         /usr/lib64/libsasl2.so.2.0.23
3c48e19000-3c49018000 ---p 00019000 fd:00 148385                         /usr/lib64/libsasl2.so.2.0.23
3c49018000-3c49019000 r--p 00018000 fd:00 148385                         /usr/lib64/libsasl2.so.2.0.23
3c49019000-3c4901a000 rw-p 00019000 fd:00 148385                         /usr/lib64/libsasl2.so.2.0.23
3c49a00000-3c49a16000 r-xp 00000000 fd:00 132687                         /lib64/libresolv-2.12.so
3c49a16000-3c49c16000 ---p 00016000 fd:00 132687                         /lib64/libresolv-2.12.so
3c49c16000-3c49c17000 r--p 00016000 fd:00 132687                         /lib64/libresolv-2.12.so
3c49c17000-3c49c18000 rw-p 00017000 fd:00 132687                         /lib64/libresolv-2.12.so
3c49c18000-3c49c1a000 rw-p 00000000 00:00 0 
3c49e00000-3c49e16000 r-xp 00000000 fd:00 156659                         /lib64/libgcc_s-4.4.7-20120601.so.1
3c49e16000-3c4a015000 ---p 00016000 fd:00 156659                         /lib64/libgcc_s-4.4.7-20120601.so.1
3c4a015000-3c4a016000 rw-p 00015000 fd:00 156659                         /lib64/libgcc_s-4.4.7-20120601.so.1
3c4a200000-3c4a271000 r-xp 00000000 fd:00 156671                         /lib64/libfreebl3.so
3c4a271000-3c4a470000 ---p 00071000 fd:00 156671                         /lib64/libfreebl3.so
3c4a470000-3c4a472000 r--p 00070000 fd:00 156671                         /lib64/libfreebl3.so
3c4a472000-3c4a473000 rw-p 00072000 fd:00 156671                         /lib64/libfreebl3.so
3c4a473000-3c4a477000 rw-p 00000000 00:00 0 
3c4a600000-3c4a607000 r-xp 00000000 fd:00 156672                         /lib64/libcrypt-2.12.so
3c4a607000-3c4a807000 ---p 00007000 fd:00 156672                         /lib64/libcrypt-2.12.so
3c4a807000-3c4a808000 r--p 00007000 fd:00 156672                         /lib64/libcrypt-2.12.so
3c4a808000-3c4a809000 rw-p 00008000 fd:00 156672                         /lib64/libcrypt-2.12.so
3c4a809000-3c4a837000 rw-p 00000000 00:00 0 
3c4aa00000-3c4aae8000 r-xp 00000000 fd:00 156660                         /usr/lib64/libstdc++.so.6.0.13
3c4aae8000-3c4ace8000 ---p 000e8000 fd:00 156660                         /usr/lib64/libstdc++.so.6.0.13
3c4ace8000-3c4acef000 r--p 000e8000 fd:00 156660                         /usr/lib64/libstdc++.so.6.0.13
3c4acef000-3c4acf1000 rw-p 000ef000 fd:00 156660                         /usr/lib64/libstdc++.so.6.0.13
3c4acf1000-3c4ad06000 rw-p 00000000 00:00 0 
3c4ae00000-3c4ae03000 r-xp 00000000 fd:00 156682                         /lib64/libcom_err.so.2.1
3c4ae03000-3c4b002000 ---p 00003000 fd:00 156682                         /lib64/libcom_err.so.2.1
3c4b002000-3c4b003000 r--p 00002000 fd:00 156682                         /lib64/libcom_err.so.2.1
3c4b003000-3c4b004000 rw-p 00003000 fd:00 156682                         /lib64/libcom_err.so.2.1
3c4b200000-3c4b239000 r-xp 00000000 fd:00 143675                         /lib64/libnspr4.so
3c4b239000-3c4b439000 ---p 00039000 fd:00 143675                         /lib64/libnspr4.so
3c4b439000-3c4b43a000 r--p 00039000 fd:00 143675                         /lib64/libnspr4.so
3c4b43a000-3c4b43c000 rw-p 0003a000 fd:00 143675                         /lib64/libnspr4.so
3c4b43c000-3c4b43e000 rw-p 00000000 00:00 0 
3c4b600000-3c4b632000 r-xp 00000000 fd:00 138871                         /lib64/libidn.so.11.6.1
3c4b632000-3c4b831000 ---p 00032000 fd:00 138871                         /lib64/libidn.so.11.6.1
3c4b831000-3c4b832000 rw-p 00031000 fd:00 138871                         /lib64/libidn.so.11.6.1
3c4ba00000-3c4ba04000 r-xp 00000000 fd:00 148594                         /lib64/libplc4.so
3c4ba04000-3c4bc03000 ---p 00004000 fd:00 148594                         /lib64/libplc4.so
3c4bc03000-3c4bc04000 r--p 00003000 fd:00 148594                         /lib64/libplc4.so
3c4bc04000-3c4bc05000 rw-p 00004000 fd:00 148594                         /lib64/libplc4.so
3c4be00000-3c4be25000 r-xp 00000000 fd:00 142996                         /usr/lib64/libnssutil3.so
3c4be25000-3c4c025000 ---p 00025000 fd:00 142996                         /usr/lib64/libnssutil3.so
3c4c025000-3c4c02b000 r--p 00025000 fd:00 142996                         /usr/lib64/libnssutil3.so
3c4c02b000-3c4c02c000 rw-p 0002b000 fd:00 142996                         /usr/lib64/libnssutil3.so
3c4c200000-3c4c203000 r-xp 00000000 fd:00 156677                         /lib64/libplds4.so
3c4c203000-3c4c402000 ---p 00003000 fd:00 156677                         /lib64/libplds4.so
3c4c402000-3c4c403000 r--p 00002000 fd:00 156677                         /lib64/libplds4.so
3c4c403000-3c4c404000 rw-p 00003000 fd:00 156677                         /lib64/libplds4.so
3c4ca00000-3c4ca02000 r-xp 00000000 fd:00 130726                         /lib64/libkeyutils.so.1.3
3c4ca02000-3c4cc01000 ---p 00002000 fd:00 130726                         /lib64/libkeyutils.so.1.3
3c4cc01000-3c4cc02000 r--p 00001000 fd:00 130726                         /lib64/libkeyutils.so.1.3
3c4cc02000-3c4cc03000 rw-p 00002000 fd:00 130726                         /lib64/libkeyutils.so.1.3
3c4ce00000-3c4ce41000 r-xp 00000000 fd:00 156684                         /lib64/libgssapi_krb5.so.2.2
3c4ce41000-3c4d041000 ---p 00041000 fd:00 156684                         /lib64/libgssapi_krb5.so.2.2
3c4d041000-3c4d042000 r--p 00041000 fd:00 156684                         /lib64/libgssapi_krb5.so.2.2
3c4d042000-3c4d044000 rw-p 00042000 fd:00 156684                         /lib64/libgssapi_krb5.so.2.2
3c4d200000-3c4d229000 r-xp 00000000 fd:00 156681                         /lib64/libk5crypto.so.3.1
3c4d229000-3c4d429000 ---p 00029000 fd:00 156681                         /lib64/libk5crypto.so.3.1
3c4d429000-3c4d42a000 r--p 00029000 fd:00 156681                         /lib64/libk5crypto.so.3.1
3c4d42a000-3c4d42b000 rw-p 0002a000 fd:00 156681                         /lib64/libk5crypto.so.3.1
3c4d42b000-3c4d42c000 rw-p 00000000 00:00 0 
3c4d600000-3c4d6db000 r-xp 00000000 fd:00 156683                         /lib64/libkrb5.so.3.3
3c4d6db000-3c4d8da000 ---p 000db000 fd:00 156683                         /lib64/libkrb5.so.3.3
3c4d8da000-3c4d8e4000 r--p 000da000 fd:00 156683                         /lib64/libkrb5.so.3.3
3c4d8e4000-3c4d8e6000 rw-p 000e4000 fd:00 156683                         /lib64/libkrb5.so.3.3
3c4da00000-3c4da0a000 r-xp 00000000 fd:00 156680                         /lib64/libkrb5support.so.0.1
3c4da0a000-3c4dc09000 ---p 0000a000 fd:00 156680                         /lib64/libkrb5support.so.0.1
3c4dc09000-3c4dc0a000 r--p 00009000 fd:00 156680                         /lib64/libkrb5support.so.0.1
3c4dc0a000-3c4dc0b000 rw-p 0000a000 fd:00 156680                         /lib64/libkrb5support.so.0.1
3c4de00000-3c4dfb9000 r-xp 00000000 fd:00 156618                         /usr/lib64/libcrypto.so.1.0.1e
3c4dfb9000-3c4e1b8000 ---p 001b9000 fd:00 156618                         /usr/lib64/libcrypto.so.1.0.1e
3c4e1b8000-3c4e1d3000 r--p 001b8000 fd:00 156618                         /usr/lib64/libcrypto.so.1.0.1e
3c4e1d3000-3c4e1df000 rw-p 001d3000 fd:00 156618                         /usr/lib64/libcrypto.so.1.0.1e
3c4e1df000-3c4e1e3000 rw-p 00000000 00:00 0 
3c4ea00000-3c4ea62000 r-xp 00000000 fd:00 137911                         /usr/lib64/libssl.so.1.0.1e
3c4ea62000-3c4ec61000 ---p 00062000 fd:00 137911                         /usr/lib64/libssl.so.1.0.1e
3c4ec61000-3c4ec65000 r--p 00061000 fd:00 137911                         /usr/lib64/libssl.so.1.0.1e
3c4ec65000-3c4ec6c000 rw-p 00065000 fd:00 137911                         /usr/lib64/libssl.so.1.0.1e
3c4f200000-3c4f227000 r-xp 00000000 fd:00 133281                         /usr/lib64/libssh2.so.1.0.1
3c4f227000-3c4f426000 ---p 00027000 fd:00 133281                         /usr/lib64/libssh2.so.1.0.1
3c4f426000-3c4f427000 rw-p 00026000 fd:00 133281                         /usr/lib64/libssh2.so.1.0.1
3c4f427000-3c4f428000 rw-p 00000000 00:00 0 
7f1b9c000000-7f1b9c021000 rw-p 00000000 00:00 0 
7f1b9c021000-7f1ba0000000 ---p 00000000 00:00 0 
7f1ba4000000-7f1ba4021000 rw-p 00000000 00:00 0 
7f1ba4021000-7f1ba8000000 ---p 00000000 00:00 0 
7f1ba8a3a000-7f1ba9a3c000 rw-p 00000000 00:00 0 
7f1ba9a3c000-7f1ba9a3d000 ---p 00000000 00:00 0 
7f1ba9a3d000-7f1baa43d000 rw-p 00000000 00:00 0 
7f1baa43d000-7f1baa43e000 ---p 00000000 00:00 0 
7f1baa43e000-7f1baae3e000 rw-p 00000000 00:00 0 
7f1baae3e000-7f1baae67000 r-xp 00000000 fd:05 2402                       /var/lib/irods/plugins/resources/libunixfilesystem.so
7f1baae67000-7f1bab067000 ---p 00029000 fd:05 2402                       /var/lib/irods/plugins/resources/libunixfilesystem.so
7f1bab067000-7f1bab068000 rw-p 00029000 fd:05 2402                       /var/lib/irods/plugins/resources/libunixfilesystem.so
7f1bab068000-7f1bab078000 r-xp 00000000 fd:05 2426                       /var/lib/irods/plugins/auth/libnative.so
7f1bab078000-7f1bab277000 ---p 00010000 fd:05 2426                       /var/lib/irods/plugins/auth/libnative.so
7f1bab277000-7f1bab278000 rw-p 0000f000 fd:05 2426                       /var/lib/irods/plugins/auth/libnative.so
7f1bab278000-7f1bab29a000 r-xp 00000000 fd:05 2417                       /var/lib/irods/plugins/network/libssl.so
7f1bab29a000-7f1bab49a000 ---p 00022000 fd:05 2417                       /var/lib/irods/plugins/network/libssl.so
7f1bab49a000-7f1bab49b000 rw-p 00022000 fd:05 2417                       /var/lib/irods/plugins/network/libssl.so
7f1bab49b000-7f1bab4a9000 r-xp 00000000 fd:05 2416                       /var/lib/irods/plugins/network/libtcp.so
7f1bab4a9000-7f1bab6a8000 ---p 0000e000 fd:05 2416                       /var/lib/irods/plugins/network/libtcp.so
7f1bab6a8000-7f1bab6a9000 rw-p 0000d000 fd:05 2416                       /var/lib/irods/plugins/network/libtcp.so
7f1bab7aa000-7f1bab7af000 r-xp 00000000 fd:00 132259                     /lib64/libnss_dns-2.12.so
7f1bab7af000-7f1bab9ae000 ---p 00005000 fd:00 132259                     /lib64/libnss_dns-2.12.so
7f1bab9ae000-7f1bab9af000 r--p 00004000 fd:00 132259                     /lib64/libnss_dns-2.12.so
7f1bab9af000-7f1bab9b0000 rw-p 00005000 fd:00 132259                     /lib64/libnss_dns-2.12.so
7f1bab9b0000-7f1bab9bc000 r-xp 00000000 fd:00 132261                     /lib64/libnss_files-2.12.so
7f1bab9bc000-7f1babbbc000 ---p 0000c000 fd:00 132261                     /lib64/libnss_files-2.12.so
7f1babbbc000-7f1babbbd000 r--p 0000c000 fd:00 132261                     /lib64/libnss_files-2.12.so
7f1babbbd000-7f1babbbe000 rw-p 0000d000 fd:00 132261                     /lib64/libnss_files-2.12.so
7f1babbca000-7f1babbd3000 r-xp 00000000 fd:05 2428                       /var/lib/irods/plugins/api/librsSetRoundRobinContext_client.so
7f1babbd3000-7f1babdd2000 ---p 00009000 fd:05 2428                       /var/lib/irods/plugins/api/librsSetRoundRobinContext_client.so
7f1babdd2000-7f1babdd3000 rw-p 00008000 fd:05 2428                       /var/lib/irods/plugins/api/librsSetRoundRobinContext_client.so
7f1babdd3000-7f1babde4000 r-xp 00000000 fd:05 2430                       /var/lib/irods/plugins/api/libhelloworld_client.so
7f1babde4000-7f1babfe3000 ---p 00011000 fd:05 2430                       /var/lib/irods/plugins/api/libhelloworld_client.so
7f1babfe3000-7f1babfe4000 rw-p 00010000 fd:05 2430                       /var/lib/irods/plugins/api/libhelloworld_client.so
7f1babfe4000-7f1babff5000 r-xp 00000000 fd:05 2429                       /var/lib/irods/plugins/api/libhelloworld_server.so
7f1babff5000-7f1bac1f4000 ---p 00011000 fd:05 2429                       /var/lib/irods/plugins/api/libhelloworld_server.so
7f1bac1f4000-7f1bac1f5000 rw-p 00010000 fd:05 2429                       /var/lib/irods/plugins/api/libhelloworld_server.so
7f1bac1f5000-7f1bac210000 r-xp 00000000 fd:05 2427                       /var/lib/irods/plugins/api/librsSetRoundRobinContext_server.so
7f1bac210000-7f1bac40f000 ---p 0001b000 fd:05 2427                       /var/lib/irods/plugins/api/librsSetRoundRobinContext_server.so
7f1bac40f000-7f1bac410000 rw-p 0001a000 fd:05 2427                       /var/lib/irods/plugins/api/librsSetRoundRobinContext_server.so
7f1bac410000-7f1bac411000 rw-p 00000000 00:00 0 
7f1bac411000-7f1bb22a2000 r--p 00000000 fd:00 153872                     /usr/lib/locale/locale-archive
7f1bb22a2000-7f1bb22b6000 rw-p 00000000 00:00 0 
7f1bb22b9000-7f1bb22bb000 rw-p 00000000 00:00 0 
7f1bb22bb000-7f1bb22c2000 r--s 00000000 fd:00 153891                     /usr/lib64/gconv/gconv-modules.cache
7f1bb22c2000-7f1bb22c3000 rw-p 00000000 00:00 0 
7fff8831b000-7fff88330000 rw-p 00000000 00:00 0                          [stack]
7fff883ff000-7fff88400000 r-xp 00000000 00:00 0                          [vdso]
ffffffffff600000-ffffffffff601000 r-xp 00000000 00:00 0                  [vsyscall]
Jun 26 11:10:34 pid:53732 NOTICE: Agent process 32378 exited with status 6

michael-conway commented 9 years ago

updates, using a dedicated test Java program run on the iCat server, clean logs

original test file (charles proxy msi) 2 times and another “file80MB” as well. This worked, telling from the file size and Jargon execution speed, while the charles proxy msi file failed in both times.

runit.out_20150706_0842 <- failed transfer runit.out_20150706_0948 <- transfer seemed to have worked runit.out_20150706_0951 <- failed transfer

sgpeo 0 bhcqa2Resc 43621760 2015-07-06.08:45 & charles-mc-pam-from-icat sgpeo 0 bhcqa2Resc 43621760 2015-07-06.09:53 & charles-mc-pam-from-icat2 sgpeo 0 bhcqa2Resc 83886080 2015-07-06.09:48 & file80MB-from-icat

original files: -rw-r----- 1 gbecd unixdef 49853441 Jul 6 08:05 charles-proxy-win64-3.8.3.msi -rw-r--r-- 1 gbecd unixdef 83886080 Jun 3 07:08 file80MB

michael-conway commented 9 years ago

This is the issue. Jargon doesn't have SSL implemented yet in the transport

""ok, good! Another information that comes to my mind: we have the cs_neg_require option set so that SSL is used (not only for authentication, but all data transfer). Maybe I should compile a couple of config files and send them over, so you get a complete picture? I could do that tomorrow."

michael-conway commented 9 years ago

This is an issue with SSL negotiation, and will be addressed in issue #4

Work is in the issue4 branch of Jargon

DICE-UNC / jargon

sys len read error parallel transfer 4.0.3 iRODS / PAM, remote storage resource #132