Invalid message length in SFTP protocol [40]

[jamoros]

This new error has been happening, it seems that the files are downloading but our job deletes them after because of the error. What could be causing this and how can we resolve it? Thanks as always

"[Invalid message length in SFTP protocol [40], Invalid message length in SFTP protocol [1694498825], Invalid message length in SFTP protocol [1426063360], Invalid message length in SFTP protocol [0], Invalid message length in SFTP protocol [391407717], Invalid message length in SFTP protocol [544174181], Invalid message length in SFTP protocol [1918989417]

[jamoros]

I turned on TRACE logging and it seems the culprit is that we run out of memory. The connection closes but our code keeps trying to download files (we can fix that part if we have to but we kinda do an all or nothing, OR even just batch them). Here is the logging hopefully this may help catch a bug

`28 Jun 2022 16:14:03,795 [ pool-5-thread-1] TRACE - transport-protocol: Operation task is starting 28 Jun 2022 16:14:03,795 [ pool-5-thread-1] TRACE - Starting transport-client WRITE 28 Jun 2022 16:14:03,795 [ pool-5-thread-1] TRACE - Processing socket WRITE event 28 Jun 2022 16:14:03,795 [ pool-5-thread-1] DEBUG - Processing APPLICATION WRITE event 28 Jun 2022 16:14:03,795 [ pool-5-thread-1] TRACE - Written 148 bytes to socket 28 Jun 2022 16:14:03,893 [ pool-5-thread-1] DEBUG - Sent SSH_MSG_CHANNEL_DATA seq=2449 len=61 channel=0 remote=0 localWindow=744412 remoteWindow=902389 28 Jun 2022 16:14:03,894 [ pool-5-thread-1] TRACE - transport-protocol: No more tasks, will wait for a few more seconds before completing task 28 Jun 2022 16:14:03,894 [ pool-5-thread-1] TRACE - {}: Operation task has ended 28 Jun 2022 16:14:03,894 [ SSHD-TRANSFER-1] TRACE - transport-client has state ops=1 READ 28 Jun 2022 16:14:03,894 [ SSHD-TRANSFER-1] TRACE - Selected key 28 Jun 2022 16:14:03,894 [ SSHD-TRANSFER-1] TRACE - Processing transport-client READ 28 Jun 2022 16:14:03,894 [ SSHD-TRANSFER-1] TRACE - transport-protocol: Starting new subsystem task 28 Jun 2022 16:14:03,894 [ pool-5-thread-1] TRACE - transport-protocol: Operation task is starting 28 Jun 2022 16:14:03,894 [ pool-5-thread-1] TRACE - Starting transport-client READ 28 Jun 2022 16:14:03,894 [ pool-5-thread-1] TRACE - Processing socket READ event 28 Jun 2022 16:14:03,895 [ pool-2-thread-1] TRACE - Received sent data notification 28 Jun 2022 16:14:03,895 [ pool-2-thread-1] TRACE - connection-protocol: Starting new subsystem task 28 Jun 2022 16:14:03,895 [ pool-5-thread-1] TRACE - Read 16484 bytes from socket 28 Jun 2022 16:14:03,895 [ pool-5-thread-1] TRACE - Processing APPLICATION READ data 28 Jun 2022 16:14:03,896 [ pool-5-thread-1] TRACE - Resetting idle state 28 Jun 2022 16:14:03,896 [ pool-2-thread-1] TRACE - Checking window space on channel=0 window=744412 cached=0 extended=0 java.lang.OutOfMemoryError: Java heap space at java.util.Arrays.copyOf(Arrays.java:3332) at java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:124) at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:649) at java.lang.StringBuffer.append(StringBuffer.java:381) at com.sshtools.common.util.Utils.bytesToHex(Utils.java:88) at com.sshtools.common.util.Utils.bytesToHex(Utils.java:74) at com.sshtools.synergy.ssh.TransportProtocol.processMessage(TransportProtocol.java:1924) at com.sshtools.synergy.ssh.TransportProtocol.processBinaryPackets(TransportProtocol.java:627) at com.sshtools.synergy.ssh.TransportProtocol.onSocketRead(TransportProtocol.java:458) at com.sshtools.client.TransportProtocolClient.onSocketRead(TransportProtocolClient.java:64) at com.sshtools.synergy.nio.SocketConnection.processReadEvent(SocketConnection.java:294) at com.sshtools.synergy.nio.SshEngine$SocketReadWriteTask.doTask(SshEngine.java:779) at com.sshtools.common.ssh.ConnectionAwareTask.run(ConnectionAwareTask.java:45) at com.sshtools.common.ssh.ExecutorOperationSupport$OperationTask.executeAllTasks(ExecutorOperationSupport.java:127) at com.sshtools.common.ssh.ExecutorOperationSupport$OperationTask.run(ExecutorOperationSupport.java:84) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 28 Jun 2022 16:14:04,119 [ pool-3-thread-1] TRACE - connection-protocol: Operation task is starting 28 Jun 2022 16:14:04,121 [ pool-3-thread-1] TRACE - connection-protocol: No more tasks, will wait for a few more seconds before completing task 28 Jun 2022 16:14:04,121 [ pool-3-thread-1] TRACE - {}: Operation task has ended 28 Jun 2022 16:14:04,121 [ pool-5-thread-1] INFO - Transport error localhost/127.0.0.1:3128 Java heap space 28 Jun 2022 16:14:04,122 [ pool-5-thread-1] DEBUG - Connection Error java.lang.OutOfMemoryError: Java heap space at java.util.Arrays.copyOf(Arrays.java:3332) at java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:124) at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:649) at java.lang.StringBuffer.append(StringBuffer.java:381) at com.sshtools.common.util.Utils.bytesToHex(Utils.java:88) at com.sshtools.common.util.Utils.bytesToHex(Utils.java:74) at com.sshtools.synergy.ssh.TransportProtocol.processMessage(TransportProtocol.java:1924) at com.sshtools.synergy.ssh.TransportProtocol.processBinaryPackets(TransportProtocol.java:627) at com.sshtools.synergy.ssh.TransportProtocol.onSocketRead(TransportProtocol.java:458) at com.sshtools.client.TransportProtocolClient.onSocketRead(TransportProtocolClient.java:64) at com.sshtools.synergy.nio.SocketConnection.processReadEvent(SocketConnection.java:294) at com.sshtools.synergy.nio.SshEngine$SocketReadWriteTask.doTask(SshEngine.java:779) at com.sshtools.common.ssh.ConnectionAwareTask.run(ConnectionAwareTask.java:45) at com.sshtools.common.ssh.ExecutorOperationSupport$OperationTask.executeAllTasks(ExecutorOperationSupport.java:127) at com.sshtools.common.ssh.ExecutorOperationSupport$OperationTask.run(ExecutorOperationSupport.java:84) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745)

28 Jun 2022 16:14:04,122 [ pool-5-thread-1] INFO - Disconnect localhost/127.0.0.1:3128 The application encountered an error 28 Jun 2022 16:14:04,123 [ pool-5-thread-1] DEBUG - Posting message com.sshtools.synergy.ssh.TransportProtocol$DisconnectMessage to queue 28 Jun 2022 16:14:04,123 [ pool-5-thread-1] TRACE - There is 0 bytes left to process on socket 28 Jun 2022 16:14:04,123 [ pool-5-thread-1] TRACE - transport-protocol: No more tasks, will wait for a few more seconds before completing task 28 Jun 2022 16:14:04,123 [ pool-5-thread-1] TRACE - {}: Operation task has ended 28 Jun 2022 16:14:04,123 [ SSHD-TRANSFER-1] TRACE - Flag selector as READ/WRITE 28 Jun 2022 16:14:04,123 [ SSHD-TRANSFER-1] TRACE - transport-client has state ops=5 READ/WRITE 28 Jun 2022 16:14:04,124 [ SSHD-TRANSFER-1] TRACE - Selected key 28 Jun 2022 16:14:04,124 [ SSHD-TRANSFER-1] TRACE - Processing transport-client WRITE 28 Jun 2022 16:14:04,124 [ SSHD-TRANSFER-1] TRACE - transport-protocol: Starting new subsystem task 28 Jun 2022 16:14:04,124 [ pool-5-thread-1] TRACE - transport-protocol: Operation task is starting 28 Jun 2022 16:14:04,124 [ pool-5-thread-1] TRACE - Starting transport-client WRITE 28 Jun 2022 16:14:04,124 [ pool-5-thread-1] TRACE - Processing socket WRITE event 28 Jun 2022 16:14:04,124 [ pool-5-thread-1] DEBUG - Processing APPLICATION WRITE event 28 Jun 2022 16:14:04,125 [ pool-5-thread-1] TRACE - Written 132 bytes to socket 28 Jun 2022 16:14:04,125 [ pool-5-thread-1] DEBUG - Sent SSH_MSG_DISCONNECT reason=2 The application encountered an error 28 Jun 2022 16:14:04,125 [ pool-5-thread-1] TRACE - Closing socket 28 Jun 2022 16:14:04,126 [ pool-5-thread-1] TRACE - Closing protocol engine 28 Jun 2022 16:14:04,126 [ pool-5-thread-1] INFO - Connection closed localhost/127.0.0.1:3128 28 Jun 2022 16:14:04,126 [ pool-5-thread-1] DEBUG - Performing internal disconnect 01b2c0f2-1663-4a51-bd5f-6fb37e8d2fcb 28 Jun 2022 16:14:04,127 [ pool-5-thread-1] DEBUG - Stopping the active service 28 Jun 2022 16:14:04,127 [ pool-5-thread-1] DEBUG - Cleaning up connection protocol references 28 Jun 2022 16:14:04,127 [ pool-5-thread-1] DEBUG - Checking close state force=true channelType=session channel=0 remote=0 localWindow=744412 remoteWindow=902389 28 Jun 2022 16:14:04,127 [ pool-5-thread-1] DEBUG - Adding our close message to queue channel=0 remote=0 localWindow=744412 remoteWindow=902389 28 Jun 2022 16:14:04,127 [ pool-5-thread-1] DEBUG - Requesting to complete the close operation connected=false forceClose=true channel=0 remote=0 localWindow=744412 remoteWindow=902389 28 Jun 2022 16:14:04,228 [ pool-5-thread-1] TRACE - connection-protocol: Starting new subsystem task 28 Jun 2022 16:14:04,228 [ pool-5-thread-1] DEBUG - Logging off user 28 Jun 2022 16:14:04,228 [ pool-5-thread-1] DEBUG - Submitting transport cleanup to executor service 28 Jun 2022 16:14:04,228 [ pool-3-thread-1] TRACE - connection-protocol: Operation task is starting 28 Jun 2022 16:14:04,229 [ pool-3-thread-1] DEBUG - Completing the close operation channel=0 remote=0 localWindow=744412 remoteWindow=902389 28 Jun 2022 16:14:04,230 [ pool-2-thread-1] TRACE - Checking window space on channel=0 window=744412 cached=0 extended=0 28 Jun 2022 16:14:04,230 [ pool-2-thread-1] TRACE - Checking window space on channel=0 window=744412 cached=0 extended=0 28 Jun 2022 16:14:04,230 [ pool-2-thread-1] TRACE - Checking window space on channel=0 window=744412 cached=0 extended=0 28 Jun 2022 16:14:04,231 [ pool-2-thread-1] DEBUG - Checking close state force=false channelType=session channel=0 remote=0 localWindow=744412 remoteWindow=902389 28 Jun 2022 16:14:04,231 [ pool-2-thread-1] DEBUG - Requesting to complete the close operation connected=false forceClose=false channel=0 remote=0 localWindow=744412 remoteWindow=902389 28 Jun 2022 16:14:04,231 [ pool-3-thread-1] DEBUG - Freeing channel=0 28 Jun 2022 16:14:04,231 [ pool-5-thread-1] TRACE - transport-protocol: Starting new subsystem task 28 Jun 2022 16:14:04,231 [ pool-5-thread-1] TRACE - transport-protocol: No more tasks, will wait for a few more seconds before completing task 28 Jun 2022 16:14:04,232 [ pool-5-thread-1] TRACE - {}: Operation task has ended 28 Jun 2022 16:14:04,232 [ pool-2-thread-1] INFO - Optimized read did not transfer any data 28 Jun 2022 16:14:04,232 [ pool-4-thread-1] TRACE - transport-protocol: Operation task is starting 28 Jun 2022 16:14:04,233 [ pool-4-thread-1] TRACE - transport-protocol: Submitting clean up operation to executor service 28 Jun 2022 16:14:04,234 [ pool-5-thread-1] TRACE - transport-protocol: Cleaning up operations 28 Jun 2022 16:14:04,235 [ pool-5-thread-1] TRACE - transport-protocol: Waiting for operations to complete 28 Jun 2022 16:14:04,238 [ pool-3-thread-1] DEBUG - Freeing channel channel=0 remote=0 localWindow=744412 remoteWindow=902389 28 Jun 2022 16:14:04,239 [ pool-3-thread-1] TRACE - connection-protocol: No more tasks, will wait for a few more seconds before completing task 28 Jun 2022 16:14:04,239 [ pool-3-thread-1] TRACE - {}: Operation task has ended 28 Jun 2022 16:14:04,240 [ pool-4-thread-1] DEBUG - Firing EVENT_DISCONNECTED success=true 28 Jun 2022 16:14:04,240 [ pool-4-thread-1] TRACE - transport-protocol: No more tasks, will wait for a few more seconds before completing task 28 Jun 2022 16:14:04,240 [ pool-4-thread-1] TRACE - {}: Operation task has ended 28 Jun 2022 16:14:04,241 [ pool-5-thread-1] TRACE - transport-protocol: All operations have completed 28 Jun 2022 16:14:04,367 [ pool-2-thread-1] DEBUG - Queue Buffer rem=49 pos=0 limit=49 capacity=35004 28 Jun 2022 16:14:04,368 [ pool-2-thread-1] ERROR - Channel I/O error java.io.IOException: Channel has been closed at com.sshtools.synergy.ssh.ChannelNG.sendChannelDataAndBlock(ChannelNG.java:502) at com.sshtools.synergy.ssh.ChannelNG.sendChannelDataAndBlock(ChannelNG.java:476) at com.sshtools.synergy.ssh.ChannelNG.sendChannelDataAndBlock(ChannelNG.java:462) at com.sshtools.client.tasks.AbstractSubsystem.sendMessage(AbstractSubsystem.java:137) at com.sshtools.client.sftp.SftpChannel.closeHandle(SftpChannel.java:2172) at com.sshtools.client.sftp.SftpChannel.closeFile(SftpChannel.java:2193) at com.sshtools.client.sftp.SftpClient.get(SftpClient.java:1555) at com.sshtools.client.sftp.SftpClient.get(SftpClient.java:1105) at com.sshtools.client.sftp.SftpClient.get(SftpClient.java:1185) at com.sshtools.client.sftp.SftpClient.get(SftpClient.java:1205) at com.sshtools.client.sftp.SftpClientTask.get(SftpClientTask.java:660) at ftm_manager.ftm_manager_0_1.ftm_manager$3.doSftp(ftm_manager.java:26902) at com.sshtools.client.sftp.SftpClientTask.doTask(SftpClientTask.java:55) at com.sshtools.common.ssh.ConnectionAwareTask.run(ConnectionAwareTask.java:45) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745)`

