reflect backup running twice


Author
Message
Rob Latour
Rob Latour
New Member
New Member (8 reputation)New Member (8 reputation)New Member (8 reputation)New Member (8 reputation)New Member (8 reputation)New Member (8 reputation)New Member (8 reputation)New Member (8 reputation)New Member (8 reputation)
Group: Forum Members
Posts: 7, Visits: 18
It appears my nightly Reflect backups are running twice.

However, it is defined in Reflect to only run once, every day at 2 pm.  This matches what I see in task scheduler.  

I have just turned history on in task scheduler, so I won't know until tomorrow what it says - but the last run time according to task scheduler is 2:02:40 am.

Oddly on my qnap server, where the backup it written to, the time stamps on the two files most recently created are as follows:

date created  2017-05-09 1:00 am  date modified 2017-05-09 1:53 am
and 
date created  2017-05-09 2:03 am  date modified 2017-05-09 2:54 am

I have no tasks scheduled to run at 1:00 am

I checked the system time on my qnap sever at it is the same as the host windows machine doing the backups.

Of note, I have Reflect set up to retain 7 backup files.  I first noticed a couple days ago and deleted some of the duplicate backups.  I now have seven backup files - but the last two (as noted above) are for the same date.

Running Windows 10 version 1703 (OS build 15063.250) 64bit

Any help would be appreciated.










Edited 9 May 2017 12:12 PM by Rob Latour
jphughan
jphughan
Macrium Evangelist
Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)
Group: Forum Members
Posts: 3.6K, Visits: 27K
Short Answer:
To determine whether a backup is in fact running twice, check the backup date timestamps within Reflect for those files (under the Restore tab) and/or check your Reflect logs. Do NOT rely on Date Created/Modified timestamps within Windows, since for Reflect files those will not always correspond to the date that the backup contained within the file was performed.

Long Answer:
There are occasions where Reflect will need to modify earlier backup files after a job runs, which will cause the Date Modified timestamp in Windows to change to something close to the date of the most recently executed backup. For example, in an Incrementals Forever with Synthetic Fulls strategy, every time a consolidation happens between the root Full and oldest Incremental, the Date Modified timestamp of the root Full would change to the date of the most recent backup since that's when the file was modified, even though the actual backup it contains would be the oldest in the entire set. Additionally, if you're using synthetic fulls and NOT using Delta Incremental indexes, this consolidation will mean that every Incremental built off of that Full will need its index updated to reflect the revised contents of the Full at the root of the set, so you can end up with ALL of the files in your set having a Date Modified timestamp corresponding to the date of the most recent backup. And if that wasn't enough, the Date CREATED timestamp on the synthetic Full itself will always remain as the date of the first Full you captured, even though these consolidations mean that it won't contain data from that far back anymore. This is why it's best to look at the date within Reflect, or by right-clicking a file, selecting Properties, and looking at the Macrium Reflect tab. Hopefully this helps! Smile

Also note that if you feel the need to manually delete backups, you should do so from within Reflect since it will make sure you don't delete anything in a way that would break an existing backup chain and therefore invalidate your set. And as you can probably tell by now, deleting files based on their Windows timestamp will not always guarantee that you are deleting only the oldest/newest backups anyway.

If you still have questions, it would be helpful to post the full details of your backup schedule and retention policy, and perhaps the log file from the date that you suspect a backup ran twice.  Lastly, just as an fyi, the system time on the NAS would not affect the timestamps you see when viewing files from Windows.  The only clocks that affect those figures are the ones on the system that created and/or last modified the file and on the system being used to view it later.

Edited 9 May 2017 3:30 PM by jphughan
Mark R
Mark R
New Member
New Member (4 reputation)New Member (4 reputation)New Member (4 reputation)New Member (4 reputation)New Member (4 reputation)New Member (4 reputation)New Member (4 reputation)New Member (4 reputation)New Member (4 reputation)
Group: Awaiting Activation
Posts: 4, Visits: 16
 I also sometimes get two incrementals (same windows time stamp) - one based off the current full backup, and one based on the previous full backup from a month ago.
