Android Logger Refactor- Sin Forgiven
Last we left our hero; unit tests were red. The horrible horrible red bar! faints
I believe it was in Kent Beck's TDD book that he recommends ending the work day with a failing test. It gives you an explicit place to start working again the following day.
This is a little different; but I wanted to throw that in somewhere. :)
In our case, we're refactoring away from Primitive Obsession and utilizing objects (new concept, I know) to represent things. Our unit tests actually rely on some implementation details to work. Which, as this refactor is showing, creates fragile tests.
Our existing unit test class is available here; it's 200+ lines so I'm not embedding it.
What I will embed is the first method with an error; and we'll focus on getting this one to compile/test. The rest will be commented out as we resolve these one at a time.
The error we're experiencing is line 14 in the gist
FyzLog.logLevel = i;
This was incrementing the log level each loop; and then validating that it logged (or not) correctly, with the correct tags.
I'm going to point out how crappy my naming in this test is. i? s? What? Loop variables need some work; definitely.
First step I'm going to take is to change the loop from a counter; for (int i = Log.VERBOSE - 1; i <= Log.ASSERT + 1; i++) {; to looping over a collection like I did for the tags; for (final String s : new String[]{"V", "D", "I", "W", "E", "WTF"}) {.
The new log level loop looks like for (final LogLevel logLevel : new LogLevel[]{LogLevel.VERBOSE, LogLevel.DEBUG, LogLevel.INFO, LogLevel.WARN, LogLevel.ERROR, LogLevel.ASSERT}) { which is a bit long, but it's the first step in bringing the test back to green.
The compile error line is updated to be FyzLog.logLevel = logLevel;. This is looking pretty good. Though now we have an issue constructing the string to compare against here final String prefix = configureSystemTest(s, i);.
It may be obvious or obvious once pointed out; I'm doing my best to let the code direct my changes. There's an error here, so fix it; now there's an error over there, fix... Repeat as required. This approach when you can't do Red-Green-Refactor helps minimize the changes you actually have to make to get the unit tests back online. During some earlier work I did, I rewrote things; trying to "do it right" and it was over complicated. Sure, it worked - but it wasn't code I was happy with. Showed the "follow the code" approach, I did and it was a much smaller change, and didn't have that "uck" feel to the result.
Back to the refactor - we need to update this method
so that it takes a LogLevel instead of an int. If you're following along at home; this will continue to cascade changes, and we'll have to update the getLevelTag method to be log level. Except; that's just getting the tag value (go look at here ). We already set the tag up; as part of the LogLevel; public final static LogLevel VERBOSE = new LogLevel(Log.VERBOSE, "V");
Since that method is doing what the LogLevel object can; let's just use the object... huh; objects doing things... fancy.
This changes the line in the configureSystemTest from
final String logLevel = prefix + "@" + getLevelTag(level) + "/ ";
to
final String logLevel = prefix + "@" + level.tag() + "/ ";
Looking good so far; except back in massiveTestOfAllPrintMessageCombinations our assert isn't compiling.
assertEquals("Failed at [s=" + s + "][i=" + i + "]", expected + "\n", target);.
Kinda obvious why, i is still hanging around. That s also really annoys me. I'm renaming it to tag. Fixing the i to be logLevel will change this line to
assertEquals("Failed at [tag=" + tag + "][logLevel=" + logLevel.tag() + "]", expected + "\n", target);. No more errors in this test.
Run Tests
A test failed!
We have a check in our tests to ensure we ran the correct number. This is incase an exception blew out of the loop early.
The first tests, if checked carefully, went 1 below Log.VERBOSE and 1 above Log.ASSERT. This was to ensure functionality available due to operating on an int. It could be set to values not in our log levels. The refactor to an object kills that as a possibility.
The assert of the number of checks looks like assertThat(ctr).isEqualTo(6 * (6 + 2)); and we can clearly see the + 2 in there. Our test failed because we ran 12 less than the assert expected. As we've refactored the requirements have changed. Updating tests should be done with much hesitation and full understanding of why it needs to be changed to pass. As explained above, we've removed 12 'tests' which were required because of working on a primitive. Removing that removes the extra tests.
With the reason for modification identified; we'll go ahead and drop the + 2 and check again. I want to call out that I actually have + 2 in the code. It's my early attempt to show that there's something going on that is strange.
With the assert now being assertThat(ctr).isEqualTo(6 * 6);
Run Tests
PASS!
At this point we'll uncomment the massiveTestOfAllPrintMessageFormatCombinations test. This is almost identical to the previous test; but confirming that it correctly formats the string args.
I won't try to be clever; I C&P'd the loops from the earlier test. They're identical. This identically makes me wanna look into reducing duplicate code.
A quick update to fix naming and we can
Run Tests
Passes!
There's now the massiveAndroidLogging test to update. It's requiring a little more re-working. Some train-wreck Law of Demeter happening. All sins are forgiven in the pursuit of a green bar. We'll let it ride for now; as well as building a string array of the LogLevel tags.
final String[] tags = new String[]{LogLevel.VERBOSE.tag().toLowerCase(), LogLevel.DEBUG.tag().toLowerCase(), LogLevel.INFO.tag().toLowerCase(), LogLevel.WARN.tag().toLowerCase(), LogLevel.ERROR.tag().toLowerCase(), LogLevel.ASSERT.tag().toLowerCase()};
Pretty dang hanky. We'll get it cleaned up once we're green.
Going back to the massiveAndroidLogging; a lot of it's calculations rely on the primitive value. This requires a bit of a re-write to make sense and not be a hack-fest.
For reference; here's the original form of this method
Now I'll do stuff....
and here's the updated version
I think more time could clean this up a bit; but there's nothing standing out to me (aside from the if block there) that needs loving.
The final androidLogDoesNothingGivenNull test needed just a little tweaking; not worth showing explicitly.
All tests pass. We're Green. All sins are allowed to get here... Now we make amends - Clean up time!
What I wanted to clean I mentioned above; so I'll just highlight them here and show the final code.
- Switching on tag
- Heavy use of the
tag()in logic
The unit tests got a refactor and a bit of a clean up. They new version is available here.
There's still a lot of duplication between the tests; this can be cleaned up but it's not the push I'm looking for. One thing that's really standing out is how we're configuring the log level => FyzLog.logLevel = currentLogLevel;
That looks pretty naked. This is the same for configuring to use the system print or the android log.
FyzLog.doPrint = false;
These violations of encapsulation need to go - later.
Later being the next post! In this part we've refactored the tests to work with the new LogLevel object. There was additional clean up in the tests to remove some of the ugly. Still a bunch of duplicated code, but it's prudent to finish the refactor of the code before starting optimizations on the tests.
Next time we'll focus on fixing encapsulation. I expect it to be a short post; but encapsulation is an important feature.