我目前正在为客户网站(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
and
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 是我的问题根源吗?
- 我的日志配置是否有问题?
- 这是一个慢性内存泄漏还是性能调整问题(在我看来,它似乎会慢慢地出现一周左右)?
欢迎任何建议。
提前感谢。