valid,invalid

関心を持てる事柄について

十分明解に語られる問題は、半分解決した問題である

"A Problem well stated is half solved." という格言がコンサル業界では最初に教えられることらしい。

www.levyinnovation.com

プログラミングの世界でいう「名前重要」、適切な名前を与えることが多様な場面で効用を生むことは知られており、これに近しいものかなと思った。名付けられない・語れない問題については十分に理解がされていない、ゆえに解決されないということ。

ウィトゲンシュタインの「語り得ぬもの」を思い起こさせる…とそれっぽいことを言ってみるが字面が似ているのを持ってきただけでよくわかっていないので論理学や形而上学に詳しい方の解説が待たれる

最後の1-on-1でEngineering Managerとしての自分へフィードバックを貰えて良かった話

昨年9月にQuipperに入社した@ujihisaさんという方のEngineering Managerを9ヶ月のあいだ務めました。

5月末をもって彼のマネジャーが変わる*1ため、僕がEngineering Managerとして行う最後の1-on-1が行われたのが去る日令和元年五月二十二日。その中で「僕が9ヶ月間Engineering Managerとしてどうだったか」についてフィードバックを貰えて非常に良い体験だったのでそのことについて書きます。

フィードバックのメモ

いつも1-on-1で使っているGoogle documentをそのままスクショして貼ります。

なお、「このメモはフリー素材として使って良い」との許諾をこちらから切り出す前に彼から提言してもらいました。いやー、そういうところが凄いんだよな。

特に事前準備もしてもらわずに先制質問したようす

f:id:ohbarye:20190524003623p:plain
ポジティブなところを挙げてもらっているところ

褒められ慣れていないので終始embarrassing

(マネジャーではあったが事情によりずっと違うチームでの開発だったのでそのへんのフィードバックチャンスを逸したのが残念)

改善点があれば聞きたい!と突っついたようす

フィードバック力が高い

f:id:ohbarye:20190524003709p:plain
ネガティブフィードバックを貰おうとしたときにすごい気付きがあった様子

僕をふらっと捕まえづらい状態が一時期続いたのはさすがに良くなかったと反省していたので図星の反省。 このことが彼にとってクリティカルな問題を引き起こしはしなかったけど、他ならぬ僕自身にとっての困りごとだった。

また、ロールモデルが近くにいない」は僕がぼんやり感じていたことをずばり言い当ててくれました。ここでいうロールモデルは完全上位互換を指して言っています。これまで僕はいろんな方のいろんな強いところを組み合わせた空想上のキメラロールモデルをただぼんやり描いていたけれども、自分の完全上位互換がロールモデルとして身近にいる状態だとモチベーションやプレッシャーが全く違ってくるんだろうなぁ。

この指摘は本当に僕にぶっ刺さっていて、2日経ってもまだ抜けない

1-on-1について語るようす

週1回20分をずっとやってました。

f:id:ohbarye:20190524003747p:plain
1-on-1についてのフィードバック

物理的に同じ部屋でやったり、リモートのときはZoomでつないだりしてました。中でも1-on-1の日に最寄り駅で偶然遭遇したときにやった"電車内1-on-1"には圧倒的新規性があって良かったです。


マネジャーがフィードバックを貰う機会を増やす

1-on-1などの対話ではメンバーの話を聞くことが多いのでEngineering Managerとしてのフィードバックを貰う機会はさほど多くない。(自分の上司から評価を貰う機会はあるけれども)

意識して増やすか、意識せずともフィードバックが集まるような仕組みづくりをしたい。

フィードバックを貰う勇気

正直「自分マネジャーとしてどう?」と聞くのはこわい、勇気が必要。

「ぜんぜん仕事してないように見える」とか「空回りしてないすか?」とか「自分にはマネジャーいらないんで何もしないでください」とか言われると相当凹むと思う。*2

まぁでも、そうした率直なフィードバックは凹むけど改善に繋げられるのでありがたくて、もし心にもないお世辞など言われようものならその時点で「うわ〜〜〜どこからやり直せばいいんだ…おれたちは…」という感じになりますよね、本当。

f:id:ohbarye:20190524005703p:plain

って感じになると思います、本当。


余談

メモの最後に残された謎の言葉────

f:id:ohbarye:20190524003821p:plain
:goodpoem:

*1:ujihisaさんが5月末にカナダに移住予定。異動的なものが発生してマネジャーが変わる

*2:今の会社にそういうことを言う人はいないと思うけど、ついついそういうケースを考えてしまう性(さが)

docker run -it で学ぶ tty とか標準入出力とかファイルディスクリプタとか

たとえばRubyのちょっとしたスクリプトを試したいときにdocker run -it ruby等でirbを立ち上げて試したりするわけですが、よく使うdocker rundocker exec-i, -t ってそもそも何なんだろうとふとした時に思いました。

そして、それぞれ何のためのオプションなのか、--helpを見ても「Keep STDIN open...? pseudo-TTY...?」ぱっと理解できなくて辛くなり。

-i, --interactive Keep STDIN open even if not attached

-t, --tty Allocate a pseudo-TTY

docs.docker.com

なるほどUNIXプロセス』を読んでこのあたりの基礎知識が身についた気がしているので、「とりあえず付けておけばOKでしょ」ぐらいのふわっとした理解から「なぜ無いといけないのか」がわかるところまで掘り下げてみたメモです。

途中で標準入出力とかファイルディスクリプタ等の知識が必要なシーンがあり、個人的に同書の内容の一部について良い復習になりました。

用語

本記事中に出てくる言葉などをサクッと見つめてみます。

/dev

Unixにおいてデバイスファイルをマウントするためのディレクトリ。

Unixの世界では「すべてがファイル」であり、デバイスもソケットやパイプも全てファイルとして扱われる。

