Time Machine auto backups fail on my new M2 Pro 16 MacBook?

[rjjacobson]

Well my new USB San disk is working great (very quick) but after having since last night I am observing that when screen is open the automated backup goes fine. But if I am away and screen is off something else also must be asleep because the auto backup does not complete and I get that same message:

“Time Machine did not finish backing up because some files were unavailable. Backups will resume when your Mac is unlocked.”

I read all the discussions about this and as I mentioned it seems more common on the newer M series Macs allthough not 100 percent. I read one guy saying turn on in advanced under display to keep MacBook from going asleep on the power connector but that did not solve problem. Last backup was before bed so when I got up at 7 it had not but after less than minute open the backup started. So something i cannot set is putting the process to sleep, this never happened on my old 15 inch late 2018 Macbook pro it is only happened on my new 16 inch M2-Pro MacBook.

Also note my new USB-c SSD drive was not here for a day so I was using old USB-3 HD and the same error starting occurring. The drive worked fine on the old 15 inch late 2018 i7 MacBook pro before attaching to my new M2 16 inch MacBook. And it had same error. Just curious what is going on if there is something else I can turn on to keep it awake 24/7?

This is not end of world just means the auto hourly backups do not happen until I open screen a minute or less later. Just a curious thing. So my old USB-3 drive was not failing although I wanted to move to this new USB-C San disk anyway

 

[rjjacobson]

Well interesting “conclusion“ to my Time Machine not working well in auto mode. Last night at 10 I noticed this backup did its first auto backup without me opening the screen from screen saver. I had during day turned the turn screen off mode to never, but added the screen saver. Did not seem to make difference but then this happened, like something settled in almost finally somewhere (on my new M2 16 inch macbook??) or is it that there are now about a dozen of the TM snapshots now backed up?

May never know if my moving to screen saver only helped or not or the bug worked out in OS code/something changed with files on HD it was always copying who knows?

 

[svenmany]

This problem just started with me yesterday. I am also using a brand new SanDisk SSD. About a week ago, I did adjust my screensaver to a timeout lower than just turning the display off. However, the error "Time Machine did not finish backing up because some files were unavailable" happened while I was using the computer.

I went ahead and reformatted the entire drive and restarted the backup; it tried to complete over night. This morning, I noticed that it had failed with the files unavailable error.

This is a new drive, just a few days old. My other two SanDisk TimeMachine disks are having no problems.

 

[rjjacobson]

This problem just started with me yesterday. I am also using a brand new SanDisk SSD. About a week ago, I did adjust my screensaver to a timeout lower than just turning the display off. However, the error "Time Machine did not finish backing up because some files were unavailable" happened while I was using the computer.

I went ahead and reformatted the entire drive and restarted the backup; it tried to complete over night. This morning, I noticed that it had failed with the files unavailable error.

This is a new drive, just a few days old. My other two SanDisk TimeMachine disks are having no problems.

For me it first happened on my new 16 inch M2 Pro MacBook Pro I got a week ago. It was then using my old external USB-3 HD (to install from my old 15 inch i7 Macbook pro -late 2018). And that was old drive that worked on the previous mac no problem. I had ordered the sandisk this weekend just to get a USB-c model and help speed. And of course it had same problem it is something with the new Mac and how these powered by Mac external drives work, sleep or something.

Well I spoke too soon, after the 10 hours of not failing (after just using screen saver along) the 10 am back up failed wit same error. I have been learning a lot about external SSDs this morning it seems.

 

[rjjacobson]

This problem just started with me yesterday. I am also using a brand new SanDisk SSD. About a week ago, I did adjust my screensaver to a timeout lower than just turning the display off. However, the error "Time Machine did not finish backing up because some files were unavailable" happened while I was using the computer.

I went ahead and reformatted the entire drive and restarted the backup; it tried to complete over night. This morning, I noticed that it had failed with the files unavailable error.

This is a new drive, just a few days old. My other two SanDisk TimeMachine disks are having no problems.

Given that mine was both old drive and my new sandisk drive I am leaning towards the settings that I read external drives have to “sleep” or almost sleep…. No way to know those settings however. This is what person on Apple communities told me…

“

ou received a reply​

Tesserax has replied to your question. You can view the full discussion in Communities. Time machine auto backups fail on my new M2 Pro 16 Macbook pro Whether or not these drives would enter "sleep" mode would be based on the manufacturer's design. A number of external drives do enter this mode when idle for a specific amount of time. The only way to really understand what is going on would require that you analyze the macOS logs. One great utility that I use is called Mints. The following article was written around macOS Catalina, but it still is valid for Ventura. It goes over the series of events that are logged during a normal TM backup process. As you will see, there is a lot of "magic" going on in the background. Ref: Time Machine 16: Reading a normal backup in Catalina using Mints - The Eclectic Light Company

 

[svenmany]

I have a two-month old 16 M2 MacBook Pro. It failed when connected to a CalDigit TB3 hub and it failed when connected directly to the Mac. For the entirety of the last two months, neither of my other SanDisk disks, connected to the hub, have failed.

I'm not sure if my problem is worse or different than yours, though. After the error we're discussing here, a subsequent backup failed saying the disk was full. That's the point at which I decided to reformat.

I'll report back here with any developments. Also, looking forward to anything you discover.

Mints is pretty nice. The developer is kind of famous and has other log query tools. I like Consolation3 - much simpler than using "log" at the command line.

I'll never consider keeping devices awake as a solution, especially so as we barrel towards extinction.

 

[rjjacobson]

I have a two-month old 16 M2 MacBook Pro. It failed when connected to a CalDigit TB3 hub and it failed when connected directly to the Mac. For the entirety of the last two months, neither of my other SanDisk disks, connected to the hub, have failed.

I'm not sure if my problem is worse or different than yours, though. After the error we're discussing here, a subsequent backup failed saying the disk was full. That's the point at which I decided to reformat.

I'll report back here with any developments. Also, looking forward to anything you discover.

Mints is pretty nice. The developer is kind of famous and has other log query tools. I like Consolation3 - much simpler than using "log" at the command line.

I'll never consider keeping devices awake as a solution, especially so as we barrel towards extinction.

