Rocket.Chat icon indicating copy to clipboard operation
Rocket.Chat copied to clipboard

After upgrade from 6.6.6 to 6.11-latest (19.8.2024) stuck loading on loging in web & desktop app before refresh page

Open matoproject opened this issue 1 year ago • 5 comments

Manual installation on ubuntu according to official rocketchat instructions....

Description:

After clicking the login button the system still only shows three dots until the page is reloaded with F5(refresh), there are no errors in the rocketchat records, but it visibly contains less of the records than when the login was successful. However, all records end with code 200. Log in failed below. When trying to find the problem, it can be seen in the F12 console of the browser that when accessing the API, the server returns the error code 401 Unauthorized

The error occurs across all devices and browsers windows, android - chrome, firefox, edge. The error also occurs in the Desktop Windows application in both the older and the latest version 4.0.1. Only the mobile app works properly.

It is interesting that pressing F5 or reload in the desktop application causes the chat to be activated immediately and works without problems until the next login. The error occurs across all users regardless of rights

Steps to reproduce:

  1. Update from 6.6.6 to 6.11.1 latest use this: https://docs.rocket.chat/docs/updating-rocketchat

Expected behavior:

After clicking the login button, the user's splash screen will appear

Actual behavior:

After clicking the login button, the system still only shows three dots until the page is reloaded with F5(refresh)

Server Setup Information:

  • Version of Rocket.Chat Server: 6.11.1
  • License Type: Community
  • Number of Users: 7
  • Operating System: Ubuntu 22.04.3 LTS (GNU/Linux 5.15.0-118-generic x86_64)
  • Deployment Method: Manual
  • Number of Running Instances: 1
  • DB Replicaset Oplog:
  • NodeJS Version: 14.21.3
  • MongoDB Version: 5.0.22 / wiredTiger (oplog Enabled)

Client Setup Information

  • Desktop App or Browser Version: BOTH (ALL)
  • Operating System: Windows 10, 11 + Android 14 (ALL)

Additional context

Use NGINX proxy on external server but connection directly on the ip server without change... access from the local or external network also does not change the error

Relevant logs:

FROM SERVER srp 20 17:30:03 social-penny rocketchat[845]: {"level":20,"time":"2024-08-20T15: 30:03.640Z","pid":845,"hostname":"social-penny","name":"Callbacks","msg":"Execut ing callback with id 2fa for hook onValidateLogin"} srp 20 17:30:03 social-penny rocketchat[845]: {"level":20,"time":"2024-08-20T15: 30:03.643Z","pid":845,"hostname":"social-penny","name":"Callbacks","msg":"Execut ing callback with id ChauDCRrtc6xws6kh for hook afterValidateLogin"} srp 20 17:30:03 social-penny rocketchat[845]: {"level":35,"time":"2024-08-20T15: 30:03.644Z","pid":845,"hostname":"social-penny","name":"API","method":"POST","ur l":"/api/v1/method.callAnon/login","userId":"3PBaoy9hSdchXbf4T","userAgent":"Moz illa/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Ch rome/127.0.0.0 Safari/537.36","length":"238","host":"xxxxxxxx.cz","referer ":"https://xxxxxxxxxxx.cz/home","remoteIP":"172.16.4.100","status":200,"respo nseTime":70} srp 20 17:30:03 social-penny rocketchat[845]: {"level":20,"time":"2024-08-20T15: 30:03.646Z","pid":845,"hostname":"social-penny","name":"Callbacks","msg":"Execut ing callback with id add-webdav-server for hook afterValidateLogin"} srp 20 17:30:03 social-penny rocketchat[845]: {"level":20,"time":"2024-08-20T15: 30:03.653Z","pid":845,"hostname":"social-penny","name":"Callbacks","msg":"Execut ing callback with id 2fa for hook onValidateLogin"} srp 20 17:30:03 social-penny rocketchat[845]: {"level":20,"time":"2024-08-20T15: 30:03.665Z","pid":845,"hostname":"social-penny","name":"Callbacks","msg":"Execut ing callback with id ChauDCRrtc6xws6kh for hook afterValidateLogin"} srp 20 17:30:03 social-penny rocketchat[845]: {"level":20,"time":"2024-08-20T15: 30:03.668Z","pid":845,"hostname":"social-penny","name":"Callbacks","msg":"Execut ing callback with id add-webdav-server for hook afterValidateLogin"} srp 20 17:30:03 social-penny rocketchat[845]: {"level":35,"time":"2024-08-20T15: 30:03.678Z","pid":845,"hostname":"social-penny","name":"API","method":"GET","url ":"/api/apps/languages","userId":"3PBaoy9hSdchXbf4T","userAgent":"Mozilla/5.0 (W indows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/127.0. 0.0 Safari/537.36","host":"xxxxxxxxx.cz","referer":"https://xxxxxxx. cz/home","remoteIP":"172.16.4.100","status":200,"responseTime":1} srp 20 17:30:03 social-penny rocketchat[845]: {"level":35,"time":"2024-08-20T15: 30:03.699Z","pid":845,"hostname":"social-penny","name":"API","method":"GET","url ":"/api/apps/actionButtons","userId":"3PBaoy9hSdchXbf4T","userAgent":"Mozilla/5. 0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/12 7.0.0.0 Safari/537.36","host":"xxxxxxxx.cz","referer":"https://xxxx xxxx.cz/home","remoteIP":"172.16.4.100","status":200,"responseTime":0}

