dwbrecovery wrote:
Hi,
- With an assumption that ExtHDD3 is a disk connected to the Server, run Disk Utility -> Verify Disk for ExtHDD3.
- Are there more Console log entires for backupd that you can post ( using the filter ). Take care to remove private information.
- At this stage iI do not think the mds entires are relevant, but if you can look at the Console logs and filter by mds and check this as well.
Cheers
I will verify the disk during the next days. I assume that it should be good. It was used in my previous FreeBSD server as a disk for the backup dump files and showed no problems so far - of course that does not prove anything :-)
In the meantime I was thinking about the mds log entries and decided to exclude the disk "Macintosh HD2" from spotlight, This is the disk which contains a huge amount of files and which are served as a file server. Since then the backups run successfully so far. (hourly backups from 14:30 until about 20:00)
I will look more closely at mds log entries, and will post what I found. For now I add a few of the backup logs:
More logs: (filtered for backup)
This is the successful backup at 4:30 :
06.07.14 04:30:16,675 com.apple.backupd[18686]: Starting automatic backup
06.07.14 04:30:17,024 com.apple.backupd[18686]: Backing up to /dev/disk2s2: /Volumes/ExtHD03/Backups.backupdb
06.07.14 04:30:35,458 com.apple.backupd[18686]: Will copy (50,9 MB) from Server HD
06.07.14 04:30:35,459 com.apple.backupd[18686]: Will copy (Zero KB) from Macintosh HD2
06.07.14 04:30:35,460 com.apple.backupd[18686]: Found 165 files (50,9 MB) needing backup
06.07.14 04:30:35,461 com.apple.backupd[18686]: 2,91 GB required (including padding), 631,14 GB available
06.07.14 04:30:38,858 com.apple.backupd[18686]: Copied 172 items (50,9 MB) from volume Server HD. Linked 528.
06.07.14 04:30:40,081 com.apple.backupd[18686]: Copied 1 items (Zero KB) from volume Macintosh HD2. Linked 10.
06.07.14 04:30:40,657 com.apple.backupd[18686]: Will copy (786 bytes) from Server HD
06.07.14 04:30:40,658 com.apple.backupd[18686]: Not using file event preflight for Macintosh HD2
06.07.14 04:30:40,661 com.apple.backupd[18686]: Found 17 files (786 bytes) needing backup
06.07.14 04:30:40,662 com.apple.backupd[18686]: 2,83 GB required (including padding), 631,09 GB available
06.07.14 04:30:41,322 com.apple.backupd[18686]: Copied 19 items (819 bytes) from volume Server HD. Linked 211.
06.07.14 04:30:41,856 com.apple.backupd[18686]: Copied 1 items (Zero KB) from volume Macintosh HD2. Linked 10.
06.07.14 04:30:42,401 com.apple.backupd[18686]: Created new backup: 2014-07-06-043042
06.07.14 04:30:43,254 com.apple.backupd[18686]: Starting post-backup thinning
06.07.14 04:30:43,254 com.apple.backupd[18686]: No post-backup thinning needed: no expired backups exist
06.07.14 04:30:43,276 com.apple.backupd[18686]: Backup completed successfully.
This is the stuck backup at 5:30 : (the one with the mds errors)
06.07.14 05:31:17,660 com.apple.backupd[20453]: Starting automatic backup
06.07.14 05:31:17,675 com.apple.backupd[20453]: Backing up to /dev/disk2s2: /Volumes/ExtHD03/Backups.backupdb
Successful backup around 15:00 - interestingly with a log entry regarding backupd burning cpu:
06.07.14 14:51:16,047 com.apple.backupd[5559]: Starting manual backup
06.07.14 14:51:16,700 com.apple.backupd[5559]: Backing up to /dev/disk2s2: /Volumes/ExtHD03/Backups.backupdb
06.07.14 14:51:19,665 com.apple.prefs.backup.remoteservice[5588]: assertion failed: 13E28: liblaunch.dylib + 25164 [A40A0C7B-3216-39B4-8AE0-B5D3BAF1DA8A]: 0x25
06.07.14 14:51:19,669 com.apple.prefs.backup.remoteservice[5588]: assertion failed: 13E28: liblaunch.dylib + 25164 [A40A0C7B-3216-39B4-8AE0-B5D3BAF1DA8A]: 0x25
06.07.14 14:51:19,689 com.apple.prefs.backup.remoteservice[5588]: assertion failed: 13E28: liblaunch.dylib + 25164 [A40A0C7B-3216-39B4-8AE0-B5D3BAF1DA8A]: 0x25
06.07.14 14:51:20,292 com.apple.prefs.backup.remoteservice[5588]: Bogus event received by listener connection:
<error: 0x7fff735cdb50> { count = 1, contents =
"XPCErrorDescription" => <string: 0x7fff735cde60> { length = 18, contents = "Connection invalid" }
}
06.07.14 14:54:04,000 kernel[0]: process backupd[5559] thread 35951 caught burning CPU! It used more than 50% CPU (Actual recent usage: 53%) over 180 seconds. thread lifetime cpu usage 90.051769 seconds, (40.741139 user, 49.310630 system) ledger info: balance: 90000405776 credit: 90000405776 debit: 0 limit: 90000000000 (50%) period: 180000000000 time since last refill (ns): 168293143923
06.07.14 14:54:10,001 spindump[5898]: Saved cpu_resource.spin report for backupd version ??? (???) to /Library/Logs/DiagnosticReports/backupd_2014-07-06-145409_macsrv.cpu_resource.s pin
06.07.14 14:58:39,727 com.apple.backupd[5559]: Will copy (1,16 GB) from Server HD
06.07.14 14:58:40,162 com.apple.backupd[5559]: Will copy (22 KB) from Macintosh HD2
06.07.14 14:58:40,179 com.apple.backupd[5559]: Found 146769 files (2,43 GB) needing backup
06.07.14 14:58:40,817 com.apple.backupd[5559]: 5,02 GB required (including padding), 631,68 GB available
06.07.14 15:01:22,552 com.apple.backupd[5559]: Copied 8824 items (969,1 MB) from volume Server HD. Linked 13927.
06.07.14 15:01:37,074 com.apple.backupd[5559]: Copied 34 items (286,3 MB) from volume Macintosh HD2. Linked 453.
06.07.14 15:01:39,070 com.apple.backupd[5559]: Will copy (33,6 MB) from Server HD
06.07.14 15:01:39,071 com.apple.backupd[5559]: Not using file event preflight for Macintosh HD2
06.07.14 15:01:39,074 com.apple.backupd[5559]: Found 38 files (33,6 MB) needing backup
06.07.14 15:01:39,075 com.apple.backupd[5559]: 2,16 GB required (including padding), 630,41 GB available
06.07.14 15:01:42,423 com.apple.backupd[5559]: Copied 43 items (33,6 MB) from volume Server HD. Linked 492.
06.07.14 15:01:43,409 com.apple.backupd[5559]: Copied 1 items (Zero KB) from volume Macintosh HD2. Linked 10.
06.07.14 15:01:43,974 com.apple.backupd[5559]: Created new backup: 2014-07-06-150143
06.07.14 15:01:46,140 com.apple.backupd[5559]: Starting post-backup thinning
06.07.14 15:01:46,140 com.apple.backupd[5559]: No post-backup thinning needed: no expired backups exist
06.07.14 15:01:46,168 com.apple.backupd[5559]: Backup completed successfully.
A couple of successful backups in between - here the last one from the last hour:
06.07.14 20:02:45,895 com.apple.backupd[19944]: Starting automatic backup
06.07.14 20:02:46,109 com.apple.backupd[19944]: Backing up to /dev/disk2s2: /Volumes/ExtHD03/Backups.backupdb
06.07.14 20:02:54,710 com.apple.backupd[19944]: Will copy (2,76 GB) from Server HD
06.07.14 20:02:54,711 com.apple.backupd[19944]: Will copy (8 KB) from Macintosh HD2
06.07.14 20:02:54,712 com.apple.backupd[19944]: Found 1652 files (2,76 GB) needing backup
06.07.14 20:02:54,715 com.apple.backupd[19944]: 5,44 GB required (including padding), 630,2 GB available
06.07.14 20:04:24,539 com.apple.backupd[19944]: Copied 1681 items (2,76 GB) from volume Server HD. Linked 669.
06.07.14 20:04:32,619 com.apple.backupd[19944]: Copied 14 items (16 KB) from volume Macintosh HD2. Linked 80.
06.07.14 20:04:33,513 com.apple.backupd[19944]: Will copy (33,6 MB) from Server HD
06.07.14 20:04:33,513 com.apple.backupd[19944]: Not using file event preflight for Macintosh HD2
06.07.14 20:04:33,517 com.apple.backupd[19944]: Found 38 files (33,6 MB) needing backup
06.07.14 20:04:33,517 com.apple.backupd[19944]: 2,24 GB required (including padding), 627,35 GB available
06.07.14 20:04:35,833 com.apple.backupd[19944]: Copied 42 items (33,6 MB) from volume Server HD. Linked 321.
06.07.14 20:04:36,682 com.apple.backupd[19944]: Copied 1 items (Zero KB) from volume Macintosh HD2. Linked 10.
06.07.14 20:04:37,504 com.apple.backupd[19944]: Created new backup: 2014-07-06-200437
06.07.14 20:04:39,137 com.apple.backupd[19944]: Starting post-backup thinning
06.07.14 20:04:39,140 com.apple.backupd[19944]: No post-backup thinning needed: no expired backups exist
06.07.14 20:04:39,156 com.apple.backupd[19944]: Backup completed successfully.