I got some info from mint, here is summary of TM errors it found in log with one of few failed auto backup mostly they worked today;

Ok this app a person recommended (mint) to look at logs and what if found on one random still failed TM backup

I just clipped out the errors for quick viewing. Total log too long to display here however. What i see is some issue with the screen unlock which of course maybe is not error but its in bold in the log Mint app captured so I note it.



1) 23-04-04 12:16:36.004 TimeMach Running for notifyd event com.apple.mobile.keybagd.lock_status
23-04-04 12:16:36.005 TimeMach TMPowerState: 2
23-04-04 12:16:36.005 TimeMach Triggered for screen unlock!
23-04-04 12:16:36.005 TimeMach Running for notifyd event com.apple.mobile.keybagd.lock_status
23-04-04 12:16:36.007 TimeMach TMPowerState: 2
23-04-04 12:16:36.007 TimeMach Triggered for screen unlock!
23-04-04 12:16:36.008 TimeMach Running for notifyd event com.apple.mobile.keybagd.lock_status

This next error seems to state the screen lock stuff whatever it means delayed some unfinished protected files. See error 3 below

2) 23-04-04 12:16:36.011 TimeMach TMPowerState: 2
23-04-04 12:16:36.012 TimeMach Triggered for screen unlock!
23-04-04 12:16:36.012 [other] Finished acquiring assertion 156-93-2549(target:[osservice<com.apple.backupd-helper>:157])
23-04-04 12:16:36.013 TimeMach Running on wake for destination Extreme SSD with previous result BACKUP_DELAYED_UNFINISHED_PROTECTED_FILES

Is this the key error then?

