You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@jena.apache.org by Milorad Tosic <mb...@yahoo.com> on 2011/12/16 14:39:18 UTC

comparison of JVM and Jena versions by memory usage

Hi,


There is a short discussion on the former Jena Development/Support mailing list related to memory usage of Jena OntModel using different versions of Jena. For your information I have included a segment of the correspondence at the end of the message. Since I had a problem that looks much like memory usage limit overrun, I got interested in the problem.


I repeated the same experiment but with 
different conclusions? I compared Jena 2.6.0 with Jena 2.6.4. I couldn't
 notice the difference between Jena versions as reported in your 
previous experiment (though I used the same code). Tried with several 
variations of the OntModel creations styles but with minor differences 
in memory usage only (within 10%). I run the experiment from within 
Eclipse with JVM set to jre6 using compiler compliance level 1.5 (as 
well as 1.6). The total memory usage was around 27975k.
 
Than, I changed the JVM to jdk 1.5. There was similar relative 
difference between the Jena 2.6.0 and Jena 2.6.4 (within 10%). However, 
the absolute amount of used memory dropped to about 3400k.
 
Than I again changed the JVM to jdk 1.6. As in all previous testing 
configurations, there was similar relative difference between the Jena 
2.6.0 and Jena 2.6.4 (within 10%). However, the absolute amount of used 
memory was about 6501k.
 
Consequently, I have two problems now:
 
1) I couldn't repeat you experiment with the same results. What I am doing wrong?
 
2) What should I do to put the memory usage under my control? Namely, 5
 times larger memory usage cause my application to broke on machines 
with limited memory usage.
 
Thanks,
Milorad Tosic
> 
> --- In jena-dev@yahoogroups.com, Dave Reynolds <da...@...> wrote:
> >
> > Rick,
> > 
> > Thanks for letting us know, thanks for the clear report.
> > 
> > Dave
> > 
> > rspates2 wrote:
> > > Dave,
> > > 
>
 > > I grabbed OWLProfile.java and reran my tests.  It looks fixed
 to me in terms of speed and memory use.  We should be able to use 2.6.2
 now.
> > > 
> > > Thanks for your swift resolution to the problem.
> > > 
> > > Rick
> > > 
> > > --- In jena-dev@yahoogroups.com, Dave Reynolds <dave.e.reynolds@> wrote:
> > >> Hi Rick,
> > >>
> > >> A follow up on my earlier off-list response.
> > >>
> > >> Thanks again for giving us a test case for this. It turns out not to be 
> > >> a reasoner issue as such.  There was a change in the internals of the 
> > >> Ontology API which worked inefficiently when a reasoner is present.  Ian 
> > >> has checked in some patches for this which brings the memory use down a 
> > >> lot and gives a 5x speed improvement.
> > >>
> > >> It is not quite back to 2.6.0 timings but is a significant improvement.
> > >>
> > >> We'll investigate a little more but this may be as close as we can get 
> > >> for now. Let us know if this is enough to make it usable for you.
> > >>
> > >> Cheers,
> > >> Dave
> > >>
> > >> rspates2 wrote:
> > >>> Dave,
> > >>>
> > >>> The difference seems to be between 2.6.0 and 2.6.2,
> > >>>
> > >>> OntModel.listClasses():
> > >>> 2.6.2    time: 2187, totMem: 19948k, usedMem: 13345k
> > >>> 2.6.0    time: 110, totMem: 5056k, usedMem: 3681k
> > >>> 2.5.7    time: 78, totMem: 5056k, usedMem: 3726k
> > >>>
> > >>> listHierarchyRootClasses():
> > >>> 2.6.2    time: 2312, totMem: 20152k, usedMem: 13859k
> > >>> 2.6.0    time: 172, totMem: 5056k, usedMem: 4312k
> > >>> 2.5.7    time: 188, totMem: 5056k, usedMem: 4078k
> > >>>
> > >>> Let me know if you need anything else.
> > >>>
> > >>> Thanks,
> > >>> Rick
> > >>>
> > >>> --- In jena-dev@yahoogroups.com, Dave Reynolds <dave.e.reynolds@> wrote:
> > >>>> rspates2 wrote:
> > >>>>> Hi,
> > >>>>>
>
 > >>>>> We switched our application from Jena 2.5.7 
to 2.6.2.  For an operation on OntModel.listHierarchyRootClasses() with 
an OntModelSpec of OWL_MEM_RDFS_INF, we saw a very significant increase 
in the use of memory and processing time, including out-of-memory 
condition for our full ontology.  Using a subset of our ontology and the
 code below to demonstrate, we measured processing times and memory use:
