Opened 9 years ago

Closed 8 years ago

#1522 closed defect (wontfix)

GeoNetwork 3.0.3 fails to start in 32bit system

Reported by: kalxas Owned by: live-demo@…
Priority: critical Milestone: OSGeoLive11.0
Component: OSGeoLive Keywords: geonetwork 3
Cc: live-demo@…, simonp

Description

While testing the latest nightly build, I found that GeoNetwork is consuming a lot of RAM and swaps out both my test VMs (both 32 and 64 bit, running the live system) even with 4GB RAM allocated.

This seems to be a Jetty/Java issue.

Attachments (2)

hs_err_pid4880.log​ (220.9 KB ) - added by kalxas 8 years ago.
error log
replay_pid4880.log.tar.gz​ (91.4 KB ) - added by kalxas 8 years ago.
another log

Download all attachments as: .zip

Change History (39)

comment:1 by fxp, 9 years ago

Testing beta1 64b, I don't have the issue on a 2Go RAM virtual machine (with -Xmx set to 1g for the app). It should consume quite some RAM on first startup as it builds the JS cache (minify deps for all apps - search/editor/admin - taking 2-3 min on the VM).

When do you have the error ? on startup ? on use ?

comment:2 by darkblueb, 9 years ago

VirtualBox VM: revB1 i686, 826GB of RAM, four cores no changes to -Xmx - "Unable to Connect" in Firefox, even after four minutes

comment:3 by darkblueb, 9 years ago

VM: revB1 i686, 1024GB of RAM, four cores no changes to -Xmx

Start GeoNetwork; all cores active, RAM allocated past all available to 480GB swap used; before the launcher progress bar is done, activity ceases; "Unable to Connect" even after three minutes

comment:4 by darkblueb, 9 years ago

VM: revB1 i686, 1824GB of RAM, four cores no changes to -Xmx

Start GeoNetwork?; all cores active, RAM allocated all available to some small swap used; before the launcher progress bar is done, activity ceases; "Unable to Connect"

ps aux | grep java shows no java processes running

comment:5 by kalxas, 9 years ago

The java process dies when it runs out of RAM after 5 mins or so. I am using the live system on VirtualBox, not an installed system.

comment:6 by kalxas, 9 years ago

I have prepared a branch to revert GeoNetwork back to 2.10 in case no solution is found for 3.0.1

​https://github.com/OSGeo/OSGeoLive/pull/44

comment:7 by kalxas, 9 years ago

Priority: blocker → critical

GeoNetwork 2.10 works fine in build 158 so this is not a blocker anymore...

comment:9 by kalxas, 9 years ago

Thank you, I will create a new nightly to test.

comment:11 by fxp, 9 years ago

Thanks. Build 162 starts for me without installing the VM (but it was also with previous build).

But then I've another error preventing part of the application to work properly: 

2015-08-27 13:22:23.200:WARN:oejs.ServletHandler:Error for /geonetwork/images/logos/10e9ce99-b51f-47b0-a237-4dd749a2f4e4.png
java.lang.NoClassDefFoundError: Could not initialize class org.fao.geonet.resources.Resources
	at org.fao.geonet.resources.ResourceFilter$Instance.<init>(ResourceFilter.java:65)

Could this be related to specific ImageIO setup on the osgeolive ?

comment:12 by kalxas, 9 years ago

So, I understand that providing the database binary now works fine (does not need to be created on the first startup anymore), right?

Regarding ImageIO, we have not changed anything from the default Java 7 on Ubuntu. Perhaps a permissions problem?

comment:13 by fxp, 9 years ago

So, I understand that providing the database binary now works fine

After further testing of last build with different VM configuration, I would say:

  • use GN3 on a virtual box with at least 3+Go RAM (as it looks like startup issues are mainly related to memory troubles) - 1Go does not start, 2Go sometimes starts.
  • on first startup, it still create the database and load default data so it takes some times.
  • sometimes (not sure exactly when and why) it refresh the JS cache and needs memory for that
  • ImageIO, it looks related to JDK version and the imageio version used (first time this issue is observed AFAIK). Removing imageio from the lib folder fix the issue:

/usr/local/lib/geonetwork/bin$ rm ../web/geonetwork/WEB-INF/lib/jai_imageio-1.1.jar

Once you have an application running with a default db and a JS cache populated, startup and using the application is fast.

comment:14 by kalxas, 9 years ago

Milestone: OSGeoLive9.0 → OSGeoLive9.5

comment:15 by kalxas, 9 years ago

Priority: critical → blocker

