Probleme mit TimeMachine und Airport Express nach Firmware Update

[wurzer]

Lange Zeit gab es Probleme mit Time Machine in Kombination mit Airport Express. Vor wenigen Wochen hatte ich es erneut probiert und es lief reibungslos. Nun kam ein Firmware Update von Apple heraus und plötzlich ist über das WLAN Kein Backup mehr möglich. Ich habe den Verdacht, dass Apple das Zusammenspiel von Time Machine und Airport Express absichtlich sabotiert.

Ich erhalte Fehlermeldungen im Zugriff auf die Platte, die das Backup stören:

Dec 19 10:58:01 macintosh-8 com.apple.backupd[260]: Starting standard backup
Dec 19 10:58:01 macintosh-8 com.apple.backupd[260]: Attempting to mount network destination using URL: afp://XXXXXXXXXXXXX._afpovertcp._tcp.local/Backup
Dec 19 10:58:01 macintosh-8 com.apple.backupd[260]: Mounted network destination using URL: afp://XXXXXXXXXXXXX._afpovertcp._tcp.local/Backup
Dec 19 10:58:06 macintosh-8 com.apple.backupd[260]: QUICKCHECK ONLY; FILESYSTEM CLEAN
Dec 19 10:58:12 macintosh-8 com.apple.backupd[260]: Disk image /Volumes/Backup-1/XXXXXXXXXXXXX.sparsebundle mounted at: /Volumes/MacBook Pro Backup
Dec 19 10:58:12 macintosh-8 com.apple.backupd[260]: Backing up to: /Volumes/MacBook Pro Backup/Backups.backupdb
Dec 19 11:08:06 macintosh-8 kernel[0]: Primary Reconnect succeeded /Volumes/Backup-1
Dec 19 11:12:32 macintosh-8 KernelEventAgent[32]: tid 00000000 type 'afpfs', mounted on '/Volumes/Backup', from 'afp_0W9mTQ0V7QgE00nZS90Pyetl-1.2d000003', not responding
Dec 19 11:12:43 macintosh-8 kernel[0]: Primary Reconnect succeeded /Volumes/Backup
Dec 19 11:19:42 macintosh-8 kernel[0]: Primary Reconnect succeeded /Volumes/Backup-1
Dec 19 11:21:14 macintosh-8 kernel[0]: Primary Reconnect succeeded /Volumes/Backup-1
Dec 19 11:21:42 macintosh-8 KernelEventAgent[32]: tid 00000000 type 'afpfs', mounted on '/Volumes/Backup', from 'afp_0W9mTQ0V7QgE00nZS90Pyetl-1.2d000003', not responding
Dec 19 11:21:45 macintosh-8 kernel[0]: Primary Reconnect succeeded /Volumes/Backup
Dec 19 11:40:35 macintosh-8 KernelEventAgent[32]: tid 00000000 type 'afpfs', mounted on '/Volumes/Backup', from 'afp_0W9mTQ0V7QgE00nZS90Pyetl-1.2d000003', not responding
Dec 19 11:40:40 macintosh-8 kernel[0]: Primary Reconnect succeeded /Volumes/Backup
Dec 19 11:50:46 macintosh-8 kernel[0]: Primary Reconnect succeeded /Volumes/Backup-1
Dec 19 11:51:15 macintosh-8 KernelEventAgent[32]: tid 00000000 type 'afpfs', mounted on '/Volumes/Backup', from 'afp_0W9mTQ0V7QgE00nZS90Pyetl-1.2d000003', not responding
Dec 19 11:51:18 macintosh-8 kernel[0]: Primary Reconnect succeeded /Volumes/Backup
Dec 19 12:00:30 macintosh-8 com.apple.backupd[260]: No pre-backup thinning needed: 3.81 GB requested (including padding), 55.11 GB available
Dec 19 12:02:20 macintosh-8 com.apple.backupd[260]: Copied 126 bytes of 31.4 MB, 92 of 521 items
Dec 19 12:32:08 macintosh-8 com.apple.backupd[260]: Bulk setting Spotlight attributes failed.
Dec 19 12:43:18 macintosh-8 com.apple.backupd[260]: Bulk setting Spotlight attributes failed.
Dec 19 12:53:11 macintosh-8 com.apple.backupd[260]: Bulk setting Spotlight attributes failed.
Dec 19 13:02:32 macintosh-8 com.apple.backupd[260]: Copied 28.4 MB of 31.4 MB, 8987 of 8987 items
Dec 19 13:10:40 macintosh-8 KernelEventAgent[32]: tid 00000000 type 'afpfs', mounted on '/Volumes/Backup', from 'afp_0W9mTQ0V7QgE00nZS90Pyetl-1.2d000003', not responding
Dec 19 13:10:40 macintosh-8 kernel[0]: Primary Reconnect succeeded /Volumes/Backup
Dec 19 13:23:38 macintosh-8 com.apple.backupd[260]: Error: (-8084) SrcErr:YES Copying /XXXXXXXXXX/com.apple.recentitems.plist to (null)
Dec 19 13:24:00 macintosh-8 com.apple.backupd[260]: Error: (-8084) SrcErr:YES Copying /XXXXXXXXXX/com.omnigroup.OmniOutliner3.plist to (null)
Dec 19 13:28:52 macintosh-8 com.apple.backupd[260]: Bulk setting Spotlight attributes failed.
Dec 19 13:32:42 macintosh-8 KernelEventAgent[32]: tid 00000000 type 'afpfs', mounted on '/Volumes/Backup', from 'afp_0W9mTQ0V7QgE00nZS90Pyetl-1.2d000003', not responding
Dec 19 13:32:42 macintosh-8 kernel[0]: Primary Reconnect succeeded /Volumes/Backup

 