tty

ttyとは、標準入出力となっている端末デバイス(制御端末、controlling terminal)の名前を表示するUnix系のコマンドである。元来ttyとはteletypewriter(テレタイプライター)のことを指す。 https://ja.wikipedia.org/wiki/Tty

概念を理解するには ttyとptsとは – PAYFORWARD の図と、以下の説明がわかりやすいです。

20141231_tty_pts

今では考えられないが,一昔前は1つのホストに色々な人が端末をつないで作業をしていたとのこと.ここでいう端末はWindowsMacなどのクライアント端末ではなく,キーボードのような役割を果たしていたと考えていいかな.

pts

pts - スペシャルファイル (デバイス)の説明 - Linux コマンド集 一覧表によると、ptsは擬似端末スレーブ (pseudo-terminal slave; PTS)。

ファイルシステム上では/dev/ptsに作成される、仮想端末を示す。

標準入出力

割愛しますが標準ストリーム - Wikipedia参照。

ファイルディスクリプタ

こちらも割愛します。 ファイル記述子 - Wikipedia参照。

macOS上でttyとあそぶ

macOS 10.14.2でいくつかのコマンドを試してみます。

まずterminal (私の場合はiTerm2)を起動した時点で最後にログインしたterminalのttyの情報が出力されている。(今までぜんぜん気にしていなかった)*1

Last login: Sat May 4 21:31:25 on ttys001

f:id:ohbarye:20190504213052p:plain

複数端末から接続するような状態に似せるため、terminalを2つ起動しておきます。

以降それぞれをterminal 1, terminal 2と呼び、実行したコマンドの先頭行に記載します。特に記載のないものはどちらのterminalで実行しても結果が同じものです(正確には一致しないけれども本筋じゃないので無視できるもの)。

tty

バイスファイル名を取得するという、ttyコマンドを実行します。

# terminal 1
❯ tty
/dev/ttys01

各terminalごとに異なるデバイスファイル名が割り当てられていることがわかります。

# terminal 2
❯ tty
/dev/ttys02

ps

psコマンドで起動しているzshプロセスと、紐づくTTYを確認できる。

❯ ps
  PID TTY           TIME CMD
17083 ttys001    0:00.04 /Users/ohbarye/Applications/iTerm.app/Contents/MacOS/iTerm2 --server login -fp ohbarye
17085 ttys001    0:01.26 -zsh
17126 ttys002    0:00.02 -zsh
17250 ttys003    0:00.08 /Users/ohbarye/Applications/iTerm.app/Contents/MacOS/iTerm2 --server login -fp ohbarye
17252 ttys003    0:01.08 -zsh
17293 ttys004    0:00.01 -zsh

w

wコマンドでもできる。

❯ w
21:39  up 119 days, 20:21, 3 users, load averages: 2.86 2.72 2.73
USER     TTY      FROM              LOGIN@  IDLE WHAT
ohbarye  console  -                01 319  63days -
ohbarye  s003     -                21:38       1 -zsh
ohbarye  s001     -                21:38       - w

リダイレクト

ttyコマンドでそれぞれのterminalのデバイスファイル名がわかったところで、標準出力の内容を渡してみます。

前述の通り「Unixはすべてをファイルとして扱う」ため、デバイスファイル /dev/ttys001 もファイルのように振る舞えます。他のデバイス (terminal) にメッセージを送るときもファイルにリダイレクトするかのように echo "hello from $(tty)" > /dev/ttys001 ができます。

# terminal 2echo "hello from $(tty)" > /dev/ttys001

# terminal 1 の方に hello from /dev/ttys003 と出力される
# terminal 1 で上記コマンドを実行した場合は terminal 1 にそのまま返ってくる

f:id:ohbarye:20190504214644g:plain
バイスファイルにリダイレクトする様子

リダイレクトは「標準出力の出力先を別ファイルにすること」なので送信元のターミナル(デバイス)には結果が出力されず、送信先のターミナル(デバイス)に出力されるというわけです。

リダイレクト先を自身のデバイスファイルにすると、自身のterminalに返ってきます。

docker container上でttyとあそぶ

ようやくdockerコマンド打っていくところです。

まず、1つめのterminalからdocker containerをdocker run --rm -it --name tty-test ruby bash で起動します。rubyのdocker imageをたまたま使っていますが何でもよいです。

ttyコマンドを実行すると現在利用している端末がpts(擬似端末)として表現されていることがわかります。

# terminal 1

$ docker run --rm -it --name tty-test ruby bash

root@f8e2c6358cea:/# tty
/dev/pts/0

次に、2つめのterminalからdocker exec -it tty-test bashを実行し、同じdocker container上にもう一つbashプロセスを立ち上げてみます。 今度はデバイスファイル名がincrementされた別物が出現しました。接続を増やすたびに増えていくようです。

# terminal 2

$ docker exec -it tty-test bash

root@f8e2c6358cea:/# tty
/dev/pts/1

f:id:ohbarye:20190504215525g:plain
docker container上にbashプロセスを2つ立ち上げてtty確認

/dev/ptsを見ることで現在接続されている端末の数がわかります。

root@221079d1d77c:/# ls -la /dev/pts
total 0
drwxr-xr-x 2 root root      0 May  4 09:21 .
drwxr-xr-x 5 root root    360 May  4 09:21 ..
crw--w---- 1 root tty  136, 0 May  4 09:22 0
crw--w---- 1 root tty  136, 1 May  4 09:24 1
crw-rw-rw- 1 root root   5, 2 May  4 09:24 ptmx

ptmxについてはpts - スペシャルファイル (デバイス)の説明 - Linux コマンド集 一覧表を参照(あまりよくわかっていない)

ps aすると2つのbashプロセス(とps aプロセス)が見えます。

