1437824 - Auth0 login sessions not lasting as long as expected

Status: RESOLVED FIXED

(Tree Management :: Treeherder, defect, P1)

Description

[Ed Morley [:emorley]]

Filed from:
https://groups.google.com/forum/#!topic/mozilla.dev.platform/PK_obIp20v8

Message from :philor...

> > - Treeherder session will stay alive as long as access to the site
> > happens once every 24 hours. 3 days session expiry is no longer in
> > effect.
> 
> This doesn't seem to be the case: I'm logged in when I go to bed, and 7
> hours later when I get up I'm logged out; I'm logged in when I leave for
> work, and 4.5 hours later when I get home on my lunch hour I'm logged out. 

Message from :bz...

> > - Treeherder session will stay alive as long as access to the site happens once every 24 hours. 3 days session expiry is no longer in effect.
> 
> This seems to not be working at all.  I just carefully recorded the last
> time I logged in to treeherder: 8:39pm, on Feb 12, 2018, US/Eastern time.
> 
> It is now 9:27pm on the same day.  I just loaded treeherder.  It's
> showing me logged out.
> 
> The login didn't even last for 1 hour.
> 
> Login was done via LDAP. 

Hassan, I don't suppose you could take a look? I'm guessing it may need some additional logging added to shed light on the cause.

Comment 1

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Andreea also got backed out several times during the last European night shift.

I hit the issue often yesterday in the European morning and around noon and noticed issue after I had set treeherder tabs from the previous day as active tabs - could this be related?

Using different single sign-on credentials on a different Mozilla site cause a logout from treeherder.

Comment 2

[Dustin J. Mitchell [:dustin] (he/him)]

