Multi-Tenancy example in doc does not work

susannamartinelli · March 13, 2019, 10:38am

Hello I’m trying to replicate the multitenancy example described here readonlyrest-docs/kibana.md at master · beshu-tech/readonlyrest-docs · GitHub.

I’m using ES 6.6.1 + Kibana 6.6.1 and Logstash 6.6.1 with plugins:

readonlyrest-1.17.2_es6.6.1 for elastic
readonlyrest_kbn_enterprise-1.17.1-20190309_es6.6.1 for kibana

Here my readonlyrest.yml


readonlyrest:
      access_control_rules:

    - name: "::KIBANA-SRV::"
      auth_key: kibana:kibana
      verbosity: error

    - name: "::LOGSTASH::"
      auth_key: logstash:logstash
      actions: ["cluster:monitor/main","indices:admin/types/exists","indices:data/read/*","indices:data/write/*","indices:admin/template/*","indices:admin/create"]
      indices: ["logstash-*"]
      verbosity: error

    - name: "Admin Tenancy"
      groups: ["Admins"]
      verbosity: error
      kibana_access: admin
      kibana_index: ".kibana"
    
    - name: "Template Tenancy"
      groups: ["Template"]
      verbosity: error
      kibana_access: admin
      kibana_index: ".kibana_template"
      
    - name: user1
      auth_key: user1:passwd
      kibana_access: rw
      kibana_index: ".kibana_user1"
       
    users:
    - username: admin      #wrongly called 'name' in the doc
      auth_key: admin:admin
      groups: ["Admins", "Template"] # can hop between two tenancies with top-left drop-down menu

Here my steps to reproduce:

I login in Kibana as admin
Switch to Template tenant
Create the index logstash-*
Logout
Login as user1
AND I do not see any index pattern in Discovery section

Furthermore in the elastic log i see this error: (sorry for the verbosity)

[2019-03-13T09:17:45,712][INFO ][o.e.c.m.MetaDataIndexTemplateService] [WFVmDVO] adding template [kibana_index_template:.kibana_template] for index patterns [.kibana_template]
[2019-03-13T09:18:07,423][WARN ][o.e.d.a.a.i.t.p.PutIndexTemplateRequest] [WFVmDVO] Deprecated field [template] used, replaced by [index_patterns]
[2019-03-13T09:18:07,427][INFO ][o.e.c.m.MetaDataIndexTemplateService] [WFVmDVO] adding template [kibana_index_template:.kibana_template] for index patterns [.kibana_template]
java.util.concurrent.CompletionException: java.lang.NullPointerException
	at java.base/java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:314)
	at java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:683)
	at java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:658)
	at java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2094)
	at tech.beshu.ror.acl.ACL.check(ACL.java:204)
	at tech.beshu.ror.es.IndexLevelActionFilter.handleRequest(IndexLevelActionFilter.java:159)
	at tech.beshu.ror.es.IndexLevelActionFilter.lambda$apply$1(IndexLevelActionFilter.java:135)
	at java.base/java.security.AccessController.doPrivileged(Native Method)
	at tech.beshu.ror.es.IndexLevelActionFilter.apply(IndexLevelActionFilter.java:131)
	at org.elasticsearch.action.support.TransportAction$RequestFilterChain.proceed(TransportAction.java:165)
	at org.elasticsearch.action.support.TransportAction.execute(TransportAction.java:139)
	at org.elasticsearch.action.support.TransportAction.execute(TransportAction.java:81)
	at org.elasticsearch.client.node.NodeClient.executeLocally(NodeClient.java:87)
	at org.elasticsearch.client.node.NodeClient.doExecute(NodeClient.java:76)
	at org.elasticsearch.client.support.AbstractClient.execute(AbstractClient.java:403)
	at tech.beshu.ror.es.rradmin.rest.RestRRAdminAction.lambda$prepareRequest$1(RestRRAdminAction.java:54)
	at org.elasticsearch.rest.BaseRestHandler.handleRequest(BaseRestHandler.java:97)
	at tech.beshu.ror.es.ReadonlyRestPlugin.lambda$null$8(ReadonlyRestPlugin.java:253)
	at org.elasticsearch.rest.RestController.dispatchRequest(RestController.java:240)
	at org.elasticsearch.rest.RestController.tryAllHandlers(RestController.java:336)
	at org.elasticsearch.rest.RestController.dispatchRequest(RestController.java:174)
	at org.elasticsearch.http.netty4.Netty4HttpServerTransport.dispatchRequest(Netty4HttpServerTransport.java:551)
	at org.elasticsearch.http.netty4.Netty4HttpRequestHandler.channelRead0(Netty4HttpRequestHandler.java:137)
	at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:105)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	at org.elasticsearch.http.netty4.pipelining.HttpPipeliningHandler.channelRead(HttpPipeliningHandler.java:68)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102)
	at io.netty.handler.codec.MessageToMessageCodec.channelRead(MessageToMessageCodec.java:111)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:323)
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:297)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:286)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1434)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:965)
	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163)
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:656)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysPlain(NioEventLoop.java:556)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:510)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:470)
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:909)
	at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.lang.NullPointerException
	at tech.beshu.ror.es.RequestInfo.extractRemoteAddress(RequestInfo.java:447)
	at tech.beshu.ror.acl.ACL$1.getRemoteAddress(ACL.java:363)
	at tech.beshu.ror.requestcontext.RequestContext.toString(RequestContext.java:454)
	at tech.beshu.ror.requestcontext.RequestContext.toString(RequestContext.java:375)
	at java.base/java.lang.String.valueOf(String.java:2951)
	at java.base/java.lang.StringBuilder.append(StringBuilder.java:168)
	at tech.beshu.ror.acl.ACL.doLog(ACL.java:170)
	at tech.beshu.ror.acl.ACL.lambda$check$4(ACL.java:217)
	at java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:680)
	... 66 more

susannamartinelli · March 13, 2019, 11:20am

Also here my kibana.yml conf:

server.name: kibana
server.host: "0"
elasticsearch.url: http://elasticsearch:9200
elasticsearch.username: "kibana"
elasticsearch.password: "kibana"
readonlyrest_kbn.kibanaIndexTemplate: ".kibana_template"

I’m using a kibana without the xpack plugin

UPDATE: I’ve tried to debug with IntelliJ the portion of code that raised the NullPointerException and seems to be related to the Logging system of readonlyrest plugin, so I’ve changed to verbosity: error all the rules.
But the user1 still does not see the template’s index pattern.

