The support forum

External command executed only when manually started backup job

Yaromil :

Nov 28, 2018

Hey there,

before every schedule of backup job I need to start my NAS, which is done by following command at "Pre-backup" setting:

"cmd /c C:\server\utils\wolnas.bat"

This works fine when I start job manually, but when a job is started automatically during schedule, this won't run and I'm getting error that destination device is missing.

Am I doing anything work or am I overlooking some particular setting?

I'm running latest version of Bvackup 2.

Thanks a lot for any help.

Yaromil :

Nov 28, 2018

* Am I doing anything wrong?

Alex Pankratov :

Nov 28, 2018



There is no difference between running a job manually or having it run on schedule. None. What you are seeing is almost certainly coincidental and it's due to some sort a timing issue.

Check you backup log and see if the command is executed. This will be in the "Running the backup" > Preparing section of it. Most likely it is. Then, check your .bat, add logging to it to trace or just add 'echo on' at the top and then capture the output.

Yaromil :

Nov 29, 2018

Alex, thank You very much for Your response! From the log:

on schechule:
Red error: Backup needs to run, but destination device  is not present
(no more info presented)

manual run:
- everything is done properly

When looking at the main screen there is always under every "backup to NAS"  notice "Waiting for network location"

Backup from: "D:\Apache\"
Backup to: "\\DISKSTATION\backup\d\Apache\"

One thing what I'm now thinking about is that the networkd drive / NAS has no drive "LETTER" attached in Windows and I'm using "\\DISKSTATION".

But again even I agree with You sechudled and manual run should be the same, at lease in my case, there is the difference, tak when running on schedule and missing network drive, backup won't start at all.

Thank You again for Your time!

Jaroslav

Yaromil :

Nov 29, 2018

From log file:

- you can see there ware several days missed backup at 18:00 every day and then I run it manually at "2018.11.28 20:34:34.393"

