[Cyberduck-trac] [Cyberduck] #8618: I/O dropping to zero for file transfers

Cyberduck trac at trac.cyberduck.io
Fri Apr 17 19:51:51 UTC 2015 

#8618: I/O dropping to zero for file transfers
----------------------------+-------------------------
 Reporter:  shorshe         |         Owner:  dkocher
     Type:  defect          |        Status:  reopened
 Priority:  high            |     Milestone:  4.7
Component:  sftp            |       Version:  4.6.5
 Severity:  normal          |    Resolution:
 Keywords:                  |  Architecture:  Intel
 Platform:  Mac OS X 10.10  |
----------------------------+-------------------------

Comment (by shorshe):

 ok here you go (just the interesting part at the end):

 {{{
 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
 }}}

-- 
Ticket URL: <https://trac.cyberduck.io/ticket/8618#comment:14>
Cyberduck <https://cyberduck.io>
Libre FTP, SFTP, WebDAV, S3 & OpenStack Swift browser for Mac and Windows

More information about the Cyberduck-trac mailing list