You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Nick Williams <ni...@nicholaswilliams.net> on 2013/05/19 06:57:31 UTC

LOG4J2-223: IllegalStateException thrown during Tomcat shutdown (memory leak, it looks like)

Can one of the very knowledgeable developers that have been discussing memory leaks in the last few days (re: Possible false-postive with JreMemoryLeakPreventionListener and Tomcat's JDBC Pool and OracleTimeoutPollingThread) chime in on this Log4j 2 bug [1]?

Log4j 2 appears to be registering a shutdown hook that, I believe, will result in a memory leak in Tomcat. The JreMemoryLeakPreventionListener does not detect it (which might be a separate Tomcat bug, assuming I'm right that it's a memory leak). I don't know nearly as much about class loaders and memory leaks in a web application as some of the guys I've read talking on here the last few days, and it would be helpful for us to get the knowledgeable opinion of one or more Tomcat developers about how to solve this.

Thanks,

Nick

[1] https://issues.apache.org/jira/browse/LOG4J2-223

(Note: I don't normally post to both lists, but since the memory leak topic was occurring on the user's list, and I also wanted to get the attention of as many developers as possible, I made an exception this time.)

Re: LOG4J2-223: IllegalStateException thrown during Tomcat shutdown (memory leak, it looks like)

Posted by Mark Eggers <it...@yahoo.com>.
On 5/20/2013 2:45 PM, Nick Williams wrote:
>
> On May 20, 2013, at 4:39 PM, Christopher Schultz wrote:
>
>> -----BEGIN PGP SIGNED MESSAGE----- Hash: SHA256
>>
>> Nick,
>>
>> On 5/20/13 4:10 PM, Nick Williams wrote:
>>>
>>> On May 20, 2013, at 2:59 PM, Christopher Schultz wrote:
>>>
>>>> -----BEGIN PGP SIGNED MESSAGE----- Hash: SHA256
>>>>
>>>> Nick,
>>>>
>>>> On 5/20/13 12:48 PM, Nick Williams wrote:
>>>>>
>>>>> On May 20, 2013, at 10:56 AM, Christopher Schultz wrote:
>>>>>
>>>>>> -----BEGIN PGP SIGNED MESSAGE----- Hash: SHA256
>>>>>>
>>>>>> Nick,
>>>>>>
>>>>>> On 5/19/13 11:25 AM, Nick Williams wrote:
>>>>>>> Unfortunately, requiring users to call System.gc()
>>>>>>> before shutdown for logging to work properly is no better
>>>>>>> than requiring users to register a listener in a web
>>>>>>> application for logging to work properly. Surely there's
>>>>>>> a better way...
>>>>>>
>>>>>> Do you initialize your logging system in a
>>>>>> ServletContextListener (or similar)? If so, then you
>>>>>> should destroy it at the same level.
>>>>>>
>>>>>> If you aren't initializing your logging system in a
>>>>>> ServletContextListener... then how are you initializing
>>>>>> it?
>>>>>>
>>>>>> Long ago, I abandoned log4j's auto-initialization
>>>>>> primarily because it sometimes guesses wrong.
>>>>>
>>>>> First, remember that this is Log4j 2, so things are
>>>>> obviously different.
>>>>
>>>> It's different, but it's the same.
>>>>
>>>>> Log4j initializes with the first call to
>>>>> LogManager#getLogger(), whenever that occurs. In my case
>>>>> loggers are static, so it happens when the classes are
>>>>> initialized. In the specific case of the replication project
>>>>> attached to the issue, it happens on the first request to
>>>>> the only Servlet in the application.
>>>>
>>>> Right. What I'm saying is that you should take full control
>>>> over the initialization (and destruction) of the logging
>>>> system. Your ServletContextListeners should be invoked before
>>>> your servlet classes are loader.
>>>
>>> And I'm saying you shouldn't /have/ to. It should "just work"
>>> without you having to do much thinking. See below.
>>>
>>>>
>>>>> Unfortunately, I've just about given up on it being possible
>>>>> to make logging work "right" without a
>>>>> ServletContextListener. Man oh man did I want to avoid
>>>>> that...
>>>>
>>>> You act like a ServletContextListener is some evil hack that
>>>> should be avoided at all costs. Instead, it's exactly the
>>>> right mechanism to do what you are trying to do: configure
>>>> something at webapp launch and de-configure it when the webapp
>>>> is stopped.
>>>
>>> Not what I'm saying at all. I love listeners. They are extremely
>>> helpful, and I use them all the time.
>>>
>>> What I'm saying is that the concept of logging, philosophically,
>>> is supposed to be as unobtrusive as possible. Something you
>>> don't really have to think about how exactly it works; you just
>>> know to get a logger and put logging statements in your code and
>>> things "just work." The act of having to set up a listener to
>>> initialize and deinitialize logging, to me, seems like more than
>>> Log4j users should have to worry about. Perhaps just as
>>> importantly, Log4j 1 worked without a listener to
>>> initialize/deinitialize, so this is yet again one more thing
>>> users are going to have to do to switch from Log4j 1 to Log4j 2.
>>
>> That's like saying that aspect-oriented programming should "just
>> work" without having to run the AOP compiler against the code,
>> first.
>>
>> This at least used to be a problem in log4j 1 as well: you had to
>> call LogManager.shutdown in order to free all the resources, flush
>> all the buffers, etc. when your webapp unloaded, otherwise you ran
>> the risk of pinning the old webapp's ClassLoader, etc. in memory.
>> The only way to run LogManager.shutdown() on webapp unload is to
>> configure a ServletContextListener.
>>
>>> Thankfully, we can use web-fragments in Servlet 3.0 and higher
>>> to configure the listener behind-the-scenes without the user
>>> even knowing. That's much more acceptable in my book.
>>
>> While I agree, it increases the amount of "magic" that I generally
>> prefer to keep to a minimum. I know I'm apparently an old guy who
>> just doesn't get it, but I honestly prefer explicit configuration
>> to auto-configuration. You can diagnose problems much more easily
>> with explicit configuration than by attaching a debugger and
>> stepping-through the entire bootstrap process to figure out wtf is
>> going on.
>>
>>> Users of Servlet 2.5 will still have to declare them manually,
>>> but I think they will probably be the minority users.
>>
>> Ha ha ha. Don't you see the posts from people trying to figure out
>> how to move their Tomcat 3.x installations to a new Windows 2000
>> server? Again, I'm a apparently a dinosaur, but I don't have a
>> single servlet-3.0 webapp deployed in production anywhere. Not even
>> in testing.
>
> Oh, I see the posts. I just figure if they're that far behind they
> won't be using Log4j 2 for at least another 10 years.
>
> Nick
>

Hopefully sometime this year (currently porting one of those types of 
applications).

I do have a Maven artifact with some utility listeners that I make use 
of (including a log4j listener). I just add the dependency, modify the 
web.xml accordingly, and I'm good to go.

Yes, annotations would make things a little less cumbersome. However, I 
still like seeing everything. Maybe once I get a bit more comfortable 
with servlet spec 3.0, I'll rely on logEffectiveWebXml in Tomcat's 
context.xml to troubleshoot rather than seeing the configuration explicitly.

I'm not sure how you would produce this in other servelt containers or 
servers, though.

. . . just my two cents.
/mde/

>>
>>> So with a little more polishing of the Log4j 2 source code we
>>> can make this a little better. I just wish there was a solution
>>> that would work for both standalone applications /and/ web
>>> applications to initialize and deinitialize Log4j correctly
>>> without any users (including Servlet 2.5 users) having to think
>>> about it.
>>
>> The solution is to have a magic annotation-processor running all
>> the time in the JVM, right? Isn't that what OSGi is for?
>>
>> - -chris
>
> ---------------------------------------------------------------------
>
>
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
>


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: LOG4J2-223: IllegalStateException thrown during Tomcat shutdown (memory leak, it looks like)

Posted by Nick Williams <ni...@nicholaswilliams.net>.
On May 20, 2013, at 4:39 PM, Christopher Schultz wrote:

> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA256
> 
> Nick,
> 
> On 5/20/13 4:10 PM, Nick Williams wrote:
>> 
>> On May 20, 2013, at 2:59 PM, Christopher Schultz wrote:
>> 
>>> -----BEGIN PGP SIGNED MESSAGE----- Hash: SHA256
>>> 
>>> Nick,
>>> 
>>> On 5/20/13 12:48 PM, Nick Williams wrote:
>>>> 
>>>> On May 20, 2013, at 10:56 AM, Christopher Schultz wrote:
>>>> 
>>>>> -----BEGIN PGP SIGNED MESSAGE----- Hash: SHA256
>>>>> 
>>>>> Nick,
>>>>> 
>>>>> On 5/19/13 11:25 AM, Nick Williams wrote:
>>>>>> Unfortunately, requiring users to call System.gc() before 
>>>>>> shutdown for logging to work properly is no better than 
>>>>>> requiring users to register a listener in a web
>>>>>> application for logging to work properly. Surely there's a
>>>>>> better way...
>>>>> 
>>>>> Do you initialize your logging system in a 
>>>>> ServletContextListener (or similar)? If so, then you should 
>>>>> destroy it at the same level.
>>>>> 
>>>>> If you aren't initializing your logging system in a 
>>>>> ServletContextListener... then how are you initializing it?
>>>>> 
>>>>> Long ago, I abandoned log4j's auto-initialization primarily 
>>>>> because it sometimes guesses wrong.
>>>> 
>>>> First, remember that this is Log4j 2, so things are obviously 
>>>> different.
>>> 
>>> It's different, but it's the same.
>>> 
>>>> Log4j initializes with the first call to
>>>> LogManager#getLogger(), whenever that occurs. In my case
>>>> loggers are static, so it happens when the classes are
>>>> initialized. In the specific case of the replication project
>>>> attached to the issue, it happens on the first request to the
>>>> only Servlet in the application.
>>> 
>>> Right. What I'm saying is that you should take full control over 
>>> the initialization (and destruction) of the logging system. Your
>>> ServletContextListeners should be invoked before your servlet 
>>> classes are loader.
>> 
>> And I'm saying you shouldn't /have/ to. It should "just work"
>> without you having to do much thinking. See below.
>> 
>>> 
>>>> Unfortunately, I've just about given up on it being possible to
>>>> make logging work "right" without a ServletContextListener.
>>>> Man oh man did I want to avoid that...
>>> 
>>> You act like a ServletContextListener is some evil hack that
>>> should be avoided at all costs. Instead, it's exactly the right
>>> mechanism to do what you are trying to do: configure something at
>>> webapp launch and de-configure it when the webapp is stopped.
>> 
>> Not what I'm saying at all. I love listeners. They are extremely 
>> helpful, and I use them all the time.
>> 
>> What I'm saying is that the concept of logging, philosophically,
>> is supposed to be as unobtrusive as possible. Something you don't
>> really have to think about how exactly it works; you just know to
>> get a logger and put logging statements in your code and things
>> "just work." The act of having to set up a listener to initialize
>> and deinitialize logging, to me, seems like more than Log4j users
>> should have to worry about. Perhaps just as importantly, Log4j 1
>> worked without a listener to initialize/deinitialize, so this is
>> yet again one more thing users are going to have to do to switch
>> from Log4j 1 to Log4j 2.
> 
> That's like saying that aspect-oriented programming should "just work"
> without having to run the AOP compiler against the code, first.
> 
> This at least used to be a problem in log4j 1 as well: you had to call
> LogManager.shutdown in order to free all the resources, flush all the
> buffers, etc. when your webapp unloaded, otherwise you ran the risk of
> pinning the old webapp's ClassLoader, etc. in memory. The only way to
> run LogManager.shutdown() on webapp unload is to configure a
> ServletContextListener.
> 
>> Thankfully, we can use web-fragments in Servlet 3.0 and higher to 
>> configure the listener behind-the-scenes without the user even 
>> knowing. That's much more acceptable in my book.
> 
> While I agree, it increases the amount of "magic" that I generally
> prefer to keep to a minimum. I know I'm apparently an old guy who just
> doesn't get it, but I honestly prefer explicit configuration to
> auto-configuration. You can diagnose problems much more easily with
> explicit configuration than by attaching a debugger and
> stepping-through the entire bootstrap process to figure out wtf is
> going on.
> 
>> Users of Servlet 2.5 will still have to declare them manually, but
>> I think they will probably be the minority users.
> 
> Ha ha ha. Don't you see the posts from people trying to figure out how
> to move their Tomcat 3.x installations to a new Windows 2000 server?
> Again, I'm a apparently a dinosaur, but I don't have a single
> servlet-3.0 webapp deployed in production anywhere. Not even in testing.

Oh, I see the posts. I just figure if they're that far behind they won't be using Log4j 2 for at least another 10 years.

Nick

> 
>> So with a little more polishing of the Log4j 2 source code we can 
>> make this a little better. I just wish there was a solution that 
>> would work for both standalone applications /and/ web applications
>> to initialize and deinitialize Log4j correctly without any users 
>> (including Servlet 2.5 users) having to think about it.
> 
> The solution is to have a magic annotation-processor running all the
> time in the JVM, right? Isn't that what OSGi is for?
> 
> - -chris

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: LOG4J2-223: IllegalStateException thrown during Tomcat shutdown (memory leak, it looks like)

Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Nick,

On 5/20/13 4:10 PM, Nick Williams wrote:
> 
> On May 20, 2013, at 2:59 PM, Christopher Schultz wrote:
> 
>> -----BEGIN PGP SIGNED MESSAGE----- Hash: SHA256
>> 
>> Nick,
>> 
>> On 5/20/13 12:48 PM, Nick Williams wrote:
>>> 
>>> On May 20, 2013, at 10:56 AM, Christopher Schultz wrote:
>>> 
>>>> -----BEGIN PGP SIGNED MESSAGE----- Hash: SHA256
>>>> 
>>>> Nick,
>>>> 
>>>> On 5/19/13 11:25 AM, Nick Williams wrote:
>>>>> Unfortunately, requiring users to call System.gc() before 
>>>>> shutdown for logging to work properly is no better than 
>>>>> requiring users to register a listener in a web
>>>>> application for logging to work properly. Surely there's a
>>>>> better way...
>>>> 
>>>> Do you initialize your logging system in a 
>>>> ServletContextListener (or similar)? If so, then you should 
>>>> destroy it at the same level.
>>>> 
>>>> If you aren't initializing your logging system in a 
>>>> ServletContextListener... then how are you initializing it?
>>>> 
>>>> Long ago, I abandoned log4j's auto-initialization primarily 
>>>> because it sometimes guesses wrong.
>>> 
>>> First, remember that this is Log4j 2, so things are obviously 
>>> different.
>> 
>> It's different, but it's the same.
>> 
>>> Log4j initializes with the first call to
>>> LogManager#getLogger(), whenever that occurs. In my case
>>> loggers are static, so it happens when the classes are
>>> initialized. In the specific case of the replication project
>>> attached to the issue, it happens on the first request to the
>>> only Servlet in the application.
>> 
>> Right. What I'm saying is that you should take full control over 
>> the initialization (and destruction) of the logging system. Your
>>  ServletContextListeners should be invoked before your servlet 
>> classes are loader.
> 
> And I'm saying you shouldn't /have/ to. It should "just work"
> without you having to do much thinking. See below.
> 
>> 
>>> Unfortunately, I've just about given up on it being possible to
>>>  make logging work "right" without a ServletContextListener.
>>> Man oh man did I want to avoid that...
>> 
>> You act like a ServletContextListener is some evil hack that
>> should be avoided at all costs. Instead, it's exactly the right
>> mechanism to do what you are trying to do: configure something at
>> webapp launch and de-configure it when the webapp is stopped.
> 
> Not what I'm saying at all. I love listeners. They are extremely 
> helpful, and I use them all the time.
> 
> What I'm saying is that the concept of logging, philosophically,
> is supposed to be as unobtrusive as possible. Something you don't
> really have to think about how exactly it works; you just know to
> get a logger and put logging statements in your code and things
> "just work." The act of having to set up a listener to initialize
> and deinitialize logging, to me, seems like more than Log4j users
> should have to worry about. Perhaps just as importantly, Log4j 1
> worked without a listener to initialize/deinitialize, so this is
> yet again one more thing users are going to have to do to switch
> from Log4j 1 to Log4j 2.

That's like saying that aspect-oriented programming should "just work"
without having to run the AOP compiler against the code, first.

This at least used to be a problem in log4j 1 as well: you had to call
LogManager.shutdown in order to free all the resources, flush all the
buffers, etc. when your webapp unloaded, otherwise you ran the risk of
pinning the old webapp's ClassLoader, etc. in memory. The only way to
run LogManager.shutdown() on webapp unload is to configure a
ServletContextListener.

> Thankfully, we can use web-fragments in Servlet 3.0 and higher to 
> configure the listener behind-the-scenes without the user even 
> knowing. That's much more acceptable in my book.

While I agree, it increases the amount of "magic" that I generally
prefer to keep to a minimum. I know I'm apparently an old guy who just
doesn't get it, but I honestly prefer explicit configuration to
auto-configuration. You can diagnose problems much more easily with
explicit configuration than by attaching a debugger and
stepping-through the entire bootstrap process to figure out wtf is
going on.

> Users of Servlet 2.5 will still have to declare them manually, but
> I think they will probably be the minority users.

Ha ha ha. Don't you see the posts from people trying to figure out how
to move their Tomcat 3.x installations to a new Windows 2000 server?
Again, I'm a apparently a dinosaur, but I don't have a single
servlet-3.0 webapp deployed in production anywhere. Not even in testing.

> So with a little more polishing of the Log4j 2 source code we can 
> make this a little better. I just wish there was a solution that 
> would work for both standalone applications /and/ web applications
> to initialize and deinitialize Log4j correctly without any users 
> (including Servlet 2.5 users) having to think about it.

The solution is to have a magic annotation-processor running all the
time in the JVM, right? Isn't that what OSGi is for?

- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG/MacGPG2 v2.0.17 (Darwin)
Comment: GPGTools - http://gpgtools.org
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQIcBAEBCAAGBQJRmpggAAoJEBzwKT+lPKRYQ24P/iPvZkN/WQIgYWCOHKFyLvFx
Kjs6CfgW04AV/I4xHG/BvN8v/tAI03bAj8d1jaHNr8hkkhc9lWrp/pMG9Vx5jBLn
wMm8a17QYbotyUZnd1XmYVGDyGSrsh/XTL1DmFZv+lih9HMMVqxCjklvLtvpdoXR
NuCJlO0dyHdQa/tLw7QGe71JAWzNvmcWWe0n3znNk0RKFe3r94IohxVg/IqTA3dB
Zd55qTovpkDWD8FWOGuCvY7v/bkqRmz/xp12KQ+AWrX6GBUiaMLmkAAYrcmeXD1e
C+PFx1+VOCDu6a6tPkBI1gVa85cfhTqcZCtCm5i/3s95z3F5twUb31UdfkQIJh7K
2HhofaYT6EcCYmAaEREYWTogdRNNe/9YYaSzOIgBI9SzUP3uMFzcQ9gOu9doIQkg
HETOyFJsJ2rpM6P52XLvNwRmuHeoXcFznL/VhIwwfGjhjAl1uGdwVbSYsCRHFP7c
nuH+4FtC2PE1oQRm4nuu3E1wC6RWCxTZvlijcuve1qsh2csh4JgkKShiml8YqjNI
mljpqBjIvAON7fDssEDjuFsdN5/TxvvY7R94Ezw+c/UaoXi2SAd0x7eJA2GIziPg
pbIoAHN+Ux4xfAoU0vmBbV0bljhZNqEZTKrRK4y8o9NL2z3uGMT+/fNWpJweegB8
3GgxKah7JttN7hpjItm9
=zpE/
-----END PGP SIGNATURE-----

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: LOG4J2-223: IllegalStateException thrown during Tomcat shutdown (memory leak, it looks like)

Posted by Nick Williams <ni...@nicholaswilliams.net>.
On May 20, 2013, at 2:59 PM, Christopher Schultz wrote:

> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA256
> 
> Nick,
> 
> On 5/20/13 12:48 PM, Nick Williams wrote:
>> 
>> On May 20, 2013, at 10:56 AM, Christopher Schultz wrote:
>> 
>>> -----BEGIN PGP SIGNED MESSAGE----- Hash: SHA256
>>> 
>>> Nick,
>>> 
>>> On 5/19/13 11:25 AM, Nick Williams wrote:
>>>> Unfortunately, requiring users to call System.gc() before 
>>>> shutdown for logging to work properly is no better than
>>>> requiring users to register a listener in a web application for
>>>> logging to work properly. Surely there's a better way...
>>> 
>>> Do you initialize your logging system in a
>>> ServletContextListener (or similar)? If so, then you should
>>> destroy it at the same level.
>>> 
>>> If you aren't initializing your logging system in a 
>>> ServletContextListener... then how are you initializing it?
>>> 
>>> Long ago, I abandoned log4j's auto-initialization primarily
>>> because it sometimes guesses wrong.
>> 
>> First, remember that this is Log4j 2, so things are obviously 
>> different.
> 
> It's different, but it's the same.
> 
>> Log4j initializes with the first call to LogManager#getLogger(), 
>> whenever that occurs. In my case loggers are static, so it happens
>> when the classes are initialized. In the specific case of the 
>> replication project attached to the issue, it happens on the first
>> request to the only Servlet in the application.
> 
> Right. What I'm saying is that you should take full control over the
> initialization (and destruction) of the logging system. Your
> ServletContextListeners should be invoked before your servlet classes
> are loader.

And I'm saying you shouldn't /have/ to. It should "just work" without you having to do much thinking. See below.

> 
>> Unfortunately, I've just about given up on it being possible to
>> make logging work "right" without a ServletContextListener. Man oh
>> man did I want to avoid that...
> 
> You act like a ServletContextListener is some evil hack that should be
> avoided at all costs. Instead, it's exactly the right mechanism to do
> what you are trying to do: configure something at webapp launch and
> de-configure it when the webapp is stopped.

Not what I'm saying at all. I love listeners. They are extremely helpful, and I use them all the time.

What I'm saying is that the concept of logging, philosophically, is supposed to be as unobtrusive as possible. Something you don't really have to think about how exactly it works; you just know to get a logger and put logging statements in your code and things "just work." The act of having to set up a listener to initialize and deinitialize logging, to me, seems like more than Log4j users should have to worry about. Perhaps just as importantly, Log4j 1 worked without a listener to initialize/deinitialize, so this is yet again one more thing users are going to have to do to switch from Log4j 1 to Log4j 2.

Thankfully, we can use web-fragments in Servlet 3.0 and higher to configure the listener behind-the-scenes without the user even knowing. That's much more acceptable in my book. Users of Servlet 2.5 will still have to declare them manually, but I think they will probably be the minority users. So with a little more polishing of the Log4j 2 source code we can make this a little better. I just wish there was a solution that would work for both standalone applications /and/ web applications to initialize and deinitialize Log4j correctly without any users (including Servlet 2.5 users) having to think about it.

Nick
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: LOG4J2-223: IllegalStateException thrown during Tomcat shutdown (memory leak, it looks like)

Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Nick,

On 5/20/13 12:48 PM, Nick Williams wrote:
> 
> On May 20, 2013, at 10:56 AM, Christopher Schultz wrote:
> 
>> -----BEGIN PGP SIGNED MESSAGE----- Hash: SHA256
>> 
>> Nick,
>> 
>> On 5/19/13 11:25 AM, Nick Williams wrote:
>>> Unfortunately, requiring users to call System.gc() before 
>>> shutdown for logging to work properly is no better than
>>> requiring users to register a listener in a web application for
>>> logging to work properly. Surely there's a better way...
>> 
>> Do you initialize your logging system in a
>> ServletContextListener (or similar)? If so, then you should
>> destroy it at the same level.
>> 
>> If you aren't initializing your logging system in a 
>> ServletContextListener... then how are you initializing it?
>> 
>> Long ago, I abandoned log4j's auto-initialization primarily
>> because it sometimes guesses wrong.
> 
> First, remember that this is Log4j 2, so things are obviously 
> different.

It's different, but it's the same.

> Log4j initializes with the first call to LogManager#getLogger(), 
> whenever that occurs. In my case loggers are static, so it happens
>  when the classes are initialized. In the specific case of the 
> replication project attached to the issue, it happens on the first
>  request to the only Servlet in the application.

Right. What I'm saying is that you should take full control over the
initialization (and destruction) of the logging system. Your
ServletContextListeners should be invoked before your servlet classes
are loader.

> Unfortunately, I've just about given up on it being possible to
> make logging work "right" without a ServletContextListener. Man oh
> man did I want to avoid that...

You act like a ServletContextListener is some evil hack that should be
avoided at all costs. Instead, it's exactly the right mechanism to do
what you are trying to do: configure something at webapp launch and
de-configure it when the webapp is stopped.

Some things just aren't appropriate to do with @Annotations. Sorry.

- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG/MacGPG2 v2.0.17 (Darwin)
Comment: GPGTools - http://gpgtools.org
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQIcBAEBCAAGBQJRmoCoAAoJEBzwKT+lPKRYEkgQALHbPr3SPqsDmIdYWa4Cb2VF
gZubG1MRsupGK2Kqlsq4HDTQMYjM5Twyig8McaVaxmqeUn9pWnSm2VgJCqeP0D8n
kGAsu9LZFoyEqkpO8+6xHwtvkPNCbj3qMrMRuqgXuV11VrlUL4N1q8pMYK3m0c5l
8iytqXUHk7R5MPjwZS4e3zC2jGnMhiIENWwfZa/ulNhmWCpLcC5tIU3Ka1s4VoFT
7S92vWG0CoveGkfVbtl9G9LPrdEYig0PFXeCvALFVE4Ff4rWP/jJiN+fE3GeTBSI
rR4eWpgvHM5BwvgFvSB6dzkaSQJaqX0GV1CJUdR3lvzh6jtRkeAlMzdA7DFFfQD3
pY/J/B+0ZeJzHDLrlYa528NaufA46vbhIr3l/fQqdMO5nHJePzv6bQIUOFu9zcHO
chwXohDvF9rQDAQE1H/DeVuDy7izQqn1k25PbsKDa/Ju86yk4V+ak/AcSzqKIm9o
zPLvHN4v3qPJ5QXElrX8aeXi7HUZEHjsVzvQmWpqpWd1aelNkn6FMSbrF59XpYkh
hTGXYz91gIbpshnwxpE5GQVv/1GwOFICi/HsT54ru0rEKmIDmTu9lu7ByzKp3Idv
U5dxMRUVzx+pJ2hfq2Mcqdy/LbYr9SX1uC3njtwdu2yuWWkbgC/Vnrns1hlDdpw/
+X1XT/+ZnfqzAQ66rger
=w+w1
-----END PGP SIGNATURE-----

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: LOG4J2-223: IllegalStateException thrown during Tomcat shutdown (memory leak, it looks like)

Posted by Nick Williams <ni...@nicholaswilliams.net>.
On May 20, 2013, at 10:56 AM, Christopher Schultz wrote:

> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA256
> 
> Nick,
> 
> On 5/19/13 11:25 AM, Nick Williams wrote:
>> Unfortunately, requiring users to call System.gc() before shutdown
>> for logging to work properly is no better than requiring users to
>> register a listener in a web application for logging to work
>> properly. Surely there's a better way...
> 
> Do you initialize your logging system in a ServletContextListener (or
> similar)? If so, then you should destroy it at the same level.
> 
> If you aren't initializing your logging system in a
> ServletContextListener... then how are you initializing it?
> 
> Long ago, I abandoned log4j's auto-initialization primarily because it
> sometimes guesses wrong.

First, remember that this is Log4j 2, so things are obviously different.

Log4j initializes with the first call to LogManager#getLogger(), whenever that occurs. In my case loggers are static, so it happens when the classes are initialized. In the specific case of the replication project attached to the issue, it happens on the first request to the only Servlet in the application.

Unfortunately, I've just about given up on it being possible to make logging work "right" without a ServletContextListener. Man oh man did I want to avoid that...

Nick
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: LOG4J2-223: IllegalStateException thrown during Tomcat shutdown (memory leak, it looks like)

Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Nick,

On 5/19/13 11:25 AM, Nick Williams wrote:
> Unfortunately, requiring users to call System.gc() before shutdown
> for logging to work properly is no better than requiring users to
> register a listener in a web application for logging to work
> properly. Surely there's a better way...

Do you initialize your logging system in a ServletContextListener (or
similar)? If so, then you should destroy it at the same level.

If you aren't initializing your logging system in a
ServletContextListener... then how are you initializing it?

Long ago, I abandoned log4j's auto-initialization primarily because it
sometimes guesses wrong.

- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG/MacGPG2 v2.0.17 (Darwin)
Comment: GPGTools - http://gpgtools.org
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQIcBAEBCAAGBQJRmkekAAoJEBzwKT+lPKRY6uMP/3P72gxh2/wg3Jw5fNllv5PS
MX2gow3Fr+RnBXELnD/Mdtlq95j87tzKSiRIMT99FMXXHWXUWW9iHvA7ojye+SGd
mKaXJlPQsTGrLH7rRJzXX6CXH7xW2mQ3DEYCLQ/97pktn8SgO324BWz2MvJGGtDx
FwVB+rny0HS1JROADLFgzkLfNRRpnR7uvdUqE6G/vY85sbFBq7tWo6k9s6FdWvev
TqSo0WxbN7goHPcJH5mwcq8MATztRunOTMev6XrG7myqjs/wD5FGOcVyAM01j9qW
QgAwdAVd8z9Gkpw1c8FLb5BXKd6YwfjaS2DxDsojbd0MLHIgaVG8jqL8C4/Tdyxv
8IN9fubTKfWIKzj7uQCNGcXZWuAhAj1GWiK1GADZiuMm9Xj9Pdo1z1gqewoOPYqQ
tJnH69+62AcAU9dr/78Y7NvVqtor+fF49o1qzMqkEzT14x2S0fjhk79SmS3gDlyo
GBInETKqKBLycKpwKplcOoFRlXopXwSCsnpZmcuJQP2j2DuZHzwqoWYK5UgZaidu
xFRdTKmvGdX3UcksUDgxTjUQrtKUsqK1XxlOlHnbLYYuob2K21d6KTnLkDj3Sr+p
I5ZErRUX36j25jafGtDHZUv7dDA0QKA7ygrn4xqh1rSiewfz85NcxvZGCIi6XKV8
OxLz5ev4cxVMBGq4x2MC
=uLGt
-----END PGP SIGNATURE-----

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: LOG4J2-223: IllegalStateException thrown during Tomcat shutdown (memory leak, it looks like)

Posted by Konstantin Kolinko <kn...@gmail.com>.
2013/5/19 Nick Williams <ni...@nicholaswilliams.net>:
>
> On May 19, 2013, at 10:01 AM, Caldarale, Charles R wrote:
>
>>> From: Nick Williams [mailto:nicholas@nicholaswilliams.net]
>>> Subject: Re: LOG4J2-223: IllegalStateException thrown during Tomcat shutdown (memory leak, it looks like)
>>
>>> Log4j 1 never required a listener to be configured to be shut down
>>> properly when an application is undeployed.

It did.
E.g. this discussion is from March 2004:
https://issues.apache.org/bugzilla/show_bug.cgi?id=26372#c2

>>
>> What bearing does that have on a different logging mechanism?
>
> To be fair, Log4j 2 is not a different logging mechanism. It is a new version of Log4j 1. My point was mostly philosophical; it "feels wrong" to have to configure a listener just to support logging.


You can configure the listener from within a library either
a) by providing a javax.servlet.ServletContainerInitializer (starting
with Servlet 3.0) or
b) by configuring it in a TLD file of a tag library (starting with JSP 1.2).


