Rainer Schwarze

Q: Mavericks: Backup: Stuck at "prepare" after a few successful backups

Hi,

 

after a few backups (two or three) the backup is stuck at the preparation phase. In the console logs I found these lines:

 

06.07.14 05:31:17,660 com.apple.backupd[20453]: Starting automatic backup

06.07.14 05:31:17,675 com.apple.backupd[20453]: Backing up to /dev/disk2s2: /Volumes/ExtHD03/Backups.backupdb

06.07.14 05:31:17,930 mds[76]: (Warning) QueryTask: Haven't sent anything for 60 seconds; try despite not having received RTS notification.

06.07.14 05:31:17,930 mds[76]: (Warning) QueryTask: Haven't sent anything for 60 seconds; try despite not having received RTS notification.

06.07.14 05:31:17,931 mds[76]: (Warning) QueryTask: Haven't sent anything for 60 seconds; try despite not having received RTS notification.

 

 

The backup before that logged that:

 

06.07.14 04:30:16,675 com.apple.backupd[18686]: Starting automatic backup

06.07.14 04:30:17,024 com.apple.backupd[18686]: Backing up to /dev/disk2s2: /Volumes/ExtHD03/Backups.backupdb

06.07.14 04:30:18,118 serveradmin[18695]: SCNetworkReachabilityCreateWithAddress[Pair] called with invalid address family 1

06.07.14 04:30:21,096 serveradmin[18716]: servermgr_swupdate[INF]: Verifying Software Update catalog configuration.

06.07.14 04:30:21,100 serveradmin[18716]: servermgr_swupdate[INF]: Verifying Software Update catalog configuration.

06.07.14 04:30:21,101 serveradmin[18716]: servermgr_swupdate[WRN]: Missing or invalid language for product items request.  Using default "en".

06.07.14 04:30:25,037 serveradmin[18793]: SCNetworkReachabilityCreateWithAddress[Pair] called with invalid address family 1

06.07.14 04:30:28,204 serveradmin[18830]: servermgr_swupdate[INF]: Verifying Software Update catalog configuration.

06.07.14 04:30:28,207 serveradmin[18830]: servermgr_swupdate[INF]: Verifying Software Update catalog configuration.

06.07.14 04:30:28,207 serveradmin[18830]: servermgr_swupdate[WRN]: Missing or invalid language for product items request.  Using default "en".

06.07.14 04:30:28,239 serveradmin[18831]: servermgr_swupdate[INF]: Verifying Software Update catalog configuration.

06.07.14 04:30:35,458 com.apple.backupd[18686]: Will copy (50,9 MB) from Server HD

 

I assume that the servermgr lines are not really relevant.

 

What do the lines with "mds[76]: (Warning) QueryTask..." mean?

Can I find more details about that?

Can this be the reason for the backup problem?

 

 

I was trying to do backup with a Time Capsule before, but after some time it won't even do a single backup (stuck at prepare). Now I did a fresh install with Mavericks and attached a fresh 1TB HD (SATA) with a USB HD dock. Interestingly the same happens: Some backups work, but then it is stuck at "prepare".

 

I have a macmini4.1 server. I installed OS X Server (3.1.2) and macports with samba3. Also the second disk in the mac mini server contains a lot of files which are shared by SMB to Windows clients.

 

Thanks in advance and best wishes,

Rainer

Posted on Jul 6, 2014 2:38 AM

Close

Q: Mavericks: Backup: Stuck at "prepare" after a few successful backups

  • All replies
  • Helpful answers