sscarduzio · March 13, 2019, 11:31am

Thanks for the great report, will handle this today

sscarduzio · March 13, 2019, 5:16pm

Hi @susannamartinelli,

I found the bug on the Kibana side: basically when you use the OSS distribution, you won’t have Spaces enabled. So the logic erroneously skipped the copying of the kibana objects. This is fixed.

Will have a look at the ES side tomorrow and let you have a build to try.

susannamartinelli · March 14, 2019, 9:07am

Ok @sscarduzio, I’m going to try with kibana standard version.
Thanks

susannamartinelli · March 14, 2019, 9:31am

Hi @sscarduzio I’m getting an error with kibana Standard version while trying to log with the admin user (the readonlyrest.yml is the same).

kibana.yml

server.name: kibana
server.host: "0"
elasticsearch.url: http://elasticsearch:9200
elasticsearch.username: "kibana"
elasticsearch.password: "kibana"
readonlyrest_kbn.kibanaIndexTemplate: ".kibana_template"
#disabling xpack for readonlyrest API plugin
xpack.graph.enabled: false
xpack.ml.enabled: false
xpack.monitoring.enabled: false
xpack.security.enabled: false
xpack.watcher.enabled: false

kibana logs

{"type":"log","@timestamp":"2019-03-14T08:24:15Z","tags":["info","readonlyrest_kbn"],"pid":1,"message":"try extract credentials from JSON"}
{"type":"log","@timestamp":"2019-03-14T08:24:15Z","tags":["info","readonlyrest_kbn"],"pid":1,"message":" received identity payload: {\"x-ror-current-group\":\"Admins\",\"x-ror-username\":\"admin\",\"x-ror-kibana-hidden-apps\":[],\"x-ror-kibana_access\":\"admin\",\"x-ror-available-groups\":[\"Admins\",\"Template\"],\"x-ror-kibana_index\":\".kibana\"}"}
{"type":"log","@timestamp":"2019-03-14T08:24:15Z","tags":["info","readonlyrest_kbn"],"pid":1,"message":"ON_IDENTITY setting kibana index to .kibana"}
{"type":"log","@timestamp":"2019-03-14T08:24:15Z","tags":["info","readonlyrest_kbn"],"pid":1,"message":"ensuring index exists: .kibana"}
{"type":"log","@timestamp":"2019-03-14T08:24:15Z","tags":["error","readonlyrest_kbn"],"pid":1,"message":"kbnIndex check failed with an unusual error: "}
{"type":"log","@timestamp":"2019-03-14T08:24:15Z","tags":["info","readonlyrest_kbn"],"pid":1,"message":"CHECKED_INDEX: .kibana"}
{"type":"log","@timestamp":"2019-03-14T08:24:15Z","tags":["info","readonlyrest_kbn"],"pid":1,"message":"error creating proxy for path: .kibana"}
{"type":"log","@timestamp":"2019-03-14T08:24:15Z","tags":["info","readonlyrest_kbn"],"pid":1,"message":"reindexing .kibanafrom template kibana index .kibana_template"}
{"type":"log","@timestamp":"2019-03-14T08:24:15Z","tags":["info","readonlyrest_kbn"],"pid":1,"message":"[reindex] reindexing all Kibana objects from: .kibana_template to: .kibana"}
{"type":"log","@timestamp":"2019-03-14T08:24:15Z","tags":["info","readonlyrest_kbn"],"pid":1,"message":"template index was not found, reindexing from default kibana index: .kibana"}
{"type":"log","@timestamp":"2019-03-14T08:24:15Z","tags":["info","readonlyrest_kbn"],"pid":1,"message":"[reindex] copying over just the spaces and configuration Kibana ojects from: .kibana to: .kibana"}
{"type":"log","@timestamp":"2019-03-14T08:24:15Z","tags":["ror","error"],"pid":1,"message":"identity error: {\"x-ror-current-group\":\"Admins\",\"x-ror-username\":\"admin\",\"x-ror-kibana-hidden-apps\":[],\"x-ror-kibana_access\":\"admin\",\"x-ror-available-groups\":[\"Admins\",\"Template\"],\"x-ror-kibana_index\":\".kibana\",\"username\":\"admin\",\"authHeaders\":{\"authorization\":\"Basic YWRtaW46YWRtaW4=\"},\"hiddenApps\":[],\"kibanaIndex\":\".kibana\",\"kibanaAccess\":\"admin\",\"groupsAvailable\":[\"Admins\",\"Template\"],\"groupCurrent\":\"Admins\",\"sid\":\"050cec54-1b46-486d-bfcb-06e0e75d360b\",\"expiresAt\":1552811055490}"}

sscarduzio · March 14, 2019, 2:14pm

Hi @susannamartinelli can you please try this build? OSS or XPack, either ways should work.

Will link you also the pre build of the ES plugin as soon as it’s coming out from CI, should fix the NPE trying to log the origin address. BTW, it is not supposed to happen. Please see this thread.

susannamartinelli · March 14, 2019, 4:45pm

Hi @sscarduzio Thanks!
So with this build seems to work.

I’ve created 2 different users (013 and 011) which actually are filtered by a field (firmid).

I connect first as admin
switch to Template
create index pattern and a visualization
logout
login as 013 and i see correctly index_pattern, visualization and data are filtered.

This is my configuration multitenancy_static

readonlyrest:
    audit_collector: true
    access_control_rules:

    - name: "::KIBANA-SRV::"
      auth_key: kibana:kibana
      verbosity: error
    
    - name: "::LOGSTASH::"
      auth_key: logstash:logstash
      actions: ["cluster:monitor/main","indices:admin/types/exists","indices:data/read/*","indices:data/write/*","indices:admin/template/*","indices:admin/create"]
      indices: ["negotiation-*", "trade-*", "transation-*", "logstash-*"]
      verbosity: error

    - name: "Admin Tenancy"
      groups: ["Admins"]
      verbosity: error
      kibana_access: admin
      kibana_index: ".kibana"
      verbosity: error
    
    - name: "Template Tenancy"
      groups: ["Template"]
      verbosity: error
      kibana_access: admin
      kibana_index: ".kibana_template"
      verbosity: error

    - name: "011-data"
      auth_key: zeroundici:zeroundici
      indices: ["negotiation-*", "trade-*", "transation-*"]
      filter: '{"bool": { "must": { "match": { "firmid": "011" }}}}'

    - name: "011"
      auth_key: zeroundici:zeroundici
      kibana_access: rw
      kibana_index: ".kibana_011"
      kibana_hide_apps: ["readonlyrest_kbn", "kibana:dev_tools", "kibana:management"]

    - name: "013-data"
      auth_key: zerotredici:zerotredici
      indices: ["negotiation-*", "trade-*", "transation-*"]
      filter: '{"bool": { "must": { "match": { "firmid": "013" }}}}'
        
    - name: "013"
      auth_key: zerotredici:zerotredici
      kibana_access: rw
      kibana_index: ".kibana_013"
      kibana_hide_apps: ["readonlyrest_kbn", "kibana:dev_tools", "kibana:management"]
           
    users:
    - username: admin     
      auth_key: admin:admin
      groups: ["Admins", "Template"]

