Hateburo: kazeburo hatenablog

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

ISUCON10予選に「チーム中目黒乗り過ごし」で参加し本選出場決まりました

ISUCON10の予選に尊敬するエンジニアであるhanabokuro氏、mtokioka氏と参加して、9位で本戦出場できることになりました。うれしい! ISUCON8は予選落ち、去年は出題をやらせていただいたので、本選出場は3年ぶりになります

今年の問題も、よく練られた問題で開始から終了まで楽しむことができました。運営のみなさま朝早くから遅くまで本当にありがとうございます。

準備

GoはMackerelプラグインミドルウェアでよく書いておりますが、、いわゆるWebアプリケーションはあまり書いてないので、手を動かすために去年のISUCON9予選の問題を手元で動かして取り組んでみてました。

ローカル環境で動かすのは以下の記事が役立ちます。

isucon.net

また、Cloud TraceやProfilerを試すために、takonomura氏の記事やgithub repositoryをすごくすごく参考にしました。ありがとうございます!

www.takono.io

当日

六本木のオフィスで集まってやることに決めていたので、自宅から移動。

これを言いたいが為だけにこのチーム名になっていることは秘密。

開始が12時すぎになったので、半年ぶりにいったオフィスで賞味期限がきれたお菓子などを片付けたりして準備してました。

構成と最終スコア

最終的には3台を使う構成になりました。

f:id:kazeburo:20200914103843p:plain

作業の順序的にベンチマーカーは103に向けて、NginxとGoがそこで動きます。DBを2つに分割し、chair用とestate用それぞれ専用にしました。 この構成でCPU使用率はGoが40%程度、MySQLの負荷は99%以上になるような状況でしたので、まだまだ改善はできたのではないか、やれることはあったはずと思っています。

最終スコアは 3016 でした。

f:id:kazeburo:20200914104420p:plain

予選でつかったrepositoryはこちらになります

github.com

序盤

開始されてからしばらくベンチマークを動かすことができなかったので、当日マニュアルやソースコードを読む時間にあてました。明らかに不足しているインデックスを追加したり、featureやnazotte検索あたりが重そうだなというと手を付ける箇所を検討していました。空いた時間でbotを避けるnginxの設定もいれました。

今回の予選のサーバは3台すべて1coreのサーバで、ベンチマークを動かしたところMySQLが多くのCPUを使っていることがわかったので、profilerやtraceは一旦おいておいて良さそうと判断し、まずpt-query-digestを使い、DBの解析行いました。

初めの段階でCPU時間を使っているクエリは

SELECT * FROM chair WHERE stock > 0 ORDER BY price ASC, id ASC LIMIT 20

SELECT * FROM estate WHERE rent >= 50000 AND rent < 100000 ORDER BY popularity DESC, id ASC LIMIT 25 OFFSET 0

SELECT * FROM estate WHERE (door_width >= 191 AND door_height >= 183) OR (door_width >= 191 AND door_height >= 173) OR (door_width >= 183 AND door_height >= 191) OR (door_width >= 183 AND door_height >= 173) OR (door_width >= 173 AND door_height >= 191) OR (door_width >= 173 AND door_height >= 183) ORDER BY popularity DESC, id ASC LIMIT 20

最初のクエリは単純にindexで済み、3つ目はクエリをもっと単純にできそうでしたが、問題は昇順と降順が混ざる ORDER BY popularity DESC, id ASC でこれを解決するために、MySQL8のアップデートを試すことにしました。

中盤

MySQL8アップデートの作業は他のチューニングとぶつからないように、103のサーバで行いました。MySQL8のアップデートは初めてでしたので、google様に聞いて以下のサイトを参考にしました。画像までありわかりやすかったです。ありがとうございます!

obel.hatenablog.jp

インストール中に、認証方式を新しい認証方式にするか、5.7と互換性にあるモードにするか聞いてくるらしい、というのがわかったのがとくに嬉しいところでした。実際にやってみたところ、最後にmy.cnfの設定を、今の設定を残すか、新しい設定で上書きするか聞いてくれたのも便利でした。設定のdiffもみれ、何が起きるのかも明確でした。別のところで悩みなくなかったのでここは5.7互換モードを選び、新しい設定で上書きしました。

