Readonlyrest for elastic won't start (1.18.8_es6.8.1)

1

Hi,
When I run elastic without readonlyrest, it works.
I have 2 elastic servers with readonlyrest that are working fine.
On the 3rd one, readonlyrest won’t start.

In the logs, everything looks fine, no errors, even in DEBUG logging mode.
It says if is loading config but never starts
[2020-08-04T10:46:51,985][INFO ][t.b.r.b.Ror$ ] [Elastic-octane-rec-3] Loading ReadonlyREST settings from index failed: cannot find index
[2020-08-04T10:46:51,987][INFO ][t.b.r.b.Ror$ ] [Elastic-octane-rec-3] Loading ReadonlyREST settings from file: /etc/elasticsearch/readonlyrest.yml

curl says it is not ready
curl 127.0.0.1:9200
{“error”:{“root_cause”:[{“reason”:“Waiting for ReadonlyREST start”}],“reason”:“Waiting for ReadonlyREST start”,“status”:503}}[root@p-elastic-rec3 images]

How an I debut that ?
I have tried with readonlyrest 1.20 and it does not start either.

my readonlyrest.yml
readonlyrest:
access_control_rules:

- name: "Require HTTP Basic Auth"
  type: allow
  auth_key: xxx:yyy

in elasticsearch.yml
#using readonlyrest thus disabling xpack
xpack.security.enabled: false

Any advice would be much appreciated
Thanks

2

can you confirm that, without ROR installed in the problematic node, your cluster state reaches green state?

can you confirm the readonlyrest.yml is identical in the other nodes?

3

Hi Simone,
Yes, my cluster is green and sees the 3 nodes, whether ROR is installed or not, no difference
Both elasticsearch.yml and readonlyrest.yml are the same on the 3 nodes.
It is just that I cannot connect to node3 with the “Waiting for ReadonlyREST start” message
Thanks for you help

4

Maybe @clutroth has better insights on this. He has just finished enhancing the setting discovery process.

5

@lucette could you please send us full ES logs (debug mode will be appreciated) from ROR launching?

7

Hi Mateusz,
The forum says “Sorry, new users can not upload attachments.” :frowning:
DEBUG ROR traces are :
[2020-08-05T11:38:18,908][INFO ][o.e.p.PluginsService ] [Elastic-octane-rec-3] loaded plugin [readonlyrest]
[2020-08-05T11:38:25,829][INFO ][t.b.r.b.Ror$ ] [Elastic-octane-rec-3] [CLUSTERWIDE SETTINGS] Loading ReadonlyREST settings from index …
[2020-08-05T11:38:26,106][DEBUG][o.e.a.ActionModule ] [Elastic-octane-rec-3] Using REST wrapper from plugin tech.beshu.ror.es.ReadonlyRestPlugin
[2020-08-05T11:38:46,886][INFO ][t.b.r.b.Ror$ ] [Elastic-octane-rec-3] Loading ReadonlyREST settings from index failed: cannot find index
[2020-08-05T11:38:46,887][INFO ][t.b.r.b.Ror$ ] [Elastic-octane-rec-3] Loading ReadonlyREST settings from file: /etc/elasticsearch/readonlyrest.yml
[2020-08-05T11:38:59,617][INFO ][o.e.n.Node ] [Elastic-octane-rec-3] started
no other ROR traces which is my problem, no errors, no warnings, but not working :frowning:

