maandag 23 juni 2014

Logging and Proguard

When you develop an Android app, you tend - I hope - to add (debug) logging information in your code. Unfortunately, forgotten debug logging, is more than often a source of data leaks.

Proguard, which we discussed in this post, will give you the opportunity to strip these logging statements from your compiled code. "Cool!" (you'll undoubtably utter these words while dancing around your desk, praising the Java Gods).

Well, sort of "Cool!". If you use logging correctly many of your basic logging statements will be stripped from the compiled code. But Proguard has a downside, that it doesn't know what to do with String manipulations.

Imagine that we start with this example:

    private final static String TAG = MainActivity.class.getSimpleName();

    @Override
    protected void onCreate(Bundle savedInstanceState) {
        super.onCreate(savedInstanceState);
        setContentView(R.layout.activity_main);

        ButterKnife.inject(this);

        //you can start working with the annotated widgets after you injected them

        Log.d(TAG, "Log1 - onCreate completed");
        Logger.d(TAG, "Log2 - onCreate completed");

        Log.d(TAG, "Log3 - onCreate was called from class " + TAG);
        Logger.d(TAG, "Log4 - onCreate was called from class %s", TAG);
    }

You all know the "Log.x" statements (verbose, debug, info, warn, error and wtf) from the android.util.Log class. The "Logger.x" class is a custom class, call it a wrapper for the (in)famous android.util.Log class.

The result of the debugging statements might look like this:

MainActivity - Log1 - onCreate completed
MainActivity - Log2 - onCreate completed
MainActivity - Log3 - onCreate was called from class MainActivity
MainActivity - Log4 - onCreate was called from class MainActivity

If you would like to strip the logging statements from the compiled classes, you might have added these rules to the Proguard script:

...
# remove logging
-assumenosideeffects class android.util.Log {
    *;
}
...

We now extend the rules taking into account the Logging wrapper class (from the be.acuzio.mrta package) when compiling the classes:

...
# remove logging wrapper
-assumenosideeffects class be.acuzio.mrta.util.Logger {
    *;
}
...

What you'll end up with, is this compiled class (if you decompile it):
  
  protected void onCreate(Bundle paramBundle)
  {
    super.onCreate(paramBundle);
    setContentView(2130903064);
    ButterKnife.inject(this);
    new StringBuilder("Log3 - onCreate was called from class ").append(a);
    new java.lang.Object[1][0] = a;
  }

What you'll notice is that all the "trivial" logging statements are removed without any problem from your code:

...
        Log.d(TAG, "Log1 - onCreate completed");
        Logger.d(TAG, "Log2 - onCreate completed");
...

The problem arises with the logging statements that manipulate Strings:

...
        Log.d(TAG, "Log3 - onCreate was called from class " + TAG);
        Logger.d(TAG, "Log4 - onCreate was called from class %s", TAG);
...

As you can see, the Log.d statement has been removed, but the actual String is still readable in the decompiled code. This can still be considered as a data leak or security issue as it is now quite easy to figure out what the content the variable ("a" in the decompiled code) is meant to be (it's the name of the class, if you got a bit lost by now).

So what's so special about our custom Logger class? Let's have a look:

package be.acuzio.mrta.util;

import android.util.Log;

public final class Logger {
    /**
     * A wrapper for the Log.d function
     * * e.g. 
     * Logger.d(TAG, "Batman goes like %d, %d, %d, \"%s\"", 1, 2, 3, "Pow!");
     * //prints: Batman goes like 1, 2, 3, "Pow!"
     * Logger.d(TAG, "Holy Cows Batman!");
     * //prints: Holy Cows Batman!
     * 
     *
     * @param tag     The tag used in the logcat
     * @param message The message, which can be formatted according to String.format
     * @param args    The arguments, optional
     */
    public static void d(String tag, String message, Object... args) {
        Log.d(tag, String.format(message, args));
    }

    /**
     * A wrapper for the Log.i function
     * 
* e.g. * Logger.i(TAG, "Batman goes like %d, %d, %d, \"%s\"", 1, 2, 3, "Pow!"); * //prints: Batman goes like 1, 2, 3, "Pow!" * Logger.i(TAG, "Holy Cows Batman!"); * //prints: Holy Cows Batman! * * * @param tag The tag used in the logcat * @param message The message, which can be formatted according to String.format * @param args The arguments, optional */ public static void i(String tag, String message, Object... args) { Log.i(tag, String.format(message, args)); } /** * A wrapper for the Log.e function *
* e.g. * * try { * ... * throw new Exception("Holy Cow Batman!"); * } catch(Exception e) { * Logger.e("MyTag", e); * //prints: * // ... E/MyTag﹕ Holy Cows Batman! * // java.lang.Exception: Holy Cows Batman! * // at ... * // at ... * } * * * @param tag The tag used in the logcat * @param e The exception */ public static void e(String tag, Exception e) { Log.e(tag, e.getMessage(), e); } public static void e(String tag, String message, Exception e) { Log.e(tag, message, e); } }

Because we offer a fixed structure to Proguard, it finds it much easier to strip the logging statements from the compiled code. We just end up with this:

    ...
    new java.lang.Object[1][0] = a;
    ...

Instead of this:

    ...
    new StringBuilder("Log3 - onCreate was called from class ").append(a);
    ...

So that's already much better! Purist will say that it still indicates that you want to do something there. True. But that you can easily fix. We defined this function in our Logger class, which takes an array of Objects as final argument:
    public static void d(String tag, String message, Object... args) {
        ...
    }

If you don't want to use the array, just define a method per variable, like:

    public static void d(String tag, String message, Object arg1);
    public static void d(String tag, String message, Object arg1, Object arg2);
    public static void d(String tag, String message, Object arg1, Object arg2, Object arg3);    
    ... //you catch my drift

In the latter case you will remove all the logging statements that were defined by the rules in the Proguard file. Why? Because you always provide a fixed structure for printing information.

Hope this helps in improving your code, if you have any suggestions, please feel free to post them! The code is also available on GitHub.





Geen opmerkingen:

Een reactie posten