2018.11.20 08:56:38.906 (UTC+1) 2 0 Destination network share is no longer accessible
2018.11.20 18:00:00.038 (UTC+1) 0 0 Backup needs to run, but destination device is not present
2018.11.20 18:00:00.038 (UTC+1) 3 1     Scheduled time: 2018/11/20 18:00:00.038
2018.11.21 19:16:54.890 (UTC+1) 0 0 Backup needs to run, but destination device is not present
2018.11.21 19:16:54.890 (UTC+1) 3 1     Scheduled time: 2018/11/21 19:16:54.890
2018.11.22 18:00:00.012 (UTC+1) 0 0 Backup needs to run, but destination device is not present
2018.11.22 18:00:00.012 (UTC+1) 3 1     Scheduled time: 2018/11/22 18:00:00.005
2018.11.23 18:00:00.028 (UTC+1) 0 0 Backup needs to run, but destination device is not present
2018.11.23 18:00:00.028 (UTC+1) 3 1     Scheduled time: 2018/11/23 18:00:00.023
2018.11.24 18:00:00.010 (UTC+1) 0 0 Backup needs to run, but destination device is not present
2018.11.24 18:00:00.010 (UTC+1) 3 1     Scheduled time: 2018/11/24 18:00:00.010
2018.11.25 18:00:00.021 (UTC+1) 0 0 Backup needs to run, but destination device is not present
2018.11.25 18:00:00.021 (UTC+1) 3 1     Scheduled time: 2018/11/25 18:00:00.017
2018.11.26 19:32:52.511 (UTC+1) 0 0 Backup needs to run, but destination device is not present
2018.11.26 19:32:52.512 (UTC+1) 3 1     Scheduled time: 2018/11/26 19:32:52.509
2018.11.27 18:27:09.231 (UTC+1) 0 0 Backup needs to run, but destination device is not present
2018.11.27 18:27:09.231 (UTC+1) 3 1     Scheduled time: 2018/11/27 18:27:09.230
2018.11.28 18:00:39.423 (UTC+1) 0 0 Backup needs to run, but destination device is not present
2018.11.28 18:00:39.424 (UTC+1) 3 1     Scheduled time: 2018/11/28 18:00:39.423
2018.11.28 20:34:34.393 (UTC+1) 2 0 Destination network share is accessible
2018.11.28 20:34:34.412 (UTC+1) 2 0 Queued
2018.11.28 20:34:34.412 (UTC+1) 3 1     Position: 1
2018.11.28 20:36:49.382 (UTC+1) 2 0 Running the backup ...
2018.11.28 20:36:49.382 (UTC+1) 2 1     Preparing ...
2018.11.28 20:36:49.382 (UTC+1) 3 2         Run number: 1670
2018.11.28 20:36:49.382 (UTC+1) 3 3             Version: 79.14
2018.11.28 20:36:49.382 (UTC+1) 3 3             Source: C:\server\
2018.11.28 20:36:49.382 (UTC+1) 3 3             Destination: \\DISKSTATION\backup\c\server\
2018.11.28 20:36:49.382 (UTC+1) 3 3             Copying: contents, timestamps (modified, created, accessed), attributes
2018.11.28 20:36:49.382 (UTC+1) 2 2         Running external pre-backup command ...
2018.11.28 20:36:49.384 (UTC+1) 3 3             Command: cmd /c C:\server\utils\wolnas.bat
2018.11.28 20:36:49.384 (UTC+1) 3 4                 Spawn as: process
2018.11.28 20:36:49.384 (UTC+1) 3 4                 Timeout: 1 hour
2018.11.28 20:36:49.384 (UTC+1) 3 4                 Exit code: any
2018.11.28 20:36:49.531 (UTC+1) 3 3             Completed
2018.11.28 20:36:49.531 (UTC+1) 3 4                 Exit code: 0
2018.11.28 20:36:49.531 (UTC+1) 2 2         Verifying configuration ...
2018.11.28 20:36:49.531 (UTC+1) 2 2         Checking source...
2018.11.28 20:36:49.531 (UTC+1) 3 3             Normalized path: \\?\C:\server\
2018.11.28 20:36:49.533 (UTC+1) 2 2         Checking destination...
2018.11.28 20:36:49.533 (UTC+1) 3 3             Normalized path: \\?\UNC\DISKSTATION\backup\c\server\
2018.11.28 20:36:49.556 (UTC+1) 2 2         Checking environment...
2018.11.28 20:36:49.556 (UTC+1) 2 2         Scanning source ...
2018.11.28 20:36:49.576 (UTC+1) 3 3             Excluded: prog\Apache24\logs\error.log
2018.11.28 20:36:49.870 (UTC+1) 3 3             Completed in 314 ms
2018.11.28 20:36:49.870 (UTC+1) 3 4                 1202 folders, 18946 files, 1.54 GB
2018.11.28 20:36:49.870 (UTC+1) 2 2         Loading destination snapshot ...
2018.11.28 20:36:49.907 (UTC+1) 3 3             1202 folders, 18895 files, 1.54 GB
2018.11.28 20:36:49.955 (UTC+1) 2 2         Running archive maintenance ...
2018.11.28 20:36:49.955 (UTC+1) 3 3             Location: \\DISKSTATION\backup\c\server\$Archive (Bvckup 2)\
2018.11.28 20:36:49.966 (UTC+1) 3 3             Scanning...
2018.11.28 20:36:49.967 (UTC+1) 3 4                 Configuration
2018.11.28 20:36:49.967 (UTC+1) 3 5                     Flags 0x00, threads 8, priority -1
2018.11.28 20:36:50.030 (UTC+1) 3 4                 Completed in 64 ms
2018.11.28 20:36:50.030 (UTC+1) 3 5                     6 folders, 2 files, 13 bytes
2018.11.28 20:36:50.030 (UTC+1) 3 3             No items older than 2 weeks
2018.11.28 20:36:50.030 (UTC+1) 3 3             Next maintenance in 1 hour
2018.11.28 20:36:50.030 (UTC+1) 2 2         Deducing changes ...

Yaromil :

Nov 29, 2018

Sorry for another post, but to be more precise, You can see log from 1st backup job in the queue (I have every backup job scheduled to 18:00 everyday), but every backup jot has the same "Pre-backup" command.

