RoR Ent: switch group results in logout

RoR Ent: 1.18.3 (both in Kibana and on Elasticsearch)
ELK: 6.8.0 (both in Kibana and on Elasticsearch)

Example config (it is a simplified version of production config

readonlyrest:
  enable: true
  prompt_for_basic_auth: false
  response_if_req_forbidden: "Computer says no!"
  audit_collector: true
  audit_index_template: "'readonlyrest_audit'-yyyy-MM"
  access_control_rules:
  - name: "Kibana user"
    auth_key_sha256: "sha256 hash of the user used by kibana"
    type: "allow"
    verbosity: "info"
    
  - name: "Readonly master kibana"
    indices: [".kibana"]
    kibana_access: "ro_strict"
    kibana_hide_apps: ["monitoring", "maps", "uptime", "timelion", "readonlyrest_kbn", "canvas", "apm", "infra:home", "infra:logs", "kibana:dev_tools", "kibana:management"]
    groups: ["masterkibanareadonly"]
    
  - name: "Write master kibana"
    indices: [".kibana"]
    kibana_access: "rw"
    kibana_hide_apps: ["monitoring", "maps", "uptime", "timelion", "readonlyrest_kbn", "canvas", "apm", "infra:home", "infra:logs", "kibana:dev_tools", "kibana:management"]
    groups: ["masterkibanawrite"]
    
  - name: "dave"
    indices: [".kibana", "davetest"]
    kibana_access: "rw"
    kibana_index: "davetest"
    kibana_hide_apps: ["monitoring", "maps", "uptime", "timelion", "readonlyrest_kbn", "canvas", "apm", "infra:home", "infra:logs", "kibana:dev_tools", "kibana:management"]
    groups: ["dave"]
    
  - name: "Elasticsearch machines are allowed to do anything"
    hosts: ["127.0.0.1", "10.x.x.x"]
    type: "allow"
    
  users:
  - username: "henk"
    auth_key: "henk:henk"
    groups: ["masterkibanareadonly", "dave"]

Please note the 10.x.x.x on the block name: “Elasticsearch machines are allowed to do anything”
It is the production IP of the ELK machine.

User Henk can login, he will be logged in as context henk@masterkibanareadonly.
The moment I try to switch to the henk@dave context I am send back to login screen.
In the RoR audit logs I don’t see any forbidden or error messages.
I have enabled versbose mode in Kibana and upon doing the context switch I see these logs:

Jul 31 11:36:58 xxxxx kibana[28834]: {"type":"log","@timestamp":"2019-07-31T09:36:58Z","tags":["debug","legacy-proxy"],"pid":28834,"message":"Event is being forwarded: connection"}
Jul 31 11:36:58 xxxxx kibana[28834]: {"type":"log","@timestamp":"2019-07-31T09:36:58Z","tags":["debug","legacy-service"],"pid":28834,"message":"Request will be handled by proxy GET:/switch-group?group=dave&redirectTo=http
s%3A%2F%2Ffqdnalias%2Fapp%2Fkibana."}
Jul 31 11:36:58 xxxxx kibana[28834]: {"type":"log","@timestamp":"2019-07-31T09:36:58Z","tags":["debug","readonlyrest_kbn:credentialsHeaders"],"pid":28834,"message":"forwarding whitelisted header for login attempt 0: Basic
 aGVuazpoZW5r"}
Jul 31 11:36:58 xxxxx kibana[28834]: {"type":"log","@timestamp":"2019-07-31T09:36:58Z","tags":["debug","readonlyrest_kbn:extractCredentials"],"pid":28834,"message":"extracting from cookie coz already auth"}
Jul 31 11:36:58 xxxxx kibana[28834]: {"type":"log","@timestamp":"2019-07-31T09:36:58Z","tags":["debug","readonlyrest_kbn:enrichFromEs"],"pid":28834,"message":"enriching identity from es using authHeaders: "}
Jul 31 11:36:58 xxxxx kibana[28834]: {"type":"log","@timestamp":"2019-07-31T09:36:58Z","tags":["debug","readonlyrest_kbn:enrichFromEs"],"pid":28834,"message":" received identity payload: {\"x-ror-current-group\":\"dave\"}
"}
Jul 31 11:36:58 xxxxx kibana[28834]: {"type":"log","@timestamp":"2019-07-31T09:36:58Z","tags":["debug","readonlyrest_kbn:enrichFromEs"],"pid":28834,"message":"ON_IDENTITY no kibana index from headers, setting kibana index
 to default configured .kibana"}
Jul 31 11:36:58 xxxxx kibana[28834]: {"type":"log","@timestamp":"2019-07-31T09:36:58Z","tags":["error","readonlyrest_kbn:writeIdentity"],"pid":28834,"message":"invalid identity"}
Jul 31 11:36:58 xxxxx kibana[28834]: {"type":"log","@timestamp":"2019-07-31T09:36:58Z","tags":["debug","readonlyrest_kbn:changeCurrentGroup"],"pid":28834,"message":"error writing identity"}
Jul 31 11:36:58 xxxxx kibana[28834]: {"type":"log","@timestamp":"2019-07-31T09:36:58Z","tags":["license","debug","xpack"],"pid":28834,"message":"Calling [data] Elasticsearch _xpack API. Polling frequency: 30001"}
Jul 31 11:36:58 xxxxx kibana[28834]: {"type":"log","@timestamp":"2019-07-31T09:36:58Z","tags":["error","readonlyrest_kbn:onPreResponse"],"pid":28834,"message":"got an error [500] Internal Server Error for path /switch-gro
up"}
Jul 31 11:36:58 xxxxx kibana[28834]: {"type":"log","@timestamp":"2019-07-31T09:36:58Z","tags":["error","readonlyrest_kbn:onPreResponse"],"pid":28834,"message":"{\"isBoom\":true,\"isServer\":true,\"data\":null,\"output\":{
\"statusCode\":500,\"payload\":{\"statusCode\":500,\"error\":\"Internal Server Error\",\"message\":\"An internal server error occurred\"},\"headers\":{\"kbn-name\":\"kibana\",\"kbn-xpack-sig\":\"f229eabc7602d57edd0d3e5eaae93c16\"}}}"}
Jul 31 11:36:58 xxxxx kibana[28834]: {"type":"log","@timestamp":"2019-07-31T09:36:58Z","tags":["debug","readonlyrest_kbn:onPreResponse"],"pid":28834,"message":"Rogue deep link, or has valid credentials but was unauthorize
d, must have insufficient privileges. Redirecting to logout: /logout"}
Jul 31 11:36:58 xxxxx kibana[28834]: { Error: invalid identity {"x-ror-current-group":"dave","authHeaders":{"authorization":"Basic aGVuazp1bmRlZmluZWQ=","x-ror-current-group":"dave"},"hiddenApps":[],"sid":"a5e5d9a5-785a-4
111-9ecd-ccf31709c8e6","groupCurrent":"dave"}
Jul 31 11:36:58 xxxxx kibana[28834]: at writeIdentity (/usr/share/kibana/plugins/readonlyrest_kbn/server/routes/lib/auth.js:1:969)
Jul 31 11:36:58 xxxxx kibana[28834]: at changeCurrentGroup (/usr/share/kibana/plugins/readonlyrest_kbn/server/routes/lib/auth.js:1:728)
Jul 31 11:36:58 xxxxx kibana[28834]: isBoom: true,
Jul 31 11:36:58 xxxxx kibana[28834]: isServer: true,
Jul 31 11:36:58 xxxxx kibana[28834]: data: null,
Jul 31 11:36:58 xxxxx kibana[28834]: output:
Jul 31 11:36:58 xxxxx kibana[28834]: { statusCode: 500,
Jul 31 11:36:58 xxxxx kibana[28834]: payload:
Jul 31 11:36:58 xxxxx kibana[28834]: { statusCode: 500,
Jul 31 11:36:58 xxxxx kibana[28834]: error: 'Internal Server Error',
Jul 31 11:36:58 xxxxx kibana[28834]: message: 'An internal server error occurred' },
Jul 31 11:36:58 xxxxx kibana[28834]: headers:
Jul 31 11:36:58 xxxxx kibana[28834]: { 'kbn-name': 'kibana',
Jul 31 11:36:58 xxxxx kibana[28834]: 'kbn-xpack-sig': 'f229eabc7602d57edd0d3e5eaae93c16' } },
Jul 31 11:36:58 xxxxx kibana[28834]: reformat: [Function] }
Jul 31 11:36:58 xxxxx kibana[28834]: redirecting to  /login
Jul 31 11:36:58 xxxxx kibana[28834]: {"type":"response","@timestamp":"2019-07-31T09:36:58Z","tags":[],"pid":28834,"method":"get","statusCode":302,"req":{"url":"/switch-group?group=dave&redirectTo=https%3A%2F%2Ffqdnalias%2Fapp%2Fkibana","method":"get","headers":{"host":"fqdnalias","upgrade-insecure-requests":"1","user-agent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/75.0.3770.142 Safari/537.36","accept":"text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3","referer":"https://fqdnalias/app/kibana","accept-encoding":"gzip, deflate, br","accept-language":"en-US,en;q=0.9,de;q=0.8,nl;q=0.7","x-smc-reverseproxy-ip-address":"10.zz.zz.zz","x-forwarded-for":"10.zz.zz.zz","x-forwarded-host":"fqdnalias","x-forwarded-server":"fqdnalias","connection":"Keep-Alive","x-ror-current-group":"masterkibanareadonly"},"remoteAddress":"10.aa.aa.aa","userAgent":"10.aa.aa.aa","referer":"https://fqdnalias/app/kibana"},"res":{"statusCode":302,"responseTime":72,"contentLength":9},"message":"GET /switch-group?group=dave&redirectTo=https%3A%2F%2Ffqdnalias%2Fapp%2Fkibana 302 72ms - 9.0B"}
Jul 31 11:36:58 xxxxx kibana[28834]: {"type":"log","@timestamp":"2019-07-31T09:36:58Z","tags":["debug","legacy-proxy"],"pid":28834,"message":"Event is being forwarded: connection"}
Jul 31 11:36:58 xxxxx kibana[28834]: {"type":"log","@timestamp":"2019-07-31T09:36:58Z","tags":["debug","legacy-service"],"pid":28834,"message":"Request will be handled by proxy GET:/login."}
Jul 31 11:36:58 xxxxx kibana[28834]: {"type":"log","@timestamp":"2019-07-31T09:36:58Z","tags":["debug","readonlyrest_kbn:postAuth"],"pid":28834,"message":"groupCurrent not found (probably it's never been set) [object Object]"}
Jul 31 11:36:58 xxxxx kibana[28834]: {"type":"log","@timestamp":"2019-07-31T09:36:58Z","tags":["debug","readonlyrest_kbn:extractCredentials"],"pid":28834,"message":"try extract credentials from JSON"}
Jul 31 11:36:58 xxxxx kibana[28834]: {"type":"log","@timestamp":"2019-07-31T09:36:58Z","tags":["debug","readonlyrest_kbn:extractCredentials"],"pid":28834,"message":"try extract credentials from Basic Auth"}
Jul 31 11:36:58 xxxxx kibana[28834]: {"type":"response","@timestamp":"2019-07-31T09:36:58Z","tags":[],"pid":28834,"method":"get","statusCode":200,"req":{"url":"/login","method":"get","headers":{"host":"fqdnalias","upgrade-insecure-requests":"1","user-agent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/75.0.3770.142 Safari/537.36","accept":"text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3","referer":"https://fqdnalias/app/kibana","accept-encoding":"gzip, deflate, br","accept-language":"en-US,en;q=0.9,de;q=0.8,nl;q=0.7","x-smc-reverseproxy-ip-address":"10.zz.zz.zz","x-forwarded-for":"10.zz.zz.zz","x-forwarded-host":"fqdnalias","x-forwarded-server":"fqdnalias","connection":"Keep-Alive","kbn-xsrf":"6.8.0","kbn-version":"6.8.0"},"remoteAddress":"10.aa.aa.aa","userAgent":"10.aa.aa.aa","referer":"https://fqdnalias/app/kibana"},"res":{"statusCode":200,"responseTime":5,"contentLength":9},"message":"GET /login 200 5ms - 9.0B"}
Jul 31 11:36:58 xxxxx kibana[28834]: {"type":"log","@timestamp":"2019-07-31T09:36:58Z","tags":["debug","legacy-proxy"],"pid":28834,"message":"Event is being forwarded: connection"}
Jul 31 11:36:58 xxxxx kibana[28834]: {"type":"log","@timestamp":"2019-07-31T09:36:58Z","tags":["plugin","debug"],"pid":28834,"message":"Checking Elasticsearch version"}

I have to anonymize the logs for security reasons, but it should still tell you enough to get an idea of what is going on.

In the 1.18.1 trial Ent version this config worked.

I have been working through it a bit trying to figure out if it is something weird on 1 machine or 1 cluster.
But similar configs on both the production and the acceptance cluster result in the same behaviour.
Everything else seems to work as expected, it is just the context switching that fails.

We are releasing 1.18.4 later today.

1 Like

I downloaded and tested with 1.18.4 and this indeed solves the problem, thanks!

PS. The release notes on the download page show version 1.18.4 with the release note text from 1.18.3

1 Like

Release notes updated, thanks!