[
https://issues.apache.org/jira/browse/SSHD-1334?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Thomas Wolf resolved SSHD-1334.
-------------------------------
Fix Version/s: 2.13.0
Resolution: Fixed
Was fixed in [https://github.com/apache/mina-sshd/issues/427] .
> DefaultScpClient::upload(InputStream, ...) will always hit the exit status
> timeout
> ----------------------------------------------------------------------------------
>
> Key: SSHD-1334
> URL: https://issues.apache.org/jira/browse/SSHD-1334
> Project: MINA SSHD
> Issue Type: Bug
> Affects Versions: 2.10.0
> Reporter: Ryan Livingston
> Priority: Major
> Fix For: 2.13.0
>
> Attachments: file-based.txt, stream-based.txt
>
>
> When attempting to upload/scp a byte stream using the below method, the main
> thread will always block until the exit status timeout is reached.
> {code:java}
> DefaultScpClient::upload(InputStream local, String remote, long
> size,Collection<PosixFilePermission> perms, ScpTimestampCommandDetails
> time){code}
> It appears this is the case because the _handleCommandExitStatus(cmd,
> channel)_ is called before the In/Out channels are auto-closed by the
> try-with-resources block, and thus the EOF is not sent to the remote prior to
> handling the exit status. The current implementation always times out first
> and then sends an EOF while closing the channels.
> Using the API to send based on file paths will invoke
> _DefaultScpClient::runUpload()_ which first closes the channel resources and
> then waits for the exit status. This API works well without the exit status
> blocking the thread.
> I have overridden the default client to ignore the exit status result, and
> there is a dedicated property to adjust this timeout. Though, this is not
> really a solution to this issue.
> I attempted to override and close the channels first prior to handling the
> exit status like {_}runUpload(){_}, but this introduced some async issues
> when processing some remaining inbound messages from the remote after the
> pipe is closed.
> This issue is persistent on remote SSH servers running with CentOS and MacOS.
> This example is being run on MacOS 13.3.1 with a remote SSH server that has
> no explicit SSH configuration.
> Path based logging:
> {code:java}
> 2023-08-02 14:17:50 DEBUG ScpHelper:597 -
> sendStream(ScpHelper[ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]])[/Users/ryanlivingston/tmp/testfile.txt]
> command='C0644 9 testfile.txt' ACK=0
> 2023-08-02 14:17:50 DEBUG ChannelExec:940 - sendEof(ChannelExec[id=0,
> recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
> SSH_MSG_CHANNEL_EOF (state=Opened)
> 2023-08-02 14:17:50 DEBUG ClientSessionImpl:1402 -
> encode(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) packet #11
> sending command=96[SSH_MSG_CHANNEL_EOF] len=5
> 2023-08-02 14:17:50 DEBUG Nio2Session:179 -
> writeBuffer(Nio2Session[local=/127.0.0.1:54429,
> remote=localhost/127.0.0.1:22]) writing 36 bytes
> 2023-08-02 14:17:50 DEBUG DefaultScpClient:155 -
> runUpload(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
> /Users/ryanlivingston/tmp/testfile2.txt =>
> [/Users/ryanlivingston/tmp/testfile.txt] - failed
> (UnsupportedOperationException) to close file
> system=sun.nio.fs.MacOSXFileSystem@9ebe38b: null
> 2023-08-02 14:17:50 DEBUG ClientSessionImpl:544 -
> doHandleMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
> process #16 SSH_MSG_CHANNEL_EOF
> 2023-08-02 14:17:50 DEBUG ChannelExec:873 - handleEof(ChannelExec[id=0,
> recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
> SSH_MSG_CHANNEL_EOF
> 2023-08-02 14:17:50 DEBUG ClientSessionImpl:544 -
> doHandleMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
> process #17 SSH_MSG_CHANNEL_REQUEST
> 2023-08-02 14:17:50 DEBUG ChannelExec:271 -
> handleChannelRequest(ChannelExec[id=0,
> recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
> SSH_MSG_CHANNEL_REQUEST exit-status wantReply=false
> 2023-08-02 14:17:50 DEBUG ExitStatusChannelRequestHandler:50 -
> processRequestValue(ChannelExec[id=0,
> recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
> status=0
> 2023-08-02 14:17:50 DEBUG ExitStatusChannelRequestHandler:59 -
> process(ChannelExec[id=0,
> recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])[exit-status]
> wantReply=false: 0
> 2023-08-02 14:17:50 DEBUG ChannelExec:114 - notifyEvent(ChannelExec[id=0,
> recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]):
> exit-status
> 2023-08-02 14:17:50 DEBUG ExitStatusChannelRequestHandler:101 -
> notifyStateChanged(ChannelExec[id=0,
> recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])[exit-status]
> event=exit-status
> 2023-08-02 14:17:50 DEBUG ChannelExec:345 - sendResponse(ChannelExec[id=0,
> recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
> request=exit-status result=ReplySuccess, want-reply=false
> 2023-08-02 14:17:50 DEBUG ChannelExec:247 - waitFor(ChannelExec[id=0,
> recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
> mask=[CLOSED, EXIT_STATUS] - exit status=0
> 2023-08-02 14:17:50 DEBUG ClientSessionImpl:544 -
> doHandleMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
> process #18 SSH_MSG_CHANNEL_CLOSE
> 2023-08-02 14:17:50 DEBUG DefaultScpClient:176 -
> handleCommandExitStatus(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
> cmd='scp -t -- /Users/ryanlivingston/tmp/testfile2.txt', waited=636667
> nanos, events=[EOF, EXIT_STATUS, OPENED]
> 2023-08-02 14:17:50 DEBUG DefaultScpClient:206 -
> handleCommandExitStatus(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
> cmd='scp -t -- /Users/ryanlivingston/tmp/testfile2.txt', exit-status=OK
> {code}
> Stream based logging:
> {code:java}
> 2023-08-02 14:32:57 DEBUG ScpHelper:597 -
> sendStream(ScpHelper[ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]])[scp
> -p -t -- /Users/ryanlivingston/tmp/testfile.txt] command='C0666 9
> testfile.txt' ACK=0 2023-08-02 14:32:57 DEBUG ClientSessionImpl:544 -
> doHandleMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
> process #15 SSH_MSG_CHANNEL_DATA 2023-08-02 14:32:57 DEBUG LocalWindow:87 -
> Consume LocalWindow[client](ChannelExec[id=0,
> recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) by 1
> down to 2097148 2023-08-02 14:32:57 DEBUG ChannelExec:788 -
> handleData(ChannelExec[id=0,
> recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
> SSH_MSG_CHANNEL_DATA len=1 2023-08-02 14:33:02 DEBUG DefaultScpClient:176 -
> handleCommandExitStatus(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
> cmd='scp -p -t -- /Users/ryanlivingston/tmp/testfile.txt', waited=5007089542
> nanos, events=[TIMEOUT, OPENED] 2023-08-02 14:33:02 DEBUG
> DefaultScpClient:206 -
> handleCommandExitStatus(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
> cmd='scp -p -t -- /Users/ryanlivingston/tmp/testfile.txt', exit-status=null
> 2023-08-02 14:33:02 DEBUG ChannelExec:940 - sendEof(ChannelExec[id=0,
> recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
> SSH_MSG_CHANNEL_EOF (state=Opened) 2023-08-02 14:33:02 DEBUG
> ClientSessionImpl:1402 -
> encode(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) packet #12
> sending command=96[SSH_MSG_CHANNEL_EOF] len=5 2023-08-02 14:33:02 DEBUG
> Nio2Session:179 - writeBuffer(Nio2Session[local=/127.0.0.1:54518,
> remote=localhost/127.0.0.1:22]) writing 36 bytes 2023-08-02 14:33:02 DEBUG
> ChannelExec:107 - close(ChannelExec[id=0,
> recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
> Closing gracefully {code}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@mina.apache.org
For additional commands, e-mail: dev-h...@mina.apache.org
