android – Logging best practices and thoughts-ThrowExceptions

Exception or error:

I’m about to do some refactoring off my app and I came to think about this simple yet complex topic, logging, how can it be so hard to do clean, effective and informative logging…

When you read documentation on logging you often see this snippet

if (BuildConfig.DEBUG) {
    Log.d(TAG + "message");
}

and it makes me wonder what the purpose is with it? According to the documentation, Android Developer – Log, the debug log messages are compiled in but stripped at runtime, so you wouldn’t need to have the log call within that if statement. Or am I missunderstanding anything?

Then I’m also kind of wondering what the real benefit is with using any other Log.x() calls except debug as the log entries will not be seen by the user or logged into some errorfile, so they will be compiled in and executed in the production environment for no purpose at all? This is maybe a use case for the if statement before?

I mentioned earlier that the log entry isn’t logged into a file. Why isn’t this a built in feature in Android? Is it because of performance issues, unnecessary permission usage or something else? I have implemented this functionality in my own logging class, but now I wonder if it’s bad practice? But it’s also nice to have logs with important log entries?

So to wrap it up, to implement clean, effective and informative logging, both during development and in production. What’s the best practices?

How to solve:

Logs only needed to debug applications during development, to ensure that the feature works as expected and produces desired results. The best practice is, I believe, to do logging in any way which is most convenient to you and allows to find and resolve issues as quickly and efficiently as possible

I mentioned earlier that the log entry isn’t logged into a file. Why
isn’t this a built in feature in Android?

Who (except a programmer on the development stage) would want an application to waste limited storage space on one’s device with useless data? Users don’t see, don’t read, don’t use logs. They don’t need this garbage. Application in production must not produce any logs and, of course, must not save them to files.

The only logging which should be implemented in released application is unhandled exceptions logging. Moreover, it’s application’s responsibility to handle these logs if it suggests sending crash reports, and removing them after the report has been sent.

Another reason logs should not be created by released apps is that they may contain sensitive data and output which requires user authorization, thus introducing security flaws.

I believe the best practice is to remove all logs as soon as the module or feature is fully implemented and thoroughly tested, before deployment to production. Introducing if (BuildConfig.DEBUG) condition helps to ensure this has been achieved.

###

This will generate clean debug tags with this format ClasssName[MethodName] - LineNumber with reflection.

Complete code with inline comments is available as a gist here.

import android.util.Log;

public class Logger {

    public enum LOGGER_DEPTH {
        ACTUAL_METHOD(4),
        LOGGER_METHOD(3),
        STACK_TRACE_METHOD(1),
        JVM_METHOD(0);

        private final int value;

        private LOGGER_DEPTH(final int newValue) {
            value = newValue;
        }

        public int getValue() {
            return value;
        }
    }

    private static final String personalTAG = "Logger";

    private StringBuilder sb;

    private Logger() {
        if (LoggerLoader.instance != null) {
            Log.e(personalTAG, "Error: Logger already instantiated");
            throw new IllegalStateException("Already Instantiated");
        } else {
            this.sb = new StringBuilder(255);
        }
    }

    public static Logger getLogger() {
        return LoggerLoader.instance;
    }

    private String getTag(LOGGER_DEPTH depth) {
        try {
            String className = Thread.currentThread().getStackTrace()[depth.getValue()].getClassName();
            sb.append(className.substring(className.lastIndexOf(".") + 1));
            sb.append("[");
            sb.append(Thread.currentThread().getStackTrace()[depth.getValue()].getMethodName());
            sb.append("] - ");
            sb.append(Thread.currentThread().getStackTrace()[depth.getValue()].getLineNumber());
            return sb.toString();
        } catch (Exception ex) {
            ex.printStackTrace();
            Log.d(personalTAG, ex.getMessage());
        } finally {
            sb.setLength(0);
        }
        return null;
    }

    public void d(String msg) {
        try {
            Log.d(getTag(LOGGER_DEPTH.ACTUAL_METHOD), msg);
        } catch (Exception exception) {
            Log.e(getTag(LOGGER_DEPTH.ACTUAL_METHOD), "Logger failed, exception: " + exception.getMessage());
        }
    }

    public void d(String msg, LOGGER_DEPTH depth) {
        try {
            Log.d(getTag(depth), msg);
        } catch (Exception exception) {
            Log.e(getTag(LOGGER_DEPTH.ACTUAL_METHOD), "Logger failed, exception: " + exception.getMessage());
        }
    }