root@221079d1d77c:/# ps a
  PID TTY      STAT   TIME COMMAND
    1 pts/0    Ss     0:00 bash
    7 pts/1    Ss+    0:00 bash
   25 pts/0    R+     0:00 ps a

docker run (terminal 1側) で先に起動したのはpid=1の方です。dockerはcontainerを立ち上げるときに指定されたコマンドをpid=1で実行するためです。

消去法でdocker execで後に起動したのはpid=7の方だとわかりますが、このpidは実行のたびに変わるので同じ番号であることは保証されません。

pid=1に関する余談

ふつうUnixではpid=1はinitプロセスで、initプロセスに対する操作は特殊な扱いになります。(man 2 kill等に記載あり)

また、node.jsをdocker container上で動かす場合にこのpid=1が問題になることがあるようです。

Docker で node.js を動かすときは PID 1 にしてはいけない - ngzmのブログ


docker container上でも同じくリダイレクトによるメッセージの送り合いが echo "hello from $(tty)" > /dev/pts/0 等で出来ます。

f:id:ohbarye:20190504220833g:plain
`echo "hello from $(tty)" > /dev/pts/0`

ptsとファイルディスクリプタ

/proc/<pid>/fdを確認することで各bashプロセスが利用するファイルディスクリプタを確認することもできます。