I am missing the following lines that I find on my 2 other servers :
[2020-08-05T11:43:15,189][INFO ][t.b.r.a.f.RawRorConfigBasedCoreFactory] [Elastic-octane-rec] ADDING BLOCK: { name: ‘Require HTTP Basic Auth’, policy: ALLOW, rules: [auth_key]
[2020-08-05T11:43:15,513][INFO ][t.b.r.b.RorInstance ] [Elastic-octane-rec] Readonly REST plugin core was loaded …

Thanks a lot for your investigation

8

I have seen a similar issue before when I have not allowed port 9300 (or what ever your internal transport port is) access on the server so that it can connect to the other nodes in the cluster.

9

Thanks Richard but port 9300 is allowed and connection between nodes is working fine.
The problem is http access throught port 9200 because ROR did no start but with no message in the logs.

10

I found a trace in the journalctl -u elasticsearch saying :

Aug 05 11:30:28 p-elastic-rec3 systemd[1]: Started Elasticsearch.
Aug 05 11:38:46 p-elastic-rec3 elasticsearch[1357]: java.security.AccessControlException: access denied (“java.lang.RuntimePermission” “modifyThreadGroup”)
Aug 05 11:38:46 p-elastic-rec3 elasticsearch[1357]: at java.security.AccessControlContext.checkPermission(AccessControlContext.java:472)
Aug 05 11:38:46 p-elastic-rec3 elasticsearch[1357]: at java.security.AccessController.checkPermission(AccessController.java:886)
Aug 05 11:38:46 p-elastic-rec3 elasticsearch[1357]: at java.lang.SecurityManager.checkPermission(SecurityManager.java:549)
Aug 05 11:38:46 p-elastic-rec3 elasticsearch[1357]: at org.elasticsearch.secure_sm.SecureSM.checkThreadGroupAccess(SecureSM.java:190)
Aug 05 11:38:46 p-elastic-rec3 elasticsearch[1357]: at org.elasticsearch.secure_sm.SecureSM.checkAccess(SecureSM.java:145)
Aug 05 11:38:46 p-elastic-rec3 elasticsearch[1357]: at java.lang.ThreadGroup.checkAccess(ThreadGroup.java:315)
Aug 05 11:38:46 p-elastic-rec3 elasticsearch[1357]: at java.lang.Thread.init(Thread.java:394)
Aug 05 11:38:46 p-elastic-rec3 elasticsearch[1357]: at java.lang.Thread.init(Thread.java:349)
Aug 05 11:38:46 p-elastic-rec3 elasticsearch[1357]: at java.lang.Thread.(Thread.java:511)
Aug 05 11:38:46 p-elastic-rec3 elasticsearch[1357]: at java.util.concurrent.ForkJoinWorkerThread.(ForkJoinWorkerThread.java:89)
Aug 05 11:38:46 p-elastic-rec3 elasticsearch[1357]: at scala.concurrent.impl.ExecutionContextImpl$DefaultThreadFactory$$anon$1.(ExecutionContextImpl.scala:62)
Aug 05 11:38:46 p-elastic-rec3 elasticsearch[1357]: at scala.concurrent.impl.ExecutionContextImpl$DefaultThreadFactory.newThread(ExecutionContextImpl.scala:62)
Aug 05 11:38:46 p-elastic-rec3 elasticsearch[1357]: at java.util.concurrent.ForkJoinPool.createWorker(ForkJoinPool.java:1485)
Aug 05 11:38:46 p-elastic-rec3 elasticsearch[1357]: at java.util.concurrent.ForkJoinPool.tryAddWorker(ForkJoinPool.java:1517)
Aug 05 11:38:46 p-elastic-rec3 elasticsearch[1357]: at java.util.concurrent.ForkJoinPool.deregisterWorker(ForkJoinPool.java:1609)
Aug 05 11:38:46 p-elastic-rec3 elasticsearch[1357]: at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:173)

not sure if it is related ?

11

please send full logs with email: mateusz at readonlyrest dot com

12

Hi Mateuz,
I have sent you the full DEBUG log by mail.
I have also tried ROR 1.20.0 but it does not start either.
Thanks

13

Thanks, I received your email. Will take a look and let you know if I found sth (probably in the middle of next week)

14

Thanks a lot, waiting for you insight before I try to reinstall everything

15

For info, I tried to uninstall elastic and to reinstall everything from scratch but it is still doing the same.
Elastic starts and works fine, ROR does not start.
I am really stuck there.
Thanks for your help.

16

I’ve checked your logs and there is nothing which could tell us what is wrongs. When ROR fails to start there should be error logged - like this:

[2020-08-13T17:41:19,993][INFO ][t.b.r.b.Ror              ] [n1_it] Loading ReadonlyREST settings from index failed: cannot find index
[2020-08-13T17:41:19,994][INFO ][t.b.r.b.Ror              ] [n1_it] Loading ReadonlyREST settings from file: /etc/elasticsearch/readonlyrest.yml
[2020-08-13T17:41:20,006][ERROR][t.b.r.b.Ror              ] [n1_it] Loading ReadonlyREST from file failed: Cannot find settings file: /etc/elasticsearch/readonlyrest.yml
[2020-08-13T17:41:20,008][ERROR][t.b.r.e.IndexLevelActionFilter] [n1_it] ROR starting failure:

You said that 2 nodes are working great with the same config, so it should be sth wrong with your node configuration I suppose. And maybe the error logs were logged to stderr and that’s why we see nothing here? Maybe you should also try to run the 3rd node in docker container and check if it starts? It’s really hard to help you, because I don’t think it’s ROR issue (at least not directly).

17

And please use the newest ROR.

18

I installed ROR 1.21 on my 2 working nodes, it is working fine and I see there are more ROR traces at startup.
I have asked my failing node VM to be fully rebuild and I will retry installing everything the ROR 1.21 as soon as the new VM is ready.
I will keep you posted.
Thanks

19

I have reinstall everything.
The new ROR version is tracinbg much more and an error appears.
Is is saying :
access denied (“java.io.FilePermission” “/etc/elasticsearch/elasticsearch.yml” “read”)

