Android Logger Refactor - Final Refactor

Android Logger Refactor - Final Refactor

It has been a while since I've worked on refactoring the FyzLog. I've been occupied with the VBM on Android series.

The practices demonstrated in this series though; hugely important ones that will need to be applied once code is written. This is the practice of rutheless refactoring.

I may have covered all this before; as said; it's been a while.


It looks like I was planning to be

extracting a Logger instance for the Android Log functionality!

Sounds like a plan.


Looking at our current Logger, we only have the

/* package */ static final Logger SystemOut = new Logger();

Logger instance defined. This is where we want to create an AndroidLogger.

First step is to look in FyzLog and identify all the methods used by the else branch in the repeated snippet

public static void e(@NonNull final String msgFormat, final Object... args) {
        if (doPrint) {
            Logger.SystemOut.println(LogLevel.ERROR, logLevel, msgFormat, args);
        } else {
            log(LogLevel.ERROR, msgFormat, args);
        }
    }

Doing a quick copy and paste from FyzLog to Logger of the log method (which is the one in the else branch);

    private static void log(final LogLevel level, final String msgFormat, final Object... args) {
        if (level.logAt(logLevel) && msgFormat != null) {
            final StackTraceElement frame = getCallingStackTraceElement();
            final String tag = createTag(frame);
            final String msg = String.format(Locale.US, msgFormat, args);
            final String message = createMessage(frame, msg);

            if(level == LogLevel.VERBOSE)
                Log.v(tag, message);
            else if(level == LogLevel.DEBUG)
                Log.d(tag, message);
            else if(level == LogLevel.INFO)
                Log.i(tag, message);
            else if(level == LogLevel.WARN)
                Log.w(tag, message);
            else if(level == LogLevel.ERROR)
                Log.e(tag, message);
            else if(level == LogLevel.ASSERT)
                Log.wtf(tag, message);
        }
    }

I'm not seeing any additional dependencies via the IDE. What I do see is that there's an undefined variable

This is very similar to the naming issues we had for our println method:

    /* package */ void println(final LogLevel level, final LogLevel logLevel, final String msgFormat, final Object... args) {
        if(msgFormat == null) throw new IllegalArgumentException("FyzLog message can not be null");

        final StackTraceElement frame = getCallingStackTraceElement();
        final String output =
                level.tag() + "@" + logLevel.tag() + "/ " +
                        createTag(frame) + " " +
                        createMessage(frame, String.format(Locale.US, msgFormat, args));
        System.out.println(output);
    }

