Re: fsevents vs backup redundancy

classic Classic list List threaded Threaded
8 messages Options
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: fsevents vs backup redundancy

Doug Hogg
I wonder what would happen if you used Carbon Copy Cloner to.back up your server. There is a free trial.

:-)

Doug Hogg

Sent from my iPhone

> On Jun 26, 2017, at 7:56 PM, gastropod <[hidden email]> wrote:
>
> Some increasingly frequent Chronosync warning messages have made me
> think about backups and all of the parts that need to be redundant, and
> reminded me that some crucial lack of redundancy can be hidden deep
> down.
>
> I use Time Machine, Chronosync and Crashplan for backups. TM and CS both
> run on a 2014 mini running El Capitan server.  Crashplan runs on a Snow
> Leopard mac for historical reasons until I get something better than a
> slow DSL connection.
>
> For the last month or so, Chronosync has been increasingly throwing a
> warning of
>
> "Possible file system event database problems on: "FolderName" on
> "DriveName"
>
> It does this for any of the disks involved, both source and destination.
> The recommended action is to dismount the drive and remount it, or
> reboot if remounting doesn't work.  Since CS runs on my file server,
> it's a real hassle, and often even rebooting doesn't clear it up.  Disk
> Utility never finds a problem.  The 'common causes' of unexpected
> dismounts or kernel panics don't apply, though I've seen a couple of
> reports that journaling can cause fsevents to be somewhat out of date,
> so maybe that's it. The backups seemingly worked just fine despite the
> warning. Saturday I finally went looking at Chronosync techsupport, and
> found a nice technote:
>
> https://www.econtechnologies.com/support/tech-question.php?p=1&t=2&q=6
>
> They have a SmartScan feature (on by default) that uses the fsevents
> database to limit where on the disk they check for changes, which can
> speed things up quite a bit.  If they detect the fsevents database out
> of sync warning, they pass the warning into the log, then do a
> check-all-the-files scan instead of a SmartScan.  So the backups are
> still done properly, but possibly more slowly.
>
> Time Machine also uses the fsevents database to know what to back up.  I
> don't see any errors or warnings in the logs for backupd, and I have no
> idea how TM handles things.  Whether the TM backups are being done
> completely correctly I don't know, and I don't know a simple way to find
> out; spot checks are too limited.  Crashplan doesn't use fsevents at
> all--it pays attention to the file directory and disk blocks (only
> changed blocks are backed up).  Even if Chronosync and Time Machine were
> doing the wrong thing and believing the fsevents database, I'd still
> have redundancy because Crashplan does something completely different.
> Even without Crashplan, I'm ok because Chronosync developers are smart,
> and use fsevents as a hint, not the truth.
>
> It's too easy to think that you have redundant backups because you're
> using two or more different software packages, when really they're
> relying on the exact same underlying software; if that software has bugs
> all of the higher level software will fail in the same way.  I ran into
> this about 10 years ago (on Leopard?), when several backup programs were
> using os x rsync which had some known bugs with metadata, but I'd
> forgotten.  I'm glad that I got reminded in a non-disastrous way.
>
> --
> gastropod
>
>
> ____________TidBITS Talk Participation Guidelines____________
> Post only when you have something substantive to contribute.
> Be polite and constructive, and comment on posts, not people.
> Quote sparingly, if at all. We all read the previous message.
> Start threads with a new message to [hidden email].
> Read archives at: http://tidbits.com/pipermail/tidbits-talk/
> Unsubscribe at: http://tidbits.com/mailman/options/tidbits-talk
> ____Mailing List Manners: http://tidbits.com/series/1141 ____



____________TidBITS Talk Participation Guidelines____________
Post only when you have something substantive to contribute.
Be polite and constructive, and comment on posts, not people.
Quote sparingly, if at all. We all read the previous message.
Start threads with a new message to [hidden email].
Read archives at: http://tidbits.com/pipermail/tidbits-talk/
Unsubscribe at: http://tidbits.com/mailman/options/tidbits-talk
____Mailing List Manners: http://tidbits.com/series/1141 ____
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: fsevents vs backup redundancy

