Authentication: User logins sometimes breaks Grafana (OpenShift oauth-proxy)

rstudio · February 21, 2024, 8:45am

What happened?

Sometimes when I log in to Grafana, I get the following errors and Grafana hangs for about 30 seconds (get a 504 Gateway time-out):

logger=user.sync t=2024-02-08T15:47:27.385024849Z level=error msg="Failed to fetch user" error="context canceled" auth_module=authproxy auth_id=<REDACTED>
logger=authn.service t=2024-02-08T15:47:27.385095343Z level=error msg="Failed to run post auth hook" client=auth.client.proxy id= error="[user.sync.internal] unable to retrieve user"

What did you expect to happen?

Grafana runs without any hangs.

Did this work before?

I have not noticed this with Grafana 9.2.1 and I cannot reproduce it.

How do we reproduce it?

It is really not easy to reproduce it.

Deploy Grafana with the Grafana Operator v5.6.2 on OpenShift with a OpenShift oauth-proxy container.
Open a icognito browser tab and login with OpenShift (SAML)
Go to Explore wait until the Prometheus metrics are loaded (in code view)
Repeat step 1-3 for 1-10 times.

Is the bug inside a dashboard panel?

no, the whole Grafana hangs for all users and sometime even the ReadinessProbe on /api/health fails and I have configured a timeout of 30 seconds.

Environment (with versions)?

Grafana: 10.1.6, 10.2.3, 10.3.1, 10.3.3
OS: Grafana Docker Image on OpenShift Workernodes
Browser: Edge, Chrome
OpenShift oauth-proxy: 4.12, 4.13, 4.14

Grafana platform?

Kubernetes

Datasource(s)?

Prometheus 2.39.x

rstudio · February 21, 2024, 8:47am

I also created a GitHub issue, but haven’t received any responses yet: Authentication: User logins sometimes breaks Grafana (OpenShift oauth-proxy) · Issue #82262 · grafana/grafana · GitHub

jangaraj · February 21, 2024, 9:14am

Use standard debugging approach: increase log level to debug and check/provide logs.

rstudio · February 21, 2024, 9:51am

I already changed that, but as I mentioned only following logs are interesting:

logger=user.sync t=2024-02-08T15:47:27.385024849Z level=error msg="Failed to fetch user" error="context canceled" auth_module=authproxy auth_id=<REDACTED>
logger=authn.service t=2024-02-08T15:47:27.385095343Z level=error msg="Failed to run post auth hook" client=auth.client.proxy id= error="[user.sync.internal] unable to retrieve user"

jangaraj · February 21, 2024, 10:37am

No, you provided only errors. But it is not clear what Grafana is doing, when it is not responsive (that can be visible on non error logs).

Go to higher level and enable opentelemtry tracing om the Grafana level and inspect generated traces.

I bet Grafana database can be a root cause. Use serious DB and not default SQLite.

rstudio · February 21, 2024, 11:38am

I will do that.

Ok, but for opentelemetry traces I need a tracing system like tempo right? (unfortunately we don’t have tracing).

Do we need a “serious” DB when our Grafana instance is very small (max 30 users, 1 datasource and about 50 dashboards)? We had never a issue with Grafana 9.2.1 and the sqlite DB.

rstudio · February 21, 2024, 12:47pm

Grafana Debug Logs

logger=auth.client.proxy t=2024-02-21T12:13:27.385371956Z level=warn msg="Could not resolved cached user" error="user not found" userId=29
logger=accesscontrol.service t=2024-02-21T12:13:27.403786297Z level=debug msg="Cache permissions" key=rbac-permissions-1-user-1
logger=accesscontrol.service t=2024-02-21T12:13:27.404557689Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-1
logger=context userId=1 orgId=1 uname=<REDACTED_USERNAME> logger=context userId=1 orgId=1 uname=<REDACTED_USERNAME> logger=context userId=11 orgId=1 uname=<REDACTED_USERNAME> logger=context userId=11 orgId=1 uname=<REDACTED_USERNAME> logger=context userId=11 orgId=1 uname=<REDACTED_USERNAME> logger=context userId=11 orgId=1 uname=<REDACTED_USERNAME> logger=secrets t=2024-02-21T12:14:07.36198301Z level=debug msg="Removing expired data keys from cache..."
logger=secrets t=2024-02-21T12:14:07.362012879Z level=debug msg="Removing expired data keys from cache finished successfully"
logger=live t=2024-02-21T12:14:15.593809464Z level=debug msg="Client disconnected" user=29 client=13b6e9c5-5804-42ed-a4dc-2013ad555f1e reason="connection closed" elapsed=1m27.096209134s
logger=live t=2024-02-21T12:14:19.637470227Z level=debug msg="Client disconnected" user=1 client=bcf01e19-646a-450a-bddd-b82bdf4a3436 reason="connection closed" elapsed=1m25.201198915s
logger=user.sync t=2024-02-21T12:14:28.76915133Z level=error msg="Failed to fetch user" error="context canceled" auth_module=authproxy auth_id=exroh
logger=authn.service t=2024-02-21T12:14:28.769187812Z level=error msg="Failed to run post auth hook" client=auth.client.proxy id= error="[user.sync.internal] unable to retrieve user"
logger=context userId=0 orgId=0 uname=<REDACTED_USERNAME> logger=org.sync t=2024-02-21T12:14:28.784315895Z level=debug msg="Syncing organization roles" id=user:34 extOrgRoles=map[]
logger=org.sync t=2024-02-21T12:14:28.784349748Z level=debug msg="Not syncing organization roles since external user doesn't have any" id=user:34
logger=authn.service t=2024-02-21T12:14:28.787421304Z level=warn msg="Failed to authenticate request" client=auth.client.basic error="context canceled"
logger=context userId=0 orgId=0 uname=<REDACTED_USERNAME> logger=context userId=0 orgId=0 uname=<REDACTED_USERNAME> logger=authn.service t=2024-02-21T12:14:28.846229992Z level=warn msg="Failed to authenticate request" client=auth.client.session error="context canceled"
logger=context userId=0 orgId=0 uname=<REDACTED_USERNAME> logger=context userId=0 orgId=0 uname=<REDACTED_USERNAME> logger=context userId=1 orgId=1 uname=<REDACTED_USERNAME> logger=context userId=1 orgId=1 uname=<REDACTED_USERNAME> logger=authn.service t=2024-02-21T12:14:28.936639688Z level=warn msg="Failed to authenticate request" client=auth.client.basic error="context canceled"
logger=context userId=0 orgId=0 uname=<REDACTED_USERNAME> logger=context userId=0 orgId=0 uname=<REDACTED_USERNAME> logger=accesscontrol.service t=2024-02-21T12:14:28.954704081Z level=debug msg="Fetch permissions from store" key=rbac-permissions-1-user-34
logger=ngalert.notifier.alertmanager 1=(MISSING) t=2024-02-21T12:14:29.049687386Z level=debug msg="Neither config nor template have changed, skipping configuration sync."
logger=authn.service t=2024-02-21T12:14:29.053497459Z level=warn msg="Failed to authenticate request" client=auth.client.basic error="context canceled"
logger=context userId=0 orgId=0 uname=<REDACTED_USERNAME> logger=context userId=0 orgId=0 uname=<REDACTED_USERNAME> logger=authn.service t=2024-02-21T12:14:29.064080245Z level=warn msg="Failed to authenticate request" client=auth.client.session error="context canceled"
logger=context userId=0 orgId=0 uname=<REDACTED_USERNAME> logger=authn.service t=2024-02-21T12:14:29.135547146Z level=warn msg="Failed to authenticate request" client=auth.client.basic error="context canceled"
logger=context userId=0 orgId=0 uname=<REDACTED_USERNAME> logger=context userId=0 orgId=0 uname=<REDACTED_USERNAME> logger=accesscontrol.service t=2024-02-21T12:14:29.137377523Z level=debug msg="Cache permissions" key=rbac-permissions-1-user-34
logger=auth.client.proxy t=2024-02-21T12:14:29.137449587Z level=debug msg="Cache proxy user" userId=34
logger=auth.client.proxy t=2024-02-21T12:14:29.139548173Z level=debug msg="User was loaded from cache, skip syncs" userId=6
logger=accesscontrol.service t=2024-02-21T12:14:29.139610119Z level=debug msg="Fetch permissions from store" key=rbac-permissions-1-user-6
logger=auth.client.proxy t=2024-02-21T12:14:29.142961077Z level=debug msg="User was loaded from cache, skip syncs" userId=6
logger=accesscontrol.service t=2024-02-21T12:14:29.143001234Z level=debug msg="Fetch permissions from store" key=rbac-permissions-1-user-6
logger=auth.client.proxy t=2024-02-21T12:14:29.143629483Z level=debug msg="User was loaded from cache, skip syncs" userId=6
logger=accesscontrol.service t=2024-02-21T12:14:29.143660092Z level=debug msg="Fetch permissions from store" key=rbac-permissions-1-user-6
logger=context userId=34 orgId=1 uname=<REDACTED_USERNAME> logger=context userId=34 orgId=1 uname=<REDACTED_USERNAME> logger=accesscontrol.service t=2024-02-21T12:14:29.147012124Z level=debug msg="Cache permissions" key=rbac-permissions-1-user-6
logger=datasources t=2024-02-21T12:14:29.147218318Z level=debug msg="Querying for data source via SQL store" uid=prometheus orgId=1
logger=query_data t=2024-02-21T12:14:29.150333936Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=query_data t=2024-02-21T12:14:29.150401484Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=secrets.kvstore t=2024-02-21T12:14:29.150748228Z level=debug msg="got secret value" orgId=1 type=datasource namespace=prometheus
logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=auth.client.proxy t=2024-02-21T12:14:29.151385902Z level=debug msg="User was loaded from cache, skip syncs" userId=6
logger=accesscontrol.service t=2024-02-21T12:14:29.151422293Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-6
logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=query_data t=2024-02-21T12:14:29.151563398Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=secrets.kvstore t=2024-02-21T12:14:29.151618279Z level=debug msg="got secret value from cache" orgId=1 type=datasource namespace=prometheus
logger=context userId=6 orgId=1 uname=<REDACTED_USERNAME> logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=context userId=6 orgId=1 uname=<REDACTED_USERNAME> logger=ngalert.multiorg.alertmanager t=2024-02-21T12:14:29.235005875Z level=debug msg="Done synchronizing Alertmanagers for orgs"
logger=auth.client.proxy t=2024-02-21T12:14:29.23647468Z level=debug msg="User was loaded from cache, skip syncs" userId=11
logger=accesscontrol.service t=2024-02-21T12:14:29.236507927Z level=debug msg="Fetch permissions from store" key=rbac-permissions-1-user-11
logger=accesscontrol.service t=2024-02-21T12:14:29.236790527Z level=debug msg="Cache permissions" key=rbac-permissions-1-user-6
logger=query_data t=2024-02-21T12:14:29.236946691Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=secrets.kvstore t=2024-02-21T12:14:29.237007064Z level=debug msg="got secret value from cache" orgId=1 type=datasource namespace=prometheus
logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=context userId=6 orgId=1 uname=<REDACTED_USERNAME> logger=accesscontrol.service t=2024-02-21T12:14:29.238358874Z level=debug msg="Fetch permissions from store" key=rbac-permissions-1-user-1
logger=auth.client.proxy t=2024-02-21T12:14:29.23947566Z level=debug msg="User was loaded from cache, skip syncs" userId=11
logger=accesscontrol.service t=2024-02-21T12:14:29.239499739Z level=debug msg="Fetch permissions from store" key=rbac-permissions-1-user-11
logger=ngalert.sender.router t=2024-02-21T12:14:29.244398919Z level=debug msg="Attempting to sync admin configs" count=0
logger=ngalert.sender.router t=2024-02-21T12:14:29.244423187Z level=debug msg="Finish of admin configuration sync"
logger=ngalert.scheduler t=2024-02-21T12:14:<REDACTED_IP>9Z level=debug msg="Alert rules fetched" rulesCount=0 foldersCount=0 updatedRules=0
logger=auth.client.proxy t=2024-02-21T12:14:29.246532837Z level=debug msg="User was loaded from cache, skip syncs" userId=6
logger=accesscontrol.service t=2024-02-21T12:14:29.246563653Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-6
logger=query_data t=2024-02-21T12:14:29.246731017Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=secrets.kvstore t=2024-02-21T12:14:29.246841912Z level=debug msg="got secret value from cache" orgId=1 type=datasource namespace=prometheus
logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=auth.client.proxy t=2024-02-21T12:14:29.247352329Z level=debug msg="User was loaded from cache, skip syncs" userId=11
logger=accesscontrol.service t=2024-02-21T12:14:29.247377317Z level=debug msg="Fetch permissions from store" key=rbac-permissions-1-user-11
logger=auth.client.proxy t=2024-02-21T12:14:29.247586025Z level=debug msg="User was loaded from cache, skip syncs" userId=6
logger=accesscontrol.service t=2024-02-21T12:14:29.247610568Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-6
logger=accesscontrol.service t=2024-02-21T12:14:29.247983312Z level=debug msg="Cache permissions" key=rbac-permissions-1-user-11
logger=query_data t=2024-02-21T12:14:29.248085575Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=secrets.kvstore t=2024-02-21T12:14:29.248125713Z level=debug msg="got secret value from cache" orgId=1 type=datasource namespace=prometheus
logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=auth.client.proxy t=2024-02-21T12:14:29.248403869Z level=debug msg="User was loaded from cache, skip syncs" userId=11
logger=context userId=11 orgId=1 uname=<REDACTED_USERNAME> logger=accesscontrol.service t=2024-02-21T12:14:29.248427183Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-11
logger=query_data t=2024-02-21T12:14:29.248518682Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=secrets.kvstore t=2024-02-21T12:14:29.248555454Z level=debug msg="got secret value from cache" orgId=1 type=datasource namespace=prometheus
logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=auth.client.proxy t=2024-02-21T12:14:29.248930721Z level=debug msg="User was loaded from cache, skip syncs" userId=11
logger=accesscontrol.service t=2024-02-21T12:14:29.248965519Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-11
logger=user.sync t=2024-02-21T12:14:29.249549326Z level=error msg="Failed to fetch user" error="context canceled" auth_module=authproxy auth_id=exroh
logger=authn.service t=2024-02-21T12:14:29.249578996Z level=error msg="Failed to run post auth hook" client=auth.client.proxy id= error="[user.sync.internal] unable to retrieve user"
logger=context userId=0 orgId=0 uname=<REDACTED_USERNAME> logger=user.sync t=2024-02-21T12:14:29.250277743Z level=error msg="Failed to fetch user" error="context canceled" auth_module=authproxy auth_id=ubjsp
logger=authn.service t=2024-02-21T12:14:29.250301162Z level=error msg="Failed to run post auth hook" client=auth.client.proxy id= error="[user.sync.internal] unable to retrieve user"
logger=context userId=0 orgId=0 uname=<REDACTED_USERNAME> logger=context userId=0 orgId=0 uname=<REDACTED_USERNAME> logger=user.sync t=2024-02-21T12:14:29.250532635Z level=error msg="Failed to fetch user" error="context canceled" auth_module=authproxy auth_id=exroh
logger=authn.service t=2024-02-21T12:14:29.250553958Z level=error msg="Failed to run post auth hook" client=auth.client.proxy id= error="[user.sync.internal] unable to retrieve user"
logger=context userId=0 orgId=0 uname=<REDACTED_USERNAME> logger=user.sync t=2024-02-21T12:14:29.251111567Z level=error msg="Failed to fetch user" error="context canceled" auth_module=authproxy auth_id=eotmr
logger=authn.service t=2024-02-21T12:14:29.251127378Z level=error msg="Failed to run post auth hook" client=auth.client.proxy id= error="[user.sync.internal] unable to retrieve user"
logger=context userId=0 orgId=0 uname=<REDACTED_USERNAME> logger=context userId=0 orgId=0 uname=<REDACTED_USERNAME> logger=auth.client.proxy t=2024-02-21T12:14:29.251516093Z level=debug msg="User was loaded from cache, skip syncs" userId=6
logger=accesscontrol.service t=2024-02-21T12:14:29.251533444Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-6
logger=query_data t=2024-02-21T12:14:29.251690793Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=query_data t=2024-02-21T12:14:29.251717047Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=secrets.kvstore t=2024-02-21T12:14:29.251740438Z level=debug msg="got secret value from cache" orgId=1 type=datasource namespace=prometheus
logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=context userId=6 orgId=1 uname=<REDACTED_USERNAME> logger=context userId=6 orgId=1 uname=<REDACTED_USERNAME> logger=ngalert.scheduler t=2024-02-21T12:14:29.256068811Z level=debug msg="Alert rules fetched" rulesCount=0 foldersCount=0 updatedRules=0
logger=auth.client.proxy t=2024-02-21T12:14:29.256222305Z level=debug msg="User was loaded from cache, skip syncs" userId=6
logger=accesscontrol.service t=2024-02-21T12:14:29.256247052Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-6
logger=query_data t=2024-02-21T12:14:29.256354565Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=query_data t=2024-02-21T12:14:29.256384667Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=secrets.kvstore t=2024-02-21T12:14:29.256410212Z level=debug msg="got secret value from cache" orgId=1 type=datasource namespace=prometheus
logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=ngalert.scheduler t=2024-02-21T12:14:29.256882049Z level=debug msg="Alert rules fetched" rulesCount=0 foldersCount=0 updatedRules=0
logger=ngalert.scheduler t=2024-02-21T12:14:29.25744902Z level=debug msg="Alert rules fetched" rulesCount=0 foldersCount=0 updatedRules=0
logger=ngalert.scheduler t=2024-02-21T12:14:29.257819855Z level=debug msg="Alert rules fetched" rulesCount=0 foldersCount=0 updatedRules=0
logger=accesscontrol.service t=2024-02-21T12:14:29.261185202Z level=debug msg="Cache permissions" key=rbac-permissions-1-user-1
logger=accesscontrol.service t=2024-02-21T12:14:29.261640838Z level=debug msg="Cache permissions" key=rbac-permissions-1-user-11
logger=query_data t=2024-02-21T12:14:29.26184106Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=secrets.kvstore t=2024-02-21T12:14:29.261888614Z level=debug msg="got secret value from cache" orgId=1 type=datasource namespace=prometheus
logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=accesscontrol.service t=2024-02-21T12:14:29.337872032Z level=debug msg="Cache permissions" key=rbac-permissions-1-user-11
logger=context userId=11 orgId=1 uname=<REDACTED_USERNAME> logger=query_data t=2024-02-21T12:14:29.338079988Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=context userId=11 orgId=1 uname=<REDACTED_USERNAME> logger=authn.service t=2024-02-21T12:14:29.339105952Z level=warn msg="Failed to authenticate request" client=auth.client.basic error="context canceled"
logger=context userId=0 orgId=0 uname=<REDACTED_USERNAME> logger=context userId=0 orgId=0 uname=<REDACTED_USERNAME> logger=ngalert.scheduler t=2024-02-21T12:14:29.339777875Z level=debug msg="Alert rules fetched" rulesCount=0 foldersCount=0 updatedRules=0
logger=auth.client.proxy t=2024-02-21T12:14:29.343354739Z level=debug msg="User was loaded from cache, skip syncs" userId=6
logger=accesscontrol.service t=2024-02-21T12:14:29.343440424Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-6
logger=query_data t=2024-02-21T12:14:29.343640256Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=secrets.kvstore t=2024-02-21T12:14:29.343754151Z level=debug msg="got secret value from cache" orgId=1 type=datasource namespace=prometheus
logger=auth.client.proxy t=2024-02-21T12:14:29.343933253Z level=debug msg="User was loaded from cache, skip syncs" userId=6
logger=accesscontrol.service t=2024-02-21T12:14:29.343967056Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-6
logger=auth.client.proxy t=2024-02-21T12:14:29.344072309Z level=debug msg="User was loaded from cache, skip syncs" userId=6
logger=accesscontrol.service t=2024-02-21T12:14:29.344112444Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-6
logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=query_data t=2024-02-21T12:14:29.344256949Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=query_data t=2024-02-21T12:14:29.344254157Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=secrets.kvstore t=2024-02-21T12:14:29.34429837Z level=debug msg="got secret value from cache" orgId=1 type=datasource namespace=prometheus
logger=secrets.kvstore t=2024-02-21T12:14:29.344329698Z level=debug msg="got secret value from cache" orgId=1 type=datasource namespace=prometheus
logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=secrets.kvstore t=2024-02-21T12:14:29.344788948Z level=debug msg="got secret value from cache" orgId=1 type=datasource namespace=prometheus
logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=auth.client.proxy t=2024-02-21T12:14:29.347505331Z level=debug msg="User was loaded from cache, skip syncs" userId=34
logger=accesscontrol.service t=2024-02-21T12:14:29.347534579Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-34
logger=context userId=6 orgId=1 uname=<REDACTED_USERNAME> logger=accesscontrol.service t=2024-02-21T12:14:29.348316512Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-1
logger=authn.service t=2024-02-21T12:14:29.349434948Z level=warn msg="Failed to authenticate request" client=auth.client.basic error="context canceled"
logger=context userId=0 orgId=0 uname=<REDACTED_USERNAME> logger=context userId=0 orgId=0 uname=<REDACTED_USERNAME> logger=accesscontrol.service t=2024-02-21T12:14:29.350412246Z level=debug msg="Cache permissions" key=rbac-permissions-1-user-6
logger=query_data t=2024-02-21T12:14:29.350531764Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=query_data t=2024-02-21T12:14:29.350565388Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=secrets.kvstore t=2024-02-21T12:14:29.350592231Z level=debug msg="got secret value from cache" orgId=1 type=datasource namespace=prometheus
logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=accesscontrol.evaluator t=2024-02-21T12:14:29.355198312Z level=debug msg="Matched scope" userscope=settings:* targetscope=settings:*
logger=accesscontrol.service t=2024-02-21T12:14:29.355226526Z level=debug msg="Fetch permissions from store" key=rbac-permissions-0-user-1
logger=accesscontrol.service t=2024-02-21T12:14:29.356292496Z level=debug msg="Fetch permissions from store" key=rbac-permissions-0-user-34
logger=accesscontrol.service t=2024-02-21T12:14:29.357312706Z level=debug msg="Cache permissions" key=rbac-permissions-0-user-1
logger=accesscontrol.evaluator t=2024-02-21T12:14:29.357389354Z level=debug msg="Matched scope" userscope=settings:* targetscope=settings:*
logger=accesscontrol.service t=2024-02-21T12:14:29.35787482Z level=debug msg="Cache permissions" key=rbac-permissions-0-user-34
logger=accesscontrol t=2024-02-21T12:14:29.357899073Z level=debug msg="No permissions set for entity" namespace=user id=34 orgID=0 login=exroh
logger=context userId=6 orgId=1 uname=<REDACTED_USERNAME> logger=accesscontrol.service t=2024-02-21T12:14:29.359027921Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-1
logger=accesscontrol.service t=2024-02-21T12:14:29.359144166Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-34
logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=context userId=1 orgId=1 uname=<REDACTED_USERNAME> logger=context userId=34 orgId=1 uname=<REDACTED_USERNAME> logger=context userId=11 orgId=1 uname=<REDACTED_USERNAME> logger=accesscontrol.service t=2024-02-21T12:14:29.363306157Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-1
logger=auth.client.proxy t=2024-02-21T12:14:29.366753484Z level=debug msg="User was loaded from cache, skip syncs" userId=6
logger=accesscontrol.service t=2024-02-21T12:14:29.366782676Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-6
logger=query_data t=2024-02-21T12:14:29.366893348Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=secrets.kvstore t=2024-02-21T12:14:29.366940659Z level=debug msg="got secret value from cache" orgId=1 type=datasource namespace=prometheus
logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=context userId=6 orgId=1 uname=<REDACTED_USERNAME> logger=accesscontrol.evaluator t=2024-02-21T12:14:29.377463773Z level=debug msg="Matched scope" userscope=settings:* targetscope=settings:*
logger=accesscontrol.service t=2024-02-21T12:14:29.377503852Z level=debug msg="Using cached permissions" key=rbac-permissions-0-user-1
logger=accesscontrol.evaluator t=2024-02-21T12:14:29.377570214Z level=debug msg="Matched scope" userscope=settings:* targetscope=settings:*
logger=auth.client.proxy t=2024-02-21T12:14:29.378257028Z level=debug msg="User was loaded from cache, skip syncs" userId=34
logger=accesscontrol.service t=2024-02-21T12:14:29.378290078Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-34
logger=auth.client.proxy t=2024-02-21T12:14:29.378437635Z level=debug msg="User was loaded from cache, skip syncs" userId=6
logger=accesscontrol.service t=2024-02-21T12:14:29.378466234Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-6
logger=query_data t=2024-02-21T12:14:29.378570329Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=secrets.kvstore t=2024-02-21T12:14:29.378624633Z level=debug msg="got secret value from cache" orgId=1 type=datasource namespace=prometheus
logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=accesscontrol.service t=2024-02-21T12:14:29.379106858Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-1
logger=context userId=6 orgId=1 uname=<REDACTED_USERNAME> logger=context userId=1 orgId=1 uname=<REDACTED_USERNAME> logger=context userId=1 orgId=1 uname=<REDACTED_USERNAME> logger=auth.client.proxy t=2024-02-21T12:14:29.386492856Z level=debug msg="User was loaded from cache, skip syncs" userId=6
logger=accesscontrol.service t=2024-02-21T12:14:29.386533743Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-6
logger=query_data t=2024-02-21T12:14:29.386776054Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=secrets.kvstore t=2024-02-21T12:14:29.386846305Z level=debug msg="got secret value from cache" orgId=1 type=datasource namespace=prometheus
logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=accesscontrol.service t=2024-02-21T12:14:29.392587482Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-1
logger=accesscontrol.service t=2024-02-21T12:14:29.394341631Z level=debug msg="Using cached permissions" key=rbac-permissions-0-user-34
logger=accesscontrol t=2024-02-21T12:14:29.394369886Z level=debug msg="No permissions set for entity" namespace=user id=34 orgID=0 login=exroh
logger=accesscontrol.service t=2024-02-21T12:14:29.434903064Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-34
logger=context userId=34 orgId=1 uname=<REDACTED_USERNAME> logger=auth.client.proxy t=2024-02-21T12:14:29.44375023Z level=debug msg="User was loaded from cache, skip syncs" userId=6
logger=accesscontrol.service t=2024-02-21T12:14:29.4437934Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-6
logger=query_data t=2024-02-21T12:14:29.443957257Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=secrets.kvstore t=2024-02-21T12:14:29.444005718Z level=debug msg="got secret value from cache" orgId=1 type=datasource namespace=prometheus
logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=context userId=6 orgId=1 uname=<REDACTED_USERNAME> logger=auth.client.proxy t=2024-02-21T12:14:29.47615612Z level=debug msg="User was loaded from cache, skip syncs" userId=6
logger=accesscontrol.service t=2024-02-21T12:14:29.476193358Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-6
logger=query_data t=2024-02-21T12:14:29.47630305Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=secrets.kvstore t=2024-02-21T12:14:29.476347666Z level=debug msg="got secret value from cache" orgId=1 type=datasource namespace=prometheus
logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=context userId=1 orgId=1 uname=<REDACTED_USERNAME> logger=context userId=6 orgId=1 uname=<REDACTED_USERNAME> logger=context userId=11 orgId=1 uname=<REDACTED_USERNAME> logger=auth.client.proxy t=2024-02-21T12:14:29.532807183Z level=debug msg="User was loaded from cache, skip syncs" userId=6
logger=accesscontrol.service t=2024-02-21T12:14:29.5328517Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-6
logger=query_data t=2024-02-21T12:14:29.532978193Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=secrets.kvstore t=2024-02-21T12:14:29.533020394Z level=debug msg="got secret value from cache" orgId=1 type=datasource namespace=prometheus
logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=context userId=6 orgId=1 uname=<REDACTED_USERNAME> logger=auth.client.proxy t=2024-02-21T12:14:29.552424483Z level=debug msg="User was loaded from cache, skip syncs" userId=6
logger=accesscontrol.service t=2024-02-21T12:14:29.552462546Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-6
logger=query_data t=2024-02-21T12:14:29.552570336Z level=debug msg="Processing metrics query" query="unsupported value type"
logger=secrets.kvstore t=2024-02-21T12:14:29.552610336Z level=debug msg="got secret value from cache" orgId=1 type=datasource namespace=prometheus
logger=tsdb.prometheus endpoint=queryData pluginId=prometheus dsName=prometheus dsUID=prometheus uname=<REDACTED_USERNAME> logger=accesscontrol.service t=2024-02-21T12:14:29.555360973Z level=debug msg="Using cached permissions" key=rbac-permissions-1-user-1
logger=accesscontrol.evaluator t=2024-02-21T12:14:29.565268287Z level=debug msg="Matched scope" userscope=dashboards:* targetscope=dashboards:uid:communityApiJvmDashboard