http://forum.macrium.com/uploads/images/4e291ead-9f61-49dd-a829-d929.png
http://forum.macrium.com/uploads/images/90b2aa70-2e15-482d-88a5-39fb.png
http://forum.macrium.com/uploads/images/17eb82bb-7cdc-4c1f-9d98-d16e.png

I can see from Macrium's time stamp in properties that you definitely do not want to manually delete it from the backup drive.
jphughan
jphughan
Macrium Evangelist
Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)
Group: Forum Members
Posts: 3.6K, Visits: 27K
Well those two Incrementals have the same Date Modified timestamps, but the Reflect tab clearly shows that they were actually captured a month apart, so you didn't actually get two Incrementals at the same time.  You'd have to look at Reflect logs for jobs that occurred on May 9 (or maybe May 8th that completed in the wee hours of May 9) to see what might have caused the backup captured on April 9 to be modified on May 9.  My guess is that the job that's generating backups for the Disk ID beginning A1CC is running either Synthetic Full or Incremental Merge.  Either way, the logs from May 8th or 9th pertaining to the job for the A1CC set would say something about a consolidation operation.

Edited 9 May 2017 5:02 PM by jphughan
Mark R
Mark R
New Member
New Member (4 reputation)New Member (4 reputation)New Member (4 reputation)New Member (4 reputation)New Member (4 reputation)New Member (4 reputation)New Member (4 reputation)New Member (4 reputation)New Member (4 reputation)
Group: Awaiting Activation
Posts: 4, Visits: 16
Log from 5/9/2017 shows a consolidation process as you correctly surmised... Thank You!

http://forum.macrium.com/uploads/images/10c9e517-5952-40d2-b249-1112.png 
jphughan
jphughan
Macrium Evangelist
Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)
Group: Forum Members
Posts: 3.6K, Visits: 27K
Awesome! Smile  But yeah this is a textbook case of why you wouldn't want to delete files based on their Windows timestamp, because that 05-05.mrimg file despite having a very recent Date Modified timestamp is actually the oldest Incremental in the set, so manually deleting that file would destroy your entire backup chain except for the Full that the old Incremental itself is based on.

Edited 9 May 2017 6:33 PM by jphughan
Rob Latour
Rob Latour
New Member
New Member (8 reputation)New Member (8 reputation)New Member (8 reputation)New Member (8 reputation)New Member (8 reputation)New Member (8 reputation)New Member (8 reputation)New Member (8 reputation)New Member (8 reputation)
Group: Forum Members
Posts: 7, Visits: 18
Thank you ... but backup dates and times do seem to align inside and outside of Reflect.
Here is what I am seeing inside reflect

http://forum.macrium.com/uploads/images/1b13ce02-31f1-4159-86ea-5488.jpg
http://forum.macrium.com/uploads/images/70897bf4-e3b4-4b88-ba2f-684e.jpg

Also, both backups are full, with the second backup starting for no apparent reason after the first completed.

With task scheduler history on l'll see what happens overnight and update this post. 


jphughan
jphughan
Macrium Evangelist
Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)
Group: Forum Members
Posts: 3.6K, Visits: 27K
The different Image IDs indicate that those are two completely different jobs presumably controlled by two different definition files, so my consolidation theory wouldn't apply.  But you don't have to wait for Task Scheduler history.  Go to the Logs tab within Reflect and see what jobs executed.  The image ID shown in those file names will also be included in the log, and that same log will show the path to the definition file that triggered the backup to run.  You can also check the Scheduled Backups tab to see what jobs are scheduled to run next before they actually do.