NixR

matoproject avatar Aug 20 '24 17:08 matoproject

Has the server URL been mistakenly update by someone trying to login locally?

Have you checked you have a websocket on the login page?

Browser, Inspect, Network, filter for WS

What do your Nginx logs say?

reetp avatar Aug 21 '24 12:08 reetp

No, the URL was not updated after local login local login I used it only to test if the error is on the proxy or on the rocketchat server. Since the error occurs even with local access, I do not assume that it is not an error of my external proxy server

The Ubuntu server on which rocketchat runs is practically in the default settings, only rocketchat was manually installed and now updated according to the above-mentioned instructions, which ran without errors.

I checked the web socket as you requested, I'm not an expert on this communication. But as you can see from the attached picture, when accessing the chat address, the websocket is loaded, but if I delete the entry from the log, and then log in, the websocket will not be called again. I don't know if it's okay. However, if I reload the page, the login happens immediately and the websocket is visible in the log. I think it's just my misunderstanding of how this works. And that there is no problem with loading the websocket.

Access Log from nginx in attachment, error log is empty... Thank you very much for your help. acess.log.txt

xunO

matoproject avatar Aug 21 '24 22:08 matoproject

Hi, I'm still trying to solve this problem, I'm .. not very good at these things, I'm more of a HW admin, sorry for any misunderstanding. I'm trying to figure out where the problem is in the login process and I came across something that I don't know if it's right or wrong. Can someone please confirm or deny this for me? thank you very much

Examining the content of the requests and responses in the dev tool in the browser I saw that after the api/login is called it is called with the session token

`{"msg":"method","id":"4","method":"login","params":[{"user":{"username":"Test"},"password":{"digest":"af5427f811380edcd2277e83be53c0c21043e721b16085583b8c8eabdfa90b8d","algorithm":"sha-256"}}]}`


x-auth-token:
VI5d0Upbs06Zx7_xIVZLrm768cZp63FX5x8A2k0d3Oj
x-user-id:
3PBaoy9hSdchXbf4T

reply is...

{
    "message": "{\"msg\":\"result\",\"id\":\"4\",\"result\":{\"id\":\"3PBaoy9hSdchXbf4T\",\"token\":\"jJZqvE1geCccuEg5T94xS-sRvmYNPl0DJEasvFixbTP\",\"tokenExpires\":{\"$date\":1732316758048},\"type\":\"password\"}}",
    "success": true
}

that seems fine in my opinion. But the call to the next api in the sequence is called with the original token, and that's the bug I think. Since this call already returns 401, after F5 this api is called with the new token returned by api/login in its response and the return code is now 200 and everything works as it should

call after click login button emoji-custom.list and other is called (401 Error)

x-auth-token:
VI5d0Upbs06Zx7_xIVZLrm768cZp63FX5x8A2k0d3Oj
x-user-id:
3PBaoy9hSdchXbf4T

after refresh page is emoji-custom.list and other called (200 OK)

x-auth-token:
jJZqvE1geCccuEg5T94xS-sRvmYNPl0DJEasvFixbTP
x-user-id:
3PBaoy9hSdchXbf4T

Am I on the right track when I say that the emoji-custom.list call should already send the x-atuh-token provided in the api/v1/login response?

How can I find out more about this?

Thanks

EDIT1: I see that after logging in I have a new token ("yyy") stored in localstorage and cookies, but in session storage the old token ("xxx") after refresh I have a new token ("yyy") everywhere

EDIT2 after disable "Forget User Session on Window Close" login worked fine...

matoproject avatar Aug 24 '24 23:08 matoproject

this information helped another user find a similar or the same error, it seems it could be the same as this problem

#32954

matoproject avatar Aug 24 '24 23:08 matoproject

See my comment here:

https://github.com/RocketChat/Rocket.Chat/issues/32954#issuecomment-2312358072

Note also you images above are 404 so I can't see them either.

reetp avatar Aug 27 '24 11:08 reetp

Hi, sorry for the late reply, the first image only shows a 401 unauthorized error and the second one only shows the websocket as active as you requested. I see both of these images on multiple devices with multiple ISPs. I've moved my response to the issue to the thread you mentioned so it's not scattered all over github. Can't the problems be merged? I don't know much about Github :(

Error 401 Image

Thanks

matoproject avatar Aug 31 '24 07:08 matoproject

I think this may be related.

Look at 6.11.2 changelog

https://github.com/RocketChat/Rocket.Chat/pull/33129

https://github.com/RocketChat/Rocket.Chat/pull/33040

reetp avatar Sep 03 '24 22:09 reetp

This issue has been marked as stale because there has been no further activity in the last 10 days. If the issue remains stale for the next 4 days (a total of 14 days with no activity), then it will be assumed that the question has been resolved and the issue will be automatically closed.

github-actions[bot] avatar Sep 18 '24 00:09 github-actions[bot]

This issue was closed because it has been inactive for 14 days since being marked as stale.

github-actions[bot] avatar Oct 02 '24 00:10 github-actions[bot]