|
I just realized that every single logline is about "something wrong". I guess the impact of the above mentioned problem them becomes rather small - but it is still an inefficient type of code!
I got confused by the use of java.util.logging.Level.FINE on all of them, which typically is used for debug logging. If this really *only* is used for error logging, then you'd just as well define a "ErrorReport" interface, let it have two methods "boolean isErrorReportEnabled()" and "void reportError(String msg, Exception e)" possibly with a overload w/o the Exception. You could, I guess, just let it report the actual message key? Again, it would be fantastic if this could be injected ("globally" this time), so that I could supply my own ErrorReport implementation, hooking into my world. .. or just use slf4j, reporting on "WARN" and "ERROR" levels. If we use slf4j, what's your recommendation for accessing the logger from log sites? Invoking the slf4j logger factory or something else? A logger is too prevalent a dependency to be injecting into every class.
By "log sites", I assume you mean where the log.debug|info|error invocations actually are?
I agree that it is a somewhat prevalent dependency - every class needs at least one. However, users of the Guice project have actually asked for such a thing - with Guice you can say @Inject on fields, and thus one could do this on the "Logger log" field, and have this injected automatically, by using a Provider (Guice term - a instance factory) that know of the class that it is being asked to manufacture an instance for (the requested enhancement). .. if that made sense. It is standard to use the static LoggerFactory construct that the logging system provides - i.e. "the bad way" when it comes to IoC. However, this isn't really a biggie - since you configure the logging system from the outside. In addition, this (in my maybe twistde opinion) isn't quite the same as piecing together the application - this is more like new StringBuffer(), only that you use a static factory so that the factory *may* speed things up by caching, which is what the logging factories does. However, in the latest projects I've had hands on, I've used a project-private LoggerCreator, which takes the class name as parameter to a createLogger method, with an overloaded method that also takes a String postfix, which is appended to the constructed log-category. This means that I can change how the final logging categories are created one single place, by for example having all Servlets in the project (as resolved using introspection, getting the implemented interfaces) get the logging category "MyProject.SERVLET."+SimpleClassName, instead of simply the full classname (which is really the common way to do things). If you used the overloaded method with the postfix, that would be tacked on like this: "MyProject.SERVLET."+SimpleClassName+'.'+postfix. In my projects, this has been done using a static method in a static class - "the bad way" IoC-wise. My excuse is the projects I'm talking about are applications, not libraries...! It would however be possible to extend this by making the LoggerCreator thingy a injectable dependency - so that if I wanted all WorldWind loggers to have a different naming scheme, I could do this by implementing the LoggerCreator interface, and inject it somewhere.. I'm not quite sure how this idea would pan out, but it should be doable. PS: The most important thing is that the Logger instance isn't gotten anew for each "log site" - this should be done in a static initialization block for the class, or simply the standard "private static final Logger log = LoggerCreator.createLogger(ThisClass.class);" Decision has been made to stick with JRE logging but to provide example of integrating and overriding in application. slf4j logging requires two additional libraries, one of which must be chosen by the application developer at build time. We believe it's more cumbersome to require all applications to deal with this rather than requiring relatively few applications to deal with mapping JRE logging to their system.
|
||||||||||||||||||||||||||||||||||||||||||||||
 |
|
Improvement
Closed
Major
slf4j logging instead of "java native" java.util.logging (JSR 47 logging)
For every single potential log entry in the system, the following is done
1) It constructs the log-argument whether logging will be done or not
2) It then invokes the static method on WorldWind called logger(), which looks up in the Configuration object, which is a Properties object
4) Properties is an extension of Hashtable, and a *synchronized* lookup commences.
5) The logger name is now found, and java.util.Logging.Logger.getLogger() is invoked, which obviously is a *synchronized* call, which have to get the context LogManager, and from that again get the actual Logger instance, which is *yet another synchronized* Hashtable lookup.
6) After some nullchecks, the Logger instance is returned
7) The log(UsingSomeLevel, msg) is finally invoked
8) The log-line is probably not written afterall, and all the above is in vain.
The system doesn't have a clear startup-point for logging, which I guess is the reason for using the Logger.global, which is a deprecated field.
The common way to do logging in java is like this (this goes for all logging systems currently in existence):
class Blabla {
private static final Logger log = Logger.getLogger("whatever"); // typically Blabla.class
(or one may say "log = SomeProprietaryLoggerCreator.getLogger(Blabla.class);, which then does lookup logic and whatnot)
method() {
// Bla bla
if (log.isDebugEnabled()) log.debug("This is a debug line, stating that the customer is " + customer);
}
}
This ensures that the Logger instance is only looked up once, and that every subsequent log-line that ISN'T logged will NOT incur the String-creation overhead (which as we know entails creating a StringBuilder, and then concatenating the different elements), and there will be at most one synchronized invocation per non-logged call.
All logging frameworks made in java have this "isWhateverEnabled", due to the above mentioned not-logged scenario.
Typically the startup-point is handled by having the boostrap class not construct the logger in a static field, but first letting the main method (the boostrap method) take care of reading logging config, and then construct the log instance. From there on, the Logger.getLogger() will work, and the above suggested proprietary "LoggerCreator" would return sane values.
I still suggest using slf4j - as that would be way more flexible. Further, I *definitely* advocate having a different name per class, typically this is the class itself, as shown above. This makes the logging very much more useful.