docker runで起動したpid=1のプロセス(bash)では0:標準入力(stdin)、1:標準出力(stdout)、2:標準エラー出力(stderr)の3つが/dev/pts/0に割り当てられています。(255はbash特有のもの*2

# terminal 1
root@8ee8c01fb676:/# ls -la /proc/1/fd
total 0
dr-x------ 2 root root  0 May  4 09:40 .
dr-xr-xr-x 9 root root  0 May  4 09:40 ..
lrwx------ 1 root root 64 May  4 09:40 0 -> /dev/pts/0
lrwx------ 1 root root 64 May  4 09:40 1 -> /dev/pts/0
lrwx------ 1 root root 64 May  4 09:40 2 -> /dev/pts/0
lrwx------ 1 root root 64 May  4 09:40 255 -> /dev/pts/0

docker execで起動したプロセス側も同様に/dev/pts/1が使われています。

# terminal 2
root@8ee8c01fb676:/# ls -la /proc/7/fd
total 0
dr-x------ 2 root root  0 May  4 09:40 .
dr-xr-xr-x 9 root root  0 May  4 09:40 ..
lrwx------ 1 root root 64 May  4 09:40 0 -> /dev/pts/1
lrwx------ 1 root root 64 May  4 09:40 1 -> /dev/pts/1
lrwx------ 1 root root 64 May  4 09:40 2 -> /dev/pts/1
lrwx------ 1 root root 64 May  4 09:40 255 -> /dev/pts/1

-t, -i の役割を確認する

長らく本題から逸れました。

ここからようやく、それぞれのオプションが無い場合にどんな挙動をするかを見ることで、-t, -i オプションの役割を確認する作業に入っていきます。

-t オプションを無くしてみる

docker exec --helpを見ると-tはpseudo-TTY (pts) を割り当てるオプションとあります。

  -t, --tty                  Allocate a pseudo-TTY

ptsが無い場合にどのような挙動をするのか見てみます。

docker run --rm -it --name tty-test ruby bash で立ち上げたterminal 1側のbashプロセスはそのままに、docker exec -i tty-test bash (-tがないことに注目) を実行します。

ps axを実行するとdocker exec側のbashプロセスのTTYが ? になっています。 これは制御するターミナル(デバイス)が割り当てられていないことを示しています。

# terminal 1
$ docker run --rm -it --name tty-test ruby bash

# terminal 2
$ docker exec -i tty-test bash

# terminal 1
root@a7144f8d8ef0:/# ps ax
  PID TTY      STAT   TIME COMMAND
    1 pts/0    Ss     0:00 bash
   17 ?        Ss     0:00 bash
   41 pts/0    R+     0:00 ps ax

ちなみにps aではterminal 2側のbashプロセスは出てきません。xオプションが必要です。このオプションをつけることで制御端末がないプロセスも含むようになります。

# terminal 1
root@a7144f8d8ef0:/# ps a
  PID TTY      STAT   TIME COMMAND
    1 pts/0    Ss     0:00 bash
   40 pts/0    R+     0:00 ps a

include processes which do not have a controlling terminal man ps より

/dev/ptsを見てみても、たしかに0(terminal 1, docker run側)しかいません。

root@a7144f8d8ef0:/# ls -la /dev/pts
total 0
drwxr-xr-x 2 root root      0 May  4 09:28 .
drwxr-xr-x 5 root root    360 May  4 09:28 ..
crw--w---- 1 root tty  136, 0 May  4 09:38 0
crw-rw-rw- 1 root root   5, 2 May  4 09:38 ptmx

(terminal 2, docker exec側で)立ち上げたbashプロセスのファイルディスクリプタはどうなっているのでしょうか?

すべてpipe:[2700x]のような表記になっています。これが何なのかよくわかっていないが少なくともデバイスファイルでなくpipeであることはわかりました。

root@203d1f3d7ddb:/# ls -la /proc/6/fd
total 0
dr-x------ 2 root root  0 May  4 09:41 .
dr-xr-xr-x 9 root root  0 May  4 09:41 ..
lr-x------ 1 root root 64 May  4 09:41 0 -> pipe:[27004]
l-wx------ 1 root root 64 May  4 09:41 1 -> pipe:[27005]
l-wx------ 1 root root 64 May  4 09:41 2 -> pipe:[27006]

また、docker execしたほうのterminal 2でttyを打ってみると、not a ttyという結果が返ってきます。

# terminal 2
❯ docker exec -i tty-test bash
tty
not a tty

つまり「-tオプションを付けないと、ptsが割り当てられず=標準入出力がterminalに繋がらず、インタラクティブな操作ができない」ことがわかりました。

-i オプションをなくしてみる

次は-iオプションを見てみます。こちらもdocker exec --helpによる説明を貼っておきます。

  -i, --interactive          Keep STDIN open even if not attached

今度は-i抜きのコマンドdocker exec -t tty-test bashを試してみます。

docker exec側のterminal 2では標準入力を受け付けなくなります。echo '1'などを実行しても結果が返ってきません。

ただし-tによりptsが割り当てられているのでデバイスファイル名を特定すればメッセージを送りつけることはできます。

f:id:ohbarye:20190504230515g:plain
`-i`オプションがないと標準入力を受け付けなくなる

# terminal 1
root@fe2c5869d96c:/# ps au
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root         1  0.0  0.0  18184  3240 pts/0    Ss   14:05   0:00 bash
root         6  0.0  0.0  18180  3160 pts/1    Ss+  14:05   0:00 bash
root        13  0.0  0.0  36632  2764 pts/0    R+   14:07   0:00 ps au

root@fe2c5869d96c:/# ls -la /proc/6/fd
total 0
dr-x------ 2 root root  0 May  4 14:05 .
dr-xr-xr-x 9 root root  0 May  4 14:05 ..
lrwx------ 1 root root 64 May  4 14:05 0 -> /dev/pts/1
lrwx------ 1 root root 64 May  4 14:05 1 -> /dev/pts/1
lrwx------ 1 root root 64 May  4 14:05 2 -> /dev/pts/1
lrwx------ 1 root root 64 May  4 14:07 255 -> /dev/pts/1

root@fb2a467d7ee8:/# echo "hello from $(tty)" > /dev/pts/1
# terminal 2 側に表示される

-iオプションはhelpの説明そのままですが「-iオプションを付けないと、terminalからの入力を受け付けなくなる」ことが実際に試してわかりました。

-it オプションをなくしてみる

-i-tも省略したdocker exec tty-test bashを実行すると一瞬で終了します。

# terminal 2
$ docker exec tty-test bash

f:id:ohbarye:20190504231038g:plain

うーん、何も受け付けないし出力もしないbashプロセスが立ち上がるのではと思ったのですが、どういう仕組みでこのプロセスを終了させているのかよくわかっていません。

docker attach

docker execと似ているけどぜんぜん違うコマンドdocker attachについてもついでに見ておきます。

  • docker attachは指定した起動中のcontainerのルートプロセス(pid=1のプロセス)の標準出力・標準入力につなぐ
  • docker execは指定した起動中のcontainerで新しいプロセスを立ち上げる
# terminal 1 で起動したあとに
$ docker run --rm -it --name tty-test ruby bash

# terminal 2 で attach する
$ docker attach tty-test

f:id:ohbarye:20190504232538g:plain
docker attachでpid=1と同化したようす

片方のterminalで行った入出力がまったく同じようにもう一方のterminalに再現するのがわかります。macOS上のterminalは2つでも、docker container上ではまったく同一のプロセスであり、標準入出力が同一のpts (ここでは/dev/pts/0) に割り当てられているためです。

また、docker attach--no-stdin オプションをつけるとSTDOUT、STDERRは受け付けるが入力は受け付けられないことも同様のやり方で確認できます。

f:id:ohbarye:20190504233113g:plain
`docker attach --no-stdin`でSTDINを受け付けないようす

ちなみにプロセスをexitせずにattachを抜けるには Ctrl+P -> Ctrl+Q です。このショートカットが他のソフトウェアと衝突する場合には --detach-keysショートカットで別のkeyを割り当てることもできます。*3

感想

docker (run|exec)-i, tオプションからttyとは何かを理解しようと手を動かす中で、dockerを理解するにはUnixシステムの初歩の初歩を押さえることが本当に大事だと痛感しました。これまでもこの辺(プロセス・ファイルディスクリプタ・標準入出力 etc.)の理解が足りなかったんだろうな〜と反省。

ふだん何気なく使っているdockerのコマンド群もUnixシステムの理解がないといつまでも「俺たちは雰囲気でdockerを使っている」状態から抜け出せないなと思うわけです。

これからもやっていくぞ!!

参考

The Art of UNIX Programming
The Art of UNIX Programming
posted with amazlet at 19.05.04
Eric S.Raymond
KADOKAWA (2019-03-08)
売り上げランキング: 193,583

映画『チェイサー』、ヨッピー似のキム・ヨンソクが凄い

Netflixで『チェイサー』を観た。

www.imdb.com

これは後味の悪い鬱映画…だが感情が動かされるので映画としては素晴らしい…でも辛い…

冒頭でヨッピー氏みたいなキャラが出てきて親しめそうと思うじゃん。

f:id:ohbarye:20190505005700p:plain

が、駄目…っ…暴力的でまったく優しくない。

それでも次第に感情移入していけるような演技がすごい。評価は最低からスタートしているので上がるしかないというのもあるし、ヨッピー氏に似ているから最終的に親しめたのかもしれない。

一方で犯人役、と書くとネタバレ感がすごいかもだが作中ではまったく隠していないので問題ない、Jung-woo Haもまたすごい。映像からまったく感情や行動が読めない。

「あ、こいつは完全に理解できない異常者だ」というのがすっと伝わってくる凄さ。かと思えば好青年ぽい振る舞いや表情もあったりして余計に怖い。

彼ら2人を中心に演技の凄さもさることながら、構成や演出のあらゆるところで陰惨さが出ており、とにかく作品のアクが強い。

全員に見て欲しいとは思わないがサイコスリラー・サスペンスもので衝撃が欲しいという人にはおすすめできる。

『なるほどUnixプロセス』付録DのSpyglassを起動する (Ruby2.6.3, bundler1.17.2)

なるほどUnixプロセス』付録D の「Spyglass」は触って学べるWebサーバー。同書で解説されているUnixプログラミングのテクニックを盛り込んでいる。

せっかくなので試そうと以下のコマンドにて起動を試みたが、起動しない。

# application's root dir
$ spyglass

環境

結論

以下のコマンドで実行可能になる。

$ bundle install
$ bundle exec rake compile
$ bundle exec bin/spyglass

f:id:ohbarye:20190504165422p:plain

dockerで起動する

docker container上で起動することもできる

$ docker run -it -v $PWD:/app -w /app ruby bash
# bundle installの結果等を永続化しないやり方

で立ち上げたあとは同じく bundle install から行う。

ローカルマシンで http://localhost:4222 にアクセスすると動いていることが確認できる。

f:id:ohbarye:20190504164740p:plain

bundle install ~ spyglassを立ち上げるまでのfull log

root@62f15c7de4e3:/app# bundle install
Fetching gem metadata from https://rubygems.org/.
.......
Fetching rake 10.1.0
Installing rake 10.1.0
Fetching addressable 2.3.4
Installing addressable 2.3.4
Using bundler 1.17.2
Fetching excon 0.25.3
Installing excon 0.25.3
Fetching launchy 2.3.0
Installing launchy 2.3.0
Fetching minitest 5.0.6
Installing minitest 5.0.6
Fetching posix-spawn 0.3.6
Installing posix-spawn 0.3.6 with native extensions
Fetching rack 1.3.10
Installing rack 1.3.10
Fetching rack-protection 1.5.0
Installing rack-protection 1.5.0
Fetching rake-compiler 0.8.3
Installing rake-compiler 0.8.3
Fetching tilt 1.4.1
Installing tilt 1.4.1
Fetching sinatra 1.3.3
Installing sinatra 1.3.3
Bundle complete! 7 Gemfile dependencies, 12 gems now installed.
Bundled gems are installed into `/usr/local/bundle`

root@62f15c7de4e3:/app# bundle exec rake compile
mkdir -p tmp/x86_64-linux/spyglass_parser/2.6.3
cd tmp/x86_64-linux/spyglass_parser/2.6.3
/usr/local/bin/ruby -I. ../../../../ext/spyglass_parser/extconf.rb
checking for main() in -lc... yes
creating Makefile
cd -
cd tmp/x86_64-linux/spyglass_parser/2.6.3
make
compiling ../../../../ext/spyglass_parser/parser.c
In file included from parser.rl:7:0:
parser.rl: In function 'spyglass_http_parser_execute':
parser.rl:112:17: warning: comparison between signed and unsigned integer expressions [-Wsign-compare]
parser.rl: In function 'spyglass_http_parser_finish':
parser.rl:142:7: warning: implicit declaration of function 'spyglass_http_parser_has_error' [-Wimplicit-function-declaration]
parser.rl:144:14: warning: implicit declaration of function 'spyglass_http_parser_is_finished' [-Wimplicit-function-declaration]
parser.rl: At top level:
cc1: warning: unrecognized command line option '-Wno-self-assign'
cc1: warning: unrecognized command line option '-Wno-parentheses-equality'
cc1: warning: unrecognized command line option '-Wno-constant-logical-operand'
cc1: warning: unrecognized command line option '-Wno-cast-function-type'
compiling ../../../../ext/spyglass_parser/spyglass.c
../../../../ext/spyglass_parser/spyglass.c: In function 'Spyglass_HttpParser_alloc':
../../../../ext/spyglass_parser/spyglass.c:251:3: warning: implicit declaration of function 'spyglass_http_parser_init' [-Wimplicit-function-declaration]
   spyglass_http_parser_init(hp);
   ^~~~~~~~~~~~~~~~~~~~~~~~~
../../../../ext/spyglass_parser/spyglass.c: In function 'Spyglass_HttpParser_finish':
../../../../ext/spyglass_parser/spyglass.c:303:3: warning: implicit declaration of function 'spyglass_http_parser_finish' [-Wimplicit-function-declaration]
   spyglass_http_parser_finish(http);
   ^~~~~~~~~~~~~~~~~~~~~~~~~~~
../../../../ext/spyglass_parser/spyglass.c:305:10: warning: implicit declaration of function 'spyglass_http_parser_is_finished' [-Wimplicit-function-declaration]
   return spyglass_http_parser_is_finished(http) ? Qtrue : Qfalse;
          ^~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
../../../../ext/spyglass_parser/spyglass.c: In function 'Spyglass_HttpParser_execute':
../../../../ext/spyglass_parser/spyglass.c:343:5: warning: implicit declaration of function 'spyglass_http_parser_execute' [-Wimplicit-function-declaration]
     spyglass_http_parser_execute(http, dptr, dlen, from);
     ^~~~~~~~~~~~~~~~~~~~~~~~~~~~
../../../../ext/spyglass_parser/spyglass.c:347:8: warning: implicit declaration of function 'spyglass_http_parser_has_error' [-Wimplicit-function-declaration]
     if(spyglass_http_parser_has_error(http)) {
        ^~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
../../../../ext/spyglass_parser/spyglass.c: At top level:
cc1: warning: unrecognized command line option '-Wno-self-assign'
cc1: warning: unrecognized command line option '-Wno-parentheses-equality'
cc1: warning: unrecognized command line option '-Wno-constant-logical-operand'
cc1: warning: unrecognized command line option '-Wno-cast-function-type'
linking shared-object spyglass_parser.so
cd -
install -c tmp/x86_64-linux/spyglass_parser/2.6.3/spyglass_parser.so lib/spyglass_parser.so

root@62f15c7de4e3:/app# bundle exec bin/spyglass
[96] [Spyglass::Server] Listening on port 0.0.0.0:4222
[96] [Spyglass::Lookout] Received incoming connection
[97] [Spyglass::Master] Loaded the app
[97] [Spyglass::Master] Spawned 2 workers. Babysitting now...

(warningが出ているが…動く)

参考

『なるほどUnixプロセス』付録のSpyglassを起動する - Qiitaを参考にさせてもらったが、このやり方ではうまくいかなかった。

zshの起動が遅かったのでzprofでプロファイリングしながら起動速度を3倍速くした

(追記: 2021-07-18) 本記事の続編 => zshの起動がいつの間にか速くなっていた - valid,invalid

zshの起動速度が遅いのをずっと放置していたので改善した。もともと遅かったので自慢できる数字ではないが、とても大雑把に言うと起動時間がおよそ3秒→1秒と3倍速くなった

やったこと

zprofでボトルネック特定

今回はこの方法を知ることが出来たので一番の収穫だったかもしれない。

まず、単純にtimeコマンドで計測するとおおまかな処理時間はわかるが、ボトルネックがわからない。

# チューニング前の time コマンド実行結果
❯ for i in $(seq 1 10); do time zsh -i -c exit; done
zsh -i -c exit  1.84s user 1.29s system 103% cpu 3.013 total
zsh -i -c exit  1.90s user 1.32s system 103% cpu 3.119 total
zsh -i -c exit  1.96s user 1.37s system 103% cpu 3.199 total
zsh -i -c exit  1.92s user 1.30s system 104% cpu 3.092 total
zsh -i -c exit  2.04s user 1.49s system 102% cpu 3.445 total
zsh -i -c exit  1.90s user 1.34s system 103% cpu 3.140 total
zsh -i -c exit  1.90s user 1.29s system 103% cpu 3.073 total
zsh -i -c exit  2.23s user 1.53s system 91% cpu 4.109 total
zsh -i -c exit  2.35s user 1.91s system 84% cpu 5.025 total
zsh -i -c exit  2.01s user 1.53s system 101% cpu 3.493 total

zsh 起動 遅い」等でググるzprofなるものが提供されているとわかった。zshの起動が遅いのでなんとかしたい - Qiita に従って.zshenvの最初と.zshrcの最後に以下を付け足す。

# .zshenv
zmodload zsh/zprof && zprof
# .zshrc
if (which zprof > /dev/null 2>&1) ;then
  zprof
fi

すると起動時にプロファイル結果が出力される。長いので詳細は省略している。

num  calls                time                       self            name
-----------------------------------------------------------------------------------
 1)    6        2320.87   386.81   68.33%    907.63   151.27   26.72%  pmodload
 2)    2         888.63   444.32   26.16%    888.32   444.16   26.16%  nvm_die_on_prefix
 3)    2        1916.71   958.35   56.44%    449.40   224.70   13.23%  nvm_auto
 4)    1         372.65   372.65   10.97%    372.25   372.25   10.96%  __kubectl_bash_source
 5)    4        1467.30   366.83   43.20%    356.07    89.02   10.48%  nvm
 6)    2         222.32   111.16    6.55%    198.99    99.50    5.86%  nvm_ensure_version_installed
 7)    1          74.28    74.28    2.19%     73.80    73.80    2.17%  _zsh_highlight_load_highlighters
 8)    2          29.95    14.97    0.88%     29.95    14.97    0.88%  compaudit
 9)    1          25.38    25.38    0.75%     25.38    25.38    0.75%  -zcache-hook-antigen
