search

liximomo / vscode-sftp

Super fast sftp/ftp extension for VS Code
MIT License
1.5k stars 260 forks source link

Uploading the active file occasionally fails silently #735

Open dumb opened 4 years ago

dumb commented 4 years ago

Do you read the FAQ?

Describe the bug Uploading the active file will occasionally fail silently, without providing any feedback via the UI or output log.

Although it's possible that the network connection has been interrupted, unfortunately vscode-sftp doesn't provide any insight into what went wrong, or even indicate that there was an error in the first place.

To Reproduce Steps to reproduce the behavior:

  1. Configure SFTP with the following sftp.json (identifiable data removed): 
    {
"name": "example.com",
"host": "example.com",
"protocol": "sftp",
"port": 22,
"username": "example_username",
"remotePath": "/var/www/example.com/html/",
"uploadOnSave": false,
"privateKeyPath": "/Users/me/id_rsa"
}
  2. Run command 'Upload Active File', either via Command Palette or keyboard shortcut
  3. SFTP text on status bar blinks momentarily, then reverts to SFTP
  4. No error message is presented, and the file is not sent to the server

Expected behavior

  1. Run command 'Upload Active File', either via Command Palette or keyboard shortcut
  2. On a successful upload
    1. SFTP text on status bar should show local ➞ remote example.ts and then done example.ts
    2. New/updated file is on server
  3. On a failed upload
    1. SFTP text on status bar should indicate an error occurred
    2. A notification with error details should appear

Desktop

Extension Logs from Startup - required

Below are examples of a successful and failed upload attempt (identifiable data removed).

A successful upload attempt:

[03-03 11:16:16] [trace] run command 'Upload Active File'
[03-03 11:16:16] [trace] handle upload file for /folder/example.ts
[03-03 11:16:16] [debug] Outgoing: Writing MKDIR
[03-03 11:16:16] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:16:16] [debug] Outgoing: Writing LSTAT
[03-03 11:16:16] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:16:16] [debug] Outgoing: Writing OPEN
[03-03 11:16:16] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:16:16] [debug] Outgoing: Writing FSTAT
[03-03 11:16:16] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:16:16] [debug] Outgoing: Writing FSETSTAT
[03-03 11:16:16] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:16:16] [debug] Outgoing: Writing WRITE
[03-03 11:16:16] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:16:16] [debug] Outgoing: Writing FSETSTAT
[03-03 11:16:16] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:16:16] [debug] Outgoing: Writing CLOSE
[03-03 11:16:16] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:16:17] [info] local ➞ remote /folder/example.ts

A failed upload attempt:

[03-03 11:17:59] [trace] run command 'Upload Active File'
[03-03 11:17:59] [trace] handle upload file for /folder/example.ts
[03-03 11:18:00] [debug] Outgoing: Writing MKDIR
[03-03 11:18:00] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:18:00] [debug] Outgoing: Writing LSTAT
[03-03 11:18:00] [debug] Outgoing: Writing CHANNEL_DATA (0)

Nothing follows, no matter how long I wait.

The full output log follows, showing 3 successful uploads and 1 silent failure, using the same file and connection:

