読者です 読者をやめる 読者になる 読者になる

kariaの日記 @ Alice::Diary

フフーン、ノリツッコミの鳩子がはてなブログ書いちゃうよー

kariaの日記です。本家サイトはside=2です。Twitter ID:@karia
過去記事へのリンクとかは最下部参照。

slackのreminderの日時指定がわかりにくかったのでメモ

みんな大好きチャットツールのslackですが、reminder機能の日時指定の方法がわかりにくくて試行錯誤してしまったのでメモっておく。

サンプル

/remind #channel_name on 02/10/2016 at 10:00am to メッセージ本文

説明

  • on:日付を設定
  • at:時間を設定
  • to:メッセージ本文

試行錯誤したところ

onの日付の設定がなかなかうまくいきませんでした。

何故か?

YYYY/MM/DD (年/月/日) の順序で書いていましたが、この年月日の順序こそが誤りでslackに無視され続けていました。

実際には MM/DD/YYYY (月/日/年) の記法で書くのが正解。日本人にはなじみが薄い書き方なので、ヘルプを見るまで気付きませんでしたよ……。

ヘルプ(公式):

get.slack.help

余談

ちなみにon,at,toの順序性は特にないですが、書き方によっては誤った記法で指定した on の日付がメッセージ本文の一部として認識されてしまったりするので注意が必要です。柔軟すぎるのも中々考え物だなぁ。

My Space

My Space

誕生日なのでMySQLの話をする(その2)

この記事は、animateLAB Advent Calendar 2015 13日目の記事です。

こんばんは、kariaです。きょうは昨日の「誕生日なのでMySQLの話をする(その1)」の続きを書こうと思います。

これまでのあらすじ

MySQLのデータ(本番環境)を過去のダンプファイルで上書きされちゃった!?どーしよ!?

復旧までの道のり

我々の手元に残されたデータは以下の2つです。

  • 早朝のデータ移行時に使用したダンプファイル
  • MySQLのデータディレクトリ一式(←夕方に上書きされちゃったやつ)

上書きされちゃったやつはもはやどうしようもないし、早朝時点のダンプファイルを使って再構築し直してその日中帯のトランザクションは諦めるか、という案もありました。とはいえ、「諦めって言われてもその間のトランザクションは具体的にどうするんだ、ログから全部洗うか?」という事になりますし、「無くなりました、ゴメンナサイ」ということにはしたくないものです。

ここでMySQLのとあるオプションを思い出してみましょう。

log_bin         = /var/lib/mysql/mysql-bin.log
expire_logs_days        = 0

これはバイナリログの保存先ディレクトリと、どれぐらいの期間でexpire(削除)するかというオプションです。バイナリログは通常MySQLレプリケーションを実現するために使用されます(マスターDBが差分をバイナリログファイルとして出力して、スレーブDBが取り込んで反映する)。MySQLのデータディレクトリが肥大化するのを防ぐため、バイナリログをexpireされるまでの日数を小さく制限するというTIPSをよく見かけます。

が、MySQL リファレンスマニュアルにあるバイナリログの項目を読むと以下のように記載されています。

バイナリロギングを有効にしてサーバーを実行すると、パフォーマンスがいくらか低下します。ただし、レプリケーションをセットアップでき、リストア操作に対応できるというバイナリログの利点は、一般的にこのパフォーマンスの減少よりも重要です。

そう、バイナリログはリストア操作のためのバックアップとしても機能します。ということは

早朝のデータ移行時に使用したダンプファイル + 早朝~夕方(サイト閉鎖直前)までのbinlog ⇒ サイト閉鎖直前までの完全なデータが帰ってくる!!!

やったー!!ということで夜を徹しての復旧作業が始まりました。

具体的な復旧手順

バイナリログからのリカバリですが、具体的には、mysqlbinlogというユーティリティーを使用します。使用方法は以下の通り。

# mysqlbinlog (binlog_filename)

※手元の環境で試したところ、一般ユーザで実行するとPermission deniedと言われてしまったのでroot権限で実行しています。

すると、以下のようにトランザクションの中身が平文で表示されます。

# at 684657
#151213 23:25:52 server id 1  end_log_pos 684657 CRC32 0x3e4f5587       Intvar
SET INSERT_ID=1268556/*!*/;
#151213 23:25:52 server id 1  end_log_pos 684989 CRC32 0x25bc1ac9       Query   thread_id=36    exec_time=0     error_code=0
SET TIMESTAMP=1450016752/*!*/;
insert into log (is_notice,nick_id,channel_id,log,created_on,updated_on) values ('0','42','1','うんっ!行くよっ!いつも、今が、最高でしょ!れでぃーごー! 14(aije) (from Alice Cartelet)',now(),now())
/*!*/;

平文で表示されますので、そのままパイプでmysqlコマンドに食わせても良いですし、ファイルに出力したりgrepしたりしても構いません。なお上記サンプルは、tiarraMetroに付属するLog::DBIというtiarraのmoduleを利用して、私がTwitterに以下のような発言をした際に発行されたinsert文です。

このコマンドがあれば実質的にMySQLへ発行された更新系のクエリを全て追うことができ、非常に便利なコマンドですので覚えておきましょう。

