SFX not transferring full file

[ITry]

Transfer is only pulling 32 of 45 KB.

Transferring file...
2007-09-19 15:17:56, 00001: Transfer(00B9A920): SEND : Open: /Test/file_name030001.zip.pgp, mode 0x1
Remote file closed.
2007-09-19 15:17:57, 00001: Transfer(00B9A920): 32.0 KB (of 44.0 KB) transferred in 0.55 seconds (58.51 KB/s).
...
2007-09-19 15:17:57, 00001: Transfer(00B9A920): SUMMARY: Transferred 1 files successfully.


My command line looks like....

sfxcl.exe %P_MOVE_PARM% /Log %P_LOG_PARM% %P_OVERWRITE_PARM% /Q /S /%P_SFTP_SESSION% %P_SESSION_PATH_PARM%%P_FILE_NAME_PARM% "%P_PATH_PARM%%P_FILE_NAME_PARM%"

Any ideas why I disconnect before the transfer is complete?

also, In test I've been sending a good file to the remote server with SFX and it looks like everything is working. the cmd lines are basically the same but I also noted the get uses ' mode 0x1 ' and the send uses ' mode 0x1a '

[tnygren]

Hi ITry,

I just need to get a little more information to find out what is happening.

Which version of SecureFX is installed?

This can be found by selecting 'About SecureFX' from the 'Help' menu.

Could you post the complete log file for SFXCL?

Is the file corrupted after the download?

If you would prefer not to post the log file in a public forum, please feel free to email it to me. Just send it to support@vandyke.com with a subject of 'ATTN: Teresa Forum Thread 2475'.

[ITry]

Windows version 4.5

The file I retrieve is corrupted, decryption ofthe file fails with a bock size warning. The decrypted file is in zip format. That file is missing data when decompressed.

not familiar with term 'SFXCL' but the log file is listed below. I executed the session twice. Once to list the contents on the remote server and once to retrieve the file... I deleted part of the log related to the 'list' session to meet your sites posting restrictions

================================================== ====

sfxcl.exe /list /Log \\server\path\work\file_name_030001.lck.log /Q /S SESSION_ID Pick/Test/
2007-09-19 15:17:51, 00001: sfxcl version 4.5.1.407 (Official Release - May 17, 2007)
2007-09-19 15:17:51, 00001: Session 00001 established for transfer from SESSION_ID
2007-09-19 15:17:51, 00001: SSH2Core version 4.3.0.407
2007-09-19 15:17:51, 00001: Connecting to afts.SESSION_ID.com:22 ...
2007-09-19 15:17:51, 00001: Changing state from STATE_NOT_CONNECTED to STATE_EXPECT_KEX_INIT
2007-09-19 15:17:51, 00001: Using protocol SSH2
2007-09-19 15:17:51, 00001: RECV : Remote Identifier = "SSH-2.0-1.36_sshlib GlobalSCAPE"
.
.
.
Connection to afts.SESSION_ID.com established.
2007-09-19 15:17:52, 00001: SEND: SERVICE_REQUEST[ssh-userauth]
2007-09-19 15:17:52, 00001: RECV: SERVICE_ACCEPT[ssh-userauth] -- OK
2007-09-19 15:17:52, 00001: SENT : USERAUTH_REQUEST [none]
2007-09-19 15:17:52, 00001: RECV : SSH_MSG_USERAUTH_BANNER
2007-09-19 15:17:52, 00001: RECV : USERAUTH_FAILURE, continuations [password,publickey]
2007-09-19 15:17:52, 00001: SENT : USERAUTH_REQUEST [password]
2007-09-19 15:17:52, 00001: RECV : AUTH_SUCCESS
Connection to afts.SESSION_ID.com established.
2007-09-19 15:17:52, 00001: RECV : Server Sftp Version: 3
2007-09-19 15:17:52, 00001: SENT : fs-multiple-roots-supported request[On]
2007-09-19 15:17:52, 00001: SENT : vendor-id request
2007-09-19 15:17:52, 00001: RECV : fs-multiple-roots-supported reply: 8
2007-09-19 15:17:52, 00001: SEND : Stat .
2007-09-19 15:17:53, 00001: SEND : RealPath, base=.
2007-09-19 15:17:53, 00001: Resolved RealPath: /
2007-09-19 15:17:53, 00001: SEND : Stat /Pick/Test
2007-09-19 15:17:53, 00001: SEND : RealPath, base=/Pick/Test
2007-09-19 15:17:53, 00001: Resolved RealPath: /Pick/Test
2007-09-19 15:17:53, 00001: rw-rw-rw- 45095 Wed 19-Sep-2007 15:18:10 file_name_030001.zip.pgp (S)
2007-09-19 15:17:53, 00001: rw-rw-rw- 7602643 Tue 21-Aug-2007 10:42:04 file_name_040001.zip.pgp (S)
2007-09-19 15:17:53, 00001: rw-rw-rw- 15711 Tue 21-Aug-2007 10:42:12 file_name_040002.zip.pgp (S)
2007-09-19 15:17:53, 00001: rw-rw-rw- 32768 Wed 19-Sep-2007 13:57:00 file_name_040003.pgp (S)
2007-09-19 15:17:53, 00001: rw-rw-rw- 323 Tue 21-Aug-2007 10:42:36 file_name_040004.pgp (S)
2007-09-19 15:17:53, 00001: rw-rw-rw- 2229081 Tue 21-Aug-2007 10:42:55 file_name_040005.pgp (S)


