Problemi di prestazioni AEM (perdita di memoria lenta) org.slf4j.helpers.BasicMarker e org.slf4j.helpers.BasicMarkerFactory

Question

Attualmente sto utilizzando Adobe Experience Manager (AEM noto anche come CQ) per il sito di un client (piattaforma Java). Esso utilizza 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) 

Si è in esecuzione sul Rackspace con il seguente:

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

Dal momento che è stato in produzione Ho sperimentato prestazioni molto lenta da parte dell'applicazione. È così che lancio l'app, tutto è fluido, quindi dai 7 ai 10 giorni successivi l'utilizzo della CPU raggiunge il 400% (circa 4000 utenti al giorno colpiscono il sito). Il sito diventa eccezionalmente lento e non diventa mai un'eccezione OOM.

Poiché sono un principiante della gestione della memoria Java, ho iniziato a leggere come funziona e ho trovato strumenti come jstat e jmap. Quando il sistema è stato travolto la seconda volta, ho trovato una discarica e ci ho scavato dentro.

Tutto sembra essere sottolineando a org.slf4j.helpers.BasicMarkerFactory e org.slf4j.helpers.BasicMarker come quando analizzo con MAT Eclipse vedo che il più grande oggetto trattenuto dalla dimensione conservato è:

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

e

quando eseguo una sospetti di fughe riportano ottengo il seguente risultato:

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 

e

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 

Anche quando ho eseguito:

$ 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 

ho notato:

4:  7563527  181524648 org.slf4j.helpers.BasicMarker 

e

8210:    1    16 org.slf4j.helpers.BasicMarkerFactory 

quando vado nella documentazione dei org.slf4j.helpers .BasicMarkerFacotry Vedo quanto segue la mia attenzione:

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 

In particolare:

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

1. Speriamo che qualcuno sarà in grado di contribuire a individuare la causa dei miei problemi come io sono un po 'perso qui?
2. Qualcuno ha visto questo prima?
3. Come posso risolvere ulteriormente questo problema?
4. Siete d'accordo che org.slf4j.helpers.BasicMarker e org.slf4j.helpers.BasicMarkerFactory sembrano essere la causa principale dei miei problemi?
5. La mia configurazione di registrazione è sospetta?
6. Si tratta di una perdita di memoria lenta o di un problema di ottimizzazione delle prestazioni (a mio parere sembra che la memoria si scarichi lentamente nell'arco di una settimana o giù di lì)?

Qualsiasi consiglio è gradito.

Grazie in anticipo.

Answer 1

Stai utilizzando lo MarkerFactory per creare le tue istanze Marker?

Sembra ovvio che lo ConcurrentHashMap che regge il tuo indicatore sia in continua crescita. Questo sarebbe il caso per es. se crei un marcatore ogni volta con un nome diverso (ad esempio utilizzando una data). I marker devono contrassegnare il tuo log in modo da poterli filtrare di conseguenza. Potresti voler postare la parte del codice in cui stai creando il tuo marcatore.