Rodney

On Jun 27, 2017, at 04:56, gastropod <[hidden email]> wrote:

Time Machine also uses the fsevents database to know what to back up.  I
don't see any errors or warnings in the logs for backupd, and I have no
idea how TM handles things.

I don’t know that I have any insight into your particular problem, but maybe I can pass on some stuff that might help to see what’s going on. I apologize in advance if it is stuff you already know.

I had various problems with Time Machine in early 2015 (was it Yosemite back then?) when I got my current iMac. Among them, if I dismounted and remounted an external drive, then the UUID wouldn’t match what was previously associated with the drive, and TM would do a deep scan and ignore fsevents. The big problem was that this would trash my exclusion list. Stuff I didn’t want backed up, such as Parallels VMs, would be backed up, and I’d have to delete the unneeded backed up items manually and recreate my exclusion list. This was a big problem with my new (at the time) Drobo. The solution was to shut down the computer before shutting down the Drobo.

Things have improved a lot in the past two years. I haven’t had many problems, but I still watch TM fairly closely. I used to use a widget called Time Machine Buddy, but it broke a macOS release or two ago. I have cobbled together some command line tools that give me the same information that Time Machine Buddy provided, except a lot more clumsily. I haven’t done much shell scripting in 10+ years.

Here is what I use. Maybe it will help. Since you know about fsevents, I assume that you are comfortable with Terminal. If you have a better way of doing this stuff, I hope you’ll pass it along!

After a bit of googling, I found this command for displaying TM history:

log show --predicate 'subsystem == "com.apple.TimeMachine"' --info | grep 'upd: (' | cut -c 1-19,140-999

It is S-L-O-W. Here is some sample output:

2017-06-27 10:06:12 Starting automatic backup
2017-06-27 10:06:12 Backing up to /dev/disk4s2: /Volumes/Time Machine/Backups.backupdb
2017-06-27 10:06:14 Will copy (30.5 MB) from Macintosh HD
2017-06-27 10:06:14 Will copy (Zero KB) from Drobo
2017-06-27 10:06:14 Found 510 files (30.5 MB) needing backup
2017-06-27 10:06:14 5.31 GB required (including padding), 4.76 TB available
2017-06-27 10:06:37 Copied 562 items (30.6 MB) from volume Macintosh HD. Linked 4962.
2017-06-27 10:06:38 Copied 2 items (Zero KB) from volume Drobo. Linked 14.
2017-06-27 10:06:39 Created new backup: 2017-06-27-100638
2017-06-27 10:06:40 Starting post-backup thinning
2017-06-27 10:06:40 No post-backup thinning needed: no expired backups exist
2017-06-27 10:06:40 Backup completed successfully.
2017-06-27 11:11:24 Starting automatic backup
2017-06-27 11:11:24 Backing up to /dev/disk4s2: /Volumes/Time Machine/Backups.backupdb
2017-06-27 11:11:25 Will copy (33 KB) from Drobo
2017-06-27 11:11:25 Will copy (39.4 MB) from Macintosh HD
2017-06-27 11:11:25 Found 476 files (39.4 MB) needing backup
2017-06-27 11:11:25 5.32 GB required (including padding), 4.76 TB available
2017-06-27 11:11:26 Copied 8 items (33 KB) from volume Drobo. Linked 41.
2017-06-27 11:12:23 Copied 520 items (39.4 MB) from volume Macintosh HD. Linked 7170.
2017-06-27 11:12:25 Created new backup: 2017-06-27-111224
2017-06-27 11:12:26 Starting post-backup thinning
2017-06-27 11:12:26 No post-backup thinning needed: no expired backups exist
2017-06-27 11:12:26 Backup completed successfully.

If TM ignores fsevents and does a deep scan, it will show up in the messages.

To make life easier, I put the above command in a shell script in /usr/local/bin called tm-history.sh.

The default output covers quite a few days of backups, so what I normally do is just pipe it through something like “tail -50” to see recent backups.

I’m currently working with Apple on an issue where TM will silently skip many automatic backups after my iMac has been up for several days. As a quick and dirty way to see the list of recent backups, I do this:

tm-history.sh | grep ' Starting ' | grep -v 'thinning' | tail -20

I end up with something like this:

2017-06-26 20:56:10 Starting automatic backup
2017-06-26 22:01:58 Starting automatic backup
2017-06-26 22:48:22 Starting manual backup
2017-06-27 00:04:47 Starting automatic backup
2017-06-27 00:59:00 Starting automatic backup
2017-06-27 09:35:47 Starting automatic backup
2017-06-27 10:06:12 Starting automatic backup
2017-06-27 11:11:24 Starting automatic backup

HTH.




____________TidBITS Talk Participation Guidelines____________
Post only when you have something substantive to contribute.
Be polite and constructive, and comment on posts, not people.
Quote sparingly, if at all. We all read the previous message.
Start threads with a new message to [hidden email].
Read archives at: http://tidbits.com/pipermail/tidbits-talk/
Unsubscribe at: http://tidbits.com/mailman/options/tidbits-talk
____Mailing List Manners: http://tidbits.com/series/1141 ____
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: fsevents vs backup redundancy

Roger D. Parish
You might find this helpful, although you seem to already have developed your own solution.

Consolation (1.0b5) for macOS Sierra
Howard Oakley
https://eclecticlight.co

Roger D. Parish
Lovettsville, VA



> On Jun 27, 2017, at 6:07 AM, Rodney <[hidden email]> wrote:
>
> log show --predicate 'subsystem == "com.apple.TimeMachine"' --info | grep 'upd: (' | cut -c 1-19,140-999




____________TidBITS Talk Participation Guidelines____________
Post only when you have something substantive to contribute.
Be polite and constructive, and comment on posts, not people.
Quote sparingly, if at all. We all read the previous message.
Start threads with a new message to [hidden email].
Read archives at: http://tidbits.com/pipermail/tidbits-talk/
Unsubscribe at: http://tidbits.com/mailman/options/tidbits-talk
____Mailing List Manners: http://tidbits.com/series/1141 ____
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: fsevents vs backup redundancy

Roger D. Parish
In reply to this post by Rodney
re: my previous message about Consolation. It has been updated. Here is the new version: <https://eclecticlight.co/2017/06/26/consolation-2-3-released-to-improve-search-predicate-support/>

Roger D. Parish
Lovettsville, VA



> On Jun 27, 2017, at 6:07 AM, Rodney <[hidden email]> wrote:
>
> log show --predicate 'subsystem == "com.apple.TimeMachine"' --info | grep 'upd: (' | cut -c 1-19,140-999




____________TidBITS Talk Participation Guidelines____________
Post only when you have something substantive to contribute.
Be polite and constructive, and comment on posts, not people.
Quote sparingly, if at all. We all read the previous message.
Start threads with a new message to [hidden email].
Read archives at: http://tidbits.com/pipermail/tidbits-talk/
Unsubscribe at: http://tidbits.com/mailman/options/tidbits-talk
____Mailing List Manners: http://tidbits.com/series/1141 ____
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: fsevents vs backup redundancy

@lbutlr
In reply to this post by Rodney
On Jun 27, 2017, at 4:07 AM, Rodney <[hidden email]> wrote:
> It is S-L-O-W. Here is some sample output:
>
> 2017-06-27 10:06:12 Starting automatic backup
> 2017-06-27 10:06:40 Backup completed successfully.

28 seconds is slow?

--
Apple broke AppleScripting signatures in Mail.app, so no random signatures.



____________TidBITS Talk Participation Guidelines____________
Post only when you have something substantive to contribute.
Be polite and constructive, and comment on posts, not people.
Quote sparingly, if at all. We all read the previous message.
Start threads with a new message to [hidden email].
Read archives at: http://tidbits.com/pipermail/tidbits-talk/
Unsubscribe at: http://tidbits.com/mailman/options/tidbits-talk
____Mailing List Manners: http://tidbits.com/series/1141 ____
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: fsevents vs backup redundancy

Rodney

On Jun 29, 2017, at 00:07, @lbutlr <[hidden email]> wrote:

28 seconds is slow?

No. What was slow was:

log show --predicate 'subsystem == "com.apple.TimeMachine"' --info | grep 'upd: (' | cut -c 1-19,140-999






____________TidBITS Talk Participation Guidelines____________
Post only when you have something substantive to contribute.
Be polite and constructive, and comment on posts, not people.
Quote sparingly, if at all. We all read the previous message.
Start threads with a new message to [hidden email].
Read archives at: http://tidbits.com/pipermail/tidbits-talk/
Unsubscribe at: http://tidbits.com/mailman/options/tidbits-talk
____Mailing List Manners: http://tidbits.com/series/1141 ____
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: fsevents vs backup redundancy

@lbutlr


> On Jun 28, 2017, at 4:11 PM, Rodney <[hidden email]> wrote:
>
>
>> On Jun 29, 2017, at 00:07, @lbutlr <[hidden email]> wrote:
>>
>> 28 seconds is slow?
>
> No. What was slow was:
>
> log show --predicate 'subsystem == "com.apple.TimeMachine"' --info | grep 'upd: (' | cut -c 1-19,140-999

Well yes, of course it is; it’s searching a massive amount of data. And you’re probably running it on a spinning disk (it’s not especially fast, nor specially slow on my 2009 MBP with an SSD upgrade).

bounding it with a --start and --end helps, though --last is even better.

% time log show --predicate 'subsystem == "com.apple.TimeMachine"' --info --last 2h| grep 'upd: ‘

 [ … ]

real 0m3.248s
user 0m2.836s
sys 0m0.340s

time log show --predicate 'subsystem == "com.apple.TimeMachine"' --info --last 1d| grep 'upd: ‘

 [ … ]

real 0m6.217s
user 0m5.134s
sys 0m0.698s



--
Apple broke AppleScripting signatures in Mail.app, so no random signatures.




____________TidBITS Talk Participation Guidelines____________
Post only when you have something substantive to contribute.
Be polite and constructive, and comment on posts, not people.
Quote sparingly, if at all. We all read the previous message.
Start threads with a new message to [hidden email].
Read archives at: http://tidbits.com/pipermail/tidbits-talk/
Unsubscribe at: http://tidbits.com/mailman/options/tidbits-talk
____Mailing List Manners: http://tidbits.com/series/1141 ____
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: fsevents vs backup redundancy

Rodney

> On Jun 29, 2017, at 00:28, @lbutlr <[hidden email]> wrote:
>
> Well yes, of course it is; it’s searching a massive amount of data.

I wasn't complaining, just observing...

> And you’re probably running it on a spinning disk

No. Late 2014 5k iMac with SSD.

Terms like "fast" and "slow" can be subjective. The command isn't too slow to be useful.

> bounding it with a --start and --end helps, though --last is even better.

That is VERY helpful. Thanks. I'd been just piping the output through "tail", "grep", whatever, to get a subset of the data.



____________TidBITS Talk Participation Guidelines____________
Post only when you have something substantive to contribute.
Be polite and constructive, and comment on posts, not people.
Quote sparingly, if at all. We all read the previous message.
Start threads with a new message to [hidden email].
Read archives at: http://tidbits.com/pipermail/tidbits-talk/
Unsubscribe at: http://tidbits.com/mailman/options/tidbits-talk
____Mailing List Manners: http://tidbits.com/series/1141 ____
Loading...