Scheduled task failing

I have a Windows Server 2003 R2 scheduled task invoking a batch file to upload some files to a vendor.

The batch file is as follows:
"C:\Program Files\WinSCP\WinSCP.exe" /console /script=d:\scripts\my-script.txt /log=d:\logs\my-logfile.log

The script is as follows:

option batch abort
option confirm on
open sftp://ftp-user:My_Passwd123@ftp4.RemoteDomain.com:22 -hostkey="ssh-rsa 1536 01:02:03:04:05:72:f6:71:ac:ab:da:1f:e2:3f:53:2f"
cd in/prod
lcd D:\Projects\AP\FileExport
option transfer binary
put *.*
close
exit

The WinSCP client is configured to store in INI file. We have initially logged on as the user whose context runs the Windows scheduled task, and when logging on the time/date stamp of the .INI file and the %appdata%/winscp.rnd were updated. The script runs fine when manually invoked. I'm concerned that the log file satates "Configuration: HKEY_CURRENT_USER" etc. since of course as a scheduled task, without that user logged on, there is not HKCU hive available for that user.

When we leave it to run by itself, it fails I believe while waiting to accept the host key - it just times out. I've tried increasing the timeout to 90 seconds. It takes 4-5 seconds to authenticate when manually running the batch job.

The log files look like this:

. 2012-06-27 20:05:00.195 --------------------------------------------------------------------------
. 2012-06-27 20:05:00.195 WinSCP Version 4.3.8 (Build 1771) (OS 5.2.3790 Service Pack 2)
. 2012-06-27 20:05:00.195 Configuration: HKEY_CURRENT_USER\Software\Martin Prikryl\WinSCP 2\
. 2012-06-27 20:05:00.195 Local account: OURDOMAIN\ServiceAccount
. 2012-06-27 20:05:00.195 Login time: Wednesday, June 27, 2012 8:05:00 PM
. 2012-06-27 20:05:00.195 --------------------------------------------------------------------------
. 2012-06-27 20:05:00.195 Session name: ftp-user@ftp4.RemoteDomain.com (Ad-Hoc session)
. 2012-06-27 20:05:00.195 Host name: ftp4.RemoteDomain.com (Port: 22)
. 2012-06-27 20:05:00.195 User name: ftp-user (Password: Yes, Key file: No)
. 2012-06-27 20:05:00.195 Tunnel: No
. 2012-06-27 20:05:00.195 Transfer Protocol: SFTP
. 2012-06-27 20:05:00.195 Ping type: -, Ping interval: 30 sec; Timeout: 15 sec
. 2012-06-27 20:05:00.211 Proxy: none
. 2012-06-27 20:05:00.211 SSH protocol version: 2; Compression: No
. 2012-06-27 20:05:00.211 Bypass authentication: No
. 2012-06-27 20:05:00.211 Try agent: Yes; Agent forwarding: No; TIS/CryptoCard: No; KI: Yes; GSSAPI: No
. 2012-06-27 20:05:00.211 Ciphers: aes,blowfish,3des,WARN,arcfour,des; Ssh2DES: No
. 2012-06-27 20:05:00.211 SSH Bugs: -,-,-,-,-,-,-,-,-
. 2012-06-27 20:05:00.211 SFTP Bugs: -,-
. 2012-06-27 20:05:00.211 Return code variable: Autodetect; Lookup user groups: Yes
. 2012-06-27 20:05:00.211 Shell: default
. 2012-06-27 20:05:00.211 EOL: 0, UTF: 2
. 2012-06-27 20:05:00.211 Clear aliases: Yes, Unset nat.vars: Yes, Resolve symlinks: Yes
. 2012-06-27 20:05:00.211 LS: ls -la, Ign LS warn: Yes, Scp1 Comp: No
. 2012-06-27 20:05:00.211 Local directory: default, Remote directory: home, Update: No, Cache: Yes
. 2012-06-27 20:05:00.211 Cache directory changes: Yes, Permanent: Yes
. 2012-06-27 20:05:00.211 DST mode: 1
. 2012-06-27 20:05:00.211 --------------------------------------------------------------------------
. 2012-06-27 20:05:00.211 Looking up host "ftp4.RemoteDomain.com"
. 2012-06-27 20:05:00.461 Connecting to 12.34.56.19 port 22
. 2012-06-27 20:05:00.554 Server version: SSH-2.0-6.0.4.118 SSH Tectia Server
. 2012-06-27 20:05:00.554 Using SSH protocol version 2
. 2012-06-27 20:05:00.554 We claim version: SSH-2.0-WinSCP_release_4.3.8
. 2012-06-27 20:05:05.383 Using Diffie-Hellman with standard group "group1"
. 2012-06-27 20:05:05.383 Doing Diffie-Hellman key exchange with hash SHA-1
. 2012-06-27 20:05:05.554 Host key fingerprint is:
. 2012-06-27 20:05:05.554 ssh-rsa 1536 01:02:03:04:05:72:f6:71:ac:ab:da:1f:e2:3f:53:2f
. 2012-06-27 20:05:05.554 Initialised AES-256 CBC client->server encryption
. 2012-06-27 20:05:05.554 Initialised HMAC-SHA1 client->server MAC algorithm
. 2012-06-27 20:05:05.554 Initialised AES-256 CBC server->client encryption
. 2012-06-27 20:05:05.554 Initialised HMAC-SHA1 server->client MAC algorithm
! 2012-06-27 20:05:05.851 Using username "ftp-user".
. 2012-06-27 20:05:20.852 Waiting for data timed out, asking user what to do.
. 2012-06-27 20:05:20.852 Asking user:
. 2012-06-27 20:05:20.852 Host is not communicating for 15 seconds.
. 2012-06-27 20:05:20.852
. 2012-06-27 20:05:20.852 Wait for another 15 seconds? ()
. 2012-06-27 20:05:20.852 Attempt to close connection due to fatal exception:
* 2012-06-27 20:05:20.852 Terminated by user.
. 2012-06-27 20:05:20.852 Closing connection.
. 2012-06-27 20:05:20.852 Sending special code: 12