Page 1 of 3 last Next
  • by dwbrecovery,

    dwbrecovery dwbrecovery Jul 6, 2014 5:03 AM in response to Rainer Schwarze
    Level 3 (589 points)
    Servers Enterprise
    Jul 6, 2014 5:03 AM in response to Rainer Schwarze

    Hi,

    - With an assumption that ExtHDD3 is a disk connected to the Server, run Disk Utility  -> Verify Disk  for ExtHDD3.

    - Are there more Console log entires for backupd  that you can post ( using the filter ).    Take care to remove private information.

    - At this stage iI do not think the mds entires are relevant, but if you can look at the Console logs and filter by  mds and check this as well.

     

    Cheers

  • by Linc Davis,

    Linc Davis Linc Davis Jul 6, 2014 7:13 AM in response to Rainer Schwarze
    Level 10 (208,000 points)
    Applications
    Jul 6, 2014 7:13 AM in response to Rainer Schwarze
  • by Rainer Schwarze,

    Rainer Schwarze Rainer Schwarze Jul 6, 2014 11:30 AM in response to Linc Davis
    Level 1 (0 points)
    Jul 6, 2014 11:30 AM in response to Linc Davis

    Regarding the "preparing" KB article:

     

    Citing:

     

    "The preparing stage can also take longer if:"

    • "The previous Time Machine backup was interrupted."

    It was running around 4:30 at night - the logs say, that it was completed.


    • "The Mac was not shut down properly."

    Was not restarted since the last successful backup.


    • "A disk was disconnected from your computer before being ejected."

    No disk connect/disconnect (no one touched it over the night).


    • "A software update was recently installed."

    No changes since last successful backup.


    • "You used your Mac for several days without performing a backup. This can happen if the backup disk was disconnected."

    Last backup around 4:30 at night - backup disk not disconnected since then.


    I let the backup run over night knowing that the preparation may take a long time. Eventually around 3 am it completed the first backup. Further backups were much quicker. I excluded my file server disk from Spotlight and since then it works. Complete time for an hourly backup about 2 min. I will describe that spotlight change in the other post.

  • by Rainer Schwarze,

    Rainer Schwarze Rainer Schwarze Jul 6, 2014 11:50 AM in response to dwbrecovery
    Level 1 (0 points)
    Jul 6, 2014 11:50 AM in response to dwbrecovery

    dwbrecovery wrote:

     

    Hi,

    - With an assumption that ExtHDD3 is a disk connected to the Server, run Disk Utility  -> Verify Disk  for ExtHDD3.

    - Are there more Console log entires for backupd  that you can post ( using the filter ).    Take care to remove private information.

    - At this stage iI do not think the mds entires are relevant, but if you can look at the Console logs and filter by  mds and check this as well.

     

    Cheers

     

    I will verify the disk during the next days. I assume that it should be good. It was used in my previous FreeBSD server as a disk for the backup dump files and showed no problems so far - of course that does not prove anything :-)

     

    In the meantime I was thinking about the mds log entries and decided to exclude the disk "Macintosh HD2" from spotlight, This is the disk which contains a huge amount of files and which are served as a file server. Since then the backups run successfully so far. (hourly backups from 14:30 until about 20:00)

     

    I will look more closely at mds log entries, and will post what I found. For now I add a few of the backup logs:

     

     

     

    More logs: (filtered for backup)

     

    This is the successful backup at 4:30 :

     

    06.07.14 04:30:16,675 com.apple.backupd[18686]: Starting automatic backup

    06.07.14 04:30:17,024 com.apple.backupd[18686]: Backing up to /dev/disk2s2: /Volumes/ExtHD03/Backups.backupdb

    06.07.14 04:30:35,458 com.apple.backupd[18686]: Will copy (50,9 MB) from Server HD

    06.07.14 04:30:35,459 com.apple.backupd[18686]: Will copy (Zero KB) from Macintosh HD2

    06.07.14 04:30:35,460 com.apple.backupd[18686]: Found 165 files (50,9 MB) needing backup

    06.07.14 04:30:35,461 com.apple.backupd[18686]: 2,91 GB required (including padding), 631,14 GB available

    06.07.14 04:30:38,858 com.apple.backupd[18686]: Copied 172 items (50,9 MB) from volume Server HD. Linked 528.

    06.07.14 04:30:40,081 com.apple.backupd[18686]: Copied 1 items (Zero KB) from volume Macintosh HD2. Linked 10.

    06.07.14 04:30:40,657 com.apple.backupd[18686]: Will copy (786 bytes) from Server HD

    06.07.14 04:30:40,658 com.apple.backupd[18686]: Not using file event preflight for Macintosh HD2

    06.07.14 04:30:40,661 com.apple.backupd[18686]: Found 17 files (786 bytes) needing backup

    06.07.14 04:30:40,662 com.apple.backupd[18686]: 2,83 GB required (including padding), 631,09 GB available

    06.07.14 04:30:41,322 com.apple.backupd[18686]: Copied 19 items (819 bytes) from volume Server HD. Linked 211.

    06.07.14 04:30:41,856 com.apple.backupd[18686]: Copied 1 items (Zero KB) from volume Macintosh HD2. Linked 10.

    06.07.14 04:30:42,401 com.apple.backupd[18686]: Created new backup: 2014-07-06-043042

    06.07.14 04:30:43,254 com.apple.backupd[18686]: Starting post-backup thinning

    06.07.14 04:30:43,254 com.apple.backupd[18686]: No post-backup thinning needed: no expired backups exist

    06.07.14 04:30:43,276 com.apple.backupd[18686]: Backup completed successfully.

     

    This is the stuck backup at 5:30 : (the one with the mds errors)

     

    06.07.14 05:31:17,660 com.apple.backupd[20453]: Starting automatic backup

    06.07.14 05:31:17,675 com.apple.backupd[20453]: Backing up to /dev/disk2s2: /Volumes/ExtHD03/Backups.backupdb

     

    Successful backup around 15:00 - interestingly with a log entry regarding backupd burning cpu:

     

    06.07.14 14:51:16,047 com.apple.backupd[5559]: Starting manual backup

    06.07.14 14:51:16,700 com.apple.backupd[5559]: Backing up to /dev/disk2s2: /Volumes/ExtHD03/Backups.backupdb

    06.07.14 14:51:19,665 com.apple.prefs.backup.remoteservice[5588]: assertion failed: 13E28: liblaunch.dylib + 25164 [A40A0C7B-3216-39B4-8AE0-B5D3BAF1DA8A]: 0x25

    06.07.14 14:51:19,669 com.apple.prefs.backup.remoteservice[5588]: assertion failed: 13E28: liblaunch.dylib + 25164 [A40A0C7B-3216-39B4-8AE0-B5D3BAF1DA8A]: 0x25

    06.07.14 14:51:19,689 com.apple.prefs.backup.remoteservice[5588]: assertion failed: 13E28: liblaunch.dylib + 25164 [A40A0C7B-3216-39B4-8AE0-B5D3BAF1DA8A]: 0x25

    06.07.14 14:51:20,292 com.apple.prefs.backup.remoteservice[5588]: Bogus event received by listener connection:

    <error: 0x7fff735cdb50> { count = 1, contents =

      "XPCErrorDescription" => <string: 0x7fff735cde60> { length = 18, contents = "Connection invalid" }

    }

    06.07.14 14:54:04,000 kernel[0]: process backupd[5559] thread 35951 caught burning CPU! It used more than 50% CPU (Actual recent usage: 53%) over 180 seconds. thread lifetime cpu usage 90.051769 seconds, (40.741139 user, 49.310630 system) ledger info: balance: 90000405776 credit: 90000405776 debit: 0 limit: 90000000000 (50%) period: 180000000000 time since last refill (ns): 168293143923

    06.07.14 14:54:10,001 spindump[5898]: Saved cpu_resource.spin report for backupd version ??? (???) to /Library/Logs/DiagnosticReports/backupd_2014-07-06-145409_macsrv.cpu_resource.s pin

    06.07.14 14:58:39,727 com.apple.backupd[5559]: Will copy (1,16 GB) from Server HD

    06.07.14 14:58:40,162 com.apple.backupd[5559]: Will copy (22 KB) from Macintosh HD2

    06.07.14 14:58:40,179 com.apple.backupd[5559]: Found 146769 files (2,43 GB) needing backup

    06.07.14 14:58:40,817 com.apple.backupd[5559]: 5,02 GB required (including padding), 631,68 GB available

    06.07.14 15:01:22,552 com.apple.backupd[5559]: Copied 8824 items (969,1 MB) from volume Server HD. Linked 13927.

    06.07.14 15:01:37,074 com.apple.backupd[5559]: Copied 34 items (286,3 MB) from volume Macintosh HD2. Linked 453.

    06.07.14 15:01:39,070 com.apple.backupd[5559]: Will copy (33,6 MB) from Server HD

    06.07.14 15:01:39,071 com.apple.backupd[5559]: Not using file event preflight for Macintosh HD2

    06.07.14 15:01:39,074 com.apple.backupd[5559]: Found 38 files (33,6 MB) needing backup

    06.07.14 15:01:39,075 com.apple.backupd[5559]: 2,16 GB required (including padding), 630,41 GB available

    06.07.14 15:01:42,423 com.apple.backupd[5559]: Copied 43 items (33,6 MB) from volume Server HD. Linked 492.

    06.07.14 15:01:43,409 com.apple.backupd[5559]: Copied 1 items (Zero KB) from volume Macintosh HD2. Linked 10.

    06.07.14 15:01:43,974 com.apple.backupd[5559]: Created new backup: 2014-07-06-150143

    06.07.14 15:01:46,140 com.apple.backupd[5559]: Starting post-backup thinning

    06.07.14 15:01:46,140 com.apple.backupd[5559]: No post-backup thinning needed: no expired backups exist

    06.07.14 15:01:46,168 com.apple.backupd[5559]: Backup completed successfully.

     

    A couple of successful backups in between - here the last one from the last hour:

     

    06.07.14 20:02:45,895 com.apple.backupd[19944]: Starting automatic backup

    06.07.14 20:02:46,109 com.apple.backupd[19944]: Backing up to /dev/disk2s2: /Volumes/ExtHD03/Backups.backupdb

    06.07.14 20:02:54,710 com.apple.backupd[19944]: Will copy (2,76 GB) from Server HD

    06.07.14 20:02:54,711 com.apple.backupd[19944]: Will copy (8 KB) from Macintosh HD2

    06.07.14 20:02:54,712 com.apple.backupd[19944]: Found 1652 files (2,76 GB) needing backup

    06.07.14 20:02:54,715 com.apple.backupd[19944]: 5,44 GB required (including padding), 630,2 GB available

    06.07.14 20:04:24,539 com.apple.backupd[19944]: Copied 1681 items (2,76 GB) from volume Server HD. Linked 669.

    06.07.14 20:04:32,619 com.apple.backupd[19944]: Copied 14 items (16 KB) from volume Macintosh HD2. Linked 80.

    06.07.14 20:04:33,513 com.apple.backupd[19944]: Will copy (33,6 MB) from Server HD

    06.07.14 20:04:33,513 com.apple.backupd[19944]: Not using file event preflight for Macintosh HD2

    06.07.14 20:04:33,517 com.apple.backupd[19944]: Found 38 files (33,6 MB) needing backup

    06.07.14 20:04:33,517 com.apple.backupd[19944]: 2,24 GB required (including padding), 627,35 GB available

    06.07.14 20:04:35,833 com.apple.backupd[19944]: Copied 42 items (33,6 MB) from volume Server HD. Linked 321.

    06.07.14 20:04:36,682 com.apple.backupd[19944]: Copied 1 items (Zero KB) from volume Macintosh HD2. Linked 10.

    06.07.14 20:04:37,504 com.apple.backupd[19944]: Created new backup: 2014-07-06-200437

    06.07.14 20:04:39,137 com.apple.backupd[19944]: Starting post-backup thinning

    06.07.14 20:04:39,140 com.apple.backupd[19944]: No post-backup thinning needed: no expired backups exist

    06.07.14 20:04:39,156 com.apple.backupd[19944]: Backup completed successfully.

  • by Linc Davis,

    Linc Davis Linc Davis Jul 6, 2014 2:55 PM in response to Rainer Schwarze
    Level 10 (208,000 points)
    Applications
    Jul 6, 2014 2:55 PM in response to Rainer Schwarze

    You seem to have solved the problem, as far as Time Machine is concerned.

  • by dwbrecovery,

    dwbrecovery dwbrecovery Jul 6, 2014 10:00 PM in response to Rainer Schwarze
    Level 3 (589 points)
    Servers Enterprise
    Jul 6, 2014 10:00 PM in response to Rainer Schwarze

    - The Time Machine backups appear to function as expected now.  ( 2 opinions )

    - A reset of Spotlight on vol HD2 should be the next step, after confirming the backups function

    - either via mdutil command or Spotlight: How to re-index folders or volumes

     

    all under control 

  • by Rainer Schwarze,

    Rainer Schwarze Rainer Schwarze Jul 7, 2014 2:02 PM in response to dwbrecovery
    Level 1 (0 points)
    Jul 7, 2014 2:02 PM in response to dwbrecovery

    I have removed the HD2 disk from the spotlight exclusion list. According to the spotlight menu it is indexing for the next 3 hours. I will see whether backup still works tomorrow in the morning.

     

    Is there some information somewhere what that mds warning means?

     

    06.07.14 05:31:17,930 mds[76]: (Warning) QueryTask: Haven't sent anything for 60 seconds; try despite not having received RTS notification.

     

    Being a Mac newbie I would assume it tries to communicate with another process, which turned silent in the mean time. Maybe it stumbled over weird content or access rights on that HD2 disk?

  • by Rainer Schwarze,

    Rainer Schwarze Rainer Schwarze Jul 7, 2014 9:20 PM in response to Rainer Schwarze
    Level 1 (0 points)
    Jul 7, 2014 9:20 PM in response to Rainer Schwarze

    The backup is stuck again. (Spotlight enabled for the HD2 disk)

     

    08.07.14 03:39:29,444 com.apple.backupd[81024]: Backing up to /dev/disk2s2: /Volumes/ExtHD03/Backups.backupdb

    08.07.14 03:39:29,512 mds[45]: (Warning) QueryTask: Haven't sent anything for 60 seconds; try despite not having received RTS notification.

     

    Last successful backups: (But each seems to have such an mds warning like above:)

     

    07.07.14 23:36:20,659 com.apple.backupd[73588]: Backup completed successfully.

    ...

    08.07.14 00:37:12,072 com.apple.backupd[75465]: Backup completed successfully.

    ...

    08.07.14 01:38:06,431 com.apple.backupd[77317]: Backup completed successfully.

    ...

    08.07.14 02:38:55,668 com.apple.backupd[79168]: Backup completed successfully.

     

    So the problem seems to be related to the spotlight.

     

    I will look at the mds related log entries later today.

  • by dkolba,

    dkolba dkolba Jul 7, 2014 9:21 PM in response to Rainer Schwarze
    Level 1 (5 points)
    Jul 7, 2014 9:21 PM in response to Rainer Schwarze

    Had this same problem on 1 of the computers out of 3 that were backing up to the same time capsule.  even hired an IT guy to come and look at it.  didn't fix the problem till we formatted the computer and did a clean install of the OS.  No problems since.  Wish i could give you some fix we had for this but couldn't seem to get any further then a format.

  • by dwbrecovery,

    dwbrecovery dwbrecovery Jul 7, 2014 10:30 PM in response to Rainer Schwarze
    Level 3 (589 points)
    Servers Enterprise
    Jul 7, 2014 10:30 PM in response to Rainer Schwarze

    Hi, thanks for the updates.

    Use Disk Utility to " Verify Disk" of HD2 to check whether it needs to be repaired.

    If the verify is ok, perform a " Verify Disk Permissions " to determine if permissions are ok.

    The Verifications will not make any changes to HD2

     

    The lockup may be due to a corruption of HD2.   Is HD2 the only copy of the files?

  • by Rainer Schwarze,

    Rainer Schwarze Rainer Schwarze Jul 8, 2014 1:15 AM in response to dwbrecovery
    Level 1 (0 points)
    Jul 8, 2014 1:15 AM in response to dwbrecovery

    dwbrecovery wrote:

     

    Hi, thanks for the updates.

    Use Disk Utility to " Verify Disk" of HD2 to check whether it needs to be repaired.

    If the verify is ok, perform a " Verify Disk Permissions " to determine if permissions are ok.

    The Verifications will not make any changes to HD2

     

    The lockup may be due to a corruption of HD2.   Is HD2 the only copy of the files?

     

    Verify Disk:

     

    It says "The Volume ... is apparently ok" (original German message: "Das Volume „Macintosh HD2“ ist anscheinend in Ordnung.")

    The button "Zugriffsrechte des Volumes überprüfen" is grayed out. (I assume this is the one which would be "Verify Disk Permissions")

     

    The files from HD2 are still available in my FreeBSD server. The files there are not updated currently, we were working on the new HD2 disk so far. Also I assume that from the previously working Time Capsule backup they should still be on the Time Capsule. So currently I have two backups and an older "mirror".

     

    I was hoping at first that I simply do some clickety-click in OS X Server's file sharing to turn the mac mini into our new server. However, Apple's samba leads to broken files, disconnects and lots of other issues. So I installed samba3 from macports and disabled SMB on the max mini. I wonder whether macports or Apple's samba messed with some files.

     

    The access rights on the file server disk are not relevant. This server is only used by me and my wife in our little IT business, so I can set each and every file and directory to a new owner etc. I assume that there are more things than only chmod and chown on Mavericks. How would I recursively set owner and rights including access control and maybe other things I do not yet know? (certainly more than "chown -R ..." :-) )

     

    The remaining text deals with spotlight related log entries:

     

     

    These are the mds entries:

     

    07.07.14 10:11:58,573 mds[45]: (Normal) Volume: volume:0x7fe49308a000 ********** Bootstrapped Creating a default store:0 SpotLoc:(null) SpotVerLoc:(null) occlude:0 /Volumes/VMware Fusion

    07.07.14 18:27:16,984 mds[45]: (Normal) DiskStore: Starting health check...

    07.07.14 18:27:16,984 mds[45]: (Normal) DiskStore: Starting health check...

    07.07.14 18:27:29,302 mds[45]: (Normal) Volume: volume:0x7fe49308b000 ********** Bootstrapped Creating a default store:0 SpotLoc:(null) SpotVerLoc:(null) occlude:0 /Volumes/Recovery HD

    07.07.14 22:41:08,262 mds[45]: (Warning) QueryTask: Haven't sent anything for 60 seconds; try despite not having received RTS notification.

    07.07.14 23:35:46,839 mds[45]: (Warning) QueryTask: Haven't sent anything for 60 seconds; try despite not having received RTS notification.

    08.07.14 00:36:54,550 mds[45]: (Warning) QueryTask: Haven't sent anything for 60 seconds; try despite not having received RTS notification.

    08.07.14 01:37:49,723 mds[45]: (Warning) QueryTask: Haven't sent anything for 60 seconds; try despite not having received RTS notification.

    08.07.14 02:38:39,597 mds[45]: (Warning) QueryTask: Haven't sent anything for 60 seconds; try despite not having received RTS notification.

    08.07.14 03:39:29,512 mds[45]: (Warning) QueryTask: Haven't sent anything for 60 seconds; try despite not having received RTS notification.

     

     

    And these are the mdworker entries: (I add some comments in between)

     

    The following files are not on HD2, but on the Server HD disk. I removed them in the meantime - they were a copy of the previous installation of the OS X Server Wiki:

     

    06.07.14 20:00:05,609 sandboxd[130]: ([19811]) mdworker(19811) deny file-read-xattr /Users/fsc/Desktop/Wiki (pre-plugin fstype:hfs fsflag:480D000 flags:250000005E diag:0 isXCode:0 uti:public.folder plugin:internalPlainTextImporter - find suspect file using: sudo mdutil -t 973707)

    06.07.14 20:00:05,770 sandboxd[130]: ([19819]) mdworker(19819) deny file-read-xattr /Users/fsc/Desktop/Wiki (pre-plugin fstype:hfs fsflag:480D000 flags:250000005E diag:0 isXCode:0 uti:public.folder plugin:internalPlainTextImporter - find suspect file using: sudo mdutil -t 973707)

    06.07.14 20:00:05,824 sandboxd[130]: ([19820]) mdworker(19820) deny file-read-xattr /Users/fsc/Desktop/Wiki (pre-plugin fstype:hfs fsflag:480D000 flags:250000005E diag:0 isXCode:0 uti:public.folder plugin:internalPlainTextImporter - find suspect file using: sudo mdutil -t 973740)

    06.07.14 20:00:08,124 sandboxd[130]: ([19820]) mdworker(19820) deny file-read-xattr /Users/fsc/Desktop/Wiki (pre-ls-info-1 fstype: fsflag:0 flags:250000005E diag:0 isXCode:0 uti:public.folder plugin:internalPlainTextImporter - find suspect file using: sudo mdutil -t 0)

    06.07.14 20:00:08,289 sandboxd[130]: ([19821]) mdworker(19821) deny file-read-xattr /Users/fsc/Desktop/Wiki (pre-plugin fstype:hfs fsflag:480D000 flags:250000005E diag:0 isXCode:0 uti:public.folder plugin:internalPlainTextImporter - find suspect file using: sudo mdutil -t 973740)

    06.07.14 20:00:47,512 sandboxd[130]: ([19821]) mdworker(19821) deny file-read-xattr /Users/fsc/Desktop/Wiki (pre-plugin fstype:hfs fsflag:480D000 flags:250000005E diag:0 isXCode:0 uti:public.folder plugin:internalPlainTextImporter - find suspect file using: sudo mdutil -t 975066)

    06.07.14 20:00:47,828 sandboxd[130]: ([19820]) mdworker(19820) deny file-read-xattr /Users/fsc/Desktop/Wiki (pre-plugin fstype:hfs fsflag:480D000 flags:250000005E diag:0 isXCode:0 uti:public.folder plugin:internalPlainTextImporter - find suspect file using: sudo mdutil -t 975066)

    06.07.14 20:00:47,886 sandboxd[130]: ([19811]) mdworker(19811) deny file-read-xattr /Users/fsc/Desktop/Wiki (pre-plugin fstype:hfs fsflag:480D000 flags:250000005E diag:0 isXCode:0 uti:public.folder plugin:internalPlainTextImporter - find suspect file using: sudo mdutil -t 975128)

     

    Don't know what these are:

     

    07.07.14 17:52:05,969 sandboxd[130]: ([62565]) mdworker(62565) deny mach-lookup com.apple.distributed_notifications@1v3

    07.07.14 18:27:17,240 sandboxd[130]: ([63869]) mdworker(63869) deny mach-lookup com.apple.distributed_notifications@1v3

     

    From here on the log messages are after the spotlight has been enabled on HD2:

     

    This is from a backup directory of a Nintendo 3DS. The "content" directory contains files with an .app extension which are certainly not Mac compatible app packages. What does the log message actually tell me? (one of the mdutil commands displays the full path to the file "00000003.app" in the contents directory)

     

    07.07.14 22:42:56,249 sandboxd[130]: ([72059]) mdworker(72059) deny file-read-data /Volumes/Macintosh HD2/Storage/backups/nds/3ds-backup/3ds-rot/2012-09-13/00032600/content (pre-ls-info-2 fstype:hfs fsflag:4809000 flags:40000005E diag:0 isXCode:0 uti:com.apple.application-file plugin:/Library/Spotlight/Application.mdimporter - find suspect file using: sudo mdutil -t 446464)

    07.07.14 22:42:56,255 sandboxd[130]: ([72059]) mdworker(72059) deny file-read-data /Volumes/Macintosh HD2/Storage/backups/nds/3ds-backup/3ds-rot/2012-09-13/00032600/content (pre-ls-info-2 fstype:hfs fsflag:4809000 flags:40000005E diag:0 isXCode:0 uti:com.apple.application-file plugin:/Library/Spotlight/Application.mdimporter - find suspect file using: sudo mdutil -t 446464)

    07.07.14 22:42:57,615 sandboxd[130]: ([72059]) mdworker(72059) deny file-read-data /Volumes/Macintosh HD2/Storage/backups/nds/3ds-backup/3ds-rot/2012-09-13/00032600/content (pre-ls-info-2 fstype:hfs fsflag:4809000 flags:40000005E diag:0 isXCode:0 uti:com.apple.application-file plugin:/Library/Spotlight/Application.mdimporter - find suspect file using: sudo mdutil -t 446465)

    07.07.14 22:42:57,642 sandboxd[130]: ([72059]) mdworker(72059) deny file-read-data /Volumes/Macintosh HD2/Storage/backups/nds/3ds-backup/3ds-rot/2012-09-13/00032600/content (pre-ls-info-2 fstype:hfs fsflag:4809000 flags:40000005E diag:0 isXCode:0 uti:com.apple.application-file plugin:/Library/Spotlight/Application.mdimporter - find suspect file using: sudo mdutil -t 446465)

     

    Looks like some PNG files problems:

     

    07.07.14 22:44:04,907 mdworker[72111]: ImageIO: PNG [00][00][00][00]: invalid chunk type

    (above line repeated several times)

     

    Don't know what these are:

     

    07.07.14 22:58:23,267 mdworker32[72522]: CGSConnectionByID: 0 is not a valid connection ID.

    07.07.14 22:58:23,267 mdworker32[72522]: CGSGetSpaceManagementMode: No connection with id 0x       0

    07.07.14 23:02:14,903 mdworker32[72597]: CGSConnectionByID: 0 is not a valid connection ID.

    07.07.14 23:02:14,903 mdworker32[72597]: CGSGetSpaceManagementMode: No connection with id 0x       0

     

    Looks like a bad MIDI file:

     

    07.07.14 23:14:22,107 mdworker[72819]: 23:14:22.099 NOTE:      [0x10ed87000] StandardMidiFile.cpp:201: ReadStandardMidiFile: Sequence::ReadStandardMidiFile(): invalid track length

     

    Bad cpio file:

     

    07.07.14 23:15:16,304 mdworker[72901]: cpio importer encountered an error (3) scanning "(a file with .cpio extension)".

     

    Bad photoshop file:

     

    07.07.14 23:23:52,812 mdworker[73073]: ImageIO: readPhotoshopImageResource Corrupt 8BIM data. Reported 8BIM length (32754 bytes) exceeds actual length (31400 bytes).

     

    I would assume that spotlight shouldn't stumble over incorrectly understood files (bad images and the like...)...

  • by Rainer Schwarze,

    Rainer Schwarze Rainer Schwarze Jul 8, 2014 9:29 AM in response to dkolba
    Level 1 (0 points)
    Jul 8, 2014 9:29 AM in response to dkolba

    dkolba wrote:

     

    Had this same problem on 1 of the computers out of 3 that were backing up to the same time capsule.  even hired an IT guy to come and look at it.  didn't fix the problem till we formatted the computer and did a clean install of the OS.  No problems since.  Wish i could give you some fix we had for this but couldn't seem to get any further then a format.

     

    I was hoping to do without a new install. The Server HD is now formatted anew and the problem seems to be on the HD2. I think I can switch back to the Time Capsule backup and turn off spotlight on HD2 for now. The ExtHD03 has enough space for a manual copy of the HD2 files, so I could do a nice reformat and see whether a Time Capsule restore works, and if not use ExtHD03...

  • by dwbrecovery,

    dwbrecovery dwbrecovery Jul 8, 2014 9:58 AM in response to Rainer Schwarze
    Level 3 (589 points)
    Servers Enterprise
    Jul 8, 2014 9:58 AM in response to Rainer Schwarze

    Thanks for the logs.

    - I totally reset spotlight on a server ( mdutil  -Ea ) to compare logs

    - I got the mds…QueryTask…RTS events as well as the  sandbox…..deny events and spotlight eventually re-indexed everything without lockup.

    - Found no references for the mds RTS events, so can only keep looking.

    From your logs:

    - Before you restore HD2 from the Time Capsule ( good redundancy plan ) try with Disk Utility to "Repair Disk Permissions ", then " Repair Disk" on HD2 followed by a reset / reindex of Spotlight on HD2. 

     

    - As for your permissions on your shares, investigate using ACLs.  it may sort your issues with Samba.

     

    Cheers

  • by Rainer Schwarze,

    Rainer Schwarze Rainer Schwarze Jul 9, 2014 7:08 AM in response to dwbrecovery
    Level 1 (0 points)
    Jul 9, 2014 7:08 AM in response to dwbrecovery

    I let the server work over night. Created a backup image of the HD2, erased and formatted the disk, restored from image. This was finished in the morning. A big backup was done successfully. Then I turned on spotlight for HD2 again - and only one backup worked, the next one is stuck.

     

    Regarding the verify permissions: For the HD2 volume the disk util says "Not available because the volume ignores ownership" (translated from German). In the disk util on the lower left it says: "Eigentuemer aktiviert: Ja" (probably "Ownership activated: yes"). When I open "Info" on the volume, the little box at the very bottom of the window is ticked off ("Eigentuemer auf diesem Volume ignorieren" - "Ignore ownership on this volume"?).

     

    Why would then the permissions button be disabled in diskutil?

     

    When I click that checkbox in the Info window, the ownership label in disk util changes accordingly. However, the permissions button is never enabled.

Page 1 of 3 last Next