【问题标题】:java application crashed by suspicious jdbc memory leakjava 应用程序因可疑的 jdbc 内存泄漏而崩溃
【发布时间】:2016-11-27 16:42:30
【问题描述】:

我一直在开发一个 java 应用程序,它使用 http-client(version4.3.3) 从 Internet 抓取页面。它使用一个fixedThreadPool,有5个线程,每个线程都是一个循环线程。伪代码如下。

public class Spiderling extends Runnable{
  @Override
  public void run() {

    while (true) {
        T task = null;
        try {
            task = scheduler.poll();

            if (task != null) {
                if Ehcache contains task's config
                        taskConfig = Ehcache.getConfig;
                else{
                    taskConfig = Query task config from db;//close the conn every time
                    put taskConfig into Ehcache
                }


                spider(task,taskConfig);
            }

        } catch (Exception e) {
            e.printStackTrace();
        }
    }
    LOG.error("spiderling is DEAD");
}
}

我在服务器(2 cpu,2G 内存)上使用以下参数 -Duser.timezone=GMT+8 -server -Xms1536m -Xmx1536m -Xloggc:/home/datalord/logs/gc-2016-07-23-10-28-24.log -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintHeapAtGC 运行它,它在两三天内经常崩溃一次,没有 OutOfMemoryError 和 JVM 错误日志。

这是我的分析;

  1. 我用GC-EASY分析gc日志,报告是here。奇怪的是 Old Gen 缓慢增加直到分配的最大堆大小,但 Full Gc 从未发生过一次。
  2. 我怀疑它可能有内存泄漏,所以我使用 cmd jmap -dump:format=b,file=soldier.bin 转储堆映射并使用 Eclipse MAT 分析转储文件。这里的问题是怀疑哪个对象占用 280+ M 字节。

类“com.mysql.jdbc.NonRegisteringDriver”, 由“sun.misc.Launcher$AppClassLoader @ 0xa0018490”加载,占用281,118,144 (68.91%) 个字节。内存是在一个实例中累积的 由“”加载的“java.util.concurrent.ConcurrentHashMap$Segment[]”。

关键字 com.mysql.jdbc.NonRegisteringDriver java.util.concurrent.ConcurrentHashMap$Segment[] sun.misc.Launcher$AppClassLoader @ 0xa0018490。

我使用 c3p0-0.9.1.2 作为 mysql 连接池,使用 mysql-connector-java-5.1.34 作为 jdbc 连接器,使用 Ehcache-2.6.10 作为内存缓存。我已经看到所有关于 'com.mysql.jdbc. NonregisteringDriver 内存泄漏',仍然没有任何线索。

这个问题让我发疯了好几天,任何建议或帮助将不胜感激!

**********************07-24补充说明****************

我使用了一个名为 JFinal(github.com/jfinal/jfinal) 的 JAVA WEB + ORM 框架,它是在 github 中打开的。 以下是一些核心代码,用于进一步描述问题。

/**
 * CacheKit. Useful tool box for EhCache.
 * 
 */

public class CacheKit {

private static CacheManager cacheManager;
private static final Logger log = Logger.getLogger(CacheKit.class);

static void init(CacheManager cacheManager) {
    CacheKit.cacheManager = cacheManager;
}

public static CacheManager getCacheManager() {
    return cacheManager;
}

static Cache getOrAddCache(String cacheName) {
    Cache cache = cacheManager.getCache(cacheName);
    if (cache == null) {
        synchronized(cacheManager) {
            cache = cacheManager.getCache(cacheName);
            if (cache == null) {
                log.warn("Could not find cache config [" + cacheName + "], using default.");
                cacheManager.addCacheIfAbsent(cacheName);
                cache = cacheManager.getCache(cacheName);
                log.debug("Cache [" + cacheName + "] started.");
            }
        }
    }
    return cache;
}

public static void put(String cacheName, Object key, Object value) {
    getOrAddCache(cacheName).put(new Element(key, value));
}

@SuppressWarnings("unchecked")
public static <T> T get(String cacheName, Object key) {
    Element element = getOrAddCache(cacheName).get(key);
    return element != null ? (T)element.getObjectValue() : null;
}

@SuppressWarnings("rawtypes")
public static List getKeys(String cacheName) {
    return getOrAddCache(cacheName).getKeys();
}

public static void remove(String cacheName, Object key) {
    getOrAddCache(cacheName).remove(key);
}

public static void removeAll(String cacheName) {
    getOrAddCache(cacheName).removeAll();
}

@SuppressWarnings("unchecked")
public static <T> T get(String cacheName, Object key, IDataLoader dataLoader) {
    Object data = get(cacheName, key);
    if (data == null) {
        data = dataLoader.load();
        put(cacheName, key, data);
    }
    return (T)data;
}

@SuppressWarnings("unchecked")
public static <T> T get(String cacheName, Object key, Class<? extends IDataLoader> dataLoaderClass) {
    Object data = get(cacheName, key);
    if (data == null) {
        try {
            IDataLoader dataLoader = dataLoaderClass.newInstance();
            data = dataLoader.load();
            put(cacheName, key, data);
        } catch (Exception e) {
            throw new RuntimeException(e);
        }
    }
    return (T)data;
}

}

