mirror of https://github.com/apache/lucene.git
75 lines
3.3 KiB
Plaintext
75 lines
3.3 KiB
Plaintext
Using log calls
|
|
===============
|
|
|
|
There are several gotchas when logging. In particular, methods
|
|
are called and strings are concatenated that have variables
|
|
and objects can be constructed even if the logging level
|
|
is more restrictive than the call. For instance, if the logging
|
|
level is WARN, then a call like:
|
|
log.trace("something {}", some_object.toString())
|
|
will cause some_object.toString() to be called, then the resulting
|
|
string is passed to log.trace() where the log level is evaluated
|
|
and the logging call may be aborted. Any method called explicitly
|
|
as part of a logging call is executed regardless of whether the
|
|
message will be logged or not.
|
|
|
|
This can be very expensive as per measurements with Java Flight
|
|
Recorder. It's particularly egregious when complex operations
|
|
are performed for, say, debug or trace levels, which
|
|
are rarely reported.
|
|
|
|
Here are a few patterns that generate useless strings/objects:
|
|
|
|
- log.info("some stuff " + some_object) will concatenate the
|
|
some_object.toString() and create a new string. The only
|
|
exception is if "some_object" is a literal string.
|
|
|
|
- log.info("some stuff {}", object.method()) will execute the
|
|
method.
|
|
|
|
- log.info("some stuff {}", object.toString()) will execute
|
|
the toString and then may throw the results away.
|
|
log.info("some stuff{}", object)
|
|
is safe, the object's toString() method is called only after
|
|
the log/do not log decision has been made.
|
|
|
|
-----------
|
|
NOTES:
|
|
|
|
- If you're creating a logging call that has no choice but to
|
|
do something expensive, surround it with "if (log.is*Enabled)".
|
|
Validation will flag any situation where the level in the "if"
|
|
clause does not match the level of the actual call.
|
|
|
|
- Logging calls can take a bare exception, but do not
|
|
use the braces if you want the stack trace! So
|
|
log.info("stuff {}", exception) will not print the full stack,
|
|
log.info("stuff ", exception) _will_ print the full stack.
|
|
log.info("stuff {} ", some_object, exception) will print "stuff + the result
|
|
of the object's toString() method" plus the full stack. If you're puzzled
|
|
as to why so many logging calls don't have a matching number of curly-braces
|
|
and parameters, this is usually why.
|
|
|
|
- When slf4j supports lambdas in logging calls (log4j2 does now),
|
|
we can use lambdas rather than "if log.is*Enabled". slf4j 2.0
|
|
will when released. This will probably mean this check has to be re-worked
|
|
to avoid false flags
|
|
|
|
- warn, error, and fatal level messages are NOT flagged for explicit,
|
|
function calls, but will be flagged if they contain plusses that aren't
|
|
simple concatenation. This last is something of a style check.
|
|
|
|
- You can get into some pretty convolued consructs trying to pass some of these
|
|
checks. Adding //nowarn, with or without spaces will cause the line to pass
|
|
no matter what. Please use this hack sparingly and be conscientious about
|
|
surrounding with 'if (log.is*Enabled)'.
|
|
|
|
- String constants may be added with '+', but they _must_ be literal strings.
|
|
The compiler is smart enough to concatenate them when compiling. For example:
|
|
log.info("some {} "+ "more nonsense {}", object1, object2) is fine
|
|
log.info("some{} " + " more nonsense " + object1, object2) is NOT fine (note
|
|
the plus in front of object1).
|
|
|
|
For a fuller discussion, see LUCENE-7788 and the other JIRAs linked
|
|
from there.
|