Hi,

I tested the GeoNetwork 3.0.1 setup again in latest 9.5 nightly build (live system under Virtual Box):

  1. I removed the jai_imageio-1.1.jar library manually as suggested.
  2. With 2GB RAM the VM goes to swap and finally dies...
  3. With 4GB RAM it takes ~6 mins to finally start up. In the meanwhile the Firefox window shows up with an "page not found" error.
  4. After the application starts it seems that there are no data loaded in the application. I guess this is not expected, right?

I am very concerned that a simple user will not be patient enough to wait for 6 mins for the application to start (even if we update the Quickstart to mention this). Is there any way we can create the database with a script during the installation process?

Best, Angelos

comment:16 by kalxas, 9 years ago

Update: After the first startup, restarting GeoNetwork takes only 2 mins. The sample data are easy to find and load from the UI. We need to revert the OSGeoLive-doc commits to the 3.0.1 version...

comment:17 by kalxas, 9 years ago

Update: I have asked for feedback on GeoNetwork-devel mailing list.

comment:18 by kalxas, 9 years ago

Keywords: geonetwork 3 added
Priority: blocker → critical

comment:19 by simonp, 9 years ago

Have built 3.0.4 with compile time js/css cache - a couple of issues remain but this should avoid the cpu/memory intensive problems with wro4j building the js/css cache at run time when the app is first used.

comment:20 by kalxas, 9 years ago

Excellent news. Waiting for a pull request so we can build an iso and test the result.

comment:22 by kalxas, 9 years ago

With this PR the launch time of GeoNetwork seems to be much less (CPU takes 3 mins to settle down) the service seems to be down after that.

ISO to test: ​http://aiolos.survey.ntua.gr/gisvm/dev/osgeo-live-nightly-pr84-amd64-1b2aaf7.iso

comment:23 by simonp, 9 years ago

Ok - thanks Angelos - working on why this is failing now. Updated the pull request with correct settings db file. Still appears to be some issues with loading templates and sample data in my vm once the app starts up. I'll do some more checking.

Last edited 9 years ago by simonp (previous) (diff)

comment:24 by simonp, 9 years ago

The old sealing violation pain on the jai stuff was causing a misleading exception due to a static initialization in a GN class that required the jai imageio code. Seems the best fix to get this working reliably is to chuck away the jai jars installed in GeoNetwork lib after installation - so a fix to install_geonetwork.sh will do this. Without the jai jars it works reliably.

Could also extend the startup delay for the progress bar to take into account longer startup time?

comment:26 by kalxas, 9 years ago

Cc: simonp added

The pull request has been merged, but the installation still has issues. I have extended the startup delay as requested.

There is a new nightly build:

​http://aiolos.survey.ntua.gr/gisvm/dev/osgeo-live-nightly-build151-amd64-81cad69.iso

GeoNetwork fails to start the first time (503 error after the CPU has calmed). The memory allocation and time to startup is much better now. After killing jetty and restarting GeoNetwork, it works as expected.

At least now the status is better than before...

comment:27 by kalxas, 9 years ago

Issue fixed with

​https://github.com/OSGeo/OSGeoLive/pull/90

Thanks Simon for your efforts!

comment:28 by kalxas, 9 years ago

Resolution: → fixed
Status: new → closed

comment:29 by kalxas, 9 years ago

Priority: critical → blocker
Resolution: fixed
Status: closed → reopened
Summary: GeoNetwork 3.0.1 fails to start in a VM → GeoNetwork 3.0.3 fails to start in 32bit system

While GeoNetwork 3.0.3 is working as expected in 64 bit system (RC1), unfortunately it fails to work on the 32 bit system.

Here is the Jetty output log from the live 32bit RC1 iso: 