我使用像 CacheKit.get("cfg_extract_rule_tree", extractRootId, new ExtractRuleTreeDataloader(extractRootId)) 这样的 CacheKit。如果 extractRootId 在缓存中找不到任何内容,则将调用 ExtractRuleTreeDataloader 类。

public class ExtractRuleTreeDataloader implements IDataLoader {
public static final Logger LOG = LoggerFactory.getLogger(ExtractRuleTreeDataloader.class);
private int                ruleTreeId;

public ExtractRuleTreeDataloader(int ruleTreeId) {
    super();
    this.ruleTreeId = ruleTreeId;
}

@Override
public Object load() {
    List<Record> ruleTreeList = Db.find("SELECT * FROM cfg_extract_fule WHERE root_id=?", ruleTreeId);
    TreeHelper<ExtractRuleNode> treeHelper = ExtractUtil.batchRecordConvertTree(ruleTreeList);//convert List<Record> to and tree
    if (treeHelper.isValidTree()) {
        return treeHelper.getRoot();
    } else {
        LOG.warn("rule tree id :{} is an error tree #end#", ruleTreeId);
        return null;
    }
}

前面说了,我用的是JFinal ORM。Db.find方法代码是

public List<Record> find(String sql, Object... paras) {
    Connection conn = null;
    try {
        conn = config.getConnection();
        return find(config, conn, sql, paras);
    } catch (Exception e) {
        throw new ActiveRecordException(e);
    } finally {
        config.close(conn);
    }
}

config close方法代码是

public final void close(Connection conn) {
    if (threadLocal.get() == null)      // in transaction if conn in threadlocal
        if (conn != null)
            try {conn.close();} catch (SQLException e) {throw new ActiveRecordException(e);}
}

我的代码中没有事务,所以我很确定每次都会调用 conn.close()。

**********************07-28******************更多描述

首先,我使用 Ehcache 将 taskConfigs 存储在内存中。而且taskConfigs几乎永远不会改变,所以我想将它们永久存储在内存中,如果内存不能全部存储它们,则将它们存储到磁盘。

我用MAT找出了NonRegisteringDriver的GC Roots,结果如下图所示。 The Gc Roots of NonRegisteringDriver

但是我还是不明白为什么Ehcache的默认行为会导致内存泄漏。taskConfig是一个扩展Model类的类。

public class TaskConfig extends Model<TaskConfig> {
    private static final long    serialVersionUID = 5000070716569861947L;
    public static TaskConfig DAO              = new TaskConfig();

}

Model的源代码在这个页面(github.com/jfinal/jfinal/blob/jfinal-2.0/src/com/jfinal/plugin/activerecord/Model.java)。正如@Jeremiah 猜测的那样,我找不到对连接对象的任何引用(直接或间接)。

然后我看了NonRegisteringDriver的源码,不明白为什么NonRegisteringDriver的map字段connectionPhantomRefs保存了&lt;ConnectionPhantomReference, ConnectionPhantomReference&gt;的5000多个条目,但是在队列字段@987654340中找不到ConnectionImpl @NonRegisteringDriver。因为我在AbandonedConnectionCleanupThread 类中看到了清理代码,这意味着它将在NonRegisteringDriver.connectionPhantomRefs 中移动ref,同时从NonRegisteringDriver.refQueue 放弃连接ref

@Override
public void run() {
    threadRef = this;
    while (running) {
        try {
            Reference<? extends ConnectionImpl> ref = NonRegisteringDriver.refQueue.remove(100);
            if (ref != null) {
                try {
                    ((ConnectionPhantomReference) ref).cleanup();
                } finally {
                    NonRegisteringDriver.connectionPhantomRefs.remove(ref);
                }
            }

        } catch (Exception ex) {
            // no where to really log this if we're static
        }
    }
}

感谢@Jeremiah 提供的帮助!

【问题讨论】:

  • 你需要展示一些代码。您是否正在关闭诸如结果集、语句和连接之类的资源?您是否正在查询(非常)大数据集(因为 MySQL 默认一次将所有行加载到内存中)?
  • 您能否为 taskConfig 引用发布您的 ehcache.xml 配置?
  • @Jeremiah 我使用默认的 ehcache 配置。&lt;ehcache&gt; &lt;diskStore path="java.io.tmpdir"/&gt; &lt;defaultCache maxElementsInMemory="10000" eternal="true" overflowToDisk="true" diskPersistent="false" diskExpiryThreadIntervalSeconds="120"/&gt; &lt;/ehcache&gt;。并且缓存的key是taskConfigId,value是记录。
  • @MarkRotteveel 我在帖子中添加了更多核心代码。 mysql表的行数不大,平均行长不超过200字节。
  • @abu 还有什么更新吗?

标签: jdbc memory-leaks


【解决方案1】:

从上面的 cmets 我几乎可以肯定你的内存泄漏实际上是来自 EhCache 的内存使用。您看到的 ConcurrentHashMap 是 MemoryStore 的支持者,我猜 taskConfig 持有对连接对象的引用(直接或间接),这就是它显示在您的堆栈中的原因。

在默认缓存中设置永恒=“真”使得插入的对象永远不会过期。即使没有这个,timeToLive 和 timeToIdle 值默认为无限生命周期!

将其与 Ehcache 在检索元素时的默认行为相结合,即通过序列化复制它们(我上次检查过)!每次提取 taskConfig 并将其放回 ehcache 时,您只是在堆叠新的 Object 引用。

最好的测试方法(在我看来)是更改您的默认缓存配置。将永恒更改为 false,并实现 timeToIdle 值。 timeToIdle 是一个值可能存在于缓存中而不被访问的时间(以秒为单位)。

