Hateburo: kazeburo hatenablog

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

YAPC::Okinawa 2018 ONNASON に行ってきた

YAPC::Hokkaido、YAPC::Fukuoka に続き YAPC::Okinawa 2018 に行ってきました。

発表

発表は2つ。

前夜祭

開催前日に作った資料。logrotateとfluentdとPHPが絡んだわりと複雑な問題に対してLD_PRELOADというやや斜め上の方法をとった話です。

本編スペシャルセッション

PHPとGo言語が中心になっている企業の中での「Perlのお仕事」の紹介です。cronlogにslackへの通知機能を盛り込んだslacklogと、大規模なトラフィックの一部を支えているPerlQ4Mの話を紹介しました。今後Perlがどのような立場になっていくのか個人的な考えも含め述べさせていただきました。

冒頭でmemcachedの問題についてもすこし紹介しています。

他にもバススポンサーをやらせていただいていたので、バスの中でトークなどを行いました。

会場のOIST、すごく綺麗な場所で驚きました。今回は天気が残念でしたがまたチャンスがあれば行きたい。

他の方のtalkではxaicronのPerlでH2の話やmacopyのwebsocketの話などが印象に残りました。PerlでH2の話を聞いて思い出したので、Gazelleに103 Early Hintsの対応を会場で行い、リリースしておきました。

nipotanのLINE NEWSの話がとても懐かしく、楽しく聞かせていただきました。

見てきた

花粉はすごく楽でした。

前日昼過ぎについたので、少し観光

去年の夏にJR最南端は行ったので、今度は日本最南端と最西端の駅。 最西端はゆいレール那覇空港、最南端はその隣の赤嶺駅

そのままゆいレールに乗って首里城まで行ってきた。

首里城は要塞のような印象をうけました。

今回のYAPC用にデザイナさんに作っていただいたメルカリのシール。個人的にかなり気に入りました。

f:id:kazeburo:20180306004718p:plain

さいごに

沖縄で開かれるYAPC最高でした。また沖縄行きたい。 スタッフの皆様、参加者の皆様ありがとうございました!

2泊3日行かせてくれた奥様、息子娘、そして来ていただいた奥様の実家の義母にも感謝。ありがとうー。

さて、次は東京で開催。行くぞ!

2017年 喋ってきたまとめ

振り返り的なエントリです。

3月

さくらインターネット プレゼンツ メルカリ×はてなの夕べ

さくらさん、はてなさんのイベントのセッションに参加しました。専用サーバをどのように使っているかという話をはてな id:wtatsuru さんとしました。

hatenanews.com

SendGrid Night 7

SendGrid Night 7 メルカリUS-UKでの事例とバウンスメール処理/Mercari US-UK and Bounced mail processing // Speaker Deck

メルカリUS/UKで使っているメール配信の話をしました。EventHookを使ってリターンメール処理とmackerelによるモニタリングを実現しています。

sendgrid.kke.co.jp

AWS Dev Day 2017

Cloud connect the world as a Glue - AWS Dev Day 2017 // Speaker Deck

AWSさんのカンファレンスで、メルカリの世界3拠点での開発運用体制、クラウドの利用について喋りました。 DC間、クラウド間の通信を効率的に行う chocon というプロダクトに興味をもっていただいた方が多くいました

www.awssummit.tokyo tech.mercari.com

7月

YAPC::Fukuoka 2017 Hakata

Mercari Timeline Personalization powered by Perl in 5minutes // Speaker Deck

博多で行われたYAPCでのLTです。Personalized Timelineはよりパワーアップしており、その基盤をPerlが支えています。

yapcjapan.org

8月

hbstudy#75 SRE大全:メルカリ編

SRE大全 メルカリ編 前半 #hbstudy 75 / SRE Taizen Mercari 1 hbstudy#75 // Speaker Deck

SRE大全 メルカリ編 後半 #hbstudy 75 / SRE Taizen Mercari 2 hbstudy#75 // Speaker Deck