2016-03-14 19:20:50.516:INFO:oejs.Server:jetty-8.1.16.v20140903
2016-03-14 19:20:50.762:INFO:oejdp.ScanningAppProvider:Deployment monitor /usr/local/lib/geonetwork/web at interval 1
2016-03-14 19:20:50.768:INFO:oejd.DeploymentManager:Deployable added: /usr/local/lib/geonetwork/web/geonetwork
2016-03-14 19:21:52.707:WARN:oejuc.AbstractLifeCycle:FAILED o.e.j.w.WebAppContext{/geonetwork,[file:/usr/local/lib/geonetwork/web/geonetwork/, jar:file:/usr/local/lib/geonetwork/web/geonetwork/WEB-INF/lib/coffee-script-1.8.0.jar!/META-INF/resources/, jar:file:/usr/local/lib/geonetwork/web/geonetwork/WEB-INF/lib/emberjs-1.5.0.jar!/META-INF/resources/, jar:file:/usr/local/lib/geonetwork/web/geonetwork/WEB-INF/lib/handlebars-1.3.0.jar!/META-INF/resources/, jar:file:/usr/local/lib/geonetwork/web/geonetwork/WEB-INF/lib/jquery-1.10.2-1.jar!/META-INF/resources/, jar:file:/usr/local/lib/geonetwork/web/geonetwork/WEB-INF/lib/jshint-2.4.3.jar!/META-INF/resources/, jar:file:/usr/local/lib/geonetwork/web/geonetwork/WEB-INF/lib/jslint-c657984cd7.jar!/META-INF/resources/, jar:file:/usr/local/lib/geonetwork/web/geonetwork/WEB-INF/lib/json2-20110223.jar!/META-INF/resources/, jar:file:/usr/local/lib/geonetwork/web/geonetwork/WEB-INF/lib/less-1.3.3.jar!/META-INF/resources/]},/usr/local/lib/geonetwork/web/geonetwork: java.lang.OutOfMemoryError
java.lang.OutOfMemoryError
	at java.util.zip.Inflater.inflateBytes(Native Method)
	at java.util.zip.Inflater.inflate(Inflater.java:259)
	at java.util.zip.InflaterInputStream.read(InflaterInputStream.java:152)
	at java.io.FilterInputStream.read(FilterInputStream.java:133)
	at java.io.FilterInputStream.read(FilterInputStream.java:133)
	at org.objectweb.asm.ClassReader.a(Unknown Source)
	at org.objectweb.asm.ClassReader.<init>(Unknown Source)
	at org.eclipse.jetty.annotations.AnnotationParser.scanClass(AnnotationParser.java:898)
	at org.eclipse.jetty.annotations.AnnotationParser$2.processEntry(AnnotationParser.java:857)
	at org.eclipse.jetty.webapp.JarScanner.matched(JarScanner.java:161)
	at org.eclipse.jetty.util.PatternMatcher.matchPatterns(PatternMatcher.java:100)
	at org.eclipse.jetty.util.PatternMatcher.match(PatternMatcher.java:82)
	at org.eclipse.jetty.webapp.JarScanner.scan(JarScanner.java:84)
	at org.eclipse.jetty.annotations.AnnotationParser.parse(AnnotationParser.java:869)
	at org.eclipse.jetty.annotations.AnnotationParser.parse(AnnotationParser.java:884)
	at org.eclipse.jetty.annotations.AnnotationConfiguration.parseWebInfLib(AnnotationConfiguration.java:422)
	at org.eclipse.jetty.annotations.AnnotationConfiguration.configure(AnnotationConfiguration.java:120)
	at org.eclipse.jetty.webapp.WebAppContext.configure(WebAppContext.java:468)
	at org.eclipse.jetty.webapp.WebAppContext.startContext(WebAppContext.java:1237)
	at org.eclipse.jetty.server.handler.ContextHandler.doStart(ContextHandler.java:717)
	at org.eclipse.jetty.webapp.WebAppContext.doStart(WebAppContext.java:494)
	at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:64)
	at org.eclipse.jetty.deploy.bindings.StandardStarter.processBinding(StandardStarter.java:39)
	at org.eclipse.jetty.deploy.AppLifeCycle.runBindings(AppLifeCycle.java:186)
	at org.eclipse.jetty.deploy.DeploymentManager.requestAppGoal(DeploymentManager.java:494)
	at org.eclipse.jetty.deploy.DeploymentManager.addApp(DeploymentManager.java:141)
	at org.eclipse.jetty.deploy.providers.ScanningAppProvider.fileAdded(ScanningAppProvider.java:145)
	at org.eclipse.jetty.deploy.providers.ScanningAppProvider$1.fileAdded(ScanningAppProvider.java:56)
	at org.eclipse.jetty.util.Scanner.reportAddition(Scanner.java:615)
	at org.eclipse.jetty.util.Scanner.reportDifferences(Scanner.java:540)
	at org.eclipse.jetty.util.Scanner.scan(Scanner.java:403)
	at org.eclipse.jetty.util.Scanner.doStart(Scanner.java:337)
	at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:64)
	at org.eclipse.jetty.deploy.providers.ScanningAppProvider.doStart(ScanningAppProvider.java:121)
	at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:64)
	at org.eclipse.jetty.deploy.DeploymentManager.startAppProvider(DeploymentManager.java:555)
	at org.eclipse.jetty.deploy.DeploymentManager.doStart(DeploymentManager.java:230)
	at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:64)
	at org.eclipse.jetty.util.component.AggregateLifeCycle.doStart(AggregateLifeCycle.java:81)
	at org.eclipse.jetty.server.handler.AbstractHandler.doStart(AbstractHandler.java:58)
	at org.eclipse.jetty.server.handler.HandlerWrapper.doStart(HandlerWrapper.java:96)
	at org.eclipse.jetty.server.Server.doStart(Server.java:282)
	at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:64)
	at org.eclipse.jetty.xml.XmlConfiguration$1.run(XmlConfiguration.java:1274)
	at java.security.AccessController.doPrivileged(Native Method)
	at org.eclipse.jetty.xml.XmlConfiguration.main(XmlConfiguration.java:1197)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.eclipse.jetty.start.Main.invokeMain(Main.java:473)
	at org.eclipse.jetty.start.Main.start(Main.java:615)
	at org.eclipse.jetty.start.Main.main(Main.java:96)#