 <ehcache> <diskStore path="java.io.tmpdir"/> <defaultCache maxElementsInMemory="10000" eternal="false" timeToIdle="120"  overflowToDisk="true" diskPersistent="false" diskExpiryThreadIntervalSeconds="120"/>

如果可行,那么您可能需要进一步调整您的 ehcache 配置设置,或者为您的类提供比默认值更自定义的缓存引用。

调整 ehcache 时需要考虑多种性能。我确信您的业务模型有更好的配置。 Ehcache 文档很好,但是当我试图弄清楚时,我发现该站点有点分散。我在下面列出了一些我认为有用的链接。

http://www.ehcache.org/documentation/2.8/configuration/cache-size.html

http://www.ehcache.org/documentation/2.8/configuration/configuration.html

http://www.ehcache.org/documentation/2.8/apis/cache-eviction-algorithms.html#provided-memorystore-eviction-algorithms

祝你好运!


要测试您的内存泄漏,请尝试以下操作:

  1. 将 TaskConfig 插入 ehcache
  2. 立即从缓存中取回它。
  3. 输出TaskConfig1.equals(TaskConfig2)的值;

如果它返回 false,那就是你的内存泄漏。覆盖equalshash 在您的 TaskConfig 对象中并重新运行测试。

【讨论】:

  • 这也可能有助于确保您的 TaskConfig 对象具有良好实现的 .equals() 和 .hash() ,这样即使 ehcache 确实执行了序列化复制,引用也将是 .equals ,即使他们不是'=='
  • 抱歉延迟更新。我觉得你基本上是对的,因为我用 MAT 发现 NonRegisteringDriver 的 GC Roots 是类net.sf.ehcache.CacheManager。其实这几天看了一些Ehcache和Jdbc连接器的源码,还是不明白为什么这种情况下Ehcache的默认行为会导致内存泄漏。所以我在帖子中添加了一些更详细的描述。
  • @abu 我在回复的底部添加了一个块作为您可以尝试的用例。我坚信这与您的潜在问题有关。当您从代码中调用 ehcache.get 时,您将获得 TaskConfig 的副本
  • ,我按你说的试了试,结果是真的。代码和结果会更新到您回复的底部。
  • @abu 如果您在 TaskConfig 中覆盖了equalshash,如果没有完全解决,问题应该会大大减少?
【解决方案2】:

java程序的根本原因是Linux操作系统内存不足,OOM Killer杀死了进程。 我在 /var/log/messages 中找到了日志,如下所示。

Aug  3 07:24:03 iZ233tupyzzZ kernel: Out of memory: Kill process 17308 (java) score 890 or sacrifice child
Aug  3 07:24:03 iZ233tupyzzZ kernel: Killed process 17308, UID 0, (java) total-vm:2925160kB, anon-rss:1764648kB, file-rss:248kB
Aug  3 07:24:03 iZ233tupyzzZ kernel: Thread (pooled) invoked oom-killer: gfp_mask=0x201da, order=0, oom_adj=0, oom_score_adj=0
Aug  3 07:24:03 iZ233tupyzzZ kernel: Thread (pooled) cpuset=/ mems_allowed=0
Aug  3 07:24:03 iZ233tupyzzZ kernel: Pid: 6721, comm: Thread (pooled) Not tainted 2.6.32-431.23.3.el6.x86_64 #1

我还发现 maxIdleTime 的默认值是 20 秒,C3p0Plugin 是 JFinal 中的一个 c3p0 插件,所以我认为这就是为什么 Object NonRegisteringDriver 占用 MAT 中显示的 280+ M 字节报告。所以我将maxIdleTime 设置为3600 秒,对象NonRegisteringDriver 在MAT 报告中不再可疑。

然后我将 jvm 参数重置为 -Xms512m -Xmx512m。这个java程序已经运行了好几天了。当 Old Gen 已满时,Full Gc 将按预期调用。

【讨论】:

    猜你喜欢
    • 2018-04-04
    • 2011-07-08
    • 1970-01-01
    • 1970-01-01
    • 1970-01-01
    • 1970-01-01
    • 2015-03-31
    • 1970-01-01
    • 1970-01-01
    相关资源
    最近更新 更多