We'll just pull the final LogLevel logLevel param from println and add it into log and everything's cleared up.

    private static void log(final LogLevel level, final LogLevel logLevel, final String msgFormat, final Object... args) { //...

We've moved and removed red...

Run Tests
Unsurprisingly; passed. We didn't modify FyzLog; so sure.

Now let's move the else to call the Logger#log.

Modified FyzLog now follows this form

    public static void wtf(@NonNull final String msgFormat, final Object... args) {
        if (doPrint) {
            Logger.SystemOut.println(LogLevel.ASSERT, logLevel, msgFormat, args);
        } else {
            Logger.log(LogLevel.ASSERT, logLevel, msgFormat, args);
        }
    }

Run Tests
Passing.

Now we'll update Logger#log to be non-static; update FyzLog to be

   public static void wtf(@NonNull final String msgFormat, final Object... args) {
        if (doPrint) {
            Logger.SystemOut.println(LogLevel.ASSERT, logLevel, msgFormat, args);
        } else {
            Logger.SystemOut.log(LogLevel.ASSERT, logLevel, msgFormat, args);
        }
    }

Run Tests
Passing.

Looking closely; we're still stuck with an else block. We haven't made this any better. This is where the slugs come into play. We currently have two methods; println and log. We need one method, log.

Before I do that though - I just realized that the existing log method is UGLY... That needs some fixing. Like; no if-else if-else-if...

Hmmm... We call different methods... Java doesn't have methods as first class citizens; so we can't pass the method around.

Since we're accessing the LogLevel; maybe we can push the behavior into LogLevel. This is a very simple class still


public class LogLevel {

    public final static LogLevel VERBOSE = new LogLevel(Log.VERBOSE, "V");
    public final static LogLevel DEBUG = new LogLevel(Log.DEBUG, "D");
    public final static LogLevel INFO = new LogLevel(Log.INFO, "I");
    public final static LogLevel WARN = new LogLevel(Log.WARN, "W");
    public final static LogLevel ERROR = new LogLevel(Log.ERROR, "E");
    public final static LogLevel ASSERT = new LogLevel(Log.ASSERT, "WTF");

    private final int level;
    private final String tag;

    public LogLevel(final int level, final String tag) {
        this.level = level;
        this.tag = tag;
    }

    public String tag() {
        return tag;
    }

    public boolean logAt(final LogLevel other) {
        return this.level >= other.level;
    }
}

and it'll need a log method to embed the behavior. I think this'll become inheritance for each log level.

The result of adding an abstract log and making each slug an anonymous class makes LogLevel look like (also made everything package-protected

/* package */ abstract class LogLevel {

    /* package */ final static LogLevel VERBOSE = new LogLevel(Log.VERBOSE, "V"){
        @Override /* package */ void log(final String msg) { Log.v(tag(), msg);}
    };
    /* package */ final static LogLevel DEBUG = new LogLevel(Log.DEBUG, "D"){
        @Override /* package */ void log(final String msg) { Log.d(tag(), msg);}
    };
    /* package */ final static LogLevel INFO = new LogLevel(Log.INFO, "I"){
        @Override /* package */ void log(final String msg) { Log.i(tag(), msg);}
    };
    /* package */ final static LogLevel WARN = new LogLevel(Log.WARN, "W"){
        @Override /* package */ void log(final String msg) { Log.w(tag(), msg);}
    };
    /* package */ final static LogLevel ERROR = new LogLevel(Log.ERROR, "E"){
        @Override /* package */ void log(final String msg) { Log.e(tag(), msg);}
    };
    /* package */ final static LogLevel ASSERT = new LogLevel(Log.ASSERT, "WTF"){
        @Override /* package */ void log(final String msg) { Log.wtf(tag(), msg);}
    };

    private final int level;
    private final String tag;

    private LogLevel(final int level, final String tag) {
        this.level = level;
        this.tag = tag;
    }

    /* package */ abstract void log(final String msg);

    /* package */ String tag() {
        return tag;
    }

    /* package */ boolean logAt(final LogLevel other) {
        return this.level >= other.level;
    }
}

Run Tests
Passing.

Now in Logger#log we can just call the log method off of the passed in LogLevel level
...
at which point I realize I need to pass in the tag; not use the log level character tag.
This changes the LogLevel#log to look something like:

/* package */ final static LogLevel ASSERT = new LogLevel(Log.ASSERT, "WTF"){
        @Override /* package */ void log(final String logTag, final String msg) { Log.wtf(logTag, msg);}
    };

I made many steps there. I did them all instead of just one. But...
Run Tests
Passing.

Because the unused log method in FyzLog is annoying me; going to clean that; and it's subsequently unused methods out.
All the methods that got cleaned are already migrated to Logger.
Run Tests
Passing.

I'm doing a little duplicate comparison between println and log; and while there's some method calls the same; I don't see much value in complicating the parameters. I'll leave them as they are for now.

Since we want to call just a single method; which we'll call log; we need to do something similar to how we updated LogLevel. Abstract class and private constructor!

And I've double stepped again - I moved both the println and log method into the derived class... I SHOULD have done one at a time... TOO LATE!!! (ok, not really; but I'm invoking obvious implementation... or... jumping the gun, either way)

The FyzLog code reflects the change looking like

    public static void v(@NonNull final String msgFormat, final Object... args) {
        if (doPrint) {
            Logger.SystemOut.log(LogLevel.VERBOSE, logLevel, msgFormat, args);
        } else {
            Logger.AndroidLog.log(LogLevel.VERBOSE, logLevel, msgFormat, args);
        }
    }

and Logger grew a bit more verbose at the slugs since the methods moved inside

    /* package */ static final Logger SystemOut = new Logger(){
        @Override
        /* package */ void log(LogLevel level, LogLevel logLevel, String msgFormat, Object... args) {
            if(msgFormat == null) throw new IllegalArgumentException("FyzLog message can not be null");

            final StackTraceElement frame = getCallingStackTraceElement();
            final String output =
                    level.tag() + "@" + logLevel.tag() + "/ " +
                            createTag(frame) + " " +
                            createMessage(frame, String.format(Locale.US, msgFormat, args));
            System.out.println(output);
        }
    };
    /* package */ static final Logger AndroidLog = new Logger() {
        @Override
        /* package */ void log(LogLevel level, LogLevel logLevel, String msgFormat, Object... args) {
            if (level.logAt(logLevel) && msgFormat != null) {
                final StackTraceElement frame = getCallingStackTraceElement();
                final String tag = createTag(frame);
                final String msg = String.format(Locale.US, msgFormat, args);
                final String message = createMessage(frame, msg);

                level.log(tag, message);
            }
        }
    };

What effect will this have on the tests!?!?!
Run Tests
Passing.
Neat - None.

I hope that it's easy to see the MASSIVE duplication in the logging if-else block

        if (doPrint) {
            Logger.SystemOut.log(LogLevel.WARN, logLevel, msgFormat, args);
        } else {
            Logger.AndroidLog.log(LogLevel.WARN, logLevel, msgFormat, args);
        }

We branch on the doPrint variable; which is 'controlled' in the following methods

    private static boolean doPrint = false;
    /* package */ static void writeToSystem(){
        doPrint = true;
    }
    /* package */ static void writeToLog(){
        doPrint = false;
    }

We don't really need to know if we want to print or not... Just which logger we use to write.

Let's change the writeTo[System|Log] methods to just flip which Logger slug gets used.

    private static Logger ActiveLogger = Logger.AndroidLog;
    /* package */ static void writeToSystem(){
        ActiveLogger = Logger.SystemOut;
    }
    /* package */ static void writeToLog(){
        ActiveLogger = Logger.AndroidLog;
    }

All of the FyzLog#Z methods get transformed to be a single line

ActiveLogger.log(LogLevel.VERBOSE, logLevel, msgFormat, args);

Run Tests
Passing.

This has seen us create the AndroidLog slug to mirror the previous SystemOut and set them up as derived classes to dictate behavior and have no branching.

As I look for what I'll write about in the next refactor... I... Think I'm done. There's no more obvious refactoring that needs to take place.

Conclusion

This is the end of the series... I wasn't actually expecting that. This is a cleaner solution that I did before.

So we've reduced FyzLog to about 159 lines; which is about half of the original size.

If you look at my original solution and the new solution
I've done the same work with one less class.

Which... Huh - Would not have expected that. There was something that felt off, kinda clumsy, about my original refactor. I'm glad continued work has improved? the design. I question it a little because I can't judge the communication of the code particularly well.

A Failure

One thing I'd like to point out that I realized working through the code this last time, where I, behind the scenes, corrected a few mistakes - I didn't TDD this.
I failed to apply TDD as a practice to this code. How would that have changed it? I don't know.
I have the original tests; and I kept those passing; but there were some additions that 100% should have been TDD'd. The biggest standout of this to me is the `LogLevel#logAt'. This is doing a comparison. It will explode on a null. MAYBE that's okay as it's a 'hidden' class; but if it was TDD'd; that'd not be a question.

Part of doing Software as a Craft; is recognizing and admitting your mistakes. Learning form them and looking to improve the your practice of the craft.

To that - Here I am declaring - I failed to do the practices at my best. This is definitely an excellent lesson for me; and a huge part of doing this blog, in general. I get to practice; and see where I'm at.

Part 1 - Part 2 - Part 3 - Part 4 - Part 5 - [Part 6]

Show Comments