[ludup]

Invalid length like that generally means the SFTP stream has become corrupted in some way, such as a message being received that does not conform to the protocol and thus data gets out of sync and we attempt to decode an int from data that is not an encoded int.

I think your debug caused the OOM as it's trying to output the data as hex. It's certainly not the real issue as that code is only executed in debug. There are generally checks to ensure arrays like that are not allocated from messages received by the client.

Can you consistently reproduce the error (the original error)? If so running some binary logging would help; we could see where the stream becomes corrupted.

[jamoros]

So our fix was to just bump up the Xmx value and now it wont fail, so we're good to go here.

[jamoros]

I reopened this issue because we're having the same issue with another SFTP. This time we're not getting OOM, here is with INFO logging and my own logging.

08 Aug 2022 16:29:11,854 [     pool-1-thread-1]   INFO - Connnection filetransfer.site.com:2022 identifies itself as SSH-2.0-Serv-U_15.0.1.20
Is Connected: true
Authenticated
Working directory: /
Current filename contains wildcard.
Folder path: /mailbox
Exception: SshException
Exception message: Unexpected length of 808464432 bytes exceeds available data of 129824 bytes
08 Aug 2022 16:29:12,744 [                main]   INFO - Disconnect filetransfer.site.com:2022 By Application
End of SFTP Download
08 Aug 2022 16:29:12,749 [     pool-2-thread-1]   INFO - Connection closed filetransfer.site.com:2022

I am able to consistently reproduce this error, can you please point me to the right direct on binary logging?

Because I have to support wildcards, I implemented something like this, and then it loops through the array to match file names using Pattern/Matcher.

        System.out.println("Current filename contains wildcard.");
        System.out.println("Folder path: " + folderPath);
        SftpFile[] filesFound = ls(folderPath);
        System.out.println("Files found: " + filesFound.length);

It fails at

SftpFile[] filesFound = ls(folderPath);

Would love to resolve this asap, any help would be greatly appreciated.

Thanks

[jamoros]

So debugging, when trying to checkLength (which throws the exception) via bar.readString in SftpChannel #extractFiles. One of the strings returns a long string instead of a regular file name (like a few previous file names). The string has all the file names plus unreadable characters. On the next loop the checkLength throws the exception. Hopefully this provides more insight on whats happening here. Im wondering if its the SFTP thats returning something we dont require.

[ludup]

All you need to do to get binary logging is to enable TRACE mode.

However, if you can step through the code can you check what the API does and compare it to the SFTP specifications. As I said earlier in the issue this happens when the stream becomes corrupt such as a message being received that does not conform to the protocol. If you can find out what that is, we're halfway to fixing it.