sfxcl.exe /move /Log \\server\path\work\file_name_030001.lck.log /Q /S /SESSION_ID Pick/Test/file_name_030001.zip.pgp "\\server\path\work\file_name_030001.zip.pgp"
2007-09-19 15:17:54, 00001: sfxcl version 4.5.1.407 (Official Release - May 17, 2007)
2007-09-19 15:17:54, 00001: Session 00001 established for transfer from /SESSION_ID
2007-09-19 15:17:54, 00001: SSH2Core version 4.3.0.407
2007-09-19 15:17:54, 00001: Connecting to afts.SESSION_ID.com:22 ...
2007-09-19 15:17:54, 00001: Changing state from STATE_NOT_CONNECTED to STATE_EXPECT_KEX_INIT
2007-09-19 15:17:54, 00001: Using protocol SSH2
2007-09-19 15:17:54, 00001: RECV : Remote Identifier = "SSH-2.0-1.36_sshlib GlobalSCAPE"
2007-09-19 15:17:54, 00001: CAP : Remote can re-key
2007-09-19 15:17:54, 00001: CAP : Remote sends language in password change requests
2007-09-19 15:17:54, 00001: CAP : Remote sends algorithm name in PK_OK packets
2007-09-19 15:17:54, 00001: CAP : Remote sends algorithm name in public key packets
2007-09-19 15:17:54, 00001: CAP : Remote sends algorithm name in signatures
2007-09-19 15:17:54, 00001: CAP : Remote sends error text in open failure packets
2007-09-19 15:17:54, 00001: CAP : Remote sends name in service accept packets
2007-09-19 15:17:54, 00001: CAP : Remote includes port number in x11 open packets
2007-09-19 15:17:54, 00001: CAP : Remote uses 160 bit keys for SHA1 MAC
2007-09-19 15:17:54, 00001: CAP : Remote supports new diffie-hellman group exchange messages
2007-09-19 15:17:54, 00001: CAP : Remote correctly handles unknown SFTP extensions
2007-09-19 15:17:54, 00001: CAP : Remote correctly encodes OID for gssapi
2007-09-19 15:17:54, 00001: CAP : Remote correctly uses connected addresses in forwarded-tcpip requests
2007-09-19 15:17:54, 00001: CAP : Remote can do SFTP version 4
2007-09-19 15:17:54, 00001: CAP : Remote uses SHA1 hash in RSA signatures for x.509v3
2007-09-19 15:17:54, 00001: CAP : Remote x.509v3 uses ASN.1 encoding for DSA signatures
2007-09-19 15:17:54, 00001: SEND : KEXINIT
2007-09-19 15:17:54, 00001: RECV : Read kexinit
2007-09-19 15:17:54, 00001: Available Remote Kex Methods = diffie-hellman-group1-sha1
2007-09-19 15:17:54, 00001: Selected Kex Method = diffie-hellman-group1-sha1
2007-09-19 15:17:54, 00001: Available Remote Host Key Algos = ssh-dss
2007-09-19 15:17:54, 00001: Selected Host Key Algo = ssh-dss
2007-09-19 15:17:54, 00001: Available Remote Send Ciphers = twofish-cbc,twofish128-cbc,blowfish-cbc,3des-cbc,arcfour,cast128-cbc,aes128-cbc
2007-09-19 15:17:54, 00001: Selected Send Cipher = aes128-cbc
2007-09-19 15:17:54, 00001: Available Remote Recv Ciphers = twofish-cbc,twofish128-cbc,blowfish-cbc,3des-cbc,arcfour,cast128-cbc,aes128-cbc
2007-09-19 15:17:54, 00001: Selected Recv Cipher = aes128-cbc
2007-09-19 15:17:55, 00001: Available Remote Send Macs = hmac-sha1,hmac-md5,hmac-sha1-96,hmac-md5-96
2007-09-19 15:17:55, 00001: Selected Send Mac = hmac-md5
2007-09-19 15:17:55, 00001: Available Remote Recv Macs = hmac-sha1,hmac-md5,hmac-sha1-96,hmac-md5-96
2007-09-19 15:17:55, 00001: Selected Recv Mac = hmac-md5
2007-09-19 15:17:55, 00001: Available Remote Compressors = zlib,none
2007-09-19 15:17:55, 00001: Selected Compressor = none
2007-09-19 15:17:55, 00001: Available Remote Decompressors = zlib,none
2007-09-19 15:17:55, 00001: Selected Decompressor = none
2007-09-19 15:17:55, 00001: Changing state from STATE_EXPECT_KEX_INIT to STATE_KEY_EXCHANGE
2007-09-19 15:17:55, 00001: SEND : KEXDH_INIT
2007-09-19 15:17:55, 00001: RECV : KEXDH_REPLY
2007-09-19 15:17:55, 00001: SEND : NEWKEYS
2007-09-19 15:17:55, 00001: Changing state from STATE_KEY_EXCHANGE to STATE_EXPECT_NEWKEYS
2007-09-19 15:17:55, 00001: RECV : NEWKEYS
2007-09-19 15:17:55, 00001: Changing state from STATE_EXPECT_NEWKEYS to STATE_CONNECTION
Connection to afts.SESSION_ID.com established.
2007-09-19 15:17:55, 00001: SEND: SERVICE_REQUEST[ssh-userauth]
2007-09-19 15:17:55, 00001: RECV: SERVICE_ACCEPT[ssh-userauth] -- OK
2007-09-19 15:17:55, 00001: SENT : USERAUTH_REQUEST [none]
2007-09-19 15:17:55, 00001: RECV : SSH_MSG_USERAUTH_BANNER
2007-09-19 15:17:55, 00001: RECV : USERAUTH_FAILURE, continuations [password,publickey]
2007-09-19 15:17:55, 00001: SENT : USERAUTH_REQUEST [password]
2007-09-19 15:17:55, 00001: RECV : AUTH_SUCCESS
Connection to afts.SESSION_ID.com established.
2007-09-19 15:17:56, 00001: RECV : Server Sftp Version: 3
2007-09-19 15:17:56, 00001: SENT : fs-multiple-roots-supported request[On]
2007-09-19 15:17:56, 00001: SENT : vendor-id request
2007-09-19 15:17:56, 00001: RECV : fs-multiple-roots-supported reply: 8
2007-09-19 15:17:56, 00001: SEND : Stat .
2007-09-19 15:17:56, 00001: SEND : RealPath, base=.
2007-09-19 15:17:56, 00001: Resolved RealPath: /
Beginning transfer.
Changing directories...
2007-09-19 15:17:56, 00001: Transfer(00B9A920): SEND : Stat /Pick/Test/file_name_030001.zip.pgp
2007-09-19 15:17:56, 00001: Transfer(00B9A920): SEND : RealPath, base=/Pick/Test/file_name_030001.zip.pgp
2007-09-19 15:17:56, 00001: Transfer(00B9A920):
Changing directories...
2007-09-19 15:17:56, 00001: Transfer(00B9A920): SEND : Stat /Pick/Test/
2007-09-19 15:17:56, 00001: Transfer(00B9A920): SEND : RealPath, base=/Pick/Test/
2007-09-19 15:17:56, 00001: Transfer(00B9A920): Resolved RealPath: /Pick/Test
Checking remote file status...
2007-09-19 15:17:56, 00001: Transfer(00B9A920): SEND : Stat /Pick/Test/file_name_030001.zip.pgp
2007-09-19 15:17:56, 00001: Transfer(00B9A920): Opening file 'file_name_030001.zip.pgp' for download as 'file_name_030001.zip.pgp'.
Transferring file...
2007-09-19 15:17:56, 00001: Transfer(00B9A920): SEND : Open: /Pick/Test/file_name_030001.zip.pgp, mode 0x1
Remote file closed.
2007-09-19 15:17:57, 00001: Transfer(00B9A920): 32.0 KB (of 44.0 KB) transferred in 0.55 seconds (58.51 KB/s).
2007-09-19 15:17:57, 00001: Transfer(00B9A920): SUMMARY: Attempted to transfer 0 files.
2007-09-19 15:17:57, 00001: Transfer(00B9A920): SUMMARY: Transferred 1 files successfully.
2007-09-19 15:17:57, 00001: Channel Closed: 00000000 (The operation completed successfully. )