> > >>>>>
> > >>>>> 2.6.2    time: 2063, totMem: 20008k, usedMem: 14539k
> > >>>>> 2.5.7    time: 172, totMem: 5056k, usedMem: 3974k
> > >>>> Certainly a huge jump :(
> > >>>>
>
 > >>>>> The specifications OWL_MEM_RDFS_INF and 
OWL_DL_MEM_RDFS_INF produced comparable results, while 
OWL_DL_MEM_TRANS_INF at 2.6.2 was comparable to our 2.5.7 run with 
OWL_MEM_RDFS_INF.
> > >>>>>
> > 
>>>>> I can post the subset ontology if you need it (170 
k), but thought there might be some known explanation you could provide 
without running the demo code.  
> > >>>>>
> > >>>>> Any idea what is causing this?
> > >>>> No immediate ideas. The RFDS rule file itself hasn't changed in that 
> > >>>> time frame. It is tricky to trace back code changes over that period 
> > >>>> because we did a code reorg which hides a lot of the history. However, 
> > >>>> from memory (and the release notes) I can't think of anything that 
> > >>>> should have had an effect like that. There were changes around handling 
> > >>>> validation of data types but that isn't relevant here. We generalized 
> > >>>> handling of non-legal RDF triples but again that shouldn't be relevant.
> > >>>>
> > >>>> Could you try two experiments?
> > >>>>
> > >>>> First, would it be possible to time a simpler operation, such as listing 
> > >>>> all classes, to eliminate listHierarchyRootClasses as a factor?
> > >>>>
> > >>>> Secondly, is it possible to check with Jena 2.6.0 - that would separate 
> > >>>> the Java 5 changes and the datatype validation from more recent tweaks?
> > >>>>
> > >>>> If that's a problem then send me your ontology subset and I'll take a 
> > >>>> look when I can.
> > >>>>
> > >>>> Dave
> > >>>>
> > >>>>> Thanks for your help,
> > >>>>> Rick
> > >>>>>
> > >>>>> import java.io.InputStream;
> > >>>>> import org.junit.Test;
> > >>>>>
> > >>>>> import com.hp.hpl.jena.ontology.OntModel;
> > >>>>> import com.hp.hpl.jena.ontology.OntModelSpec;
> > >>>>> import com.hp.hpl.jena.rdf.model.Model;
> > >>>>> import com.hp.hpl.jena.rdf.model.ModelFactory;
> > >>>>> import com.hp.hpl.jena.util.iterator.ExtendedIterator;
> > >>>>>
> > >>>>> public class TestReasonerProblem {
> > >>>>>
> > >>>>>     @Test
> > >>>>>     public void test() throws Exception {
> > >>>>>
> > >>>>>         Model model = ModelFactory.createDefaultModel();
> > >>>>>         String file="clinical-factDCMapVent.owl";
> > >>>>>         InputStream fis =  this.getClass().getResourceAsStream(file);
> > >>>>>         model.read(fis, null, "RDF/XML");
> > >>>>>         OntModelSpec spec = OntModelSpec.OWL_MEM_RDFS_INF;
> > >>>>> //        OntModelSpec spec = OntModelSpec.OWL_DL_MEM_RDFS_INF;
> > >>>>> //        OntModelSpec spec = OntModelSpec.OWL_DL_MEM_TRANS_INF;
> > >>>>>         OntModel ontModel = ModelFactory.createOntologyModel(spec, model);
> > >>>>>        
> > >>>>>         long ctms = System.currentTimeMillis();
> > >>>>>         for (ExtendedIterator j = ontModel.listHierarchyRootClasses(); j.hasNext(); ){
> > >>>>>             j.next();
> > >>>>>         }
> > >>>>>         System.out.printf("time: %d, totMem: %dk, usedMem: %dk\n",
> > >>>>>                 (System.currentTimeMillis()-ctms),
> > >>>>>                 (Runtime.getRuntime().totalMemory()/1024),
> > >>>>>                 ((Runtime.getRuntime().totalMemory()-Runtime.getRuntime().freeMemory())/1024));
> > >>>>>     }
> > >>>>>
> > >>>>> }
> > >>>>>
> > >>>>>
> > >>>>>
> > >>>>>
> > >>>>> ------------------------------------
> > >>>>>
> > >>>>> Yahoo! Groups Links
> > >>>>>
> > >>>>>
> > >>>>>
> > >>>
> > >>>
> > >>>
> > >>> ------------------------------------
> > >>>
> > >>> Yahoo! Groups Links
> > >>>
> > >>>
> > >>>
> > > 
> > > 
> > > 
> > > 
> > > ------------------------------------
> > > 
> > > Yahoo! Groups Links
> > > 
> > > 
> > >
> >
> 
> 

Re: comparison of JVM and Jena versions by memory usage

Posted by Milorad Tosic <mb...@yahoo.com>.

Hi Dave,

Thank you for your help with this issue!!! It is solved. Namely, the main problem was default XML parser used by Resin 2.1.13. After we changed the parser, the problem was eliminated.

Thank you again. Your help was very very effective.

Milorad

>________________________________
> From: Dave Reynolds <da...@gmail.com>
>To: jena-users@incubator.apache.org 
>Cc: Milorad Tosic <mb...@yahoo.com> 
>Sent: Monday, December 26, 2011 12:28 PM
>Subject: Re: comparison of JVM and Jena versions by memory usage
> 
>On 25/12/2011 10:24, Milorad Tosic wrote:
>> Hi Dave,
>>
>> I created simple test just to be sure that eventual additional dependencies are eliminated. Hence, I am now able to answer you questions:
>>
>>
>>> Is it the identical war file (assuming this is a war) in both cases?
>>
>> Yes.
>>
>>
>>> Is it an identical web container?
>>
>> No. One is Tomcat the other is Resin.
>
>Can you run the same test on a local Resin to test whether it is Resin 
>or the Java environment which is the problem?
>
>>> Is it the same jvm in each case?
>>
>>
>> I do not know! I can not know jvm version running on the shared rented server.
>
>Actually you can, write a test war (or an extra test page in the current 
>war) that lists the content of java.util.System.getProperties.
>
>>> Your error trace is from when the Jena Runtime starts up - it is loading
>>> a metadata file which should be in the Jena jar and accessible via the
>>> classloader. It looks like the classloader can't find the resource which
>>> suggests a broken set of jars or just maybe a duff jvm.
>>
>> Yes. It definitely looks like a problem with classloader. Broken set of jars: I copied all jars from lib directory from Jena installation (C:\Install\Jena\Jena-2.6.4\lib). The only additional jar included in WAR is json.jar. I doubt that broken set of jar may be in question here?
>
>Assuming your war is correctly packaged then that sounds OK.
>
>However, most application containers also have a notion of an "endorsed" 
>directory. If your hosting environment has an inconsistent copy of jena 
>in "endorsed" that might explain it (though that sounds wildly unlikely!).
>
>> Duff jvm: Though I can not tell what jvm is it, this is the first time that something like this error happens. Assuming the jvm is duff, but I do not have administration rights over it, what are my options to fix the problem?
>
>Short of asking your hosting provider to offer a different jvm then I'm 
>not sure.
>
>If, via the above suggestion, you identify the jvm and can then run that 
>jvm and Resin locally to reproduce the problem then you may be able to 
>find a work around. Depends on the underlying cause which currently I, 
>at least, have no idea about!
>
>Dave
>
>
>
>>
>> Thanks,
>> Milorad
>>
>>
>>> ________________________________
>>> From: Dave Reynolds<da...@gmail.com>
>>> To: Milorad Tosic<mb...@yahoo.com>
>>> Cc: "jena-users@incubator.apache.org"<je...@incubator.apache.org>
>>> Sent: Saturday, December 17, 2011 6:45 PM
>>> Subject: Re: comparison of JVM and Jena versions by memory usage
>>>
>>> Hi Milorad,
>>>
>>>> Memory limit was my best theory about what is going on with my application. Namely, I am trying to migrate an application using Jena from dedicated server to a shared server. The exactly same code is running without any problems until it is ported on the dedicated server. I paste my error trace at the end of the message for your reference.
>>>
>>> That looks likely to be an inconsistent set of jars.
>>>
>>> Is it the identical war file (assuming this is a war) in both cases?
>>> Is it an identical web container?
>>> Might you have multiple versions of Jena on the classpath (e.g. due to
>>> putting something in an endorsed directory)?
>>> Is it the same jvm in each case?
>>>
>>>> The application simply diminish without any exception caught. I traced it down to the single line instantiating OntModel (default reasoner, no ontology loaded initially):
>>>>
>>>> OntModel metaMCQ = null;
>>>>
>>>> metaMCQ = ModelFactory.createOntologyModel();
>>>
>>> I suspect that's just because it is the first call which causes Jena to
>>> do anything non trivial.
>>>
>>> Your error trace is from when the Jena Runtime starts up - it is loading
>>> a metadata file which should be in the Jena jar and accessible via the
>>> classloader. It looks like the classloader can't find the resource which
>>> suggests a broken set of jars or just maybe a duff jvm.
>>>
>>> Dave
>>>
>>>>
>>>> Exactly the same code works on the dedicated server while keeps crashing on the shared server?
>>>>
>>>> Thank you in advance,
>>>> Milorad
>>>>
>>>>
>>>> My error trace follows:
>>>>
>>>> java.lang.ExceptionInInitializerError
>>>> at com.hp.hpl.jena.rdf.model.impl.RDFReaderFImpl.&lt;clinit>(RDFReaderFImpl.java:85)
>>>> at com.hp.hpl.jena.rdf.model.impl.ModelCom.&lt;clinit>(ModelCom.java:42)
>>>> at com.hp.hpl.jena.rdf.model.ModelFactory.createDefaultModel(ModelFactory.java:122)
>>>> at com.hp.hpl.jena.rdf.model.ModelFactory.createDefaultModel(ModelFactory.java:116)
>>>> at com.hp.hpl.jena.vocabulary.OWL.&lt;clinit>(OWL.java:37)
>>>> at com.hp.hpl.jena.ontology.ProfileRegistry.&lt;clinit>(ProfileRegistry.java:48)
>>>> at com.hp.hpl.jena.rdf.model.ModelFactory.createOntologyModel(ModelFactory.java:344)
>>>> at com.virtuona.service.semcqgenerator.SeMCQgeneratorService.runApp(SeMCQgeneratorService.java:182)
>>>> at com.virtuona.service.semcqgenerator.SeMCQgeneratorService.runService(SeMCQgeneratorService.java:380)
>>>> at com.virtuona.service.ServiceCaller.callService(ServiceCaller.java:28)
>>>> at com.virtuona.service.ServletServiceCaller.callService(ServletServiceCaller.java:397)
>>>> at com.virtuona.service.ServletServiceCaller.procesRequest(ServletServiceCaller.java:258)
>>>> at com.virtuona.service.ServletServiceCaller.doPost(ServletServiceCaller.java:107)
>>>> at javax.servlet.http.HttpServlet.service(HttpServlet.java:165)
>>>> at javax.servlet.http.HttpServlet.service(HttpServlet.java:103)
>>>> at com.caucho.server.http.FilterChainServlet.doFilter(FilterChainServlet.java:96)
>>>> at com.caucho.server.http.Invocation.service(Invocation.java:315)
>>>> at com.caucho.server.http.CacheInvocation.service(CacheInvocation.java:135)
>>>> at com.caucho.server.http.RunnerRequest.handleRequest(RunnerRequest.java:346)
>>>> at com.caucho.server.http.RunnerRequest.handleConnection(RunnerRequest.java:274)
>>>> at com.caucho.server.TcpConnection.run(TcpConnection.java:139)
>>>> at java.lang.Thread.run(Thread.java:595)
>>>> Caused by: java.lang.NullPointerException
>>>> at java.util.XMLUtils.load(XMLUtils.java:62)
>>>> at java.util.Properties.loadFromXML(Properties.java:701)
>>>> at com.hp.hpl.jena.util.Metadata.read(Metadata.java:67)
>>>> at com.hp.hpl.jena.util.Metadata.addMetadata(Metadata.java:41)
>>>> at com.hp.hpl.jena.util.Metadata.&lt;init>(Metadata.java:35)
>>>> at com.hp.hpl.jena.JenaRuntime.&lt;clinit>(JenaRuntime.java:25)
>>>> ... 22 more
>>>>
>>>>
>>>>
>>>>
>>>>> ________________________________
>>>>> From: Dave Reynolds<da...@gmail.com>
>>>>> To: Milorad Tosic<mb...@yahoo.com>
>>>>> Cc: "jena-users@incubator.apache.org"<je...@incubator.apache.org>
>>>>> Sent: Friday, December 16, 2011 4:41 PM
>>>>> Subject: Re: comparison of JVM and Jena versions by memory usage
>>>>>
>>>>> Hi,
>>>>>
>>>>> On Fri, 2011-12-16 at 05:39 -0800, Milorad Tosic wrote:
>>>>>> Hi,
>>>>>>
>>>>>>
>>>>>> There is a short discussion on the former Jena Development/Support mailing list related to memory usage of Jena OntModel using different versions of Jena. For your information I have included a segment of the correspondence at the end of the message. Since I had a problem that looks much like memory usage limit overrun, I got interested in the problem.
>>>>>>
>>>>>>
>>>>>> I repeated the same experiment but with
>>>>>> different conclusions? I compared Jena 2.6.0 with Jena 2.6.4. I couldn't
>>>>>>    notice the difference between Jena versions as reported in your
>>>>>> previous experiment (though I used the same code). Tried with several
>>>>>> variations of the OntModel creations styles but with minor differences
>>>>>> in memory usage only (within 10%). I run the experiment from within
>>>>>> Eclipse with JVM set to jre6 using compiler compliance level 1.5 (as
>>>>>> well as 1.6). The total memory usage was around 27975k.
>>>>>>
>>>>>> Than, I changed the JVM to jdk 1.5. There was similar relative
>>>>>> difference between the Jena 2.6.0 and Jena 2.6.4 (within 10%). However,
>>>>>> the absolute amount of used memory dropped to about 3400k.
>>>>>>
>>>>>> Than I again changed the JVM to jdk 1.6. As in all previous testing
>>>>>> configurations, there was similar relative difference between the Jena
>>>>>> 2.6.0 and Jena 2.6.4 (within 10%). However, the absolute amount of used
>>>>>> memory was about 6501k.
>>>>>>
>>>>>> Consequently, I have two problems now:
>>>>>>
>>>>>> 1) I couldn't repeat you experiment with the same results. What I am doing wrong?
>>>>>
>>>>> Assuming you are running the code that Rick originally posted then the
>>>>> problem is that that uses a naive way to measure memory usage.
>>>>> If I run with java 1.6 (sun-java on Linux) and the current Jena snapshot
>>>>> and run in eclipse I get:
>>>>>
>>>>> time: 19, totMem: 122688k, usedMem: 4859k
>>>>>
>>>>> If I run identical code from the command line I get:
>>>>> time: 12, totMem: 122688k, usedMem: 28548k
>>>>>
>>>>> The difference is down to whether a garbage collect has kicked in. If I
>>>>> force a System.gc() in that code then I get:
>>>>>
>>>>> time: 86, totMem: 122688k, usedMem: 4006k
>>>>>
>>>>> where the extra time comes from the garbage collect.
>>>>>
>>>>>
>>>>>> 2) What should I do to put the memory usage under my control? Namely, 5
>>>>>>    times larger memory usage cause my application to broke on machines
>>>>>> with limited memory usage.
>>>>>
>>>>> I don't think there's any evidence that the problem in the thread that
>>>>> you are referring to is still an issue.
>>>>>
>>>>> You would need to explain more about what you are actually do in your
>>>>> application before we could help with that. However, if you are
>>>>> currently using inference and are having memory problems then avoiding
>>>>> inference, or using a weaker inference setting, would be a good place to
>>>>> start.
>>>>>
>>>>> Dave
>>>>>
>>>>>>
>>>>>> Thanks,
>>>>>> Milorad Tosic
>>>>>>>
>>>>>>> --- In jena-dev@yahoogroups.com, Dave Reynolds<da...@...>  wrote:
>>>>>>>>
>>>>>>>> Rick,
>>>>>>>>
>>>>>>>> Thanks for letting us know, thanks for the clear report.
>>>>>>>>
>>>>>>>> Dave
>>>>>>>>
>>>>>>>> rspates2 wrote:
>>>>>>>>> Dave,
>>>>>>>>>
>>>>>>>
>>>>>>    >  >  I grabbed OWLProfile.java and reran my tests.  It looks fixed
>>>>>>    to me in terms of speed and memory use.  We should be able to use 2.6.2
>>>>>>    now.
>>>>>>>>>
>>>>>>>>> Thanks for your swift resolution to the problem.
>>>>>>>>>
>>>>>>>>> Rick
>>>>>>>>>
>>>>>>>>> --- In jena-dev@yahoogroups.com, Dave Reynolds<dave.e.reynolds@>  wrote:
>>>>>>>>>> Hi Rick,
>>>>>>>>>>
>>>>>>>>>> A follow up on my earlier off-list response.
>>>>>>>>>>
>>>>>>>>>> Thanks again for giving us a test case for this. It turns out not to be
>>>>>>>>>> a reasoner issue as such.  There was a change in the internals of the
>>>>>>>>>> Ontology API which worked inefficiently when a reasoner is present.  Ian
>>>>>>>>>> has checked in some patches for this which brings the memory use down a
>>>>>>>>>> lot and gives a 5x speed improvement.
>>>>>>>>>>
>>>>>>>>>> It is not quite back to 2.6.0 timings but is a significant improvement.
>>>>>>>>>>
>>>>>>>>>> We'll investigate a little more but this may be as close as we can get
>>>>>>>>>> for now. Let us know if this is enough to make it usable for you.
>>>>>>>>>>
>>>>>>>>>> Cheers,
>>>>>>>>>> Dave
>>>>>>>>>>
>>>>>>>>>> rspates2 wrote:
>>>>>>>>>>> Dave,
>>>>>>>>>>>
>>>>>>>>>>> The difference seems to be between 2.6.0 and 2.6.2,
>>>>>>>>>>>
>>>>>>>>>>> OntModel.listClasses():
>>>>>>>>>>> 2.6.2    time: 2187, totMem: 19948k, usedMem: 13345k
>>>>>>>>>>> 2.6.0    time: 110, totMem: 5056k, usedMem: 3681k
>>>>>>>>>>> 2.5.7    time: 78, totMem: 5056k, usedMem: 3726k
>>>>>>>>>>>
>>>>>>>>>>> listHierarchyRootClasses():
>>>>>>>>>>> 2.6.2    time: 2312, totMem: 20152k, usedMem: 13859k
>>>>>>>>>>> 2.6.0    time: 172, totMem: 5056k, usedMem: 4312k
>>>>>>>>>>> 2.5.7    time: 188, totMem: 5056k, usedMem: 4078k
>>>>>>>>>>>
>>>>>>>>>>> Let me know if you need anything else.
>>>>>>>>>>>
>>>>>>>>>>> Thanks,
>>>>>>>>>>> Rick
>>>>>>>>>>>
>>>>>>>>>>> --- In jena-dev@yahoogroups.com, Dave Reynolds<dave.e.reynolds@>  wrote:
>>>>>>>>>>>> rspates2 wrote:
>>>>>>>>>>>>> Hi,
>>>>>>>>>>>>>
>>>>>>>
>>>>>>    >  >>>>>  We switched our application from Jena 2.5.7
>>>>>> to 2.6.2.  For an operation on OntModel.listHierarchyRootClasses() with
>>>>>> an OntModelSpec of OWL_MEM_RDFS_INF, we saw a very significant increase
>>>>>> in the use of memory and processing time, including out-of-memory
>>>>>> condition for our full ontology.  Using a subset of our ontology and the
>>>>>>    code below to demonstrate, we measured processing times and memory use:
>>>>>>>>>>>>>
>>>>>>>>>>>>> 2.6.2    time: 2063, totMem: 20008k, usedMem: 14539k
>>>>>>>>>>>>> 2.5.7    time: 172, totMem: 5056k, usedMem: 3974k
>>>>>>>>>>>> Certainly a huge jump :(
>>>>>>>>>>>>
>>>>>>>
>>>>>>    >  >>>>>  The specifications OWL_MEM_RDFS_INF and
>>>>>> OWL_DL_MEM_RDFS_INF produced comparable results, while
>>>>>> OWL_DL_MEM_TRANS_INF at 2.6.2 was comparable to our 2.5.7 run with
>>>>>> OWL_MEM_RDFS_INF.
>>>>>>>>>>>>>
>>>>>>>>
>>>>>>>>>>> I can post the subset ontology if you need it (170
>>>>>> k), but thought there might be some known explanation you could provide
>>>>>> without running the demo code.
>>>>>>>>>>>>>
>>>>>>>>>>>>> Any idea what is causing this?
>>>>>>>>>>>> No immediate ideas. The RFDS rule file itself hasn't changed in that
>>>>>>>>>>>> time frame. It is tricky to trace back code changes over that period
>>>>>>>>>>>> because we did a code reorg which hides a lot of the history. However,
>>>>>>>>>>>> from memory (and the release notes) I can't think of anything that
>>>>>>>>>>>> should have had an effect like that. There were changes around handling
>>>>>>>>>>>> validation of data types but that isn't relevant here. We generalized
>>>>>>>>>>>> handling of non-legal RDF triples but again that shouldn't be relevant.
>>>>>>>>>>>>
>>>>>>>>>>>> Could you try two experiments?
>>>>>>>>>>>>
>>>>>>>>>>>> First, would it be possible to time a simpler operation, such as listing
>>>>>>>>>>>> all classes, to eliminate listHierarchyRootClasses as a factor?
>>>>>>>>>>>>
>>>>>>>>>>>> Secondly, is it possible to check with Jena 2.6.0 - that would separate
>>>>>>>>>>>> the Java 5 changes and the datatype validation from more recent tweaks?
>>>>>>>>>>>>
>>>>>>>>>>>> If that's a problem then send me your ontology subset and I'll take a
>>>>>>>>>>>> look when I can.
>>>>>>>>>>>>
>>>>>>>>>>>> Dave
>>>>>>>>>>>>
>>>>>>>>>>>>> Thanks for your help,
>>>>>>>>>>>>> Rick
>>>>>>>>>>>>>
>>>>>>>>>>>>> import java.io.InputStream;
>>>>>>>>>>>>> import org.junit.Test;
>>>>>>>>>>>>>
>>>>>>>>>>>>> import com.hp.hpl.jena.ontology.OntModel;
>>>>>>>>>>>>> import com.hp.hpl.jena.ontology.OntModelSpec;
>>>>>>>>>>>>> import com.hp.hpl.jena.rdf.model.Model;
>>>>>>>>>>>>> import com.hp.hpl.jena.rdf.model.ModelFactory;
>>>>>>>>>>>>> import com.hp.hpl.jena.util.iterator.ExtendedIterator;
>>>>>>>>>>>>>
>>>>>>>>>>>>> public class TestReasonerProblem {
>>>>>>>>>>>>>
>>>>>>>>>>>>>       @Test
>>>>>>>>>>>>>       public void test() throws Exception {
>>>>>>>>>>>>>
>>>>>>>>>>>>>           Model model = ModelFactory.createDefaultModel();
>>>>>>>>>>>>>           String file="clinical-factDCMapVent.owl";
>>>>>>>>>>>>>           InputStream fis =  this.getClass().getResourceAsStream(file);
>>>>>>>>>>>>>           model.read(fis, null, "RDF/XML");
>>>>>>>>>>>>>           OntModelSpec spec = OntModelSpec.OWL_MEM_RDFS_INF;
>>>>>>>>>>>>> //        OntModelSpec spec = OntModelSpec.OWL_DL_MEM_RDFS_INF;
>>>>>>>>>>>>> //        OntModelSpec spec = OntModelSpec.OWL_DL_MEM_TRANS_INF;
>>>>>>>>>>>>>           OntModel ontModel = ModelFactory.createOntologyModel(spec, model);
>>>>>>>>>>>>>
>>>>>>>>>>>>>           long ctms = System.currentTimeMillis();
>>>>>>>>>>>>>           for (ExtendedIterator j = ontModel.listHierarchyRootClasses(); j.hasNext(); ){
>>>>>>>>>>>>>               j.next();
>>>>>>>>>>>>>           }
>>>>>>>>>>>>>           System.out.printf("time: %d, totMem: %dk, usedMem: %dk\n",
>>>>>>>>>>>>>                   (System.currentTimeMillis()-ctms),
>>>>>>>>>>>>>                   (Runtime.getRuntime().totalMemory()/1024),
>>>>>>>>>>>>>                   ((Runtime.getRuntime().totalMemory()-Runtime.getRuntime().freeMemory())/1024));
>>>>>>>>>>>>>       }
>>>>>>>>>>>>>
>>>>>>>>>>>>> }
>>>>>>>>>>>>>
>>>>>>>>>>>>>
>>>>>>>>>>>>>
>>>>>>>>>>>>>
>>>>>>>>>>>>> ------------------------------------
>>>>>>>>>>>>>
>>>>>>>>>>>>> Yahoo! Groups Links
>>>>>>>>>>>>>
>>>>>>>>>>>>>
>>>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>> ------------------------------------
>>>>>>>>>>>
>>>>>>>>>>> Yahoo! Groups Links
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> ------------------------------------
>>>>>>>>>
>>>>>>>>> Yahoo! Groups Links
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>
>>>>>>>>
>>>>>>>
>>>>>>>
>>>>>
>>>>>
>>>>>
>>>>>
>>>>>
>>>>>
>>>
>>>
>>>
>>>
>>>
>
>
>
>

Re: comparison of JVM and Jena versions by memory usage

Posted by Dave Reynolds <da...@gmail.com>.
On 25/12/2011 10:24, Milorad Tosic wrote:
> Hi Dave,
>
> I created simple test just to be sure that eventual additional dependencies are eliminated. Hence, I am now able to answer you questions:
>
>
>> Is it the identical war file (assuming this is a war) in both cases?
>
> Yes.
>
>
>> Is it an identical web container?
>
> No. One is Tomcat the other is Resin.

Can you run the same test on a local Resin to test whether it is Resin 
or the Java environment which is the problem?

>> Is it the same jvm in each case?
>
>
> I do not know! I can not know jvm version running on the shared rented server.

Actually you can, write a test war (or an extra test page in the current 
war) that lists the content of java.util.System.getProperties.

>> Your error trace is from when the Jena Runtime starts up - it is loading
>> a metadata file which should be in the Jena jar and accessible via the
>> classloader. It looks like the classloader can't find the resource which
>> suggests a broken set of jars or just maybe a duff jvm.
>
> Yes. It definitely looks like a problem with classloader. Broken set of jars: I copied all jars from lib directory from Jena installation (C:\Install\Jena\Jena-2.6.4\lib). The only additional jar included in WAR is json.jar. I doubt that broken set of jar may be in question here?

Assuming your war is correctly packaged then that sounds OK.

However, most application containers also have a notion of an "endorsed" 
directory. If your hosting environment has an inconsistent copy of jena 
in "endorsed" that might explain it (though that sounds wildly unlikely!).

> Duff jvm: Though I can not tell what jvm is it, this is the first time that something like this error happens. Assuming the jvm is duff, but I do not have administration rights over it, what are my options to fix the problem?

Short of asking your hosting provider to offer a different jvm then I'm 
not sure.

If, via the above suggestion, you identify the jvm and can then run that 
jvm and Resin locally to reproduce the problem then you may be able to 
find a work around. Depends on the underlying cause which currently I, 
at least, have no idea about!

Dave



>
> Thanks,
> Milorad
>
>
>> ________________________________
>> From: Dave Reynolds<da...@gmail.com>
>> To: Milorad Tosic<mb...@yahoo.com>
>> Cc: "jena-users@incubator.apache.org"<je...@incubator.apache.org>
>> Sent: Saturday, December 17, 2011 6:45 PM
>> Subject: Re: comparison of JVM and Jena versions by memory usage
>>
>> Hi Milorad,
>>
>>> Memory limit was my best theory about what is going on with my application. Namely, I am trying to migrate an application using Jena from dedicated server to a shared server. The exactly same code is running without any problems until it is ported on the dedicated server. I paste my error trace at the end of the message for your reference.
>>
>> That looks likely to be an inconsistent set of jars.
>>
>> Is it the identical war file (assuming this is a war) in both cases?
>> Is it an identical web container?
>> Might you have multiple versions of Jena on the classpath (e.g. due to
>> putting something in an endorsed directory)?
>> Is it the same jvm in each case?
>>
>>> The application simply diminish without any exception caught. I traced it down to the single line instantiating OntModel (default reasoner, no ontology loaded initially):
>>>
>>> OntModel metaMCQ = null;
>>>
>>> metaMCQ = ModelFactory.createOntologyModel();
>>
>> I suspect that's just because it is the first call which causes Jena to
>> do anything non trivial.
>>
>> Your error trace is from when the Jena Runtime starts up - it is loading
>> a metadata file which should be in the Jena jar and accessible via the
>> classloader. It looks like the classloader can't find the resource which
>> suggests a broken set of jars or just maybe a duff jvm.
>>
>> Dave
>>
>>>
>>> Exactly the same code works on the dedicated server while keeps crashing on the shared server?
>>>
>>> Thank you in advance,
>>> Milorad
>>>
>>>
>>> My error trace follows:
>>>
>>> java.lang.ExceptionInInitializerError
>>> at com.hp.hpl.jena.rdf.model.impl.RDFReaderFImpl.&lt;clinit>(RDFReaderFImpl.java:85)
>>> at com.hp.hpl.jena.rdf.model.impl.ModelCom.&lt;clinit>(ModelCom.java:42)
>>> at com.hp.hpl.jena.rdf.model.ModelFactory.createDefaultModel(ModelFactory.java:122)
>>> at com.hp.hpl.jena.rdf.model.ModelFactory.createDefaultModel(ModelFactory.java:116)
>>> at com.hp.hpl.jena.vocabulary.OWL.&lt;clinit>(OWL.java:37)
>>> at com.hp.hpl.jena.ontology.ProfileRegistry.&lt;clinit>(ProfileRegistry.java:48)
>>> at com.hp.hpl.jena.rdf.model.ModelFactory.createOntologyModel(ModelFactory.java:344)
>>> at com.virtuona.service.semcqgenerator.SeMCQgeneratorService.runApp(SeMCQgeneratorService.java:182)
>>> at com.virtuona.service.semcqgenerator.SeMCQgeneratorService.runService(SeMCQgeneratorService.java:380)
>>> at com.virtuona.service.ServiceCaller.callService(ServiceCaller.java:28)
>>> at com.virtuona.service.ServletServiceCaller.callService(ServletServiceCaller.java:397)
>>> at com.virtuona.service.ServletServiceCaller.procesRequest(ServletServiceCaller.java:258)
>>> at com.virtuona.service.ServletServiceCaller.doPost(ServletServiceCaller.java:107)
>>> at javax.servlet.http.HttpServlet.service(HttpServlet.java:165)
>>> at javax.servlet.http.HttpServlet.service(HttpServlet.java:103)
>>> at com.caucho.server.http.FilterChainServlet.doFilter(FilterChainServlet.java:96)
>>> at com.caucho.server.http.Invocation.service(Invocation.java:315)
>>> at com.caucho.server.http.CacheInvocation.service(CacheInvocation.java:135)
>>> at com.caucho.server.http.RunnerRequest.handleRequest(RunnerRequest.java:346)
>>> at com.caucho.server.http.RunnerRequest.handleConnection(RunnerRequest.java:274)
>>> at com.caucho.server.TcpConnection.run(TcpConnection.java:139)
>>> at java.lang.Thread.run(Thread.java:595)
>>> Caused by: java.lang.NullPointerException
>>> at java.util.XMLUtils.load(XMLUtils.java:62)
>>> at java.util.Properties.loadFromXML(Properties.java:701)
>>> at com.hp.hpl.jena.util.Metadata.read(Metadata.java:67)
>>> at com.hp.hpl.jena.util.Metadata.addMetadata(Metadata.java:41)
>>> at com.hp.hpl.jena.util.Metadata.&lt;init>(Metadata.java:35)
>>> at com.hp.hpl.jena.JenaRuntime.&lt;clinit>(JenaRuntime.java:25)
>>> ... 22 more
>>>
>>>
>>>
>>>
>>>> ________________________________
>>>> From: Dave Reynolds<da...@gmail.com>
>>>> To: Milorad Tosic<mb...@yahoo.com>
>>>> Cc: "jena-users@incubator.apache.org"<je...@incubator.apache.org>
>>>> Sent: Friday, December 16, 2011 4:41 PM
>>>> Subject: Re: comparison of JVM and Jena versions by memory usage
>>>>
>>>> Hi,
>>>>
>>>> On Fri, 2011-12-16 at 05:39 -0800, Milorad Tosic wrote:
>>>>> Hi,
>>>>>
>>>>>
>>>>> There is a short discussion on the former Jena Development/Support mailing list related to memory usage of Jena OntModel using different versions of Jena. For your information I have included a segment of the correspondence at the end of the message. Since I had a problem that looks much like memory usage limit overrun, I got interested in the problem.
>>>>>
>>>>>
>>>>> I repeated the same experiment but with
>>>>> different conclusions? I compared Jena 2.6.0 with Jena 2.6.4. I couldn't
>>>>>    notice the difference between Jena versions as reported in your
>>>>> previous experiment (though I used the same code). Tried with several
>>>>> variations of the OntModel creations styles but with minor differences
>>>>> in memory usage only (within 10%). I run the experiment from within
>>>>> Eclipse with JVM set to jre6 using compiler compliance level 1.5 (as
>>>>> well as 1.6). The total memory usage was around 27975k.
>>>>>
>>>>> Than, I changed the JVM to jdk 1.5. There was similar relative
>>>>> difference between the Jena 2.6.0 and Jena 2.6.4 (within 10%). However,
>>>>> the absolute amount of used memory dropped to about 3400k.
>>>>>
>>>>> Than I again changed the JVM to jdk 1.6. As in all previous testing
>>>>> configurations, there was similar relative difference between the Jena
>>>>> 2.6.0 and Jena 2.6.4 (within 10%). However, the absolute amount of used
>>>>> memory was about 6501k.
>>>>>
>>>>> Consequently, I have two problems now:
>>>>>
>>>>> 1) I couldn't repeat you experiment with the same results. What I am doing wrong?
>>>>
>>>> Assuming you are running the code that Rick originally posted then the
>>>> problem is that that uses a naive way to measure memory usage.
>>>> If I run with java 1.6 (sun-java on Linux) and the current Jena snapshot
>>>> and run in eclipse I get:
>>>>
>>>> time: 19, totMem: 122688k, usedMem: 4859k
>>>>
>>>> If I run identical code from the command line I get:
>>>> time: 12, totMem: 122688k, usedMem: 28548k
>>>>
>>>> The difference is down to whether a garbage collect has kicked in. If I
>>>> force a System.gc() in that code then I get:
>>>>
>>>> time: 86, totMem: 122688k, usedMem: 4006k
>>>>
>>>> where the extra time comes from the garbage collect.
>>>>
>>>>
>>>>> 2) What should I do to put the memory usage under my control? Namely, 5
>>>>>    times larger memory usage cause my application to broke on machines
>>>>> with limited memory usage.
>>>>
>>>> I don't think there's any evidence that the problem in the thread that
>>>> you are referring to is still an issue.
>>>>
>>>> You would need to explain more about what you are actually do in your
>>>> application before we could help with that. However, if you are
>>>> currently using inference and are having memory problems then avoiding
>>>> inference, or using a weaker inference setting, would be a good place to
>>>> start.
>>>>
>>>> Dave
>>>>
>>>>>
>>>>> Thanks,
>>>>> Milorad Tosic
>>>>>>
>>>>>> --- In jena-dev@yahoogroups.com, Dave Reynolds<da...@...>  wrote:
>>>>>>>
>>>>>>> Rick,
>>>>>>>
>>>>>>> Thanks for letting us know, thanks for the clear report.
>>>>>>>
>>>>>>> Dave
>>>>>>>
>>>>>>> rspates2 wrote:
>>>>>>>> Dave,
>>>>>>>>
>>>>>>
>>>>>    >  >  I grabbed OWLProfile.java and reran my tests.  It looks fixed
>>>>>    to me in terms of speed and memory use.  We should be able to use 2.6.2
>>>>>    now.
>>>>>>>>
>>>>>>>> Thanks for your swift resolution to the problem.
>>>>>>>>
>>>>>>>> Rick
>>>>>>>>
>>>>>>>> --- In jena-dev@yahoogroups.com, Dave Reynolds<dave.e.reynolds@>  wrote:
>>>>>>>>> Hi Rick,
>>>>>>>>>
>>>>>>>>> A follow up on my earlier off-list response.
>>>>>>>>>
>>>>>>>>> Thanks again for giving us a test case for this. It turns out not to be
>>>>>>>>> a reasoner issue as such.  There was a change in the internals of the
>>>>>>>>> Ontology API which worked inefficiently when a reasoner is present.  Ian
>>>>>>>>> has checked in some patches for this which brings the memory use down a
>>>>>>>>> lot and gives a 5x speed improvement.
>>>>>>>>>
>>>>>>>>> It is not quite back to 2.6.0 timings but is a significant improvement.
>>>>>>>>>
>>>>>>>>> We'll investigate a little more but this may be as close as we can get
>>>>>>>>> for now. Let us know if this is enough to make it usable for you.
>>>>>>>>>
>>>>>>>>> Cheers,
>>>>>>>>> Dave
>>>>>>>>>
>>>>>>>>> rspates2 wrote:
>>>>>>>>>> Dave,
>>>>>>>>>>
>>>>>>>>>> The difference seems to be between 2.6.0 and 2.6.2,
>>>>>>>>>>
>>>>>>>>>> OntModel.listClasses():
>>>>>>>>>> 2.6.2    time: 2187, totMem: 19948k, usedMem: 13345k
>>>>>>>>>> 2.6.0    time: 110, totMem: 5056k, usedMem: 3681k
>>>>>>>>>> 2.5.7    time: 78, totMem: 5056k, usedMem: 3726k
>>>>>>>>>>
>>>>>>>>>> listHierarchyRootClasses():
>>>>>>>>>> 2.6.2    time: 2312, totMem: 20152k, usedMem: 13859k
>>>>>>>>>> 2.6.0    time: 172, totMem: 5056k, usedMem: 4312k
>>>>>>>>>> 2.5.7    time: 188, totMem: 5056k, usedMem: 4078k
>>>>>>>>>>
>>>>>>>>>> Let me know if you need anything else.
>>>>>>>>>>
>>>>>>>>>> Thanks,
>>>>>>>>>> Rick
>>>>>>>>>>
>>>>>>>>>> --- In jena-dev@yahoogroups.com, Dave Reynolds<dave.e.reynolds@>  wrote:
>>>>>>>>>>> rspates2 wrote:
>>>>>>>>>>>> Hi,
>>>>>>>>>>>>
>>>>>>
>>>>>    >  >>>>>  We switched our application from Jena 2.5.7
>>>>> to 2.6.2.  For an operation on OntModel.listHierarchyRootClasses() with
>>>>> an OntModelSpec of OWL_MEM_RDFS_INF, we saw a very significant increase
>>>>> in the use of memory and processing time, including out-of-memory
>>>>> condition for our full ontology.  Using a subset of our ontology and the
>>>>>    code below to demonstrate, we measured processing times and memory use:
>>>>>>>>>>>>
>>>>>>>>>>>> 2.6.2    time: 2063, totMem: 20008k, usedMem: 14539k
>>>>>>>>>>>> 2.5.7    time: 172, totMem: 5056k, usedMem: 3974k
>>>>>>>>>>> Certainly a huge jump :(
>>>>>>>>>>>
>>>>>>
>>>>>    >  >>>>>  The specifications OWL_MEM_RDFS_INF and
>>>>> OWL_DL_MEM_RDFS_INF produced comparable results, while
>>>>> OWL_DL_MEM_TRANS_INF at 2.6.2 was comparable to our 2.5.7 run with
>>>>> OWL_MEM_RDFS_INF.
>>>>>>>>>>>>
>>>>>>>
>>>>>>>>>> I can post the subset ontology if you need it (170
>>>>> k), but thought there might be some known explanation you could provide
>>>>> without running the demo code.
>>>>>>>>>>>>
>>>>>>>>>>>> Any idea what is causing this?
>>>>>>>>>>> No immediate ideas. The RFDS rule file itself hasn't changed in that
>>>>>>>>>>> time frame. It is tricky to trace back code changes over that period
>>>>>>>>>>> because we did a code reorg which hides a lot of the history. However,
>>>>>>>>>>> from memory (and the release notes) I can't think of anything that
>>>>>>>>>>> should have had an effect like that. There were changes around handling
>>>>>>>>>>> validation of data types but that isn't relevant here. We generalized
>>>>>>>>>>> handling of non-legal RDF triples but again that shouldn't be relevant.
>>>>>>>>>>>
>>>>>>>>>>> Could you try two experiments?
>>>>>>>>>>>
>>>>>>>>>>> First, would it be possible to time a simpler operation, such as listing
>>>>>>>>>>> all classes, to eliminate listHierarchyRootClasses as a factor?
>>>>>>>>>>>
>>>>>>>>>>> Secondly, is it possible to check with Jena 2.6.0 - that would separate
>>>>>>>>>>> the Java 5 changes and the datatype validation from more recent tweaks?
>>>>>>>>>>>
>>>>>>>>>>> If that's a problem then send me your ontology subset and I'll take a
>>>>>>>>>>> look when I can.
>>>>>>>>>>>
>>>>>>>>>>> Dave
>>>>>>>>>>>
>>>>>>>>>>>> Thanks for your help,
>>>>>>>>>>>> Rick
>>>>>>>>>>>>
>>>>>>>>>>>> import java.io.InputStream;
>>>>>>>>>>>> import org.junit.Test;
>>>>>>>>>>>>
>>>>>>>>>>>> import com.hp.hpl.jena.ontology.OntModel;
>>>>>>>>>>>> import com.hp.hpl.jena.ontology.OntModelSpec;
>>>>>>>>>>>> import com.hp.hpl.jena.rdf.model.Model;
>>>>>>>>>>>> import com.hp.hpl.jena.rdf.model.ModelFactory;
>>>>>>>>>>>> import com.hp.hpl.jena.util.iterator.ExtendedIterator;
>>>>>>>>>>>>
>>>>>>>>>>>> public class TestReasonerProblem {
>>>>>>>>>>>>
>>>>>>>>>>>>       @Test
>>>>>>>>>>>>       public void test() throws Exception {
>>>>>>>>>>>>
>>>>>>>>>>>>           Model model = ModelFactory.createDefaultModel();
>>>>>>>>>>>>           String file="clinical-factDCMapVent.owl";
>>>>>>>>>>>>           InputStream fis =  this.getClass().getResourceAsStream(file);
>>>>>>>>>>>>           model.read(fis, null, "RDF/XML");
>>>>>>>>>>>>           OntModelSpec spec = OntModelSpec.OWL_MEM_RDFS_INF;
>>>>>>>>>>>> //        OntModelSpec spec = OntModelSpec.OWL_DL_MEM_RDFS_INF;
>>>>>>>>>>>> //        OntModelSpec spec = OntModelSpec.OWL_DL_MEM_TRANS_INF;
>>>>>>>>>>>>           OntModel ontModel = ModelFactory.createOntologyModel(spec, model);
>>>>>>>>>>>>
>>>>>>>>>>>>           long ctms = System.currentTimeMillis();
>>>>>>>>>>>>           for (ExtendedIterator j = ontModel.listHierarchyRootClasses(); j.hasNext(); ){
>>>>>>>>>>>>               j.next();
>>>>>>>>>>>>           }
>>>>>>>>>>>>           System.out.printf("time: %d, totMem: %dk, usedMem: %dk\n",
>>>>>>>>>>>>                   (System.currentTimeMillis()-ctms),
>>>>>>>>>>>>                   (Runtime.getRuntime().totalMemory()/1024),
>>>>>>>>>>>>                   ((Runtime.getRuntime().totalMemory()-Runtime.getRuntime().freeMemory())/1024));
>>>>>>>>>>>>       }
>>>>>>>>>>>>
>>>>>>>>>>>> }
>>>>>>>>>>>>
>>>>>>>>>>>>
>>>>>>>>>>>>
>>>>>>>>>>>>
>>>>>>>>>>>> ------------------------------------
>>>>>>>>>>>>
>>>>>>>>>>>> Yahoo! Groups Links
>>>>>>>>>>>>
>>>>>>>>>>>>
>>>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> ------------------------------------
>>>>>>>>>>
>>>>>>>>>> Yahoo! Groups Links
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>> ------------------------------------
>>>>>>>>
>>>>>>>> Yahoo! Groups Links
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>
>>>>>>
>>>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>
>>
>>
>>
>>


Re: comparison of JVM and Jena versions by memory usage

Posted by Milorad Tosic <mb...@yahoo.com>.
Hi Dave,

I created simple test just to be sure that eventual additional dependencies are eliminated. Hence, I am now able to answer you questions: 


>Is it the identical war file (assuming this is a war) in both cases? 

Yes.


>Is it an identical web container? 

No. One is Tomcat the other is Resin.


>Might you have multiple versions of Jena on the classpath (e.g. due to
>putting something in an endorsed directory)?

No. The Jena packaged within the WAR is the only one.


>Is it the same jvm in each case?


I do not know! I can not know jvm version running on the shared rented server.


>Your error trace is from when the Jena Runtime starts up - it is loading
>a metadata file which should be in the Jena jar and accessible via the
>classloader. It looks like the classloader can't find the resource which
>suggests a broken set of jars or just maybe a duff jvm.

Yes. It definitely looks like a problem with classloader. Broken set of jars: I copied all jars from lib directory from Jena installation (C:\Install\Jena\Jena-2.6.4\lib). The only additional jar included in WAR is json.jar. I doubt that broken set of jar may be in question here? Duff jvm: Though I can not tell what jvm is it, this is the first time that something like this error happens. Assuming the jvm is duff, but I do not have administration rights over it, what are my options to fix the problem?

Thanks,
Milorad


>________________________________
> From: Dave Reynolds <da...@gmail.com>
>To: Milorad Tosic <mb...@yahoo.com> 
>Cc: "jena-users@incubator.apache.org" <je...@incubator.apache.org> 
>Sent: Saturday, December 17, 2011 6:45 PM
>Subject: Re: comparison of JVM and Jena versions by memory usage
> 
>Hi Milorad,
>
>> Memory limit was my best theory about what is going on with my application. Namely, I am trying to migrate an application using Jena from dedicated server to a shared server. The exactly same code is running without any problems until it is ported on the dedicated server. I paste my error trace at the end of the message for your reference.
>
>That looks likely to be an inconsistent set of jars. 
>
>Is it the identical war file (assuming this is a war) in both cases? 
>Is it an identical web container? 
>Might you have multiple versions of Jena on the classpath (e.g. due to
>putting something in an endorsed directory)?
>Is it the same jvm in each case?
>
>> The application simply diminish without any exception caught. I traced it down to the single line instantiating OntModel (default reasoner, no ontology loaded initially):
>> 
>> OntModel metaMCQ = null;
>> 
>> metaMCQ = ModelFactory.createOntologyModel();
>
>I suspect that's just because it is the first call which causes Jena to
>do anything non trivial.
>
>Your error trace is from when the Jena Runtime starts up - it is loading
>a metadata file which should be in the Jena jar and accessible via the
>classloader. It looks like the classloader can't find the resource which
>suggests a broken set of jars or just maybe a duff jvm.
>
>Dave
>
>> 
>> Exactly the same code works on the dedicated server while keeps crashing on the shared server?
>> 
>> Thank you in advance,
>> Milorad
>> 
>> 
>> My error trace follows:
>> 
>> java.lang.ExceptionInInitializerError
>> at com.hp.hpl.jena.rdf.model.impl.RDFReaderFImpl.&lt;clinit>(RDFReaderFImpl.java:85)
>> at com.hp.hpl.jena.rdf.model.impl.ModelCom.&lt;clinit>(ModelCom.java:42)
>> at com.hp.hpl.jena.rdf.model.ModelFactory.createDefaultModel(ModelFactory.java:122)
>> at com.hp.hpl.jena.rdf.model.ModelFactory.createDefaultModel(ModelFactory.java:116)
>> at com.hp.hpl.jena.vocabulary.OWL.&lt;clinit>(OWL.java:37)
>> at com.hp.hpl.jena.ontology.ProfileRegistry.&lt;clinit>(ProfileRegistry.java:48)
>> at com.hp.hpl.jena.rdf.model.ModelFactory.createOntologyModel(ModelFactory.java:344)
>> at com.virtuona.service.semcqgenerator.SeMCQgeneratorService.runApp(SeMCQgeneratorService.java:182)
>> at com.virtuona.service.semcqgenerator.SeMCQgeneratorService.runService(SeMCQgeneratorService.java:380)
>> at com.virtuona.service.ServiceCaller.callService(ServiceCaller.java:28)
>> at com.virtuona.service.ServletServiceCaller.callService(ServletServiceCaller.java:397)
>> at com.virtuona.service.ServletServiceCaller.procesRequest(ServletServiceCaller.java:258)
>> at com.virtuona.service.ServletServiceCaller.doPost(ServletServiceCaller.java:107)
>> at javax.servlet.http.HttpServlet.service(HttpServlet.java:165)
>> at javax.servlet.http.HttpServlet.service(HttpServlet.java:103)
>> at com.caucho.server.http.FilterChainServlet.doFilter(FilterChainServlet.java:96)
>> at com.caucho.server.http.Invocation.service(Invocation.java:315)
>> at com.caucho.server.http.CacheInvocation.service(CacheInvocation.java:135)
>> at com.caucho.server.http.RunnerRequest.handleRequest(RunnerRequest.java:346)
>> at com.caucho.server.http.RunnerRequest.handleConnection(RunnerRequest.java:274)
>> at com.caucho.server.TcpConnection.run(TcpConnection.java:139)
>> at java.lang.Thread.run(Thread.java:595)
>> Caused by: java.lang.NullPointerException
>> at java.util.XMLUtils.load(XMLUtils.java:62)
>> at java.util.Properties.loadFromXML(Properties.java:701)
>> at com.hp.hpl.jena.util.Metadata.read(Metadata.java:67)
>> at com.hp.hpl.jena.util.Metadata.addMetadata(Metadata.java:41)
>> at com.hp.hpl.jena.util.Metadata.&lt;init>(Metadata.java:35)
>> at com.hp.hpl.jena.JenaRuntime.&lt;clinit>(JenaRuntime.java:25)
>> ... 22 more
>> 
>> 
>> 
>> 
>> >________________________________
>> > From: Dave Reynolds <da...@gmail.com>
>> >To: Milorad Tosic <mb...@yahoo.com> 
>> >Cc: "jena-users@incubator.apache.org" <je...@incubator.apache.org> 
>> >Sent: Friday, December 16, 2011 4:41 PM
>> >Subject: Re: comparison of JVM and Jena versions by memory usage
>> > 
>> >Hi,
>> >
>> >On Fri, 2011-12-16 at 05:39 -0800, Milorad Tosic wrote: 
>> >> Hi,
>> >> 
>> >> 
>> >> There is a short discussion on the former Jena Development/Support mailing list related to memory usage of Jena OntModel using different versions of Jena. For your information I have included a segment of the correspondence at the end of the message. Since I had a problem that looks much like memory usage limit overrun, I got interested in the problem.
>> >> 
>> >> 
>> >> I repeated the same experiment but with 
>> >> different conclusions? I compared Jena 2.6.0 with Jena 2.6.4. I couldn't
>> >>  notice the difference between Jena versions as reported in your 
>> >> previous experiment (though I used the same code). Tried with several 
>> >> variations of the OntModel creations styles but with minor differences 
>> >> in memory usage only (within 10%). I run the experiment from within 
>> >> Eclipse with JVM set to jre6 using compiler compliance level 1.5 (as 
>> >> well as 1.6). The total memory usage was around 27975k.
>> >>  
>> >> Than, I changed the JVM to jdk 1.5. There was similar relative 
>> >> difference between the Jena 2.6.0 and Jena 2.6.4 (within 10%). However, 
>> >> the absolute amount of used memory dropped to about 3400k.
>> >>  
>> >> Than I again changed the JVM to jdk 1.6. As in all previous testing 
>> >> configurations, there was similar relative difference between the Jena 
>> >> 2.6.0 and Jena 2.6.4 (within 10%). However, the absolute amount of used 
>> >> memory was about 6501k.
>> >>  
>> >> Consequently, I have two problems now:
>> >>  
>> >> 1) I couldn't repeat you experiment with the same results. What I am doing wrong?
>> >
>> >Assuming you are running the code that Rick originally posted then the
>> >problem is that that uses a naive way to measure memory usage.
>> >If I run with java 1.6 (sun-java on Linux) and the current Jena snapshot
>> >and run in eclipse I get:
>> >
>> >time: 19, totMem: 122688k, usedMem: 4859k
>> >
>> >If I run identical code from the command line I get:
>> >time: 12, totMem: 122688k, usedMem: 28548k
>> >
>> >The difference is down to whether a garbage collect has kicked in. If I
>> >force a System.gc() in that code then I get:
>> >
>> >time: 86, totMem: 122688k, usedMem: 4006k
>> >
>> >where the extra time comes from the garbage collect.
>> >
>> >
>> >> 2) What should I do to put the memory usage under my control? Namely, 5
>> >>  times larger memory usage cause my application to broke on machines 
>> >> with limited memory usage.
>> >
>> >I don't think there's any evidence that the problem in the thread that
>> >you are referring to is still an issue.
>> >
>> >You would need to explain more about what you are actually do in your
>> >application before we could help with that. However, if you are
>> >currently using inference and are having memory problems then avoiding
>> >inference, or using a weaker inference setting, would be a good place to
>> >start.
>> >
>> >Dave
>> >
>> >>  
>> >> Thanks,
>> >> Milorad Tosic
>> >> > 
>> >> > --- In jena-dev@yahoogroups.com, Dave Reynolds <da...@...> wrote:
>> >> > >
>> >> > > Rick,
>> >> > > 
>> >> > > Thanks for letting us know, thanks for the clear report.
>> >> > > 
>> >> > > Dave
>> >> > > 
>> >> > > rspates2 wrote:
>> >> > > > Dave,
>> >> > > > 
>> >> >
>> >>  > > I grabbed OWLProfile.java and reran my tests.  It looks fixed
>> >>  to me in terms of speed and memory use.  We should be able to use 2.6.2
>> >>  now.
>> >> > > > 
>> >> > > > Thanks for your swift resolution to the problem.
>> >> > > > 
>> >> > > > Rick
>> >> > > > 
>> >> > > > --- In jena-dev@yahoogroups.com, Dave Reynolds <dave.e.reynolds@> wrote:
>> >> > > >> Hi Rick,
>> >> > > >>
>> >> > > >> A follow up on my earlier off-list response.
>> >> > > >>
>> >> > > >> Thanks again for giving us a test case for this. It turns out not to be 
>> >> > > >> a reasoner issue as such.  There was a change in the internals of the 
>> >> > > >> Ontology API which worked inefficiently when a reasoner is present.  Ian 
>> >> > > >> has checked in some patches for this which brings the memory use down a 
>> >> > > >> lot and gives a 5x speed improvement.
>> >> > > >>
>> >> > > >> It is not quite back to 2.6.0 timings but is a significant improvement.
>> >> > > >>
>> >> > > >> We'll investigate a little more but this may be as close as we can get 
>> >> > > >> for now. Let us know if this is enough to make it usable for you.
>> >> > > >>
>> >> > > >> Cheers,
>> >> > > >> Dave
>> >> > > >>
>> >> > > >> rspates2 wrote:
>> >> > > >>> Dave,
>> >> > > >>>
>> >> > > >>> The difference seems to be between 2.6.0 and 2.6.2,
>> >> > > >>>
>> >> > > >>> OntModel.listClasses():
>> >> > > >>> 2.6.2    time: 2187, totMem: 19948k, usedMem: 13345k
>> >> > > >>> 2.6.0    time: 110, totMem: 5056k, usedMem: 3681k
>> >> > > >>> 2.5.7    time: 78, totMem: 5056k, usedMem: 3726k
>> >> > > >>>
>> >> > > >>> listHierarchyRootClasses():
>> >> > > >>> 2.6.2    time: 2312, totMem: 20152k, usedMem: 13859k
>> >> > > >>> 2.6.0    time: 172, totMem: 5056k, usedMem: 4312k
>> >> > > >>> 2.5.7    time: 188, totMem: 5056k, usedMem: 4078k
>> >> > > >>>
>> >> > > >>> Let me know if you need anything else.
>> >> > > >>>
>> >> > > >>> Thanks,
>> >> > > >>> Rick
>> >> > > >>>
>> >> > > >>> --- In jena-dev@yahoogroups.com, Dave Reynolds <dave.e.reynolds@> wrote:
>> >> > > >>>> rspates2 wrote:
>> >> > > >>>>> Hi,
>> >> > > >>>>>
>> >> >
>> >>  > >>>>> We switched our application from Jena 2.5.7 
>> >> to 2.6.2.  For an operation on OntModel.listHierarchyRootClasses() with 
>> >> an OntModelSpec of OWL_MEM_RDFS_INF, we saw a very significant increase 
>> >> in the use of memory and processing time, including out-of-memory 
>> >> condition for our full ontology.  Using a subset of our ontology and the
>> >>  code below to demonstrate, we measured processing times and memory use:
>> >> > > >>>>>
>> >> > > >>>>> 2.6.2    time: 2063, totMem: 20008k, usedMem: 14539k
>> >> > > >>>>> 2.5.7    time: 172, totMem: 5056k, usedMem: 3974k
>> >> > > >>>> Certainly a huge jump :(
>> >> > > >>>>
>> >> >
>> >>  > >>>>> The specifications OWL_MEM_RDFS_INF and 
>> >> OWL_DL_MEM_RDFS_INF produced comparable results, while 
>> >> OWL_DL_MEM_TRANS_INF at 2.6.2 was comparable to our 2.5.7 run with 
>> >> OWL_MEM_RDFS_INF.
>> >> > > >>>>>
>> >> > > 
>> >> >>>>> I can post the subset ontology if you need it (170 
>> >> k), but thought there might be some known explanation you could provide 
>> >> without running the demo code.  
>> >> > > >>>>>
>> >> > > >>>>> Any idea what is causing this?
>> >> > > >>>> No immediate ideas. The RFDS rule file itself hasn't changed in that 
>> >> > > >>>> time frame. It is tricky to trace back code changes over that period 
>> >> > > >>>> because we did a code reorg which hides a lot of the history. However, 
>> >> > > >>>> from memory (and the release notes) I can't think of anything that 
>> >> > > >>>> should have had an effect like that. There were changes around handling 
>> >> > > >>>> validation of data types but that isn't relevant here. We generalized 
>> >> > > >>>> handling of non-legal RDF triples but again that shouldn't be relevant.
>> >> > > >>>>
>> >> > > >>>> Could you try two experiments?
>> >> > > >>>>
>> >> > > >>>> First, would it be possible to time a simpler operation, such as listing 
>> >> > > >>>> all classes, to eliminate listHierarchyRootClasses as a factor?
>> >> > > >>>>
>> >> > > >>>> Secondly, is it possible to check with Jena 2.6.0 - that would separate 
>> >> > > >>>> the Java 5 changes and the datatype validation from more recent tweaks?
>> >> > > >>>>
>> >> > > >>>> If that's a problem then send me your ontology subset and I'll take a 
>> >> > > >>>> look when I can.
>> >> > > >>>>
>> >> > > >>>> Dave
>> >> > > >>>>
>> >> > > >>>>> Thanks for your help,
>> >> > > >>>>> Rick
>> >> > > >>>>>
>> >> > > >>>>> import java.io.InputStream;
>> >> > > >>>>> import org.junit.Test;
>> >> > > >>>>>
>> >> > > >>>>> import com.hp.hpl.jena.ontology.OntModel;
>> >> > > >>>>> import com.hp.hpl.jena.ontology.OntModelSpec;
>> >> > > >>>>> import com.hp.hpl.jena.rdf.model.Model;
>> >> > > >>>>> import com.hp.hpl.jena.rdf.model.ModelFactory;
>> >> > > >>>>> import com.hp.hpl.jena.util.iterator.ExtendedIterator;
>> >> > > >>>>>
>> >> > > >>>>> public class TestReasonerProblem {
>> >> > > >>>>>
>> >> > > >>>>>     @Test
>> >> > > >>>>>     public void test() throws Exception {
>> >> > > >>>>>
>> >> > > >>>>>         Model model = ModelFactory.createDefaultModel();
>> >> > > >>>>>         String file="clinical-factDCMapVent.owl";
>> >> > > >>>>>         InputStream fis =  this.getClass().getResourceAsStream(file);
>> >> > > >>>>>         model.read(fis, null, "RDF/XML");
>> >> > > >>>>>         OntModelSpec spec = OntModelSpec.OWL_MEM_RDFS_INF;
>> >> > > >>>>> //        OntModelSpec spec = OntModelSpec.OWL_DL_MEM_RDFS_INF;
>> >> > > >>>>> //        OntModelSpec spec = OntModelSpec.OWL_DL_MEM_TRANS_INF;
>> >> > > >>>>>         OntModel ontModel = ModelFactory.createOntologyModel(spec, model);
>> >> > > >>>>>        
>> >> > > >>>>>         long ctms = System.currentTimeMillis();
>> >> > > >>>>>         for (ExtendedIterator j = ontModel.listHierarchyRootClasses(); j.hasNext(); ){
>> >> > > >>>>>             j.next();
>> >> > > >>>>>         }
>> >> > > >>>>>         System.out.printf("time: %d, totMem: %dk, usedMem: %dk\n",
>> >> > > >>>>>                 (System.currentTimeMillis()-ctms),
>> >> > > >>>>>                 (Runtime.getRuntime().totalMemory()/1024),
>> >> > > >>>>>                 ((Runtime.getRuntime().totalMemory()-Runtime.getRuntime().freeMemory())/1024));
>> >> > > >>>>>     }
>> >> > > >>>>>
>> >> > > >>>>> }
>> >> > > >>>>>
>> >> > > >>>>>
>> >> > > >>>>>
>> >> > > >>>>>
>> >> > > >>>>> ------------------------------------
>> >> > > >>>>>
>> >> > > >>>>> Yahoo! Groups Links
>> >> > > >>>>>
>> >> > > >>>>>
>> >> > > >>>>>
>> >> > > >>>
>> >> > > >>>
>> >> > > >>>
>> >> > > >>> ------------------------------------
>> >> > > >>>
>> >> > > >>> Yahoo! Groups Links
>> >> > > >>>
>> >> > > >>>
>> >> > > >>>
>> >> > > > 
>> >> > > > 
>> >> > > > 
>> >> > > > 
>> >> > > > ------------------------------------
>> >> > > > 
>> >> > > > Yahoo! Groups Links
>> >> > > > 
>> >> > > > 
>> >> > > >
>> >> > >
>> >> > 
>> >> > 
>> >
>> >
>> >
>> >
>> >
>> >
>
>
>
>
>

Re: comparison of JVM and Jena versions by memory usage

Posted by Dave Reynolds <da...@gmail.com>.
Hi Milorad,

> Memory limit was my best theory about what is going on with my application. Namely, I am trying to migrate an application using Jena from dedicated server to a shared server. The exactly same code is running without any problems until it is ported on the dedicated server. I paste my error trace at the end of the message for your reference.

That looks likely to be an inconsistent set of jars. 

Is it the identical war file (assuming this is a war) in both cases? 
Is it an identical web container? 
Might you have multiple versions of Jena on the classpath (e.g. due to
putting something in an endorsed directory)?
Is it the same jvm in each case?

> The application simply diminish without any exception caught. I traced it down to the single line instantiating OntModel (default reasoner, no ontology loaded initially):
> 
> OntModel metaMCQ = null;
> 
> metaMCQ = ModelFactory.createOntologyModel();

I suspect that's just because it is the first call which causes Jena to
do anything non trivial.

Your error trace is from when the Jena Runtime starts up - it is loading
a metadata file which should be in the Jena jar and accessible via the
classloader. It looks like the classloader can't find the resource which
suggests a broken set of jars or just maybe a duff jvm.

Dave

> 
> Exactly the same code works on the dedicated server while keeps crashing on the shared server?
> 
> Thank you in advance,
> Milorad
> 
> 
> My error trace follows:
> 
> java.lang.ExceptionInInitializerError
> at com.hp.hpl.jena.rdf.model.impl.RDFReaderFImpl.&lt;clinit>(RDFReaderFImpl.java:85)
> at com.hp.hpl.jena.rdf.model.impl.ModelCom.&lt;clinit>(ModelCom.java:42)
> at com.hp.hpl.jena.rdf.model.ModelFactory.createDefaultModel(ModelFactory.java:122)
> at com.hp.hpl.jena.rdf.model.ModelFactory.createDefaultModel(ModelFactory.java:116)
> at com.hp.hpl.jena.vocabulary.OWL.&lt;clinit>(OWL.java:37)
> at com.hp.hpl.jena.ontology.ProfileRegistry.&lt;clinit>(ProfileRegistry.java:48)
> at com.hp.hpl.jena.rdf.model.ModelFactory.createOntologyModel(ModelFactory.java:344)
> at com.virtuona.service.semcqgenerator.SeMCQgeneratorService.runApp(SeMCQgeneratorService.java:182)
> at com.virtuona.service.semcqgenerator.SeMCQgeneratorService.runService(SeMCQgeneratorService.java:380)
> at com.virtuona.service.ServiceCaller.callService(ServiceCaller.java:28)
> at com.virtuona.service.ServletServiceCaller.callService(ServletServiceCaller.java:397)
> at com.virtuona.service.ServletServiceCaller.procesRequest(ServletServiceCaller.java:258)
> at com.virtuona.service.ServletServiceCaller.doPost(ServletServiceCaller.java:107)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:165)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:103)
> at com.caucho.server.http.FilterChainServlet.doFilter(FilterChainServlet.java:96)
> at com.caucho.server.http.Invocation.service(Invocation.java:315)
> at com.caucho.server.http.CacheInvocation.service(CacheInvocation.java:135)
> at com.caucho.server.http.RunnerRequest.handleRequest(RunnerRequest.java:346)
> at com.caucho.server.http.RunnerRequest.handleConnection(RunnerRequest.java:274)
> at com.caucho.server.TcpConnection.run(TcpConnection.java:139)
> at java.lang.Thread.run(Thread.java:595)
> Caused by: java.lang.NullPointerException
> at java.util.XMLUtils.load(XMLUtils.java:62)
> at java.util.Properties.loadFromXML(Properties.java:701)
> at com.hp.hpl.jena.util.Metadata.read(Metadata.java:67)
> at com.hp.hpl.jena.util.Metadata.addMetadata(Metadata.java:41)
> at com.hp.hpl.jena.util.Metadata.&lt;init>(Metadata.java:35)
> at com.hp.hpl.jena.JenaRuntime.&lt;clinit>(JenaRuntime.java:25)
> ... 22 more
> 
> 
> 
> 
> >________________________________
> > From: Dave Reynolds <da...@gmail.com>
> >To: Milorad Tosic <mb...@yahoo.com> 
> >Cc: "jena-users@incubator.apache.org" <je...@incubator.apache.org> 
> >Sent: Friday, December 16, 2011 4:41 PM
> >Subject: Re: comparison of JVM and Jena versions by memory usage
> > 
> >Hi,
> >
> >On Fri, 2011-12-16 at 05:39 -0800, Milorad Tosic wrote: 
> >> Hi,
> >> 
> >> 
> >> There is a short discussion on the former Jena Development/Support mailing list related to memory usage of Jena OntModel using different versions of Jena. For your information I have included a segment of the correspondence at the end of the message. Since I had a problem that looks much like memory usage limit overrun, I got interested in the problem.
> >> 
> >> 
> >> I repeated the same experiment but with 
> >> different conclusions? I compared Jena 2.6.0 with Jena 2.6.4. I couldn't
> >>  notice the difference between Jena versions as reported in your 
> >> previous experiment (though I used the same code). Tried with several 
> >> variations of the OntModel creations styles but with minor differences 
> >> in memory usage only (within 10%). I run the experiment from within 
> >> Eclipse with JVM set to jre6 using compiler compliance level 1.5 (as 
> >> well as 1.6). The total memory usage was around 27975k.
> >>  
> >> Than, I changed the JVM to jdk 1.5. There was similar relative 
> >> difference between the Jena 2.6.0 and Jena 2.6.4 (within 10%). However, 
> >> the absolute amount of used memory dropped to about 3400k.
> >>  
> >> Than I again changed the JVM to jdk 1.6. As in all previous testing 
> >> configurations, there was similar relative difference between the Jena 
> >> 2.6.0 and Jena 2.6.4 (within 10%). However, the absolute amount of used 
> >> memory was about 6501k.
> >>  
> >> Consequently, I have two problems now:
> >>  
> >> 1) I couldn't repeat you experiment with the same results. What I am doing wrong?
> >
> >Assuming you are running the code that Rick originally posted then the
> >problem is that that uses a naive way to measure memory usage.
> >If I run with java 1.6 (sun-java on Linux) and the current Jena snapshot
> >and run in eclipse I get:
> >
> >time: 19, totMem: 122688k, usedMem: 4859k
> >
> >If I run identical code from the command line I get:
> >time: 12, totMem: 122688k, usedMem: 28548k
> >
> >The difference is down to whether a garbage collect has kicked in. If I
> >force a System.gc() in that code then I get:
> >
> >time: 86, totMem: 122688k, usedMem: 4006k
> >
> >where the extra time comes from the garbage collect.
> >
> >
> >> 2) What should I do to put the memory usage under my control? Namely, 5
> >>  times larger memory usage cause my application to broke on machines 
> >> with limited memory usage.
> >
> >I don't think there's any evidence that the problem in the thread that
> >you are referring to is still an issue.
> >
> >You would need to explain more about what you are actually do in your
> >application before we could help with that. However, if you are
> >currently using inference and are having memory problems then avoiding
> >inference, or using a weaker inference setting, would be a good place to
> >start.
> >
> >Dave
> >
> >>  
> >> Thanks,
> >> Milorad Tosic
> >> > 
> >> > --- In jena-dev@yahoogroups.com, Dave Reynolds <da...@...> wrote:
> >> > >
> >> > > Rick,
> >> > > 
> >> > > Thanks for letting us know, thanks for the clear report.
> >> > > 
> >> > > Dave
> >> > > 
> >> > > rspates2 wrote:
> >> > > > Dave,
> >> > > > 
> >> >
> >>  > > I grabbed OWLProfile.java and reran my tests.  It looks fixed
> >>  to me in terms of speed and memory use.  We should be able to use 2.6.2
> >>  now.
> >> > > > 
> >> > > > Thanks for your swift resolution to the problem.
> >> > > > 
> >> > > > Rick
> >> > > > 
> >> > > > --- In jena-dev@yahoogroups.com, Dave Reynolds <dave.e.reynolds@> wrote:
> >> > > >> Hi Rick,
> >> > > >>
> >> > > >> A follow up on my earlier off-list response.
> >> > > >>
> >> > > >> Thanks again for giving us a test case for this. It turns out not to be 
> >> > > >> a reasoner issue as such.  There was a change in the internals of the 
> >> > > >> Ontology API which worked inefficiently when a reasoner is present.  Ian 
> >> > > >> has checked in some patches for this which brings the memory use down a 
> >> > > >> lot and gives a 5x speed improvement.
> >> > > >>
> >> > > >> It is not quite back to 2.6.0 timings but is a significant improvement.
> >> > > >>
> >> > > >> We'll investigate a little more but this may be as close as we can get 
> >> > > >> for now. Let us know if this is enough to make it usable for you.
> >> > > >>
> >> > > >> Cheers,
> >> > > >> Dave
> >> > > >>
> >> > > >> rspates2 wrote:
> >> > > >>> Dave,
> >> > > >>>
> >> > > >>> The difference seems to be between 2.6.0 and 2.6.2,
> >> > > >>>
> >> > > >>> OntModel.listClasses():
> >> > > >>> 2.6.2    time: 2187, totMem: 19948k, usedMem: 13345k
> >> > > >>> 2.6.0    time: 110, totMem: 5056k, usedMem: 3681k
> >> > > >>> 2.5.7    time: 78, totMem: 5056k, usedMem: 3726k
> >> > > >>>
> >> > > >>> listHierarchyRootClasses():
> >> > > >>> 2.6.2    time: 2312, totMem: 20152k, usedMem: 13859k
> >> > > >>> 2.6.0    time: 172, totMem: 5056k, usedMem: 4312k
> >> > > >>> 2.5.7    time: 188, totMem: 5056k, usedMem: 4078k
> >> > > >>>
> >> > > >>> Let me know if you need anything else.
> >> > > >>>
> >> > > >>> Thanks,
> >> > > >>> Rick
> >> > > >>>
> >> > > >>> --- In jena-dev@yahoogroups.com, Dave Reynolds <dave.e.reynolds@> wrote:
> >> > > >>>> rspates2 wrote:
> >> > > >>>>> Hi,
> >> > > >>>>>
> >> >
> >>  > >>>>> We switched our application from Jena 2.5.7 
> >> to 2.6.2.  For an operation on OntModel.listHierarchyRootClasses() with 
> >> an OntModelSpec of OWL_MEM_RDFS_INF, we saw a very significant increase 
> >> in the use of memory and processing time, including out-of-memory 
> >> condition for our full ontology.  Using a subset of our ontology and the
> >>  code below to demonstrate, we measured processing times and memory use:
> >> > > >>>>>
> >> > > >>>>> 2.6.2    time: 2063, totMem: 20008k, usedMem: 14539k
> >> > > >>>>> 2.5.7    time: 172, totMem: 5056k, usedMem: 3974k
> >> > > >>>> Certainly a huge jump :(
> >> > > >>>>
> >> >
> >>  > >>>>> The specifications OWL_MEM_RDFS_INF and 
> >> OWL_DL_MEM_RDFS_INF produced comparable results, while 
> >> OWL_DL_MEM_TRANS_INF at 2.6.2 was comparable to our 2.5.7 run with 
> >> OWL_MEM_RDFS_INF.
> >> > > >>>>>
> >> > > 
> >> >>>>> I can post the subset ontology if you need it (170 
> >> k), but thought there might be some known explanation you could provide 
> >> without running the demo code.  
> >> > > >>>>>
> >> > > >>>>> Any idea what is causing this?
> >> > > >>>> No immediate ideas. The RFDS rule file itself hasn't changed in that 
> >> > > >>>> time frame. It is tricky to trace back code changes over that period 
> >> > > >>>> because we did a code reorg which hides a lot of the history. However, 
> >> > > >>>> from memory (and the release notes) I can't think of anything that 
> >> > > >>>> should have had an effect like that. There were changes around handling 
> >> > > >>>> validation of data types but that isn't relevant here. We generalized 
> >> > > >>>> handling of non-legal RDF triples but again that shouldn't be relevant.
> >> > > >>>>
> >> > > >>>> Could you try two experiments?
> >> > > >>>>
> >> > > >>>> First, would it be possible to time a simpler operation, such as listing 
> >> > > >>>> all classes, to eliminate listHierarchyRootClasses as a factor?
> >> > > >>>>
> >> > > >>>> Secondly, is it possible to check with Jena 2.6.0 - that would separate 
> >> > > >>>> the Java 5 changes and the datatype validation from more recent tweaks?
> >> > > >>>>
> >> > > >>>> If that's a problem then send me your ontology subset and I'll take a 
> >> > > >>>> look when I can.
> >> > > >>>>
> >> > > >>>> Dave
> >> > > >>>>
> >> > > >>>>> Thanks for your help,
> >> > > >>>>> Rick
> >> > > >>>>>
> >> > > >>>>> import java.io.InputStream;
> >> > > >>>>> import org.junit.Test;
> >> > > >>>>>
> >> > > >>>>> import com.hp.hpl.jena.ontology.OntModel;
> >> > > >>>>> import com.hp.hpl.jena.ontology.OntModelSpec;
> >> > > >>>>> import com.hp.hpl.jena.rdf.model.Model;
> >> > > >>>>> import com.hp.hpl.jena.rdf.model.ModelFactory;
> >> > > >>>>> import com.hp.hpl.jena.util.iterator.ExtendedIterator;
> >> > > >>>>>
> >> > > >>>>> public class TestReasonerProblem {
> >> > > >>>>>
> >> > > >>>>>     @Test
> >> > > >>>>>     public void test() throws Exception {
> >> > > >>>>>
> >> > > >>>>>         Model model = ModelFactory.createDefaultModel();
> >> > > >>>>>         String file="clinical-factDCMapVent.owl";
> >> > > >>>>>         InputStream fis =  this.getClass().getResourceAsStream(file);
> >> > > >>>>>         model.read(fis, null, "RDF/XML");
> >> > > >>>>>         OntModelSpec spec = OntModelSpec.OWL_MEM_RDFS_INF;
> >> > > >>>>> //        OntModelSpec spec = OntModelSpec.OWL_DL_MEM_RDFS_INF;
> >> > > >>>>> //        OntModelSpec spec = OntModelSpec.OWL_DL_MEM_TRANS_INF;
> >> > > >>>>>         OntModel ontModel = ModelFactory.createOntologyModel(spec, model);
> >> > > >>>>>        
> >> > > >>>>>         long ctms = System.currentTimeMillis();
> >> > > >>>>>         for (ExtendedIterator j = ontModel.listHierarchyRootClasses(); j.hasNext(); ){
> >> > > >>>>>             j.next();
> >> > > >>>>>         }
> >> > > >>>>>         System.out.printf("time: %d, totMem: %dk, usedMem: %dk\n",
> >> > > >>>>>                 (System.currentTimeMillis()-ctms),
> >> > > >>>>>                 (Runtime.getRuntime().totalMemory()/1024),
> >> > > >>>>>                 ((Runtime.getRuntime().totalMemory()-Runtime.getRuntime().freeMemory())/1024));
> >> > > >>>>>     }
> >> > > >>>>>
> >> > > >>>>> }
> >> > > >>>>>
> >> > > >>>>>
> >> > > >>>>>
> >> > > >>>>>
> >> > > >>>>> ------------------------------------
> >> > > >>>>>
> >> > > >>>>> Yahoo! Groups Links
> >> > > >>>>>
> >> > > >>>>>
> >> > > >>>>>
> >> > > >>>
> >> > > >>>
> >> > > >>>
> >> > > >>> ------------------------------------
> >> > > >>>
> >> > > >>> Yahoo! Groups Links
> >> > > >>>
> >> > > >>>
> >> > > >>>
> >> > > > 
> >> > > > 
> >> > > > 
> >> > > > 
> >> > > > ------------------------------------
> >> > > > 
> >> > > > Yahoo! Groups Links
> >> > > > 
> >> > > > 
> >> > > >
> >> > >
> >> > 
> >> > 
> >
> >
> >
> >
> >
> >



Re: comparison of JVM and Jena versions by memory usage

Posted by Milorad Tosic <mb...@yahoo.com>.
Hi Dave,

Thanks for helping me and particularly for your prompt and valuable response.

I understand and agree with the gc() explanation. Thanks.

Memory limit was my best theory about what is going on with my application. Namely, I am trying to migrate an application using Jena from dedicated server to a shared server. The exactly same code is running without any problems until it is ported on the dedicated server. I paste my error trace at the end of the message for your reference.

The application simply diminish without any exception caught. I traced it down to the single line instantiating OntModel (default reasoner, no ontology loaded initially):

OntModel metaMCQ = null;

metaMCQ = ModelFactory.createOntologyModel();


Exactly the same code works on the dedicated server while keeps crashing on the shared server?

Thank you in advance,
Milorad


My error trace follows:

java.lang.ExceptionInInitializerError
at com.hp.hpl.jena.rdf.model.impl.RDFReaderFImpl.&lt;clinit>(RDFReaderFImpl.java:85)
at com.hp.hpl.jena.rdf.model.impl.ModelCom.&lt;clinit>(ModelCom.java:42)
at com.hp.hpl.jena.rdf.model.ModelFactory.createDefaultModel(ModelFactory.java:122)
at com.hp.hpl.jena.rdf.model.ModelFactory.createDefaultModel(ModelFactory.java:116)
at com.hp.hpl.jena.vocabulary.OWL.&lt;clinit>(OWL.java:37)
at com.hp.hpl.jena.ontology.ProfileRegistry.&lt;clinit>(ProfileRegistry.java:48)
at com.hp.hpl.jena.rdf.model.ModelFactory.createOntologyModel(ModelFactory.java:344)
at com.virtuona.service.semcqgenerator.SeMCQgeneratorService.runApp(SeMCQgeneratorService.java:182)
at com.virtuona.service.semcqgenerator.SeMCQgeneratorService.runService(SeMCQgeneratorService.java:380)
at com.virtuona.service.ServiceCaller.callService(ServiceCaller.java:28)
at com.virtuona.service.ServletServiceCaller.callService(ServletServiceCaller.java:397)
at com.virtuona.service.ServletServiceCaller.procesRequest(ServletServiceCaller.java:258)
at com.virtuona.service.ServletServiceCaller.doPost(ServletServiceCaller.java:107)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:165)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:103)
at com.caucho.server.http.FilterChainServlet.doFilter(FilterChainServlet.java:96)
at com.caucho.server.http.Invocation.service(Invocation.java:315)
at com.caucho.server.http.CacheInvocation.service(CacheInvocation.java:135)
at com.caucho.server.http.RunnerRequest.handleRequest(RunnerRequest.java:346)
at com.caucho.server.http.RunnerRequest.handleConnection(RunnerRequest.java:274)
at com.caucho.server.TcpConnection.run(TcpConnection.java:139)
at java.lang.Thread.run(Thread.java:595)
Caused by: java.lang.NullPointerException
at java.util.XMLUtils.load(XMLUtils.java:62)
at java.util.Properties.loadFromXML(Properties.java:701)
at com.hp.hpl.jena.util.Metadata.read(Metadata.java:67)
at com.hp.hpl.jena.util.Metadata.addMetadata(Metadata.java:41)
at com.hp.hpl.jena.util.Metadata.&lt;init>(Metadata.java:35)
at com.hp.hpl.jena.JenaRuntime.&lt;clinit>(JenaRuntime.java:25)
... 22 more




