AEM 性能问题（慢速内存泄漏）org.slf4j.helpers.BasicMarker 和 org.slf4j.helpers.BasicMarkerFactory
2022-09-04 04:55:11
我目前正在为客户站点（Java平台）使用Adobe 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.
- 希望有人能够帮助查明我的问题的原因，因为我在这里有点迷路了？
- 以前有人见过这个吗？
- 我该如何进一步解决此问题？
- 您是否同意 org.slf4j.helpers.BasicMarker 和 org.slf4j.helpers.BasicMarkerFactory 似乎是我问题的根本原因？
- 我的日志记录配置是否可疑？
- 这是缓慢的内存泄漏还是性能调整问题（在我看来，内存泄漏似乎在一周左右的时间里缓慢）？
欢迎任何建议。
提前致谢。