>>
>>> It should be possible to do this without a listener.
>>
>> Not easily.
>>
>>> Could a `finalize` method be used instead of a shutdown hook/listener?
>>
>> Finalizers should be avoided like the plague.  The gyrations the JVM has to go through to handle them result in continual run time impacts, and require at least two GC passes to actually get rid of the objects.
>
> The extra performance impact is bad, yes, when you're talking about an object who has many short-lived instances in memory that could be garbage collected regularly. However, when you're talking about a lone singleton instance that is created when the application starts and garbage collected when the application shuts down, I would argue this is not a problem at all. Of course, I'm open to the idea that I could be proven wrong.
>
>>
>>> What I don't know is if it is guaranteed to be called in non-web applications
>>> when the JVM just shuts down.
>>
>> Finalizers are not called at JVM termination, since the process exit is expected to release resources automatically.  You cannot actually count on a finalizer ever being invoked; it's one of those "seemed like a good idea at the time" things that is now widely regretted by JVM implementers.
>
> After some experimentation, it would appear that it's not so much that finalizers are not called at JVM termination as it is that finalizers are not called if the garbage collector never runs, and the garbage collector isn't guaranteed to run at JVM shutdown.

There exists such API as JVM shutdown hooks. An issue with them though
is that if there are several hooks, then all of them are started at
the same time and run in parallel.

