Hi,
As you may know, Microsoft is now using WinSCP 5.7.7 in BizTalk's SFTP adapter code. We use BizTalk2016 to retrieve files from an SFTP location. It works fine for a while but then suddenly it would just stop polling files from the SFTP server until the service that hosts the SFTP process is restarted (in this case the BizTalk host instance). After restarting the host instance, files are retrieved successfully from the SFTP server with on problem. I am attaching two sections of the log here, the first Section is to give you an idea what was happening when the files were not being retrieved. The second section is after restarting the service and files could be retrieved successfully.
So, the first Section is as follows:
. 2017-06-07 12:24:39.214 Using SFTP protocol.
. 2017-06-07 12:24:39.214 Doing startup conversation with host.
> 2017-06-07 12:24:39.214 Type: SSH_FXP_INIT, Size: 5, Number: -1
< 2017-06-07 12:24:39.229 Type: SSH_FXP_VERSION, Size: 5, Number: -1
. 2017-06-07 12:24:39.229 SFTP version 4 negotiated.
. 2017-06-07 12:24:39.229 We will use UTF-8 strings as it is mandatory with SFTP version 4 and newer
. 2017-06-07 12:24:39.229 Getting current directory name.
. 2017-06-07 12:24:39.229 Getting real path for '.'
> 2017-06-07 12:24:39.229 Type: SSH_FXP_REALPATH, Size: 10, Number: 16
< 2017-06-07 12:24:39.464 Type: SSH_FXP_NAME, Size: 23, Number: 16
. 2017-06-07 12:24:39.464 Real path is '/'
. 2017-06-07 12:24:39.464 Startup conversation with host finished.
< 2017-06-07 12:24:39.464 Script: Active session: [1] xxxxxxxxxxxxxxxxxxxx@xxxxxxxxxxxxxxx
> 2017-06-07 12:24:39.635 Script: pwd
< 2017-06-07 12:24:39.635 Script: /
> 2017-06-07 12:24:39.776 Script: ls -- "live/LiveEmployeeList/"
. 2017-06-07 12:24:39.776 Listing directory "/live/LiveEmployeeList".
> 2017-06-07 12:24:39.776 Type: SSH_FXP_OPENDIR, Size: 31, Number: 267
< 2017-06-07 12:24:39.839 Type: SSH_FXP_HANDLE, Size: 11, Number: 267
> 2017-06-07 12:24:39.839 Type: SSH_FXP_READDIR, Size: 11, Number: 524
< 2017-06-07 12:24:39.870 Type: SSH_FXP_NAME, Size: 191, Number: 524
> 2017-06-07 12:24:39.870 Type: SSH_FXP_READDIR, Size: 11, Number: 780
< 2017-06-07 12:24:39.901 Type: SSH_FXP_STATUS, Size: 28, Number: 780
< 2017-06-07 12:24:39.901 Status code: 1
> 2017-06-07 12:24:39.901 Type: SSH_FXP_CLOSE, Size: 11, Number: 1028
. 2017-06-07 12:24:39.901 .;D;0;2017-06-07T11:20:15.000Z;"" [0];"" [0];rwxr-x---;2
. 2017-06-07 12:24:39.901 ..;D;0;2017-01-11T19:50:14.000Z;"" [0];"" [0];rwxr-x---;0
. 2017-06-07 12:24:39.901 LiveEmployeeList.csv;-;521220;2017-06-07T11:20:15.000Z;"" [0];"" [0];rwxr-x---;0
. 2017-06-07 12:24:39.901 New;D;0;2017-06-07T11:20:15.000Z;"" [0];"" [0];rwxr-x---;0
< 2017-06-07 12:24:39.901 Script: Drwxr-x--- 0 0 Jun 7 12:20:15 2017 .
< 2017-06-07 12:24:39.901 Script: Drwxr-x--- 0 0 Jan 11 19:50:14 2017 ..
< 2017-06-07 12:24:39.901 Script: -rwxr-x--- 0 521220 Jun 7 12:20:15 2017 LiveEmployeeList.csv
< 2017-06-07 12:24:39.901 Script: Drwxr-x--- 0 0 Jun 7 12:20:15 2017 New
> 2017-06-07 12:24:39.901 Script: exit
. 2017-06-07 12:24:39.901 Script: Exit code: 0
. 2017-06-07 12:24:39.901 Closing connection.
. 2017-06-07 12:24:39.901 Sending special code: 12
. 2017-06-07 12:24:39.901 Sent EOF message
After Restarting the service the following is section 2 of the log:
. 2017-06-07 12:41:21.212 Using SFTP protocol.
. 2017-06-07 12:41:21.212 Doing startup conversation with host.
> 2017-06-07 12:41:21.212 Type: SSH_FXP_INIT, Size: 5, Number: -1
< 2017-06-07 12:41:21.227 Type: SSH_FXP_VERSION, Size: 5, Number: -1
. 2017-06-07 12:41:21.227 SFTP version 4 negotiated.
. 2017-06-07 12:41:21.227 We will use UTF-8 strings as it is mandatory with SFTP version 4 and newer
. 2017-06-07 12:41:21.227 Getting current directory name.
. 2017-06-07 12:41:21.227 Getting real path for '.'
> 2017-06-07 12:41:21.227 Type: SSH_FXP_REALPATH, Size: 10, Number: 16
< 2017-06-07 12:41:21.274 Type: SSH_FXP_NAME, Size: 23, Number: 16
. 2017-06-07 12:41:21.274 Real path is '/'
. 2017-06-07 12:41:21.274 Startup conversation with host finished.
< 2017-06-07 12:41:21.274 Script: Active session: [1] xxxxxxxxxxxxxxxxxxxx@xxxxxxxxxxxxxxxx
> 2017-06-07 12:41:21.594 Script: pwd
< 2017-06-07 12:41:21.594 Script: /
> 2017-06-07 12:41:21.735 Script: rm -- "live/LiveEmployeeList/LiveEmployeeList.csv"
. 2017-06-07 12:41:21.735 Listing file "live/LiveEmployeeList/LiveEmployeeList.csv".
> 2017-06-07 12:41:21.735 Type: SSH_FXP_LSTAT, Size: 56, Number: 263
< 2017-06-07 12:41:21.797 Type: SSH_FXP_ATTRS, Size: 46, Number: 263
. 2017-06-07 12:41:21.797 LiveEmployeeList.csv;-;521220;2017-06-07T11:40:15.000Z;"" [0];"" [0];rwxr-x---;0
. 2017-06-07 12:41:21.797 Deleting file "live/LiveEmployeeList/LiveEmployeeList.csv".
> 2017-06-07 12:41:21.797 Type: SSH_FXP_REMOVE, Size: 52, Number: 525
< 2017-06-07 12:41:21.828 Type: SSH_FXP_STATUS, Size: 17, Number: 525
< 2017-06-07 12:41:21.828 Status code: 0
< 2017-06-07 12:41:21.828 Script: live/LiveEmployeeList/LiveEmployeeList.csv
> 2017-06-07 12:41:21.875 Script: exit
. 2017-06-07 12:41:21.875 Script: Exit code: 0
. 2017-06-07 12:41:21.875 Closing connection.
. 2017-06-07 12:41:21.875 Sending special code: 12
. 2017-06-07 12:41:21.875 Sent EOF message
Could you please see from both logs what could have happened when restarting the service? would you suggest a bug in WinSCP or in BizTalk? Please note that this service runs every minute and checks the existence of files on the SFTP server
Regards, Maz