Elasticsearch Won't Start


(Jeff Mounce) #1

Windows 10 - MSI installer - JAVA_HOME is set

Service starts but never registers on 9200.
netstat -a -n confirms that no listener on 9200

Log shows that the DiscoveryModule never starts and setup doesn't proceed. What gives???:

[2018-07-09T23:41:10,006][INFO ][o.e.n.Node               ] [DESKTOP-4V5GU7D] initializing ...
[2018-07-09T23:41:10,262][INFO ][o.e.e.NodeEnvironment    ] [DESKTOP-4V5GU7D] using [1] data paths, mounts [[390GB (H:)]], net usable_space [96.6gb], net total_space [389.9gb], types [NTFS]
[2018-07-09T23:41:10,262][INFO ][o.e.e.NodeEnvironment    ] [DESKTOP-4V5GU7D] heap size [1.9gb], compressed ordinary object pointers [true]
[2018-07-09T23:41:10,265][INFO ][o.e.n.Node               ] [DESKTOP-4V5GU7D] node name [DESKTOP-4V5GU7D], node ID [wP2YrVubRee-t9zkHFiWJw]
[2018-07-09T23:41:10,266][INFO ][o.e.n.Node               ] [DESKTOP-4V5GU7D] version[6.3.1], pid[1256], build[unknown/unknown/eb782d0/2018-06-29T21:59:26.107521Z], OS[Windows 10/10.0/amd64], JVM[Oracle Corporation/Java HotSpot(TM) 64-Bit Server VM/1.8.0_171/25.171-b11]
[2018-07-09T23:41:10,268][INFO ][o.e.n.Node               ] [DESKTOP-4V5GU7D] JVM arguments [-XX:+UseConcMarkSweepGC, -XX:CMSInitiatingOccupancyFraction=75, -XX:+UseCMSInitiatingOccupancyOnly, -XX:+AlwaysPreTouch, -Xss1m, -Djava.awt.headless=true, -Dfile.encoding=UTF-8, -Djna.nosys=true, -XX:-OmitStackTraceInFastThrow, -Dio.netty.noUnsafe=true, -Dio.netty.noKeySetOptimization=true, -Dio.netty.recycler.maxCapacityPerThread=0, -Dlog4j.shutdownHookEnabled=false, -Dlog4j2.disable.jmx=true, -Djava.io.tmpdir=C:\Windows\TEMP\elasticsearch, -XX:+HeapDumpOnOutOfMemoryError, -XX:HeapDumpPath=data, -XX:ErrorFile=logs/hs_err_pid%p.log, -XX:+PrintGCDetails, -XX:+PrintGCDateStamps, -XX:+PrintTenuringDistribution, -XX:+PrintGCApplicationStoppedTime, -Xloggc:logs/gc.log, -XX:+UseGCLogFileRotation, -XX:NumberOfGCLogFiles=32, -XX:GCLogFileSize=64m, -Xmx2g, -Xms2g, -Delasticsearch, -Des.path.home=H:\Tools\Elasticsearch\6.3.1, -Des.path.conf=H:\Tools\Elasticsearch\6.3.1\config]
[2018-07-09T23:41:19,262][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [aggs-matrix-stats]
[2018-07-09T23:41:19,262][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [analysis-common]
[2018-07-09T23:41:19,263][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [ingest-common]
[2018-07-09T23:41:19,263][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [lang-expression]
[2018-07-09T23:41:19,263][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [lang-mustache]
[2018-07-09T23:41:19,263][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [lang-painless]
[2018-07-09T23:41:19,263][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [mapper-extras]
[2018-07-09T23:41:19,263][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [parent-join]
[2018-07-09T23:41:19,263][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [percolator]
[2018-07-09T23:41:19,265][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [rank-eval]
[2018-07-09T23:41:19,265][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [reindex]
[2018-07-09T23:41:19,265][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [repository-url]
[2018-07-09T23:41:19,267][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [transport-netty4]
[2018-07-09T23:41:19,267][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [tribe]
[2018-07-09T23:41:19,267][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [x-pack-core]
[2018-07-09T23:41:19,267][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [x-pack-deprecation]
[2018-07-09T23:41:19,268][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [x-pack-graph]
[2018-07-09T23:41:19,270][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [x-pack-logstash]
[2018-07-09T23:41:19,270][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [x-pack-ml]
[2018-07-09T23:41:19,270][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [x-pack-monitoring]
[2018-07-09T23:41:19,270][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [x-pack-rollup]
[2018-07-09T23:41:19,274][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [x-pack-security]
[2018-07-09T23:41:19,280][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [x-pack-sql]
[2018-07-09T23:41:19,281][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [x-pack-upgrade]
[2018-07-09T23:41:19,286][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] loaded module [x-pack-watcher]
[2018-07-09T23:41:19,294][INFO ][o.e.p.PluginsService     ] [DESKTOP-4V5GU7D] no plugins loaded

(Tim Vernum) #2

If the process is just hanging but is still alive then jstack is probably going to be the simpler way to work out what might going on.

Can you run that and provide the output?


(Jeff Mounce) #3

May not be very helpful:

PS C:\Program Files\Java\jdk1.8.0_171\bin> .\jstack.exe 4068
4068: jvm.dll not loaded by target process
The -F option can be used when the target process is not responding

PS C:\Program Files\Java\jdk1.8.0_171\bin> .\jstack.exe -F 4068
Attaching to process ID 4068, please wait...
Error attaching to process: Doesn't appear to be a HotSpot VM (could not find symbol "gHotSpotVMTypes" in remote process)
sun.jvm.hotspot.debugger.DebuggerException: Doesn't appear to be a HotSpot VM (could not find symbol "gHotSpotVMTypes" in remote process)
        at sun.jvm.hotspot.HotSpotAgent.setupVM(HotSpotAgent.java:411)
        at sun.jvm.hotspot.HotSpotAgent.go(HotSpotAgent.java:305)
        at sun.jvm.hotspot.HotSpotAgent.attach(HotSpotAgent.java:140)
        at sun.jvm.hotspot.tools.Tool.start(Tool.java:185)
        at sun.jvm.hotspot.tools.Tool.execute(Tool.java:118)
        at sun.jvm.hotspot.tools.JStack.main(JStack.java:92)
        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:498)
        at sun.tools.jstack.JStack.runJStackTool(JStack.java:140)
        at sun.tools.jstack.JStack.main(JStack.java:106)

(Jeff Mounce) #4

I think I was using the wrong PID. I used elasticsearch.exe for the above dump.
I think it is the java.exe that you want...

PS C:\Program Files\Java\jdk1.8.0_171\bin> .\jstack.exe 1256
2018-07-10 10:46:28
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.171-b11 mixed mode):

"Service Thread" #9 daemon prio=9 os_prio=0 tid=0x00000000159ae800 nid=0x1738 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C1 CompilerThread1" #8 daemon prio=9 os_prio=2 tid=0x00000000159a1800 nid=0x2104 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #7 daemon prio=9 os_prio=2 tid=0x000000001599f800 nid=0x1054 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Attach Listener" #6 daemon prio=5 os_prio=2 tid=0x000000001599e000 nid=0x16d4 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" #5 daemon prio=9 os_prio=2 tid=0x000000001599c000 nid=0x1a98 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Surrogate Locker Thread (Concurrent GC)" #4 daemon prio=9 os_prio=0 tid=0x000000001599a800 nid=0x1328 waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" #3 daemon prio=8 os_prio=1 tid=0x000000001597b800 nid=0x7ac in Object.wait() [0x0000000015d1f000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x000000008aa07580> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
        - locked <0x000000008aa07580> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
        at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:212)

"Reference Handler" #2 daemon prio=10 os_prio=2 tid=0x000000001595a000 nid=0xed8 in Object.wait() [0x0000000015c1e000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x000000008aa075b0> (a java.lang.ref.Reference$Lock)
        at java.lang.Object.wait(Object.java:502)
        at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
        - locked <0x000000008aa075b0> (a java.lang.ref.Reference$Lock)
        at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)

"main" #1 prio=5 os_prio=0 tid=0x0000000000ee4000 nid=0xe6c runnable [0x0000000000eae000]
   java.lang.Thread.State: RUNNABLE
        at sun.management.OperatingSystemImpl.getSystemCpuLoad(Native Method)
        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:498)
        at org.elasticsearch.monitor.Probes.getLoadAndScaleToPercent(Probes.java:29)
        at org.elasticsearch.monitor.os.OsProbe.getSystemCpuPercent(OsProbe.java:172)
        at org.elasticsearch.monitor.os.OsProbe.osStats(OsProbe.java:528)
        at org.elasticsearch.xpack.ml.MachineLearning.additionalSettings(MachineLearning.java:315)
        at org.elasticsearch.plugins.PluginsService.updatedSettings(PluginsService.java:209)
        at org.elasticsearch.node.Node.<init>(Node.java:312)
        at org.elasticsearch.node.Node.<init>(Node.java:252)
        at org.elasticsearch.bootstrap.Bootstrap$5.<init>(Bootstrap.java:213)
        at org.elasticsearch.bootstrap.Bootstrap.setup(Bootstrap.java:213)
        at org.elasticsearch.bootstrap.Bootstrap.init(Bootstrap.java:326)
        at org.elasticsearch.bootstrap.Elasticsearch.init(Elasticsearch.java:136)
        at org.elasticsearch.bootstrap.Elasticsearch.execute(Elasticsearch.java:127)
        at org.elasticsearch.cli.EnvironmentAwareCommand.execute(EnvironmentAwareCommand.java:86)
        at org.elasticsearch.cli.Command.mainWithoutErrorHandling(Command.java:124)
        at org.elasticsearch.cli.Command.main(Command.java:90)
        at org.elasticsearch.bootstrap.Elasticsearch.main(Elasticsearch.java:93)
        at org.elasticsearch.bootstrap.Elasticsearch.main(Elasticsearch.java:86)

"VM Thread" os_prio=2 tid=0x0000000015951000 nid=0x2020 runnable

"Gang worker#0 (Parallel GC Threads)" os_prio=2 tid=0x0000000000ef1000 nid=0x1ca0 runnable

"Gang worker#1 (Parallel GC Threads)" os_prio=2 tid=0x0000000000ef6800 nid=0x58c runnable

"Concurrent Mark-Sweep GC Thread" os_prio=2 tid=0x0000000000f24800 nid=0x11e0 runnable

"VM Periodic Task Thread" os_prio=2 tid=0x0000000015a16800 nid=0x164c waiting on condition

JNI global references: 650

(Jeff Mounce) #5

With -F flag:

PS C:\Program Files\Java\jdk1.8.0_171\bin> .\jstack.exe -F 1256
Attaching to process ID 1256, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.171-b11
Deadlock Detection:

No deadlocks found.

Thread 10: (state = BLOCKED)


Thread 9: (state = BLOCKED)


Thread 8: (state = BLOCKED)


Thread 7: (state = BLOCKED)
 - java.lang.Object.wait(long) @bci=0 (Interpreted frame)
 - java.lang.ref.ReferenceQueue.remove(long) @bci=59, line=143 (Compiled frame)
 - java.lang.ref.ReferenceQueue.remove() @bci=2, line=164 (Compiled frame)
 - java.lang.ref.Finalizer$FinalizerThread.run() @bci=36, line=212 (Interpreted frame)


Thread 6: (state = BLOCKED)
 - java.lang.Object.wait(long) @bci=0 (Interpreted frame)
 - java.lang.Object.wait() @bci=2, line=502 (Compiled frame)
 - java.lang.ref.Reference.tryHandlePending(boolean) @bci=54, line=191 (Compiled frame)
 - java.lang.ref.Reference$ReferenceHandler.run() @bci=1, line=153 (Interpreted frame)


Thread 1: (state = IN_NATIVE)
 - sun.management.OperatingSystemImpl.getSystemCpuLoad() @bci=0 (Interpreted frame)
 - sun.reflect.NativeMethodAccessorImpl.invoke0(java.lang.reflect.Method, java.lang.Object, java.lang.Object[]) @bci=0 (Interpreted frame)
 - sun.reflect.NativeMethodAccessorImpl.invoke(java.lang.Object, java.lang.Object[]) @bci=100, line=62 (Interpreted frame)
 - sun.reflect.DelegatingMethodAccessorImpl.invoke(java.lang.Object, java.lang.Object[]) @bci=6, line=43 (Compiled frame)
 - java.lang.reflect.Method.invoke(java.lang.Object, java.lang.Object[]) @bci=56, line=498 (Compiled frame)
 - org.elasticsearch.monitor.Probes.getLoadAndScaleToPercent(java.lang.reflect.Method, java.lang.management.OperatingSystemMXBean) @bci=10, line=29 (Interpreted frame)
 - org.elasticsearch.monitor.os.OsProbe.getSystemCpuPercent() @bci=6, line=172 (Interpreted frame)
 - org.elasticsearch.monitor.os.OsProbe.osStats() @bci=5, line=528 (Interpreted frame)
 - org.elasticsearch.xpack.ml.MachineLearning.additionalSettings() @bci=130, line=315 (Interpreted frame)
 - org.elasticsearch.plugins.PluginsService.updatedSettings() @bci=61, line=209 (Interpreted frame)
 - org.elasticsearch.node.Node.<init>(org.elasticsearch.env.Environment, java.util.Collection) @bci=466, line=312 (Interpreted frame)
 - org.elasticsearch.node.Node.<init>(org.elasticsearch.env.Environment) @bci=5, line=252 (Interpreted frame)
 - org.elasticsearch.bootstrap.Bootstrap$5.<init>(org.elasticsearch.bootstrap.Bootstrap, org.elasticsearch.env.Environment) @bci=7, line=213 (Interpreted frame)
 - org.elasticsearch.bootstrap.Bootstrap.setup(boolean, org.elasticsearch.env.Environment) @bci=174, line=213 (Interpreted frame)
 - org.elasticsearch.bootstrap.Bootstrap.init(boolean, java.nio.file.Path, boolean, org.elasticsearch.env.Environment) @bci=164, line=326 (Interpreted frame)
 - org.elasticsearch.bootstrap.Elasticsearch.init(boolean, java.nio.file.Path, boolean, org.elasticsearch.env.Environment) @bci=13, line=136 (Interpreted frame)
 - org.elasticsearch.bootstrap.Elasticsearch.execute(org.elasticsearch.cli.Terminal, joptsimple.OptionSet, org.elasticsearch.env.Environment) @bci=210, line=127 (Interpreted frame)
 - org.elasticsearch.cli.EnvironmentAwareCommand.execute(org.elasticsearch.cli.Terminal, joptsimple.OptionSet) @bci=219, line=86 (Interpreted frame)
 - org.elasticsearch.cli.Command.mainWithoutErrorHandling(java.lang.String[], org.elasticsearch.cli.Terminal) @bci=78, line=124 (Interpreted frame)
 - org.elasticsearch.cli.Command.main(java.lang.String[], org.elasticsearch.cli.Terminal) @bci=47, line=90 (Interpreted frame)
 - org.elasticsearch.bootstrap.Elasticsearch.main(java.lang.String[], org.elasticsearch.bootstrap.Elasticsearch, org.elasticsearch.cli.Terminal) @bci=3, line=93 (Interpreted frame)
 - org.elasticsearch.bootstrap.Elasticsearch.main(java.lang.String[]) @bci=26, line=86 (Interpreted frame)

(Jeff Mounce) #6

getSystemCpuLoad() seems to hang on my version of Windows.
Hmmm...guess I figured it out myself.

What version of Java does ES6.3 need?


(Jeff Mounce) #7

I am running Windows in a VM.
Does that matter? It seems to for me.
On the Host, it is fine, but in the VM on VMWare, it hangs.
I tested getSystemCpuLoad() as a standalone Java program and it definitely hangs.

Maybe you should test it in a VMWare VM.
Are you there?


(Russ Cam) #8

On the Host, it is fine, but in the VM on VMWare, it hangs.

The installer in tested on Virtualbox VMs.

Do you see the same issue using the zip archive for installation?


(Russ Cam) #9

What does

.\elasticsearch.exe --debug-env

output on the VM? it'll be something like

-------------
Elasticsearch
-------------
ES_HOME (in order of precedence)
- HomeDirectoryProcessVariable =
- HomeDirectoryUserVariable =
- HomeDirectoryMachineVariable = C:\Program Files\Elastic\Elasticsearch\6.3.1\
- From executable location = C:\Program Files\Elastic\Elasticsearch\6.3.1
ES_PATH_CONF (in order of precedence)
- ConfigDirectoryProcessVariable =
- ConfigDirectoryUserVariable =
- ConfigDirectoryMachineVariable = C:\ProgramData\Elastic\Elasticsearch\config
- Fallback to ES_HOME = C:\Program Files\Elastic\Elasticsearch\6.3.1\config

-------------
Java
-------------
Java paths
- current = C:\Program Files\Java\jre1.8.0_162\bin\java.exe
Java Candidates (in order of precedence)
- JavaHomeProcessVariable = C:\Program Files\Java\jre1.8.0_162
- JavaHomeUserVariable =
- JavaHomeMachineVariable = C:\Program Files\Java\jre1.8.0_162
- JdkRegistry64 = C:\Program Files\Java\jdk1.8.0_162
- JreRegistry64 = C:\Program Files\Java\jre1.8.0_162
- JdkRegistry32 =
- JreRegistry32 =
Java checks
- Using32BitJava = False
- JAVA_HOME as machine and user variable = False

(Jeff Mounce) #10
PS H:\tools\Elasticsearch\6.3.1\bin> .\elasticsearch.exe --debug-env
-------------
Elasticsearch
-------------
ES_HOME (in order of precedence)
- HomeDirectoryProcessVariable = H:\Tools\Elasticsearch\6.3.1\
- HomeDirectoryUserVariable =
- HomeDirectoryMachineVariable = H:\Tools\Elasticsearch\6.3.1\
- From executable location = H:\tools\Elasticsearch\6.3.1
ES_PATH_CONF (in order of precedence)
- ConfigDirectoryProcessVariable = H:\Tools\Elasticsearch\6.3.1\config
- ConfigDirectoryUserVariable =
- ConfigDirectoryMachineVariable = H:\Tools\Elasticsearch\6.3.1\config
- Fallback to ES_HOME = H:\Tools\Elasticsearch\6.3.1\config

-------------
Java
-------------
Java paths
- current = C:\Program Files\Java\jre1.8.0_171\bin\java.exe
Java Candidates (in order of precedence)
- JavaHomeProcessVariable =
- JavaHomeUserVariable =
- JavaHomeMachineVariable =
- JdkRegistry64 =
- JreRegistry64 = C:\Program Files\Java\jre1.8.0_171
- JdkRegistry32 =
- JreRegistry32 =
Java checks
- Using32BitJava = False
- JAVA_HOME as machine and user variable = False

I tried it on another VM with a newer Windows10 OS and it works.
Probably just my old Win10 OS not determining the Management iface.

You can probably close the case. This seems to be an anomaly.


(Jeff Mounce) #11

Unless...you can tell me how to stop it from calling: getLoadAndScaleToPercent()
..or remove XPack.


(Russ Cam) #12

The debug environment output looks OK to me.

I tried it on another VM with a newer Windows10 OS and it works.

Good to hear! The issue does look to be specific to this VM.

Unless...you can tell me how to stop it from calling: getLoadAndScaleToPercent()
..or remove XPack.

There's only one distribution of Windows Installer, which always includes X-Pack. If you're looking to install without X-Pack on Windows, you should install the OSS distribution of the zip archive.


(Jeff Mounce) #13

I'll try the ZIP and let you know.


(Jeff Mounce) #14

Doesn't matter. Close the ticket.