java - 多线程java应用程序中的奇怪行为(没有锁的死锁？)

Question

当我尝试运行多个线程来收集 HTTP 连接中的数据时，我遇到了奇怪的行为。

事实上，我正在尝试使用 Jena Semantic Web Framework 处理多个 SPARQL 查询。

我的应用程序使用以下代码创建线程轮询:

final ExecutorService executor = Executors.newFixedThreadPool(X);

其中 X 是我选择的线程数。

因此，我在 200 多个 SPARQL 端点上运行相同的查询。该过程可以在多线程环境中进行，因为每个端点(通常)是不同的服务器。每个端点的延迟应该允许我创建比我拥有的物理处理器数量大得多的线程数量。

使用大量线程时，我遇到了奇怪的行为。如果我使用15个线程，系统会正常处理。但是，例如，如果我使用超过 30 个线程，系统将停止工作。我的意思是，日志(带有异步附加程序的 log4j)只是停止获取新消息，CPU 使用率降至 0%，什么也没有发生。

我首先怀疑的是僵局。使用java安装提供的“Java Visual VM”，我看到每个线程都继续运行，甚至什么也没做!接下来要做的就是线程转储。大多数线程的结果类似于以下内容:

pool-2-thread-100" #117 prio=5 os_prio=0 tid=0x000000000b61c800 nid=0x1e4c in Object.wait() [0x0000000022e0e000]
   java.lang.Thread.State: RUNNABLE
    at com.hp.hpl.jena.query.QueryFactory.create(QueryFactory.java:78)
    at com.hp.hpl.jena.query.QueryFactory.create(QueryFactory.java:52)
    at com.hp.hpl.jena.query.QueryFactory.create(QueryFactory.java:40)
    at com.hp.hpl.jena.query.QueryExecutionFactory.sparqlService(QueryExecutionFactory.java:347)
    at websemantics.UtilitiesSparql.getExecution(UtilitiesSparql.java:378)
    at websemantics.UtilitiesSparql.runSparqlQuery(UtilitiesSparql.java:410)
    at websemantics.UtilitiesSparql.runSparqlQuery(UtilitiesSparql.java:245)
    - locked <0x0000000081268d10> (a websemantics.model.Dataset)
    at websemantics.UtilitiesSparql$SparqlTask.call(UtilitiesSparql.java:75)
    at websemantics.UtilitiesSparql$SparqlTask.call(UtilitiesSparql.java:1)
    at java.util.concurrent.FutureTask.run(Unknown Source)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
    at java.lang.Thread.run(Unknown Source)

   Locked ownable synchronizers:
    - <0x0000000081273738> (a java.util.concurrent.ThreadPoolExecutor$Worker)

堆栈中间的锁只是保证每个端点一次只执行一个查询。在测试代​​码中不会发生这种情况。如上面的代码所示，所有线程的状态都是“RUNNABLE”。

正如您所看到的，代码“锁定”了查询对象的创建(稍后将通过网络执行)。为了测试，我添加了一个同步块(synchronized block)，其中方法 QueryFactory.create 将被调用一次。在这种情况下，耶拿代码的另一部分(我不认为它是负责的) block =(

整个情况对我来说太奇怪了，我认为这可能是 JVM 错误。我在 JDK 1.7(天蓝色计算机上的 Windows 8 和 Server 2012)、JDK 1.8(今天!Windows 8 计算机)和 OpenJDK 1.7 (Ubuntu 13.*) 上进行了测试，每个测试都有相同的行为。所以我不认为这是一个 JVM 错误，可能是我的错误，但我可以看到我做错了什么。

有人知道 JVM 何时以这种方式工作吗？整件事让我发疯!

非常感谢!

更新 1:我正在按照其他人的要求添加有关该问题的更多信息。

我再次运行该工具，并在不同时间(13:03、13:04、13:08 和 13:15)进行了四次线程转储。每一个都与其他的非常相似:代码在一段时间后就会卡住。我已将文件上传到我的 onedrive:http://1drv.ms/1nGihAF

大多数线程停在上面堆栈的同一点，但有些线程停在这里:

at com.hp.hpl.jena.rdf.model.ModelFactory.createDefaultModel(ModelFactory.java:140)
    at com.hp.hpl.jena.util.FileManager.loadModelWorker(FileManager.java:305)
    at com.hp.hpl.jena.util.FileManager.loadModel(FileManager.java:258)
    at websemantics.utils.UtilitiesJena.getModelInEverySyntax(UtilitiesJena.java:140)
    at websemantics.utils.UtilitiesJena.getOntologyByURLNonSilently(UtilitiesJena.java:121)
    at websemantics.utils.UtilitiesJena.getOntologyByURLNonSilently(UtilitiesJena.java:54)
    at websemantics.utils.UtilitiesJena.getOntologyByURL(UtilitiesJena.java:184)
    at websemantics.utils.UtilitiesSparql.runSparqlQueryOverDump(UtilitiesSparql.java:299)
    at websemantics.utils.UtilitiesSparql.runSparqlQuery(UtilitiesSparql.java:249)
    at websemantics.utils.UtilitiesSparql$SparqlTask.call(UtilitiesSparql.java:74)
    at websemantics.utils.UtilitiesSparql$SparqlTask.call(UtilitiesSparql.java:41)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:744)