>________________________________
> From: Dave Reynolds <da...@gmail.com>
>To: Milorad Tosic <mb...@yahoo.com> 
>Cc: "jena-users@incubator.apache.org" <je...@incubator.apache.org> 
>Sent: Friday, December 16, 2011 4:41 PM
>Subject: Re: comparison of JVM and Jena versions by memory usage
> 
>Hi,
>
>On Fri, 2011-12-16 at 05:39 -0800, Milorad Tosic wrote: 
>> Hi,
>> 
>> 
>> There is a short discussion on the former Jena Development/Support mailing list related to memory usage of Jena OntModel using different versions of Jena. For your information I have included a segment of the correspondence at the end of the message. Since I had a problem that looks much like memory usage limit overrun, I got interested in the problem.
>> 
>> 
>> I repeated the same experiment but with 
>> different conclusions? I compared Jena 2.6.0 with Jena 2.6.4. I couldn't
>>  notice the difference between Jena versions as reported in your 
>> previous experiment (though I used the same code). Tried with several 
>> variations of the OntModel creations styles but with minor differences 
>> in memory usage only (within 10%). I run the experiment from within 
>> Eclipse with JVM set to jre6 using compiler compliance level 1.5 (as 
>> well as 1.6). The total memory usage was around 27975k.
>>  
>> Than, I changed the JVM to jdk 1.5. There was similar relative 
>> difference between the Jena 2.6.0 and Jena 2.6.4 (within 10%). However, 
>> the absolute amount of used memory dropped to about 3400k.
>>  
>> Than I again changed the JVM to jdk 1.6. As in all previous testing 
>> configurations, there was similar relative difference between the Jena 
>> 2.6.0 and Jena 2.6.4 (within 10%). However, the absolute amount of used 
>> memory was about 6501k.
>>  
>> Consequently, I have two problems now:
>>  
>> 1) I couldn't repeat you experiment with the same results. What I am doing wrong?
>
>Assuming you are running the code that Rick originally posted then the
>problem is that that uses a naive way to measure memory usage.
>If I run with java 1.6 (sun-java on Linux) and the current Jena snapshot
>and run in eclipse I get:
>
>time: 19, totMem: 122688k, usedMem: 4859k
>
>If I run identical code from the command line I get:
>time: 12, totMem: 122688k, usedMem: 28548k
>
>The difference is down to whether a garbage collect has kicked in. If I
>force a System.gc() in that code then I get:
>
>time: 86, totMem: 122688k, usedMem: 4006k
>
>where the extra time comes from the garbage collect.
>
>
>> 2) What should I do to put the memory usage under my control? Namely, 5
>>  times larger memory usage cause my application to broke on machines 
>> with limited memory usage.
>
>I don't think there's any evidence that the problem in the thread that
>you are referring to is still an issue.
>
>You would need to explain more about what you are actually do in your
>application before we could help with that. However, if you are
>currently using inference and are having memory problems then avoiding
>inference, or using a weaker inference setting, would be a good place to
>start.
>
>Dave
>
>>  
>> Thanks,
>> Milorad Tosic
>> > 
>> > --- In jena-dev@yahoogroups.com, Dave Reynolds <da...@...> wrote:
>> > >
>> > > Rick,
>> > > 
>> > > Thanks for letting us know, thanks for the clear report.
>> > > 
>> > > Dave
>> > > 
>> > > rspates2 wrote:
>> > > > Dave,
>> > > > 
>> >
>>  > > I grabbed OWLProfile.java and reran my tests.  It looks fixed
>>  to me in terms of speed and memory use.  We should be able to use 2.6.2
>>  now.
>> > > > 
>> > > > Thanks for your swift resolution to the problem.
>> > > > 
>> > > > Rick
>> > > > 
>> > > > --- In jena-dev@yahoogroups.com, Dave Reynolds <dave.e.reynolds@> wrote:
>> > > >> Hi Rick,
>> > > >>
>> > > >> A follow up on my earlier off-list response.
>> > > >>
>> > > >> Thanks again for giving us a test case for this. It turns out not to be 
>> > > >> a reasoner issue as such.  There was a change in the internals of the 
>> > > >> Ontology API which worked inefficiently when a reasoner is present.  Ian 
>> > > >> has checked in some patches for this which brings the memory use down a 
>> > > >> lot and gives a 5x speed improvement.
>> > > >>
>> > > >> It is not quite back to 2.6.0 timings but is a significant improvement.
>> > > >>
>> > > >> We'll investigate a little more but this may be as close as we can get 
>> > > >> for now. Let us know if this is enough to make it usable for you.
>> > > >>
>> > > >> Cheers,
>> > > >> Dave
>> > > >>
>> > > >> rspates2 wrote:
>> > > >>> Dave,
>> > > >>>
>> > > >>> The difference seems to be between 2.6.0 and 2.6.2,
>> > > >>>
>> > > >>> OntModel.listClasses():
>> > > >>> 2.6.2    time: 2187, totMem: 19948k, usedMem: 13345k
>> > > >>> 2.6.0    time: 110, totMem: 5056k, usedMem: 3681k
>> > > >>> 2.5.7    time: 78, totMem: 5056k, usedMem: 3726k
>> > > >>>
>> > > >>> listHierarchyRootClasses():
>> > > >>> 2.6.2    time: 2312, totMem: 20152k, usedMem: 13859k
>> > > >>> 2.6.0    time: 172, totMem: 5056k, usedMem: 4312k
>> > > >>> 2.5.7    time: 188, totMem: 5056k, usedMem: 4078k
>> > > >>>
>> > > >>> Let me know if you need anything else.
>> > > >>>
>> > > >>> Thanks,
>> > > >>> Rick
>> > > >>>
>> > > >>> --- In jena-dev@yahoogroups.com, Dave Reynolds <dave.e.reynolds@> wrote:
>> > > >>>> rspates2 wrote:
>> > > >>>>> Hi,
>> > > >>>>>
>> >
>>  > >>>>> We switched our application from Jena 2.5.7 
>> to 2.6.2.  For an operation on OntModel.listHierarchyRootClasses() with 
>> an OntModelSpec of OWL_MEM_RDFS_INF, we saw a very significant increase 
>> in the use of memory and processing time, including out-of-memory 
>> condition for our full ontology.  Using a subset of our ontology and the
>>  code below to demonstrate, we measured processing times and memory use:
>> > > >>>>>
>> > > >>>>> 2.6.2    time: 2063, totMem: 20008k, usedMem: 14539k
>> > > >>>>> 2.5.7    time: 172, totMem: 5056k, usedMem: 3974k
>> > > >>>> Certainly a huge jump :(
>> > > >>>>
>> >
>>  > >>>>> The specifications OWL_MEM_RDFS_INF and 
>> OWL_DL_MEM_RDFS_INF produced comparable results, while 
>> OWL_DL_MEM_TRANS_INF at 2.6.2 was comparable to our 2.5.7 run with 
>> OWL_MEM_RDFS_INF.
>> > > >>>>>
>> > > 
>> >>>>> I can post the subset ontology if you need it (170 
>> k), but thought there might be some known explanation you could provide 
>> without running the demo code.  
>> > > >>>>>
>> > > >>>>> Any idea what is causing this?
>> > > >>>> No immediate ideas. The RFDS rule file itself hasn't changed in that 
>> > > >>>> time frame. It is tricky to trace back code changes over that period 
>> > > >>>> because we did a code reorg which hides a lot of the history. However, 
>> > > >>>> from memory (and the release notes) I can't think of anything that 
>> > > >>>> should have had an effect like that. There were changes around handling 
>> > > >>>> validation of data types but that isn't relevant here. We generalized 
>> > > >>>> handling of non-legal RDF triples but again that shouldn't be relevant.
>> > > >>>>
>> > > >>>> Could you try two experiments?
>> > > >>>>
>> > > >>>> First, would it be possible to time a simpler operation, such as listing 
>> > > >>>> all classes, to eliminate listHierarchyRootClasses as a factor?
>> > > >>>>
>> > > >>>> Secondly, is it possible to check with Jena 2.6.0 - that would separate 
>> > > >>>> the Java 5 changes and the datatype validation from more recent tweaks?
>> > > >>>>
>> > > >>>> If that's a problem then send me your ontology subset and I'll take a 
>> > > >>>> look when I can.
>> > > >>>>
>> > > >>>> Dave
>> > > >>>>
>> > > >>>>> Thanks for your help,
>> > > >>>>> Rick
>> > > >>>>>
>> > > >>>>> import java.io.InputStream;
>> > > >>>>> import org.junit.Test;
>> > > >>>>>
>> > > >>>>> import com.hp.hpl.jena.ontology.OntModel;
>> > > >>>>> import com.hp.hpl.jena.ontology.OntModelSpec;
>> > > >>>>> import com.hp.hpl.jena.rdf.model.Model;
>> > > >>>>> import com.hp.hpl.jena.rdf.model.ModelFactory;
>> > > >>>>> import com.hp.hpl.jena.util.iterator.ExtendedIterator;
>> > > >>>>>
>> > > >>>>> public class TestReasonerProblem {
>> > > >>>>>
>> > > >>>>>     @Test
>> > > >>>>>     public void test() throws Exception {
>> > > >>>>>
>> > > >>>>>         Model model = ModelFactory.createDefaultModel();
>> > > >>>>>         String file="clinical-factDCMapVent.owl";
>> > > >>>>>         InputStream fis =  this.getClass().getResourceAsStream(file);
>> > > >>>>>         model.read(fis, null, "RDF/XML");
>> > > >>>>>         OntModelSpec spec = OntModelSpec.OWL_MEM_RDFS_INF;
>> > > >>>>> //        OntModelSpec spec = OntModelSpec.OWL_DL_MEM_RDFS_INF;
>> > > >>>>> //        OntModelSpec spec = OntModelSpec.OWL_DL_MEM_TRANS_INF;
>> > > >>>>>         OntModel ontModel = ModelFactory.createOntologyModel(spec, model);
>> > > >>>>>        
>> > > >>>>>         long ctms = System.currentTimeMillis();
>> > > >>>>>         for (ExtendedIterator j = ontModel.listHierarchyRootClasses(); j.hasNext(); ){
>> > > >>>>>             j.next();
>> > > >>>>>         }
>> > > >>>>>         System.out.printf("time: %d, totMem: %dk, usedMem: %dk\n",
>> > > >>>>>                 (System.currentTimeMillis()-ctms),
>> > > >>>>>                 (Runtime.getRuntime().totalMemory()/1024),
>> > > >>>>>                 ((Runtime.getRuntime().totalMemory()-Runtime.getRuntime().freeMemory())/1024));
>> > > >>>>>     }
>> > > >>>>>
>> > > >>>>> }
>> > > >>>>>
>> > > >>>>>
>> > > >>>>>
>> > > >>>>>
>> > > >>>>> ------------------------------------
>> > > >>>>>
>> > > >>>>> Yahoo! Groups Links
>> > > >>>>>
>> > > >>>>>
>> > > >>>>>
>> > > >>>
>> > > >>>
>> > > >>>
>> > > >>> ------------------------------------
>> > > >>>
>> > > >>> Yahoo! Groups Links
>> > > >>>
>> > > >>>
>> > > >>>
>> > > > 
>> > > > 
>> > > > 
>> > > > 
>> > > > ------------------------------------
>> > > > 
>> > > > Yahoo! Groups Links
>> > > > 
>> > > > 
>> > > >
>> > >
>> > 
>> > 
>
>
>
>
>
>

Re: comparison of JVM and Jena versions by memory usage

Posted by Dave Reynolds <da...@gmail.com>.
Hi,

On Fri, 2011-12-16 at 05:39 -0800, Milorad Tosic wrote: 
> Hi,
> 
> 
> There is a short discussion on the former Jena Development/Support mailing list related to memory usage of Jena OntModel using different versions of Jena. For your information I have included a segment of the correspondence at the end of the message. Since I had a problem that looks much like memory usage limit overrun, I got interested in the problem.
> 
> 
> I repeated the same experiment but with 
> different conclusions? I compared Jena 2.6.0 with Jena 2.6.4. I couldn't
>  notice the difference between Jena versions as reported in your 
> previous experiment (though I used the same code). Tried with several 
> variations of the OntModel creations styles but with minor differences 
> in memory usage only (within 10%). I run the experiment from within 
> Eclipse with JVM set to jre6 using compiler compliance level 1.5 (as 
> well as 1.6). The total memory usage was around 27975k.
>  
> Than, I changed the JVM to jdk 1.5. There was similar relative 
> difference between the Jena 2.6.0 and Jena 2.6.4 (within 10%). However, 
> the absolute amount of used memory dropped to about 3400k.
>  
> Than I again changed the JVM to jdk 1.6. As in all previous testing 
> configurations, there was similar relative difference between the Jena 
> 2.6.0 and Jena 2.6.4 (within 10%). However, the absolute amount of used 
> memory was about 6501k.
>  
> Consequently, I have two problems now:
>  
> 1) I couldn't repeat you experiment with the same results. What I am doing wrong?