3) 23-04-04 12:16:48.495 TimeMach Failed to enumerate URLs under /private/var/folders/5f/zlnns3rn5cd_kjd8kmnwcn400000gp/T/AppTranslocation/25B42771-77F0-45D4-B711-F1AC6158ACAD for SnapshotStorage reuse with error Error Domain=NSCocoaErrorDomain Code=256 "The file “25B42771-77F0-45D4-B711-F1AC6158ACAD” couldn’t be opened." UserInfo={NSURL=file:///private/var/folders/5f/zlnns3rn5cd_kjd8kmnwcn400000gp/T/AppTranslocation/25B42771-77F0-45D4-B711-F1AC6158ACAD, NSFilePath=/private/var/folders/5f/zlnns3rn5cd_kjd8kmnwcn400000gp/T/AppTranslocation/25B42771-77F0-45D4-B711-F1AC6158ACAD, NSUnderlyingError=0x124238500 {Error Domain=NSPOSIXErrorDomain Code=34 "Result too large"}}
23-04-04 12:16:48.564 DuetAS Rescoring all 369 activities [<private>]
23-04-04 12:16:48.565 TimeMach Failed to enumerate URLs under /private/var/folders/5f/zlnns3rn5cd_kjd8kmnwcn400000gp/T/AppTranslocation/25B42771-77F0-45D4-B711-F1AC6158ACAD for SnapshotStorage reuse with error Error Domain=NSCocoaErrorDomain Code=256 "The file “25B42771-77F0-45D4-B711-F1AC6158ACAD” couldn’t be opened." UserInfo={NSURL=file:///private/var/folders/5f/zlnns3rn5cd_kjd8kmnwcn400000gp/T/AppTranslocation/25B42771-77F0-45D4-B711-F1AC6158ACAD, NSFilePath=/private/var/folders/5f/zlnns3rn5cd_kjd8kmnwcn400000gp/T/AppTranslocation/25B42771-77F0-45D4-B711-F1AC6158ACAD, NSUnderlyingError=0x154733930 {Error Domain=NSPOSIXErrorDomain Code=34 "Result too large"}}

4) this little “error” also appears on the successful backup log so not sure its related or not:

23-04-04 12:16:48.937 TimeMach Failed to create volume info from disk '<TMDisk: 0x16302e800> '/System/Volumes/Data/home'', error: missingURLForRemounting
2

 

[rjjacobson]

Here is entire TM log for the one failed (of two that have failed). Its a PDF

 

[svenmany]

Here is entire TM log for the one failed (of two that have failed). Its a PDF

I'll certainly take a look tonight. I'll see if there are similar entries in my logs.

Today I had a different error. When my backup started on the new drive, the disk was ejected. When the volumes were remounted, the backup resumed and completed without errors. I tend to think this is a different issue.

I now have three disks connected to my Mac, each having 3 APFS volumes. I'll study my logs to see if there's some correlation to my errors and yours.

 

[rjjacobson]

I'll certainly take a look tonight. I'll see if there are similar entries in my logs.

Today I had a different error. When my backup started on the new drive, the disk was ejected. When the volumes were remounted, the backup resumed and completed without errors. I tend to think this is a different issue.

I now have three disks connected to my Mac, each having 3 APFS volumes. I'll study my logs to see if there's some correlation to my errors and yours.

Ok worked more with Mint below is a collection of logs of a failure, then a manual forced backup, then hour later autobackup log from TM

Failed log 5 PM below note the error in bold I marked. This temp folder T is shown in screen dump attached.

23-04-04 14:54:34.440 TimeMach Failed to enumerate URLs under /private/var/folders/5f/zlnns3rn5cd_kjd8kmnwcn400000gp/T/AppTranslocation/E07E7B4C-6E23-49D7-B6CB-076D76E7F2ED for SnapshotStorage reuse with error Error Domain=NSCocoaErrorDomain Code=256 "The file “E07E7B4C-6E23-49D7-B6CB-076D76E7F2ED” couldn’t be opened." UserInfo={NSURL=file:///private/var/folders/5f/zlnns3rn5cd_kjd8kmnwcn400000gp/T/AppTranslocation/E07E7B4C-6E23-49D7-B6CB-076D76E7F2ED, NSFilePath=/private/var/folders/5f/zlnns3rn5cd_kjd8kmnwcn400000gp/T/AppTranslocation/E07E7B4C-6E23-49D7-B6CB-076D76E7F2ED, NSUnderlyingError=0x12461dcb0 {Error Domain=NSPOSIXErrorDomain Code=34 "Result too large"}}
23-04-04 14:54:34.517 TimeMach Failed to enumerate URLs under /private/var/folders/5f/zlnns3rn5cd_kjd8kmnwcn400000gp/T/AppTranslocation/E07E7B4C-6E23-49D7-B6CB-076D76E7F2ED for SnapshotStorage reuse with error Error Domain=NSCocoaErrorDomain Code=256 "The file “E07E7B4C-6E23-49D7-B6CB-076D76E7F2ED” couldn’t be opened." UserInfo={NSURL=file:///private/var/folders/5f/zlnns3rn5cd_kjd8kmnwcn400000gp/T/AppTranslocation/E07E7B4C-6E23-49D7-B6CB-076D76E7F2ED, NSFilePath=/private/var/folders/5f/zlnns3rn5cd_kjd8kmnwcn400000gp/T/AppTranslocation/E07E7B4C-6E23-49D7-B6CB-076D76E7F2ED, NSUnderlyingError=0x154711a10 {Error Domain=NSPOSIXErrorDomain Code=34 "Result too large"}}
23-04-04 14:54:34.888 TimeMach Failed to create volume info from disk '<TMDisk: 0x162837e00> '/System/Volumes/Data/home'', error: missingURLForRemounting

Successful log 6 PM from a forced update (choose update now)

23-04-04 17:57:51.157 TimeMach Failed to create volume info from disk '<TMDisk: 0x16201cc00> '/System/Volumes/Data/home'', error: missingURLForRemounting
23-04-04 17:57:51.596 TimeMach Finished copying from volume "Data"
1727 Total Items Added (l: 1.21 GB p: 1.24 GB)
3 Total Items Propagated (shallow) (l: Zero KB p: Zero KB)
1832 Total Items Propagated (recursive) (l: 424.4 MB p: 418 MB)
3559 Total Items in Backup (l: 1.63 GB p: 1.66 GB)
1583 Files Copied (l: 1.19 GB p: 1.22 GB)
84 Directories Copied (l: Zero KB p: Zero KB)
57 Symlinks Copied (l: 1 KB p: Zero KB)
3 Directories Move Skipped (l: Zero KB p: Zero KB) | 1829 items propagated (l: 424.4 MB p: 418 MB)
3 Files Delta Copied (l: 16.5 MB p: 17 MB)
1 Files Optimized Moved (l: Zero KB p: Zero KB) | 1 items propagated (l: 300.8 MB p: 310.1 MB)
1297 Directories Optimized Moved (l: Zero KB p: Zero KB) | 1034584 items propagated (l: 612.14 GB p: 611.01 GB)
23-04-04 17:57:52.463 TimeMach FileProtectionAssertionBox: Dropped assertion!
23-04-04 17:57:52.468 TimeMach Closing device lock assertion taken at 2023-04-04-175740 with reason: Backup Completed.
23-04-04 17:57:52.468 TimeMach .•+********•.
23-04-04 17:57:52.469 TimeMach Time Estimates Evaluation
Actual: 0.1506893495718638 minutes
Mean variance: 0.0 minutes (-)
Time without estimate: 0.15 minutes
23-04-04 17:57:52.609 TimeMach Unmounted '/Volumes/com.apple.TimeMachine.localsnapshots/Backups.backupdb/Russ's 2023 16 inch M2. Pro -Macbook Pro/2023-04-04-175737/Data'
23-04-04 17:57:52.632 TimeMach Unmounted local snapshot: com.apple.TimeMachine.2023-04-04-175737.local at path: /Volumes/com.apple.TimeMachine.localsnapshots/Backups.backupdb/Russ's 2023 16 inch M2. Pro -Macbook Pro/2023-04-04-175737/Data source: Data
23-04-04 17:57:52.863 TimeMach Unmounted '/Volumes/com.apple.TimeMachine.localsnapshots/Backups.backupdb/Russ's 2023 16 inch M2. Pro -Macbook Pro/2023-04-04-144823/Data'
23-04-04 17:57:52.876 TimeMach Unmounted local snapshot: com.apple.TimeMachine.2023-04-04-144823.local at path: /Volumes/com.apple.TimeMachine.localsnapshots/Backups.backupdb/Russ's 2023 16 inch M2. Pro -Macbook Pro/2023-04-04-144823/Data source: Data
23-04-04 17:57:53.109 TimeMach Marked as reference snapshot: com.apple.TimeMachine.2023-04-04-175737.local
23-04-04 17:57:53.109 TimeMach Backup result: {
BackupStrategy = 3;
BlocksToCopy = 152101008;
BytesToCopy = 623005728768;
ClientID = "com.apple.backupd";
DestinationMountPoint = "/Volumes/Extreme SSD";
FreeBytes = 663467180032;
PaddedBytesRequired = 623005728768;
Progress = {
Percent = "0.2524874190372889";
"_raw_Percent" = "0.2524874190372889";
"_raw_totalBytes" = 623005728768;
bytes = 1238863872;
files = 1665;
sizingFreePreflight = 1;
totalBytes = 623005728768;
totalFiles = 1074301;
};
Running = 1;
"com.apple.backupd.SnapshotTotalBytesCopied" = 1238872064;
}
23-04-04 17:57:53.111 TimeMach Failed to create volume info from disk '<TMDisk: 0x162840a00> '/System/Volumes/Data/home'', error: missingURLForRemounting
23-04-04 17:57:53.142 TimeMach Found incomplete backups ready for deletion: (
"<APFSBackup: 0x14c7701d0> (2023-04-04-155234.interrupted) interrupted",
"<APFSBackup: 0x14c7b5a10> (2023-04-04-175344.interrupted) interrupted",
"<APFSBackup: 0x14c795d90> (2023-04-04-144903.previous) baseline",
"<APFSBackup: 0x14c7fc650> (2023-04-04-165311.interrupted) interrupted"
)
23-04-04 17:57:53.146 TimeMach No machine store path in notification __CFNotification 0x6000008298f0 {name = com.apple.backupd.thinningbackup; object = com.apple.backupd; userInfo = {
BackupPath = "/Volumes/Extreme SSD/2023-04-04-155234.interrupted";
}}. Ignoring...
23-04-04 17:57:53.254 TimeMach Failed to create volume info from disk '<TMDisk: 0x157818400> '/System/Volumes/Data/home'', error: missingURLForRemounting
23-04-04 17:57:58.729 TimeMach Deleted incomplete backup '/Volumes/Extreme SSD/2023-04-04-155234.interrupted'
23-04-04 17:57:58.733 TimeMach No machine store path in notification __CFNotification 0x600000828930 {name = com.apple.backupd.thinningbackup; object = com.apple.backupd; userInfo = {
BackupPath = "/Volumes/Extreme SSD/2023-04-04-175344.interrupted";
}}. Ignoring...
23-04-04 17:57:58.948 TimeMach Deleted incomplete backup '/Volumes/Extreme SSD/2023-04-04-175344.interrupted'
23-04-04 17:57:58.952 TimeMach No machine store path in notification __CFNotification 0x600000862e20 {name = com.apple.backupd.thinningbackup; object = com.apple.backupd; userInfo = {
BackupPath = "/Volumes/Extreme SSD/2023-04-04-144903.previous";
}}. Ignoring...
23-04-04 17:57:59.276 TimeMach Deleted incomplete backup '/Volumes/Extreme SSD/2023-04-04-144903.previous'
23-04-04 17:57:59.280 TimeMach No machine store path in notification __CFNotification 0x600000bfd170 {name = com.apple.backupd.thinningbackup; object = com.apple.backupd; userInfo = {
BackupPath = "/Volumes/Extreme SSD/2023-04-04-165311.interrupted";
}}. Ignoring...
23-04-04 17:57:59.811 TimeMach Deleted incomplete backup '/Volumes/Extreme SSD/2023-04-04-165311.interrupted'
23-04-04 17:57:59.811 TimeMach Creating APFS snapshot com.apple.TimeMachine.2023-04-04-175752.backup
23-04-04 17:58:00.010 TimeMach 21 backups: 2023-04-02-184850 to 2023-04-03-145232 (1hr,16d,4wk) MΔ: 30.27 GB
23-04-04 17:58:00.057 TimeMach Completed backup: 2023-04-04-175752.backup
23-04-04 17:58:00.059 TimeMach Mountpoint '/Volumes/Extreme SSD' is still valid
23-04-04 17:58:00.070 TimeMach Thinning 2 backups using age-based thinning, expected free space: 3.34 TB actual free space: 3.34 TB trigger 50 GB thin 83.33 GB dates: (
"2023-04-03-145232",
"2023-04-03-160454"
)
23-04-04 17:58:00.086 TimeMach Accepting a new connection from 'Finder' for service com.apple.backupd.session.xpc
23-04-04 17:58:00.086 TimeMach Backup list requested for machine store: /Volumes/Extreme SSD
23-04-04 17:58:00.159 TimeMach Found APFS backup "2023-04-04-175752"
23-04-04 17:58:00.160 TimeMach Deleted APFS backup "2023-04-03-145232"
23-04-04 17:58:00.240 TimeMach Unmounted '/Volumes/.timemachine/661249C8-5399-476C-A791-F6BE54B29420/2023-04-03-145232.backup'
23-04-04 17:58:00.253 TimeMach Accepting a new connection from 'Finder' for service com.apple.backupd.session.xpc
23-04-04 17:58:00.254 TimeMach Backup list requested for machine store: /Volumes/Extreme SSD
23-04-04 17:58:00.312 TimeMach Deleted APFS backup "2023-04-03-160454"
23-04-04 17:58:00.362 TimeMach Accepting a new connection from 'Finder' for service com.apple.backupd.session.xpc
23-04-04 17:58:00.362 TimeMach Backup list requested for machine store: /Volumes/Extreme SSD
23-04-04 17:58:00.476 TimeMach Unmounted '/Volumes/.timemachine/661249C8-5399-476C-A791-F6BE54B29420/2023-04-03-160454.backup'
23-04-04 17:58:00.480 TimeMach Mountpoint '/Volumes/Extreme SSD' is still valid
23-04-04 17:58:00.715 TimeMach Failed to create volume info from disk '<TMDisk: 0x16201c800> '/System/Volumes/Data/home'', error: missingURLForRemounting
23-04-04 17:58:00.876 TimeMach Failed to create volume info from disk '<TMDisk: 0x160010c00> '/System/Volumes/Data/home'', error: missingURLForRemounting

Successful log 7 PM TM ran auto update on own again.

23-04-04 19:06:15.113 TimeMach Running for notifyd event com.apple.mobile.keybagd.lock_status
23-04-04 19:06:15.114 TimeMach TMPowerState: 2
23-04-04 19:06:15.114 TimeMach Triggered for screen unlock!
23-04-04 19:06:15.114 TimeMach Running for notifyd event com.apple.mobile.keybagd.lock_status
23-04-04 19:06:15.114 TimeMach TMPowerState: 2
23-04-04 19:06:15.114 TimeMach Triggered for screen unlock!
23-04-04 19:06:15.141 TimeMach Changed from "deviceIsLocked" to "deviceIsUnlocked"
23-04-04 19:06:15.142 TimeMach Running for notifyd event com.apple.mobile.keybagd.lock_status
23-04-04 19:06:15.144 TimeMach Changed from "deviceIsLocked" to "deviceIsUnlocked"
23-04-04 19:06:15.146 TimeMach Changed from "deviceIsLocked" to "deviceIsUnlocked"
23-04-04 19:06:15.147 TimeMach Changed from "deviceIsLocked" to "deviceIsUnlocked"
23-04-04 19:06:15.149 TimeMach Changed from "deviceIsLocked" to "deviceIsUnlocked"
23-04-04 19:06:15.149 TimeMach TMPowerState: 2
23-04-04 19:06:15.149 TimeMach Triggered for screen unlock!
23-04-04 19:06:15.150 TimeMach Changed from "deviceIsLocked" to "deviceIsUnlocked"
23-04-04 19:06:15.151 TimeMach Changed from "deviceIsUnlocked" to "deviceIsUnlocked"
23-04-04 19:06:15.153 TimeMach Changed from "deviceIsUnlocked" to "deviceIsUnlocked"
23-04-04 19:06:15.154 TimeMach Changed from "deviceIsUnlocked" to "deviceIsUnlocked"
23-04-04 19:06:15.155 TimeMach Changed from "deviceIsUnlocked" to "deviceIsUnlocked"
23-04-04 19:06:15.155 TimeMach Changed from "deviceIsUnlocked" to "deviceIsUnlocked"
23-04-04 19:06:15.156 TimeMach Changed from "deviceIsUnlocked" to "deviceIsUnlocked"
23-04-04 19:06:15.156 TimeMach Changed from "deviceIsUnlocked" to "deviceIsUnlocked"
23-04-04 19:06:15.157 TimeMach Changed from "deviceIsUnlocked" to "deviceIsUnlocked"
23-04-04 19:06:15.158 TimeMach Changed from "deviceIsUnlocked" to "deviceIsUnlocked"
23-04-04 19:06:15.159 TimeMach Changed from "deviceIsUnlocked" to "deviceIsUnlocked"
23-04-04 19:06:15.160 TimeMach Changed from "deviceIsUnlocked" to "deviceIsUnlocked"
23-04-04 19:06:15.161 TimeMach Changed from "deviceIsUnlocked" to "deviceIsUnlocked"

 

[svenmany]

The AppTranslocation thing is probably not an issue - although I'd like to hear more if you think it is. Did it cause TimeMachine to report an error, other than in the logs?

/private/var/folders/5f/zlnns3rn5cd_kjd8kmnwcn400000gp/T - is your temporary directory, which is cleared after rebooting. The AppTranslocation/E07E7B4C-6E23-49D7-B6CB-076D76E7F2ED is an "app translocation". Coincidentally, the author of Mints explains that here.

In that E07... directory is some kind of special file where an application bundle is mounted. The "mount" command at the terminal will show mounted translocations. Perhaps you ran a program from somewhere other than your applications folder and it had it mounted there when your backup was run. I'm not surprised that TimeMachine failed to back up such a thing.

You see where your log says "{Error Domain=NSPOSIXErrorDomain Code=34 "Result too large"}}"? If you use terminal and navigate to that app translocation directory and run the "ls" command, you'll get the result "ls: fts_read: Result too large". (I just triggered an app translocation to test that.) I think TimeMachine is just logging that failure.

But, to be honest, I know almost nothing about app translocation.

I do see a lines like "23-04-04 12:16:48.937 TimeMach Failed to create volume info from disk '<TMDisk: 0x16302e800> '/System/Volumes/Data/home'', error: missingURLForRemounting" in my logs. I ran "log show --predicate '(sender=="TimeMachine" && eventMessage CONTAINS "Failed to create volume")' and got a ton of results showing that same path over the last two days (since I last rebooted). '/System/Volumes/Data' is just where your main data volume is mounted. I'm not sure why the "home" subdirectory is problematic, but Finder does show it with a disk icon (so TimeMachine seems to try to mount something there but fails since it doesn't know what to mount). Once again, I'm not convinced this is an issue.

When I got the time machine error about some file being unavailable, it wasn't a file in my temp folder or some other special directory. I'm sorry that I can't remember the name of the file. I'm going to have to wait till it happens again and report what I see in the logs.

 

[rjjacobson]

The AppTranslocation thing is probably not an issue - although I'd like to hear more if you think it is. Did it cause TimeMachine to report an error, other than in the logs?

/private/var/folders/5f/zlnns3rn5cd_kjd8kmnwcn400000gp/T - is your temporary directory, which is cleared after rebooting. The AppTranslocation/E07E7B4C-6E23-49D7-B6CB-076D76E7F2ED is an "app translocation". Coincidentally, the author of Mints explains that here.

In that E07... directory is some kind of special file where an application bundle is mounted. The "mount" command at the terminal will show mounted translocations. Perhaps you ran a program from somewhere other than your applications folder and it had it mounted there when your backup was run. I'm not surprised that TimeMachine failed to back up such a thing.

You see where your log says "{Error Domain=NSPOSIXErrorDomain Code=34 "Result too large"}}"? If you use terminal and navigate to that app translocation directory and run the "ls" command, you'll get the result "ls: fts_read: Result too large". (I just triggered an app translocation to test that.) I think TimeMachine is just logging that failure.

But, to be honest, I know almost nothing about app translocation.

I do see a lines like "23-04-04 12:16:48.937 TimeMach Failed to create volume info from disk '<TMDisk: 0x16302e800> '/System/Volumes/Data/home'', error: missingURLForRemounting" in my logs. I ran "log show --predicate '(sender=="TimeMachine" && eventMessage CONTAINS "Failed to create volume")' and got a ton of results showing that same path over the last two days (since I last rebooted). '/System/Volumes/Data' is just where your main data volume is mounted. I'm not sure why the "home" subdirectory is problematic, but Finder does show it with a disk icon (so TimeMachine seems to try to mount something there but fails since it doesn't know what to mount). Once again, I'm not convinced this is an issue.

When I got the time machine error about some file being unavailable, it wasn't a file in my temp folder or some other special directory. I'm sorry that I can't remember the name of the file. I'm going to have to wait till it happens again and report what I see in the logs.

I see those errors also not sure what goes on my auto backup did not run til I opened screen, I saw some message about screen lock something I am suspicious of the screen lock (needing my password, fingerprint or watch to unlock the computer even from screen saver mode. Might experiment and turn the unlock off and see what happens.

I see lots of errors like yours you mentioned “23-04-04 12:16:48.937 TimeMach Failed to create volume info from disk '<TMDisk: 0x16302e800> '/System/Volumes/Data/home'', error: missingURLForRemounting"” curious what those mean but I am clueless


Yea the error /private/var/folders/5f/zlnns3rn5cd_kjd8kmnwcn400000gp/T - is definately temporary directory, which is cleared after rebooting. The AppTranslocation is interesting my mint is in applications/utilities but if I just move to applications still puts that temp there. Look at the photo below with the Mint running and the T folder open in window the temp file appears as soon as I open Mint and then leaves when I quit mint. Will have to read that link and documentation LOL I never read much of docs just start using LOL

 

[rjjacobson]

The AppTranslocation thing is probably not an issue - although I'd like to hear more if you think it is. Did it cause TimeMachine to report an error, other than in the logs?

/private/var/folders/5f/zlnns3rn5cd_kjd8kmnwcn400000gp/T - is your temporary directory, which is cleared after rebooting. The AppTranslocation/E07E7B4C-6E23-49D7-B6CB-076D76E7F2ED is an "app translocation". Coincidentally, the author of Mints explains that here.

In that E07... directory is some kind of special file where an application bundle is mounted. The "mount" command at the terminal will show mounted translocations. Perhaps you ran a program from somewhere other than your applications folder and it had it mounted there when your backup was run. I'm not surprised that TimeMachine failed to back up such a thing.

You see where your log says "{Error Domain=NSPOSIXErrorDomain Code=34 "Result too large"}}"? If you use terminal and navigate to that app translocation directory and run the "ls" command, you'll get the result "ls: fts_read: Result too large". (I just triggered an app translocation to test that.) I think TimeMachine is just logging that failure.

But, to be honest, I know almost nothing about app translocation.

I do see a lines like "23-04-04 12:16:48.937 TimeMach Failed to create volume info from disk '<TMDisk: 0x16302e800> '/System/Volumes/Data/home'', error: missingURLForRemounting" in my logs. I ran "log show --predicate '(sender=="TimeMachine" && eventMessage CONTAINS "Failed to create volume")' and got a ton of results showing that same path over the last two days (since I last rebooted). '/System/Volumes/Data' is just where your main data volume is mounted. I'm not sure why the "home" subdirectory is problematic, but Finder does show it with a disk icon (so TimeMachine seems to try to mount something there but fails since it doesn't know what to mount). Once again, I'm not convinced this is an issue.

When I got the time machine error about some file being unavailable, it wasn't a file in my temp folder or some other special directory. I'm sorry that I can't remember the name of the file. I'm going to have to wait till it happens again and report what I see in the logs.

Wow interesting discussion on the translocation issue. App never crashe’s though just that translocation occurring. I guess even after reusing from applications or applications/utilities where I put it does not get rid of the quarantine flag he talks about. Not sure why that info shows up either when I run Mint after a failed or successful backup. For now backups seem to randomly occur successfully, but mainly when I open the screen — that screen lock message in log perhaps?

 

[rjjacobson]

The AppTranslocation thing is probably not an issue - although I'd like to hear more if you think it is. Did it cause TimeMachine to report an error, other than in the logs?

/private/var/folders/5f/zlnns3rn5cd_kjd8kmnwcn400000gp/T - is your temporary directory, which is cleared after rebooting. The AppTranslocation/E07E7B4C-6E23-49D7-B6CB-076D76E7F2ED is an "app translocation". Coincidentally, the author of Mints explains that here.

In that E07... directory is some kind of special file where an application bundle is mounted. The "mount" command at the terminal will show mounted translocations. Perhaps you ran a program from somewhere other than your applications folder and it had it mounted there when your backup was run. I'm not surprised that TimeMachine failed to back up such a thing.

You see where your log says "{Error Domain=NSPOSIXErrorDomain Code=34 "Result too large"}}"? If you use terminal and navigate to that app translocation directory and run the "ls" command, you'll get the result "ls: fts_read: Result too large". (I just triggered an app translocation to test that.) I think TimeMachine is just logging that failure.

But, to be honest, I know almost nothing about app translocation.

I do see a lines like "23-04-04 12:16:48.937 TimeMach Failed to create volume info from disk '<TMDisk: 0x16302e800> '/System/Volumes/Data/home'', error: missingURLForRemounting" in my logs. I ran "log show --predicate '(sender=="TimeMachine" && eventMessage CONTAINS "Failed to create volume")' and got a ton of results showing that same path over the last two days (since I last rebooted). '/System/Volumes/Data' is just where your main data volume is mounted. I'm not sure why the "home" subdirectory is problematic, but Finder does show it with a disk icon (so TimeMachine seems to try to mount something there but fails since it doesn't know what to mount). Once again, I'm not convinced this is an issue.

When I got the time machine error about some file being unavailable, it wasn't a file in my temp folder or some other special directory. I'm sorry that I can't remember the name of the file. I'm going to have to wait till it happens again and report what I see in the logs.

Ok here is what documentation says about the categories for the Time Machine Log:

DAS (Duet Activity Scheduler)
CTS (XPC, Centralized Task Scheduling).
Other (who knows a catch all I suppose LOL)

 

[rjjacobson]

@svenmany and found the explanation for time setting on my log windows. Cool I guess actually reading documentation helps LOL

 

[svenmany]

You are developing quite the skill set. It will serve you well.

That developer is a gem; so much to learn from him (not to mention the art). I'm going to study https://eclecticlight.co/2020/07/17/time-machine-16-reading-a-normal-backup-in-catalina-using-mints/ a bit tonight.

So far, the only thing in common between us is that we both got the error that a file was unavailable. I don't seem to have any issues with sleep (whiskey solves that one). Instead, I have some USB disconnect issues. It could be that the file issue is a side-effect of various actual problems and we might have different ones.

The quest continues...

 

[rjjacobson]

You are developing quite the skill set. It will serve you well.

That developer is a gem; so much to learn from him (not to mention the art). I'm going to study https://eclecticlight.co/2020/07/17/time-machine-16-reading-a-normal-backup-in-catalina-using-mints/ a bit tonight.

Will have to use that link also to stud more finding eclectriclight.co is a real eyeopener such a weath of info I explored it a lot besides downloading Mint.

So far, the only thing in common between us is that we both got the error that a file was unavailable. I don't seem to have any issues with sleep (whiskey solves that one). Instead, I have some USB disconnect issues. It could be that the file issue is a side-effect of various actual problems and we might have different ones.

Would not be impossible. When you look at in this one log the detail of what is going on, realize how many thousands? Millions? lines of code involved and what can be going on there its amazing these machines work at all LOL

what is whiskey? Maybe I need that to test the sleep issue more???

The quest continues...

 

[rjjacobson]

You are developing quite the skill set. It will serve you well.

That developer is a gem; so much to learn from him (not to mention the art). I'm going to study https://eclecticlight.co/2020/07/17/time-machine-16-reading-a-normal-backup-in-catalina-using-mints/ a bit tonight.

So far, the only thing in common between us is that we both got the error that a file was unavailable. I don't seem to have any issues with sleep (whiskey solves that one). Instead, I have some USB disconnect issues. It could be that the file issue is a side-effect of various actual problems and we might have different ones.

The quest continues...

Well I now know how to look at log for previous failed backup through the next successful one (without that error about protected files or such ). I looked at the log, turning each thing off to see and such, I agree the error seems to be one of two things not sure which:

1) errors about files not available a bunch of those —- even during successful backup hmmm wonder what that means?

2) Issues with screen lock do show up sorta especially during success it says it is open and then if basically goes. Thinking it is my screen lock even in just screen saver mode with the screen off mode never.

The next test will be to turn screen lock off unless that removes too much security (its at my home office I am retired)

Below are two log sets first whole log, then one with the other turned off as author suggests. Feel free to look at them or compare as you continue on this quest ;-)

the second is everything it is 2.7 MB vs the first just code without the other much shorter.

 

[rjjacobson]

You are developing quite the skill set. It will serve you well.

That developer is a gem; so much to learn from him (not to mention the art). I'm going to study https://eclecticlight.co/2020/07/17/time-machine-16-reading-a-normal-backup-in-catalina-using-mints/ a bit tonight.

So far, the only thing in common between us is that we both got the error that a file was unavailable. I don't seem to have any issues with sleep (whiskey solves that one). Instead, I have some USB disconnect issues. It could be that the file issue is a side-effect of various actual problems and we might have different ones.

The quest continues...

Well problem is solved and as I suspected it was the dang screen lock on this new M2 Pro 16 inch MacBook Pro I got a week ago. Never happed with my old USB-3 drive on my 15 inch i7 MacBook Pro in Ventura 13.3 just when I moved that drive to the new M2 Pro 16 inch. And with the new sandisk SSD as well same issue. I have had now 6 hourly backups with the screen lock off. Of course then people can get into my macbook which is at home as it warned me and wondered if I wanted keychain off so someone could not see it. They still have to figure out password to see my login data. Most of time not a problem as my machine is at home and I am retired so not in a high security risk area. I might turn it on when out of town or something but we will cross that when need arises.

 

[rjjacobson]

You are developing quite the skill set. It will serve you well.

That developer is a gem; so much to learn from him (not to mention the art). I'm going to study https://eclecticlight.co/2020/07/17/time-machine-16-reading-a-normal-backup-in-catalina-using-mints/ a bit tonight.

So far, the only thing in common between us is that we both got the error that a file was unavailable. I don't seem to have any issues with sleep (whiskey solves that one). Instead, I have some USB disconnect issues. It could be that the file issue is a side-effect of various actual problems and we might have different ones.

The quest continues...

Just to complete this for now here is the 9 PM backup it’s been backing up since 11 AM with the screen lock off. It seemed to miss the 8 PM out of all those 11 Am to 9 PM but I guess it did not need one??? Anyway here is PDF of the log of the 9 PM with other turned off so there is less to look through . Still see those errors about files not copying or things not mounting but backup worked there is new snapshot on my SSD.

Note Towards the end it grabs info from the begining of the time frame I gave it 4 minutes back so for some reason the addition of the following where it sees the file created by Mint and it is trying to do something with this protected file because the OS still does not fully trust Mint I guess? Here is section not part of back up but looks like it was getttign ready when the file was created for eventual backup?

”23-04-05 21:01:12.163 TimeMach Failed to enumerate URLs
under /private/var/folders/5f/
zlnns3rn5cd_kjd8kmnwcn400000gp/T/AppTranslocation/
64D44F0F-FAF6-458B-8C22-F50ED7F4F0C3 for SnapshotStorage
reuse with error Error Domain=NSCocoaErrorDomain Code=256
"The file “64D44F0F-FAF6-458B-8C22-F50ED7F4F0C3” couldn’t
be opened." UserInfo={NSURL=file:///private/var/folders/
5f/zlnns3rn5cd_kjd8kmnwcn400000gp/T/AppTranslocation/
64D44F0F-FAF6-458B-8C22-F50ED7F4F0C3, NSFilePath=/private/
var/folders/5f/zlnns3rn5cd_kjd8kmnwcn400000gp/T/
AppTranslocation/64D44F0F-FAF6-458B-8C22-F50ED7F4F0C3,
NSUnderlyingError=0x11f0046f0 {Error
Domain=NSPOSIXErrorDomain Code=34 "Result too large"}}
23-04-05 21:01:12.237 TimeMach Failed to enumerate URLs
under /private/var/folders/5f/
zlnns3rn5cd_kjd8kmnwcn400000gp/T/AppTranslocation/
64D44F0F-FAF6-458B-8C22-F50ED7F4F0C3 for SnapshotStorage
reuse with error Error Domain=NSCocoaErrorDomain Code=256
"The file “64D44F0F-FAF6-458B-8C22-F50ED7F4F0C3” couldn’t
be opened." UserInfo={NSURL=file:///private/var/folders/