我使用的 Jena 版本是 2.10.0，因为我对 Maven 的依赖显示:

<dependency>
    <groupId>org.apache.jena</groupId>
    <artifactId>apache-jena-libs</artifactId>
    <type>pom</type>
    <version>2.10.0</version>
</dependency>

第一个堆栈上 QueryFactory 的第 78 行如下(在箭头 --> 处):

   static public Query create(String queryString, String baseURI, Syntax syntax)
   {
78->Query query = new Query() ;
       return parse(query, queryString, baseURI, syntax) ;
   }

第二个堆栈上 ModelFactory 的第 144 行是:

public static Model createDefaultModel()
        144->{ return new ModelCom( Factory.createGraphMem( ) ); }

据我所知，以下调用都没有任何同步块(synchronized block)。

Answer 1

我在耶拿没有看到任何明显的东西会导致您描述的死锁行为类型。首先这是什么版本的 Jena？

第 78 行的

QueryFactory.create() 只是创建一个对象的新实例，因此您可能会遇到 JVM 的 GC 问题，尽管通常我希望看到非零 CPU 使用率(如果是这种情况)。增加堆大小并在使用完资源后调用 close() 来检查是否正确处置了诸如 QueryExecution 之类的资源可能会有所帮助。

您提到，如果您同步 QueryFactory.create() 调用，那么您会在其他地方看到死锁，提供此信息将有助于诊断您的问题。在您的答案中发布完整的线程转储也会很有用，这样我们就可以看到每个线程正在做什么，而不仅仅是一个线程。

请注意，Jena 的并发查询数量不应有任何硬性限制。在我的雇主，我们经常运行使用 Jena 的测试工具，并愉快地运行 100 个并发查询请求以进行压力测试。

编辑

所以我认为问题是静态类初始化器中有同步 block ，请从 1315 转储中查看这个特定线程:

"pool-1-thread-62" prio=6 tid=0x0000000029cf7000 nid=0xcbc in Object.wait() [0x000000002f9cd000]
   java.lang.Thread.State: RUNNABLE
    at org.apache.jena.riot.RIOT.<clinit>(RIOT.java:38)
    at java.lang.Class.forName0(Native Method)
    at java.lang.Class.forName(Class.java:190)
    at com.hp.hpl.jena.rdf.model.impl.IO_Ctl.callByRefection(IO_Ctl.java:54)
    at com.hp.hpl.jena.rdf.model.impl.IO_Ctl.init(IO_Ctl.java:36)
    - locked <0x00000006e5bda610> (a java.lang.Object)
    at com.hp.hpl.jena.rdf.model.impl.ModelCom.<clinit>(ModelCom.java:65)
    at com.hp.hpl.jena.rdf.model.ModelFactory.createDefaultModel(ModelFactory.java:140)
    at com.hp.hpl.jena.util.FileManager.loadModelWorker(FileManager.java:305)
    at com.hp.hpl.jena.util.FileManager.loadModel(FileManager.java:258)
    at websemantics.utils.UtilitiesJena.getModelInEverySyntax(UtilitiesJena.java:140)
    at websemantics.utils.UtilitiesJena.getOntologyByURLNonSilently(UtilitiesJena.java:121)
    at websemantics.utils.UtilitiesJena.getOntologyByURLNonSilently(UtilitiesJena.java:54)
    at websemantics.utils.UtilitiesJena.getOntologyByURL(UtilitiesJena.java:184)
    at websemantics.utils.UtilitiesSparql.runSparqlQueryOverDump(UtilitiesSparql.java:299)
    at websemantics.utils.UtilitiesSparql.runSparqlQuery(UtilitiesSparql.java:249)
    at websemantics.utils.UtilitiesSparql$SparqlTask.call(UtilitiesSparql.java:74)
    at websemantics.utils.UtilitiesSparql$SparqlTask.call(UtilitiesSparql.java:41)
    at java.util.concurrent.FutureTask.run(FutureTask.java:262)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:744)

ModelCom 有一个静态类初始化程序，它调用 IO_Ctl.init()，后者调用具有静态类初始化程序的 RIOT。当然，在过去，我知道我们有错误报告静态初始化链进入循环引用，这会导致死锁或者事物会以错误的顺序初始化并相互破坏。

我知道我们已经修复了这方面的错误，因此升级到当前稳定的 2.11.1 版本，因此从 2013 年 2 月的 Jena 2.10.0 升级到 2014 年 1 月的 2.11.1 可能会解决问题。

您可以尝试的另一种可能的解决方法是在代码进入多线程之前自己显式调用相关的初始化程序，例如

ARQ.init();
RIOT.init();