mime: add logging to InputDataOperation

4 files changed, 104 insertions, 52 deletions

diff --git a/OpenKeychain/src/main/java/org/sufficientlysecure/keychain/operations/InputDataOperation.java b/OpenKeychain/src/main/java/org/sufficientlysecure/keychain/operations/InputDataOperation.java
index 030c0a285..cb26080e8 100644
--- a/OpenKeychain/src/main/java/org/sufficientlysecure/keychain/operations/InputDataOperation.java
+++ b/OpenKeychain/src/main/java/org/sufficientlysecure/keychain/operations/InputDataOperation.java
@@ -30,7 +30,6 @@ import android.support.annotation.NonNull;
 
 import org.apache.james.mime4j.MimeException;
 import org.apache.james.mime4j.codec.DecodeMonitor;
-import org.apache.james.mime4j.dom.FieldParser;
 import org.apache.james.mime4j.dom.field.ContentDispositionField;
 import org.apache.james.mime4j.field.DefaultFieldParser;
 import org.apache.james.mime4j.parser.AbstractContentHandler;
@@ -38,7 +37,6 @@ import org.apache.james.mime4j.parser.MimeStreamParser;
 import org.apache.james.mime4j.stream.BodyDescriptor;
 import org.apache.james.mime4j.stream.Field;
 import org.apache.james.mime4j.stream.MimeConfig;
-import org.sufficientlysecure.keychain.Constants;
 import org.sufficientlysecure.keychain.operations.results.DecryptVerifyResult;
 import org.sufficientlysecure.keychain.operations.results.InputDataResult;
 import org.sufficientlysecure.keychain.operations.results.OperationResult.LogType;
@@ -50,7 +48,6 @@ import org.sufficientlysecure.keychain.provider.ProviderHelper;
 import org.sufficientlysecure.keychain.provider.TemporaryStorageProvider;
 import org.sufficientlysecure.keychain.service.InputDataParcel;
 import org.sufficientlysecure.keychain.service.input.CryptoInputParcel;
-import org.sufficientlysecure.keychain.util.Log;
 
 
 /** This operation deals with input data, trying to determine its type as it goes. */