ハートビーツさんの勉強会にて前後半あわせて2時間の長時間発表をしました。ここまでのSREの取り組みのまとめとなりました。

heartbeats.jp tech.mercari.com

WEB+DB PRESS Vol.100 メルカリ特集

登壇ではありませんが、1号からお世話になっているWEB+DB PRESSの記念すべきVol.100 のメルカリ特集に寄稿しました。

gihyo.jp

tech.mercari.com

9月

Enterprise Development Conference

開発と運用でサービスの信頼性を高める 「SRE」の実践/Mercari SRE in practice Enterprise Development Conference // Speaker Deck

日経BPさん主催のイベントで喋りました。 SREやメルカリSREの取り組みについて紹介しました

ac.nikkeibp.co.jp

10月

Mackerel Day

Driving Mercari with 50+ custom plugins / Mackerel DAY // Speaker Deck

Mackerel 3周年のイベントで、Mackerelの利用方法や監視設計、プラグインをいっぱい作っている話をしました。プラグインはまだまだ増えてます

mackerelio.connpass.com

Fastly Yamagoya Meetup 2017

CDNの使い方 in Mercari/CDN in Mercari // Speaker Deck

メルカリでも導入を行なっているCDN、Faslyさんのイベントで喋りました。

techplay.jp

11月

Monitoring Seminar in mercari

メルカリのシステム・サービス監視について/Monitoring Mercari service and servers // Speaker Deck

はてなさんとの共同イベントで話ました。メルカリのサービス拡大と監視システムとの関わりや、監視内容について紹介しました。

mackerelio.connpass.com

まとめと来年にむけて

各イベントに足を運んでいただいた皆様、主催者の皆様ありがとうございました。参考になる話があれば幸いです。 2018年は2月にデブサミ、3月にMANABIYAにて登壇予定です。YAPC::Okinawaにも参加します。今後ともぜひよろしくお願いします。

ISUCON7 予選通過した!!

ISUCON7に id:sugyanid:gfx と、チーム「スギャブロエックス」で出場して、2日目の2位、全体でも2位で予選通過できました。

icon画像さえ突破できれば、よく練られている問題で楽しめました。サーバもベンチマークも快適に動いて課題に集中出来ました。運営の皆様ありがとうございます。

すでに同じチームの2名がblogを書いているので、そちらも御覧ください

memo.sugyan.com

gfx.hatenablog.com

チームのソースコード、設定もgithubで公開しています。

github.com

最終スコアは 522461、ベストスコアも 522461 です。

言語の選択

最初はGo or Perlという話をしていたのですが、nodejsがサポートされるということが発表された段階で、gfxよりnodejsで行きたいという提案があり、nodejsで行くことにしました。

ISUCON出るなら新しいことを吸収しようという思いがあり、アプリケーションを書いたことはありませんでしたが、読めないことはないだろうということで、nodejsでいくことに。

実際には去年の問題をmatsuuさんのvagrantでローカルに作成し、gfxに少し教わりながらhackすることで勉強しました。最初スコア0だったのを36,000まであげることができました。

その際に

qiita.com

こちらの記事がとても参考になりました。ありがとうございます。

nodejs、正直これまであまりよい印象はありませんでしたが、await/asyncがつかえるようになると、callback地獄にならず普通の言語のように書ける、また高速だというのがわかりました。今後も使う機会増えそうです。

また、今回、サーバが1コアだったこともあり、nodejsという選択はかなり良かったのではないかと思います。

帯域問題

iconの画像配信をどうするか、というのがまずの問題でした。画像データはisucon3でやったのと同じく、webdavで1台に集める方法をとりました。

3台のサーバをisu701、isu702、isu703とすると、

  • isu701 - nginx(reverse proxy), app
  • isu702 - nginx(reverse proxy), app
  • isu703 - nginx(reverse proxy, webdav), mysql

のような構成になりました。703はmysqlが動くことがあり、appは動かさず他の2台にproxyしています。

