Skip to content

I/O dropping to zero for file transfers #8618

Closed
Bug
Closed
I/O dropping to zero for file transfers#8618
Bug
Assignees
dkocher
Labels
high prioritysftpSFTP Protocol Implementation
Milestone
4.7

Description

@cyberduck
cyberduck
opened on Feb 27, 2015

79644cb created the issue

I have a strange issue:

Upload to a SFTP-Server stops transferring after 60 seconds. Without any error message. Just IO dropping to zero.
Testing with FileZilla with the same server same login credentials same OS same files has no issues.

Attachments

Activity

  1. cyberduck commented on Feb 27, 2015

    @cyberduck
    cyberduck
    on Feb 27, 2015
    ContributorAuthor

    79644cb commented

    Cyberduck CLI shows the same behaviour.
    Successful connection successful start of transfer with subsequent stall until local timeout.

  2. cyberduck commented on Mar 3, 2015

    @cyberduck
    cyberduck
    on Mar 3, 2015
    ContributorAuthor

    0d52d7f commented

    Same issue also with ftp,
    I can connect to every FTP server just fine, however being inactive for X amount of minutes causes me to be unable to save an open document on the server because the connection has been lost. I tried to change my code editor, backets sublime text, coda, nothing changes.
    Trying with Filezilla, the problem does not appear.
    The workaround is to go back to my bookmarks page and navigate the filesystem and reopen the document for editing. This is very constraining

    I'm using Cyberduck 4.6.5 (17000)

  3. cyberduck commented on Mar 31, 2015

    @cyberduck
    cyberduck
    on Mar 31, 2015
    ContributorAuthor

    @dkocher commented

    #8699 closed as duplicate.

  4. cyberduck commented on Mar 31, 2015

    @cyberduck
    cyberduck
    on Mar 31, 2015
    ContributorAuthor

    @dkocher commented

    #8710 closed as duplicate.

  5. cyberduck commented on Apr 17, 2015

    @cyberduck
    cyberduck
    on Apr 17, 2015
    ContributorAuthor

    @dkocher commented

    Please update to the latest snapshot build available and report if the issue persists.

  6. cyberduck commented on Apr 17, 2015

    @cyberduck
    cyberduck
    on Apr 17, 2015
    ContributorAuthor

    79644cb commented

    tested with Version 4.7 (17316) still persists for me.

  7. cyberduck commented on Apr 17, 2015

    @cyberduck
    cyberduck
    on Apr 17, 2015
    ContributorAuthor

    @dkocher commented

    Replying to [comment:9 shorshe]:

    tested with Version 4.7 (17316) still persists for me.
    Is it possible to get a test account on this server?

  8. cyberduck commented on Apr 17, 2015

    @cyberduck
    cyberduck
    on Apr 17, 2015
    ContributorAuthor

    79644cb commented

    I'll ask the admin on monday.

    Is there any info/log I could give you in the meantime?

  9. cyberduck commented on Apr 17, 2015

    @cyberduck
    cyberduck
    on Apr 17, 2015
    ContributorAuthor

    @dkocher commented

    Replying to [comment:12 shorshe]:

    I'll ask the admin on monday.

    Is there any info/log I could give you in the meantime?
    Would a remote session to my machine help?

    It would help if you can run Cyberduck CLI with logging enabled and attach the output.

    env "logging=debug" duck --upload …

  10. cyberduck commented on Apr 17, 2015

    @cyberduck
    cyberduck
    on Apr 17, 2015
    ContributorAuthor

    79644cb commented

    ok here you go (just the interesting part at the end - Full logfile as attachment above):

    2015-04-17 21:48:14,939 [background-1] DEBUG net.schmizz.sshj.connection.channel.Window$Remote - Consuming by 184 down to 98258
