logging-log4j-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Veit Guna" <Veit.G...@gmx.de>
Subject Aw: Re: still: Memoryleak - org.apache.log4j.helpers.ThreadLocalMap
Date Fri, 18 Dec 2015 17:28:11 GMT
Hi Ralph.
 
Okidoki.
 
Concerning threads: I know ;).
 
That's the reason why the JEE spec comes with things like @Timeout for scheduling and container
managed connection pools. But they're always behind the cool
stuff that comes from the open source community - so one can't really avoid using threads
when you want to be uptodate. So I agree with you.
 
But maybe for a "low-level" logging component one could keep an eye on such things and at
least provide a thread-less-option for some things. That would make the
JEE guys happy ;).
 
Thanks for your support!
Veit
 

Gesendet: Freitag, 18. Dezember 2015 um 17:35 Uhr
Von: "Ralph Goers" <ralph.goers@dslextreme.com>
An: "Log4J Users List" <log4j-user@logging.apache.org>
Betreff: Re: still: Memoryleak - org.apache.log4j.helpers.ThreadLocalMap
Thanks. I’ll take a look at that. The scheduler threads should be shutting down.

Although the specs tell you not to create your own threads lots of stuff does. Otherwise you
wouldn’t be able to use the Quartz scheduler, connection pooling, etc.

Ralph

