Evgeny Goldin works as a Technical Evangelist for the JetBrains TeamCity CI build server. He speaks Java, JavaScript, Perl and Groovy. His favorite products are MediaWiki, Intellij IDEA, Git, Artifactory, Gradle, YouTrack and TeamCity. He enjoys driving, learning and solving challenging problems. He doesn't like wasting time and being unproductive and believes that simplicity, attention to details and tidy working environments are the most efficient approaches to successful delivery. Evgeny is a DZone MVB and is not an employee of DZone and has posted 17 posts at DZone. You can read more from them at their website. View Full User Profile

An importance of wrapping variables

06.20.2011
| 4386 views |
  • submit to reddit

Long time ago I developed a habit of wrapping every variable logged in [ .. ]:

Java:   log.error( "Class [" + c + "] not found" )
Java:   log.error( String.format( "Class [%s] not found", c ))
Groovy: log.error( "Class [$c] not found" )

The reasons were mostly to spot any trailing whitespaces in variables logged which was very helpful in error messages. As simple as it sounds, lots of messages thrown or logged today still don’t enclose variables in any special characters which can make them quite obscure.

What would you say about this error message ?

..
java.lang.IllegalArgumentException: No enum const class Something.
    at java.lang.Enum.valueOf(Enum.java:196)
..

I was surprised why failing Enum.valueOf() didn’t include the wrong value in the error message. But it did! Here’s the failing code:

..
enum Something{ A, B }
assert Something.A != Something.valueOf( '' )
..

So it was an empty String. Normally, wrong Enum.valueOf() input is printed:

.
enum Something{ A, B }
assert Something.A != Something.valueOf( 'C' )
 
java.lang.IllegalArgumentException: No enum const class Something.C
    at java.lang.Enum.valueOf(Enum.java:196)
..

But with empty argument "No enum const class Something." simply looked like a period at the end of the sentence! I wish it was "No enum const class [Something.]" instead.

// "java/lang/Enum.java"
public static <T extends Enum<T>> T valueOf(Class<T> enumType,
                                            String name) {
    T result = enumType.enumConstantDirectory().get(name);
    if (result != null)
        return result;
    if (name == null)
        throw new NullPointerException("Name is null");
    throw new IllegalArgumentException(
        "No enum const " + enumType +"." + name);
}

 

From http://evgeny-goldin.com/blog/wrapping-variables/

Published at DZone with permission of Evgeny Goldin, author and DZone MVB.

(Note: Opinions expressed in this article and its replies are the opinions of their respective authors and not those of DZone, Inc.)

Comments

Andrew Gilmartin replied on Fri, 2011/06/24 - 10:28am

A useful feature to add to any logging tool is to allow the formatting of the log message. For example,

File file = ...
...
logger.info( "unable to open file: file-name={0}", file );

Doing this has two key advantages. The first is that the ease of adding relevant data to the message is very easy to do. This then encourages messages that truly aid monitoring and debugging. The second is that there is a very low performance cost to logging in that if the message is never used (due to the log level) then the only cost to making the call is loading and unloading the stack.

The second advantage becomes significant for debugging messages. For example,

logger.debug("{0} moving towards {1}", a, b );

is a lot cheaper to ignore than is

logger.debug( a + " moving towards " + b );

And especially so in a tight loop. One can argue that you can always check the debug level before making a debug call. In practice, however, this tends to not to be done and instead the useful debug call is never written.

Andrew Gilmartin replied on Thu, 2011/06/23 - 8:22am

Oh, I forgot the most relevant part. It is trivial in the logger implementation to both quote and escape the message's parameters. My implementation passes them through a JSON converter so that I can also see the internals of the parameter's values.

ionuion@yahoo.com (not verified) replied on Fri, 2011/06/24 - 9:30am

Evgeny,

I too have had this thing in my mind for some time. Personally, I use the <> characters to delimit dynamic parts of a logging message in sensitive messages (e.g. map keys or where empty strings may occur.)

At times the <> characters may themselves denote data parts of the message rather than delimiters (e.g. parts of xml files.) In this case, where does the dynamic part start and where does it end? Then you need other characters to denote delimiting, e.g. [] or {}. Quite a set of rules already.

How about some special characters be used for that?

I attempted to use graphical unicode separators directly in my java file. But would that really be a solution? Some team members might have question marks or squares of all sorts displayed both in editors and log files. They might not care about fonts, encoding, keyboard layouts and that's ok. 

The rules for potential delimiters would be:

  • in ASCII
  • typeable on en_US, en_GB, de_DE, fr_FR, pt_BR and all the other keyboard layouts the programmers use.
  • not part of the actual message and not a punctuation mark
  • still be special

That's quite a set of constraints. I've come to think that when the special need arises, special treatment need be applied, as your [] or my <>.

 

Comment viewing options

Select your preferred way to display the comments and click "Save settings" to activate your changes.