5f/zlnns3rn5cd_kjd8kmnwcn400000gp/T/AppTranslocation/
64D44F0F-FAF6-458B-8C22-F50ED7F4F0C3, NSFilePath=/private/
var/folders/5f/zlnns3rn5cd_kjd8kmnwcn400000gp/T/
AppTranslocation/64D44F0F-FAF6-458B-8C22-F50ED7F4F0C3,
NSUnderlyingError=0x10ea24510 {Error
Domain=NSPOSIXErrorDomain Code=34 "Result too large"}}
23-04-05 21:01:12.624 TimeMach Failed to create volume
info from disk '<TMDisk: 0x15a03a400> '/System/Volumes/
Data/home'', error: missingURLForRemounting”

 

[rjjacobson]

You are developing quite the skill set. It will serve you well.

That developer is a gem; so much to learn from him (not to mention the art). I'm going to study https://eclecticlight.co/2020/07/17/time-machine-16-reading-a-normal-backup-in-catalina-using-mints/ a bit tonight.

So far, the only thing in common between us is that we both got the error that a file was unavailable. I don't seem to have any issues with sleep (whiskey solves that one). Instead, I have some USB disconnect issues. It could be that the file issue is a side-effect of various actual problems and we might have different ones.

The quest continues...

Well now I solved issue I am looking at little details.
Just some wrap up learning with Time Machine backups. I basically just let default setting run once a particular external drive is attached. While I solved my backup failures and it was the screen lock feature it never was issue on my trusty 15 inch late 2018 i7 MacBook Pro so I went back and looked at the drive I was using (a Toshiba 3 TB USB-3 drive). It only has backups til early last year but it was backing up weekly (I thought it was doing more often given how I would sometimes seem to hit backups slowing things down when backing up my iphone andi ipad to the Mac)