When Tomcat is run with JULI it takes care of JULI shutdown (a)
disables JULI's own shutdown hook via
ClassLoaderLogManager.setUseShutdownHook(false), b) shuts down JULI
from its own shutdown hook thread).

Best regards,
Konstantin Kolinko

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: LOG4J2-223: IllegalStateException thrown during Tomcat shutdown (memory leak, it looks like)

Posted by Nick Williams <ni...@nicholaswilliams.net>.
On May 19, 2013, at 10:01 AM, Caldarale, Charles R wrote:

>> From: Nick Williams [mailto:nicholas@nicholaswilliams.net] 
>> Subject: Re: LOG4J2-223: IllegalStateException thrown during Tomcat shutdown (memory leak, it looks like)
> 
>> Log4j 1 never required a listener to be configured to be shut down 
>> properly when an application is undeployed.
> 
> What bearing does that have on a different logging mechanism?

To be fair, Log4j 2 is not a different logging mechanism. It is a new version of Log4j 1. My point was mostly philosophical; it "feels wrong" to have to configure a listener just to support logging.

> 
>> It should be possible to do this without a listener.
> 
> Not easily.
> 
>> Could a `finalize` method be used instead of a shutdown hook/listener?
> 
> Finalizers should be avoided like the plague.  The gyrations the JVM has to go through to handle them result in continual run time impacts, and require at least two GC passes to actually get rid of the objects.