Furthermore I’ve tried to introduce a new configuration, starting from the previous one, but in this case authentication and group associations are externally demanded.
Unfortunately this configuration does not work.
I get no error on elastic side, the user correctly login but the index_pattern and the visualizations disappeared

multitenancy_external

readonlyrest:
    audit_collector: true

    access_control_rules:

    - name: "::KIBANA-SRV::"
      auth_key: kibana:kibana
      verbosity: error

    - name: "::LOGSTASH::"
      auth_key: logstash:logstash
      actions: ["cluster:monitor/main","indices:admin/types/exists","indices:data/read/*","indices:data/write/*","indices:admin/template/*","indices:admin/create"]
      indices: ["negotiation-*", "trade-*", "transation-*", "logstash-*"]
      verbosity: error

    - name: "Admin Tenancy"
      groups: ["Admins"]
      verbosity: error
      kibana_access: admin
      kibana_index: ".kibana"
      verbosity: error
    
    - name: "Template Tenancy"
      groups: ["Template"]
      verbosity: error
      kibana_access: admin
      kibana_index: ".kibana_template"
      verbosity: error
     
    - name: "011-data"
      external_authentication: "ExternalAuthService"
      groups_provider_authorization:
        user_groups_provider: "ExternalGroupService"
        groups: ["011"]
      indices: ["negotiation-*", "trade-*", "transation-*"]
      filter: '{"bool": { "must": { "match": { "firmid": "011" }}}}'

    - name: "011"
      external_authentication: "ExternalAuthService"
      groups_provider_authorization:
        user_groups_provider: "ExternalGroupService"
        groups: ["011"]
      kibana_access: rw
      kibana_index: ".kibana_@{user}"
      kibana_hide_apps: ["readonlyrest_kbn", "kibana:dev_tools", "kibana:management"]
     

    - name: "013-data"
      external_authentication: "ExternalAuthService"
      groups_provider_authorization:
        user_groups_provider: "ExternalGroupService"
        groups: ["013"]
      indices: ["negotiation-*", "trade-*", "transation-*"]
      filter: '{"bool": { "must": { "match": { "firmid": "013" }}}}'

    - name: "013"
      external_authentication: "ExternalAuthService"
      groups_provider_authorization:
        user_groups_provider: "ExternalGroupService"
        groups: ["013"]
      kibana_access: rw
      kibana_index: ".kibana_@{user}"
      kibana_hide_apps: ["readonlyrest_kbn", "kibana:dev_tools", "kibana:management"]
      

    external_authentication_service_configs:
    - name: "ExternalAuthService"
      authentication_endpoint: "http://authprovider:8080/auth"
      success_status_code: 200
      cache_ttl_in_sec: 1
      validate: false 

    user_groups_providers:
    - name: "ExternalGroupService"
      groups_endpoint: "http://authprovider:8080/groups"
      auth_token_name: "token"
      auth_token_passed_as: QUERY_PARAM                       
      response_groups_json_path: "$..groups[?(@.name)].name"  
      cache_ttl_in_sec: 1
      http_connection_settings:
        connection_timeout_in_sec: 5                          
        socket_timeout_in_sec: 3                              
        connection_request_timeout_in_sec: 3                     
        connection_pool_size: 10  

    users:
    - username: admin
      auth_key: admin:admin
      groups: ["Admins", "Template"]

Any ideas?

susannamartinelli · March 14, 2019, 5:14pm

I’m using kibana-oss:6.6.1 logstash-oss:6.6.1
kibana.yml

---
# Default Kibana configuration from kibana-docker.

server.name: kibana
server.host: "0"
elasticsearch.hosts: http://elasticsearch:9200
elasticsearch.username: "kibana"
elasticsearch.password: "kibana"
readonlyrest_kbn.kibanaIndexTemplate: ".kibana_template"
#disabling xpack for readonlyrest API plugin
#xpack.graph.enabled: false
#xpack.ml.enabled: false
#xpack.monitoring.enabled: false
#xpack.security.enabled: false
#xpack.watcher.enabled: false

In Elasticsearch log I constantly see this exception