10)    2          23.32    11.66    0.69%     23.32    11.66    0.69%  nvm_is_version_installed
11)    2          16.74     8.37    0.49%     16.74     8.37    0.49%  nvm_supports_source_options
12)    2          41.45    20.73    1.22%     11.51     5.75    0.34%  compinit
13)   21          10.90     0.52    0.32%     10.90     0.52    0.32%  (anon)
14)    2           9.60     4.80    0.28%      9.60     4.80    0.28%  promptinit
15)    1           6.95     6.95    0.20%      6.95     6.95    0.20%  _zsh_highlight_bind_widgets
16)    1           4.06     4.06    0.12%      4.06     4.06    0.12%  async_init
17)    2           8.09     4.05    0.24%      2.22     1.11    0.07%  prompt_pure_setup
18)   12           1.79     0.15    0.05%      1.79     0.15    0.05%  add-zsh-hook
19)    2           5.55     2.77    0.16%      1.48     0.74    0.04%  async
20)    1           1.47     1.47    0.04%      1.47     1.47    0.04%  colors
21)    3           0.87     0.29    0.03%      0.87     0.29    0.03%  is-at-least
22)    1           0.78     0.78    0.02%      0.78     0.78    0.02%  -antigen-interactive-mode
23)    4           0.65     0.16    0.02%      0.65     0.16    0.02%  compdef
24)    4           0.59     0.15    0.02%      0.59     0.15    0.02%  nvm_has
25)    2        1933.81   966.91   56.94%      0.36     0.18    0.01%  nvm_process_parameters
26)    1           8.84     8.84    0.26%      0.20     0.20    0.01%  set_prompt
27)    4           0.19     0.05    0.01%      0.19     0.05    0.01%  -set-default
28)    1           5.57     5.57    0.16%      0.16     0.16    0.00%  -antigen-env-setup
29)    1           0.40     0.40    0.01%      0.15     0.15    0.00%  complete
30)    1           0.18     0.18    0.01%      0.12     0.12    0.00%  -zcache-antigen
31)    1          25.48    25.48    0.75%      0.10     0.10    0.00%  zcache-start
32)    2           0.23     0.12    0.01%      0.09     0.05    0.00%  -zcache-antigen-hook
33)    1           8.90     8.90    0.26%      0.06     0.06    0.00%  prompt
34)    1           0.04     0.04    0.00%      0.04     0.04    0.00%  bashcompinit
35)    1           0.04     0.04    0.00%      0.04     0.04    0.00%  is-callable
36)    2           0.03     0.02    0.00%      0.03     0.02    0.00%  nvm_is_zsh
37)    1           0.26     0.26    0.01%      0.03     0.03    0.00%  antigen
38)    1           0.06     0.06    0.00%      0.02     0.02    0.00%  antigen-bundle