Make sure you select the right protocol version, you should be able to see that in the log.

Or identify the packet being parsed that generates the error and paste it back here along with the protocol version and I'll check.

[jamoros]

According to the winscp log the transfer protocol is SFTP (SCP).

Here is the trace log:

09 Aug 2022 11:45:54,071 [     SSHD-TRANSFER-1]  TRACE - Selected key
09 Aug 2022 11:45:54,071 [     SSHD-TRANSFER-1]  TRACE - Processing transport-client READ
09 Aug 2022 11:45:54,071 [     SSHD-TRANSFER-1]  TRACE - transport-protocol: Starting new subsystem task
09 Aug 2022 11:45:54,071 [     pool-4-thread-1]  TRACE - transport-protocol: Operation task is starting
09 Aug 2022 11:45:54,071 [     pool-4-thread-1]  TRACE - Starting transport-client READ
09 Aug 2022 11:45:54,071 [     pool-4-thread-1]  TRACE - Processing socket READ event
09 Aug 2022 11:45:54,072 [     pool-4-thread-1]  TRACE - Read 4240 bytes from socket
09 Aug 2022 11:45:54,072 [     pool-4-thread-1]  TRACE - Processing APPLICATION READ data
09 Aug 2022 11:45:54,073 [     pool-4-thread-1]  TRACE - Resetting idle state
09 Aug 2022 11:45:54,074 [     pool-4-thread-1]  TRACE - 
5e 00 00 00 00 00 00 10 4f 00 00 10 4b 68 00 00 00 05 00 00 00 1c 00 00 00 43 45 78 74 50 6f 73  [ ^.......O...Kh...........CExtPos ]
69 74 69 6f 6e 42 61 6c 61 6e 63 65 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 38 2d 30 31  [ itionBalance_6500WYNK_2022-08-01 ]
5f 32 30 32 32 30 38 30 31 5f 30 30 30 30 30 30 2d 31 30 32 31 31 36 30 37 2e 43 53 56 00 00 03  [ _20220801_000000-10211607.CSV... ]
bd 01 00 00 00 00 00 01 5c 9e 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00  [ ........\.....user....group..... ]
00 00 00 62 e8 8d 05 00 00 00 00 00 00 00 00 62 e8 8c f9 00 00 00 00 00 00 00 00 62 e8 8c f9 00  [ ...b...........b...........b.... ]
00 00 00 00 00 00 10 00 00 00 f7 00 00 00 44 45 78 74 50 6f 73 69 74 69 6f 6e 42 61 6c 61 6e 63  [ ..............DExtPositionBalanc ]
65 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 38 2d 30 38 5f 32 30 32 32 30 38 30 38 5f 30  [ e_6500WYNK_2022-08-08_20220808_0 ]
30 30 30 30 30 2d 38 34 38 33 36 35 30 38 38 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 01 5c 93  [ 00000-848365088.CSV...........\. ]
00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 f1 c5 0d 00 00 00  [ ....user....group........b...... ]
00 00 00 00 00 62 f1 c5 03 00 00 00 00 00 00 00 00 62 f1 c5 03 00 00 00 00 00 00 00 10 00 00 00  [ .....b...........b.............. ]
f7 00 00 00 40 4f 70 65 6e 52 65 70 6f 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f 32 30  [ ....@OpenRepoExtract_6500WYNK_20 ]
32 32 2d 30 38 2d 30 31 5f 32 30 32 32 30 38 30 31 5f 30 30 30 30 30 30 2d 33 33 33 30 39 31 36  [ 22-08-01_20220801_000000-3330916 ]
30 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 00 4f aa 00 00 00 04 75 73 65 72 00 00 00 05 67 72  [ 0.CSV...........O.....user....gr ]
6f 75 70 00 00 81 b6 00 00 00 00 62 e8 8d 2e 00 00 00 00 00 00 00 00 62 e8 8c fc 00 00 00 00 00  [ oup........b...........b........ ]
00 00 00 62 e8 8c fc 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 43 52 70 74 41 63 74 69 76 69  [ ...b..................CRptActivi ]
74 79 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 38 2d 30 31 5f 32 30  [ tyExtract_6500WYNK_2022-08-01_20 ]
32 32 30 38 30 31 5f 30 30 30 30 30 30 35 37 39 38 36 38 39 38 33 2e 43 53 56 00 00 03 bd 01 00  [ 220801_000000579868983.CSV...... ]
00 00 00 00 00 0b 4a 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00  [ ......J....user....group........ ]
62 e8 8d 2e 00 00 00 00 00 00 00 00 62 e8 8d 21 00 00 00 00 00 00 00 00 62 e8 8d 21 00 00 00 00  [ b...........b..!........b..!.... ]
00 00 00 10 00 00 00 f7 00 00 00 43 45 78 74 50 6f 73 69 74 69 6f 6e 42 61 6c 61 6e 63 65 5f 36  [ ...........CExtPositionBalance_6 ]
35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 38 2d 30 32 5f 32 30 32 32 30 38 30 32 5f 30 30 30 30  [ 500WYNK_2022-08-02_20220802_0000 ]
30 30 31 37 39 37 39 38 36 35 39 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 01 5c 93 00 00 00 04  [ 00179798659.CSV...........\..... ]
75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 e9 de 13 00 00 00 00 00 00 00  [ user....group........b.......... ]
00 62 e9 de 04 00 00 00 00 00 00 00 00 62 e9 de 04 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00  [ .b...........b.................. ]
40 4f 70 65 6e 52 65 70 6f 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30  [ @OpenRepoExtract_6500WYNK_2022-0 ]
38 2d 30 38 5f 32 30 32 32 30 38 30 38 5f 30 30 30 30 30 30 38 31 31 32 31 38 35 35 39 2e 43 53  [ 8-08_20220808_000000811218559.CS ]
56 00 00 03 bd 01 00 00 00 00 00 00 4f aa 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00  [ V...........O.....user....group. ]
00 81 b6 00 00 00 00 62 f1 c5 22 00 00 00 00 00 00 00 00 62 f1 c5 17 00 00 00 00 00 00 00 00 62  [ .......b.."........b...........b ]
f1 c5 17 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 45 52 70 74 41 63 74 69 76 69 74 79 45 78  [ ..................ERptActivityEx ]
74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 38 2d 30 38 5f 32 30 32 32 30 38  [ tract_6500WYNK_2022-08-08_202208 ]
30 38 5f 30 30 30 30 30 30 2d 31 34 31 36 30 39 37 35 37 39 2e 43 53 56 00 00 03 bd 01 00 00 00  [ 08_000000-1416097579.CSV........ ]
00 00 00 05 c6 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 f1  [ .........user....group........b. ]
c5 36 00 00 00 00 00 00 00 00 62 f1 c5 29 00 00 00 00 00 00 00 00 62 f1 c5 29 00 00 00 00 00 00  [ .6........b..)........b..)...... ]
00 10 00 00 00 f7 00 00 00 40 4f 70 65 6e 52 65 70 6f 45 78 74 72 61 63 74 5f 36 35 30 30 57 59  [ .........@OpenRepoExtract_6500WY ]
4e 4b 5f 32 30 32 32 2d 30 38 2d 30 32 5f 32 30 32 32 30 38 30 32 5f 30 30 30 30 30 30 35 33 33  [ NK_2022-08-02_20220802_000000533 ]
36 32 39 34 36 36 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 00 4f a0 00 00 00 04 75 73 65 72 00  [ 629466.CSV...........O.....user. ]
00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 e9 de 2a 00 00 00 00 00 00 00 00 62 e9 de 07  [ ...group........b..*........b... ]
00 00 00 00 00 00 00 00 62 e9 de 07 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 42 45 78 74 50  [ ........b..................BExtP ]
6f 73 69 74 69 6f 6e 42 61 6c 61 6e 63 65 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 38 2d  [ ositionBalance_6500WYNK_2022-08- ]
30 33 5f 32 30 32 32 30 38 30 33 5f 30 30 30 30 30 30 32 34 36 36 39 38 39 35 2e 43 53 56 00 00  [ 03_20220803_00000024669895.CSV.. ]
03 bd 01 00 00 00 00 00 01 5c 94 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6  [ .........\.....user....group.... ]
00 00 00 00 62 f1 70 15 00 00 00 00 00 00 00 00 62 eb 2e f1 00 00 00 00 00 00 00 00 62 eb 2e f1  [ ....b.p.........b...........b... ]
00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 45 45 78 74 50 6f 73 69 74 69 6f 6e 42 61 6c 61 6e  [ ...............EExtPositionBalan ]
63 65 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 37 2d 32 37 5f 32 30 32 32 30 37 32 37 5f  [ ce_6500WYNK_2022-07-27_20220727_ ]
30 30 30 30 30 30 2d 31 38 30 39 32 36 35 35 30 38 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 01  [ 000000-1809265508.CSV........... ]
55 15 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 e1 fe 70 00  [ U.....user....group........b..p. ]
00 00 00 00 00 00 00 62 e1 fe 67 00 00 00 00 00 00 00 00 62 e1 fe 67 00 00 00 00 00 00 00 10 00  [ .......b..g........b..g......... ]
00 00 f7 00 00 00 3f 4f 70 65 6e 52 65 70 6f 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f  [ ......?OpenRepoExtract_6500WYNK_ ]
32 30 32 32 2d 30 37 2d 32 37 5f 32 30 32 32 30 37 32 37 5f 30 30 30 30 30 30 31 33 36 35 33 34  [ 2022-07-27_20220727_000000136534 ]
36 30 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 00 4a 07 00 00 00 04 75 73 65 72 00 00 00 05 67  [ 60.CSV...........J.....user....g ]
72 6f 75 70 00 00 81 b6 00 00 00 00 62 e1 fe 84 00 00 00 00 00 00 00 00 62 e1 fe 69 00 00 00 00  [ roup........b...........b..i.... ]
00 00 00 00 62 e1 fe 69 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 45 52 70 74 41 63 74 69 76  [ ....b..i...............ERptActiv ]
69 74 79 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 38 2d 30 32 5f 32  [ ityExtract_6500WYNK_2022-08-02_2 ]
30 32 32 30 38 30 32 5f 30 30 30 30 30 30 2d 31 32 31 35 37 34 30 35 31 36 2e 43 53 56 00 00 03  [ 0220802_000000-1215740516.CSV... ]
bd 01 00 00 00 00 00 00 08 80 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00  [ ..............user....group..... ]
00 00 00 62 e9 de 53 00 00 00 00 00 00 00 00 62 e9 de 2c 00 00 00 00 00 00 00 00 62 e9 de 2c 00  [ ...b..S........b..,........b..,. ]
00 00 00 00 00 00 10 00 00 00 f7 00 00 00 40 4f 70 65 6e 52 65 70 6f 45 78 74 72 61 63 74 5f 36  [ ..............@OpenRepoExtract_6 ]
35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 38 2d 30 33 5f 32 30 32 32 30 38 30 33 5f 30 30 30 30  [ 500WYNK_2022-08-03_20220803_0000 ]
30 30 39 35 34 32 31 32 30 31 37 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 00 4f aa 00 00 00 04  [ 00954212017.CSV...........O..... ]
75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 f1 50 a4 00 00 00 00 00 00 00  [ user....group........b.P........ ]
00 62 eb 2f 07 00 00 00 00 00 00 00 00 62 eb 2f 07 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00  [ .b./.........b./................ ]
43 52 70 74 41 63 74 69 76 69 74 79 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32  [ CRptActivityExtract_6500WYNK_202 ]
32 2d 30 38 2d 30 33 5f 32 30 32 32 30 38 30 33 5f 30 30 30 30 30 30 32 36 37 31 39 32 38 34 38  [ 2-08-03_20220803_000000267192848 ]
2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 00 06 ff 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f  [ .CSV.................user....gro ]
75 70 00 00 81 b6 00 00 00 00 62 f1 70 0a 00 00 00 00 00 00 00 00 62 eb 2f 17 00 00 00 00 00 00  [ up........b.p.........b./....... ]
00 00 62 eb 2f 17 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 44 45 78 74 50 6f 73 69 74 69 6f  [ ..b./................DExtPositio ]
6e 42 61 6c 61 6e 63 65 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 38 2d 30 34 5f 32 30 32  [ nBalance_6500WYNK_2022-08-04_202 ]
32 30 38 30 34 5f 30 30 30 30 30 30 31 38 35 31 36 35 30 30 36 39 2e 43 53 56 00 00 03 bd 01 00  [ 20804_0000001851650069.CSV...... ]
00 00 00 00 01 5c 94 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00  [ .....\.....user....group........ ]
62 ec 86 a0 00 00 00 00 00 00 00 00 62 ec 86 92 00 00 00 00 00 00 00 00 62 ec 86 92 00 00 00 00  [ b...........b...........b....... ]
00 00 00 10 00 00 00 f7 00 00 00 44 52 70 74 41 63 74 69 76 69 74 79 45 78 74 72 61 63 74 5f 36  [ ...........DRptActivityExtract_6 ]
35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 38 2d 30 34 5f 32 30 32 32 30 38 30 34 5f 30 30 30 30  [ 500WYNK_2022-08-04_20220804_0000 ]
30 30 2d 33 39 31 38 30 34 34 35 38 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 00 0b 7e 00 00 00  [ 00-391804458.CSV............~... ]
04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 ec 86 c8 00 00 00 00 00 00  [ .user....group........b......... ]
00 00 62 ec 86 b9 00 00 00 00 00 00 00 00 62 ec 86 b9 00 00 00 00 00 00 00 10 00 00 00 f7 00 00  [ ..b...........b................. ]
00 3f 4f 70 65 6e 52 65 70 6f 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d  [ .?OpenRepoExtract_6500WYNK_2022- ]
30 38 2d 30 34 5f 32 30 32 32 30 38 30 34 5f 30 30 30 30 30 30 32 38 39 30 31 39 36 39 2e 43 53  [ 08-04_20220804_00000028901969.CS ]
56 00 00 03 bd 01 00 00 00 00 00 00 4f 9b 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00  [ V...........O.....user....group. ]
00 81 b6 00 00 00 00 62 ec 86 dd 00 00 00 00 00 00 00 00 62 ec 86 99 00 00 00 00 00 00 00 00 62  [ .......b...........b...........b ]
ec 86 99 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 44 45 78 74 50 6f 73 69 74 69 6f 6e 42 61  [ ..................DExtPositionBa ]
6c 61 6e 63 65 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 38 2d 30 35 5f 32 30 32 32 30 38  [ lance_6500WYNK_2022-08-05_202208 ]
30 35 5f 30 30 30 30 30 30 31 34 32 35 39 36 32 34 37 31 2e 43 53 56 00 00 03 bd 01 00 00 00 00  [ 05_0000001425962471.CSV......... ]
00 01 5c 93 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 ed ef  [ ..\.....user....group........b.. ]
8f 00 00 00 00 00 00 00 00 62 ed ef 87 00 00 00 00 00 00 00 00 62 ed ef 87 00 00 00 00 00 00 00  [ .........b...........b.......... ]
10 00 00 00 f7 00 00 00 41 4f 70 65 6e 52 65 70 6f 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e  [ ........AOpenRepoExtract_6500WYN ]
4b 5f 32 30 32 32 2d 30 38 2d 30 35 5f 32 30 32 32 30 38 30 35 5f 30 30 30 30 30 30 31 31 33 31  [ K_2022-08-05_20220805_0000001131 ]
37 39 33 30 35 36 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 00 4f a0 00 00 00 04 75 73 65 72 00  [ 793056.CSV...........O.....user. ]
00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 ed ef a7 00 00 00 00 00 00 00 00 62 ed ef 96  [ ...group........b...........b... ]
00 00 00 00 00 00 00 00 62 ed ef 96 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 44 52 70 74 41  [ ........b..................DRptA ]
63 74 69 76 69 74 79 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 37 2d  [ ctivityExtract_6500WYNK_2022-07- ]
32 37 5f 32 30 32 32 30 37 32 37 5f 30 30 30 30 30 30 2d 35 31 32 39 31 32 34 33 37 2e 43 53 56  [ 27_20220727_000000-512912437.CSV ]
00 00 03 bd 01 00 00 00 00 00 00 0c a4 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00  [ .................user....group.. ]
81 b6 00 00 00 00 62 e1 fe af 00 00 00 00 00 00 00 00 62 e1 fe 8e 00 00 00 00 00 00 00 00 62 e1  [ ......b...........b...........b. ]
fe 8e 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 44 45 78 74 50 6f 73 69 74 69 6f 6e 42 61 6c  [ .................DExtPositionBal ]
61 6e 63 65 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 37 2d 32 38 5f 32 30 32 32 30 37 32  [ ance_6500WYNK_2022-07-28_2022072 ]
38 5f 30 30 30 30 30 30 2d 34 30 37 31 31 39 33 39 30 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00  [ 8_000000-407119390.CSV.......... ]
01 55 18 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 e3 48 4f  [ .U.....user....group........b.HO ]
00 00 00 00 00 00 00 00 62 e3 48 47 00 00 00 00 00 00 00 00 62 e3 48 47 00 00 00 00 00 00 00 10  [ ........b.HG........b.HG........ ]
00 00 00 f7 00 00 00 41 4f 70 65 6e 52 65 70 6f 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b  [ .......AOpenRepoExtract_6500WYNK ]
5f 32 30 32 32 2d 30 37 2d 32 38 5f 32 30 32 32 30 37 32 38 5f 30 30 30 30 30 30 31 36 32 38 33  [ _2022-07-28_20220728_00000016283 ]
30 37 30 38 30 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 00 4a 11 00 00 00 04 75 73 65 72 00 00  [ 07080.CSV...........J.....user.. ]
00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 e3 48 63 00 00 00 00 00 00 00 00 62 e3 48 5b 00  [ ..group........b.Hc........b.H[. ]
00 00 00 00 00 00 00 62 e3 48 5b 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 45 52 70 74 41 63  [ .......b.H[...............ERptAc ]
74 69 76 69 74 79 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 37 2d 32  [ tivityExtract_6500WYNK_2022-07-2 ]
38 5f 32 30 32 32 30 37 32 38 5f 30 30 30 30 30 30 2d 31 36 39 36 34 30 34 39 38 36 2e 43 53 56  [ 8_20220728_000000-1696404986.CSV ]
00 00 03 bd 01 00 00 00 00 00 00 05 c6 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00  [ .................user....group.. ]
81 b6 00 00 00 00 62 e3 48 8c 00 00 00 00 00 00 00 00 62 e3 48 6e 00 00 00 00 00 00 00 00 62 e3  [ ......b.H.........b.Hn........b. ]
48 6e 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 42 4f 70 65 6e 52 65 70 6f 45 78 74 72 61 63  [ Hn...............BOpenRepoExtrac ]
74 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 37 2d 32 38 5f 32 30 32 32 30 37 32 38 5f 30  [ t_6500WYNK_2022-07-28_20220728_0 ]
30 30 30 30 30 2d 31 35 30 39 30 34 35 33 38 32 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 00 4a  [ 00000-1509045382.CSV...........J ]
11 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 e3 55 55 00 00  [ .....user....group........b.UU.. ]
00 00 00 00 00 00 62 e3 55 49 00 00 00 00 00 00 00 00 62 e3 55 49 00 00 00 00 00 00 00 10 00 00  [ ......b.UI........b.UI.......... ]
00 f7 00 00 00 45 45 78 74 50 6f 73 69 74 69 6f 6e 42 61 6c 61 6e 63 65 5f 36 35 30 30 57 59 4e  [ .....EExtPositionBalance_6500WYN ]
4b 5f 32 30 32 32 2d 30 37 2d 32 39 5f 32 30 32 32 30 37 32 39 5f 30 30 30 30 30 30 2d 31 31 30  [ K_2022-07-29_20220729_000000-110 ]
38 39 36 36 35 32 33 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 01 5c 9a 00 00 00 04 75 73 65 72  [ 8966523.CSV...........\.....user ]
00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 e4 a5 a1 00 00 00 00 00 00 00 00 62 e4 a5  [ ....group........b...........b.. ]
94 00 00 00 00 00 00 00 00 62 e4 a5 94 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 43 52 70 74  [ .........b..................CRpt ]
41 63 74 69 76 69 74 79 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 38  [ ActivityExtract_6500WYNK_2022-08 ]
2d 30 35 5f 32 30 32 32 30 38 30 35 5f 30 30 30 30 30 30 37 37 39 38 34 33 31 34 36 2e 43 53 56  [ -05_20220805_000000779843146.CSV ]
00 00 03 bd 01 00 00 00 00 00 00 05 c6 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00  [ .................user....group.. ]
81 b6 00 00 00 00 62 ed ef bc 00 00 00 00 00 00 00 00 62 ed ef ad 00 00 00 00 00 00 00 00 62 ed  [ ......b...........b...........b. ]
ef ad 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 43 52 70 74 41 63 74 69 76 69 74 79 45 78 74  [ .................CRptActivityExt ]
72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 37 2d 32 39 5f 32 30 32 32 30 37 32  [ ract_6500WYNK_2022-07-29_2022072 ]
39 5f 30 30 30 30 30 30 39 33 35 32 35 30 30 33 37 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 00  [ 9_000000935250037.CSV........... ]
21 76 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 e4 a5 ca 00  [ !v....user....group........b.... ]
00 00 00 00 00 00 00 62 e4 a5 bd 00 00 00 00 00 00 00 00 62 e4 a5 bd 00 00 00 00 00 00 00 10 00  [ .......b...........b............ ]
00 00 f7 00 00 00 42 4f 70 65 6e 52 65 70 6f 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f  [ ......BOpenRepoExtract_6500WYNK_ ]
32 30 32 32 2d 30 37 2d 32 39 5f 32 30 32 32 30 37 32 39 5f 30 30 30 30 30 30 2d 31 39 37 34 33  [ 2022-07-29_20220729_000000-19743 ]
38 35 30 30 37 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 00 4f 96 00 00 00 04 75 73 65 72 00 00  [ 85007.CSV...........O.....user.. ]
00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 e4 a5 e0 00 00 00 00 00 00 00 00 62 e4 a5 96 00  [ ..group........b...........b.... ]
00 00 00 00 00 00 00 62 e4 a5 96 00 00 00 00 00 00 00 10 00 00 00 f7 01                          [ .......b................         ]

09 Aug 2022 11:45:54,075 [     pool-4-thread-1]  DEBUG - Processing transport protocol message id 94
09 Aug 2022 11:45:54,075 [     pool-4-thread-1]  TRACE - Posting mesage id 94 to active service for processing
09 Aug 2022 11:45:54,075 [     pool-4-thread-1]  TRACE - transport-protocol: Starting new subsystem task
09 Aug 2022 11:45:54,075 [     pool-4-thread-1]  TRACE - Transport protocol is expecting another packet
09 Aug 2022 11:45:54,075 [     pool-4-thread-1]  TRACE - There is 0 bytes left to process on socket
09 Aug 2022 11:45:54,075 [     pool-2-thread-1]  TRACE - transport-protocol: Operation task is starting
09 Aug 2022 11:45:54,075 [     pool-2-thread-1]  TRACE - Processing active service message id 94
09 Aug 2022 11:45:54,075 [     SSHD-TRANSFER-1]  TRACE - transport-client has state ops=1 READ
09 Aug 2022 11:45:54,075 [     pool-2-thread-1]  TRACE - connection-protocol: Starting new subsystem task
09 Aug 2022 11:45:54,075 [     pool-2-thread-1]  TRACE - transport-protocol: No more tasks, will wait for a few more seconds before completing task
09 Aug 2022 11:45:54,075 [     pool-2-thread-1]  TRACE - {}: Operation task has ended
09 Aug 2022 11:45:54,075 [     pool-4-thread-1]  TRACE - transport-protocol: No more tasks, will wait for a few more seconds before completing task
09 Aug 2022 11:45:54,075 [     pool-4-thread-1]  TRACE - {}: Operation task has ended
09 Aug 2022 11:45:54,077 [     pool-3-thread-1]  TRACE - connection-protocol: Operation task is starting
09 Aug 2022 11:45:54,077 [     pool-3-thread-1]  DEBUG - Consuming 4175 bytes local window space before=1023767 after=1019592 channel=0 remote=0 localWindow=1023767 remoteWindow=2147483541
09 Aug 2022 11:45:54,077 [     pool-3-thread-1]  DEBUG - Received SSH_MSG_CHANNEL_DATA len=4175 channel=0 remote=0 localWindow=1019592 remoteWindow=2147483541
09 Aug 2022 11:45:54,077 [     pool-3-thread-1]  TRACE - Written 4175 bytes from cached data window position=0 remaining=4175 limit=4175
09 Aug 2022 11:45:54,077 [     pool-3-thread-1]  TRACE - connection-protocol: No more tasks, will wait for a few more seconds before completing task
09 Aug 2022 11:45:54,077 [     pool-3-thread-1]  TRACE - {}: Operation task has ended
09 Aug 2022 11:45:54,077 [     pool-1-thread-1]  TRACE - Read 1 bytes from cached data window position=1 remaining=4174 limit=4175
09 Aug 2022 11:45:54,077 [     pool-1-thread-1]  TRACE - Checking window space on channel=0 window=1019592 cached=4174 extended=0
09 Aug 2022 11:45:54,077 [     pool-1-thread-1]  TRACE - Read returning 0
09 Aug 2022 11:45:54,077 [     pool-1-thread-1]  TRACE - Checking window space on channel=0 window=1019592 cached=4174 extended=0
09 Aug 2022 11:45:54,077 [     pool-1-thread-1]  TRACE - Read 1 bytes from cached data window position=2 remaining=4173 limit=4175
09 Aug 2022 11:45:54,077 [     pool-1-thread-1]  TRACE - Checking window space on channel=0 window=1019592 cached=4173 extended=0
09 Aug 2022 11:45:54,077 [     pool-1-thread-1]  TRACE - Read returning 0
09 Aug 2022 11:45:54,077 [     pool-1-thread-1]  TRACE - Checking window space on channel=0 window=1019592 cached=4173 extended=0
09 Aug 2022 11:45:54,077 [     pool-1-thread-1]  TRACE - Read 1 bytes from cached data window position=3 remaining=4172 limit=4175
09 Aug 2022 11:45:54,078 [     pool-1-thread-1]  TRACE - Checking window space on channel=0 window=1019592 cached=4172 extended=0
09 Aug 2022 11:45:54,078 [     pool-1-thread-1]  TRACE - Read returning 16
09 Aug 2022 11:45:54,078 [     pool-1-thread-1]  TRACE - Checking window space on channel=0 window=1019592 cached=4172 extended=0
09 Aug 2022 11:45:54,078 [     pool-1-thread-1]  TRACE - Read 1 bytes from cached data window position=4 remaining=4171 limit=4175
09 Aug 2022 11:45:54,078 [     pool-1-thread-1]  TRACE - Checking window space on channel=0 window=1019592 cached=4171 extended=0
09 Aug 2022 11:45:54,078 [     pool-1-thread-1]  TRACE - Read returning 75
09 Aug 2022 11:45:54,078 [     pool-1-thread-1]  TRACE - Checking window space on channel=0 window=1019592 cached=4171 extended=0
09 Aug 2022 11:45:54,078 [     pool-1-thread-1]  TRACE - Read 4171 bytes from cached data window position=4175 remaining=0 limit=4175
09 Aug 2022 11:45:54,078 [     pool-1-thread-1]  TRACE - Checking window space on channel=0 window=1019592 cached=0 extended=0
09 Aug 2022 11:45:54,078 [     pool-1-thread-1]  TRACE - There are 1 SFTP responses waiting to be processed
Exception: SshException
Exception message: Unexpected length of 808673072 bytes exceeds available data of 129824 bytes

[jamoros]

Here is the value in the IDE

[jamoros]

So it seems that the large string that returns is a list of all the file names, the user, groups, and rw. I am not sure why it does this and I don't know how to make it stop or what I can say to the SFTP owner to fix it on their end. I don't think its encoding since the server is based out of NY, it should be UTF8.

[ludup]

Do you have the exact stack trace of the original error.. does it show exactly in SftpFileAttributes where the exception is thrown? I don't see that above.

[jamoros]

The checkLength method in the byte read array class throws the exception, but it doesn't show up in the logs.

[ludup]

Did you catch the version of SFTP being negotiated in the logs? That's quite important to this issue.

And what is the server? what vendor/version?

[ludup]

I've been able to extract the packet and replay it. There is certainly a problem with parsing the data, and I've already discovered one related bug. Although fixing it has not resolved the problem, I need to dig further.

I was going to recommend downgrading the SFTP version as it looks like it's related to the less widely used version 5. But it seems we don't have the facility to downgrade the client through configuration in this API.

[jamoros]

@ludup I've looked over the logs a few times and I can't see where the SFTP version is being negotiated. May you please point me in the right direction? Thanks

[ludup]

At TRACE level, should output "Version is....."

[jamoros]

Got it, thank you:

Version is 6 [Server=6 Client=6]

I should mention we're in contact with the server side team if we need to ask/request anything in particular.

[ludup]

It looks like the bug I reported earlier has fixed this. My recent commit 912cf882 "When supported attributes is not null, only process flags when there is actually a value set." fixed this.

Since we did not define any supported flags for V6 the older code was not reading the attributes, the fix was to ignore supported flags if the value is zero. So they get read.

My test is below.. if you have the patch version this code works and prints out the file listing, without the patch it fails with the errors reported.

`String msg = "5e 00 00 00 00 00 00 10 4f 00 00 10 4b 68 00 00 00 05 00 00 00 1c 00 00 00 43 45 78 74 50 6f 73 [ ^.......O...Kh...........CExtPos ]\n"

• "69 74 69 6f 6e 42 61 6c 61 6e 63 65 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 38 2d 30 31 [ itionBalance_6500WYNK_2022-08-01 ]\n"
• "5f 32 30 32 32 30 38 30 31 5f 30 30 30 30 30 30 2d 31 30 32 31 31 36 30 37 2e 43 53 56 00 00 03 [ _20220801_000000-10211607.CSV... ]\n"
• "bd 01 00 00 00 00 00 01 5c 9e 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 [ ........\.....user....group..... ]\n"
• "00 00 00 62 e8 8d 05 00 00 00 00 00 00 00 00 62 e8 8c f9 00 00 00 00 00 00 00 00 62 e8 8c f9 00 [ ...b...........b...........b.... ]\n"
• "00 00 00 00 00 00 10 00 00 00 f7 00 00 00 44 45 78 74 50 6f 73 69 74 69 6f 6e 42 61 6c 61 6e 63 [ ..............DExtPositionBalanc ]\n"
• "65 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 38 2d 30 38 5f 32 30 32 32 30 38 30 38 5f 30 [ e_6500WYNK_2022-08-08_20220808_0 ]\n"
• "30 30 30 30 30 2d 38 34 38 33 36 35 30 38 38 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 01 5c 93 [ 00000-848365088.CSV...........\. ]\n"
• "00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 f1 c5 0d 00 00 00 [ ....user....group........b...... ]\n"
• "00 00 00 00 00 62 f1 c5 03 00 00 00 00 00 00 00 00 62 f1 c5 03 00 00 00 00 00 00 00 10 00 00 00 [ .....b...........b.............. ]\n"
• "f7 00 00 00 40 4f 70 65 6e 52 65 70 6f 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f 32 30 [ ....@OpenRepoExtract_6500WYNK_20 ]\n"
• "32 32 2d 30 38 2d 30 31 5f 32 30 32 32 30 38 30 31 5f 30 30 30 30 30 30 2d 33 33 33 30 39 31 36 [ 22-08-01_20220801_000000-3330916 ]\n"
• "30 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 00 4f aa 00 00 00 04 75 73 65 72 00 00 00 05 67 72 [ 0.CSV...........O.....user....gr ]\n"
• "6f 75 70 00 00 81 b6 00 00 00 00 62 e8 8d 2e 00 00 00 00 00 00 00 00 62 e8 8c fc 00 00 00 00 00 [ oup........b...........b........ ]\n"
• "00 00 00 62 e8 8c fc 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 43 52 70 74 41 63 74 69 76 69 [ ...b..................CRptActivi ]\n"
• "74 79 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 38 2d 30 31 5f 32 30 [ tyExtract_6500WYNK_2022-08-01_20 ]\n"
• "32 32 30 38 30 31 5f 30 30 30 30 30 30 35 37 39 38 36 38 39 38 33 2e 43 53 56 00 00 03 bd 01 00 [ 220801_000000579868983.CSV...... ]\n"
• "00 00 00 00 00 0b 4a 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 [ ......J....user....group........ ]\n"
• "62 e8 8d 2e 00 00 00 00 00 00 00 00 62 e8 8d 21 00 00 00 00 00 00 00 00 62 e8 8d 21 00 00 00 00 [ b...........b..!........b..!.... ]\n"
• "00 00 00 10 00 00 00 f7 00 00 00 43 45 78 74 50 6f 73 69 74 69 6f 6e 42 61 6c 61 6e 63 65 5f 36 [ ...........CExtPositionBalance_6 ]\n"
• "35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 38 2d 30 32 5f 32 30 32 32 30 38 30 32 5f 30 30 30 30 [ 500WYNK_2022-08-02_20220802_0000 ]\n"
• "30 30 31 37 39 37 39 38 36 35 39 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 01 5c 93 00 00 00 04 [ 00179798659.CSV...........\..... ]\n"
• "75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 e9 de 13 00 00 00 00 00 00 00 [ user....group........b.......... ]\n"
• "00 62 e9 de 04 00 00 00 00 00 00 00 00 62 e9 de 04 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 [ .b...........b.................. ]\n"
• "40 4f 70 65 6e 52 65 70 6f 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 [ @OpenRepoExtract_6500WYNK_2022-0 ]\n"
• "38 2d 30 38 5f 32 30 32 32 30 38 30 38 5f 30 30 30 30 30 30 38 31 31 32 31 38 35 35 39 2e 43 53 [ 8-08_20220808_000000811218559.CS ]\n"
• "56 00 00 03 bd 01 00 00 00 00 00 00 4f aa 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 [ V...........O.....user....group. ]\n"
• "00 81 b6 00 00 00 00 62 f1 c5 22 00 00 00 00 00 00 00 00 62 f1 c5 17 00 00 00 00 00 00 00 00 62 [ .......b..\"........b...........b ]\n"
• "f1 c5 17 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 45 52 70 74 41 63 74 69 76 69 74 79 45 78 [ ..................ERptActivityEx ]\n"
• "74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 38 2d 30 38 5f 32 30 32 32 30 38 [ tract_6500WYNK_2022-08-08_202208 ]\n"
• "30 38 5f 30 30 30 30 30 30 2d 31 34 31 36 30 39 37 35 37 39 2e 43 53 56 00 00 03 bd 01 00 00 00 [ 08_000000-1416097579.CSV........ ]\n"
• "00 00 00 05 c6 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 f1 [ .........user....group........b. ]\n"
• "c5 36 00 00 00 00 00 00 00 00 62 f1 c5 29 00 00 00 00 00 00 00 00 62 f1 c5 29 00 00 00 00 00 00 [ .6........b..)........b..)...... ]\n"
• "00 10 00 00 00 f7 00 00 00 40 4f 70 65 6e 52 65 70 6f 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 [ .........@OpenRepoExtract_6500WY ]\n"
• "4e 4b 5f 32 30 32 32 2d 30 38 2d 30 32 5f 32 30 32 32 30 38 30 32 5f 30 30 30 30 30 30 35 33 33 [ NK_2022-08-02_20220802_000000533 ]\n"
• "36 32 39 34 36 36 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 00 4f a0 00 00 00 04 75 73 65 72 00 [ 629466.CSV...........O.....user. ]\n"
• "00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 e9 de 2a 00 00 00 00 00 00 00 00 62 e9 de 07 [ ...group........b..*........b... ]\n"
• "00 00 00 00 00 00 00 00 62 e9 de 07 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 42 45 78 74 50 [ ........b..................BExtP ]\n"
• "6f 73 69 74 69 6f 6e 42 61 6c 61 6e 63 65 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 38 2d [ ositionBalance_6500WYNK_2022-08- ]\n"
• "30 33 5f 32 30 32 32 30 38 30 33 5f 30 30 30 30 30 30 32 34 36 36 39 38 39 35 2e 43 53 56 00 00 [ 03_20220803_00000024669895.CSV.. ]\n"
• "03 bd 01 00 00 00 00 00 01 5c 94 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 [ .........\.....user....group.... ]\n"
• "00 00 00 00 62 f1 70 15 00 00 00 00 00 00 00 00 62 eb 2e f1 00 00 00 00 00 00 00 00 62 eb 2e f1 [ ....b.p.........b...........b... ]\n"
• "00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 45 45 78 74 50 6f 73 69 74 69 6f 6e 42 61 6c 61 6e [ ...............EExtPositionBalan ]\n"
• "63 65 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 37 2d 32 37 5f 32 30 32 32 30 37 32 37 5f [ ce_6500WYNK_2022-07-2720220727 ]\n"
• "30 30 30 30 30 30 2d 31 38 30 39 32 36 35 35 30 38 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 01 [ 000000-1809265508.CSV........... ]\n"
• "55 15 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 e1 fe 70 00 [ U.....user....group........b..p. ]\n"
• "00 00 00 00 00 00 00 62 e1 fe 67 00 00 00 00 00 00 00 00 62 e1 fe 67 00 00 00 00 00 00 00 10 00 [ .......b..g........b..g......... ]\n"
• "00 00 f7 00 00 00 3f 4f 70 65 6e 52 65 70 6f 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f [ ......?OpenRepoExtract6500WYNK ]\n"
• "32 30 32 32 2d 30 37 2d 32 37 5f 32 30 32 32 30 37 32 37 5f 30 30 30 30 30 30 31 33 36 35 33 34 [ 2022-07-27_20220727_000000136534 ]\n"
• "36 30 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 00 4a 07 00 00 00 04 75 73 65 72 00 00 00 05 67 [ 60.CSV...........J.....user....g ]\n"
• "72 6f 75 70 00 00 81 b6 00 00 00 00 62 e1 fe 84 00 00 00 00 00 00 00 00 62 e1 fe 69 00 00 00 00 [ roup........b...........b..i.... ]\n"
• "00 00 00 00 62 e1 fe 69 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 45 52 70 74 41 63 74 69 76 [ ....b..i...............ERptActiv ]\n"
• "69 74 79 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 38 2d 30 32 5f 32 [ ityExtract_6500WYNK_2022-08-02_2 ]\n"
• "30 32 32 30 38 30 32 5f 30 30 30 30 30 30 2d 31 32 31 35 37 34 30 35 31 36 2e 43 53 56 00 00 03 [ 0220802_000000-1215740516.CSV... ]\n"
• "bd 01 00 00 00 00 00 00 08 80 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 [ ..............user....group..... ]\n"
• "00 00 00 62 e9 de 53 00 00 00 00 00 00 00 00 62 e9 de 2c 00 00 00 00 00 00 00 00 62 e9 de 2c 00 [ ...b..S........b..,........b..,. ]\n"
• "00 00 00 00 00 00 10 00 00 00 f7 00 00 00 40 4f 70 65 6e 52 65 70 6f 45 78 74 72 61 63 74 5f 36 [ ..............@OpenRepoExtract_6 ]\n"
• "35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 38 2d 30 33 5f 32 30 32 32 30 38 30 33 5f 30 30 30 30 [ 500WYNK_2022-08-03_20220803_0000 ]\n"
• "30 30 39 35 34 32 31 32 30 31 37 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 00 4f aa 00 00 00 04 [ 00954212017.CSV...........O..... ]\n"
• "75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 f1 50 a4 00 00 00 00 00 00 00 [ user....group........b.P........ ]\n"
• "00 62 eb 2f 07 00 00 00 00 00 00 00 00 62 eb 2f 07 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 [ .b./.........b./................ ]\n"
• "43 52 70 74 41 63 74 69 76 69 74 79 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 [ CRptActivityExtract_6500WYNK_202 ]\n"
• "32 2d 30 38 2d 30 33 5f 32 30 32 32 30 38 30 33 5f 30 30 30 30 30 30 32 36 37 31 39 32 38 34 38 [ 2-08-03_20220803_000000267192848 ]\n"
• "2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 00 06 ff 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f [ .CSV.................user....gro ]\n"
• "75 70 00 00 81 b6 00 00 00 00 62 f1 70 0a 00 00 00 00 00 00 00 00 62 eb 2f 17 00 00 00 00 00 00 [ up........b.p.........b./....... ]\n"
• "00 00 62 eb 2f 17 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 44 45 78 74 50 6f 73 69 74 69 6f [ ..b./................DExtPositio ]\n"
• "6e 42 61 6c 61 6e 63 65 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 38 2d 30 34 5f 32 30 32 [ nBalance_6500WYNK_2022-08-04_202 ]\n"
• "32 30 38 30 34 5f 30 30 30 30 30 30 31 38 35 31 36 35 30 30 36 39 2e 43 53 56 00 00 03 bd 01 00 [ 20804_0000001851650069.CSV...... ]\n"
• "00 00 00 00 01 5c 94 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 [ .....\.....user....group........ ]\n"
• "62 ec 86 a0 00 00 00 00 00 00 00 00 62 ec 86 92 00 00 00 00 00 00 00 00 62 ec 86 92 00 00 00 00 [ b...........b...........b....... ]\n"
• "00 00 00 10 00 00 00 f7 00 00 00 44 52 70 74 41 63 74 69 76 69 74 79 45 78 74 72 61 63 74 5f 36 [ ...........DRptActivityExtract_6 ]\n"
• "35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 38 2d 30 34 5f 32 30 32 32 30 38 30 34 5f 30 30 30 30 [ 500WYNK_2022-08-04_20220804_0000 ]\n"
• "30 30 2d 33 39 31 38 30 34 34 35 38 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 00 0b 7e 00 00 00 [ 00-391804458.CSV............~... ]\n"
• "04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 ec 86 c8 00 00 00 00 00 00 [ .user....group........b......... ]\n"
• "00 00 62 ec 86 b9 00 00 00 00 00 00 00 00 62 ec 86 b9 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 [ ..b...........b................. ]\n"
• "00 3f 4f 70 65 6e 52 65 70 6f 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d [ .?OpenRepoExtract_6500WYNK_2022- ]\n"
• "30 38 2d 30 34 5f 32 30 32 32 30 38 30 34 5f 30 30 30 30 30 30 32 38 39 30 31 39 36 39 2e 43 53 [ 08-04_20220804_00000028901969.CS ]\n"
• "56 00 00 03 bd 01 00 00 00 00 00 00 4f 9b 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 [ V...........O.....user....group. ]\n"
• "00 81 b6 00 00 00 00 62 ec 86 dd 00 00 00 00 00 00 00 00 62 ec 86 99 00 00 00 00 00 00 00 00 62 [ .......b...........b...........b ]\n"
• "ec 86 99 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 44 45 78 74 50 6f 73 69 74 69 6f 6e 42 61 [ ..................DExtPositionBa ]\n"
• "6c 61 6e 63 65 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 38 2d 30 35 5f 32 30 32 32 30 38 [ lance_6500WYNK_2022-08-05_202208 ]\n"
• "30 35 5f 30 30 30 30 30 30 31 34 32 35 39 36 32 34 37 31 2e 43 53 56 00 00 03 bd 01 00 00 00 00 [ 05_0000001425962471.CSV......... ]\n"
• "00 01 5c 93 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 ed ef [ ..\.....user....group........b.. ]\n"
• "8f 00 00 00 00 00 00 00 00 62 ed ef 87 00 00 00 00 00 00 00 00 62 ed ef 87 00 00 00 00 00 00 00 [ .........b...........b.......... ]\n"
• "10 00 00 00 f7 00 00 00 41 4f 70 65 6e 52 65 70 6f 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e [ ........AOpenRepoExtract_6500WYN ]\n"
• "4b 5f 32 30 32 32 2d 30 38 2d 30 35 5f 32 30 32 32 30 38 30 35 5f 30 30 30 30 30 30 31 31 33 31 [ K_2022-08-05_20220805_0000001131 ]\n"
• "37 39 33 30 35 36 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 00 4f a0 00 00 00 04 75 73 65 72 00 [ 793056.CSV...........O.....user. ]\n"
• "00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 ed ef a7 00 00 00 00 00 00 00 00 62 ed ef 96 [ ...group........b...........b... ]\n"
• "00 00 00 00 00 00 00 00 62 ed ef 96 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 44 52 70 74 41 [ ........b..................DRptA ]\n"
• "63 74 69 76 69 74 79 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 37 2d [ ctivityExtract_6500WYNK_2022-07- ]\n"
• "32 37 5f 32 30 32 32 30 37 32 37 5f 30 30 30 30 30 30 2d 35 31 32 39 31 32 34 33 37 2e 43 53 56 [ 27_20220727_000000-512912437.CSV ]\n"
• "00 00 03 bd 01 00 00 00 00 00 00 0c a4 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 [ .................user....group.. ]\n"
• "81 b6 00 00 00 00 62 e1 fe af 00 00 00 00 00 00 00 00 62 e1 fe 8e 00 00 00 00 00 00 00 00 62 e1 [ ......b...........b...........b. ]\n"
• "fe 8e 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 44 45 78 74 50 6f 73 69 74 69 6f 6e 42 61 6c [ .................DExtPositionBal ]\n"
• "61 6e 63 65 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 37 2d 32 38 5f 32 30 32 32 30 37 32 [ ance_6500WYNK_2022-07-28_2022072 ]\n"
• "38 5f 30 30 30 30 30 30 2d 34 30 37 31 31 39 33 39 30 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 [ 8_000000-407119390.CSV.......... ]\n"
• "01 55 18 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 e3 48 4f [ .U.....user....group........b.HO ]\n"
• "00 00 00 00 00 00 00 00 62 e3 48 47 00 00 00 00 00 00 00 00 62 e3 48 47 00 00 00 00 00 00 00 10 [ ........b.HG........b.HG........ ]\n"
• "00 00 00 f7 00 00 00 41 4f 70 65 6e 52 65 70 6f 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b [ .......AOpenRepoExtract_6500WYNK ]\n"
• "5f 32 30 32 32 2d 30 37 2d 32 38 5f 32 30 32 32 30 37 32 38 5f 30 30 30 30 30 30 31 36 32 38 33 [ _2022-07-28_20220728_00000016283 ]\n"
• "30 37 30 38 30 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 00 4a 11 00 00 00 04 75 73 65 72 00 00 [ 07080.CSV...........J.....user.. ]\n"
• "00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 e3 48 63 00 00 00 00 00 00 00 00 62 e3 48 5b 00 [ ..group........b.Hc........b.H[. ]\n"
• "00 00 00 00 00 00 00 62 e3 48 5b 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 45 52 70 74 41 63 [ .......b.H[...............ERptAc ]\n"
• "74 69 76 69 74 79 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 37 2d 32 [ tivityExtract_6500WYNK_2022-07-2 ]\n"
• "38 5f 32 30 32 32 30 37 32 38 5f 30 30 30 30 30 30 2d 31 36 39 36 34 30 34 39 38 36 2e 43 53 56 [ 8_20220728_000000-1696404986.CSV ]\n"
• "00 00 03 bd 01 00 00 00 00 00 00 05 c6 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 [ .................user....group.. ]\n"
• "81 b6 00 00 00 00 62 e3 48 8c 00 00 00 00 00 00 00 00 62 e3 48 6e 00 00 00 00 00 00 00 00 62 e3 [ ......b.H.........b.Hn........b. ]\n"
• "48 6e 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 42 4f 70 65 6e 52 65 70 6f 45 78 74 72 61 63 [ Hn...............BOpenRepoExtrac ]\n"
• "74 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 37 2d 32 38 5f 32 30 32 32 30 37 32 38 5f 30 [ t_6500WYNK_2022-07-28_20220728_0 ]\n"
• "30 30 30 30 30 2d 31 35 30 39 30 34 35 33 38 32 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 00 4a [ 00000-1509045382.CSV...........J ]\n"
• "11 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 e3 55 55 00 00 [ .....user....group........b.UU.. ]\n"
• "00 00 00 00 00 00 62 e3 55 49 00 00 00 00 00 00 00 00 62 e3 55 49 00 00 00 00 00 00 00 10 00 00 [ ......b.UI........b.UI.......... ]\n"
• "00 f7 00 00 00 45 45 78 74 50 6f 73 69 74 69 6f 6e 42 61 6c 61 6e 63 65 5f 36 35 30 30 57 59 4e [ .....EExtPositionBalance_6500WYN ]\n"
• "4b 5f 32 30 32 32 2d 30 37 2d 32 39 5f 32 30 32 32 30 37 32 39 5f 30 30 30 30 30 30 2d 31 31 30 [ K_2022-07-29_20220729_000000-110 ]\n"
• "38 39 36 36 35 32 33 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 01 5c 9a 00 00 00 04 75 73 65 72 [ 8966523.CSV...........\.....user ]\n"
• "00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 e4 a5 a1 00 00 00 00 00 00 00 00 62 e4 a5 [ ....group........b...........b.. ]\n"
• "94 00 00 00 00 00 00 00 00 62 e4 a5 94 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 43 52 70 74 [ .........b..................CRpt ]\n"
• "41 63 74 69 76 69 74 79 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 38 [ ActivityExtract_6500WYNK_2022-08 ]\n"
• "2d 30 35 5f 32 30 32 32 30 38 30 35 5f 30 30 30 30 30 30 37 37 39 38 34 33 31 34 36 2e 43 53 56 [ -05_20220805_000000779843146.CSV ]\n"
• "00 00 03 bd 01 00 00 00 00 00 00 05 c6 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 [ .................user....group.. ]\n"
• "81 b6 00 00 00 00 62 ed ef bc 00 00 00 00 00 00 00 00 62 ed ef ad 00 00 00 00 00 00 00 00 62 ed [ ......b...........b...........b. ]\n"
• "ef ad 00 00 00 00 00 00 00 10 00 00 00 f7 00 00 00 43 52 70 74 41 63 74 69 76 69 74 79 45 78 74 [ .................CRptActivityExt ]\n"
• "72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f 32 30 32 32 2d 30 37 2d 32 39 5f 32 30 32 32 30 37 32 [ ract_6500WYNK_2022-07-29_2022072 ]\n"
• "39 5f 30 30 30 30 30 30 39 33 35 32 35 30 30 33 37 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 00 [ 9_000000935250037.CSV........... ]\n"
• "21 76 00 00 00 04 75 73 65 72 00 00 00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 e4 a5 ca 00 [ !v....user....group........b.... ]\n"
• "00 00 00 00 00 00 00 62 e4 a5 bd 00 00 00 00 00 00 00 00 62 e4 a5 bd 00 00 00 00 00 00 00 10 00 [ .......b...........b............ ]\n"
• "00 00 f7 00 00 00 42 4f 70 65 6e 52 65 70 6f 45 78 74 72 61 63 74 5f 36 35 30 30 57 59 4e 4b 5f [ ......BOpenRepoExtract6500WYNK ]\n"
• "32 30 32 32 2d 30 37 2d 32 39 5f 32 30 32 32 30 37 32 39 5f 30 30 30 30 30 30 2d 31 39 37 34 33 [ 2022-07-29_20220729_000000-19743 ]\n"
• "38 35 30 30 37 2e 43 53 56 00 00 03 bd 01 00 00 00 00 00 00 4f 96 00 00 00 04 75 73 65 72 00 00 [ 85007.CSV...........O.....user.. ]\n"
• "00 05 67 72 6f 75 70 00 00 81 b6 00 00 00 00 62 e4 a5 e0 00 00 00 00 00 00 00 00 62 e4 a5 96 00 [ ..group........b...........b.... ]\n"

• "00 00 00 00 00 00 00 62 e4 a5 96 00 00 00 00 00 00 00 10 00 00 00 f7 01 [ .......b................ ]";

  BufferedReader reader = new BufferedReader(new StringReader(msg));
  ByteArrayOutputStream out = new ByteArrayOutputStream();
  String line;
  while((line = reader.readLine())!= null) {
      int x = 0;
      int i = 32;
      while(i > 0) {
          String hex = line.substring(x, x+2);
          if(Utils.isNotBlank(hex)) {
              out.write(Integer.parseInt(hex, 16));
          }
          x+=3;
          i--;
      }
  }
  
  ByteArrayReader r = new ByteArrayReader(out.toByteArray());
  
  r.read();    // Channel Data Message
  r.readInt(); // Channel ID
  int length = (int) r.readInt(); // Channel Message Length
  
  byte[] subsystemMessage = r.readBinaryString();
  
  ByteArrayReader s = new ByteArrayReader(subsystemMessage);
  int id = s.read(); // SFTP Message ID
  
  // SSH_FXP_NAME
  int requestId = (int) s.readInt();
  int numNames = (int) s.readInt();
  
  for(int i=0;i<numNames;i++) {
  
      String filename = s.readString();
      System.out.println(filename);
      SftpFileAttributes attrs = new SftpFileAttributes(s, 6, "UTF-8");
      System.out.println(SftpClient.formatLongname(attrs, filename));
  
  }

  `

[jamoros]

I tested version 3.0.9 and it is now passing. As always, thank you very much @ludup .