apt-get install のあとmysqlコンソールでデータが読めるか確認したところ、何事もなく読めたので、ベンチマーカの向き先を 103 にして実行。スコアは半分程度にさがりましたが無事にベンチマークが成功しているので、クエリとindexのチューニングで改善すると考え、MySQL8で続行しました。

create index idx_pop on isuumo.chair(popularity desc);
create index idx_pop on isuumo.estate(popularity desc);

ORDER BYに関してはこの2つで多くは解消しました。

mysql> explain SELECT * FROM chair WHERE price >= 3000 AND price < 6000 AND height >= 80 AND height < 110 AND width >= 80 AND width < 110 AND depth >= 150 AND stock > 0 ORDER BY popularity DESC, id ASC LIMIT 25 OFFSET 25\G
*************************** 1. row ***************************
           id: 1
  select_type: SIMPLE
        table: chair
   partitions: NULL
         type: index
possible_keys: idx_price,idx_depth,idx_height,idx_width,stock
          key: idx_pop
      key_len: 4
          ref: NULL
         rows: 286
     filtered: 0.16
        Extra: Using where
1 row in set, 1 warning (0.00 sec)

idx_popが選ばれて、rowsが小さくなってます。MySQL8賢い。信じてた。

MySQL8のアップデート後一旦さがったスコアは、indexの整理、ドアの大きさのクエリの改善、nazotte検索のN+1の解消、SELECT COUNT(*) を goroutineで取得などをいれることで良くなり、1000を超えるスコアになってきていました。

nazotte検索のN+1は

SELECT id,latitude,longitude FROM estate WHERE latitude <= ? AND latitude >= ? AND longitude <= ? AND longitude >= ?

のクエリのあと

SELECT * FROM estate WHERE 
   (id = ? AND ST_Contains(ST_PolygonFromText(%s), ST_GeomFromText('POINT(%f %f)'))) 
OR (id = ? AND ST_Contains(ST_PolygonFromText(%s), ST_GeomFromText('POINT(%f %f)')))
OR (id = ? AND ST_Contains(ST_PolygonFromText(%s), ST_GeomFromText('POINT(%f %f)')))
..

と2回のクエリで取得するようにしています。ベンチマーカーからのリクエストではHitするのが多くても数百件でしたのでこれで十分な性能がでると判断しました。

ここまで1台でやってきてましたが、MySQLの負荷を低減させるのが難しく複数台構成への変更を行いました。chairとestateテーブルはJOINを行わなず、複雑なトランザクションなどもないので、テーブルごとにDBを分割する方法をとりました。自分はレプリケーション案を出していましたが、分割案ではレプリケーション遅延などを考える必要もなくシンプルに負荷分散ができるこちらで行くことに決め、101、102のサーバのMySQLのアップグレード作業を行いました。

分割後、スコアは2000程度まで上昇。これがだいたい18:30ぐらいでした。

終盤

ここから、細かく次のようなチューニングを行い、

  • estateとchairのbuk insert
  • buyChair時のクエリを削減
  • getLowest のcache
  • chair と estateの検索をcache
  • nazotte検索の最初のクエリをcovering indexになるように調整

20時をまわったところで一旦再起動試験、ufwやapparmorを無効にして再起動して問題がないことを確認。 20時半に3000点を超えたところで、作業を終了にしました。

よかったところと反省点

初手から複数台構成やキャッシュ戦略を取らず、pt-query-digestやkataribeを使い、ログを解析しながら手を動かして行った点、複数台構成を最初に行わなかったことで大きな変更の検証や、MySQL8へのアップグレードを使ってないサーバを使って試せたのはよかった。逆に、MySQLの負荷が最後まで下がらず、負荷を大幅に押さえるような手段が取れなかったのは、まだまだ精進しなければならないところ。本選に行くチャンスを得たので、反省含め頑張っていきたい。

今回、生中継があったので奥さん、息子、娘も家でちょこちょこ見て応援してくれていたようです!ありがとう!!!

Nginxのupstreamコンテキストでの名前解決に nginx-dynamic-upstream-resolve-servers を使う

Nginxでproxyする際に、名前解決を動的に行ってからupstreamへ接続をするというのは、S3だったりConsulで管理されたサーバ群に対するproxyを行いたい場合に使いたくなる機能のひとつ。

ただ、upstreamコンテキスト内の resolve オプションは有償の Nginx Plusにしかない機能なので、set変数を使ってやるというのがこれまでの方式

