The support forum

Just updated to R80 and get many "Missed schedule run..." notices?

DocRoot :

Jun 20, 2019

Hi, I've just updated to R80 (specifically 80.1), after being prompted by the software. However, after installation I'm notified that 6 of my 8 scheduled backup jobs "failed" with "Missed scheduled run N hours ago". The error in the log states "Backup needed to run, but the app wasn't running".

However, the app was running and, according to the email notification I received several hours ago (and indeed earlier in the log) - the scheduled backup job did run successfully?

Is this an expected side effect with updating to R80? But then why are "only" 6 of the 8 jobs affected? There is nothing particularly different with the 2 jobs that don't show this error as far as I can see.

Alex Pankratov :

Jun 20, 2019



Don't have an answer for you. This is not a known issue.

What do the "Missed a run" entries in the log say? They will have the exact expected time of said missed runs.

DocRoot :

Jun 20, 2019

The time of the stated missed run is the exact time when the backup job did actually run (according to the log and email notification).

Extract from the logs (this is a very small backup with just a few files) that shows the backup job completing at the scheduled time and then the later error (immediately after the software update) stating that it didn't:

2019.06.19 19:25:00.044 (UTC+0) 2 0 Running the backup ...
2019.06.19 19:25:00.287 (UTC+0) 2 1     Preparing ...
2019.06.19 19:25:01.249 (UTC+0) 2 1     Processing ...
2019.06.19 19:25:01.330 (UTC+0) 2 1     Updating folder information...
2019.06.19 19:25:01.616 (UTC+0) 2 1     Completed in 1.57 sec with no errors
2019.06.19 19:25:01.616 (UTC+0) 3 2         Read 647 KB, wrote 647 KB, throughput 7.85 MBps / 8236300 bps
2019.06.20 00:15:01.826 (UTC+0) 2 0 Loaded
2019.06.20 00:15:03.684 (UTC+0) 0 0 Backup needed to run, but the app wasn't running
2019.06.20 00:15:03.684 (UTC+0) 3 1     Scheduled time: 2019/06/19 19:25:00.678
2019.06.20 00:15:03.684 (UTC+0) 3 1     Sending email alert...
2019.06.20 00:15:03.693 (UTC+0) 2 0 Device status
2019.06.20 00:15:04.960 (UTC+0) 2 0 Source network share is accessible
2019.06.20 00:15:04.963 (UTC+0) 3 0 Email alert was sent

Alex Pankratov :

Jun 20, 2019



Hmm... yes, that's not right.

Can I take a look at a copy of your %LocalAppData%\Bvckup2\bvckup2.log? Via email to support@pipemetrics.com. If you aren't comfortable sharing it in full, I can explain the bits I need to see.

justbackmeup :

Jun 20, 2019

I saw this too when I upgraded. Just FYI.

Alex Pankratov :

Jun 20, 2019

Do *you* have a log file a can look at? :)

DocRoot :

Jun 20, 2019

Hi Alex, I've emailed you my bvckup2.log file.
Thanks.

justbackmeup :

Jun 20, 2019

Sent as well. :)

swebs :

Jun 21, 2019

I think I saw this too when upgrading from 79 to 80. I think last nights backup worked ok, but when I upgraded the UI said that the previous backup had failed. I'll send my log.

Alex Pankratov :

Jun 24, 2019



Thanks for the logs, gentlemen.

This worked out to be an one-time issue triggered by updating from pre-80 releases. It was caused by the fact that R80 switched from using second-level scheduling to millisecond granularity.

In particular, pre-80 versions scheduled periodic jobs to run on a second boundary, but they also kept milliseconds set in the date/time of the first run. For example, if you at some point set a backup to run daily at 12:00, it might've been recorded internally as 12:00:00.345, whereby 345 came from the original value that is initialized to current time.

The backup would still run at 12:00:00 or thereabouts and this time will be recorded and used to determine the next run, which in turn was used at program's launch to check if any runs were missed.

So in pre-80 releases a job could end up with:

        first_run     2019/01/01  12:00:00.345
        last_run      2019/06/20  12:00:00.023          - the actual run time

Next, comes in release 80 with its ms scheduling precision, looks at first_run and last_run and ends up with

      2019/06/20 12:00:00.345

being the next run (only 300 ms after recorded last_run) => et voila, it looks we missed a run, so it will show the warning.

This is a one-time upgrade issue, so if you already went through this, you are all set. For new upgrades there's a build 80.1.1 and it will take care of this on first run.

New topic

Create
Made by IO Bureau in Switzerland
Support

Updates
Blog / RSS
Follow Twitter
Reddit
Miscellanea Press kit
Testimonials
Company Imprint

Legal Terms
Privacy