[Beinhorn]

Airport Firmware Downgrade

Wenn es mit der aktuellen Firmware nicht klappt, kannst Du auch eine ältere Version installieren:

Öffne das AirPort-Dienstprogramm.
Wähle die Basisstation aus und dann die Option "Manuelle Konfiguration", oder doppelklicke auf das Symbol der Wi-Fi-Basisstation.
Wähle "Basisstation" > "Firmware laden …"
Wähle im daraufhin angezeigten Fenster die gewünschte Firmware-Version aus, und klicke auf "OK".
Wenn Du im Menü "Version laden" die Option "Andere" wählst, wirst Du aufgefordert, das Firmware-Update manuell zu suchen (wenn es sich um sehr alte Versionen handelt).

 

[wurzer]

Besten Dank. Das kann ich mal versuchen. Ich glaube jedoch, dass durch die neue Firmware irgendwelche Preferences, Properties oder Caches nicht mehr stimmen bzw. konsistent sind. Das Löschen der TimeMachine Preferences hat leider nicht gebracht. Ich werde den Lösungsvorschlag mal probieren.

 

[wurzer]

Leider hat der Firmware-Downgrade kein positives Ergebnis gebracht. Durch den vorangehenden Firmware-Upgrade scheinen Preferences bzw. Properties überschrieben worden zu sein, so dass das System nicht mehr konsistent ist. Ich werde mit dem Festplatten dienstprogramm jetzt von allen Platten einen vollständigen Scann machen. Aber ich vermute, das auch das kein Ergebnis bringt.

 

[wurzer]

Nun habe ich die Backup-Festplatte mit dem Dienstprogramm überprüft und auf meiner lokalen Festplatte den Cache vollständig gelöscht. Leider war alles erfolglos. Ich vermute irgendwo falsche Preferences oder Properties durch den Firmware-Upgrade der Airport Extreme Station. Das Zurücksetzen der Firmware hat leider nicht zu einer Lösung geführt. Hier ein aktueller Ausschnitt aus meinem Log-File.

