DSpace 5.3 and many SOLR memory problems

[Francis Brouns]

Hi all,

I am preparing the upgrade from our DSpace 1.8 to DSpace 5.3 and am running in many unpredictable memory issues. It is not clear when these happen, or why, but when it happens, the only way to fix it is to shut down Tomcat, wait a little and start Tomcat. Increasing heap size allocation to Catalina and java only seems to delay when the out of memory problems occur. One type of problems reports a Map failed error. This error refers to a blogpost that recommends not to allocate more that the really needed heapsize.

Any advice on still allocating sufficient memory to Tomcat so that the processes run properly but not run into these MMAP errors?

Our test server is a new 64bit Linux server, Sun java 8, Tomcat 8.0.24, DSpace 5.3, Oracle11g. Our repository is small, about 5000 items. 

The problems occur both when I do a fresh install or use an upgrade of the database with a clean dspace 5.3 code base.  We have not used SOLR before, so any SOLR indexes are created new.

Importing OAI, importing converted logs for statistics, creating discovery indexes most of the time fail at some point. Part of the indexes are written, but then it stops. This is on a test server that is not being used by others. When I run the scripts, no other scripts are being run. Every script is being run as the dspace user.

When I performed an upgrade of our 1.8 database, the browse and search indexes were not created. So, I manually ran [dspace]/bin dspace index-discovery as the dspace user. This starts fine, indexes are being written, but it then stops because of Map failed errors. 

2015-09-08 17:09:31,867 ERROR org.dspace.discovery.SolrServiceImpl @ Error while writing item to discovery index: 1820/1376 message:Map failed: MMapIndexInput(path="/dspace/dspace183/solr/search/data/index/_n6.fdt") [this may be caused by lack of enough unfragmented virtual address space or too restrictive virtual memory limits enforced by the operating system, preventing us to map a chunk of 35127671 bytes. Please review 'ulimit -v', 'ulimit -m' (both should return 'unlimited'), and 'sysctl vm.max_map_count'. More information: http://blog.thetaphi.de/2012/07/use-lucenes-mmapdirectory-on-64bit.html]

org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Map failed: MMapIndexInput(path="/dspace/dspace183/solr/search/data/index/_n6.fdt") [this may be caused by lack of enough unfragmented virtual address space or too restrictive virtual memory limits enforced by the operating system, preventing us to map a chunk of 35127671 bytes. Please review 'ulimit -v', 'ulimit -m' (both should return 'unlimited'), and 'sysctl vm.max_map_count'. More information: http://blog.thetaphi.de/2012/07/use-lucenes-mmapdirectory-on-64bit.html]

at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:552)

at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:210)

at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:206)

at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:124)

at org.dspace.discovery.SolrServiceImpl.writeDocument(SolrServiceImpl.java:738)

at org.dspace.discovery.SolrServiceImpl.buildDocument(SolrServiceImpl.java:1419)

at org.dspace.discovery.SolrServiceImpl.indexContent(SolrServiceImpl.java:225)

at org.dspace.discovery.SolrServiceImpl.updateIndex(SolrServiceImpl.java:405)

at org.dspace.discovery.IndexClient.main(IndexClient.java:127)

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

at java.lang.reflect.Method.invoke(Method.java:497)

at org.dspace.app.launcher.ScriptLauncher.runOneCommand(ScriptLauncher.java:226)

at org.dspace.app.launcher.ScriptLauncher.main(ScriptLauncher.java:78)

When importing OAI items, it also fails with a MMAP error

2015-09-02 16:03:39,299 INFO  org.apache.solr.update.processor.LogUpdateProcessor @ [oai] webapp=/solr path=/update params={wt=javabin&version=2} {add=[1820/3352 (1511210477730922496)]} 0 3