The extra performance impact is bad, yes, when you're talking about an object who has many short-lived instances in memory that could be garbage collected regularly. However, when you're talking about a lone singleton instance that is created when the application starts and garbage collected when the application shuts down, I would argue this is not a problem at all. Of course, I'm open to the idea that I could be proven wrong.

> 
>> What I don't know is if it is guaranteed to be called in non-web applications 
>> when the JVM just shuts down.
> 
> Finalizers are not called at JVM termination, since the process exit is expected to release resources automatically.  You cannot actually count on a finalizer ever being invoked; it's one of those "seemed like a good idea at the time" things that is now widely regretted by JVM implementers.

After some experimentation, it would appear that it's not so much that finalizers are not called at JVM termination as it is that finalizers are not called if the garbage collector never runs, and the garbage collector isn't guaranteed to run at JVM shutdown. However, if you call System.gc() right before the JVM shuts down, finalizers appear to run every time. Unfortunately, requiring users to call System.gc() before shutdown for logging to work properly is no better than requiring users to register a listener in a web application for logging to work properly. Surely there's a better way...

While I do not disagree that finalizers are very often misused, they are not without their uses. I find it hard to believe that the Sun JRE 6 source code would contain 50 uses of finalizers if they should never be used. You'd think if they regretted creating the method so much they would deprecate it and/or document clearly that it's best to never implement a finalizer, but the documentation for finalizers makes no such assertion, even in the latest Java 8.

