baiglin commented on issue #904:
URL: https://github.com/apache/mina-sshd/issues/904#issuecomment-4876586799
Hi @tomaswolf here is what we have done to try to demonstrate server is the
culprit:
`ublic class SftpClient extends DefaultSftpClient {
/**
* @param clientSession
* The {@link ClientSession}
* @param initialVersionSelector
* The initial {@link SftpVersionSelector} - if {@code null} then
version 6 is assumed.
* @param errorDataHandler
* The {@link SftpErrorDataHandler} to handle incoming data
through the error stream - if {@code null} the
* data is silently ignored
* @throws IOException
* If failed to initialize
*/
public SftpClient(ClientSession clientSession,
SftpVersionSelector initialVersionSelector,
SftpErrorDataHandler errorDataHandler) throws IOException {
super(clientSession, initialVersionSelector, errorDataHandler);
}
/**
* {@inheritDoc
*/
@Override
public SftpMessage write(int cmd, Buffer buffer) throws IOException {
return new InternalSftpMessage(super.write(cmd, buffer));
}
class InternalSftpMessage extends SftpMessage {
public InternalSftpMessage(SftpMessage sftpMessage) {
super(sftpMessage.getId(), sftpMessage.getFuture(),
sftpMessage.getTimeout());
}
@Override
public void waitUntilSent() throws IOException {
long time = System.currentTimeMillis();
super.waitUntilSent();
// Compute the wait time and update statistics
long waitTime = System.currentTimeMillis() - time;
// UPdatae the stat objects created in the channel listener
SftpClient.this.getChannel()
.getAttribute(ChannelMonitorListener.CHANNEL_STATS_ATTRIBUTE_KEY)
.getMessageWaitTime()
.add(waitTime);
}`
`
@Slf4j
public class ChannelMonitorListener implements ChannelListener {
// Default SSH channel window size (2,097,152 bytes)
CoreModuleProperties.DEFAULT_WINDOW_SIZE
// Threshold: warn if server assigns less than 1MB (indicating
rate-limiting)
private static final long WINDOW_SIZE_WARNING_THRESHOLD = 1_048_576L;
/**
* SSH_MSG_CHANNEL_WINDOW_ADJUST is a constant representing the SSH
message type for channel window adjustment events.
*/
public static final String SSH_MSG_CHANNEL_WINDOW_ADJUST =
"SSH_MSG_CHANNEL_WINDOW_ADJUST";
/**
* Attribute to store channel stats
*/
public static final AttributeRepository.AttributeKey<ChannelStats>
CHANNEL_STATS_ATTRIBUTE_KEY =
new AttributeRepository.AttributeKey<>();
@Override
public void channelInitialized(Channel channel) {
SessionMdcPropagator.extractMdcContextToChannel(channel);
LOG.info("Channel 'id={}' initialized from session localAddress={},
remoteAddress={}", channel.getChannelId(),
channel.getSession().getLocalAddress(),
channel.getSession().getRemoteAddress());
// Create channel stats object
channel.setAttribute(CHANNEL_STATS_ATTRIBUTE_KEY, new ChannelStats());
}
@Override
public void channelOpenSuccess(Channel channel) {
try {
SessionMdcPropagator.propagateMdcContextFromAttributes(channel);
channel.getAttribute(CHANNEL_STATS_ATTRIBUTE_KEY).updateStats(channel);
} finally {
SessionMdcPropagator.clear(channel);
}
}
`
In the end to compute stats as channel closed:
Channel 'id=0' closed from session localAddress=/xx.xx.xx.xx.xx:58352,
remoteAddress=/xx.xx.xx.xx:22 after 6043518 ms (6043.518 s.). Reason: Normal
closure.
Round Trip Time (RTT): 642 ms
Packet Size: local size=32768 bytes, remote size=32768 bytes
Number of transfers on this channel: 1
Sftp Message Wait time statistics: average size=1343.6645089285723 ms, max
size=16281.0 ms, min size=0.0 ms, deviation=2760.3744373805444 ms, count=4480
Local Window statistics: average size=2055742.5244444483 bytes, max
size=2097152.0 bytes, min size=1998884.0 bytes, deviation=29255.405394112648
bytes, count=1125
Remote Window statistics: average size=1672537.548444444 bytes, max
size=2097152.0 bytes, min size=98289.0 bytes, deviation=409827.6400159729
bytes, count=1125
Elapsed time between window adjust statistics: average
time=5371.843555555543 ms, max time=15737.0 ms, min time=0.0 ms,
deviation=2910.765478314483 ms, count=1125
Number of time remote window size was 0: 0
In normal time we see Sftp Message Wait time statistics: average size=0.25
ms, max size=1.0 ms, min size=0.0 ms, deviation=0.4330127018922193 ms, count=4
I wanted to confirm that the only possibility to wait during the upload in
the `waitUntilSent` method is when we are waiting for window expansion ...
Because normally the IOFuture should return as soon as write operation is done.
When I check the code SftpOutputStreamAsinc#internalFlush -> client.write()
-> ChannelAsyncOutputStream#writeBuffer ->
ChannelAsyncOutputStream#doWriteIfPossible ->
ChannelAsyncOutputStream#writePacket that return the future without doin this,
while if possible it should perform the write and return null.
So this should completely confirm the culprit is server is lon to read and
sends WINDOW ADJUST
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