davに切り替えた時点で、expireヘッダを追加していましたが、どうも304になっている数が少く、100Mbpsにぶつかっているということでスコアが伸びず悩んでいました。この間でgzip_staticやapigzip圧縮などもしていましたが、まったく伸びず。

そこで思いつきで、immutableを追加したらいいじゃねということで expire やめて以下を追加。

add_header Cache-Control "public, max-age=31536000, immutable";

immutableは関係ありませんでしたが、publicが効いて304の数が圧倒的に増えました。近頃Cacheしない方向の知見を溜めてた分、publicはなかなか出てこなかった。

これでスコアが一気に8万点まで上昇。他の上位陣からはだいぶ遅れましたが、やっと他のチューニングができる状態になりました。

その他のチューニング

  • nginx <-> app とnginx <-> nginx 間のkeepalive。効果わからず断念
  • 一番小さいcssだけcache-control追加しない。効果わからず断念
  • 最後に nginxのaccesslog off
  • fail2ban、ufwの停止、sysctlを追加設定

反省・感想など

  • callbackが大量に使われるコードが読めず、もう少しいろんなコードを読んでおくべきだった
  • appのチューニングはもう少しできることがあったなと思わないこともなく。画像に時間がかかり過ぎた
  • チームを組むのが初めてのメンバーで、しかも互いに同僚ではないが、いい感じで作業分担できた
  • 1年間固定してたツイート外した
  • 家で応援してくれた奥さん、息子、娘ありがとうー

GCP HTTP(S) load balancing 配下のnginxでクライアントIPを取得する方法

GCP HTTP(S) load balancing の X-Forwarded-For ヘッダは少し変わっているのでメモ。

X-Forwarded-For とクライアントIP

ELBや他のproxyを使って、その配下のサーバにリクエスト元のIPアドレスを伝える際には、X-Forwarded-For ヘッダが使われます。

X-Forwarded-For: $remote_addr

リクエストにすでにX-F-Fヘッダがあった場合は、後ろに追加します。

X-Forwarded-For: $http_x_forwarded_for, $remote_addr

となります。

X-F-Fを受け取ったサーバでは、アクセス元のIPが信用できるIPアドレスまたはIP帯域の場合に、X-F-Fの最後のIPアドレスを、remote_addrとして利用します。

nginxでは ngx_http_realip_module を使います。

set_real_ip_from  192.168.1.0/24;
real_ip_header    X-Forwarded-For;

アクセス元が 192.168.1.0/24 の場合、X-F-Fの最後のIPを利用するという意味です。

GCP HTTP(S) load balancing の X-F-F

本題のGCP HTTP(S) load balancingの場合、X-F-Fは

X-Forwarded-For: 1.2.3.4, 35.186.x.x

となります。この場合、1.2.3.4 が実際のclientのIPアドレス、35.186.x.xがロードバランサーに割り当てたIPアドレスです。また、アクセス元のIPアドレスは、以下の帯域(2017/2/21現在)となります。

130.211.0.0/22
35.191.0.0/16

この状態で、

まず

set_real_ip_from 130.211.0.0/22;
set_real_ip_from 35.191.0.0/16;
real_ip_header   X-Forwarded-For;

という設定をいれると、nginxはアクセス元を信用してX-F-Fの最後の一つをクライアントIPだとします。この場合は 35.186.x.x になってしまい、クライアントIPではありません。

さらに設定が必要になります。

set_real_ip_from 130.211.0.0/22;
set_real_ip_from 35.191.0.0/16;
set_real_ip_from 35.186.x.x;
real_ip_header   X-Forwarded-For;
real_ip_recursive on;

set_real_ip_from 35.186.x.xreal_ip_recursive を追加しました。real_ip_recursiveを有効にすると信用できるIPである限り再帰的にX-F-Fをたどっていきます。set_real_ip_fromにロードバランサーのIPを追加することで、35.186.x.xを信用し、次のIPアドレスをクライアントのIPとして採用ができるようになります。

この設定でようやく$remote_addrが1.2.3.4となりました。

まとめ

IPアドレスの追加の機会はそれほど回数がないので、IPアドレスをバランサーに追加した際にset_real_ip_from の追加を忘れるということは必ず発生するでしょう(発生した)。

アクセスログで正しくIPアドレスが解決ができているかの監視を行ったり、blogに書くなどしてチームに共有する必要があります。

Googleの皆様におかれましては、X-F-Fだけではなく、Akamai/CloudFlareのように True-Client-IP ヘッダの採用をお願いしたく候。True-Client-IPがあれば、ロードバランサーIPアドレスをnginxのconfに書く必要がなくなり、

set_real_ip_from 130.211.0.0/22;
set_real_ip_from 35.191.0.0/16;
real_ip_header True-Client-IP;

だけとなります。

何卒 :bow:

N秒間だけクエリ実行ログを取りたい

pt-query-digestだったり調査のために、N秒間だけmysqlの全クエリのログを取得したいということはよくありますよね

そんな時はこんなコマンドを使うと簡単に指定の秒数slowlogを切り替えて保存、取得後に元に戻してくれます。

$ slowlog.pl --duration 10 -- --default-extra-file=/hoge/my.cnf -uuser

-- のあとはmysqlコマンドに渡すオプション

ソース

#!/usr/bin/perl

use strict;
use warnings;
use IO::Handle;
use Getopt::Long;
use File::Spec;

sub find_path {
    my $pg = shift;
    my $path;
    for ( split /:/, $ENV{PATH} ) {
        if ( -x "$_/$pg" ) {
            $path = "$_/$pg";
            last;
        }
    }
    $path;
}

my $duration = 10;
Getopt::Long::Configure ("no_ignore_case");
GetOptions(
    "duration=s" => \$duration,
);
my @mysqlopt = @ARGV;
$|=1;

die "duration does not seems numeric" unless $duration =~ m!^\d+$!;
$duration += 0;

my $mysql = find_path('mysql')
    or die "could not find mysql";
my $tmpdir = File::Spec->tmpdir();

my $before = <<'EOF';
SET @cur_long_query_time = @@long_query_time;
SET @cur_slow_query_log_file = @@slow_query_log_file;
SET @cur_slow_query_log = @@slow_query_log;
SET GLOBAL slow_query_log_file = "<TMP_DIR>/slow_query_<DATE>.log";
SET GLOBAL long_query_time = 0;
SET GLOBAL slow_query_log = 1;
EOF

my $after = <<'EOF';
SET GLOBAL long_query_time = @cur_long_query_time;
SET GLOBAL slow_query_log_file = @cur_slow_query_log_file;
SET GLOBAL slow_query_log = @cur_slow_query_log;
EOF

$before =~ s!<TMP_DIR>!$tmpdir!;
my @lt = localtime();
my $date = sprintf('%04d%02d%02d%02d%02d%02d',$lt[5]+1900,$lt[4],$lt[3],$lt[2],$lt[1],$lt[0]);
$before =~ s!<DATE>!$date!;

print STDERR "exec mysql to change long_query_time and slow_query_log_file\n";
print STDERR "save slowlog to $tmpdir/slow_query_$date.log\n";
my $pid = fork;
if ( defined $pid && $pid == 0 ) {
    my $stop = 0;
    local $SIG{INT} = sub {
        $stop++;
    };
    local $SIG{TERM} = sub {
        $stop++;
    };

    open(STDOUT,'>/dev/null');
    open(my $pipe, '|-', $mysql, @mysqlopt, '--sigint-ignore');
    $pipe->autoflush;
    $pipe->print($before);
    for my $i ( 0..$duration ) {
        last if $stop;
        $pipe->print("SELECT 1;\n") if $i % 7 == 0;
        sleep 1;
    }
    $pipe->print($after);
    exit;
}
print STDERR "wait $duration seconds\n";
while (wait == -1) {}
my $exit_code = $?;
if ( $exit_code != 0 ) {
    die sprintf("Error: mysql exited with code: %d", $exit_code >> 8);
}

