[10.11 El Capitan] TM Backup sehr langsam

[FritzS]

Seit kurzem ist das TM sehr langsam. Der Fortschrittsbalken bleibt öfters für lange Zeit stehen. Wo 3 bis 8 GB früher im nu durch waren (wenige Minuten), dauert es jetzt mitunter eine Stunde.
Seltsamer weise trat es nach dem Anschluss meines neuen Monitors auf. Kann damit aber kaum zusammenhängen, denn nun ohne angeschlossenen Monitor gebootet tritt dies auch auf. Reiner Zufall?

Als es das erste Mal während eines TM Backups auftrat war der Rechner sehr langsam und des gab viele md... Prozesse.



Im System Log findet man Block weise sehr viele

kernel[0]: Sandbox: mdworker (...) deny(1) file-read-data /Application/.....

Fehlermeldungen.

PS: Das hatte ich ähnlich schon unter 10.8 und 10.9
https://www.apfeltalk.de/community/...dworker-meldungen-safemode-stillstand.434755/
https://www.apfeltalk.de/community/threads/tm-backup-sehr-langsam.478344/

MacBookPro 15" 5,1 Late 2008 / El Capitan 10.11 / 8GB RAM / 1TB SSD (Trim enabled)

 

[FritzS]

Ergänzend dazu:
Ich verwende alternierend zwei externe USB Festplatten für das TM Backup.
Es bei Beiden gleich, da kann es nicht an diesen Festplatten liegen.

Momentan läuft ein TM Backup über 900 MB und hängt in etwa der Mitte mit der Meldung noch 10 Minuten, hat sich aber verkürzt.

Kann es sein, dass das macOS 10.11 von selbst die Spotlight db neu aufbaute und dies nur die Nachwirkungen davon sind?
Mein MBP 15" läuft ja nicht durch.

Wie kann man die Spotlight db auf Fehler oder deren Status prüfen?

 

[FritzS]

mds_stores schreibt ~24 GB und liest ~22 GB / TM steht noch immer bei 62,5 MB von 9,89 GB - verbleibende Zeit berechnen ....
Und das schon seit etlichen Minuten.
Ich hatte das MBP vorher neu gestartet.

Da ich als „Normaluser unterwegs“ bin, müsste ich erst einen Benutzerwechsel machen um an die System Logs heranzukommen. Werde ich demnächst nachholen.

Kann es sein, dass die Spotlight db einen Defekt hat - und wie kann man das überprüfen?
Wo soll ich da ansetzen?

Ich überlege schon die letze Version con El Capitan herunter zu laden und einfach darüber zu installieren.

 

[ottomane]

Da ich als „Normaluser unterwegs“ bin, müsste ich erst einen Benutzerwechsel machen um an die System Logs heranzukommen.

Das ist nicht nötig. Im Terminal kannst du alles auch so machen, z.B. so

sudo cat /var/log/system.log

 

[FritzS]

Mittlerweile mds_stores 40GB geschrieben / 45 GB gelesen / TM Fortschrittsbalken steht bei 450 MB von 10 GB

 

[FritzS]

Log in eine Testdatei „geschossen“ muss erst „durchwühlen“

Leider sehr groß, da von etlichen WebKit Meldungen durchsetzt.

 

[FritzS]

Ein kleiner Auszug - nach was soll ich noch im System.log suchen?

Gestern:
Feb 26 18:07:11 mymac fseventsd[54]: Logging disabled completely for device:1: /Volumes/Recovery HD
Feb 26 18:07:12 mymac mdworker[12517]: (ImportBailout.Error:1331) Asked to exit for Diskarb
Feb 26 18:07:12 mymac mdworker[12583]: (ImportBailout.Error:1331) Asked to exit for Diskarb
..... rund 30 folgten

Feb 26 18:40:54 mymac kernel[0]: LS(5116) FATAL: m1c2d432d:0x122
Feb 26 18:40:54 mymac kernel[0]: LS(5116) m0675adba:22 1
..... rund 20 folgten