2015-04-17 21:48:14,940 [background-1] INFO  ch.cyberduck.core.Session - 228 WRITE
2015-04-17 21:48:14,940 [background-1] DEBUG ch.cyberduck.core.sftp.SFTPSession$4 - Sending Request{228;WRITE}
2015-04-17 21:48:14,942 [background-1] DEBUG net.schmizz.sshj.connection.channel.Window$Remote - Consuming by 32814 down to 65444
2015-04-17 21:48:14,942 [background-1] INFO  ch.cyberduck.core.Session - 229 WRITE
2015-04-17 21:48:14,942 [background-1] DEBUG ch.cyberduck.core.sftp.SFTPSession$4 - Sending Request{229;WRITE}
2015-04-17 21:48:14,944 [background-1] DEBUG net.schmizz.sshj.connection.channel.Window$Remote - Consuming by 32814 down to 32630
2015-04-17 21:48:14,945 [background-1] INFO  ch.cyberduck.core.Session - 230 WRITE
2015-04-17 21:48:14,945 [background-1] DEBUG ch.cyberduck.core.sftp.SFTPSession$4 - Sending Request{230;WRITE}
2015-04-17 21:48:14,946 [background-1] DEBUG net.schmizz.sshj.connection.channel.Window$Remote - Consuming by 32630 down to 0
2015-04-17 21:48:14,946 [background-1] DEBUG net.schmizz.sshj.connection.channel.Window$Remote - Waiting, need size to grow from 0 bytes
2015-04-17 21:48:15,141 [reader] DEBUG net.schmizz.sshj.connection.channel.Window$Local - Consuming by 53 down to 2085173
2015-04-17 21:48:15,141 [sftp reader] DEBUG net.schmizz.sshj.sftp.PacketReader - Received STATUS packet
2015-04-17 21:48:15,141 [sftp reader] DEBUG net.schmizz.concurrent.Promise - Setting <<sftp / 227>> to `Buffer [rpos=5, wpos=49, size=49]`
2015-04-17 21:48:15,732 [reader] DEBUG net.schmizz.sshj.connection.channel.Window$Local - Consuming by 53 down to 2085120
2015-04-17 21:48:15,732 [sftp reader] DEBUG net.schmizz.sshj.sftp.PacketReader - Received STATUS packet
2015-04-17 21:48:15,732 [sftp reader] DEBUG net.schmizz.concurrent.Promise - Setting <<sftp / 228>> to `Buffer [rpos=5, wpos=49, size=49]`
2015-04-17 21:48:15,784 [reader] DEBUG net.schmizz.sshj.connection.channel.Window$Local - Consuming by 53 down to 2085067
2015-04-17 21:48:15,785 [sftp reader] DEBUG net.schmizz.sshj.sftp.PacketReader - Received STATUS packet
2015-04-17 21:48:15,785 [sftp reader] DEBUG net.schmizz.concurrent.Promise - Setting <<sftp / 229>> to `Buffer [rpos=5, wpos=49, size=49]`
2015-04-17 21:48:15,785 [reader] DEBUG net.schmizz.sshj.connection.channel.direct.SessionChannel - Received window adjustment for 98442 bytes
2015-04-17 21:48:15,785 [reader] DEBUG net.schmizz.sshj.connection.channel.Window$Remote - Increasing by 98442 up to 98442
2015-04-17 21:48:15,785 [background-1] DEBUG net.schmizz.sshj.connection.channel.Window$Remote - Consuming by 184 down to 98258
2015-04-17 21:48:15,785 [background-1] INFO  ch.cyberduck.core.Session - 231 WRITE
2015-04-17 21:48:15,785 [background-1] DEBUG ch.cyberduck.core.sftp.SFTPSession$4 - Sending Request{231;WRITE}
2015-04-17 21:48:15,787 [background-1] DEBUG net.schmizz.sshj.connection.channel.Window$Remote - Consuming by 32814 down to 65444
2015-04-17 21:48:15,788 [background-1] INFO  ch.cyberduck.core.Session - 232 WRITE
2015-04-17 21:48:15,788 [background-1] DEBUG ch.cyberduck.core.sftp.SFTPSession$4 - Sending Request{232;WRITE}
2015-04-17 21:48:15,789 [background-1] DEBUG net.schmizz.sshj.connection.channel.Window$Remote - Consuming by 32814 down to 32630
2015-04-17 21:48:15,790 [background-1] INFO  ch.cyberduck.core.Session - 233 WRITE
2015-04-17 21:48:15,790 [background-1] DEBUG ch.cyberduck.core.sftp.SFTPSession$4 - Sending Request{233;WRITE}
2015-04-17 21:48:15,792 [background-1] DEBUG net.schmizz.sshj.connection.channel.Window$Remote - Consuming by 32630 down to 0
2015-04-17 21:48:15,792 [background-1] DEBUG net.schmizz.sshj.connection.channel.Window$Remote - Waiting, need size to grow from 0 bytes
2015-04-17 21:48:15,899 [reader] DEBUG net.schmizz.sshj.connection.channel.Window$Local - Consuming by 53 down to 2085014
2015-04-17 21:48:15,900 [sftp reader] DEBUG net.schmizz.sshj.sftp.PacketReader - Received STATUS packet
2015-04-17 21:48:15,900 [sftp reader] DEBUG net.schmizz.concurrent.Promise - Setting <<sftp / 230>> to `Buffer [rpos=5, wpos=49, size=49]`
2015-04-17 21:48:16,167 [reader] DEBUG net.schmizz.sshj.connection.channel.Window$Local - Consuming by 53 down to 2084961
2015-04-17 21:48:16,167 [sftp reader] DEBUG net.schmizz.sshj.sftp.PacketReader - Received STATUS packet
2015-04-17 21:48:16,167 [sftp reader] DEBUG net.schmizz.concurrent.Promise - Setting <<sftp / 231>> to `Buffer [rpos=5, wpos=49, size=49]`
2015-04-17 21:48:16,502 [reader] DEBUG net.schmizz.sshj.connection.channel.Window$Local - Consuming by 53 down to 2084908
2015-04-17 21:48:16,502 [sftp reader] DEBUG net.schmizz.sshj.sftp.PacketReader - Received STATUS packet
2015-04-17 21:48:16,502 [reader] DEBUG net.schmizz.sshj.connection.channel.direct.SessionChannel - Received window adjustment for 98442 bytes
2015-04-17 21:48:16,502 [reader] DEBUG net.schmizz.sshj.connection.channel.Window$Remote - Increasing by 98442 up to 98442
2015-04-17 21:48:16,502 [sftp reader] DEBUG net.schmizz.concurrent.Promise - Setting <<sftp / 232>> to `Buffer [rpos=5, wpos=49, size=49]`
2015-04-17 21:48:16,503 [background-1] DEBUG net.schmizz.sshj.connection.channel.Window$Remote - Consuming by 184 down to 98258
2015-04-17 21:48:16,503 [background-1] INFO  ch.cyberduck.core.Session - 234 WRITE
2015-04-17 21:48:16,503 [background-1] DEBUG ch.cyberduck.core.sftp.SFTPSession$4 - Sending Request{234;WRITE}
2015-04-17 21:48:16,505 [background-1] DEBUG net.schmizz.sshj.connection.channel.Window$Remote - Consuming by 32814 down to 65444
2015-04-17 21:48:16,505 [background-1] INFO  ch.cyberduck.core.Session - 235 WRITE
2015-04-17 21:48:16,505 [background-1] DEBUG ch.cyberduck.core.sftp.SFTPSession$4 - Sending Request{235;WRITE}
2015-04-17 21:48:16,507 [background-1] DEBUG net.schmizz.sshj.connection.channel.Window$Remote - Consuming by 32814 down to 32630
2015-04-17 21:48:16,507 [background-1] INFO  ch.cyberduck.core.Session - 236 WRITE
2015-04-17 21:48:16,507 [background-1] DEBUG ch.cyberduck.core.sftp.SFTPSession$4 - Sending Request{236;WRITE}
2015-04-17 21:48:16,509 [background-1] DEBUG net.schmizz.sshj.connection.channel.Window$Remote - Consuming by 32630 down to 0
2015-04-17 21:48:16,509 [background-1] DEBUG net.schmizz.sshj.connection.channel.Window$Remote - Waiting, need size to grow from 0 bytes
2015-04-17 21:48:16,660 [reader] DEBUG net.schmizz.sshj.connection.channel.Window$Local - Consuming by 53 down to 2084855
2015-04-17 21:48:16,660 [sftp reader] DEBUG net.schmizz.sshj.sftp.PacketReader - Received STATUS packet
2015-04-17 21:48:16,660 [sftp reader] DEBUG net.schmizz.concurrent.Promise - Setting <<sftp / 233>> to `Buffer [rpos=5, wpos=49, size=49]`
2015-04-17 21:48:17,015 [reader] DEBUG net.schmizz.sshj.connection.channel.Window$Local - Consuming by 53 down to 2084802
2015-04-17 21:48:17,015 [sftp reader] DEBUG net.schmizz.sshj.sftp.PacketReader - Received STATUS packet
2015-04-17 21:48:17,015 [sftp reader] DEBUG net.schmizz.concurrent.Promise - Setting <<sftp / 234>> to `Buffer [rpos=5, wpos=49, size=49]`
2015-04-17 21:48:17,134 [keep-alive] DEBUG net.schmizz.keepalive.KeepAliveRunner - Sending keep-alive since 10 seconds elapsed
2015-04-17 21:48:17,134 [keep-alive] ERROR net.schmizz.sshj.transport.TransportImpl - Dying because - {}