The error “Grafana hangs” at 12:14.04:

oc get events --sort-by='.metadata.creationTimestamp' -o custom-columns=FirstSeen:.firstTimestamp,LastSeen:.lastTimestamp,Count:.count,From:.source.component,Type:.type,Reason:.reason,Message:.message | grep failed

FirstSeen              LastSeen               Count    From                    Type      Reason              Message
2024-02-21T12:14:04Z   2024-02-21T12:19:04Z   5        kubelet                 Warning   Unhealthy           Readiness probe failed: Get "http://10.130.2.96:3000/api/health": context deadline exceeded (Client.Timeout exceeded while awaiting headers)

rstudio · February 21, 2024, 12:49pm

OpenShift oAuth-Proxy Container (sidecar) Logs

2024/02/21 12:10:06 provider.go:129: Defaulting client-id to system:serviceaccount:<REDACTED_COMPANY>-grafana:grafana-oauth-sa
2024/02/21 12:10:06 provider.go:134: Defaulting client-secret to service account token /var/run/secrets/kubernetes.io/serviceaccount/token
2024/02/21 12:10:06 oauthproxy.go:203: mapping path "/" => upstream "http://localhost:3000/"
2024/02/21 12:10:06 oauthproxy.go:224: compiled skip-auth-regex => "^/metrics"
2024/02/21 12:10:06 oauthproxy.go:230: OAuthProxy configured for  Client ID: system:serviceaccount:<REDACTED_COMPANY>-grafana:grafana-oauth-sa
2024/02/21 12:10:06 oauthproxy.go:240: Cookie settings: name:_oauth_proxy secure(https):true httponly:true expiry:168h0m0s domain:<default> samesite: refresh:disabled
2024/02/21 12:10:06 http.go:107: HTTPS: listening on [::]:9091
I0221 12:10:06.848246       1 dynamic_serving_content.go:130] Starting serving::/etc/tls/private/tls.crt::/etc/tls/private/tls.key
2024/02/21 12:10:39 provider.go:631: Performing OAuth discovery against https://<REDACTED_IP>/.well-known/oauth-authorization-server
2024/02/21 12:10:39 provider.go:671: 200 GET https://<REDACTED_IP>/.well-known/oauth-authorization-server {
  "issuer": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com",
  "authorization_endpoint": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com/oauth/authorize",
  "token_endpoint": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com/oauth/token",
  "scopes_supported": [
    "user:check-access",
    "user:full",
    "user:info",
    "user:list-projects",
    "user:list-scoped-projects"
  ],
  "response_types_supported": [
    "code",
    "token"
  ],
  "grant_types_supported": [
    "authorization_code",
    "implicit"
  ],
  "code_challenge_methods_supported": [
    "plain",
    "S256"
  ]
}
2024/02/21 12:10:41 provider.go:631: Performing OAuth discovery against https://<REDACTED_IP>/.well-known/oauth-authorization-server
2024/02/21 12:10:41 provider.go:671: 200 GET https://<REDACTED_IP>/.well-known/oauth-authorization-server {
  "issuer": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com",
  "authorization_endpoint": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com/oauth/authorize",
  "token_endpoint": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com/oauth/token",
  "scopes_supported": [
    "user:check-access",
    "user:full",
    "user:info",
    "user:list-projects",
    "user:list-scoped-projects"
  ],
  "response_types_supported": [
    "code",
    "token"
  ],
  "grant_types_supported": [
    "authorization_code",
    "implicit"
  ],
  "code_challenge_methods_supported": [
    "plain",
    "S256"
  ]
}
2024/02/21 12:10:41 provider.go:671: 200 GET https://<REDACTED_IP>/apis/user.openshift.io/v1/users/~ {"kind":"User","apiVersion":"user.openshift.io/v1","metadata":{<REDACTED_USER_OBJECT>}
2024/02/21 12:10:41 oauthproxy.go:684: <REDACTED_IP>:59816 authentication complete Session{<REDACTED_USERNAME>@cluster.local token:true}
2024/02/21 12:10:52 provider.go:631: Performing OAuth discovery against https://<REDACTED_IP>/.well-known/oauth-authorization-server
2024/02/21 12:10:52 provider.go:671: 200 GET https://<REDACTED_IP>/.well-known/oauth-authorization-server {
  "issuer": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com",
  "authorization_endpoint": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com/oauth/authorize",
  "token_endpoint": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com/oauth/token",
  "scopes_supported": [
    "user:check-access",
    "user:full",
    "user:info",
    "user:list-projects",
    "user:list-scoped-projects"
  ],
  "response_types_supported": [
    "code",
    "token"
  ],
  "grant_types_supported": [
    "authorization_code",
    "implicit"
  ],
  "code_challenge_methods_supported": [
    "plain",
    "S256"
  ]
}
2024/02/21 12:10:54 provider.go:631: Performing OAuth discovery against https://<REDACTED_IP>/.well-known/oauth-authorization-server
2024/02/21 12:10:54 provider.go:671: 200 GET https://<REDACTED_IP>/.well-known/oauth-authorization-server {
  "issuer": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com",
  "authorization_endpoint": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com/oauth/authorize",
  "token_endpoint": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com/oauth/token",
  "scopes_supported": [
    "user:check-access",
    "user:full",
    "user:info",
    "user:list-projects",
    "user:list-scoped-projects"
  ],
  "response_types_supported": [
    "code",
    "token"
  ],
  "grant_types_supported": [
    "authorization_code",
    "implicit"
  ],
  "code_challenge_methods_supported": [
    "plain",
    "S256"
  ]
}
2024/02/21 12:10:54 provider.go:671: 200 GET https://<REDACTED_IP>/apis/user.openshift.io/v1/users/~ {"kind":"User","apiVersion":"user.openshift.io/v1","metadata":{<REDACTED_USER_OBJECT>}
2024/02/21 12:10:54 oauthproxy.go:684: <REDACTED_IP>:53868 authentication complete Session{<REDACTED_USERNAME>@cluster.local token:true}
2024/02/21 12:11:02 provider.go:631: Performing OAuth discovery against https://<REDACTED_IP>/.well-known/oauth-authorization-server
2024/02/21 12:11:02 provider.go:671: 200 GET https://<REDACTED_IP>/.well-known/oauth-authorization-server {
  "issuer": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com",
  "authorization_endpoint": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com/oauth/authorize",
  "token_endpoint": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com/oauth/token",
  "scopes_supported": [
    "user:check-access",
    "user:full",
    "user:info",
    "user:list-projects",
    "user:list-scoped-projects"
  ],
  "response_types_supported": [
    "code",
    "token"
  ],
  "grant_types_supported": [
    "authorization_code",
    "implicit"
  ],
  "code_challenge_methods_supported": [
    "plain",
    "S256"
  ]
}
2024/02/21 12:11:18 provider.go:631: Performing OAuth discovery against https://<REDACTED_IP>/.well-known/oauth-authorization-server
2024/02/21 12:11:18 provider.go:671: 200 GET https://<REDACTED_IP>/.well-known/oauth-authorization-server {
  "issuer": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com",
  "authorization_endpoint": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com/oauth/authorize",
  "token_endpoint": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com/oauth/token",
  "scopes_supported": [
    "user:check-access",
    "user:full",
    "user:info",
    "user:list-projects",
    "user:list-scoped-projects"
  ],
  "response_types_supported": [
    "code",
    "token"
  ],
  "grant_types_supported": [
    "authorization_code",
    "implicit"
  ],
  "code_challenge_methods_supported": [
    "plain",
    "S256"
  ]
}
2024/02/21 12:11:18 provider.go:671: 200 GET https://<REDACTED_IP>/apis/user.openshift.io/v1/users/~ {"kind":"User","apiVersion":"user.openshift.io/v1","metadata":{<REDACTED_USER_OBJECT>}
2024/02/21 12:11:18 oauthproxy.go:684: <REDACTED_IP>:58898 authentication complete Session{<REDACTED_USERNAME>@cluster.local token:true}
2024/02/21 12:11:55 provider.go:631: Performing OAuth discovery against https://<REDACTED_IP>/.well-known/oauth-authorization-server
2024/02/21 12:11:55 provider.go:671: 200 GET https://<REDACTED_IP>/.well-known/oauth-authorization-server {
  "issuer": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com",
  "authorization_endpoint": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com/oauth/authorize",
  "token_endpoint": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com/oauth/token",
  "scopes_supported": [
    "user:check-access",
    "user:full",
    "user:info",
    "user:list-projects",
    "user:list-scoped-projects"
  ],
  "response_types_supported": [
    "code",
    "token"
  ],
  "grant_types_supported": [
    "authorization_code",
    "implicit"
  ],
  "code_challenge_methods_supported": [
    "plain",
    "S256"
  ]
}
2024/02/21 12:12:09 provider.go:631: Performing OAuth discovery against https://<REDACTED_IP>/.well-known/oauth-authorization-server
2024/02/21 12:12:09 provider.go:671: 200 GET https://<REDACTED_IP>/.well-known/oauth-authorization-server {
  "issuer": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com",
  "authorization_endpoint": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com/oauth/authorize",
  "token_endpoint": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com/oauth/token",
  "scopes_supported": [
    "user:check-access",
    "user:full",
    "user:info",
    "user:list-projects",
    "user:list-scoped-projects"
  ],
  "response_types_supported": [
    "code",
    "token"
  ],
  "grant_types_supported": [
    "authorization_code",
    "implicit"
  ],
  "code_challenge_methods_supported": [
    "plain",
    "S256"
  ]
}
2024/02/21 12:12:10 provider.go:671: 200 GET https://<REDACTED_IP>/apis/user.openshift.io/v1/users/~ {"kind":"User","apiVersion":"user.openshift.io/v1","metadata":{<REDACTED_USER_OBJECT>}
2024/02/21 12:12:10 oauthproxy.go:684: <REDACTED_IP>:60434 authentication complete Session{<REDACTED_USERNAME>@cluster.local token:true}
2024/02/21 12:12:45 provider.go:631: Performing OAuth discovery against https://<REDACTED_IP>/.well-known/oauth-authorization-server
2024/02/21 12:12:45 provider.go:671: 200 GET https://<REDACTED_IP>/.well-known/oauth-authorization-server {
  "issuer": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com",
  "authorization_endpoint": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com/oauth/authorize",
  "token_endpoint": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com/oauth/token",
  "scopes_supported": [
    "user:check-access",
    "user:full",
    "user:info",
    "user:list-projects",
    "user:list-scoped-projects"
  ],
  "response_types_supported": [
    "code",
    "token"
  ],
  "grant_types_supported": [
    "authorization_code",
    "implicit"
  ],
  "code_challenge_methods_supported": [
    "plain",
    "S256"
  ]
}
2024/02/21 12:12:47 provider.go:631: Performing OAuth discovery against https://<REDACTED_IP>/.well-known/oauth-authorization-server
2024/02/21 12:12:47 provider.go:671: 200 GET https://<REDACTED_IP>/.well-known/oauth-authorization-server {
  "issuer": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com",
  "authorization_endpoint": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com/oauth/authorize",
  "token_endpoint": "https://oauth-openshift.apps.<REDACTED_CLUSTER>.ocp.<REDACTED_COMPANY>.com/oauth/token",
  "scopes_supported": [
    "user:check-access",
    "user:full",
    "user:info",
    "user:list-projects",
    "user:list-scoped-projects"
  ],
  "response_types_supported": [
    "code",
    "token"
  ],
  "grant_types_supported": [
    "authorization_code",
    "implicit"
  ],
  "code_challenge_methods_supported": [
    "plain",
    "S256"
  ]
}
2024/02/21 12:12:47 provider.go:671: 200 GET https://<REDACTED_IP>/apis/user.openshift.io/v1/users/~ {"kind":"User","apiVersion":"user.openshift.io/v1","metadata":{<REDACTED_USER_OBJECT>}
2024/02/21 12:12:47 oauthproxy.go:684: <REDACTED_IP>:58790 authentication complete Session{<REDACTED_USERNAME>@cluster.local token:true}
2024/02/21 12:13:29 reverseproxy.go:491: http: proxy error: context canceled
2024/02/21 12:13:35 reverseproxy.go:491: http: proxy error: context canceled
2024/02/21 12:13:39 reverseproxy.go:491: http: proxy error: context canceled
2024/02/21 12:14:01 reverseproxy.go:491: http: proxy error: context canceled
2024/02/21 12:14:09 reverseproxy.go:491: http: proxy error: context canceled
2024/02/21 12:14:09 reverseproxy.go:491: http: proxy error: context canceled
2024/02/21 12:14:09 reverseproxy.go:491: http: proxy error: context canceled
2024/02/21 12:14:15 reverseproxy.go:491: http: proxy error: context canceled
2024/02/21 12:14:25 reverseproxy.go:491: http: proxy error: context canceled
2024/02/21 12:14:25 reverseproxy.go:491: http: proxy error: context canceled
2024/02/21 12:14:25 reverseproxy.go:491: http: proxy error: context canceled
2024/02/21 12:14:25 reverseproxy.go:491: http: proxy error: context canceled
2024/02/21 12:14:25 reverseproxy.go:491: http: proxy error: context canceled

rstudio · February 27, 2024, 7:08am

I tried to enable Grafana tracing, but it seems not really working with the browser.

rstudio · February 27, 2024, 10:35am

At the moment it looks better if I increase sync_ttl (but this more a workaround):

    auth.proxy:
      enabled: "true"
      enable_login_token: "true"
      auto_sign_up: "true"
      sync_ttl: "1440"

Since I have increased sync_ttl to 1440 and we no longer have the problem, but does anyone have any idea how I can fix this permanently?

rstudio · May 1, 2024, 6:15am

I have the same issue with Azure OAuth2 as authentication provider.

Topic		Replies	Views
Grafana timing out when querying Prometheus datasource Prometheus	1	9113	August 5, 2021
Grafana timing out when querying Elastic datasource Grafana	1	1439	April 6, 2022
[Help] Grafana logs out random Grafana	3	1535	August 12, 2020
Grafana login page logs out immediately Configuration backend-platform , ha-grafana , login , nginx	1	886	August 17, 2022
Hosted Grafana: Authorization Failed Grafana Cloud	21	3371	May 27, 2025