2015-09-02 16:03:39,398 ERROR org.apache.solr.update.CommitTracker @ auto commit error...:java.io.IOException: Map failed: MMapIndexInput(path="/dspace/dspace183/solr/oai/data/index/_1z_Lucene41_0.tim") [this may be caused by lack of enough unfragmented virtual address space or too restrictive virtual memory limits enforced by the operating system, preventing us to map a chunk of 164256 bytes. Please review 'ulimit -v', 'ulimit -m' (both should return 'unlimited'), and 'sysctl vm.max_map_count'. More information: http://blog.thetaphi.de/2012/07/use-lucenes-mmapdirectory-on-64bit.html]

at sun.nio.ch.FileChannelImpl.map(FileChannelImpl.java:907)

at org.apache.lucene.store.MMapDirectory.map(MMapDirectory.java:224)

at org.apache.lucene.store.MMapDirectory.openInput(MMapDirectory.java:199)

at org.apache.lucene.store.NRTCachingDirectory.openInput(NRTCachingDirectory.java:198)

at org.apache.lucene.codecs.blocktree.BlockTreeTermsReader.<init>(BlockTreeTermsReader.java:106)

at org.apache.lucene.codecs.lucene41.Lucene41PostingsFormat.fieldsProducer(Lucene41PostingsFormat.java:441)

at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat$FieldsReader.<init>(PerFieldPostingsFormat.java:197)

at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat.fieldsProducer(PerFieldPostingsFormat.java:254)

at org.apache.lucene.index.SegmentCoreReaders.<init>(SegmentCoreReaders.java:120)

at org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:108)

at org.apache.lucene.index.ReadersAndUpdates.getReader(ReadersAndUpdates.java:144)

at org.apache.lucene.index.BufferedUpdatesStream.applyDeletesAndUpdates(BufferedUpdatesStream.java:282)

at org.apache.lucene.index.IndexWriter.applyAllDeletesAndUpdates(IndexWriter.java:3271)

at org.apache.lucene.index.IndexWriter.maybeApplyDeletes(IndexWriter.java:3262)

at org.apache.lucene.index.IndexWriter.prepareCommitInternal(IndexWriter.java:2952)

at org.apache.lucene.index.IndexWriter.commitInternal(IndexWriter.java:3097)

at org.apache.lucene.index.IndexWriter.commit(IndexWriter.java:3064)

at org.apache.solr.update.DirectUpdateHandler2.commit(DirectUpdateHandler2.java:582)

at org.apache.solr.update.CommitTracker.run(CommitTracker.java:216)

at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)

at java.util.concurrent.FutureTask.run(FutureTask.java:266)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)

at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)

at java.lang.Thread.run(Thread.java:745)

importing of statistics from converted logs most of the time does not complete. Part of the statistics are written to the SOLR index and then is suddenly stops. For example with this IOError as reported in console. The log file sometimes also report an out of memory.

Processed 4733 log lines                                                                                                             

 - 135 entries added to solr: 2.852%                                                                                                 

 - 4598 errors: 97.148%                                                                                                              

 - 0 search engine activity skipped: 0%                                                                                              

About to commit data to solr...Error committing statistics to solr server!                                                           

org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://localhost:8080/solr/statistics

        at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:566)                                    

        at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:210)                                          

        at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:206)                                          

        at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:124)

        at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:168)

        at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:146)

        at org.dspace.statistics.util.StatisticsImporter.load(StatisticsImporter.java:371)

        at org.dspace.statistics.util.StatisticsImporter.main(StatisticsImporter.java:486)

        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)

        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

        at java.lang.reflect.Method.invoke(Method.java:497)

        at org.dspace.app.launcher.ScriptLauncher.runOneCommand(ScriptLauncher.java:226)

        at org.dspace.app.launcher.ScriptLauncher.main(ScriptLauncher.java:78)

Caused by: org.apache.http.NoHttpResponseException: localhost:8080 failed to respond

        at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:143)

        at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)

        at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:260)

        at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283)

        at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251)

        at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197)

        at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:271)

        at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:123)

        at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:685)

        at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:487)

        at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:863)

        at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)

        at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106)

        at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:57)

        at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:448)

        ... 13 more