nvm関連とpmodload関連の処理が重いとわかった。

nvm.sh を遅延ロードしてシェルの起動を高速化

NVM の nvm.sh を遅延ロードしてシェルの起動を高速化する - Qiita

↑の記事の対応をそのまま行ったところ、0.5~0.8秒ほどの改善が見られた。

❯ for i in $(seq 1 10); do time zsh -i -c exit; donezsh -i -c exit  1.46s user 1.01s system 99% cpu 2.480 total
zsh -i -c exit  1.42s user 0.95s system 100% cpu 2.364 total
zsh -i -c exit  1.42s user 0.96s system 100% cpu 2.372 total
zsh -i -c exit  1.43s user 0.97s system 98% cpu 2.431 total
zsh -i -c exit  1.44s user 0.97s system 95% cpu 2.539 total
zsh -i -c exit  1.46s user 0.98s system 100% cpu 2.429 total
zsh -i -c exit  1.38s user 0.97s system 103% cpu 2.278 total
zsh -i -c exit  1.38s user 0.95s system 103% cpu 2.242 total
zsh -i -c exit  1.40s user 0.93s system 104% cpu 2.223 total
zsh -i -c exit  1.41s user 0.91s system 104% cpu 2.219 total
num  calls                time                       self            name
-----------------------------------------------------------------------------------
 1)    6        1738.74   289.79   81.14%    610.52   101.75   28.49%  pmodload
 2)    1         984.57   984.57   45.95%    401.19   401.19   18.72%  nvm_auto
 3)    1         362.83   362.83   16.93%    362.45   362.45   16.91%  __kubectl_bash_source
 4)    1         302.44   302.44   14.11%    302.29   302.29   14.11%  nvm_die_on_prefix
 5)    2         583.38   291.69   27.23%    170.47    85.23    7.96%  nvm
 6)    1         110.33   110.33    5.15%     97.92    97.92    4.57%  nvm_ensure_version_installed
 7)    1          69.76    69.76    3.26%     69.33    69.33    3.24%  _zsh_highlight_load_highlighters
 8)    1          29.12    29.12    1.36%     29.12    29.12    1.36%  -zcache-hook-antigen
 9)    2          28.16    14.08    1.31%     28.16    14.08    1.31%  compaudit
