me0wster / javamelody

Automatically exported from code.google.com/p/javamelody
0 stars 0 forks source link

"One day" memory leak #339

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago
When using JavaMelody to monitor one of our applications, we noticed, that 
CounterRequest class instances occupy a significant part of our Java heap 
(unfortunately I cannot provide more details, because it happened half a year 
ago and since then JavaMelody has been disabled). Most of the instances were 
owned by the "log" counter, which was caused by most of our messages being 
unique, because they contained dynamic data (mostly internal IDs). We are 
aware, that monitoring messages with dynamic data are bad idea and we should 
use "log-transform-pattern" parameter to remove the dynamic data.

But anyway - the number of CounterRequests for the "log" counter is limited by 
500 in the static initializer of the LoggingHandler class, so the number of 
CounterRequests should drop back to 500 each time the collector is run (which 
is 1 minute by default). So I tried a simple test with JavaMelody 1.46 - I 
generated 10 thousand unique log messages, then waited for the collector to 
run, generated another 10 thousand unique log messages and so on. Surprisingly, 
the total number of CounterRequests increased after each collector run. In a 
few minutes, there was a counter, which contained more than 3 thousand 
CounterRequests (after running the collector).

I analyzed the situation and found the Collector.collectCounterRequestData 
method, which updates day counter. This method is called once for each of the 
up to 500 CounterRequests and it updates the CounterRequest data in the day 
counter or adds it to the day counter, if it does not exist (it's a little bit 
more complex, but this is the most interesting part for me). The problem is, 
that each time the collector is run, the "log" counter can change - it can 
contain a different set of 500 CounterRequests, because some of the 
CounterRequests from the previous collector run may be removed as part of the 
counter size reduction to 500. As a result, the number of CounterRequests held 
by the day counter may increase after each collector run, which is what I 
observed. However, If I understand it correctly, the CounterRequests are 
removed the next day, when a new day counter is created. So the "memory leak" 
exists for just one day.

I'd like to ask you to have a look at this problem. I'd also like to ask you to 
consider setting a "hard limit" on the number of CounterRequests, that can be 
held by a single Counter. This should prevent excessive memory usage caused by 
misbehaving applications and could also solve the aforementioned problem. I've 
already tried this approach and I'm attaching a diff with version 1.46.

My implementation works as follows:
- For each counter there is a new parameter called <counter name>-max-items 
(i.e. log-max-items for the "log" counter).
- The new parameter is read at startup by FilterContext and its value is set to 
the maxRequestsCount property of the Counter.
- When trying to add new CounterRequest in the 
Counter.getCounterRequestInternal method and the requests map already contains 
the "maxRequestsCount" items, there is a warning message issued to stderr and a 
"fallback" CounterRequest is returned (its name is OVERFLOW_REQUEST_NAME). The 
warning message is not intentionally logged using standard logger, because this 
could trigger another "overflow" and infinite recursion.

In my implementation I set the "hard limit" equal to the "soft limit" 
represented by the Counter.maxRequestsCount property. Of course, the "hard 
limit" could be also set higher than the "soft limit", but in this case, the 
"hard limit" does not solve the aforementioned problem. Anyway, I would really 
appreciate having such a "hard limit".

Thank you,
Pavel

Original issue reported on code.google.com by zem...@gmail.com on 10 Sep 2013 at 9:11

Attachments:

GoogleCodeExporter commented 9 years ago
Hi Pavel,
I am ok to look at this problem and I have more or less reproduced the issue.
The analysis is good, very good in fact. But your solution is not the best to 
me.
I would like to fix this problem without adding any new parameter, because new 
parameters are not good for the users. And for example, overflow requests in 
day counters should be removed automatically, every minute.
This seems easy in the Collector class, but i think it is a bit tricky to find 
a good solution.

Original comment by evernat@free.fr on 15 Sep 2013 at 10:57

GoogleCodeExporter commented 9 years ago
I have written a fix now.
The fix is committed in trunk (revision 3513) and ready for the next release 
(1.47).

I have made a new build from the trunk including the fix and it is available at:
https://javamelody.googlecode.com/files/javamelody-20130924.jar

Thanks for the issue!

Original comment by evernat@free.fr on 24 Sep 2013 at 9:12