    public void d(String msg, Throwable t, LOGGER_DEPTH depth) {
        try {
            Log.d(getTag(depth), msg, t);
        } catch (Exception exception) {
            Log.e(getTag(LOGGER_DEPTH.ACTUAL_METHOD), "Logger failed, exception: " + exception.getMessage());
        }
    }

    public void e(String msg) {
        try {
            Log.e(getTag(LOGGER_DEPTH.ACTUAL_METHOD), msg);
        } catch (Exception exception) {
            Log.e(getTag(LOGGER_DEPTH.ACTUAL_METHOD), "Logger failed, exception: " + exception.getMessage());
        }
    }

    public void e(String msg, LOGGER_DEPTH depth) {
        try {
            Log.e(getTag(depth), msg);
        } catch (Exception exception) {
            Log.e(getTag(LOGGER_DEPTH.ACTUAL_METHOD), "Logger failed, exception: " + exception.getMessage());
        }
    }

    public void e(String msg, Throwable t, LOGGER_DEPTH depth) {
        try {
            Log.e(getTag(depth), msg, t);
        } catch (Exception exception) {
            Log.e(getTag(LOGGER_DEPTH.ACTUAL_METHOD), "Logger failed, exception: " + exception.getMessage());
        }
    }

    public void w(String msg) {
        try {
            Log.w(getTag(LOGGER_DEPTH.ACTUAL_METHOD), msg);
        } catch (Exception exception) {
            Log.e(getTag(LOGGER_DEPTH.ACTUAL_METHOD), "Logger failed, exception: " + exception.getMessage());
        }
    }

    public void w(String msg, LOGGER_DEPTH depth) {
        try {
            Log.w(getTag(depth), msg);
        } catch (Exception exception) {
            Log.e(getTag(LOGGER_DEPTH.ACTUAL_METHOD), "Logger failed, exception: " + exception.getMessage());
        }
    }

    public void w(String msg, Throwable t, LOGGER_DEPTH depth) {
        try {
            Log.w(getTag(depth), msg, t);
        } catch (Exception exception) {
            Log.e(getTag(LOGGER_DEPTH.ACTUAL_METHOD), "Logger failed, exception: " + exception.getMessage());
        }
    }

    public void v(String msg) {
        try {
            Log.v(getTag(LOGGER_DEPTH.ACTUAL_METHOD), msg);
        } catch (Exception exception) {
            Log.e(getTag(LOGGER_DEPTH.ACTUAL_METHOD), "Logger failed, exception: " + exception.getMessage());
        }
    }

    public void v(String msg, LOGGER_DEPTH depth) {
        try {
            Log.v(getTag(depth), msg);
        } catch (Exception exception) {
            Log.e(getTag(LOGGER_DEPTH.ACTUAL_METHOD), "Logger failed, exception: " + exception.getMessage());
        }
    }

    public void v(String msg, Throwable t, LOGGER_DEPTH depth) {
        try {
            Log.v(getTag(depth), msg, t);
        } catch (Exception exception) {
            Log.e(getTag(LOGGER_DEPTH.ACTUAL_METHOD), "Logger failed, exception: " + exception.getMessage());
        }
    }

    public void i(String msg) {
        try {
            Log.i(getTag(LOGGER_DEPTH.ACTUAL_METHOD), msg);
        } catch (Exception exception) {
            Log.e(getTag(LOGGER_DEPTH.ACTUAL_METHOD), "Logger failed, exception: " + exception.getMessage());
        }
    }

    public void i(String msg, LOGGER_DEPTH depth) {
        try {
            Log.i(getTag(depth), msg);
        } catch (Exception exception) {
            Log.e(getTag(LOGGER_DEPTH.ACTUAL_METHOD), "Logger failed, exception: " + exception.getMessage());
        }
    }

    public void i(String msg, Throwable t, LOGGER_DEPTH depth) {
        try {
            Log.i(getTag(depth), msg, t);
        } catch (Exception exception) {
            Log.e(getTag(LOGGER_DEPTH.ACTUAL_METHOD), "Logger failed, exception: " + exception.getMessage());
        }
    }

    public void wtf(String msg) {
        try {
            Log.wtf(getTag(LOGGER_DEPTH.ACTUAL_METHOD), msg);
        } catch (Exception exception) {
            Log.e(getTag(LOGGER_DEPTH.ACTUAL_METHOD), "Logger failed, exception: " + exception.getMessage());
        }
    }

