Lambda Custom Runtimes上でbashを対話的に操作してその内部仕様を丸裸にする
この記事は AWS Lambda Custom Runtimes芸人 Advent Calendar 2018
の19日目です。
これは何?
「Lambdaの中に入ってみたいと思ったことはありませんか?」これはそんな歪んだ願望を叶える試みです。と同時にそれを足がかりにAWS Lambdaというシステムをより深く理解するための検証とその結果を記したものです。
ちなみに毎年恒例?のLambdaのリバースエンジニアリング(?)シリーズです。
2016年 marcy.hatenablog.com
2017年 marcy.hatenablog.com
Lambda Custom Runtimesとは
Lambda Custom Runtimesは一般的にはAWS Lambdaが公式に対応していないプログラミング言語のRuntimeを動かすための機能です。仕様は以下の通り。
3行でまとめる
bootstrap
実行ファイルで起動Next Invocation API
でイベントを取得Invocation Response(or Error) API
に処理結果を伝えるまで動き続ける
ということです。この仕様さえ満たせばなんだって動かせるわけです(これは微妙に違ったんだけど詳しくは後述)
シェルを対話的に動かす方法
Custom Runtimesに限らずLambda上でbashを実行できることは周知の事実(?)*1かと思いますが、問題はそこに対話的にアクセスできるコネクションを確立することです。Custom RuntimesでOpenSSH Serverが仮に起動できたとしても外からの接続はできません。
そこで、ngrokを利用してtunnelingを行います。ngrokはhttpやtcpのトンネルをクラウド上のエンドポイントまで繋ぎ、そのクラウド上のエンドポイントへ接続させることでNATの裏にある個人端末上のサーバへの一時的なアクセスを提供する*2ような時によく使われるSaaSサービスです。
OpenSSH Serverは依存ライブラリの関係で起動は難しそうですし、ログインユーザやログイン情報の管理も面倒なので、TCPでコマンドを受信してbashと標準入出力でやりとりする簡易なサーバを自前で作って、そのサーバに向けてngrokでトンネルを掘ります。これでシェルが対話で操作できればもうやりたい放題です! ε=\_〇ノヒャッホーイ!! *3
やり方
基本的にはREADMEを参照してください。ngrok アカウント*4が必要です。
ざっくり解説
Goで雑に書いた、TCPでコマンド受けてbashに流すサーバを起動し、ngrokでtunnelを掘り、Custom Runtimes APIとイベントとその結果をやり取りをするまでを一手に担う*5 bootstrap
実行ファイルのソースはこちら。
lambda-interactive/bootstrap.go at master · marcy-terui/lambda-interactive · GitHub
デプロイにはAWS SAMを利用しており、ngrokのアクセストークンは再現手順の簡略化のためローカルの環境変数をLambdaの環境変数に --parameter-override
で渡すスタイル*6でFunctionをデプロイしてます。そして、API GatewayのEndpointを生やしてCFnのOutputで出力しておく。ここをクエリしてそのエンドポイントへリクエストを投げることで最初の起動、および実行が止まった環境の再起動ができる。
lambda-interactive/template.yaml at master · marcy-terui/lambda-interactive · GitHub
GoのビルドやFunctionのデプロイまで含め一連の操作はMakefileでまとめてます。
lambda-interactive/Makefile at master · marcy-terui/lambda-interactive · GitHub
ちなみに ngrok
コマンドもGoで書かれておりシングルバイナリで動くのでLinux 64bit向けをダウンロードして同梱してます。
ここからが本番
わざわざこんなことをするのは、もちろんただCustom Runtimeの中に入って色々見てみたいという単純な興味はもちろんのこと、確かめたいことがあったからです。
何を調べたいか
Custom Runtimes APIの公開によって、下記のような今までおぼろげだったLambda実行環境のライフサイクルに明確にフックできるようになるのではないかと考えました。これらのタイミングでのLambda実行環境の振る舞いを調べたいのです。
- 作成(Bootstrap)
新しい実行環境の立ち上げ。bootstrap
実行ファイルが呼ばれる - 起動(Cold Start)
bootstrap
から最初のNext Invocation API
呼び出し - 停止(Suspend)
Invocation Response(or Error) API
呼び出し(これは微妙に違ったんだけど詳しくは後述) - 再開(Warm Start)
2回目以降のNext Invocation API
呼び出し - 破棄(Delete)
Invocation Response(or Error) API
が呼び出されてからしばらく次のイベントがない、またはデプロイ直後の最初の実行など
この中でDeleteはまあ良いとして、BootstrapからCold Startは起動から一連の処理が行われるのでまあ分かりやすいです。特に調べたいのはSuspendからのWarm Startの挙動です。
仮説
Lambdaをそれなりに使い込んでいる方はある程度察しはついているかもしれませんが、一度起動されたLambdaの実行環境はある程度使い回されます。起動してFunctionの実行が完了した後も数十秒程度はそのまま残り、その間に新たな呼び出しが行われればその起動済みの環境が割り当てられます。この起動済み環境からFunctionの処理を始めることをWarm Start、新しい環境の立ち上げから始まるFunctionをCold Startと呼んだりします。
このWarm Startが行われる際に、プログラム内のglobalスコープやstaticなオブジェクトは残っているので、都度オブジェクトを生成するのではなく使い回すことでFunctionの実行を高速・効率化する方法が知られています。また、それらのオブジェクトが所有しているTCPコネクションのようなものも残ります。なので、コネクションプーリングのような実装は限定的ではありますが有効です。
これ、内部的にはどうなってるんでしょうね?
一番簡単なのはバックグラウンドでプロセスを動かし続けることですが、それをやってしまうと課金はあくまでFunctionの実行時間に対するものになるので、結果を返した後もFunctionが動き続けてしまえるのはAWSからすれば取りっぱぐれです。*7
というか、そもそもそんなことはできないようになっています。Node.jsランタイムを使ったことがあるとご存知かもしれませんが、Node.jsでやりがちなミスとして「非同期処理で先に結果を返してしまって全ての処理が行われる前に停止させられてしまう」というケースがあります。つまり、結果を返した後のFunctionは処理が許されていません。でも、メモリ上のデータや状態は残る。
メモリの内容をダンプして復元するCRIUのような方法もありますが、TCPコネクションまで復元するのはなかなか難しいと聞きますし、そもそもWarm StartのFunctionの起動はms未満〜1桁ms(感覚値)で行われます。さすがにそこまでの早さは出せなそうな気がします。挙動としてはまるで 時間を止められ、また動き出している ようです。
そう、 時間を止めている んです。おそらく、結果を返した後のLambda実行環境内にあるプロセスにはCPU時間が一切割当てられなくなるのです。それは、Lambdaの実行環境基盤であるFirecracker MicroVMにCPUの割り込みタイマーを外部から操作できるIFが設けられていることからも、割り込みによってCPUの割当を停止しているのではないかと推測することができます。
2018-12-20 20:50 訂正
re:Inventでそんなこと聞いた記憶があって斜め読みして書いてると思ったんですが、よくよく読み返してみるとタイマーとAPIについて近い場所で語られているだけで両者の関連については書かれておらず、ソースコード読むと(これまた斜め読みですが)cgroupsも使っているようなのでそっちかもしれません・・・
この挙動を検証してみます。
検証
READMEの通りにデプロイまで終わっている所からスタートします。
$ make start curl `aws cloudformation describe-stacks \ --stack-name interact-custom-runtime \ --query "Stacks[0].Outputs[0].OutputValue" \ --output text`
ngrokのダッシュボードを確認します。トンネルが起動していますね。
これにtelnetでつなぎます。bashが起動して操作できます!
$ telnet 0.tcp.ngrok.io 15733 Trying 52.15.194.28... Connected to 0.tcp.ngrok.io. Escape character is '^]'. bash: no job control in this shell bash-4.2$
pstree結果。bootstrapを親プロセスとしてbashとngrokが起動してます。
bash-4.2$ pstree pstree init-+-bootstrap-+-bash---pstree | |-ngrok---7*[{ngrok}] | `-6*[{bootstrap}] `-5*[{init}]
挙動を調べるためにバックグラウンドで1秒おきに時間を書き込む別のプロセスを起動しておきます。停止している間は書き込まれない時間ができるはず。
bash-4.2$ sh -c "while sleep 1; do date >> /tmp/date.txt ; done" & sh -c "while sleep 1; do date >> /tmp/date.txt ; done" & [1] 24 bash-4.2$ pstree pstree init-+-bootstrap-+-bash-+-pstree | | `-sh---sleep | |-ngrok---7*[{ngrok}] | `-6*[{bootstrap}] `-5*[{init}]
セッションを切ります。セッションを切ると結果を Invocation Response API
に投げて停止するようになってます。停止の目印に一時ファイルを使っているのがダサいですが、bashプロセスを終了してしまうとその子プロセスも終了されてしまったり色々問題があるので、一時ファイルを目印にbootstrapプロセスからbashプロセスは残してTCPのセッションだけ切るようにしています。
bash-4.2$ touch /tmp/exit touch /tmp/exit bash-4.2$ bash-4.2$ Connection closed by foreign host.
もう一回繋ごうとするとListenはされていて接続拒否はされませんが、停止されているのでbashに入れません。
$ telnet 0.tcp.ngrok.io 15733 Trying 52.15.194.28... Connected to 0.tcp.ngrok.io. Escape character is '^]'.
もう一度起動すると・・・
$ make start curl `aws cloudformation describe-stacks \ --stack-name interact-custom-runtime \ --query "Stacks[0].Outputs[0].OutputValue" \ --output text`
再接続の必要なく待ち状態のコマンドからそのままbashに入れます。Lambda <-> ngrok間のTCPコネクションは生きていたという証左ですね(ngrokはコネクションが切れるとトンネルを破棄して接続が拒否されるようになります)
ちなみにここで起動のタイミングを誤ると別の環境が立ち上がってしまい、次回以降はそちらの新しい方が起動されるようになってしまいます。ngrokの無料アカウントでは同時に起動できるトンネルは1つだけなので、Lambdaがタイムアウトして破棄されるまでの数分間何もできず、ただ課金のみが発生する無力感に苛まれることになります(私はなりました)
$ telnet 0.tcp.ngrok.io 15733 Trying 52.15.194.28... Connected to 0.tcp.ngrok.io. Escape character is '^]'. bash: no job control in this shell bash-4.2$ bash-4.2$ pstree pstree init-+-bootstrap-+-bash | |-bash---pstree | |-ngrok---7*[{ngrok}] | `-6*[{bootstrap}] |-sh---sleep `-5*[{init}]
時間を書き込んでいたファイルを見てみます。
$ cat /tmp/date.txt cat /tmp/date.txt <snip> Wed Dec 19 05:52:40 UTC 2018 Wed Dec 19 05:52:41 UTC 2018 Wed Dec 19 05:52:42 UTC 2018 Wed Dec 19 05:52:43 UTC 2018 <-- 停止 Wed Dec 19 05:53:00 UTC 2018 <-- 再開 Wed Dec 19 05:53:01 UTC 2018 Wed Dec 19 05:53:02 UTC 2018 Wed Dec 19 05:53:03 UTC 2018 Wed Dec 19 05:53:04 UTC 2018 Wed Dec 19 05:53:05 UTC 2018 Wed Dec 19 05:53:06 UTC 2018 Wed Dec 19 05:53:07 UTC 2018 Wed Dec 19 05:53:08 UTC 2018 Wed Dec 19 05:53:09 UTC 2018 Wed Dec 19 05:53:10 UTC 2018 <snip>
バックグラウンドのプロセスも含め停止していたことを示しています。思ったとおりの挙動ですね!
CloudWatch Logsでこの間のログを見てみます。*9たしかに 05:52:44
に停止、 05:53:00
に再開してます。
05:50:53 START RequestId: 0c3bd497-0352-11e9-83e4-2167b3748717 Version: $LATEST 05:50:53 read the event data ===> 05:50:53 connection open ===> 05:51:03 bash start ===> 05:52:44 close connection ===> 05:52:44 post the result ===> 05:52:44 read the result ===> 05:52:44 {"status":"OK"} 05:52:44 get the next event ===> 05:52:44 END RequestId: 0c3bd497-0352-11e9-83e4-2167b3748717 <- 停止 05:52:44 REPORT RequestId: 0c3bd497-0352-11e9-83e4-2167b3748717 Duration: 110871.63 ms Billed Duration: 110900 ms Memory Size: 1024 MB Max Memory Used: 48 MB 05:53:00 START RequestId: 57e81627-0352-11e9-941d-3dc2342c79e3 Version: $LATEST <- 再開 05:53:00 read the event data ===>
ちなみに分かりづらいと思いますが、一応処理の段階をログに残しています。「 Invocation Response(or Error) API
に処理結果を伝えるまで動き続ける」と思っていたのですが、それを示す post the result
, read the result
から、さらに get the next event
とあるので Next Invocation API
で次のイベントの取得まで行ってしまってますね・・・ レスポンスが得られたことを示す read the event data
は次の実行時のようですが、これは仕様なのでしょうか?もしかしたら微妙な時間差でそこまで処理が進んでしまっている(レスポンスが得られるまでには止まるから問題ない)だけかも?
Invocation Response API
を呼んだ後に1秒スリープを入れてみます。
$ git diff diff --git a/src/bootstrap.go b/src/bootstrap.go index 7a349ff..dec1307 100644 --- a/src/bootstrap.go +++ b/src/bootstrap.go @@ -88,6 +88,7 @@ func main() { fmt.Println("get the result ===>") body, _ = ioutil.ReadAll(resp.Body) fmt.Println(string(body)) + time.Sleep(1 * time.Second) } }
変わらず。
07:53:13 START RequestId: 22e5ec6b-0363-11e9-8263-5fe7d4dd840f Version: $LATEST 07:53:13 read the event data ===> 07:53:13 connection open ===> 07:53:28 bash start ===> 07:53:37 close connection ===> 07:53:37 post the result ===> 07:53:37 get the result ===> 07:53:38 07:53:38 get the next event ===> 07:53:38 END RequestId: 22e5ec6b-0363-11e9-8263-5fe7d4dd840f 07:53:38 REPORT RequestId: 22e5ec6b-0363-11e9-8263-5fe7d4dd840f Init Duration: 59.46 ms Duration: 24958.54 ms Billed Duration: 25100 ms Memory Size: 1024 MB Max Memory Used: 47 MB
どうやら結果を Invocation Response(or Error) API
にPostして次の Next Invocation API
を呼び出してレスポンスを待っている状態で止まるようです。わざわざTCPコネクションを開かせて止めるなんて贅沢な!とか思ってしまったけど、よく考えたらきっとCustom Runtimes APIは各LambdaのWorkerあるいはその上位に居るWorker Manager毎にあるイメージな気がするので、1つの各Workerは言わずもがな各Worker ManagerがハンドリングするWorkerの数も限られてるだろうから良いのか(この辺のイメージは下記のre:Invent資料を参照)
ネットワークIO待ちというのは停止点を作りやすいというのもありそう。かといって Invocation Response(or Error) API
のレスポンス待ちで止めてしまうとResponse返すのに成功したか検査できなくなっちゃうし。
まとめ
Custom Runtimeは任意の言語を動かせるのもそうだけど、Runtimeの挙動とライフサイクルが明確というのがLambda上で実験をするのに最適。
仮説検証結果①:ライフサイクルまとめ
bootstrap
実行ファイルで起動Next Invocation API
でイベントを取得Invocation Response(or Error) API
に処理結果を伝えるNext Invocation API
で次のイベントを待つ -> 即時実行できるイベントがなければ停止 -> さらに数十秒イベントがなければ破棄
仮説検証結果②:停止時の状態
プロセスは生かしたまま割り込みによってCPU時間が割り当てられなくなりその環境上の時が止まったような状態(未だブラックボックスな部分はあるので状況からくる推測の域は出ないので確実にそうだとは言い切れないけど)
おまけ
TunnelingすればLambdaの中にだってbashで入れる。bashで入れればもうやりたい放題、内部は丸裸です。他にも色々おもしろい実験ができそうですね!
ついでに「俺は今あのLambdaの中に入っているんだ」という謎の高揚感を得ることが出来ます。ぜひお試しあれ!(自己責任で!)
*1:ちなみにre:InventでCustom RuntimesとLayersの開発者セッションで「よーし、おじさんBash "Internet Ready" LanguageでAPI Gatewayからレスポンス返すFunction作っちゃうぞー」的なデモを繰り広げて大ウケしてました
*2:プロトタイプを誰かに見せるとか
*3:もはや完全なバックドアですね。怒られないかな・・・?w
*4:無料で作れます
*5:といっても数十行で書けるからGoは便利
*6:機密情報なのでKMSで暗号化したssm parameterが理想ではある
*7:そういえばLambdaの公開当初Cold StartのFunctionに入る前のスタートアップ処理は課金対象外となっていたけど、そこでマイニングとかしだす輩が続出して課金対象になったって話があった気がするw
*9:一部出力を除外してます