Unable to save direct channel

[william]

Summary

We recently upgraded to 5.28.0 and 5.28.1 from 5.23.0. Now we have issues with creating new DM and joining new Channels/Teams since the upgrade. Multiple users are able to reproduce the problem including myself.

Steps to reproduce

Create a new DM to someone you have not chatted with before and the button will not doing anything and there is a 500 in the browser dev tools. The MM server logs also show the 500 and an SQL error. Shown below.

Expected behavior

Able to create new DMs and join Teams and Channels.

Observed behavior

We are seeing these errors in the log.

{"level":"warn","ts":1603218877.2037811,"caller":"app/channel.go:2419","msg":"Failed to get membership","error":"resource: ChannelMember id: channelId=<masked>, userId=<masked>"}

{"level":"error","ts":1603218901.399542,"caller":"mlog/log.go:229","msg":"Unable to save direct channel.","path":"/api/v4/channels/group","request_id":"<masked>","ip_addr":"x.x.x.x","user_id":"<masked>","method":"POST","err_where":"createGroupChannel","http_code":500,"err_details":"default_channel_roles_select: Error 1064: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'Admin FROM Channels LEFT JOIN Schemes ChannelScheme ON Channels.SchemeId = Chann' at line 1"}

Thanks.

[ahmaddanial]

Hi, @william

Trying to understand the upgrade process here since the error involves SQL query. Can you please confirm on the following:

• Did you upgrade from 5.23.0 > 5.28.0 > 5.28.1? Just want to be sure on this since you mentioned that you recently upgraded to 5.28.0 and 5.28.1 from 5.23.0.
• Were you referring to the official guide when the upgrade took place? Did you stop the mattermost service before the upgrade?
• Were there any changes that took place on the database level prior to the upgrade?

If this was done on a staging instance / you have a backup that you generated prior to the upgrade, I’d suggest you roll back since it is impacting productivity.

[william]

I forgot to mention we use docker in AWS ECS. So the new container gets deployed and then the old one is removed for zero downtime. We have done many upgrades this way.

That is correct from 5.23.0 then deployed the 5.28 container which had the problem and then tried 5.28.1 the same way.

I didn’t do anything with the DB itself. Its MySQL 8.0.11 in RDS.

Can we roll back without affecting the DB schema version?

[william]

The logs show it updating the DB for each version. This is from the first upgrade.

{"level":"warn","ts":1603152795.592293,"caller":"sqlstore/upgrade.go:207","msg":"Attempting to upgrade the database schema version","current_version":"5.23.0","new_version":"5.24.0"}
{"level":"warn","ts":1603152796.2753894,"caller":"sqlstore/upgrade.go:202","msg":"The database schema version has been upgraded","version":"5.24.0"}
{"level":"warn","ts":1603152796.2759662,"caller":"sqlstore/upgrade.go:207","msg":"Attempting to upgrade the database schema version","current_version":"5.24.0","new_version":"5.25.0"}
{"level":"warn","ts":1603152796.280457,"caller":"sqlstore/upgrade.go:202","msg":"The database schema version has been upgraded","version":"5.25.0"}
{"level":"warn","ts":1603152796.2810585,"caller":"sqlstore/upgrade.go:207","msg":"Attempting to upgrade the database schema version","current_version":"5.25.0","new_version":"5.26.0"}
{"level":"warn","ts":1603152796.5837111,"caller":"sqlstore/upgrade.go:202","msg":"The database schema version has been upgraded","version":"5.26.0"}
{"level":"warn","ts":1603152796.5842907,"caller":"sqlstore/upgrade.go:207","msg":"Attempting to upgrade the database schema version","current_version":"5.26.0","new_version":"5.27.0"}
{"level":"warn","ts":1603152796.5899973,"caller":"sqlstore/upgrade.go:202","msg":"The database schema version has been upgraded","version":"5.27.0"}
{"level":"warn","ts":1603152796.5908985,"caller":"sqlstore/upgrade.go:207","msg":"Attempting to upgrade the database schema version","current_version":"5.27.0","new_version":"5.28.0"}
{"level":"warn","ts":1603152797.0409153,"caller":"sqlstore/upgrade.go:202","msg":"The database schema version has been upgraded","version":"5.28.0"}

[XxLilBoPeepsxX]