# There is insufficient memory for the Java Runtime Environment to continue.
# Native memory allocation (malloc) failed to allocate 32756 bytes for ChunkPool::allocate
# An error report file with more information is saved as:
# /usr/local/lib/geonetwork/jetty/hs_err_pid3960.log

and /usr/local/lib/geonetwork/jetty/hs_err_pid3960.log 

#
# There is insufficient memory for the Java Runtime Environment to continue.
# Native memory allocation (malloc) failed to allocate 32756 bytes for ChunkPool::allocate
# Possible reasons:
#   The system is out of physical RAM or swap space
#   In 32 bit mode, the process size limit was hit
# Possible solutions:
#   Reduce memory load on the system
#   Increase physical memory or swap space
#   Check if swap backing store is full
#   Use 64 bit Java on a 64 bit OS
#   Decrease Java heap size (-Xmx/-Xms)
#   Decrease number of Java threads
#   Decrease Java thread stack sizes (-Xss)
#   Set larger code cache with -XX:ReservedCodeCacheSize=
# This output file may be truncated or incomplete.
#
#  Out of Memory Error (allocation.cpp:214), pid=3960, tid=3008150336
#
# JRE version: OpenJDK Runtime Environment (7.0_95) (build 1.7.0_95-b00)
# Java VM: OpenJDK Client VM (24.95-b01 mixed mode, sharing linux-x86 )
# Derivative: IcedTea 2.6.4
# Distribution: Ubuntu 14.04.3 LTS, package 7u95-2.6.4-0ubuntu0.14.04.1
# Failed to write core dump. Core dumps have been disabled. To enable core dumping, try "ulimit -c unlimited" before starting Java again
#

---------------  T H R E A D  ---------------

Current thread (0xb674dc00):  JavaThread "C1 CompilerThread0" daemon [_thread_in_native, id=3970, stack(0xb344b000,0xb34cc000)]

Stack: [0xb344b000,0xb34cc000]

Current CompileTask:
C1:  66070  812

comment:30 by kalxas, 9 years ago

Testing environment:

VirtualBox with 32bit RC1 iso mounted (live system)

CPU: 1 core

RAM: 4GB

comment:31 by kalxas, 9 years ago

Priority: blocker → critical

Fixed in master:

​https://github.com/OSGeo/OSGeoLive/pull/102

comment:32 by kalxas, 9 years ago

Resolution: → fixed
Status: reopened → closed

comment:33 by kalxas, 8 years ago

Milestone: OSGeoLive9.5 → OSGeoLive10.0
Resolution: fixed
Status: closed → reopened

This issue is back on 32 bit iso

by kalxas, 8 years ago

Attachment: hs_err_pid4880.log​ added

error log

by kalxas, 8 years ago

Attachment: replay_pid4880.log.tar.gz​ added

another log

comment:34 by kalxas, 8 years ago

As can be seen from the attached logs (32 bit system), java runs out of memory on a 4GB VM.

comment:35 by kalxas, 8 years ago

Milestone: OSGeoLive10.0 → OSGeoLive10.5

Ticket retargeted after milestone closed

comment:36 by kalxas, 8 years ago

Milestone: OSGeoLive10.5 → OSGeoLive11.0

Ticket retargeted after milestone closed

comment:37 by kalxas, 8 years ago

Resolution: → wontfix
Status: reopened → closed

32bit system will not be officially supported for 11.0 release

Note: See TracTickets for help on using tickets.