Failed to create column context deadline exceeded when upgrading

Summary

Upgrade times out after 30s because of longer running sql queries

Steps to reproduce

Any step that takes longer then 30s times out during upgrade.

3.3.0 is the current version being upgraded from.

Expected behavior

Describe your issue in detail

Observed behavior

root@mattermostpv1:/opt/backup# sudo -u mattermost /opt/mattermost/bin/mattermost
{“level”:“info”,“ts”:1568939052.7580247,“caller”:“utils/i18n.go:83”,“msg”:“Loaded system translations for ‘en’ from ‘/opt/mattermost/i18n/en.json’”}
{“level”:“info”,“ts”:1568939052.7581768,“caller”:“app/server_app_adapters.go:58”,“msg”:“Server is initializing…”}
{“level”:“debug”,“ts”:1568939052.7587671,“caller”:“utils/html.go:31”,“msg”:“Parsing server templates at /opt/mattermost/templates”}
{“level”:“info”,“ts”:1568939052.7603598,“caller”:“sqlstore/supplier.go:223”,“msg”:“Pinging SQL master database”}
{“level”:“warn”,“ts”:1568939053.116703,“caller”:“sqlstore/upgrade.go:181”,“msg”:“Attempting to upgrade the database schema version from 3.3.0 to 3.4.0”}
{“level”:“warn”,“ts”:1568939053.2579632,“caller”:“sqlstore/upgrade.go:176”,“msg”:“The database schema has been upgraded to version 3.4.0”}
{“level”:“warn”,“ts”:1568939053.2582364,“caller”:“sqlstore/upgrade.go:181”,“msg”:“Attempting to upgrade the database schema version from 3.4.0 to 3.5.0”}
{“level”:“error”,“ts”:1568939083.5785387,“caller”:“sqlstore/supplier.go:554”,“msg”:“Failed to create column context deadline exceeded”}

Tried setting longer read/write timeouts but they don’t seem to apply.

config/config.json.

Server Settings:
“ReadTimeout”: 300,
“WriteTimeout”: 300

SqlSettings:
“DataSource”: “mattermost:password@tcp(127.0.0.1:3306)/mattermost?charset=utf8mb4,utf&readTimeout=300s&writeTimeout=300s”,

Example query:

mysql> show processlist;
±—±-----------±----------------±-----------±--------±-----±------------------±--------------------------------------------------------+
| Id | User | Host | db | Command | Time | State | Info |
±—±-----------±----------------±-----------±--------±-----±------------------±--------------------------------------------------------+
| 5 | mattermost | localhost:54928 | mattermost | Query | 214 | copy to tmp table | ALTER TABLE Posts ADD FileIds varchar(150) DEFAULT ‘’ |
| 6 | root | localhost | NULL | Query | 0 | starting | show processlist |
±—±-----------±----------------±-----------±--------±-----±------------------±--------------------------------------------------------+

Never mind… found it. There is a setting for QueryTimeout

/opt/mattermost/bin/mattermost config show (will show all available settings)

"SqlSettings": {
    "DriverName": "mysql",
    "DataSource": "mattermost:password@tcp(127.0.0.1:3306)/mattermost?charset=utf8mb4,utf&readTimeout=300s&writeTimeout=300s",
    "DataSourceReplicas": [],
    "MaxIdleConns": 10,
    "MaxOpenConns": 10,
    "Trace": false,
    "AtRestEncryptKey": "Dc8951XufgA46DBQ+rnVSFrwylbnZWkF",
    "QueryTimeout": 300
},
1 Like

Actually now it just gets stuck here:

root@mattermostpv1:/opt/mattermost# sudo -u mattermost /opt/mattermost/bin/mattermost
{“level”:“info”,“ts”:1568946767.8535483,“caller”:“utils/i18n.go:83”,“msg”:“Loaded system translations for ‘en’ from ‘/opt/mattermost/i18n/en.json’”}
{“level”:“info”,“ts”:1568946767.8536906,“caller”:“app/server_app_adapters.go:58”,“msg”:“Server is initializing…”}
{“level”:“debug”,“ts”:1568946767.8542275,“caller”:“utils/html.go:31”,“msg”:“Parsing server templates at /opt/mattermost/templates”}
{“level”:“info”,“ts”:1568946767.855562,“caller”:“sqlstore/supplier.go:223”,“msg”:“Pinging SQL master database”}
{“level”:“debug”,“ts”:1568946767.9272604,“caller”:“sqlstore/preference_store.go:41”,“msg”:“Deleting any unused pre-release features”}

Hi @kcorupe, these docs might help as a next step: