Holly-molly, a unicorn sighting
barrymundi :
Jan 11, 2018
Hi all,
I just recently manually started a delta copy job which has not been run for a while and after the scan the job has initiated a full sync and a log message of "Holly-molly, a unicorn sighting". Is this because I have not run this in a while ? Are the time factors I need to consider for manual delta copy jobs ? I don't believe the source and destination have changed much.
regards
Barry
1
Alex Pankratov :
Jan 11, 2018
Barry,
This was an issue with one of the earlier 78.xx releases. The message itself is shown when a file is processed with delta copying, no modified blocks are found, but the hash of the whole file appears changed. This is something that is exceedingly unlikely to ever happen, hence the unicorn reference.
Please update to a more recent version (
https://bvckup2.com/update) and re-run your backups.
2
barrymundi :
Jan 12, 2018
Thanks Alex,
I was on 17.16, so I upgraded to the latest download 17.17.
When I ran the backup again after the upgrade it did the same thing and sighted the unicorn. Is this because the version changed ?
3
barrymundi :
Jan 12, 2018
typo on the version numbers :-) 78.16 to 78.17
4
Alex Pankratov :
Jan 12, 2018
No, this should not be happening. We'll need to take this to email then. I'll need a bit more details from your setup.
5
barrymundi :
Jan 12, 2018
Thanks for the response, I think I found my unicorn. There was another process “touching” the target file, that was causing the diff in hash. Once I stopped that happening, all good.
Thanks for the help
6
Froggie :
Jan 12, 2018
Not so fast :)
While perusing some LOGs this morning, I, too, have just started seeing some of these (never before, now running 78.17). One of them occurred with a file that was RENAMEd yesterday (nothing more), and the other I have to look at deeper. No new software at play here, just lots of new UNICORNs.
7
Froggie :
Jan 12, 2018
The 2nd one noted occurred on a file which was "archived" yesterday at 1647 EST and flowed off System this morning at appx. 0905 EST.
I guess I should look back to see when all this started! I can't have Unicorns running all about my office like this (they can be very messy)!
8
Froggie :
Jan 12, 2018
Looking back, this started (for me) on 11 December. Some of the files are disk images, others are just random occurrences... doesn't seem to be any common denominator. OS (Win7) has been constant as well as installed AV (MSE + Malwarebytes v3).
Don't have a clue yet.
9
Alex Pankratov :
Jan 12, 2018
this started (for me) on 11 December
Can you check which version it happened with and what was the last version before that that didn't have this problem?
This will be in the following part of the log:
2018.01.12 18:30:52 Preparing ...
2018.01.12 18:30:52 Run number: 4
2018.01.12 18:30:52 App: 78.17 <===
10
Froggie :
Jan 12, 2018
Errors started on 11Dec under v78.16 (other dates = Dec. 14th, 15th, 31st & Jan. 4th, 6th, 7th, 9th & 12th) last error this morning under v78.17. Last version to run prior to beginning of error was v78.15
11
Froggie :
Jan 12, 2018
In looking at all these occurences, I noticed an operation, yesterday, where 2-files were simply renamed and on the next backup (1-min interval), one was updated correctly and the 2nd had the Unicorn issue.
Strange... I woulda expected them both to just be an update without issue.
12
Froggie :
Jan 12, 2018
Here are the two LOG entries for the above 2 files in mention...
5. Updating file Documents\Philips 50pfl5601_f7 (Quick Start Guide).pdf
2018.01.11 16:48:17.311 (UTC-5) 3 3 Details
2018.01.11 16:48:17.311 (UTC-5) 3 4 Source: 1.63 MB, created 2017.09.02 09:51:32.375, modified 2017.09.02 09:51:32.596, archived / not-indexed
2018.01.11 16:48:17.311 (UTC-5) 3 5 Raw: 1709300 / 131488374923755913 / 131488374925966039 / 00002020
2018.01.11 16:48:17.311 (UTC-5) 3 4 Backup: 1.63 MB, created 2017.09.02 09:51:32.375, modified 2017.09.02 09:51:32.596, archived / not-indexed
2018.01.11 16:48:17.311 (UTC-5) 3 5 Raw: 1709300 / 131488374923755913 / 131488374925966039 / 00002020
2018.01.11 16:48:17.677 (UTC-5) 3 3 Performance
2018.01.11 16:48:17.677 (UTC-5) 3 4 4.46 MBps / 4672414 bps, 365 ms
2018.01.11 16:48:17.677 (UTC-5) 3 3 Completed in 366 ms, no data copied
2018.01.11 16:48:17.677 (UTC-5) 2 2 6. Updating file Documents\Philips 50pfl5601_f7 (User Manual).pdf
2018.01.11 16:48:17.677 (UTC-5) 3 3 Details
2018.01.11 16:48:17.677 (UTC-5) 3 4 Source: 12.43 MB, created 2017.09.02 09:51:38.455, modified 2017.09.02 09:53:33.657, archived / not-indexed
2018.01.11 16:48:17.677 (UTC-5) 3 5 Raw: 13037535 / 131488374984559390 / 131488376136575282 / 00002020
2018.01.11 16:48:17.677 (UTC-5) 3 4 Backup: 12.43 MB, created 2017.09.02 09:51:38.455, modified 2017.09.02 09:53:33.657, archived / not-indexed
2018.01.11 16:48:17.677 (UTC-5) 3 5 Raw: 13037535 / 131488374984559390 / 131488376136575282 / 00002020
2018.01.11 16:48:17.747 (UTC-5) 2 3 Holly-molly, a Unicorn sighting
2018.01.11 16:48:17.747 (UTC-5) 3 4 Last run: 3b0b715828f90c53d2bf5433c430f7c50f718843
2018.01.11 16:48:17.747 (UTC-5) 3 4 This run: dacabb95604f800ad69bee32de0e8f7e225e76f1
2018.01.11 16:48:17.799 (UTC-5) 3 3 Performance
2018.01.11 16:48:17.799 (UTC-5) 3 4 101.98 MBps / 106936917 bps, 121 ms
2018.01.11 16:48:17.799 (UTC-5) 3 3 Completed in 122 ms, copied in full
13
Froggie :
Jan 12, 2018
In both cases of error (yesterday for in-System backup and today for off-line backup), a ReScan of the destination area was performed as per configuration.
14
Froggie :
Jan 12, 2018
Sorry for all this brain dumping... re: the pair of renamed files mentioned above.
The Unicorn error during the in-System backup yesterday AND the off-line backup today was on the exact same file... very strange.
15
Froggie :
Jan 12, 2018
In-System backup = file01 > file02
Off-System backup = file02 > file03
16
Alex Pankratov :
Jan 12, 2018
Ok, reproduced, isolated and fixed.
The good news is that it's completely benign. It was caused by a flaw in how file blocks were queued for hashing. In some very rare cases they ended up being hashed out of order thus causing the full-file hash to appear different.
Stand by for an update.
17
Froggie :
Jan 13, 2018
Fantastic... great job, Alex!! (I can finally clean up the mess in my office)
18
Alex Pankratov :
Jan 15, 2018
OK, the fix is out.
Direct download link for 78.18 is
https://bvckup2.com/update