java.lang.NullPointerException
    at tech.beshu.ror.es.RequestInfo.extractIndices(RequestInfo.java:252)
    at tech.beshu.ror.acl.ACL$1.extractIndices(ACL.java:393)
    at tech.beshu.ror.requestcontext.RequestContext$7.initialize(RequestContext.java:208)
    at tech.beshu.ror.requestcontext.RequestContext$7.initialize(RequestContext.java:205)
    at tech.beshu.ror.requestcontext.Transactional.lazyLoad(Transactional.java:69)
    at tech.beshu.ror.requestcontext.Transactional.lambda$commit$0(Transactional.java:54)
    at tech.beshu.ror.requestcontext.Delayed.commit(Delayed.java:64)
    at tech.beshu.ror.requestcontext.Transactional.commit(Transactional.java:63)
    at java.base/java.lang.Iterable.forEach(Iterable.java:75)
    at tech.beshu.ror.requestcontext.Delayed.commit(Delayed.java:72)
    at tech.beshu.ror.acl.ACL.lambda$doCheck$7(ACL.java:249)
    at tech.beshu.ror.utils.FuturesSequencer.lambda$runInSeqUntilConditionIsUndone$2(FuturesSequencer.java:54)
    at java.base/java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1106)
    at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2235)
    at tech.beshu.ror.utils.FuturesSequencer.runInSeqUntilConditionIsUndone(FuturesSequencer.java:53)
    at tech.beshu.ror.utils.FuturesSequencer.runInSeqUntilConditionIsUndone(FuturesSequencer.java:41)
    at tech.beshu.ror.acl.ACL.doCheck(ACL.java:238)
    at tech.beshu.ror.acl.ACL.check(ACL.java:186)
    at tech.beshu.ror.es.IndexLevelActionFilter.handleRequest(IndexLevelActionFilter.java:159)
    at tech.beshu.ror.es.IndexLevelActionFilter.lambda$apply$1(IndexLevelActionFilter.java:135)
    at java.base/java.security.AccessController.doPrivileged(Native Method)
    at tech.beshu.ror.es.IndexLevelActionFilter.apply(IndexLevelActionFilter.java:131)
    at org.elasticsearch.action.support.TransportAction$RequestFilterChain.proceed(TransportAction.java:165)
    at org.elasticsearch.action.support.TransportAction.execute(TransportAction.java:139)
    at org.elasticsearch.action.support.TransportAction.execute(TransportAction.java:81)
    at org.elasticsearch.client.node.NodeClient.executeLocally(NodeClient.java:87)
    at org.elasticsearch.index.reindex.AbstractBaseReindexRestHandler.lambda$doPrepareRequest$0(AbstractBaseReindexRestHandler.java:62)
    at org.elasticsearch.rest.BaseRestHandler.handleRequest(BaseRestHandler.java:97)
    at tech.beshu.ror.es.ReadonlyRestPlugin.lambda$null$8(ReadonlyRestPlugin.java:253)
    at org.elasticsearch.rest.RestController.dispatchRequest(RestController.java:240)
    at org.elasticsearch.rest.RestController.tryAllHandlers(RestController.java:336)
    at org.elasticsearch.rest.RestController.dispatchRequest(RestController.java:174)
    at org.elasticsearch.http.netty4.Netty4HttpServerTransport.dispatchRequest(Netty4HttpServerTransport.java:551)
    at org.elasticsearch.http.netty4.Netty4HttpRequestHandler.channelRead0(Netty4HttpRequestHandler.java:137)
    at io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:105)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
    at org.elasticsearch.http.netty4.pipelining.HttpPipeliningHandler.channelRead(HttpPipeliningHandler.java:68)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
    at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102)
    at io.netty.handler.codec.MessageToMessageCodec.channelRead(MessageToMessageCodec.java:111)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
    at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
    at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
    at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:323)
    at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:297)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
    at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:286)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
    at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
    at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1434)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
    at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:965)
    at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163)
    at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:656)
    at io.netty.channel.nio.NioEventLoop.processSelectedKeysPlain(NioEventLoop.java:556)
    at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:510)
    at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:470)
    at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:909)
    at java.base/java.lang.Thread.run(Thread.java:834)

sscarduzio · March 15, 2019, 11:33am

Just addressed the NPE, well spotted! Will release a new build today for you.
About the external groups resolution, have you verified that ROR is extracting the groups correctly from the response?

I.e. setting ES root logger in debug mode from config/log4j2.properties

susannamartinelli · March 18, 2019, 9:54am

Hi @sscarduzio Just tried with ES root logging to debug
The plugin configuration is multitenancy_external like previous post.
Steps:

Connect to Kibana as Admin
Switch to Template tenant
Create the index_pattern and a visualization
Logout
Login with user (freddie who belong to 013 and 013-data rules )
I cannot see any Index_pattern or visualizations

When Logging as user I see this error on elasticsearch log:

