New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Upgrade Apache Jena to 3.2.0 #45

Closed
lewismc opened this Issue Apr 12, 2017 · 15 comments

Comments

Projects
None yet
2 participants
@lewismc
Contributor

lewismc commented Apr 12, 2017

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

This comment has been minimized.

Show comment
Hide comment
@carueda

carueda Apr 12, 2017

Member

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

Member

carueda commented Apr 12, 2017

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

This comment has been minimized.

Show comment
Hide comment
@lewismc

lewismc Apr 12, 2017

Contributor

Working on a pull request just now.

Contributor

lewismc commented Apr 12, 2017

Working on a pull request just now.

@lewismc lewismc closed this Apr 12, 2017

@lewismc lewismc reopened this Apr 12, 2017

@carueda

This comment has been minimized.

Show comment
Hide comment
@carueda

carueda Apr 12, 2017

Member

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!!

Member

carueda commented Apr 12, 2017

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

This comment has been minimized.

Show comment
Hide comment
@lewismc

lewismc Apr 12, 2017

Contributor

See #46

Contributor

lewismc commented Apr 12, 2017

See #46

@carueda

This comment has been minimized.

Show comment
Hide comment
@carueda

carueda Apr 12, 2017

Member

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

Member

carueda commented Apr 12, 2017

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

@lewismc

This comment has been minimized.

Show comment
Hide comment
Contributor

lewismc commented Apr 12, 2017

@carueda

This comment has been minimized.

Show comment
Hide comment
@carueda

carueda Apr 12, 2017

Member

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.

Member

carueda commented Apr 12, 2017

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

This comment has been minimized.

Show comment
Hide comment
@lewismc

lewismc Apr 12, 2017

Contributor

ack

Contributor

lewismc commented Apr 12, 2017

ack

@carueda

This comment has been minimized.

Show comment
Hide comment
@carueda

carueda Apr 12, 2017

Member

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.

Member

carueda commented Apr 12, 2017

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

This comment has been minimized.

Show comment
Hide comment
@lewismc

lewismc Apr 12, 2017

Contributor

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

Contributor

lewismc commented Apr 12, 2017

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

@carueda carueda closed this in 74b26eb Apr 12, 2017

@carueda

This comment has been minimized.

Show comment
Hide comment
@carueda

carueda Apr 12, 2017

Member

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

Member

carueda commented Apr 12, 2017

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

This comment has been minimized.

Show comment
Hide comment
@carueda

carueda May 29, 2017

Member

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:

  • > testOnly org.mmisw.orr.ont.app.SequenceSpec
  • > testOnly org.mmisw.orr.ont.swld.m2rSpec
  • > testOnly org.mmisw.orr.ont.swld.v2rSpec
Member

carueda commented May 29, 2017

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:

  • > testOnly org.mmisw.orr.ont.app.SequenceSpec
  • > testOnly org.mmisw.orr.ont.swld.m2rSpec
  • > testOnly org.mmisw.orr.ont.swld.v2rSpec

@carueda carueda closed this in 3a7119f May 30, 2017

@carueda

This comment has been minimized.

Show comment
Hide comment
@carueda

carueda May 30, 2017

Member

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)
Member

carueda commented May 30, 2017

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 carueda removed the bug label May 30, 2017

@carueda carueda added this to the June-2017 milestone May 30, 2017

@carueda

This comment has been minimized.

Show comment
Hide comment
@carueda

carueda May 30, 2017

Member

@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.

Member

carueda commented May 30, 2017

@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

This comment has been minimized.

Show comment
Hide comment
@lewismc

lewismc May 30, 2017

Contributor

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

Contributor

lewismc commented May 30, 2017

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment