mmisw / orr-ont

ORR Backend system
Apache License 2.0
8 stars 5 forks source link

Upgrade Apache Jena to 3.2.0 #45

Closed lewismc closed 7 years ago

lewismc commented 7 years ago

ORR currently uses Jena version 2.11.1 which is old and still contains the old HP package naming convention. This has now been changed to org.apache.jena so hopefully updating the version and package naming should be all that is required to perform the upgrade. I'll send a pull request with exactly that.

carueda commented 7 years ago

Yes, definitely! Thanks for the reminder!

I in fact started using the newer version in other projects, most recently https://github.com/mmisw/orr-reg

lewismc commented 7 years ago

Working on a pull request just now.

carueda commented 7 years ago

Tests should be performed by Travis by the time you submit your PR (I think). Anyways, if you want to test locally, just have MongoDB running on its default port 27017. If this represent overhead for you, I can take care of the tests from your fork after I get the PR notification. Thanks again for the offer to contribute!!

lewismc commented 7 years ago

See #46

carueda commented 7 years ago

Exactly what I was saying ; ) -- Travis is doing the tests for us.

lewismc commented 7 years ago

https://travis-ci.org/mmisw/orr-ont/jobs/221190663

carueda commented 7 years ago

Hmm, seems to be failing in the same way. I'll take a look closer by cloning your fork and testing locally on my side.

lewismc commented 7 years ago

ack

carueda commented 7 years ago

I just reproduced the issue locally. Although the Jena class names and method signatures have not changed (so compilation completes just fine), it seems that there's some API semantic discrepancy somewhere, which is causing the issue. This is not completely clear and I will need to review the Jena calls and possible use of deprecated methods, differences in behavior, etc. I'll let you know of course. Many thanks again for pushing this long-standing pending upgrade.

lewismc commented 7 years ago

ok doke, sounds good. I'll also try debugging the tests and see what I can come up with.

carueda commented 7 years ago

Hmm, I'm actually noting that SequenceSpec sometimes get stuck and never completes. The success at Travis was just a lucky run.

$ sbt test
...
21:26:24.318 [qtp553377743-86] DEBUG org.mmisw.orr.ont.service.OntService - saving uploaded file to ./orr-ont-base-directory-test/uploads/user-a8a81867-8304-41d6-bd74-8ae11246aba5/1491971184318.rdf
21:26:24.319 [qtp553377743-86] DEBUG org.mmisw.orr.ont.service.OntService - loading model from ./orr-ont-base-directory-test/uploads/user-a8a81867-8304-41d6-bd74-8ae11246aba5/1491971184318.rdf
21:26:24.320 [qtp553377743-86] DEBUG o.mmisw.orr.ont.swld.ontFileLoader$ - ontFileLoader.loadOntModel: lang=RDF/XML

No more output here.

By typing Ctrl+\ and looking at the stacktraces:

...
"qtp553377743-86" #86 prio=5 os_prio=31 tid=0x00007fc073034000 nid=0x8507 in Object.wait() [0x0000700008553000]
   java.lang.Thread.State: RUNNABLE
    at org.mmisw.orr.ont.util.Util2._createDefaultOntModel(Util2.java:74)
    at org.mmisw.orr.ont.util.Util2._loadModel(Util2.java:61)
    at org.mmisw.orr.ont.util.Util2.loadOntModel(Util2.java:44)
...
"specs2.DefaultExecutionStrategy-2" #67 prio=5 os_prio=31 tid=0x00007fc06fc2a800 nid=0x5b0b in Object.wait() [0x000070000772a000]
   java.lang.Thread.State: RUNNABLE
    at org.apache.jena.ontology.OntModelSpec.<clinit>(OntModelSpec.java:49)
    at org.mmisw.orr.ont.swld.ontUtil$.createDefaultOntModel(ontUtil.scala:256)
    at org.mmisw.orr.ont.swld.v2r$.getModel(v2r.scala:118)
    at org.mmisw.orr.ont.swld.v2rSpec$$anonfun$1$$anonfun$apply$20.apply(v2rSpec.scala:74)
...
"specs2.DefaultExecutionStrategy-1" #66 prio=5 os_prio=31 tid=0x00007fc075ed1800 nid=0x5a17 in Object.wait() [0x0000700007627000]
   java.lang.Thread.State: RUNNABLE
    at org.mmisw.orr.ont.swld.ontUtil$.createDefaultOntModel(ontUtil.scala:256)
    at org.mmisw.orr.ont.swld.v2r$.getModel(v2r.scala:118)
    at org.mmisw.orr.ont.swld.v2rSpec$$anonfun$1$$anonfun$apply$11.apply(v2rSpec.scala:48)
...
"pool-7-thread-1" #56 prio=5 os_prio=31 tid=0x00007fc076945000 nid=0x1407 in Object.wait() [0x0000700006d09000]
   java.lang.Thread.State: RUNNABLE
    at org.apache.jena.assembler.assemblers.OntModelAssembler.<clinit>(OntModelAssembler.java:56)
    at org.apache.jena.assembler.ConstAssembler.ontModel(ConstAssembler.java:59)
    at org.apache.jena.assembler.ConstAssembler.general(ConstAssembler.java:147)
    at org.apache.jena.sparql.core.assembler.AssemblerUtils.registerDataset(AssemblerUtils.java:68)
    at org.apache.jena.sparql.core.assembler.AssemblerUtils.init(AssemblerUtils.java:60)
    at org.apache.jena.query.ARQ.init(ARQ.java:590)
    - locked <0x00000007bb248660> (a java.lang.Object)
    at org.apache.jena.sparql.system.InitARQ.start(InitARQ.java:29)
    at org.apache.jena.system.JenaSystem.lambda$init$50(JenaSystem.java:119)