net.schmizz.sshj.connection.ConnectionException: [CONNECTION_LOST] Did not receive any keep-alive response for 50 seconds
	at net.schmizz.keepalive.KeepAliveRunner.checkMaxReached(KeepAliveRunner.java:63)
	at net.schmizz.keepalive.KeepAliveRunner.doKeepAlive(KeepAliveRunner.java:56)
	at net.schmizz.keepalive.KeepAlive.run(KeepAlive.java:64)
2015-04-17 21:48:17,135 [keep-alive] WARN  ch.cyberduck.core.sftp.SFTPSession - Disconnected CONNECTION_LOST
2015-04-17 21:48:17,136 [keep-alive] DEBUG net.schmizz.sshj.transport.KeyExchanger - Got notified of net.schmizz.sshj.connection.ConnectionException: [CONNECTION_LOST] Did not receive any keep-alive response for 50 seconds
2015-04-17 21:48:17,136 [keep-alive] DEBUG net.schmizz.sshj.connection.ConnectionImpl - Notified of net.schmizz.sshj.connection.ConnectionException: [CONNECTION_LOST] Did not receive any keep-alive response for 50 seconds

  11. cyberduck commented on Apr 17, 2015

    @cyberduck
    cyberduck
    on Apr 17, 2015
    ContributorAuthor

    @dkocher commented

    Thanks for posting the transcript. I suspect there might be an interoperability issue with the SSH serverwith the heartbeat packets sent. Can you try with

    env "ssh.heartbeat.seconds=0" duck …

  12. cyberduck commented on Apr 17, 2015

    @cyberduck
    cyberduck
    on Apr 17, 2015
    ContributorAuthor

    79644cb commented

    Seems to work fine. I'm well beyond the 50 sec mark and still going.

    I think you found the reason!
    Upload still alive after 10 minutes bandwidth fluctuation in normal range.

    FYI: older Versions of Cyberduck could work with this server.

  13. cyberduck commented on Apr 17, 2015

    @cyberduck
    cyberduck
    on Apr 17, 2015
    ContributorAuthor

    @dkocher commented

    Replying to [comment:16 shorshe]:

    FYI: older Versions of Cyberduck could work with this server.

    The sending of keep alive packages was introduced in 2cfb268.

  14. cyberduck commented on Apr 17, 2015

    @cyberduck
    cyberduck
    on Apr 17, 2015
    ContributorAuthor

    @dkocher commented

    In fb84b56.

  15. cyberduck
    closed this as completedon Apr 17, 2015

  16. cyberduck commented on Apr 18, 2015

    @cyberduck
    cyberduck
    on Apr 18, 2015
    ContributorAuthor

    79644cb commented

    That's great news!!
    Thanks a lot!

  17. cyberduck
    assigned
    dkocher
    on Nov 26, 2021
  18. iterate-ch
    locked as resolved and limited conversation to collaborators on Nov 26, 2021
  19. dkocher
    removed
    bug
    on Sep 1, 2025
  20. dkocher
    added the
    Bug
    issue type on Sep 1, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

high prioritysftpSFTP Protocol Implementation

Type

Bug

Projects

No projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions