Carbonite woes

I’ve been using Carbonite for a while and it’s worked well most of this time (though how do you know if a backup tool is working?), but recently I’ve started to notice a few issues with it and I may end up switching to another cloud backup service (I’m currently evaluating CrashPlan and another part of me is seriously considering going old-school and using good ol’ rsync or maybe just cloning to a bunch of spare hard drives and then leaving them with friends and family). Some if these issues might not be serious, but when it comes to a backup tool, it makes me nervous when I see weird unexplainable behavior. I like my backup software to just work. And that is why I’m detailing everything weird I saw, even if some of it is the inevitable stuff that you get when you peek too closely into the sausage factory.

Issue 1: Backups can stop progressing; no alerts to tell me this

A couple of weeks ago, I noticed that Carbonite had been “stuck” – there were about 1500 files that were pending backup and that number was not shrinking.

I happened to notice this because we had taken a lot of photos and I decided to check whether they were getting backed up. If I had not checked and our hard drive crashed, that could’ve been really bad.

This stuck backup lead to me spending quite a few hours measuring, diagnosing, disk repairing, and tweaking and it looks like things are working better now (I have only 42 files pending backup now). It also lead to the discovery of other issues that are detailed below. But the main point I want to make here is that I should not have to notice that backups have stalled. Carbonite should detect that it is not progressing and send me an alert email and/or popup on my screen.

Issue 2: Carbonite not backing up because CPU Idle is too low (and Carbonite is using the bulk of the CPU)

This is possibly one of the big reasons for the Issue 1.

When my backup wasn’t progressing, I looked for clues by looking at /Library/Application Support/Carbonite/Data/Carbonite.log and noticed that CPU Idle was almost never at the CPU Idle target of 75%. I’m wondering if this is causing Carbonite to not back up? I tried quitting every program on my computer (including all sorts of menu bar apps and background apps such as, Dropbox, Evernote, Jenkins, etc). The only thing that is using a lot of CPU, according to Activity Monitor, is Carbonite itself.

At this point, I started looking at what Carbonite was looking at using the fs_usage command.

Ideally, I shouldn’t have to quit every program on my computer in order to get the CPU usage low enough for Carbonite to be able to do backups. The beauty of a cloud backup app like Carbonite is that it just should just do its thing in the background without me having to change my workflow. When it’s working well, this is how it works. I’m not sure of why it has been stumbling lately.

Issue 3: Internal program errors in the logs

I also noticed some internal errors in the log and I wonder if Carbonite is crashing when it tries to back up certain files and thus is unable to make progress – e.g.:

1346811842  = 19:24:02
1346811842  @ 2954915840: Backup progress: completed 38%, file counts last 2 22:10:34 All: 3617 (1081M bytes) Unique: 3225 (731M bytes), Compressed: 848M bytes.
1346811842  @ 2954915840: Backup progress: remaining time unknown, file counts All: 563085 (217G bytes), Pending: 1396 (1767M bytes).
1346811842  @ 2954915840: Backup progress: task seconds last minute, Active: 0 (0%) Response Waiting: 61 (100%) Send Waiting: 0 (0%) Sending: 61 (100%) 
1346811873  ! 2957045760: Internal program error: ASSERT "LogFile.SetFilePointer(dwBufferPosition)" (/Library/Bamboo/home/xml-data/build-dir/MAC-CLI-JOB1/Client/Mac/daemon/../../../Shared/Common/LogMsg.cpp:735)
1346811873  @ 2957045760: DumpStack: stack trace not available
1346811873  ! 2957045760: Internal program error: ASSERT "LogFile.SetFilePointer(dwBufferPosition)" (/Library/Bamboo/home/xml-data/build-dir/MAC-CLI-JOB1/Client/Mac/daemon/../../../Shared/Common/LogMsg.cpp:1255)
1346811903  = 19:25:03

This does not inspire confidence.

Issue 4: Delaying backup due to zero length file modified within the last minute

Carbonite says that it’s “delaying backup due to zero length file modified within the last minute” – the issue is that these files are zero-length but they have not been modified within the last minute. For example:

1347897240  # 2956513280: Delaying backup due to zero length file modified within the last minute: "/Volumes/Momentus/Users/marc/Library/Preferences/MaxBack .mxbk".
1347897240  # 2956513280: Delaying backup due to zero length file modified within the last minute: "/Volumes/Momentus/Users/marc/Dropbox/Camera Uploads/Icon ".
1347897240  # 2956513280: Delaying backup due to zero length file modified within the last minute: "/Volumes/Momentus/Users/marc/Library/Application Support/Evernote/accounts/Evernote/msabramo/note.index/write.lock".
1347897240  # 2956513280: Delaying backup due to zero length file modified within the last minute: "/Volumes/Momentus/Users/marc/Library/Application Support/Google/Chrome/Default/Extension State/LOCK".

But the apps that write these files are not running and these files have not been modified recently at all.

$ date
Mon Sep 17 09:19:25 PDT 2012

$ ls -l "/Volumes/Momentus/Users/marc/Library/Preferences/MaxBack .mxbk"
-rw-r--r--  1 marc  marc  0 Sep 11 02:40 /Volumes/Momentus/Users/marc/Library/Preferences/MaxBack .mxbk

$ ls -l "/Volumes/Momentus/Users/marc/Dropbox/Camera Uploads/Icon^M" 
-rw-r--r--@ 1 marc  marc  0 Sep 10 23:28 /Volumes/Momentus/Users/marc/Dropbox/Camera Uploads/Icon?

$ ls -l "/Volumes/Momentus/Users/marc/Library/Application Support/Evernote/accounts/Evernote/msabramo/note.index/write.lock"
-rw-------  1 marc  marc  0 Sep 16 22:23 /Volumes/Momentus/Users/marc/Library/Application Support/Evernote/accounts/Evernote/msabramo/note.index/write.lock

$ ls -l "/Volumes/Momentus/Users/marc/Library/Application Support/Google/Chrome/Default/Extension State/LOCK"
-rw-------@ 1 marc  marc  0 Sep 10 06:07 /Volumes/Momentus/Users/marc/Library/Application Support/Google/Chrome/Default/Extension State/LOCK

This may or may not be affecting my backup appreciably, but the issue here is that when I’ve already had some difficulty getting Carbonite to do its backups, then when I look through the logs and notice other thing that seem incorrect, it further erodes my confidence in the product.

Issue 5: Carbonite wasting its time repeatedly checking files and directories that have long been deleted

Carbonite doesn’t log every single file it looks at (Thank goodness! That would be extremely inefficient.), so most folks wouldn’t even notice this one. I only did because my backup was not progressing and I kept seeing messages in the logs saying that Carbonite was waiting because CPU usage was too high, and Carbonite was the only app using a lot of CPU, so I went poking around to see what it was so busy doing.

$ sudo fs_usage | grep '/.*CarboniteDae'

08:33:34  getattrlist       //Users/marc/etsylister/parts>>>>>>>>>>>>>>>                                     0.000038   CarboniteDae
08:33:34  getattrlist       //Users/marc/etsylister/parts>>>>>>>>>>>>>>>                                     0.000007   CarboniteDae
08:33:34  getattrlist       //Users/marc/etsylister/parts>>>>>>>>>>>>>>>                                     0.000008   CarboniteDae

I cut this off at 3 entries, but in reality, I saw this 44 times in one second (and it happened for more than one second, but I stopped counting). This also isn’t the only directory that it’s continuing to check – there are several others.

The fact that an app is repeatedly accessing the same file over and over 44 times per second is concerning in itself. To add fuel to the fire, this directory no longer exists! See, I noticed this message many times in the past and I thought that I could give Carbonite a hand and get it past its compulsive checking by deleting this directory and a bunch of other ones that it was compulsively checking. So maybe a week ago, I went on a rampage and blew away a bunch of directories that Carbonite was obsesssing over that weren’t important to me. Problem is, Carbonite is still checking them! And this is even after I uninstalled Carbonite, blew away all its preferences and support files, rebooted, and reinstalled Carbonite. Either I missed deleting the file on my local filesystem that carries this state, or, more likely, the knowledge of this file is in Carbonite’s servers. Perhaps after some amount of time or some number of failed attempts to access the file (how many?), Carbonite will forget about these files. But in the meantime, I worry that it’s wasting its time checking stuff that’s gone and it could be better spending its time backing up the files that I do have.

