Can't log out, I just get an endless spinner

RESOLVED FIXED in M3

Status

Pancake
General
--
critical
RESOLVED FIXED
6 years ago
6 years ago

People

(Reporter: dria, Assigned: sfoster)

Tracking

unspecified
x86
Mac OS X

Details

I've been trying to switch between accounts for testing purposes, but logging out doesn't work for me at all.  I hit the log out button and it just sits there with an endless spinner.  I have to delete and reinstall the app to change accounts, which is sort of a pain in the butt :)
(Reporter)

Updated

6 years ago
Severity: normal → critical
Target Milestone: --- → M3
This also effects the "wipe data" functionality - I just tested with an alternate account, and the data was wiped, but the logout never happened (which is really a dupe of https://bugzilla.mozilla.org/show_bug.cgi?id=758593 , but that bug doesn't cover the straight logout issue).

Comment 2

6 years ago
Sam can you take a look at this?
Assignee: nobody → sfoster
(Assignee)

Comment 3

6 years ago
I'm not able to reproduce. The code requests /api/logout and then sends an xmessage to the native layer.  It /should/ at least throw up an error if that /api/logout request times out. Reducing that timeout is about all I can do with this on the FE.
This just happened to me on play. I do see the following two requests:

pancake-web:
2012-07-03 15:05:08,146 INFO  [wsgi][worker 27] 66.207.208.98 - - [03/Jul/2012:15:05:07 +0000] "POST /api/wipe HTTP/1.1" 200 17 "http://play.fxhome.mozillalabs.com:6543/account?platform=ios" "Mozilla/5.0 (iPad; CPU OS 6_0 like Mac OS X) AppleWebKit/536.13 (KHTML, like Gecko) Mobile/10A5338d"

fxhome-lattice:
[I 120703 15:05:08 web:1393] 200 DELETE /lattice/sarentz%40mozilla.com/wipe (127.0.0.1) 160.05ms

pancake-user-api:
[I 120703 15:05:07 web:1393] 200 DELETE /user/sarentz%40mozilla.com (127.0.0.1) 43.04ms

But I do not see the PancakeViewController#handleCallWithName:arguments: method being called in the native code.
Sorry, my case was a Wipe Account action. Not logout. But the two are probably related?
Something different just happened:

1) Open account menu
2) Click Log Out
3) Nothing happens .. spinner does not appear, account menu stays open, no logout message to native code

It seems that first /api/logout is called, and then the spinner.png is loaded. Could this be a race condition?

Here is a network trace. Note that both /api/logout and /theme-origami/core/img/spinner.png are requested over the same connection (destination port number stays the same). So there is no doubt that this is happening in that order.


#########
T 10.242.28.67:62840 -> 67.23.46.146:6543 [AP]
POST /api/logout HTTP/1.1.
Host: play.fxhome.mozillalabs.com:6543.
Accept-Language: en-us.
User-Agent: Mozilla/5.0 (iPad; CPU OS 6_0 like Mac OS X) AppleWebKit/536.13 (KHTML, like Gecko) Mobile/10A5338d.
X-Requested-With: XMLHttpRequest.
Accept: application/json.
Referer: http://play.fxhome.mozillalabs.com:6543/account?platform=ios.
Content-Type: application/x-www-form-urlencoded.
X-XSRFToken: 85440066833981af0238e737953b2da8b66bdf78.
Connection: keep-alive.
Cookie: sessionid=e9daa24a601c5c3a4916c9d434b8b5e398f31f54847cc0bbe30740aab472f87d44ff6c31.
Content-Length: 51.
Origin: http://play.fxhome.mozillalabs.com:6543.
Accept-Encoding: gzip, deflate.
.

#
T 10.242.28.67:62840 -> 67.23.46.146:6543 [AP]
csrf_token=85440066833981af0238e737953b2da8b66bdf78
###
T 67.23.46.146:6543 -> 10.242.28.67:62840 [AP]
HTTP/1.0 200 OK.

