|
我写的JOSP平台，为每个模块提供了一个父类，当中有一个消息队列是用LinkedBlockingQueue实现的，后来
根据XXX的邮件《测试机器运行十天后，内存占用情况》来看，运行9天（实际为9天），josp.mas内存占用达到2307M。josp.omc占用达到2314M。毫无疑问，存在很严重的内存泄露。
以下是同事YYY的检查结果分析：
后来，我们又进行了一次测试，通过java vm参数-Xmx100m将2个进程的内存限制在100M，8个小时后，还是内存泄露，出现内存不够的异常OutofmemeryException，模块全线崩溃。
经过几天的排查，发现，在我本人的机器上，mas进程很正常。而且通过代码也看到，mas进程的9个模块是很简单的，在不做任何事情的情况下，应该不会有内存泄露。
于是，测试了josp平台，发现也是没有内存泄露的。
于是，只好分析代码，发现，调用最为频繁的是这JTaskFactory一段代码：
while (true) {
TaskMsg msg = null;
try {
synchronized(m_tb.getClass()){
msg = (TaskMsg) m_tb.queue_.poll(100,TimeUnit.MILLISECONDS);
}
m_tb.remainInQueueAmount.setValue(m_tb.queue_.size());
} catch (Exception e) {
在没有消息的情况下，每个模块每秒钟会调用Poll函数10次（1秒除以100毫秒）。于是，在jbuilder2006下测试了这个函数，观察gc日志，果不其然，令人欣慰的一幕出现了：
[GC 512K->232K(1984K), 0.0039062 secs]
[GC 744K->442K(1984K), 0.0024386 secs]
[GC 954K->652K(1984K), 0.0015416 secs]
[GC 1164K->862K(1984K), 0.0012926 secs]
[GC 1374K->1072K(1984K), 0.0014093 secs]
。。。。。。。。。。。。。。。。。。。。
这个函数存在内存泄露，每调用1万次，会泄露312K内存。后来测试发现，只有在JDK1.5下有内存泄露，而在JDK1.6下，GC日志显示，这个函数没有泄露：
[GC 896K->215K(5056K), 0.0029709 secs]
[GC 1111K->215K(5056K), 0.0008942 secs]
[GC 1111K->215K(5056K), 0.0003455 secs]
[GC 1111K->215K(5056K), 0.0001933 secs]
。。。。。。。。。。。。。。
北京环境正好是JDK1.5。
于是，我用JOSP做了一下测试，JDK1.5环境加载一个模块，这个模块不做任何事情，限制内存42M，1002秒后，模块因为内存不够崩溃，gc日志：
。。。。。。。。。。。。。
0.066: [Full GC 730K->730K(41664K), 0.0323995 secs]
0.099: [Full GC 730K->627K(42688K), 0.0386444 secs]
4.953: [Full GC 42281K->39992K(42688K), 0.0811821 secs]
5.938: [Full GC 42687K->40780K(42688K), 0.1345104 secs]
7.547: [Full GC 42687K->41747K(42688K), 0.1410599 secs]
125.547: [Full GC 42687K->41885K(42688K), 0.1583355 secs]
429.919: [Full GC 42687K->42071K(42688K), 0.1803768 secs]
568.374: [Full GC 42688K->42155K(42688K), 0.2544925 secs]
774.676: [Full GC 42688K->42281K(42688K), 0.1433841 secs]
912.935: [Full GC 42687K->42365K(42688K), 0.1431487 secs]
1034.963: [Full GC 42687K->42440K(42688K), 0.1457875 secs]
1035.111: [Full GC 42440K->42440K(42688K), 0.2028878 secs]
1435.741: [Full GC 42687K->42685K(42688K), 0.2041293 secs]
1435.948: [Full GC 42685K->42685K(42688K), 0.1681726 secs]
1438.172: [Full GC 42688K->42686K(42688K), 0.1547281 secs]
1438.329: [Full GC 42686K->42686K(42688K), 0.1533963 secs]
1439.510: [Full GC 42687K->42687K(42688K), 0.1537239 secs]
。。。。。。。。。。。。
而JDK1.6下，3600秒后模块依然正常，gc日志显示，内存达到41888K后就不变了：
。。。。。。。。。。。
2334.178: [Full GC 42687K->41888K(42688K), 0.1302688 secs]
2636.473: [Full GC 42687K->41889K(42688K), 0.1334375 secs]
2938.790: [Full GC 42687K->41888K(42688K), 0.1462437 secs]
2938.953: [Full GC 42367K->41888K(42688K), 0.1297961 secs]
3242.218: [Full GC 42687K->41888K(42688K), 0.1493409 secs]
3544.285: [Full GC 42687K->41889K(42688K), 0.1619370 secs]
3682.247: [Full GC 42687K->41888K(42688K), 0.1322534 secs]
。。。。。。。。
假设josp的内存泄露就是poll引起，内存泄露量计算，
0）调用1次poll函数将泄露内存312/10000K的内存
1): 每个模块（即使有多个线程，也只会有一个线程调用poll函数）每秒将调用 10次poll函数
2) MAS进程有9个模块
故9天时间内（北京机器实际运行时间为9天），mas进程将泄露的内存量为：
(312.0/10000.0)（K） * 9(模块) * 10（每秒次数） * 3600（一个小时秒数） * 24（一天的小时数） * 9（天）
结果：2,132.325M. （约2.1G）
Omc有11个模块，应该泄露2,606.175M内存 （这个地方有疑问，就是泄露的值比实际的还大。应该是已经出现了内存占满的异常，后续java不分配内存）。
综合上面的情况，基本得到结论，基本是因为使用JDK1.5而发生内存泄露。
|
|
