2019年 作った・喋ってきたまとめ
振り返り的なやつです。
去年の振り返りはこちらです。
ISUCON9 予選出題した
bokko, catatsuy, sota1235 とともにISUCON9の予選出題をやらせていただいた。7月から9月にかけて圧倒的に手を動かした。
解説と講評のほか、ローカル環境で予選問題を動かす方法についての記事を書かせてもらった。
参加していただいた方、出題メンバー、各言語への移植をやっていただいた皆様、さくらインターネットの皆様、アリババクラウドの皆様、そして941さんをはじめLINEの皆様、改めて感謝です。
作った
percentile
説明はないが、簡単にpercentileを求められるようにするコマンドです。
$ grep status:499 access.log|lltsv -K -k ptime|percentile count: 353 avg: 0.0088 95pt: 0.0440 90pt: 0.0400 75pt: 0.0030
grep、jqやlltsvと組みあわせると便利
mackerel-plugin-axslog
mackerel-plugin-accesslogで少し足りない機能があったので作った。一度つくった上で、より速いやつが書けそうだと思って書き直したら速くなった。
blogも書いている
「秒間2万req、1分間で120万行のログが記録される、よくある環境」はほんの少し盛っている
ppdp
某DBサーバへの通信のログを取りたいということで作った。アクセス元も必要なのでproxy protocol対応を行なった。
どこか => [tcp] => nginx stream => [proxy proto] => ppdp => [tcp] => mysql
のように使う。
名前はペンパイナッポーアッポーペンからきている
deteco
公開鍵で暗号化したJWTをnginxのauth_requestで認証するための、簡単な認証サーバ
TCP over websocket と組み合わせて使うことを考えていた。
mackerel-plugin-log-incr-rate
2つのログの増える行数の比率を出すmackerel plugin。アプリケーションのログが爆発したときに書いた。
Go言語の初期状態のbufio.Scannerは1行の長さが65kを越えると、すぎゃんをやめてしまう仕様なのだが、その中で1MBを越えるログが発見された思ひでも
mackerel-plugin-postfix-log
メール送信をインストール型のソフトウェアからクラウド型のサービスに切り替えたので、中継サーバとしてのpostfixの監視重要性が高まったので書いた。
メトリクスはいくつか増えるが、役に立っているかどうか聞かれると、そんな役に立ってない。まだ。
consul-service-has-ip
指定したconsulのサービスに、任意のIPアドレスが含まれるかどうか確認するのを簡単にするAPIサーバ。
Slaveサーバの分散・切り離しに必要になって作ったが、もっと良い別の方法を発見し、3日ぐらいでお蔵入り。書いたからってそこにしがみつかないことも大事。
mackerel-plugin-pinging
データセンター間の通信を普段からモニタリングしていくために作った。
Mackerel アドベントカレンダーの記事として紹介している
成功失敗だけではなく、RTTのパーセンタイルもでるので、便利。
myps
MySQLのprocesslistをgrepしたり、思いの強いクエリKILLするのに便利なコマンド。便利ツールはいざと言う時に思い出さず、やくに立たないので、作ったことを自分で忘れないようにblogも書いた。
grepとlltsvで別の監視に使うことも考えている。
喋ってきた
なんと2回しか喋ってない
第22回 Lucene/Solr勉強会 10/28
検索まわりのこれまでストーリーを短めに紹介させてもらった。
タイトル・構成はYAPC::Asia 2007 の際の Brad Fitzpatrickの発表「LiveJournal: Behind The Scenes」のインスパイアです
Mackerel day #2 12/23
ここ1年で作ってきたプラグインやDB周りの監視について課題を交えながら紹介した。見事に時間オーバーした。
--
先日、10年ぶりぐらいにデータセンターにて、1Uサーバのハードウェアを増設する作業を行なった。以前は作業していると手がいつのまにか赤くそまっているようなことがあったが、サーバもサーバをマウントするレールもラックも非常に精度が高く作られており、スムーズにきっちりと動くことに非常に感動した。こういった機器を設計、製造する方々のおかげで我々の業務が成り立っているとの思いを新たにした。
家族、チームのメンバーに感謝するとともにお客様に信頼性や価値を届けるため、面白かっこいいぜ！な仕組みの構築運用に取り組んで行きたい
MySQLのprocesslistをgrep して killする myps コマンド
なんらかの理由で MySQLにクソ重いクエリがたくさん流れてしまった場合、SHOW PROCESSLISTをみて、クエリをKILLするなんてことは、あったりなかったりします。
この時にクエリが数十個となると、手作業ではやりきれませんので、コマンドを駆使して対応することになります。
ちょっと前にやったのが以下のコマンド
/usr/bin/mysql --defaults-extra-file=/path/to/.my-other.cnf -NB -e 'SELECT GROUP_CONCAT(ID) FROM \ information_schema.PROCESSLIST WHERE STATE = "Creating sort index" AND TIME > 1000 AND INFO \ LIKE "select%example%"' | grep -v NULL | /usr/bin/xargs -r /usr/bin/mysqladmin --defaults-extra-file=/path/to/.my-other.cnff kill
mysqladmin killは複数個のidを受け取れるのでGROUP_CONCATが使うのがおしゃれですね
この手のコマンドでも使い慣れているし、その場にあわせて変更していけるという強みはあるのですが、流石になんとかしたいと思い、ちょっとしたコマンドを作りました。
myps
pgrep、pkillのようにprocesslistをgrepしてkillできることを目指しました。
ある程度作ってから、pt-kill ってのがあると教えてもらいました。そっちを使ってもいいかと思います。
使い方
まず grep
$ myps grep --duration 0 ID:142 USER:root HOST:localhost:59393 DB: COMMAND:Query TIME:57 STATE:User sleep INFO:select sleep(3600) ID:150 USER:root HOST:localhost:59814 DB: COMMAND:Sleep TIME:2 STATE: INFO: ID:145 USER:root HOST:localhost:59800 DB: COMMAND:Query TIME:13 STATE:User sleep INFO:select sleep(360)
select文のみにする
$ myps grep --duration 10 --info 'select%' ID:142 USER:root HOST:localhost:59393 DB: COMMAND:Query TIME:86 STATE:User sleep INFO:select sleep(3600) ID:145 USER:root HOST:localhost:59800 DB: COMMAND:Query TIME:42 STATE:User sleep INFO:select sleep(360)
grepの条件は
-t, --time= 時間 -u, --user= ユーザ -d, --db= DB -c, --command= コマンド -s, --state= 状態 -i, --info= info(クエリ)
が利用できます。時間以外にはワイルドカードとして % と _ が使えます。
killする際は
$ myps kill --duration 10 --info 'select%' KILLED:142 USER:root HOST:localhost:59393 DB: COMMAND:Query TIME:129 STATE:User sleep INFO:select sleep(3600) KILLED:145 USER:root HOST:localhost:59800 DB: COMMAND:Query TIME:85 STATE:User sleep INFO:select sleep(360)
grepをkillに書き換えるとKILLクエリが発行されます。
出力はすべてltsvで、ターミナルでは色もつきます。見やすく、間違いにくくなるのではないかと思います。
実装
mypsは information_schema.PROCESSLIST を使っています。ワイルドカードが使えるのは時間以外はすべて、LIKE文を使って検索しているからなのです。
SELECT /* SHOW PROCESSLIST */ ID, IFNULL(USER,"") USER, IFNULL(HOST,"") HOST, IFNULL(DB,"") DB, \ IFNULL(COMMAND,"") COMMAND, TIME, IFNULL(STATE,"") STATE, IFNULL(INFO,"") INFO \ FROM information_schema.PROCESSLIST WHERE ID != CONNECTION_ID() AND IFNULL(INFO,"") LIKE ?
NULLは空っぽ文字列として扱ってます。このあたり使い勝手に影響するか、まだこれから使ってみないとわからないところです。
まとめ
使う時が限られる便利ツールは、いざという時に思い出さず、使い慣れたgrep awk xargsなどを組み合わせることになりがちですが、全てのDBサーバにいれて、ブログも書いたので、いざという時に使おうと思います。
mackerel-plugin-pinging について
この記事はMackerelアドベントカレンダー9日目の記事です。 今年新たに作ったmackerel pluginの数がとても少なかったのでショックを受けているMackerelアンバサダーのkazeburoです。
この記事ではそのうちの一つを紹介します。
mackerel-agent-pinging
公式のpluginとして、check-pingがありますが、こちらはmetricsを取得するためのpluginとなります。
ariarijp さんによる mackerel-plugin-ping もありますが、こちらとは取得しているメトリクスが異なります。
使い方
$ sudo /usr/local/bin/mackerel-plugin-pinging --count 10 --key-prefix=example --host x.x.x.x pinging.example_rtt_count.success 10.000000 1575852276 pinging.example_rtt_count.error 0.000000 1575852276 pinging.example_rtt_ms.max 0.544514 1575852276 pinging.example_rtt_ms.min 0.464331 1575852276 pinging.example_rtt_ms.average 0.499242 1575852276 pinging.example_rtt_ms.90_percentile 0.526231 1575852276
実行には、SUIDを設定またはroot権限が必要になります。
この例では x.x.x.x に対して、10回pingパケットを送信し、その成功回数、失敗回数とRTTのMax、Min、平均と90%tileを出力します。
タイムアウトやpingを送出する間隔はオプションにて変更できます。
/usr/local/bin/mackerel-plugin-pinging -h
Usage:
mackerel-plugin-pinging [OPTIONS]
Application Options:
--host= Hostname to ping
--timeout= timeout millisec per ping (default: 1000)
--interval= sleep millisec after every ping (default: 10)
--count= Count Sending ping (default: 10)
--key-prefix= Metric key prefix
-v, --version Show version
Help Options:
-h, --help Show this help message
使用例
mackerel-plugin-pinging はデータセンター間のレイテンシや、ネットワーク上の問題を検出するために使っています。
このグラフから某所から某所へのRTTは18msec、pingの失敗は観測されていないことがわかります。
NAT経由での外部との通信品質の監視、マルチクラウド環境でのVPNやinterconnectの監視にも利用できるかと思います。機会があればご利用ください。
秒間数千件以上のアクセスログでも高速に集計し、可視化できる mackerel-plugin-axslog の紹介
Mackerelアンバサダーになりました
Mackerelアンバサダーになったので、グッズ頂いた。ありがとうございます pic.twitter.com/UzCmANa84O
— Masahiro 💺 (@kazeburo) March 23, 2019
ということで、新しいmackerel-pluginの紹介です。
mackerel-plugin-axslog とは
Mackerelの公式プラグインに mackerel-plugin-accesslog というとても便利なプラグインがあります。公式のブログに詳しく解説があります。
これを使うと、アクセスログのファイルサイズを記録しながら差分を読み、ステータスコードごとのアクセス数や割合、レイテンシなどを集計、可視化できます。
mackerel-plugin-accesslog、サーバの可視化のため、とても便利そうでとても使いたかったのですが、ltsvのラベルが ltsv.org でレコメンドされているラベルで固定であり、某所でレスポンス速度を記録しているものと異なるため、使うことができませんでした。
そこで、
- LTSVのラベルカスタマイズができること
- JSON形式のログにも対応していること
と言ったあたりを目標にYet Anotherなmackerel-pluginを作りました。
最初のバージョンを作ってから、それほどパフォーマンスが良くないに気づき、また、大量のアクセスを捌くサーバでは毎時間ログローテートが動作するので、欠損が目立つことにわかったので、
- 秒間数千以上の環境でも問題なく利用できる動作速度
- 公式にもあるログローテート対応
あたりを中心に改善に取り組んで、バージョンv0.0.6まできております。
結果としとして、上記2つの課題は解決し、毎秒数千以上のリクエストを捌く環境でもアクセスログの集計と可視化が安定してできるようになりました。
ベンチマーク
秒間2万req、1分間で120万行のログが記録される、よくある環境を想定し、ベンチーマークを行いました。ログファイルのサイズは287MBになりました。
mackerel-plugin-accesslog
$ time ./mackerel-plugin-accesslog --format ltsv demo.log accesslog.access_rate.5xx_percentage 0 1554390519 accesslog.access_rate.4xx_percentage 0 1554390519 accesslog.access_rate.3xx_percentage 0 1554390519 accesslog.access_rate.2xx_percentage 100 1554390519 accesslog.latency.99_percentile 0.030000 1554390519 accesslog.latency.95_percentile 0.030000 1554390519 accesslog.latency.90_percentile 0.030000 1554390519 accesslog.latency.average 0.030000 1554390519 accesslog.access_num.total_count 1200000 1554390519 accesslog.access_num.5xx_count 0 1554390519 accesslog.access_num.4xx_count 0 1554390519 accesslog.access_num.3xx_count 0 1554390519 accesslog.access_num.2xx_count 1200000 1554390519 real 0m7.843s user 0m7.947s sys 0m0.346s
mackerel-plugin-axslog
$ time ../mackerel-plugin-axslog --key-prefix demo --logfile demo.log --ptime-key=reqtime axslog.latency_demo.average 0.030000 1554390518 axslog.latency_demo.99_percentile 0.030000 1554390518 axslog.latency_demo.95_percentile 0.030000 1554390518 axslog.latency_demo.90_percentile 0.030000 1554390518 axslog.access_num_demo.1xx_count 0.000000 1554390518 axslog.access_num_demo.2xx_count 1200000.000000 1554390518 axslog.access_num_demo.3xx_count 0.000000 1554390518 axslog.access_num_demo.4xx_count 0.000000 1554390518 axslog.access_num_demo.499_count 0.000000 1554390518 axslog.access_num_demo.5xx_count 0.000000 1554390518 axslog.access_total_demo.count 1200000.000000 1554390518 axslog.access_ratio_demo.1xx_percentage 0.000000 1554390518 axslog.access_ratio_demo.2xx_percentage 1.000000 1554390518 axslog.access_ratio_demo.3xx_percentage 0.000000 1554390518 axslog.access_ratio_demo.4xx_percentage 0.000000 1554390518 axslog.access_ratio_demo.499_percentage 0.000000 1554390518 axslog.access_ratio_demo.5xx_percentage 0.000000 1554390518 real 0m0.393s user 0m0.279s sys 0m0.126s
ここではaccesslogの7.843sに対して、axslogは0.393sなので、約20倍高速に動作することが確認できました。
benchmarkに利用したscriptは、axslogのrepositoryのdemoディレクトリ以下にあります。なおベンチマークはMacbook Pro上で実行しました。
高速化のためにやったこと
ざっとあげると
- LTSVのパーサの高速化のため、初期バージョンは別のltsvパーサライブラリを利用していたが、必要なことだけを行う独自のパーサを実装
- メモリアロケートをさけるため stringをさけ
[]byteのまま処理を行う - mapも同じ
- JSONに関しては、json-iterator/go を利用。まだ改善の余地がある状態
これくらいです。監視のツールなので、複数のcpuに処理を分散するような手法はいまのところとっていません。
まとめ
ぜひ使って見てくださいませ。
また、動作優先で全く綺麗なコードではないですが、さらになにかできそうなことがあれば、教えてください。
2018年 作った・喋ってきたまとめ
振り返り的なやつです。
作った
no_excl_open
LD_PRELOADをつかって、ファイルを作成する際の O_EXCLを取り除いてみるもの。
詳しくは YAPC::Okinawa 2018 前夜祭で喋った
relaxlogs
daemontoolsで動かしているデーモンのログをもう少し長くとりたいということで書いたもの。lestrratさんのfile-rotatelogsをコマンドにしたものとも言える
wsgate-server
なんらかの汎用的な認証を通して、MySQLに繋ぎたいということで書いていたもの。WebSocketはインターンにきていた優秀な若者がだしたアイディアからきている。
wsgate-client
wsgate-serverのclient。そういえば某productionでMySQLに対してコンテナから接続するために動き始めている。
この2つに関してはblog書いていた。
mackerel-plugin-linux-process-status
プロセス単位のCPU使用率をとるために書いた。statusと言いつつCPU使用率しかとれないので名前負けしている。
とあるリリースでMySQLのCPU使用率があがっていたが、昼間に気づかずアクセスの上がる夜間にサービスに影響がでてしまった障害があり、影響が出てしまう前に検知するためにつくった。
サーバのCPU使用率で十分じゃないかと思うが、backupやログの圧縮でCPU使うことがあり、単純な監視では誤検知が多くなりそうということで、この監視プラグインを作成した。現在は全てのMySQLサーバに導入済み。
sabo
毎日0時に動くとある処理に、複数のDBからデータをmysqldumpなどでかき集めて、処理に適したフォーマットに変換して、S3にアップロードするというものがあるのだが、その際にネットワークを使いすぎて、サービスに影響が出ているかもしれないということで作った。（サービスへの影響は別の原因だったわけだが）
throttleというコマンドがあり、これはpipeで挟み込むことで処理の速度を制限するものがある。production環境でも巨大なログの転送などで利用している。
cgroupsを使うというアイディアもチームで話をしたときにあったが、ピンポイントで帯域制限ができるthrottle形式でやってみた。
MAX_BW=100M WORK_DIR=/tmp/sabo_for_dump mkdir -p /tmp/sabo_for_dump mysqldump -h backup1 db table1 | sabo --max-bandwidth $MAX_BW --work-dir $WORK_DIR > /tmp/sabo_for_dump/table1.sql & mysqldump -h backup2 db table2 | sabo --max-bandwidth $MAX_BW --work-dir $WORK_DIR > /tmp/sabo_for_dump/table2.sql & wait
saboはwork-dir内にファイルをつくり、flockをかける。一定間隔でwork-dir内のflockがかかったファイルの数を数え、max-bandwidthをそれで割る。
なので、2つのmysqldumpのうち、一つが終われば残った方は最大の帯域が使えるようになるということ。production環境でも落としてくるデータのサイズはバラバラなので、等しく帯域制限をかけてしまうと無駄が多くなる。
名前は「みいつけた」からとった。
motarei
Dockerコンテナを雑に動かして、さらにHot Deployしたいと思って書いたもの。blogも書いていた。
motarei + server starterという環境でproductionで某某が動き始めている。
ところで、productionで動かし始めて気づいたことではあるが、go版のserver starterには、新しいプロセスが正しく起動してなくても、古いプロセスを止めてしまうという問題があった。
こちらは修正済みになる。
Fix worker exiting detection by kazeburo · Pull Request #17 · lestrrat-go/server-starter · GitHub
ちなみに名前は「みいつけた」からとった。
--
6/7がGo言語、のこり一つがC言語。 社内のrepoにしかないものでもGo言語が増えている。Perlで書くのはmackerelの監視プラグインぐらいだ。
喋ってきた
気づいたら後半は喋ってない
2月 Developers Summit
インフラチームからSREへ / SRE in Mercari Developers Summit 2018
3月 YAPC::Okinawa 2018 ONNASON
沖縄楽しかった！
3月 MANABIYA Teratail developer days
7月 July Tech Festa 2018
--
仕事ではSREに新メンバーが増え、MySQL、検索、データセンターのプロジェクトなどチームとしてできることがかなり広がってきました。その一方で北海道での地震の影響、外部のネットワークトラブル、データベースへの負荷などお客様にご迷惑をおかけしてしまうこっとも多くありました。お客様に信頼性や価値を届けるためにできることはまだまだあると考えており、来年以降も取り組んでいきます。
そろそろ「SREは死んだ、これからはXXXだ」みたいなトークやりたい
TCP over WebSocket & IAP
Googleのhuproxyみたいなもので、任意のprotocolが通しやすく、Google Cloud Load BalancingのIdentity aware proxyに対応したものが欲しかったので、作ってみた。
GCPの中のMySQLに対して、service accountで認証して接続するイメージとしては以下のようになる。
server側
pathとforward先の設定を行うmapファイルをまずつくる
mysql,10.0.x.x:3306 ssh,127.0.0.1:22
起動
$ wsgate-server --listen 0.0.0.0:8080 --map map-server.txt
これで、
ws://example.com/proxy/mysql にWebSocketで通信を行うと 10.0.x.xの3306 に対してforwardするproxyが起動する
client側
serverと同じようにmapファイルをつくる。今度はportと行き先のurl
127.0.0.1:8306,https://example.com/proxy/mysql 127.0.0.1:8022,https://example.com/proxy/ssh
起動
$ wsgate-client --map map-client.txt
これで各サーバにログインできるようになる。
# mysql $ mysql -h 127.0.0.1 --port 8306 --user ... # ssh ssh -p 8022 user@127.0.0.1
IAPを使う場合
Google Cloud Load Balancing を設定し、IAPを有効にする。 WebSocketを使う場合、timeoutを長くするのがおすすめ
クライアント側は、service accountのJSONファイルと、OAuth2のClient IDを指定して起動する
$ wsgate-client --map map-client.txt --iap-credential=/path/to/json --iap-client-id=foo.bar
これで、service accountで認証しつつ、任意のサーバと通信ができるようになる。
この他、wsgate-server, wsgate-clientには簡単な公開鍵認証と、任意のヘッダがつけれる仕組みがあるので、認証しつつ任意のプロトコルで通信することが簡単に実現できる。
TCP over WebSocket、去年の夏にインターンに来てくれた若者がアイディアを出してくれて、それ以降少しずつ使っているところが増えている。便利
普通のサーバでDocker ContainerをHot DeployしたかったのでProxy書いた
2018年も後半だけど、普通のサーバ上でコンテナをHot Deployしたいと思ってproxy書いた
任意のラベルがついたDocker containerのpublic portをdocker api経由で取得して、private portをlistenして、proxyを開始するものです。 ラベルがついたコンテナが複数個あると、必ず一番新しいものだけにproxyするようになってます。
これで、みんな大好きserver_starterと組み合わせると、Hot Deployができます。
使い方
コンテナを起動
$ KILL_OLD_DELAY=5 start_server -- docker run -P -l app=nginx nginx
public portが32774、private portが80となります
$ docker ps CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES 20ff30afc6a9 nginx "nginx -g 'daemon of…" 7 seconds ago Up 6 seconds 0.0.0.0:32774->80/tcp practical_blackwell
この状態で motarei さんを起動
$ sudo ./motarei -l app=nginx 2018/10/09 17:28:50 Start listen 0.0.0.0:80
80番だったので、sudoが必要になりましたが、motareiが port 80をlisten開始しています。
この状態で、curl 127.0.0.1 すれば素敵なnginxのページがでます。
コンテナをアップデートしたくなったので server starter に対してHUPを送ります。
$ kill -HUP 33022
コンテナも入れ替わりました。
docker ps CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES 264bafb478ff nginx "nginx -g 'daemon of…" 53 seconds ago Up 52 seconds 0.0.0.0:32775->80/tcp agitated_dubinsky
motareiさんは、docker apiに1秒ごとにアクセスし、portの変更を検知して、proxy先を変更します。
古いコンテナ後も、curl 127.0.0.1 は成功するはずです。
もともと、gobetweenというproxyがdocker apiをみてproxy先を切り替える機能をもっていたのですが、新しいコンテナだけにリクエストを行うことができず、hot deployには使えなかったので新しく作った次第です。
ちなみに、motareiさんはあたま屋さんです