Edited 9 May 2017 11:36 PM by jphughan
jphughan
jphughan
Macrium Evangelist
Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)Macrium Evangelist (5.3K reputation)
Group: Forum Members
Posts: 3.6K, Visits: 27K
The only other possible cause I can think of would be if you have a single definition file that specifies that you want to capture images of two different physical disks.  I haven't tested that scenario, but I believe in that case Reflect will indeed split those out into separate image files so that disks can be restored independently of each other.
Edited 9 May 2017 11:36 PM by jphughan
Rob Latour
Rob Latour
New Member
New Member (8 reputation)New Member (8 reputation)New Member (8 reputation)New Member (8 reputation)New Member (8 reputation)New Member (8 reputation)New Member (8 reputation)New Member (8 reputation)New Member (8 reputation)
Group: Forum Members
Posts: 7, Visits: 18
Ok - so I went to the logs tab, the two jobs are both shown; each has the same Backup Definition File:

Macrium Reflect Log
c:\reflect backup control files\daily backup to homesever.xml

Yes, the backup is designed to backup both my c: and e: drives - however, both backups seem to be very close in size:
http://forum.macrium.com/uploads/images/69861353-15e0-4215-a770-6c5d.jpg

when in real life one drive has twice the capacity as the other (one is 237.5 gb and the other 465.6 gb) and both contain significantly different amounts of data (157.7 gb of data vs 247.7 gb of data).

Here is the content of the logs:

Log 1: 


Macrium Reflect Log
Image ID - F0B6DB549E89EF6C

Imaging Summary

Backup Definition File:c:\reflect backup control files\daily backup to homesever.xml
Auto Verify:N
Maximum File Size:Automatic
Compression:Medium
Password:N
Intelligent Copy:Y
Power Saving:N
Email On Success:N
Email On Failure:N
Total Selected:405.20 GB

Destination:
Backup Type:Full
File Name:\\HOMESERVER\home\Daily Backups\F0B6DB549E89EF6C-00-00.mrimg
Attempting to connect to: '\\HOMESERVER\home\Daily Backups'
Successfully connected

Operation 1 of 7
Hard Disk:1
Drive Letter:N/A
File System:NTFS
Label:Recovery
Size:300.0 MB
Free:60.3 MB
Used:239.7 MB

Operation 2 of 7
Hard Disk:1
Drive Letter:N/A
File System:FAT32 (LBA)
Label:NO NAME
Size:95.0 MB
Free:61.5 MB
Used:33.5 MB

Operation 3 of 7
Hard Disk:1
Drive Letter:N/A
File System:Unformatted
Label:
Size:128.0 MB
Free:0 B
Used:128.0 MB

Operation 4 of 7
Hard Disk:1
Drive Letter:C
File System:NTFS
Label:Internal_Programs
Size:237.52 GB
Free:80.91 GB
Used:156.61 GB

Operation 5 of 7
Hard Disk:1
Drive Letter:N/A
File System:NTFS
Label:
Size:450.0 MB
Free:70.7 MB
Used:379.3 MB

Operation 6 of 7
Hard Disk:3
Drive Letter:N/A
File System:Unformatted
Label:
Size:128.0 MB
Free:0 B
Used:128.0 MB

Operation 7 of 7
Hard Disk:3
Drive Letter:E
File System:NTFS
Label:Internal_Data
Size:465.63 GB
Free:217.93 GB
Used:247.70 GB

Starting Image - Tuesday, May 09, 2017 02:03:06
Initializing
Destination Drive:Free Space 1.03 TB
Free space threshold:Delete oldest backup sets when free space is less than 500.00 GB
Creating Volume Snapshot - Please Wait
Volume Snapshots Created
Analyzing file system on volume
Analyzing file system on volume
Analyzing file system on volume C:
Analyzing file system on volume
Analyzing file system on volume E:

Saving Partition - Recovery
Reading File System Bitmap
Saving Partition

Saving Partition - NO NAME
Reading File System Bitmap
Saving Partition

Saving Partition -
Reading File System Bitmap
Saving Partition

