Elastic search issues

[anand sudhan]

Hi Folks,

I have been getting OutOfMemory crashes with Sonarqube. I believe this has to do something with Elastic search heap memory settings.

I am using 5.6.6 of Sonarqube sever (LTS) and Java, Javascript and  C++ plugins.

This is what my sonar.properties file looks like :

#WEB SERVER

sonar.web.javaOpts=-Xmx768m -Xms128m -XX:+HeapDumpOnOutOfMemoryError -Djava.net.preferIPv4Stack=true

#COMPUTE ENGINE

sonar.ce.javaOpts=-Xmx512m -Xms128m -XX:+HeapDumpOnOutOfMemoryError -Djava.net.preferIPv4Stack=true

# DEVELOPMENT - only for developers

sonar.web.dev=true

I will try commenting out sonar.web.dev=true - as it is recommeded only for development).

Besides that, how can I tweak the memory settings to not crash and burn?

Thanks,

Anand

Below is the server logs (stacktrace during the crash):

-----------------------------------------------------------------------------------

2017.03.23 12:42:40 INFO  web[o.s.s.s.RegisterPermissionTemplates] Register permission templates

2017.03.23 12:42:40 INFO  web[o.s.s.s.RenameDeprecatedPropertyKeys] Rename deprecated property keys

