[Solved] Infinite refresh loop in browser clients, with "Invalid or expired session" log error spam

Summary

Since upgrading to 3.9.0 we’re seeing a lot of “Invalid or expired session” errors which are filling the logs.

Steps to reproduce

Server 3.9.0, Chrome clients - otherwise conditions not very clear.

Expected behavior

Clean logs! I wouldn’t expect an error in the log under normal conditions.

Observed behavior

Example log excerpt, repeating approximately once every second:

[2017/05/23 19:54:47 AEST] [EROR] /api/v4/users/me: code=401 rid=i74txnzwgibpijajos13z9upwh uid= ip=10.130.64.120 Invalid or expired session, please login again. [details: UserRequired]
[2017/05/23 19:54:47 AEST] [EROR] /api/v4/users/me/preferences: code=401 rid=w358uj96oj8ajgwa78skbdg3ir uid= ip=10.130.64.120 Invalid or expired session, please login again. [details: UserRequired]
[2017/05/23 19:54:47 AEST] [EROR] /api/v4/users/me/teams: code=401 rid=17bizdxaifyqpkb964uwbe75zc uid= ip=10.130.64.120 Invalid or expired session, please login again. [details: UserRequired]
[2017/05/23 19:54:47 AEST] [EROR] /api/v4/users/me/teams/members: code=401 rid=8qauua4kstrh9qgjke8zja6f1e uid= ip=10.130.64.120 Invalid or expired session, please login again. [details: UserRequired]
[2017/05/23 19:54:48 AEST] [EROR] /api/v4/channels/members/me/view: code=401 rid=k611ma686fnmuyhbceg5traajw uid= ip=10.130.64.120 Invalid or expired session, please login again. [details: UserRequired]

We are seeing this from various source IPs. It looks as if the browser client is in a refresh loop of some sort. Needless to say our logs are getting pretty large.

Users are now reporting seeing their Chrome clients stuck in an infinite refresh loop, correlated with this stream of errors in the log. A full refresh seems to fix it.

I am not sure if this only happens with sessions that were open before the upgrade, or if it can happen to any session.

Any ideas?

I saw this again today after a user changed their password in AD. I guess nobody else has seen it…? :frowning:

Hi @gubbins,

What version did you upgrade from? I believe there may have been a known refresh loop in an older version of Mattermost, but I don’t think we’ve had that reported with any newer ones

Also, do you know what caused them to be logged out? Did they all get logged out when you upgraded, or was this just regular session expiry?

Hi @hmhealey,

We upgraded from 3.8.1. Nobody got logged out during the upgrade. As for affected sessions, I am not even sure they were logged out - they just started doing this for no reason the user was aware of. Maybe all the affected sessions are ones that just expired, I am not sure.

Hi @gubbins,

Thanks for your feedback,

Could I ask you help to monitor the issue and if you continue to see random users logged out, please let us know and we can troubleshoot further?

You could also try changing the setting for session length in the system console.

We are also facing the same issue. Any help would be great.

We are still seeing the infinite refresh loops and corresponding log spam. I see 3.10 is tagged so I might wait for that upgrade and see if it looks better.

@lindy65 just to be clear, I do not believe anyone is getting logged out unexpectedly - session expiry etc seem to be fine. That’s not the issue. The issue is the infinite refresh loop, which prevents users from logging back in at all and spams the logs! Some users are forced to use incognito tabs to access mattermost when they are affected.

Hi @gubbins and @vayenampudi,

Thanks for your feedback,

v3.10 has been released and you can find the download links here.

Could you try upgrading and let us know if your issue still persists thereafter?

Hello Lindy65,
I will be upgrading MM to 3.10.0 this Friday and I will let you know how it goes.

VK

I upgraded to 3.10.0 a few days ago and have seen one example of the issue in the logs since then.

Thanks @gubbins,

Let us know if this issue persists and we’ll troubleshoot further.

After the upgrade, our environment got way better and stable. But I still see some logs a few times. Our users are not getting the 500 error anymore.

I am still seeing the same symptoms every few days. It seems to be getting less frequent (perhaps as old sessions expire naturally?)

That’s good to know that it’s clearing up, even if we haven’t found any steps to reproduce it. Let us know if you come across anything else

@hmhealey We encountered the same issue today. A user reported it and I took a look with him. Same conditions:

  • chrome appears to start rendering the page, then resets and starts again, and keeps doing that forever
    • we conclude from this that it’s not a loop of redirected URLs, it’s a loop occurring in the javascript
  • log reports Invalid or expired session in a loop while this is occurring

We confirmed that we can fix it by clearing all cached data in Chrome related to the mattermost site (so it then creates a new session).

Just to be clear once again - the issue is not that the user was logged out (quite possibly their session had indeed reached its expiry date, in which case, this is completely normal); the issue is that the user is unable to log back in because of the infinite refresh loop.

Sorry I don’t have any better information to help!

@gubbins That definitely sounds like something being caused by our app then. We have a few places we force a refresh (to have the client pick up new code or when it detects that its been logged out), so maybe it’s one of those that’s not working correctly. Next time a user has their browser start looping, can you open the Chrome developer tools (Ctrl+Shift+I on windows, Cmd+Alt+I on Mac) and check a few things for me?

  1. If you switch to the Console, is there anything logged when the page refreshes? You may need to click on the gear icon in the top right of the console and check the “Preserve log” checkbox to stop it from clearing every time the page reloads
  2. If you type the following into the Console, what is printed for each one?
    1. document.cookie
    2. localStorage.getItem('__logout__')
    3. sessionStorage.getItem('__logout__')
    4. localStorage.getItem('__login__')
    5. sessionStorage.getItem('__login__')

We have this problem with two users. Clearing session data did not work, unfortunately. The users had to create new accounts.

Another user hit this problem today. If it’s still looping tomorrow I will try to capture the information as requested above.

@hmhealey: I managed to capture some log messages in the Console during one of these refresh loops (attached).

I was unable to type the requested commands into the Console - the refresh was too fast and we could not get this to produce any output, sorry.