Ok, i tested it on the different machine but aswell ubuntu 18 and the issue is present after one restart, also i tried to disable publishing ports, so i will ensure that nothing will call the es in loading phase, but the same thing, its still stuck
It’s great that there is some more information which could help finding out what’s causing these issues. It looks like your cluster isn’t in green state during ROR startup, does it eventually go to green state? Can you check what will happen when you put this line readonlyrest.force_load_from_file: true in your elasticsearch.yml?
Have you tested it on clean ES installation?
1 Like
@Sinedko I have few questions for you to sync up where we are
- Have you tried to run ES with ROR on your problematic server with my dummy data?
- Have you tried to run my script on your second ubuntu machine?
- Can you check what happens when you start your problematic ES instance with empty data directory?
Where is your dummy data ? Unfortunately, i cannot do it, i have new data every minute from logstash, because im consuming elasticsearch and all applications logs, and i cannot disable whole environment.
I did not, you script just start and stop the es and try to curl it, its in stucked state so you can not even curl it.
The same thing, i tesed it before, probably its not related to any data.
Can you aswell test it on ubuntu 18 ? Its seems te issue is present only in that OS.
I dont have any ideas left, but we need that JWT auth.
When you restarting your ES, cluster is never green when its loading, and then it will be green, my cluster is green.
I will try this config.
Ok no change, its stuck on the same spot when using the force from file.
Latest update:
ES will load, but after aprox 10 minutes, something is very strange. After the loading from file it will continue to load after 10 minutes.
Machine resources are okay, lots of ram left and also cpu is not overwhelmed
Ok, so we investigated this more, we added some custom log entries and rebuilded the ror for ourself and we discovered that probably the issue is in this method:
Because here is the log, you can see the last step is loading the jwt_auth and its consuming like 10 minutes of time, and the load before was in miliseconds and after that everything is fine.
[2020-09-30T13:43:39,668][INFO ][tech.beshu.ror.accesscontrol.factory.RawRorConfigBasedCoreFactory] [alibaba-dev-ire-all-01] IREDEBUG: decodeRuleInCursorContext invoked name=indices definitions=DefinitionsPack(Definitions(List()),Definitions(List(UserDef(Id(elastic),Set(Group(superuser)),tech.beshu.ror.accesscontrol.blocks.rules.AuthKeyUnixRule@2cb53954), UserDef(Id(kibana),Set(Group(superuser)),tech.beshu.ror.accesscontrol.blocks.rules.AuthKeyUnixRule@65678204), UserDef(Id(logstash),Set(Group(logs)),tech.beshu.ror.accesscontrol.blocks.rules.AuthKeyUnixRule@2ba31884), UserDef(Id(alibaba),Set(Group(alibaba), Group(kibanarw), Group(logsro)),tech.beshu.ror.accesscontrol.blocks.rules.AuthKeyUnixRule@471e28c2))),Definitions(List()),Definitions(List()),Definitions(List(JwtDef(Name(jwt_provider),AuthorizationTokenDef(Name(Authorization),Bearer ),Hmac([B@42e4c6ec),Some(ClaimName(tech.beshu.ror.com.jayway.jsonpath.JsonPath@1b4a0b16)),Some(ClaimName(tech.beshu.ror.com.jayway.jsonpath.JsonPath@281e57c3))))),Definitions(List()),Definitions(List()),Definitions(List())) rorIndexNameConfiguration=RorIndexNameConfiguration(IndexName(.readonlyrest))
[2020-09-30T13:43:39,669][INFO ][tech.beshu.ror.accesscontrol.factory.RawRorConfigBasedCoreFactory] [alibaba-dev-ire-all-01] IREDEBUG: decoding result Right(RuleWithVariableUsageDefinition(tech.beshu.ror.accesscontrol.blocks.rules.IndicesRule@3c4d2025,tech.beshu.ror.accesscontrol.blocks.variables.runtime.VariableContext$VariableUsage$UsingVariable$$$Lambda$4172/0x0000000801a90840@52cf0114))
[2020-09-30T13:43:39,669][INFO ][tech.beshu.ror.accesscontrol.factory.RawRorConfigBasedCoreFactory] [alibaba-dev-ire-all-01] IREDEBUG: newCursor io.circe.cursor.ArrayCursor@163d7854
[2020-09-30T13:43:39,670][INFO ][tech.beshu.ror.accesscontrol.factory.RawRorConfigBasedCoreFactory] [alibaba-dev-ire-all-01] IREDEBUG: decodeRuleInCursorContext invoked name=jwt_auth definitions=DefinitionsPack(Definitions(List()),Definitions(List(UserDef(Id(elastic),Set(Group(superuser)),tech.beshu.ror.accesscontrol.blocks.rules.AuthKeyUnixRule@2cb53954), UserDef(Id(kibana),Set(Group(superuser)),tech.beshu.ror.accesscontrol.blocks.rules.AuthKeyUnixRule@65678204), UserDef(Id(logstash),Set(Group(logs)),tech.beshu.ror.accesscontrol.blocks.rules.AuthKeyUnixRule@2ba31884), UserDef(Id(alibaba),Set(Group(alibaba), Group(kibanarw), Group(logsro)),tech.beshu.ror.accesscontrol.blocks.rules.AuthKeyUnixRule@471e28c2))),Definitions(List()),Definitions(List()),Definitions(List(JwtDef(Name(jwt_provider),AuthorizationTokenDef(Name(Authorization),Bearer ),Hmac([B@42e4c6ec),Some(ClaimName(tech.beshu.ror.com.jayway.jsonpath.JsonPath@1b4a0b16)),Some(ClaimName(tech.beshu.ror.com.jayway.jsonpath.JsonPath@281e57c3))))),Definitions(List()),Definitions(List()),Definitions(List())) rorIndexNameConfiguration=RorIndexNameConfiguration(IndexName(.readonlyrest))
[2020-09-30T13:52:29,584][INFO ][tech.beshu.ror.accesscontrol.factory.RawRorConfigBasedCoreFactory] [alibaba-dev-ire-all-01] IREDEBUG: decoding result Right(RuleWithVariableUsageDefinition(tech.beshu.ror.accesscontrol.blocks.rules.JwtAuthRule@4c86bc34,NotUsingVariable))
[2020-09-30T13:52:29,584][INFO ][tech.beshu.ror.accesscontrol.factory.RawRorConfigBasedCoreFactory] [alibaba-dev-ire-all-01] IREDEBUG: newCursor io.circe.cursor.ArrayCursor@5bfaf091
[2020-09-30T13:52:29,588][INFO ][tech.beshu.ror.accesscontrol.factory.RawRorConfigBasedCoreFactory] [alibaba-dev-ire-all-01] IREDEBUG: aclStaticContextDecoder invoked
[2020-09-30T13:52:29,596][INFO ][tech.beshu.ror.accesscontrol.factory.RawRorConfigBasedCoreFactory] [alibaba-dev-ire-all-01] ADDING BLOCK: { name: 'Super user access', policy: ALLOW, rules: [groups,actions,indices]
[2020-09-30T13:52:29,596][INFO ][tech.beshu.ror.accesscontrol.factory.RawRorConfigBasedCoreFactory] [alibaba-dev-ire-all-01] ADDING BLOCK: { name: 'All ro access', policy: ALLOW, rules: [groups,actions,indices]
[2020-09-30T13:52:29,596][INFO ][tech.beshu.ror.accesscontrol.factory.RawRorConfigBasedCoreFactory] [alibaba-dev-ire-all-01] ADDING BLOCK: { name: 'Kibana rw access', policy: ALLOW, rules: [groups,actions,indices]
[2020-09-30T13:52:29,596][INFO ][tech.beshu.ror.accesscontrol.factory.RawRorConfigBasedCoreFactory] [alibaba-dev-ire-all-01] ADDING BLOCK: { name: 'Kibana ro access', policy: ALLOW, rules: [groups,actions,indices]
[2020-09-30T13:52:29,597][INFO ][tech.beshu.ror.accesscontrol.factory.RawRorConfigBasedCoreFactory] [alibaba-dev-ire-all-01] ADDING BLOCK: { name: 'Alibaba all access', policy: ALLOW, rules: [groups,actions,indices]
[2020-09-30T13:52:29,597][INFO ][tech.beshu.ror.accesscontrol.factory.RawRorConfigBasedCoreFactory] [alibaba-dev-ire-all-01] ADDING BLOCK: { name: 'Logs all access', policy: ALLOW, rules: [groups,actions,indices]
[2020-09-30T13:52:29,597][INFO ][tech.beshu.ror.accesscontrol.factory.RawRorConfigBasedCoreFactory] [alibaba-dev-ire-all-01] ADDING BLOCK: { name: 'Logs ro access', policy: ALLOW, rules: [groups,actions,indices]
[2020-09-30T13:52:29,597][INFO ][tech.beshu.ror.accesscontrol.factory.RawRorConfigBasedCoreFactory] [alibaba-dev-ire-all-01] ADDING BLOCK: { name: 'JWT TEST', policy: ALLOW, rules: [jwt_auth,headers_and,actions,indices]
[2020-09-30T13:52:29,612][INFO ][tech.beshu.ror.boot.RorInstance] [alibaba-dev-ire-all-01] ReadonlyREST core was loaded ...
You can see there is jump from 2020-09-30T13:43:39,670 to 2020-09-30T13:52:29,584 in decodeRuleInCursorContext invoked name=jwt_auth
So its only related to this acl block, please have a look on that.
Thank you.
I think I’ve found reason of this weird behaviour. Can you add this configuration option -Djava.security.egd=file:/dev/./urandom to your jvm.options file? I think problem lies with lack of entropy from /dev/random generator. This configuration will change random source to /dev/urandom which is a bit less random, but enough for ROR.
This thing helps, now the elasticsearch is starting much faster and the issue is gone.
Should i still use this option or you change something in future releases ?
Thank you!
1 Like
It’s great that it finally works 
I’ve checked code responsible for this random generator part and it looks that it can be optimised, so future releases probably won’t need this option.
1 Like
@Sinedko we have just released new version of ROR(1.24.0) which doesn’t need -Djava.security.egd=file:/dev/./urandom option
2 Likes
Hello, Thank you for informing, i have some issues to install it, can you check aswell ?
The 6.5.0 version is fine but 7.7.1 version have issue.
That’s weird, can you give us a checksum of your zip file? And the output of jar -ft ?
Have you tried downloading it again?
sha256sum plugins/readonlyrest-1.24.0_es7.7.1.zip
5fc5298fefc0fd43dfc4f2c2544260cacafc78bcd5c963a8a4cadbb9a24ce1e7 plugins/readonlyrest-1.24.0_es7.7.1.zip
Not sure how to do the jar -ft thingy, cuz its zip and in the zip there all the jars, zip file looks okay, aswell the plugin desriptor looks okay.
I will try, its bit problematic to dowload something to our environment, let you know in meantime
Strange, the new download worked fine.
The new release if working fine without the urandom.
Thank you!
2 Likes