2017.03.23 12:42:40 INFO  web[o.s.s.p.MasterServletFilter] Initializing servlet filter org.sonar.server.authentication.InitFilter@5ed5073 [pattern=/sessions/init/*]

2017.03.23 12:42:40 INFO  web[o.s.s.p.MasterServletFilter] Initializing servlet filter org.sonar.server.authentication.OAuth2CallbackFilter@38f30417 [pattern=/oauth2/callback/*]

2017.03.23 12:42:40 INFO  web[o.s.s.e.IndexerStartupTask] Index activities

2017.03.23 12:42:40 INFO  web[o.s.s.e.IndexerStartupTask] Index issues

2017.03.23 12:42:40 INFO  web[o.s.s.e.IndexerStartupTask] Index tests

2017.03.23 12:42:40 INFO  web[o.s.s.e.IndexerStartupTask] Index users

2017.03.23 12:42:40 INFO  web[o.s.s.e.IndexerStartupTask] Index views

2017.03.23 12:42:40 INFO  web[o.s.s.p.w.RestartAction] WebServer restarted

java.lang.OutOfMemoryError: GC overhead limit exceeded

Dumping heap to java_pid32176.hprof ...

Heap dump file created [1247585818 bytes in 16.127 secs]

2017.03.23 14:55:27 INFO  web[o.e.client.transport] [sonar-1490276583968] failed to get node info for [#transport#-1][asudhaka-deb7-64.dhcp.mathworks.com][inet[/127.0.0.1:9001]], disconnecting...

org.elasticsearch.transport.ReceiveTimeoutTransportException: [][inet[/127.0.0.1:9001]][cluster:monitor/nodes/info] request_id [3875] timed out after [5463ms]

at org.elasticsearch.transport.TransportService$TimeoutHandler.run(TransportService.java:529) ~[elasticsearch-1.7.5.jar:na]

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_101]

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_101]

at java.lang.Thread.run(Thread.java:745) [na:1.8.0_101]

SEVERE:Memory usage is low, parachute is non existent, your system may start failing.

java.lang.OutOfMemoryError: GC overhead limit exceeded

at java.util.Arrays.copyOf(Arrays.java:3236)

at java.util.zip.ZipCoder.getBytes(ZipCoder.java:89)

at java.util.zip.ZipFile.getEntry(ZipFile.java:310)

at java.util.jar.JarFile.getEntry(JarFile.java:240)

at java.util.jar.JarFile.getJarEntry(JarFile.java:223)

at sun.misc.URLClassPath$JarLoader.getResource(URLClassPath.java:1005)

at sun.misc.URLClassPath.getResource(URLClassPath.java:212)

at java.net.URLClassLoader$1.run(URLClassLoader.java:365)

at java.net.URLClassLoader$1.run(URLClassLoader.java:362)

at java.security.AccessController.doPrivileged(Native Method)

at java.net.URLClassLoader.findClass(URLClassLoader.java:361)

at java.lang.ClassLoader.loadClass(ClassLoader.java:424)

at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:331)

at java.lang.ClassLoader.loadClass(ClassLoader.java:357)

at ch.qos.logback.classic.spi.PackagingDataCalculator.loadClass(PackagingDataCalculator.java:207)

at ch.qos.logback.classic.spi.PackagingDataCalculator.bestEffortLoadClass(PackagingDataCalculator.java:232)

at ch.qos.logback.classic.spi.PackagingDataCalculator.computeBySTEP(PackagingDataCalculator.java:138)

at ch.qos.logback.classic.spi.PackagingDataCalculator.populateUncommonFrames(PackagingDataCalculator.java:113)

at ch.qos.logback.classic.spi.PackagingDataCalculator.populateFrames(PackagingDataCalculator.java:105)

at ch.qos.logback.classic.spi.PackagingDataCalculator.calculate(PackagingDataCalculator.java:57)

at ch.qos.logback.classic.spi.ThrowableProxy.calculatePackagingData(ThrowableProxy.java:147)

at ch.qos.logback.classic.spi.LoggingEvent.<init>(LoggingEvent.java:124)

at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:440)

at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:396)

at ch.qos.logback.classic.Logger.log(Logger.java:788)

at org.slf4j.bridge.SLF4JBridgeHandler.callLocationAwareLogger(SLF4JBridgeHandler.java:221)

at org.slf4j.bridge.SLF4JBridgeHandler.publish(SLF4JBridgeHandler.java:297)

at java.util.logging.Logger.log(Logger.java:738)

at java.util.logging.Logger.doLog(Logger.java:765)

at java.util.logging.Logger.logp(Logger.java:1041)

at org.apache.juli.logging.DirectJDKLog.log(DirectJDKLog.java:182)

at org.apache.juli.logging.DirectJDKLog.error(DirectJDKLog.java:148)

2017.03.23 14:55:27 WARN  web[o.e.transport] [sonar-1490276583968] Received response for a request that has timed out, sent [5468ms] ago, timed out [5ms] ago, action [cluster:monitor/nodes/info], node [[#transport#-1][asudhaka-deb7-64.dhcp.mathworks.com][inet[/127.0.0.1:9001]]], id [3875]

2017.03.23 14:55:42 ERROR web[o.a.t.u.n.NioEndpoint] 

java.lang.OutOfMemoryError: GC overhead limit exceeded

at org.jruby.RubyHash.internalPutSmall(RubyHash.java:535) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.RubyHash.internalPut(RubyHash.java:515) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.RubyHash.internalPut(RubyHash.java:505) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.RubyHash.fastASetCheckString(RubyHash.java:966) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.RubyHash.op_aset(RubyHash.java:985) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.RubyHash$26.visit(RubyHash.java:1789) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.RubyHash.visitLimited(RubyHash.java:642) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.RubyHash.visitAll(RubyHash.java:628) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.RubyHash.replaceCommon(RubyHash.java:1817) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.RubyHash.replace(RubyHash.java:1787) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.RubyHash.initialize_copy(RubyHash.java:1770) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.RubyHash$INVOKER$i$1$0$initialize_copy.call(RubyHash$INVOKER$i$1$0$initialize_copy.gen) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.RubyClass.finvoke(RubyClass.java:690) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.runtime.Helpers.invoke(Helpers.java:498) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.RubyBasicObject.callMethod(RubyBasicObject.java:363) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.RubyBasicObject.initCopy(RubyBasicObject.java:841) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.RubyBasicObject.dup(RubyBasicObject.java:818) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.RubyHash.merge(RubyHash.java:1762) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.RubyHash$INVOKER$i$1$0$merge.call(RubyHash$INVOKER$i$1$0$merge.gen) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.internal.runtime.methods.JavaMethod$JavaMethodOneOrNBlock.call(JavaMethod.java:350) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:168) ~[jruby-complete-1.7.9.jar:na]

at rubyjit.ActionController::Routing::DividerSegment$$initialize_2398D7D7EFB62DF25CBA38624E093D4355402D3F1999257874.__file__(/opt/sonar/devSonar563/sonarqube-5.6.6/web/WEB-INF/gems/gems/actionpack-2.3.15/lib/action_controller/routing/segments.rb:117) ~[na:na]

at rubyjit.ActionController::Routing::DividerSegment$$initialize_2398D7D7EFB62DF25CBA38624E093D4355402D3F1999257874.__file__(/opt/sonar/devSonar563/sonarqube-5.6.6/web/WEB-INF/gems/gems/actionpack-2.3.15/lib/action_controller/routing/segments.rb) ~[na:na]

at org.jruby.ast.executable.AbstractScript.__file__(AbstractScript.java:46) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.internal.runtime.methods.JittedMethod.call(JittedMethod.java:241) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:211) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:217) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.RubyClass.newInstance(RubyClass.java:811) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.RubyClass$INVOKER$i$newInstance.call(RubyClass$INVOKER$i$newInstance.gen) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.internal.runtime.methods.JavaMethod$JavaMethodZeroOrOneOrTwoOrNBlock.call(JavaMethod.java:314) ~[jruby-complete-1.7.9.jar:na]

at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:202) ~[jruby-complete-1.7.9.jar:na]

at rubyjit.ActionController::Routing::RouteBuilder$$segment_for_F932F4A0C6BBAFFD252658B6BA9407F474F13AF41999257874.__file__(/opt/sonar/devSonar563/sonarqube-5.6.6/web/WEB-INF/gems/gems/actionpack-2.3.15/lib/action_controller/routing/builder.rb:49) ~[na:na]

[anand sudhan]

Just to supplement the information : I am using Mysql 5.6 database. (Not H2).

Thanks - Anand

[anand sudhan]

To answer my own question: I solved this issue by adding more memory to  Elastic search JVM : like so:

sonar.search.javaOpts=-Xmx2G -Xms256m ..

Now its super fast and more robust.

-Anand

On Thursday, March 23, 2017 at 3:06:44 PM UTC-4, anand sudhan wrote:

[G. Ann Campbell]

Hi Anand,

Thanks for following up. I'm glad you solved it.

:-)

Ann

[anand sudhan]

You are welcome Ann. :-)

-Anand