Why a Logging Framework Should Not Log | Hacker News Reader

Why a Logging Framework Should Not Log

russet.org.uk

92 pointsphillord55 comments

No, this guy is 100% wrong. The distinction is absolutely clear. If someone else is expected to build on top of a framework he provides then he is building a library, and it would be inappropriate to tie future consumers to a back-end. This is relatively simple to fix - you mark his library as a dependency and add an additional <exclude> for slf4j-nop to that dependency, but it's not the right way to do this. Those messages aren't meant for him, they're meant for future consumers, and now after including his library they have to dig through and figure out why SLF4J suddenly broke.

I can't find exactly what this Tawny-OWL thing is (his link is broken), but it sounds like it might have some kind of interpreter application provided. If he is offering a finished application within the same build unit as his UI library, this is the "big ball of mud" architecture. The fix is to break his application out into a separate build unit that depends on his library. The application can then include slf4j-nop without messing up SLF4J for all his library's consumers. Maven Reactor can automatically build his dependencies when his main application builds, if desired.

The thing about having to deal with 2 different logging frameworks is exactly what SLF4J is meant to fix. SLF4J lets you route the messages from multiple sources to a single sink/backend defined by the final consumer application. Yeah, it sucks to deal with multiple logging frameworks, but that's simply how it is and you don't help anything by having a whinge about it. You include the routing/bridge modules (JUL-to-SLF4J, Commons-to-SLF4J, etc) in the final-consumer application and call it a day. If you don't want to do that, find some other dependency that doesn't use those logger frameworks.

My framework is built in Clojure. The interpreter is always there. Think of it like a statistics library with R.

The idea of a "main application" is itself not a clear one. There are a set of functions you can use. Whether you choose to launch directly over the library or import it is a matter of convenience.

I would say that the responsibility to define a backend falls either on the Clojure interpreter or the user of the interpreter, then. Java is not typically run on an interpreter shell and the defaults that normally are sensible for Java probably aren't appropriate there.

It's a perfectly sensible default for a framework to warn you at runtime that it's not configured properly, and stderr is the appropriate channel for that to go out over. I would even go so far as to say that it should default to stderr output on warn/error messages unless explicitly muted, instead of merely switching to NOP output after the initial misconfiguration warning. An interpreter might prefer another default but I think that's probably the best default for most Java projects.

The way I see it here, Clojure built on top of a stack without understanding the caveats that go with the stack. It's simply a fact that Java logging is a mess, there are four major competing standards and you need to tell Java which one you prefer, because any project will eventually need to interact with all of them if it continues growing. It's a fact of building on that stack.

The problem is that it is a Facade/API that is initializing and printing to STDERR.

