Background Upload Losing Connection upon SSH_FXP_CLOSE / Host is not communicating for 15 seconds

Using the same transfer options for a foreground file upload succeeds while the background equivalent fails. There is a Cisco FireSight in play. Also on server side there is a filewatcher picking up file once it is written and moving it. Here is the relevant session log entries:
(using latest bits: 5.13.9) (full session log attached)

**I have confirmed this problem only occurs when going through the firewall. So the question is what is the difference when it is a background transfer. As best I can tell the background xfer uses 2 TCP/IP endpoints (ports) / connections therefore I believe Snort (malware software) is seeing this as a potential brute force attack.

(WORKING)
. 2019-03-25 14:12:42.442 Copying 1 files/directories to remote directory "/incoming/paymode/" - total size: 30,566
. 2019-03-25 14:12:42.442 PrTime: No; PrRO: No; Rght: rw-r--r--; PrR: No (No); FnCs: N; RIC: 0100; Resume: S (102400); CalcS: Yes; Mask: *.*
. 2019-03-25 14:12:42.442 TM: B; ClAr: No; RemEOF: No; RemBOM: No; CPS: 0; NewerOnly: No; InclM: ; ResumeL: 0
. 2019-03-25 14:12:42.442 AscM: *.*html; *.htm; *.txt; *.php; *.php3; *.cgi; *.c; *.cpp; *.h; *.pas; *.bas; *.tex; *.pl; *.js; .htaccess; *.xtml; *.css; *.cfg; *.ini; *.sh; *.xml
. 2019-03-25 14:12:42.443 Getting real path for '/incoming/paymode/'
> 2019-03-25 14:12:42.443 Type: SSH_FXP_REALPATH, Size: 27, Number: 4368
< 2019-03-25 14:12:42.443 Type: SSH_FXP_STATUS, Size: 40, Number: 4100
. 2019-03-25 14:12:42.443 Discarding reserved response
< 2019-03-25 14:12:42.492 Type: SSH_FXP_NAME, Size: 83, Number: 4368
. 2019-03-25 14:12:42.492 Real path is '/incoming/paymode'
. 2019-03-25 14:12:42.494 File: '\\xxx\Integrations\Treasury\Accounts Payable\TEST\CURRENT\TEST-PM201903200944544454TTA.TXT' [2019-03-20T16:45:02.241Z] [30566]
. 2019-03-25 14:12:42.599 Copying "\\xxx\Integrations\Treasury\Accounts Payable\TEST\CURRENT\TEST-PM201903200944544454TTA.TXT" to remote directory started.
. 2019-03-25 14:12:42.600 Binary transfer mode selected.
. 2019-03-25 14:12:42.600 Opening remote file.
> 2019-03-25 14:12:42.600 Type: SSH_FXP_OPEN, Size: 75, Number: 4611
< 2019-03-25 14:12:42.710 Type: SSH_FXP_HANDLE, Size: 10, Number: 4611
> 2019-03-25 14:12:42.710 Type: SSH_FXP_WRITE, Size: 30588, Number: 5126
> 2019-03-25 14:12:42.711 Type: SSH_FXP_CLOSE, Size: 10, Number: 5380
< 2019-03-25 14:12:42.798 Type: SSH_FXP_STATUS, Size: 49, Number: 5126
< 2019-03-25 14:12:42.798 Status code: 0
< 2019-03-25 14:12:42.847 Type: SSH_FXP_STATUS, Size: 40, Number: 5380
< 2019-03-25 14:12:42.847 Status code: 0
. 2019-03-25 14:12:42.847 Transfer done: '\\xxx\Integrations\Treasury\Accounts Payable\TEST\CURRENT\TEST-PM201903200944544454TTA.TXT' => '/incoming/paymode/TEST-PM201903200944544454TTA.TXT' [30566]