Heute:
Feb 27 07:12:32 localhost kernel[0]: Sandbox: launchd(1) System Policy: deny(1) file-write-flags /private/var/run/dyld_shared_cache_x86_64
Feb 27 07:12:32 localhost kernel[0]: Sandbox: launchd(1) System Policy: deny(1) file-write-unlink /private/var/run/dyld_shared_cache_x86_64
Feb 27 07:12:32 localhost kernel[0]: Sandbox: launchd(1) System Policy: deny(1) file-write-flags /private/var/run/dyld_shared_cache_x86_64.map
...... dürfte vom Boot Vorgang sein

Feb 27 07:13:47 mymac kernel[0]: Sandbox: launchctl(579) System Policy: deny(1) mach-priv-task-port
Feb 27 07:13:48 mymac kernel[0]: Sandbox: launchctl(580) System Policy: deny(1) mach-priv-task-port
Feb 27 07:13:48 mymac kernel[0]: Sandbox: launchctl(581) System Policy: deny(1) mach-priv-task-port
Feb 27 07:13:48 mymac kernel[0]: Sandbox: launchctl(582) System Policy: deny(1) mach-priv-task-port
Feb 27 07:13:48 mymac kernel[0]: Sandbox: launchctl(583) System Policy: deny(1) mach-priv-task-port
Feb 27 07:13:48 mymac kernel[0]: Sandbox: launchctl(584) System Policy: deny(1) mach-priv-task-port
Feb 27 07:13:48 mymac kernel[0]: Sandbox: launchctl(585) System Policy: deny(1) mach-priv-task-port
Feb 27 07:13:48 mymac kernel[0]: Sandbox: launchctl(586) System Policy: deny(1) mach-priv-task-port
Feb 27 07:13:48 mymac fontd[403]: BUG in libdispatch client: dispatch_mig_server: mach_msg() failed (ipc/send) invalid memory - 0x1000000c
Feb 27 07:13:49 mymac kernel[0]: Sandbox: launchctl(587) System Policy: deny(1) mach-priv-task-port
..... mehrmals


Feb 27 07:14:34 mymac kernel[0]: LS(5116) FATAL: m1c2d432d:0x122
Feb 27 07:14:34 mymac kernel[0]: LS(5116) m0675adba:22 1
..... mehrmals

Feb 27 07:16:47 --- last message repeated 1 time ---
Feb 27 07:16:47 mymac coreduetd[79]: LaunchServices: disconnect event received for service com.apple.lsd.mapdb
Feb 27 07:16:47 mymac coreduetd[79]: Error -54 registering path /System/Library/CoreServices/CoreTypes.bundle
Feb 27 07:16:47 mymac kernel[0]: Sandbox: coreduetd(79) deny(1) file-read-metadata /
Feb 27 07:16:47 --- last message repeated 22 times ---
Feb 27 07:16:47 mymac kernel[0]: Sandbox: coreduetd(79) deny(1) file-read-metadata /Applications/App Store.app
Feb 27 07:16:47 --- last message repeated 4 times ---
Feb 27 07:16:47 mymac kernel[0]: Sandbox: coreduetd(79) deny(1) file-read-metadata /Applications/Automator.app
Feb 27 07:16:47 --- last message repeated 4 times ---
Feb 27 07:16:47 mymac kernel[0]: Sandbox: coreduetd(79) deny(1) file-read-metadata /Applications/Calculator.app
Feb 27 07:16:47 --- last message repeated 4 times ---
...... das geht die meisten Apps so durch