[ITry]

fyi....

I asked our tech services area to logon via the SecureFX interface and it failed the same way. I then put a non-pgp file on the remote site and then ran my script against it (and the was no data loss)....

Transferring file...
2007-09-19 16:29:05, 00001: Transfer(00B9A8F0): SEND : Open: /Pick/test/file_name_030001.zip, mode 0x1
Remote file closed.
2007-09-19 16:29:07, 00001: Transfer(00B9A8F0): 328.1 KB transferred in 1.58 seconds (207.90 KB/s).
2007-09-19 16:29:07, 00001: Transfer(00B9A8F0): SUMMARY: Attempted to transfer 0 files.
2007-09-19 16:29:07, 00001: Transfer(00B9A8F0): SUMMARY: Transferred 1 files successfully.
2007-09-19 16:29:07, 00001: Channel Closed: 00000000 (The operation completed successfully. )






An interesting thing is that when I send a pgp file to them there's no loss it's only when I try to retrieve a pgp file. Bug?

[tnygren]

Hi ITry,

I had a couple of other questions after looking at the log file.

How many bytes transferred does the Globescape's log file show for this transfer?

Was the test file that was uploaded also a PGP encrypted zip file?

What happens if a non-PGP encrypted zip file is used?

[tnygren]

An interesting thing is that when I send a pgp file to them there's no loss it's only when I try to retrieve a pgp file. Bug?