さて、これを踏まえて具体的な復旧手順は以下のようになります。

  1. 早朝時点のデータダンプを改めてインポートする
  2. mysqlbinlogユーリティティを使用して早朝時点~夕方(サイト閉鎖時点)までのトランザクションをバイナリログから取りだす
  3. インポートしたdatabaseに上記トランザクションを適用する

かんたん3ステップ!というように見えますがそうはいきません。

2ステップ目で「早朝時点~夕方(サイト閉鎖時点)までのトランザクションをバイナリログから取りだし」と書いてますが、MySQLのバイナリログはmysql-bin.000001といったように無機質な連番でファイルが作成されていくので、一見してどこからどこまでが適用対象のトランザクションなのかがわかりません。ただ、一定のファイルサイズを超えると次の番号のファイルへ出力されるようになるのと、上記で示したようにトランザクション実行日時がコメントアウトされた形で示されていますので、ファイルのタイムスタンプとトランザクション実行日時を手がかりに当該のトランザクションを全て洗い出します。これ自体は手作業(目視)で行うことになりました。

これらの作業をたまたま空いていた別環境を用意して検証し、トランザクション適用で1件もエラーが出ないこと・夕方時点までのトランザクションが実際に入っていることを確認した上で、本番環境で実施・およびアプリケーションの動作確認・メンテナンスモード解除といった流れとなりました。また、これら作業の中で「default charset=utf8つけた???」と親の敵のように何度も確認したことも忘れられない思い出です。

データ量にもよりますがこれらの作業にはそれなりの時間がかかります。確かトランザクションの適用中のことだったと思うのですが、日付が変わったあとどこかで「昨日誕生日だったんですよね……」と漏らしたところ、当時の上司がケーキを買ってきてくれるという出来事がありました。バイナリログから復旧させるというアイデア自体も私ではなく別の上司のアイデアですし、1人できる復旧作業ではありませんでしたので当時の同僚や上司には本当に感謝しています。

ということで、私の中で「誕生日といえばMySQL」という謎のワードが生まれたきっかけになった出来事をご紹介しました。mysqlbinlogコマンドは大変便利ですので是非活用しましょう。また、log_binオプションはデフォルトだと無効になっているので、レプリケーションを行わない環境であっても有効にしておくと良いでしょう。

誕生日なのでMySQLの話をする(その1)

この記事は animateLAB Advent Calendar 2015 12日目の記事です。

ということで12月12日を迎えました。本日は私の誕生日です。おめでとうございます。ありがとうございます。

誕生日といえばなんとなくAmazonウィッシュリストを貼ってなんとなく送りあう文化がありますが、さすがにこの記事に貼るのはやめておきます。誕生日といえば、MySQLです。

数年前の誕生日のこと、0時を過ぎて誕生日になり、SNSにウェーイって感じでウィッシュリストのURLを貼りながら、とあるサイトがメンテナンス表示になったのを確認して寝ました。その日は、サーバーの老朽化に伴い別サーバーへの移行が行われる日だったのです。

サーバーの移行って、新サーバーに引っ越し終われば(DNSの切り替えが済めば)完了でしょうか?たいていの場合はそのようなことはなく、引っ越し終わってからがお祭りの始まりです。

翌朝、出社してから報告があった主な出来事は次のようなものでした。

  • なんかたまにエラーがでる
  • なんかたまに文字化けしてる

「なんかたまにエラーがでる」はDNS切り替え手順にまつわる話であんまり大したことはないので置いておくとして、厄介なのは「なんかたまに文字化けしてる」のほうです。文字化け自体厄介なのに「たまに」って何だよって話です。

とにかく文字化けしたデータをなんとかしなくてはなりませんので、「なんかたまにエラーがでる」をなんとか夕方ぐらいまでに潰し、文字化けの調査・検証を本格的に始めようとしたときにそれは起きました。

な ん か デ ー タ が 消 え て い く

さすがに目を疑いました。全く同じ結果が返ってくるはずのSELECT文を何回か投げると毎回結果が減っていくのです。恐怖しかありません。

仕方ないので、サイトを閉鎖し本格的に原因調査が始まりました。結論から言うと原因は以下のようなものでした。

  • 文字化けの原因:データ移行作業中に行ったMySQLのデータインポート時に、"default charset"の指定が足りない箇所があった
  • データが消えていく原因:とある作業者が文字化けの検証のためにデータダンプを別のdatabase指定でデータインポートをしようとしたところ、誤って本番のdatabaseに上書きしてしまった

文字化けが発生したのは、MySQLのdatabaseやtableにdefault charsetを指定していなかっため,tableの文字コードはlatin1なのに実データはutf8みたいなミスマッチが起こってしまったためです。しかもアプリケーションとのJDBC接続においてutf8かどうか明示的に指定してたりしてなかったりしたため、「たまに文字化けする」という事象につながった記憶があります。

このような事象MySQLのテーブル作成がカッチリとutf8で行われていれば発生しませんでしたので、単に指定漏れですね。

問題なのは後者です。たまに本番作業をしていると「このコマンドミスったら本番のdatabase上書きだなー怖いな-」といった場面に出くわすことがありますけど、本当に上書きされてしまった現場に遭遇するとは思いませんでした。

どうする折部やすな。

明日へ続く!!