not - memory leak java code

Problemas de rendimiento de AEM(pérdida lenta de memoria) org.slf4j.helpers.BasicMarker y org.slf4j.helpers.BasicMarkerFactory

Question

Actualmente estoy usando Adobe Experience Manager (AEM también conocido como CQ) para el sitio de un cliente (plataforma Java). Utiliza OpenJDK:

java version "1.7.0_65" 
OpenJDK Runtime Environment (rhel-2.5.1.2.el6_5-x86_64 u65-b17) 
OpenJDK 64-Bit Server VM (build 24.65-b04, mixed mode)

Se ejecuta en Rackspace con lo siguiente:

vCPU: 4 
Memory: 16GB 
Guest OS: Red Hat Enterprise Linux 6 (64-bit)

Dado que ha estado en producción, he estado experimentando un rendimiento muy lento por parte de la aplicación. Funciona así. Lanzo la aplicación, todo está sin problemas, luego de 7 a 10 días, el uso de la CPU aumenta a 400% (~ 4000 usuarios / día llegan al sitio). El sitio se vuelve excepcionalmente lento y nunca se convierte en una excepción OOM.

Como soy un novato en la administración de la memoria Java, comencé a leer sobre cómo funciona y encontré herramientas como jstat y jmap. Cuando el sistema se vio abrumado la segunda vez, obtuve un volcado de pila y lo busqué.

Todo parece apuntar a org.slf4j.helpers.BasicMarkerFactory y org.slf4j.helpers.BasicMarker como cuando lo analizo con MAT eclipse Veo que el objeto retenido más grande por tamaño retenido es:

org.slf4j.helpers.BasicMarkerFactory @ 0x6021a4f00
Shallow Size: 16 B Retained Size: 6.8 GB

y

Cuando ejecuto un informe de sospechosos de fugas obtengo el siguiente resultado:

Description
One instance of "org.slf4j.helpers.BasicMarkerFactory" loaded by "org.apache.felix.framework.BundleWiringImpl$BundleClassLoaderJava5 @ 0x60219a878" occupies 7,263,024,848 (96.71%) bytes. The memory is accumulated in one instance of "java.util.concurrent.ConcurrentHashMap$Segment[]" loaded by "<system class loader>".

Keywords
java.util.concurrent.ConcurrentHashMap$Segment[]
org.apache.felix.framework.BundleWiringImpl$BundleClassLoaderJava5 @ 0x60219a878
org.slf4j.helpers.BasicMarkerFactory

y

Shortest Paths To the Accumulation Point

Class Name                                                                                  Shallow Heap    Retained Heap

java.util.concurrent.ConcurrentHashMap$Segment[16] @ 0x6021a4f40                                80              7,263,024,784
.
... segments java.util.concurrent.ConcurrentHashMap @ 0x6021a4f10                               48              7,263,024,832
    .
    ... markerMap org.slf4j.helpers.BasicMarkerFactory @ 0x6021a4f00                            16              7,263,024,848
        .
        ... markerFactory org.slf4j.impl.StaticMarkerBinder @ 0x6021d3970                       16                         16
            .
            ... SINGLETON class org.slf4j.impl.StaticMarkerBinder @ 0x6021d38f8                 8                          24
                .
                ... [328] java.lang.Object[640] @ 0x6021d2ee8                                   2,576                   9,592
                    .
                    ... elementData java.util.Vector @ 0x6021d0fe0                              32                      9,624
                        .
                        ... classes org.apache.felix.framework.BundleWiringImpl$
                            BundleClassLoaderJava5 @ 0x6021c32e0                                96                     26,888
                            .
                            ... <classloader> class ch.qos.logback.classic.Logger @ 
                                0x600be4310                                                     16                         16
                            .   .
                            .   ...<class> ch.qos.logback.classic.Logger @ 0x600282a78          48                          48
                            .
                            ... <Java Local> java.lang.Thread @ 0x60077b450
                                pool-9-thread-1 Thread                                          104                     3,344
                                .
                                ... <class> ch.qos.logback.classic.Logger @ 0x60025b850         48                          48
                                .
                                ... <class> ch.qos.logback.classic.Logger @ 0x604b0a708         48                          48
                                .
                                ... <class> ch.qos.logback.classic.Logger @ 0x604b0a6d8         48                          48
                                .
                                ... <class> ch.qos.logback.classic.Logger @ 0x6049debe0         48                          48
                                .
                                ... <class> ch.qos.logback.classic.Logger @ 0x604535228         48                          48
                                .
                                ... <class> ch.qos.logback.classic.Logger @ 0x604124248         48                         48

También cuando corro:

$ sudo -u aem jmap -histo PID


 num     #instances         #bytes  class name
----------------------------------------------
   1:      11460084      950827248  [C
   2:      10740160      257763840  java.lang.String
   3:       7681495      245807840  java.util.concurrent.ConcurrentHashMap$HashEntry
   4:       7563527      181524648  org.slf4j.helpers.BasicMarker
   5:        217007      173568376  [I
   6:        177602      158721184  [B
   7:         60611       69739136  [Ljava.util.concurrent.ConcurrentHashMap$HashEntry;
   8:       1147481       69348496  [Ljava.lang.Object;
   9:       1797107       43130568  org.apache.jackrabbit.oak.plugins.segment.RecordId
  10:        208912       33824544  <constMethodKlass>
  11:        570143       31928008  org.mozilla.javascript.ast.Name
  12:         22350       27643920  <constantPoolKlass>
  13:        208912       26752544  <methodKlass>
  14:        821217       26278944  java.util.UUID
  15:        793800       25401600  java.util.HashMap$Entry
  16:        532946       21317840  org.mozilla.javascript.Node
  17:        792296       19015104  java.lang.Long
  18:        191294       18335600  [Ljava.util.HashMap$Entry;
  19:         22350       16133328  <instanceKlassKlass>
  20:        173883       15855152  [Ljava.lang.String;
  21:        635690       15256560  org.apache.sling.engine.impl.request.SlingRequestProgressTracker$TrackingEntry
  22:         18509       14662848  <constantPoolCacheKlass>
  23:        911112       14577792  java.lang.Integer
  24:        255426       14303856  org.apache.jackrabbit.oak.plugins.segment.SegmentNodeBuilder
  25:        519324       12463776  java.util.ArrayList
  26:        254643       12222864  org.apache.jackrabbit.oak.core.SecureNodeBuilder
  27:        137703       11016240  java.lang.reflect.Method
  28:        312116        9987712  org.apache.jackrabbit.oak.plugins.segment.SegmentNodeState
  29:         19236        9828448  [Lorg.apache.jackrabbit.oak.plugins.segment.SegmentId;
  30:        242179        9687160  java.util.TreeMap$Entry
  31:        197121        9461808  java.util.HashMap
  32:         15041        9416328  <methodDataKlass>
  33:        387927        9310248  org.apache.jackrabbit.oak.plugins.segment.MapRecord
  34:        250049        8001568  org.apache.jackrabbit.oak.plugins.memory.MemoryNodeBuilder$UnconnectedHead
  35:        248586        7954752  org.apache.jackrabbit.oak.core.MutableTree
  36:        107865        7948112  [S
  37:        191950        7678000  java.util.LinkedHashMap$Entry
  38:        102212        6541568  org.mozilla.javascript.ast.PropertyGet
  39:         37021        6515696  org.mozilla.javascript.ast.FunctionNode
  40:        161905        6476200  org.mozilla.javascript.ScriptableObject$Slot

.....

8210:             1             16   org.slf4j.helpers.BasicMarkerFactory

Me di cuenta:

   4:       7563527      181524648  org.slf4j.helpers.BasicMarker

y

8210:             1             16  org.slf4j.helpers.BasicMarkerFactory

Cuando ingreso a la documentación de org.slf4j.helpers.BasicMarkerFacotry veo lo siguiente que me llama la atención:

detachMarker
public boolean detachMarker(String name)
Description copied from interface: IMarkerFactory
Detach an existing marker.
Note that after a marker is detached, there might still be "dangling" references to the detached marker.

Specified by:
detachMarker in interface IMarkerFactory
Parameters:
name - The name of the marker to detach
Returns:
whether the marker could be detached or not

En particular:

Note that after a marker is detached, there might still be "dangling" references to the detached marker.

1. Espero que alguien pueda ayudar a identificar la causa de mis problemas ya que estoy un poco perdido aquí?
2. Alguien ha visto esto antes ?
3. ¿Cómo podría seguir solucionando este problema?
4. ¿Está de acuerdo con que org.slf4j.helpers.BasicMarker y org.slf4j.helpers.BasicMarkerFactory parecen ser la causa principal de mis problemas?
5. ¿Mi configuración de registro es sospechosa?
6. ¿Se trata de una fuga de memoria lenta o un problema de ajuste del rendimiento (en mi opinión, parece que la memoria se filtra lentamente durante una semana más o menos)?

Cualquier consejo es bienvenido

Gracias por adelantado.

Answer 1

¿Estás usando MarkerFactory para crear tus instancias de Marker ?

Parece obvio que el ConcurrentHashMap sostiene su Marker está en constante crecimiento. Ese sería el caso, por ejemplo, si crea un marcador con cada vez un nombre diferente (por ejemplo, usando una fecha). Marker debe marcar su registro para que pueda filtrarlos en consecuencia. Es posible que desee publicar la parte del código donde está creando su marcador.