お金をかけずにサーバーの勉強をしよう

[障害対応例] Mattermostインストールと MySQL

2024年5月19日
メニューへ戻る

Mattermostを MySQL8.4で動かそうとして問題が出た際の調査の例を書いてみました。

このようなコンテンツに需要があるか分からないのですが、サーバーインフラ系の作業で問題が出た時の調査をこんな風にやりましたって話を書いてみたいと思います。

サーバーエンジニアは運用に携わっている事が多かろうと思われ、障害発生時の対応の詳細、どういう風に考えてその結論に至ったかといった思考のプロセスは結構大事なノウハウになると思うのですが、このような観点で残された記録はほとんど見たことがありません。

今回 Mattermostを MySQLを使って稼働させようとしたときに、手頃な(?)問題が発生しましたので、私がどう考えて何を調べたのか、その思考プロセスを綴ってみたいと思いました。

結果が分かってしまえば、それまでのプロセスなどどうでも良い気がしてしまいますが、ご興味があれば読んでみると何か拾えるものがあるか知れませんよ。


A．何をしようとしたか

「Mattermostインストール」を最新バージョンを使った内容にアップデートしようとしました。

そのため以下の環境を容易しました。

OSUbuntu Server 24.04
データベースMySQL 8.4
ミドルウェアMattermost Community Edition 9.8.0

2024年5月19日時点での最新も最新のセットです。


B．何が起きたか

Mattermost構築作業のうち、systemdを使って Mattermostを起動しようとして失敗します。

コマンド的にはこれをやった時です。 

subro@UbuntuServer2404-2:~$ sudo systemctl start mattermost

Mattermostは初めての起動時だけ、MySQLの [mattermostdb]データベースに対して、MySQLの [mmuser]ユーザーで必要なテーブルを作ります。

この過程でエラーとなり、Mattermostが立ち上がらないのです。


ここから以下が調査内容となります。


１．systemdのログ確認

systemdでの起動時に失敗したときは、systemctl statusコマンドで対象のサービスの状態を調べます。 

subro@UbuntuServer2404-2:~$ sudo systemctl status mattermost
● mattermost.service - Mattermost
     Loaded: loaded (/usr/lib/systemd/system/mattermost.service; enabled; preset: enabled)
     Active: activating (auto-restart) (Result: exit-code) since Sun 2024-05-19 20:08:13 JST; 1s ago
    Process: 1993 ExecStart=/opt/mattermost/bin/mattermost (code=exited, status=1/FAILURE)
   Main PID: 1993 (code=exited, status=1/FAILURE)
        CPU: 419ms

起動に失敗している、ということだけは分かりました。

systemdでは対象のプログラムが吐いたメッセージを journaldが拾ってくれていますので、journalctlコマンドで [mattermost.service]ユニットからのものに限定して詳細なログを見てみます。

journalctlコマンドに与える引数は 2つ。

-nログの後ろから n行を表示する
-u対象の(サービス)ユニット名を指定する

ちょっと長いですが、全部載せます。
横に伸びてしまってるのはご容赦下さい。
実際の journalctlコマンドの出力結果もこんな感じなので。

