Log statements prevent refactoring: how to help this?

Question

Hello all,

I have some relatively large legacy method that I would like to refactor. It fits "Bulleted method" type as specified in Michael Feathers' "Working Effectively With Legacy Code" and thus it could be split in several sequential methods in rather straight-forward way . But each of its sequential steps outputs some log message and forming that message requires much more data than for the step itself. So when I try to extract method, I end up with method having, say, 6 parameters. If I had removed those log statements I would have method with only 1 parameter. So I effectively cannot refactor anything. And I'm not allowed to just drop log statements.

A part of method looks like that:

// much of code before
Device device = getDevice(deviceID);
boolean isFirstRegistration = false;

if (device == null) {
    /*logger.trace(
            "DeviceId", deviceID,
            "ADM", adminCode,
            "Phone", clientData.getPhone()
    );
    logger.info("First registration of the device. Device ID - " + deviceID);*/
    isFirstRegistration = true;
} else {
    /*logger.trace(
            "DeviceId", deviceID,
            "ADM", adminCode,
            "Phone", clientData.getPhone()
    );
    logger.info("Device ID - " + deviceID
            + " has been previously registered by adminCode: "
            + device.getAdminCode());*/
}
// much of code after

As you see, commented out logging statements. In this case I can extract method boolean isFirstRegistration(String deviceId). But when they are uncommented, signature bloats up to boolean isFirstRegistration(String deviceId, String adminCode, ClientData clientData). And that is not the most extreme case, just one from the first glimpse. Have you any ideas how should I refactor such method?

Answer 1

Sprout class. Turn logging over to a helper class and feed it all the data it needs, as it needs it.

Update: Using the example variables presented, I would call, for example, myLogger.setDevice(device) as soon as the device was populated; similarly for adminCode, clientData,etc. Give the logger log methods like traceDeviceAdminCodeAndPhone() and logFirstRegistration(), where it uses its own instance variables. Anywhere the variables change, feed them again to the logger. Now, pass the logger in to the methods you're extracting, plus any parameters that are directly needed by the new method (but no more), and your logger can still report what it needs to from within the extracted method.

Also, in case this is starting to look like your logger is too intimate with your method, an alternative would be to extract the method into a new class and convert some of the local variables to instance variables; then the logger could simply ask the new class for the values instead of holding onto them itself. But the logger class as a helper is probably a smaller, less impactful, refactoring. Whether that's good or bad depends on where you want to go with it.

Answer 2

Carl's answer is certainly valid, but I think there is at least another good option.

Some logging frameworks support a so called Mapped Diagnostic Context. You can store key-value pairs in them, and then the framework can add them to the log lines in the format you specify in its config files. As you seem to log usually the same data (at least in trace) I think it would fit pretty well to your needs.

Some of the frameworks that do support it are Log4J, SLF4J, but I guess something similar should exist in "non-Java" world as well.

I think you could use it at least for/instead of the trace messages and would gain quite a lot:

• less, cleaner code
• no need to pass params that are needed only for logging
• uniformly logged messages (formatted by the framework according to the pattern you give it)
• more flexibility - what/when/how is logged is controlled in logging config (where it belongs).

One thing to be noted: the key/value pairs are typically stored in thread local variables which leads to some possible pitfalls:

• it may not work too well/won't be easy to use if you frequently switch threads
• usually the cleanup (removing unwanted values) is your task, not done automatically by the framework.