Saving Partition - Internal_Programs (CSmile
Reading File System Bitmap
Saving Partition

Saving Partition -
Reading File System Bitmap
Saving Partition

Saving Partition -
Reading File System Bitmap
Saving Partition

Saving Partition - Internal_Data (ESmile
Reading File System Bitmap
Saving Partition

Saving Index
New File: 278 GBF0B6DB549E89EF6C-00-00.mrimg

Retention Rules
Rules will be applied to all matching backup sets in the destination folder
Full:Retain 7 full images
Linked incremental and differential images will also be deleted
Backup Sets:8 sets found
Delete File:\\HOMESERVER\home\Daily Backups\946156C73AFCFDEC-00-00.mrimg

Image Completed Successfully in 00:50:57

I/O Performance:Read 3.2 Gb/s - Write 816.9 Mb/s



Log 2:

Macrium Reflect Log
Image ID - E829BB7303AAEBF3

Imaging Summary

Backup Definition File:c:\reflect backup control files\daily backup to homesever.xml
Auto Verify:N
Maximum File Size:Automatic
Compression:Medium
Password:N
Intelligent Copy:Y
Power Saving:N
Email On Success:N
Email On Failure:N
Total Selected:405.08 GB

Destination:
Backup Type:Full
File Name:\\HOMESERVER\home\Daily Backups\E829BB7303AAEBF3-00-00.mrimg
Attempting to connect to: '\\HOMESERVER\home\Daily Backups'
Successfully connected
Successfully connected: User admin

Operation 1 of 7
Hard Disk:1
Drive Letter:N/A
File System:NTFS
Label:Recovery
Size:300.0 MB
Free:60.3 MB
Used:239.7 MB

Operation 2 of 7
Hard Disk:1
Drive Letter:N/A
File System:FAT32 (LBA)
Label:NO NAME
Size:95.0 MB
Free:61.5 MB
Used:33.5 MB

Operation 3 of 7
Hard Disk:1
Drive Letter:N/A
File System:Unformatted
Label:
Size:128.0 MB
Free:0 B
Used:128.0 MB

Operation 4 of 7
Hard Disk:1
Drive Letter:C
File System:NTFS
Label:Internal_Programs
Size:237.52 GB
Free:81.03 GB
Used:156.49 GB

Operation 5 of 7
Hard Disk:1
Drive Letter:N/A
File System:NTFS
Label:
Size:450.0 MB
Free:70.7 MB
Used:379.3 MB

Operation 6 of 7
Hard Disk:3
Drive Letter:N/A
File System:Unformatted
Label:
Size:128.0 MB
Free:0 B
Used:128.0 MB

Operation 7 of 7
Hard Disk:3
Drive Letter:E
File System:NTFS
Label:Internal_Data
Size:465.63 GB
Free:217.93 GB
Used:247.70 GB

Starting Image - Tuesday, May 09, 2017 01:00:42
Initializing
Destination Drive:Free Space 1.30 TB
Free space threshold:Delete oldest backup sets when free space is less than 500.00 GB
Creating Volume Snapshot - Please Wait
Volume Snapshots Created
Analyzing file system on volume
Analyzing file system on volume
Analyzing file system on volume C:
Analyzing file system on volume
Analyzing file system on volume E:

Saving Partition - Recovery
Reading File System Bitmap
Saving Partition

Saving Partition - NO NAME
Reading File System Bitmap
Saving Partition

Saving Partition -
Reading File System Bitmap
Saving Partition

Saving Partition - Internal_Programs (CSmile
Reading File System Bitmap
Saving Partition

Saving Partition -
Reading File System Bitmap
Saving Partition

Saving Partition -
Reading File System Bitmap
Saving Partition

Saving Partition - Internal_Data (ESmile
Reading File System Bitmap
Saving Partition

Saving Index
New File: 278 GBE829BB7303AAEBF3-00-00.mrimg

Retention Rules
Rules will be applied to all matching backup sets in the destination folder
Full:Retain 7 full images
Linked incremental and differential images will also be deleted
Backup Sets:7 sets found
Nothing to delete

Image Completed Successfully in 00:53:06

I/O Performance:Read 3.2 Gb/s - Write 780.1 Mb/s


Edited 10 May 2017 1:26 AM by Rob Latour
GO

Merge Selected

Merge into selected topic...



Merge into merge target...



Merge into a specific topic ID...




Similar Topics

Reading This Topic

Login

Explore
Messages
Mentions
Search