にゃみかんてっくろぐ

猫か百合を見守る壁になりたい

2020 年を振り返る

以前、はじめて転職活動をした際に「過去をしっかり振り返っておくことが大事」と言われたことがあり、実感として確かに大事だと感じた。

ということで 2020 年にやったことを整理しておく。

技術的なもの

「言語いっぱい触った」と書いても情報量に欠けるので、より具体的なアウトプットを並べてみる。

仕事: SRE 寄り

転職直後は「まずはサーバサイド頑張ろ」という気持ちだったが、ここ 1 年半ほどは「チームでインフラ触っている人少ないしやってみよ」ってこと SRE に近い立ち位置でいる。

過去に「できること、やりたいこと、求められていることの 3 つが重なっていると良い」と聞いたことがあり、その重なるところにスポッと入ったイメージである。

AtCoder

AtCoder color 色 です」と言われても「すごい(よくわかってない)」という感じだったので、短期集中でガッと Beginner Contest にチャレンジした。

chokudai さん曰く『エンジニアとしてもある程度の安心感がある』とされる緑色に到達したところで満足して止めた。

コンテスト成績表 から各コンテストの提出状況を見れば分かるが、 D 問題が解けたり解けなかったりしている。 A~C 問題を短時間で解いてレートを稼いでいた節はある。

新規 Web サービス

今年は 2 つの Web サービスを開発・公開した。

メトロ遅延なう

フロントエンドは TypeScript, React, MUI (Material Design) 、サーバサイドは馴染みある Ruby, Sinatra で開発。いわゆるテレワークで使わなくなってしまったが、それまでは CX (Commuter Experience: 通勤体験) の向上に役立っていた。


Uchibi (おうち美術館)

フロントエンドは TypeScript, Vue 、サーバサイドはやはり Ruby, Sinatra 。 美術展が軒並み中止や延期となる中、「美術展に行くことで創作意欲が刺激されていたのかもしれない」と思い立って開発。最近はあまり見ていない…

GitHub - typewriter/home-museum: Virtual museum using public domain (CC0) collections

既存サービス: P2P 地震情報 16 周年

今月で 17 年目に突入。劇的な変化はないものの、地道に運用、地道に改善を進めている。

  • JSON API v2, WebSocket API を開発・公開。実装は Golang
  • Flutter (Dart) でスマートフォン版の統一を目論む。開発途中。
  • 地震感知情報の評価結果 (信頼度)」について、 Golang へ移植し MongoDB コレクションに登録することでデータベース化した。これまでは VB6 製のアプリケーションでリアルタイムにしか確認できなかった。

初コントリビュート

自動的に Let's Encrypt の証明書を取得して HTTPS リバースプロキシを立ててくれる https-portalIPv6 対応にした。

typewriter.hatenablog.jp

技術的であるがお気持ちが強いもの

Mac mini, WSL2

1 月に Mac mini を調達したが、 4 月に HDMI 出力の不調でそのまま眠りについている。仕事は Mac 、プライベートは Windows 、という両立が実現しているのは WSL2 によるところが大きい。

WSL2 は地味だが体験として非常によい。起動が非常に早く、 Windows Terminal もまともなターミナルとして機能している。この記事も、 Windows Terminal 上の Neovim で textlint を動かしながら書いた。


Zen 3

上記の通り Windows に戻ってしまったが、 7 年前に組んだ自作 PC だった。まあ早いと思っていたが、 Zen 3 である Ryzen 5 5600X と M.2 SSD へ換装したところさらに快適になった。

現在 Flutter でアプリケーション開発を進めているが、 Android Emulator の起動やアプリケーションのデバッグもストレスなく出来ている。

プライベートでの技術戦略

仕事に役立つかどうかは一切気にせずやっている。今年で言えば、 Crystal, Golang, Flutter (Dart), WSL2 あたりだ。 Golang は結局仕事でも使ったが。

面白くて楽しいというのが一番の理由。プラス面は色々あると思うが、「プログラミング言語は複数習得すべき」とか「言語だけでなく文化も学ぶ」の二番煎じになりそうなので端折る。

技術的でないもの

Oculus Quest

2 が出る前に購入。 VR 酔いするので長時間は難しいが、外出がしづらい中で「別の世界」がそこにある、という体験は不思議で楽しい。

もともと VR 枯山水作りたいという気持ちで購入したが、 Unity を少し触った結果「これゴールまで遠すぎるわ…」と思ってまだプレイする側から抜け出していない。

百合

渡月橋で限界オタクになり、朗読劇ささつで佐伯沙弥香を追体験した。

