Password reset verification should show a loading spinner after "I have verified my email address"

[richvdh]

password reset gives a pop-up about being unable to check the email verification ... but then seems to work anyway?

[turt2live]

Did it loop? If so, duplicate of #6544

Related: #2780

[richvdh]

I don't think so. as far as I recall, I dismissed the popup and then I got the "your password has been reset" confirmation.

[turt2live]

"great".

[richvdh]

tbh I didn't pay that much attention. It's entirely possible I was mistaken

[turt2live]

Honestly I can believe that it's just utter garbage and broke in 5 different ways.

[richvdh]

😢

[kittykat]

@richvdh I can't reproduce it, still an issue? Can you please update with more info if it is?

[richvdh]

For context, the popup in question comes after clicking "I have verified my email address":

and the popup looks like:

I just tried reproducing this, and was successful, but didn't catch it on video, and can't repro it again.

However, I have server-side logs, which include the following:

2021-08-02 11:44:38,657 - synapse.handlers.ui_auth.checkers - 150 - INFO - POST-818180 - Getting validated threepid. threepidcreds: ({'sid': 'KkfieTJmXveCPucH', 'client_secret': 'xn071o9iZht0FBXrmdpBS0xUEYDT39Cu'},)
2021-08-02 11:44:43,557 - synapse.handlers.ui_auth.checkers - 150 - INFO - POST-818188 - Getting validated threepid. threepidcreds: ({'sid': 'KkfieTJmXveCPucH', 'client_secret': 'xn071o9iZht0FBXrmdpBS0xUEYDT39Cu'},)
2021-08-02 11:44:43,562 - synapse.handlers.ui_auth.checkers - 150 - INFO - POST-818189 - Getting validated threepid. threepidcreds: ({'sid': 'KkfieTJmXveCPucH', 'client_secret': 'xn071o9iZht0FBXrmdpBS0xUEYDT39Cu'},)
2021-08-02 11:44:43,563 - synapse.handlers.ui_auth.checkers - 150 - INFO - POST-818196 - Getting validated threepid. threepidcreds: ({'sid': 'KkfieTJmXveCPucH', 'client_secret': 'xn071o9iZht0FBXrmdpBS0xUEYDT39Cu'},)
2021-08-02 11:44:43,566 - synapse.handlers.ui_auth.checkers - 150 - INFO - POST-818202 - Getting validated threepid. threepidcreds: ({'sid': 'KkfieTJmXveCPucH', 'client_secret': 'xn071o9iZht0FBXrmdpBS0xUEYDT39Cu'},)
2021-08-02 11:44:53,139 - synapse.http.site - 325 - INFO - POST-818216 - Connection from client lost before response was sent
2021-08-02 11:44:53,143 - synapse.http.site - 325 - INFO - POST-818219 - Connection from client lost before response was sent
2021-08-02 11:44:53,738 - synapse.http.site - 325 - INFO - POST-818189 - Connection from client lost before response was sent
2021-08-02 11:44:53,738 - synapse.http.site - 325 - INFO - POST-818196 - Connection from client lost before response was sent
2021-08-02 11:44:53,738 - synapse.http.site - 325 - INFO - POST-818188 - Connection from client lost before response was sent
2021-08-02 11:44:53,743 - synapse.http.site - 325 - INFO - POST-818202 - Connection from client lost before response was sent
2021-08-02 11:44:53,743 - synapse.http.site - 325 - INFO - POST-818180 - Connection from client lost before response was sent
2021-08-02 11:44:54,649 - synapse.handlers.ui_auth.checkers - 150 - INFO - POST-818219 - Getting validated threepid. threepidcreds: ({'sid': 'KkfieTJmXveCPucH', 'client_secret': 'xn071o9iZht0FBXrmdpBS0xUEYDT39Cu'},)
2021-08-02 11:44:54,666 - synapse.handlers.ui_auth.checkers - 150 - INFO - POST-818216 - Getting validated threepid. threepidcreds: ({'sid': 'KkfieTJmXveCPucH', 'client_secret': 'xn071o9iZht0FBXrmdpBS0xUEYDT39Cu'},)
2021-08-02 11:44:57,156 - synapse.http.site - 325 - INFO - POST-818223 - Connection from client lost before response was sent
2021-08-02 11:44:57,157 - synapse.http.site - 325 - INFO - POST-818229 - Connection from client lost before response was sent
2021-08-02 11:44:59,427 - synapse.http.server - 657 - WARNING - POST-818180 - Not sending response to request <XForwardedForRequest at 0x7f178f5ba7f0 method='POST' uri='/_matrix/client/r0/account/password' clientproto='HTTP/1.0' site='8008'>, already disconnected.
2021-08-02 11:44:59,427 - synapse.access.http.8008 - 410 - INFO - POST-818180 - 2001:8b0:ba7a:e98f:3252:cbff:fee8:6489 - 8008 - {None} Processed request: 28.428sec/-5.684sec (0.313sec, 0.002sec) (0.025sec/0.289sec/5) 0B 200! "POST /_matrix/client/r0/account/password HTTP/1.0" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:88.0) Gecko/20100101 Firefox/88.0" [0 dbevts]
2021-08-02 11:44:59,440 - synapse.handlers.ui_auth.checkers - 150 - INFO - POST-818223 - Getting validated threepid. threepidcreds: ({'sid': 'KkfieTJmXveCPucH', 'client_secret': 'xn071o9iZht0FBXrmdpBS0xUEYDT39Cu'},)
2021-08-02 11:44:59,441 - synapse.handlers.ui_auth.checkers - 150 - INFO - POST-818229 - Getting validated threepid. threepidcreds: ({'sid': 'KkfieTJmXveCPucH', 'client_secret': 'xn071o9iZht0FBXrmdpBS0xUEYDT39Cu'},)
2021-08-02 11:45:04,007 - synapse.http.server - 657 - WARNING - POST-818189 - Not sending response to request <XForwardedForRequest at 0x7f1788281470 method='POST' uri='/_matrix/client/r0/account/password' clientproto='HTTP/1.0' site='8008'>, already disconnected.
2021-08-02 11:45:04,007 - synapse.access.http.8008 - 410 - INFO - POST-818189 - 2001:8b0:ba7a:e98f:3252:cbff:fee8:6489 - 8008 - {None} Processed request: 28.420sec/-10.270sec (0.312sec, 0.004sec) (0.042sec/0.059sec/5) 0B 200! "POST /_matrix/client/r0/account/password HTTP/1.0" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:88.0) Gecko/20100101 Firefox/88.0" [0 dbevts]
2021-08-02 11:45:04,008 - synapse.http.server - 657 - WARNING - POST-818202 - Not sending response to request <XForwardedForRequest at 0x7f1784982080 method='POST' uri='/_matrix/client/r0/account/password' clientproto='HTTP/1.0' site='8008'>, already disconnected.
2021-08-02 11:45:04,008 - synapse.access.http.8008 - 410 - INFO - POST-818202 - 2001:8b0:ba7a:e98f:3252:cbff:fee8:6489 - 8008 - {None} Processed request: 28.407sec/-10.265sec (0.316sec, 0.001sec) (0.038sec/0.074sec/5) 0B 200! "POST /_matrix/client/r0/account/password HTTP/1.0" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:88.0) Gecko/20100101 Firefox/88.0" [0 dbevts]
2021-08-02 11:45:04,008 - synapse.http.server - 657 - WARNING - POST-818196 - Not sending response to request <XForwardedForRequest at 0x7f179110fba8 method='POST' uri='/_matrix/client/r0/account/password' clientproto='HTTP/1.0' site='8008'>, already disconnected.
2021-08-02 11:45:04,010 - synapse.access.http.8008 - 410 - INFO - POST-818196 - 2001:8b0:ba7a:e98f:3252:cbff:fee8:6489 - 8008 - {None} Processed request: 28.415sec/-10.272sec (0.317sec, 0.002sec) (0.038sec/0.077sec/5) 0B 200! "POST /_matrix/client/r0/account/password HTTP/1.0" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:88.0) Gecko/20100101 Firefox/88.0" [0 dbevts]
2021-08-02 11:45:04,010 - synapse.http.server - 657 - WARNING - POST-818188 - Not sending response to request <XForwardedForRequest at 0x7f17882aaa58 method='POST' uri='/_matrix/client/r0/account/password' clientproto='HTTP/1.0' site='8008'>, already disconnected.
2021-08-02 11:45:04,010 - synapse.access.http.8008 - 410 - INFO - POST-818188 - 2001:8b0:ba7a:e98f:3252:cbff:fee8:6489 - 8008 - {None} Processed request: 28.425sec/-10.272sec (0.321sec, 0.001sec) (0.037sec/0.064sec/5) 0B 200! "POST /_matrix/client/r0/account/password HTTP/1.0" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:88.0) Gecko/20100101 Firefox/88.0" [0 dbevts]
2021-08-02 11:45:12,262 - synapse.http.server - 657 - WARNING - POST-818216 - Not sending response to request <XForwardedForRequest at 0x7f179f44af60 method='POST' uri='/_matrix/client/r0/account/password' clientproto='HTTP/1.0' site='8008'>, already disconnected.
2021-08-02 11:45:12,263 - synapse.access.http.8008 - 410 - INFO - POST-818216 - 2001:8b0:ba7a:e98f:3252:cbff:fee8:6489 - 8008 - {None} Processed request: 26.163sec/-19.124sec (0.319sec, 0.000sec) (0.034sec/0.034sec/5) 0B 200! "POST /_matrix/client/r0/account/password HTTP/1.0" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:88.0) Gecko/20100101 Firefox/88.0" [0 dbevts]
2021-08-02 11:45:12,264 - synapse.http.server - 657 - WARNING - POST-818219 - Not sending response to request <XForwardedForRequest at 0x7f178657d0f0 method='POST' uri='/_matrix/client/r0/account/password' clientproto='HTTP/1.0' site='8008'>, already disconnected.
2021-08-02 11:45:12,265 - synapse.access.http.8008 - 410 - INFO - POST-818219 - 2001:8b0:ba7a:e98f:3252:cbff:fee8:6489 - 8008 - {None} Processed request: 26.156sec/-19.122sec (0.313sec, 0.002sec) (0.025sec/0.042sec/5) 0B 200! "POST /_matrix/client/r0/account/password HTTP/1.0" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:88.0) Gecko/20100101 Firefox/88.0" [0 dbevts]
2021-08-02 11:45:16,888 - synapse.http.server - 657 - WARNING - POST-818229 - Not sending response to request <XForwardedForRequest at 0x7f178a9d7358 method='POST' uri='/_matrix/client/r0/account/password' clientproto='HTTP/1.0' site='8008'>, already disconnected.
2021-08-02 11:45:16,888 - synapse.access.http.8008 - 410 - INFO - POST-818229 - 2001:8b0:ba7a:e98f:3252:cbff:fee8:6489 - 8008 - {None} Processed request: 23.161sec/-19.731sec (0.327sec, 0.002sec) (0.068sec/0.096sec/5) 0B 200! "POST /_matrix/client/r0/account/password HTTP/1.0" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:88.0) Gecko/20100101 Firefox/88.0" [0 dbevts]
2021-08-02 11:45:16,889 - synapse.http.server - 657 - WARNING - POST-818223 - Not sending response to request <XForwardedForRequest at 0x7f1798d6e860 method='POST' uri='/_matrix/client/r0/account/password' clientproto='HTTP/1.0' site='8008'>, already disconnected.
2021-08-02 11:45:16,889 - synapse.access.http.8008 - 410 - INFO - POST-818223 - 2001:8b0:ba7a:e98f:3252:cbff:fee8:6489 - 8008 - {None} Processed request: 23.179sec/-19.733sec (0.334sec, 0.002sec) (0.058sec/0.046sec/5) 0B 200! "POST /_matrix/client/r0/account/password HTTP/1.0" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:88.0) Gecko/20100101 Firefox/88.0" [0 dbevts]