I completely disagree with the idea of making slf4j-nop a required exclusion dependency (that is a I agree with @paulmd and not the OP) but a facade/api should have very little interaction with the boot process of Java. The default should be to do nothing and require either a java.util.ServiceLoader like mechanism or some other explicit configuration (or in SL4J's case adding a bridge).

That is slf4j-nop behavior should be the default (not the dependency). I understand that would confuse users but I think it would be the correct behavior. (also see my other comment for more reasons)

Java is getting an interpreter shell, as it happens.

Logging should default to warn/error on standard err? I find this a strange idea. Having a "--verbose" switch is pretty standard on the command line. Some applications do have an "be absolutely silent" switch, true but that normally switches everything off.

I don't think any of this is a Clojure specific issue. You can do all of the same things in Clojure with JVM logging libraries as you can in Java.

Whoa. The author recommends including slf4j-nop as an explicit dependency of libraries?! This means that when a developer writes an application and forgets to include an slf4j backend, instead of getting a warning that no backend is configured, that developer will get absolutely no output. This is really bad advice.

It's ugly advice. Wish there was a better alternative. Ideas on a post-card please.

The JVM works this way after C programs popularized the precedent - refuse to run at all with a dynamic link error stating the shared library that was expected without any mention of what version of the library should be present in the LD_LIBRARY_PATH or that the shared library version expected actually doesn't match the ABI in some corner cases and silently fails during runtime. That's part of why customizable classloaders in the JVM exist.

That is not what is happening with SLF4J. The nop logger is present in the API artifact. The API artifact chooses to warn when using it. The nop dependency, despite the name, contains no logger at all. It just explicitly forces the usage of the nop logger.

It's pretty clever actually, and works in a straight-forward way.

This is a well understood problem and I think the design pattern SLF4J uses has become quite popular.

The ability to allow consumers to bind at runtime the implementation they want by providing an api jar is kind of a neat idea.

The thing I dislike the most is when libraries force me to use their logging runtime. If they need it just for tests they should add the 'test' scope and just use the 'api' jar as a 'compile' dependency.

It has become popular, but it is still wrong. If you're a nested dependency, then DON'T require end developers to be aware that you're there. Doing so makes you a leaky abstraction.

http://www.joelonsoftware.com/articles/LeakyAbstractions.htm...

Though the author does have a point that fault here could be put on the library that added the dependency without a default logging behavior. However I'd still blame SLF4J for making the default case suboptimal.

But it seems useful because you can decide what behavior your want for your project.

Right, it is configurable.

But there is no reason why a configurable library can't have reasonable default behavior if no configuration is supplied. While still being configurable. If you're winding up as a buried dependency that end developers may not be aware of or care about, you want to do this.

True enough. I guess the main downside would be including a library that may never be used.

What reasonable default behaviour? If you're writing a console application, dumping to stderr is probably not a good idea - writing random log files that the end-user/admin has no idea about is probably not a good idea - shutting up and doing nothing is probably not a good idea (Java code has a tendency to use logging to warn about non-fatal configuration errors, etc). And let's not get started on what verbosity to set by default.

A good default is to write to STDERR if the severity level is above some threshold, otherwise do nothing.

That way the console can tell you about configuration errors, and by default the library will log nothing. If the library author considers it important to log somewhere, the library author is responsible for putting both an understandable warning up, and writing documentation.

If you are creating a library? You shouldn't log at all. Return errors or throw them - do not log.

If you are creating a console application? Stderr is the standard way to log errors. Let the user decide if where it points to.

If you are creating a daemon, set the log destiny at the launch script. The application can either log to stderr anyway and let the script handle everything, or offer a parameter for setting the log channel.

The Java community fixation on logging is really not deserved. It's more caused by bad error handling by their main web servers than by any fundamental problem.

Logging is useful for more than just error conditions; how does that square with your advice to library authors?

If it's not an error condition, you return it.

Libraries must not do any covert IO (in fact, any covert anything). A logging library is the only one that should log, and not their own messages.

They may write into some main application supplied collector, if it is not global, or if it is clearly handled as a message passing API.

The Java way is simply bad.

Maybe I'm misunderstanding your point -- by "do not log," do you mean do not call logging statements in a logging library's API, or simply do not force a concrete implementation of a logging library? I understand and agree with the second one completely, but the first one seems unrealistic.

I can't see how the Apache httpclient library could sanely "return" the different state transitions and pieces of data that are logged in its wire-level logging, but this is certainly a case where the logging statements are welcome.

Yes, if you created a framework, that will call your code, yes, it can log. It can also provide a logger implementation, or request one from you, whatever it deems better, and your code must comply.

But a library, that your code will call, must not log. Ever. That includes any portion of a framework that you have to call, but it using services upper on the stack can make this rule hard to see. It must not include a logger implementation, and not call any global logger supplied from you.

It seems we are arguing over the definition of those two cases.

So in the case of Apache HTTPClient (which I would call a library), are you saying that it is a design flaw that it provides logging statements of its internals, when provided the proper configuration/logging implementation?

If so, I would have to disagree based on pragmatic grounds, unless you have another credible way to acquire the information present in http wire logging or connection pool events, for example.

It doesn't force anything though, unless you statically refer to the runtime. It does force you to exclude their logging backend, but that is straight-forward enough.

Yes, but you have to know to exclude their backend. And, that library may be several dependencies deep. Now you're expecting potentially junior developers to have the insight to grep their entire transitive dependency tree, find the nop dep, and exclude it. This kind of silent failure is worse than the alternative.

Dependency exclusions is a code smell everywhere but java. I don't understand why someone is actively giving this advice.

The alternative is not specifying a nop dependencies and then inflicting on downstream uses the choice that I was not prepared to make.

My feeling is that SLF4J and in general the boot strap initialization is fundamentally flawed in Java because of the plethora of libraries that do static initialization. I have been meaning to blog about this for sometime. The reason is simple. Bootstrap configuration should load before logging but that is not the case.

In a large application it can be very difficult to control what boots up and the overall order of things being initialized particularly with SL4J, configuration frameworks like commons-configuration (archaius) and DI frameworks like Spring and Guice.

I understand that SLF4Js binding method is a static dependency to enable the very small case of Java JIT elision of method calls when using the NOOP logger.

But that is such a small case. If you have a library that is extremely hi performance do not use SLF4J for god sakes.

The reality is most large application projects should really create their own SLF4J binding so that they can control the initialization process particularly if you use a networking logging infrastructure such as AMQP. And this is fairly annoying because you will have to copy and paste the bridge library (ie because of the static nature it is impossibly to intercept the logging framework).

SLF4J should really do its binding dynamically (one option would be to use java.util.ServiceLoader). This is so that you could wrap and load existing bridges with out essentially having to copy and paste existing bridges.

Overall I would say if you have either a hi performance library, networking library, configuration library, or any other low level library please do not link to SLF4J. It is trivial to make your own one class logger that either uses system properties or what not to do its dispatching.

Some example libraries that do this correctly are the Kryo serializer, RESTEasy, and Tomcat (although flawed Tomcat does try).

Spring and most Apache projects some of the worse because they rely on Commons logging and the use static loggers on initialization (commons-config and most of Spring).

Caches:

https://web.archive.org/web/20160505153552/http://www.russet...

http://webcache.googleusercontent.com/search?q=cache:9BEl9sv...

ty!

I really wish Java developers would just use java.util.logging and be done with it.

That's an all-or-nothing solution. As third-party libraries often use alternative loggers, and java.util.logging cannot be substituted on the classpath (because of the java.* namespace), then using JUL locks consumers out of using their own logging facade as it cannot be bridged to SLF4J.

java.util.logging can be bridged into SLF4J using the jul-to-slf4j bridge.

I really wish java.util.logging was good enough to just use and be done with it. But it isn't.

I always found SLF4J's reasoning quite simple and logical and not at all an example of "those situations which show that software is difficult, and that often there are only compromises".

I think the core problem in this case is that the author is not clear if they are writing a library or a (command line) application.

The following workflow has always worked well for me:

1) Do you expect users of your project to use it by putting it in their classpath and calling its methods from their code? Then it's a library. You have no idea what else will be on the classpath and which context your library will be loaded in. (In fact, the user might not even be aware they are using your library thanks to transitive dependencies)