[03-03 11:09:32] [debug] register command "Cancel All Transfer" from "./commandCancelAllTransfer.ts"
[03-03 11:09:32] [debug] register command "Config" from "./commandConfig.ts"
[03-03 11:09:32] [debug] register command "List Active Folder" from "./commandListActiveFolder.ts"
[03-03 11:09:32] [debug] register command "Open Ssh Connection" from "./commandOpenSshConnection.ts"
[03-03 11:09:32] [debug] register command "Set Profile" from "./commandSetProfile.ts"
[03-03 11:09:32] [debug] register command "Toggle Output Panel" from "./commandToggleOutputPanel.ts"
[03-03 11:09:32] [debug] register command "Upload Changed Files" from "./commandUploadChangedFiles.ts"
[03-03 11:09:32] [debug] register command "Delete Remote" from "./fileCommandDeleteRemote.ts"
[03-03 11:09:32] [debug] register command "Diff" from "./fileCommandDiff.ts"
[03-03 11:09:32] [debug] register command "Diff Active File" from "./fileCommandDiffActiveFile.ts"
[03-03 11:09:32] [debug] register command "Download" from "./fileCommandDownload.ts"
[03-03 11:09:32] [debug] register command "Download Active File" from "./fileCommandDownloadActiveFile.ts"
[03-03 11:09:32] [debug] register command "Download Active Folder" from "./fileCommandDownloadActiveFolder.ts"
[03-03 11:09:32] [debug] register command "Download File" from "./fileCommandDownloadFile.ts"
[03-03 11:09:32] [debug] register command "Download Folder" from "./fileCommandDownloadFolder.ts"
[03-03 11:09:32] [debug] register command "Download Force" from "./fileCommandDownloadForce.ts"
[03-03 11:09:32] [debug] register command "Download Project" from "./fileCommandDownloadProject.ts"
[03-03 11:09:32] [debug] register command "Edit In Local" from "./fileCommandEditInLocal.ts"
[03-03 11:09:32] [debug] register command "List" from "./fileCommandList.ts"
[03-03 11:09:32] [debug] register command "List All" from "./fileCommandListAll.ts"
[03-03 11:09:32] [debug] register command "Reveal In Explorer" from "./fileCommandRevealInExplorer.ts"
[03-03 11:09:32] [debug] register command "Reveal In Remote Explorer" from "./fileCommandRevealInRemoteExplorer.ts"
[03-03 11:09:32] [debug] register command "Sync Both Directions" from "./fileCommandSyncBothDirections.ts"
[03-03 11:09:32] [debug] register command "Sync Local To Remote" from "./fileCommandSyncLocalToRemote.ts"
[03-03 11:09:32] [debug] register command "Sync Remote To Local" from "./fileCommandSyncRemoteToLocal.ts"
[03-03 11:09:32] [debug] register command "Upload" from "./fileCommandUpload.ts"
[03-03 11:09:32] [debug] register command "Upload Active File" from "./fileCommandUploadActiveFile.ts"
[03-03 11:09:32] [debug] register command "Upload Active Folder" from "./fileCommandUploadActiveFolder.ts"
[03-03 11:09:32] [debug] register command "Upload File" from "./fileCommandUploadFile.ts"
[03-03 11:09:32] [debug] register command "Upload Folder" from "./fileCommandUploadFolder.ts"
[03-03 11:09:32] [debug] register command "Upload Force" from "./fileCommandUploadForce.ts"
[03-03 11:09:32] [debug] register command "Upload Project" from "./fileCommandUploadProject.ts"
[03-03 11:09:32] [info] config at /folder {"remotePath":"/var/www/example.com/html/","uploadOnSave":false,"downloadOnOpen":false,"ignore":[],"concurrency":4,"protocol":"sftp","connectTimeout":10000,"interactiveAuth":false,"secure":false,"remoteTimeOffsetInHours":0,"name":"example.com","host":"example.com","port":22,"username":"******","privateKeyPath":"/Users/me/id_rsa"}
[03-03 11:11:37] [trace] run command 'Upload Active File'
[03-03 11:11:37] [trace] handle upload file for /folder/example.ts
[03-03 11:11:37] [debug] Local ident: 'SSH-2.0-ssh2js0.4.5'
[03-03 11:11:37] [debug] Client: Trying example.com on port 22 ...
[03-03 11:11:37] [debug] Client: Connected
[03-03 11:11:37] [debug] Remote ident: 'SSH-2.0-OpenSSH_7.2p2 Ubuntu-4ubuntu2.8'
[03-03 11:11:37] [debug] Outgoing: Writing KEXINIT
[03-03 11:11:37] [debug] DEBUG: Comparing KEXINITs ...
[03-03 11:11:37] [debug] (local) KEX algorithms: ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha1
[03-03 11:11:37] [debug] (remote) KEX algorithms: curve25519-sha256@libssh.org,ecdh-sha2-nistp256,ecdh-sha2-nistp384,ecdh-sha2-nistp521,diffie-hellman-group-exchange-sha256,diffie-hellman-group14-sha1
[03-03 11:11:37] [debug] KEX algorithm: ecdh-sha2-nistp256
[03-03 11:11:37] [debug] (local) Host key formats: ssh-ed25519,ssh-rsa,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521
[03-03 11:11:37] [debug] (remote) Host key formats: ssh-rsa,rsa-sha2-512,rsa-sha2-256,ecdsa-sha2-nistp256,ssh-ed25519
[03-03 11:11:37] [debug] Host key format: ssh-ed25519
[03-03 11:11:37] [debug] (local) Client->Server ciphers: aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm,aes128-gcm@openssh.com,aes256-gcm,aes256-gcm@openssh.com
[03-03 11:11:37] [debug] (remote) Client->Server ciphers: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
[03-03 11:11:37] [debug] Client->Server Cipher: aes128-ctr
[03-03 11:11:37] [debug] (local) Server->Client ciphers: aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm,aes128-gcm@openssh.com,aes256-gcm,aes256-gcm@openssh.com
[03-03 11:11:37] [debug] (remote) Server->Client ciphers: chacha20-poly1305@openssh.com,aes128-ctr,aes192-ctr,aes256-ctr,aes128-gcm@openssh.com,aes256-gcm@openssh.com
[03-03 11:11:37] [debug] Server->Client Cipher: aes128-ctr
[03-03 11:11:37] [debug] (local) Client->Server HMAC algorithms: hmac-sha2-256,hmac-sha2-512,hmac-sha1
[03-03 11:11:37] [debug] (remote) Client->Server HMAC algorithms: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
[03-03 11:11:37] [debug] Client->Server HMAC algorithm: hmac-sha2-256
[03-03 11:11:37] [debug] (local) Server->Client HMAC algorithms: hmac-sha2-256,hmac-sha2-512,hmac-sha1
[03-03 11:11:37] [debug] (remote) Server->Client HMAC algorithms: umac-64-etm@openssh.com,umac-128-etm@openssh.com,hmac-sha2-256-etm@openssh.com,hmac-sha2-512-etm@openssh.com,hmac-sha1-etm@openssh.com,umac-64@openssh.com,umac-128@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha1
[03-03 11:11:37] [debug] Server->Client HMAC algorithm: hmac-sha2-256
[03-03 11:11:37] [debug] (local) Client->Server compression algorithms: none,zlib@openssh.com,zlib
[03-03 11:11:37] [debug] (remote) Client->Server compression algorithms: none,zlib@openssh.com
[03-03 11:11:37] [debug] Client->Server compression algorithm: none
[03-03 11:11:37] [debug] (local) Server->Client compression algorithms: none,zlib@openssh.com,zlib
[03-03 11:11:37] [debug] (remote) Server->Client compression algorithms: none,zlib@openssh.com
[03-03 11:11:37] [debug] Server->Client compression algorithm: none
[03-03 11:11:37] [debug] Outgoing: Writing KEXECDH_INIT
[03-03 11:11:37] [debug] DEBUG: Checking host key format
[03-03 11:11:37] [debug] DEBUG: Checking signature format
[03-03 11:11:37] [debug] DEBUG: Verifying host fingerprint
[03-03 11:11:37] [debug] DEBUG: Host accepted by default (no verification)
[03-03 11:11:37] [debug] DEBUG: Verifying signature
[03-03 11:11:37] [debug] Outgoing: Writing NEWKEYS
[03-03 11:11:37] [debug] Outgoing: Writing SERVICE_REQUEST (ssh-userauth)
[03-03 11:11:38] [debug] Outgoing: Writing USERAUTH_REQUEST (none)
[03-03 11:11:38] [debug] Client: none auth failed
[03-03 11:11:38] [debug] Outgoing: Writing USERAUTH_REQUEST (publickey -- check)
[03-03 11:11:38] [debug] Outgoing: Writing USERAUTH_REQUEST (publickey)
[03-03 11:11:38] [debug] Outgoing: Writing CHANNEL_OPEN (0, session)
[03-03 11:11:38] [debug] Outgoing: Writing CHANNEL_REQUEST (0, subsystem: sftp)
[03-03 11:11:38] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:11:38] [debug] Outgoing: Writing MKDIR
[03-03 11:11:38] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:11:38] [debug] Outgoing: Writing LSTAT
[03-03 11:11:38] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:11:38] [debug] Outgoing: Writing OPEN
[03-03 11:11:38] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:11:38] [debug] Outgoing: Writing FSTAT
[03-03 11:11:38] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:11:38] [debug] Outgoing: Writing FSETSTAT
[03-03 11:11:38] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:11:38] [debug] Outgoing: Writing WRITE
[03-03 11:11:38] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:11:38] [debug] Outgoing: Writing FSETSTAT
[03-03 11:11:38] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:11:38] [debug] Outgoing: Writing CLOSE
[03-03 11:11:38] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:11:38] [info] local ➞ remote /folder/example.ts
[03-03 11:11:47] [trace] run command 'Toggle Output Panel'
[03-03 11:12:08] [debug] Outgoing: Writing ping (GLOBAL_REQUEST: keepalive@openssh.com)
[03-03 11:12:11] [trace] run command 'Upload Active File'
[03-03 11:12:11] [trace] handle upload file for /folder/example.ts
[03-03 11:12:11] [debug] Outgoing: Writing MKDIR
[03-03 11:12:11] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:12:11] [debug] Outgoing: Writing LSTAT
[03-03 11:12:11] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:12:11] [debug] Outgoing: Writing OPEN
[03-03 11:12:11] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:12:11] [debug] Outgoing: Writing FSTAT
[03-03 11:12:11] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:12:11] [debug] Outgoing: Writing FSETSTAT
[03-03 11:12:11] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:12:11] [debug] Outgoing: Writing WRITE
[03-03 11:12:11] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:12:11] [debug] Outgoing: Writing FSETSTAT
[03-03 11:12:11] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:12:11] [debug] Outgoing: Writing CLOSE
[03-03 11:12:11] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:12:12] [info] local ➞ remote /folder/example.ts
[03-03 11:12:38] [debug] Outgoing: Writing ping (GLOBAL_REQUEST: keepalive@openssh.com)
[03-03 11:13:08] [debug] Outgoing: Writing ping (GLOBAL_REQUEST: keepalive@openssh.com)
[03-03 11:13:38] [debug] Outgoing: Writing ping (GLOBAL_REQUEST: keepalive@openssh.com)
[03-03 11:14:08] [debug] Outgoing: Writing ping (GLOBAL_REQUEST: keepalive@openssh.com)
[03-03 11:14:38] [debug] Outgoing: Writing ping (GLOBAL_REQUEST: keepalive@openssh.com)
[03-03 11:15:08] [debug] Outgoing: Writing ping (GLOBAL_REQUEST: keepalive@openssh.com)
[03-03 11:15:38] [debug] Outgoing: Writing ping (GLOBAL_REQUEST: keepalive@openssh.com)
[03-03 11:16:08] [debug] Outgoing: Writing ping (GLOBAL_REQUEST: keepalive@openssh.com)
[03-03 11:16:38] [debug] Outgoing: Writing ping (GLOBAL_REQUEST: keepalive@openssh.com)
[03-03 11:17:08] [debug] Outgoing: Writing ping (GLOBAL_REQUEST: keepalive@openssh.com)
[03-03 11:17:38] [debug] Outgoing: Writing ping (GLOBAL_REQUEST: keepalive@openssh.com)
[03-03 11:17:59] [trace] run command 'Upload Active File'
[03-03 11:17:59] [trace] handle upload file for /folder/example.ts
[03-03 11:18:00] [debug] Outgoing: Writing MKDIR
[03-03 11:18:00] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:18:00] [debug] Outgoing: Writing LSTAT
[03-03 11:18:00] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:18:08] [debug] Outgoing: Writing ping (GLOBAL_REQUEST: keepalive@openssh.com)
[03-03 11:18:09] [trace] run command 'Toggle Output Panel'
[03-03 11:18:38] [debug] Outgoing: Writing ping (GLOBAL_REQUEST: keepalive@openssh.com)
[03-03 11:19:01] [trace] run command 'Upload Active File'
[03-03 11:19:01] [trace] handle upload file for /folder/example.ts
[03-03 11:19:01] [debug] Outgoing: Writing MKDIR
[03-03 11:19:01] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:19:01] [debug] Outgoing: Writing LSTAT
[03-03 11:19:01] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:19:01] [debug] Outgoing: Writing OPEN
[03-03 11:19:01] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:19:01] [debug] Outgoing: Writing FSTAT
[03-03 11:19:01] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:19:01] [debug] Outgoing: Writing FSETSTAT
[03-03 11:19:01] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:19:01] [debug] Outgoing: Writing WRITE
[03-03 11:19:01] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:19:01] [debug] Outgoing: Writing FSETSTAT
[03-03 11:19:01] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:19:01] [debug] Outgoing: Writing CLOSE
[03-03 11:19:01] [debug] Outgoing: Writing CHANNEL_DATA (0)
[03-03 11:19:01] [info] local ➞ remote /folder/example.ts

If there is any further information I can provide or tests I can do I'd be happy to do so.

gnnpls commented 4 years ago

I have the same issue.

eldark commented 4 years ago

Same issue here 🙋