また、はるゆき百合雑談から、 VTuber (バーチャルライバー) の Crossick (当時はにじさんじ性癖コンビ) の沼にハマってしまった。末永く幸せでいてほしい。

おわりに

「来年は」という話だが、新卒就活の際に計画的偶発性理論を聞いて「これだ」と思ったため、来年も良い方向に進むよう日々積み重ねていく、としか言えない。めでたしめでたし。

システムコールトレーシング: 吸い込まれる標準入力を観察する

Linuxその2 Advent Calendar 2020 18 日目の記事です。


スクリプト書いてたんですが、なぜか途中で止まるんです」と言われた。

f:id:no_clock:20201217003234p:plain
止まっている様子(シンタックスハイライトが綺麗でないので画像で)

確かに yarn gen で止まっている。 yarn startdate も実行されていない。終了コードは 0 で、正常だ。

「ファイルとして実行してみて」と伝えた。

f:id:no_clock:20201217003428p:plain
最後まで実行される様子

最後まで実行された。

雰囲気で「たぶん 標準入力が吸い込まれている」と雑返答をしてしまったが、ここでその正体を明らかにしておきたい。

1. strace でシステムコールを記録する

ソースコードを読むより strace コマンドで挙動を追うのが好きなので、 bash に strace をアタッチしてシステムコールを記録させる。

$ strace -p 10088 -f 2>&1 | tee strace.bash.log
strace: Process 10088 attached
pselect6(1, [0], NULL, NULL, NULL, {[], 8}

## この状態で、アタッチ中の bash に対して「途中で止まる」スクリプトを入力する
## ```
## bash <<EOF
## date
## yarn gen
## yarn start
## date
## EOF
## ```
(大量のトレース結果)
## Ctrl+C でデタッチする

^Cstrace: Process 10088 detached
 <detached ...>
$ wc -l strace.bash.log
33677 strace.bash.log

2. システムコールから挙動を観察する

2-1. ヒアドキュメントの書き出し

clone システムコールで子プロセスが作成し、その子プロセスでヒアドキュメントを書き出している。

clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLDstrace: Process 11360 attached
, child_tidptr=0x7f6ed3e90a10) = 11360
[pid 11360] openat(AT_FDCWD, "/tmp/sh-thd.7rsuca", O_RDWR|O_CREAT|O_EXCL, 0600) = 3
[pid 11360] fchmod(3, 0600)             = 0
[pid 11360] fcntl(3, F_SETFD, FD_CLOEXEC) = 0
[pid 11360] dup(3)                      = 4
[pid 11360] fcntl(4, F_GETFL)           = 0x8002 (flags O_RDWR|O_LARGEFILE)
[pid 11360] fstat(4, {st_mode=S_IFREG|0600, st_size=0, ...}) = 0
[pid 11360] write(4, "date\nyarn gen\nyarn start\ndate\n", 30) = 30
[pid 11360] close(4)                    = 0

2-2. 標準入力をヒアドキュメントに差し替え

書き出したヒアドキュメントは、読み取り専用で開き直してファイルディスクリプタ 0 (stdin) に複製する。すなわち子プロセスの 標準入力をヒアドキュメントに差し替えている

[pid 11360] openat(AT_FDCWD, "/tmp/sh-thd.7rsuca", O_RDONLY) = 4
[pid 11360] close(3)                    = 0
[pid 11360] unlink("/tmp/sh-thd.7rsuca") = 0
[pid 11360] fchmod(4, 0400)             = 0
[pid 11360] dup2(4, 0)                  = 0
[pid 11360] close(4)                    = 0

2-3. bash を実行

execve で、この子プロセスが bash に置き換わる。

[pid 11360] execve("/usr/bin/bash", ["bash"], 0x5642bbf4ca80 /* 25 vars */) = 0

2-4. 標準入力を読み込み

標準入力 (実体はファイルである) の先頭にシークして一気に読み込む。

fstat でサイズを調べて、 read でそのサイズ分を一気に読んでいるようだ。

[pid 11360] fcntl(0, F_GETFL)           = 0x8000 (flags O_RDONLY|O_LARGEFILE)
[pid 11360] fstat(0, {st_mode=S_IFREG|0400, st_size=30, ...}) = 0
[pid 11360] lseek(0, 0, SEEK_CUR)       = 0
[pid 11360] read(0, "date\nyarn gen\nyarn start\ndate\n", 30) = 30

2-5. date コマンドを探す

最初は date コマンドであることが分かったので、 PATH を順番に探しているようだ。

