Possible bug in Book of Vaadin: static loggers in section 11.

[Bobby (Bobby Bissett)]

Hi all,

From
this thread
, I saw in
section 11.13 of the Book of Vaadin
, that you recommend loggers be declared static. It’s my understanding that this leads directly to memory leaks, though it’s not a well-known issue. It’s hard for me to find a good reference about this now, but here’s one page that talks about a similar issue (in this example the leak is through Level and not Logger):

https://blogs.oracle.com/fkieviet/entry/classloader_leaks_the_dreaded_java

(Frantic searching…) Oh, here’s another one, but it talks about a slightly different issue:

http://wiki.apache.org/commons/Logging/StaticLog

I used to have this one great article about it, but of course I can’t find it now. Grrr. Anyway…

There’s no problem with declaring some random object static in a class in a web/EE app
as long as the container does not also have a handle to that object
. With a logger obtained from Logger.getLogger(“example”), your class’ classloader has a handle to that logger, and so does the JVM through a map of weak references. So when the application is undeployed, the instances of the class go away but the classloader cannot be garbage collected because it has a non-weak reference to an object that can’t be GC’ed itself. Someone on the Sun JDK told me a couple years ago that this would be fixed in Java 7, but I don’t know anything else about that. (To be completely honest, I can’t explain now why this is different from instances having non-static references, but that may be that it’s Friday.)

The simple fix is to not declare loggers as static. I’ve read many places online that this means you’re creating lots of loggers, but that’s simply not true. Logger.getLogger(String) only creates one logger for each name, and returns a reference to it whenever you call getLogger(). Sure, there’s a very slight hit for the map lookup, but that’s trivial compared to running into
the root of all evil
(I’m referring to his quote, not the person!).

At least, this is my memory of the problem. I wish I could find some better references on it, but I remember this from my days working on the GlassFish team, and the consensus was that it’s ok for the container to use static loggers, but the applications never should. You’ll have to go through a lot of deployment cycles probably to run into the memory issue, but it’s simple enough to avoid the issue. From my experience, most code out there does this wrong, but it works fine up to a point. Then you restart the server…

Cheers,
Bobby

p.s. I suppose maybe, possibly, you could use a static weak reference to a logger in your code, but that’s just silly.

[Marko1 (Marko Grönroos)]

Hi Bobby,

This certainly looks like an interesting issue. I’ll change the recommendation in the book to be non-static and add some explanation, such as:

            Having static logger instances, that is, one for each class, rather than one for every class instance, would save a bit of memory and time. However, it could cause the application to leak PermGen memory with some application servers when redeploying the application. The problem is that Logger library maintains references to its instances. As the library could be loaded with a classloader with a scope wider than the application, the references to classes loaded with a per-application classloader would prevent garbage-collecting them after redeploying, hence leaking memory. As the size of the PermGen memory where class object are stored is fixed, the leakage will lead to a server crash after many redeployments. The issue depends on the way how the server manages classloaders. 

Well, I don’t know if that detailed explanation is necessary.

I’m just wondering, how probable this problem is? Is it common or only in some servers? I understood that it only occurs
if
the server uses a shared classloader to load logging libraries. It sounds rather odd that the issue would occur also with a logging library included in the web app itself.

[Bobby (Bobby Bissett)]

Hi again Marko,

Even as I wrote the section above, the part about the weak references didn’t sit right with me (even though I’ve “known” this to be a problem). I did some testing over the weekend, and after a few thousand deploy/access/undeploy cycles with some test apps and jconsole, I don’t think the weak reference from java.util.logging.Logger is a problem, unlike the
strong reference from Level
. So the Java logger isn’t an issue – sorry about that. Though it looks like
things could change in JDK 7
and then it’s a problem.

With other loggers, the leak can be a problem, but it’s really not a large one. For other loggers, there
isn’t a clear recommendation one way or the other
.

So I’m starting to think you should leave the example as it is, but with some explanatory text that, with some loggers and some containers, there
could
be a problem with configuration or memory leaks. If someone Googles “static loggers” then that’s more info than you’d ever want. One issue with the tutorial is that, if the logger isn’t declared static, then it needs to be declared transient since all Vaadin application components are (or should be) serializable. That means someone needs to make sure the logger isn’t null in case an object is deserialized. I think that’s more than you want to get into in the logging section. It’s fairly easy to put all that in one helper class and have other classes get the loggers as needed, but it’s overkill for the tutorial. (Personally, I tend to use method-scoped loggers since the map lookup is not really a performance bottleneck.)

@Marko Grönroos

I’m just wondering, how probable this problem is? Is it common or only in some servers? I understood that it only occurs
if
the server uses a shared classloader to load logging libraries. It sounds rather odd that the issue would occur also with a logging library included in the web app itself.

I’m only familiar with the java.util.logger case, and even if you go out of your way to force a leak, it’s only a problem after a large number of deployment cycles. I don’t know of a server that doesn’t use a new classloader for a deployed application, and I suspect that would break some rules in the EE spec if you did it. Though who knows what’s possible with OSGi.

Like you said, if a web app completely contains its own logging facility, then I’m not sure what the problem could be. There must be some shared information, maybe something at the System level, in the loggers I read about that said they could have configuration issues across applications.

So, reversing myself (sorry), what do you think about leaving the code sample as it is and adding text that there could be issues and the user should read the documentation for the logging facility that she or he is using?

Causing more than my share of trouble,
Bobby

p.s. I wanted to test for myself that new java.util loggers really
aren’t
created when two separate applications call Logger.getLogger(“somename”), and found that you do get exactly the same object, shared among separate apps. For
April 1st
, I should write a blog about using the logging facility instead of JMS for communicating information between deployed applications. You can create arbitrarily-named loggers, so the logger name would be the property and the logging level would be the data. Heh heh.

[Marko1 (Marko Grönroos)]

Ok, the recommendation is now static as it was before, but I added a note about the possible PermGen leakage issue.

Looks like I had misunderstood the basic things about how the Logger works. I had imagined that it would be much thinner and that the problematic references would be in a third-party implementation JAR that could be included in the WAR, but it is in the Java platform lib after all. So, according to the Servlet spec, it always gets loaded with a shared classloader.