> 
> - Chuck
> 
> 
> THIS COMMUNICATION MAY CONTAIN CONFIDENTIAL AND/OR OTHERWISE PROPRIETARY MATERIAL and is thus for use only by the intended recipient. If you received this in error, please contact the sender and delete the e-mail and its attachments from all computers.
> 
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
> 


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


RE: LOG4J2-223: IllegalStateException thrown during Tomcat shutdown (memory leak, it looks like)

Posted by "Caldarale, Charles R" <Ch...@unisys.com>.
> From: Nick Williams [mailto:nicholas@nicholaswilliams.net] 
> Subject: Re: LOG4J2-223: IllegalStateException thrown during Tomcat shutdown (memory leak, it looks like)

> Log4j 1 never required a listener to be configured to be shut down 
> properly when an application is undeployed.

What bearing does that have on a different logging mechanism?

> It should be possible to do this without a listener.

Not easily.

> Could a `finalize` method be used instead of a shutdown hook/listener?

Finalizers should be avoided like the plague.  The gyrations the JVM has to go through to handle them result in continual run time impacts, and require at least two GC passes to actually get rid of the objects.

> What I don't know is if it is guaranteed to be called in non-web applications 
> when the JVM just shuts down.

Finalizers are not called at JVM termination, since the process exit is expected to release resources automatically.  You cannot actually count on a finalizer ever being invoked; it's one of those "seemed like a good idea at the time" things that is now widely regretted by JVM implementers.

 - Chuck