Could you perhaps enable the most verbose logging available to your install, and attempt to take the same actions that have been failing, to generate the logs, and send them here, if you could? It would be useful as far as finding where specifically in the source code there has been a conflict, since we are talking about an expansive project here, of course.

[william]

Sure @XxLilBoPeepsxX , I set logging to DEBUG:

{"level":"error","ts":1603335212.1025755,"caller":"mlog/log.go:229","msg":"Unable to save direct channel.","path":"/api/v4/channels/direct","request_id":"bhdfw531rpd8befmhmbmi86w3w","ip_addr":"x.x.x.x","user_id":"<masked>","method":"POST","err_where":"CreateDirectChannel","http_code":500,"err_details":"default_channel_roles_select: Error 1064: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'Admin FROM Channels LEFT JOIN Schemes ChannelScheme ON Channels.SchemeId = Chann' at line 1"}
{"level":"debug","ts":1603335212.1042838,"caller":"web/handlers.go:100","msg":"Received HTTP request","method":"POST","url":"/api/v4/channels/direct","request_id":"bhdfw531rpd8befmhmbmi86w3w","status_code":"500"}
{"level":"error","ts":1603335212.7648458,"caller":"mlog/log.go:229","msg":"Unable to save direct channel.","path":"/api/v4/channels/direct","request_id":"m6s6ikq3p3g47gm4tfukp8o4jh","ip_addr":"x.x.x.x","user_id":"<masked>","method":"POST","err_where":"CreateDirectChannel","http_code":500,"err_details":"default_channel_roles_select: Error 1064: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'Admin FROM Channels LEFT JOIN Schemes ChannelScheme ON Channels.SchemeId = Chann' at line 1"}
{"level":"debug","ts":1603335212.7649376,"caller":"web/handlers.go:100","msg":"Received HTTP request","method":"POST","url":"/api/v4/channels/direct","request_id":"m6s6ikq3p3g47gm4tfukp8o4jh","status_code":"500"}
{"level":"error","ts":1603335213.345216,"caller":"mlog/log.go:229","msg":"Unable to save direct channel.","path":"/api/v4/channels/direct","request_id":"5xm8tfxw4if17k3ifxy5sb553r","ip_addr":"x.x.x.x","user_id":"<masked>","method":"POST","err_where":"CreateDirectChannel","http_code":500,"err_details":"default_channel_roles_select: Error 1064: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'Admin FROM Channels LEFT JOIN Schemes ChannelScheme ON Channels.SchemeId = Chann' at line 1"}
{"level":"debug","ts":1603335213.3453906,"caller":"web/handlers.go:100","msg":"Received HTTP request","method":"POST","url":"/api/v4/channels/direct","request_id":"5xm8tfxw4if17k3ifxy5sb553r","status_code":"500"}
{"level":"error","ts":1603335213.8434176,"caller":"mlog/log.go:229","msg":"Unable to save direct channel.","path":"/api/v4/channels/direct","request_id":"z8jsqpt6hfbsxeae7k9tbzmtja","ip_addr":"x.x.x.x","user_id":"<masked>","method":"POST","err_where":"CreateDirectChannel","http_code":500,"err_details":"default_channel_roles_select: Error 1064: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'Admin FROM Channels LEFT JOIN Schemes ChannelScheme ON Channels.SchemeId = Chann' at line 1"}
{"level":"debug","ts":1603335213.8435194,"caller":"web/handlers.go:100","msg":"Received HTTP request","method":"POST","url":"/api/v4/channels/direct","request_id":"z8jsqpt6hfbsxeae7k9tbzmtja","status_code":"500"}
{"level":"debug","ts":1603335214.9734864,"caller":"app/web_conn.go:419","msg":"websocket.read: closing websocket","user_id":"h4gyrqsu8t86mxunnbbhb7k1gh","error":"websocket: close 1006 (abnormal closure): unexpected EOF"}
{"level":"debug","ts":1603335214.9736311,"caller":"web/handlers.go:100","msg":"Received HTTP request","method":"GET","url":"/api/v4/websocket","request_id":"pqhie38ujjnx3rtp8uw5juqheo"}
{"level":"debug","ts":1603335215.8061407,"caller":"web/handlers.go:100","msg":"Received HTTP request","method":"POST","url":"/api/v4/channels/members/me/view","request_id":"o4jwpdhw73f6tpg6mizt3dr43a","status_code":"200"}