(In reply to Sebastian Hengst [:aryx][:archaeopteryx] (needinfo on intermittent or backout) from comment #1)
> Using different single sign-on credentials on a different Mozilla site cause
> a logout from treeherder.

This part is known -- Auth0 sign-in is "browser-wide".  If you login as another Auth0 identity in another tab, that affects all tabs.

Comment 3

[Boris Zbarsky [:bzbarsky]]

I have _not_ been logging in as another Auth0 identity, fwiw.

Comment 4

[Aki Sasaki (not active)]

(In reply to Dustin J. Mitchell [:dustin] pronoun: he from comment #2)
> (In reply to Sebastian Hengst [:aryx][:archaeopteryx] (needinfo on
> intermittent or backout) from comment #1)
> > Using different single sign-on credentials on a different Mozilla site cause
> > a logout from treeherder.
> 
> This part is known -- Auth0 sign-in is "browser-wide".  If you login as
> another Auth0 identity in another tab, that affects all tabs.

https://addons.mozilla.org/en-US/firefox/addon/multi-account-containers/ ?
Then Auth0 sign-in will be container-wide.

Comment 5

[Dustin J. Mitchell [:dustin] (he/him)]

Yep, this bug is valid -- I just didn't want to confuse it with the multi-login situation.

Comment 6

[Treeherder GitHub Bugbot]

Commit pushed to master at https://github.com/mozilla/treeherder

https://github.com/mozilla/treeherder/commit/7b79be8fccc96fce76dcc4725023c776758a835d
Bug 1437824 - Add logging to help debug session issue (#3220)

* Add auth logging to backend

* Use .warn instead of .info so that it shows in production

* Use notifications as an attempt to debug Bug 1437824

Comment 7

[Phil Ringnalda (:philor)]

Even though we don't *always* repeat the same mistakes, one thing to keep an eye out for would be the same thing that gave us short logins after treestatus switched to auth0, getting seconds and treating them as milliseconds, https://github.com/mozilla-releng/services/pull/702

Comment 8

[Hassan Ali (:hassan)]

The next time you get logged out, could you please:

- post a screenshot of the recent notifications menu (the bell icon beside the infra dropdown)
- let me know whether you had more than a single Treeherder tab open when the issue occurred

Comment 9

[Boris Zbarsky [:bzbarsky]]

> - post a screenshot of the recent notifications menu (the bell icon beside the infra dropdown)

Here's what I see in there when I just load treeherder for inbound:

 2/14/18 10:10 AM User either is not authenticated in the back-end or there has been some race condition with localStorage
 2/14/18 10:10 AM User is authenticated in the back-end on page load
 2/14/18 10:10 AM User either is not authenticated in the back-end or there has been some race condition with localStorage
 2/14/18 10:10 AM User is authenticated in the back-end on page load
 2/13/18 10:40 PM User either is not authenticated in the back-end or there has been some race condition with localStorage
 2/13/18 10:40 PM User is authenticated in the back-end on page load 

I can get you a screenshot if it would be really useful.

> - let me know whether you had more than a single Treeherder tab open when the issue occurred

I have 15 treeherder tabs open, but I'm not sure how many of them are actually loaded/restored.  Definitely not all, but it could well be more than 1.

Comment 10

[Phil Ringnalda (:philor)]

Attachment: Notification screen shot

For me, it'll always be at least six tabs open. Computer would have been asleep starting around 00:15, and the significance of 04:21 is probably that my cat tried to wake me up by "accidentally" stepping on the keyboard and waking the computer up then.

Comment 11

[Boris Zbarsky [:bzbarsky]]

More data, starting where the other one picked up:

 2/14/18 10:42 AM User either is not authenticated in the back-end or there has been some race condition with localStorage
 2/14/18 10:42 AM User is authenticated in the back-end on page load 
 2/14/18 10:41 AM User either is not authenticated in the back-end or there has been some race condition with localStorage
 2/14/18 10:41 AM User is authenticated in the back-end on page load
 2/14/18 10:21 AM User is authenticated in the back-end on page load
 2/14/18 10:15 AM User is authenticated in the back-end on page load
 2/14/18 10:14 AM User is authenticated in the back-end on page load
 2/14/18 10:14 AM User is authenticated in the back-end on page load
 2/14/18 10:14 AM User is authenticated in the back-end on page load
 2/14/18 10:10 AM User either is not authenticated in the back-end or there has been some race condition with localStorage
 2/14/18 10:10 AM User is authenticated in the back-end on page load 

(this time me being logged in clearly lasted about 30 minutes...)

Comment 12

[Treeherder GitHub Bugbot]

Commit pushed to master at https://github.com/mozilla/treeherder

https://github.com/mozilla/treeherder/commit/0cc341619fae1f5eb81748861ad7b18fe1bc11c1
Bug 1437824 - Stop logging out users if renewal fails (#3228)

In case:
* multiple tabs are trying to renew at the same time, where one
   tab will throw an error hence logging users out
* the renewal fails for transient reasons (eg wifi not re-established
  after machine resumes from sleep)

Comment 13

[Ed Morley [:emorley]]

The hopeful fix has just been deployed to production - please let us know how it works out :-)

Comment 14

[Phil Ringnalda (:philor)]

My login survived the sleep between lunch and coming home from work, which has been a 100% logout, so I'd say it's fixed for my case.

Comment 15

[Boris Zbarsky [:bzbarsky]]

Looks good on my end too: I last loaded a treeherder thing about 7 hours ago, just loaded one now, and I'm still logged in.  ;)

Comment 16

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Hm, after sleeping I was logged out again. Let me have an extra eye on it today.

Comment 17

[Andreea Pavel [:apavel]]

hi, i'm on the day shift today, will keep you posted if i get logged out again.

Comment 18

[Henrik Skupin [:whimboo][⌚️UTC+2]]

So I got logged out again since I posted the last time which are 8h. How long should a session survive?

Comment 19

[Marco Castelluccio [:marco]]

Same here, I was logged out after a few hours (less than 4).

Comment 20

[Hassan Ali (:hassan)]

Henrik, Marco - Would you be able to provide me with the content of your recent notifications tab. Be sure to refresh the page before doing so just so it can have the most up to date notifications.

Comment 21

[Hassan Ali (:hassan)]

The notifications menu is the bell icon beside the infra dropdown in the navbar.

Comment 22

[Marco Castelluccio [:marco]]

Sorry, I thought this was Taskcluster and not Treeherder. I guess I should file another bug.

Comment 23

[Dustin J. Mitchell [:dustin] (he/him)]

Marco, the bugs probably have a common solution, so that's fine.

Comment 24

[Marco Castelluccio [:marco]]

> 2/15/18 5:07 PM User either is not authenticated in the back-end or there has been some race condition with localStorage
> 2/15/18 4:33 PM User either is not authenticated in the back-end or there has been some race condition with localStorage

Comment 25

[Ed Morley [:emorley]]

Was there a chance that some old Treeherder tabs open, that had not yet been refreshed since the comment 13 deployment? (The fix was client side and iirc even when tabs appear to be reloaded when re-activated after restoring a browser session, the page is actually being loaded from the browser cache).

Comment 26

[Ed Morley [:emorley]]

(Eugh sorry I should learn to re-read after copy-paste rearranging a sentence)

Comment 27

[Marco Castelluccio [:marco]]

Attachment: Screenshot-2018-2-15 Authorize Application.png

(In reply to Ed Morley [:emorley] from comment #25)
> Was there a chance that some old Treeherder tabs open, that had not yet been
> refreshed since the comment 13 deployment? (The fix was client side and iirc
> even when tabs appear to be reloaded when re-activated after restoring a
> browser session, the page is actually being loaded from the browser cache).

I'm not sure, I'll test again tomorrow.
When I tried to login again now with Taskcluster, I got this authorization screen.

Comment 28

[Andreea Pavel [:apavel]]

As an update I did not get logged out in the last two shifts, 1 day shift and 1 night shift RO time, in treeherder. 
Regarding taskcluster, i got the authorization screen, however after log out, log in, it worked as expected.

Comment 29

[Henrik Skupin [:whimboo][⌚️UTC+2]]

I haven't seen it again. Looks like i works now.

Comment 30

[Ed Morley [:emorley]]

Could you remove the debug logging?

Comment 31

[Hassan Ali (:hassan)]

I will send a PR your way shortly.

Comment 32

[Treeherder GitHub Bugbot]

Commit pushed to master at https://github.com/mozilla/treeherder

https://github.com/mozilla/treeherder/commit/b7c1d8bee70acb40826bc85b9e195c087853aafa
Bug 1437824 - Remove debugging logging now that sessions seem to work (#3260)

Comment 33

[Andreea Pavel [:apavel]]

(In reply to Henrik Skupin (:whimboo) from comment #29)
> I haven't seen it again. Looks like i works now.

Hi, sorry to disappoint, i started the shift at 8am RO time and until 11am RO time, i got logged out 3 times, no error message. I only had treeherder and bugzilla tabs opened, no other pages that required other login information.