Update 2012-09-27

I’ve accumulated the info in this post over the course of the last several weeks. At one point, I did a bunch of fiddling including a disk repair on my startup disk and managed to get Carbonite to make a bunch of progress so that only 70 or so files were pending backup (it’s quite possible that disk errors were confusing Carbonite). Still I wanted them all to be backed up or at least know which files those were that were not being backed up and why. The latest is that I talked to Carbonite support and had a fairly nice and helpful guy connect to my machine remotely and make Carbonite exclude some files that are supposedly problematic (browser caches and the like) and mess around with some Carbonite caches. This didn’t really make Carbonite catch up and back up the remaining 70 files. In fact, over the course of the last few days that number has grown to a little over 300. This suggests to me that Carbonite is having trouble with some of these files and is “stuck” and will likely fall further and further behind but I don’t know which files are the problematic ones and Carbonite support hasn’t yet been able to tell me which files these are.

Most likely, I will let my Carbonite subscription lapse when it comes up for renewal. I might go with CrashPlan, but I think more likely is that I will forego cloud backup services entirely and instead just clone my stuff to hard drives and store a couple in some offsite locations like the homes of friends and family. The knocks against cloud backup:

  • Hard to know whether it’s working – how do I really know which files the provider has and which they don’t?
  • Cloud backup uses a ton of my computer CPU and Internet and network bandwidth for months and months. When I do do backups myself, I kick it off and after a few hours it’s done.
  • When the time comes to restore files, I will have to download a tremendous amount of data or pay over a hundred dollars for them to ship me a hard drive. Even then, the hard drive or files downloaded will just be files; not a bootable image. Conversely if I go to a friend’s house and pick up a hard drive with a clone of my system, I have all of my files fast and I have something I can boot off of.
  • I could save the money on the subscription fee and use it towards my hard drive budget.

Memeo backup = slow

I replaced a defective Seagate GoFlex portable hard drive a few days ago and the new one that Seagate sent me had Memeo backup software on it. I decided to give it a whirl.

I got it configured, but judging from how long it appears to take to do a complete backup, I don’t think it will be sticking around long.

22,023 hours remaining?!?!

I already have Carbon Copy Cloner for cloning my whole drive to a USB hard drive and I have Carbonite for doing backups of various important files such as pictures and music to the cloud. That is probably good enough.

MozyHome – The Never-Ending Backup

I’ve been wanting to look at online backup for a while to backup photos and music and such and to supplement local measures like using a ReadyNAS with RAID and having some spare hard drives for backups.

The other day I signed up for the MozyHome trial account with 2 GB of space. I downloaded the OS X client (version — pretty simple to install. Configuring it was a little strange — when I tell it to not back up a certain folder, it takes a very long time for it to register the change and the UI doesn’t give any impression that it’s working on it. I actually didn’t know for a while whether it was doing anything.

Finally, I kicked off a backup of 1.2 GB of files. This was on the morning of January 10. It’s now almost the morning of January 14 and the backup is only around 75% done. Now I have DSL with a paltry upload speed of 512 Kbps, but still…that should give me 100 megabytes or so per hour, conservatively. That would finish in less than 12 hours.

The strange thing is that Mozy seems to not send data for large stretches of time. Sometimes it is active and sometime there is no outbound network traffic at all (according to iStat Pro).

And taking a look at the history which tells you how much data was transferred per day:

January 10 – Files sent: 2,759; Size sent: 697.2 MB
January 11 – Files sent: 2,452; Size sent: 57.1 MB
January 12 – Files sent: 5,680; Size sent: 37.3 MB

I’m curious what’s going on here. Do they transfer less and less each day or is the speed proportional to how much you have left? Or are the backups limited to a certain number of hours?

Anyone else see this? Is this typical of other online backup services — e.g.: Carbonite (which is next on my list to try)?