(FAILING)
. 2019-03-25 14:13:15.490 [Background 1] Copying 1 files/directories to remote directory "/incoming/paymode/" - in parallel, with 1 total files - total size: 30,566
. 2019-03-25 14:13:15.490 [Background 1] PrTime: No; PrRO: No; Rght: rw-r--r--; PrR: No (No); FnCs: N; RIC: 0100; Resume: S (102400); CalcS: Yes; Mask: *.*
. 2019-03-25 14:13:15.490 [Background 1] TM: B; ClAr: No; RemEOF: No; RemBOM: No; CPS: 0; NewerOnly: No; InclM: ; ResumeL: 0
. 2019-03-25 14:13:15.490 [Background 1] AscM: *.*html; *.htm; *.txt; *.php; *.php3; *.cgi; *.c; *.cpp; *.h; *.pas; *.bas; *.tex; *.pl; *.js; .htaccess; *.xtml; *.css; *.cfg; *.ini; *.sh; *.xml
. 2019-03-25 14:13:15.490 [Background 1] Getting real path for '/incoming/paymode/'
> 2019-03-25 14:13:15.490 [Background 1] Type: SSH_FXP_REALPATH, Size: 27, Number: 11280
< 2019-03-25 14:13:15.531 [Background 1] Type: SSH_FXP_STATUS, Size: 40, Number: 11012
. 2019-03-25 14:13:15.531 [Background 1] Discarding reserved response
< 2019-03-25 14:13:15.611 [Background 1] Type: SSH_FXP_NAME, Size: 83, Number: 11280
. 2019-03-25 14:13:15.611 [Background 1] Real path is '/incoming/paymode'
. 2019-03-25 14:13:15.611 [Background 1] File: '\\xxx\Integrations\Treasury\Accounts Payable\TEST\CURRENT\TEST-PM201903200944544454TTA.TXT' [2019-03-20T16:45:02.241Z] [30566]
. 2019-03-25 14:13:15.716 [Background 1] Copying "\\xxx\Integrations\Treasury\Accounts Payable\TEST\CURRENT\TEST-PM201903200944544454TTA.TXT" to remote directory started.
. 2019-03-25 14:13:15.716 [Background 1] Binary transfer mode selected.
. 2019-03-25 14:13:15.716 [Background 1] Opening remote file.
> 2019-03-25 14:13:15.716 [Background 1] Type: SSH_FXP_OPEN, Size: 75, Number: 11523
< 2019-03-25 14:13:15.845 [Background 1] Type: SSH_FXP_HANDLE, Size: 10, Number: 11523
> 2019-03-25 14:13:15.846 [Background 1] Type: SSH_FXP_WRITE, Size: 30588, Number: 12038
> 2019-03-25 14:13:15.846 [Background 1] Type: SSH_FXP_CLOSE, Size: 10, Number: 12292
. 2019-03-25 14:13:30.848 [Background 1] Waiting for data timed out, asking user what to do.

====

Please advise.

There's no difference between foreground and background connection in this respect.
Do you have an access to server-side logs?

No FTP server side logs yet. As best I can tell it is just a timing issue introduced when doing the background transfer (or .net automated transfer) that is triggering the Gobbles 128:1:2 Exploit rule in the Cisco FirePower device. As you stated to me the calls made are essentially the same (as best I can tell) it is just the timing of the TCP packets / acks. Will let you know if we learn anything else, thanks!

Marty Supple

Based on some further analysis it seems that the Cisco Firepower malware software is triggering the [128:1:2] SSH Gobbles exploit when we perform Background WinSCP uploads vs Foreground for certain size files (30k in this case), where smaller files (under 10k) did not trigger the exploit rule. Since we are using username/password authentication and also based on the different timing of packet processing of a foreground vs background transfer (which you can see in a network trace) the buffer overrun portion of the Gobbles exploit rule/signature gets fired (I believe). I assume the background xfer is running on a separate thread that is not also dispatching other Windows messages and can dedicate more cycles to the upload. We are going to move to KEY based authentication in any event, which will be more secure. Although this should avoid triggering the exploit we will likely white list the IP to avoid any other false positives.

For anyone interested that may be running into a similar problem (Firewall Alerting Gobbles SSH Exploit when doing file upload) here is what I figured out:

The Cisco FirePower IP Security runs a Snort SSH Pre-processor (source code referenced here:
https://github.com/threatstream/snort/blob/master/src/dynamic-preprocessors/ssh/spp_ssh.c )

When doing an SFTP file upload of a 'larger' file (our failure was 30k, where files less than 10k worked), this SSH pre processor fires a potential buffer overrun (Gobbles) exploit warning (and in our case the SSH connection got killed by the firewall, and the SFTP upload failed).

The Snort ssh algorithm basically looks for the client sending a certain number of bytes without a server response within the beginning of the SSH conversation (based on # packets). The reason this was failing for a background (or .net) upload is that there was less chatter happening in the SSH conversation before the file upload whereas when I did the upload in foreground mode I was issuing additional commands to navigate to the target folder on the server before starting the upload, thus getting past the first N packets of the conversation before sending a large number of bytes without a server response.

You can get around the exploit rule by issuing additional commands before your file upload (I just did a session.FileExists in a loop of 10) then the putfile works. Obviously you will want a better solution like disabling this rule in your firewall ;)

Marty

Thanks for sharing your findings!