Assuming you are running the code that Rick originally posted then the
problem is that that uses a naive way to measure memory usage.
If I run with java 1.6 (sun-java on Linux) and the current Jena snapshot
and run in eclipse I get:

time: 19, totMem: 122688k, usedMem: 4859k

If I run identical code from the command line I get:
time: 12, totMem: 122688k, usedMem: 28548k

The difference is down to whether a garbage collect has kicked in. If I
force a System.gc() in that code then I get:

time: 86, totMem: 122688k, usedMem: 4006k

where the extra time comes from the garbage collect.


> 2) What should I do to put the memory usage under my control? Namely, 5
>  times larger memory usage cause my application to broke on machines 
> with limited memory usage.

I don't think there's any evidence that the problem in the thread that
you are referring to is still an issue.

You would need to explain more about what you are actually do in your
application before we could help with that. However, if you are
currently using inference and are having memory problems then avoiding
inference, or using a weaker inference setting, would be a good place to
start.

Dave

>  
> Thanks,
> Milorad Tosic
> > 
> > --- In jena-dev@yahoogroups.com, Dave Reynolds <da...@...> wrote:
> > >
> > > Rick,
> > > 
> > > Thanks for letting us know, thanks for the clear report.
> > > 
> > > Dave
> > > 
> > > rspates2 wrote:
> > > > Dave,
> > > > 
> >
>  > > I grabbed OWLProfile.java and reran my tests.  It looks fixed
>  to me in terms of speed and memory use.  We should be able to use 2.6.2
>  now.
> > > > 
> > > > Thanks for your swift resolution to the problem.
> > > > 
> > > > Rick
> > > > 
> > > > --- In jena-dev@yahoogroups.com, Dave Reynolds <dave.e.reynolds@> wrote:
> > > >> Hi Rick,
> > > >>
> > > >> A follow up on my earlier off-list response.
> > > >>
> > > >> Thanks again for giving us a test case for this. It turns out not to be 
> > > >> a reasoner issue as such.  There was a change in the internals of the 
> > > >> Ontology API which worked inefficiently when a reasoner is present.  Ian 
> > > >> has checked in some patches for this which brings the memory use down a 
> > > >> lot and gives a 5x speed improvement.
> > > >>
> > > >> It is not quite back to 2.6.0 timings but is a significant improvement.
> > > >>
> > > >> We'll investigate a little more but this may be as close as we can get 
> > > >> for now. Let us know if this is enough to make it usable for you.
> > > >>
> > > >> Cheers,
> > > >> Dave
> > > >>
> > > >> rspates2 wrote:
> > > >>> Dave,
> > > >>>
> > > >>> The difference seems to be between 2.6.0 and 2.6.2,
> > > >>>
> > > >>> OntModel.listClasses():
> > > >>> 2.6.2    time: 2187, totMem: 19948k, usedMem: 13345k
> > > >>> 2.6.0    time: 110, totMem: 5056k, usedMem: 3681k
> > > >>> 2.5.7    time: 78, totMem: 5056k, usedMem: 3726k
> > > >>>
> > > >>> listHierarchyRootClasses():
> > > >>> 2.6.2    time: 2312, totMem: 20152k, usedMem: 13859k
> > > >>> 2.6.0    time: 172, totMem: 5056k, usedMem: 4312k
> > > >>> 2.5.7    time: 188, totMem: 5056k, usedMem: 4078k
> > > >>>
> > > >>> Let me know if you need anything else.
> > > >>>
> > > >>> Thanks,
> > > >>> Rick
> > > >>>
> > > >>> --- In jena-dev@yahoogroups.com, Dave Reynolds <dave.e.reynolds@> wrote:
> > > >>>> rspates2 wrote:
> > > >>>>> Hi,
> > > >>>>>
> >
>  > >>>>> We switched our application from Jena 2.5.7 
> to 2.6.2.  For an operation on OntModel.listHierarchyRootClasses() with 
> an OntModelSpec of OWL_MEM_RDFS_INF, we saw a very significant increase 
> in the use of memory and processing time, including out-of-memory 
> condition for our full ontology.  Using a subset of our ontology and the
>  code below to demonstrate, we measured processing times and memory use:
> > > >>>>>
> > > >>>>> 2.6.2    time: 2063, totMem: 20008k, usedMem: 14539k
> > > >>>>> 2.5.7    time: 172, totMem: 5056k, usedMem: 3974k
> > > >>>> Certainly a huge jump :(
> > > >>>>
> >
>  > >>>>> The specifications OWL_MEM_RDFS_INF and 
> OWL_DL_MEM_RDFS_INF produced comparable results, while 
> OWL_DL_MEM_TRANS_INF at 2.6.2 was comparable to our 2.5.7 run with 
> OWL_MEM_RDFS_INF.
> > > >>>>>
> > > 
> >>>>> I can post the subset ontology if you need it (170 
> k), but thought there might be some known explanation you could provide 
> without running the demo code.  
> > > >>>>>
> > > >>>>> Any idea what is causing this?
> > > >>>> No immediate ideas. The RFDS rule file itself hasn't changed in that 
> > > >>>> time frame. It is tricky to trace back code changes over that period 
> > > >>>> because we did a code reorg which hides a lot of the history. However, 
> > > >>>> from memory (and the release notes) I can't think of anything that 
> > > >>>> should have had an effect like that. There were changes around handling 
> > > >>>> validation of data types but that isn't relevant here. We generalized 
> > > >>>> handling of non-legal RDF triples but again that shouldn't be relevant.
> > > >>>>
> > > >>>> Could you try two experiments?
> > > >>>>
> > > >>>> First, would it be possible to time a simpler operation, such as listing 
> > > >>>> all classes, to eliminate listHierarchyRootClasses as a factor?
> > > >>>>
> > > >>>> Secondly, is it possible to check with Jena 2.6.0 - that would separate 
> > > >>>> the Java 5 changes and the datatype validation from more recent tweaks?
> > > >>>>
> > > >>>> If that's a problem then send me your ontology subset and I'll take a 
> > > >>>> look when I can.
> > > >>>>
> > > >>>> Dave
> > > >>>>
> > > >>>>> Thanks for your help,
> > > >>>>> Rick
> > > >>>>>
> > > >>>>> import java.io.InputStream;
> > > >>>>> import org.junit.Test;
> > > >>>>>
> > > >>>>> import com.hp.hpl.jena.ontology.OntModel;
> > > >>>>> import com.hp.hpl.jena.ontology.OntModelSpec;
> > > >>>>> import com.hp.hpl.jena.rdf.model.Model;
> > > >>>>> import com.hp.hpl.jena.rdf.model.ModelFactory;
> > > >>>>> import com.hp.hpl.jena.util.iterator.ExtendedIterator;
> > > >>>>>
> > > >>>>> public class TestReasonerProblem {
> > > >>>>>
> > > >>>>>     @Test
> > > >>>>>     public void test() throws Exception {
> > > >>>>>
> > > >>>>>         Model model = ModelFactory.createDefaultModel();
> > > >>>>>         String file="clinical-factDCMapVent.owl";
> > > >>>>>         InputStream fis =  this.getClass().getResourceAsStream(file);
> > > >>>>>         model.read(fis, null, "RDF/XML");
> > > >>>>>         OntModelSpec spec = OntModelSpec.OWL_MEM_RDFS_INF;
> > > >>>>> //        OntModelSpec spec = OntModelSpec.OWL_DL_MEM_RDFS_INF;
> > > >>>>> //        OntModelSpec spec = OntModelSpec.OWL_DL_MEM_TRANS_INF;
> > > >>>>>         OntModel ontModel = ModelFactory.createOntologyModel(spec, model);
> > > >>>>>        
> > > >>>>>         long ctms = System.currentTimeMillis();
> > > >>>>>         for (ExtendedIterator j = ontModel.listHierarchyRootClasses(); j.hasNext(); ){
> > > >>>>>             j.next();
> > > >>>>>         }
> > > >>>>>         System.out.printf("time: %d, totMem: %dk, usedMem: %dk\n",
> > > >>>>>                 (System.currentTimeMillis()-ctms),
> > > >>>>>                 (Runtime.getRuntime().totalMemory()/1024),
> > > >>>>>                 ((Runtime.getRuntime().totalMemory()-Runtime.getRuntime().freeMemory())/1024));
> > > >>>>>     }
> > > >>>>>
> > > >>>>> }
> > > >>>>>
> > > >>>>>
> > > >>>>>
> > > >>>>>
> > > >>>>> ------------------------------------
> > > >>>>>
> > > >>>>> Yahoo! Groups Links
> > > >>>>>
> > > >>>>>
> > > >>>>>
> > > >>>
> > > >>>
> > > >>>
> > > >>> ------------------------------------
> > > >>>
> > > >>> Yahoo! Groups Links
> > > >>>
> > > >>>
> > > >>>
> > > > 
> > > > 
> > > > 
> > > > 
> > > > ------------------------------------
> > > > 
> > > > Yahoo! Groups Links
> > > > 
> > > > 
> > > >
> > >
> > 
> >