[jira] [Comment Edited] (SSHD-1173) SFTP worker threads got stuck while processing PUT methods against one specific SFTP server
[
https://issues.apache.org/jira/browse/SSHD-1173?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17615236#comment-17615236
]
Kirk Rasmussen edited comment on SSHD-1173 at 10/10/22 9:46 PM:
Here's simple test harness (Apache Mina client SSHD 2.8.0) I was using to debug
remote server (MOVEIT Transfer 2018 SP1). I was able to verify in their server
logs that it wasn't sending the window adjustment message so your explanation
was right on the money as to why it was deadlocked. The following may not be
100% accurate (I'm trying to recreate the exact test setup - it should be close)
{code:java}
private static void write(final SftpClient client,
final String path,
final int size,
final int bufferSize) throws IOException {
System.out.printf("write(\"%s\", %d, %d)%n", path, size, bufferSize);
final Path uploadFile = createUploadFile(size);
final StopWatch stopWatch = new StopWatch();
stopWatch.start();
try (InputStream inputStream = Files.newInputStream(uploadFile);
OutputStream outputStream = client.write(
path,
bufferSize,
SftpClient.OpenMode.Write, SftpClient.OpenMode.Create,
SftpClient.OpenMode.Truncate)) {
final byte[] buffer = new byte[1_024];
int sent = 0;
int read;
while ((read = inputStream.read(buffer)) != -1) {
outputStream.write(buffer, 0, read);
sent += read;
System.out.print(".");
//System.out.printf("\tsent=%-15d (%3.02f%%) :: %s%n", sent,
(double)sent/size * 100.0, stopWatch.formatTime());
}
System.out.printf("%n\tTotal: %s%n", stopWatch.formatTime());
} catch (SftpException ex) {
System.out.printf("write(\"%s\") failed: %s (%d)%n", path, ex,
ex.getStatus());
}
}
{code}
It would deadlock w/o the SftpModuleProperties.CHUNK_IF_WINDOW_LESS_THAN_PACKET
setting , e.g.
{code:java}
write("/sftp-test.txt", 1048576, 0)
sent=1024 (0.10%) :: 00:00:00.126
sent=2048 (0.20%) :: 00:00:00.140
sent=3072 (0.29%) :: 00:00:00.140
sent=4096 (0.39%) :: 00:00:00.140
sent=5120 (0.49%) :: 00:00:00.140
sent=6144 (0.59%) :: 00:00:00.140
sent=7168 (0.68%) :: 00:00:00.140
sent=8192 (0.78%) :: 00:00:00.140
sent=9216 (0.88%) :: 00:00:00.141
sent=10240 (0.98%) :: 00:00:00.141
sent=11264 (1.07%) :: 00:00:00.141
sent=12288 (1.17%) :: 00:00:00.141
sent=13312 (1.27%) :: 00:00:00.141
sent=14336 (1.37%) :: 00:00:00.141
sent=15360 (1.46%) :: 00:00:00.141
sent=16384 (1.56%) :: 00:00:00.141
sent=17408 (1.66%) :: 00:00:00.142
sent=18432 (1.76%) :: 00:00:00.142
sent=19456 (1.86%) :: 00:00:00.142
sent=20480 (1.95%) :: 00:00:00.142
sent=21504 (2.05%) :: 00:00:00.142
sent=22528 (2.15%) :: 00:00:00.142
sent=23552 (2.25%) :: 00:00:00.142
sent=24576 (2.34%) :: 00:00:00.142
sent=25600 (2.44%) :: 00:00:00.143
sent=26624 (2.54%) :: 00:00:00.143
sent=27648 (2.64%) :: 00:00:00.143
sent=28672 (2.73%) :: 00:00:00.143
sent=29696 (2.83%) :: 00:00:00.143
sent=30720 (2.93%) :: 00:00:00.143
sent=31744 (3.03%) :: 00:00:00.143
{code}
I don't have the full stack trace unfortunately and I lost access to the server
but here's a partial grab (which is very similar to the original reporter's)
{code:java}
Caused by: java.io.InterruptedIOException:
IoWriteFutureImpl[SftpChannelSubsystem[id=0,
recipient=0]-ClientSessionImpl[cpq_dump@/10.18.242.4:8080][sftp][SSH_MSG_CHANNEL_DATA]]:
Interrupted after 37644419 msec.
at
org.apache.sshd.common.future.DefaultSshFuture.lambda$await0$0(DefaultSshFuture.java:74)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.AbstractSshFuture.formatExceptionMessage(AbstractSshFuture.java:185)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:73)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:109)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:39)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:30)
~[sshd-common-2.8.0.jar:2.8.0]
at
[jira] [Comment Edited] (SSHD-1173) SFTP worker threads got stuck while processing PUT methods against one specific SFTP server
[
https://issues.apache.org/jira/browse/SSHD-1173?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17615261#comment-17615261
]
Kirk Rasmussen edited comment on SSHD-1173 at 10/10/22 9:28 PM:
BTW this is strictly an us problem but when I said it would be "nightmarish" I
simply meant that our customer's typically outsource managed file transfer to
3rd party companies and have little idea what SFTP protocol even is so trying
to explain why suddenly their files aren't being transferred anymore because
the "window adjustment message" isn't being sent their eyes will just glaze
over.
Prior to our latest release last week (when we switched our internal SFTP
client to Apache Mina) we were using JSch for many years which didn't have this
problem and we got caught at the last minute unfortunately (we have many
customers w/ a variety of SFTP servers which we have no control; this
particular problematic one used MOVEIT) - they have no idea nor do they need to
know what SFTP client library we use in our product.
Your explanation makes sense to me though thanks for all your help! [~twolf]
was (Author: JIRAUSER296597):
BTW this is strictly an us problem but when I said it would be "nightmarish" I
simply meant that our customer's typically outsource managed file transfer to
3rd party companies and have little idea what SFTP protocol even is so trying
to explain why suddenly their files aren't being transferred anymore because
the "window adjustment message" isn't being sent their eyes will just glaze
over.
Prior to our latest release last week we were using JSch for many years which
didn't have this problem and we got caught at the last minute unfortunately (we
have many customers w/ a variety of SFTP servers which we have no control; this
particular problematic one used MOVEIT) - they have no idea nor do they need to
know what SFTP client library we use in our product.
Your explanation makes sense to me though thanks for all your help! [~twolf]
> SFTP worker threads got stuck while processing PUT methods against one
> specific SFTP server
> ---
>
> Key: SSHD-1173
> URL: https://issues.apache.org/jira/browse/SSHD-1173
> Project: MINA SSHD
> Issue Type: Question
>Affects Versions: 2.6.0
>Reporter: Pavel Pohner
>Priority: Critical
> Labels: SFTP, mina, sshd
> Time Spent: 10m
> Remaining Estimate: 0h
>
> Hey guys,
> Recently I've encountered one remote SFTP server, that causes SFTP worker
> threads to enter TIMED_WAITING state, from which they do not recover. Please,
> take a look into this thread dump:
> {code:java}
> SFTP-worker-3 #2155 prio=5 os_prio=0 cpu=61692.09ms elapsed=1136151.86s
> tid=0x7fe41c005800 nid=0x18808 in Object.wait()
> [0x7fe145b1d000]SFTP-worker-3" #2155 prio=5 os_prio=0 cpu=61692.09ms
> elapsed=1136151.86s tid=0x7fe41c005800 nid=0x18808 in Object.wait()
> [0x7fe145b1d000] java.lang.Thread.State: TIMED_WAITING (on object
> monitor) at java.lang.Object.wait(java.base@11.0.10/Native Method) - waiting
> on at
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:69)
> - waiting to re-lock in wait() <0x0006e3bbc420> (a
> org.apache.sshd.common.channel.IoWriteFutureImpl) at
> org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:109)
> at
> org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:39)
> at
> org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:30)
> at
> org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43)
> at
> org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:292)
> at
> org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.flush(SftpOutputStreamAsync.java:210)
> at
> org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.write(SftpOutputStreamAsync.java:141)
> at java.io.InputStream.transferTo(java.base@11.0.10/InputStream.java:705) at
> com.mina.command.Put.replyInto(Put.java:55) at
> com.sftpserver.MinaSftpHandler.channelReadInternal(MinaSftpHandler.java:251)
> at
> com.sftpserver.MinaSftpHandler.lambda$channelRead$0(MinaSftpHandler.java:125)
> at com.sftpserver.MinaSftpHandler$$Lambda$392/0x000800764040.run(Unknown
> Source) at
> java.util.concurrent.Executors$RunnableAdapter.call(java.base@11.0.10/Executors.java:515)
> at
> java.util.concurrent.FutureTask.run(java.base@11.0.10/FutureTask.java:264) at
> java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.10/ThreadPoolExecutor.java:1128)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.10/ThreadPoolExecutor.java:628)
> at
[jira] [Comment Edited] (SSHD-1173) SFTP worker threads got stuck while processing PUT methods against one specific SFTP server
[
https://issues.apache.org/jira/browse/SSHD-1173?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17615261#comment-17615261
]
Kirk Rasmussen edited comment on SSHD-1173 at 10/10/22 9:27 PM:
BTW this is strictly an us problem but when I said it would be "nightmarish" I
simply meant that our customer's typically outsource managed file transfer to
3rd party companies and have little idea what SFTP protocol even is so trying
to explain why suddenly their files aren't being transferred anymore because
the "window adjustment message" isn't being sent their eyes will just glaze
over.
Prior to our latest release last week we were using JSch for many years which
didn't have this problem and we got caught at the last minute unfortunately (we
have many customers w/ a variety of SFTP servers which we have no control; this
particular problematic one used MOVEIT) - they have no idea nor do they need to
know what SFTP client library we use in our product.
Your explanation makes sense to me though thanks for all your help! [~twolf]
was (Author: JIRAUSER296597):
BTW when I said it would be "nightmarish" I simply meant that our customer's
typically outsource managed file transfer to 3rd party companies and have
little idea what SFTP protocol even is so trying to explain why suddenly their
files aren't being transferred anymore because the "window adjustment message"
isn't being sent their eyes will just glaze over. Prior to our latest release
last week we were using JSch for many years which didn't have this problem and
we got caught at the last minute unfortunately (we have many customers w/ a
variety of SFTP servers which we have no control; this particular problematic
one used MOVEIT) - they have no idea nor do they need to know what SFTP client
library we use in our product.
Your explanation makes sense to me though thanks for all your help! [~twolf]
> SFTP worker threads got stuck while processing PUT methods against one
> specific SFTP server
> ---
>
> Key: SSHD-1173
> URL: https://issues.apache.org/jira/browse/SSHD-1173
> Project: MINA SSHD
> Issue Type: Question
>Affects Versions: 2.6.0
>Reporter: Pavel Pohner
>Priority: Critical
> Labels: SFTP, mina, sshd
> Time Spent: 10m
> Remaining Estimate: 0h
>
> Hey guys,
> Recently I've encountered one remote SFTP server, that causes SFTP worker
> threads to enter TIMED_WAITING state, from which they do not recover. Please,
> take a look into this thread dump:
> {code:java}
> SFTP-worker-3 #2155 prio=5 os_prio=0 cpu=61692.09ms elapsed=1136151.86s
> tid=0x7fe41c005800 nid=0x18808 in Object.wait()
> [0x7fe145b1d000]SFTP-worker-3" #2155 prio=5 os_prio=0 cpu=61692.09ms
> elapsed=1136151.86s tid=0x7fe41c005800 nid=0x18808 in Object.wait()
> [0x7fe145b1d000] java.lang.Thread.State: TIMED_WAITING (on object
> monitor) at java.lang.Object.wait(java.base@11.0.10/Native Method) - waiting
> on at
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:69)
> - waiting to re-lock in wait() <0x0006e3bbc420> (a
> org.apache.sshd.common.channel.IoWriteFutureImpl) at
> org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:109)
> at
> org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:39)
> at
> org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:30)
> at
> org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43)
> at
> org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:292)
> at
> org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.flush(SftpOutputStreamAsync.java:210)
> at
> org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.write(SftpOutputStreamAsync.java:141)
> at java.io.InputStream.transferTo(java.base@11.0.10/InputStream.java:705) at
> com.mina.command.Put.replyInto(Put.java:55) at
> com.sftpserver.MinaSftpHandler.channelReadInternal(MinaSftpHandler.java:251)
> at
> com.sftpserver.MinaSftpHandler.lambda$channelRead$0(MinaSftpHandler.java:125)
> at com.sftpserver.MinaSftpHandler$$Lambda$392/0x000800764040.run(Unknown
> Source) at
> java.util.concurrent.Executors$RunnableAdapter.call(java.base@11.0.10/Executors.java:515)
> at
> java.util.concurrent.FutureTask.run(java.base@11.0.10/FutureTask.java:264) at
> java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.10/ThreadPoolExecutor.java:1128)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.10/ThreadPoolExecutor.java:628)
> at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)
> {code}
> Seems like the thread is waiting for lock in
>
[jira] [Comment Edited] (SSHD-1173) SFTP worker threads got stuck while processing PUT methods against one specific SFTP server
[
https://issues.apache.org/jira/browse/SSHD-1173?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17615261#comment-17615261
]
Kirk Rasmussen edited comment on SSHD-1173 at 10/10/22 9:25 PM:
BTW when I said it would be "nightmarish" I simply meant that our customer's
typically outsource managed file transfer to 3rd party companies and have
little idea what SFTP protocol even is so trying to explain why suddenly their
files aren't being transferred anymore because the "window adjustment message"
isn't being sent their eyes will just glaze over. Prior to our latest release
last week we were using JSch for many years which didn't have this problem and
we got caught at the last minute unfortunately (we have many customers w/ a
variety of SFTP servers which we have no control; this particular problematic
one used MOVEIT) - they have no idea nor do they need to know what SFTP client
library we use in our product.
Your explanation makes sense to me though thanks for all your help! [~twolf]
was (Author: JIRAUSER296597):
BTW when I said it would be "nightmarish" I simply meant that our customer's
typically outsource managed file transfer to 3rd party companies and have
little idea what SFTP protocol even is so trying to explain why suddenly their
files aren't being transferred anymore because the "window adjustment message"
isn't being sent their eyes will just glaze over. Prior to our latest release
last week we were using JSch for many years which didn't have this problem and
we got caught at the last minute unfortunately - they have no idea nor do they
need to know what SFTP library we use.
Your explanation makes sense to me though thanks for all your help! [~twolf]
> SFTP worker threads got stuck while processing PUT methods against one
> specific SFTP server
> ---
>
> Key: SSHD-1173
> URL: https://issues.apache.org/jira/browse/SSHD-1173
> Project: MINA SSHD
> Issue Type: Question
>Affects Versions: 2.6.0
>Reporter: Pavel Pohner
>Priority: Critical
> Labels: SFTP, mina, sshd
> Time Spent: 10m
> Remaining Estimate: 0h
>
> Hey guys,
> Recently I've encountered one remote SFTP server, that causes SFTP worker
> threads to enter TIMED_WAITING state, from which they do not recover. Please,
> take a look into this thread dump:
> {code:java}
> SFTP-worker-3 #2155 prio=5 os_prio=0 cpu=61692.09ms elapsed=1136151.86s
> tid=0x7fe41c005800 nid=0x18808 in Object.wait()
> [0x7fe145b1d000]SFTP-worker-3" #2155 prio=5 os_prio=0 cpu=61692.09ms
> elapsed=1136151.86s tid=0x7fe41c005800 nid=0x18808 in Object.wait()
> [0x7fe145b1d000] java.lang.Thread.State: TIMED_WAITING (on object
> monitor) at java.lang.Object.wait(java.base@11.0.10/Native Method) - waiting
> on at
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:69)
> - waiting to re-lock in wait() <0x0006e3bbc420> (a
> org.apache.sshd.common.channel.IoWriteFutureImpl) at
> org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:109)
> at
> org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:39)
> at
> org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:30)
> at
> org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43)
> at
> org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:292)
> at
> org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.flush(SftpOutputStreamAsync.java:210)
> at
> org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.write(SftpOutputStreamAsync.java:141)
> at java.io.InputStream.transferTo(java.base@11.0.10/InputStream.java:705) at
> com.mina.command.Put.replyInto(Put.java:55) at
> com.sftpserver.MinaSftpHandler.channelReadInternal(MinaSftpHandler.java:251)
> at
> com.sftpserver.MinaSftpHandler.lambda$channelRead$0(MinaSftpHandler.java:125)
> at com.sftpserver.MinaSftpHandler$$Lambda$392/0x000800764040.run(Unknown
> Source) at
> java.util.concurrent.Executors$RunnableAdapter.call(java.base@11.0.10/Executors.java:515)
> at
> java.util.concurrent.FutureTask.run(java.base@11.0.10/FutureTask.java:264) at
> java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.10/ThreadPoolExecutor.java:1128)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.10/ThreadPoolExecutor.java:628)
> at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)
> {code}
> Seems like the thread is waiting for lock in
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java),
> I'm currently not sure what thread holds the lock and why it's not ever
> released.
> Also, I'm not able to reproduce
[jira] [Comment Edited] (SSHD-1173) SFTP worker threads got stuck while processing PUT methods against one specific SFTP server
[
https://issues.apache.org/jira/browse/SSHD-1173?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17615261#comment-17615261
]
Kirk Rasmussen edited comment on SSHD-1173 at 10/10/22 9:09 PM:
BTW when I said it would be "nightmarish" I simply meant that our customer's
typically outsource managed file transfer to 3rd party companies and have
little idea what SFTP protocol even is so trying to explain why suddenly their
files aren't being transferred anymore because the "window adjustment message"
isn't being sent their eyes will just glaze over. Prior to our latest release
last week we were using JSch for many years which didn't have this problem and
we got caught at the last minute unfortunately - they have no idea nor do they
need to know what SFTP library we use.
Your explanation makes sense to me though thanks for all your help! [~twolf]
was (Author: JIRAUSER296597):
BTW when I said it would be "nightmarish" I simply meant that our customer's
typically outsource managed file transfer to 3rd party companies and have
little idea what SFTP protocol even is so trying to explain why suddenly their
files aren't being transferred anymore because the "window adjustment message"
isn't being sent their eyes will just glaze over. Prior to this latest release
last week we were using JSch for many years which didn't have this problem and
we got caught at the last minute unfortunately - they have no idea nor do they
need to know what SFTP library we use.
Your explanation makes sense to me though thanks for all your help! [~twolf]
> SFTP worker threads got stuck while processing PUT methods against one
> specific SFTP server
> ---
>
> Key: SSHD-1173
> URL: https://issues.apache.org/jira/browse/SSHD-1173
> Project: MINA SSHD
> Issue Type: Question
>Affects Versions: 2.6.0
>Reporter: Pavel Pohner
>Priority: Critical
> Labels: SFTP, mina, sshd
> Time Spent: 10m
> Remaining Estimate: 0h
>
> Hey guys,
> Recently I've encountered one remote SFTP server, that causes SFTP worker
> threads to enter TIMED_WAITING state, from which they do not recover. Please,
> take a look into this thread dump:
> {code:java}
> SFTP-worker-3 #2155 prio=5 os_prio=0 cpu=61692.09ms elapsed=1136151.86s
> tid=0x7fe41c005800 nid=0x18808 in Object.wait()
> [0x7fe145b1d000]SFTP-worker-3" #2155 prio=5 os_prio=0 cpu=61692.09ms
> elapsed=1136151.86s tid=0x7fe41c005800 nid=0x18808 in Object.wait()
> [0x7fe145b1d000] java.lang.Thread.State: TIMED_WAITING (on object
> monitor) at java.lang.Object.wait(java.base@11.0.10/Native Method) - waiting
> on at
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:69)
> - waiting to re-lock in wait() <0x0006e3bbc420> (a
> org.apache.sshd.common.channel.IoWriteFutureImpl) at
> org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:109)
> at
> org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:39)
> at
> org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:30)
> at
> org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43)
> at
> org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:292)
> at
> org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.flush(SftpOutputStreamAsync.java:210)
> at
> org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.write(SftpOutputStreamAsync.java:141)
> at java.io.InputStream.transferTo(java.base@11.0.10/InputStream.java:705) at
> com.mina.command.Put.replyInto(Put.java:55) at
> com.sftpserver.MinaSftpHandler.channelReadInternal(MinaSftpHandler.java:251)
> at
> com.sftpserver.MinaSftpHandler.lambda$channelRead$0(MinaSftpHandler.java:125)
> at com.sftpserver.MinaSftpHandler$$Lambda$392/0x000800764040.run(Unknown
> Source) at
> java.util.concurrent.Executors$RunnableAdapter.call(java.base@11.0.10/Executors.java:515)
> at
> java.util.concurrent.FutureTask.run(java.base@11.0.10/FutureTask.java:264) at
> java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.10/ThreadPoolExecutor.java:1128)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.10/ThreadPoolExecutor.java:628)
> at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)
> {code}
> Seems like the thread is waiting for lock in
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java),
> I'm currently not sure what thread holds the lock and why it's not ever
> released.
> Also, I'm not able to reproduce this, but it constantly happens to all the
> PUT methods targeting one specific remote server (which I don't own), so I
> suppose there would be
[jira] [Comment Edited] (SSHD-1173) SFTP worker threads got stuck while processing PUT methods against one specific SFTP server
[
https://issues.apache.org/jira/browse/SSHD-1173?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17615261#comment-17615261
]
Kirk Rasmussen edited comment on SSHD-1173 at 10/10/22 9:09 PM:
BTW when I said it would be "nightmarish" I simply meant that our customer's
typically outsource managed file transfer to 3rd party companies and have
little idea what SFTP protocol even is so trying to explain why suddenly their
files aren't being transferred anymore because the "window adjustment message"
isn't being sent their eyes will just glaze over. Prior to this latest release
last week we were using JSch for many years which didn't have this problem and
we got caught at the last minute unfortunately - they have no idea nor do they
need to know what SFTP library we use.
Your explanation makes sense to me though thanks for all your help! [~twolf]
was (Author: JIRAUSER296597):
BTW when I said it would be "nightmarish" I simply meant that our customer's
typically outsource managed file transfer to 3rd party companies and have
little idea what SFTP protocol even is so trying to explain why suddenly their
files aren't being transferred anymore because the "window adjustment message"
isn't being sent their eyes will just glaze over. Prior to this we were using
JSch which didn't have this problem and we got caught at the last minute
unfortunately - they have no idea nor do they need to know what SFTP library we
use.
Your explanation makes sense to me though thanks for all your help! [~twolf]
> SFTP worker threads got stuck while processing PUT methods against one
> specific SFTP server
> ---
>
> Key: SSHD-1173
> URL: https://issues.apache.org/jira/browse/SSHD-1173
> Project: MINA SSHD
> Issue Type: Question
>Affects Versions: 2.6.0
>Reporter: Pavel Pohner
>Priority: Critical
> Labels: SFTP, mina, sshd
> Time Spent: 10m
> Remaining Estimate: 0h
>
> Hey guys,
> Recently I've encountered one remote SFTP server, that causes SFTP worker
> threads to enter TIMED_WAITING state, from which they do not recover. Please,
> take a look into this thread dump:
> {code:java}
> SFTP-worker-3 #2155 prio=5 os_prio=0 cpu=61692.09ms elapsed=1136151.86s
> tid=0x7fe41c005800 nid=0x18808 in Object.wait()
> [0x7fe145b1d000]SFTP-worker-3" #2155 prio=5 os_prio=0 cpu=61692.09ms
> elapsed=1136151.86s tid=0x7fe41c005800 nid=0x18808 in Object.wait()
> [0x7fe145b1d000] java.lang.Thread.State: TIMED_WAITING (on object
> monitor) at java.lang.Object.wait(java.base@11.0.10/Native Method) - waiting
> on at
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:69)
> - waiting to re-lock in wait() <0x0006e3bbc420> (a
> org.apache.sshd.common.channel.IoWriteFutureImpl) at
> org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:109)
> at
> org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:39)
> at
> org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:30)
> at
> org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43)
> at
> org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:292)
> at
> org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.flush(SftpOutputStreamAsync.java:210)
> at
> org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.write(SftpOutputStreamAsync.java:141)
> at java.io.InputStream.transferTo(java.base@11.0.10/InputStream.java:705) at
> com.mina.command.Put.replyInto(Put.java:55) at
> com.sftpserver.MinaSftpHandler.channelReadInternal(MinaSftpHandler.java:251)
> at
> com.sftpserver.MinaSftpHandler.lambda$channelRead$0(MinaSftpHandler.java:125)
> at com.sftpserver.MinaSftpHandler$$Lambda$392/0x000800764040.run(Unknown
> Source) at
> java.util.concurrent.Executors$RunnableAdapter.call(java.base@11.0.10/Executors.java:515)
> at
> java.util.concurrent.FutureTask.run(java.base@11.0.10/FutureTask.java:264) at
> java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.10/ThreadPoolExecutor.java:1128)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.10/ThreadPoolExecutor.java:628)
> at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)
> {code}
> Seems like the thread is waiting for lock in
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java),
> I'm currently not sure what thread holds the lock and why it's not ever
> released.
> Also, I'm not able to reproduce this, but it constantly happens to all the
> PUT methods targeting one specific remote server (which I don't own), so I
> suppose there would be something odd with the remote server, but
[jira] [Comment Edited] (SSHD-1173) SFTP worker threads got stuck while processing PUT methods against one specific SFTP server
[
https://issues.apache.org/jira/browse/SSHD-1173?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17615261#comment-17615261
]
Kirk Rasmussen edited comment on SSHD-1173 at 10/10/22 9:01 PM:
BTW when I said it would be "nightmarish" I simply meant that our customer's
typically outsource managed file transfer to 3rd party companies and have
little idea what SFTP protocol even is so trying to explain why suddenly their
files aren't being transferred anymore because the "window adjustment message"
isn't being sent their eyes will just glaze over. Prior to this we were using
JSch which didn't have this problem and we got caught at the last minute
unfortunately - they have no idea nor do they need to know what SFTP library we
use.
Your explanation makes sense to me though thanks for all your help! [~twolf]
was (Author: JIRAUSER296597):
BTW when I said it would be "nightmarish" I simply meant that customer's
typically outsource managed file transfer to 3rd party companies and have
little idea what SFTP protocol even is so trying to explain why suddenly their
files aren't being transferred anymore because the "window adjustment message"
isn't being sent their eyes will just glaze over. Prior to this we were using
JSch which didn't have this problem and we got caught at the last minute
unfortunately - they have no idea nor do they need to know what SFTP library we
use.
Your explanation makes sense to me though thanks for all your help! [~twolf]
> SFTP worker threads got stuck while processing PUT methods against one
> specific SFTP server
> ---
>
> Key: SSHD-1173
> URL: https://issues.apache.org/jira/browse/SSHD-1173
> Project: MINA SSHD
> Issue Type: Question
>Affects Versions: 2.6.0
>Reporter: Pavel Pohner
>Priority: Critical
> Labels: SFTP, mina, sshd
> Time Spent: 10m
> Remaining Estimate: 0h
>
> Hey guys,
> Recently I've encountered one remote SFTP server, that causes SFTP worker
> threads to enter TIMED_WAITING state, from which they do not recover. Please,
> take a look into this thread dump:
> {code:java}
> SFTP-worker-3 #2155 prio=5 os_prio=0 cpu=61692.09ms elapsed=1136151.86s
> tid=0x7fe41c005800 nid=0x18808 in Object.wait()
> [0x7fe145b1d000]SFTP-worker-3" #2155 prio=5 os_prio=0 cpu=61692.09ms
> elapsed=1136151.86s tid=0x7fe41c005800 nid=0x18808 in Object.wait()
> [0x7fe145b1d000] java.lang.Thread.State: TIMED_WAITING (on object
> monitor) at java.lang.Object.wait(java.base@11.0.10/Native Method) - waiting
> on at
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:69)
> - waiting to re-lock in wait() <0x0006e3bbc420> (a
> org.apache.sshd.common.channel.IoWriteFutureImpl) at
> org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:109)
> at
> org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:39)
> at
> org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:30)
> at
> org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43)
> at
> org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:292)
> at
> org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.flush(SftpOutputStreamAsync.java:210)
> at
> org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.write(SftpOutputStreamAsync.java:141)
> at java.io.InputStream.transferTo(java.base@11.0.10/InputStream.java:705) at
> com.mina.command.Put.replyInto(Put.java:55) at
> com.sftpserver.MinaSftpHandler.channelReadInternal(MinaSftpHandler.java:251)
> at
> com.sftpserver.MinaSftpHandler.lambda$channelRead$0(MinaSftpHandler.java:125)
> at com.sftpserver.MinaSftpHandler$$Lambda$392/0x000800764040.run(Unknown
> Source) at
> java.util.concurrent.Executors$RunnableAdapter.call(java.base@11.0.10/Executors.java:515)
> at
> java.util.concurrent.FutureTask.run(java.base@11.0.10/FutureTask.java:264) at
> java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.10/ThreadPoolExecutor.java:1128)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.10/ThreadPoolExecutor.java:628)
> at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)
> {code}
> Seems like the thread is waiting for lock in
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java),
> I'm currently not sure what thread holds the lock and why it's not ever
> released.
> Also, I'm not able to reproduce this, but it constantly happens to all the
> PUT methods targeting one specific remote server (which I don't own), so I
> suppose there would be something odd with the remote server, but it doesn't
> mean, that we shouldn't be
[jira] [Commented] (SSHD-1173) SFTP worker threads got stuck while processing PUT methods against one specific SFTP server
[
https://issues.apache.org/jira/browse/SSHD-1173?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17615261#comment-17615261
]
Kirk Rasmussen commented on SSHD-1173:
--
BTW when I said it would be "nightmarish" I simply meant that customer's
typically outsource managed file transfer to 3rd party companies and have
little idea what SFTP protocol even is so trying to explain why suddenly their
files aren't being transferred anymore because the "window adjustment message"
isn't being sent their eyes will just glaze over. Prior to this we were using
JSch which didn't have this problem and we got caught at the last minute
unfortunately - they have no idea nor do they need to know what SFTP library we
use.
Your explanation makes sense to me though thanks for all your help! [~twolf]
> SFTP worker threads got stuck while processing PUT methods against one
> specific SFTP server
> ---
>
> Key: SSHD-1173
> URL: https://issues.apache.org/jira/browse/SSHD-1173
> Project: MINA SSHD
> Issue Type: Question
>Affects Versions: 2.6.0
>Reporter: Pavel Pohner
>Priority: Critical
> Labels: SFTP, mina, sshd
> Time Spent: 10m
> Remaining Estimate: 0h
>
> Hey guys,
> Recently I've encountered one remote SFTP server, that causes SFTP worker
> threads to enter TIMED_WAITING state, from which they do not recover. Please,
> take a look into this thread dump:
> {code:java}
> SFTP-worker-3 #2155 prio=5 os_prio=0 cpu=61692.09ms elapsed=1136151.86s
> tid=0x7fe41c005800 nid=0x18808 in Object.wait()
> [0x7fe145b1d000]SFTP-worker-3" #2155 prio=5 os_prio=0 cpu=61692.09ms
> elapsed=1136151.86s tid=0x7fe41c005800 nid=0x18808 in Object.wait()
> [0x7fe145b1d000] java.lang.Thread.State: TIMED_WAITING (on object
> monitor) at java.lang.Object.wait(java.base@11.0.10/Native Method) - waiting
> on at
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:69)
> - waiting to re-lock in wait() <0x0006e3bbc420> (a
> org.apache.sshd.common.channel.IoWriteFutureImpl) at
> org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:109)
> at
> org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:39)
> at
> org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:30)
> at
> org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43)
> at
> org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:292)
> at
> org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.flush(SftpOutputStreamAsync.java:210)
> at
> org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.write(SftpOutputStreamAsync.java:141)
> at java.io.InputStream.transferTo(java.base@11.0.10/InputStream.java:705) at
> com.mina.command.Put.replyInto(Put.java:55) at
> com.sftpserver.MinaSftpHandler.channelReadInternal(MinaSftpHandler.java:251)
> at
> com.sftpserver.MinaSftpHandler.lambda$channelRead$0(MinaSftpHandler.java:125)
> at com.sftpserver.MinaSftpHandler$$Lambda$392/0x000800764040.run(Unknown
> Source) at
> java.util.concurrent.Executors$RunnableAdapter.call(java.base@11.0.10/Executors.java:515)
> at
> java.util.concurrent.FutureTask.run(java.base@11.0.10/FutureTask.java:264) at
> java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.10/ThreadPoolExecutor.java:1128)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.10/ThreadPoolExecutor.java:628)
> at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)
> {code}
> Seems like the thread is waiting for lock in
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java),
> I'm currently not sure what thread holds the lock and why it's not ever
> released.
> Also, I'm not able to reproduce this, but it constantly happens to all the
> PUT methods targeting one specific remote server (which I don't own), so I
> suppose there would be something odd with the remote server, but it doesn't
> mean, that we shouldn't be able to deal with that.
> Have you ever seen such behavior? Could it be Mina sshd's bug? (seems like
> verify() in
> org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:292)
> is called without any timeout, which then defaults to LONG.MAX here: at
> org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43),
> shouldn't we have configurable timeout here? or what's the point of default
> timeout? what are we really waiting for in at
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:69)?)
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
-
To
[jira] [Comment Edited] (SSHD-1173) SFTP worker threads got stuck while processing PUT methods against one specific SFTP server
[
https://issues.apache.org/jira/browse/SSHD-1173?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17615236#comment-17615236
]
Kirk Rasmussen edited comment on SSHD-1173 at 10/10/22 5:59 PM:
Here's simple test harness (Apache Mina client SSHD 2.8.0) I was using to debug
remote server (MOVEIT Transfer 2018 SP1). I was able to verify in their server
logs that it wasn't sending the window adjustment message so your explanation
was right on the money as to why it was deadlocked. The following may not be
100% accurate (I'm trying to recreate the exact test setup - it should be close)
{code:java}
private static void write(final SftpClient client,
final String path,
final int size,
final int bufferSize) throws IOException {
System.out.printf("write(\"%s\", %d, %d)%n", path, size, bufferSize);
final Path uploadFile = createUploadFile(size);
final StopWatch stopWatch = new StopWatch();
stopWatch.start();
try (InputStream inputStream = Files.newInputStream(uploadFile);
OutputStream outputStream = client.write(
path,
bufferSize,
SftpClient.OpenMode.Write, SftpClient.OpenMode.Create,
SftpClient.OpenMode.Truncate)) {
final byte[] buffer = new byte[1_024];
int sent = 0;
int read;
while ((read = inputStream.read(buffer)) != -1) {
outputStream.write(buffer, 0, read);
sent += read;
System.out.print(".");
//System.out.printf("\tsent=%-15d (%3.02f%%) :: %s%n", sent,
(double)sent/size * 100.0, stopWatch.formatTime());
}
System.out.printf("%n\tTotal: %s%n", stopWatch.formatTime());
} catch (SftpException ex) {
System.out.printf("write(\"%s\") failed: %s (%d)%n", path, ex,
ex.getStatus());
}
}
{code}
It would deadlock w/o the SftpModuleProperties.CHUNK_IF_WINDOW_LESS_THAN_PACKET
setting , e.g.
{code:java}
write("/sftp-test.txt", 1048576, 0)
sent=1024 (0.10%) :: 00:00:00.126
sent=2048 (0.20%) :: 00:00:00.140
sent=3072 (0.29%) :: 00:00:00.140
sent=4096 (0.39%) :: 00:00:00.140
sent=5120 (0.49%) :: 00:00:00.140
sent=6144 (0.59%) :: 00:00:00.140
sent=7168 (0.68%) :: 00:00:00.140
sent=8192 (0.78%) :: 00:00:00.140
sent=9216 (0.88%) :: 00:00:00.141
sent=10240 (0.98%) :: 00:00:00.141
sent=11264 (1.07%) :: 00:00:00.141
sent=12288 (1.17%) :: 00:00:00.141
sent=13312 (1.27%) :: 00:00:00.141
sent=14336 (1.37%) :: 00:00:00.141
sent=15360 (1.46%) :: 00:00:00.141
sent=16384 (1.56%) :: 00:00:00.141
sent=17408 (1.66%) :: 00:00:00.142
sent=18432 (1.76%) :: 00:00:00.142
sent=19456 (1.86%) :: 00:00:00.142
sent=20480 (1.95%) :: 00:00:00.142
sent=21504 (2.05%) :: 00:00:00.142
sent=22528 (2.15%) :: 00:00:00.142
sent=23552 (2.25%) :: 00:00:00.142
sent=24576 (2.34%) :: 00:00:00.142
sent=25600 (2.44%) :: 00:00:00.143
sent=26624 (2.54%) :: 00:00:00.143
sent=27648 (2.64%) :: 00:00:00.143
sent=28672 (2.73%) :: 00:00:00.143
sent=29696 (2.83%) :: 00:00:00.143
sent=30720 (2.93%) :: 00:00:00.143
sent=31744 (3.03%) :: 00:00:00.143
{code}
I don't have the full stack trace unfortunately and I lost access to the server
but here's a partial grab (which is very similar to the original reporter's)
{code:java}
Caused by: java.io.InterruptedIOException:
IoWriteFutureImpl[SftpChannelSubsystem[id=0,
recipient=0]-ClientSessionImpl[cpq_dump@/10.18.242.4:8080][sftp][SSH_MSG_CHANNEL_DATA]]:
Interrupted after 37644419 msec.
at
org.apache.sshd.common.future.DefaultSshFuture.lambda$await0$0(DefaultSshFuture.java:74)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.AbstractSshFuture.formatExceptionMessage(AbstractSshFuture.java:185)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:73)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:109)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:39)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:30)
~[sshd-common-2.8.0.jar:2.8.0]
at
[jira] [Comment Edited] (SSHD-1173) SFTP worker threads got stuck while processing PUT methods against one specific SFTP server
[
https://issues.apache.org/jira/browse/SSHD-1173?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17615236#comment-17615236
]
Kirk Rasmussen edited comment on SSHD-1173 at 10/10/22 5:57 PM:
Here's simple test harness (Apache Mina client SSHD 2.8.0) I was using to debug
remote server (MOVEIT Transfer 2018 SP1). I was able to verify in their server
logs that it wasn't sending the window adjustment message so your explanation
was right on the money as to why it was deadlocked.
{code:java}
private static void write(final SftpClient client,
final String path,
final int size,
final int bufferSize) throws IOException {
System.out.printf("write(\"%s\", %d, %d)%n", path, size, bufferSize);
final Path uploadFile = createUploadFile(size);
final StopWatch stopWatch = new StopWatch();
stopWatch.start();
try (InputStream inputStream = Files.newInputStream(uploadFile);
OutputStream outputStream = client.write(
path,
bufferSize,
SftpClient.OpenMode.Write, SftpClient.OpenMode.Create,
SftpClient.OpenMode.Truncate)) {
final byte[] buffer = new byte[16 * 1_024];
int sent = 0;
int read;
while ((read = inputStream.read(buffer)) != -1) {
outputStream.write(buffer, 0, read);
sent += read;
System.out.print(".");
//System.out.printf("\tsent=%-15d (%3.02f%%) :: %s%n", sent,
(double)sent/size * 100.0, stopWatch.formatTime());
}
System.out.printf("%n\tTotal: %s%n", stopWatch.formatTime());
} catch (SftpException ex) {
System.out.printf("write(\"%s\") failed: %s (%d)%n", path, ex,
ex.getStatus());
}
}
{code}
It would deadlock w/o the SftpModuleProperties.CHUNK_IF_WINDOW_LESS_THAN_PACKET
setting , e.g.
{code:java}
write("/sftp-test.txt", 1048576, 0)
sent=1024 (0.10%) :: 00:00:00.126
sent=2048 (0.20%) :: 00:00:00.140
sent=3072 (0.29%) :: 00:00:00.140
sent=4096 (0.39%) :: 00:00:00.140
sent=5120 (0.49%) :: 00:00:00.140
sent=6144 (0.59%) :: 00:00:00.140
sent=7168 (0.68%) :: 00:00:00.140
sent=8192 (0.78%) :: 00:00:00.140
sent=9216 (0.88%) :: 00:00:00.141
sent=10240 (0.98%) :: 00:00:00.141
sent=11264 (1.07%) :: 00:00:00.141
sent=12288 (1.17%) :: 00:00:00.141
sent=13312 (1.27%) :: 00:00:00.141
sent=14336 (1.37%) :: 00:00:00.141
sent=15360 (1.46%) :: 00:00:00.141
sent=16384 (1.56%) :: 00:00:00.141
sent=17408 (1.66%) :: 00:00:00.142
sent=18432 (1.76%) :: 00:00:00.142
sent=19456 (1.86%) :: 00:00:00.142
sent=20480 (1.95%) :: 00:00:00.142
sent=21504 (2.05%) :: 00:00:00.142
sent=22528 (2.15%) :: 00:00:00.142
sent=23552 (2.25%) :: 00:00:00.142
sent=24576 (2.34%) :: 00:00:00.142
sent=25600 (2.44%) :: 00:00:00.143
sent=26624 (2.54%) :: 00:00:00.143
sent=27648 (2.64%) :: 00:00:00.143
sent=28672 (2.73%) :: 00:00:00.143
sent=29696 (2.83%) :: 00:00:00.143
sent=30720 (2.93%) :: 00:00:00.143
sent=31744 (3.03%) :: 00:00:00.143
{code}
I don't have the full stack trace unfortunately and I lost access to the server
but here's a partial grab (which is very similar to the original reporter's)
{code:java}
Caused by: java.io.InterruptedIOException:
IoWriteFutureImpl[SftpChannelSubsystem[id=0,
recipient=0]-ClientSessionImpl[cpq_dump@/10.18.242.4:8080][sftp][SSH_MSG_CHANNEL_DATA]]:
Interrupted after 37644419 msec.
at
org.apache.sshd.common.future.DefaultSshFuture.lambda$await0$0(DefaultSshFuture.java:74)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.AbstractSshFuture.formatExceptionMessage(AbstractSshFuture.java:185)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:73)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:109)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:39)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:30)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43)
~[sshd-common-2.8.0.jar:2.8.0]
at
[jira] [Comment Edited] (SSHD-1173) SFTP worker threads got stuck while processing PUT methods against one specific SFTP server
[
https://issues.apache.org/jira/browse/SSHD-1173?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17615236#comment-17615236
]
Kirk Rasmussen edited comment on SSHD-1173 at 10/10/22 5:54 PM:
Here's simple test harness (Apache Mina client SSHD 2.8.0) I was using to debug
remote server (MOVEIT Transfer 2018 SP1).
{code:java}
private static void write(final SftpClient client,
final String path,
final int size,
final int bufferSize) throws IOException {
System.out.printf("write(\"%s\", %d, %d)%n", path, size, bufferSize);
final Path uploadFile = createUploadFile(size);
final StopWatch stopWatch = new StopWatch();
stopWatch.start();
try (InputStream inputStream = Files.newInputStream(uploadFile);
OutputStream outputStream = client.write(
path,
bufferSize,
SftpClient.OpenMode.Write, SftpClient.OpenMode.Create,
SftpClient.OpenMode.Truncate)) {
final byte[] buffer = new byte[16 * 1_024];
int sent = 0;
int read;
while ((read = inputStream.read(buffer)) != -1) {
outputStream.write(buffer, 0, read);
sent += read;
System.out.print(".");
//System.out.printf("\tsent=%-15d (%3.02f%%) :: %s%n", sent,
(double)sent/size * 100.0, stopWatch.formatTime());
}
System.out.printf("%n\tTotal: %s%n", stopWatch.formatTime());
} catch (SftpException ex) {
System.out.printf("write(\"%s\") failed: %s (%d)%n", path, ex,
ex.getStatus());
}
}
{code}
It would deadlock w/o the SftpModuleProperties.CHUNK_IF_WINDOW_LESS_THAN_PACKET
setting , e.g.
{code:java}
write("/sftp-test.txt", 1048576, 0)
sent=1024 (0.10%) :: 00:00:00.126
sent=2048 (0.20%) :: 00:00:00.140
sent=3072 (0.29%) :: 00:00:00.140
sent=4096 (0.39%) :: 00:00:00.140
sent=5120 (0.49%) :: 00:00:00.140
sent=6144 (0.59%) :: 00:00:00.140
sent=7168 (0.68%) :: 00:00:00.140
sent=8192 (0.78%) :: 00:00:00.140
sent=9216 (0.88%) :: 00:00:00.141
sent=10240 (0.98%) :: 00:00:00.141
sent=11264 (1.07%) :: 00:00:00.141
sent=12288 (1.17%) :: 00:00:00.141
sent=13312 (1.27%) :: 00:00:00.141
sent=14336 (1.37%) :: 00:00:00.141
sent=15360 (1.46%) :: 00:00:00.141
sent=16384 (1.56%) :: 00:00:00.141
sent=17408 (1.66%) :: 00:00:00.142
sent=18432 (1.76%) :: 00:00:00.142
sent=19456 (1.86%) :: 00:00:00.142
sent=20480 (1.95%) :: 00:00:00.142
sent=21504 (2.05%) :: 00:00:00.142
sent=22528 (2.15%) :: 00:00:00.142
sent=23552 (2.25%) :: 00:00:00.142
sent=24576 (2.34%) :: 00:00:00.142
sent=25600 (2.44%) :: 00:00:00.143
sent=26624 (2.54%) :: 00:00:00.143
sent=27648 (2.64%) :: 00:00:00.143
sent=28672 (2.73%) :: 00:00:00.143
sent=29696 (2.83%) :: 00:00:00.143
sent=30720 (2.93%) :: 00:00:00.143
sent=31744 (3.03%) :: 00:00:00.143
{code}
I don't have the full stack trace unfortunately and I lost access to the server
but here's a partial grab (which is very similar to the original reporter's)
{code:java}
Caused by: java.io.InterruptedIOException:
IoWriteFutureImpl[SftpChannelSubsystem[id=0,
recipient=0]-ClientSessionImpl[cpq_dump@/10.18.242.4:8080][sftp][SSH_MSG_CHANNEL_DATA]]:
Interrupted after 37644419 msec.
at
org.apache.sshd.common.future.DefaultSshFuture.lambda$await0$0(DefaultSshFuture.java:74)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.AbstractSshFuture.formatExceptionMessage(AbstractSshFuture.java:185)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:73)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:109)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:39)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:30)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:301)
~[sshd-sftp-2.8.0.jar:2.8.0]
at
org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.flush(SftpOutputStreamAsync.java:207)
[jira] [Comment Edited] (SSHD-1173) SFTP worker threads got stuck while processing PUT methods against one specific SFTP server
[
https://issues.apache.org/jira/browse/SSHD-1173?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17615236#comment-17615236
]
Kirk Rasmussen edited comment on SSHD-1173 at 10/10/22 5:52 PM:
Here's simple test harness I was using to debug remote server.
{code:java}
private static void write(final SftpClient client,
final String path,
final int size,
final int bufferSize) throws IOException {
System.out.printf("write(\"%s\", %d, %d)%n", path, size, bufferSize);
final Path uploadFile = createUploadFile(size);
final StopWatch stopWatch = new StopWatch();
stopWatch.start();
try (InputStream inputStream = Files.newInputStream(uploadFile);
OutputStream outputStream = client.write(
path,
bufferSize,
SftpClient.OpenMode.Write, SftpClient.OpenMode.Create,
SftpClient.OpenMode.Truncate)) {
final byte[] buffer = new byte[16 * 1_024];
int sent = 0;
int read;
while ((read = inputStream.read(buffer)) != -1) {
outputStream.write(buffer, 0, read);
sent += read;
System.out.print(".");
//System.out.printf("\tsent=%-15d (%3.02f%%) :: %s%n", sent,
(double)sent/size * 100.0, stopWatch.formatTime());
}
System.out.printf("%n\tTotal: %s%n", stopWatch.formatTime());
} catch (SftpException ex) {
System.out.printf("write(\"%s\") failed: %s (%d)%n", path, ex,
ex.getStatus());
}
}
{code}
It would deadlock w/o the SftpModuleProperties.CHUNK_IF_WINDOW_LESS_THAN_PACKET
setting , e.g.
{code:java}
write("/sftp-test.txt", 1048576, 0)
sent=1024 (0.10%) :: 00:00:00.126
sent=2048 (0.20%) :: 00:00:00.140
sent=3072 (0.29%) :: 00:00:00.140
sent=4096 (0.39%) :: 00:00:00.140
sent=5120 (0.49%) :: 00:00:00.140
sent=6144 (0.59%) :: 00:00:00.140
sent=7168 (0.68%) :: 00:00:00.140
sent=8192 (0.78%) :: 00:00:00.140
sent=9216 (0.88%) :: 00:00:00.141
sent=10240 (0.98%) :: 00:00:00.141
sent=11264 (1.07%) :: 00:00:00.141
sent=12288 (1.17%) :: 00:00:00.141
sent=13312 (1.27%) :: 00:00:00.141
sent=14336 (1.37%) :: 00:00:00.141
sent=15360 (1.46%) :: 00:00:00.141
sent=16384 (1.56%) :: 00:00:00.141
sent=17408 (1.66%) :: 00:00:00.142
sent=18432 (1.76%) :: 00:00:00.142
sent=19456 (1.86%) :: 00:00:00.142
sent=20480 (1.95%) :: 00:00:00.142
sent=21504 (2.05%) :: 00:00:00.142
sent=22528 (2.15%) :: 00:00:00.142
sent=23552 (2.25%) :: 00:00:00.142
sent=24576 (2.34%) :: 00:00:00.142
sent=25600 (2.44%) :: 00:00:00.143
sent=26624 (2.54%) :: 00:00:00.143
sent=27648 (2.64%) :: 00:00:00.143
sent=28672 (2.73%) :: 00:00:00.143
sent=29696 (2.83%) :: 00:00:00.143
sent=30720 (2.93%) :: 00:00:00.143
sent=31744 (3.03%) :: 00:00:00.143
{code}
I don't have the full stack trace unfortunately and I lost access to the server
but here's a partial grab (which is very similar to the original reporter's)
{code:java}
Caused by: java.io.InterruptedIOException:
IoWriteFutureImpl[SftpChannelSubsystem[id=0,
recipient=0]-ClientSessionImpl[cpq_dump@/10.18.242.4:8080][sftp][SSH_MSG_CHANNEL_DATA]]:
Interrupted after 37644419 msec.
at
org.apache.sshd.common.future.DefaultSshFuture.lambda$await0$0(DefaultSshFuture.java:74)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.AbstractSshFuture.formatExceptionMessage(AbstractSshFuture.java:185)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:73)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:109)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:39)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:30)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:301)
~[sshd-sftp-2.8.0.jar:2.8.0]
at
org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.flush(SftpOutputStreamAsync.java:207)
~[sshd-sftp-2.8.0.jar:2.8.0]
at
[jira] [Comment Edited] (SSHD-1173) SFTP worker threads got stuck while processing PUT methods against one specific SFTP server
[
https://issues.apache.org/jira/browse/SSHD-1173?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17615236#comment-17615236
]
Kirk Rasmussen edited comment on SSHD-1173 at 10/10/22 5:49 PM:
Here's simple test harness I was using to debug remote server.
{code:java}
private static void write(final SftpClient client,
final String path,
final int size,
final int bufferSize) throws IOException {
System.out.printf("write(\"%s\", %d, %d)%n", path, size, bufferSize);
final Path uploadFile = createUploadFile(size);
final StopWatch stopWatch = new StopWatch();
stopWatch.start();
try (InputStream inputStream = Files.newInputStream(uploadFile);
OutputStream outputStream = client.write(
path,
bufferSize,
SftpClient.OpenMode.Write, SftpClient.OpenMode.Create,
SftpClient.OpenMode.Truncate)) {
final byte[] buffer = new byte[16 * 1_024];
int sent = 0;
int read;
while ((read = inputStream.read(buffer)) != -1) {
outputStream.write(buffer, 0, read);
sent += read;
System.out.print(".");
//System.out.printf("\tsent=%-15d (%3.02f%%) :: %s%n", sent,
(double)sent/size * 100.0, stopWatch.formatTime());
}
System.out.printf("%n\tTotal: %s%n", stopWatch.formatTime());
} catch (SftpException ex) {
System.out.printf("write(\"%s\") failed: %s (%d)%n", path, ex,
ex.getStatus());
}
}
{code}
It would deadlock w/o the SftpModuleProperties.CHUNK_IF_WINDOW_LESS_THAN_PACKET
setting , e.g.
{code:java}
write("/sftp-test.txt", 1048576, 0)
sent=1024 (0.10%) :: 00:00:00.126
sent=2048 (0.20%) :: 00:00:00.140
sent=3072 (0.29%) :: 00:00:00.140
sent=4096 (0.39%) :: 00:00:00.140
sent=5120 (0.49%) :: 00:00:00.140
sent=6144 (0.59%) :: 00:00:00.140
sent=7168 (0.68%) :: 00:00:00.140
sent=8192 (0.78%) :: 00:00:00.140
sent=9216 (0.88%) :: 00:00:00.141
sent=10240 (0.98%) :: 00:00:00.141
sent=11264 (1.07%) :: 00:00:00.141
sent=12288 (1.17%) :: 00:00:00.141
sent=13312 (1.27%) :: 00:00:00.141
sent=14336 (1.37%) :: 00:00:00.141
sent=15360 (1.46%) :: 00:00:00.141
sent=16384 (1.56%) :: 00:00:00.141
sent=17408 (1.66%) :: 00:00:00.142
sent=18432 (1.76%) :: 00:00:00.142
sent=19456 (1.86%) :: 00:00:00.142
sent=20480 (1.95%) :: 00:00:00.142
sent=21504 (2.05%) :: 00:00:00.142
sent=22528 (2.15%) :: 00:00:00.142
sent=23552 (2.25%) :: 00:00:00.142
sent=24576 (2.34%) :: 00:00:00.142
sent=25600 (2.44%) :: 00:00:00.143
sent=26624 (2.54%) :: 00:00:00.143
sent=27648 (2.64%) :: 00:00:00.143
sent=28672 (2.73%) :: 00:00:00.143
sent=29696 (2.83%) :: 00:00:00.143
sent=30720 (2.93%) :: 00:00:00.143
sent=31744 (3.03%) :: 00:00:00.143
{code}
I don't have the full stack trace unfortunately and I lost access to the server
but here's a partial grab (which is very similar to the original reporter's)
{code:java}
Caused by: java.io.InterruptedIOException:
IoWriteFutureImpl[SftpChannelSubsystem[id=0,
recipient=0]-ClientSessionImpl[cpq_dump@/10.18.242.4:8080][sftp][SSH_MSG_CHANNEL_DATA]]:
Interrupted after 37644419 msec.
at
org.apache.sshd.common.future.DefaultSshFuture.lambda$await0$0(DefaultSshFuture.java:74)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.AbstractSshFuture.formatExceptionMessage(AbstractSshFuture.java:185)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:73)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:109)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:39)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:30)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:301)
~[sshd-sftp-2.8.0.jar:2.8.0]
at
org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.flush(SftpOutputStreamAsync.java:207)
~[sshd-sftp-2.8.0.jar:2.8.0]
at
[jira] [Comment Edited] (SSHD-1173) SFTP worker threads got stuck while processing PUT methods against one specific SFTP server
[
https://issues.apache.org/jira/browse/SSHD-1173?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17615236#comment-17615236
]
Kirk Rasmussen edited comment on SSHD-1173 at 10/10/22 5:47 PM:
Here's simple test harness I was using to debug remote server.
{code:java}
private static void write(final SftpClient client,
final String path,
final int size,
final int bufferSize) throws IOException {
System.out.printf("write(\"%s\", %d, %d)%n", path, size, bufferSize);
final Path uploadFile = createUploadFile(size);
final StopWatch stopWatch = new StopWatch();
stopWatch.start();
try (InputStream inputStream = Files.newInputStream(uploadFile);
OutputStream outputStream = client.write(
path,
bufferSize,
SftpClient.OpenMode.Write, SftpClient.OpenMode.Create,
SftpClient.OpenMode.Truncate)) {
final byte[] buffer = new byte[16 * 1_024];
int sent = 0;
int read;
while ((read = inputStream.read(buffer)) != -1) {
outputStream.write(buffer, 0, read);
sent += read;
System.out.print(".");
//System.out.printf("\tsent=%-15d (%3.02f%%) :: %s%n", sent,
(double)sent/size * 100.0, stopWatch.formatTime());
}
System.out.printf("%n\tTotal: %s%n", stopWatch.formatTime());
} catch (SftpException ex) {
System.out.printf("write(\"%s\") failed: %s (%d)%n", path, ex,
ex.getStatus());
}
}
{code}
It would deadlock w/o the SftpModuleProperties.CHUNK_IF_WINDOW_LESS_THAN_PACKET
setting , e.g.
{code:java}
write("/sftp-test.txt", 1048576, 0)
sent=1024 (0.10%) :: 00:00:00.126
sent=2048 (0.20%) :: 00:00:00.140
sent=3072 (0.29%) :: 00:00:00.140
sent=4096 (0.39%) :: 00:00:00.140
sent=5120 (0.49%) :: 00:00:00.140
sent=6144 (0.59%) :: 00:00:00.140
sent=7168 (0.68%) :: 00:00:00.140
sent=8192 (0.78%) :: 00:00:00.140
sent=9216 (0.88%) :: 00:00:00.141
sent=10240 (0.98%) :: 00:00:00.141
sent=11264 (1.07%) :: 00:00:00.141
sent=12288 (1.17%) :: 00:00:00.141
sent=13312 (1.27%) :: 00:00:00.141
sent=14336 (1.37%) :: 00:00:00.141
sent=15360 (1.46%) :: 00:00:00.141
sent=16384 (1.56%) :: 00:00:00.141
sent=17408 (1.66%) :: 00:00:00.142
sent=18432 (1.76%) :: 00:00:00.142
sent=19456 (1.86%) :: 00:00:00.142
sent=20480 (1.95%) :: 00:00:00.142
sent=21504 (2.05%) :: 00:00:00.142
sent=22528 (2.15%) :: 00:00:00.142
sent=23552 (2.25%) :: 00:00:00.142
sent=24576 (2.34%) :: 00:00:00.142
sent=25600 (2.44%) :: 00:00:00.143
sent=26624 (2.54%) :: 00:00:00.143
sent=27648 (2.64%) :: 00:00:00.143
sent=28672 (2.73%) :: 00:00:00.143
sent=29696 (2.83%) :: 00:00:00.143
sent=30720 (2.93%) :: 00:00:00.143
sent=31744 (3.03%) :: 00:00:00.143
{code}
I don't have the full stack trace unfortunately and I lost access to the server
but here's a partial grab (which is very similar to the original reporter's)
{code:java}
Caused by: java.io.InterruptedIOException:
IoWriteFutureImpl[SftpChannelSubsystem[id=0,
recipient=0]-ClientSessionImpl[cpq_dump@/10.18.242.4:8080][sftp][SSH_MSG_CHANNEL_DATA]]:
Interrupted after 37644419 msec.
at
org.apache.sshd.common.future.DefaultSshFuture.lambda$await0$0(DefaultSshFuture.java:74)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.AbstractSshFuture.formatExceptionMessage(AbstractSshFuture.java:185)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:73)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:109)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:39)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:30)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:301)
~[sshd-sftp-2.8.0.jar:2.8.0]
at
org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.flush(SftpOutputStreamAsync.java:207)
~[sshd-sftp-2.8.0.jar:2.8.0]
at
[jira] [Comment Edited] (SSHD-1173) SFTP worker threads got stuck while processing PUT methods against one specific SFTP server
[
https://issues.apache.org/jira/browse/SSHD-1173?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17615236#comment-17615236
]
Kirk Rasmussen edited comment on SSHD-1173 at 10/10/22 5:44 PM:
Here's simple test harness I was using to debug remote server.
{code:java}
private static void write(final SftpClient client,
final String path,
final int size,
final int bufferSize) throws IOException {
System.out.printf("write(\"%s\", %d, %d)%n", path, size, bufferSize);
final Path uploadFile = createUploadFile(size);
final StopWatch stopWatch = new StopWatch();
stopWatch.start();
try (InputStream inputStream = Files.newInputStream(uploadFile);
OutputStream outputStream = client.write(
path,
bufferSize,
SftpClient.OpenMode.Write, SftpClient.OpenMode.Create,
SftpClient.OpenMode.Truncate)) {
final byte[] buffer = new byte[16 * 1_024];
int sent = 0;
int read;
while ((read = inputStream.read(buffer)) != -1) {
outputStream.write(buffer, 0, read);
sent += read;
System.out.print(".");
//System.out.printf("\tsent=%-15d (%3.02f%%) :: %s%n", sent,
(double)sent/size * 100.0, stopWatch.formatTime());
}
System.out.printf("%n\tTotal: %s%n", stopWatch.formatTime());
} catch (SftpException ex) {
System.out.printf("write(\"%s\") failed: %s (%d)%n", path, ex,
ex.getStatus());
}
}
{code}
I did find there was one other workaround I found that worked ok was using a
custom bufferSize (e.g. 15000)
otherwise it would deadlock w/o the
SftpModuleProperties.CHUNK_IF_WINDOW_LESS_THAN_PACKET setting , e.g.
{code:java}
write("/sftp-test.txt", 1048576, 0)
sent=1024 (0.10%) :: 00:00:00.126
sent=2048 (0.20%) :: 00:00:00.140
sent=3072 (0.29%) :: 00:00:00.140
sent=4096 (0.39%) :: 00:00:00.140
sent=5120 (0.49%) :: 00:00:00.140
sent=6144 (0.59%) :: 00:00:00.140
sent=7168 (0.68%) :: 00:00:00.140
sent=8192 (0.78%) :: 00:00:00.140
sent=9216 (0.88%) :: 00:00:00.141
sent=10240 (0.98%) :: 00:00:00.141
sent=11264 (1.07%) :: 00:00:00.141
sent=12288 (1.17%) :: 00:00:00.141
sent=13312 (1.27%) :: 00:00:00.141
sent=14336 (1.37%) :: 00:00:00.141
sent=15360 (1.46%) :: 00:00:00.141
sent=16384 (1.56%) :: 00:00:00.141
sent=17408 (1.66%) :: 00:00:00.142
sent=18432 (1.76%) :: 00:00:00.142
sent=19456 (1.86%) :: 00:00:00.142
sent=20480 (1.95%) :: 00:00:00.142
sent=21504 (2.05%) :: 00:00:00.142
sent=22528 (2.15%) :: 00:00:00.142
sent=23552 (2.25%) :: 00:00:00.142
sent=24576 (2.34%) :: 00:00:00.142
sent=25600 (2.44%) :: 00:00:00.143
sent=26624 (2.54%) :: 00:00:00.143
sent=27648 (2.64%) :: 00:00:00.143
sent=28672 (2.73%) :: 00:00:00.143
sent=29696 (2.83%) :: 00:00:00.143
sent=30720 (2.93%) :: 00:00:00.143
sent=31744 (3.03%) :: 00:00:00.143
{code}
I don't have the full stack trace unfortunately and I lost access to the server
but here's a partial grab (which is very similar to the original reporter's)
{code:java}
Caused by: java.io.InterruptedIOException:
IoWriteFutureImpl[SftpChannelSubsystem[id=0,
recipient=0]-ClientSessionImpl[cpq_dump@/10.18.242.4:8080][sftp][SSH_MSG_CHANNEL_DATA]]:
Interrupted after 37644419 msec.
at
org.apache.sshd.common.future.DefaultSshFuture.lambda$await0$0(DefaultSshFuture.java:74)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.AbstractSshFuture.formatExceptionMessage(AbstractSshFuture.java:185)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:73)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:109)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:39)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:30)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:301)
~[sshd-sftp-2.8.0.jar:2.8.0]
at
[jira] [Comment Edited] (SSHD-1173) SFTP worker threads got stuck while processing PUT methods against one specific SFTP server
[
https://issues.apache.org/jira/browse/SSHD-1173?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17615236#comment-17615236
]
Kirk Rasmussen edited comment on SSHD-1173 at 10/10/22 5:43 PM:
Here's simple test harness I was using to debug remote server.
{code:java}
private static void write(final SftpClient client,
final String path,
final int size,
final int bufferSize) throws IOException {
System.out.printf("write(\"%s\", %d, %d)%n", path, size, bufferSize);
final Path uploadFile = createUploadFile(size);
final StopWatch stopWatch = new StopWatch();
stopWatch.start();
try (InputStream inputStream = Files.newInputStream(uploadFile);
OutputStream outputStream = client.write(
path,
bufferSize,
SftpClient.OpenMode.Write, SftpClient.OpenMode.Create,
SftpClient.OpenMode.Truncate)) {
final byte[] buffer = new byte[16 * 1_024];
int sent = 0;
int read;
while ((read = inputStream.read(buffer)) != -1) {
outputStream.write(buffer, 0, read);
sent += read;
System.out.print(".");
//System.out.printf("\tsent=%-15d (%3.02f%%) :: %s%n", sent,
(double)sent/size * 100.0, stopWatch.formatTime());
}
System.out.printf("%n\tTotal: %s%n", stopWatch.formatTime());
} catch (SftpException ex) {
System.out.printf("write(\"%s\") failed: %s (%d)%n", path, ex,
ex.getStatus());
}
}
{code}
I did find there was one other workaround I found that worked ok was using a
custom bufferSize (e.g. 15000)
otherwise it would deadlock w/o the
SftpModuleProperties.CHUNK_IF_WINDOW_LESS_THAN_PACKET setting , e.g.
{code:java}
write("/sftp-test.txt", 1048576, 1024)
sent=1024 (0.10%) :: 00:00:00.126
sent=2048 (0.20%) :: 00:00:00.140
sent=3072 (0.29%) :: 00:00:00.140
sent=4096 (0.39%) :: 00:00:00.140
sent=5120 (0.49%) :: 00:00:00.140
sent=6144 (0.59%) :: 00:00:00.140
sent=7168 (0.68%) :: 00:00:00.140
sent=8192 (0.78%) :: 00:00:00.140
sent=9216 (0.88%) :: 00:00:00.141
sent=10240 (0.98%) :: 00:00:00.141
sent=11264 (1.07%) :: 00:00:00.141
sent=12288 (1.17%) :: 00:00:00.141
sent=13312 (1.27%) :: 00:00:00.141
sent=14336 (1.37%) :: 00:00:00.141
sent=15360 (1.46%) :: 00:00:00.141
sent=16384 (1.56%) :: 00:00:00.141
sent=17408 (1.66%) :: 00:00:00.142
sent=18432 (1.76%) :: 00:00:00.142
sent=19456 (1.86%) :: 00:00:00.142
sent=20480 (1.95%) :: 00:00:00.142
sent=21504 (2.05%) :: 00:00:00.142
sent=22528 (2.15%) :: 00:00:00.142
sent=23552 (2.25%) :: 00:00:00.142
sent=24576 (2.34%) :: 00:00:00.142
sent=25600 (2.44%) :: 00:00:00.143
sent=26624 (2.54%) :: 00:00:00.143
sent=27648 (2.64%) :: 00:00:00.143
sent=28672 (2.73%) :: 00:00:00.143
sent=29696 (2.83%) :: 00:00:00.143
sent=30720 (2.93%) :: 00:00:00.143
sent=31744 (3.03%) :: 00:00:00.143
{code}
I don't have the full stack trace unfortunately and I lost access to the server
but here's a partial grab (which is very similar to the original reporter's)
{code:java}
Caused by: java.io.InterruptedIOException:
IoWriteFutureImpl[SftpChannelSubsystem[id=0,
recipient=0]-ClientSessionImpl[cpq_dump@/10.18.242.4:8080][sftp][SSH_MSG_CHANNEL_DATA]]:
Interrupted after 37644419 msec.
at
org.apache.sshd.common.future.DefaultSshFuture.lambda$await0$0(DefaultSshFuture.java:74)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.AbstractSshFuture.formatExceptionMessage(AbstractSshFuture.java:185)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:73)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:109)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:39)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:30)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:301)
~[sshd-sftp-2.8.0.jar:2.8.0]
at
[jira] [Commented] (SSHD-1173) SFTP worker threads got stuck while processing PUT methods against one specific SFTP server
[
https://issues.apache.org/jira/browse/SSHD-1173?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17615236#comment-17615236
]
Kirk Rasmussen commented on SSHD-1173:
--
Here's simple test harness I was using to debug remote server.
{code:java}
private static void write(final SftpClient client,
final String path,
final int size,
final int bufferSize) throws IOException {
System.out.printf("write(\"%s\", %d, %d)%n", path, size, bufferSize);
final Path uploadFile = createUploadFile(size);
final StopWatch stopWatch = new StopWatch();
stopWatch.start();
try (InputStream inputStream = Files.newInputStream(uploadFile);
OutputStream outputStream = client.write(
path,
bufferSize,
SftpClient.OpenMode.Write, SftpClient.OpenMode.Create,
SftpClient.OpenMode.Truncate)) {
final byte[] buffer = new byte[16 * 1_024];
int sent = 0;
int read;
while ((read = inputStream.read(buffer)) != -1) {
outputStream.write(buffer, 0, read);
sent += read;
System.out.print(".");
//System.out.printf("\tsent=%-15d (%3.02f%%) :: %s%n", sent,
(double)sent/size * 100.0, stopWatch.formatTime());
}
System.out.printf("%n\tTotal: %s%n", stopWatch.formatTime());
} catch (SftpException ex) {
System.out.printf("write(\"%s\") failed: %s (%d)%n", path, ex,
ex.getStatus());
}
}
{code}
I did find there was one other workaround I found that worked ok was using a
custom bufferSize (e.g. 15000)
otherwise it would deadlock w/o the
SftpModuleProperties.CHUNK_IF_WINDOW_LESS_THAN_PACKET setting , e.g.
{code:java}
write("/cpq/cpq_dump/cpq-sftp-test.txt", 1048576, 1024)
sent=1024 (0.10%) :: 00:00:00.126
sent=2048 (0.20%) :: 00:00:00.140
sent=3072 (0.29%) :: 00:00:00.140
sent=4096 (0.39%) :: 00:00:00.140
sent=5120 (0.49%) :: 00:00:00.140
sent=6144 (0.59%) :: 00:00:00.140
sent=7168 (0.68%) :: 00:00:00.140
sent=8192 (0.78%) :: 00:00:00.140
sent=9216 (0.88%) :: 00:00:00.141
sent=10240 (0.98%) :: 00:00:00.141
sent=11264 (1.07%) :: 00:00:00.141
sent=12288 (1.17%) :: 00:00:00.141
sent=13312 (1.27%) :: 00:00:00.141
sent=14336 (1.37%) :: 00:00:00.141
sent=15360 (1.46%) :: 00:00:00.141
sent=16384 (1.56%) :: 00:00:00.141
sent=17408 (1.66%) :: 00:00:00.142
sent=18432 (1.76%) :: 00:00:00.142
sent=19456 (1.86%) :: 00:00:00.142
sent=20480 (1.95%) :: 00:00:00.142
sent=21504 (2.05%) :: 00:00:00.142
sent=22528 (2.15%) :: 00:00:00.142
sent=23552 (2.25%) :: 00:00:00.142
sent=24576 (2.34%) :: 00:00:00.142
sent=25600 (2.44%) :: 00:00:00.143
sent=26624 (2.54%) :: 00:00:00.143
sent=27648 (2.64%) :: 00:00:00.143
sent=28672 (2.73%) :: 00:00:00.143
sent=29696 (2.83%) :: 00:00:00.143
sent=30720 (2.93%) :: 00:00:00.143
sent=31744 (3.03%) :: 00:00:00.143
{code}
I don't have the full stack trace unfortunately and I lost access to the server
but here's a partial grab (which is very similar to the original reporter's)
{code:java}
Caused by: java.io.InterruptedIOException:
IoWriteFutureImpl[SftpChannelSubsystem[id=0,
recipient=0]-ClientSessionImpl[cpq_dump@/10.18.242.4:8080][sftp][SSH_MSG_CHANNEL_DATA]]:
Interrupted after 37644419 msec.
at
org.apache.sshd.common.future.DefaultSshFuture.lambda$await0$0(DefaultSshFuture.java:74)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.AbstractSshFuture.formatExceptionMessage(AbstractSshFuture.java:185)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:73)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:109)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:39)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:30)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43)
~[sshd-common-2.8.0.jar:2.8.0]
at
org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:301)
~[sshd-sftp-2.8.0.jar:2.8.0]
at
[jira] [Commented] (SSHD-1173) SFTP worker threads got stuck while processing PUT methods against one specific SFTP server
[
https://issues.apache.org/jira/browse/SSHD-1173?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17615230#comment-17615230
]
Kirk Rasmussen commented on SSHD-1173:
--
Sorry I didn't fully grok what you were saying in the PR now that I re-read it
I understand. I just freaked out when you said you were removing an option
which was the only thing that allowing our client to communicate successfully
with MOVEIT SFTP server w/o deadlock - was in middle of a major release so was
under a lot of pressure last week.
I'll provide some examples for posterity (v 2.8.0) in case anyone else ran into
this issue and are looking for solutions.
> SFTP worker threads got stuck while processing PUT methods against one
> specific SFTP server
> ---
>
> Key: SSHD-1173
> URL: https://issues.apache.org/jira/browse/SSHD-1173
> Project: MINA SSHD
> Issue Type: Question
>Affects Versions: 2.6.0
>Reporter: Pavel Pohner
>Priority: Critical
> Labels: SFTP, mina, sshd
> Time Spent: 10m
> Remaining Estimate: 0h
>
> Hey guys,
> Recently I've encountered one remote SFTP server, that causes SFTP worker
> threads to enter TIMED_WAITING state, from which they do not recover. Please,
> take a look into this thread dump:
> {code:java}
> SFTP-worker-3 #2155 prio=5 os_prio=0 cpu=61692.09ms elapsed=1136151.86s
> tid=0x7fe41c005800 nid=0x18808 in Object.wait()
> [0x7fe145b1d000]SFTP-worker-3" #2155 prio=5 os_prio=0 cpu=61692.09ms
> elapsed=1136151.86s tid=0x7fe41c005800 nid=0x18808 in Object.wait()
> [0x7fe145b1d000] java.lang.Thread.State: TIMED_WAITING (on object
> monitor) at java.lang.Object.wait(java.base@11.0.10/Native Method) - waiting
> on at
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:69)
> - waiting to re-lock in wait() <0x0006e3bbc420> (a
> org.apache.sshd.common.channel.IoWriteFutureImpl) at
> org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:109)
> at
> org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:39)
> at
> org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:30)
> at
> org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43)
> at
> org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:292)
> at
> org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.flush(SftpOutputStreamAsync.java:210)
> at
> org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.write(SftpOutputStreamAsync.java:141)
> at java.io.InputStream.transferTo(java.base@11.0.10/InputStream.java:705) at
> com.mina.command.Put.replyInto(Put.java:55) at
> com.sftpserver.MinaSftpHandler.channelReadInternal(MinaSftpHandler.java:251)
> at
> com.sftpserver.MinaSftpHandler.lambda$channelRead$0(MinaSftpHandler.java:125)
> at com.sftpserver.MinaSftpHandler$$Lambda$392/0x000800764040.run(Unknown
> Source) at
> java.util.concurrent.Executors$RunnableAdapter.call(java.base@11.0.10/Executors.java:515)
> at
> java.util.concurrent.FutureTask.run(java.base@11.0.10/FutureTask.java:264) at
> java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.10/ThreadPoolExecutor.java:1128)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.10/ThreadPoolExecutor.java:628)
> at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)
> {code}
> Seems like the thread is waiting for lock in
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java),
> I'm currently not sure what thread holds the lock and why it's not ever
> released.
> Also, I'm not able to reproduce this, but it constantly happens to all the
> PUT methods targeting one specific remote server (which I don't own), so I
> suppose there would be something odd with the remote server, but it doesn't
> mean, that we shouldn't be able to deal with that.
> Have you ever seen such behavior? Could it be Mina sshd's bug? (seems like
> verify() in
> org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:292)
> is called without any timeout, which then defaults to LONG.MAX here: at
> org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43),
> shouldn't we have configurable timeout here? or what's the point of default
> timeout? what are we really waiting for in at
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:69)?)
--
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
[jira] [Commented] (SSHD-1173) SFTP worker threads got stuck while processing PUT methods against one specific SFTP server
[
https://issues.apache.org/jira/browse/SSHD-1173?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17614175#comment-17614175
]
Kirk Rasmussen commented on SSHD-1173:
--
One more important detail. If the client session is forcibly closed (I used 2
mins) for being idle it will still deadlock the main thread doing the
stfp.write() operation.
> SFTP worker threads got stuck while processing PUT methods against one
> specific SFTP server
> ---
>
> Key: SSHD-1173
> URL: https://issues.apache.org/jira/browse/SSHD-1173
> Project: MINA SSHD
> Issue Type: Question
>Affects Versions: 2.6.0
>Reporter: Pavel Pohner
>Priority: Critical
> Labels: SFTP, mina, sshd
> Time Spent: 10m
> Remaining Estimate: 0h
>
> Hey guys,
> Recently I've encountered one remote SFTP server, that causes SFTP worker
> threads to enter TIMED_WAITING state, from which they do not recover. Please,
> take a look into this thread dump:
> {code:java}
> SFTP-worker-3 #2155 prio=5 os_prio=0 cpu=61692.09ms elapsed=1136151.86s
> tid=0x7fe41c005800 nid=0x18808 in Object.wait()
> [0x7fe145b1d000]SFTP-worker-3" #2155 prio=5 os_prio=0 cpu=61692.09ms
> elapsed=1136151.86s tid=0x7fe41c005800 nid=0x18808 in Object.wait()
> [0x7fe145b1d000] java.lang.Thread.State: TIMED_WAITING (on object
> monitor) at java.lang.Object.wait(java.base@11.0.10/Native Method) - waiting
> on at
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:69)
> - waiting to re-lock in wait() <0x0006e3bbc420> (a
> org.apache.sshd.common.channel.IoWriteFutureImpl) at
> org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:109)
> at
> org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:39)
> at
> org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:30)
> at
> org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43)
> at
> org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:292)
> at
> org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.flush(SftpOutputStreamAsync.java:210)
> at
> org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.write(SftpOutputStreamAsync.java:141)
> at java.io.InputStream.transferTo(java.base@11.0.10/InputStream.java:705) at
> com.mina.command.Put.replyInto(Put.java:55) at
> com.sftpserver.MinaSftpHandler.channelReadInternal(MinaSftpHandler.java:251)
> at
> com.sftpserver.MinaSftpHandler.lambda$channelRead$0(MinaSftpHandler.java:125)
> at com.sftpserver.MinaSftpHandler$$Lambda$392/0x000800764040.run(Unknown
> Source) at
> java.util.concurrent.Executors$RunnableAdapter.call(java.base@11.0.10/Executors.java:515)
> at
> java.util.concurrent.FutureTask.run(java.base@11.0.10/FutureTask.java:264) at
> java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.10/ThreadPoolExecutor.java:1128)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.10/ThreadPoolExecutor.java:628)
> at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)
> {code}
> Seems like the thread is waiting for lock in
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java),
> I'm currently not sure what thread holds the lock and why it's not ever
> released.
> Also, I'm not able to reproduce this, but it constantly happens to all the
> PUT methods targeting one specific remote server (which I don't own), so I
> suppose there would be something odd with the remote server, but it doesn't
> mean, that we shouldn't be able to deal with that.
> Have you ever seen such behavior? Could it be Mina sshd's bug? (seems like
> verify() in
> org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:292)
> is called without any timeout, which then defaults to LONG.MAX here: at
> org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43),
> shouldn't we have configurable timeout here? or what's the point of default
> timeout? what are we really waiting for in at
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:69)?)
--
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
[jira] [Commented] (SSHD-1173) SFTP worker threads got stuck while processing PUT methods against one specific SFTP server
[
https://issues.apache.org/jira/browse/SSHD-1173?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17614173#comment-17614173
]
Kirk Rasmussen commented on SSHD-1173:
--
Try explaining the above to a customer will be nightmarish.
I strongly urge you to reconsider keeping this option. I will say its an old
unsupported SFTP server (Windows based on the sshlib project I'm guessing based
on server id) but I imagine there's other out there with same problem:
{code:java}
Server Version: SSH-2.0-9.99 sshlib {code}
We don't even have access to latest MOVEIT to confirm if they have fixed it or
not.
> SFTP worker threads got stuck while processing PUT methods against one
> specific SFTP server
> ---
>
> Key: SSHD-1173
> URL: https://issues.apache.org/jira/browse/SSHD-1173
> Project: MINA SSHD
> Issue Type: Question
>Affects Versions: 2.6.0
>Reporter: Pavel Pohner
>Priority: Critical
> Labels: SFTP, mina, sshd
> Time Spent: 10m
> Remaining Estimate: 0h
>
> Hey guys,
> Recently I've encountered one remote SFTP server, that causes SFTP worker
> threads to enter TIMED_WAITING state, from which they do not recover. Please,
> take a look into this thread dump:
> {code:java}
> SFTP-worker-3 #2155 prio=5 os_prio=0 cpu=61692.09ms elapsed=1136151.86s
> tid=0x7fe41c005800 nid=0x18808 in Object.wait()
> [0x7fe145b1d000]SFTP-worker-3" #2155 prio=5 os_prio=0 cpu=61692.09ms
> elapsed=1136151.86s tid=0x7fe41c005800 nid=0x18808 in Object.wait()
> [0x7fe145b1d000] java.lang.Thread.State: TIMED_WAITING (on object
> monitor) at java.lang.Object.wait(java.base@11.0.10/Native Method) - waiting
> on at
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:69)
> - waiting to re-lock in wait() <0x0006e3bbc420> (a
> org.apache.sshd.common.channel.IoWriteFutureImpl) at
> org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:109)
> at
> org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:39)
> at
> org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:30)
> at
> org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43)
> at
> org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:292)
> at
> org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.flush(SftpOutputStreamAsync.java:210)
> at
> org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.write(SftpOutputStreamAsync.java:141)
> at java.io.InputStream.transferTo(java.base@11.0.10/InputStream.java:705) at
> com.mina.command.Put.replyInto(Put.java:55) at
> com.sftpserver.MinaSftpHandler.channelReadInternal(MinaSftpHandler.java:251)
> at
> com.sftpserver.MinaSftpHandler.lambda$channelRead$0(MinaSftpHandler.java:125)
> at com.sftpserver.MinaSftpHandler$$Lambda$392/0x000800764040.run(Unknown
> Source) at
> java.util.concurrent.Executors$RunnableAdapter.call(java.base@11.0.10/Executors.java:515)
> at
> java.util.concurrent.FutureTask.run(java.base@11.0.10/FutureTask.java:264) at
> java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.10/ThreadPoolExecutor.java:1128)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.10/ThreadPoolExecutor.java:628)
> at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)
> {code}
> Seems like the thread is waiting for lock in
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java),
> I'm currently not sure what thread holds the lock and why it's not ever
> released.
> Also, I'm not able to reproduce this, but it constantly happens to all the
> PUT methods targeting one specific remote server (which I don't own), so I
> suppose there would be something odd with the remote server, but it doesn't
> mean, that we shouldn't be able to deal with that.
> Have you ever seen such behavior? Could it be Mina sshd's bug? (seems like
> verify() in
> org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:292)
> is called without any timeout, which then defaults to LONG.MAX here: at
> org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43),
> shouldn't we have configurable timeout here? or what's the point of default
> timeout? what are we really waiting for in at
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:69)?)
--
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
[jira] [Commented] (SSHD-1173) SFTP worker threads got stuck while processing PUT methods against one specific SFTP server
[
https://issues.apache.org/jira/browse/SSHD-1173?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17613818#comment-17613818
]
Kirk Rasmussen commented on SSHD-1173:
--
Adding this to my sshClient instance fixed it for me.
{code:java}
SftpModuleProperties.CHUNK_IF_WINDOW_LESS_THAN_PACKET.set(sshClient, true);
{code}
alternatively can use System property:
{code:java}
org.apache.sshd.config.sftp-chunk-if-window-less-than-packet=true {code}
This issue is referenced here as a server client compatibility problem but it
applies equally to client as well: [SSHD-1123] ChannelAsyncOutputStream breaks
downloads of sftp client by not chunking when the remote window is smaller than
the packet size - ASF JIRA (apache.org)
> SFTP worker threads got stuck while processing PUT methods against one
> specific SFTP server
> ---
>
> Key: SSHD-1173
> URL: https://issues.apache.org/jira/browse/SSHD-1173
> Project: MINA SSHD
> Issue Type: Question
>Affects Versions: 2.6.0
>Reporter: Pavel Pohner
>Priority: Critical
> Labels: SFTP, mina, sshd
>
> Hey guys,
> Recently I've encountered one remote SFTP server, that causes SFTP worker
> threads to enter TIMED_WAITING state, from which they do not recover. Please,
> take a look into this thread dump:
> {code:java}
> SFTP-worker-3 #2155 prio=5 os_prio=0 cpu=61692.09ms elapsed=1136151.86s
> tid=0x7fe41c005800 nid=0x18808 in Object.wait()
> [0x7fe145b1d000]SFTP-worker-3" #2155 prio=5 os_prio=0 cpu=61692.09ms
> elapsed=1136151.86s tid=0x7fe41c005800 nid=0x18808 in Object.wait()
> [0x7fe145b1d000] java.lang.Thread.State: TIMED_WAITING (on object
> monitor) at java.lang.Object.wait(java.base@11.0.10/Native Method) - waiting
> on at
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:69)
> - waiting to re-lock in wait() <0x0006e3bbc420> (a
> org.apache.sshd.common.channel.IoWriteFutureImpl) at
> org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:109)
> at
> org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:39)
> at
> org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:30)
> at
> org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43)
> at
> org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:292)
> at
> org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.flush(SftpOutputStreamAsync.java:210)
> at
> org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.write(SftpOutputStreamAsync.java:141)
> at java.io.InputStream.transferTo(java.base@11.0.10/InputStream.java:705) at
> com.mina.command.Put.replyInto(Put.java:55) at
> com.sftpserver.MinaSftpHandler.channelReadInternal(MinaSftpHandler.java:251)
> at
> com.sftpserver.MinaSftpHandler.lambda$channelRead$0(MinaSftpHandler.java:125)
> at com.sftpserver.MinaSftpHandler$$Lambda$392/0x000800764040.run(Unknown
> Source) at
> java.util.concurrent.Executors$RunnableAdapter.call(java.base@11.0.10/Executors.java:515)
> at
> java.util.concurrent.FutureTask.run(java.base@11.0.10/FutureTask.java:264) at
> java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.10/ThreadPoolExecutor.java:1128)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.10/ThreadPoolExecutor.java:628)
> at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)
> {code}
> Seems like the thread is waiting for lock in
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java),
> I'm currently not sure what thread holds the lock and why it's not ever
> released.
> Also, I'm not able to reproduce this, but it constantly happens to all the
> PUT methods targeting one specific remote server (which I don't own), so I
> suppose there would be something odd with the remote server, but it doesn't
> mean, that we shouldn't be able to deal with that.
> Have you ever seen such behavior? Could it be Mina sshd's bug? (seems like
> verify() in
> org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:292)
> is called without any timeout, which then defaults to LONG.MAX here: at
> org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43),
> shouldn't we have configurable timeout here? or what's the point of default
> timeout? what are we really waiting for in at
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:69)?)
--
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
[jira] [Comment Edited] (SSHD-1173) SFTP worker threads got stuck while processing PUT methods against one specific SFTP server
[
https://issues.apache.org/jira/browse/SSHD-1173?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=17613590#comment-17613590
]
Kirk Rasmussen edited comment on SSHD-1173 at 10/6/22 3:08 PM:
---
I believe I may have also run into this running against MOVEIT transfer 2018
SP1 where transfers (11MB) are hanging in the same way as described above.
I've seen other areas where MOVEIT is buggy (e.g. canonicalPath("foo/bar.txt)
for a relative file) doesn't resolve correctly but directories do).
was (Author: JIRAUSER296597):
I believe I may have also run into this running against MOVEIT transfer 2018
SP1 where transfers (11MB) are hanging in the same way as described above.
> SFTP worker threads got stuck while processing PUT methods against one
> specific SFTP server
> ---
>
> Key: SSHD-1173
> URL: https://issues.apache.org/jira/browse/SSHD-1173
> Project: MINA SSHD
> Issue Type: Question
>Affects Versions: 2.6.0
>Reporter: Pavel Pohner
>Priority: Critical
> Labels: SFTP, mina, sshd
>
> Hey guys,
> Recently I've encountered one remote SFTP server, that causes SFTP worker
> threads to enter TIMED_WAITING state, from which they do not recover. Please,
> take a look into this thread dump:
> {code:java}
> SFTP-worker-3 #2155 prio=5 os_prio=0 cpu=61692.09ms elapsed=1136151.86s
> tid=0x7fe41c005800 nid=0x18808 in Object.wait()
> [0x7fe145b1d000]SFTP-worker-3" #2155 prio=5 os_prio=0 cpu=61692.09ms
> elapsed=1136151.86s tid=0x7fe41c005800 nid=0x18808 in Object.wait()
> [0x7fe145b1d000] java.lang.Thread.State: TIMED_WAITING (on object
> monitor) at java.lang.Object.wait(java.base@11.0.10/Native Method) - waiting
> on at
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:69)
> - waiting to re-lock in wait() <0x0006e3bbc420> (a
> org.apache.sshd.common.channel.IoWriteFutureImpl) at
> org.apache.sshd.common.future.AbstractSshFuture.verifyResult(AbstractSshFuture.java:109)
> at
> org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:39)
> at
> org.apache.sshd.common.io.AbstractIoWriteFuture.verify(AbstractIoWriteFuture.java:30)
> at
> org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43)
> at
> org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:292)
> at
> org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.flush(SftpOutputStreamAsync.java:210)
> at
> org.apache.sshd.sftp.client.impl.SftpOutputStreamAsync.write(SftpOutputStreamAsync.java:141)
> at java.io.InputStream.transferTo(java.base@11.0.10/InputStream.java:705) at
> com.mina.command.Put.replyInto(Put.java:55) at
> com.sftpserver.MinaSftpHandler.channelReadInternal(MinaSftpHandler.java:251)
> at
> com.sftpserver.MinaSftpHandler.lambda$channelRead$0(MinaSftpHandler.java:125)
> at com.sftpserver.MinaSftpHandler$$Lambda$392/0x000800764040.run(Unknown
> Source) at
> java.util.concurrent.Executors$RunnableAdapter.call(java.base@11.0.10/Executors.java:515)
> at
> java.util.concurrent.FutureTask.run(java.base@11.0.10/FutureTask.java:264) at
> java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.10/ThreadPoolExecutor.java:1128)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.10/ThreadPoolExecutor.java:628)
> at java.lang.Thread.run(java.base@11.0.10/Thread.java:834)
> {code}
> Seems like the thread is waiting for lock in
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java),
> I'm currently not sure what thread holds the lock and why it's not ever
> released.
> Also, I'm not able to reproduce this, but it constantly happens to all the
> PUT methods targeting one specific remote server (which I don't own), so I
> suppose there would be something odd with the remote server, but it doesn't
> mean, that we shouldn't be able to deal with that.
> Have you ever seen such behavior? Could it be Mina sshd's bug? (seems like
> verify() in
> org.apache.sshd.sftp.client.impl.DefaultSftpClient.send(DefaultSftpClient.java:292)
> is called without any timeout, which then defaults to LONG.MAX here: at
> org.apache.sshd.common.future.VerifiableFuture.verify(VerifiableFuture.java:43),
> shouldn't we have configurable timeout here? or what's the point of default
> timeout? what are we really waiting for in at
> org.apache.sshd.common.future.DefaultSshFuture.await0(DefaultSshFuture.java:69)?)
--
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