THIS COMMUNICATION MAY CONTAIN CONFIDENTIAL AND/OR OTHERWISE PROPRIETARY MATERIAL and is thus for use only by the intended recipient. If you received this in error, please contact the sender and delete the e-mail and its attachments from all computers.


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: LOG4J2-223: IllegalStateException thrown during Tomcat shutdown (memory leak, it looks like)

Posted by Nick Williams <ni...@nicholaswilliams.net>.
On May 19, 2013, at 3:33 AM, Mark Thomas wrote:

> On 19/05/2013 05:57, Nick Williams wrote:
>> Can one of the very knowledgeable developers that have been
>> discussing memory leaks in the last few days (re: Possible
>> false-postive with JreMemoryLeakPreventionListener and Tomcat's JDBC
>> Pool and OracleTimeoutPollingThread) chime in on this Log4j 2 bug
>> [1]?
>> 
>> Log4j 2 appears to be registering a shutdown hook that, I believe,
>> will result in a memory leak in Tomcat. The
>> JreMemoryLeakPreventionListener does not detect it (which might be a
>> separate Tomcat bug, assuming I'm right that it's a memory leak). I
>> don't know nearly as much about class loaders and memory leaks in a
>> web application as some of the guys I've read talking on here the
>> last few days, and it would be helpful for us to get the
>> knowledgeable opinion of one or more Tomcat developers about how to
>> solve this.
> 
> It looks like Ralph has already answered this [2].
> 
> If log4j2 is initialised by the webapp, it needs to be shutdown by the
> webapp.

