Duplicati won’t run my run-script-after script. I checked the obvious - that it actually runs when I double-click it (it’s a simple Windows batch file) and that Duplicati is being pointed to the correct file (it is). I ran Duplicati in Profiling log level to see if there was an error anywhere and, nope, all is fine. Nothing in Windows Event Log either.
I have no clue how to debug this since, as I mentioned, I know the script actually runs properly and nothing in Duplicati is telling me why it’s not running it. I have a script I’m running before in run-script-before-required and that works perfectly fine.
How would I debug this? Using beta 2.0.4.5. Thanks.
To tell when such a script runs, relative to Profiling log information, I inserted a timeout 600 at script top, then put it in a backup using the jobs GUI Commandline option. Instead of a delay, I got an error message:
Backup started at 1/7/2019 9:15:29 PM
Checking remote backup ...
Listing remote folder ...
Scanning local files ...
11 files need to be examined (69 bytes) (still counting)
181 files need to be examined (60.41 MB) (still counting)
402 files need to be examined (62.09 MB)
Uploading file (10.81 KB) ...
Checking remote backup ...
Listing remote folder ...
Verifying remote backup ...
Remote backup verification completed
Downloading file (1.43 KB) ...
Downloading file (11.64 KB) ...
Downloading file (15.19 MB) ...
The script "C:\<etc>\append.bat" reported error messages: ERROR: Input redirection is not supported, exiting the process immediately.
Duration of backup: 00:01:05
Remote files: 14
Remote size: 31.87 MB
Total remote quota: 231.42 GB
Available remote quota: 44.38 GB
Files added: 0
Files deleted: 0
Files changed: 0
Data uploaded: 10.81 KB
Data downloaded: 15.20 MB
Backup completed successfully!
Return code: 2
In my profiling log, the error message was between these two lines, and I guess a non-error is a silent event:
2019-01-07 21:16:34 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Controller-RunBackup]: Running Backup took 0:00:01:05.185
2019-01-07 21:16:34 -05 - [Warning-Duplicati.Library.Modules.Builtin.RunScript-StdErrorNotEmpty]: The script "C:\<etc>\append.bat" reported error messages: ERROR: Input redirection is not supported, exiting the process immediately.
2019-01-07 21:16:34 -05 - [Information-Duplicati.Library.Main.Controller-CompletedOperation]: The operation Backup has completed
Maybe your script would have some similar sort of error due to the non-standard I/O environment it runs in?
Do the lines I showed above and below the RunScript appear with no other messages in between?
There have been previous cases where the after-backup reporting (e.g. email) develops a problem.
This could possibly prevent later after-backup processing (such as the script) from actually running.
Can you persuade --run-script-after to run on a small test backup with no other setups for scripting?
For more serious debug on whether the script is touched, you can run Sysinternals Process Monitor.
RunScript doesn’t appear at all nor does a search for my bat file. BTW I’m running a script before which runs successfully and that doesn’t appear in the Profiling log either if that’s relevant.
It’s even weirder; Duplicati only runs part of the script. I added a new section the other day - one line “start xxx.exe” and that’s the part that Duplicati ignores. Since I know the script works, this is making me wonder: does Duplicati cache a copy of the script somewhere and, if so, maybe it’s using the old version and not the new version? Or maybe the
Because it makes no sense that Duplicati would somehow “ignore” a single line in a batch file that otherwise runs perfectly does it? I tried renaming the new script to something else and changing the name in run-script-after and that didn’t solve the problem either.
I’ll try Procmon next and see if that explains anything.
Please look for context where RunScript was, as quoted earlier. Do top and bottom exist? What’s in between?
2019-01-07 21:16:34 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Controller-RunBackup]: Running Backup took 0:00:01:05.185
2019-01-07 21:16:34 -05 - [Warning-Duplicati.Library.Modules.Builtin.RunScript-StdErrorNotEmpty]: The script "C:\<etc>\append.bat" reported error messages: ERROR: Input redirection is not supported, exiting the process immediately.
2019-01-07 21:16:34 -05 - [Information-Duplicati.Library.Main.Controller-CompletedOperation]: The operation Backup has completed
The other debug idea in the queue is the simple test. How you proceed is of course up to you, and Procmon certainly is a reasonable next step, especially with the new wrinkle of the modified script not being picked up. Keeping with the simplicity idea, you could also try modifying it to add a less complex clue, e.g. echo redirect.
I doubt it. I think this is the script start, done using Start(ProcessStartInfo). I’m not an expert in all this though.
Improvements for –run-script-before/after options which is new in beta in 2.0.4.5 seems like it may potentially affect the maybe-not-run-at-all (Procmon will say if it tried) case of --run-script-after. I don’t totally understand what it’s trying to do, but I think run might be conditional on numeric result code of the backup, which you can maybe see if you run it using the GUI Commandline option. Or try –run-script-before-required. Ignore naming.
I’ll see what Procmon says then try the other debug with a fake backup and then try running again with Profile debug logging and seeing if the log items you mentioned above appear. I tried the GUI Commandline with Profiling but I could see it was going to take forever and was eating CPU resources (and ultimately crashed Firefox where I was watching it) so that was a bust.
