【问题标题】:Weird behavior in a multithread java application (deadlock without lock?)多线程 Java 应用程序中的奇怪行为(没有锁的死锁?)
【发布时间】:2014-03-20 22:42:04
【问题描述】:

在尝试运行多个线程来收集 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”。

如您所见,代码“锁定”了查询对象的创建(稍后将通过网络执行)。为了测试,我已经包含了一个同步块,方法 QueryFactory.create 将被调用一次。在这种情况下,耶拿代码的另一部分(我认为它不是负责任的)阻塞 =(

整个情况对我来说太奇怪了,我认为这可能是一个 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( ) ); }

据我所知,以下调用都没有任何同步块。

【问题讨论】:

  • 是 QueryFactory.java:78 中的大多数线程吗?这条线包含什么?如果是一个复杂的语句,试着把它分成几行。
  • 另一件事(在检查大多数线程停止的代码之后)您应该尝试获取多个线程转储并比较它们。可能应该出现一些模式。从接线解决方案中获取转储信息以查看是否有任何不同也可能会有所帮助。
  • 嗨,我在你问的问题中添加了更多信息 =)

标签: java multithreading deadlock jena


【解决方案1】:

我在 Jena 中看不到任何明显会导致您描述的死锁行为类型的东西。首先,这是什么版本的 Jena?

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

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

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

编辑

所以我认为问题在于静态类初始化程序中有 synchronized 块,请参阅 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();

【讨论】:

  • 我也不是 =) 实际上,我认为这不是耶拿问题。我使用的版本是 2.10.0,但我会使用最新版本进行测试。
  • 关于同步块,我现在无法做到这一点,但晚上我会,然后我把更多信息放在这里。非常感谢!
  • 好的,我想我知道可能是什么问题了,看看我编辑的答案
  • 嗨!我真的尝试升级版本,我的工具能够正常运行 =) 非常感谢!问题是:线程转储不应该在这些情况下将此线程显示为阻塞?我的意思是,我从来没有在静态块中遇到死锁,所以这种行为非常奇怪 =)
猜你喜欢
  • 1970-01-01
  • 1970-01-01
  • 2014-03-20
  • 2014-07-19
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 2018-06-16
相关资源
最近更新 更多