Libraries should never (if they can avoid it in any way) modify application-wide settings. So: Don't include any logger implementation at all, especially not the nop logger. (Please. Seriously. I've had to deal with misbehaving libraries in that regard and finding out why your logger settings are suddenly overwritten is a serious PITA.)

2) Do you expect your project to be used as a command line/standalone utility via java -jar ... or java -cp ...? Then you're writing an application. Do include a logger implementation and all necessary configuration. You can do it safely here as no one else should be using your project as a dependency.

3) Your project is a mix of 1) and 2) : Find out which parts of your project are library and which are application and split into sub-projects accordingly.

There are a few special cases I see, but not many:

4) You're writing unit tests for a library project: Do include a logger implementation, but make sure it's only visible to the test system. E.g., in Maven, you would add the logger implementation as a test-scoped dependency and put all configuration in src/test/resources.

5) You're writing a plugin/servlet/etc: Read up on your host system and find out if they provide logging or if it's your responsibillity. Proceed accordingly.

6) You're not using SLF4J but one of your dependencies does and so you get that message: Think about using SLF4J in your own project. Really. It's becoming almost a standard and usually you can keep using your old logging framework below it - but it will make things much easier later on. But if you don't want to, for some reason... 6a) If you're writing a library: Don't do anything at all. Do not include any logger implementation. See 1). The user of your library will be in a much better position to deal with the problem than you are. 6b) If you're writing an application: Include the slf4j-xxx implementation that corresponds to your logging framework: The log events from your dependency will be routed to the logging framework you're using and you can continue like you did before. If you're very certain you don't want any logging from any library using SLF4J, use the nop logger - however that is a very unusual case and a very inflexible solution.

It's a set of clojure code that I expect people to use in an interactive shell by, yes, calling methods. Whether people do that within an IDE, directly at a REPL or by running a script is up to them.

I'm still not understanding why I should perform major surgery on my tool for the sake of a logging library which is a transitive dependency.

Nor am I understanding why I should pass the error message that confused me on to downstream users. I'm happy to make the decision rather than sit on the fence.

My point is that "not passing on the error message" could make life harder for downstream users too, depending on who those users are. (Sorry if my reply was arrogant or harsh - I got burned by this in the past, that's why I'm telling it)

If you're developing a project and use SLF4J by yourself, and use a third-party-dependency that already includes a logger implementation, this dependency can override your logging and cause all sorts of havoc. This can be a frustrating and hard to find bug.

(I'd say the fact that this can happen at all is a design flaw in it's own, partly caused by Maven's way of dependency resolution, partly by SLF4J. But I don't see that changing in the near future...)

I think it's important to consider how your project will be used. if it's really just for exploratory use in a REPL/a few scripts, then including a logger is fine. If you think this project could be used in larger projects, you should consider leaving it as it is or restructuring.