subro@UbuntuServer2404-2:~$ journalctl -n 100 -u  mattermost.service
 5月 19 20:24:09 UbuntuServer2404-2 systemd[1]: Failed to start mattermost.service - Mattermost.
 5月 19 20:24:19 UbuntuServer2404-2 systemd[1]: mattermost.service: Scheduled restart job, restart counter is at 137.
 5月 19 20:24:19 UbuntuServer2404-2 systemd[1]: Starting mattermost.service - Mattermost...
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: {"timestamp":"2024-05-19 20:24:19.605 +09:00","level":"info","msg":"Server is initializing...","caller":"platform/service.go:175","go_version":"go1.21.8"}
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: {"timestamp":"2024-05-19 20:24:19.606 +09:00","level":"info","msg":"Pinging SQL","caller":"sql/sql_utils.go:67","database":"master","dataSource":"****:****@unix(/run/mysqld/mysqld.sock)/mattermostdb?charset=utf8mb4%2Cutf8"}
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: {"timestamp":"2024-05-19 20:24:19.621 +09:00","level":"info","msg":"Pinging SQL","caller":"sql/sql_utils.go:67","database":"master","dataSource":"****:****@unix(/run/mysqld/mysqld.sock)/mattermostdb?multiStatements=true&charset=utf8mb4%2Cu
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: Error: failed to initialize platform: cannot create store: failed to apply database migrations: driver: mysql, message: failed when applying migration, command: apply_migration, originalError: Error 1064 (42000): 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 'Manual tinyint(1) DEFAULT NULL,
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     LastActivityAt bigint(20) DEFAULT NULL,
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     ' at line 4, query:
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: CREATE TABLE IF NOT EXISTS Status (
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     UserId varchar(26) NOT NULL,
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     Status varchar(32) DEFAULT NULL,
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     Manual tinyint(1) DEFAULT NULL,
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     LastActivityAt bigint(20) DEFAULT NULL,
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     PRIMARY KEY (UserId)
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: ) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4;
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: SET @preparedStatement = (SELECT IF(
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     (
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:         SELECT COUNT(*) FROM INFORMATION_SCHEMA.COLUMNS
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:         WHERE table_name = 'Status'
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:         AND table_schema = DATABASE()
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:         AND column_name = 'ActiveChannel'
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     ) > 0,
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     'ALTER TABLE Status DROP COLUMN ActiveChannel;',
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     'SELECT 1'
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: ));
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: PREPARE alterIfExists FROM @preparedStatement;
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: EXECUTE alterIfExists;
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: DEALLOCATE PREPARE alterIfExists;
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: SET @preparedStatement = (SELECT IF(
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     (
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:         SELECT COUNT(*) FROM INFORMATION_SCHEMA.STATISTICS
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:         WHERE table_name = 'Status'
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:         AND table_schema = DATABASE()
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:         AND index_name = 'idx_status_status'
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     ) > 0,
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     'SELECT 1',
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     'CREATE INDEX idx_status_status ON Status(Status);'
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: ));
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: PREPARE createIndexIfNotExists FROM @preparedStatement;
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: EXECUTE createIndexIfNotExists;
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: DEALLOCATE PREPARE createIndexIfNotExists;
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: SET @preparedStatement = (SELECT IF(
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     (
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:         SELECT COUNT(*) FROM INFORMATION_SCHEMA.COLUMNS
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:         WHERE table_name = 'Status'
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:         AND table_schema = DATABASE()
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:         AND column_name = 'DNDEndTime'
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     ) > 0,
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     'SELECT 1',
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     'ALTER TABLE Status ADD COLUMN DNDEndTime BIGINT;'
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: ));
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: PREPARE alterIfNotExists FROM @preparedStatement;
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: EXECUTE alterIfNotExists;
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: DEALLOCATE PREPARE alterIfNotExists;
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: SET @preparedStatement = (SELECT IF(
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     (
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:         SELECT COUNT(*) FROM INFORMATION_SCHEMA.COLUMNS
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:         WHERE table_name = 'Status'
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:         AND table_schema = DATABASE()
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:         AND column_name = 'PrevStatus'
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     ) > 0,

最初の方の右の方、ピンクの箇所に何か出ています。

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 'Manual tinyint(1) DEFAULT NULL,

「'Manual tinyint(1) DEFAULT NULL,」の近くに文法エラーがあるって言っています。

そもそも「'Manual tinyint(1) DEFAULT NULL,」とは何なのかなんですが、ここで過去の経験からくる気づきがありました。


２．SQL文と特定

「'Manual tinyint(1) DEFAULT NULL,」という文字列から、データベースをやったことがある私は「これは SQL文くさい。CREATE TABLE文の一部だろ！」って思ったんですね。

ログのうちエラーが出ている該当行の次以降はこうなっています。 

 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     LastActivityAt bigint(20) DEFAULT NULL,
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     ' at line 4, query:
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: CREATE TABLE IF NOT EXISTS Status (
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     UserId varchar(26) NOT NULL,
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     Status varchar(32) DEFAULT NULL,
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     Manual tinyint(1) DEFAULT NULL,
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     LastActivityAt bigint(20) DEFAULT NULL,
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     PRIMARY KEY (UserId)
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: ) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4;

ピンクの箇所、唐突な感じのログになっています。

「'」(シングルクォート)で始まる文ってナンだよ？！
このインデントは？

って思いました。
「'」も「"」も普通は 2つで 1対として使われることが普通のはずです。
(ということも経験的に気づきました)

「'」のもう 1つを辿るとですね、こういう塊であることが分かるのでした。

'Manual tinyint(1) DEFAULT NULL,
    LastActivityAt bigint(20) DEFAULT NULL,
    ' at line 4, query:

以下 2行を含む SQL文の 4行目に文法エラーがあると言ってるのではないでしょうか。
こう並べてみると、いかにも CREATE TABLE文の一部だって思います。 

Manual tinyint(1) DEFAULT NULL,
LastActivityAt bigint(20) DEFAULT NULL,

そして、ログを眺めていて思うのでした。

上の 2行はこの箇所と酷似…というか同じではないか。 

 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     LastActivityAt bigint(20) DEFAULT NULL,
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     ' at line 4, query:
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: CREATE TABLE IF NOT EXISTS Status (
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     UserId varchar(26) NOT NULL,
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     Status varchar(32) DEFAULT NULL,
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     Manual tinyint(1) DEFAULT NULL,
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     LastActivityAt bigint(20) DEFAULT NULL,
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]:     PRIMARY KEY (UserId)
 5月 19 20:24:19 UbuntuServer2404-2 mattermost[3006]: ) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4;

ログの出方がどうなってるのか良く分かりませんが、対象の CREATE TABLE文ってこれのことでしょう。 

CREATE TABLE IF NOT EXISTS Status (
     UserId varchar(26) NOT NULL,
     Status varchar(32) DEFAULT NULL,
     Manual tinyint(1) DEFAULT NULL,
     LastActivityAt bigint(20) DEFAULT NULL,
     PRIMARY KEY (UserId)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4;

上のピンクの行が問題と思われる 4行目です。

ですけど、CREATE TABLE文として文法に問題があるようには見えないんですよね。
間違ってません。


3．間違いのない CREATE TABLE文

文法的な間違いは無いはずなのに、ここでエラーになるという不思議。

おもそもの切り分けとして「これホントにエラーになんの？」を確認するため、mysqlコマンドで当文を実行してみます。

対象の CREATE TABLE文はさして特殊なわけでもないので、仮にこの作業でテーブルができちゃっても、dropしてやりゃ良いのですし。

文法エラーになるかどうかなので、MySQLの [root]ユーザーを使っちゃってます。 

mysql> use mattermostdb
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed

mysql> CREATE TABLE IF NOT EXISTS Status (
    ->       UserId varchar(26) NOT NULL,
    ->       Status varchar(32) DEFAULT NULL,
    ->       Manual tinyint(1) DEFAULT NULL,
    ->       LastActivityAt bigint(20) DEFAULT NULL,
    ->       PRIMARY KEY (UserId)
    ->  ) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4;
ERROR 1064 (42000): 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 'Manual tinyint(1) DEFAULT NULL,
     LastActivityAt bigint(20) DEFAULT NULL,
   ' at line 4

しっかりエラーになるんですよね、これが。

問題箇所を特定するため、関係なさげな行を削ってみました。 

mysql> CREATE TABLE IF NOT EXISTS Status (
    ->       Manual tinyint(1) DEFAULT NULL);
ERROR 1064 (42000): 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 'Manual tinyint(1) DEFAULT NULL)' at line 2

更に小さく。 

mysql> CREATE TABLE Status (
    ->       Manual tinyint(1));
ERROR 1064 (42000): 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 'Manual tinyint(1))' at line 2

「もう完全にココだよ」と特定ができましたが、やっぱり文法的な誤りはありません。
tinyintのバイト数の指定でも間違ってるんでしょうか。

ここで経験的にある用語が脳裏を過(よぎ)り、こんな文を実行してみます。 

mysql> CREATE TABLE Status (
    ->       Manual char(1));
ERROR 1064 (42000): 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 'Manual char(1))' at line 2

「ﾊｧ?!」、tinyintじゃ無かったらもう「Manual」しか残ってないじゃん!!


４．予約語

先の確認で私の脳裏を過ったのは「予約語」というコンピューター用語で、プログラム開発言語で良く出てきますが、

文法上特別な意味を持つため変数名などには使えない単語

とでも言えば良いでしょうか。

でね、これ、データベースにもあります。

多分 MySQLでは「Manual」って列(カラム)名に使えないんですよ。

そこで、MySQL 8.4の公式ドキュメントを見ますとこんな箇所が。
MySQL 8.4 New Keywords and Reserved Words

ウム、ありよるわ。
MANUAL

[(R)]ってなにかと思えば、こう書いてあります。
The following list shows the keywords and reserved words that are added in MySQL 8.4, compared to MySQL 8.0. Reserved keywords are marked with (R).

MANUALさんは 8.4でデビューだそうです。


５．原因

初回起動時に [Status]テーブルを作ろうとした際に、[Manual]列を作れずにエラーとなっている。
多分 Mattermostはこの SQL処理のエラーを起点に、Mattermost全体をエラーとして停止している。

※真の原因はリリースされたばかりの MySQL 8.4に未対応ってことです。


６．対応

①カラム名を変える
[Manual]という使えないカラム名を使えるものに変える。
しかしこの [Status]テーブルは、プログラムの中で結構色々なところからアクセスされていそうな気がする。
製造元も頭を抱えているのではないか？

②無理矢理「Manual」を使用継続する
[`](バッククォート)で括ってやると予約後の制限を回避できるそうである。
しかし MySQL 8.4が「今後『MANUAL』は使うんじゃねーゾ、分かったな？」と言っている以上、あまり良くない手である。
製造元がそんなことしないと思いますが…。

③PostgreSQLを使う
負けた気がする。


＝＝＝＝＝＝＝＝＝＝
最初から最後まで読むと、追体験できましたかね。

結局この問題は、Mattermostが MySQL 8.4に対応してくれるかどうかにかかっているので、私は待つしかありません。

実際はここに書いたよりもうちょっと紆余曲折していますが、判断ポイントはほぼこんな感じでした。

自分で書いてみて、「経験的に」気付いていたところがありますね。

どれだけの引き出しをを自分の中に持っていられるか、お勉強することで知識を溜め込むことはできます。

ただその引き出しに適宜アクセスできるかが経験なのかな〜と思います。
この点だけは残念ながら初心者には難しいかも知れません。