best wishes,

Francis Brouns

[Andrea Schweer]

Hi,

I note this in the error message:

On 11/09/15 10:42, Francis Brouns wrote:

Please review 'ulimit -v', 'ulimit -m' (both should return 'unlimited'), and 'sysctl vm.max_map_count'. More information: http://blog.thetaphi.de/2012/07/use-lucenes-mmapdirectory-on-64bit.html

What do you get for
ulimit -v
ulimit -m
(I'm assuming these both need to be run as the same user that's running Tomcat)

What value do you have for vm.max_map_count in /etc/sysctl.conf? According to the link from the error message:

The default value of vm.max_map_count is 65530, you may need to raise it

Though it looks like sorting out the limits should be the first step.

What are your memory settings for Tomcat? How does that compare to the physical RAM size of the machine and/or how much RAM is typically in use for other processes? Is this machine running only DSpace? Which web apps do you have deployed?

Do I understand correctly that you also had out of memory problems in addition to the mmap error? If so, out of what type of memory -- in my experience, the main culprit with Discovery has been PermGen, not heap size.

cheers,
Andrea

-- 
Dr Andrea Schweer
IRR Technical Specialist, ITS Information Systems
The University of Waikato, Hamilton, New Zealand
+64-7-837 9120

[Francis Brouns]

Dear Andrea,

thanks for your quick reply.

Because I encountered various memory problems (heap size) with the  512MB as suggested for heapsize in the DSpace manual, I have increased that to 1024m for both -Xms -Xmx, in CATALINA_OPTS. That may be a little high, because the server only has 1.8GiB. 

However, the test server is dedicated to DSpace, running only Tomcat and jspui, oai and solr. The database is at another server. No users access the server except for me. 

in bin/dspace java_opts  -Xms is set to 256m

While I ran the index-discovery script, no access was made to dspace jspui via the browser.

ulimit returns unlimited

ulimit -v 3215760

ulimit -m 1635060

vm.max_map_count is not set in /etc/sysctl.conf

I'll ask the IT Department to change ulimit and add vm.max_map_count

As far as I recall, memory problems were about heap size. When I also set MaxPermSize, java returns a warning, because this no longer is supported in java 8. Instead MetaSpace is being used.

The Oracle jbdc pool also gets exhausted quite often, and sometimes this also results in memory problems. The only way to fix this is to stop and start Tomcat.

Until now we never had to give Tomcat a lot of memory, although we do restart Tomcat daily. I guess the system engineers need to look into tuning the server and Tomcat.

best wishes,

Francis Brouns

[Alan Orth]

The first thing I'm wondering is if Java 8 + Tomcat 8 is a configuration that has been tested well... all my DSpace instances use Oracle Java 7 and Tomcat 7.

Alan

--
You received this message because you are subscribed to the Google Groups "DSpace Technical Support" group.
To unsubscribe from this group and stop receiving emails from it, send an email to dspace-tech...@googlegroups.com.
To post to this group, send email to dspac...@googlegroups.com.
Visit this group at http://groups.google.com/group/dspace-tech.
For more options, visit https://groups.google.com/d/optout.

[Francis Brouns]

Dear Alan,

maybe I got confused about the Java version, because on page 39 of the PDF Manual it states that Java 8 update 20 or later is recommended, but that might apply to Elastic search 

The manual recommends Apache Tomcat 7.0 or higher and warns about the need to change Tomcat's configuration for the JSP compilation when using Tomcat 7.0. That is why I'd chosen Tomcat 8.

So, your advice would be to downgrade to java 7 and Tomcat 7? Oracle however warns against using java 7 as public updates are no longer provided. I'd rather not install a product that is no longer supported on a server in a production environment.

best wishes,

Francis

[Alan Orth]