10)    1          12.41    12.41    0.58%     12.41    12.41    0.58%  nvm_is_version_installed
11)    2          40.29    20.14    1.88%     12.13     6.06    0.57%  compinit
12)   21          10.97     0.52    0.51%     10.97     0.52    0.51%  (anon)
13)    2           9.25     4.62    0.43%      9.25     4.62    0.43%  promptinit
14)    1           8.08     8.08    0.38%      8.08     8.08    0.38%  nvm_supports_source_options
15)    1           6.63     6.63    0.31%      6.63     6.63    0.31%  _zsh_highlight_bind_widgets
16)    1           3.20     3.20    0.15%      3.20     3.20    0.15%  async_init
17)   12           1.81     0.15    0.08%      1.81     0.15    0.08%  add-zsh-hook
18)    1           1.21     1.21    0.06%      1.21     1.21    0.06%  colors
19)    2           5.35     2.68    0.25%      1.02     0.51    0.05%  prompt_pure_setup
20)    3           0.81     0.27    0.04%      0.81     0.27    0.04%  is-at-least
21)    4           0.71     0.18    0.03%      0.71     0.18    0.03%  compdef
22)    2           3.90     1.95    0.18%      0.71     0.35    0.03%  async
23)    1           0.34     0.34    0.02%      0.34     0.34    0.02%  -antigen-interactive-mode
24)    2           0.30     0.15    0.01%      0.30     0.15    0.01%  nvm_has
25)    1         992.92   992.92   46.34%      0.27     0.27    0.01%  nvm_process_parameters
26)    4           0.21     0.05    0.01%      0.21     0.05    0.01%  -set-default
27)    1           6.11     6.11    0.29%      0.21     0.21    0.01%  set_prompt
28)    2           0.38     0.19    0.02%      0.18     0.09    0.01%  -zcache-antigen-hook
29)    1           6.42     6.42    0.30%      0.18     0.18    0.01%  -antigen-env-setup
30)    1           0.26     0.26    0.01%      0.16     0.16    0.01%  -zcache-antigen
31)    1          29.28    29.28    1.37%      0.16     0.16    0.01%  zcache-start
32)    1           0.38     0.38    0.02%      0.14     0.14    0.01%  complete
33)    1           0.43     0.43    0.02%      0.06     0.06    0.00%  antigen
34)    1           0.05     0.05    0.00%      0.05     0.05    0.00%  is-callable
35)    1           6.16     6.16    0.29%      0.05     0.05    0.00%  prompt
36)    1           0.04     0.04    0.00%      0.04     0.04    0.00%  bashcompinit
37)    1           0.09     0.09    0.00%      0.03     0.03    0.00%  antigen-bundle
38)    1           0.01     0.01    0.00%      0.01     0.01    0.00%  nvm_is_zsh

しかし見てみると、nvm関連の処理がまだまだ存在している… 奴はすでに葬ったはずでは…?