resolver 127.0.0.1 valid=30s ipv6=off;
server {
  set $backend_host "backend-apps.service.dc.consul:8080";

  location / {
    proxy_pass http://$backend_host;
  }
}

この方式は問題なく動くのですが、

  • upstream keepaliveが有効にならない
  • 名前解決した結果に複数のIPがあっても、接続が失敗した際のretryが行われない

といった問題、課題がありました。

そこで、nginxにchoconを同居させ

upstream chocon {
  server 127.0.0.1:8080 max_fails=5 fail_timeout=3s;
  server 127.0.0.2:8080 max_fails=5 fail_timeout=3s backup;
  keepalive 16;
  keepalive_requests 1000;
}

server {
  proxy_http_version 1.1;
  proxy_set_header Connection "";
  proxy_set_header Host "backend-apps.service.dc.consul.ccnproxy";
  location / {
    proxy_pass http://chocon;
  }
}

などという方法をとっていましたが、ミドルウェアを減らしよりシンプルにしたいなとずっと考えていました。

3rd party moduleの利用

流れ星に resolve オプションがOSSにきますようにと願いながら、3rd party moduleでresolve相当の機能がある

github.com

を試しました。

こちらのnginxモジュールを使うと、

resolver 127.0.0.1 valid=30s ipv6=off;

upstream backend_apps {
  server backend-apps.service.dc.consul:8080 resolve max_fails=10 fail_timeout=3s;
  keepalive 16;
  keepalive_requests 1000;
}

server {
  proxy_http_version 1.1;
  proxy_set_header Connection "";
  location / {
    proxy_pass http://backend_apps;
  }
}

と、resolveオプションが使えるようになります。何これ最高!

、、、だったのですが、検証の結果、一見問題ないのですが、サーバの増減時にNginxのworkerがsegmentation faultで落ちるということがわかりました。

モジュール自体、最終更新から5年たっており、修正される気配もなさそうです。

そこで次に見つけたのが nginx-upstream-dynamic-servers のissueで紹介されていた zhaofeng0019 さんの nginx-dynamic-upstream-resolve-servers

github.com

このモジュールは nginx-upstream-dynamic-servers のsegvなどのissueを修正し、いくつか変更を加えています。もっとも大きな違いは、Nginx本体へのpatchが必要なことです。コードを追いかけていけば本体へのpatchは納得する範囲です。

使い方は nginx-upstream-dynamic-servers とまったく同じで。use_lastというオプションが追加されています。

ビルド方法

cubicdaiyaことbokkoのnginx-buildを使ってbuildしていきます。nginx-1.18.0で確認済みです

configure.sh

#!/bin/sh

./configure \
        --prefix=/path/to/nginx-1.18 \
        --with-http_ssl_module \
        --with-http_realip_module \
        --with-http_stub_status_module \
        --with-http_v2_module \
        --with-pcre-jit \

modules3rd.ini

[nginx-upstream-dynamic-resolve-servers]
form=git
url=https://github.com/zhaofeng0019/nginx-upstream-dynamic-resolve-servers.git
rev=9ad9322e99fa9f07fb3dc1cbdef355d1ae81f376

ビルド

Nginxへのpatchはこちら

$ curl -O https://gist.githubusercontent.com/kazeburo/01d1901eece9341aaaa92194ce1b4251/raw/03a126359746b8a41ed03124aa952120ae83815d/nginx-upstream-dynamic-resolve-servers.patch
$ nginx-build \
    -clear \
    -d work \
    -v 1.18.0 \
    -patch nginx-upstream-dynamic-resolve-servers.patch \
    -patch-opt "-p1" \
    -c configure.sh \
    -m modules3rd.ini \
    -zlib \
    -zlibversion=1.2.11 \
    -verbose \
    -pcre \
    -pcreversion=8.44 \
    -openssl \
    -opensslversion=1.1.1g \

これでビルドできると思われます。Mac上で確認しています。

実は nginx-upstream-dynamic-resolve-servers にもsegvする問題があったのですが、PRを出したところ解決していただきました。

早速productionでもconsulで構成するserver群に対して nginx-upstream-dynamic-resolve-servers でproxyして問題なく動いてます。consul maintを行って数秒後にはリクエストが正しく止まること、keepaliveされることなどは確認、検証しています。便利!!

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だ」みたいなトークやりたい