Further information: When it works, the log files show that I'm using an *.ini configuration. Yet I did nothing to change it. I'm currently rounding up my coworkers to accuse them of having changed this setting in the GUI - > Preferences > Storage > Windows Registry vs INI file.

2012-06-27 09:42:41.747 WinSCP Version 4.3.8 (Build 1771) (OS 5.2.3790 Service Pack 2)
. 2012-06-27 09:42:41.747 Configuration: d:\scripts\upload-innovate.ini
. 2012-06-27 09:42:41.747 Local account: Domain\ServiceAccount
. 2012-06-27 09:42:41.747 Login time: Wednesday, June 27, 2012 9:42:41 AM
. 2012-06-27 09:42:41.747 --------------------------------------------------------------------------

All right, I've updated the batch file that calls the script, to include the path to the INI file:

Calling .bat file:
The batch file is as follows:
"C:\Program Files\WinSCP\WinSCP.exe" /console /ini=d:\scripts\my-script.ini /script=d:\scripts\my-script.txt /log=d:\logs\my-logfile.log

And the script still hangs. Here is the log output:


. 2012-06-28 17:05:00.209 --------------------------------------------------------------------------
. 2012-06-28 17:05:00.209 WinSCP Version 4.3.8 (Build 1771) (OS 5.2.3790 Service Pack 2)
. 2012-06-28 17:05:00.209 Configuration: d:\scripts\my-script.ini
. 2012-06-28 17:05:00.209 Local account: OURDOMAIN\ServiceAccount
. 2012-06-28 17:05:00.209 Login time: Thursday, June 28, 2012 5:05:00 PM
. 2012-06-28 17:05:00.209 --------------------------------------------------------------------------
. 2012-06-28 17:05:00.209 Session name: ftp-user@ftp4.RemoteDomain.com (Ad-Hoc session)
. 2012-06-28 17:05:00.209 Host name: ftp4.RemoteDomain.com (Port: 22)
. 2012-06-28 17:05:00.209 User name: ftp-user (Password: Yes, Key file: No)
. 2012-06-28 17:05:00.209 Tunnel: No
. 2012-06-28 17:05:00.209 Transfer Protocol: SFTP
. 2012-06-28 17:05:00.209 Ping type: -, Ping interval: 30 sec; Timeout: 15 sec
. 2012-06-28 17:05:00.209 Proxy: none
. 2012-06-28 17:05:00.209 SSH protocol version: 2; Compression: No
. 2012-06-28 17:05:00.209 Bypass authentication: No
. 2012-06-28 17:05:00.209 Try agent: Yes; Agent forwarding: No; TIS/CryptoCard: No; KI: Yes; GSSAPI: No
. 2012-06-28 17:05:00.209 Ciphers: aes,blowfish,3des,WARN,arcfour,des; Ssh2DES: No
. 2012-06-28 17:05:00.209 SSH Bugs: -,-,-,-,-,-,-,-,-
. 2012-06-28 17:05:00.209 SFTP Bugs: -,-
. 2012-06-28 17:05:00.209 Return code variable: Autodetect; Lookup user groups: Yes
. 2012-06-28 17:05:00.209 Shell: default
. 2012-06-28 17:05:00.209 EOL: 0, UTF: 2
. 2012-06-28 17:05:00.209 Clear aliases: Yes, Unset nat.vars: Yes, Resolve symlinks: Yes
. 2012-06-28 17:05:00.209 LS: ls -la, Ign LS warn: Yes, Scp1 Comp: No
. 2012-06-28 17:05:00.209 Local directory: default, Remote directory: home, Update: No, Cache: Yes
. 2012-06-28 17:05:00.209 Cache directory changes: Yes, Permanent: Yes
. 2012-06-28 17:05:00.209 DST mode: 1
. 2012-06-28 17:05:00.209 --------------------------------------------------------------------------
. 2012-06-28 17:05:00.209 Looking up host "ftp4.RemoteDomain.com"
. 2012-06-28 17:05:00.397 Connecting to 209.166.136.19 port 22
. 2012-06-28 17:05:00.506 Server version: SSH-2.0-6.0.4.118 SSH Tectia Server
. 2012-06-28 17:05:00.506 Using SSH protocol version 2
. 2012-06-28 17:05:00.506 We claim version: SSH-2.0-WinSCP_release_4.3.8
. 2012-06-28 17:05:05.241 Using Diffie-Hellman with standard group "group1"
. 2012-06-28 17:05:05.241 Doing Diffie-Hellman key exchange with hash SHA-1
. 2012-06-28 17:05:05.428 Host key fingerprint is:
. 2012-06-28 17:05:05.428 ssh-rsa 1536 01:02:03:04:05:72:f6:71:ac:ab:da:1f:e2:3f:53:2f
. 2012-06-28 17:05:05.428 Initialised AES-256 CBC client->server encryption
. 2012-06-28 17:05:05.428 Initialised HMAC-SHA1 client->server MAC algorithm
. 2012-06-28 17:05:05.428 Initialised AES-256 CBC server->client encryption
. 2012-06-28 17:05:05.428 Initialised HMAC-SHA1 server->client MAC algorithm
! 2012-06-28 17:05:05.663 Using username "ftp-user".
. 2012-06-28 17:05:20.663 Waiting for data timed out, asking user what to do.
. 2012-06-28 17:05:20.663 Asking user:
. 2012-06-28 17:05:20.663 Host is not communicating for 15 seconds.
. 2012-06-28 17:05:20.663
. 2012-06-28 17:05:20.663 Wait for another 15 seconds? ()
. 2012-06-28 17:05:20.663 Attempt to close connection due to fatal exception:
* 2012-06-28 17:05:20.663 Terminated by user.
. 2012-06-28 17:05:20.663 Closing connection.
. 2012-06-28 17:05:20.663 Sending special code: 12

In reviewing the .ini file, I see that it has not been updated since 48 hours ago, so I am not certain how to verify that the host key is cached in there. I am afraid that this may be the issue. I have anonymized the hostnames, etc, but will email the .ini file in its original state if requested.

It's not related to the host key verification.
Have you tried increasing the timeout?

Yes, I've tried up to 90 seconds. When the task is run from the command line, or from the console, it runs in between 4 and 5 seconds every time. Changing timeout to 90 seconds merely makes it keep trying for 90 seconds, and then fails. Thank you.