@@ -69,13 +66,15 @@ public class InputDataOperation extends BaseOperation<InputDataParcel> {
 
         final OperationLog log = new OperationLog();
 
-        log.add(LogType.MSG_MIME_PARSING, 0);
+        log.add(LogType.MSG_DATA, 0);
 
         Uri currentUri;
 
         PgpDecryptVerifyInputParcel decryptInput = input.getDecryptInput();
         if (decryptInput != null) {
 
+            log.add(LogType.MSG_DATA_DECRYPT, 1);
+
             PgpDecryptVerifyOperation op =
                     new PgpDecryptVerifyOperation(mContext, mProviderHelper, mProgressable);
 
@@ -88,6 +87,7 @@ public class InputDataOperation extends BaseOperation<InputDataParcel> {
             if (result.isPending()) {
                 return new InputDataResult(log, result);
             }
+            log.addByMerge(result, 2);
 
         } else {
             currentUri = input.getInputUri();
@@ -96,76 +96,96 @@ public class InputDataOperation extends BaseOperation<InputDataParcel> {
         // If we aren't supposed to attempt mime decode, we are done here
         if (!input.getMimeDecode()) {
 
+            if (decryptInput == null) {
+                throw new AssertionError("no decryption or mime decoding, this is probably a bug");
+            }
+
+            log.add(LogType.MSG_DATA_SKIP_MIME, 1);
+
             ArrayList<Uri> uris = new ArrayList<>();
             uris.add(currentUri);
+
+            log.add(LogType.MSG_DATA_OK, 1);
             return new InputDataResult(InputDataResult.RESULT_OK, log, uris);
 
         }
 
+        log.add(LogType.MSG_DATA_MIME, 1);
+
+        InputStream in;
         try {
-            InputStream in = mContext.getContentResolver().openInputStream(currentUri);
+            in = mContext.getContentResolver().openInputStream(currentUri);
+        } catch (FileNotFoundException e) {
+            log.add(LogType.MSG_DATA_ERROR_IO, 2);
+            return new InputDataResult(InputDataResult.RESULT_ERROR, log, null);
+        }
+        MimeStreamParser parser = new MimeStreamParser((MimeConfig) null);
 
-            MimeStreamParser parser = new MimeStreamParser((MimeConfig) null);
+        final ArrayList<Uri> outputUris = new ArrayList<>();
 
-            final ArrayList<Uri> outputUris = new ArrayList<>();
+        parser.setContentDecoding(true);
+        parser.setRecurse();
+        parser.setContentHandler(new AbstractContentHandler() {
+            String mFilename;
 
-            parser.setContentDecoding(true);
-            parser.setRecurse();
-            parser.setContentHandler(new AbstractContentHandler() {
-                String mFilename;
+            @Override
+            public void startHeader() throws MimeException {
+                mFilename = null;
+            }
 
-                @Override
-                public void startHeader() throws MimeException {
-                    mFilename = null;
+            @Override
+            public void field(Field field) throws MimeException {
+                field = DefaultFieldParser.getParser().parse(field, DecodeMonitor.SILENT);
+                if (field instanceof ContentDispositionField) {
+                    mFilename = ((ContentDispositionField) field).getFilename();
                 }
+            }
 
-                @Override
-                public void field(Field field) throws MimeException {
-                    field = DefaultFieldParser.getParser().parse(field, DecodeMonitor.SILENT);
-                    if (field instanceof ContentDispositionField) {
-                        mFilename = ((ContentDispositionField) field).getFilename();
-                    }
-                }
+            @Override
+            public void body(BodyDescriptor bd, InputStream is) throws MimeException, IOException {
+
+                log.add(LogType.MSG_DATA_MIME_PART, 2);
 
-                @Override
-                public void body(BodyDescriptor bd, InputStream is) throws MimeException, IOException {
+                log.add(LogType.MSG_DATA_MIME_TYPE, 3, bd.getMimeType());
+                if (mFilename != null) {
+                    log.add(LogType.MSG_DATA_MIME_FILENAME, 3, mFilename);
+                }
+                log.add(LogType.MSG_DATA_MIME_LENGTH, 3, bd.getContentLength());
 
-                    // log.add(LogType.MSG_MIME_PART, 0, bd.getMimeType());
+                Uri uri = TemporaryStorageProvider.createFile(mContext, mFilename, bd.getMimeType());
+                OutputStream out = mContext.getContentResolver().openOutputStream(uri, "w");
 
-                    Uri uri = TemporaryStorageProvider.createFile(mContext, mFilename, bd.getMimeType());
-                    OutputStream out = mContext.getContentResolver().openOutputStream(uri, "w");
+                if (out == null) {
+                    throw new IOException("Error getting file for writing!");
+                }
 
-                    if (out == null) {
-                        Log.e(Constants.TAG, "error!");
-                        return;
-                    }
+                int len;
+                while ((len = is.read(buf)) > 0) {
+                    out.write(buf, 0, len);
+                }
 
-                    int len;
-                    while ( (len = is.read(buf)) > 0) {
-                        out.write(buf, 0, len);
-                    }
+                out.close();
+                outputUris.add(uri);
 
-                    out.close();
-                    outputUris.add(uri);
+            }
+        });
 
-                }
-            });
+        try {
 
             parser.parse(in);
+            log.add(LogType.MSG_DATA_MIME_OK, 2);
 
-            log.add(LogType.MSG_MIME_PARSING_SUCCESS, 1);
-
+            log.add(LogType.MSG_DATA_OK, 1);
             return new InputDataResult(InputDataResult.RESULT_OK, log, outputUris);
 
-        } catch (FileNotFoundException e) {
+        } catch (IOException e) {
             e.printStackTrace();
+            log.add(LogType.MSG_DATA_MIME_ERROR, 2);
             return new InputDataResult(InputDataResult.RESULT_ERROR, log, null);
         } catch (MimeException e) {
             e.printStackTrace();
-            return new InputDataResult(InputDataResult.RESULT_ERROR, log, null);
-        } catch (IOException e) {
-            e.printStackTrace();
-            return new InputDataResult(InputDataResult.RESULT_ERROR, log, null);
+            log.add(LogType.MSG_DATA_MIME_ERROR, 2);
+            return new InputDataResult(InputDataResult.RESULT_ERROR, log, outputUris);
         }
 
     }
diff --git a/OpenKeychain/src/main/java/org/sufficientlysecure/keychain/operations/results/OperationResult.java b/OpenKeychain/src/main/java/org/sufficientlysecure/keychain/operations/results/OperationResult.java
index 3856209b3..69e7d3d2d 100644
--- a/OpenKeychain/src/main/java/org/sufficientlysecure/keychain/operations/results/OperationResult.java
+++ b/OpenKeychain/src/main/java/org/sufficientlysecure/keychain/operations/results/OperationResult.java
@@ -126,6 +126,13 @@ public abstract class OperationResult implements Parcelable {
             Log.v(Constants.TAG, "log: " + this);
         }
 
+        /** Clones this LogEntryParcel, adding extra indent. Note that the parameter array is NOT cloned! */
+        public LogEntryParcel (LogEntryParcel original, int extraIndent) {
+            mType = original.mType;
+            mParameters = original.mParameters;
+            mIndent = original.mIndent +extraIndent;
+        }
+
         public LogEntryParcel(Parcel source) {
             mType = LogType.values()[source.readInt()];
             mParameters = (Object[]) source.readSerializable();
@@ -818,10 +825,19 @@ public abstract class OperationResult implements Parcelable {
         MSG_KEYBASE_ERROR_PAYLOAD_MISMATCH(LogLevel.ERROR,
                 R.string.msg_keybase_error_msg_payload_mismatch),
 
-        // mime parsing
-        MSG_MIME_PARSING(LogLevel.START,R.string.msg_mime_parsing_start),
-        MSG_MIME_PARSING_ERROR(LogLevel.ERROR,R.string.msg_mime_parsing_error),
-        MSG_MIME_PARSING_SUCCESS(LogLevel.OK,R.string.msg_mime_parsing_success),
+        // InputData Operation
+        MSG_DATA (LogLevel.START, R.string.msg_data),
+        MSG_DATA_DECRYPT (LogLevel.DEBUG, R.string.msg_data_decrypt),
+        MSG_DATA_ERROR_IO (LogLevel.ERROR, R.string.msg_data_error_io),
+        MSG_DATA_MIME_ERROR (LogLevel.ERROR, R.string.msg_data_mime_error),
+        MSG_DATA_MIME_FILENAME (LogLevel.DEBUG, R.string.msg_data_mime_filename),
+        MSG_DATA_MIME_LENGTH (LogLevel.DEBUG, R.string.msg_data_mime_length),
+        MSG_DATA_MIME (LogLevel.DEBUG, R.string.msg_data_mime),
+        MSG_DATA_MIME_OK (LogLevel.INFO, R.string.msg_data_mime_ok),
+        MSG_DATA_MIME_PART (LogLevel.DEBUG, R.string.msg_data_mime_part),
+        MSG_DATA_MIME_TYPE (LogLevel.DEBUG, R.string.msg_data_mime_type),
+        MSG_DATA_OK (LogLevel.OK, R.string.msg_data_ok),
+        MSG_DATA_SKIP_MIME (LogLevel.DEBUG, R.string.msg_data_skip_mime),
 
         MSG_LV (LogLevel.START, R.string.msg_lv),
         MSG_LV_MATCH (LogLevel.DEBUG, R.string.msg_lv_match),
@@ -901,6 +917,13 @@ public abstract class OperationResult implements Parcelable {
             mParcels.add(new SubLogEntryParcel(subResult, subLog.getFirst().mType, indent, subLog.getFirst().mParameters));
         }
 
+        public void addByMerge(OperationResult subResult, int indent) {
+            OperationLog subLog = subResult.getLog();
+            for (LogEntryParcel entry : subLog) {
+                mParcels.add(new LogEntryParcel(entry, indent));
+            }
+        }
+
         public SubLogEntryParcel getSubResultIfSingle() {
             if (mParcels.size() != 1) {
                 return null;
diff --git a/OpenKeychain/src/main/res/values/strings.xml b/OpenKeychain/src/main/res/values/strings.xml
index 56bb95f3f..a1e21e661 100644
--- a/OpenKeychain/src/main/res/values/strings.xml
+++ b/OpenKeychain/src/main/res/values/strings.xml
@@ -1355,6 +1355,18 @@
     <string name="msg_lv_fetch_error_format">"Format error!"</string>
     <string name="msg_lv_fetch_error_nothing">"Resource not found!"</string>
 
+    <string name="msg_data">""</string>
+    <string name="msg_data_decrypt">""</string>
+    <string name="msg_data_error_io">""</string>
+    <string name="msg_data_mime_error">""</string>
+    <string name="msg_data_mime_filename">""</string>
+    <string name="msg_data_mime_length">""</string>
+    <string name="msg_data_mime">""</string>
+    <string name="msg_data_mime_ok">""</string>
+    <string name="msg_data_mime_part">""</string>
+    <string name="msg_data_mime_type">""</string>
+    <string name="msg_data_ok">""</string>
+    <string name="msg_data_skip_mime">""</string>
 
     <string name="msg_acc_saved">"Account saved"</string>
 
diff --git a/OpenKeychain/src/test/java/org/sufficientlysecure/keychain/pgp/InputDataOperationTest.java b/OpenKeychain/src/test/java/org/sufficientlysecure/keychain/pgp/InputDataOperationTest.java
index 71673bdb7..59b52ea85 100644
--- a/OpenKeychain/src/test/java/org/sufficientlysecure/keychain/pgp/InputDataOperationTest.java
+++ b/OpenKeychain/src/test/java/org/sufficientlysecure/keychain/pgp/InputDataOperationTest.java
@@ -37,8 +37,6 @@ import org.junit.runner.RunWith;
 import org.robolectric.RobolectricGradleTestRunner;
 import org.robolectric.RuntimeEnvironment;
 import org.robolectric.annotation.Config;
-import org.robolectric.shadows.ShadowContentProvider;
-import org.robolectric.shadows.ShadowContentResolver;
 import org.robolectric.shadows.ShadowLog;
 import org.spongycastle.jce.provider.BouncyCastleProvider;
 import org.sufficientlysecure.keychain.WorkaroundBuildConfig;
@@ -50,7 +48,6 @@ import org.sufficientlysecure.keychain.service.InputDataParcel;
 import org.sufficientlysecure.keychain.service.input.CryptoInputParcel;
 
 import static org.mockito.Mockito.any;
-import static org.mockito.Mockito.atLeast;
 import static org.mockito.Mockito.eq;
 import static org.mockito.Mockito.mock;
 import static org.mockito.Mockito.spy;