print STDERR "finished capturing slowlog.\n";

RDSとかAuroraとかよく知りません

【29年ぶりの大雪】YAPC::Hokkaido 2016 SAPPORO へ行ってきた! 【試される大地】

JPAの新しいメンバーのもと、REBOOTされたYAPC::Asia、YAPC::Hokkaido 2016 SAPPOROに、ゲストスピーカーとして呼んでいただけたので、行ってきました。

発表資料はこちら。

メルカリの技術ブログで紹介したSRE、1年たってエンジニアの新しいロールとして少しずつ浸透してきたと思います。今回の発表ではSREとはということで、本家であるGoogleのSREについて、メルカリでの取り組みについて、そしてYAPCなので、SREとPerlを結びつけてまとめとしました。参考になれば幸いです。

Read more

libeatmydataを使ってpostfixを劇速にする [用法用量要確認]

libeatmydataというLD_PRELOADを使って、起動したプロセスのfsyncを無効化するライブラリがあったので試してみています。

libeatmydata - disable fsync and SAVE!

fsyncがないと何が嬉しいかというとクラウドのようなIOまわりの環境が弱いところで、安全性は若干犠牲になりますが、パフォーマンスを稼ぐことができるようになります。

まず perlでfsyncを発行してどうなるかstraceをつかって確認してみます。

libeatmydataなし