Ralph may have responded, but I don't believe it's the right answer. Log4j 1 never required a listener to be configured to be shut down properly when an application is undeployed. It should be possible to do this without a listener. Just a thought, is there a way to detect if a ClassLoader is being shut down/unloaded? Could a `finalize` method be used instead of a shutdown hook/listener? I'm fairly confident the finalize method would always be called when the application is undeployed (though I could be wrong). What I don't know is if it is guaranteed to be called in non-web applications when the JVM just shuts down.

> 
>> (Note: I don't normally post to both lists, but since the memory leak
>> topic was occurring on the user's list, and I also wanted to get the
>> attention of as many developers as possible, I made an exception this
>> time.)
> 
> No matter how important you think your issue is, please do not cross
> post. As a general guide, if you aren't sure, use the users list. The
> committers are all active or lurking here so they will all see it and
> will move the discussion to the dev list of necessary.

My apologies.


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: LOG4J2-223: IllegalStateException thrown during Tomcat shutdown (memory leak, it looks like)

Posted by Mark Thomas <ma...@apache.org>.
On 19/05/2013 05:57, Nick Williams wrote:
> Can one of the very knowledgeable developers that have been
> discussing memory leaks in the last few days (re: Possible
> false-postive with JreMemoryLeakPreventionListener and Tomcat's JDBC
> Pool and OracleTimeoutPollingThread) chime in on this Log4j 2 bug
> [1]?
> 
> Log4j 2 appears to be registering a shutdown hook that, I believe,
> will result in a memory leak in Tomcat. The
> JreMemoryLeakPreventionListener does not detect it (which might be a
> separate Tomcat bug, assuming I'm right that it's a memory leak). I
> don't know nearly as much about class loaders and memory leaks in a
> web application as some of the guys I've read talking on here the
> last few days, and it would be helpful for us to get the
> knowledgeable opinion of one or more Tomcat developers about how to
> solve this.

It looks like Ralph has already answered this [2].

If log4j2 is initialised by the webapp, it needs to be shutdown by the
webapp.

> (Note: I don't normally post to both lists, but since the memory leak
> topic was occurring on the user's list, and I also wanted to get the
> attention of as many developers as possible, I made an exception this
> time.)

No matter how important you think your issue is, please do not cross
post. As a general guide, if you aren't sure, use the users list. The
committers are all active or lurking here so they will all see it and
will move the discussion to the dev list of necessary.

Mark

[1] https://issues.apache.org/jira/browse/LOG4J2-223

[2]
https://issues.apache.org/jira/browse/LOG4J2-223?focusedCommentId=13661501&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-13661501

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org