I have a Java server technology (Ignition by Inductive Automation specifically) that calls a batch file that is meant to use WinSCP to transfer some text files overnight to our customer. It is not working and I am not sure why.
Here is the batch file – actual information has been changed so any typos are not representative of actual batch file. Note that
set sftpPathData=C:\SFTP\Up\Data*.txt.gpg
echo sftpPathData
FOR /F "delims=|" %%I IN ('DIR %sftpPathData% /B /O:D') DO SET NewestDataFile=%%I
echo NewestDataFile is %NewestDataFile%
set filePathData=C:\SFTP\Up\%NewestDataFile%
"C:\Program Files (x86)\WinSCP\WinSCP.exe" SiteName /log=c:\temp\winscp2.log /loglevel=* /privatekey=C:\Keys\key_nopassphrase.ppk /command "open sftp://User:password.url.net:6055/" "cd firstdirectory\secondDirectory\" "put %filePathData%" "close"
exit /b
I call this via a Python (technically Jython) subprocess call and log the stderr, but I don't see any issues there – nothing in my logs the past month come through for the stderr.
In the WinSCP logs this is what I see – I am truncating a lot but showing what I believe is relevant, it logs in and attempts to copy the file over but I see a Status code: 3 whereas previously when it was working this was a Status code: 0.
Logs from this morning -
. 2022-01-07 04:10:02.120 Copying "C:\SFTP\Up\Data01072020.txt.gpg" to remote directory started.
. 2022-01-07 04:10:02.120 Binary transfer mode selected.
. 2022-01-07 04:10:02.120 Opening remote file.
> 2022-01-07 04:10:02.120 Type: SSH_FXP_OPEN, Size: 76, Number: 771
< 2022-01-07 04:10:02.520 Type: SSH_FXP_HANDLE, Size: 10, Number: 771
> 2022-01-07 04:10:02.521 Type: SSH_FXP_WRITE, Size: 4118, Number: 1286
. 2022-01-07 04:10:02.523 16 skipped SSH_FXP_WRITE, SSH_FXP_READ, SSH_FXP_DATA and SSH_FXP_STATUS packets.
> 2022-01-07 04:10:02.523 Type: SSH_FXP_CLOSE, Size: 10, Number: 5636
> 2022-01-07 04:10:02.523 Type: SSH_FXP_SETSTAT, Size: 72, Number: 1033
< 2022-01-07 04:10:02.547 Type: SSH_FXP_STATUS, Size: 49, Number: 1286
< 2022-01-07 04:10:02.561 Type: SSH_FXP_STATUS, Size: 49, Number: 1542
< 2022-01-07 04:10:02.561 Type: SSH_FXP_STATUS, Size: 49, Number: 1798
< 2022-01-07 04:10:02.564 Type: SSH_FXP_STATUS, Size: 49, Number: 2054
< 2022-01-07 04:10:02.565 Type: SSH_FXP_STATUS, Size: 49, Number: 2310
< 2022-01-07 04:10:02.579 Type: SSH_FXP_STATUS, Size: 49, Number: 2566
< 2022-01-07 04:10:02.583 Type: SSH_FXP_STATUS, Size: 49, Number: 2822
< 2022-01-07 04:10:02.586 Type: SSH_FXP_STATUS, Size: 49, Number: 3078
< 2022-01-07 04:10:02.587 Type: SSH_FXP_STATUS, Size: 49, Number: 3334
< 2022-01-07 04:10:02.588 Type: SSH_FXP_STATUS, Size: 49, Number: 3590
< 2022-01-07 04:10:02.588 Type: SSH_FXP_STATUS, Size: 49, Number: 3846
< 2022-01-07 04:10:02.588 Type: SSH_FXP_STATUS, Size: 49, Number: 4102
< 2022-01-07 04:10:02.595 Type: SSH_FXP_STATUS, Size: 49, Number: 4358
< 2022-01-07 04:10:02.601 Type: SSH_FXP_STATUS, Size: 49, Number: 4614
< 2022-01-07 04:10:02.601 Type: SSH_FXP_STATUS, Size: 49, Number: 4870
< 2022-01-07 04:10:02.602 Type: SSH_FXP_STATUS, Size: 49, Number: 5126
< 2022-01-07 04:10:02.602 Type: SSH_FXP_STATUS, Size: 49, Number: 5382
< 2022-01-07 04:10:02.772 Type: SSH_FXP_STATUS, Size: 40, Number: 5636
< 2022-01-07 04:10:02.772 Status code: 0
. 2022-01-07 04:10:02.772 Preserving timestamp [2022-01-07T09:00:01.000Z]
< 2022-01-07 04:10:02.807 Type: SSH_FXP_STATUS, Size: 176, Number: 1033
< 2022-01-07 04:10:02.807 Status code: 3
. 2022-01-07 04:10:02.807 Transfer done: 'C:\SFTP\Up\Data01072020.txt.gpg' [65702]
> 2022-01-07 04:10:02.808 Script: close
. 2022-01-07 04:10:02.808 Closing connection.
. 2022-01-07 04:10:02.808 Sending special code: 12
. 2022-01-07 04:10:02.808 Sent EOF message
When this was working this line -
< 2022-01-07 04:10:02.807 Status code: 3
would appear as
< 2022-01-07 04:10:02.807 Status code: 0
Any help or ability to point me in the right direction is greatly appreciated. I see here https://winscp.net/eng/docs/sftp_codes that 3 means
Permission denied The user does not have sufficient permissions to perform the operation.
The Java server technology that is running as a Windows Service that is calling the batch file is logged in as the Administrator account.
Using the WinSCP GUI directly I am able to drag and drop files to the appropriate remote directory.
I am at a loss. Any information on how to fix this issue or perhaps a different way to do this with WinSCP (send the latest two files in a specific directory with a specific extension to the remote server via WinSCP once a day) would be greatly appreciated.
To me it looks like this issue:
Why is uploaded file not showing in a remote directory or showing with a different name?
The code 3 is most likely a failed attempt to update timestamp of the just uploaded file that was meanwhile deleted/moved. Why it sometimes succeeds and sometimes fails can be just timing issue. Sometimes WinSCP might manage to update the timestamp before the file gets deleted/moved, sometimes not. You may want to disable timestamp update with -nopreservetime switch of the put command.