2018.11.20 08:56:38.906 (UTC+1) 2 0 Destination network share is no longer accessible
2018.11.20 18:00:00.038 (UTC+1) 0 0 Backup needs to run, but destination device is not present
2018.11.20 18:00:00.038 (UTC+1) 3 1     Scheduled time: 2018/11/20 18:00:00.038
2018.11.21 19:16:54.890 (UTC+1) 0 0 Backup needs to run, but destination device is not present
2018.11.21 19:16:54.890 (UTC+1) 3 1     Scheduled time: 2018/11/21 19:16:54.890
2018.11.22 18:00:00.009 (UTC+1) 0 0 Backup needs to run, but destination device is not present
2018.11.22 18:00:00.011 (UTC+1) 3 1     Scheduled time: 2018/11/22 18:00:00.005
2018.11.23 18:00:00.023 (UTC+1) 0 0 Backup needs to run, but destination device is not present
2018.11.23 18:00:00.027 (UTC+1) 3 1     Scheduled time: 2018/11/23 18:00:00.023
2018.11.24 18:00:00.010 (UTC+1) 0 0 Backup needs to run, but destination device is not present
2018.11.24 18:00:00.010 (UTC+1) 3 1     Scheduled time: 2018/11/24 18:00:00.010
2018.11.25 18:00:00.017 (UTC+1) 0 0 Backup needs to run, but destination device is not present
2018.11.25 18:00:00.021 (UTC+1) 3 1     Scheduled time: 2018/11/25 18:00:00.017
2018.11.26 19:32:52.509 (UTC+1) 0 0 Backup needs to run, but destination device is not present
2018.11.26 19:32:52.510 (UTC+1) 3 1     Scheduled time: 2018/11/26 19:32:52.509
2018.11.27 18:27:09.231 (UTC+1) 0 0 Backup needs to run, but destination device is not present
2018.11.27 18:27:09.231 (UTC+1) 3 1     Scheduled time: 2018/11/27 18:27:09.230
2018.11.28 18:00:39.423 (UTC+1) 0 0 Backup needs to run, but destination device is not present
2018.11.28 18:00:39.423 (UTC+1) 3 1     Scheduled time: 2018/11/28 18:00:39.423
2018.11.28 20:30:49.958 (UTC+1) 2 0 Running the backup ...
2018.11.28 20:30:49.958 (UTC+1) 2 1     Preparing ...
2018.11.28 20:30:49.958 (UTC+1) 3 2         Run number: 1780
2018.11.28 20:30:49.958 (UTC+1) 3 3             Version: 79.14
2018.11.28 20:30:49.958 (UTC+1) 3 3             Source: D:\Apache\
2018.11.28 20:30:49.958 (UTC+1) 3 3             Destination: \\DISKSTATION\backup\d\Apache\
2018.11.28 20:30:49.958 (UTC+1) 3 3             Copying: contents, timestamps (modified, created, accessed), attributes
2018.11.28 20:30:49.958 (UTC+1) 2 2         Running external pre-backup command ...
2018.11.28 20:30:49.962 (UTC+1) 3 3             Command: cmd /c C:\server\utils\wolnas.bat
2018.11.28 20:30:49.962 (UTC+1) 3 4                 Spawn as: process
2018.11.28 20:30:49.962 (UTC+1) 3 4                 Timeout: 1 hour
2018.11.28 20:30:49.962 (UTC+1) 3 4                 Exit code: any
2018.11.28 20:30:50.070 (UTC+1) 3 3             Completed
2018.11.28 20:30:50.070 (UTC+1) 3 4                 Exit code: 0
2018.11.28 20:30:50.070 (UTC+1) 2 2         Verifying configuration ...
2018.11.28 20:30:50.071 (UTC+1) 2 2         Checking source...
2018.11.28 20:30:50.071 (UTC+1) 3 3             Normalized path: \\?\D:\Apache\
2018.11.28 20:30:50.073 (UTC+1) 2 2         Checking destination...
2018.11.28 20:30:50.073 (UTC+1) 3 3             Normalized path: \\?\UNC\DISKSTATION\backup\d\Apache\
2018.11.28 20:30:50.073 (UTC+1) 0 3             Error: destination device is missing
2018.11.28 20:30:50.124 (UTC+1) 2 1     Completed in 169 ms with 1 error
2018.11.28 20:34:34.410 (UTC+1) 2 0 Destination network share is accessible
2018.11.28 20:34:34.412 (UTC+1) 2 0 Running the backup ...
2018.11.28 20:34:34.412 (UTC+1) 2 1     Preparing ...
2018.11.28 20:34:34.412 (UTC+1) 3 2         Run number: 1781
2018.11.28 20:34:34.412 (UTC+1) 3 3             Version: 79.14
2018.11.28 20:34:34.412 (UTC+1) 3 3             Source: D:\Apache\
2018.11.28 20:34:34.412 (UTC+1) 3 3             Destination: \\DISKSTATION\backup\d\Apache\
2018.11.28 20:34:34.412 (UTC+1) 3 3             Copying: contents, timestamps (modified, created, accessed), attributes
2018.11.28 20:34:34.412 (UTC+1) 2 2         Running external pre-backup command ...
2018.11.28 20:34:34.416 (UTC+1) 3 3             Command: cmd /c C:\server\utils\wolnas.bat
2018.11.28 20:34:34.416 (UTC+1) 3 4                 Spawn as: process
2018.11.28 20:34:34.416 (UTC+1) 3 4                 Timeout: 1 hour
2018.11.28 20:34:34.416 (UTC+1) 3 4                 Exit code: any
2018.11.28 20:34:34.548 (UTC+1) 3 3             Completed
2018.11.28 20:34:34.548 (UTC+1) 3 4                 Exit code: 0
2018.11.28 20:34:34.548 (UTC+1) 2 2         Verifying configuration ...
2018.11.28 20:34:34.548 (UTC+1) 2 2         Checking source...
2018.11.28 20:34:34.548 (UTC+1) 3 3             Normalized path: \\?\D:\Apache\
2018.11.28 20:34:34.553 (UTC+1) 2 2         Checking destination...
2018.11.28 20:34:34.553 (UTC+1) 3 3             Normalized path: \\?\UNC\DISKSTATION\backup\d\Apache\
2018.11.28 20:34:34.562 (UTC+1) 2 2         Checking environment...
2018.11.28 20:34:34.562 (UTC+1) 2 2         Scanning source ...
2018.11.28 20:34:42.643 (UTC+1) 3 3             Completed in 8.08 sec
2018.11.28 20:34:42.643 (UTC+1) 3 4                 47886 folders, 260287 files, 11.07 GB
2018.11.28 20:34:42.644 (UTC+1) 2 2         Loading destination snapshot ...
2018.11.28 20:34:43.207 (UTC+1) 3 3             47787 folders, 260020 files, 10.96 GB
2018.11.28 20:34:43.225 (UTC+1) 2 2         Running archive maintenance ...

