Hateburo: kazeburo hatenablog

Operations Engineer / Site Reliability / 運用系小姑 / Perl Monger

2019年 作った・喋ってきたまとめ

振り返り的なやつです。

去年の振り返りはこちらです。

kazeburo.hatenablog.com

ISUCON9 予選出題した

bokko, catatsuy, sota1235 とともにISUCON9の予選出題をやらせていただいた。7月から9月にかけて圧倒的に手を動かした。

解説と講評のほか、ローカル環境で予選問題を動かす方法についての記事を書かせてもらった。

isucon.net

isucon.net

参加していただいた方、出題メンバー、各言語への移植をやっていただいた皆様、さくらインターネットの皆様、アリババクラウドの皆様、そして941さんをはじめLINEの皆様、改めて感謝です。

作った

percentile

github.com

説明はないが、簡単に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

github.com

mackerel-plugin-accesslogで少し足りない機能があったので作った。一度つくった上で、より速いやつが書けそうだと思って書き直したら速くなった。

blogも書いている

kazeburo.hatenablog.com

「秒間2万req、1分間で120万行のログが記録される、よくある環境」はほんの少し盛っている

ppdp

github.com

某DBサーバへの通信のログを取りたいということで作った。アクセス元も必要なのでproxy protocol対応を行なった。

どこか => [tcp] => nginx stream => [proxy proto] => ppdp => [tcp] => mysql 

のように使う。

名前はペンパイナッポーアッポーペンからきている

deteco

github.com

公開鍵で暗号化したJWTをnginxのauth_requestで認証するための、簡単な認証サーバ

TCP over websocket と組み合わせて使うことを考えていた。

mackerel-plugin-log-incr-rate

github.com

2つのログの増える行数の比率を出すmackerel plugin。アプリケーションのログが爆発したときに書いた。

Go言語の初期状態のbufio.Scannerは1行の長さが65kを越えると、すぎゃんをやめてしまう仕様なのだが、その中で1MBを越えるログが発見された思ひでも

mackerel-plugin-postfix-log

github.com

メール送信をインストール型のソフトウェアからクラウド型のサービスに切り替えたので、中継サーバとしてのpostfixの監視重要性が高まったので書いた。

メトリクスはいくつか増えるが、役に立っているかどうか聞かれると、そんな役に立ってない。まだ。

consul-service-has-ip

github.com

指定したconsulのサービスに、任意のIPアドレスが含まれるかどうか確認するのを簡単にするAPIサーバ。

Slaveサーバの分散・切り離しに必要になって作ったが、もっと良い別の方法を発見し、3日ぐらいでお蔵入り。書いたからってそこにしがみつかないことも大事。

mackerel-plugin-pinging

github.com

データセンター間の通信を普段からモニタリングしていくために作った。

Mackerel アドベントカレンダーの記事として紹介している

kazeburo.hatenablog.com

成功失敗だけではなく、RTTのパーセンタイルもでるので、便利。

myps

github.com

MySQLのprocesslistをgrepしたり、思いの強いクエリKILLするのに便利なコマンド。便利ツールはいざと言う時に思い出さず、やくに立たないので、作ったことを自分で忘れないようにblogも書いた。

kazeburo.hatenablog.com

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できることを目指しました。

github.com

ある程度作ってから、pt-kill ってのがあると教えてもらいました。そっちを使ってもいいかと思います。

www.percona.com

使い方

まず 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で、ターミナルでは色もつきます。見やすく、間違いにくくなるのではないかと思います。

f:id:kazeburo:20191216153706p:plain

実装

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

github.com

公式のpluginとして、check-pingがありますが、こちらはmetricsを取得するためのpluginとなります。

ariarijp さんによる mackerel-plugin-ping もありますが、こちらとは取得しているメトリクスが異なります。

github.com

使い方

$ 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 はデータセンター間のレイテンシや、ネットワーク上の問題を検出するために使っています。

f:id:kazeburo:20191209101755p:plain

このグラフから某所から某所へのRTTは18msec、pingの失敗は観測されていないことがわかります。

NAT経由での外部との通信品質の監視、マルチクラウド環境でのVPNやinterconnectの監視にも利用できるかと思います。機会があればご利用ください。

秒間数千件以上のアクセスログでも高速に集計し、可視化できる mackerel-plugin-axslog の紹介

Mackerelアンバサダーになりました

ということで、新しいmackerel-pluginの紹介です。

mackerel-plugin-axslog とは

Mackerelの公式プラグインに mackerel-plugin-accesslog というとても便利なプラグインがあります。公式のブログに詳しく解説があります。

