Requests to auth-tokens/rotate on very fast succession

  • What Grafana version and what operating system are you using?
    Grafana v10.4.2 (22809dea50) on Debian VM

  • What happened?
    After logging in as admin, the browser gets bogged down. Checking the Network Dev Tools tab, is possible to see a very large of requests to http://localhost:4000/api/user/auth-tokens/rotate on very fast succession.

Sometimes, editing a dashboard fails:

Server Logs:

logger=authn.service t=2024-05-13T18:21:20.129330576Z level=warn msg="Failed to authenticate request" client=auth.client.session error="user token not found"
logger=context userId=0 orgId=0 uname= t=2024-05-13T18:21:20.130379532Z level=warn msg=Unauthorized error="user token not found" remote_addr=10.0.2.2 traceID=
logger=context userId=0 orgId=0 uname= t=2024-05-13T18:21:20.131209455Z level=info msg="Request Completed" method=POST path=/api/datasources/proxy/uid/edllt6vkh8f7kf/api/v1/query_range status=401 remote_addr=10.0.2.2 time_ms=61 duration=61.235832ms size=40 referer="http://localhost:4000/d/bdlltkqolc9hce/energy?editPanel=2&from=now-24h&orgId=1&to=now" handler=/api/datasources/proxy/uid/:uid/* status_source=server
logger=authn.service t=2024-05-13T18:21:20.277162728Z level=warn msg="Failed to authenticate request" client=auth.client.session error="user token not found"
logger=context userId=0 orgId=0 uname= t=2024-05-13T18:21:20.279412732Z level=error msg=Unauthorized error="user token not found" remote_addr=10.0.2.2 traceID=
logger=context userId=0 orgId=0 uname= t=2024-05-13T18:21:20.279783761Z level=info msg="Request Completed" method=POST path=/api/user/auth-tokens/rotate status=401 remote_addr=10.0.2.2 time_ms=135 duration=135.056663ms size=39 referer="http://localhost:4000/d/bdlltkqolc9hce/energy?editPanel=2&from=now-24h&orgId=1&to=now" handler=/api/user/auth-tokens/rotate status_source=server
logger=context userId=0 orgId=0 uname= t=2024-05-13T18:21:20.548517227Z level=info msg="Request Completed" method=GET path=/api/datasources/3 status=401 remote_addr=10.0.2.2 time_ms=112 duration=112.515364ms size=105 referer="http://localhost:4000/d/bdlltkqolc9hce/energy?editPanel=2&from=now-24h&orgId=1&to=now" handler=/api/datasources/:id status_source=server
logger=authn.service t=2024-05-13T18:21:20.669155714Z level=warn msg="Failed to authenticate request" client=auth.client.session error="user token not found"
logger=context userId=0 orgId=0 uname= t=2024-05-13T18:21:20.67082543Z level=warn msg=Unauthorized error="user token not found" remote_addr=10.0.2.2 traceID=
logger=context userId=0 orgId=0 uname= t=2024-05-13T18:21:20.674594644Z level=info msg="Request Completed" method=GET path=/api/datasources/proxy/3/api/v1/label/__name__/values status=401 remote_addr=10.0.2.2 time_ms=170 duration=170.818281ms size=40 referer="http://localhost:4000/d/bdlltkqolc9hce/energy?editPanel=2&from=now-24h&orgId=1&to=now" handler=/api/datasources/proxy/:id/* status_source=server
logger=context userId=1 orgId=1 uname=admin t=2024-05-13T18:21:21.728251575Z level=info msg="Request Completed" method=GET path=/api/live/ws status=-1 remote_addr=10.0.2.2 time_ms=11 duration=11.644112ms size=0 referer= handler=/api/live/ws status_source=server
  • What did you expect to happen?
    For auth key requests to not be repeated so fast.

As a followup:
I noticed that the server was having issues with keeping time. So I guess that it was checking that grafana_session_expiry was always in the past (at least for the browser perspective).

1 Like