Users log out after a few seconds with Could not refresh the session against ES: + Wrong credentials

carlosm · November 24, 2022, 3:02pm

Hi, we’re testing the migration from our pro (Pro-1.37.0_es7.16.1 ) to a new version in our systems together with the Enterprise (Enterprise 1.44.0_es7.16.3 ), and we’re trying it in our local envs to test our deployments with a clean machine (kind of same config of our current but upgrading our docker images with the new version.).

So after we launch the ES with Kibana and we activate the keys for the enterprise, everything seems to work, in one of our local systems our ldap users get logged out after a few seconds-minute (with activity,seems not related to a logout after inactivity).

We have:
elasticsearch:7.16.3-1
kibana:7.16.3-1

Reproduce:

Launch ES and Kibana with ROR.
Activate the enterprise solution login as admin and adding the keys
Log in with an ldap user (for example in this logs is carlos.xxxx)

Result:
4) It logs out after a few seconds (or maybe even 1 minute, is quite random). This does not happen with admin users.

We’ve tried different browsers and incognito mode, but given the error in kibana below I don’t think i matters. We’ve tried to use different config in the kibana.yml related to idle time, but it doesn’t help (and also, it logs out even with activity):

This our kibana.yml:
elasticsearch.password: XXXXX
elasticsearch.requestTimeout: 500000
elasticsearch.shardTimeout: 500000
elasticsearch.ssl.verificationMode: none
elasticsearch.hosts: [“https://velasticsearch:9200”]
elasticsearch.username: kibana_system
server.host: 0.0.0.0
server.publicBaseUrl: vkibana
xpack.apm.enabled: false
xpack.apm.ui.enabled: false
xpack.canvas.enabled: false
xpack.infra.enabled: false
xpack.ml.enabled: false
xpack.security.enabled: false
monitoring.cluster_alerts.email_notifications.email_address: mymail@mail.net
readonlyrest_kbn.sessions_probe_interval_seconds: 180
console.enabled: true
logging.json: false
logging.verbose: true

Logs here are obfuscated a bit the ldap info:
Elasticsearch logs:
[227.673s][info ][gc,start ] GC(15) Pause Young (Normal) (G1 Evacuation Pause)
[227.673s][info ][gc,task ] GC(15) Using 8 workers of 8 for evacuation
[227.697s][info ][gc,phases ] GC(15) Pre Evacuate Collection Set: 0.2ms
[227.697s][info ][gc,phases ] GC(15) Merge Heap Roots: 0.1ms
[227.697s][info ][gc,phases ] GC(15) Evacuate Collection Set: 19.5ms
[227.697s][info ][gc,phases ] GC(15) Post Evacuate Collection Set: 2.8ms
[227.697s][info ][gc,phases ] GC(15) Other: 1.5ms
[227.697s][info ][gc,heap ] GC(15) Eden regions: 291->0(291)
[227.697s][info ][gc,heap ] GC(15) Survivor regions: 16->16(39)
[227.697s][info ][gc,heap ] GC(15) Old regions: 14->14
[227.697s][info ][gc,heap ] GC(15) Archive regions: 2->2
[227.697s][info ][gc,heap ] GC(15) Humongous regions: 2->2
[227.697s][info ][gc,metaspace] GC(15) Metaspace: 157462K(159296K)->157462K(159296K) NonClass: 136174K(137216K)->136174K(137216K) Class: 21287K(22080K)->21287K(22080K)
[227.697s][info ][gc ] GC(15) Pause Young (Normal) (G1 Evacuation Pause) 1292M->128M(2048M) 24.114ms
[227.697s][info ][gc,cpu ] GC(15) User=0.13s Sys=0.00s Real=0.03s
{“type”: “server”, “timestamp”: “2022-11-24T11:37:03,605Z”, “level”: “INFO”, “component”: “t.b.r.a.l.AccessControlLoggingDecorator”, “cluster.name”: “piab-cluster”, “node.name”: “node-piab”, “message”: “\u001B[36mALLOWED by { name: ‘LDAP Role: rCompany’, policy: ALLOW, rules: [ldap_auth,kibana_hide_apps,kibana_access,indices] req={ ID:10097326-53289848#3058, TYP:RRUserMetadataRequest, CGR:N/A, USR:carlos.xxxx, BRS:true, KDX:null, ACT:cluster:ror/user_metadata/get, OA:10.191.1.27/32, XFF:null, DA:10.191.1.26/32, IDX:<N/A>, MET:GET, PTH:/_readonlyrest/metadata/current_user, CNT:<N/A>, HDR:Accept-Encoding=gzip,deflate, Accept=/, Authorization=, Connection=close, Host=velasticsearch:9200, User-Agent=node-fetch/1.0 (+https://github.com/bitinn/node-fetch), content-length=0, HIS:[Read actions for kibana_system-> RULES:[actions->false]], [ROR Administrator-> RULES:[auth_key->false]], [Company Ldap - Group Director-> RULES:[ldap_auth->false]], [avapinky-> RULES:[auth_key_sha256->false]], [SpeedyGonzales-> RULES:[auth_key_sha256->false]], [Logtash-> RULES:[auth_key_sha256->false]], [Wazuh-> RULES:[auth_key_sha256->false]], [Kibana-> RULES:[auth_key_sha256->false]], [Prometheus exporter-> RULES:[actions->false]], [Elasticsearch docker exporter-> RULES:[auth_key_sha256->false]], [squealerBackend-> RULES:[auth_key_sha256->false]], [elastalert write block-> RULES:[auth_key_sha256->false]], [Jaeger-> RULES:[auth_key_sha256->false]], [Kibana indexes-> RULES:[indices->true]], [No access allowed to ReadonlyRest-> RULES:[indices->true]], [LDAP Role for actions: rGroup-> RULES:[ldap_auth->true, actions->false] RESOLVED:[user=carlos.xxxx;group=rGroup;av_groups=rGroup,rCompany]], [No write actions allowed-> RULES:[actions->false]], [elastalert-> RULES:[auth_key_sha256->false]], [LDAP Role: rCompany-> RULES:[ldap_auth->true, kibana_hide_apps->true, kibana_access->true, indices->true] RESOLVED:[user=carlos.xxxx;group=rGroup;av_groups=rGroup,rCompany]], }\u001B[0m”, “cluster.uuid”: “fmq8xkLWT6-Xf0Sv0_rPrg”, “node.id”: “XoISUvo3T0Cb3riAaJ21IQ” }
{“type”: “server”, “timestamp”: “2022-11-24T11:37:06,929Z”, “level”: “INFO”, “component”: “t.b.r.a.l.AccessControlLoggingDecorator”, “cluster.name”: “piab-cluster”, “node.name”: “node-piab”, “message”: “\u001B[36mALLOWED by { name: ‘Read actions for kibana_system’, policy: ALLOW, rules: [actions] req={ ID:1519437829-1755488615#3168, TYP:IndexRequest, CGR:rGroup, USR:carlos.xxxx (attempted), BRS:true, KDX:null, ACT:indices:data/write/index, OA:10.191.1.27/32, XFF:vkibana.obs, DA:10.191.1.26/32, IDX:.kibana, MET:PUT, PTH:/.kibana/_create/search-session:d48a7356-f0e6-4d4f-a8d2-cbc6002028c5, CNT:<OMITTED, LENGTH=785.0 B> , HDR:Accept-Charset=utf-8, Authorization=, Host=velasticsearch:9200, connection=close, content-length=785, content-type=application/json, user-agent=elasticsearch-js/7.16.0-canary.7 (linux 5.14.0-1005-oem-x64; Node.js v16.13.0), x-elastic-client-meta=es=7.16.0p,js=16.13.0,t=7.16.0p,hc=16.13.0, x-elastic-product-origin=kibana, x-forwarded-for=vkibana.obs, x-opaque-id=21a1249b-6560-4fcb-a225-a475511483e2, x-ror-correlation-id=0bc35df9-ecd1-4494-a1c1-dcd692c05d68, x-ror-current-group=rGroup, x-ror-kibana-request-method=post, x-ror-kibana-request-path=/s/default/internal/bsearch, HIS:[Read actions for kibana_system-> RULES:[actions->true] RESOLVED:[group=rGroup;indices=.kibana]], }\u001B[0m”, “cluster.uuid”: “fmq8xkLWT6-Xf0Sv0_rPrg”, “node.id”: “XoISUvo3T0Cb3riAaJ21IQ” }
{“type”: “server”, “timestamp”: “2022-11-24T11:37:23,944Z”, “level”: “INFO”, “component”: “t.b.r.a.l.AccessControlLoggingDecorator”, “cluster.name”: “piab-cluster”, “node.name”: “node-piab”, “message”: “\u001B[35mFORBIDDEN by default req={ ID:1427452531-1940098389#3420, TYP:RRUserMetadataRequest, CGR:rGroup, USR:carlos.xxxx (attempted), BRS:true, KDX:null, ACT:cluster:ror/user_metadata/get, OA:10.191.1.27/32, XFF:null, DA:10.191.1.26/32, IDX:<N/A>, MET:GET, PTH:/_readonlyrest/metadata/current_user, CNT:<N/A>, HDR:Accept-Encoding=gzip,deflate, Accept=/, Authorization=, Connection=close, Host=velasticsearch:9200, User-Agent=node-fetch/1.0 (+https://github.com/bitinn/node-fetch), content-length=0, x-ror-correlation-id=undefined, x-ror-current-group=rGroup, HIS:[Read actions for kibana_system-> RULES:[actions->false] RESOLVED:[group=rGroup]], [ROR Administrator-> RULES:[auth_key->false] RESOLVED:[group=rGroup]], [Company Ldap - Group Director-> RULES:[ldap_auth->false] RESOLVED:[group=rGroup]], [avapinky-> RULES:[auth_key_sha256->false] RESOLVED:[group=rGroup]], [SpeedyGonzales-> RULES:[auth_key_sha256->false] RESOLVED:[group=rGroup]], [Logtash-> RULES:[auth_key_sha256->false] RESOLVED:[group=rGroup]], [Wazuh-> RULES:[auth_key_sha256->false] RESOLVED:[group=rGroup]], [Kibana-> RULES:[auth_key_sha256->false] RESOLVED:[group=rGroup]], [Prometheus exporter-> RULES:[actions->false] RESOLVED:[group=rGroup]], [Elasticsearch docker exporter-> RULES:[auth_key_sha256->false] RESOLVED:[group=rGroup]], [squealerBackend-> RULES:[auth_key_sha256->false] RESOLVED:[group=rGroup]], [elastalert write block-> RULES:[auth_key_sha256->false] RESOLVED:[group=rGroup]], [Jaeger-> RULES:[auth_key_sha256->false] RESOLVED:[group=rGroup]], [Kibana indexes-> RULES:[indices->true] RESOLVED:[group=rGroup]], [No access allowed to ReadonlyRest-> RULES:[indices->true] RESOLVED:[group=rGroup]], [LDAP Role for actions: rGroup-> RULES:[ldap_auth->true, actions->false] RESOLVED:[user=carlos.xxxx;group=rGroup;av_groups=rGroup,rCompany]], [No write actions allowed-> RULES:[actions->false] RESOLVED:[group=rGroup]], [elastalert-> RULES:[auth_key_sha256->false] RESOLVED:[group=rGroup]], [LDAP Role: rCompany-> RULES:[ldap_auth->false] RESOLVED:[group=rGroup]], }\u001B[0m”, “cluster.uuid”: “fmq8xkLWT6-Xf0Sv0_rPrg”, “node.id”: “XoISUvo3T0Cb3riAaJ21IQ” }
{“type”: “server”, “timestamp”: “2022-11-24T11:37:23,992Z”, “level”: “INFO”, “component”: “t.b.r.a.l.AccessControlLoggingDecorator”, “cluster.name”: “piab-cluster”, “node.name”: “node-piab”, “message”: “\u001B[36mALLOWED by { name: ‘Read actions for kibana_system’, policy: ALLOW, rules: [actions] req={ ID:1630102326-1251046874#3421, TYP:RRAuditEventRequest, CGR:N/A, USR:carlos.xxxx (attempted), BRS:true, KDX:null, ACT:cluster:ror/audit_event/put, OA:10.191.1.27/32, XFF:null, DA:10.191.1.26/32, IDX:<N/A>, MET:POST, PTH:/_readonlyrest/admin/audit/event, CNT:<OMITTED, LENGTH=64.0 B> , HDR:Accept-Encoding=gzip,deflate, Accept=/, Authorization=, Connection=close, Content-Type=application/json, Host=velasticsearch:9200, User-Agent=node-fetch/1.0 (+https://github.com/bitinn/node-fetch), content-length=64, x-ror-correlation-id=undefined, HIS:[Read actions for kibana_system-> RULES:[actions->true]], }\u001B[0m”, “cluster.uuid”: “fmq8xkLWT6-Xf0Sv0_rPrg”, “node.id”: “XoISUvo3T0Cb3riAaJ21IQ” }

Kibana (same session):

[11:37:14:268] [warning][plugins][ReadonlyREST][requestInterceptor] Could not access most recently accessed session’s kibanaIndex for isReportingRequest
^[[F[11:37:20:241] [warning][plugins][ReadonlyREST][requestInterceptor] Could not access most recently accessed session’s kibanaIndex for isReportingRequest
[11:37:20:241] [warning][plugins][ReadonlyREST][requestInterceptor] Could not access most recently accessed session’s kibanaIndex for isReportingRequest
[11:37:23:939] [info][plugins][ReadonlyREST][authController] Refreshing session against ES
[11:37:23:946] [error][plugins][ReadonlyREST][esClient] ES Authorization error: 403 Error: ES Authorization error: 403
at l.e (/usr/share/kibana/plugins/readonlyrestkbn/proxy/core/esClient.js:1:16663)
at l.e (/usr/share/kibana/plugins/readonlyrestkbn/proxy/core/esClient.js:1:5171)
at tryCatch (/usr/share/kibana/plugins/readonlyrestkbn/node_modules/regenerator-runtime/runtime.js:45:40)
at Generator.invoke [as _invoke] (/usr/share/kibana/plugins/readonlyrestkbn/node_modules/regenerator-runtime/runtime.js:274:22)
at Generator.prototype. [as next] (/usr/share/kibana/plugins/readonlyrestkbn/node_modules/regenerator-runtime/runtime.js:97:21)
at asyncGeneratorStep (/usr/share/kibana/plugins/readonlyrestkbn/node_modules/@babel/runtime/helpers/asyncToGenerator.js:3:24)
at _next (/usr/share/kibana/plugins/readonlyrestkbn/node_modules/@babel/runtime/helpers/asyncToGenerator.js:25:9)
at runMicrotasks ()
at processTicksAndRejections (node:internal/process/task_queues:96:5)
[11:37:23:947] [info][plugins][ReadonlyREST][authController] Could not refresh the session against ES: + Wrong credentials
[11:37:26:275] [warning][plugins][ReadonlyREST][requestInterceptor] Could not access most recently accessed session’s kibanaIndex for isReportingRequest
[11:37:26:275] [warning][plugins][ReadonlyREST][requestInterceptor] Could not access most recently accessed session’s kibanaIndex for isReportingRequest
[11:37:32:281] [warning][plugins][ReadonlyREST][requestInterceptor] Could not access most recently accessed session’s kibanaIndex for isReportingRequest

carlosm · November 24, 2022, 3:07pm

I’m working with @gustavo.yoshizaki in this issue if you need a customer’s ponit of contact.

Dzuming · November 24, 2022, 8:22pm

Hi, Thanks for your message. I’m trying to reproduce this issue locally. Could you also provide your readonlyrest.yml config? You can send it as a private message.

carlosm · November 25, 2022, 9:40am

how can I send you the file privately? thanks

sscarduzio · November 25, 2022, 10:20pm

@carlosm the forum has direct messages.
Sending configuration files through DM is encouraged to Enterprise/PRO customers when they believe the configuration files cannot be sent to support over the public threads because they contain reserved information that is not easy to remove without altering the config file structure.

carlosm · November 27, 2022, 9:27am

yes, I’ve tried but I havent seen be able too. when I click on send message I’ve get redirected to the / in the forum, and I cannot see any button to send a private message in the user’s profile

carlosm · November 27, 2022, 9:28am

I’ve gete redirected to the main page when I click message a staff memeber

Dzuming · November 28, 2022, 6:06am

That’s strange, If you go to the profile, you should see “Message” button

I sent you a private message, let’s see if it works this way. If not, you can send me this config via e-mail at dawid@readonlyrest.com

sscarduzio · November 28, 2022, 7:25am

@carlosm the topic/PM are automatically created if you use our customer portal

sscarduzio · November 28, 2022, 9:14am

@carlosm I discovered you were not affiliated to your employer’s account! Please try again now to access the customer portal now!

carlosm · November 28, 2022, 12:34pm

OK, thanks a lot Simone, I sent Dawid an emial with the file, but I’ll probably open a ticket anyway.

sscarduzio · November 29, 2022, 9:04am

OK let me know when you create the ticket, as the portal infrastructure is very new and we are still ironing the process and the software.