If you do include a logger, leave a note about it in the documentation. This way, users can at least exclude it again if they have to.

The logging in java is supper idiotic. This is because everyone agrees that Java's logging is shit.

So every library uses something else. I have a small project and have 4 logging systems (that I had to integrate).

ps: if you are a business person and have an option on this, I don't care for it regardless of your pov.

Yeah, it's the exact situation described in that XKCD: "There are 14 competing standards! Let's create one that is perfect for everyone's use-case!" "There are 15 competing standards..."

https://xkcd.com/927/

And, as you noticed, pretty much every Java project will reach a point where it has to deal with all four-ish of the major logging frameworks. Some module, somewhere, will include an Apache dependency and then you get JCL, and some other purist will insist on java.util.logging and away you go.

With that said, it really isn't that bad to fix. You can use the SLF4J bridge modules and dump all 4 of the logging systems to a single output system. This doesn't actually have to be via SLF4J either - there are modules to dump SLF4J out to JCL or JUL or whatever.

http://www.slf4j.org/legacy.html

This is one of those things about Java that's annoying as hell to get set up, but you plug through it for an hour and then you never need to touch it again. And the next time you can crib from your working build and 99% of it will be the same.

I like to imagine that particular XKCD was written with Java logging in mind.

I doubt that you have used the SLF4J bridge in any realsitic situation, else you would not say that it works.

I have and it works fine.

I don't believe you.

Even the docs say it does not work w/ multiple loggers. But I'm not here to teach, good luck.

You're quite simply wrong - the docs do not say that anywhere.

What they do say is that you are not allowed to route loggers circularly - if you route (for example) JUL through SLF4J, you are not allowed to route that output back to JUL, otherwise messages would never be dumped to output.

That's why I said that you have not used it in anger in production environments. Anyway, good luck.

Yes, this is exactly right. What a fucking nightmare. Every time I need to set up java logging for a new project, update a project, revisit an old project, I am dragged back to logging configuration hell.

Which logging package do I use? What is the logging config file called and where do I put it? How do I specify it? What do I do if different packages use different packages? A logging layer on TOP of other logging packages only makes things worse.

I'm sure many Java people remember the XML library hell. Each time you integrated another package that relied on XML configuration, you had to be sure to have the right version of the xerces library. Except that XML was simpler because XML itself didn't change that much. Logging is much worse.

To go on an even longer rant: Everything has become so fractured and distributed in the name of good modularity. Except that the interfaces are underspecified, or if adequately specified, they keep wiggling around. And good luck finding documentation to help you configure. It's got to match your version of every component, or you will likely fail. I am working on a project involving jetty, a Postgres database, a JDBC connection pool, and a logging system. Absolutely conventional stuff. I spent a couple of DAYS trying to do things the right way, doing XML config of everything. I absolutely could not make it work. I finally wrote my own trivial connection pool and configured everything in code. Took half an hour, done. I don't care that I can't swap out my logging system at runtime. That's a stupid thing to do anyway. When I need to change my connection pool, I will modify my code configuring it and re-deploy. The slightly improved flexibility is just not worth the fragility and maintenance headaches of doing things the "right" way.

It's even more fun when your project uses native libraries, with their own logging, that you can't seem to override at all. (Looking at Mesos, right now.)

So how does state-of-the-art logging work these days?

Well if you really want to talk to "state-of-the-art" the closest would be the principle of "12-factor application." So basically everything goes through stdout and stderr, and the dameon running the server (like monit or supervisord) just captures them and redirect to a stdout file and a stderr file.

Not hard, just so many people including myself is used to writing logger....

If your libs use multiple loggers, then you are SOL.

I do not think Java is the only outlier here. In general library authors should never force a logger to write to anything. It should be a do-nothing logger. It should provide a configuration so logs are going through the application utilizing the library. If I am wrong interpreting your comment, let me know.

[1]: http://docs.python-guide.org/en/latest/writing/logging/#logg...

Yup. This is the best that I've found:

(Gradle dependencies format)

compile group: 'ch.qos.logback:logback-classic:1.1.3'

compile group: 'org.slf4j:jcl-over-slf4j:1.7.12'

compile group: 'org.slf4j:jul-to-slf4j:1.7.12'

compile group: 'org.slf4j:log4j-over-slf4j:1.7.12'

At least you only need to configure one logging subsystem then.

slf4j API should be in the compile group. At minimum, logback-classic should be runtime, as should jul-to-slf4j.

Good points. This config is from an app - not a library.

Archive.org cached version: https://web.archive.org/web/20160505153552/http://www.russet...

Reply on news.ycombinator.com