Recall earlier that I had mentioned that I learnt through logs of existing program/framework.
It's weird, but I cannot emphasize enough about the importance and need to log.
I have been using a rather new approach to logging. Well, not exactly to logging, but a new approach combining logging and coding style.
First off, I keep my methods short. For example, given the following algorithm:
public void login(final String username, final String password) {
// authenticate
// check if user container is active
// check if user is active
}
It will most likely evolve into the following code:
public void login(final String username, final String password) {
authenticate(username, password);
verifyUserContainerIsActive(username);
verifyUserIsActive(username);
}
void authenticate(final String username, final String password) {
final boolean valid = checkUserCredentials(username, password);
if (!valid) throw new AuthenticationException();
}
void verifyUserContainerIsActive(final String username) {
final Container container = getUserContainer(username);
if (container.isInactive()) throw new UserContainerInactiveException();
}
void verifyUserIsActive(final String username) {
final User user = getUser(username);
if (user.isInactive()) throw new UserInactiveException();
}
That's just a rough idea. Basically, each method is composed of many more methods, which serve to describe what each step do. Benefits? Eliminate the need to comment complicated algorithms. Comments run the highest risk of being out of sync with the actual code intent.
Also, notice the use of exceptions in the inner methods. I had started out with an alternative idea, that the inner methods would return true/false values, which would. It basically create the following nasty code block:
public void login(final String username, final String password) {
if (isValidCredentials(username, password)) {
if (isUserContainerIsActive(username)) {
if (isUserIsActive(username)) return;
throw new UserInactiveException();
}
throw new UserContainerInactiveException();
}
throw new AuthenticationException();
}
Of course, the better way is as follows:
public void login(final String username, final String password) {
if (isNotValidCredentials(username, password)) throw new AuthenticationException();
if (isUserContainerNotIsActive(username)) throw new UserContainerInactiveException();
if (isUserIsNotActive(username)) throw new UserInactiveException();
}
Personally, I still felt that my first example up there produce a much more readable version of the algorithm, which communicates the intent much better.
But the basic idea/rule here is, exit early. What is most important is to communicate the basic intent of the code. The other possible cases are, well, exceptions (pun intended), and should not clutter the original intent of the code.
And finally, on to logging.
Now, I log all entry and exit of a method, as well as method arguments and method return values. Ideally this should be done with AOP, but I am not doing that yet.
What benefit does this logging bring me?
I can actually, from tracing the method entry logs, form a very clear view of how a request pass through the entire system. An example of the above log might be as follows:
enter: login {username:kentlai, password:xxx}
enter: authenticate {username:kentlai, password:xxx}
exit: authenticate
enter: verifyUserContainerIsActive {username: kentlai}
exit: verifyUserContainerIsActive
enter: verifyUserIsActive
exception caught: UserInactiveException
With shorter methods, logging every method invocations, I can trace the flow very accurately. Sure, there is an increase in the size of logs, but the return in such investment is easier debugging. Without even hooking up to the debugger.
With the logged method arguments, and knowing which method is causing a problem (from the logs), I can actually write a quick unit test to fix any potential problem found.
But there is one last magic elixer in this combination. No side effects.
Basically, each class should not have mutable state. The only mutable state should be from external storage (eg. database). And if a function need to use any values from such storage, they should, themselves be encapsulated into methods of their own, with the return values logged.
Why? This allow you to put together a complete picture, the context and environment of which a method was executed under. When every variable becomes known and can be supplied once again to a method during unit testing, a method can be guaranteed to work consistently and constantly as expected, which allows for more robust code.
Funny it took me so long to realize such principals.
Posts
