「DMM.com Labo ツチノコ杯」第4回ICTトラブルシューティングコンテスト 問題解説 “Redmineの意図しない挙動の調査について (Survey of behavior not intended for Redmine)”

こんにちは、whywaitaです。
「DMM.com Labo ツチノコ杯」第4回ICTトラブルシューティングコンテスト にて運営委員を務めさせて頂きました。

「DMM.com Labo ツチノコ杯」第4回ICTトラブルシューティングコンテスト(以下、トラコン)では全部で13問の問題が出題され、その全てが学生の手によって作問されました!
今回はトラコン初の試みとして、問題文の公開、及び、作問者自身による問題解説を行いたいと思います!

問題文(出題したそのまま)を公開します!

Redmineの意図しない挙動の調査について (Survey of behavior not intended for Redmine)

問題文(Problem statement)

最近入社した社員が、Redmineでエラーを起こしたらしい。
A junior engineer caused the error on Redmine.

「若手で1番優秀な僕がエラーを出すことはありえないですよ!バグなんて絶対作りません!」
“There is no possible way that there is something wrong with my configuration. I absolutley do not create bugs!”

Redmineに発生した挙動を判断し、新入社員が再び操作しても壊れないようにしてください。
Determine the error occurred on Redmine.

症状(Symptom)

  • 新人社員がRedmineを操作した所、意図していない挙動が発生している。(After the junior engineer changed the configuration for Redmine/Server, it started to malfunction.)
  • 新人社員が操作した後は誰も操作を行っていない。(No one has touched the server after the junior engineer.)

チェックポイント(Checkpoint)

新入社員が再び同じ操作しても壊れないようにしてください。
Even if the junior employee carries out the same steps he has done before, Redmine should not show any error.

問題解説

この問題を解くのに必要なのが、「ログを読む力」と「ミドルウェアへの理解」でした。
トラコンは初期からネットワーク系の問題が非常に多い傾向にあり、多くのミドルウェアに対する問題が問われる事が少なかったため、本問題ではそれに反してRuby on Railsで開発されているRedmineをベースとした問題を取り扱いました。

解法

最初に運営側が想定していた解法についてお伝えしたいと思います。
※一部ログなどが出ますが、記事作成用に問題を再現した環境を作成しており、問題環境そのままでないことをご了承ください。

ログのバックアップを取る

これは通常のオペレーションではあまり取り扱われないことではないかと思うのですが、今回はどのタイミングで新入社員が不正な挙動を行ったかのヒントが少ないです。
通常であれば時間ベースで追いかける事も出来ると想うのですが、コンテストである性質上問題文中に「新人社員が操作した後は誰も操作を行っていない。」という文面を盛り込みました。この文面から、各種ミドルウェアのログのバックアップ(障害が起きているであろう箇所)を取ると問題が解きやすかったかもしれません。

エラーログを探す

ここで「ログを読む力」が生きてきます。
ApacheやNginxなどのwebサーバのアクセスログが、1アクセス=1行に対して、Redmine(というよりRails)はそれ以上のログを生み出します。
このような時に、「どのようなログであるか」「どのように抽出すれば上手くエラー箇所だけを抜き出すことができるのか」を即座に判断する必要があるのです。
ここで、「すぐにお手製のワンライナーを書けるのか?」という疑問が出てきます。これは、普段からシェルで色々な文章を扱っている人で無ければ難しいかもしれません。

ということで、抽出したログが以下になります。
自分の場合はHTTPステータスコードでエラーが吐いている事から、grepコマンドの検索を使って検索しました。

原因を見つける

このログを見つければ原因自体は分かりそうです。
Redmineが利用しているデータベース(今回はMySQLでした)に問題がありそうですね。
ついでに”U+1F60A”という見慣れない単語が見えます。これは何なのでしょう?

検索してみると分かりますが、これは「絵文字」です。皆さんもslackやHipChatなどで利用しているかもしれませんね。
通常のUTF-8で設定されているMySQLデータベースに絵文字を入れようとして、エラーを出力しているようです。
ここを解決出来れば、何とかなりそうですね!

対処する

原因が判明したのであれば、それを解決するだけですね。
MySQLの設定ファイルはmy.cnfです。今回の環境であれば/etc/mysql/my.cnfにあるので、ここを編集します。
[mysqld]セクションに以下の文字列を追加すると良いでしょう。

設定ファイルを書き換えたら、MySQLの再起動を行います。これでMySQLがutf8mb4に変更されました!

対処する(その2)

回答を見ていると、上記の対応をして回答としているチームが散見しました。
原因を発見出来ていて素晴らしいのですが、ここで問題文のチェックポイントを見返してみましょう。
「新入社員が再び同じ操作しても壊れないようにしてください。」とありますね。
実はこのままでは「再び同じ操作をした時」同じエラーが出ないとも限りません。それは何故か?既存のデータベースがUTF-8のままだからです

ここが残念ながら出来てなかったチームが多かったです。(勿論この処理を行ったチームをいらっしゃいました!)
既存のデータベースをしっかり変換して、ようやく完答となります。お疲れ様でした。

まとめ

通称「Redmine絵文字問題」、如何だったでしょうか?
Redmineが利用している言語であるRubyはマルチバイト文字にデフォルトで対応しているのですが、MySQLを初めとするバックエンド類はまだまだデフォルト対応とは言えない物が多いように思えます。
最近は海外でも”emoji”の愛称で呼ばれるようになった日本発祥の文化「絵文字」を取り扱う事も多くなるので、動向・扱い方はしっかり捉えていきましょう!

余談

「Redmine 絵文字」で検索すると、かなり上の方にこのブログ記事が出てきます。

Redmine構築後のDBの文字コードをutf8mb4に変換して絵文字に対応する – Dig that groovy!

このブログを読むと完答までの流れが書いてあるのですが、実はこのブログの筆者はトラコンの運営委員だったのです!
参加者の方の中にはこのブログを読んだのかな?と思われる回答もありましたが、本人は複雑な表情をしていました(笑)


PAGE TOP