Get preferences on Mattermost 6.2

[VincentSC]

For some reason the library stops working on Mattermost 6.2.

Line 113 in /mattermost-client/src/client.js:

this.getPreferences();

causes an Error: WebSocket was closed before the connection was established.

For all functions, when data is null, there is the possibility of an uncaught exception. This means there needs to be a check if data is null in all functions. The above error I get when I fix this for _onPeferences.

See https://gitlab.com/benoit.lavorata/node-red-contrib-mattermost-ws/-/issues/9 for more info - that nodejs package depends on 6.1.2, but 6.4.1 also has the problem.

I'm not understanding exactly how this library works, and I don't know where to start to fix this. :(
I also tried the latest 8.2.x version of Mattermost, but they all have the unexpected closing of the the socket.

But I did find a fix, based on an assumption that there might be a security fix that closes the connection in some situations. PR coming up soon.

[Marthym]

I try to run on a docker environment, postgres:14.1 and mattermost/mattermost-team-edition:release-6.2.

beforeEach(() => {
    tested = new Client(
        MATTERMOST_PREVIEW_SERVER_URL,
        MATTERMOST_PREVIEW_SERVER_GROUP,
        MATTERMOST_PREVIEW_SERVER_OPTIONS);
});

describe('Mattermost integration tests ...', () => {
    test('should login with credentials', async () => {
        let loginResult = tested.login(MATTERMOST_USERNAME, MATTERMOST_PASSWORD, null);
        await new Promise((r) => setTimeout(r, 4000));
        log.info('loginResult', loginResult);
    });
});

But everything seems to be ok :

i Logging in...
* POST /users/login
* api url: http://localhost:8065/api/v4/users/login
* request callback
* statusCode:  200
i Websocket URL: ws://localhost:8065/api/v4/websocket
* Loading /users/me
* GET /users/me
* api url: http://localhost:8065/api/v4/users/me
* Loading /users/me/preferences
* GET /users/me/preferences
* api url: http://localhost:8065/api/v4/users/me/preferences
* Loading /users/me/teams
* GET /users/me/teams
* api url: http://localhost:8065/api/v4/users/me/teams
* request callback
* statusCode:  200
i Loaded Me...
* request callback
* statusCode:  200
i Loaded Preferences...
* request callback
* statusCode:  200
i Found 1 teams.
* Testing jedi == jedi
i Found team: ajm3wi5z5pbfjdqgs87go7tojh
* Loading /users?page=0&per_page=200&in_team=ajm3wi5z5pbfjdqgs87go7tojh
* GET /users?page=0&per_page=200&in_team=ajm3wi5z5pbfjdqgs87go7tojh
* api url: http://localhost:8065/api/v4/users?page=0&per_page=200&in_team=ajm3wi5z5pbfjdqgs87go7tojh
* Loading /users/me/teams/ajm3wi5z5pbfjdqgs87go7tojh/channels
* GET /users/me/teams/ajm3wi5z5pbfjdqgs87go7tojh/channels
* api url: http://localhost:8065/api/v4/users/me/teams/ajm3wi5z5pbfjdqgs87go7tojh/channels
i Connecting...
i Sending challenge...
i Starting pinger...
* request callback
* statusCode:  200
i Found 2 subscribed channels.
* Received unhandled message:
* { status: 'OK', seq_reply: 1 }
* request callback
* statusCode:  200
i Found 1 profiles.
* Loading /users?page=1&per_page=200&in_team=ajm3wi5z5pbfjdqgs87go7tojh
* GET /users?page=1&per_page=200&in_team=ajm3wi5z5pbfjdqgs87go7tojh
* api url: http://localhost:8065/api/v4/users?page=1&per_page=200&in_team=ajm3wi5z5pbfjdqgs87go7tojh
* request callback
* statusCode:  200
i Found 0 profiles.

We can see, all status code to 200 and no errors.

The project node-red-contrib-mattermost-ws depend on an old version with a know and fix problem on WS (#134). You write you have test with the latest mm-client version, can you please provide a use case to reproduce ?

[Marthym]

@VincentSC Any additionnal informations before closing ?

[VincentSC]

Seems best to first focus on the node red library, and reopen this issue if needed. I'll be working on it later this month

[VincentSC]

Looked further into it. I cannot find out why it happens. In MM 6.4 it even gets worse and a reconnect does not work anymore.

But there is a simple solution. I do see that self.preferences` is not used anywhere - it is even not instantiated in the constructor. So the call can be fully removed - or is it WIP-code?

[Marthym]

I don't know if the code is WIP or not.

I will inspect it and if useless I will update it

[VincentSC]

Thanks! It is about the variable this.preferences on this line:

mattermost-client/src/client.js

Line 176 in 2d57570

this.preferences = data;

I don't see being used anywhere, including hubot

If important, then it needs to be correctly initiated in the constructor. If not important for logging in, it would be very convenient for me to be removed.

Let me know if I can do something for you.

[Marthym]

I have check and double check, there are no change on preferences API which can explain your problem.

The possible issue can be on the Mattermost instance you use. What I can do is avoid reconnet on error.

In the latests versions we have improve logging. It could be interesting to have the debug log for your case.

Anyway, I will improve error handling on preferences.

[VincentSC]

Got docker and can switch between 6.1, 6.2, 6.3 and 6.4 in half a minute. So without making any other change, all works fine when reverting to 6.1 and stops working when I go to a newer one. I neither see any API-change and it makes no sense to me either, so that it got worse in 6.4 makes no sense to me.

It looks like that the connection drops quicker and reconnect does not work as intended. So I don't think it has to do with the call, but that there are multiple calls in a row. I have not tested, but I won't be surprised it will work when I call it manually after the login-succeeded.

Latest version is on NPM? I will then update the dependency in the nodered-plugin, so I can test.

And did you remove the getPreferences in that new version? If not, then I know I might need to patch it here.

[Marthym]

This is what I do for this answer #275 (comment)
But I haven't reproduce. with the lastest code version. I havent test the npm release. Maybe try to build mattermost-client from source and test it.

If you have a docker-compose I will test to reproduce.

if the current code version fix the problem @loafoe will produce a release asap for npm.

[Marthym]

Ok, after lot of test, it seems that calling /api/v4/users/me/preferences with a BEARER token, return 200 with body containing "null". This cause an error and start reconnect process.

I will fix it ASAP.

[VincentSC]

Ah, I thought the null was coming from somewhere else - not really used to js..

Thanks for the effort!

[VincentSC]

I have tested it and it works