...
    - locked <0x00000007832e5690> (a java.lang.Object)
    at org.apache.jena.rdf.model.ModelFactory.<clinit>(ModelFactory.java:49)

Seems like some sort of deadlock is happening in Jena (or in ORR code in combination with class initializations in Jena).

SequenceSpec itself runs pretty much in sequence so the concurrent use of Jena is happening when other tests are being executed as well, which is the case with sbt test. In fact, running only SequenceSpec:

$ sbt testOnly org.mmisw.orr.ont.app.SequenceSpec

seems to consistently complete OK after many executions.

So, in conclusion, compared with the older version used, seems like the new Jena version is triggering situations that now need explicit controls for concurrent access. Need to carefully review this. One reference: https://jena.apache.org/documentation/notes/concurrency-howto.html

carueda commented 7 years ago

With the general test command sbt test I just reproduced the issue about SequenceSpec getting stuck. Attached is the output upon a Ctrl+\. jena32_stacks.txt

But I also just verified that the individual test files, when run in isolation, consistently complete OK:

carueda commented 7 years ago

The observed deadlock misbehavior seems to have been fixed by calling JenaSystem.init() at the very beginning of the tests.

Per https://jena.apache.org/documentation/notes/system-initialization.html, "Initialization occurs when JenaSystem.init() is first called." Although it then says, "Jena ensures that this is done when the application first uses any Jena code by using class initializers," which seems to suggest the call is not strictly required in application code(?).

Anyways, making the explicit call looks like a good adjustment in general.

Of course, JenaSystem.init() also called in the main application.


The following shows the top of some of the stacks upon other tests before the fix. Note they mostly happen in Jena code.

"qtp961048885-712" #712 prio=5 os_prio=31 tid=0x00007fe76b5e9800 nid=0xc51f in Object.wait() [0x0000700005353000]
   java.lang.Thread.State: RUNNABLE
    at org.apache.jena.ontology.OntModelSpec.<clinit>(OntModelSpec.java:49)
    at org.mmisw.orr.ont.util.Util2._createDefaultOntModel(Util2.java:74)
"specs2.DefaultExecutionStrategy-4" #682 prio=5 os_prio=31 tid=0x00007fe769c16800 nid=0x9537 in Object.wait() [0x0000700003e15000]
   java.lang.Thread.State: RUNNABLE
    at org.apache.jena.vocabulary.DC_11.<clinit>(DC_11.java:29)
    at org.mmisw.orr.ont.swld.v2rSpec.vr1$lzycompute(v2rSpec.scala:17)
"pool-42-thread-4" #672 prio=5 os_prio=31 tid=0x00007fe771498800 nid=0x674b in Object.wait() [0x0000700001d88000]
   java.lang.Thread.State: RUNNABLE
    at org.apache.jena.shared.PrefixMapping.<clinit>(PrefixMapping.java:221)
    at org.apache.jena.sparql.ARQConstants.<clinit>(ARQConstants.java:106)
    at org.apache.jena.query.ARQ.init(ARQ.java:582)
    - locked <0x0000000790f11188> (a java.lang.Object)
    at org.apache.jena.sparql.system.InitARQ.start(InitARQ.java:29)
    at org.apache.jena.system.JenaSystem.lambda$init$43(JenaSystem.java:119)
    at org.apache.jena.system.JenaSystem$$Lambda$383/1521855729.accept(Unknown Source)
    at java.util.ArrayList.forEach(ArrayList.java:1249)
    at org.apache.jena.system.JenaSystem.forEach(JenaSystem.java:194)
"specs2.DefaultExecutionStrategy-4" #682 prio=5 os_prio=31 tid=0x00007fe769c16800 nid=0x9537 in Object.wait() [0x0000700003e15000]
   java.lang.Thread.State: RUNNABLE
    at org.apache.jena.vocabulary.DC_11.<clinit>(DC_11.java:29)
    at org.mmisw.orr.ont.swld.v2rSpec.vr1$lzycompute(v2rSpec.scala:17)
    - locked <0x0000000790ebf798> (a org.mmisw.orr.ont.swld.v2rSpec)
    at org.mmisw.orr.ont.swld.v2rSpec.vr1(v2rSpec.scala:14)
carueda commented 7 years ago

@lewismc Lewis, FYI I just enabled the resulting new ORR version with the underlying Jena libraries (now 3.3.0) in the MMI ORR instance at https://mmisw.org/ont/. The ORR there is now 3.5.0. I just upgraded the MMI ORR instance from the old v2 and took the opportunity to include this library update as part of the ongoing tests. I will of course update the COR instance in due course.

lewismc commented 7 years ago

Excellent @carueda I'm also working with Jena master so it is looking good. Please ping me if you experience any persistent issues. Thanks