Forum » Support and Bug Reports »

Post a reply

Before posting, please read how to report bug or request support effectively.

Bug reports without an attached log file are usually useless.

Options
Add an Attachment

If you do not want to add an Attachment to your Post, please leave the Fields blank.

(maximum 10 MB; please compress large files; only common media, archive, text and programming file formats are allowed)

Options

Topic review

martin

Re: Batch File Command exits before uploading files via ftp after lengthy batch file

There is some issue with logging information while opening a session in scripting. That's the reason why the log seems to truncated:
https://winscp.net/tracker/1956

Though, the root cause of your problem is that your script open command is just wrong: 
open ftp://Path@site.com:Password\GOES16Web_video\FINAL\GOES24Hours.mp4" /GOES16DATA/

Compare with the meaningful command in your other session: 
open ftp://Path@site.com:***@username.com
creinemann

Batch File Command exits before uploading files via ftp after lengthy batch file

I have windows batch file that uses imagemagick and some other software to create timed animations of geostationary satellite imagery. As the last line of the file, I am using this to upload and rename a video file. 
"C:\Program Files (x86)\WinSCP\WinSCP.exe" "/log=C:\Users\crein\Documents\WinSCPusradioguy.log" /loglevel=1 /ini=nul /command "open ftp://Path@site.com:XXXXXXXX@username.com" "put -latest ""F:\GOES16Web_video\FINAL\GOES24Hours.mp4"" /GOES16DATA/" "mv /GOES16DATA/GOES24Hours.mp4 /GOES16DATA/GOES24Hoursnow.mp4" "exit"

The issue I run into is that it does not upload the file. But rather exits. If I use the exact line in a new batch file all by itself, the WinSCP line runs exactly as intended with no problems. So in summary, the same line at the end of the lengthy batch script does not work, but when run as a single line in a new batch file it works correctly.