    public void wtf(String msg, LOGGER_DEPTH depth) {
        try {
            Log.wtf(getTag(depth), msg);
        } catch (Exception exception) {
            Log.e(getTag(LOGGER_DEPTH.ACTUAL_METHOD), "Logger failed, exception: " + exception.getMessage());
        }
    }

    public void wtf(String msg, Throwable t, LOGGER_DEPTH depth) {
        try {
            Log.wtf(getTag(depth), msg, t);
        } catch (Exception exception) {
            Log.e(getTag(LOGGER_DEPTH.ACTUAL_METHOD), "Logger failed, exception: " + exception.getMessage());
        }
    }

    private static class LoggerLoader {
        private static final Logger instance = new Logger();
    }
}

###

I’ve stumbled with that very same problem since I started working in Android and I have created this open source project(Android Studio Macros) that allows you to do what you want plus some more complicated things by using “//<#DEBUG_AREA> and //<#/DEBUG_AREA>” tags within your code, the basic idea is that anything within those tags will be commented when you change your build variants for example if you have something like this in a for loop:

       //=========This piece of code is only for logging purposes...=========
        Log.e("LogUserInfo", "Name: " + name);
        Log.e("LogUserInfo", "Id: " + user.getId());
        Log.e("LogUserInfo", "Id: " + user.getDistance());
        //====================================================================

In stead of doing this:

if(DEBUG){
      Log.e("LogginUserInfo", "Name: " + name);
      Log.e("LogginUserInfo", "Id: " + user.getId());
      Log.e("LogginUserInfo", "Id: " + user.getDistance());
 }

With this macro you can do this(full method):

private List<String> getNamesOfUsersNearMe(String zipCode){
    List<User> users = mBusinessLogic.getUsersByZipcode(zipCode);
    if(users == null || users.size() < 1){
        return null;
    }

    List<String> names = new ArrayList<String>();
    int totalUsers = users.size();
    for(int i = 0; i < totalUsers; i++){
        User user = users.get(i);
        String name = user.getName();
        names.add(name);
        //<#DEBUG_AREA>
        Log.e("LogginUserInfo", "Name: " + name);
        Log.e("LogginUserInfo", "Id: " + user.getId());
        Log.e("LogginUserInfo", "Id: " + user.getDistance());
        //</#DEBUG_AREA>
    }
    return names;
}

And when you change your build variant to release it would become something like this:

private List<String> getNamesOfUsersNearMe(String zipCode){
    List<User> users = mBusinessLogic.getUsersByZipcode(zipCode);
    if(users == null || users.size() < 1){
        return null;
    }

    List<String> names = new ArrayList<String>();
    int totalUsers = users.size();
    for(int i = 0; i < totalUsers; i++){
        User user = users.get(i);
        String name = user.getName();
        names.add(name);
        /*<#DEBUG_OFF>
            Log.e("LogginUserInfo", "Name: " + name);
            Log.e("LogginUserInfo", "Id: " + user.getId());
            Log.e("LogginUserInfo", "Id: " + user.getDistance());
        </#DEBUG_OFF>*/
    }

    return names;
}

Which is way better in performance for long loops and makes your code cleaner by getting rid of the unnecessary code while in “release” mode, of course if you go back to “debug” it will uncomment the area and leave it the way it originally was with the “<#DEBUG_AREA>” tags…

Also trying to fit the most common scenarios, seems like there’s times when you don’t need a full area to get rid of but instead only one single Log, so for that case the project also has a Log wrapper class that you can use as follows:

if(users == null || users.size() < 1){
    ASDebuggerMacroLog.e("LogUserInfo", "There's no users available near me...");
    return null;
}

The line of code used by the class “ASDebuggerMacroLog” will be commented after changing to “release” mode in your Android Studio.

Hope it Helps!

Regards!

###

Standard outputs should not be used directly to log anything (squid:S106)

When logging a message there are several important requirements which must be fulfilled:

  • The user must be able to easily retrieve the logs
  • The format of all logged message must be uniform to allow the user to easily read
    the log
  • Logged data must actually be recorded
  • Sensitive data must only be logged securely

If a program directly writes to the standard outputs, there is absolutely no way to comply with those requirements. That’s why defining and using a dedicated logger is highly recommended.

Source: Sonarcloud

###

I highly recommend using Timber library: https://github.com/JakeWharton/timber

It’s a very small library on top of Android Log class which takes care of all logging requirements easily. some features:

  • It automatically figures out which class is being called and use its name as TAG
  • You can plant different Tree for each build type
  • All logs going through a central place in Tree. so you process them or upload them somewhere if needed.

Leave a Reply

Your email address will not be published. Required fields are marked *