Skip to content

Slowness in 0.32.1-SNAPSHOT compared to 0.32.0 release #777

@brenttyler

Description

@brenttyler

In testing my recent Pull Request #775 for Issue #700, I came across some weird slowness compared to the old v0.23 jar we had been using for years. Pulling my hair out thinking it was something I had done, I decided to directly compare the official 0.32.0 release and the 0.32.1-SNAPSHOT (as it is today). Here are my sample code and findings:

 public void execute(String host, int port, String user, String pass, File file) throws Throwable { try (SSHClient ssh = new SSHClient()) { ssh.addHostKeyVerifier(new PromiscuousVerifier()); ssh.connect(host, port); ssh.authPassword(user, pass); try (SFTPClient sftp = ssh.newSFTPClient()) { final long startTime = System.nanoTime(); sftp.get(file.getName(), file.getName()); final double timeSeconds = TimeUnit.NANOSECONDS.toMillis (System.nanoTime() - startTime) / 1000.0; final double sizeKiB = file.length() / 1024.0; log.info(String.format("%1$,.1f KiB transferred in %2$,.1f seconds (%3$,.2f KiB/s)", sizeKiB, timeSeconds, (sizeKiB / timeSeconds))); } } } 

I have logback set to info for this, hence the copied log.info() from StringCopier.copy(). Here are the results:

sshj-0.32.0.jar:
18:41:04 [main] INFO n.s.sshj.transport.random.JCERandom - Creating new SecureRandom.
18:41:04 [main] INFO n.s.sshj.transport.TransportImpl - Client identity string: SSH-2.0-SSHJ_0.32.0
18:41:04 [main] INFO n.s.sshj.transport.TransportImpl - Server identity string: SSH-2.0-OpenSSH_7.2p2 Ubuntu-4ubuntu2.10
18:41:05 [main] INFO n.s.s.c.c.direct.SessionChannel - Will request sftp subsystem
18:49:05 [main] WARN net.schmizz.sshj.xfer.FileSystemFile - Could not set permissions for <file> to 1b0
18:49:05 [main] INFO sshj.resume.test2.SlownessTest - 11,161,746.5 KiB transferred in 480.8 seconds (23,215.57 KiB/s)
18:49:05 [main] INFO n.s.sshj.transport.TransportImpl - Disconnected - BY_APPLICATION

sshj-0.32.1-SNAPSHOT.jar:
18:49:42 [main] INFO n.s.sshj.transport.random.JCERandom - Creating new SecureRandom.
18:49:42 [main] INFO n.s.sshj.transport.TransportImpl - Client identity string: SSH-2.0-SSHJ_0.32.1_SNAPSHOT
18:49:42 [main] INFO n.s.sshj.transport.TransportImpl - Server identity string: SSH-2.0-OpenSSH_7.2p2 Ubuntu-4ubuntu2.10
18:49:43 [main] INFO n.s.s.c.c.direct.SessionChannel - Will request sftp subsystem
21:03:35 [main] WARN net.schmizz.sshj.xfer.FileSystemFile - Could not set permissions for <file> to 1b0
21:03:35 [main] INFO sshj.resume.test2.SlownessTest - 11,161,746.5 KiB transferred in 8,032.3 seconds (1,389.61 KiB/s)
21:03:35 [main] INFO n.s.sshj.transport.TransportImpl - Disconnected - BY_APPLICATION

This was done without compression as well. As you can see, 0.32.1-SNAPSHOT is slower by a factor of 16.7x. I am not familiar enough with the code base or the technology behind it to have a valid opinion on what is going on, but I figured it was worth pointing out to someone who might.

I have since replicated my #775 changes on a branch from the 0.32.0 tag and validated that it works as expected. The only difference between my two almost-identical branches is that against 0.32.0 I didn't need to modify RemoteFile.ReadAheadRemoteFileInputStream to add a (int, long) constructor which, under 0.32.1-SNAPSHOT, merely passed-through to the (int, long, long) constructor because in 0.32.0 it was already there. (apologies for the very confusing sentence, but I'm trying to be detailed here as I don't 100% know what I'm talking about).

It might be worth looking at recent changes to RemoteFile.ReadAheadRemoteFileInputStream, but that's just a complete guess merely based on my two branches.

You can see these at my fork https://github.com/brenttyler/sshj on the issue-700 branch (#775) and the 0.32.0-issue-700 branches (no Pull Request).

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions