java - AEM 性能问题(缓慢的内存泄漏)org.slf4j.helpers.BasicMarker 和 org.slf4j.helpers.BasicMarkerFactory

Question

我目前正在为客户的站点(Java 平台)使用 Adob​​e Experience Manager(AEM 也称为 CQ)。它使用 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)

它在 Rackspace 上运行，具有以下内容:

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

自从它投入生产以来，我的应用程序性能一直很慢。就像我启动应用程序一样，一切都很顺利，然后 7 到 10 天后 CPU 使用率飙升至 400%(约 4000 个用户/天访问该站点)。该站点变得异常缓慢，并且永远不会成为 OOM 异常。

因为我是 Java 内存管理方面的新手，所以我开始阅读它的工作原理，并找到了 jstat 和 jmap 等工具。当系统第二次不堪重负时，我得到了一个堆转储并对其进行了挖掘。

这一切似乎都在 org.slf4j.helpers.BasicMarkerFactory 和 org.slf4j.helpers.BasicMarker 上指出，因为当我用 MAT eclipse 分析它时，我看到按保留大小计算的最大保留对象是:

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

和

当我运行泄漏嫌疑人报告时，我得到以下结果:

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

和

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

还有当我运行时:

$ 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

我注意到:

   4:       7563527      181524648  org.slf4j.helpers.BasicMarker

和

8210:             1             16  org.slf4j.helpers.BasicMarkerFactory

当我进入 org.slf4j.helpers.BasicMarkerFacotry 的文档时，我看到以下内容引起了我的注意:

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

特别是:

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

1. 希望有人能够帮助查明我的问题的原因，因为我在这里有点迷路？
2. 有没有人见过这个？
3. 我该如何进一步解决这个问题？
4. 您是否同意 org.slf4j.helpers.BasicMarker 和 org.slf4j.helpers.BasicMarkerFactory 似乎是我出现问题的根本原因？
5. 我的日志记录配置有问题吗？
6. 这是缓慢的内存泄漏还是性能调整问题(在我看来，内存泄漏似乎在一周左右的时间里缓慢发生)？

欢迎任何建议。

提前致谢。

Answer 1

您使用的是 MarkerFactory创建你的 Marker实例？

听起来很明显，保存标记的ConcurrentHashMap 一直在增长。例如，情况就是这样。如果您创建的标记每次都使用不同的名称(例如使用日期)。标记用于标记您的日志，以便您可以相应地过滤它们。您可能想要发布您正在创建标记的代码部分。