$ strace perl -MIO::Handle -e 'open(my $fh,">:unix","test.txt"); print $fh "test"; IO::Handle::sync($fh);'
open("test.txt", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 3
fstat(3, {st_mode=S_IFREG|0664, st_size=0, ...}) = 0
fcntl(3, F_SETFD, FD_CLOEXEC)           = 0
write(3, "test", 4)                     = 4
fsync(3)                                = 0
close(3)  

libeatmydataあり

$ strace  eatmydata perl -MIO::Handle -e 'open(my $fh,">:unix","test.txt"); print $fh "test"; IO::Handle::sync($fh);'
open("test.txt", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 3
fstat(3, {st_mode=S_IFREG|0664, st_size=0, ...}) = 0
fcntl(3, F_SETFD, FD_CLOEXEC)           = 0
write(3, "test", 4)                     = 4
close(3)   

IO::Handle::syncやってるはずなのに、fsyncが表示されていません。

postfixのパフォーマンス改善

某所でPostfixを経由して外部の配信サービスにメールを転送しているサーバがあり、このIO負荷が高いのが課題となってました。

f:id:kazeburo:20161111142853p:plain

一斉メール送信のタイミングでかなりIO-waitが上がっています。

postfixの構成

www.wakhok.ac.jp

がわかりやすい。

postfixはいくつかのプロセスに分かれて動作します。メールを受けるときは、smtpdのプロセスが送信者からデータを受け取り、cleanupというプロセスに渡し、cleanupプロセスが実際にdiskに書き込む流れになっています。このcleanupプロセスがメールをdiskに書き込む時にfsyncを行うので、ここだけlibeatmydataを入れ込めば良いはず。

そこで /usr/libexec/postfix に cleanup_nosync というファイルを用意

#!/bin/sh
exec /usr/bin/eatmydata /usr/libexec/postfix/cleanup $*

master.cfを変更する

cleanup   unix  n       -       n       -       0       cleanup_nosync #最後だけ変更

postfixをreloadすれば設定が反映されます。

効果の確認

以上の設定をいれたサーバにて、受け取ったメールをすべて捨てるサーバ宛に大量にメールを送信して確認しました。

まず libeatmydata 適用前

$ vmstat 1
procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 1  0      0 2420292 249248 1677904    0    0     0    41    2    0  4  0 95  1  0
 1  0      0 2420284 249248 1677904    0    0     0     0 1264  325 23  2 74  0  0
 1  3      0 2387640 249248 1677904    0    0     0  1180 2660 3530 21  3 64 11  0
 0  0      0 2386628 249248 1677916    0    0     0  4356 5434 11669  9  4 77 10  0
 0  5      0 2385868 249248 1677956    0    0     0  3620 4632 10255 13  3 75  9  0
 0  0      0 2385844 249248 1678004    0    0     0  2792 4294 12083  4  4 88  4  0
 0  0      0 2385596 249248 1678052    0    0     0  3724 4772 13095  3  4 88  4  0
 0  0      0 2386200 249248 1678116    0    0     0  3408 4452 11660  4  4 86  6  0
 0  0      0 2387968 249248 1678136    0    0     0  2908 4327 10611  4  3 82 11  0
 0  0      0 2390704 249248 1678200    0    0     0  4724 5314 13459  4  5 86  6  0
 0  0      0 2388580 249248 1678240    0    0     0  5212 5520 13300  4  5 85  6  0
 3  1      0 2388208 249248 1678292    0    0     0  4716 5934 13486  4  5 86  6  0
 0  1      0 2387960 249248 1678344    0    0     0  4608 5947 13964  4  4 85  7  0
 0  1      0 2386720 249248 1678392    0    0     0  3164 4561 10527  3  4 81 11  0
 0  0      0 2386464 249248 1678424    0    0     0  4544 5555 13150  4  4 86  6  0
 0  0      0 2386092 249248 1678472    0    0     0  5052 6135 13801  4  4 85  7  0
 0  1      0 2387456 249248 1678524    0    0     0  5232 5905 13530  5  5 84  7  0
 0  0      0 2402424 249248 1678560    0    0     0   920 1203 2561  1  1 97  2  0
 0  0      0 2402424 249248 1678560    0    0     0     8  160  300  0  0 100  0  0

iowaitが5-10%前後でています。

libeatmydata 適用後

$ vmstat 1
procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 0  0      0 2421320 249256 1678660    0    0     0     8  266  474  0  0 100  0  0
 0  0      0 2391500 249256 1678660    0    0     0     0 2248 4025  5  2 93  0  0
 0  0      0 2391212 249256 1678652    0    0     0     0 6185 13856  4  4 92  0  0
 0  0      0 2390824 249256 1678976    0    0     0     0 6106 13950  4  4 92  0  0
 0  0      0 2391552 249256 1678804    0    0     0     0 5932 13648  4  4 92  0  0
 0  0      0 2388644 249256 1678868    0    0     0   104 5901 13003  5  5 91  0  0
 0  0      0 2389644 249256 1678896    0    0     0     0 5552 13448  4  4 92  0  0
 4  0      0 2389280 249256 1678936    0    0     0     0 5912 13921  4  4 93  0  0
 5  0      0 2391024 249256 1679004    0    0     0     0 6185 13774  4  4 93  0  0
 1  0      0 2390528 249256 1679056    0    0     0     0 5848 13187  4  4 92  0  0
 0  0      0 2390404 249256 1679108    0    0     0   116 6250 12982  5  4 91  0  0
 0  0      0 2387496 249256 1679156    0    0     0    12 6977 13495  6  6 89  0  0
 0  0      0 2389112 249256 1679176    0    0     0     0 6074 14039  4  4 92  0  0
 0  0      0 2387616 249256 1679236    0    0     0     0 5966 13956  4  4 92  0  0
 0  0      0 2403196 249256 1679296    0    0     0     0 1412 2950  1  1 99  0  0
 0  0      0 2403444 249256 1679304    0    0     0   136  217  450  0  0 100  0  0

iowaitは常に 0。圧倒的な効果がでました。

データの安全性対策

念のため、1秒間隔でdiskへのsyncが行われるように設定しました。

$ sudo sysctl -w vm.dirty_writeback_centisecs=100

productionへの適用

f:id:kazeburo:20161111142950p:plain

IO-waitが消え、送信にかかる時間も短くなりました。やった!