Sorry, I don't actually have a recommendation ― I just haven't heard much about Java 8 on the mailing list so it just struck me as a configuration that might not have been tested very well. Also, the fact that Oracle has end of life'd Java 7 doesn't mean that DSpace automatically works with Java 8. ;)

As for your problem, look at your memory allocations a bit closer. I think 1.8GiB of physical RAM might be cutting it close if you've allocated 1GiB to Tomcat, in addition to the indexing batch job and the normal operating system stuff. Check `free -m` and `dmesg` while running the job to see if you run out of RAM, start swapping, or if the OS kills the process for some reason.

Alan

--

You received this message because you are subscribed to the Google Groups "DSpace Technical Support" group.
To unsubscribe from this group and stop receiving emails from it, send an email to dspace-tech...@googlegroups.com.
To post to this group, send email to dspac...@googlegroups.com.
Visit this group at http://groups.google.com/group/dspace-tech.
For more options, visit https://groups.google.com/d/optout.

--

Alan Orth
alan...@gmail.com
https://alaninkenya.org
https://mjanja.ch
"In heaven all the interesting people are missing." -Friedrich Nietzsche

GPG public key ID: 0x8cb0d0acb5cd81ec209c6cdfbd1a0e09c2f836c0

[Francis Brouns]

Dear Alan,

thanks for your suggestion. Indeed, 1.8G RAM is probably not enough. I did not really check available RAM when setting Tomcat. It should not be a problem to give the production server more than 2G RAM. That might solve part of the problem.

I'll try to run the scripts you suggest. maybe that will give a better indication.

We also will try java 7 and tomcat 7.

kind regards,

Francis Brouns 

[Alan Orth]

For reference, our DSpace has 50,000 items and runs on a server with 8GiB of RAM. Right now our Tomcat's JAVA_OPTS are the following:

-Djava.awt.headless=true -Xms4096m -Xmx4096m -XX:MaxPermSize=256m -XX:+UseG1GC

And I just checked our JVM heap usage from the system's munin graphs and it looks like we are only using 2GiB, so I'm actually wasting RAM (the OS could be using it for caches, but also it causes overhead for Java's garbage collection)! I'll adjust that to something like 3GiB next time I re-deploy. Also, I am using the new G1GC garbage collector (well, new in Java 7 several years ago) but I should perhaps switch back to the default, as that was a case of pre-mature optimization.

Regards,

Alan

--

You received this message because you are subscribed to the Google Groups "DSpace Technical Support" group.
To unsubscribe from this group and stop receiving emails from it, send an email to dspace-tech...@googlegroups.com.
To post to this group, send email to dspac...@googlegroups.com.
Visit this group at http://groups.google.com/group/dspace-tech.
For more options, visit https://groups.google.com/d/optout.

[Hilton Gibson]

Hi All,

Our settings plus a Munin graph are available here: http://wiki.lib.sun.ac.za/index.php/SUNScholar/Prepare_Ubuntu/S05/Ubuntu-14.04#Step_5.4_Java_environment_settings_for_Tomcat_webapp_server

Cheers

hg

Hilton Gibson

Stellenbosch University Library

http://staff.lib.sun.ac.za/~hgibson/about

[Alan Orth]

Hey, Hilton.

Interesting, you guys are using a pretty beefy server. I would be interested to see your jvm stats. Our DSpace repositories are pretty comparable (50,000–60,000 items) but you've allocated four times as much RAM as us. Munin can monitor Tomcat's jvm heap but it doesn't work out of the box. I've attached mine, which shows that my heap size is actually way too large!

Alan

[Hilton Gibson]

Hi Alan,

See attached.

The spikes are a result of a regular morning restart.

Cheers

hg

Hilton Gibson

Stellenbosch University Library

http://staff.lib.sun.ac.za/~hgibson/about

[Alan Orth]

Interesting. You're definitely using more memory than us, but you still have quite a bit of over-allocated heap. You could easily free up 1.5GiB of that and give it back to the OS for other things!

Alan