RyanLivingston opened a new issue, #427:
URL: https://github.com/apache/mina-sshd/issues/427
### Version
2.11.0
### Bug description
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.
`DefaultScpClient::upload(InputStream local, String remote, long
size,Collection<PosixFilePermission> perms, ScpTimestampCommandDetails time)`
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.
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. Testing on sshd-scp 2.10.0 and 2.11.0.
Overriding the client to do the following seems to resolve the issue:
```java
@Override
public void upload(
InputStream local, String remote, long size,
Collection<PosixFilePermission> perms, ScpTimestampCommandDetails time)
throws IOException {
int namePos = ValidateUtils.checkNotNullAndNotEmpty(remote, "No
remote location specified").lastIndexOf('/');
String name = (namePos < 0)
? remote
:
ValidateUtils.checkNotNullAndNotEmpty(remote.substring(namePos + 1), "No name
value in remote=%s", remote);
Collection<Option> options = (time != null) ?
EnumSet.of(Option.PreserveAttributes) : Collections.emptySet();
String cmd = ScpClient.createSendCommand(remote, options);
ClientSession session = getClientSession();
ChannelExec channel = openCommandChannel(session, cmd);
try {
try (InputStream invOut = channel.getInvertedOut();
OutputStream invIn = channel.getInvertedIn()) {
// NOTE: we use a mock file system since we expect no
invocations for it
ScpHelper helper = new ScpHelper(session, invOut, invIn, new
MockFileSystem(remote), opener, listener);
Path mockPath = new MockPath(remote);
helper.sendStream(new DefaultScpStreamResolver(name,
mockPath, perms, time, size, local, cmd),
options.contains(Option.PreserveAttributes),
ScpHelper.DEFAULT_SEND_BUFFER_SIZE);
}
handleCommandExitStatus(cmd, channel);
}finally {
channel.close(false);
}
}
```
### Actual behavior
The upload method blocked the main thread after byte transfer for 5 seconds.
### Expected behavior
The upload SCP routine should receive an exit status immediately after byte
array upload.
### Relevant log output
```Shell
2023-10-31 14:44:24 INFO BouncyCastleSecurityProviderRegistrar:112 -
getOrCreateProvider(BC) created instance of
org.bouncycastle.jce.provider.BouncyCastleProvider
2023-10-31 14:44:24 DEBUG SecurityUtils:450 - register(EdDSA) not registered
- enabled=true, supported=false
2023-10-31 14:44:25 INFO DefaultIoServiceFactoryFactory:68 - No
detected/configured IoServiceFactoryFactory; using Nio2ServiceFactoryFactory
2023-10-31 14:44:25 INFO DefaultConfigFileHostEntryResolver:89 -
resolveEffectiveResolver(ryanlivingston@localhost:22/null) no configuration
file at /Users/ryanlivingston/.ssh/config
2023-10-31 14:44:25 DEBUG DefaultConfigFileHostEntryResolver:62 -
resolveEffectiveHost(ryanlivingston@localhost:22/null) => null
2023-10-31 14:44:25 DEBUG SshClient:700 -
connect(ryanlivingston@localhost:22) no overrides
2023-10-31 14:44:25 DEBUG Nio2Connector:62 - Connecting to
localhost/127.0.0.1:22
2023-10-31 14:44:25 DEBUG Nio2Connector:201 - setOption(SO_REUSEADDR)[true]
from property=Property[socket-reuseaddr](Boolean]
2023-10-31 14:44:25 DEBUG Nio2Connector:101 -
connect(localhost/127.0.0.1:22): waiting for connection (timeout=60000ms)
2023-10-31 14:44:25 DEBUG Nio2Session:93 - Creating IoSession on
/127.0.0.1:60645 from localhost/127.0.0.1:22 via null
2023-10-31 14:44:25 DEBUG ClientSessionImpl:78 - Client session created:
Nio2Session[local=/127.0.0.1:60645, remote=localhost/127.0.0.1:22]
2023-10-31 14:44:25 DEBUG ClientUserAuthService:107 -
ClientUserAuthService(ClientSessionImpl[null@localhost/127.0.0.1:22]) client
methods: [publickey, keyboard-interactive, password]
2023-10-31 14:44:25 DEBUG SessionTimeoutListener:50 -
sessionCreated(ClientSessionImpl[null@localhost/127.0.0.1:22]) tracking
2023-10-31 14:44:25 DEBUG ClientSessionImpl:332 -
initializeProxyConnector(ClientSessionImpl[null@localhost/127.0.0.1:22]) no
proxy to initialize
2023-10-31 14:44:25 DEBUG ClientSessionImpl:850 -
sendIdentification(ClientSessionImpl[null@localhost/127.0.0.1:22]):
SSH-2.0-APACHE-SSHD-2.11.0
2023-10-31 14:44:25 DEBUG Nio2Session:179 -
writeBuffer(Nio2Session[local=/127.0.0.1:60645, remote=localhost/127.0.0.1:22])
writing 28 bytes
2023-10-31 14:44:25 DEBUG ClientSessionImpl:1703 -
sendKexInit(ClientSessionImpl[null@localhost/127.0.0.1:22]) Send SSH_MSG_KEXINIT
2023-10-31 14:44:25 DEBUG ClientSessionImpl:1402 -
encode(ClientSessionImpl[null@localhost/127.0.0.1:22]) packet #0 sending
command=20[SSH_MSG_KEXINIT] len=1234
2023-10-31 14:44:25 DEBUG Nio2Session:179 -
writeBuffer(Nio2Session[local=/127.0.0.1:60645, remote=localhost/127.0.0.1:22])
writing 1248 bytes
2023-10-31 14:44:25 DEBUG SshClient:849 -
setupDefaultSessionIdentities(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
key identity provider override in session listener
2023-10-31 14:44:25 DEBUG DefaultConnectFuture:59 - Connected to
localhost/127.0.0.1:22 after 20944625 nanos
2023-10-31 14:44:25 DEBUG ClientSessionImpl:922 -
doReadIdentification(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
line='SSH-2.0-OpenSSH_9.0'
2023-10-31 14:44:25 DEBUG ClientSessionImpl:533 -
readIdentification(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
Server version string: SSH-2.0-OpenSSH_9.0
2023-10-31 14:44:25 DEBUG OpenSSHKeyPairResourceParser:127 -
extractKeyPairs(/Users/ryanlivingston/.ssh/id_rsa) decode 1 keys using
context=OpenSSHParserContext[cipher=none, kdfOptions=none: options=]
2023-10-31 14:44:25 DEBUG ClientSessionImpl:544 -
doHandleMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
process #0 SSH_MSG_KEXINIT
2023-10-31 14:44:25 DEBUG ClientSessionImpl:825 -
handleKexInit(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
SSH_MSG_KEXINIT
2023-10-31 14:44:25 DEBUG ClientSessionImpl:2172 -
setNegotiationResult(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
Kex: kex algorithms = curve25519-sha256
2023-10-31 14:44:25 DEBUG ClientSessionImpl:2172 -
setNegotiationResult(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
Kex: server host key algorithms = ecdsa-sha2-nistp256
2023-10-31 14:44:25 DEBUG ClientSessionImpl:2172 -
setNegotiationResult(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
Kex: encryption algorithms (client to server) = chacha20-poly1...@openssh.com
2023-10-31 14:44:25 DEBUG ClientSessionImpl:2172 -
setNegotiationResult(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
Kex: encryption algorithms (server to client) = chacha20-poly1...@openssh.com
2023-10-31 14:44:25 DEBUG ClientSessionImpl:2172 -
setNegotiationResult(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
Kex: mac algorithms (client to server) = hmac-sha2-256-...@openssh.com
2023-10-31 14:44:25 DEBUG ClientSessionImpl:2172 -
setNegotiationResult(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
Kex: mac algorithms (server to client) = hmac-sha2-256-...@openssh.com
2023-10-31 14:44:25 DEBUG ClientSessionImpl:2172 -
setNegotiationResult(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
Kex: compression algorithms (client to server) = none
2023-10-31 14:44:25 DEBUG ClientSessionImpl:2172 -
setNegotiationResult(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
Kex: compression algorithms (server to client) = none
2023-10-31 14:44:25 DEBUG DHGClient:102 -
init(DHGClient[curve25519-sha256])[ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]]
Send SSH_MSG_KEXDH_INIT
2023-10-31 14:44:25 DEBUG ClientSessionImpl:1402 -
encode(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) packet #1
sending command=30[30] len=37
2023-10-31 14:44:25 DEBUG Nio2Session:179 -
writeBuffer(Nio2Session[local=/127.0.0.1:60645, remote=localhost/127.0.0.1:22])
writing 56 bytes
2023-10-31 14:44:25 DEBUG ClientSessionImpl:544 -
doHandleMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
process #1 31
2023-10-31 14:44:25 DEBUG DHGClient:119 -
next(DHGClient[curve25519-sha256])[ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]]
process command=SSH_MSG_KEXDH_REPLY
2023-10-31 14:44:25 DEBUG ClientSessionImpl:145 -
setServerKey(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
keyType=ecdsa-sha2-nistp256,
digest=SHA256:RByIUcL/TqyhhieJda6AIKHXaEiav7ylwTRHbp2olt0
2023-10-31 14:44:25 DEBUG ClientSessionImpl:724 -
handleKexMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])[curve25519-sha256]
KEX processing complete after cmd=31
2023-10-31 14:44:25 WARN AcceptAllServerKeyVerifier:59 - Server at
localhost/127.0.0.1:22 presented unverified EC key:
SHA256:RByIUcL/TqyhhieJda6AIKHXaEiav7ylwTRHbp2olt0
2023-10-31 14:44:25 DEBUG ClientSessionImpl:639 -
checkKeys(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
key=ecdsa-sha2-nistp256-SHA256:RByIUcL/TqyhhieJda6AIKHXaEiav7ylwTRHbp2olt0,
verified=true
2023-10-31 14:44:25 DEBUG ClientSessionImpl:666 -
sendNewKeys(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) Send
SSH_MSG_NEWKEYS
2023-10-31 14:44:25 DEBUG ClientSessionImpl:1832 -
prepareNewKeys(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
session
ID=ff:2c:23:bf:7b:d2:78:4b:4d:40:3c:99:d7:ba:20:00:34:ff:ea:89:85:1e:ab:d9:cc:d8:b1:6e:ab:d0:9c:c6
2023-10-31 14:44:25 DEBUG ClientSessionImpl:1402 -
encode(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) packet #2
sending command=21[SSH_MSG_NEWKEYS] len=1
2023-10-31 14:44:25 DEBUG Nio2Session:179 -
writeBuffer(Nio2Session[local=/127.0.0.1:60645, remote=localhost/127.0.0.1:22])
writing 16 bytes
2023-10-31 14:44:25 DEBUG ClientSessionImpl:1953 -
setOutputEncoding(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]):
cipher org.apache.sshd.common.cipher.ChaCha20Cipher@60ae53d0; mac null;
compression none[Deflater/-1]; blocks limit 134217728
2023-10-31 14:44:25 DEBUG ClientSessionImpl:705 -
handleNewKeys(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) No
pending packets to flush at end of KEX
2023-10-31 14:44:25 DEBUG ClientSessionImpl:544 -
doHandleMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
process #2 SSH_MSG_NEWKEYS
2023-10-31 14:44:25 DEBUG ClientSessionImpl:900 -
handleNewKeys(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
SSH_MSG_NEWKEYS command=SSH_MSG_NEWKEYS
2023-10-31 14:44:25 DEBUG ClientSessionImpl:1985 -
setInputEncoding(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]):
cipher org.apache.sshd.common.cipher.ChaCha20Cipher@622abc83; mac null;
compression none[Inflater/-1]; blocks limit 134217728
2023-10-31 14:44:25 DEBUG ClientSessionImpl:231 -
sendInitialServiceRequest(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
Send SSH_MSG_SERVICE_REQUEST for ssh-userauth
2023-10-31 14:44:25 DEBUG ClientSessionImpl:1402 -
encode(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) packet #3
sending command=5[SSH_MSG_SERVICE_REQUEST] len=17
2023-10-31 14:44:25 DEBUG Nio2Session:179 -
writeBuffer(Nio2Session[local=/127.0.0.1:60645, remote=localhost/127.0.0.1:22])
writing 52 bytes
2023-10-31 14:44:25 DEBUG ClientSessionImpl:544 -
doHandleMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
process #3 7
2023-10-31 14:44:25 DEBUG DefaultClientKexExtensionHandler:104 -
handleServerSignatureAlgorithms(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]):
[ssh-ed25519, ssh-rsa, rsa-sha2-256, rsa-sha2-512, ssh-dss,
ecdsa-sha2-nistp256, ecdsa-sha2-nistp384, ecdsa-sha2-nistp521]
2023-10-31 14:44:25 DEBUG DefaultClientKexExtensionHandler:112 -
handleServerSignatureAlgorithms(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]):
PubkeyAcceptedAlgorithms before: [ecdsa-sha2-nistp256-cert-...@openssh.com,
ecdsa-sha2-nistp384-cert-...@openssh.com,
ecdsa-sha2-nistp521-cert-...@openssh.com, rsa-sha2-512-cert-...@openssh.com,
rsa-sha2-256-cert-...@openssh.com, ecdsa-sha2-nistp256, ecdsa-sha2-nistp384,
ecdsa-sha2-nistp521, sk-ecdsa-sha2-nistp...@openssh.com, rsa-sha2-512,
rsa-sha2-256, ssh-rsa]
2023-10-31 14:44:25 DEBUG DefaultClientKexExtensionHandler:129 -
handleServerSignatureAlgorithms(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]):
PubkeyAcceptedAlgorithms after: [ecdsa-sha2-nistp256, ecdsa-sha2-nistp384,
ecdsa-sha2-nistp521, rsa-sha2-512, rsa-sha2-256, ssh-rsa,
ecdsa-sha2-nistp256-cert-...@openssh.com,
ecdsa-sha2-nistp384-cert-...@openssh.com,
ecdsa-sha2-nistp521-cert-...@openssh.com, rsa-sha2-512-cert-...@openssh.com,
rsa-sha2-256-cert-...@openssh.com, sk-ecdsa-sha2-nistp...@openssh.com]
2023-10-31 14:44:25 INFO HostBoundPubkeyAuthentication:58 - Server
announced support for publickey-hostbo...@openssh.com version 0
2023-10-31 14:44:25 DEBUG ClientSessionImpl:544 -
doHandleMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
process #4 SSH_MSG_SERVICE_ACCEPT
2023-10-31 14:44:25 DEBUG ClientSessionImpl:813 -
handleServiceAccept(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
SSH_MSG_SERVICE_ACCEPT service=ssh-userauth
2023-10-31 14:44:25 DEBUG FileKeyPairProvider:157 -
doLoadKeys(/Users/ryanlivingston/.ssh/id_rsa) loaded
2023-10-31 14:44:25 DEBUG ClientSessionImpl:296 -
addPublicKeyIdentity(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
ssh-rsa-SHA256:TPc6+7awmzPVoiyDGeBpM2YBTTc9KL1OjThm9a/6emw
2023-10-31 14:44:25 DEBUG ClientUserAuthService:213 -
auth(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])[ssh-connection]
send SSH_MSG_USERAUTH_REQUEST for 'none'
2023-10-31 14:44:25 DEBUG ClientSessionImpl:1402 -
encode(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) packet #4
sending command=50[SSH_MSG_USERAUTH_REQUEST] len=45
2023-10-31 14:44:25 DEBUG Nio2Session:179 -
writeBuffer(Nio2Session[local=/127.0.0.1:60645, remote=localhost/127.0.0.1:22])
writing 76 bytes
2023-10-31 14:44:25 DEBUG ClientSessionImpl:544 -
doHandleMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
process #5 SSH_MSG_USERAUTH_FAILURE
2023-10-31 14:44:25 DEBUG ClientUserAuthService:315 -
processUserAuth(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
Received SSH_MSG_USERAUTH_FAILURE - partial=false,
methods=publickey,password,keyboard-interactive
2023-10-31 14:44:25 DEBUG ClientUserAuthService:358 -
tryNext(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) starting
authentication mechanisms: client=[publickey, keyboard-interactive, password],
server=[publickey, password, keyboard-interactive]
2023-10-31 14:44:25 DEBUG ClientUserAuthService:407 -
tryNext(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) attempting
method=publickey
2023-10-31 14:44:25 DEBUG UserAuthPublicKey:237 -
sendAuthDataRequest(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])[ssh-connection]
send SSH_MSG_USERAUTH_REQUEST request publickey-hostbound-...@openssh.com
type=rsa-sha2-512 -
fingerprint=SHA256:TPc6+7awmzPVoiyDGeBpM2YBTTc9KL1OjThm9a/6emw
2023-10-31 14:44:25 DEBUG ClientSessionImpl:1402 -
encode(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) packet #5
sending command=50[SSH_MSG_USERAUTH_REQUEST] len=612
2023-10-31 14:44:25 DEBUG Nio2Session:179 -
writeBuffer(Nio2Session[local=/127.0.0.1:60645, remote=localhost/127.0.0.1:22])
writing 644 bytes
2023-10-31 14:44:25 DEBUG ClientUserAuthService:369 -
tryNext(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) successfully
processed initial buffer by method=publickey
2023-10-31 14:44:25 DEBUG ClientSessionImpl:544 -
doHandleMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
process #6 60
2023-10-31 14:44:25 DEBUG ClientUserAuthService:340 -
processUserAuth(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
delegate processing of 60 to publickey
2023-10-31 14:44:25 DEBUG UserAuthPublicKey:379 -
processAuthDataRequest(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])[ssh-connection][publickey-hostbound-...@openssh.com]
SSH_MSG_USERAUTH_PK_OK type=rsa-sha2-512,
fingerprint=SHA256:TPc6+7awmzPVoiyDGeBpM2YBTTc9KL1OjThm9a/6emw
2023-10-31 14:44:25 DEBUG UserAuthPublicKey:410 -
processAuthDataRequest(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])[ssh-connection][publickey-hostbound-...@openssh.com]:
signing with algorithm rsa-sha2-512
2023-10-31 14:44:25 DEBUG ClientSessionImpl:1402 -
encode(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) packet #6
sending command=50[SSH_MSG_USERAUTH_REQUEST] len=1020
2023-10-31 14:44:25 DEBUG Nio2Session:179 -
writeBuffer(Nio2Session[local=/127.0.0.1:60645, remote=localhost/127.0.0.1:22])
writing 1052 bytes
2023-10-31 14:44:25 DEBUG ClientSessionImpl:544 -
doHandleMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
process #7 SSH_MSG_USERAUTH_SUCCESS
2023-10-31 14:44:25 DEBUG ClientUserAuthService:286 -
processUserAuth(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
SSH_MSG_USERAUTH_SUCCESS Succeeded with publickey
2023-10-31 14:44:25 DEBUG UserAuthPublicKey:99 -
destroy(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])[ssh-connection]
2023-10-31 14:44:25 DEBUG ClientConnectionService:279 -
stopHeartBeat(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) no
heartbeat to stop
2023-10-31 14:44:25 DEBUG ClientConnectionService:192 -
startHeartbeat(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
heartbeat type=NONE, interval=PT0S
2023-10-31 14:44:25 DEBUG ClientSessionImpl:544 -
doHandleMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
process #8 SSH_MSG_GLOBAL_REQUEST
2023-10-31 14:44:25 DEBUG ClientConnectionService:857 -
globalRequest(ClientConnectionService[ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]])
received SSH_MSG_GLOBAL_REQUEST hostkeys...@openssh.com want-reply=false
2023-10-31 14:44:25 DEBUG ChannelExec:389 - init()
service=ClientConnectionService[ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]]
session=ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22] id=0
2023-10-31 14:44:25 DEBUG LocalWindow:110 -
init(LocalWindow[client](ChannelExec[id=0,
recipient=-1]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]))
size=2097152, max=2097152, packet=32768
2023-10-31 14:44:25 DEBUG ClientConnectionService:420 -
registerChannel(ClientConnectionService[ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]])[id=0,
registered=true] ChannelExec[id=0,
recipient=-1]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]
2023-10-31 14:44:25 DEBUG ClientSessionImpl:392 -
createExecChannel(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])[scp
-p -t -- /Users/ryanlivingston/tmp/testfile.txt] created id=0 - PTY=null
2023-10-31 14:44:25 DEBUG ChannelExec:351 - open(ChannelExec[id=0,
recipient=-1]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) Send
SSH_MSG_CHANNEL_OPEN - type=session
2023-10-31 14:44:25 DEBUG ClientSessionImpl:1402 -
encode(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) packet #7
sending command=90[SSH_MSG_CHANNEL_OPEN] len=24
2023-10-31 14:44:25 DEBUG Nio2Session:179 -
writeBuffer(Nio2Session[local=/127.0.0.1:60645, remote=localhost/127.0.0.1:22])
writing 60 bytes
2023-10-31 14:44:25 DEBUG OpenSshHostKeysHandler:75 -
process(ClientConnectionService[ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]])[hostkeys...@openssh.com]
key type=ssh-rsa,
fingerprint=SHA256:MvFu/b1/RZ5YFloo+tMPHB0NNDSake2BuDCoI/NGwqk
2023-10-31 14:44:25 DEBUG OpenSshHostKeysHandler:75 -
process(ClientConnectionService[ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]])[hostkeys...@openssh.com]
key type=ecdsa-sha2-nistp256,
fingerprint=SHA256:RByIUcL/TqyhhieJda6AIKHXaEiav7ylwTRHbp2olt0
2023-10-31 14:44:25 WARN ClientConnectionService:624 -
globalRequest(ClientConnectionService[ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]])[hostkeys...@openssh.com,
want-reply=false] failed (SshException) to process: EdDSA provider not
supported
org.apache.sshd.common.SshException: EdDSA provider not supported
at
org.apache.sshd.common.util.buffer.Buffer.getRawPublicKey(Buffer.java:567)
at
org.apache.sshd.common.util.buffer.Buffer.getPublicKey(Buffer.java:542)
at
org.apache.sshd.common.global.AbstractOpenSshHostKeysHandler.process(AbstractOpenSshHostKeysHandler.java:73)
at
org.apache.sshd.common.global.AbstractOpenSshHostKeysHandler.process(AbstractOpenSshHostKeysHandler.java:38)
at
org.apache.sshd.common.session.helpers.AbstractConnectionService.globalRequest(AbstractConnectionService.java:868)
at
org.apache.sshd.common.session.helpers.AbstractConnectionService.process(AbstractConnectionService.java:486)
at
org.apache.sshd.common.session.helpers.CurrentService.process(CurrentService.java:109)
at
org.apache.sshd.common.session.helpers.AbstractSession.doHandleMessage(AbstractSession.java:592)
at
org.apache.sshd.common.session.helpers.AbstractSession.lambda$handleMessage$0(AbstractSession.java:523)
at
org.apache.sshd.common.util.threads.ThreadUtils.runAsInternal(ThreadUtils.java:68)
at
org.apache.sshd.common.session.helpers.AbstractSession.handleMessage(AbstractSession.java:522)
at
org.apache.sshd.common.session.helpers.AbstractSession.decode(AbstractSession.java:1649)
at
org.apache.sshd.common.session.helpers.AbstractSession.messageReceived(AbstractSession.java:483)
at
org.apache.sshd.common.session.helpers.AbstractSessionIoHandler.messageReceived(AbstractSessionIoHandler.java:64)
at
org.apache.sshd.common.io.nio2.Nio2Session.handleReadCycleCompletion(Nio2Session.java:409)
at
org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:382)
at
org.apache.sshd.common.io.nio2.Nio2Session$1.onCompleted(Nio2Session.java:377)
at
org.apache.sshd.common.io.nio2.Nio2CompletionHandler.lambda$completed$0(Nio2CompletionHandler.java:38)
at
java.base/java.security.AccessController.doPrivileged(AccessController.java:318)
at
org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:37)
at java.base/sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:129)
at java.base/sun.nio.ch.Invoker$2.run(Invoker.java:221)
at
java.base/sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:113)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.security.NoSuchAlgorithmException: EdDSA provider not
supported
at
org.apache.sshd.common.util.security.SecurityUtils.generateEDDSAPublicKey(SecurityUtils.java:633)
at
org.apache.sshd.common.util.buffer.keys.ED25519BufferPublicKeyParser.getRawPublicKey(ED25519BufferPublicKeyParser.java:46)
at
org.apache.sshd.common.util.buffer.keys.BufferPublicKeyParser$2.getRawPublicKey(BufferPublicKeyParser.java:102)
at
org.apache.sshd.common.util.buffer.Buffer.getRawPublicKey(Buffer.java:565)
... 25 more
2023-10-31 14:44:25 DEBUG ClientConnectionService:899 -
sendGlobalResponse(ClientConnectionService[ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]])[hostkeys...@openssh.com]
result=ReplyFailure, want-reply=false
2023-10-31 14:44:25 DEBUG ClientSessionImpl:544 -
doHandleMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
process #9 SSH_MSG_DEBUG
2023-10-31 14:44:25 DEBUG ReservedSessionMessagesHandlerAdapter:87 -
handleDebugMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
SSH_MSG_DEBUG (display=false) [lang=]
'/Users/ryanlivingston/.ssh/authorized_keys:1: key options: agent-forwarding
port-forwarding pty user-rc x11-forwarding'
2023-10-31 14:44:25 DEBUG ClientSessionImpl:544 -
doHandleMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
process #10 SSH_MSG_DEBUG
2023-10-31 14:44:25 DEBUG ReservedSessionMessagesHandlerAdapter:87 -
handleDebugMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
SSH_MSG_DEBUG (display=false) [lang=]
'/Users/ryanlivingston/.ssh/authorized_keys:1: key options: agent-forwarding
port-forwarding pty user-rc x11-forwarding'
2023-10-31 14:44:25 DEBUG ClientSessionImpl:544 -
doHandleMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
process #11 SSH_MSG_CHANNEL_OPEN_CONFIRMATION
2023-10-31 14:44:25 DEBUG ClientConnectionService:534 -
channelOpenConfirmation(ChannelExec[id=0,
recipient=-1]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
SSH_MSG_CHANNEL_OPEN_CONFIRMATION sender=0, window-size=0, packet-size=32768
2023-10-31 14:44:25 DEBUG ChannelExec:197 - setRecipient(ChannelExec[id=0,
recipient=-1]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
recipient=0
2023-10-31 14:44:25 DEBUG RemoteWindow:110 -
init(RemoteWindow[client](ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])) size=0,
max=0, packet=32768
2023-10-31 14:44:25 DEBUG ChannelExec:69 - doOpen(ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) send
SSH_MSG_CHANNEL_REQUEST exec command=scp -p -t --
/Users/ryanlivingston/tmp/testfile.txt
2023-10-31 14:44:25 DEBUG ClientSessionImpl:1402 -
encode(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) packet #8
sending command=98[SSH_MSG_CHANNEL_REQUEST] len=69
2023-10-31 14:44:25 DEBUG Nio2Session:179 -
writeBuffer(Nio2Session[local=/127.0.0.1:60645, remote=localhost/127.0.0.1:22])
writing 100 bytes
2023-10-31 14:44:25 DEBUG ClientSessionImpl:544 -
doHandleMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
process #12 SSH_MSG_CHANNEL_WINDOW_ADJUST
2023-10-31 14:44:25 DEBUG ChannelExec:949 -
handleWindowAdjust(ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
SSH_MSG_CHANNEL_WINDOW_ADJUST window=2097152
2023-10-31 14:44:25 DEBUG RemoteWindow:108 -
expand(RemoteWindow[client](ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]))
increase window from 0 by 2097152 up to 2097152
2023-10-31 14:44:25 DEBUG RemoteWindow:192 -
waitForSpace(RemoteWindow[client](ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]))
available: 2097152
2023-10-31 14:44:25 DEBUG RemoteWindow:151 -
waitAndConsume(RemoteWindow[client](ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])) -
requested=27, available=2097152
2023-10-31 14:44:25 DEBUG RemoteWindow:82 - Consume
RemoteWindow[client](ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) by 27
down to 2097125
2023-10-31 14:44:25 DEBUG ClientSessionImpl:1402 -
encode(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) packet #9
sending command=94[SSH_MSG_CHANNEL_DATA] len=36
2023-10-31 14:44:25 DEBUG Nio2Session:179 -
writeBuffer(Nio2Session[local=/127.0.0.1:60645, remote=localhost/127.0.0.1:22])
writing 68 bytes
2023-10-31 14:44:25 DEBUG ClientSessionImpl:544 -
doHandleMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
process #13 SSH_MSG_CHANNEL_DATA
2023-10-31 14:44:25 DEBUG LocalWindow:85 - Consume
LocalWindow[client](ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) by 2
down to 2097150
2023-10-31 14:44:25 DEBUG ChannelExec:829 - handleData(ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
SSH_MSG_CHANNEL_DATA len=2
2023-10-31 14:44:25 DEBUG ScpHelper:556 -
sendStream(ScpHelper[ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]])[scp
-p -t -- /Users/ryanlivingston/tmp/testfile.txt] command='T1698777865 0
1698777865 0' ACK=0
2023-10-31 14:44:25 DEBUG ScpHelper:569 -
sendStream(ScpHelper[ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]])[scp
-p -t -- /Users/ryanlivingston/tmp/testfile.txt] send 'C' command: C0666 9
testfile.txt
2023-10-31 14:44:25 DEBUG RemoteWindow:192 -
waitForSpace(RemoteWindow[client](ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]))
available: 2097125
2023-10-31 14:44:25 DEBUG RemoteWindow:151 -
waitAndConsume(RemoteWindow[client](ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])) -
requested=21, available=2097125
2023-10-31 14:44:25 DEBUG RemoteWindow:82 - Consume
RemoteWindow[client](ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) by 21
down to 2097104
2023-10-31 14:44:25 DEBUG ClientSessionImpl:1402 -
encode(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) packet #10
sending command=94[SSH_MSG_CHANNEL_DATA] len=30
2023-10-31 14:44:25 DEBUG Nio2Session:179 -
writeBuffer(Nio2Session[local=/127.0.0.1:60645, remote=localhost/127.0.0.1:22])
writing 60 bytes
2023-10-31 14:44:25 DEBUG ScpHelper:574 -
sendStream(ScpHelper[ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]])[scp
-p -t -- /Users/ryanlivingston/tmp/testfile.txt] command='C0666 9 testfile.tx'
ACK=0
2023-10-31 14:44:25 DEBUG RemoteWindow:192 -
waitForSpace(RemoteWindow[client](ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]))
available: 2097104
2023-10-31 14:44:25 DEBUG RemoteWindow:151 -
waitAndConsume(RemoteWindow[client](ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])) -
requested=10, available=2097104
2023-10-31 14:44:25 DEBUG ClientSessionImpl:544 -
doHandleMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
process #14 SSH_MSG_CHANNEL_DATA
2023-10-31 14:44:25 DEBUG RemoteWindow:82 - Consume
RemoteWindow[client](ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) by 10
down to 2097094
2023-10-31 14:44:25 DEBUG LocalWindow:85 - Consume
LocalWindow[client](ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) by 1
down to 2097149
2023-10-31 14:44:25 DEBUG ChannelExec:829 - handleData(ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
SSH_MSG_CHANNEL_DATA len=1
2023-10-31 14:44:25 DEBUG ClientSessionImpl:1402 -
encode(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) packet #11
sending command=94[SSH_MSG_CHANNEL_DATA] len=19
2023-10-31 14:44:25 DEBUG Nio2Session:179 -
writeBuffer(Nio2Session[local=/127.0.0.1:60645, remote=localhost/127.0.0.1:22])
writing 52 bytes
2023-10-31 14:44:25 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-10-31 14:44:25 DEBUG ClientSessionImpl:544 -
doHandleMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
process #15 SSH_MSG_CHANNEL_DATA
2023-10-31 14:44:25 DEBUG LocalWindow:85 - Consume
LocalWindow[client](ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) by 1
down to 2097148
2023-10-31 14:44:25 DEBUG ChannelExec:829 - handleData(ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
SSH_MSG_CHANNEL_DATA len=1
2023-10-31 14:44:30 DEBUG DefaultScpClient:177 -
handleCommandExitStatus(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
cmd='scp -p -t -- /Users/ryanlivingston/tmp/testfile.txt', waited=5005150209
nanos, events=[TIMEOUT, OPENED]
2023-10-31 14:44:30 DEBUG DefaultScpClient:207 -
handleCommandExitStatus(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
cmd='scp -p -t -- /Users/ryanlivingston/tmp/testfile.txt', exit-status=null
2023-10-31 14:44:30 DEBUG ChannelExec:1004 - sendEof(ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
SSH_MSG_CHANNEL_EOF (state=Opened)
2023-10-31 14:44:30 DEBUG ClientSessionImpl:1402 -
encode(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) packet #12
sending command=96[SSH_MSG_CHANNEL_EOF] len=5
2023-10-31 14:44:30 DEBUG Nio2Session:179 -
writeBuffer(Nio2Session[local=/127.0.0.1:60645, remote=localhost/127.0.0.1:22])
writing 36 bytes
2023-10-31 14:44:30 DEBUG ChannelExec:107 - close(ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) Closing
gracefully
2023-10-31 14:44:30 DEBUG LocalWindow:136 - Closing
LocalWindow[client](ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
2023-10-31 14:44:30 DEBUG RemoteWindow:136 - Closing
RemoteWindow[client](ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
2023-10-31 14:44:30 DEBUG ClientSessionImpl:544 -
doHandleMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
process #16 SSH_MSG_CHANNEL_EOF
2023-10-31 14:44:30 DEBUG ChannelExec:934 - handleEof(ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
SSH_MSG_CHANNEL_EOF
2023-10-31 14:44:30 DEBUG ClientSessionImpl:544 -
doHandleMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
process #17 SSH_MSG_CHANNEL_REQUEST
2023-10-31 14:44:30 DEBUG ChannelExec:296 -
handleChannelRequest(ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
SSH_MSG_CHANNEL_REQUEST exit-status wantReply=false
2023-10-31 14:44:30 DEBUG ExitStatusChannelRequestHandler:50 -
processRequestValue(ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) status=0
2023-10-31 14:44:30 DEBUG ExitStatusChannelRequestHandler:59 -
process(ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])[exit-status]
wantReply=false: 0
2023-10-31 14:44:30 DEBUG ChannelExec:114 - notifyEvent(ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]):
exit-status
2023-10-31 14:44:30 DEBUG ExitStatusChannelRequestHandler:101 -
notifyStateChanged(ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])[exit-status]
event=exit-status
2023-10-31 14:44:30 DEBUG ChannelExec:370 - sendResponse(ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
request=exit-status result=ReplySuccess, want-reply=false
2023-10-31 14:44:30 DEBUG ClientSessionImpl:544 -
doHandleMessage(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
process #18 SSH_MSG_CHANNEL_CLOSE
2023-10-31 14:44:30 DEBUG ChannelExec:565 - handleClose(ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
SSH_MSG_CHANNEL_CLOSE
2023-10-31 14:44:30 DEBUG ChannelExec:130 - close(ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])[Graceful]
state already Graceful
2023-10-31 14:44:30 DEBUG AbstractChannel$GracefulChannelCloseable:649 -
close(ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])[immediately=false]
processing
2023-10-31 14:44:30 DEBUG AbstractChannel$GracefulChannelCloseable:660 -
close(ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])[immediately=false]
send SSH_MSG_CHANNEL_CLOSE
2023-10-31 14:44:30 DEBUG ClientSessionImpl:1402 -
encode(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) packet #13
sending command=97[SSH_MSG_CHANNEL_CLOSE] len=5
2023-10-31 14:44:30 DEBUG Nio2Session:179 -
writeBuffer(Nio2Session[local=/127.0.0.1:60645, remote=localhost/127.0.0.1:22])
writing 36 bytes
2023-10-31 14:44:30 DEBUG AbstractChannel$GracefulChannelCloseable:697 -
handleClosePacketWritten(ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])[immediately=false]
SSH_MSG_CHANNEL_CLOSE written on channel
2023-10-31 14:44:30 DEBUG ClientConnectionService:441 -
unregisterChannel(ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
result=ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]
2023-10-31 14:44:30 DEBUG SequentialCloseable:63 -
doClose(org.apache.sshd.common.util.closeable.SequentialCloseable$1@2c07545f)
signal close complete immediately=false
2023-10-31 14:44:30 DEBUG SequentialCloseable:63 -
doClose(org.apache.sshd.common.util.closeable.SequentialCloseable$1@e57b96d)
signal close complete immediately=false
2023-10-31 14:44:30 DEBUG SequentialCloseable:63 -
doClose(org.apache.sshd.common.util.closeable.SequentialCloseable$1@32c726ee)
signal close complete immediately=false
2023-10-31 14:44:30 DEBUG AbstractChannel$GracefulChannelCloseable:649 -
close(ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])[immediately=true]
processing
2023-10-31 14:44:30 DEBUG ClientConnectionService:441 -
unregisterChannel(ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
result=null
2023-10-31 14:44:30 DEBUG SequentialCloseable:63 -
doClose(org.apache.sshd.common.util.closeable.SequentialCloseable$1@34c01041)
signal close complete immediately=true
2023-10-31 14:44:30 DEBUG SequentialCloseable:63 -
doClose(org.apache.sshd.common.util.closeable.SequentialCloseable$1@76f4b65)
signal close complete immediately=true
2023-10-31 14:44:30 DEBUG SequentialCloseable:63 -
doClose(org.apache.sshd.common.util.closeable.SequentialCloseable$1@c94fd30)
signal close complete immediately=true
2023-10-31 14:44:30 DEBUG ChannelExec:116 - close(ChannelExec[id=0,
recipient=0]-ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]][Graceful]
- operationComplete() closed
2023-10-31 14:44:30 DEBUG ClientSessionImpl:92 -
close(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) Closing
immediately
2023-10-31 14:44:30 DEBUG ClientSessionImpl:200 -
signalAuthFailure(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
type=SshException, signalled=false, first=false: Session is being closed
2023-10-31 14:44:30 DEBUG SessionTimeoutListener:71 -
sessionClosed(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])
un-tracked
2023-10-31 14:44:30 DEBUG ClientConnectionService:92 -
close(ClientConnectionService[ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]])
Closing immediately
2023-10-31 14:44:30 DEBUG ClientConnectionService:279 -
stopHeartBeat(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]) no
heartbeat to stop
2023-10-31 14:44:30 DEBUG ClientConnectionService:97 -
close(ClientConnectionService[ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22]])[Immediately]
closed
2023-10-31 14:44:30 DEBUG Nio2Session:92 -
close(Nio2Session[local=/127.0.0.1:60645, remote=localhost/127.0.0.1:22])
Closing immediately
2023-10-31 14:44:30 DEBUG Nio2Session:268 -
doCloseImmediately(Nio2Session[local=/127.0.0.1:60645,
remote=localhost/127.0.0.1:22]) closing
socket=sun.nio.ch.UnixAsynchronousSocketChannelImpl[connected
local=/127.0.0.1:60645 remote=localhost/127.0.0.1:22]
2023-10-31 14:44:30 DEBUG Nio2Session:274 -
doCloseImmediately(Nio2Session[local=/127.0.0.1:60645,
remote=localhost/127.0.0.1:22])
socket=sun.nio.ch.UnixAsynchronousSocketChannelImpl[closed] closed
2023-10-31 14:44:30 DEBUG Nio2Connector:147 - unmapSession(id=101):
Nio2Session[local=/127.0.0.1:60645, remote=localhost/127.0.0.1:22]
2023-10-31 14:44:30 DEBUG ClientSessionImpl:101 -
close(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])[Immediately]
state already Immediate
2023-10-31 14:44:30 DEBUG Nio2Session:97 -
close(Nio2Session[local=/127.0.0.1:60645,
remote=localhost/127.0.0.1:22])[Immediately] closed
2023-10-31 14:44:30 DEBUG SequentialCloseable:63 -
doClose(org.apache.sshd.common.util.closeable.SequentialCloseable$1@41e68d87)
signal close complete immediately=true
2023-10-31 14:44:30 DEBUG Nio2Session:568 -
handleReadCycleFailure(Nio2Session[local=/127.0.0.1:60645,
remote=localhost/127.0.0.1:22]) AsynchronousCloseException after 5787750 nanos
at read cycle=15: null
2023-10-31 14:44:30 DEBUG ClientSessionImpl:97 -
close(ClientSessionImpl[ryanlivingston@localhost/127.0.0.1:22])[Immediately]
closed
```
### Other information
_No response_
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: dev-unsubscr...@mina.apache.org.apache.org
For queries about this service, please contact Infrastructure at:
us...@infra.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@mina.apache.org
For additional commands, e-mail: dev-h...@mina.apache.org