[pid 11360] stat("/home/linuxbrew/.linuxbrew/bin/date", 0x7fffccf3db80) = -1 ENOENT (No such file or directory)
[pid 11360] stat("/usr/local/sbin/date", 0x7fffccf3db80) = -1 ENOENT (No such file or directory)
[pid 11360] stat("/usr/local/bin/date", 0x7fffccf3db80) = -1 ENOENT (No such file or directory)
[pid 11360] stat("/usr/sbin/date", 0x7fffccf3db80) = -1 ENOENT (No such file or directory)
[pid 11360] stat("/usr/bin/date", {st_mode=S_IFREG|0755, st_size=108920, ...}) = 0

2-6. 標準入力をシークしなおし、 date を実行する

ここがポイントである。 読みすぎた標準入力のシーク位置を巻き戻している。 次の read でちょうど yarn gen 以降が読み込める位置だ。

clone でまた子プロセスを生成し、 bash は子プロセス終了を待つ。子プロセスは execve によって date に置換され実行されているが、詳細は省く。

[pid 11360] lseek(0, -25, SEEK_CUR)     = 5
[pid 11360] clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLDstrace: Process 11361 attached
, child_tidptr=0x7f685563ca10) = 11361
[pid 11360] wait4(-1,  <unfinished ...>
[pid 11361] execve("/usr/bin/date", ["date"], 0x55df84d668b0 /* 25 vars */) = 0
(略)
[pid 11361] exit_group(0)               = ?
[pid 11361] +++ exited with 0 +++
[pid 11360] <... wait4 resumed>[{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0, NULL) = 11361

2-7. 標準入力を再度読み込み

bash に戻ってきて、標準入力をまた読み込む。今度は yarn gen 以降を読み取る。

[pid 11360] read(0, "yarn gen\nyarn start\ndate\n", 30) = 25

2-8. yarn を探し、標準入力をシークし、実行し、そして…?

yarn コマンドが実行されるまでは date コマンドと同じ、コマンド検索 & シーク & 実行である。

シーク位置は、次に yarn start 以降が読み込まれる箇所だ。

[pid 11360] stat("/home/linuxbrew/.linuxbrew/bin/yarn", 0x7fffccf3db80) = -1 ENOENT (No such file or directory)
[pid 11360] stat("/home/typewriter/.nodenv/shims/yarn", {st_mode=S_IFREG|0755, st_size=405, ...}) = 0 
[pid 11360] lseek(0, -16, SEEK_CUR)     = 14
[pid 11360] clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLDstrace: Process 11362 attached
 <unfinished ...>
[pid 11360] wait4(-1,  <unfinished ...>
[pid 11362] execve("/home/typewriter/.nodenv/shims/yarn", ["yarn", "gen"], 0x55df84d66f70 /* 25 vars */) = 0

しかし、問題はこの先である。子プロセスを何度か作成し、 run-p コマンド(に置換されたプロセス)の子プロセス (pid: 11409) に辿り着く。 yarn start\ndate\n を読み込んでしまっている。

[pid 11362] clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLDstrace: Process 11400 attached
 <unfinished ...>
[pid 11400] clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLDstrace: Process 11401 attached
 <unfinished ...>
[pid 11401] execve("/home/typewriter/.nodenv/versions/12.18.3/bin/run-p", ["run-p", "-s", "--print-label", "gen:*"], 0x55dcfacf6f68 /* 58 vars */ <unfinished ...>
[pid 11401] clone(child_stack=0x7f6061052f70, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTIDstrace: Process 11409 attached
 <unfinished ...>
[pid 11409] read(0,  <unfinished ...>
(略)
[pid 11409] <... read resumed>"yarn start\ndate\n", 65536) = 16

2-9. 標準入力は空っぽ。完

yarn gen が終わり、次に標準入力を読むと、空になってしまっている。 yarn start と date が実行されないまま bash が終了する。

[pid 11362] +++ exited with 0 +++
[pid 11360] <... wait4 resumed>[{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0, NULL) = 11362
[pid 11360] read(0, "", 30)             = 0
[pid 11360] exit_group(0)               = ?
[pid 11360] +++ exited with 0 +++
<... wait4 resumed>[{WIFEXITED(s) && WEXITSTATUS(s) == 0}], WSTOPPED|WCONTINUED, NULL) = 11360

観察した挙動をまとめる

標準入力にまつわる一連の挙動を整理するとこうだ。

f:id:no_clock:20201217231123p:plain
図: 標準入力の吸い込まれ具合(▽印はファイルのオフセット)

3. ドキュメントから挙動を解釈する

挙動は整理できたが、なぜこのような挙動をするのか、ドキュメントから解釈していく。

read, lseek によるファイルのオフセットの変更

read するとオフセットが進むが、 lseek で自由に変更できる。

seek に対応しているファイルでは、read は現在のファイルオフセットから行われ、ファイルオフセットは読み込んだバイト数分だけ進められる。

Man page of READ

lseek() 関数は、ファイルディスクリプター (descriptor) fd に対応するオープンされたファイルのオフセットを、 whence に基づき offset 引き数の位置へ以下のように変更する (略)

Man page of LSEEK

標準入力を共有している挙動

標準入力、標準出力、標準エラー出力は、ファイルディスクリプタ 0, 1, 2 に割り当てられている。

プログラムの起動時には、 ストリーム stdin, stdout, stderr に結びつけられているファイルディスクリプターの番号は、 それぞれ 0, 1, 2 である。

Man page of STDIN

そして、 clone システムコールのドキュメントを読むと、ファイルディスクリプタを共有または複製するとある。今回は、( run-p を除き) CLONE_FILES フラグが設定されていないため、 複製 されている。いずれにせよ、 bash の標準入力を date や yarn が共有するのは確かなようだ。

CLONE_FILES (Linux 2.0 以降)

CLONE_FILES が設定された場合、呼び出し元のプロセスと子プロセスはファイルディスクリプターの テーブルを共有する。 (略)

CLONE_FILES が設定されていない場合、子プロセスは、 clone() が実行された時点で、呼び出し元のプロセスがオープンしている全ての ファイルディスクリプターのコピーを継承する (子プロセスの複製されたファイルディスクリプターは、 対応する呼び出し元のプロセスのファイルディスクリプターと 同じファイル記述 (open(2) 参照) を参照する)。 これ以降に、呼び出し元のプロセスと子プロセスの一方が ファイルディスクリプターの操作 (ファイルディスクリプターの オープン・クローズや、ファイルディスクリプターフラグの変更) を行っても、もう一方のプロセスには影響を与えない。

Man page of CLONE

標準入力のシーク位置を共有している挙動

さきほどの clone のドキュメントには、「呼び出し元のプロセスのファイルディスクリプターと 同じファイル記述 (open(2) 参照) を参照する」とあった。「ファイル記述」とはなにか、 open システムコールのドキュメントを参照する。

ファイル記述とは、システム全体のオープン中のファイルのテーブルのエントリーである。 このオープンファイル記述は、ファイルオフセットとファイル状態フラグ (下記参照) が保持する。 ファイルディスクリプターはオープンファイルっ記述への参照である。 (※原文ママ)

Man page of OPEN

「ファイルディスクリプタ」と「ファイル記述」は名前が似ているが別物のようだ。図にするとこうだろうか?

f:id:no_clock:20201218001105p:plain
図: ファイルディスクリプタとファイル記述とファイルの関係

ここで重要なのは、どのプロセスも同じ「ファイル記述」を指していて、ファイルオフセットを共有しているということだ。

つまり、「たぶん 標準入力が吸い込まれている」の正体は、「bash と同じファイル記述を共有する孫プロセス run-p が標準入力を read したためにファイルオフセットが進んでしまい、 bash は標準入力から何も読み取れずに終了した」ということだった。

おまけ: ファイルとして実行した場合の挙動

ファイルとして実行した場合は、ファイルディスクリプタ 255 に割り当てて読み取っている。これにより、子プロセスが標準入力をいくら吸い取っても問題にはならない。 255 には何か意味があるようだが 、未調査のため割愛する。

[pid 12990] lseek(255, 0, SEEK_CUR)     = 0
[pid 12990] read(255, "#!/bin/bash\n\ndate\nyarn gen\nyarn "..., 43) = 43

まとめ

  • 標準入力をすげかえない限り、標準入力やそのオフセット(を含むファイル記述)は子プロセスと共有される。
  • 子プロセスが標準入力を read してしまうと、オフセットが進んで親プロセス bash が読みたかったコマンドを通り過ぎてしまう。

参考

同じドメインに A レコードが複数あるときのクライアントの挙動 (Chrome, Safari, curl)

おことわり: TCP/IP スタックの設定値などを深追いしておらず、「こう動いたが、根拠は調べていない」というレベルのものです。

いきなりまとめ

前提条件

同一ドメインに複数の A レコードを設定する。なお、 IP アドレスは RFC5737 で規定されている仕様書やドキュメント向けの IPv4 アドレスであり、接続はできない。

$ dig roundrobin.nyamikan.net A

; <<>> DiG 9.16.1-Ubuntu <<>> roundrobin.nyamikan.net A
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 49795
;; flags: qr rd ad; QUERY: 1, ANSWER: 4, AUTHORITY: 0, ADDITIONAL: 0
;; WARNING: recursion requested but not available

;; QUESTION SECTION:
;roundrobin.nyamikan.net.       IN      A

;; ANSWER SECTION:
roundrobin.nyamikan.net. 0      IN      A       203.0.113.1
roundrobin.nyamikan.net. 0      IN      A       203.0.113.3
roundrobin.nyamikan.net. 0      IN      A       203.0.113.4
roundrobin.nyamikan.net. 0      IN      A       203.0.113.2

確認方法

HTTP アクセスを試み、 Wireshark でパケットキャプチャして挙動を観測する。

  • 複数の IPv4 アドレスに接続しにいくか
  • 順番に接続しにいくか、同時に接続しにいくか
  • 接続間隔( 1 IPv4 アドレスあたりのタイムアウト)はどの程度か

確認結果

OS ツール 挙動
Windows 10
バージョン 20H2
OS ビルド 19042.630
Google Chrome
87.0.4280.66
アドレスバー入力
約 21 秒間隔で順番に接続試行
その後 ERR_CONNECTION_TIMED_OUT 表示
さらに自動的にリトライ
Windows 10
バージョン 20H2
OS ビルド 19042.630
Google Chrome
87.0.4280.66
Fetch API
約 21 秒間隔で順番に接続試行
その後エラー
Ubuntu 20.04.1 LTS
Windows Subsystem for Linux 2
curl 約 32 秒間隔で順番に接続試行
その後エラー
macOS Mojave
(バージョン 10.14.6)
Google Chrome
86.0.4240.198
アドレスバー入力
約 75 秒間隔で順番に接続試行
4 分経過時点で ERR_CONNECTION_TIMED_OUT 表示
さらに自動的にリトライ
macOS Mojave
(バージョン 10.14.6)
Google Chrome
86.0.4240.198
Fetch API
約 75 秒間隔で順番に接続試行
4 分経過時点でエラー
macOS Mojave
(バージョン 10.14.6)
Safari
13.1.2 (14609.3.5.1.5)
アドレスバー入力
0.25 秒間隔で同時に接続試行
約 70 秒でエラー
macOS Mojave
(バージョン 10.14.6)
Safari
13.1.2 (14609.3.5.1.5)
Fetch API
0.25 秒間隔で同時に接続試行
約 70 秒でエラー
macOS Mojave
(バージョン 10.14.6)
curl 約 75 秒間隔で順番に接続試行
その後エラー
  • いずれのツールも複数の IPv4 アドレスに接続試行していた。
  • 順番に接続試行するものが多く、 また試行間隔が長いものが多い。
  • macOS Safari が 0.25 秒間隔で同時に接続試行している点は興味深い。

不正確な推測、憶測

詳細な確認結果

続きを読む

「インデックスが作成されていないカラムを WHERE 句に書かない」コーディング規約と、暗黙的なコンテキスト

一部フィクションを含むポエムです。

XX システム SQL コーディング規約

性能劣化の可能性があるため、インデックスが作成されていないカラムを WHERE 句に書かないこと。
(インデックスの作成有無はテーブル定義書を参照)

こうしたコーディング規約が ある ところは、 SQL 文を書くメンバが、概ね文法のみを知っていればよい、と言える。 誤解を恐れずに言えば、 メンバは RDBMS をあまり知らなくてよい

では、逆の場合、コーディング規約が ない ところを考えたい。

SQL 文を書くメンバは、 RDBMS を知っていて当然」、つまり暗黙的なコンテキストを設定していると言えるだろうか。必ずしもそうではないように感じる。いくつかのケースが思いつく。

暗黙的なコンテキストとして「みな知っていて当然」としているケース。 SQL 文を書くメンバは 当然 RDBMS の検索処理を知っており、適切な SQL 文を書くことができる、というもの。

「誰かが知っていて、ツッコミが入るはず」としているケース。たとえば、 SQL 文にアーキテクトやレビュアのチェックが入り、リリースまでに適切な SQL 文になるはずである、といったもの。

無秩序なケース。リリースして火を吹く可能性があるが、そのリスクを受け入れる、というもの。


「みな知っていて当然」は状態として最高のように思えるが、人間は全知全能の神ではないため「当然」というのはプレッシャーにもなりうる。一方で、無秩序なケースはプレッシャーを感じなかったとしても将来大きな損害を被る恐れがある。

いまのチーム、いまのプロジェクト、いまの現場は、どのケースだろうか。リスクとリターンを天秤に乗せたときに、ベターな状態だろうか。

Amazon ECS: curl コンテナを使ってタスク定義だけでモックサーバを設定する

3 行まとめ

  • API のモック化ツール WireMock には、動的にスタブ/モックを定義できる Admin API がある
  • ECS タスク定義に「 Admin API を叩く curl コンテナ」を加えて WireMock のスタブ/モック定義を行う
  • タスク定義だけ完結するので楽

タスク定義だけでモックサーバを設定する

テスト用のモックサーバの 1 つに WireMock がありますが、この WireMock には動的にスタブ/モックを定義できる Admin API があります (Stubbing - WireMock) 。

この Admin API を利用します。 Amazon ECS のタスク定義に「 WireMock コンテナ」に加えて「 Admin API を叩く curl コンテナ」を用意することで、 WireMock の設定が可能になります。

タスク定義例

ポイントは 2 点です。

  • WireMock が起動したあとに curl を叩くよう、ヘルスチェックと依存関係を設定
  • curl コンテナは実行後終了するので essential: false とする
{
    "containerDefinitions": [
        {
            "portMappings": [
                {
                    "hostPort": 8080,
                    "protocol": "tcp",
                    "containerPort": 8080
                }
            ],
            "cpu": 0,
            "image": "rodolpheche/wiremock:latest",
            "healthCheck": {
                "retries": 3,
                "command": [
                    "CMD-SHELL",
                    "curl -f http://localhost:8080/__admin/mappings || exit 1"
                ],
                "timeout": 5,
                "interval": 10,
                "startPeriod": 30
            },
            "essential": true,
            "name": "wiremock"
        },
        {
            "command": [
                "curl", "-X", "POST", "--data", "{ \"request\": { \"url\": \"/test\", \"method\": \"GET\" }, \"response\": { \"status\": 200, \"body\": \"Hello world!\" }}", "http://localhost:8080/__admin/mappings"
            ],
            "cpu": 0,
            "image": "curlimages/curl:latest",
            "dependsOn": [
                {
                    "containerName": "wiremock",
                    "condition": "HEALTHY"
                }
            ],
            "essential": false,
            "name": "curl"
        }
    ],
    "memory": "512",
    "family": "fargate-wiremock-with-curl",
    "requiresCompatibilities": [
        "FARGATE"
    ],
    "networkMode": "awsvpc",
    "cpu": "256"
}

実行例

タスクを起動してしばらくすると、 curl コンテナは Admin API を叩いた後に終了します。

f:id:no_clock:20201001235224p:plain

GET /__admin/mappings で期待通り定義されていることが確認できます。また、 GET /test でも定義通りに WireMock がレスポンスを返却していることがわかります。

$ curl http://example.com:8080/__admin/mappings
{
  "mappings" : [ {
    "id" : "f8819ad0-32ca-408a-b248-d77a05767409",
    "request" : {
      "url" : "/test",
      "method" : "GET"
    },
    "response" : {
      "status" : 200,
      "body" : "Hello world!"
    },
    "uuid" : "f8819ad0-32ca-408a-b248-d77a05767409"
  } ],
  "meta" : {
    "total" : 1
  }
}
$ curl -v http://example.com:8080/test
(省略)
< HTTP/1.1 200 OK
< Matched-Stub-Id: f8819ad0-32ca-408a-b248-d77a05767409
< Vary: Accept-Encoding, User-Agent
< Transfer-Encoding: chunked
<
Hello world!

お手軽で再現性もある

実際に活用しましたが、ちょっとしたモックサーバを準備したいときにピッタリでした。

  • 設定ファイルを S3 からダウンロードしてマウントする、設定ファイルを含む自前の Docker イメージを作る、といった作業は不要
  • 手で Admin API を叩く場合と比較して、モック定義に再現性がある
  • タスク定義に閉じるため、管理するもの・考えるものが少なくて済む

参考

Traefik でお手軽に Docker コンテナの無停止 Blue/Green デプロイを実現した

3 行でまとめると

  • Traefik を使って Docker Compose だけで無停止デプロイを実現
  • docker-compose.yml に定義するだけ、他の設定ファイルは不要のお手軽さ
  • コンテナは graceful shutdown するようにしておく

docker-compose.yml

ざっくり作り上げた docker-compose.yml がこちらです。

gist.github.com

これだけで動きます。リクエストを投げながら nginx-blue, nginx-green のどちらか一方を落としてもエラーになることはありません。

f:id:no_clock:20200603225248p:plain
nginx-blue を停止してもエラーなくレスポンスし続けている様子

Traefik とは

Traefik はある種のリバースプロキシです。ただし、 HAProxy や nginx と違ってサービス検出機能が備わっているほか、環境変数メタデータ (Docker の場合は labels) で設定ができるのも特徴的です。

サービス検出機能と 仲良く なる必要はあるものの、設定の記述量が少なくて済みます。 Docker の場合は、 Traefik 自身が Docker デーモンにアクセス出来るようにします。

    volumes:
      - "/var/run/docker.sock:/var/run/docker.sock:ro"

ちょっと気をつけたいところ

  1. 公式ドキュメントのみを頼ったほうが良いです。Google 検索で調べても情報は出てきますが、 frontendbackend といった v1.x 系列の設定を取り上げた記事がヒットして非常に混乱します。
  2. EntryPoints, Routers, Services と複数段定義する必要があり、とっつきにくい印象があるかもしれません。めちゃくちゃ端折って Nginx と対比すると下記の通りです、難しくないと思い込みましょう。
Traefik Nginx
EntryPoints listen ディレクティブ
Routers server ディレクティブ(ホスト名) と location ディレクティブ
Services upstream ディレクティブ

無停止デプロイする

さて、無停止デプロイをしましょう。ポイントは 2 点です。

  • コンテナが graceful shutdown *1 するか、リクエストが冪等であること。
    • traefik はクラウドロードバランサーサービスにあるような接続ドレインの機能を持ちません。コンテナ自身が受け付けたリクエストを正しく処理しきることが望ましく、それが出来ない場合はリクエストの処理を冪等にしておく必要があります。
  • Retry middleware を使う

冒頭の docker-compose.yml では、 nginx に SIGQUIT を投げることで graceful shutdown を実現しています。

    image: "nginx:alpine"
    stop_signal: SIGQUIT
    labels:
(略)
      - "traefik.http.middlewares.nginx-retry.retry.attempts=4"

healthcheck はなくても大丈夫

traefik には healthcheck 機能があり、これを使ったコンテナの切り離しも可能です。

    labels:
(略)
      - "traefik.http.services.nginx-bg.loadbalancer.healthcheck.path=/"
      - "traefik.http.services.nginx-bg.loadbalancer.healthcheck.interval=1s"
      - "traefik.http.services.nginx-bg.loadbalancer.healthcheck.timeout=1s"

ただし、 Retry middleware を使うことで下記の動きとなるため、 healthcheck を設定しなくても問題はありません。

  1. Listen をやめた停止中のコンテナにルーティング
  2. コネクションが確立出来ないため、即座にリトライ
  3. 実行中のコンテナにルーティング

メモリ使用量

かなり雑ですが、 1MB のファイルを 100 同時接続で計 10,000 リクエスト、 10GB 分の転送をさせました。

$ ab -n 10000 -c 100 -H "Host: localhost" http://localhost/
# 起動直後
$ docker stats
CONTAINER ID        NAME                    CPU %               MEM USAGE / LIMIT     MEM %               NET I/O             BLOCK I/O           PIDS
903a420aa79c        traefik_nginx-blue_1    0.00%               1.898MiB / 592.5MiB   0.32%               800B / 42B          6.21MB / 0B         2
bb10478ecb4b        traefik_traefik_1       0.03%               10.18MiB / 592.5MiB   1.72%               800B / 0B           46.3MB / 0B         6
7f123e90926c        traefik_nginx-green_1   0.00%               1.777MiB / 592.5MiB   0.30%               578B / 0B           348kB / 0B          2

# リクエスト後
$ docker stats
CONTAINER ID        NAME                    CPU %               MEM USAGE / LIMIT     MEM %               NET I/O             BLOCK I/O           PIDS
903a420aa79c        traefik_nginx-blue_1    0.00%               2.191MiB / 592.5MiB   0.37%               4.28MB / 5.21GB     7.27MB / 0B         2
bb10478ecb4b        traefik_traefik_1       0.00%               25.42MiB / 592.5MiB   4.29%               10.5GB / 10.5GB     46.8MB / 0B         19
7f123e90926c        traefik_nginx-green_1   0.00%               2.293MiB / 592.5MiB   0.39%               4.22MB / 5.22GB     1.4MB / 0B          2

nginx のメモリ使用量の少なさが際立ちますが、 traefik も 25MB に収まっています。実行中も 30MB を超えることはありませんでした。

参考

*1:明確な定義はないですが、ここでは、 Listen をやめ新たなリクエストを受け付けないようにした後、既存のリクエストを処理しきってから終了する振る舞いを指します。参考: Apache HTTP Server の停止と再起動 - Apache HTTP サーバ バージョン 2.4

個人開発サービスのログをぜんぶ CloudWatch Logs にまとめた

3 行でまとめると

  • ログを CloudWatch Logs に集約した
  • Metric filter でエラー数をメトリクス化した
  • CloudWatch Alarms ではなく Lambda でエラーを Slack 通知させるようにした

CloudWatch Logs にログを集約した

zenrei.nyamikan.net をすべて Docker 化した のに続いて、 P2P 地震情報にゃみかんの個人開発サービスのログを CloudWatch Logs に集約しました。

むかし

これまでは MonitXymon (旧 Hobbit ) を使ったログ監視を行っていました。

f:id:no_clock:20200531163107p:plain
旧構成

ログファイルとアラート対象のキーワードを指定するシンプルな仕組みでしたが、 長期運用するには少し面倒 でした。あと使っているものが古い 。

  • ディスクフル。気がつくとログがいっぱいになりがち。ログは残しておきたいので logrotate で消すわけにもいかず、定期的に退避する仕組みを用意するのも面倒で、手で退避させる作業を時々やっていた。
  • 再設定の手間Debian GNU/Linux の LTS リリースの度にサーバを構築し直しているが、 2 年に 1 回なのでいつも設定方法を忘れて四苦八苦していた。

いま

いまは CloudWatch へ集約した形にしました(その他、大部分を Docker コンテナ化してポータビリティを高めています)。

f:id:no_clock:20200531151932p:plain
新構成

ログ収集

CloudWatch エージェント もしくは "awslogs" Docker ログドライバ を用いて CloudWatch Logs にログを集約します。この際、サーバ起動時に logs.*.amazonaws.com が解決できない問題にハマりました。 Docker サービス起動前に 30 秒のスリープを入れる雑な方法で対処しています。

エラーの検出

エラー検出には、 CloudWatch のメトリクスフィルタを使用しています。特定のキーワードがあると、メトリクスがカウントされます。

f:id:no_clock:20200531171226p:plain
エラーがメトリクスでカウントされている様子

20 弱あるロググループを手で設定するのは大変なので、 AWS CDK (C#) でコード化しています(参考: AWS CDK for .NET: C# で CloudWatch Metric Filter を設定する - にゃみかんてっくろぐ)。

エラーの通知

ふつうはメトリクスを CloudWatch Alarms で監視させますが、今回は使いませんでした。 CloudWatch Events で Lambda をキックして Slack に通知させています。

  • アラームメトリクスあたり $0.1/month で、今後メトリクスを増やすとそこそこのお値段になってしまう。
  • 個人開発で Lambda を有効活用してみたい。

合理的というよりは 興味本位 の選択です。

コードは Gist に置いていますが、不慣れな JavaScript && 動けばいいやの精神なので可読性はお察しください → Notify CloudWatch Metrics to Slack (typewriter/metrics-to-slack.js)

f:id:no_clock:20200531172812p:plain
ゆかりさんが Slack にエラー発生を通知してくれている図

おねだん

気になるお値段はざっとこんな感じです。

サービス 月額料金 備考
CloudWatch Logs ログ収集 $0.76 無料枠 5GB/ 月 を超え、毎月 6GB ほどのログを収集している
CloudWatch Logs ログ保管 $0.00 無料枠 5GB/ 月 以下(まだ運用して 1 ヶ月ほどで蓄積がないため)
CloudWatch Metrics $0.00 無料枠 10 メトリクス / 月以下。メトリクスフィルタはデータポイントが発生しない部分は課金されない様子
CloudWatch Events $0.04 ? 無料枠なし。まだ請求に上がって来ていないが、カスタムイベント扱い・毎分実行の場合で計算
Lambda $0.00 実行回数 43,200 回(無料枠 1,000,000 回)、実行時間 3,240 GB 秒(無料枠 400,000 GB 秒)

感想

総合すると、そこそこ楽になりました。

  • よいところ
    • ディスクフルを気にしなくていい
    • 1 箇所に集約されている安心感
    • 「とりあえず CloudWatch Logs に流しちゃお」というデフォルトの選択肢が出来た
  • わるいところ
    • 雑に作った通知がエラー数だけで、エラー内容は見に行かないと行けない
  • どちらでもないところ
    • 毎月 6GB もログが発生していることに初めて気づいた