I have encountered the same problem on two protected disk image files as well. Once in January and then again a few days ago.
I first thought that the first lockout was a fluke. Now after the second image lockout I'm very vary of opening another encrypted backup. I'm losing data. Even copies of the .dmg on different drives fail to authenticate. Searching for answers I found this thread.
Is it possible that a kernel panic / forced shutdown can corrupt an encrypted file? I wonder, but my encrypted home directory (FileVault sparsebundle) is fine.
Any insights would be appreciated.
This is my log:
Last login: Sun May 11 07:35:13 on ttys000
kevin:~ kevin$ hdiutil attach -debug /Volumes/kevin/busted.dmg calling DIHLDiskImageAttach with
agent: hdiutil
drive-options:
debug: true
image-options:
verbose: false
quiet: false
main-url: /Volumes/kevin/busted.dmg
2008-05-12 18:11:17.015 hdiutil[1745:1c03] using helper tool at "/System/Library/PrivateFrameworks/DiskImages.framework/Resources/diskimages-he lper".
2008-05-12 18:11:17.040 hdiutil[1745:1c03] connectToFramework
2008-05-12 18:11:17.141 hdiutil[1745:1c03] sendOperationToHelper: about to ask proxy to start operation
status proc called: initialize
2008-05-12 18:11:17.173 diskimages-helper[1747:1603] _imageOptions: {
"enable-keychain" = 1;
}
2008-05-12 18:11:17.176 diskimages-helper[1747:1603] _driveOptions: {
autodiskmount = 1;
"unmount-timeout" = 0;
}
2008-05-12 18:11:17.178 diskimages-helper[1747:1603] DIHelperAttach: initializing framework
DILoadDriver: checking for disk image driver...DILoadDriver: DI_kextExists() returned 0x00000000 (0)...DIIsInitialized: returning NO2008-05-12 18:11:17.188 diskimages-helper[1747:1603] -checkForPreviouslyAttachedImage: entry
2008-05-12 18:11:17.189 diskimages-helper[1747:1603]
file://localhost/Volumes/kevin/busted.dmg - (null) ((null), (null)). perm=0
DIIsInitialized: returning YESDIBackingStoreNewWithCFURL: entry with
file://localhost/Volumes/kevin/busted.dmg
skip-permissions-check: true
DIBackingStoreInstantiatorProbe: entry
file://localhost/Volumes/kevin/busted.dmg
skip-permissions-check: true
DIBackingStoreInstantiatorProbe: probing interface 0 CBSDBackingStore
CBSDBackingStore::newProbe score 100 for
file://localhost/Volumes/kevin/busted.dmg
DIBackingStoreInstantiatorProbe: probing interface 1 CBundleBackingStore
CBundleBackingStore::newProbe score -1000 for
file://localhost/Volumes/kevin/busted.dmg
DIBackingStoreInstantiatorProbe: probing interface 2 CRAMBackingStore
CRAMBackingStore::probe: scheme "file": not ram: or ramdisk: scheme.
CRAMBackingStore::probe: score -1000 for
file://localhost/Volumes/kevin/busted.dmg
DIBackingStoreInstantiatorProbe: probing interface 3 CCarbonBackingStore
CCarbonBackingStore::newProbe: setting initial rval to +100
CCarbonBackingStore::newProbe: has resource fork, +100
CCarbonBackingStore::newProbe score 200 for
file://localhost/Volumes/kevin/busted.dmg
DIBackingStoreInstantiatorProbe: probing interface 4 CDevBackingStore
CDevBackingStore::newProbe: not /dev/disk or /dev/rdisk (/Volumes/kevin/busted.dmg).CDevBackingStore::newProbe score -1000 for
DIBackingStoreInstantiatorProbe: probing interface 5 CCURLBackingStore
CCURLBackingStore::probe: scheme is
file
CCURLBackingStore::probe: not recognized URL scheme.
CCURLBackingStore::probe: score -1000 for
file://localhost/Volumes/kevin/busted.dmg
DIBackingStoreInstantiatorProbe: probing interface 6 CVectoredBackingStore
CVectoredBackingStore::newProbe not "vectored" scheme.
CVectoredBackingStore::newProbe score -1000 for
file://localhost/Volumes/kevin/busted.dmg
DIBackingStoreNewWithCFURL: CCarbonBackingStore
DIBackingStoreNewWithCFURL: instantiator returned 0
DIBackingStoreNewWithCFURL: returning 0x00000000
2008-05-12 18:11:17.190 diskimages-helper[1747:1603] -checkForPreviouslyAttachedImage: resolving
file://localhost/Volumes/kevin/busted.dmg returned 0
2008-05-12 18:11:17.191 diskimages-helper[1747:1603] -checkForPreviouslyAttachedImage: imageUID (
"d234881039:i8914"
) shadowUID (null)
*** testing:
0: d234881039:i9111
(null)
(null)
*** testing:
0: d234881039:i9111
(null)
(null)
*** testing:
0: d234881039:i9111
(null)
(null)
2008-05-12 18:11:17.194 diskimages-helper[1747:1603] DIHelperAttach: resolving disk image
DIIsInitialized: returning YESDIIsInitialized: returning YESDIBackingStoreNewWithCFURL: entry with
file://localhost/Volumes/kevin/busted.dmg
enable-keychain: true
image-path: /Volumes/kevin/busted.dmg
DIBackingStoreInstantiatorProbe: entry
file://localhost/Volumes/kevin/busted.dmg
enable-keychain: true
image-path: /Volumes/kevin/busted.dmg
DIBackingStoreInstantiatorProbe: probing interface 0 CBSDBackingStore
CBSDBackingStore::newProbe score 100 for
file://localhost/Volumes/kevin/busted.dmg
DIBackingStoreInstantiatorProbe: probing interface 1 CBundleBackingStore
CBundleBackingStore::newProbe score -1000 for
file://localhost/Volumes/kevin/busted.dmg
DIBackingStoreInstantiatorProbe: probing interface 2 CRAMBackingStore
CRAMBackingStore::probe: scheme "file": not ram: or ramdisk: scheme.
CRAMBackingStore::probe: score -1000 for
file://localhost/Volumes/kevin/busted.dmg
DIBackingStoreInstantiatorProbe: probing interface 3 CCarbonBackingStore
CCarbonBackingStore::newProbe: setting initial rval to +100
CCarbonBackingStore::newProbe: has resource fork, +100
CCarbonBackingStore::newProbe score 200 for
file://localhost/Volumes/kevin/busted.dmg
DIBackingStoreInstantiatorProbe: probing interface 4 CDevBackingStore
CDevBackingStore::newProbe: not /dev/disk or /dev/rdisk (/Volumes/kevin/busted.dmg).CDevBackingStore::newProbe score -1000 for
DIBackingStoreInstantiatorProbe: probing interface 5 CCURLBackingStore
CCURLBackingStore::probe: scheme is
file
CCURLBackingStore::probe: not recognized URL scheme.
CCURLBackingStore::probe: score -1000 for
file://localhost/Volumes/kevin/busted.dmg
DIBackingStoreInstantiatorProbe: probing interface 6 CVectoredBackingStore
CVectoredBackingStore::newProbe not "vectored" scheme.
CVectoredBackingStore::newProbe score -1000 for
file://localhost/Volumes/kevin/busted.dmg
DIBackingStoreNewWithCFURL: CCarbonBackingStore
opening /Volumes/kevin/busted.dmg setPermission 1723
CBSDBackingStore::OpenLockFriendly: mapping flags 0x00000002 -> 0x00000026 (locks are MANDATORY)
(RW lock acquired)
closing /Volumes/kevin/busted.dmg setPermission 1731
DIBackingStoreNewWithCFURL: instantiator returned 0
DIBackingStoreNewWithCFURL: returning 0x00000000
DIResolveURLToBackingStore: processing level 1 encodings.
DIFileEncodingNewWithBackingStore: entry for encoding level 1
DIFileEncodingInstantiatorProbe: entry for level 1
enable-keychain: true
image-path: /Volumes/kevin/busted.dmg
DIFileEncodingInstantiatorProbe: probing level 1 interface 0 CMacBinaryEncoding
CBSDBackingStore::openDataFork: about to open /Volumes/kevin/busted.dmg
opening /Volumes/kevin/busted.dmg openDataFork 1904
CBSDBackingStore::OpenLockFriendly: mapping flags 0x00000002 -> 0x00000026 (locks are MANDATORY)
(RW lock acquired)
closing 3 /Volumes/kevin/busted.dmg closeDataFork 1984
00000000: 656e 6372 6364 7361 0000 0002 0000 0010 | encrcdsa........ |
00000010: 0000 0005 8000 0001 0000 0100 0000 005b | ...............[ |
00000020: 0000 00a0 548a 2877 86c1 4f17 877b cf66 | ....T.(w..O..{.f |
00000030: beea 6066 0000 1000 0000 0002 780e 1734 | ..`f........x..4 |
00000040: 0000 0000 0001 e000 0000 0001 0000 0001 | ................ |
00000050: 0000 0000 0000 0060 0000 0000 0000 0268 | .......`.......h |
00000060: 0000 0067 0000 0000 0000 03e8 0000 0014 | ...g............ |
00000070: d369 cd83 75e8 bb7c 72e5 020d fdd3 68a9 | .i..u..|r.....h. |
diskimages-helper: fileNameLength $0000006E
diskimages-helper: resourceForkLength $60000000
diskimages-helper: dataForkLength $00000000
diskimages-helper: commentLength $00006700
diskimages-helper: MacBinary III signature (0x00000000)
diskimages-helper: header CRC $0000FDD3
diskimages-helper: minimum decoder version $0000000D
diskimages-helper: encoder version $00000002
no MacBinary III signature - checking for MacBinary I or IIDIFileEncodingInstantiatorProbe: probing level 1 interface 1 CAppleSingleEncoding
CBSDBackingStore::openDataFork: about to open /Volumes/kevin/busted.dmg
opening /Volumes/kevin/busted.dmg openDataFork 1904
CBSDBackingStore::OpenLockFriendly: mapping flags 0x00000002 -> 0x00000026 (locks are MANDATORY)
(RW lock acquired)
00000000: 7263 6e65 6173 6463 0000 0002 0000 0010 | rcneasdc........ |
00000010: 0000 0005 8000 0001 0000 0100 0000 005b | ...............[ |
00000020: 0000 00a0 548a .... .... .... .... .... | ....T........... |
closing 3 /Volumes/kevin/busted.dmg closeDataFork 1984
CAppleSingleEncoding::isAppleSingleFile loadAppleSingleHeader failed with error 22
DIFileEncodingInstantiatorProbe: probing level 1 interface 2 CEncryptedEncoding
CBSDBackingStore::openDataFork: about to open /Volumes/kevin/busted.dmg
opening /Volumes/kevin/busted.dmg openDataFork 1904
CBSDBackingStore::OpenLockFriendly: mapping flags 0x00000002 -> 0x00000026 (locks are MANDATORY)
(RW lock acquired)
CEncryptedEncoding::copyHeaderInformation: inBackingStore->openDataFork returned 0
CEncryptedEncoding::copyHeaderInformation: inBackingStore->getDataForkLength (stub header) returned 0
CEncryptedEncoding::copyHeaderInformation: backingStore data fork length is 0x0000000278100000 (10604249088)
CEncryptedEncoding::copyHeaderInformation: reading V1 header from offset 0x00000002780FFB04 (10604247812)
CEncryptedEncoding::copyHeaderInformation: inBackingStore->readDataFork (stub header) returned 0
CEncryptedEncoding::copyHeaderInformation: not recognized as v1 header
CEncryptedEncoding::copyHeaderInformation: reading V2 header from offset 0x0000000000000000 (0)
CEncryptedEncoding::copyHeaderInformation: inBackingStore->readDataFork (stub header) returned 0
CEncryptedEncoding::copyHeaderInformation: reading auth-entry count from offset 0x0000000000000048 (72)
CEncryptedEncoding::copyHeaderInformation: inBackingStore->readDataFork (auth entry count) returned 0
CEncryptedEncoding::copyHeaderInformation: reading auth table from offset 0x0000000000000048 (72)
CEncryptedEncoding::copyHeaderInformation: inBackingStore->readDataFork (auth entry count) returned 0
closing 3 /Volumes/kevin/busted.dmg closeDataFork 1984
max-key-count: 1
blocksize: 4096
uuid: 548A2877-86C1-4F17-877B-CF66BEEA6066
version: 2
passphrase-count: 1
private-key-count: 0
CBSDBackingStore::openDataFork: about to open /Volumes/kevin/busted.dmg
opening /Volumes/kevin/busted.dmg openDataFork 1904
CBSDBackingStore::OpenLockFriendly: mapping flags 0x00000002 -> 0x00000026 (locks are MANDATORY)
(RW lock acquired)
closing 3 /Volumes/kevin/busted.dmg closeDataFork 1984
CBSDBackingStore::openDataFork: about to open /Volumes/kevin/busted.dmg
opening /Volumes/kevin/busted.dmg openDataFork 1904
CBSDBackingStore::OpenLockFriendly: mapping flags 0x00000002 -> 0x00000026 (locks are MANDATORY)
(RW lock acquired)
closing 3 /Volumes/kevin/busted.dmg closeDataFork 1984
diskimages-helper: DiskImages secure mode enabled
CEncryptedEncoding:unclock
CANTHROW: trying to unlock with normal keychain
UNLOCK: cannot find passphrase in keychain search list.
UNLOCK: SessionGetInfo returned 0
UNLOCK: sessionHasGraphicAccess
UNLOCK: sessionHasTTY
UNLOCK: sessionWasInitialized
UNLOCK: using TTY to prompt for passphrase
Enter password to access "busted.dmg":
unlockCoreFromTTY: passphrase is wrong
DIFileEncodingNewWithBackingStore: returning 0x00000050
DIResolveURLToBackingStore: level 1 encoding match failed. 80.
DIResolveURLToDiskImage: resolving backing store/file encoding failed. 80.
status proc called: attach
error code: 80
status proc called: cleanup
2008-05-12 18:11:41.081 diskimages-helper[1747:1603] DIHelperAttach performOperation: returning 80
2008-05-12 18:11:41.082 diskimages-helper[1747:1603] -decrementBackgroundThreadCount: _backgroundThreadCount is now 0.
2008-05-12 18:11:41.082 diskimages-helper[1747:10b] DIHelper
reportresults: reporting {
payload = {
};
"result-code" = 80;
}
2008-05-12 18:11:41.083 hdiutil[1745:1c03] reportResultsToFramework: proxy has finished operation
2008-05-12 18:11:41.084 hdiutil[1745:1c03] reportResultsToFramework: results are: {
payload = {
};
"result-code" = 80;
}
2008-05-12 18:11:41.084 hdiutil[1745:1c03] reportResultsToFramework: _threadResultsError is 80
2008-05-12 18:11:41.085 hdiutil[1745:1c03] reportResultsToFramework: disconnecting from helper.
2008-05-12 18:11:41.186 hdiutil[1745:1c03] disconnectFromHelper: removing observers
2008-05-12 18:11:41.187 hdiutil[1745:1c03] disconnectFromHelper: terminating proxy
2008-05-12 18:11:41.189 diskimages-helper[1747:10b] DIHelper: terminateHelper: entry.
2008-05-12 18:11:41.190 hdiutil[1745:1c03] disconnectFromHelper: terminated proxy
2008-05-12 18:11:41.290 diskimages-helper[1747:10b] -DIHelperAgentMaster terminateUIAgentConnection.
DIHLDiskImageAttach() returned 80
2008-05-12 18:11:41.293 diskimages-helper[1747:10b] DIHelper dealloc.
2008-05-12 18:11:41.294 diskimages-helper[1747:10b] -DIHelperAgentMaster terminateUIAgentConnection.
hdiutil: attach failed - Authentication error
kevin:~ kevin$