[2019-03-18T08:39:23,602][INFO ][t.b.r.a.ACL              ] [W1ADDph] ALLOWED by { name: '013', policy: ALLOW, rules: [external_authentication, groups_provider_authorization, kibana_access, kibana_index, kibana_hide_apps]} req={ ID:2030304955-124063168#5056, TYP:RRAdminRequest, CGR:N/A, USR:freddie, BRS:false, KDX:.kibana_freddie, ACT:cluster:admin/rradmin/refreshsettings, OA:172.18.0.4, DA:172.18.0.3, IDX:<N/A>, MET:GET, PTH:/_readonlyrest/metadata/current_user, CNT:<N/A>, HDR:{authorization=Basic ZnJlZGRpZTpmcmVkZGll, Connection=close, content-length=0, Host=elasticsearch:9200}, HIS:[::KIBANA-SRV::->[auth_key->false]], [::LOGSTASH::->[auth_key->false]], [Admin Tenancy->[groups->false]], [Template Tenancy->[groups->false]], [011-data->[indices->true, groups_provider_authorization->false, external_authentication->true]], [011->[kibana_access->true, groups_provider_authorization->false, external_authentication->true]], [013-data->[filter->false, indices->true, groups_provider_authorization->true, external_authentication->true]], [013->[kibana_access->true, groups_provider_authorization->true, kibana_hide_apps->true, kibana_index->true, external_authentication->true]] } 
[2019-03-18T08:39:23,603][DEBUG][o.a.h.i.n.c.InternalIODispatch] [W1ADDph] http-outgoing-1 [ACTIVE] [content length: 27; pos: 27; completed: true]
[2019-03-18T08:39:23,603][DEBUG][o.a.h.i.n.c.InternalIODispatch] [W1ADDph] http-outgoing-1 [ACTIVE] Request ready
[2019-03-18T08:39:23,603][DEBUG][o.a.h.i.n.c.ManagedNHttpClientConnectionImpl] [W1ADDph] http-outgoing-1 172.18.0.3:47528<->172.18.0.2:8080[ACTIVE][r:rw]: Event cleared [w]
[2019-03-18T08:39:23,619][DEBUG][t.b.r.a.ACL              ] [W1ADDph] checking request:490471298-111885024#5057
[2019-03-18T08:39:23,620][DEBUG][t.b.r.e.RequestInfo      ] [W1ADDph] Discovered indices: .kibana_freddie
[2019-03-18T08:39:23,620][INFO ][t.b.r.a.b.r.i.AuthKeySyncRule] [W1ADDph] Attempting Login as: kibana rc: { ID:490471298-111885024#5057, TYP:CreateIndexRequest, CGR:N/A, USR:kibana(?), BRS:false, KDX:null, ACT:indices:admin/create, OA:172.18.0.4, DA:172.18.0.3, IDX:.kibana_freddie, MET:PUT, PTH:/.kibana_freddie, CNT:{"refresh":"true","settings":{"number_of_shards":1,"auto_expand_replicas":"0-1"},"mappings":{"doc":{"dynamic":"strict","properties":{"config":{"dynamic":"true","properties":{"buildNum":{"type":"keyword"}}},"migrationVersion":{"dynamic":"true","type":"object"},"type":{"type":"keyword"},"namespace":{"type":"keyword"},"updated_at":{"type":"date"},"index-pattern":{"properties":{"fieldFormatMap":{"type":"text"},"fields":{"type":"text"},"intervalName":{"type":"keyword"},"notExpandable":{"type":"boolean"},"sourceFilters":{"type":"text"},"timeFieldName":{"type":"keyword"},"title":{"type":"text"},"type":{"type":"keyword"},"typeMeta":{"type":"keyword"}}},"visualization":{"properties":{"description":{"type":"text"},"kibanaSavedObjectMeta":{"properties":{"searchSourceJSON":{"type":"text"}}},"savedSearchId":{"type":"keyword"},"title":{"type":"text"},"uiStateJSON":{"type":"text"},"version":{"type":"integer"},"visState":{"type":"text"}}},"search":{"properties":{"columns":{"type":"keyword"},"description":{"type":"text"},"hits":{"type":"integer"},"kibanaSavedObjectMeta":{"properties":{"searchSourceJSON":{"type":"text"}}},"sort":{"type":"keyword"},"title":{"type":"text"},"version":{"type":"integer"}}},"dashboard":{"properties":{"description":{"type":"text"},"hits":{"type":"integer"},"kibanaSavedObjectMeta":{"properties":{"searchSourceJSON":{"type":"text"}}},"optionsJSON":{"type":"text"},"panelsJSON":{"type":"text"},"refreshInterval":{"properties":{"display":{"type":"keyword"},"pause":{"type":"boolean"},"section":{"type":"integer"},"value":{"type":"integer"}}},"timeFrom":{"type":"keyword"},"timeRestore":{"type":"boolean"},"timeTo":{"type":"keyword"},"title":{"type":"text"},"uiStateJSON":{"type":"text"},"version":{"type":"integer"}}},"url":{"properties":{"accessCount":{"type":"long"},"accessDate":{"type":"date"},"createDate":{"type":"date"},"url":{"type":"text","fields":{"keyword":{"type":"keyword","ignore_above":2048}}}}},"server":{"properties":{"uuid":{"type":"keyword"}}},"kql-telemetry":{"properties":{"optInCount":{"type":"long"},"optOutCount":{"type":"long"}}},"timelion-sheet":{"properties":{"description":{"type":"text"},"hits":{"type":"integer"},"kibanaSavedObjectMeta":{"properties":{"searchSourceJSON":{"type":"text"}}},"timelion_chart_height":{"type":"integer"},"timelion_columns":{"type":"integer"},"timelion_interval":{"type":"keyword"},"timelion_other_interval":{"type":"keyword"},"timelion_rows":{"type":"integer"},"timelion_sheet":{"type":"text"},"title":{"type":"text"},"version":{"type":"integer"}}}}}}}, HDR:{Authorization=Basic a2liYW5hOmtpYmFuYQ==, Connection=keep-alive, Content-Length=2536, content-type=application/json, Host=elasticsearch:9200}, HIS: }
[2019-03-18T08:39:23,620][DEBUG][o.e.c.s.MasterService    ] [W1ADDph] processing [create-index [.kibana_freddie], cause [api]]: execute
[2019-03-18T08:39:23,620][DEBUG][r.suppressed             ] [W1ADDph] path: /.kibana_freddie, params: {index=.kibana_freddie}
org.elasticsearch.ResourceAlreadyExistsException: index [.kibana_freddie/71iYQ_XYQKO6QLmM_4SPlA] already exists
	at org.elasticsearch.cluster.metadata.MetaDataCreateIndexService.validateIndexName(MetaDataCreateIndexService.java:150) ~[elasticsearch-6.6.1.jar:6.6.1]
	at org.elasticsearch.cluster.metadata.MetaDataCreateIndexService.validate(MetaDataCreateIndexService.java:576) ~[elasticsearch-6.6.1.jar:6.6.1]
	at org.elasticsearch.cluster.metadata.MetaDataCreateIndexService$IndexCreationTask.execute(MetaDataCreateIndexService.java:289) ~[elasticsearch-6.6.1.jar:6.6.1]
	at org.elasticsearch.cluster.ClusterStateUpdateTask.execute(ClusterStateUpdateTask.java:47) ~[elasticsearch-6.6.1.jar:6.6.1]
	at org.elasticsearch.cluster.service.MasterService.executeTasks(MasterService.java:643) ~[elasticsearch-6.6.1.jar:6.6.1]
	at org.elasticsearch.cluster.service.MasterService.calculateTaskOutputs(MasterService.java:272) ~[elasticsearch-6.6.1.jar:6.6.1]
	at org.elasticsearch.cluster.service.MasterService.runTasks(MasterService.java:202) [elasticsearch-6.6.1.jar:6.6.1]
	at org.elasticsearch.cluster.service.MasterService$Batcher.run(MasterService.java:137) [elasticsearch-6.6.1.jar:6.6.1]
	at org.elasticsearch.cluster.service.TaskBatcher.runIfNotProcessed(TaskBatcher.java:150) [elasticsearch-6.6.1.jar:6.6.1]
	at org.elasticsearch.cluster.service.TaskBatcher$BatchedTask.run(TaskBatcher.java:188) [elasticsearch-6.6.1.jar:6.6.1]
	at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingRunnable.run(ThreadContext.java:660) [elasticsearch-6.6.1.jar:6.6.1]
	at org.elasticsearch.common.util.concurrent.PrioritizedEsThreadPoolExecutor$TieBreakingPrioritizedRunnable.runAndClean(PrioritizedEsThreadPoolExecutor.java:244) [elasticsearch-6.6.1.jar:6.6.1]
	at org.elasticsearch.common.util.concurrent.PrioritizedEsThreadPoolExecutor$TieBreakingPrioritizedRunnable.run(PrioritizedEsThreadPoolExecutor.java:207) [elasticsearch-6.6.1.jar:6.6.1]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:834) [?:?]
[2019-03-18T08:39:23,621][DEBUG][o.e.c.s.MasterService    ] [W1ADDph] processing [create-index [.kibana_freddie], cause [api]]: took [0s] no change in cluster state
[2019-03-18T08:39:23,631][DEBUG][t.b.r.a.ACL              ] [W1ADDph] checking request:757530789-167858766#5058
java.lang.NullPointerException
	at tech.beshu.ror.es.RequestInfo.extractIndices(RequestInfo.java:252)
	...

The authorization service works http://authprovider:8080… fine, both for authorization an groups association:

 Authorization Requested [user: freddie, pwd: freddie]
Group Association Requested [user: freddie, response: {"groups":[{"name":"013"}]}]

sscarduzio · March 18, 2019, 10:45am

Hi Susanna,

org.elasticsearch.ResourceAlreadyExistsException: index [.kibana_freddie/71iYQ_XYQKO6QLmM_4SPlA] already exists

This exception only appears in debug and it’s ROR Enterprise trying to make sure the index exists.

But how about this one? Still happening??

java.lang.NullPointerException
at tech.beshu.ror.es.RequestInfo.extractIndices(RequestInfo.java:252)

susannamartinelli · March 18, 2019, 11:01am

I’ve upgraded kibana ROR plugin with the one you linked readonlyrest_kbn_enterprise-1.17.3-pre1-20190314_es6.6.1

But the ES one is the same (readonlyrest-1.17.2_es6.6.1), maybe this could explain the NPE?

sscarduzio · March 18, 2019, 11:03am

It definitely can

susannamartinelli · March 18, 2019, 11:33am

The latest release for ES plugin (just tried to download from the website) is the same I have on my own, did you release a newer version (prebuild) fixing this exception?

sscarduzio · March 18, 2019, 12:03pm

pre builds are not public, I handed you over the pre build for validation, but we will release tomorrow a stable one with a bunch of fixes including this.

By the way is this from your JSON authorization service log?

Authorization Requested [user: freddie, pwd: freddie]
Group Association Requested [user: freddie, response: {“groups”:[{“name”:“013”}]}]

Debug logs in the external groups connector were writing directly to stdout, I just aligned this to the rest of the code, so it logs to the debug logger.
Will be available in 1.17.3-pre4 (will link it here when it’s built).

You should then see something like:


12:51:45.666 [I/O dispatcher 13] DEBUG ApacheHttpCoreClient - HTTP REQ SUCCESS with status: 200 [cded7c95-263b-43f4-a193-881614b06a35] GET http://localhost:32776/groups
12:51:45.669 [I/O dispatcher 13] DEBUG GroupsProviderServiceHttpClient - Groups returned by groups provider 'provider1': group1,group2
12:51:45.669 [I/O dispatcher 13] DEBUG GroupsProviderAuthorizationAsyncRule - user: example_user has groups: [group2, group1], intersected: [group1]
12:51:45.669 [I/O dispatcher 13] DEBUG GroupsProviderAuthorizationAsyncRule - setting current group: group1
12:51:45.726 [I/O dispatcher 13] DEBUG GroupsProviderAuthorizationAsyncRule - adding available groups for user example_user: [group1]
12:51:45.807 [I/O dispatcher 17] DEBUG ApacheHttpCoreClient - HTTP REQ SUCCESS with status: 200 [91e1213b-c856-416a-b31b-1e1d308935ed] POST http://localhost:32776/complex/groups
12:51:45.808 [I/O dispatcher 17] DEBUG GroupsProviderServiceHttpClient - Groups returned by groups provider 'provider1': group1,group2
12:51:45.808 [I/O dispatcher 17] DEBUG GroupsProviderAuthorizationAsyncRule - user: example_user has groups: [group2, group1], intersected: [group2, group1]
12:51:45.808 [I/O dispatcher 17] DEBUG GroupsProviderAuthorizationAsyncRule - found current group: group1
12:51:45.808 [I/O dispatcher 17] DEBUG GroupsProviderAuthorizationAsyncRule - adding available groups for user example_user: [group2, group1]

EDIT: now available https://readonlyrest-data.s3-eu-west-1.amazonaws.com/build/1.17.3-pre4/readonlyrest-1.17.3-pre4_es6.6.1.zip?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=AKIAJEKIPNTOTIVGQ4EQ/20190318/eu-west-1/s3/aws4_request&X-Amz-Date=20190318T121147Z&X-Amz-Expires=604800&X-Amz-SignedHeaders=host&X-Amz-Signature=75f3c4b41a888df12959cbdca318b5ef91cb517903153d85544b7bd7a4712087

susannamartinelli · March 18, 2019, 12:11pm

I actually see the user and the group association.

user: freddie has groups: [013], intersected: [013]
found current group: 013
adding available groups for user freddie: [013]

sscarduzio · March 18, 2019, 12:13pm

OK perfect! Can we see now when do you get a “FORBIDDEN” in the ES Logs? Maybe we can reconstruct what goes wrong

susannamartinelli · March 18, 2019, 1:13pm

Actually there is no FORBIDDEN rules in elastic log.
The user and the group match correctly the 013 rule BUT I cannot see any index_pattern and visualizations in user’s kibana frontend.

lookout-elasticsearch | [2019-03-18T12:05:39,363][DEBUG][t.b.r.a.b.Block          ] [W1ADDph] **matched** { name: '013', policy: ALLOW, rules: [external_authentication, groups_provider_authorization, kibana_access, kibana_index, kibana_hide_apps]}
lookout-elasticsearch | [2019-03-18T12:05:39,364][INFO ][t.b.r.a.ACL              ] [W1ADDph] ALLOWED by { name: '013', policy: ALLOW, rules: [external_authentication, groups_provider_authorization, kibana_access, kibana_index, kibana_hide_apps]} req={ ID:1192760816-1966467419#37017, TYP:RRAdminRequest, CGR:N/A, USR:freddie, BRS:false, KDX:.kibana_freddie, ACT:cluster:admin/rradmin/refreshsettings, OA:172.18.0.4, DA:172.18.0.3, IDX:<N/A>, MET:GET, PTH:/_readonlyrest/metadata/current_user, CNT:<N/A>, HDR:{authorization=Basic ZnJlZGRpZTpmcmVkZGll, Connection=close, content-length=0, Host=elasticsearch:9200}, HIS:[::KIBANA-SRV::->[auth_key->false]], [::LOGSTASH::->[auth_key->false]], [Admin Tenancy->[groups->false]], [Template Tenancy->[groups->false]], [011-data->[indices->true, groups_provider_authorization->false, external_authentication->true]], [011->[kibana_access->true, groups_provider_authorization->false, external_authentication->true]], [013-data->[filter->false, indices->true, groups_provider_authorization->true, external_authentication->true]], [013->[kibana_access->true, groups_provider_authorization->true, kibana_hide_apps->true, kibana_index->true, external_authentication->true]] } 
[...]

[2019-03-18T12:05:39,363][DEBUG][t.b.r.a.b.r.i.ExternalAuthenticationAsyncRule] [W1ADDph] Attempting Login as: freddie rc: { ID:1192760816-1966467419#37017, TYP:RRAdminRequest, CGR:N/A, USR:freddie(?), BRS:false, KDX:null, ACT:cluster:admin/rradmin/refreshsettings, OA:172.18.0.4, DA:172.18.0.3, IDX:<N/A>, MET:GET, PTH:/_readonlyrest/metadata/current_user, CNT:<N/A>, HDR:{authorization=Basic ZnJlZGRpZTpmcmVkZGll, Connection=close, content-length=0, Host=elasticsearch:9200}, HIS:[::KIBANA-SRV::->[auth_key->false]], [::LOGSTASH::->[auth_key->false]], [Admin Tenancy->[groups->false]], [Template Tenancy->[groups->false]], [011-data->[indices->true, groups_provider_authorization->false, external_authentication->true]], [011->[kibana_access->true, groups_provider_authorization->false, external_authentication->true]], [013-data->[filter->false, indices->true, groups_provider_authorization->true, external_authentication->true]] }
lookout-elasticsearch | user: freddie has groups: [013], intersected: [013]
lookout-elasticsearch | setting current group: 013
lookout-elasticsearch | adding available groups for user freddie: [013]
lookout-elasticsearch | [2019-03-18T12:05:39,363][DEBUG][t.b.r.a.b.r.i.KibanaHideAppsSyncRule] [W1ADDph] setting hidden apps for user freddie: kibana:dev_tools,kibana:management,readonlyrest_kbn
lookout-elasticsearch | [2019-03-18T12:05:39,363][DEBUG][t.b.r.a.b.Block          ] [W1ADDph] matched { name: '013', policy: ALLOW, rules: [external_authentication, groups_provider_authorization, kibana_access, kibana_index, kibana_hide_apps]}
lookout-elasticsearch | [2019-03-18T12:05:39,364][INFO ][t.b.r.a.ACL              ] [W1ADDph] ALLOWED by { name: '013', policy: ALLOW, rules: [external_authentication, groups_provider_authorization, kibana_access, kibana_index, kibana_hide_apps]} req={ ID:1192760816-1966467419#37017, TYP:RRAdminRequest, CGR:N/A, USR:freddie, BRS:false, KDX:.kibana_freddie, ACT:cluster:admin/rradmin/refreshsettings, OA:172.18.0.4, DA:172.18.0.3, IDX:<N/A>, MET:GET, PTH:/_readonlyrest/metadata/current_user, CNT:<N/A>, HDR:{authorization=Basic ZnJlZGRpZTpmcmVkZGll, Connection=close, content-length=0, Host=elasticsearch:9200}, HIS:[::KIBANA-SRV::->[auth_key->false]], [::LOGSTASH::->[auth_key->false]], [Admin Tenancy->[groups->false]], [Template Tenancy->[groups->false]], [011-data->[indices->true, groups_provider_authorization->false, external_authentication->true]], [011->[kibana_access->true, groups_provider_authorization->false, external_authentication->true]], [013-data->[filter->false, indices->true, groups_provider_authorization->true, external_authentication->true]], [013->[kibana_access->true, groups_provider_authorization->true, kibana_hide_apps->true, kibana_index->true, external_authentication->true]] } 
lookout-elasticsearch | [2019-03-18T12:05:39,366][DEBUG][o.a.h.i.n.c.InternalIODispatch] [W1ADDph] http-outgoing-1 [ACTIVE] [content length: 27; pos: 27; completed: true]
lookout-elasticsearch | [2019-03-18T12:05:39,366][DEBUG][o.a.h.i.n.c.InternalIODispatch] [W1ADDph] http-outgoing-1 [ACTIVE] Request ready
lookout-elasticsearch | [2019-03-18T12:05:39,366][DEBUG][o.a.h.i.n.c.ManagedNHttpClientConnectionImpl] [W1ADDph] http-outgoing-1 172.18.0.3:47528<->172.18.0.2:8080[ACTIVE][r:rw]: Event cleared [w]
lookout-elasticsearch | [2019-03-18T12:05:39,381][DEBUG][t.b.r.a.ACL              ] [W1ADDph] checking request:1939522682-935320639#37018
lookout-elasticsearch | [2019-03-18T12:05:39,381][DEBUG][t.b.r.e.RequestInfo      ] [W1ADDph] Discovered indices: .kibana_freddie
lookout-elasticsearch | [2019-03-18T12:05:39,381][INFO ][t.b.r.a.b.r.i.AuthKeySyncRule] [W1ADDph] Attempting Login as: kibana rc: { ID:1939522682-935320639#37018, TYP:CreateIndexRequest, CGR:N/A, USR:kibana(?), BRS:false, KDX:null, ACT:indices:admin/create, OA:172.18.0.4, DA:172.18.0.3, IDX:.kibana_freddie, MET:PUT, PTH:/.kibana_freddie, CNT:{"refresh":"true","settings":{"number_of_shards":1,"auto_expand_replicas":"0-1"},"mappings":{"doc":{"dynamic":"strict","properties":{"config":{"dynamic":"true","properties":{"buildNum":{"type":"keyword"}}},"migrationVersion":{"dynamic":"true","type":"object"},"type":{"type":"keyword"},"namespace":{"type":"keyword"},"updated_at":{"type":"date"},"index-pattern":{"properties":{"fieldFormatMap":{"type":"text"},"fields":{"type":"text"},"intervalName":{"type":"keyword"},"notExpandable":{"type":"boolean"},"sourceFilters":{"type":"text"},"timeFieldName":{"type":"keyword"},"title":{"type":"text"},"type":{"type":"keyword"},"typeMeta":{"type":"keyword"}}},"visualization":{"properties":{"description":{"type":"text"},"kibanaSavedObjectMeta":{"properties":{"searchSourceJSON":{"type":"text"}}},"savedSearchId":{"type":"keyword"},"title":{"type":"text"},"uiStateJSON":{"type":"text"},"version":{"type":"integer"},"visState":{"type":"text"}}},"search":{"properties":{"columns":{"type":"keyword"},"description":{"type":"text"},"hits":{"type":"integer"},"kibanaSavedObjectMeta":{"properties":{"searchSourceJSON":{"type":"text"}}},"sort":{"type":"keyword"},"title":{"type":"text"},"version":{"type":"integer"}}},"dashboard":{"properties":{"description":{"type":"text"},"hits":{"type":"integer"},"kibanaSavedObjectMeta":{"properties":{"searchSourceJSON":{"type":"text"}}},"optionsJSON":{"type":"text"},"panelsJSON":{"type":"text"},"refreshInterval":{"properties":{"display":{"type":"keyword"},"pause":{"type":"boolean"},"section":{"type":"integer"},"value":{"type":"integer"}}},"timeFrom":{"type":"keyword"},"timeRestore":{"type":"boolean"},"timeTo":{"type":"keyword"},"title":{"type":"text"},"uiStateJSON":{"type":"text"},"version":{"type":"integer"}}},"url":{"properties":{"accessCount":{"type":"long"},"accessDate":{"type":"date"},"createDate":{"type":"date"},"url":{"type":"text","fields":{"keyword":{"type":"keyword","ignore_above":2048}}}}},"server":{"properties":{"uuid":{"type":"keyword"}}},"kql-telemetry":{"properties":{"optInCount":{"type":"long"},"optOutCount":{"type":"long"}}},"timelion-sheet":{"properties":{"description":{"type":"text"},"hits":{"type":"integer"},"kibanaSavedObjectMeta":{"properties":{"searchSourceJSON":{"type":"text"}}},"timelion_chart_height":{"type":"integer"},"timelion_columns":{"type":"integer"},"timelion_interval":{"type":"keyword"},"timelion_other_interval":{"type":"keyword"},"timelion_rows":{"type":"integer"},"timelion_sheet":{"type":"text"},"title":{"type":"text"},"version":{"type":"integer"}}}}}}}, HDR:{Authorization=Basic a2liYW5hOmtpYmFuYQ==, Connection=keep-alive, Content-Length=2536, content-type=application/json, Host=elasticsearch:9200}, HIS: }
lookout-elasticsearch | [2019-03-18T12:05:39,381][DEBUG][t.b.r.a.b.Block          ] [W1ADDph] matched { name: '::KIBANA-SRV::', policy: ALLOW, rules: [auth_key]}
lookout-elasticsearch | [2019-03-18T12:05:39,384][DEBUG][o.e.c.s.MasterService    ] [W1ADDph] processing [create-index [.kibana_freddie], cause [api]]: execute
lookout-elasticsearch | [2019-03-18T12:05:39,385][DEBUG][r.suppressed             ] [W1ADDph] path: /.kibana_freddie, params: {index=.kibana_freddie}
lookout-elasticsearch | org.elasticsearch.ResourceAlreadyExistsException: index [.kibana_freddie/71iYQ_XYQKO6QLmM_4SPlA] already exists
lookout-elasticsearch | 	at org.elasticsearch.cluster.metadata.MetaDataCreateIndexService.validateIndexName(MetaDataCreateIndexService.java:150) ~[elasticsearch-6.6.1.jar:6.6.1]
lookout-elasticsearch | 	at org.elasticsearch.cluster.metadata.MetaDataCreateIndexService.validate(MetaDataCreateIndexService.java:576) ~[elasticsearch-6.6.1.jar:6.6.1]
lookout-elasticsearch | 	at org.elasticsearch.cluster.metadata.MetaDataCreateIndexService$IndexCreationTask.execute(MetaDataCreateIndexService.java:289) ~[elasticsearch-6.6.1.jar:6.6.1]
lookout-elasticsearch | 	at org.elasticsearch.cluster.ClusterStateUpdateTask.execute(ClusterStateUpdateTask.java:47) ~[elasticsearch-6.6.1.jar:6.6.1]
lookout-elasticsearch | 	at org.elasticsearch.cluster.service.MasterService.executeTasks(MasterService.java:643) ~[elasticsearch-6.6.1.jar:6.6.1]
lookout-elasticsearch | 	at org.elasticsearch.cluster.service.MasterService.calculateTaskOutputs(MasterService.java:272) ~[elasticsearch-6.6.1.jar:6.6.1]
lookout-elasticsearch | 	at org.elasticsearch.cluster.service.MasterService.runTasks(MasterService.java:202) [elasticsearch-6.6.1.jar:6.6.1]
lookout-elasticsearch | 	at org.elasticsearch.cluster.service.MasterService$Batcher.run(MasterService.java:137) [elasticsearch-6.6.1.jar:6.6.1]
lookout-elasticsearch | 	at org.elasticsearch.cluster.service.TaskBatcher.runIfNotProcessed(TaskBatcher.java:150) [elasticsearch-6.6.1.jar:6.6.1]
lookout-elasticsearch | 	at org.elasticsearch.cluster.service.TaskBatcher$BatchedTask.run(TaskBatcher.java:188) [elasticsearch-6.6.1.jar:6.6.1]
lookout-elasticsearch | 	at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingRunnable.run(ThreadContext.java:660) [elasticsearch-6.6.1.jar:6.6.1]
lookout-elasticsearch | 	at org.elasticsearch.common.util.concurrent.PrioritizedEsThreadPoolExecutor$TieBreakingPrioritizedRunnable.runAndClean(PrioritizedEsThreadPoolExecutor.java:244) [elasticsearch-6.6.1.jar:6.6.1]
lookout-elasticsearch | 	at org.elasticsearch.common.util.concurrent.PrioritizedEsThreadPoolExecutor$TieBreakingPrioritizedRunnable.run(PrioritizedEsThreadPoolExecutor.java:207) [elasticsearch-6.6.1.jar:6.6.1]
lookout-elasticsearch | 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
lookout-elasticsearch | 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
lookout-elasticsearch | 	at java.lang.Thread.run(Thread.java:834) [?:?]
lookout-elasticsearch | [2019-03-18T12:05:39,387][DEBUG][o.e.c.s.MasterService    ] [W1ADDph] processing [create-index [.kibana_freddie], cause [api]]: took [2ms] no change in cluster state
lookout-elasticsearch | [2019-03-18T12:05:39,392][DEBUG][t.b.r.a.ACL              ] [W1ADDph] checking request:1406425672-350305314#37019
lookout-elasticsearch | java.lang.NullPointerException
lookout-elasticsearch | 	at tech.beshu.ror.es.RequestInfo.extractIndices(RequestInfo.java:252)
....

sscarduzio · March 18, 2019, 1:27pm

Ok can you update the es plugin? I think the reindex is failing because it can’t extract the destination index due to the npe