Whitehill
Registered
Well, strange to me. See the log below. This has been happening for about a week. The TM backup at 9PM finishes normally. Something (?) remounts the TC at 9:30PM. The TM backup at 10PM fails because the TC is already mounted.
I do have scheduled at 9:30PM M-F a SuperDuper! backup to a different device, a USB external - it completes with no problem. I have a feeling that SD is the culprit, just because of the timing. One time, with the USB disk ejected, I started SD and it told it could not find the Time Capsule?!
I just changed the SD schedule to skip tonight's backup. I'll see what happens when I get in tom'w morning.
Is there somewhere else to look to try to discover what's going on?
9/5/12 9:06:28.550 PM com.apple.backupd[42126]: Backup completed successfully.
9/5/12 9:06:31.617 PM com.apple.backupd[42126]: Ejected Time Machine disk image: /Volumes/Data/server.sparsebundle
9/5/12 9:06:31.882 PM com.apple.backupd[42126]: Ejected Time Machine network volume.
9/5/12 9:06:32.000 PM kernel[0]: AFP_VFS afpfs_unmount: /Volumes/Data, flags 0, pid 42156
9/5/12 9:06:32.000 PM kernel[0]: AFP_VFS afpfs_unmount : We are the last mnt/sbmnt using volume /Volumes/Data 0xffffff80f53f7008
9/5/12 9:06:32.000 PM kernel[0]: AFP_VFS afpfs_unmount : We are the last volume using socket /Volumes/Data 0xffffff80f53f7008
9/5/12 9:06:32.000 PM kernel[0]: AFP_VFS afpfs_unmount : afpfs_DoReconnect sent signal for unmount to proceed
9/5/12 9:30:06.000 PM kernel[0]: AFP_VFS afpfs_mount: /Volumes/Data, pid 42370
9/5/12 9:30:06.000 PM kernel[0]: AFP_VFS afpfs_mount : succeeded on volume 0xffffff80f5437008 /Volumes/Data (error = 0, retval = 0)
9/5/12 10:05:16.288 PM com.apple.backupd[43034]: Starting automatic backup
9/5/12 10:05:16.964 PM com.apple.backupd[43034]: Attempting to mount network destination URL: afp://xxxxxxx%20xxxxxxx;AUTH=SRP@My%20Time%20Capsule._afpovertcp._tcp.local/Data
9/5/12 10:05:17.457 PM com.apple.backupd[43034]: Mounted network destination at mount point: /Volumes/Data-1 using URL: afp://xxxxxxx%20xxxxxxx;AUTH=SRP@My%20Time%20Capsule._afpovertcp._tcp.local/Data
9/5/12 10:05:17.000 PM kernel[0]: ASP_TCP asp_tcp_usr_control: invalid kernelUseCount 0
9/5/12 10:05:17.000 PM kernel[0]: AFP_VFS afpfs_mount: /Volumes/Data-1, pid 43036
9/5/12 10:05:17.000 PM kernel[0]: AFP_VFS afpfs_mount : succeeded on volume 0xffffff80f5144008 /Volumes/Data-1 (error = 0, retval = 0)
9/5/12 10:05:31.139 PM com.apple.backupd[43034]: Disk image already attached: /Volumes/Data-1/server.sparsebundle, DIHLDiskImageAttach returned: 35
9/5/12 10:05:32.359 PM com.apple.backupd[43034]: Failed to mount disk image: Error Domain=com.apple.backupd.ErrorDomain Code=31 "The operation couldnt be completed. (com.apple.backupd.ErrorDomain error 31.)" UserInfo=0x7fd89a026900 {MessageParameters=(
"/Volumes/Data-1/server.sparsebundle"
)}
I do have scheduled at 9:30PM M-F a SuperDuper! backup to a different device, a USB external - it completes with no problem. I have a feeling that SD is the culprit, just because of the timing. One time, with the USB disk ejected, I started SD and it told it could not find the Time Capsule?!
I just changed the SD schedule to skip tonight's backup. I'll see what happens when I get in tom'w morning.
Is there somewhere else to look to try to discover what's going on?
9/5/12 9:06:28.550 PM com.apple.backupd[42126]: Backup completed successfully.
9/5/12 9:06:31.617 PM com.apple.backupd[42126]: Ejected Time Machine disk image: /Volumes/Data/server.sparsebundle
9/5/12 9:06:31.882 PM com.apple.backupd[42126]: Ejected Time Machine network volume.
9/5/12 9:06:32.000 PM kernel[0]: AFP_VFS afpfs_unmount: /Volumes/Data, flags 0, pid 42156
9/5/12 9:06:32.000 PM kernel[0]: AFP_VFS afpfs_unmount : We are the last mnt/sbmnt using volume /Volumes/Data 0xffffff80f53f7008
9/5/12 9:06:32.000 PM kernel[0]: AFP_VFS afpfs_unmount : We are the last volume using socket /Volumes/Data 0xffffff80f53f7008
9/5/12 9:06:32.000 PM kernel[0]: AFP_VFS afpfs_unmount : afpfs_DoReconnect sent signal for unmount to proceed
9/5/12 9:30:06.000 PM kernel[0]: AFP_VFS afpfs_mount: /Volumes/Data, pid 42370
9/5/12 9:30:06.000 PM kernel[0]: AFP_VFS afpfs_mount : succeeded on volume 0xffffff80f5437008 /Volumes/Data (error = 0, retval = 0)
9/5/12 10:05:16.288 PM com.apple.backupd[43034]: Starting automatic backup
9/5/12 10:05:16.964 PM com.apple.backupd[43034]: Attempting to mount network destination URL: afp://xxxxxxx%20xxxxxxx;AUTH=SRP@My%20Time%20Capsule._afpovertcp._tcp.local/Data
9/5/12 10:05:17.457 PM com.apple.backupd[43034]: Mounted network destination at mount point: /Volumes/Data-1 using URL: afp://xxxxxxx%20xxxxxxx;AUTH=SRP@My%20Time%20Capsule._afpovertcp._tcp.local/Data
9/5/12 10:05:17.000 PM kernel[0]: ASP_TCP asp_tcp_usr_control: invalid kernelUseCount 0
9/5/12 10:05:17.000 PM kernel[0]: AFP_VFS afpfs_mount: /Volumes/Data-1, pid 43036
9/5/12 10:05:17.000 PM kernel[0]: AFP_VFS afpfs_mount : succeeded on volume 0xffffff80f5144008 /Volumes/Data-1 (error = 0, retval = 0)
9/5/12 10:05:31.139 PM com.apple.backupd[43034]: Disk image already attached: /Volumes/Data-1/server.sparsebundle, DIHLDiskImageAttach returned: 35
9/5/12 10:05:32.359 PM com.apple.backupd[43034]: Failed to mount disk image: Error Domain=com.apple.backupd.ErrorDomain Code=31 "The operation couldnt be completed. (com.apple.backupd.ErrorDomain error 31.)" UserInfo=0x7fd89a026900 {MessageParameters=(
"/Volumes/Data-1/server.sparsebundle"
)}
