Console errors from file compression?

Discussion in 'macOS' started by jbbenni, May 30, 2012.

  1. jbbenni macrumors newbie

    Joined:
    Dec 1, 2011
    #1
    Hi,

    Under 10.7.4 Time Machine hangs and I get these in my console log:

    5/30/12 9:51:11.000 AM kernel: /SourceCache/AppleFSCompression/AppleFSCompression-37/Compressors/Dataless/compressorType5Kext.c:532: Error: post_request error for /Volumes/T3/Backups.backupdb/jbenniMac/2012-05-30-084212.inProgress/1C6092BC-1544-4B25-97EC-CAF382604372/Macintosh HD/.DocumentRevisions-V100-bad-1/PerUID/501/118/com.apple.documentVersions/08669C22-C5AD-4414-BE6D-D77C54D398CF.m: 35

    5/30/12 9:51:11.000 AM kernel: decmpfs.c:1309:decmpfs_read_compressed: decmpfs_fetch_uncompressed_data err -35

    The destination disk (direct attach, FW) is new. Both the source and dest disks verify under Disk Utils. TM hangs with X bytes written. (The time to complete estimate continues to rise indefinitely.) The above messages repeat on console every 15 secs.

    How can I find the cause?

    Thanks!
    John
     
  2. wrldwzrd89 macrumors G5

    wrldwzrd89

    Joined:
    Jun 6, 2003
    Location:
    Solon, OH
    #2
    Wow, I have not seen this particular error before... but the cause appears to be a corrupted inProgress Time Machine backup, at least at first glance. Try deleting the offending backup (it's called /Volumes/T3/Backups.backupdb/jbenniMac/2012-05-30-084212.inProgress) and perform a Time Machine backup manually when that finishes.
     
  3. jbbenni thread starter macrumors newbie

    Joined:
    Dec 1, 2011
    #3
    Erased dest volume - same problem reocurred

    Thanks for responding.

    I used Disk Utils and erased the backup disk partition, then restarted TM. It recognized the volume as a new one, recomputed space then started file backup. At the same progress point, it began to get the same errors:

    5/30/12 4:07:54.000 PM kernel: /SourceCache/AppleFSCompression/AppleFSCompression-37/Compressors/Dataless/compressorType5Kext.c:532: Error: post_request error for /.DocumentRevisions-V100-bad-1/PerUID/501/118/com.apple.documentVersions/10AFD71C-1C15-426A-8156-DD957ADD2A45.m: 35
    5/30/12 4:07:54.000 PM kernel: decmpfs.c:1309:decmpfs_read_compressed: decmpfs_fetch_uncompressed_data err -35

    Looks identical to me. Could it be a bad file on the source disk (which Verifies as clean)? If so, how to identify what file so I can skip it?

    I appreciate any help with this one!
     
  4. Mr. Retrofire macrumors 603

    Mr. Retrofire

    Joined:
    Mar 2, 2010
    Location:
    www.emiliana.cl/en
    #4
    Mhh. Looks like an error in the code of Time Machine. Enable the ownership for the Time Machine disk, and make sure it is a HFS+ (also called "Mac OS Extended") Journaled volume. NTFS, FAT32 and Linux file systems are not compatible with Time Machine, AFAIK.

    In the Terminal:
    If you see this bug again, report the bug here:
    https://bugreport.apple.com

    List of Apple Error Codes:
    http://support.apple.com/kb/HT1618?viewlocale=en_US
     
  5. jbbenni thread starter macrumors newbie

    Joined:
    Dec 1, 2011
    #5
    More console detail, will submit as bug

    Thanks Mr. Retrofire,

    I double checked that the drive partition is HFS+ (OS X extended, case-sensitive, journaled). It is.

    I confirmed volume ownership with the terminal command. That worked.

    I restarted TM and get the same problem at the same point.

    There is some other chatter on the console that I had assumed wasn't related, but it may be. So in the interest of more complete disclosure, here are some other messages. The timestamps are preserved, so you can see the sequence:
    5/30/12 4:56:23.370 PM com.apple.backupd: Starting standard backup
    5/30/12 4:56:23.475 PM com.apple.backupd: Backing up to: /Volumes/T3/Backups.backupdb
    5/30/12 4:58:03.044 PM com.apple.backupd: Backup content size: 455.3 GB excluded items size: 88.3 GB for volume Macintosh HD
    5/30/12 4:58:03.318 PM com.apple.backupd: 440.35 GB required (including padding), 2.61 TB available
    5/30/12 4:58:03.330 PM com.apple.backupd: Waiting for index to be ready (101)
    5/30/12 4:58:15.056 PM com.apple.revisiond: [ERROR] genstore_chunk_interface.m:GSChunkedFilesSatisfyReadRequest:423 no chunk store for fsid 234881030 fileid 209 offset 0 size 65536
    5/30/12 4:58:30.057 PM com.apple.revisiond: [ERROR] genstore_chunk_interface.m:GSChunkedFilesSatisfyReadRequest:423 no chunk store for fsid 234881030 fileid 209 offset 65536 size 62045
    5/30/12 4:58:30.000 PM kernel: /SourceCache/AppleFSCompression/AppleFSCompression-37/Compressors/Dataless/compressorType5Kext.c:532: Error: post_request error for /Volumes/T3/Backups.backupdb/jbenniMac/2012-05-30-160241.inProgress/85CE1122-6471-4A46-AA6E-A279496FC595/Macintosh HD/.DocumentRevisions-V100-bad-1/PerUID/501/1/com.apple.documentVersions/A6B83243-607F-49F8-B959-0DDE4EA2EAFC.pdf: 35
    5/30/12 4:58:30.000 PM kernel: decmpfs.c:1309:decmpfs_read_compressed: decmpfs_fetch_uncompressed_data err -35

    ... repetitions of similar messages at frequent intervals ...
    When I canceled TM (clicked "stop backup" in the progress bar) I got more logging:

    5/30/12 5:00:30.128 PM revisiond: send response: Invalid argument
    5/30/12 5:00:30.128 PM com.apple.revisiond: [ERROR] 181f1dcb21be [12/05/30 17:00:30.127] 72. _CSChunkRefsForToken:2425 _CSChunkRefsForToken sqlite3_step returned: 101 unknown error, for listToken: 5572
    5/30/12 5:00:30.128 PM com.apple.revisiond: [ERROR] genstore_chunk_interface.m:-[GSChunkedFilesEntry updateEntry:]:305 CSCopyChunkIDsForToken failed for 5572
    5/30/12 5:00:30.128 PM com.apple.revisiond: [ERROR] genstore_chunk_interface.m:-[GSChunkedFilesEntry _initWithPath:chunkStore:]:326 updateEntry for new entry /.DocumentRevisions-V100-bad-1/PerUID/501/118/com.apple.documentVersions/245A73B8-715A-41C8-AC92-14D37FB20C47.m failed
    5/30/12 5:00:30.128 PM com.apple.revisiond: [ERROR] genstore_chunk_interface.m:assembleInfoForOffset:376 no entry for '/.DocumentRevisions-V100-bad-1/PerUID/501/118/com.apple.documentVersions/245A73B8-715A-41C8-AC92-14D37FB20C47.m'
    5/30/12 5:00:30.128 PM com.apple.revisiond: [ERROR] genstore_chunk_interface.m:GSChunkedFilesSatisfyReadRequest:439 failed assembleInfoForOffset for fsid 234881026 fileid 118644920 offset 0 size 3391 (path /.DocumentRevisions-V100-bad-1/PerUID/501/118/com.apple.documentVersions/245A73B8-715A-41C8-AC92-14D37FB20C47.m)
    5/30/12 5:00:30.129 PM com.apple.backupd: Copied 26 files (147.0 MB) from volume Macintosh HD.
    5/30/12 5:00:30.130 PM mds: (Error) Volume: Could not find requested backup type:2 for volume
    5/30/12 5:00:30.660 PM com.apple.backupd: Backup canceled.

    I assumed the revisiond messages were unrelated, but I'd hate to omit important context.

    At this point, I'm stumped and the experts don't seem to recognize anything obviously wrong. So I'd still welcome any and all suggestions, but unless someone sees something soon I'll report it to Apple as a bug and see if they accept it.

    Thanks for your response!
     
  6. wrldwzrd89 macrumors G5

    wrldwzrd89

    Joined:
    Jun 6, 2003
    Location:
    Solon, OH
    #6
    After analyzing this problem some more, it appears that the ORIGINAL file on Macintosh HD (/.DocumentRevisions-V100-bad-1/PerUID/501/1/com.apple.documentVersions/A6B83243-607F-49F8-B959-0DDE4EA2EAFC.pdf) has gotten corrupted somehow, and is thus causing TM to try to back it up and fail. This file is a saved revision of a PDF document on your disk somewhere - PDFs aren't editable (for the most part - they can be filled in or annotated) so it should be safe to delete.
     
  7. jbbenni thread starter macrumors newbie

    Joined:
    Dec 1, 2011
    #7
    Thank you!

    wrldwzrd89,

    Yes, that appears to work. I hadn't realized that the destination path name included the source path that TM was choking on. I've also learned that it is safe to exclude from TM the entire directory:
    /.DocumentRevisions-V100-bad-1/

    Apparently if the Document Revisions database becomes corrupt for some unspecified reason, OSX renames it to /.DocumentRevisions-V100-bad (adding a suffix to ensure a unique name).

    So my backup is now running, and well past the point where it formerly hung.

    Thank you so much!
     
  8. jbbenni thread starter macrumors newbie

    Joined:
    Dec 1, 2011
    #8
    Resolved - Thank you!

    After excluding the offending hidden directory, everything worked just fine.

    I completed a backup and will now delete the offending directory (since it's invalid anyway!).

    I very much appreciate the astute advice - especially from wrldwzrd89.

    Thank you!!
     
  9. Mainyehc macrumors 6502a

    Mainyehc

    Joined:
    Mar 14, 2004
    Location:
    Lisbon, Portugal
    #9
    Well, I just had the same issue but, unlike in your case, OS X did not rename my database… But, regardless, it must be corrupt, otherwise Time Machine would work just fine.

    Anyway, this is some great advice and it solved my issue; I had just swapped the hard drive on my LaCie Quadra and I was afraid it was either defective or incompatible (even though a large file transfer done in Finder and SuperDuper! worked just fine, so I was dead sure that Time Machine/OS X itself was at fault). Thanks!
     
  10. rainev macrumors newbie

    Joined:
    Feb 21, 2012
    #10
    I had a similar problem where the backup process would right from the start get stuck at 2MB and Console would keep logging this thing about post_request error. Good thing I found this thread.

    After first turning of TM backups, this fixed it

    Code:
    $ sudo rm -rf /.DocumentRevisions-V100/
     

Share This Page