But now it’s set by default on my Ventura 13.3 on the new M2 Pro 16 incher to hourly. Not sure why things changed from old computer to new one (even for few days the old HD was being used before I got my SSD). So the burning question what is best period for backup? Three choices, hourly, once a day, or weekly. I am predisposed to change things to daily not sure why I need to have hourly backups anyway. It seemed that at least for past year it was actually weekly though from when I started the HD on my 15 inch i7 late 2018 MacBook Pro in January of 2022 on this USB-3 HD external.

Note below the option to easily change this frequency was only available in Ventura so I am guessing it was set to weekly by default before. I am thinking since I find no recommendation other than lots of folks in older OS’s using scripts to change to a preferred weekly mode.

Apple says:

Backup frequency and duration​

Time Machine makes hourly backups for the past 24 hours, daily backups for the past month, and weekly backups for all previous months. The oldest backups are deleted when your backup disk is full.
Beginning with macOS Ventura, you can change the backup frequency: Open Time Machine settings, click Options, then choose a setting from the “Back up frequency” menu. The first backup might take a long time, but you can continue using your Mac while a backup is underway. Time Machine backs up only the files that changed since the previous backup, so future backups will be faster

 

[svenmany]

I'm happy you reached closure. I haven't had the unavailable file error since I posted to this thread, so I'm going to pretend I reached closure. My drive disconnects happen right at the end of the backup; I can't completely rule out a hardware problem. I suspect I'll return the drive, but keep investigating until the end of my return window.