Feb 27 07:17:22 mymac mdworker[3761]: iWork MDI raised an exception: Could not find the end of central directory record
Feb 27 07:17:25 mymac mds[70]: (DiskStore.Normal:1705) Starting health check...
Feb 27 07:17:25 mymac mds_stores[224]: (/private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T)(Warning) IndexSDB in si_checkDuplicateOids:9858: Starting index consistency check for /.Spotlight-V100/Store-V2/F4....E15
Feb 27 07:17:26 mymac mds_stores[224]: (/private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T)(Warning) IndexSDB in si_checkDuplicateOids:9870: Finished index consistency check for /.Spotlight-V100/Store-V2/F4....E15. Missing deletes:0
Feb 27 07:17:29 mymac storeassetd[457]: multibyte ASN1 identifiers are  not supported.
Feb 27 07:17:59 --- last message repeated 1 time ---
Feb 27 07:19:19 mymac mds_stores[224]: (/private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T)(Error) IndexSDB in db2_add_field:9156: types don't match dbf_flags:20 dfb_type:9 flags:20 type:10
Feb 27 07:19:19 mymac mds_stores[224]: (/private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T)(Error) IndexSDB in db2_add_field:9156: types don't match dbf_flags:20 dfb_type:9 flags:20 type:10
Feb 27 07:19:20 --- last message repeated 1 time ---
Feb 27 07:19:20 mymac mds_stores[224]: (/private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T)(Error) IndexSDB in db2_add_field:9156: types don't match dbf_flags:a20 dfb_type:9 flags:a20 type:10
Feb 27 07:19:21 --- last message repeated 2 times ---
Feb 27 07:19:21 mymac iconservicesagent[426]: -[ISGenerateImageOp generateImageWithCompletion:] Failed to composit image for descriptor <ISBindingImageDescriptor: 0x7f8171c24450>.
Feb 27 07:19:21 mymac quicklookd[427]: Error returned from iconservicesagent: (null)
Feb 27 07:19:55 mymac mds_stores[224]: (/private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T)(Error) IndexSDB in db2_add_field:9156: types don't match dbf_flags:20 dfb_type:9 flags:20 type:10
Feb 27 07:19:55 --- last message repeated 2 times ---
Feb 27 07:19:55 mymac iconservicesagent[426]: -[ISGenerateImageOp generateImageWithCompletion:] Failed to composit image for descriptor <ISBindingImageDescriptor: 0x7f8171c18800>.
Feb 27 07:19:55 mymac quicklookd[427]: Error returned from iconservicesagent: (null)
Feb 27 07:19:56 mymac mds_stores[224]: (/private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T)(Error) IndexSDB in db2_add_field:9156: types don't match dbf_flags:a20 dfb_type:9 flags:a20 type:10
Feb 27 07:20:26 --- last message repeated 2 times ---
.....


Feb 27 07:27:52 mymac kernel[0]: SATSMARTDriver v0.8: disk serial 'S....9', revision '2BC10003', model 'ST2000LM003 HN-M201RAD'
Feb 27 07:27:56 mymac kernel[0]: hfs: mounted Seagate 2TB on device disk1s2
Feb 27 07:28:06 mymac com.apple.backupd[3824]: Starting manual backup
Feb 27 07:28:06 mymac com.apple.backupd[3824]: Backing up to /dev/disk1s2: /Volumes/Seagate 2TB/Backups.backupdb
......

Feb 27 08:33:13 mymac quicklookd[4070]: Error returned from iconservicesagent: (null)
Feb 27 08:33:14 mymac QuickLookSatellite[4071]: Failed to obtain sandbox extension for path=/Users/FritzS/Library/Caches/com.apple.quicklook.satellite. Errno:1
Feb 27 08:33:14 --- last message repeated 1 time ---
......