This is the resulting log file, the First attempt is at the end of the lengthy batch file, the second attempt is the same line but run in it's own batch file. Any thoughts? 
. 2021-03-13 10:25:01.306 --------------------------------------------------------------------------
. 2021-03-13 10:25:01.306 WinSCP Version 5.17.5 (Build 10414) (OS 10.0.19041 - Windows 10 Home)
. 2021-03-13 10:25:01.306 Configuration: nul
. 2021-03-13 10:25:01.306 Log level: Debug 1
. 2021-03-13 10:25:01.306 Local account: CARLS-HOME-DESK\crein
. 2021-03-13 10:25:01.306 Working directory: F:\GOES16Web_video\TEMPVIDEO
. 2021-03-13 10:25:01.306 Process ID: 23504
. 2021-03-13 10:25:01.307 Command-line: "C:\Program Files (x86)\WinSCP\WinSCP.exe"  "/log=C:\Users\crein\Documents\WinSCPusername.log" /loglevel=1 /ini=nul /command "open ftp://Path@site.com:Password\GOES16Web_video\FINAL\GOES24Hours.mp4"" /GOES16DATA/" "mv /GOES16DATA/GOES24Hours.mp4 /GOES16DATA/GOES24Hoursnow.mp4" "exit"
. 2021-03-13 10:25:01.307 Switch:    /log=C:\Users\crein\Documents\WinSCPusername.log
. 2021-03-13 10:25:01.307 Switch:    /loglevel=1
. 2021-03-13 10:25:01.307 Switch:    /ini=nul
. 2021-03-13 10:25:01.307 Switch:    /command
. 2021-03-13 10:25:01.307 Parameter: open ftp://Path@site.com:Password\GOES16Web_video\FINAL\GOES24Hours.mp4" /GOES16DATA/
. 2021-03-13 10:25:01.307 Parameter: mv /GOES16DATA/GOES24Hours.mp4 /GOES16DATA/GOES24Hoursnow.mp4
. 2021-03-13 10:25:01.307 Parameter: exit
. 2021-03-13 10:25:01.307 Time zone: Current: GMT-6, Standard: GMT-6 (Central Standard Time), DST: GMT-5 (Central Daylight Time), DST Start: 3/14/2021, DST End: 11/7/2021
. 2021-03-13 10:25:01.307 Login time: Saturday, March 13, 2021 10:25:01
. 2021-03-13 10:25:01.307 --------------------------------------------------------------------------
. 2021-03-13 10:25:01.307 Script: Retrospectively logging previous script records:
> 2021-03-13 10:25:01.307 Script: open ftp://Path@site.com:Password\GOES16Web_video\FINAL\GOES24Hours.mp4" /GOES16DATA/
> 2021-03-13 10:25:01.307 Script: Parameter: ftp://Path@site.com:Password\GOES16Web_video\FINAL\GOES24Hours.mp4 /GOES16DATA/
. 2021-03-13 10:25:01.307 --------------------------------------------------------------------------
. 2021-03-13 10:25:01.307 Session name: Path@site.com (Ad-Hoc site)
. 2021-03-13 10:25:01.307 Host name: username.com (Port: -1)
. 2021-03-13 10:25:01.307 User name: username (Password: No, Key file: No, Passphrase: No)
. 2021-03-13 10:25:01.307 Transfer Protocol: FTP
. 2021-03-13 10:25:01.307 Ping type: Dummy, Ping interval: 30 sec; Timeout: 15 sec
. 2021-03-13 10:25:01.307 Disable Nagle: No
. 2021-03-13 10:25:01.307 Proxy: None
. 2021-03-13 10:25:01.307 Send buffer: 262144
. 2021-03-13 10:25:01.307 UTF: Auto
. 2021-03-13 10:25:01.307 FTPS: None [Client certificate: No]
. 2021-03-13 10:25:01.307 FTP: Passive: Yes [Force IP: Auto]; MLSD: Auto [List all: Auto]; HOST: Auto
. 2021-03-13 10:25:01.307 Local directory: default, Remote directory: /GOES16DATA/, Update: Yes, Cache: Yes
. 2021-03-13 10:25:01.307 Cache directory changes: Yes, Permanent: Yes
. 2021-03-13 10:25:01.307 Recycle bin: Delete to: No, Overwritten to: No, Bin path: 
. 2021-03-13 10:25:01.307 Timezone offset: 0h 0m
. 2021-03-13 10:25:01.307 --------------------------------------------------------------------------
. 2021-03-13 10:27:23.203 --------------------------------------------------------------------------
. 2021-03-13 10:27:23.203 WinSCP Version 5.17.5 (Build 10414) (OS 10.0.19041 - Windows 10 Home)
. 2021-03-13 10:27:23.203 Configuration: nul
. 2021-03-13 10:27:23.203 Log level: Debug 1
. 2021-03-13 10:27:23.203 Local account: CARLS-HOME-DESK\crein
. 2021-03-13 10:27:23.203 Working directory: F:\MAGICK SCRIPTS
. 2021-03-13 10:27:23.203 Process ID: 26520
. 2021-03-13 10:27:23.204 Command-line: "C:\Program Files (x86)\WinSCP\WinSCP.exe"  "/log=C:\Users\crein\Documents\WinSCPusername.log" /loglevel=1 /ini=nul /command "open ftp://Path@site.com:***@username.com" "put -latest ""F:\GOES16Web_video\FINAL\GOES24Hours.mp4"" /GOES16DATA/" "mv /GOES16DATA/GOES24Hours.mp4 /GOES16DATA/GOES24Hoursnow.mp4" "exit"
. 2021-03-13 10:27:23.204 Switch:    /log=C:\Users\crein\Documents\WinSCPusername.log
. 2021-03-13 10:27:23.204 Switch:    /loglevel=1
. 2021-03-13 10:27:23.204 Switch:    /ini=nul
. 2021-03-13 10:27:23.204 Switch:    /command
. 2021-03-13 10:27:23.204 Parameter: open ftp://Path@site.com:Password!@username.com
. 2021-03-13 10:27:23.204 Parameter: put -latest "F:\GOES16Web_video\FINAL\GOES24Hours.mp4" /GOES16DATA/
. 2021-03-13 10:27:23.204 Parameter: mv /GOES16DATA/GOES24Hours.mp4 /GOES16DATA/GOES24Hoursnow.mp4
. 2021-03-13 10:27:23.204 Parameter: exit
. 2021-03-13 10:27:23.204 Time zone: Current: GMT-6, Standard: GMT-6 (Central Standard Time), DST: GMT-5 (Central Daylight Time), DST Start: 3/14/2021, DST End: 11/7/2021
. 2021-03-13 10:27:23.204 Login time: Saturday, March 13, 2021 10:27:23
. 2021-03-13 10:27:23.204 --------------------------------------------------------------------------
. 2021-03-13 10:27:23.204 Script: Retrospectively logging previous script records:
> 2021-03-13 10:27:23.204 Script: open ftp://Path@site.com:***@username.com
> 2021-03-13 10:27:23.204 Script: Parameter: ftp://Path@site.com:***@username.com
. 2021-03-13 10:27:23.204 --------------------------------------------------------------------------
. 2021-03-13 10:27:23.204 Session name: Path@site.com@username.com (Ad-Hoc site)
. 2021-03-13 10:27:23.204 Host name: username.com (Port: 21)
. 2021-03-13 10:27:23.204 User name: Path@site.com (Password: Yes, Key file: No, Passphrase: No)
. 2021-03-13 10:27:23.204 Transfer Protocol: FTP
. 2021-03-13 10:27:23.204 Ping type: Dummy, Ping interval: 30 sec; Timeout: 15 sec
. 2021-03-13 10:27:23.204 Disable Nagle: No
. 2021-03-13 10:27:23.204 Proxy: None
. 2021-03-13 10:27:23.204 Send buffer: 262144
. 2021-03-13 10:27:23.204 UTF: Auto
. 2021-03-13 10:27:23.204 FTPS: None [Client certificate: No]
. 2021-03-13 10:27:23.204 FTP: Passive: Yes [Force IP: Auto]; MLSD: Auto [List all: Auto]; HOST: Auto
. 2021-03-13 10:27:23.204 Local directory: default, Remote directory: home, Update: Yes, Cache: Yes
. 2021-03-13 10:27:23.204 Cache directory changes: Yes, Permanent: Yes
. 2021-03-13 10:27:23.204 Recycle bin: Delete to: No, Overwritten to: No, Bin path: 
. 2021-03-13 10:27:23.204 Timezone offset: 0h 0m
. 2021-03-13 10:27:23.204 --------------------------------------------------------------------------
. 2021-03-13 10:27:23.210 Connecting to username.com ...
. 2021-03-13 10:27:23.399 Connected with username.com. Waiting for welcome message...
< 2021-03-13 10:27:23.466 220---------- Welcome to Pure-FTPd [privsep] [TLS] ----------
< 2021-03-13 10:27:23.466 220-You are user number 3 of 500 allowed.
< 2021-03-13 10:27:23.466 220-Local time is now 09:27. Server port: 21.
< 2021-03-13 10:27:23.466 220-This is a private system - No anonymous login
< 2021-03-13 10:27:23.466 220 You will be disconnected after 15 minutes of inactivity.
> 2021-03-13 10:27:23.466 USER Path@site.com
< 2021-03-13 10:27:23.581 331 User Path@site.com OK. Password required
> 2021-03-13 10:27:23.581 PASS ************
< 2021-03-13 10:27:23.704 230-Your bandwidth usage is restricted
< 2021-03-13 10:27:23.704 230 OK. Current restricted directory is /
> 2021-03-13 10:27:23.704 SYST
< 2021-03-13 10:27:23.834 215 UNIX Type: L8
> 2021-03-13 10:27:23.834 FEAT
< 2021-03-13 10:27:24.351 211-Extensions supported:
< 2021-03-13 10:27:24.351  EPRT
< 2021-03-13 10:27:24.351  IDLE
< 2021-03-13 10:27:24.351  MDTM
< 2021-03-13 10:27:24.352  SIZE
< 2021-03-13 10:27:24.352  MFMT
< 2021-03-13 10:27:24.352  REST STREAM
< 2021-03-13 10:27:24.352  MLST type*;size*;sizd*;modify*;UNIX.mode*;UNIX.uid*;UNIX.gid*;unique*;
< 2021-03-13 10:27:24.352  MLSD
< 2021-03-13 10:27:24.352  AUTH TLS
< 2021-03-13 10:27:24.352  PBSZ
< 2021-03-13 10:27:24.352  PROT
< 2021-03-13 10:27:24.352  UTF8
< 2021-03-13 10:27:24.352  TVFS
< 2021-03-13 10:27:24.352  ESTA
< 2021-03-13 10:27:24.352  PASV
< 2021-03-13 10:27:24.353  EPSV
< 2021-03-13 10:27:24.353  SPSV
< 2021-03-13 10:27:24.353  ESTP
< 2021-03-13 10:27:24.353 211 End.
> 2021-03-13 10:27:24.355 OPTS UTF8 ON
< 2021-03-13 10:27:24.478 200 OK, UTF-8 enabled
. 2021-03-13 10:27:24.478 Connected
. 2021-03-13 10:27:24.480 Got reply 1 to the command 1
. 2021-03-13 10:27:24.480 --------------------------------------------------------------------------
. 2021-03-13 10:27:24.480 Using FTP protocol.
. 2021-03-13 10:27:24.480 Doing startup conversation with host.
> 2021-03-13 10:27:24.480 PWD
< 2021-03-13 10:27:24.584 257 "/" is your current location
. 2021-03-13 10:27:24.584 Got reply 1 to the command 16
. 2021-03-13 10:27:24.585 Getting current directory name.
. 2021-03-13 10:27:24.586 Startup conversation with host finished.
< 2021-03-13 10:27:24.586 Script: Active session: [1] Path@site.com@username.com
. 2021-03-13 10:27:24.586 Session upkeep
> 2021-03-13 10:27:24.586 Script: put -latest "F:\GOES16Web_video\FINAL\GOES24Hours.mp4" /GOES16DATA/
> 2021-03-13 10:27:24.586 Script: Switch:    -latest
> 2021-03-13 10:27:24.586 Script: Parameter: F:\GOES16Web_video\FINAL\GOES24Hours.mp4
> 2021-03-13 10:27:24.586 Script: Parameter: /GOES16DATA/
. 2021-03-13 10:27:24.588 Size of 1 local files/folders calculated as 13850014
. 2021-03-13 10:27:24.588 Copying 1 files/directories to remote directory "/GOES16DATA/" - total size: 13,850,014
. 2021-03-13 10:27:24.588   PrTime: Yes; PrRO: No; Rght: rw-r--r--; PrR: No (No); FnCs: N; RIC: 0100; Resume: S (102400); CalcS: No; Mask: 
. 2021-03-13 10:27:24.588   TM: B; ClAr: No; RemEOF: No; RemBOM: No; CPS: 0; NewerOnly: No; EncryptNewFiles: Yes; ExcludeHiddenFiles: No; ExcludeEmptyDirectories: No; InclM: ; ResumeL: 0
. 2021-03-13 10:27:24.588   AscM: *.*html; *.htm; *.txt; *.php; *.php3; *.cgi; *.c; *.cpp; *.h; *.pas; *.bas; *.tex; *.pl; *.js; .htaccess; *.xtml; *.css; *.cfg; *.ini; *.sh; *.xml
. 2021-03-13 10:27:24.588 File: 'F:\GOES16Web_video\FINAL\GOES24Hours.mp4' [2021-03-13T16:24:50.668Z] [13850014]
. 2021-03-13 10:27:24.588 Copying "F:\GOES16Web_video\FINAL\GOES24Hours.mp4" to remote directory started.
. 2021-03-13 10:27:24.588 Binary transfer mode selected.
. 2021-03-13 10:27:24.589 Starting upload of F:\GOES16Web_video\FINAL\GOES24Hours.mp4
> 2021-03-13 10:27:24.589 CWD /GOES16DATA
< 2021-03-13 10:27:24.711 250 OK. Current directory is /GOES16DATA
> 2021-03-13 10:27:24.711 PWD
< 2021-03-13 10:27:24.798 257 "/GOES16DATA" is your current location
> 2021-03-13 10:27:24.798 TYPE I
< 2021-03-13 10:27:25.505 200 TYPE is now 8-bit binary
> 2021-03-13 10:27:25.505 PASV
< 2021-03-13 10:27:25.600 227 Entering Passive Mode (107,180,1,225,199,44)
> 2021-03-13 10:27:25.602 STOR GOES24Hours.mp4
. 2021-03-13 10:27:25.602 Connecting to X.X.X.X:50988 ...
< 2021-03-13 10:27:25.800 150 Accepted data connection
. 2021-03-13 10:27:25.800 Transfer progress: Transferred: 0, Left: 0:00:00, CPS: 0/s
. 2021-03-13 10:27:26.876 Transfer progress: Transferred: 1,114,112, Left: 0:00:12, CPS: 1,018,300/s
. 2021-03-13 10:27:28.206 Transfer progress: Transferred: 1,638,400, Left: 0:00:18, CPS: 674,154/s
. 2021-03-13 10:27:29.213 Transfer progress: Transferred: 1,638,400, Left: 0:00:25, CPS: 476,223/s
. 2021-03-13 10:27:30.214 Transfer progress: Transferred: 1,638,400, Left: 0:00:33, CPS: 368,137/s
. 2021-03-13 10:27:31.208 Transfer progress: Transferred: 1,638,400, Left: 0:00:40, CPS: 300,039/s
. 2021-03-13 10:27:32.205 Transfer progress: Transferred: 1,671,168, Left: 0:00:47, CPS: 258,317/s
. 2021-03-13 10:27:33.207 Transfer progress: Transferred: 2,113,536, Left: 0:00:41, CPS: 283,169/s
. 2021-03-13 10:27:34.206 Transfer progress: Transferred: 2,555,904, Left: 0:00:37, CPS: 302,108/s
. 2021-03-13 10:27:35.220 Transfer progress: Transferred: 2,899,968, Left: 0:00:35, CPS: 306,047/s
. 2021-03-13 10:27:36.235 Transfer progress: Transferred: 3,506,176, Left: 0:00:30, CPS: 334,367/s
. 2021-03-13 10:27:37.291 Transfer progress: Transferred: 4,128,768, Left: 0:00:35, CPS: 277,107/s
. 2021-03-13 10:27:38.343 Transfer progress: Transferred: 4,915,200, Left: 0:00:27, CPS: 323,123/s
. 2021-03-13 10:27:39.379 Transfer progress: Transferred: 5,832,704, Left: 0:00:19, CPS: 412,338/s
. 2021-03-13 10:27:40.399 Transfer progress: Transferred: 7,077,888, Left: 0:00:12, CPS: 533,911/s
. 2021-03-13 10:27:41.593 Transfer progress: Transferred: 8,454,144, Left: 0:00:08, CPS: 655,927/s
. 2021-03-13 10:27:42.658 Transfer progress: Transferred: 8,896,512, Left: 0:00:07, CPS: 689,654/s
. 2021-03-13 10:27:43.707 Transfer progress: Transferred: 9,404,416, Left: 0:00:06, CPS: 694,369/s
. 2021-03-13 10:27:44.749 Transfer progress: Transferred: 9,994,240, Left: 0:00:05, CPS: 705,256/s
. 2021-03-13 10:27:45.761 Transfer progress: Transferred: 10,633,216, Left: 0:00:04, CPS: 729,664/s
. 2021-03-13 10:27:46.801 Transfer progress: Transferred: 11,452,416, Left: 0:00:03, CPS: 747,617/s
. 2021-03-13 10:27:47.823 Transfer progress: Transferred: 12,599,296, Left: 0:00:01, CPS: 798,119/s
< 2021-03-13 10:27:48.799 226-File successfully transferred
< 2021-03-13 10:27:48.799 226 23.000 seconds (measured here), 0.57 Mbytes per second
> 2021-03-13 10:27:48.799 MFMT 20210313162450 GOES24Hours.mp4
< 2021-03-13 10:27:49.081 213 UTIME OK
. 2021-03-13 10:27:49.081 Upload successful
. 2021-03-13 10:27:49.081 Got reply 1 to the command 4
. 2021-03-13 10:27:49.081 Transfer progress: Transferred: 13,778,944, Left: 0:00:00, CPS: 819,657/s
. 2021-03-13 10:27:49.082 Transfer done: 'F:\GOES16Web_video\FINAL\GOES24Hours.mp4' => '/GOES16DATA/GOES24Hours.mp4' [13850014]
. 2021-03-13 10:27:49.082 Copying finished: Transferred: 13,850,014, Elapsed: 0:00:24, CPS: 817,828/s
. 2021-03-13 10:27:49.082 Session upkeep
> 2021-03-13 10:27:49.082 Script: mv /GOES16DATA/GOES24Hours.mp4 /GOES16DATA/GOES24Hoursnow.mp4
> 2021-03-13 10:27:49.082 Script: Parameter: /GOES16DATA/GOES24Hours.mp4
> 2021-03-13 10:27:49.082 Script: Parameter: /GOES16DATA/GOES24Hoursnow.mp4
. 2021-03-13 10:27:49.082 Listing file "/GOES16DATA/GOES24Hours.mp4".
. 2021-03-13 10:27:49.083 Retrieving file information...
> 2021-03-13 10:27:49.083 MLST /GOES16DATA/GOES24Hours.mp4
< 2021-03-13 10:27:49.300 250-Begin
< 2021-03-13 10:27:49.300  type=file;size=13850014;modify=20210313162450;UNIX.mode=0644;UNIX.uid=6714159;UNIX.gid=6714159;unique=fd04g7860aef; /GOES16DATA/GOES24Hours.mp4
< 2021-03-13 10:27:49.300 250 End.
. 2021-03-13 10:27:49.302 type=file;size=13850014;modify=20210313162450;UNIX.mode=0644;UNIX.uid=6714159;UNIX.gid=6714159;unique=fd04g7860aef; /GOES16DATA/GOES24Hours.mp4
. 2021-03-13 10:27:49.303 Retrieving file information successful
. 2021-03-13 10:27:49.303 Got reply 1 to the command 1024
. 2021-03-13 10:27:49.303 GOES24Hours.mp4;-;13850014;2021-03-13T16:24:50.000Z;3;"6714159" [0];"6714159" [0];rw-r--r--;0
. 2021-03-13 10:27:49.303 Moving file "/GOES16DATA/GOES24Hours.mp4" to "/GOES16DATA/GOES24Hoursnow.mp4".
> 2021-03-13 10:27:49.303 RNFR /GOES16DATA/GOES24Hours.mp4
< 2021-03-13 10:27:49.488 350 RNFR accepted - file exists, ready for destination
> 2021-03-13 10:27:49.488 RNTO /GOES16DATA/GOES24Hoursnow.mp4
< 2021-03-13 10:27:49.853 250 File successfully renamed or moved
. 2021-03-13 10:27:49.853 Got reply 1 to the command 128
< 2021-03-13 10:27:49.853 Script: /GOES16DATA/GOES24Hours.mp4
. 2021-03-13 10:27:49.853 Session upkeep
> 2021-03-13 10:27:49.853 Script: exit
. 2021-03-13 10:27:49.853 Session upkeep
. 2021-03-13 10:27:49.853 Script: Exit code: 0
. 2021-03-13 10:27:49.853 Got reply 1004 to the command 128
. 2021-03-13 10:27:49.855 Disconnected from server

Documentation

Support

Associations

Follow Us