####
T 67.23.46.146:6543 -> 10.242.28.67:62840 [R]
..
###
T 10.242.28.67:62841 -> 67.23.46.146:6543 [AP]
GET /theme-origami/core/img/spinner.png HTTP/1.1.
Host: play.fxhome.mozillalabs.com:6543.
Referer: http://play.fxhome.mozillalabs.com:6543/account?platform=ios.
Accept-Encoding: gzip, deflate.
Accept: */*.
Cookie: sessionid=e9daa24a601c5c3a4916c9d434b8b5e398f31f54847cc0bbe30740aab472f87d44ff6c31.
Accept-Language: en-us.
Connection: keep-alive.
User-Agent: Mozilla/5.0 (iPad; CPU OS 6_0 like Mac OS X) AppleWebKit/536.13 (KHTML, like Gecko) Mobile/10A5338d.
.

##
T 67.23.46.146:6543 -> 10.242.28.67:62841 [AP]
HTTP/1.0 200 OK.

##
T 67.23.46.146:6543 -> 10.242.28.67:62841 [A]
Server: PasteWSGIServer/0.5 Python/2.7.2.
Date: Thu, 05 Jul 2012 14:23:21 GMT.
Last-Modified: Wed, 04 Jul 2012 00:29:40 GMT.
Content-Type: image/png; charset=UTF-8.
Content-Length: 1205.
Cache-Control: max-age=0, must-revalidate, no-cache, no-store.
Expires: Thu, 05 Jul 2012 14:23:21 GMT.
Pragma: no-cache.

[PNG Response omitted]
Trying to wipe my account, I see the following server response. This looks like an incomplete response as no response headers are being sent after the HTTP 200 OK. Investigating the server side of things if this is correct or not.



POST /api/wipe HTTP/1.1.
Host: play.fxhome.mozillalabs.com:6543.
Accept-Language: en-us.
User-Agent: Mozilla/5.0 (iPad; CPU OS 6_0 like Mac OS X) AppleWebKit/536.13 (KHTML, like Gecko) Mobile/10A5338d.
X-Requested-With: XMLHttpRequest.
Accept: application/json.
Referer: http://play.fxhome.mozillalabs.com:6543/account?platform=ios.
Content-Type: application/x-www-form-urlencoded.
X-XSRFToken: 0057289c88baefe3fe5d5b742e9981629a88c3a4.
Connection: keep-alive.
Cookie: sessionid=c75514acadf02efbbf8b50572e23fb2969e7f62c556644afb21f4bab9ccc00fce8f3c10b.
Content-Length: 51.
Origin: http://play.fxhome.mozillalabs.com:6543.
Accept-Encoding: gzip, deflate.
.

#
T 10.242.28.67:63217 -> 67.23.46.146:6543 [AP]
csrf_token=0057289c88baefe3fe5d5b742e9981629a88c3a4
###
T 67.23.46.146:6543 -> 10.242.28.67:63217 [AP]
HTTP/1.0 200 OK.

###
T 67.23.46.146:6543 -> 10.242.28.67:63217 [R]
..
This is a normal server response. So the question is, why does the output from Comment #7 happen? Does the client kill the request or does the server return an incomplete response?


T 10.242.28.67:52207 -> 67.23.46.146:6543 [AP]
POST /api/wipe HTTP/1.1.
Host: play.fxhome.mozillalabs.com:6543.
Accept-Language: en-us.
User-Agent: Mozilla/5.0 (iPad; CPU OS 6_0 like Mac OS X) AppleWebKit/536.13 (KHTML, like Gecko) Mobile/10A5338d.
X-Requested-With: XMLHttpRequest.
Accept: application/json.
Referer: http://play.fxhome.mozillalabs.com:6543/account?platform=ios.
Content-Type: application/x-www-form-urlencoded.
X-XSRFToken: 929e117ae12cc53ae26cbcd08cfd6397da5c6573.
Connection: keep-alive.
Cookie: sessionid=945b27b10174be20be0c3764721fc390d1a1d92ad28a6ae15eaa45a6b92b2dd3b24adc6f.
Content-Length: 51.
Origin: http://play.fxhome.mozillalabs.com:6543.
Accept-Encoding: gzip, deflate.
.

#
T 10.242.28.67:52207 -> 67.23.46.146:6543 [AP]
csrf_token=929e117ae12cc53ae26cbcd08cfd6397da5c6573
###
T 67.23.46.146:6543 -> 10.242.28.67:52207 [AP]
HTTP/1.0 200 OK.

#
T 67.23.46.146:6543 -> 10.242.28.67:52207 [AFP]
Server: PasteWSGIServer/0.5 Python/2.7.2.
Date: Thu, 05 Jul 2012 17:27:36 GMT.
Content-Type: application/json; charset=UTF-8.
Content-Length: 17.
Cache-Control: private.
Set-Cookie:  sessionid=f43dc4271d1a7ee008d918e29ba4b75c2a51e049863a58d6033340ad99dd464f6f6269ba; expires=Tue, 19-Jan-2038 03:14:07 GMT; httponly; Path=/.
.
{"success": true}
On 2012-07-05, at 11:03 AM, Stefan Arentz <sarentz@mozilla.com> wrote:

This is about bug https://bugzilla.mozilla.org/show_bug.cgi?id=769260

I'm looking into this bug and I need to know if this is just happening on play (development) or not.

Has anyone seen that bug happen on stage or production?

Nobody replied but I am going to assume that this bug was only observed on play.

I'm seeing a strange issue there where the response to the POST /api/wipe is incomplete.

I have not tracked this down but I do have a fix: instead of running paster for the development server on play we now run gunicorn. This is also closer to what we have on stage and production.

I can reliable reproduce this bug on paster while it has not happened yet with gunicorn.

So I am going to close this bug for now.

Sorry for the many hours wasted that we put in this one. Some are hard to track down.

One thing learned here is that it makes a huge difference to run a real packet sniffer in a window. Not a proxy, just a passive packet sniffer. (I used ngrep)
Status: NEW → RESOLVED
Last Resolved: 6 years ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.