I'm not certain that this is a bug in SecureFX as SecureFX does not download different files using the same transfer method (binary in this case) differently.

However, it may be something that is happening on the Globescape server. The server could be doing something different with the file because it is a PGP encrypted file.

I would be interested to see what the server's logs report since this is only happening on downloads of PGP encrypted files.

Would it be possible to get a log from the SFTP server?

[ITry]

Hmmm....

I understand what you are saying about "GlobalSCAPE" as a potential problem. I'm not sure I can get a log file from the trading partner. Regardless, I have put in a request for one.

Our BA has spoken with our trading partner about this issue and at this point they are saying that none of the other companies retrieving data from their server are having this issue.

I'll continue to follow up.

[ITry]

Here's the log from GlobalScape:

ex070920.log:2007-09-20 06:12:24 ip_address_masked - user_id [13496]user user_id - 331 - - - 22
ex070920.log:2007-09-20 06:12:24 ip_address_masked - user_id [13496]pass ******* - 250 - - - 22
ex070920.log:2007-09-20 06:12:25 ip_address_masked - user_id [13496]quit - - 221 - - - 22
ex070920.log:2007-09-20 06:12:26 ip_address_masked - user_id [13497]user user_id - 331 - - - 22
ex070920.log:2007-09-20 06:12:26 ip_address_masked - user_id [13497]pass ******* - 250 - - - 22
ex070920.log:2007-09-20 06:12:27 ip_address_masked - user_id [13497]sent /Pick/file_040002.zip.pgp - 226 - 16009 - 22
ex070920.log:2007-09-20 06:12:27 ip_address_masked - user_id [13497]dele /Pick/file_040002.zip.pgp - 250 - - - 22
ex070920.log:2007-09-20 06:12:27 ip_address_masked - user_id [13497]quit - - 221 - - - 22
ex070920.log:2007-09-20 06:12:29 ip_address_masked - user_id [13498]user user_id - 331 - - - 22
ex070920.log:2007-09-20 06:12:29 ip_address_masked - user_id [13498]pass ******* - 250 - - - 22
ex070920.log:2007-09-20 06:12:30 ip_address_masked - user_id [13498]quit - - 221 - - - 22
ex070920.log:2007-09-20 06:12:31 ip_address_masked - user_id [13499]user user_id - 331 - - - 22
ex070920.log:2007-09-20 06:12:31 ip_address_masked - user_id [13499]pass ******* - 250 - - - 22
ex070920.log:2007-09-20 06:12:32 ip_address_masked - user_id [13499]sent /Pick/file_030001.zip.pgp - 226 - 32768 - 22
ex070920.log:2007-09-20 06:12:32 ip_address_masked - user_id [13499]dele /Pick/file_030001.zip.pgp - 250 - - - 22
ex070920.log:2007-09-20 06:12:32 ip_address_masked - user_id [13499]quit - - 221 - - - 22