Yaromil :

Nov 29, 2018

Another think what I'm thinking of is, if in Bvckup there isn't any condidion like:

If destination drive is not present than do not run backup job on schedule. This is not the case when user run when job is run manually.

Alex Pankratov :

Nov 29, 2018



OK, I know what's up.

For backups going to/from a network location the program will monitor if a share is accessible and it will NOT attempt running a backup when the share is unavailable. Hence these log messages:

        Backup needs to run, but destination device is not present

This behavior can be overridden by forcing the program to not wait for the shares to become available. The same is for local devices by the way. This is done by putting an override in place:

        conf.wait_for_src    0
        conf.wait_for_dst    0

Obviously, use the former if it's for the source location, the latter - for destination. See https://bvckup2.com/support/forum/topic/1140 for instructions on how to add an override.

Yaromil :

Nov 29, 2018

Thanks a lot for Your help, Alex, this helped, backup job started, which is awesome, but it cycled itself and keep running everysecond and keep opening "Pre-backup" command. I cancelled it, but I think it will trying till the destination is available.  Any advice with this, please?

Alex Pankratov :

Nov 29, 2018

I can't say anything meaningful based on what you described. I need to see relevant parts of the log.

Yaromil :

Nov 29, 2018

If there is no easy solution at Bvckup setting I believe I can solve it by adding some sleep / pause into the bash file till the NAS is ready, which is in about 3minutes.

Alex Pankratov :

Nov 29, 2018

Ah, OK. Yes, your script needs to wait until your NAS is ready. That's the only way because this 3 minute delay is specific to your setup.

Yaromil :

Nov 29, 2018

Alex, thank You! With Your help I managed to solve this! Thank You!

New topic

Create
Made by Pipemetrics in Switzerland
Support

Follow
Blog / RSS
Social Twitter
Reddit
Miscellanea Press resources
Testimonials
Company
Imprint
Legal Terms
Privacy