Feb 27 08:35:01 mymac sandboxd[149] ([4279]): mdworker(4279) deny file-read-data /private/var/folders/hg/6rl166wd7ql9jnhz3zy827f40000gn/0/com.apple.LaunchServices-134501.csstore ()
Feb 27 08:35:01 mymac sandboxd[149] ([4279]): mdworker(4279) deny file-read-data /Users/FritzSadmin/Library/Preferences/com.apple.LaunchServices/com.apple.launchservices.secure.plist ()
Feb 27 08:35:01 mymac com.apple.SecurityServer[90]: Session 100025 created
Feb 27 08:35:01 mymac sandboxd[149] ([4279]): mdworker(4279) deny file-read-data /Applications/App Store.app ()
Feb 27 08:35:01 mymac sandboxd[149] ([4279]): mdworker(4279) deny file-read-data /Applications/App Store.app/Contents ()
Feb 27 08:35:01 mymac kernel[0]: Sandbox: mdworker(4279) deny(1) file-read-data /Applications/App Store.app
Feb 27 08:35:01 mymac sandboxd[149] ([4279]): mdworker(4279) deny file-read-data /Applications/App Store.app/Contents/MacOS/App Store ()
Feb 27 08:35:01 mymac kernel[0]: Sandbox: mdworker(4279) deny(1) file-read-data /Applications/App Store.app/Contents/MacOS/App Store
Feb 27 08:35:02 mymac sandboxd[149] ([4279]): mdworker(4279) deny file-read-data /Applications/App Store.app/Contents/MacOS/App Store/..namedfork/rsrc ()
Feb 27 08:35:02 mymac sandboxd[149] ([4279]): mdworker(4279) deny file-read-data /Applications/App Store.app ()
Feb 27 08:35:02 mymac kernel[0]: Sandbox: mdworker(4279) deny(1) file-read-data /Applications/App Store.app/Contents/PlugIns
Feb 27 08:35:02 mymac sandboxd[149] ([4279]): mdworker(4279) deny file-read-data /Applications/App Store.app/Contents ()
Feb 27 08:35:02 mymac kernel[0]: Sandbox: mdworker(4279) deny(1) file-read-data /Applications/Automator.app
Feb 27 08:35:02 mymac kernel[0]: Sandbox: mdworker(4279) deny(1) file-read-data /Applications/Automator.app/Contents
Feb 27 08:35:02 mymac kernel[0]: Sandbox: mdworker(4279) deny(1) file-read-data /Applications/Automator.app/Contents/MacOS/Automator
Feb 27 08:35:02 mymac kernel[0]: Sandbox: mdworker(4279) deny(1) file-read-data /Applications/Automator.app/Contents/MacOS/Automator/..namedfork/rsrc
Feb 27 08:35:02 mymac kernel[0]: Sandbox: mdworker(4279) deny(1) file-read-data /Applications/Automator.app
Feb 27 08:35:02 mymac kernel[0]: Sandbox: mdworker(4279) deny(1) file-read-data /Applications/Automator.app/Contents

.......

Feb 27 09:02:34 mymac com.apple.backupd[3824]: Deleted /Volumes/Seagate 2TB/Backups.backupdb/mymac/2018-01-27-180651 (1,06 GB)
Feb 27 09:02:34 mymac com.apple.backupd[3824]: Post-backup thinning complete: 2 expired backups removed
Feb 27 09:02:39 mymac com.apple.backupd[3824]: Backup completed successfully.
Feb 27 09:03:02 mymac syslogd[50]: ASL Sender Statistics

Feb 27 09:02:34 mymac com.apple.backupd[3824]: Deleted /Volumes/Seagate 2TB/Backups.backupdb/mymac/2018-01-27-180651 (1,06 GB)
Feb 27 09:02:34 mymac com.apple.backupd[3824]: Post-backup thinning complete: 2 expired backups removed
Feb 27 09:02:39 mymac com.apple.backupd[3824]: Backup completed successfully.

 

[ottomane]

Zu deinem Problem habe ich leider keine Idee (nur den Tipp mit dem Log ).

Aber sicher findet sich hier noch jemand...

 

[doc_holleday]

Leider gehöre ich auch nicht zu denen, die einen konkreten Tipp geben können.

Aber da du den Spotlight-Index unter Verdacht hast, kannst du den ja mal neu aufbauen lassen.

Da es aber auch (zusätzlich?) scheinbar Dateiberechtigungsprobleme zwischen Spotlight und den zu indizierenden Daten gibt, halte ich die Idee das OS noch mal drüber zu installieren auch nicht für so schlecht. Ggf. reicht auch das letzte Combo-Update.

Grundsätzlich kann ich mir vorstellen, dass TM länger braucht, wenn zusätzlich zur neuen Sicherung auch noch alte gelöscht werden müssen. Also vielleicht ist das plötzliche Auftreten an den Zeitpunkt gebunden, an dem keine neuen Stände mehr auf das Sicherungsmedium gepasst haben.

So oder so, würde ich mal noch das Dateisystem und die Partitionierung aller beteiligten Platten mit der Erste Hilfe Funktion des Festplattendienstprogramms "beackern".

Und/oder doch mal versuchen die Platten-Hardware zu prüfen.

Funktioniert denn der USB-Anschluss an dem die TM-Platten hängen sonst unauffällig? Nicht, dass es ein Problem mit der Schnittstelle ist.