So it looks like the root cause here is slow requests on the server side, coupled with rather confusing handling from the Element side.

It looks like element sends a lot of /_matrix/client/r0/account/password requests in quick succession, and they all time out on the server side.

So I think there are a few things going wrong here:

• Much of the problem is that those requests take over 25 seconds on the server side. I don't have immediate visibility as to why, though I do notice that my server is sending out notifications to 5971 (seriously) homeservers that my device list has changed (due to the forced logouts), which may be something to do with it. This isn't directly an Element-web problem, but I do think Element could deal with it more gracefully.
• Another problem is that, after I click on "I have verified my email address", there is no user feedback that anything has happened while the request is in flight, so I can't tell if anything is happening and end up clicking a bunch of times to see if anything happens. I think this explains the multiple requests (it was me hammering on the button). I think Element should show a spinner of some sort, and disable the button, while there is a validation request in flight.
• Element ought to be able to tell the difference between "your email hasn't been validated yet", and "I can't talk to the server". It would be nice if the error message distinguished between the two.

[novocaine]

@richvdh how should we flag that a synapse investigation should be useful? Should I create a ticket in the synapse issue tracker?

[novocaine]

Acceptance criteria for this ticket on Element Web:

• Element web should show a loading spinner while the request is in flight

[richvdh]

Should I create a ticket in the synapse issue tracker?

yes please!

[novocaine]

Looking at the code, that popup is only shown if the server returns a 401, which seems like the correct behaviour. So I imagine the duplicate requests probably caused that, and the remaining fix for the client is to simply show a spinner.

[Palid]

It seems that an immediate remedy for it would be to cancel old request and get a new one when clicking button, or just ignore new requests instead of making lots of requests. I can't figure out where should I put this spinner.