[XxLilBoPeepsxX]

Hi! I think, although I could be wrong, that it looks like there may have been an issue with the upgrade that caused the query line to have been cut off or something along those lines.

My thought process is along the lines of this:

I see that it says LEFT JOIN Schemes ChannelScheme ON Channels.SchemeId = Chann' at line 1"} and it seems like Chann should have been Channel? And maybe with additional statements/text to the query after that? I’m wondering if this may be the cause of the issue or contributing to it. @ahmaddanial would you be able to suggest where to find the web file that contains the code in question so we could view it, to see if there are issues with the queries and statements within the code itself?

[william]

Users are also getting error below when joining a public channel.

[ahmaddanial]

Hi, @XxLilBoPeepsxX

I came across this code at first thanks to some help by my colleagues:

}
    _, err = s.GetMaster().Select(&defaultChannelsRoles, channelRolesSql, channelRolesArgs...)
    if err != nil {
        return nil, errors.Wrap(err, "default_channel_roles_select")
    }

    for _, defaultRoles := range defaultChannelsRoles {

Digging a bit deeper into it, I came across this one:

	channelRolesQuery := s.getQueryBuilder().
		Select(
			"Channels.Id as Id",
			"ChannelScheme.DefaultChannelGuestRole as Guest",
			"ChannelScheme.DefaultChannelUserRole as User",
			"ChannelScheme.DefaultChannelAdminRole as Admin",
		).
		From("Channels").
		LeftJoin("Schemes ChannelScheme ON Channels.SchemeId = ChannelScheme.Id").
		Where(sq.Eq{"Channels.Id": channels})

Tapping back to the line of error:

{"level":"error","ts":1603335213.8434176,"caller":"mlog/log.go:229","msg":"Unable to save direct channel.","path":"/api/v4/channels/direct","request_id":"z8jsqpt6hfbsxeae7k9tbzmtja","ip_addr":"x.x.x.x","user_id":"<masked>","method":"POST","err_where":"CreateDirectChannel","http_code":500,"err_details":"default_channel_roles_select: Error 1064: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'Admin FROM Channels LEFT JOIN Schemes ChannelScheme ON Channels.SchemeId = Chann' at line 1"}

I am still not entirely why the upgrade from 5.23.0 to 5.28.0 broke it.

[XxLilBoPeepsxX]

I think I may see what could be causing the issue.

@ahmaddanial

channelRolesQuery := s.getQueryBuilder().
		Select(
			"Channels.Id as Id",
			"ChannelScheme.DefaultChannelGuestRole as Guest",
			"ChannelScheme.DefaultChannelUserRole as User",
			"ChannelScheme.DefaultChannelAdminRole as Admin",
		).
		From("Channels").
		LeftJoin("Schemes ChannelScheme ON Channels.SchemeId = ChannelScheme.Id").
		Where(sq.Eq{"Channels.Id": channels})

As I interpret this code, I see that Where(sq.Eq{"Channels.Id": channels}) is calling the channel ID to equal the channels that the webserver loads, if I am correct. (please clarify if I’m not, I’d like to learn if nothing else) Perhaps this is as simple as channels needing to be Channels?

I’m also wondering if there is the possibility that the table charsets got changed in the upgrade process, and could be returning what the database engine is thinking is the wrong data. Is that possible?

[william]

Here is a screenshot from the tables list. DB is Channels

[XxLilBoPeepsxX]

What is the charset of the tables though? For example, mine are as shown below:

+------------------+--------------+------+-----+---------+-------+
| Field            | Type         | Null | Key | Default | Extra |
+------------------+--------------+------+-----+---------+-------+
| Id               | varchar(26)  | NO   | PRI | NULL    |       |
| CreateAt         | bigint       | YES  | MUL | NULL    |       |
| UpdateAt         | bigint       | YES  | MUL | NULL    |       |
| DeleteAt         | bigint       | YES  | MUL | NULL    |       |
| TeamId           | varchar(26)  | YES  | MUL | NULL    |       |
| Type             | varchar(1)   | YES  |     | NULL    |       |
| DisplayName      | varchar(64)  | YES  |     | NULL    |       |
| Name             | varchar(64)  | YES  | MUL | NULL    |       |
| Header           | text         | YES  |     | NULL    |       |
| Purpose          | varchar(250) | YES  |     | NULL    |       |
| LastPostAt       | bigint       | YES  |     | NULL    |       |
| TotalMsgCount    | bigint       | YES  |     | NULL    |       |
| ExtraUpdateAt    | bigint       | YES  |     | NULL    |       |
| CreatorId        | varchar(26)  | YES  |     | NULL    |       |
| SchemeId         | varchar(26)  | YES  | MUL | NULL    |       |
| GroupConstrained | tinyint(1)   | YES  |     | NULL    |       |
+------------------+--------------+------+-----+---------+-------+

From your command line, you can get this output by using the command show columns from Channels;

[william]

Here is a screenshot

[XxLilBoPeepsxX]

Hmm it looks like it is as it should be, I think we’re going to need to hear back from @ahmaddanial about the possible issue having to do with capitalization of the C in the channels I referenced previously.

[william]

Looks like the DB/table is case insensitive.

[william]

@ahmaddanial Morning, any chance you could take a look today? It’s affecting new users and I am trying to avoid rolling back especially after a week.

Thanks.

[ahmaddanial]

Hi, @william

I have reached out for more help in the community server. My collation is similar to yours, so I am not entirely sure why the error appears since the capitalization of the Channels table is similar to mine:

mysql>  USE mattermost; SELECT @@character_set_database, @@collation_database;
Database changed
+--------------------------+----------------------+
| @@character_set_database | @@collation_database |
+--------------------------+----------------------+
| utf8mb4                  | utf8mb4_0900_ai_ci   |
+--------------------------+----------------------+
1 row in set (0.00 sec)

mysql> DESCRIBE Channels;
+------------------+--------------+------+-----+---------+-------+
| Field            | Type         | Null | Key | Default | Extra |
+------------------+--------------+------+-----+---------+-------+
| Id               | varchar(26)  | NO   | PRI | NULL    |       |
| CreateAt         | bigint       | YES  | MUL | NULL    |       |
| UpdateAt         | bigint       | YES  | MUL | NULL    |       |
| DeleteAt         | bigint       | YES  | MUL | NULL    |       |
| TeamId           | varchar(26)  | YES  | MUL | NULL    |       |
| Type             | varchar(1)   | YES  |     | NULL    |       |
| DisplayName      | varchar(64)  | YES  |     | NULL    |       |
| Name             | varchar(64)  | YES  | MUL | NULL    |       |
| Header           | text         | YES  |     | NULL    |       |
| Purpose          | varchar(250) | YES  |     | NULL    |       |
| LastPostAt       | bigint       | YES  |     | NULL    |       |
| TotalMsgCount    | bigint       | YES  |     | NULL    |       |
| ExtraUpdateAt    | bigint       | YES  |     | NULL    |       |
| CreatorId        | varchar(26)  | YES  |     | NULL    |       |
| SchemeId         | varchar(26)  | YES  | MUL | NULL    |       |
| GroupConstrained | tinyint(1)   | YES  |     | NULL    |       |
+------------------+--------------+------+-----+---------+-------+
16 rows in set (0.00 sec)

[agarciamontoro (Alejandro García Montoro)]

Hi @william!

I’ve been digging into this and it turns out that the admin keyword is a reserved word for MySQL, but only from version 8.0.0 up until version 8.0.11. It became an unreserved word in 8.0.12 again. See https://dev.mysql.com/doc/refman/8.0/en/keywords.html for more information.

In Mattermost 5.24, we added a new feature that introduced the SQL query mentioned by @ahmaddanial. The culprit of the error you’re seeing is that the query uses Admin as an alias for one of the columns; this line in particular:

ChannelScheme.DefaultChannelAdminRole as Admin

Is it possible for you to update your MySQL installation, at least to version 8.0.12? I am confident that should solve your errors.

In the meantime, I’ll discuss with the team how to better solve this: we can either remove that alias name or simply make sure that we document that the minimum version is 8.0.12.

Thank you for your patience!

[william]

@agarciamontoro Thank you so much! We just finished upgrading the the DB to Mysql 8.0.21 and now bug has be squashed!

[ahmaddanial]

Hi, @william

Great news! Shout out to @agarciamontoro for the assist!