fix memory leak with logger

[if6was9]

Someone at neo4j may have a better fix for this.

The logger was clearly constructed in this way with the intention of aiding diagnostics. But looking through the usage of this logger, the instance id provided by the Session.hashCode() doesn't appear to be all that useful, so I just took it out. But maybe someone at neo4j has a preferred method of fixing.

That said, it leaks memory, so it just needs to be fixed.

Just to give some context, rough estimates are that we are doing ~100 transactions/second. This burned through a 6GB heap in a few days.

[if6was9]

Found another instance of this error in the code in SocketConnection.

Should be orders of magnitude harder to get this to levels that would cause stability issues in application code, but it is still not right.

[lutovich]

Hello @if6was9,

Do you by any chance have a heap dump to share? What objects are leaking?
Does your application provide custom logging via ConfigBuilder#withLogging(Logging) method?

I guess you have a problem with amount of logger instances and not string concatenation.

Thanks for raising this issue.

[if6was9]

Yes. The number of logger instances is effectively unbounded.

I can't share the heap dump itself, but here is the histogram output that lead to the issue:

Having 25M LogNode instances caught my eye.

num     #instances         #bytes  class name
----------------------------------------------
   1:      28433684     1857307984  [C
   2:      26021876      832700032  java.util.HashMap$Node
   3:      25654249      820935968  java.util.logging.LogManager$LogNode
   4:      27962814      671107536  java.lang.String
   5:        177157      283583632  [Ljava.util.HashMap$Node;
   6:       1499250      229936712  [B
   7:        723172      126125600  [I
   8:       1449479      113432048  [Ljava.lang.Object;
   9:        975179       70212888  com.fasterxml.jackson.databind.ser.DefaultSerializerProvider$Impl
  10:        973877       70119144  com.fasterxml.jackson.databind.deser.DefaultDeserializationContext$Impl
  11:        970158       54328848  com.fasterxml.jackson.databind.util.TokenBuffer
  12:        970158       54328848  com.fasterxml.jackson.databind.util.TokenBuffer$Parser

[if6was9]

Heap dump in yourkit:

Digging further revealed them to all have the log name pattern: Session-<id> in the root logger, which matches exactly with the code.

[if6was9]

BTW, the JDK does implement its cache of Loggers with weak references. So the weak references should be eligible for GC.

But for reasons unknown the GC is unable to reclaim them.

It think this falls into the "don't do that" category and all problems just go away.

[lutovich]

Thanks for the info.
I agree, it is not good to rely on logger weak refs anyway.

We could save session and connection IDs by putting them in messages instead of logger names. What do you think about this?

I'm happy to merge this change. Could you please sign the code-contribution CLA? (build will go green when CLA is signed)
See http://neo4j.com/developer/cla/ for further information.
Additional information on contributing code is found at
http://neo4j.com/developer/contributing-code/

[zhenlineo]

I am closing this one as #362 is already merged. Thank again for raising this PR