ex070920.log:2007-09-20 14:10:28 ip_address_masked - user_id [13987]user user_id - 331 - - - 22
ex070920.log:2007-09-20 14:10:28 ip_address_masked - user_id [13987]pass ******* - 250 - - - 22
ex070920.log:2007-09-20 14:10:30 ip_address_masked - user_id [13987]quit - - 221 - - - 22
ex070920.log:2007-09-20 14:10:31 ip_address_masked - user_id [13988]user user_id - 331 - - - 22
ex070920.log:2007-09-20 14:10:31 ip_address_masked - user_id [13988]pass ******* - 250 - - - 22
ex070920.log:2007-09-20 14:10:34 ip_address_masked - user_id [13988]created /pick/test/file_040002.zip.pgp - 226 - 16009 - 22
ex070920.log:2007-09-20 14:10:34 ip_address_masked - user_id [13988]quit - - 221 - - - 22

ex070920.log:2007-09-20 14:10:37 ip_address_masked - user_id [13989]user user_id - 331 - - - 22
ex070920.log:2007-09-20 14:10:37 ip_address_masked - user_id [13989]pass ******* - 250 - - - 22
ex070920.log:2007-09-20 14:10:39 ip_address_masked - user_id [13989]quit - - 221 - - - 22

ex070920.log:2007-09-20 14:12:16 ip_address_masked - user_id [13993]user user_id - 331 - - - 22
ex070920.log:2007-09-20 14:12:16 ip_address_masked - user_id [13993]pass ******* - 250 - - - 22
ex070920.log:2007-09-20 14:12:17 ip_address_masked - user_id [13993]quit - - 221 - - - 22
ex070920.log:2007-09-20 14:12:18 ip_address_masked - user_id [13994]user user_id - 331 - - - 22
ex070920.log:2007-09-20 14:12:18 ip_address_masked - user_id [13994]pass ******* - 250 - - - 22
ex070920.log:2007-09-20 14:12:20 ip_address_masked - user_id [13994]sent /pick/test/file_040002.zip.pgp - 226 - 16009 - 22
ex070920.log:2007-09-20 14:12:20 ip_address_masked - user_id [13994]quit - - 221 - - - 22

[tnygren]

Hi ITry,

Thanks for the log file!

Unfortunately, the log does not give much information on the file size.

As a test, could you rename the file (removing the .pgp extension) and transfer the file after the rename?

This may be easier to test in the GUI interface of SecureFX.

Can other SFTP clients transfer the file with the .pgp extension?

[ITry]

Tested with GUI. Same results....

Performed some additional testing using SFTP. Then asked TP to allow FTP for testing. Switched our test server version of SecureFX to FTP mode for that TP's sessions.

I then worked with the TP and transferred various files with SecureFX using SFTP and FTP. No problems with FTP under any condition tested. Using SFTP mode we encounterd problems with Zipped, PGP, and PGP-Zipped files when the files reached some size above 30kb. In all cases there were no issues with standard ascii files.

At this point TP believes this is their vendor's issue. Until our TP can either get GlobalScape to resolve the problem or the TP gets approval to stop encrypting their data we'll work in FTP mode.

Thanks for the help!

[tnygren]

Hi ITry,

Thanks for letting me know and please let me know what happens!

I am interested is seeing what was causing this issue.

[miked]

Would you be interested in trying a pre-release version of a SecureFX 6.0 installer which should fix the problem you're experiencing?

If so, please let us know (https://secure.vandyke.com/cgi-bin/customer_forms.php?cft=support).