The main problem with investigating things using the logs is that they are cluttered with excessive messages that serve no one. I've never had Apple request those logs and I don't benefit much from all the messages. What's particularly egregious is the number of log entries that are classified as errors but really aren't. Some developer classified something as an error without considering the broader context which would explain why it's not an error. There's something fundamentally flawed if a log is full of warnings and errors which are almost always ignored.

So the burning question what is best period for backup? Three choices, hourly, once a day, or weekly. I am predisposed to change things to daily not sure why I need to have hourly backups anyway.

I need an hourly schedule based on the situations where I've depended on the backup. Maybe once a month I will have modified some file and need to go back to how it was at the beginning of the day. I'm a software developer, so I'm modifying files all of the time. Some of my tools also provide this functionality, but they're not as comprehensive.

what is whiskey?

Sorry, I really wan't clear. I'm partial to Ardbeg. (I have to remember to insert smiley faces when I crack a joke.)

 

[rjjacobson]

I'm happy you reached closure. I haven't had the unavailable file error since I posted to this thread, so I'm going to pretend I reached closure. My drive disconnects happen right at the end of the backup; I can't completely rule out a hardware problem. I suspect I'll return the drive, but keep investigating until the end of my return window.

Yeah we are sorta at temporary closure LOL

The main problem with investigating things using the logs is that they are cluttered with excessive messages that serve no one. I've never had Apple request those logs and I don't benefit much from all the messages. What's particularly egregious is the number of log entries that are classified as errors but really aren't. Some developer classified something as an error without considering the broader context which would explain why it's not an error. There's something fundamentally flawed if a log is full of warnings and errors which are almost always ignored.

