How to diagnose Time Machine / Time Capsule issues

My Time Machine backup suddenly stopped working. Apple support has been helping (and Chris has been nice!). Here’s the command by which Apple collects all info they want to debug this, and what it echoes to the terminal (slightly abbreviated). I figure I post this for the geeks among us; perhaps it helps somebody in the future avoiding support:

% sudo tmdiagnose -w
2018-11-18 11:31:30.144 tmdiagnose[3195:2503] Executing `/usr/sbin/spindump -notarget 15 -file /private/var/tmp/.../spindump.txt`
2018-11-18 11:31:32.221 tmdiagnose[3195:2003] Executing `/usr/bin/fs_usage -w -t 10 -e tmdiagnose`
2018-11-18 11:32:00.733 tmdiagnose[3195:2503] Executing `/bin/ps auxh`
2018-11-18 11:32:00.934 tmdiagnose[3195:2503] Executing `/usr/bin/top -l 10`
2018-11-18 11:32:11.229 tmdiagnose[3195:3603] Executing `/usr/bin/powermetrics -i 1000 -n 10 --show-all`
2018-11-18 11:32:21.933 tmdiagnose[3195:5107] Executing `/usr/bin/sample -file /private/var/tmp/.../backupd.txt backupd 5`
2018-11-18 11:32:28.047 tmdiagnose[3195:5107] Executing `/usr/bin/sample -file /private/var/tmp/.../Finder.txt Finder 5`
2018-11-18 11:32:33.748 tmdiagnose[3195:2503] Executing `/bin/ls -la /Volumes/`
2018-11-18 11:32:33.816 tmdiagnose[3195:2503] Executing `/bin/df -H`
2018-11-18 11:32:33.886 tmdiagnose[3195:2503] Executing `/sbin/mount`
2018-11-18 11:32:33.951 tmdiagnose[3195:2503] Executing `/usr/sbin/diskutil list`
2018-11-18 11:32:34.086 tmdiagnose[3195:2503] Executing `/usr/sbin/diskutil cs list`
2018-11-18 11:32:34.154 tmdiagnose[3195:2503] Executing `/usr/sbin/diskutil apfs list`
2018-11-18 11:32:34.349 tmdiagnose[3195:2503] Executing `/bin/bash -c /usr/sbin/diskutil list | /usr/bin/awk '/disk/ {system("/usr/sbin/diskutil info "$NF); print "*********************"}'`
2018-11-18 11:32:39.535 tmdiagnose[3195:2503] Executing `/usr/bin/tmutil listlocalsnapshots /`
2018-11-18 11:32:39.605 tmdiagnose[3195:2503] Executing `/usr/bin/tmutil listlocalsnapshots /private/var/vm`
2018-11-18 11:32:39.674 tmdiagnose[3195:2503] Executing `/usr/bin/tmutil listlocalsnapshots /Volumes/Recovery`
2018-11-18 11:32:39.745 tmdiagnose[3195:2503] Executing `/usr/bin/hdiutil info`
2018-11-18 11:32:39.937 tmdiagnose[3195:3c07] Executing `/usr/sbin/netstat -in`
2018-11-18 11:32:40.043 tmdiagnose[3195:3c07] Executing `/usr/sbin/netstat -aW -p tcp`
2018-11-18 11:32:46.138 tmdiagnose[3195:3c07] Running network reachability diagnostics...
2018-11-18 11:32:46.798 tmdiagnose[3195:3c07] Executing `/sbin/ping -c 10 -t 10 TimeCapsule.local`
2018-11-18 11:32:55.855 tmdiagnose[3195:2503] Executing `/usr/sbin/lsof +c 0`
2018-11-18 11:33:32.815 tmdiagnose[3195:3603] Executing `/usr/bin/pmset -g everything`
2018-11-18 11:33:33.812 tmdiagnose[3195:440f] Executing `/usr/sbin/ioreg -ls -w 0`
2018-11-18 11:33:34.604 tmdiagnose[3195:440f] Executing `/usr/bin/log collect --size 200m --output /private/var/tmp/.../oslog.logarchive`
2018-11-18 11:34:00.974 tmdiagnose[3195:440f] Gathering system diagnostic logs for 'backupd'
2018-11-18 11:34:00.982 tmdiagnose[3195:440f] Gathering system diagnostic logs for 'backupd-helper'
2018-11-18 11:34:00.982 tmdiagnose[3195:440f] Gathering system diagnostic logs for 'tmutil'
2018-11-18 11:34:00.983 tmdiagnose[3195:440f] Gathering system diagnostic logs for 'tmdiagnose'
2018-11-18 11:34:00.983 tmdiagnose[3195:440f] Gathering system diagnostic logs for 'UserEventAgent'
2018-11-18 11:34:00.984 tmdiagnose[3195:440f] Gathering system diagnostic logs for 'fsck_hfs'
2018-11-18 11:34:00.985 tmdiagnose[3195:440f] Gathering system diagnostic logs for 'diskmanagementd'
2018-11-18 11:34:00.985 tmdiagnose[3195:440f] Gathering system diagnostic logs for 'DesktopServicesHelper'
2018-11-18 11:34:00.986 tmdiagnose[3195:440f] Gathering system diagnostic logs for 'diskimages-helper'
2018-11-18 11:34:00.986 tmdiagnose[3195:440f] Gathering system diagnostic logs for 'newfs_hfs'
2018-11-18 11:34:00.987 tmdiagnose[3195:440f] Gathering system diagnostic logs for 'NetAuthSysAgent'
2018-11-18 11:34:00.987 tmdiagnose[3195:440f] Gathering system diagnostic logs for 'discoveryd'
2018-11-18 11:34:00.988 tmdiagnose[3195:440f] Gathering system diagnostic logs for 'TMCacheDelete'
2018-11-18 11:34:00.988 tmdiagnose[3195:440f] Gathering system diagnostic logs for 'Finder'
2018-11-18 11:34:00.989 tmdiagnose[3195:440f] Gathering system diagnostic logs for 'System Preferences'
2018-11-18 11:34:00.990 tmdiagnose[3195:440f] Gathering system diagnostic logs for 'com.apple.prefs.backup.remoteservice'
2018-11-18 11:34:00.990 tmdiagnose[3195:440f] Gathering system diagnostic logs for 'TMHelperAgent'
2018-11-18 11:34:00.991 tmdiagnose[3195:440f] Gathering system diagnostic logs for 'FileStatsAgent'
2018-11-18 11:34:00.991 tmdiagnose[3195:440f] Gathering system diagnostic logs for 'ReclaimSpaceAgent'
2018-11-18 11:34:00.992 tmdiagnose[3195:440f] Gathering system diagnostic logs for 'NetAuthSysAgent'
2018-11-18 11:34:00.993 tmdiagnose[3195:440f] Gathering system diagnostic logs for 'SystemUIServer'
2018-11-18 11:34:00.993 tmdiagnose[3195:440f] Gathering system diagnostic logs for 'Mail'
2018-11-18 11:34:00.994 tmdiagnose[3195:440f] Gathering system diagnostic logs for 'Contacts'
2018-11-18 11:34:00.994 tmdiagnose[3195:440f] Gathering recent user diagnostic logs for 'com.apple.prefs.backup.remoteservice'
2018-11-18 11:34:01.018 tmdiagnose[3195:440f] Gathering recent user diagnostic logs for 'TMHelperAgent'
2018-11-18 11:34:01.035 tmdiagnose[3195:440f] Gathering recent user diagnostic logs for 'tmutil'
2018-11-18 11:34:01.057 tmdiagnose[3195:440f] Gathering recent user diagnostic logs for 'Finder'
2018-11-18 11:34:01.081 tmdiagnose[3195:440f] Gathering recent user diagnostic logs for 'DesktopServicesHelper'
2018-11-18 11:34:01.102 tmdiagnose[3195:440f] Gathering recent user diagnostic logs for 'FileStatsAgent'
2018-11-18 11:34:01.125 tmdiagnose[3195:440f] Gathering recent user diagnostic logs for 'System Preferences'
2018-11-18 11:34:01.150 tmdiagnose[3195:440f] Gathering recent user diagnostic logs for 'NetAuthSysAgent'
2018-11-18 11:34:01.172 tmdiagnose[3195:440f] Gathering recent user diagnostic logs for 'SystemUIServer'
2018-11-18 11:34:01.195 tmdiagnose[3195:440f] Gathering recent user diagnostic logs for 'Mail'
2018-11-18 11:34:01.216 tmdiagnose[3195:440f] Gathering recent user diagnostic logs for 'Contacts'
2018-11-18 11:34:01.296 tmdiagnose[3195:2b13] Executing `/usr/sbin/system_profiler -xml -timeout 30 SPParallelATADataType SPAirPortDataType SPBluetoothDataType SPDiagnosticsDataType SPEthernetDataType SPFibreChannelDataType SPFireWireDataType SPFirewallDataType SPHardwareDataType SPHardwareRAIDDataType SPNetworkLocationDataType SPManagedClientDataType SPMemoryDataType SPNetworkDataType SPPowerDataType SPSerialATADataType SPSoftwareDataType SPUSBDataType`
2018-11-18 11:34:05.222 tmdiagnose[3195:440f] Executing `/bin/ls -Ulae@ /Library/Keychains/System.keychain`
2018-11-18 11:34:05.290 tmdiagnose[3195:440f] Executing `/usr/bin/darwinup list`
2018-11-18 11:34:05.362 tmdiagnose[3195:440f] Executing `/bin/bash -c /bin/launchctl list | /usr/bin/grep -e 'PID' -e 'com.apple.mtm' -e 'com.apple.backup' -e 'com.apple.TMHelperAgent'`
2018-11-18 11:34:05.428 tmdiagnose[3195:440f] Executing `/usr/bin/tmutil destinationinfo`
2018-11-18 11:34:05.750 tmdiagnose[3195:2b13] Executing `/usr/bin/mdfind com_apple_backup_excludeItem == com.apple.backupd`
2018-11-18 11:34:05.827 tmdiagnose[3195:2b13] Collecting diagnostics for Time Machine backups (this may take several minutes)
2018-11-18 11:34:05.828 tmdiagnose[3195:2b13] Building classic Time Machine snapshot skeletons...
2018-11-18 11:34:05.837 tmdiagnose[3195:6c03] Locating machine directory...
2018-11-18 11:34:08.135 tmdiagnose[3195:2b13] Executing `/bin/ls -lde /Volumes/Time Machine Backups/Backups.backupdb/.RecoverySets`
2018-11-18 11:34:08.202 tmdiagnose[3195:2b13] Executing `/usr/bin/xattr -l /Volumes/Time Machine Backups/Backups.backupdb/.RecoverySets`
2018-11-18 11:34:08.662 tmdiagnose[3195:2b13] Executing `/bin/ls -lde /Volumes/Time Machine Backups/Backups.backupdb/.spotlight_repair`
2018-11-18 11:34:08.729 tmdiagnose[3195:2b13] Executing `/usr/bin/xattr -l /Volumes/Time Machine Backups/Backups.backupdb/.spotlight_repair`
2018-11-18 11:34:08.929 tmdiagnose[3195:2b13] Executing `/bin/ls -lde /Volumes/Time Machine Backups/Backups.backupdb/.spotlight_temp`
2018-11-18 11:34:08.996 tmdiagnose[3195:2b13] Executing `/usr/bin/xattr -l /Volumes/Time Machine Backups/Backups.backupdb/.spotlight_temp`
2018-11-18 11:34:09.195 tmdiagnose[3195:2b13] Executing `/bin/ls -lde /Volumes/Time Machine Backups/Backups.backupdb/sharp`
2018-11-18 11:34:09.261 tmdiagnose[3195:2b13] Executing `/usr/bin/xattr -l /Volumes/Time Machine Backups/Backups.backupdb/sharp`
2018-11-18 11:34:09.462 tmdiagnose[3195:2b13] Executing `/bin/ls -l /Volumes/Time Machine Backups/Backups.backupdb/.RecoverySets`
2018-11-18 11:34:09.530 tmdiagnose[3195:2b13] Executing `/bin/ls -l /Volumes/Time Machine Backups/Backups.backupdb/.spotlight_repair`
2018-11-18 11:34:09.596 tmdiagnose[3195:2b13] Executing `/bin/ls -l /Volumes/Time Machine Backups/Backups.backupdb/.spotlight_temp`
2018-11-18 11:34:09.660 tmdiagnose[3195:2b13] Executing `/bin/ls -l /Volumes/Time Machine Backups/Backups.backupdb/sharp`
2018-11-18 11:34:28.507 tmdiagnose[3195:a127] Executing `/usr/bin/brctl diagnose --sysdiagnose /private/var/tmp/.../brctl`
2018-11-18 11:34:29.953 tmdiagnose[3195:440f] Executing `/usr/bin/mddiagnose -w -n -f /private/var/tmp/...`
2018-11-18 11:34:29.984 mddiagnose[3416:11757872] Executing '/usr/bin/sw_vers'...
2018-11-18 11:34:30.052 mddiagnose[3416:11757872] Getting system version...
2018-11-18 11:34:30.054 mddiagnose[3416:11757872] Executing '/usr/bin/arch'...
2018-11-18 11:34:30.122 mddiagnose[3416:11757872] Executing '/usr/bin/what /System/Library/Frameworks/CoreServices.framework/Frameworks/Metadata.framework/Versions/A/Support/mds'...
2018-11-18 11:34:30.253 mddiagnose[3416:11757872] Executing '/usr/bin/what /System/Library/Frameworks/CoreServices.framework/Frameworks/Metadata.framework/Versions/A/Metadata'...
2018-11-18 11:34:30.415 mddiagnose[3416:11757872] Executing '/usr/bin/top -l 2 -s 2'...
2018-11-18 11:34:33.388 mddiagnose[3416:11757872] Executing '/bin/df -H'...
2018-11-18 11:34:33.456 mddiagnose[3416:11757872] Executing '/bin/ls -la /Volumes/'...
2018-11-18 11:34:33.522 mddiagnose[3416:11757872] Executing '/sbin/mount'...
2018-11-18 11:34:33.586 mddiagnose[3416:11757872] Executing '/usr/bin/vmmap -resident -w mds'...
2018-11-18 11:34:34.698 mddiagnose[3416:11757872] Executing '/usr/bin/heap mds'...
2018-11-18 11:34:40.727 mddiagnose[3416:11757872] Executing '/usr/bin/vmmap -resident -w mds_stores'...
2018-11-18 11:34:41.768 mddiagnose[3416:11757872] Executing '/usr/bin/heap mds_stores'...
2018-11-18 11:34:43.796 mddiagnose[3416:11757872] Executing '/usr/bin/vmmap -resident -w corespotlightd'...
2018-11-18 11:34:44.324 mddiagnose[3416:11757872] Executing '/usr/bin/heap corespotlightd'...
2018-11-18 11:34:44.847 mddiagnose[3416:11757872] Executing '/usr/local/bin/ddt mds'...
2018-11-18 11:34:44.849 mddiagnose[3416:11757872] Executing '/usr/local/bin/ddt mds_stores'...
2018-11-18 11:34:44.849 mddiagnose[3416:11757872] Executing '/usr/local/bin/ddt corespotlightd'...
2018-11-18 11:34:44.849 mddiagnose[3416:11757872] Executing '/usr/sbin/lsof'...
2018-11-18 11:35:23.078 mddiagnose[3416:11757872] Sampling 'mds'...
2018-11-18 11:35:28.757 mddiagnose[3416:11757872] Spindumping 'mds'...
2018-11-18 11:35:37.673 mddiagnose[3416:11757872] Sampling 'mds_stores'...
2018-11-18 11:35:43.056 mddiagnose[3416:11757872] Sampling 'corespotlightd'...
2018-11-18 11:35:48.697 mddiagnose[3416:11757872] Logging
2018-11-18 11:35:56.323 mddiagnose[3416:11757872] Executing '/usr/bin/mdutil -L /'...
2018-11-18 11:35:56.451 mddiagnose[3416:11757872] Executing '/usr/bin/mdutil -P /'...
2018-11-18 11:35:56.522 mddiagnose[3416:11757872] Executing '/usr/bin/mdutil -L /Volumes/Time Machine Backups/Backups.backupdb'...
2018-11-18 11:35:56.589 mddiagnose[3416:11757872] Executing '/usr/bin/mdutil -P /Volumes/Time Machine Backups/Backups.backupdb'...
2018-11-18 11:35:57.075 mddiagnose[3416:11757872] Executing '/usr/bin/mdutil -L /Volumes/com.apple.TimeMachine.Data-2F398662-75DE-4661-B8E7-79CBDBAA6950'...
2018-11-18 11:35:57.141 mddiagnose[3416:11757872] Executing '/usr/bin/mdutil -P /Volumes/com.apple.TimeMachine.Data-2F398662-75DE-4661-B8E7-79CBDBAA6950'...
2018-11-18 11:35:57.209 mddiagnose[3416:11757872] Executing '/usr/bin/mdutil -L /Volumes/Time Machine Backups'...
2018-11-18 11:35:57.339 mddiagnose[3416:11757872] Executing '/usr/bin/mdutil -P /Volumes/Time Machine Backups'...
2018-11-18 11:35:57.405 mddiagnose[3416:11757872] Executing '/usr/bin/mdutil -L /Volumes/com.apple.TimeMachine.localsnapshots/Backups.backupdb/sharp/2018-11-18-110312/Macintosh HD'...
2018-11-18 11:35:57.469 mddiagnose[3416:11757872] Executing '/usr/bin/mdutil -P /Volumes/com.apple.TimeMachine.localsnapshots/Backups.backupdb/sharp/2018-11-18-110312/Macintosh HD'...
2018-11-18 11:35:57.536 mddiagnose[3416:11757872] Executing '/usr/bin/mdutil -L /.MobileBackups'...
2018-11-18 11:35:57.602 mddiagnose[3416:11757872] Executing '/usr/bin/mdutil -P /.MobileBackups'...
2018-11-18 11:35:57.667 mddiagnose[3416:11757872] Executing '/usr/bin/mdutil -L /Volumes/com.apple.TimeMachine.localsnapshots/Backups.backupdb/sharp/2018-11-18-110312/Macintosh HD/.MobileBackups'...
2018-11-18 11:35:57.732 mddiagnose[3416:11757872] Executing '/usr/bin/mdutil -P /Volumes/com.apple.TimeMachine.localsnapshots/Backups.backupdb/sharp/2018-11-18-110312/Macintosh HD/.MobileBackups'...
2018-11-18 11:35:57.860 mddiagnose[3416:11757872] Executing '/usr/bin/find / -name .metadata_never_index -maxdepth 1'...
2018-11-18 11:35:57.926 mddiagnose[3416:11757872] Executing '/usr/bin/find /Volumes -name .metadata_never_index -maxdepth 2'...
2018-11-18 11:35:58.637 mddiagnose[3416:11757872] Executing '/usr/bin/find / -name .metadata_never_index_unless_rootfs -maxdepth 1'...
2018-11-18 11:35:58.702 mddiagnose[3416:11757872] Executing '/usr/bin/find /Volumes -name .metadata_never_index_unless_rootfs -maxdepth 2'...
2018-11-18 11:35:58.767 mddiagnose[3416:11757872] Getting crash logs for 'mds'...
2018-11-18 11:35:58.769 mddiagnose[3416:11757872] Getting crash logs for 'mds_stores'...
2018-11-18 11:35:58.769 mddiagnose[3416:11757872] Getting crash logs for 'mdworker'...
2018-11-18 11:35:58.770 mddiagnose[3416:11757872] Getting crash logs for 'mdsync'...
2018-11-18 11:35:58.843 mddiagnose[3416:11757872] Spotlight diagnostic written in /private/var/tmp/.../sharp.mdsdiagnostic
2018-11-18 11:35:58.983 tmdiagnose[3195:2b13] Executing `/usr/sbin/spindump -notarget 15 -file /private/var/tmp/.../system_state_11.35.58/spindump.txt`
2018-11-18 11:36:01.057 tmdiagnose[3195:a127] Executing `/usr/bin/fs_usage -w -t 10 -e tmdiagnose`
2018-11-18 11:36:18.146 tmdiagnose[3195:2b13] Executing `/bin/ps auxh`
2018-11-18 11:36:18.280 tmdiagnose[3195:2b13] Executing `/usr/bin/top -l 10`
2018-11-18 11:36:28.588 tmdiagnose[3195:b03] Executing `/bin/chmod -R a=rwx /private/var/tmp/...`

*** Time Machine diagnostic written to: /private/var/tmp/...tmdiagnostic.zip

And that last zip file is what they want uploaded.


Posted

in

by