ここまでの変更は Lazy load nvm · ohbarye/dotfiles@5b0653b · GitHub である。

preztoのmodule読み込みで対象を減らした

プロファイラの結果をよくみると、nvm_autonvm_die_on_prefixといった処理はpmodloadから呼ばれているとわかった。

pmodloadが何をしているかというと、.zpreztorcの定義にしたがってpreztoのmoduleをloadする。名前そのままだ。

# .zpreztorc
zstyle ':prezto:load' pmodule \
  'environment' \
  ... # つづく

ここでloadしているmoduleにnodeがあったのでこれを消すと途端に速度が上がった。

この他にも使わないmoduleがないかを確認していき、ひとつずつ消していった結果のcommit: Do not load unused modules given by prezto · ohbarye/dotfiles@70fa79e · GitHub

各moduleが何をしているのかパッと見てはわからないので、https://github.com/sorin-ionescu/prezto/tree/master/modulesから一つずつ確認した。中には読んでもわからないものがあったので、一度そのmoduleを消してzshを再起動して普段と変わりなく操作できるかを確認したりもした。

大概はまったく使っていないaliasが使えなくなる程度なので大して困らなさそうだという気持ちでゴリゴリ消していった。一つmoduleを減らすたびにだいたい100~200 msec ほど高速化していったのでこれはやりがいがあった。

最終的な結果は以下:

❯ for i in $(seq 1 10); do time zsh -i -c exit; done
zsh -i -c exit  0.79s user 0.40s system 108% cpu 1.100 total
zsh -i -c exit  0.78s user 0.39s system 108% cpu 1.070 total
zsh -i -c exit  0.77s user 0.39s system 108% cpu 1.069 total
zsh -i -c exit  0.79s user 0.39s system 109% cpu 1.083 total
zsh -i -c exit  0.78s user 0.38s system 108% cpu 1.065 total
zsh -i -c exit  0.80s user 0.40s system 108% cpu 1.099 total
zsh -i -c exit  0.79s user 0.40s system 109% cpu 1.090 total
zsh -i -c exit  0.80s user 0.40s system 107% cpu 1.110 total
zsh -i -c exit  0.79s user 0.40s system 108% cpu 1.100 total
zsh -i -c exit  0.80s user 0.40s system 108% cpu 1.100 total
num  calls                time                       self            name
-----------------------------------------------------------------------------------
 1)    1         363.84   363.84   54.43%    363.55   363.55   54.39%  __kubectl_bash_source
 2)    4         266.00    66.50   39.80%    135.32    33.83   20.24%  pmodload
 3)    1          73.05    73.05   10.93%     72.62    72.62   10.86%  _zsh_highlight_load_highlighters
 4)    2          27.63    13.82    4.13%     27.63    13.82    4.13%  compaudit
 5)    1          27.16    27.16    4.06%     27.16    27.16    4.06%  -zcache-hook-antigen
 6)    2          37.80    18.90    5.66%     10.17     5.08    1.52%  compinit
 7)    2           7.16     3.58    1.07%      7.16     3.58    1.07%  promptinit
 8)    1           7.06     7.06    1.06%      7.06     7.06    1.06%  _zsh_highlight_bind_widgets
 9)   14           6.48     0.46    0.97%      6.48     0.46    0.97%  (anon)
10)    1           3.63     3.63    0.54%      3.63     3.63    0.54%  async_init
11)   12           1.84     0.15    0.27%      1.84     0.15    0.27%  add-zsh-hook
12)    1           1.20     1.20    0.18%      1.20     1.20    0.18%  colors
13)    2           5.90     2.95    0.88%      1.06     0.53    0.16%  prompt_pure_setup
14)    3           0.90     0.30    0.13%      0.90     0.30    0.13%  is-at-least
15)    2           4.44     2.22    0.66%      0.81     0.40    0.12%  async
16)    1           0.30     0.30    0.05%      0.30     0.30    0.05%  -antigen-interactive-mode
17)    2           0.26     0.13    0.04%      0.26     0.13    0.04%  compdef
18)    1           6.68     6.68    1.00%      0.21     0.21    0.03%  set_prompt
19)    4           0.21     0.05    0.03%      0.21     0.05    0.03%  -set-default
20)    1           5.59     5.59    0.84%      0.19     0.19    0.03%  -antigen-env-setup
21)    1           0.29     0.29    0.04%      0.16     0.16    0.02%  complete
22)    1           0.20     0.20    0.03%      0.14     0.14    0.02%  -zcache-antigen
23)    2           0.25     0.13    0.04%      0.10     0.05    0.01%  -zcache-antigen-hook
24)    1          27.25    27.25    4.08%      0.09     0.09    0.01%  zcache-start
25)    1           6.73     6.73    1.01%      0.05     0.05    0.01%  prompt
26)    1           0.04     0.04    0.01%      0.04     0.04    0.01%  is-callable
27)    1           0.04     0.04    0.01%      0.04     0.04    0.01%  bashcompinit
28)    1           0.28     0.28    0.04%      0.03     0.03    0.00%  antigen
29)    1           0.06     0.06    0.01%      0.02     0.02    0.00%  antigen-bundle

次のボトルネック__kubectl_bash_source...なのだが、これはkubectlの補完を効かせるやつ (ここ)。最近はkubectlを触る機会があるのでこれを外すとそこそこ困るうえに代替案がパッと思いつかなかったので一旦放置。外すとようやく1秒未満で起動するようになるので補完機能も遅延で追加できたりしないかな。

環境

  • macOS 10.14.2
  • zsh 5.3 (x86_64-apple-darwin18.0)
  • prezto (versionの確認方法がわからないが、~/.antigen/repos/.zpreztoにcloneされたrepositoryのHEADはa338cba805f63f770e9078925bc5c46129e28bde)