Yep starting to get that idea about alot of what I read.

I need an hourly schedule based on the situations where I've depended on the backup. Maybe once a month I will have modified some file and need to go back to how it was at the beginning of the day. I'm a software developer, so I'm modifying files all of the time. Some of my tools also provide this functionality, but they're not as comprehensive.

Just moved it to daily and see what that does. I am a retired geologist and i have lots of photos and such of fossil trilobites, birds and butterflies and flowers. Those are things most likely to change of course I I just upload a big batch of photos I will just do a manual backup now. So weekly would work. No software developer myself

Sorry, I really wan't clear. I'm partial to Ardbeg. (I have to remember to insert smiley faces when I crack a joke.)

LOL wondered if it were a joke, like Cab and Merlot, good craft beers and good scotch myself LOL

 

[steve123]

@rjjacobson FYI, this thread may be of interest to you.

External USB Hard Drive spins up/down all the time

macOS Monterey 12.1 on a new M1 MacBook Air with a WD Elements EasyStore 8TB USB 3 hard drive. I specifically turned off "Put Hard Disks to sleep when possible" in the Battery preference pane (on both battery and power adapter modes just to be sure). This worked fine on my previous iMac (running...

forums.macrumors.com

There is an issue with Apple Silicon macs with externally attached disks where the disks spin down and spin up again. This may be relevant because when the disk spins down a Time Machine backup may be interrupted, causing the spurious message about the disk not being available.

People have been working around the issue by preventing the computer from ever sleeping which sounds like what you are doing.

 

[rjjacobson]

@rjjacobson FYI, this thread may be of interest to you.

External USB Hard Drive spins up/down all the time

macOS Monterey 12.1 on a new M1 MacBook Air with a WD Elements EasyStore 8TB USB 3 hard drive. I specifically turned off "Put Hard Disks to sleep when possible" in the Battery preference pane (on both battery and power adapter modes just to be sure). This worked fine on my previous iMac (running...

forums.macrumors.com

There is an issue with Apple Silicon macs with externally attached disks where the disks spin down and spin up again. This may be relevant because when the disk spins down a Time Machine backup may be interrupted, causing the spurious message about the disk not being available.

People have been working around the issue by preventing the computer from ever sleeping which sounds like what you are doing.

Yeah that’s about right. Not sure how turning off screen lock helps if that is the issue but these silcon machines are different