Edited at

AWS Lambda のランタイムプロセスはコンテナとともに生き続ける

More than 1 year has passed since last update.

Serverless Framework を利用して AWS Lambda を雰囲気で使ってきましたが、初歩的な仕組みを理解できていませんでした…。


誤解していたこと

コンテナは使い回してもランタイムプロセス(?)は使い回さない(キリッ


今の認識

コンテナを使い回してランタイムプロセスも使い回す(キリッ

注) 正確(厳密)ではありません。イメージです。


  1. AWS Lambda 関数をデプロイ

  2. AWS Lambda 関数をリクエスト


    1. 初回のためコンテナを作成(コールドスタート)

    2. コンテナ上でランタイムプロセスが生成される

    3. ランタイムプロセスが関数を実行し結果を返す

    4. ランタイムプロセスは次のリクエストを待つ ← ここ、終了するものだと思っていた。



  3. 時間を空けずに AWS Lambda 関数をリクエスト


    1. 前回作成したコンテナが使えるので使い回す

    2. コンテナではランタイムプロセスが待機中 ← ここ、毎回生成されるものだと思っていた。

    3. ランタイムプロセスが関数を実行し結果を返す

    4. ランタイムプロセスは次のリクエストを待つ ← ここ、終了するものだと思っていた。



※ あと、コールドスタートにかかった時間は、 REPORT のログに記録されている Billed Duration には含まれていない、という点も正しく理解できていなかった。


確認

以下のハンドラファイルをデプロイして、ランタイムプロセスが生き続ける事を確認する。

print("Handler file loaded.")

import os
import subprocess

counter = 0

def hello(event, context):
global counter
counter += 1

print("$ uptime")
print(subprocess.check_output(["uptime"]).decode('UTF-8').rstrip())

print(f"$ ps u {os.getpid()}")
print(subprocess.check_output(["ps", "u", str(os.getpid())]).decode('UTF-8').rstrip())

return {"counter": counter}

適当に、1分間隔で関数を呼び出していく。



  • uptime でシステムの稼働時間を確認する


  • ps でランタイムプロセスの開始時間を確認する

  • グローバル変数で同一プロセスであることを確認する

$ seq 1 10 | xargs -n1 -I% bash -c '{ sls invoke -f hello -l ; sleep 60; }'

{
"counter": 1
}
--------------------------------------------------------------------
START RequestId: 4f67b37f-c60d-11e7-bf2a-df09c904a01a Version: $LATEST
$ uptime
11:50:13 up 1:29, 0 users, load average: 0.03, 0.01, 0.00
$ ps u 1
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
478 1 12.0 0.4 170480 19184 ? Ss 11:50 0:00 /var/lang/bin/python3.6 /var/runtime/awslambda/bootstrap.py
END RequestId: 4f67b37f-c60d-11e7-bf2a-df09c904a01a
REPORT RequestId: 4f67b37f-c60d-11e7-bf2a-df09c904a01a Duration: 49.17 ms Billed Duration: 100 ms Memory Size: 128 MB Max Memory Used: 22 MB

{
"counter": 2
}
--------------------------------------------------------------------
START RequestId: 74d1a410-c60d-11e7-8dcf-39cccc39d67a Version: $LATEST
$ uptime
11:51:15 up 1:30, 0 users, load average: 0.01, 0.00, 0.00
$ ps u 1
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
478 1 0.1 0.4 170480 19192 ? Rs 11:50 0:00 /var/lang/bin/python3.6 /var/runtime/awslambda/bootstrap.py
END RequestId: 74d1a410-c60d-11e7-8dcf-39cccc39d67a
REPORT RequestId: 74d1a410-c60d-11e7-8dcf-39cccc39d67a Duration: 179.24 ms Billed Duration: 200 ms Memory Size: 128 MB Max Memory Used: 22 MB

{
"counter": 3
}
--------------------------------------------------------------------
START RequestId: 99fa6e49-c60d-11e7-a48c-c30a58fa8fe6 Version: $LATEST
$ uptime
11:52:17 up 1:31, 0 users, load average: 0.00, 0.00, 0.00
$ ps u 1
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
478 1 0.0 0.4 170480 19192 ? Ss 11:50 0:00 /var/lang/bin/python3.6 /var/runtime/awslambda/bootstrap.py
END RequestId: 99fa6e49-c60d-11e7-a48c-c30a58fa8fe6
REPORT RequestId: 99fa6e49-c60d-11e7-a48c-c30a58fa8fe6 Duration: 221.70 ms Billed Duration: 300 ms Memory Size: 128 MB Max Memory Used: 23 MB

{
"counter": 4
}
--------------------------------------------------------------------
START RequestId: beea7400-c60d-11e7-8613-f14355ee452d Version: $LATEST
$ uptime
11:53:19 up 1:32, 0 users, load average: 0.00, 0.00, 0.00
$ ps u 1
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
478 1 0.0 0.4 170480 19192 ? Ss 11:50 0:00 /var/lang/bin/python3.6 /var/runtime/awslambda/bootstrap.py
END RequestId: beea7400-c60d-11e7-8613-f14355ee452d
REPORT RequestId: beea7400-c60d-11e7-8613-f14355ee452d Duration: 218.70 ms Billed Duration: 300 ms Memory Size: 128 MB Max Memory Used: 23 MB

{
"counter": 5
}
--------------------------------------------------------------------
START RequestId: e3d7e1d3-c60d-11e7-a7b2-dd75a5557d07 Version: $LATEST
$ uptime
11:54:21 up 1:33, 0 users, load average: 0.00, 0.00, 0.00
$ ps u 1
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
478 1 0.0 0.4 170480 19192 ? Ss 11:50 0:00 /var/lang/bin/python3.6 /var/runtime/awslambda/bootstrap.py
END RequestId: e3d7e1d3-c60d-11e7-a7b2-dd75a5557d07
REPORT RequestId: e3d7e1d3-c60d-11e7-a7b2-dd75a5557d07 Duration: 212.90 ms Billed Duration: 300 ms Memory Size: 128 MB Max Memory Used: 23 MB

{
"counter": 6
}
--------------------------------------------------------------------
START RequestId: 090280cf-c60e-11e7-908b-fb62b83e79bf Version: $LATEST
$ uptime
11:55:24 up 1:34, 0 users, load average: 0.00, 0.00, 0.00
$ ps u 1
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
478 1 0.0 0.4 170480 19192 ? Ss 11:50 0:00 /var/lang/bin/python3.6 /var/runtime/awslambda/bootstrap.py
END RequestId: 090280cf-c60e-11e7-908b-fb62b83e79bf
REPORT RequestId: 090280cf-c60e-11e7-908b-fb62b83e79bf Duration: 198.22 ms Billed Duration: 200 ms Memory Size: 128 MB Max Memory Used: 23 MB

{
"counter": 7
}
--------------------------------------------------------------------
START RequestId: 2de7fefe-c60e-11e7-b46e-117670d5c3cc Version: $LATEST
$ uptime
11:56:26 up 1:35, 0 users, load average: 0.00, 0.00, 0.00
$ ps u 1
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
478 1 0.0 0.4 170480 19192 ? Ss 11:50 0:00 /var/lang/bin/python3.6 /var/runtime/awslambda/bootstrap.py
END RequestId: 2de7fefe-c60e-11e7-b46e-117670d5c3cc
REPORT RequestId: 2de7fefe-c60e-11e7-b46e-117670d5c3cc Duration: 232.23 ms Billed Duration: 300 ms Memory Size: 128 MB Max Memory Used: 23 MB

{
"counter": 8
}
--------------------------------------------------------------------
START RequestId: 532b2e07-c60e-11e7-908b-fb62b83e79bf Version: $LATEST
$ uptime
11:57:28 up 1:36, 0 users, load average: 0.00, 0.00, 0.00
$ ps u 1
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
478 1 0.0 0.4 170480 19192 ? Ss 11:50 0:00 /var/lang/bin/python3.6 /var/runtime/awslambda/bootstrap.py
END RequestId: 532b2e07-c60e-11e7-908b-fb62b83e79bf
REPORT RequestId: 532b2e07-c60e-11e7-908b-fb62b83e79bf Duration: 201.68 ms Billed Duration: 300 ms Memory Size: 128 MB Max Memory Used: 23 MB

{
"counter": 9
}
--------------------------------------------------------------------
START RequestId: 78025558-c60e-11e7-8c38-ade05bfd80af Version: $LATEST
$ uptime
11:58:30 up 1:37, 0 users, load average: 0.00, 0.00, 0.00
$ ps u 1
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
478 1 0.0 0.4 170480 19192 ? Ss 11:50 0:00 /var/lang/bin/python3.6 /var/runtime/awslambda/bootstrap.py
END RequestId: 78025558-c60e-11e7-8c38-ade05bfd80af
REPORT RequestId: 78025558-c60e-11e7-8c38-ade05bfd80af Duration: 185.42 ms Billed Duration: 200 ms Memory Size: 128 MB Max Memory Used: 23 MB

{
"counter": 10
}
--------------------------------------------------------------------
START RequestId: 9d0e47dd-c60e-11e7-bb2e-9b3c16936470 Version: $LATEST
$ uptime
11:59:32 up 1:38, 0 users, load average: 0.00, 0.00, 0.00
$ ps u 1
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
478 1 0.0 0.4 170480 19192 ? Ss 11:50 0:00 /var/lang/bin/python3.6 /var/runtime/awslambda/bootstrap.py
END RequestId: 9d0e47dd-c60e-11e7-bb2e-9b3c16936470
REPORT RequestId: 9d0e47dd-c60e-11e7-bb2e-9b3c16936470 Duration: 172.61 ms Billed Duration: 200 ms Memory Size: 128 MB Max Memory Used: 23 MB

1行目の print("Handler file loaded.") の結果は sls invoke コマンドの出力では見られないが、 CloudWatch Logs の方には記録されている。

初回リクエストのランタイムプロセスが生成され、ハンドラモジュールがロードされたタイミングで評価される。そのため、二回目以降は評価されていない。