24.12.10 12:07:27 com.apple.backupd[201] Starting standard backup
24.12.10 12:07:27 com.apple.backupd[201] Attempting to mount network destination using URL: afp://XXXXXXXXXXXXXXXXXXX._afpovertcp._tcp.local/Backup
24.12.10 12:07:29 Firewall[59] Stealth Mode connection attempt to UDP XXXXXXXXXXXX from 192.168.178.1:53
24.12.10 12:07:29 Firewall[59] Stealth Mode connection attempt to TCP XXXXXXXXXXXX from 169.254.125.177:548
24.12.10 12:07:30 Firewall[59] Stealth Mode connection attempt to TCP XXXXXXXXXXXX from fe80:5::21c:b3ff:fead:39
24.12.10 12:07:32 Firewall[59] Stealth Mode connection attempt to TCP XXXXXXXXXXXX from 169.254.125.177:548
24.12.10 12:07:33 Firewall[59] Stealth Mode connection attempt to TCP XXXXXXXXXXXX from fe80:5::21c:b3ff:fead:39
24.12.10 12:07:38 Firewall[59] Stealth Mode connection attempt to TCP XXXXXXXXXXXX from 169.254.125.177:548
24.12.10 12:07:38 com.apple.backupd[201] Mounted network destination using URL: afp://XXXXXXXXXXXXXXXXXXX._afpovertcp._tcp.local/Backup
24.12.10 12:07:38 kernel AFP_VFS afpfs_mount: /Volumes/Backup, pid 202
24.12.10 12:07:39 Firewall[59] Stealth Mode connection attempt to TCP XXXXXXXXXXXX from fe80:5::21c:b3ff:fead:39
24.12.10 12:07:41 com.apple.backupd[201] Running backup verification
24.12.10 12:07:45 hdiejectd[224] running
24.12.10 12:07:47 com.apple.backupd[201] QUICKCHECK ONLY; FILESYSTEM CLEAN
24.12.10 12:07:56 Firewall[59] Stealth Mode connection attempt to TCP XXXXXXXXXXXX from 169.254.125.177:548
24.12.10 12:08:16 Firewall[59] Stealth Mode connection attempt to TCP XXXXXXXXXXXX from 169.254.125.177:548
24.12.10 12:08:20 Firewall[59] Stealth Mode connection attempt to TCP XXXXXXXXXXXX from fe80:5::21c:b3ff:fead:39
24.12.10 12:08:38 com.apple.launchd[1] (com.apple.netauth.sysagent[202]) Exited with exit code: 255
24.12.10 12:10:44 kernel ASP_TCP Disconnect: triggering reconnect by bumping reconnTrigger from curr value 0 on so 0xb2bde58
24.12.10 12:10:44 kernel AFP_VFS afpfs_DoReconnect started /Volumes/Backup prevTrigger 0 currTrigger 1
24.12.10 12:10:44 kernel AFP_VFS afpfs_DoReconnect: doing reconnect on /Volumes/Backup
24.12.10 12:10:44 kernel AFP_VFS afpfs_DoReconnect: soft mounted and hidden volume so do not notify KEA for /Volumes/Backup
24.12.10 12:10:44 kernel AFP_VFS afpfs_DoReconnect: Max reconnect time: 30 secs, Connect timeout: 15 secs for /Volumes/Backup
24.12.10 12:10:44 kernel AFP_VFS afpfs_DoReconnect: connect to the server /Volumes/Backup
24.12.10 12:10:44 kernel ASP_TCP asp_SetTCPQoS: sock_settclassopt got error 57
24.12.10 12:10:44 kernel AFP_VFS afpfs_DoReconnect: Logging in with uam 8 /Volumes/Backup
24.12.10 12:10:44 kernel AFP_VFS afpfs_DoReconnect: Restoring session /Volumes/Backup
24.12.10 12:10:44 kernel ASP_TCP ReplayPendingReqs: replaying slot 26 with reqID 284 afpCmd 0x3C on so 0xb2bde58
24.12.10 12:10:44 kernel ASP_TCP ReplayPendingReqs: replaying slot 27 with reqID 285 afpCmd 0x11 on so 0xb2bde58
24.12.10 12:10:44 kernel ASP_TCP ReplayPendingReqs: replaying slot 28 with reqID 286 afpCmd 0x3C on so 0xb2bde58
24.12.10 12:10:44 kernel AFP_VFS afpfs_DoReconnect: get the reconnect token
24.12.10 12:15:33 kernel ASP_TCP Disconnect: triggering reconnect by bumping reconnTrigger from curr value 1 on so 0xb2bde58
24.12.10 12:15:33 kernel AFP_VFS afpfs_DoReconnect started /Volumes/Backup prevTrigger 1 currTrigger 2
24.12.10 12:15:33 kernel AFP_VFS afpfs_DoReconnect: doing reconnect on /Volumes/Backup
24.12.10 12:15:33 kernel AFP_VFS afpfs_DoReconnect: soft mounted and hidden volume so do not notify KEA for /Volumes/Backup
24.12.10 12:15:33 kernel AFP_VFS afpfs_DoReconnect: Max reconnect time: 30 secs, Connect timeout: 15 secs for /Volumes/Backup
24.12.10 12:15:33 kernel AFP_VFS afpfs_DoReconnect: connect to the server /Volumes/Backup
24.12.10 12:15:33 kernel ASP_TCP asp_SetTCPQoS: sock_settclassopt got error 57
24.12.10 12:15:38 kernel AFP_VFS afpfs_DoReconnect: Logging in with uam 8 /Volumes/Backup
24.12.10 12:15:38 kernel AFP_VFS afpfs_DoReconnect: Restoring session /Volumes/Backup
24.12.10 12:15:38 kernel ASP_TCP ReplayPendingReqs: replaying slot 12 with reqID 307 afpCmd 0x3C on so 0xb2bde58
24.12.10 12:15:38 kernel ASP_TCP ReplayPendingReqs: replaying slot 13 with reqID 308 afpCmd 0x22 on so 0xb2bde58
24.12.10 12:15:38 kernel ASP_TCP ReplayPendingReqs: replaying slot 14 with reqID 309 afpCmd 0x3C on so 0xb2bde58
24.12.10 12:15:38 kernel AFP_VFS afpfs_DoReconnect: get the reconnect token
24.12.10 12:19:29 kernel PM notification timeout (pid 150, System Preferenc)
24.12.10 12:19:29 kernel PM notification timeout (pid 150, System Preferenc)
24.12.10 12:19:49 kernel hibernate image path: /var/vm/sleepimage
24.12.10 12:19:49 kernel sizeof(IOHibernateImageHeader) == 512
24.12.10 12:19:49 kernel Opened file /var/vm/sleepimage, size 4294967296, partition base 0xc805000, maxio 400000 ssd 0
24.12.10 12:19:49 kernel hibernate image major 14, minor 2, blocksize 512, pollers 5
24.12.10 12:19:49 kernel hibernate_alloc_pages flags 00000000, gobbling 0 pages
24.12.10 12:19:49 kernel hibernate_setup(0) took 0 ms
24.12.10 12:19:49 kernel NVEthernet::setLinkStatus - Valid but not Active
24.12.10 12:19:49 kernel AirPort: Link Down on en1. Reason 8 (Disassociated because station leaving).
24.12.10 12:19:49 kernel System SafeSleep
24.12.10 12:19:58 kernel hibernate_page_list_setall start 0x4449f000, 0x444be000
24.12.10 12:19:58 kernel hibernate_page_list_setall time: 210 ms
24.12.10 12:19:58 kernel pages 652429, wire 98006, act 146728, inact 202, spec 346, zf 0, throt 0, could discard act 53305 inact 173806 purgeable 36058 spec 143978
24.12.10 12:19:58 kernel hibernate_page_list_setall found pageCount 245282
24.12.10 12:19:58 kernel IOHibernatePollerOpen, ml_get_interrupts_enabled 0
24.12.10 12:19:58 kernel IOHibernatePollerOpen(0)
24.12.10 12:19:58 kernel writing 244094 pages
24.12.10 12:19:58 kernel encryptStart 2f2e0
24.12.10 12:19:58 kernel encryptEnd 6691ba0
24.12.10 12:19:58 kernel image1Size 175504384, encryptStart1 2f2e0, End1 6691ba0
24.12.10 12:19:58 kernel encryptStart a75fc00
24.12.10 12:19:58 kernel encryptEnd 194fc0b0
24.12.10 12:19:58 kernel PMStats: Hibernate write took 7015 ms
24.12.10 12:19:58 kernel all time: 7015 ms, comp time: 1402 ms, deco time: 0 ms,
24.12.10 12:19:58 kernel image 424657408, uncompressed 1000103936 (244166), compressed 422324720 (42%), sum1 fa7ee13, sum2 d26a46a6
24.12.10 12:19:58 kernel wired_pages_encrypted 58899, wired_pages_clear 37991, dirty_pages_encrypted 147276
24.12.10 12:19:58 kernel hibernate_write_image done(0)
24.12.10 12:19:58 kernel sleep
24.12.10 12:19:58 configd[13] network configuration changed.
24.12.10 12:19:58 configd[13] setting hostname to "Macintosh-8.local"
24.12.10 12:32:14 kernel Wake reason = OHC1
24.12.10 12:32:14 kernel System Wake
24.12.10 12:32:14 kernel Previous Sleep Cause: 5
24.12.10 12:32:14 kernel An unknown USB device (Port 7 of Hub at 0x4000000) may have caused a wake by issuing a remote wakeup
24.12.10 12:32:14 kernel The USB device Apple Internal Keyboard / Trackpad (Port 6 of Hub at 0x4000000) may have caused a wake by issuing a remote wakeup (3)
24.12.10 12:32:14 kernel EIR is supported.
24.12.10 12:32:14 kernel SSP is supported.
24.12.10 12:32:15 kernel NVEthernet::setLinkStatus - Valid but not Active
24.12.10 12:32:15 apsd-ft[133] <APSCourier: 0x100611630>: Stream error occurred for <APSTCPStream: 0x10013f420>: Error Domain=NSPOSIXErrorDomain Code=57 UserInfo=0x10014d740 "The operation couldn’t be completed. Socket is not connected"
24.12.10 12:32:15 apsd-ft[133] <APSCourier: 0x100611630>: Stream error occurred for <APSTCPStream: 0x10013f420>: Error Domain=kCFErrorDomainCFNetwork Code=2 UserInfo=0x100632680 "The operation couldn’t be completed. (kCFErrorDomainCFNetwork error 2.)"
24.12.10 12:32:16 loginwindow[31] in pam_sm_authenticate(): Failed to determine Kerberos principal name.
24.12.10 12:32:17 kernel ASP_TCP Disconnect: triggering reconnect by bumping reconnTrigger from curr value 2 on so 0xb2bde58
24.12.10 12:32:17 kernel AFP_VFS afpfs_DoReconnect started /Volumes/Backup prevTrigger 2 currTrigger 3
24.12.10 12:32:17 kernel AFP_VFS afpfs_DoReconnect: doing reconnect on /Volumes/Backup
24.12.10 12:32:17 kernel AFP_VFS afpfs_DoReconnect: soft mounted and hidden volume so do not notify KEA for /Volumes/Backup
24.12.10 12:32:17 kernel AFP_VFS afpfs_DoReconnect: Max reconnect time: 30 secs, Connect timeout: 15 secs for /Volumes/Backup
24.12.10 12:32:17 kernel AFP_VFS afpfs_DoReconnect: connect to the server /Volumes/Backup
24.12.10 12:32:17 kernel ASP_TCP asp_SetTCPQoS: sock_settclassopt got error 57
24.12.10 12:32:17 kernel AFP_VFS afpfs_DoReconnect: connect on /Volumes/Backup failed 65.
24.12.10 12:32:17 kernel AFP_VFS afpfs_DoReconnect: sleep for 1 seconds and then try again
24.12.10 12:32:17 kernel Auth result for: 00:1f:3f:50:18:33 MAC AUTH succeeded
24.12.10 12:32:17 kernel AirPort: Link Up on en1
24.12.10 12:32:17 kernel AirPort: RSN handshake complete on en1
24.12.10 12:32:17 configd[13] network configuration changed.
24.12.10 12:32:17 configd[13] setting hostname to "macintosh-8"
24.12.10 12:32:18 kernel AFP_VFS afpfs_DoReconnect: connect to the server /Volumes/Backup
24.12.10 12:32:18 kernel ASP_TCP asp_SetTCPQoS: sock_settclassopt got error 57
24.12.10 12:32:18 kernel AFP_VFS afpfs_DoReconnect: Logging in with uam 8 /Volumes/Backup
24.12.10 12:32:18 kernel AFP_VFS afpfs_DoReconnect: Restoring session /Volumes/Backup
24.12.10 12:32:18 kernel ASP_TCP ReplayPendingReqs: replaying slot 0 with reqID 333 afpCmd 0x3C on so 0xb2bde58
24.12.10 12:32:18 kernel ASP_TCP ReplayPendingReqs: replaying slot 1 with reqID 334 afpCmd 0x3C on so 0xb2bde58
24.12.10 12:32:18 kernel AFP_VFS afpfs_DoReconnect: get the reconnect token
24.12.10 12:32:18 ntpd[19] bind() fd 25, family 30, port 123, scope 5, addr fe80::225:ff:fe3f:6881, in6_is_addr_multicast=0 flags=0x11 fails: Can't assign requested address
24.12.10 12:32:18 ntpd[19] unable to create socket on en1 (7) for fe80::225:ff:fe3f:6881#123
24.12.10 12:32:31 apsd-ft[133] <APSCourier: 0x100611630>: Received connected response OK
24.12.10 12:37:53 kernel ASP_TCP Disconnect: triggering reconnect by bumping reconnTrigger from curr value 3 on so 0xb2bde58
24.12.10 12:37:53 kernel AFP_VFS afpfs_DoReconnect started /Volumes/Backup prevTrigger 3 currTrigger 4
24.12.10 12:37:53 kernel AFP_VFS afpfs_DoReconnect: doing reconnect on /Volumes/Backup
24.12.10 12:37:53 kernel AFP_VFS afpfs_DoReconnect: soft mounted and hidden volume so do not notify KEA for /Volumes/Backup
24.12.10 12:37:53 kernel AFP_VFS afpfs_DoReconnect: Max reconnect time: 30 secs, Connect timeout: 15 secs for /Volumes/Backup
24.12.10 12:37:53 kernel AFP_VFS afpfs_DoReconnect: connect to the server /Volumes/Backup
24.12.10 12:37:53 kernel ASP_TCP asp_SetTCPQoS: sock_settclassopt got error 57
24.12.10 12:37:54 kernel AFP_VFS afpfs_DoReconnect: Logging in with uam 8 /Volumes/Backup
24.12.10 12:37:54 kernel AFP_VFS afpfs_DoReconnect: Restoring session /Volumes/Backup
24.12.10 12:37:54 kernel ASP_TCP ReplayPendingReqs: replaying slot 1 with reqID 373 afpCmd 0x3C on so 0xb2bde58
24.12.10 12:37:54 kernel ASP_TCP ReplayPendingReqs: replaying slot 2 with reqID 374 afpCmd 0x11 on so 0xb2bde58
24.12.10 12:37:54 kernel ASP_TCP ReplayPendingReqs: replaying slot 3 with reqID 375 afpCmd 0x3C on so 0xb2bde58
24.12.10 12:37:54 kernel AFP_VFS afpfs_DoReconnect: get the reconnect token

 

[Beinhorn]

Dann kann folgendes helfen:
Nimm Deine Time Machine Sicherung (vom Zeitpunkt, an dem alles noch lief) und spiel sie mittels Wiederherstellung zurück.

 

[Dinofelis]

Apple hat schon immer sehr frühzeitig darauf hingewiesen, wenn bestimmte Funktionen nicht unterstützt werden.

Dazu gehören TimeMachine-Sicherungen auf Disks, die an AP Extreme angeschlossen sind - das wird nicht unterstützt. Es funktionierte zwar in manchen Fällen trotzdem, aber das kann ja keine Sicherheit sein.

TimeMachine basiert auf ganz speziellen Hardware/Disk/Filesystem-Voraussetzungen, insbesondere Hard Links. Das geht u.U per WLAN und Airport Extreme nicht mit jeder 3rd-Party Disk, und daher hat Apple nur die eigene TC als Lösung.

Ich denke, die Bemühungen sind zwecklos.

Oder wie du es sagst, Apple hat deine bisherige (nicht unterstützte) Konfiguration inzwischen "sabotiert".