> On Dec 18, 2015, at 9:09 AM, Veit Guna <Veit.Guna@gmx.de> wrote:
>
> Hi Ralph.
>
> Today I switched from log4j 1.2.17 to 2.5 while using SLF4J 1.7.7.
>
> Basically it works and the Memory Leak Warning doesn't seem to appear anymore under "normal"
usage.
> BUT, when using:
>
> <Configuration monitorInterval="60">
> ...
>
> There comes the little bugger again :):
>
> WARNING: The web application [mywebapp] appears to have started a thread named [Log4j2-Log4j2Scheduled-1]
but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
> sun.misc.Unsafe.park(Native Method)
> java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
> java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
> java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
> java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> java.lang.Thread.run(Thread.java:745)
>
> I think you guys start a monitoring thread that polls the config, right :)?
> Although the documentation states, that it will be checked when the next log statement
is performed - what, IMHO, is the right approach.
> In the JEE / Container world, starting threads by your own is not very welcome :). Maybe
an option (useMonitoringThread) could help.
>
> For now I can live without the monitoring since the xml is packaged within a jar anyway.
But that might change in the future.
>
> Regards,
> Veit
>
>
>
>
> Gesendet: Freitag, 18. Dezember 2015 um 02:10 Uhr
> Von: "Ralph Goers" <ralph.goers@dslextreme.com <mailto:ralph.goers@dslextreme.com>>
> An: "Log4J Users List" <log4j-user@logging.apache.org <mailto:log4j-user@logging.apache.org>>
> Betreff: Re: still: Memoryleak - org.apache.log4j.helpers.ThreadLocalMap
> Although the configuration format has changed, it shouldn’t be too difficult to figure
out how to create a similar configuration in Log4j 2. If you have any problems at all please
ask. We will be happy to help with that.
>
> Ralph
>
>> On Dec 17, 2015, at 2:29 PM, Veit Guna <Veit.Guna@gmx.de <mailto:Veit.Guna@gmx.de>>
wrote:
>>
>> Hi Gary.
>>
>> I can give it a try tomorrow. Has the log4j.xml format been changed? Or does the
bridge handle that too?
>>
>>
>> Am 17. Dezember 2015 19:16:24 MEZ, schrieb Gary Gregory <garydgregory@gmail.com>:
>>> Is there any chance you can update your app to Log4j 2.5 using our 1.2
>>> bridge?
>>>
>>> Gary
>>>
>>> On Thu, Dec 17, 2015 at 9:36 AM, Veit Guna <Veit.Guna@gmx.de> wrote:
>>>
>>>> Hi.
>>>>
>>>> We're developing a Jersey 2(.22.1) REST service with JDK8, log4j
>>> 1.2.16
>>>> and SLF4J 1.7.7 using Tomcat 8.0.23.
>>>>
>>>> Recently I stumbled across the problem mentioned here:
>>>>
>>>> https://bz.apache.org/bugzilla/show_bug.cgi?id=50486
>>>>
>>>> Where Tomcat complains about left behind ThreadLocalMaps.
>>>>
>>>> I updated to 1.2.17 which claims to fix the mentioned problem.
>>>> On first sight, it did. Starting the server and immediately stopping
>>> it
>>>> showed no warning anymore - before it did. Yay!
>>>>
>>>> But then I drove some loadtests against our REST service and after
>>>> stopping it the same message appeared again :(.
>>>>
>>>> I double checked that our MDC put/remove is performed within a
>>>> try/finally within a http filter. I also logged, what values
>>>> were put and removed from the MDC - everyting as expected.
>>>> I also made sure, that the key was really removed after
>>>> MDC.remove() by getting the key from the MDC again: null.
>>>>
>>>> Tomcat complained about a specific key/value in the ThreadLocalMap.
>>>> I checked, that this key/value was logged before - and it was
>>>> logged as "removed". So somehow it wasn't _really_ removed.
>>>>
>>>> I digged deeper into the rabbit hole and found this peace of code:
>>>>
>>>> --cut here--
>>>> final public class ThreadLocalMap extends InheritableThreadLocal {
>>>>
>>>> public
>>>> final
>>>> Object childValue(Object parentValue) {
>>>> Hashtable ht = (Hashtable) parentValue;
>>>> if(ht != null) {
>>>> return ht.clone();
>>>> } else {
>>>> return null;
>>>> }
>>>> }
>>>> }
>>>> --cut here--
>>>>
>>>> At this point, the hashtable containing the key/values is cloned
>>>> when a child thread is spawned. That would explain, why I see that
>>>> the complained key/value still exists, although I removed it from the
>>>> MDC. It still exists in the cloned instance on the spawned child
>>> thread
>>>> I guess!
>>>>
>>>> I verified it by debugging within eclipse and set a breakpoint there,
>>>> simply returning null instead of ht.clone(). And voila: no
>>> complaining
>>>> anymore when shutting down.
>>>>
>>>> Since I'm not too deep into log4j, could someone of the devs please
>>>> shed some light on this, please?
>>>>
>>>> I'm wondering, who will remove the ThreadLocalMap on the spawned
>>> child
>>>> threads? Since MDC.remove() will do this only on my parent thread
>>>> manually kicked by the filter.
>>>>
>>>> Or, maybe I'm completely wrong with this :).
>>>>
>>>> Thanks
>>>> Veit
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>> ---------------------------------------------------------------------
>>>> To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
>>>> For additional commands, e-mail: log4j-user-help@logging.apache.org
>>>>
>>>>
>>>
>>>
>>> --
>>> E-Mail: garydgregory@gmail.com | ggregory@apache.org
>>> Java Persistence with Hibernate, Second Edition
>>> <http://www.manning.com/bauer3/[http://www.manning.com/bauer3/][http://www.manning.com/bauer3/[http://www.manning.com/bauer3/]]
<http://www.manning.com/bauer3/[http://www.manning.com/bauer3/][http://www.manning.com/bauer3/[http://www.manning.com/bauer3/]]>>
>>> JUnit in Action, Second Edition <http://www.manning.com/tahchiev/[http://www.manning.com/tahchiev/][http://www.manning.com/tahchiev/[http://www.manning.com/tahchiev/]]
<http://www.manning.com/tahchiev/[http://www.manning.com/tahchiev/][http://www.manning.com/tahchiev/[http://www.manning.com/tahchiev/]]>>
>>> Spring Batch in Action <http://www.manning.com/templier/[http://www.manning.com/templier/][http://www.manning.com/templier/[http://www.manning.com/templier/]]
<http://www.manning.com/templier/[http://www.manning.com/templier/][http://www.manning.com/templier/[http://www.manning.com/templier/]]>>
>>> Blog: http://garygregory.wordpress.com[http://garygregory.wordpress.com][http://garygregory.wordpress.com[http://garygregory.wordpress.com]]
<http://garygregory.wordpress.com[http://garygregory.wordpress.com][http://garygregory.wordpress.com[http://garygregory.wordpress.com]]>
>>> Home: http://garygregory.com/[http://garygregory.com/][http://garygregory.com/[http://garygregory.com/]]
<http://garygregory.com/[http://garygregory.com/][http://garygregory.com/[http://garygregory.com/]]>
>>> Tweet! http://twitter.com/GaryGregory[http://twitter.com/GaryGregory][http://twitter.com/GaryGregory[http://twitter.com/GaryGregory]]
<http://twitter.com/GaryGregory[http://twitter.com/GaryGregory][http://twitter.com/GaryGregory[http://twitter.com/GaryGregory]]>
>>
>> --
>> Von meinem Telefon gesendet.
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org <mailto:log4j-user-unsubscribe@logging.apache.org>
> For additional commands, e-mail: log4j-user-help@logging.apache.org <mailto:log4j-user-help@logging.apache.org>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org <mailto:log4j-user-unsubscribe@logging.apache.org>
> For additional commands, e-mail: log4j-user-help@logging.apache.org <mailto:log4j-user-help@logging.apache.org>

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-user-help@logging.apache.org


Mime
View raw message