mackerel.io

これを使うと、アクセスログのファイルサイズを記録しながら差分を読み、ステータスコードごとのアクセス数や割合、レイテンシなどを集計、可視化できます。

mackerel-plugin-accesslog、サーバの可視化のため、とても便利そうでとても使いたかったのですが、ltsvのラベルが ltsv.org でレコメンドされているラベルで固定であり、某所でレスポンス速度を記録しているものと異なるため、使うことができませんでした。

そこで、

  • LTSVのラベルカスタマイズができること
  • JSON形式のログにも対応していること

と言ったあたりを目標にYet Anotherなmackerel-pluginを作りました。

github.com

最初のバージョンを作ってから、それほどパフォーマンスが良くないに気づき、また、大量のアクセスを捌くサーバでは毎時間ログローテートが動作するので、欠損が目立つことにわかったので、

  • 秒間数千以上の環境でも問題なく利用できる動作速度
  • 公式にもあるログローテート対応

あたりを中心に改善に取り組んで、バージョン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

github.com

LD_PRELOADをつかって、ファイルを作成する際の O_EXCLを取り除いてみるもの。

詳しくは YAPC::Okinawa 2018 前夜祭で喋った

speakerdeck.com

relaxlogs

github.com

daemontoolsで動かしているデーモンのログをもう少し長くとりたいということで書いたもの。lestrratさんのfile-rotatelogsをコマンドにしたものとも言える

wsgate-server

github.com

なんらかの汎用的な認証を通して、MySQLに繋ぎたいということで書いていたもの。WebSocketはインターンにきていた優秀な若者がだしたアイディアからきている。

wsgate-client

github.com

wsgate-serverのclient。そういえば某productionでMySQLに対してコンテナから接続するために動き始めている。

この2つに関してはblog書いていた。

kazeburo.hatenablog.com

mackerel-plugin-linux-process-status

github.com

プロセス単位のCPU使用率をとるために書いた。statusと言いつつCPU使用率しかとれないので名前負けしている。

とあるリリースでMySQLのCPU使用率があがっていたが、昼間に気づかずアクセスの上がる夜間にサービスに影響がでてしまった障害があり、影響が出てしまう前に検知するためにつくった。

サーバのCPU使用率で十分じゃないかと思うが、backupやログの圧縮でCPU使うことがあり、単純な監視では誤検知が多くなりそうということで、この監視プラグインを作成した。現在は全てのMySQLサーバに導入済み。

sabo

github.com

毎日0時に動くとある処理に、複数のDBからデータをmysqldumpなどでかき集めて、処理に適したフォーマットに変換して、S3にアップロードするというものがあるのだが、その際にネットワークを使いすぎて、サービスに影響が出ているかもしれないということで作った。(サービスへの影響は別の原因だったわけだが)

throttleというコマンドがあり、これはpipeで挟み込むことで処理の速度を制限するものがある。production環境でも巨大なログの転送などで利用している。

linux.die.net

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

github.com

Dockerコンテナを雑に動かして、さらにHot Deployしたいと思って書いたもの。blogも書いていた。

kazeburo.hatenablog.com

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

speakerdeck.com

3月 YAPC::Okinawa 2018 ONNASON

speakerdeck.com

沖縄楽しかった!

3月 MANABIYA Teratail developer days

speakerdeck.com

7月 July Tech Festa 2018

speakerdeck.com

--

仕事ではSREに新メンバーが増え、MySQL、検索、データセンターのプロジェクトなどチームとしてできることがかなり広がってきました。その一方で北海道での地震の影響、外部のネットワークトラブル、データベースへの負荷などお客様にご迷惑をおかけしてしまうこっとも多くありました。お客様に信頼性や価値を届けるためにできることはまだまだあると考えており、来年以降も取り組んでいきます。

そろそろ「SREは死んだ、これからはXXXだ」みたいなトークやりたい

TCP over WebSocket & IAP

Googlehuproxyみたいなもので、任意のprotocolが通しやすく、Google Cloud Load BalancingのIdentity aware proxyに対応したものが欲しかったので、作ってみた。

github.com

github.com

GCPの中のMySQLに対して、service accountで認証して接続するイメージとしては以下のようになる。

f:id:kazeburo:20181022164001p:plain

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を長くするのがおすすめ

f:id:kazeburo:20181022164955p:plain

クライアント側は、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書いた

github.com

任意のラベルがついた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には使えなかったので新しく作った次第です。

github.com

ちなみに、motareiさんはあたま屋さんです