but my file is perfectly readable it has the same rights that on the other nodes
[root@p-elastic-rec ~]# ls -al /etc/elasticsearch/
total 60
drwxr-s— 2 root elasticsearch 4096 Aug 3 15:39 .
drwxr-xr-x. 87 root root 12288 Jul 21 16:41 …
-rw-rw---- 1 root elasticsearch 3124 Aug 3 15:08 elasticsearch.yml
-rw-rw---- 1 root elasticsearch 131 Nov 22 2019 readonlyrest.yml

full error trace :
[2020-08-14T14:51:44,706][ERROR][t.b.r.e.IndexLevelActionFilter] [Elastic-octane-rec-3] ROR starting failure:
tech.beshu.ror.exceptions$StartingFailureException: Cannot start ReadonlyREST
at tech.beshu.ror.exceptions$StartingFailureException$.from(exceptions.scala:39) ~[?:?]
at tech.beshu.ror.es.IndexLevelActionFilter.$anonfun$startRorInstance$3(IndexLevelActionFilter.scala:152) ~[?:?]
at tech.beshu.ror.es.IndexLevelActionFilter.$anonfun$startRorInstance$3$adapted(IndexLevelActionFilter.scala:143) ~[?:?]
at monix.execution.Callback$$anon$2.tryApply(Callback.scala:296) ~[?:3.0.0]
at monix.execution.Callback$$anon$2.apply(Callback.scala:289) ~[?:3.0.0]
at monix.execution.Callback$$anon$2.onError(Callback.scala:286) ~[?:3.0.0]
at monix.eval.internal.TaskRunLoop$.startFull(TaskRunLoop.scala:108) ~[?:3.0.0]
at monix.eval.internal.TaskRestartCallback.syncOnSuccess(TaskRestartCallback.scala:101) ~[?:3.0.0]
at monix.eval.internal.TaskRestartCallback.onSuccess(TaskRestartCallback.scala:74) ~[?:3.0.0]
at monix.execution.Callback.apply(Callback.scala:116) ~[?:3.0.0]
at monix.eval.internal.TaskFromFuture$.$anonfun$startSimple$1(TaskFromFuture.scala:112) ~[?:3.0.0]
at monix.eval.internal.TaskFromFuture$.$anonfun$startSimple$1$adapted(TaskFromFuture.scala:111) ~[?:3.0.0]
at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:64) [?:?]
at java.util.concurrent.ForkJoinTask$RunnableExecuteAction.exec(ForkJoinTask.java:1402) [?:1.8.0_262]
at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289) [?:1.8.0_262]
at java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1056) [?:1.8.0_262]
at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1692) [?:1.8.0_262]
at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:163) [?:1.8.0_262]
Caused by: java.security.AccessControlException: access denied (“java.io.FilePermission” “/etc/elasticsearch/elasticsearch.yml” “read”)
at java.security.AccessControlContext.checkPermission(AccessControlContext.java:472) ~[?:1.8.0_262]
at java.security.AccessController.checkPermission(AccessController.java:886) ~[?:1.8.0_262]
at java.lang.SecurityManager.checkPermission(SecurityManager.java:549) ~[?:1.8.0_262]
at java.lang.SecurityManager.checkRead(SecurityManager.java:888) ~[?:1.8.0_262]
at java.io.FileInputStream.(FileInputStream.java:127) ~[?:1.8.0_262]
at java.io.FileReader.(FileReader.java:72) ~[?:1.8.0_262]
at better.files.File.newFileReader(File.scala:429) ~[?:3.8.0]
at better.files.File.fileReader(File.scala:432) ~[?:3.8.0]
at tech.beshu.ror.configuration.EsConfigFileLoader.loadConfigFromFile(EsConfigFileLoader.scala:33) ~[?:?]
at tech.beshu.ror.configuration.RorIndexNameConfiguration$.$anonfun$load$1(RorIndexNameConfiguration.scala:42) ~[?:?]
at monix.eval.internal.TaskRunLoop$.startFull(TaskRunLoop.scala:81) ~[?:3.0.0]
… 11 more

20

The only difference I see is that the java version is slitly different :
working nodes : OpenJDK 64-Bit Server VM (build 25.252-b09, mixed mode)
on failing node : OpenJDK 64-Bit Server VM (build 25.262-b10, mixed mode)
maybe the new java requires some specific rights greater than the one given to ROR during the install ?

21

I have uninstall the latest java version and install the previous one on the failing node and … it works !!!
so apparently it means that ROR for elastic 6.8.1 is not compatible with the latest java OpenJDK 64-Bit Server VM (build 25.262-b10, mixed mode.
Maybe you can build a new ROR version adding the missing java rights ?
It would be great if you could do that
Thanks