add a ton of logging to DecryptVerify

This commit is contained in:
Vincent Breitmoser 2014-09-13 21:14:06 +02:00
parent dbbefe2f41
commit efd9d1626e
4 changed files with 166 additions and 26 deletions

View File

@ -206,14 +206,14 @@ public class PgpDecryptVerify {
// else: ascii armored encryption! go on...
}
return decryptVerify(in);
return decryptVerify(in, 0);
} catch (PGPException e) {
OperationLog log = new OperationLog();
// log.add(LogLevel.ERROR, LogType.MSG_DC_ERROR_PGP_EXCEPTION);
log.add(LogLevel.ERROR, LogType.MSG_DC_ERROR_PGP_EXCEPTION, 1);
return new DecryptVerifyResult(DecryptVerifyResult.RESULT_ERROR, log);
} catch (IOException e) {
OperationLog log = new OperationLog();
// log.add(LogLevel.ERROR, LogType.MSG_DC_ERROR_IO);
log.add(LogLevel.ERROR, LogType.MSG_DC_ERROR_IO, 1);
return new DecryptVerifyResult(DecryptVerifyResult.RESULT_ERROR, log);
}
}
@ -221,10 +221,13 @@ public class PgpDecryptVerify {
/**
* Decrypt and/or verifies binary or ascii armored pgp
*/
private DecryptVerifyResult decryptVerify(InputStream in) throws IOException, PGPException {
private DecryptVerifyResult decryptVerify(InputStream in, int indent) throws IOException, PGPException {
OperationLog log = new OperationLog();
log.add(LogLevel.START, LogType.MSG_DC, indent);
indent += 1;
PGPObjectFactory pgpF = new PGPObjectFactory(in, new JcaKeyFingerprintCalculator());
PGPEncryptedDataList enc;
Object o = pgpF.nextObject();
@ -239,7 +242,7 @@ public class PgpDecryptVerify {
}
if (enc == null) {
// log.add(LogLevel.ERROR, LogType.MSG_DC_ERROR_INVALID_DATA)
log.add(LogLevel.ERROR, LogType.MSG_DC_ERROR_INVALID_SIGLIST, indent);
return new DecryptVerifyResult(DecryptVerifyResult.RESULT_ERROR, log);
}
@ -252,35 +255,44 @@ public class PgpDecryptVerify {
Iterator<?> it = enc.getEncryptedDataObjects();
boolean asymmetricPacketFound = false;
boolean symmetricPacketFound = false;
boolean anyPacketFound = false;
// go through all objects and find one we can decrypt
while (it.hasNext()) {
Object obj = it.next();
if (obj instanceof PGPPublicKeyEncryptedData) {
anyPacketFound = true;
currentProgress += 2;
updateProgress(R.string.progress_finding_key, currentProgress, 100);
PGPPublicKeyEncryptedData encData = (PGPPublicKeyEncryptedData) obj;
long subKeyId = encData.getKeyID();
log.add(LogLevel.DEBUG, LogType.MSG_DC_ASYM, indent,
PgpKeyHelper.convertKeyIdToHex(subKeyId));
CanonicalizedSecretKeyRing secretKeyRing;
try {
// get actual keyring object based on master key id
secretKeyRing = mProviderHelper.getCanonicalizedSecretKeyRing(
KeyRings.buildUnifiedKeyRingsFindBySubkeyUri(encData.getKeyID())
KeyRings.buildUnifiedKeyRingsFindBySubkeyUri(subKeyId)
);
} catch (ProviderHelper.NotFoundException e) {
// continue with the next packet in the while loop
log.add(LogLevel.DEBUG, LogType.MSG_DC_ASKIP_NO_KEY, indent +1);
continue;
}
if (secretKeyRing == null) {
// continue with the next packet in the while loop
log.add(LogLevel.DEBUG, LogType.MSG_DC_ASKIP_NO_KEY, indent +1);
continue;
}
// get subkey which has been used for this encryption packet
secretEncryptionKey = secretKeyRing.getSecretKey(subKeyId);
if (secretEncryptionKey == null) {
// continue with the next packet in the while loop
// should actually never happen, so no need to be more specific.
log.add(LogLevel.DEBUG, LogType.MSG_DC_ASKIP_NO_KEY, indent +1);
continue;
}
@ -294,6 +306,7 @@ public class PgpDecryptVerify {
if (!mAllowedKeyIds.contains(masterKeyId)) {
// this key is in our db, but NOT allowed!
// continue with the next packet in the while loop
log.add(LogLevel.DEBUG, LogType.MSG_DC_ASKIP_NOT_ALLOWED, indent +1);
continue;
}
}
@ -308,14 +321,15 @@ public class PgpDecryptVerify {
try {
// returns "" if key has no passphrase
mPassphrase = mPassphraseCache.getCachedPassphrase(subKeyId);
log.add(LogLevel.DEBUG, LogType.MSG_DC_PASS_CACHED, indent +1);
} catch (NoSecretKeyException e) {
// log.add(LogLevel.ERROR, LogType.MSG_DEC_ERROR_NO_KEY);
log.add(LogLevel.ERROR, LogType.MSG_DC_ERROR_NO_KEY, indent +1);
return new DecryptVerifyResult(DecryptVerifyResult.RESULT_ERROR, log);
}
// if passphrase was not cached, return here
// indicating that a passphrase is missing!
// if passphrase was not cached, return here indicating that a passphrase is missing!
if (mPassphrase == null) {
log.add(LogLevel.INFO, LogType.MSG_DC_PENDING_PASSPHRASE, indent +1);
DecryptVerifyResult result =
new DecryptVerifyResult(DecryptVerifyResult.RESULT_PENDING_ASYM_PASSPHRASE, log);
result.setKeyIdPassphraseNeeded(subKeyId);
@ -324,9 +338,18 @@ public class PgpDecryptVerify {
}
// break out of while, only decrypt the first packet where we have a key
// TODO???: There could be more pgp objects, which are not decrypted!
break;
} else if (mAllowSymmetricDecryption && obj instanceof PGPPBEEncryptedData) {
} else if (obj instanceof PGPPBEEncryptedData) {
anyPacketFound = true;
log.add(LogLevel.DEBUG, LogType.MSG_DC_SYM, indent);
if (! mAllowSymmetricDecryption) {
log.add(LogLevel.WARN, LogType.MSG_DC_SYM_SKIP, indent +1);
continue;
}
/*
* When mAllowSymmetricDecryption == true and we find a data packet here,
* we do not search for other available asymmetric packets!
@ -338,15 +361,30 @@ public class PgpDecryptVerify {
// if no passphrase is given, return here
// indicating that a passphrase is missing!
if (mPassphrase == null) {
log.add(LogLevel.INFO, LogType.MSG_DC_PENDING_PASSPHRASE, indent +1);
return new DecryptVerifyResult(DecryptVerifyResult.RESULT_PENDING_SYM_PASSPHRASE, log);
}
// break out of while, only decrypt the first packet
// TODO???: There could be more pgp objects, which are not decrypted!
break;
}
}
// More data, just acknowledge and ignore.
while (it.hasNext()) {
Object obj = it.next();
if (obj instanceof PGPPublicKeyEncryptedData) {
log.add(LogLevel.WARN, LogType.MSG_DC_TRAIL_ASYM, 0);
} else if (obj instanceof PGPPBEEncryptedData) {
log.add(LogLevel.WARN, LogType.MSG_DC_TRAIL_SYM, 0);
} else {
log.add(LogLevel.WARN, LogType.MSG_DC_TRAIL_UNKNOWN, 0);
}
}
log.add(LogLevel.DEBUG, LogType.MSG_DC_PREP_STREAMS, indent);
// we made sure above one of these two would be true
if (symmetricPacketFound) {
currentProgress += 2;
updateProgress(R.string.progress_preparing_streams, currentProgress, 100);
@ -358,18 +396,20 @@ public class PgpDecryptVerify {
mPassphrase.toCharArray());
clear = encryptedDataSymmetric.getDataStream(decryptorFactory);
encryptedData = encryptedDataSymmetric;
} else if (asymmetricPacketFound) {
currentProgress += 2;
updateProgress(R.string.progress_extracting_key, currentProgress, 100);
try {
log.add(LogLevel.WARN, LogType.MSG_DC_UNLOCKING, indent +1);
if (!secretEncryptionKey.unlock(mPassphrase)) {
// log.add(LogLevel.ERROR, LogType.MSG_DC_ERROR_BAD_PASSPHRASE);
log.add(LogLevel.ERROR, LogType.MSG_DC_ERROR_BAD_PASSPHRASE, indent +1);
return new DecryptVerifyResult(DecryptVerifyResult.RESULT_ERROR, log);
}
} catch (PgpGeneralException e) {
// log.add(LogLevel.ERROR, LogType.MSG_DC_ERROR_EXTRACT_KEY);
log.add(LogLevel.ERROR, LogType.MSG_DC_ERROR_EXTRACT_KEY, indent +1);
return new DecryptVerifyResult(DecryptVerifyResult.RESULT_ERROR, log);
}
@ -381,8 +421,7 @@ public class PgpDecryptVerify {
= secretEncryptionKey.getDecryptorFactory(mDecryptedSessionKey);
clear = encryptedDataAsymmetric.getDataStream(decryptorFactory);
} catch (NfcSyncPublicKeyDataDecryptorFactoryBuilder.NfcInteractionNeeded e) {
// log.add(LogLevel.ERROR, LogType.MSG_DC_ERROR_NFC_INTERACTION);
log.add(LogLevel.INFO, LogType.MSG_DC_PENDING_NFC, indent +1);
DecryptVerifyResult result =
new DecryptVerifyResult(DecryptVerifyResult.RESULT_PENDING_NFC, log);
result.setNfcEncryptedSessionKey(e.encryptedSessionKey);
@ -391,8 +430,10 @@ public class PgpDecryptVerify {
}
encryptedData = encryptedDataAsymmetric;
} else {
// If we didn't find any useful data, error out
// no packet has been found where we have the corresponding secret key in our db
// log.add(LogLevel.ERROR, LogType.MSG_DC_MISSING_SECRET_KEY);
log.add(LogLevel.ERROR,
anyPacketFound ? LogType.MSG_DC_ERROR_NO_KEY : LogType.MSG_DC_ERROR_NO_DATA, indent +1);
return new DecryptVerifyResult(DecryptVerifyResult.RESULT_ERROR, log);
}
@ -403,7 +444,11 @@ public class PgpDecryptVerify {
CanonicalizedPublicKeyRing signingRing = null;
CanonicalizedPublicKey signingKey = null;
log.add(LogLevel.DEBUG, LogType.MSG_DC_CLEAR, indent);
indent += 1;
if (dataChunk instanceof PGPCompressedData) {
log.add(LogLevel.DEBUG, LogType.MSG_DC_CLEAR_DECOMPRESS, indent +1);
currentProgress += 2;
updateProgress(R.string.progress_decompressing_data, currentProgress, 100);
@ -416,6 +461,7 @@ public class PgpDecryptVerify {
PGPOnePassSignature signature = null;
if (dataChunk instanceof PGPOnePassSignatureList) {
log.add(LogLevel.DEBUG, LogType.MSG_DC_CLEAR_SIGNATURE, indent +1);
currentProgress += 2;
updateProgress(R.string.progress_processing_signature, currentProgress, 100);
@ -466,6 +512,8 @@ public class PgpDecryptVerify {
OpenPgpMetadata metadata;
if (dataChunk instanceof PGPLiteralData) {
log.add(LogLevel.DEBUG, LogType.MSG_DC_CLEAR_DATA, indent +1);
indent += 2;
currentProgress += 4;
updateProgress(R.string.progress_decrypting, currentProgress, 100);
@ -506,8 +554,14 @@ public class PgpDecryptVerify {
literalData.getModificationTime().getTime(),
originalSize);
log.add(LogLevel.DEBUG, LogType.MSG_DC_CLEAR_META_FILE, indent +1);
log.add(LogLevel.DEBUG, LogType.MSG_DC_CLEAR_META_MIME, indent +1);
log.add(LogLevel.DEBUG, LogType.MSG_DC_CLEAR_META_TIME, indent +1);
log.add(LogLevel.DEBUG, LogType.MSG_DC_CLEAR_META_SIZE, indent +1);
// return here if we want to decrypt the metadata only
if (mDecryptMetadataOnly) {
log.add(LogLevel.OK, LogType.MSG_DC_OK_META_ONLY, indent);
DecryptVerifyResult result =
new DecryptVerifyResult(DecryptVerifyResult.RESULT_OK, log);
result.setDecryptMetadata(metadata);
@ -554,6 +608,7 @@ public class PgpDecryptVerify {
if (signature != null) {
updateProgress(R.string.progress_verifying_signature, 90, 100);
log.add(LogLevel.DEBUG, LogType.MSG_DC_CLEAR_SIGNATURE_CHECK, indent);
PGPSignatureList signatureList = (PGPSignatureList) plainFact.nextObject();
PGPSignature messageSignature = signatureList.get(signatureIndex);
@ -564,8 +619,15 @@ public class PgpDecryptVerify {
// Verify signature and check binding signatures
boolean validSignature = signature.verify(messageSignature);
if (validSignature) {
log.add(LogLevel.DEBUG, LogType.MSG_DC_CLEAR_SIGNATURE_OK, indent +1);
} else {
log.add(LogLevel.WARN, LogType.MSG_DC_CLEAR_SIGNATURE_BAD, indent +1);
}
signatureResultBuilder.setValidSignature(validSignature);
}
indent -= 1;
} else {
// If there is no literalData, we don't have any metadata
metadata = null;
@ -575,9 +637,9 @@ public class PgpDecryptVerify {
updateProgress(R.string.progress_verifying_integrity, 95, 100);
if (encryptedData.verify()) {
// log.add(LogLevel.INFO, LogType.MSG_DC_INTEGRITY_CHECK_OK)
log.add(LogLevel.INFO, LogType.MSG_DC_INTEGRITY_CHECK_OK, indent);
} else {
// log.add(LogLevel.ERROR, LogType.MSG_DC_ERROR_INTEGRITY_CHECK)
log.add(LogLevel.ERROR, LogType.MSG_DC_ERROR_INTEGRITY_CHECK, indent);
return new DecryptVerifyResult(DecryptVerifyResult.RESULT_ERROR, log);
}
} else {
@ -588,13 +650,15 @@ public class PgpDecryptVerify {
// Handle missing integrity protection like failed integrity protection!
// The MDC packet can be stripped by an attacker!
if (!signatureResultBuilder.isValidSignature()) {
// log.add(LogLevel.ERROR, LogType.MSG_DC_ERROR_INTEGRITY_CHECK)
log.add(LogLevel.ERROR, LogType.MSG_DC_ERROR_INTEGRITY_CHECK, indent);
return new DecryptVerifyResult(DecryptVerifyResult.RESULT_ERROR, log);
}
}
updateProgress(R.string.progress_done, 100, 100);
log.add(LogLevel.OK, LogType.MSG_DC_OK, indent);
// Return a positive result, with metadata and verification info
DecryptVerifyResult result =
new DecryptVerifyResult(DecryptVerifyResult.RESULT_OK, log);
@ -649,7 +713,7 @@ public class PgpDecryptVerify {
PGPSignatureList sigList = (PGPSignatureList) pgpFact.nextObject();
if (sigList == null) {
// log.add(LogLevel.ERROR, LogType.MSG_DC_ERROR_INVALID_DATA)
log.add(LogLevel.ERROR, LogType.MSG_DC_ERROR_INVALID_SIGLIST, 0);
return new DecryptVerifyResult(DecryptVerifyResult.RESULT_ERROR, log);
}

View File

@ -435,6 +435,44 @@ public class OperationResultParcel implements Parcelable {
MSG_EK_ERROR_DUMMY (R.string.msg_ek_error_dummy),
MSG_EK_ERROR_NOT_FOUND (R.string.msg_ek_error_not_found),
// decryptverify
MSG_DC_ASKIP_NO_KEY (R.string.msg_dc_askip_no_key),
MSG_DC_ASKIP_NOT_ALLOWED (R.string.msg_dc_askip_not_allowed),
MSG_DC_ASYM (R.string.msg_dc_asym),
MSG_DC_CLEAR_DATA (R.string.msg_dc_clear_data),
MSG_DC_CLEAR_DECOMPRESS (R.string.msg_dc_clear_decompress),
MSG_DC_CLEAR_META_FILE (R.string.msg_dc_clear_meta_file),
MSG_DC_CLEAR_META_MIME (R.string.msg_dc_clear_meta_mime),
MSG_DC_CLEAR_META_SIZE (R.string.msg_dc_clear_meta_size),
MSG_DC_CLEAR_META_TIME (R.string.msg_dc_clear_meta_time),
MSG_DC_CLEAR (R.string.msg_dc_clear),
MSG_DC_CLEAR_SIGNATURE_BAD (R.string.msg_dc_clear_signature_bad),
MSG_DC_CLEAR_SIGNATURE_CHECK (R.string.msg_dc_clear_signature_check),
MSG_DC_CLEAR_SIGNATURE_OK (R.string.msg_dc_clear_signature_ok),
MSG_DC_CLEAR_SIGNATURE (R.string.msg_dc_clear_signature),
MSG_DC_ERROR_BAD_PASSPHRASE (R.string.msg_dc_error_bad_passphrase),
MSG_DC_ERROR_EXTRACT_KEY (R.string.msg_dc_error_extract_key),
MSG_DC_ERROR_INTEGRITY_CHECK (R.string.msg_dc_error_integrity_check),
MSG_DC_ERROR_INVALID_SIGLIST(R.string.msg_dc_error_invalid_siglist),
MSG_DC_ERROR_IO (R.string.msg_dc_error_io),
MSG_DC_ERROR_NO_DATA (R.string.msg_dc_error_no_data),
MSG_DC_ERROR_NO_KEY (R.string.msg_dc_error_no_key),
MSG_DC_ERROR_PGP_EXCEPTION (R.string.msg_dc_error_pgp_exception),
MSG_DC_INTEGRITY_CHECK_OK (R.string.msg_dc_integrity_check_ok),
MSG_DC_OK_META_ONLY (R.string.msg_dc_ok_meta_only),
MSG_DC_OK (R.string.msg_dc_ok),
MSG_DC_PASS_CACHED (R.string.msg_dc_pass_cached),
MSG_DC_PENDING_NFC (R.string.msg_dc_pending_nfc),
MSG_DC_PENDING_PASSPHRASE (R.string.msg_dc_pending_passphrase),
MSG_DC_PREP_STREAMS (R.string.msg_dc_prep_streams),
MSG_DC (R.string.msg_dc),
MSG_DC_SYM (R.string.msg_dc_sym),
MSG_DC_SYM_SKIP (R.string.msg_dc_sym_skip),
MSG_DC_TRAIL_ASYM (R.string.msg_dc_trail_asym),
MSG_DC_TRAIL_SYM (R.string.msg_dc_trail_sym),
MSG_DC_TRAIL_UNKNOWN (R.string.msg_dc_trail_unknown),
MSG_DC_UNLOCKING (R.string.msg_dc_unlocking),
;
private final int mMsgId;

View File

@ -156,7 +156,7 @@ public class DecryptMessageFragment extends DecryptFragment {
return;
}
// error, we can't work with this!
result.createNotify(getActivity());
result.createNotify(getActivity()).show();
return;
}
@ -165,7 +165,7 @@ public class DecryptMessageFragment extends DecryptFragment {
mMessage.setText(new String(decryptedMessage));
mMessage.setHorizontallyScrolling(false);
result.createNotify(getActivity());
result.createNotify(getActivity()).show();
// display signature result in activity
onResult(result);

View File

@ -764,6 +764,44 @@
<string name="msg_ek_error_dummy">"Cannot edit keyring with stripped master key!"</string>
<string name="msg_ek_error_not_found">"Key not found!"</string>
<!-- Messages for DecryptVerify operation -->
<string name="msg_dc_askip_no_key">"Data not encrypted with known key, skipping…"</string>
<string name="msg_dc_askip_not_allowed">"Data not encrypted with allowed key, skipping…"</string>
<string name="msg_dc_asym">"Found block of asymmetrically encrypted data"</string>
<string name="msg_dc_clear_data">"Processing literal data"</string>
<string name="msg_dc_clear_decompress">"Unpacking compressed data"</string>
<string name="msg_dc_clear_meta_file">"Filesize: %s"</string>
<string name="msg_dc_clear_meta_mime">"MIME type: %s"</string>
<string name="msg_dc_clear_meta_size">"Filesize: %s"</string>
<string name="msg_dc_clear_meta_time">"Modification time: %s"</string>
<string name="msg_dc_clear_signature_bad">"Signature check NOT OK!"</string>
<string name="msg_dc_clear_signature_check">"Verifying signature data"</string>
<string name="msg_dc_clear_signature_ok">"Signature check OK"</string>
<string name="msg_dc_clear_signature">"Saving signature data for later"</string>
<string name="msg_dc_clear">"Processing cleartext data"</string>
<string name="msg_dc_error_bad_passphrase">"Error unlocking key, bad passphrase!"</string>
<string name="msg_dc_error_extract_key">"Unknown error unlocking key!"</string>
<string name="msg_dc_error_integrity_check">"Integrity check error!"</string>
<string name="msg_dc_error_invalid_siglist">"No valid signature data found!"</string>
<string name="msg_dc_error_io">"Encountered IO Exception during operation!"</string>
<string name="msg_dc_error_no_data">"No encrypted data found in stream!"</string>
<string name="msg_dc_error_no_key">"No encrypted data with known secret key found in stream!"</string>
<string name="msg_dc_error_pgp_exception">"Encountered PGP Exception during operation!"</string>
<string name="msg_dc_integrity_check_ok">"Integrity check ok!"</string>
<string name="msg_dc_ok_meta_only">"Only metadata was requested, skipping decryption"</string>
<string name="msg_dc_ok">"OK"</string>
<string name="msg_dc_pass_cached">"Using passphrase from cache"</string>
<string name="msg_dc_pending_nfc">"NFC token required, requesting user input…"</string>
<string name="msg_dc_pending_passphrase">"Passphrase required, requesting user input…"</string>
<string name="msg_dc_prep_streams">"Preparing streams for decryption"</string>
<string name="msg_dc">"Starting decrypt operation…"</string>
<string name="msg_dc_sym_skip">"Symmetric data not allowed, skipping…"</string>
<string name="msg_dc_sym">"Found block of symmetrically encrypted data"</string>
<string name="msg_dc_trail_asym">"Encountered trailing, asymmetrically encrypted data"</string>
<string name="msg_dc_trail_sym">"Encountered trailing, symmetrically encrypted data"</string>
<string name="msg_dc_trail_unknown">"Encountered trailing data of unknown type"</string>
<string name="msg_dc_unlocking">"Unlocking secret key"</string>
<!-- PassphraseCache -->
<string name="passp_cache_notif_click_to_clear">"Click to clear cached passphrases"</string>
<string name="passp_cache_notif_n_keys">"OpenKeychain has cached %d passphrases"</string>