python3 -u test.py
RUN ./ol new -p=test-dir
b'Init OL dir at /root/open-lambda/test-dir\nCreate lambda base at /root/open-lambda/test-dir/lambda (may take several minutes)\nWorking Directory: /root/open-lambda/test-dir\n\nWorker Defaults: \n{\n\t"registry": "/root/open-lambda/test-dir/registry",\n\t"registry_cache_ms": 5000,\n\t"sandbox": "sock",\n\t"cluster_name": "/root/open-lambda/test-dir",\n\t"pip_mirror": "",\n\t"Pkgs_dir": "/root/open-lambda/test-dir/lambda/packages",\n\t"handler_cache_mb": 239,\n\t"import_cache_mb": 239,\n\t"server_mode": "lambda",\n\t"worker_dir": "/root/open-lambda/test-dir/worker",\n\t"SOCK_base_path": "/root/open-lambda/test-dir/lambda",\n\t"worker_port": "5000",\n\t"Skip_pull_existing": false,\n\t"sandbox_config": {},\n\t"docker_runtime": "",\n\t"sock_cgroups": {\n\t\t"max_procs": 10,\n\t\t"max_mem_mb": 50\n\t}\n}\n\nYou may modify the defaults here: /root/open-lambda/test-dir/config.json\n\nYou may now start a server using the "ol worker" command\n'
PUSH conf: {'registry': '/root/open-lambda/test-registry'}
========================================
ping_test
========================================
RUN ./ol worker -p=test-dir --detach
b'using existing OL directory at /root/open-lambda/test-dir\nStarting worker: pid=7283, port=5000, log=/root/open-lambda/test-dir/worker.out\nready\n'
RUN ./ol kill -p=test-dir
b'Kill worker process with PID 7283\n'
{
"test": "ping_test",
"params": {},
"pass": true,
"seconds": 2.6130313873291016,
"total_seconds": 2.8889589309692383,
"stats": {
"pings_per_sec": 382.7028303449122
},
"ol-stats": {
"Create()/acquire-cgroup:ms.avg": 0,
"Create()/acquire-cgroup:ms.cnt": 1,
"Create()/acquire-mem:ms.avg": 0,
"Create()/acquire-mem:ms.cnt": 1,
"Create()/fresh-proc:ms.avg": 1534,
"Create()/fresh-proc:ms.cnt": 1,
"Create()/make-root-fs:ms.avg": 0,
"Create()/make-root-fs:ms.cnt": 1,
"Create():ms.avg": 1534,
"Create():ms.cnt": 1,
"Destroy()/detach-root:ms.avg": 0,
"Destroy()/detach-root:ms.cnt": 1,
"Destroy()/kill-procs:ms.avg": 1,
"Destroy()/kill-procs:ms.cnt": 1,
"Destroy()/remove-root:ms.avg": 0,
"Destroy()/remove-root:ms.cnt": 1,
"Destroy():ms.avg": 1,
"Destroy():ms.cnt": 1
},
"conf": {
"SOCK_base_path": "/root/open-lambda/test-dir/lambda",
"Skip_pull_existing": false,
"worker_port": "5000",
"worker_dir": "/root/open-lambda/test-dir/worker",
"Pkgs_dir": "/root/open-lambda/test-dir/lambda/packages",
"import_cache_mb": 239,
"registry_cache_ms": 5000,
"pip_mirror": "",
"sandbox": "sock",
"server_mode": "lambda",
"handler_cache_mb": 239,
"cluster_name": "/root/open-lambda/test-dir",
"sandbox_config": {},
"docker_runtime": "",
"registry": "/root/open-lambda/test-registry",
"sock_cgroups": {
"max_procs": 10,
"max_mem_mb": 50
}
},
"errors": [],
"worker_tail": [
"2019/07/03 21:43:26 remove /sys/fs/cgroup/freezer/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:43:26 remove /sys/fs/cgroup/hugetlb/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:43:26 remove /sys/fs/cgroup/memory/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:43:26 remove /sys/fs/cgroup/perf_event/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:43:26 remove /sys/fs/cgroup/systemd/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:43:26 remove /sys/fs/cgroup/pids/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:43:26 save stats to /root/open-lambda/test-dir/worker/stats.json",
"2019/07/03 21:43:26 remove worker.pid",
"2019/07/03 21:43:26 exiting",
""
]
}
PUSH conf: {'handler_cache_mb': 100, 'import_cache_mb': 0}
========================================
smoke_tests
========================================
RUN ./ol worker -p=test-dir --detach
b'using existing OL directory at /root/open-lambda/test-dir\nStarting worker: pid=7309, port=5000, log=/root/open-lambda/test-dir/worker.out\nready\n'
RUN ./ol kill -p=test-dir
b'Kill worker process with PID 7309\n'
{
"test": "smoke_tests",
"params": {},
"pass": false,
"seconds": null,
"total_seconds": 388.66093373298645,
"stats": null,
"ol-stats": {
"Channel():ms.avg": 0,
"Channel():ms.cnt": 11,
"Create()/acquire-cgroup:ms.avg": 0,
"Create()/acquire-cgroup:ms.cnt": 11,
"Create()/acquire-mem:ms.avg": 0,
"Create()/acquire-mem:ms.cnt": 11,
"Create()/fresh-proc:ms.avg": 148,
"Create()/fresh-proc:ms.cnt": 11,
"Create()/make-root-fs:ms.avg": 10,
"Create()/make-root-fs:ms.cnt": 11,
"Create():ms.avg": 159,
"Create():ms.cnt": 11,
"Destroy()/detach-root:ms.avg": 0,
"Destroy()/detach-root:ms.cnt": 11,
"Destroy()/kill-procs:ms.avg": 3,
"Destroy()/kill-procs:ms.cnt": 11,
"Destroy()/remove-root:ms.avg": 0,
"Destroy()/remove-root:ms.cnt": 11,
"Destroy():ms.avg": 3,
"Destroy():ms.cnt": 12,
"Pause():ms.avg": 3,
"Pause():ms.cnt": 4,
"evict:ms.avg": 3,
"evict:ms.cnt": 1,
"pip-install:ms.avg": 55326,
"pip-install:ms.cnt": 7
},
"conf": {
"SOCK_base_path": "/root/open-lambda/test-dir/lambda",
"Skip_pull_existing": false,
"worker_port": "5000",
"worker_dir": "/root/open-lambda/test-dir/worker",
"Pkgs_dir": "/root/open-lambda/test-dir/lambda/packages",
"import_cache_mb": 0,
"registry_cache_ms": 5000,
"pip_mirror": "",
"sandbox": "sock",
"server_mode": "lambda",
"handler_cache_mb": 100,
"cluster_name": "/root/open-lambda/test-dir",
"sandbox_config": {},
"docker_runtime": "",
"registry": "/root/open-lambda/test-registry",
"sock_cgroups": {
"max_procs": 10,
"max_mem_mb": 50
}
},
"errors": [
[
"Traceback (most recent call last):",
" File \"test.py\", line 76, in wrapper",
" rv = fn(**kwargs)",
" File \"test.py\", line 193, in smoke_tests",
" raise Exception(\"STATUS %d: %s\" % (r.status_code, r.text))",
"Exception: STATUS 500: 500: Internal Server Error500: Internal Server Error",
""
]
],
"worker_tail": [
"using existing OL directory at /root/open-lambda/test-dir",
"2019/07/03 21:43:26 save PID 7309 to file /root/open-lambda/test-dir/worker/worker.pid",
"2019/07/03 21:43:26 Start Lambda Server",
"2019/07/03 21:43:26 Create SandboxPool",
"2019/07/03 21:43:26 create /sys/fs/cgroup/blkio/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:43:26 create /sys/fs/cgroup/cpu/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:43:26 create /sys/fs/cgroup/devices/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:43:26 create /sys/fs/cgroup/freezer/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:43:26 create /sys/fs/cgroup/hugetlb/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:43:26 create /sys/fs/cgroup/memory/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:43:26 create /sys/fs/cgroup/perf_event/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:43:26 create /sys/fs/cgroup/systemd/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:43:26 create /sys/fs/cgroup/pids/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:43:26 Create ModulePuller",
"2019/07/03 21:43:26 Create HandlerPuller",
"2019/07/03 21:43:26 Setups Handlers",
"2019/07/03 21:43:26 Execute handler by POSTing to localhost:5000/run/",
"2019/07/03 21:43:26 Get status by sending request to localhost:5000/status",
"2019/07/03 21:43:26 start creating/serving CGs [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:43:27 Receive request to /pid",
"2019/07/03 21:43:27 Receive request to /run/echo",
"2019/07/03 21:43:27 debug: LambdaFunc.Task() runs on goroutine 15 [FUNC echo]",
"2019/07/03 21:43:27 increase instances to 1 [FUNC echo]",
"2019/07/03 21:43:27 .Create(, true, /root/open-lambda/test-dir/worker/lambda_code/1-echo, /root/open-lambda/test-dir/worker/scratch/func-echo-1001, &{[] []})...",
"2019/07/03 21:43:27 ...returns &{0xc000176a20 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:43:27 Channel() [SB 1]",
"2019/07/03 21:43:27 Pause() [SB 1]",
"2019/07/03 21:43:27 Receive request to /run/install",
"2019/07/03 21:43:27 debug: LambdaFunc.Task() runs on goroutine 28 [FUNC install]",
"2019/07/03 21:43:27 run pip install parso from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/parso on host",
"2019/07/03 21:43:27 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/parso, )...",
"2019/07/03 21:43:27 ...returns &{0xc0001aa060 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:43:27 Channel() [SB 2]",
"2019/07/03 21:43:27 Evict Sandbox 1",
"2019/07/03 21:43:27 Destroy() [SB 1]",
"2019/07/03 21:43:27 kill all procs in CG [SOCK 1]",
"2019/07/03 21:43:27 waiting for 1 procs in cg-1 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:43:27 unmount and remove dirs [SOCK 1]",
"Collecting parso",
" Downloading https://files.pythonhosted.org/packages/68/59/482f5a00fe3da7f0aaeedf61c2a25c445b68c9124437195f6e8b2beddbc0/parso-0.5.0-py2.py3-none-any.whl (94kB)",
"Installing collected packages: parso",
"Successfully installed parso-0.5.0",
"2019/07/03 21:43:28 Destroy() [SB 2]",
"2019/07/03 21:43:28 kill all procs in CG [SOCK 2]",
"2019/07/03 21:43:28 waiting for 1 procs in cg-2 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:43:28 unmount and remove dirs [SOCK 2]",
"2019/07/03 21:43:28 run pip install jedi from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/jedi on host",
"2019/07/03 21:43:28 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/jedi, )...",
"2019/07/03 21:43:28 ...returns &{0xc0001ab020 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:43:28 Channel() [SB 3]",
"Collecting jedi",
" Downloading https://files.pythonhosted.org/packages/68/42/6309f3871b2f8361764ac5b2fe6719f9c6e6561d9307d8cecda319cf5843/jedi-0.14.0-py2.py3-none-any.whl (1.0MB)",
"Installing collected packages: jedi",
"Successfully installed jedi-0.14.0",
"2019/07/03 21:43:30 Destroy() [SB 3]",
"2019/07/03 21:43:30 kill all procs in CG [SOCK 3]",
"2019/07/03 21:43:30 waiting for 1 procs in cg-3 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:43:30 unmount and remove dirs [SOCK 3]",
"2019/07/03 21:43:30 run pip install idna from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/idna on host",
"2019/07/03 21:43:30 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/idna, )...",
"2019/07/03 21:43:30 ...returns &{0xc0001abc80 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:43:30 Channel() [SB 4]",
"Collecting idna",
" Downloading https://files.pythonhosted.org/packages/14/2c/cd551d81dbe15200be1cf41cd03869a46fe7226e7450af7a6545bfc474c9/idna-2.8-py2.py3-none-any.whl (58kB)",
"Installing collected packages: idna",
"Killed",
"2019/07/03 21:43:30 Destroy() [SB 4]",
"2019/07/03 21:43:30 kill all procs in CG [SOCK 4]",
"2019/07/03 21:43:30 waiting for 1 procs in cg-4 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:43:30 unmount and remove dirs [SOCK 4]",
"2019/07/03 21:43:30 run pip install chardet from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/chardet on host",
"2019/07/03 21:43:30 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/chardet, )...",
"2019/07/03 21:43:31 ...returns &{0xc0001d0900 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:43:31 Channel() [SB 5]",
"Collecting chardet",
" Using cached https://files.pythonhosted.org/packages/bc/a9/01ffebfb562e4274b6487b4bb1ddec7ca55ec7510b22e4c51f14098443b8/chardet-3.0.4-py2.py3-none-any.whl",
"Installing collected packages: chardet",
"Successfully installed chardet-3.0.4",
"2019/07/03 21:43:31 Destroy() [SB 5]",
"2019/07/03 21:43:31 kill all procs in CG [SOCK 5]",
"2019/07/03 21:43:31 waiting for 1 procs in cg-5 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:43:31 unmount and remove dirs [SOCK 5]",
"2019/07/03 21:43:31 run pip install certifi from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/certifi on host",
"2019/07/03 21:43:31 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/certifi, )...",
"2019/07/03 21:43:31 ...returns &{0xc0001d1560 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:43:31 Channel() [SB 6]",
"Collecting certifi",
" Using cached https://files.pythonhosted.org/packages/69/1b/b853c7a9d4f6a6d00749e94eb6f3a041e342a885b87340b79c1ef73e3a78/certifi-2019.6.16-py2.py3-none-any.whl",
"Installing collected packages: certifi",
"Successfully installed certifi-2019.6.16",
"2019/07/03 21:43:32 Destroy() [SB 6]",
"2019/07/03 21:43:32 kill all procs in CG [SOCK 6]",
"2019/07/03 21:43:32 waiting for 1 procs in cg-6 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:43:32 unmount and remove dirs [SOCK 6]",
"2019/07/03 21:43:32 run pip install requests from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/requests on host",
"2019/07/03 21:43:32 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/requests, )...",
"2019/07/03 21:43:32 ...returns &{0xc0001f01e0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:43:32 Channel() [SB 7]",
"Collecting requests",
" Using cached https://files.pythonhosted.org/packages/51/bd/23c926cd341ea6b7dd0b2a00aba99ae0f828be89d72b2190f27c11d4b7fb/requests-2.22.0-py2.py3-none-any.whl",
"Installing collected packages: requests",
"Successfully installed requests-2.22.0",
"2019/07/03 21:43:33 Destroy() [SB 7]",
"2019/07/03 21:43:33 kill all procs in CG [SOCK 7]",
"2019/07/03 21:43:33 waiting for 1 procs in cg-7 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:43:33 unmount and remove dirs [SOCK 7]",
"2019/07/03 21:43:33 increase instances to 1 [FUNC install]",
"2019/07/03 21:43:33 .Create(, true, /root/open-lambda/test-dir/worker/lambda_code/2-install, /root/open-lambda/test-dir/worker/scratch/func-install-1002, &{[parso jedi idna chardet certifi requests] [parso jedi idna chardet certifi requests urllib3]})...",
"2019/07/03 21:43:33 ...returns &{0xc0001f0ea0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:43:33 Channel() [SB 8]",
"2019/07/03 21:43:33 Pause() [SB 8]",
"2019/07/03 21:43:33 Receive request to /stats",
"2019/07/03 21:43:33 Receive request to /run/install2",
"2019/07/03 21:43:33 debug: LambdaFunc.Task() runs on goroutine 59 [FUNC install2]",
"2019/07/03 21:43:33 skip installing parso, already installed during this run of OL",
"2019/07/03 21:43:33 skip installing jedi, already installed during this run of OL",
"2019/07/03 21:43:33 skip installing idna, already installed during this run of OL",
"2019/07/03 21:43:33 skip installing chardet, already installed during this run of OL",
"2019/07/03 21:43:33 skip installing certifi, already installed during this run of OL",
"2019/07/03 21:43:33 skip installing requests, already installed during this run of OL",
"2019/07/03 21:43:33 increase instances to 1 [FUNC install2]",
"2019/07/03 21:43:33 .Create(, true, /root/open-lambda/test-dir/worker/lambda_code/3-install2, /root/open-lambda/test-dir/worker/scratch/func-install2-1003, &{[parso jedi idna chardet certifi requests] [parso jedi idna chardet certifi requests urllib3]})...",
"2019/07/03 21:43:33 ...returns &{0xc0002243c0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:43:33 Channel() [SB 9]",
"2019/07/03 21:43:33 Pause() [SB 9]",
"2019/07/03 21:43:33 Receive request to /stats",
"2019/07/03 21:43:33 Receive request to /run/install3",
"2019/07/03 21:43:33 debug: LambdaFunc.Task() runs on goroutine 71 [FUNC install3]",
"2019/07/03 21:43:33 skip installing parso, already installed during this run of OL",
"2019/07/03 21:43:33 skip installing jedi, already installed during this run of OL",
"2019/07/03 21:43:33 skip installing idna, already installed during this run of OL",
"2019/07/03 21:43:33 skip installing chardet, already installed during this run of OL",
"2019/07/03 21:43:33 skip installing certifi, already installed during this run of OL",
"2019/07/03 21:43:33 skip installing requests, already installed during this run of OL",
"2019/07/03 21:43:33 run pip install simplejson from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/simplejson on host",
"2019/07/03 21:43:33 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/simplejson, )...",
"2019/07/03 21:43:33 ...returns &{0xc000225860 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:43:33 Channel() [SB 10]",
"Collecting simplejson",
" Downloading https://files.pythonhosted.org/packages/e3/24/c35fb1c1c315fc0fffe61ea00d3f88e85469004713dab488dee4f35b0aff/simplejson-3.16.0.tar.gz (81kB)",
"Building wheels for collected packages: simplejson",
" WARNING: Building wheel for simplejson failed: [Errno 30] Read-only file system: '/root/.cache/pip/wheels/5d'",
"Failed to build simplejson",
"Installing collected packages: simplejson",
" Running setup.py install for simplejson: started",
"Killed",
"2019/07/03 21:49:55 Destroy() [SB 10]",
"2019/07/03 21:49:55 kill all procs in CG [SOCK 10]",
"2019/07/03 21:49:55 waiting for 3 procs in cg-10 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:55 unmount and remove dirs [SOCK 10]",
"2019/07/03 21:49:55 increase instances to 1 [FUNC install3]",
"2019/07/03 21:49:55 .Create(, true, /root/open-lambda/test-dir/worker/lambda_code/4-install3, /root/open-lambda/test-dir/worker/scratch/func-install3-1004, &{[parso jedi idna chardet certifi requests simplejson] [parso jedi idna chardet certifi requests simplejson urllib3]})...",
"2019/07/03 21:49:55 ...returns &{0xc00024c600 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:49:55 Channel() [SB 11]",
"ERROR:tornado.application:Uncaught exception POST /run/install3 (0.0.0.0)",
"HTTPServerRequest(protocol='http', host='localhost:5000', method='POST', uri='/run/install3', version='HTTP/1.1', remote_ip='0.0.0.0', headers={'Host': 'localhost:5000', 'User-Agent': 'python-requests/2.9.1', 'Content-Length': '2', 'Accept': '*/*', 'Accept-Encoding': 'gzip, deflate', 'X-Forwarded-For': '127.0.0.1'})",
"Traceback (most recent call last):",
" File \"/usr/local/lib/python3.6/dist-packages/tornado/web.py\", line 1510, in _execute",
" result = method(*self.path_args, **self.path_kwargs)",
" File \"sock2.py\", line 33, in post",
" import lambda_func",
" File \"/handler/lambda_func.py\", line 3, in ",
" import simplejson",
"ModuleNotFoundError: No module named 'simplejson'",
"2019/07/03 21:49:55 Pause() [SB 11]",
"2019/07/03 21:49:55 received kill signal, cleaning up",
"Kill function: install32019/07/03 21:49:55 Destroy() [SB 11]",
"2019/07/03 21:49:55 kill all procs in CG [SOCK 11]",
"2019/07/03 21:49:55 unmount and remove dirs [SOCK 11]",
"Kill function: echo2019/07/03 21:49:55 Destroy() [SB 1]",
"Kill function: install2019/07/03 21:49:55 Destroy() [SB 8]",
"2019/07/03 21:49:55 kill all procs in CG [SOCK 8]",
"2019/07/03 21:49:55 unmount and remove dirs [SOCK 8]",
"Kill function: install22019/07/03 21:49:55 Destroy() [SB 9]",
"2019/07/03 21:49:55 kill all procs in CG [SOCK 9]",
"2019/07/03 21:49:55 unmount and remove dirs [SOCK 9]",
"2019/07/03 21:49:55 SOCKPool.Cleanup: make sure all memory is free",
"2019/07/03 21:49:55 SOCKPool.Cleanup: memory pool emptied",
"2019/07/03 21:49:55 received shutdown request [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:55 empty queues and release CGs [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:55 remove /sys/fs/cgroup/blkio/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:55 remove /sys/fs/cgroup/cpu/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:55 remove /sys/fs/cgroup/devices/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:55 remove /sys/fs/cgroup/freezer/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:55 remove /sys/fs/cgroup/hugetlb/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:55 remove /sys/fs/cgroup/memory/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:55 remove /sys/fs/cgroup/perf_event/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:55 remove /sys/fs/cgroup/systemd/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:55 remove /sys/fs/cgroup/pids/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:55 save stats to /root/open-lambda/test-dir/worker/stats.json",
"2019/07/03 21:49:55 remove worker.pid",
"2019/07/03 21:49:55 exiting",
""
]
}
POP conf: {'handler_cache_mb': 100, 'import_cache_mb': 0}
PUSH conf: {'handler_cache_mb': 250, 'import_cache_mb': 0}
========================================
smoke_tests
========================================
RUN ./ol worker -p=test-dir --detach
b'using existing OL directory at /root/open-lambda/test-dir\nStarting worker: pid=7440, port=5000, log=/root/open-lambda/test-dir/worker.out\nready\n'
RUN ./ol kill -p=test-dir
b'Kill worker process with PID 7440\n'
{
"test": "smoke_tests",
"params": {},
"pass": false,
"seconds": null,
"total_seconds": 396.4857347011566,
"stats": null,
"ol-stats": {
"Channel():ms.avg": 0,
"Channel():ms.cnt": 11,
"Create()/acquire-cgroup:ms.avg": 0,
"Create()/acquire-cgroup:ms.cnt": 11,
"Create()/acquire-mem:ms.avg": 0,
"Create()/acquire-mem:ms.cnt": 11,
"Create()/fresh-proc:ms.avg": 144,
"Create()/fresh-proc:ms.cnt": 11,
"Create()/make-root-fs:ms.avg": 1,
"Create()/make-root-fs:ms.cnt": 11,
"Create():ms.avg": 145,
"Create():ms.cnt": 11,
"Destroy()/detach-root:ms.avg": 0,
"Destroy()/detach-root:ms.cnt": 11,
"Destroy()/kill-procs:ms.avg": 3,
"Destroy()/kill-procs:ms.cnt": 11,
"Destroy()/remove-root:ms.avg": 0,
"Destroy()/remove-root:ms.cnt": 11,
"Destroy():ms.avg": 3,
"Destroy():ms.cnt": 11,
"Pause():ms.avg": 3,
"Pause():ms.cnt": 4,
"pip-install:ms.avg": 56448,
"pip-install:ms.cnt": 7
},
"conf": {
"SOCK_base_path": "/root/open-lambda/test-dir/lambda",
"Skip_pull_existing": false,
"worker_dir": "/root/open-lambda/test-dir/worker",
"Pkgs_dir": "/root/open-lambda/test-dir/lambda/packages",
"import_cache_mb": 0,
"sock_cgroups": {
"max_procs": 10,
"max_mem_mb": 50
},
"server_mode": "lambda",
"pip_mirror": "",
"sandbox": "sock",
"registry_cache_ms": 5000,
"handler_cache_mb": 250,
"cluster_name": "/root/open-lambda/test-dir",
"docker_runtime": "",
"sandbox_config": {},
"registry": "/root/open-lambda/test-registry",
"worker_port": "5000"
},
"errors": [
[
"Traceback (most recent call last):",
" File \"test.py\", line 76, in wrapper",
" rv = fn(**kwargs)",
" File \"test.py\", line 193, in smoke_tests",
" raise Exception(\"STATUS %d: %s\" % (r.status_code, r.text))",
"Exception: STATUS 500: 500: Internal Server Error500: Internal Server Error",
""
]
],
"worker_tail": [
"using existing OL directory at /root/open-lambda/test-dir",
"2019/07/03 21:49:55 save PID 7440 to file /root/open-lambda/test-dir/worker/worker.pid",
"2019/07/03 21:49:55 Start Lambda Server",
"2019/07/03 21:49:55 Create SandboxPool",
"2019/07/03 21:49:55 create /sys/fs/cgroup/blkio/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:55 create /sys/fs/cgroup/cpu/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:55 create /sys/fs/cgroup/devices/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:55 create /sys/fs/cgroup/freezer/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:55 create /sys/fs/cgroup/hugetlb/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:55 create /sys/fs/cgroup/memory/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:55 create /sys/fs/cgroup/perf_event/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:55 create /sys/fs/cgroup/systemd/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:55 create /sys/fs/cgroup/pids/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:55 Create ModulePuller",
"2019/07/03 21:49:55 Create HandlerPuller",
"2019/07/03 21:49:55 Setups Handlers",
"2019/07/03 21:49:55 Execute handler by POSTing to localhost:5000/run/",
"2019/07/03 21:49:55 Get status by sending request to localhost:5000/status",
"2019/07/03 21:49:55 start creating/serving CGs [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:55 Receive request to /pid",
"2019/07/03 21:49:55 Receive request to /run/echo",
"2019/07/03 21:49:55 debug: LambdaFunc.Task() runs on goroutine 15 [FUNC echo]",
"2019/07/03 21:49:55 increase instances to 1 [FUNC echo]",
"2019/07/03 21:49:55 .Create(, true, /root/open-lambda/test-dir/worker/lambda_code/1-echo, /root/open-lambda/test-dir/worker/scratch/func-echo-1001, &{[] []})...",
"2019/07/03 21:49:55 ...returns &{0xc00019ac60 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:49:55 Channel() [SB 1]",
"2019/07/03 21:49:55 Pause() [SB 1]",
"2019/07/03 21:49:55 Receive request to /run/install",
"2019/07/03 21:49:55 debug: LambdaFunc.Task() runs on goroutine 28 [FUNC install]",
"2019/07/03 21:49:55 run pip install parso from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/parso on host",
"2019/07/03 21:49:55 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/parso, )...",
"2019/07/03 21:49:56 ...returns &{0xc0001d62a0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:49:56 Channel() [SB 2]",
"Collecting parso",
" Downloading https://files.pythonhosted.org/packages/68/59/482f5a00fe3da7f0aaeedf61c2a25c445b68c9124437195f6e8b2beddbc0/parso-0.5.0-py2.py3-none-any.whl (94kB)",
"Installing collected packages: parso",
"Successfully installed parso-0.5.0",
"2019/07/03 21:49:56 Destroy() [SB 2]",
"2019/07/03 21:49:56 kill all procs in CG [SOCK 2]",
"2019/07/03 21:49:56 waiting for 1 procs in cg-2 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:56 unmount and remove dirs [SOCK 2]",
"2019/07/03 21:49:56 run pip install jedi from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/jedi on host",
"2019/07/03 21:49:56 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/jedi, )...",
"2019/07/03 21:49:56 ...returns &{0xc0001d6f60 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:49:56 Channel() [SB 3]",
"Collecting jedi",
" Downloading https://files.pythonhosted.org/packages/68/42/6309f3871b2f8361764ac5b2fe6719f9c6e6561d9307d8cecda319cf5843/jedi-0.14.0-py2.py3-none-any.whl (1.0MB)",
"Installing collected packages: jedi",
"Successfully installed jedi-0.14.0",
"2019/07/03 21:49:58 Destroy() [SB 3]",
"2019/07/03 21:49:58 kill all procs in CG [SOCK 3]",
"2019/07/03 21:49:58 waiting for 1 procs in cg-3 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:58 unmount and remove dirs [SOCK 3]",
"2019/07/03 21:49:58 run pip install idna from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/idna on host",
"2019/07/03 21:49:58 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/idna, )...",
"2019/07/03 21:49:58 ...returns &{0xc0001d7bc0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:49:58 Channel() [SB 4]",
"Collecting idna",
" Downloading https://files.pythonhosted.org/packages/14/2c/cd551d81dbe15200be1cf41cd03869a46fe7226e7450af7a6545bfc474c9/idna-2.8-py2.py3-none-any.whl (58kB)",
"Installing collected packages: idna",
"Successfully installed idna-2.8",
"2019/07/03 21:49:58 Destroy() [SB 4]",
"2019/07/03 21:49:58 kill all procs in CG [SOCK 4]",
"2019/07/03 21:49:58 waiting for 1 procs in cg-4 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:58 unmount and remove dirs [SOCK 4]",
"2019/07/03 21:49:58 run pip install chardet from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/chardet on host",
"2019/07/03 21:49:58 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/chardet, )...",
"2019/07/03 21:49:59 ...returns &{0xc0001fa840 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:49:59 Channel() [SB 5]",
"Collecting chardet",
" Using cached https://files.pythonhosted.org/packages/bc/a9/01ffebfb562e4274b6487b4bb1ddec7ca55ec7510b22e4c51f14098443b8/chardet-3.0.4-py2.py3-none-any.whl",
"Installing collected packages: chardet",
"Successfully installed chardet-3.0.4",
"2019/07/03 21:49:59 Destroy() [SB 5]",
"2019/07/03 21:49:59 kill all procs in CG [SOCK 5]",
"2019/07/03 21:49:59 waiting for 1 procs in cg-5 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:49:59 unmount and remove dirs [SOCK 5]",
"2019/07/03 21:49:59 run pip install certifi from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/certifi on host",
"2019/07/03 21:49:59 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/certifi, )...",
"2019/07/03 21:49:59 ...returns &{0xc0001fb4a0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:49:59 Channel() [SB 6]",
"Collecting certifi",
" Using cached https://files.pythonhosted.org/packages/69/1b/b853c7a9d4f6a6d00749e94eb6f3a041e342a885b87340b79c1ef73e3a78/certifi-2019.6.16-py2.py3-none-any.whl",
"Installing collected packages: certifi",
"Successfully installed certifi-2019.6.16",
"2019/07/03 21:50:00 Destroy() [SB 6]",
"2019/07/03 21:50:00 kill all procs in CG [SOCK 6]",
"2019/07/03 21:50:00 waiting for 1 procs in cg-6 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:50:00 unmount and remove dirs [SOCK 6]",
"2019/07/03 21:50:00 run pip install requests from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/requests on host",
"2019/07/03 21:50:00 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/requests, )...",
"2019/07/03 21:50:00 ...returns &{0xc00021e120 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:50:00 Channel() [SB 7]",
"Collecting requests",
" Using cached https://files.pythonhosted.org/packages/51/bd/23c926cd341ea6b7dd0b2a00aba99ae0f828be89d72b2190f27c11d4b7fb/requests-2.22.0-py2.py3-none-any.whl",
"Installing collected packages: requests",
"Successfully installed requests-2.22.0",
"2019/07/03 21:50:01 Destroy() [SB 7]",
"2019/07/03 21:50:01 kill all procs in CG [SOCK 7]",
"2019/07/03 21:50:01 waiting for 1 procs in cg-7 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:50:01 unmount and remove dirs [SOCK 7]",
"2019/07/03 21:50:01 increase instances to 1 [FUNC install]",
"2019/07/03 21:50:01 .Create(, true, /root/open-lambda/test-dir/worker/lambda_code/2-install, /root/open-lambda/test-dir/worker/scratch/func-install-1002, &{[parso jedi idna chardet certifi requests] [parso jedi idna chardet certifi requests urllib3]})...",
"2019/07/03 21:50:01 ...returns &{0xc00021ede0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:50:01 Channel() [SB 8]",
"2019/07/03 21:50:01 Pause() [SB 8]",
"2019/07/03 21:50:01 Receive request to /stats",
"2019/07/03 21:50:01 Receive request to /run/install2",
"2019/07/03 21:50:01 debug: LambdaFunc.Task() runs on goroutine 58 [FUNC install2]",
"2019/07/03 21:50:01 skip installing parso, already installed during this run of OL",
"2019/07/03 21:50:01 skip installing jedi, already installed during this run of OL",
"2019/07/03 21:50:01 skip installing idna, already installed during this run of OL",
"2019/07/03 21:50:01 skip installing chardet, already installed during this run of OL",
"2019/07/03 21:50:01 skip installing certifi, already installed during this run of OL",
"2019/07/03 21:50:01 skip installing requests, already installed during this run of OL",
"2019/07/03 21:50:01 increase instances to 1 [FUNC install2]",
"2019/07/03 21:50:01 .Create(, true, /root/open-lambda/test-dir/worker/lambda_code/3-install2, /root/open-lambda/test-dir/worker/scratch/func-install2-1003, &{[parso jedi idna chardet certifi requests] [parso jedi idna chardet certifi requests urllib3]})...",
"2019/07/03 21:50:01 ...returns &{0xc00024c360 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:50:01 Channel() [SB 9]",
"2019/07/03 21:50:01 Pause() [SB 9]",
"2019/07/03 21:50:01 Receive request to /stats",
"2019/07/03 21:50:01 Receive request to /run/install3",
"2019/07/03 21:50:01 debug: LambdaFunc.Task() runs on goroutine 70 [FUNC install3]",
"2019/07/03 21:50:01 skip installing parso, already installed during this run of OL",
"2019/07/03 21:50:01 skip installing jedi, already installed during this run of OL",
"2019/07/03 21:50:01 skip installing idna, already installed during this run of OL",
"2019/07/03 21:50:01 skip installing chardet, already installed during this run of OL",
"2019/07/03 21:50:01 skip installing certifi, already installed during this run of OL",
"2019/07/03 21:50:01 skip installing requests, already installed during this run of OL",
"2019/07/03 21:50:01 run pip install simplejson from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/simplejson on host",
"2019/07/03 21:50:01 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/simplejson, )...",
"2019/07/03 21:50:01 ...returns &{0xc00024d800 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:50:01 Channel() [SB 10]",
"Collecting simplejson",
" Downloading https://files.pythonhosted.org/packages/e3/24/c35fb1c1c315fc0fffe61ea00d3f88e85469004713dab488dee4f35b0aff/simplejson-3.16.0.tar.gz (81kB)",
"Building wheels for collected packages: simplejson",
" WARNING: Building wheel for simplejson failed: [Errno 30] Read-only file system: '/root/.cache/pip/wheels/5d'",
"Failed to build simplejson",
"Installing collected packages: simplejson",
" Running setup.py install for simplejson: started",
"Killed",
"2019/07/03 21:56:31 Destroy() [SB 10]",
"2019/07/03 21:56:31 kill all procs in CG [SOCK 10]",
"2019/07/03 21:56:31 waiting for 3 procs in cg-10 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:31 unmount and remove dirs [SOCK 10]",
"2019/07/03 21:56:31 increase instances to 1 [FUNC install3]",
"2019/07/03 21:56:31 .Create(, true, /root/open-lambda/test-dir/worker/lambda_code/4-install3, /root/open-lambda/test-dir/worker/scratch/func-install3-1004, &{[parso jedi idna chardet certifi requests simplejson] [parso jedi idna chardet certifi requests simplejson urllib3]})...",
"2019/07/03 21:56:31 ...returns &{0xc0002705a0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:56:31 Channel() [SB 11]",
"ERROR:tornado.application:Uncaught exception POST /run/install3 (0.0.0.0)",
"HTTPServerRequest(protocol='http', host='localhost:5000', method='POST', uri='/run/install3', version='HTTP/1.1', remote_ip='0.0.0.0', headers={'Host': 'localhost:5000', 'User-Agent': 'python-requests/2.9.1', 'Content-Length': '2', 'Accept': '*/*', 'Accept-Encoding': 'gzip, deflate', 'X-Forwarded-For': '127.0.0.1'})",
"Traceback (most recent call last):",
" File \"/usr/local/lib/python3.6/dist-packages/tornado/web.py\", line 1510, in _execute",
" result = method(*self.path_args, **self.path_kwargs)",
" File \"sock2.py\", line 33, in post",
" import lambda_func",
" File \"/handler/lambda_func.py\", line 3, in ",
" import simplejson",
"ModuleNotFoundError: No module named 'simplejson'",
"2019/07/03 21:56:32 Pause() [SB 11]",
"2019/07/03 21:56:32 received kill signal, cleaning up",
"Kill function: echo2019/07/03 21:56:32 Destroy() [SB 1]",
"2019/07/03 21:56:32 kill all procs in CG [SOCK 1]",
"2019/07/03 21:56:32 unmount and remove dirs [SOCK 1]",
"Kill function: install2019/07/03 21:56:32 Destroy() [SB 8]",
"2019/07/03 21:56:32 kill all procs in CG [SOCK 8]",
"2019/07/03 21:56:32 unmount and remove dirs [SOCK 8]",
"Kill function: install22019/07/03 21:56:32 Destroy() [SB 9]",
"2019/07/03 21:56:32 kill all procs in CG [SOCK 9]",
"2019/07/03 21:56:32 unmount and remove dirs [SOCK 9]",
"Kill function: install32019/07/03 21:56:32 Destroy() [SB 11]",
"2019/07/03 21:56:32 kill all procs in CG [SOCK 11]",
"2019/07/03 21:56:32 waiting for 1 procs in cg-11 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:32 unmount and remove dirs [SOCK 11]",
"2019/07/03 21:56:32 SOCKPool.Cleanup: make sure all memory is free",
"2019/07/03 21:56:32 SOCKPool.Cleanup: memory pool emptied",
"2019/07/03 21:56:32 received shutdown request [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:32 empty queues and release CGs [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:32 remove /sys/fs/cgroup/blkio/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:32 remove /sys/fs/cgroup/cpu/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:32 remove /sys/fs/cgroup/devices/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:32 remove /sys/fs/cgroup/freezer/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:32 remove /sys/fs/cgroup/hugetlb/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:32 remove /sys/fs/cgroup/memory/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:32 remove /sys/fs/cgroup/perf_event/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:32 remove /sys/fs/cgroup/systemd/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:32 remove /sys/fs/cgroup/pids/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:32 save stats to /root/open-lambda/test-dir/worker/stats.json",
"2019/07/03 21:56:32 remove worker.pid",
"2019/07/03 21:56:32 exiting",
""
]
}
POP conf: {'handler_cache_mb': 250, 'import_cache_mb': 0}
PUSH conf: {'handler_cache_mb': 100, 'import_cache_mb': 250}
========================================
smoke_tests
========================================
RUN ./ol worker -p=test-dir --detach
b'using existing OL directory at /root/open-lambda/test-dir\nStarting worker: pid=7577, port=5000, log=/root/open-lambda/test-dir/worker.out\nready\n'
RUN ./ol kill -p=test-dir
b'Kill worker process with PID 7577\n'
{
"test": "smoke_tests",
"params": {},
"pass": false,
"seconds": null,
"total_seconds": 327.96995306015015,
"stats": null,
"ol-stats": {
"Channel():ms.avg": 0,
"Channel():ms.cnt": 11,
"Create()/acquire-cgroup:ms.avg": 0,
"Create()/acquire-cgroup:ms.cnt": 12,
"Create()/acquire-mem:ms.avg": 0,
"Create()/acquire-mem:ms.cnt": 12,
"Create()/fork-proc:ms.avg": 8,
"Create()/fork-proc:ms.cnt": 4,
"Create()/fresh-proc:ms.avg": 146,
"Create()/fresh-proc:ms.cnt": 8,
"Create()/make-root-fs:ms.avg": 1,
"Create()/make-root-fs:ms.cnt": 12,
"Create():ms.avg": 102,
"Create():ms.cnt": 12,
"Destroy()/detach-root:ms.avg": 0,
"Destroy()/detach-root:ms.cnt": 12,
"Destroy()/kill-procs:ms.avg": 2,
"Destroy()/kill-procs:ms.cnt": 12,
"Destroy()/remove-root:ms.avg": 0,
"Destroy()/remove-root:ms.cnt": 12,
"Destroy():ms.avg": 2,
"Destroy():ms.cnt": 13,
"Pause():ms.avg": 3,
"Pause():ms.cnt": 4,
"evict:ms.avg": 3,
"evict:ms.cnt": 1,
"fork():ms.avg": 8,
"fork():ms.cnt": 4,
"forkRequest:ms.avg": 5,
"forkRequest:ms.cnt": 4,
"move-to-cg-after-fork:ms.avg": 2,
"move-to-cg-after-fork:ms.cnt": 4,
"pip-install:ms.avg": 46739,
"pip-install:ms.cnt": 7
},
"conf": {
"SOCK_base_path": "/root/open-lambda/test-dir/lambda",
"Skip_pull_existing": false,
"worker_port": "5000",
"worker_dir": "/root/open-lambda/test-dir/worker",
"Pkgs_dir": "/root/open-lambda/test-dir/lambda/packages",
"import_cache_mb": 250,
"registry_cache_ms": 5000,
"pip_mirror": "",
"sandbox": "sock",
"server_mode": "lambda",
"handler_cache_mb": 100,
"cluster_name": "/root/open-lambda/test-dir",
"sandbox_config": {},
"docker_runtime": "",
"registry": "/root/open-lambda/test-registry",
"sock_cgroups": {
"max_procs": 10,
"max_mem_mb": 50
}
},
"errors": [
[
"Traceback (most recent call last):",
" File \"test.py\", line 76, in wrapper",
" rv = fn(**kwargs)",
" File \"test.py\", line 193, in smoke_tests",
" raise Exception(\"STATUS %d: %s\" % (r.status_code, r.text))",
"Exception: STATUS 500: 500: Internal Server Error500: Internal Server Error",
""
]
],
"worker_tail": [
"using existing OL directory at /root/open-lambda/test-dir",
"2019/07/03 21:56:32 save PID 7577 to file /root/open-lambda/test-dir/worker/worker.pid",
"2019/07/03 21:56:32 Start Lambda Server",
"2019/07/03 21:56:32 Create SandboxPool",
"2019/07/03 21:56:32 create /sys/fs/cgroup/blkio/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:32 create /sys/fs/cgroup/cpu/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:32 create /sys/fs/cgroup/devices/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:32 create /sys/fs/cgroup/freezer/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:32 create /sys/fs/cgroup/hugetlb/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:32 create /sys/fs/cgroup/memory/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:32 create /sys/fs/cgroup/perf_event/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:32 create /sys/fs/cgroup/systemd/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:32 create /sys/fs/cgroup/pids/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:32 Create ModulePuller",
"2019/07/03 21:56:32 Create HandlerPuller",
"2019/07/03 21:56:32 Create ImportCache",
"2019/07/03 21:56:32 create /sys/fs/cgroup/blkio/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 21:56:32 create /sys/fs/cgroup/cpu/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 21:56:32 create /sys/fs/cgroup/devices/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 21:56:32 create /sys/fs/cgroup/freezer/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 21:56:32 create /sys/fs/cgroup/hugetlb/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 21:56:32 create /sys/fs/cgroup/memory/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 21:56:32 create /sys/fs/cgroup/perf_event/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 21:56:32 create /sys/fs/cgroup/systemd/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 21:56:32 create /sys/fs/cgroup/pids/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 21:56:32 Setups Handlers",
"2019/07/03 21:56:32 Execute handler by POSTing to localhost:5000/run/",
"2019/07/03 21:56:32 Get status by sending request to localhost:5000/status",
"2019/07/03 21:56:32 start creating/serving CGs [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:32 start creating/serving CGs [CGROUP POOL worker-sock-cache]",
"2019/07/03 21:56:32 .Create(, false, , /root/open-lambda/test-dir/worker/scratch/import-cache-1001, )...",
"2019/07/03 21:56:32 Receive request to /pid",
"2019/07/03 21:56:32 Receive request to /run/echo",
"2019/07/03 21:56:32 debug: LambdaFunc.Task() runs on goroutine 22 [FUNC echo]",
"2019/07/03 21:56:32 increase instances to 1 [FUNC echo]",
"2019/07/03 21:56:32 ...returns &{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:56:32 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/1-echo, /root/open-lambda/test-dir/worker/scratch/func-echo-1002, &{[] []})...",
"2019/07/03 21:56:32 fork(&{0xc000082690 2 /root/open-lambda/test-dir/worker/sock-handlers/2 /root/open-lambda/test-dir/worker/lambda_code/1-echo /root/open-lambda/test-dir/worker/scratch/func-echo-1002 0xc00000f260}) [SB 1]",
"2019/07/03 21:56:32 ...returns &{0xc0001c45a0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:56:32 Channel() [SB 2]",
"2019/07/03 21:56:32 Pause() [SB 2]",
"2019/07/03 21:56:32 Receive request to /run/install",
"2019/07/03 21:56:32 debug: LambdaFunc.Task() runs on goroutine 33 [FUNC install]",
"2019/07/03 21:56:32 run pip install parso from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/parso on host",
"2019/07/03 21:56:32 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/parso, )...",
"2019/07/03 21:56:32 ...returns &{0xc0001c5b60 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:56:32 Channel() [SB 3]",
"2019/07/03 21:56:32 Evict Sandbox 2",
"2019/07/03 21:56:32 Destroy() [SB 2]",
"2019/07/03 21:56:32 kill all procs in CG [SOCK 2]",
"2019/07/03 21:56:32 waiting for 1 procs in cg-1 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:32 unmount and remove dirs [SOCK 2]",
"Collecting parso",
" Downloading https://files.pythonhosted.org/packages/68/59/482f5a00fe3da7f0aaeedf61c2a25c445b68c9124437195f6e8b2beddbc0/parso-0.5.0-py2.py3-none-any.whl (94kB)",
"Installing collected packages: parso",
"Successfully installed parso-0.5.0",
"2019/07/03 21:56:33 Destroy() [SB 3]",
"2019/07/03 21:56:33 kill all procs in CG [SOCK 3]",
"2019/07/03 21:56:33 waiting for 1 procs in cg-2 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:33 unmount and remove dirs [SOCK 3]",
"2019/07/03 21:56:33 run pip install jedi from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/jedi on host",
"2019/07/03 21:56:33 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/jedi, )...",
"2019/07/03 21:56:33 ...returns &{0xc0001f6ae0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:56:33 Channel() [SB 4]",
"Collecting jedi",
" Downloading https://files.pythonhosted.org/packages/68/42/6309f3871b2f8361764ac5b2fe6719f9c6e6561d9307d8cecda319cf5843/jedi-0.14.0-py2.py3-none-any.whl (1.0MB)",
"Installing collected packages: jedi",
"Successfully installed jedi-0.14.0",
"2019/07/03 21:56:34 Destroy() [SB 4]",
"2019/07/03 21:56:34 kill all procs in CG [SOCK 4]",
"2019/07/03 21:56:34 waiting for 1 procs in cg-3 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:34 unmount and remove dirs [SOCK 4]",
"2019/07/03 21:56:34 run pip install idna from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/idna on host",
"2019/07/03 21:56:34 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/idna, )...",
"2019/07/03 21:56:34 ...returns &{0xc0001f7740 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:56:34 Channel() [SB 5]",
"Collecting idna",
" Downloading https://files.pythonhosted.org/packages/14/2c/cd551d81dbe15200be1cf41cd03869a46fe7226e7450af7a6545bfc474c9/idna-2.8-py2.py3-none-any.whl (58kB)",
"Installing collected packages: idna",
"Successfully installed idna-2.8",
"2019/07/03 21:56:35 Destroy() [SB 5]",
"2019/07/03 21:56:35 kill all procs in CG [SOCK 5]",
"2019/07/03 21:56:35 waiting for 1 procs in cg-4 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:35 unmount and remove dirs [SOCK 5]",
"2019/07/03 21:56:35 run pip install chardet from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/chardet on host",
"2019/07/03 21:56:35 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/chardet, )...",
"2019/07/03 21:56:35 ...returns &{0xc0002203c0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:56:35 Channel() [SB 6]",
"Collecting chardet",
" Using cached https://files.pythonhosted.org/packages/bc/a9/01ffebfb562e4274b6487b4bb1ddec7ca55ec7510b22e4c51f14098443b8/chardet-3.0.4-py2.py3-none-any.whl",
"Installing collected packages: chardet",
"Successfully installed chardet-3.0.4",
"2019/07/03 21:56:36 Destroy() [SB 6]",
"2019/07/03 21:56:36 kill all procs in CG [SOCK 6]",
"2019/07/03 21:56:36 waiting for 1 procs in cg-5 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:36 unmount and remove dirs [SOCK 6]",
"2019/07/03 21:56:36 run pip install certifi from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/certifi on host",
"2019/07/03 21:56:36 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/certifi, )...",
"2019/07/03 21:56:36 ...returns &{0xc000221020 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:56:36 Channel() [SB 7]",
"Collecting certifi",
" Using cached https://files.pythonhosted.org/packages/69/1b/b853c7a9d4f6a6d00749e94eb6f3a041e342a885b87340b79c1ef73e3a78/certifi-2019.6.16-py2.py3-none-any.whl",
"Installing collected packages: certifi",
"Successfully installed certifi-2019.6.16",
"2019/07/03 21:56:36 Destroy() [SB 7]",
"2019/07/03 21:56:36 kill all procs in CG [SOCK 7]",
"2019/07/03 21:56:36 waiting for 1 procs in cg-6 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:36 unmount and remove dirs [SOCK 7]",
"2019/07/03 21:56:36 run pip install requests from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/requests on host",
"2019/07/03 21:56:36 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/requests, )...",
"2019/07/03 21:56:36 ...returns &{0xc000221c80 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:56:36 Channel() [SB 8]",
"Collecting requests",
" Using cached https://files.pythonhosted.org/packages/51/bd/23c926cd341ea6b7dd0b2a00aba99ae0f828be89d72b2190f27c11d4b7fb/requests-2.22.0-py2.py3-none-any.whl",
"Installing collected packages: requests",
"Successfully installed requests-2.22.0",
"2019/07/03 21:56:37 Destroy() [SB 8]",
"2019/07/03 21:56:37 kill all procs in CG [SOCK 8]",
"2019/07/03 21:56:37 waiting for 1 procs in cg-7 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 21:56:37 unmount and remove dirs [SOCK 8]",
"2019/07/03 21:56:37 increase instances to 1 [FUNC install]",
"2019/07/03 21:56:37 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/2-install, /root/open-lambda/test-dir/worker/scratch/func-install-1003, &{[parso jedi idna chardet certifi requests] [parso jedi idna chardet certifi requests urllib3]})...",
"2019/07/03 21:56:37 fork(&{0xc000082690 9 /root/open-lambda/test-dir/worker/sock-handlers/9 /root/open-lambda/test-dir/worker/lambda_code/2-install /root/open-lambda/test-dir/worker/scratch/func-install-1003 0xc00000f340}) [SB 1]",
"2019/07/03 21:56:37 ...returns &{0xc000236960 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:56:37 Channel() [SB 9]",
"2019/07/03 21:56:37 Pause() [SB 9]",
"2019/07/03 21:56:37 Receive request to /stats",
"2019/07/03 21:56:37 Receive request to /run/install2",
"2019/07/03 21:56:37 debug: LambdaFunc.Task() runs on goroutine 64 [FUNC install2]",
"2019/07/03 21:56:37 skip installing parso, already installed during this run of OL",
"2019/07/03 21:56:37 skip installing jedi, already installed during this run of OL",
"2019/07/03 21:56:37 skip installing idna, already installed during this run of OL",
"2019/07/03 21:56:37 skip installing chardet, already installed during this run of OL",
"2019/07/03 21:56:37 skip installing certifi, already installed during this run of OL",
"2019/07/03 21:56:37 skip installing requests, already installed during this run of OL",
"2019/07/03 21:56:37 increase instances to 1 [FUNC install2]",
"2019/07/03 21:56:37 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/3-install2, /root/open-lambda/test-dir/worker/scratch/func-install2-1004, &{[parso jedi idna chardet certifi requests] [parso jedi idna chardet certifi requests urllib3]})...",
"2019/07/03 21:56:37 fork(&{0xc000082690 10 /root/open-lambda/test-dir/worker/sock-handlers/10 /root/open-lambda/test-dir/worker/lambda_code/3-install2 /root/open-lambda/test-dir/worker/scratch/func-install2-1004 0xc00000f360}) [SB 1]",
"2019/07/03 21:56:37 ...returns &{0xc000237ec0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:56:37 Channel() [SB 10]",
"2019/07/03 21:56:37 Pause() [SB 10]",
"2019/07/03 21:56:37 Receive request to /stats",
"2019/07/03 21:56:37 Receive request to /run/install3",
"2019/07/03 21:56:37 debug: LambdaFunc.Task() runs on goroutine 76 [FUNC install3]",
"2019/07/03 21:56:37 skip installing parso, already installed during this run of OL",
"2019/07/03 21:56:37 skip installing jedi, already installed during this run of OL",
"2019/07/03 21:56:37 skip installing idna, already installed during this run of OL",
"2019/07/03 21:56:37 skip installing chardet, already installed during this run of OL",
"2019/07/03 21:56:37 skip installing certifi, already installed during this run of OL",
"2019/07/03 21:56:37 skip installing requests, already installed during this run of OL",
"2019/07/03 21:56:37 run pip install simplejson from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/simplejson on host",
"2019/07/03 21:56:37 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/simplejson, )...",
"2019/07/03 21:56:37 ...returns &{0xc0002674a0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 21:56:37 Channel() [SB 11]",
"Collecting simplejson",
" Downloading https://files.pythonhosted.org/packages/e3/24/c35fb1c1c315fc0fffe61ea00d3f88e85469004713dab488dee4f35b0aff/simplejson-3.16.0.tar.gz (81kB)",
"Building wheels for collected packages: simplejson",
" WARNING: Building wheel for simplejson failed: [Errno 30] Read-only file system: '/root/.cache/pip/wheels/5d'",
"Failed to build simplejson",
"Installing collected packages: simplejson",
" Running setup.py install for simplejson: started",
"Killed",
"2019/07/03 22:01:59 Destroy() [SB 11]",
"2019/07/03 22:01:59 kill all procs in CG [SOCK 11]",
"2019/07/03 22:01:59 waiting for 3 procs in cg-10 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:01:59 unmount and remove dirs [SOCK 11]",
"2019/07/03 22:01:59 increase instances to 1 [FUNC install3]",
"2019/07/03 22:01:59 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/4-install3, /root/open-lambda/test-dir/worker/scratch/func-install3-1005, &{[parso jedi idna chardet certifi requests simplejson] [parso jedi idna chardet certifi requests simplejson urllib3]})...",
"2019/07/03 22:01:59 fork(&{0xc000082690 12 /root/open-lambda/test-dir/worker/sock-handlers/12 /root/open-lambda/test-dir/worker/lambda_code/4-install3 /root/open-lambda/test-dir/worker/scratch/func-install3-1005 0xc00000f3a0}) [SB 1]",
"2019/07/03 22:01:59 ...returns &{0xc0002a2240 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:01:59 Channel() [SB 12]",
"ERROR:tornado.application:Uncaught exception POST /run/install3 (0.0.0.0)",
"HTTPServerRequest(protocol='http', host='localhost:5000', method='POST', uri='/run/install3', version='HTTP/1.1', remote_ip='0.0.0.0', headers={'Host': 'localhost:5000', 'User-Agent': 'python-requests/2.9.1', 'Content-Length': '2', 'Accept': '*/*', 'Accept-Encoding': 'gzip, deflate', 'X-Forwarded-For': '127.0.0.1'})",
"Traceback (most recent call last):",
" File \"/usr/local/lib/python3.6/dist-packages/tornado/web.py\", line 1510, in _execute",
" result = method(*self.path_args, **self.path_kwargs)",
" File \"sock2.py\", line 33, in post",
" import lambda_func",
" File \"/handler/lambda_func.py\", line 3, in ",
" import simplejson",
"ModuleNotFoundError: No module named 'simplejson'",
"2019/07/03 22:01:59 Pause() [SB 12]",
"2019/07/03 22:01:59 received kill signal, cleaning up",
"2019/07/03 22:01:59 Destroy() [SB 1]",
"2019/07/03 22:01:59 kill all procs in CG [SOCK 1]",
"2019/07/03 22:01:59 unmount and remove dirs [SOCK 1]",
"2019/07/03 22:01:59 SOCKPool.Cleanup: make sure all memory is free",
"2019/07/03 22:01:59 SOCKPool.Cleanup: memory pool emptied",
"2019/07/03 22:01:59 received shutdown request [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:01:59 empty queues and release CGs [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:02:00 remove /sys/fs/cgroup/blkio/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:02:00 remove /sys/fs/cgroup/cpu/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:02:00 remove /sys/fs/cgroup/devices/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:02:00 remove /sys/fs/cgroup/freezer/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:02:00 remove /sys/fs/cgroup/hugetlb/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:02:00 remove /sys/fs/cgroup/memory/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:02:00 remove /sys/fs/cgroup/perf_event/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:02:00 remove /sys/fs/cgroup/systemd/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:02:00 remove /sys/fs/cgroup/pids/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"Kill function: install32019/07/03 22:02:00 Destroy() [SB 12]",
"2019/07/03 22:02:00 kill all procs in CG [SOCK 12]",
"2019/07/03 22:02:00 unmount and remove dirs [SOCK 12]",
"Kill function: echo2019/07/03 22:02:00 Destroy() [SB 2]",
"Kill function: install2019/07/03 22:02:00 Destroy() [SB 9]",
"2019/07/03 22:02:00 kill all procs in CG [SOCK 9]",
"2019/07/03 22:02:00 unmount and remove dirs [SOCK 9]",
"Kill function: install22019/07/03 22:02:00 Destroy() [SB 10]",
"2019/07/03 22:02:00 kill all procs in CG [SOCK 10]",
"2019/07/03 22:02:00 unmount and remove dirs [SOCK 10]",
"2019/07/03 22:02:00 SOCKPool.Cleanup: make sure all memory is free",
"2019/07/03 22:02:00 SOCKPool.Cleanup: memory pool emptied",
"2019/07/03 22:02:00 received shutdown request [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:00 empty queues and release CGs [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:00 remove /sys/fs/cgroup/blkio/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:00 remove /sys/fs/cgroup/cpu/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:00 remove /sys/fs/cgroup/devices/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:00 remove /sys/fs/cgroup/freezer/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:00 remove /sys/fs/cgroup/hugetlb/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:00 remove /sys/fs/cgroup/memory/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:00 remove /sys/fs/cgroup/perf_event/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:00 remove /sys/fs/cgroup/systemd/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:00 remove /sys/fs/cgroup/pids/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:00 save stats to /root/open-lambda/test-dir/worker/stats.json",
"2019/07/03 22:02:00 remove worker.pid",
"2019/07/03 22:02:00 exiting",
""
]
}
POP conf: {'handler_cache_mb': 100, 'import_cache_mb': 250}
PUSH conf: {'handler_cache_mb': 250, 'import_cache_mb': 250}
========================================
smoke_tests
========================================
RUN ./ol worker -p=test-dir --detach
b'using existing OL directory at /root/open-lambda/test-dir\nStarting worker: pid=7715, port=5000, log=/root/open-lambda/test-dir/worker.out\nready\n'
RUN ./ol kill -p=test-dir
b'Kill worker process with PID 7715\n'
{
"test": "smoke_tests",
"params": {},
"pass": false,
"seconds": null,
"total_seconds": 333.62132358551025,
"stats": null,
"ol-stats": {
"Channel():ms.avg": 0,
"Channel():ms.cnt": 11,
"Create()/acquire-cgroup:ms.avg": 0,
"Create()/acquire-cgroup:ms.cnt": 12,
"Create()/acquire-mem:ms.avg": 0,
"Create()/acquire-mem:ms.cnt": 12,
"Create()/fork-proc:ms.avg": 8,
"Create()/fork-proc:ms.cnt": 4,
"Create()/fresh-proc:ms.avg": 145,
"Create()/fresh-proc:ms.cnt": 8,
"Create()/make-root-fs:ms.avg": 1,
"Create()/make-root-fs:ms.cnt": 12,
"Create():ms.avg": 101,
"Create():ms.cnt": 12,
"Destroy()/detach-root:ms.avg": 0,
"Destroy()/detach-root:ms.cnt": 12,
"Destroy()/kill-procs:ms.avg": 3,
"Destroy()/kill-procs:ms.cnt": 12,
"Destroy()/remove-root:ms.avg": 0,
"Destroy()/remove-root:ms.cnt": 12,
"Destroy():ms.avg": 3,
"Destroy():ms.cnt": 12,
"Pause():ms.avg": 4,
"Pause():ms.cnt": 4,
"fork():ms.avg": 8,
"fork():ms.cnt": 4,
"forkRequest:ms.avg": 4,
"forkRequest:ms.cnt": 4,
"move-to-cg-after-fork:ms.avg": 3,
"move-to-cg-after-fork:ms.cnt": 4,
"pip-install:ms.avg": 47546,
"pip-install:ms.cnt": 7
},
"conf": {
"SOCK_base_path": "/root/open-lambda/test-dir/lambda",
"Skip_pull_existing": false,
"worker_dir": "/root/open-lambda/test-dir/worker",
"Pkgs_dir": "/root/open-lambda/test-dir/lambda/packages",
"import_cache_mb": 250,
"sock_cgroups": {
"max_procs": 10,
"max_mem_mb": 50
},
"server_mode": "lambda",
"pip_mirror": "",
"sandbox": "sock",
"registry_cache_ms": 5000,
"handler_cache_mb": 250,
"cluster_name": "/root/open-lambda/test-dir",
"docker_runtime": "",
"sandbox_config": {},
"registry": "/root/open-lambda/test-registry",
"worker_port": "5000"
},
"errors": [
[
"Traceback (most recent call last):",
" File \"test.py\", line 76, in wrapper",
" rv = fn(**kwargs)",
" File \"test.py\", line 193, in smoke_tests",
" raise Exception(\"STATUS %d: %s\" % (r.status_code, r.text))",
"Exception: STATUS 500: 500: Internal Server Error500: Internal Server Error",
""
]
],
"worker_tail": [
"using existing OL directory at /root/open-lambda/test-dir",
"2019/07/03 22:02:00 save PID 7715 to file /root/open-lambda/test-dir/worker/worker.pid",
"2019/07/03 22:02:00 Start Lambda Server",
"2019/07/03 22:02:00 Create SandboxPool",
"2019/07/03 22:02:00 create /sys/fs/cgroup/blkio/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:00 create /sys/fs/cgroup/cpu/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:00 create /sys/fs/cgroup/devices/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:00 create /sys/fs/cgroup/freezer/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:00 create /sys/fs/cgroup/hugetlb/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:00 create /sys/fs/cgroup/memory/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:00 create /sys/fs/cgroup/perf_event/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:00 create /sys/fs/cgroup/systemd/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:00 create /sys/fs/cgroup/pids/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:00 Create ModulePuller",
"2019/07/03 22:02:00 Create HandlerPuller",
"2019/07/03 22:02:00 Create ImportCache",
"2019/07/03 22:02:00 create /sys/fs/cgroup/blkio/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:02:00 create /sys/fs/cgroup/cpu/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:02:00 create /sys/fs/cgroup/devices/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:02:00 create /sys/fs/cgroup/freezer/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:02:00 create /sys/fs/cgroup/hugetlb/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:02:00 create /sys/fs/cgroup/memory/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:02:00 create /sys/fs/cgroup/perf_event/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:02:00 create /sys/fs/cgroup/systemd/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:02:00 create /sys/fs/cgroup/pids/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:02:00 Setups Handlers",
"2019/07/03 22:02:00 Execute handler by POSTing to localhost:5000/run/",
"2019/07/03 22:02:00 Get status by sending request to localhost:5000/status",
"2019/07/03 22:02:00 start creating/serving CGs [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:00 start creating/serving CGs [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:02:00 .Create(, false, , /root/open-lambda/test-dir/worker/scratch/import-cache-1001, )...",
"2019/07/03 22:02:00 Receive request to /pid",
"2019/07/03 22:02:00 Receive request to /run/echo",
"2019/07/03 22:02:00 debug: LambdaFunc.Task() runs on goroutine 22 [FUNC echo]",
"2019/07/03 22:02:00 increase instances to 1 [FUNC echo]",
"2019/07/03 22:02:00 ...returns &{0xc0001a9500 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:02:00 .Create(&{0xc0001a9500 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/1-echo, /root/open-lambda/test-dir/worker/scratch/func-echo-1002, &{[] []})...",
"2019/07/03 22:02:00 fork(&{0xc000082690 2 /root/open-lambda/test-dir/worker/sock-handlers/2 /root/open-lambda/test-dir/worker/lambda_code/1-echo /root/open-lambda/test-dir/worker/scratch/func-echo-1002 0xc00000f260}) [SB 1]",
"2019/07/03 22:02:00 ...returns &{0xc0001d0660 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:02:00 Channel() [SB 2]",
"2019/07/03 22:02:00 Pause() [SB 2]",
"2019/07/03 22:02:00 Receive request to /run/install",
"2019/07/03 22:02:00 debug: LambdaFunc.Task() runs on goroutine 33 [FUNC install]",
"2019/07/03 22:02:00 run pip install parso from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/parso on host",
"2019/07/03 22:02:00 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/parso, )...",
"2019/07/03 22:02:00 ...returns &{0xc0001d1bc0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:02:00 Channel() [SB 3]",
"Collecting parso",
" Downloading https://files.pythonhosted.org/packages/68/59/482f5a00fe3da7f0aaeedf61c2a25c445b68c9124437195f6e8b2beddbc0/parso-0.5.0-py2.py3-none-any.whl (94kB)",
"Installing collected packages: parso",
"Successfully installed parso-0.5.0",
"2019/07/03 22:02:01 Destroy() [SB 3]",
"2019/07/03 22:02:01 kill all procs in CG [SOCK 3]",
"2019/07/03 22:02:01 waiting for 1 procs in cg-2 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:01 unmount and remove dirs [SOCK 3]",
"2019/07/03 22:02:01 run pip install jedi from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/jedi on host",
"2019/07/03 22:02:01 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/jedi, )...",
"2019/07/03 22:02:01 ...returns &{0xc0002008a0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:02:01 Channel() [SB 4]",
"Collecting jedi",
" Downloading https://files.pythonhosted.org/packages/68/42/6309f3871b2f8361764ac5b2fe6719f9c6e6561d9307d8cecda319cf5843/jedi-0.14.0-py2.py3-none-any.whl (1.0MB)",
"Installing collected packages: jedi",
"Successfully installed jedi-0.14.0",
"2019/07/03 22:02:02 Destroy() [SB 4]",
"2019/07/03 22:02:02 kill all procs in CG [SOCK 4]",
"2019/07/03 22:02:02 waiting for 1 procs in cg-3 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:02 unmount and remove dirs [SOCK 4]",
"2019/07/03 22:02:02 run pip install idna from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/idna on host",
"2019/07/03 22:02:02 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/idna, )...",
"2019/07/03 22:02:02 ...returns &{0xc000201500 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:02:02 Channel() [SB 5]",
"Collecting idna",
" Downloading https://files.pythonhosted.org/packages/14/2c/cd551d81dbe15200be1cf41cd03869a46fe7226e7450af7a6545bfc474c9/idna-2.8-py2.py3-none-any.whl (58kB)",
"Installing collected packages: idna",
"Successfully installed idna-2.8",
"2019/07/03 22:02:03 Destroy() [SB 5]",
"2019/07/03 22:02:03 kill all procs in CG [SOCK 5]",
"2019/07/03 22:02:03 waiting for 1 procs in cg-4 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:03 unmount and remove dirs [SOCK 5]",
"2019/07/03 22:02:03 run pip install chardet from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/chardet on host",
"2019/07/03 22:02:03 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/chardet, )...",
"2019/07/03 22:02:03 ...returns &{0xc000228180 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:02:03 Channel() [SB 6]",
"Collecting chardet",
" Using cached https://files.pythonhosted.org/packages/bc/a9/01ffebfb562e4274b6487b4bb1ddec7ca55ec7510b22e4c51f14098443b8/chardet-3.0.4-py2.py3-none-any.whl",
"Installing collected packages: chardet",
"Successfully installed chardet-3.0.4",
"2019/07/03 22:02:04 Destroy() [SB 6]",
"2019/07/03 22:02:04 kill all procs in CG [SOCK 6]",
"2019/07/03 22:02:04 waiting for 1 procs in cg-5 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:04 unmount and remove dirs [SOCK 6]",
"2019/07/03 22:02:04 run pip install certifi from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/certifi on host",
"2019/07/03 22:02:04 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/certifi, )...",
"2019/07/03 22:02:04 ...returns &{0xc000228de0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:02:04 Channel() [SB 7]",
"Collecting certifi",
" Using cached https://files.pythonhosted.org/packages/69/1b/b853c7a9d4f6a6d00749e94eb6f3a041e342a885b87340b79c1ef73e3a78/certifi-2019.6.16-py2.py3-none-any.whl",
"Installing collected packages: certifi",
"Successfully installed certifi-2019.6.16",
"2019/07/03 22:02:04 Destroy() [SB 7]",
"2019/07/03 22:02:04 kill all procs in CG [SOCK 7]",
"2019/07/03 22:02:04 waiting for 1 procs in cg-6 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:04 unmount and remove dirs [SOCK 7]",
"2019/07/03 22:02:04 run pip install requests from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/requests on host",
"2019/07/03 22:02:04 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/requests, )...",
"2019/07/03 22:02:04 ...returns &{0xc000229a40 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:02:04 Channel() [SB 8]",
"Collecting requests",
" Using cached https://files.pythonhosted.org/packages/51/bd/23c926cd341ea6b7dd0b2a00aba99ae0f828be89d72b2190f27c11d4b7fb/requests-2.22.0-py2.py3-none-any.whl",
"Installing collected packages: requests",
"Successfully installed requests-2.22.0",
"2019/07/03 22:02:05 Destroy() [SB 8]",
"2019/07/03 22:02:05 kill all procs in CG [SOCK 8]",
"2019/07/03 22:02:05 waiting for 1 procs in cg-7 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:02:05 unmount and remove dirs [SOCK 8]",
"2019/07/03 22:02:05 increase instances to 1 [FUNC install]",
"2019/07/03 22:02:05 .Create(&{0xc0001a9500 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/2-install, /root/open-lambda/test-dir/worker/scratch/func-install-1003, &{[parso jedi idna chardet certifi requests] [parso jedi idna chardet certifi requests urllib3]})...",
"2019/07/03 22:02:05 fork(&{0xc000082690 9 /root/open-lambda/test-dir/worker/sock-handlers/9 /root/open-lambda/test-dir/worker/lambda_code/2-install /root/open-lambda/test-dir/worker/scratch/func-install-1003 0xc00000f340}) [SB 1]",
"2019/07/03 22:02:05 ...returns &{0xc000240720 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:02:05 Channel() [SB 9]",
"2019/07/03 22:02:05 Pause() [SB 9]",
"2019/07/03 22:02:05 Receive request to /stats",
"2019/07/03 22:02:05 Receive request to /run/install2",
"2019/07/03 22:02:05 debug: LambdaFunc.Task() runs on goroutine 63 [FUNC install2]",
"2019/07/03 22:02:05 skip installing parso, already installed during this run of OL",
"2019/07/03 22:02:05 skip installing jedi, already installed during this run of OL",
"2019/07/03 22:02:05 skip installing idna, already installed during this run of OL",
"2019/07/03 22:02:05 skip installing chardet, already installed during this run of OL",
"2019/07/03 22:02:05 skip installing certifi, already installed during this run of OL",
"2019/07/03 22:02:05 skip installing requests, already installed during this run of OL",
"2019/07/03 22:02:05 increase instances to 1 [FUNC install2]",
"2019/07/03 22:02:05 .Create(&{0xc0001a9500 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/3-install2, /root/open-lambda/test-dir/worker/scratch/func-install2-1004, &{[parso jedi idna chardet certifi requests] [parso jedi idna chardet certifi requests urllib3]})...",
"2019/07/03 22:02:05 fork(&{0xc000082690 10 /root/open-lambda/test-dir/worker/sock-handlers/10 /root/open-lambda/test-dir/worker/lambda_code/3-install2 /root/open-lambda/test-dir/worker/scratch/func-install2-1004 0xc00000f360}) [SB 1]",
"2019/07/03 22:02:05 ...returns &{0xc000241d40 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:02:05 Channel() [SB 10]",
"2019/07/03 22:02:05 Pause() [SB 10]",
"2019/07/03 22:02:05 Receive request to /stats",
"2019/07/03 22:02:05 Receive request to /run/install3",
"2019/07/03 22:02:05 debug: LambdaFunc.Task() runs on goroutine 75 [FUNC install3]",
"2019/07/03 22:02:05 skip installing parso, already installed during this run of OL",
"2019/07/03 22:02:05 skip installing jedi, already installed during this run of OL",
"2019/07/03 22:02:05 skip installing idna, already installed during this run of OL",
"2019/07/03 22:02:05 skip installing chardet, already installed during this run of OL",
"2019/07/03 22:02:05 skip installing certifi, already installed during this run of OL",
"2019/07/03 22:02:05 skip installing requests, already installed during this run of OL",
"2019/07/03 22:02:05 run pip install simplejson from a new Sandbox to /root/open-lambda/test-dir/lambda/packages/simplejson on host",
"2019/07/03 22:02:05 .Create(, true, /root/open-lambda/test-dir/worker/admin-lambdas/pip-install, /root/open-lambda/test-dir/lambda/packages/simplejson, )...",
"2019/07/03 22:02:05 ...returns &{0xc00027b260 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:02:05 Channel() [SB 11]",
"Collecting simplejson",
" Downloading https://files.pythonhosted.org/packages/e3/24/c35fb1c1c315fc0fffe61ea00d3f88e85469004713dab488dee4f35b0aff/simplejson-3.16.0.tar.gz (81kB)",
"Building wheels for collected packages: simplejson",
" WARNING: Building wheel for simplejson failed: [Errno 30] Read-only file system: '/root/.cache/pip/wheels/5d'",
"Failed to build simplejson",
"Installing collected packages: simplejson",
" Running setup.py install for simplejson: started",
"Killed",
"2019/07/03 22:07:33 Destroy() [SB 11]",
"2019/07/03 22:07:33 kill all procs in CG [SOCK 11]",
"2019/07/03 22:07:33 waiting for 3 procs in cg-10 to die [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:07:33 unmount and remove dirs [SOCK 11]",
"2019/07/03 22:07:33 increase instances to 1 [FUNC install3]",
"2019/07/03 22:07:33 .Create(&{0xc0001a9500 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/4-install3, /root/open-lambda/test-dir/worker/scratch/func-install3-1005, &{[parso jedi idna chardet certifi requests simplejson] [parso jedi idna chardet certifi requests simplejson urllib3]})...",
"2019/07/03 22:07:33 fork(&{0xc000082690 12 /root/open-lambda/test-dir/worker/sock-handlers/12 /root/open-lambda/test-dir/worker/lambda_code/4-install3 /root/open-lambda/test-dir/worker/scratch/func-install3-1005 0xc00000f3a0}) [SB 1]",
"2019/07/03 22:07:33 ...returns &{0xc0002b6000 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:07:33 Channel() [SB 12]",
"ERROR:tornado.application:Uncaught exception POST /run/install3 (0.0.0.0)",
"HTTPServerRequest(protocol='http', host='localhost:5000', method='POST', uri='/run/install3', version='HTTP/1.1', remote_ip='0.0.0.0', headers={'Host': 'localhost:5000', 'User-Agent': 'python-requests/2.9.1', 'Content-Length': '2', 'Accept': '*/*', 'Accept-Encoding': 'gzip, deflate', 'X-Forwarded-For': '127.0.0.1'})",
"Traceback (most recent call last):",
" File \"/usr/local/lib/python3.6/dist-packages/tornado/web.py\", line 1510, in _execute",
" result = method(*self.path_args, **self.path_kwargs)",
" File \"sock2.py\", line 33, in post",
" import lambda_func",
" File \"/handler/lambda_func.py\", line 3, in ",
" import simplejson",
"ModuleNotFoundError: No module named 'simplejson'",
"2019/07/03 22:07:33 Pause() [SB 12]",
"2019/07/03 22:07:33 received kill signal, cleaning up",
"2019/07/03 22:07:33 Destroy() [SB 1]",
"2019/07/03 22:07:33 kill all procs in CG [SOCK 1]",
"2019/07/03 22:07:33 unmount and remove dirs [SOCK 1]",
"2019/07/03 22:07:33 SOCKPool.Cleanup: make sure all memory is free",
"2019/07/03 22:07:33 SOCKPool.Cleanup: memory pool emptied",
"2019/07/03 22:07:33 received shutdown request [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:07:33 empty queues and release CGs [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:07:33 remove /sys/fs/cgroup/blkio/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:07:33 remove /sys/fs/cgroup/cpu/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:07:33 remove /sys/fs/cgroup/devices/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:07:33 remove /sys/fs/cgroup/freezer/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:07:33 remove /sys/fs/cgroup/hugetlb/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:07:33 remove /sys/fs/cgroup/memory/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:07:33 remove /sys/fs/cgroup/perf_event/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:07:33 remove /sys/fs/cgroup/systemd/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:07:33 remove /sys/fs/cgroup/pids/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"Kill function: echo2019/07/03 22:07:33 Destroy() [SB 2]",
"2019/07/03 22:07:33 kill all procs in CG [SOCK 2]",
"2019/07/03 22:07:33 unmount and remove dirs [SOCK 2]",
"Kill function: install2019/07/03 22:07:33 Destroy() [SB 9]",
"2019/07/03 22:07:33 kill all procs in CG [SOCK 9]",
"2019/07/03 22:07:33 unmount and remove dirs [SOCK 9]",
"Kill function: install22019/07/03 22:07:33 Destroy() [SB 10]",
"2019/07/03 22:07:33 kill all procs in CG [SOCK 10]",
"2019/07/03 22:07:33 unmount and remove dirs [SOCK 10]",
"Kill function: install32019/07/03 22:07:33 Destroy() [SB 12]",
"2019/07/03 22:07:33 kill all procs in CG [SOCK 12]",
"2019/07/03 22:07:33 unmount and remove dirs [SOCK 12]",
"2019/07/03 22:07:33 SOCKPool.Cleanup: make sure all memory is free",
"2019/07/03 22:07:33 SOCKPool.Cleanup: memory pool emptied",
"2019/07/03 22:07:33 received shutdown request [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:07:33 empty queues and release CGs [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:07:33 remove /sys/fs/cgroup/blkio/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:07:33 remove /sys/fs/cgroup/cpu/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:07:33 remove /sys/fs/cgroup/devices/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:07:33 remove /sys/fs/cgroup/freezer/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:07:33 remove /sys/fs/cgroup/hugetlb/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:07:33 remove /sys/fs/cgroup/memory/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:07:33 remove /sys/fs/cgroup/perf_event/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:07:33 remove /sys/fs/cgroup/systemd/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:07:33 remove /sys/fs/cgroup/pids/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:07:33 save stats to /root/open-lambda/test-dir/worker/stats.json",
"2019/07/03 22:07:33 remove worker.pid",
"2019/07/03 22:07:33 exiting",
""
]
}
POP conf: {'handler_cache_mb': 250, 'import_cache_mb': 250}
PUSH conf: {'handler_cache_mb': 100, 'sandbox': 'docker', 'import_cache_mb': 0}
========================================
smoke_tests
========================================
RUN ./ol worker -p=test-dir --detach
b'using existing OL directory at /root/open-lambda/test-dir\nStarting worker: pid=7866, port=5000, log=/root/open-lambda/test-dir/worker.out\nready\n'
RUN ./ol kill -p=test-dir
b'Kill worker process with PID 7866\n'
{
"test": "smoke_tests",
"params": {},
"pass": true,
"seconds": 20.12663745880127,
"total_seconds": 21.253445863723755,
"stats": null,
"ol-stats": {
"Channel():ms.avg": 0,
"Channel():ms.cnt": 22,
"Create():ms.avg": 815,
"Create():ms.cnt": 11,
"Destroy():ms.avg": 242,
"Destroy():ms.cnt": 22,
"Pause():ms.avg": 29,
"Pause():ms.cnt": 8,
"pip-install:ms.avg": 2132,
"pip-install:ms.cnt": 7
},
"conf": {
"SOCK_base_path": "/root/open-lambda/test-dir/lambda",
"Skip_pull_existing": false,
"worker_port": "5000",
"worker_dir": "/root/open-lambda/test-dir/worker",
"Pkgs_dir": "/root/open-lambda/test-dir/lambda/packages",
"import_cache_mb": 0,
"registry_cache_ms": 5000,
"pip_mirror": "",
"sandbox": "docker",
"server_mode": "lambda",
"handler_cache_mb": 100,
"cluster_name": "/root/open-lambda/test-dir",
"sandbox_config": {},
"docker_runtime": "",
"registry": "/root/open-lambda/test-registry",
"sock_cgroups": {
"max_procs": 10,
"max_mem_mb": 50
}
},
"errors": [],
"worker_tail": [
"Kill function: install32019/07/03 22:07:54 Destroy() [SB 10]",
"2019/07/03 22:07:54 Destroy() [SB 10]",
"Kill function: echo2019/07/03 22:07:54 Destroy() [SB 0]",
"2019/07/03 22:07:54 Destroy() [SB 0]",
"Kill function: install2019/07/03 22:07:54 Destroy() [SB 7]",
"2019/07/03 22:07:54 Destroy() [SB 7]",
"2019/07/03 22:07:54 save stats to /root/open-lambda/test-dir/worker/stats.json",
"2019/07/03 22:07:54 remove worker.pid",
"2019/07/03 22:07:54 exiting",
""
]
}
POP conf: {'handler_cache_mb': 100, 'sandbox': 'docker', 'import_cache_mb': 0}
PUSH conf: {'handler_cache_mb': 250, 'sandbox': 'docker', 'import_cache_mb': 0}
========================================
smoke_tests
========================================
RUN ./ol worker -p=test-dir --detach
b'using existing OL directory at /root/open-lambda/test-dir\nStarting worker: pid=10548, port=5000, log=/root/open-lambda/test-dir/worker.out\nready\n'
RUN ./ol kill -p=test-dir
b'Kill worker process with PID 10548\n'
{
"test": "smoke_tests",
"params": {},
"pass": true,
"seconds": 14.18065357208252,
"total_seconds": 15.20567512512207,
"stats": null,
"ol-stats": {
"Channel():ms.avg": 0,
"Channel():ms.cnt": 22,
"Create():ms.avg": 542,
"Create():ms.cnt": 11,
"Destroy():ms.avg": 200,
"Destroy():ms.cnt": 22,
"Pause():ms.avg": 28,
"Pause():ms.cnt": 8,
"pip-install:ms.avg": 1671,
"pip-install:ms.cnt": 7
},
"conf": {
"SOCK_base_path": "/root/open-lambda/test-dir/lambda",
"Skip_pull_existing": false,
"worker_dir": "/root/open-lambda/test-dir/worker",
"Pkgs_dir": "/root/open-lambda/test-dir/lambda/packages",
"import_cache_mb": 0,
"sock_cgroups": {
"max_procs": 10,
"max_mem_mb": 50
},
"server_mode": "lambda",
"pip_mirror": "",
"sandbox": "docker",
"registry_cache_ms": 5000,
"handler_cache_mb": 250,
"cluster_name": "/root/open-lambda/test-dir",
"docker_runtime": "",
"sandbox_config": {},
"registry": "/root/open-lambda/test-registry",
"worker_port": "5000"
},
"errors": [],
"worker_tail": [
"Kill function: echo2019/07/03 22:08:09 Destroy() [SB 0]",
"2019/07/03 22:08:09 Destroy() [SB 0]",
"Kill function: install2019/07/03 22:08:09 Destroy() [SB 7]",
"2019/07/03 22:08:09 Destroy() [SB 7]",
"Kill function: install22019/07/03 22:08:09 Destroy() [SB 8]",
"2019/07/03 22:08:09 Destroy() [SB 8]",
"2019/07/03 22:08:10 save stats to /root/open-lambda/test-dir/worker/stats.json",
"2019/07/03 22:08:10 remove worker.pid",
"2019/07/03 22:08:10 exiting",
""
]
}
POP conf: {'handler_cache_mb': 250, 'sandbox': 'docker', 'import_cache_mb': 0}
========================================
fork_bomb
========================================
RUN ./ol worker -p=test-dir --detach
b'using existing OL directory at /root/open-lambda/test-dir\nStarting worker: pid=13224, port=5000, log=/root/open-lambda/test-dir/worker.out\nready\n'
RUN ./ol kill -p=test-dir
b'Kill worker process with PID 13224\n'
{
"test": "fork_bomb",
"params": {},
"pass": true,
"seconds": 0.08835411071777344,
"total_seconds": 0.3279383182525635,
"stats": null,
"ol-stats": {
"Channel():ms.avg": 0,
"Channel():ms.cnt": 1,
"Create()/acquire-cgroup:ms.avg": 0,
"Create()/acquire-cgroup:ms.cnt": 2,
"Create()/acquire-mem:ms.avg": 0,
"Create()/acquire-mem:ms.cnt": 2,
"Create()/fork-proc:ms.avg": 8,
"Create()/fork-proc:ms.cnt": 1,
"Create()/fresh-proc:ms.avg": 148,
"Create()/fresh-proc:ms.cnt": 1,
"Create()/make-root-fs:ms.avg": 2,
"Create()/make-root-fs:ms.cnt": 2,
"Create():ms.avg": 81,
"Create():ms.cnt": 2,
"Destroy()/detach-root:ms.avg": 1,
"Destroy()/detach-root:ms.cnt": 2,
"Destroy()/kill-procs:ms.avg": 0,
"Destroy()/kill-procs:ms.cnt": 2,
"Destroy()/remove-root:ms.avg": 0,
"Destroy()/remove-root:ms.cnt": 2,
"Destroy():ms.avg": 3,
"Destroy():ms.cnt": 2,
"Pause():ms.avg": 4,
"Pause():ms.cnt": 1,
"fork():ms.avg": 8,
"fork():ms.cnt": 1,
"forkRequest:ms.avg": 6,
"forkRequest:ms.cnt": 1,
"move-to-cg-after-fork:ms.avg": 2,
"move-to-cg-after-fork:ms.cnt": 1
},
"conf": {
"SOCK_base_path": "/root/open-lambda/test-dir/lambda",
"Skip_pull_existing": false,
"worker_port": "5000",
"worker_dir": "/root/open-lambda/test-dir/worker",
"Pkgs_dir": "/root/open-lambda/test-dir/lambda/packages",
"import_cache_mb": 239,
"registry_cache_ms": 5000,
"pip_mirror": "",
"sandbox": "sock",
"server_mode": "lambda",
"handler_cache_mb": 239,
"cluster_name": "/root/open-lambda/test-dir",
"sandbox_config": {},
"docker_runtime": "",
"registry": "/root/open-lambda/test-registry",
"sock_cgroups": {
"max_procs": 10,
"max_mem_mb": 50
}
},
"errors": [],
"worker_tail": [
"2019/07/03 22:08:10 remove /sys/fs/cgroup/freezer/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:10 remove /sys/fs/cgroup/hugetlb/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:10 remove /sys/fs/cgroup/memory/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:10 remove /sys/fs/cgroup/perf_event/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:10 remove /sys/fs/cgroup/systemd/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:10 remove /sys/fs/cgroup/pids/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:10 save stats to /root/open-lambda/test-dir/worker/stats.json",
"2019/07/03 22:08:10 remove worker.pid",
"2019/07/03 22:08:10 exiting",
""
]
}
========================================
max_mem_alloc
========================================
RUN ./ol worker -p=test-dir --detach
b'using existing OL directory at /root/open-lambda/test-dir\nStarting worker: pid=13267, port=5000, log=/root/open-lambda/test-dir/worker.out\nready\n'
RUN ./ol kill -p=test-dir
b'Kill worker process with PID 13267\n'
{
"test": "max_mem_alloc",
"params": {},
"pass": true,
"seconds": 0.9103634357452393,
"total_seconds": 1.1483237743377686,
"stats": null,
"ol-stats": {
"Channel():ms.avg": 0,
"Channel():ms.cnt": 1,
"Create()/acquire-cgroup:ms.avg": 0,
"Create()/acquire-cgroup:ms.cnt": 2,
"Create()/acquire-mem:ms.avg": 0,
"Create()/acquire-mem:ms.cnt": 2,
"Create()/fork-proc:ms.avg": 8,
"Create()/fork-proc:ms.cnt": 1,
"Create()/fresh-proc:ms.avg": 150,
"Create()/fresh-proc:ms.cnt": 1,
"Create()/make-root-fs:ms.avg": 4,
"Create()/make-root-fs:ms.cnt": 2,
"Create():ms.avg": 83,
"Create():ms.cnt": 2,
"Destroy()/detach-root:ms.avg": 1,
"Destroy()/detach-root:ms.cnt": 2,
"Destroy()/kill-procs:ms.avg": 1,
"Destroy()/kill-procs:ms.cnt": 2,
"Destroy()/remove-root:ms.avg": 0,
"Destroy()/remove-root:ms.cnt": 2,
"Destroy():ms.avg": 2,
"Destroy():ms.cnt": 2,
"Pause():ms.avg": 4,
"Pause():ms.cnt": 1,
"fork():ms.avg": 8,
"fork():ms.cnt": 1,
"forkRequest:ms.avg": 7,
"forkRequest:ms.cnt": 1,
"move-to-cg-after-fork:ms.avg": 1,
"move-to-cg-after-fork:ms.cnt": 1
},
"conf": {
"SOCK_base_path": "/root/open-lambda/test-dir/lambda",
"Skip_pull_existing": false,
"worker_port": "5000",
"worker_dir": "/root/open-lambda/test-dir/worker",
"Pkgs_dir": "/root/open-lambda/test-dir/lambda/packages",
"import_cache_mb": 239,
"registry_cache_ms": 5000,
"pip_mirror": "",
"sandbox": "sock",
"server_mode": "lambda",
"handler_cache_mb": 239,
"cluster_name": "/root/open-lambda/test-dir",
"sandbox_config": {},
"docker_runtime": "",
"registry": "/root/open-lambda/test-registry",
"sock_cgroups": {
"max_procs": 10,
"max_mem_mb": 50
}
},
"errors": [],
"worker_tail": [
"2019/07/03 22:08:11 remove /sys/fs/cgroup/freezer/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:11 remove /sys/fs/cgroup/hugetlb/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:11 remove /sys/fs/cgroup/memory/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:11 remove /sys/fs/cgroup/perf_event/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:11 remove /sys/fs/cgroup/systemd/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:11 remove /sys/fs/cgroup/pids/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:11 save stats to /root/open-lambda/test-dir/worker/stats.json",
"2019/07/03 22:08:11 remove worker.pid",
"2019/07/03 22:08:11 exiting",
""
]
}
PUSH conf: {'import_cache_mb': 0, 'handler_cache_mb': 500, 'sock_cgroups': {'max_mem_mb': 250}}
========================================
numpy_test
========================================
RUN ./ol worker -p=test-dir --detach
b'using existing OL directory at /root/open-lambda/test-dir\nStarting worker: pid=13350, port=5000, log=/root/open-lambda/test-dir/worker.out\nready\n'
RUN ./ol kill -p=test-dir
b'Kill worker process with PID 13350\n'
{
"test": "numpy_test",
"params": {},
"pass": true,
"seconds": 13.071873188018799,
"total_seconds": 13.335476875305176,
"stats": null,
"ol-stats": {
"Channel():ms.avg": 0,
"Channel():ms.cnt": 5,
"Create()/acquire-cgroup:ms.avg": 0,
"Create()/acquire-cgroup:ms.cnt": 5,
"Create()/acquire-mem:ms.avg": 0,
"Create()/acquire-mem:ms.cnt": 5,
"Create()/fresh-proc:ms.avg": 298,
"Create()/fresh-proc:ms.cnt": 5,
"Create()/make-root-fs:ms.avg": 15,
"Create()/make-root-fs:ms.cnt": 5,
"Create():ms.avg": 314,
"Create():ms.cnt": 5,
"Destroy()/detach-root:ms.avg": 0,
"Destroy()/detach-root:ms.cnt": 5,
"Destroy()/kill-procs:ms.avg": 3,
"Destroy()/kill-procs:ms.cnt": 5,
"Destroy()/remove-root:ms.avg": 0,
"Destroy()/remove-root:ms.cnt": 5,
"Destroy():ms.avg": 3,
"Destroy():ms.cnt": 6,
"Pause():ms.avg": 3,
"Pause():ms.cnt": 3,
"evict:ms.avg": 7,
"evict:ms.cnt": 1,
"pip-install:ms.avg": 5702,
"pip-install:ms.cnt": 2
},
"conf": {
"SOCK_base_path": "/root/open-lambda/test-dir/lambda",
"Skip_pull_existing": false,
"worker_port": "5000",
"worker_dir": "/root/open-lambda/test-dir/worker",
"Pkgs_dir": "/root/open-lambda/test-dir/lambda/packages",
"import_cache_mb": 0,
"registry_cache_ms": 5000,
"pip_mirror": "",
"sandbox": "sock",
"server_mode": "lambda",
"handler_cache_mb": 500,
"cluster_name": "/root/open-lambda/test-dir",
"sandbox_config": {},
"docker_runtime": "",
"registry": "/root/open-lambda/test-registry",
"sock_cgroups": {
"max_procs": 10,
"max_mem_mb": 250
}
},
"errors": [],
"worker_tail": [
"2019/07/03 22:08:24 remove /sys/fs/cgroup/freezer/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:24 remove /sys/fs/cgroup/hugetlb/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:24 remove /sys/fs/cgroup/memory/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:24 remove /sys/fs/cgroup/perf_event/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:24 remove /sys/fs/cgroup/systemd/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:24 remove /sys/fs/cgroup/pids/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:24 save stats to /root/open-lambda/test-dir/worker/stats.json",
"2019/07/03 22:08:24 remove worker.pid",
"2019/07/03 22:08:24 exiting",
""
]
}
POP conf: {'import_cache_mb': 0, 'handler_cache_mb': 500, 'sock_cgroups': {'max_mem_mb': 250}}
POP conf: {'registry': '/root/open-lambda/test-registry'}
PUSH conf: {'server_mode': 'sock'}
========================================
sock_churn {'fork': True, 'seconds': 15, 'procs': 1, 'baseline': 0}
========================================
RUN ./ol worker -p=test-dir --detach
b'using existing OL directory at /root/open-lambda/test-dir\nStarting worker: pid=13412, port=5000, log=/root/open-lambda/test-dir/worker.out\nready\n'
RUN ./ol kill -p=test-dir
b'Kill worker process with PID 13412\n'
{
"test": "sock_churn",
"params": {
"fork": true,
"seconds": 15,
"procs": 1,
"baseline": 0
},
"pass": true,
"seconds": 15.167975425720215,
"total_seconds": 15.391802310943604,
"stats": {
"sandboxes_per_sec": 41.93333333333333
},
"ol-stats": {
"Create()/acquire-cgroup:ms.avg": 0,
"Create()/acquire-cgroup:ms.cnt": 630,
"Create()/acquire-mem:ms.avg": 0,
"Create()/acquire-mem:ms.cnt": 630,
"Create()/fork-proc:ms.avg": 7,
"Create()/fork-proc:ms.cnt": 629,
"Create()/fresh-proc:ms.avg": 138,
"Create()/fresh-proc:ms.cnt": 1,
"Create()/make-root-fs:ms.avg": 3,
"Create()/make-root-fs:ms.cnt": 630,
"Create():ms.avg": 11,
"Create():ms.cnt": 630,
"Destroy()/detach-root:ms.avg": 1,
"Destroy()/detach-root:ms.cnt": 630,
"Destroy()/kill-procs:ms.avg": 1,
"Destroy()/kill-procs:ms.cnt": 630,
"Destroy()/remove-root:ms.avg": 0,
"Destroy()/remove-root:ms.cnt": 630,
"Destroy():ms.avg": 1,
"Destroy():ms.cnt": 1259,
"fork():ms.avg": 7,
"fork():ms.cnt": 629,
"forkRequest:ms.avg": 6,
"forkRequest:ms.cnt": 629,
"move-to-cg-after-fork:ms.avg": 0,
"move-to-cg-after-fork:ms.cnt": 629
},
"conf": {
"SOCK_base_path": "/root/open-lambda/test-dir/lambda",
"Skip_pull_existing": false,
"worker_dir": "/root/open-lambda/test-dir/worker",
"Pkgs_dir": "/root/open-lambda/test-dir/lambda/packages",
"import_cache_mb": 239,
"sock_cgroups": {
"max_procs": 10,
"max_mem_mb": 50
},
"server_mode": "sock",
"pip_mirror": "",
"sandbox": "sock",
"registry_cache_ms": 5000,
"handler_cache_mb": 239,
"cluster_name": "/root/open-lambda/test-dir",
"docker_runtime": "",
"sandbox_config": {},
"registry": "/root/open-lambda/test-dir/registry",
"worker_port": "5000"
},
"errors": [],
"worker_tail": [
"2019/07/03 22:08:40 remove /sys/fs/cgroup/freezer/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:40 remove /sys/fs/cgroup/hugetlb/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:40 remove /sys/fs/cgroup/memory/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:40 remove /sys/fs/cgroup/perf_event/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:40 remove /sys/fs/cgroup/systemd/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:40 remove /sys/fs/cgroup/pids/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:40 save stats to /root/open-lambda/test-dir/worker/stats.json",
"2019/07/03 22:08:40 remove worker.pid",
"2019/07/03 22:08:40 exiting",
""
]
}
========================================
sock_churn {'fork': True, 'seconds': 15, 'procs': 15, 'baseline': 0}
========================================
RUN ./ol worker -p=test-dir --detach
b'using existing OL directory at /root/open-lambda/test-dir\nStarting worker: pid=15959, port=5000, log=/root/open-lambda/test-dir/worker.out\nready\n'
RUN ./ol kill -p=test-dir
b'Kill worker process with PID 15959\n'
{
"test": "sock_churn",
"params": {
"fork": true,
"seconds": 15,
"procs": 15,
"baseline": 0
},
"pass": true,
"seconds": 15.599191427230835,
"total_seconds": 15.835782289505005,
"stats": {
"sandboxes_per_sec": 40.93333333333333
},
"ol-stats": {
"Create()/acquire-cgroup:ms.avg": 0,
"Create()/acquire-cgroup:ms.cnt": 615,
"Create()/acquire-mem:ms.avg": 105,
"Create()/acquire-mem:ms.cnt": 615,
"Create()/fork-proc:ms.avg": 47,
"Create()/fork-proc:ms.cnt": 614,
"Create()/fresh-proc:ms.avg": 140,
"Create()/fresh-proc:ms.cnt": 1,
"Create()/make-root-fs:ms.avg": 3,
"Create()/make-root-fs:ms.cnt": 615,
"Create():ms.avg": 157,
"Create():ms.cnt": 615,
"Destroy()/detach-root:ms.avg": 4,
"Destroy()/detach-root:ms.cnt": 615,
"Destroy()/kill-procs:ms.avg": 7,
"Destroy()/kill-procs:ms.cnt": 615,
"Destroy()/remove-root:ms.avg": 0,
"Destroy()/remove-root:ms.cnt": 615,
"Destroy():ms.avg": 8,
"Destroy():ms.cnt": 1229,
"fork():ms.avg": 47,
"fork():ms.cnt": 614,
"forkRequest:ms.avg": 12,
"forkRequest:ms.cnt": 614,
"move-to-cg-after-fork:ms.avg": 4,
"move-to-cg-after-fork:ms.cnt": 614
},
"conf": {
"SOCK_base_path": "/root/open-lambda/test-dir/lambda",
"Skip_pull_existing": false,
"worker_dir": "/root/open-lambda/test-dir/worker",
"Pkgs_dir": "/root/open-lambda/test-dir/lambda/packages",
"import_cache_mb": 239,
"sock_cgroups": {
"max_procs": 10,
"max_mem_mb": 50
},
"server_mode": "sock",
"pip_mirror": "",
"sandbox": "sock",
"registry_cache_ms": 5000,
"handler_cache_mb": 239,
"cluster_name": "/root/open-lambda/test-dir",
"docker_runtime": "",
"sandbox_config": {},
"registry": "/root/open-lambda/test-dir/registry",
"worker_port": "5000"
},
"errors": [],
"worker_tail": [
"2019/07/03 22:08:56 remove /sys/fs/cgroup/freezer/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:56 remove /sys/fs/cgroup/hugetlb/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:56 remove /sys/fs/cgroup/memory/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:56 remove /sys/fs/cgroup/perf_event/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:56 remove /sys/fs/cgroup/systemd/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:56 remove /sys/fs/cgroup/pids/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:08:56 save stats to /root/open-lambda/test-dir/worker/stats.json",
"2019/07/03 22:08:56 remove worker.pid",
"2019/07/03 22:08:56 exiting",
""
]
}
POP conf: {'server_mode': 'sock'}
PUSH conf: {'registry': '/tmp/tmpxfy11hm8', 'registry_cache_ms': 3000, 'sandbox': 'sock'}
========================================
update_code
========================================
RUN ./ol worker -p=test-dir --detach
b'using existing OL directory at /root/open-lambda/test-dir\nStarting worker: pid=18474, port=5000, log=/root/open-lambda/test-dir/worker.out\nready\n'
RUN ./ol kill -p=test-dir
b'Kill worker process with PID 18474\n'
{
"test": "update_code",
"params": {},
"pass": true,
"seconds": 6.031397819519043,
"total_seconds": 6.2870707511901855,
"stats": null,
"ol-stats": {
"Channel():ms.avg": 0,
"Channel():ms.cnt": 3,
"Create()/acquire-cgroup:ms.avg": 0,
"Create()/acquire-cgroup:ms.cnt": 4,
"Create()/acquire-mem:ms.avg": 0,
"Create()/acquire-mem:ms.cnt": 4,
"Create()/fork-proc:ms.avg": 8,
"Create()/fork-proc:ms.cnt": 3,
"Create()/fresh-proc:ms.avg": 148,
"Create()/fresh-proc:ms.cnt": 1,
"Create()/make-root-fs:ms.avg": 3,
"Create()/make-root-fs:ms.cnt": 4,
"Create():ms.avg": 48,
"Create():ms.cnt": 4,
"Destroy()/detach-root:ms.avg": 0,
"Destroy()/detach-root:ms.cnt": 4,
"Destroy()/kill-procs:ms.avg": 0,
"Destroy()/kill-procs:ms.cnt": 4,
"Destroy()/remove-root:ms.avg": 0,
"Destroy()/remove-root:ms.cnt": 4,
"Destroy():ms.avg": 1,
"Destroy():ms.cnt": 4,
"Pause():ms.avg": 0,
"Pause():ms.cnt": 1645,
"Unpause():ms.avg": 0,
"Unpause():ms.cnt": 1642,
"fork():ms.avg": 8,
"fork():ms.cnt": 3,
"forkRequest:ms.avg": 8,
"forkRequest:ms.cnt": 3,
"move-to-cg-after-fork:ms.avg": 0,
"move-to-cg-after-fork:ms.cnt": 3
},
"conf": {
"SOCK_base_path": "/root/open-lambda/test-dir/lambda",
"Skip_pull_existing": false,
"worker_port": "5000",
"worker_dir": "/root/open-lambda/test-dir/worker",
"Pkgs_dir": "/root/open-lambda/test-dir/lambda/packages",
"import_cache_mb": 239,
"registry_cache_ms": 3000,
"pip_mirror": "",
"sandbox": "sock",
"server_mode": "lambda",
"handler_cache_mb": 239,
"cluster_name": "/root/open-lambda/test-dir",
"sandbox_config": {},
"docker_runtime": "",
"registry": "/tmp/tmpxfy11hm8",
"sock_cgroups": {
"max_procs": 10,
"max_mem_mb": 50
}
},
"errors": [],
"worker_tail": [
"2019/07/03 22:09:02 remove /sys/fs/cgroup/freezer/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:02 remove /sys/fs/cgroup/hugetlb/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:02 remove /sys/fs/cgroup/memory/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:02 remove /sys/fs/cgroup/perf_event/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:02 remove /sys/fs/cgroup/systemd/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:02 remove /sys/fs/cgroup/pids/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:02 save stats to /root/open-lambda/test-dir/worker/stats.json",
"2019/07/03 22:09:02 remove worker.pid",
"2019/07/03 22:09:02 exiting",
""
]
}
POP conf: {'registry': '/tmp/tmpxfy11hm8', 'registry_cache_ms': 3000, 'sandbox': 'sock'}
PUSH conf: {'handler_cache_mb': 250, 'registry': '/root/open-lambda/test-registry', 'sandbox': 'sock', 'import_cache_mb': 250}
========================================
stress_one_lambda {'seconds': 15, 'procs': 1}
========================================
RUN ./ol worker -p=test-dir --detach
b'using existing OL directory at /root/open-lambda/test-dir\nStarting worker: pid=18517, port=5000, log=/root/open-lambda/test-dir/worker.out\nready\n'
RUN ./ol kill -p=test-dir
b'Kill worker process with PID 18517\n'
{
"test": "stress_one_lambda",
"params": {
"seconds": 15,
"procs": 1
},
"pass": true,
"seconds": 15.046754837036133,
"total_seconds": 15.284162998199463,
"stats": {
"reqs_per_sec": 278.73333333333335
},
"ol-stats": {
"Channel():ms.avg": 0,
"Channel():ms.cnt": 3,
"Create()/acquire-cgroup:ms.avg": 0,
"Create()/acquire-cgroup:ms.cnt": 4,
"Create()/acquire-mem:ms.avg": 0,
"Create()/acquire-mem:ms.cnt": 4,
"Create()/fork-proc:ms.avg": 8,
"Create()/fork-proc:ms.cnt": 3,
"Create()/fresh-proc:ms.avg": 154,
"Create()/fresh-proc:ms.cnt": 1,
"Create()/make-root-fs:ms.avg": 4,
"Create()/make-root-fs:ms.cnt": 4,
"Create():ms.avg": 49,
"Create():ms.cnt": 4,
"Destroy()/detach-root:ms.avg": 0,
"Destroy()/detach-root:ms.cnt": 4,
"Destroy()/kill-procs:ms.avg": 0,
"Destroy()/kill-procs:ms.cnt": 4,
"Destroy()/remove-root:ms.avg": 0,
"Destroy()/remove-root:ms.cnt": 4,
"Destroy():ms.avg": 2,
"Destroy():ms.cnt": 4,
"Pause():ms.avg": 0,
"Pause():ms.cnt": 4181,
"Unpause():ms.avg": 0,
"Unpause():ms.cnt": 4178,
"fork():ms.avg": 8,
"fork():ms.cnt": 3,
"forkRequest:ms.avg": 6,
"forkRequest:ms.cnt": 3,
"move-to-cg-after-fork:ms.avg": 1,
"move-to-cg-after-fork:ms.cnt": 3
},
"conf": {
"SOCK_base_path": "/root/open-lambda/test-dir/lambda",
"Skip_pull_existing": false,
"worker_dir": "/root/open-lambda/test-dir/worker",
"Pkgs_dir": "/root/open-lambda/test-dir/lambda/packages",
"import_cache_mb": 250,
"sock_cgroups": {
"max_procs": 10,
"max_mem_mb": 50
},
"server_mode": "lambda",
"pip_mirror": "",
"sandbox": "sock",
"registry_cache_ms": 5000,
"handler_cache_mb": 250,
"cluster_name": "/root/open-lambda/test-dir",
"docker_runtime": "",
"sandbox_config": {},
"registry": "/root/open-lambda/test-registry",
"worker_port": "5000"
},
"errors": [],
"worker_tail": [
"2019/07/03 22:09:17 remove /sys/fs/cgroup/freezer/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:17 remove /sys/fs/cgroup/hugetlb/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:17 remove /sys/fs/cgroup/memory/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:17 remove /sys/fs/cgroup/perf_event/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:17 remove /sys/fs/cgroup/systemd/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:17 remove /sys/fs/cgroup/pids/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:17 save stats to /root/open-lambda/test-dir/worker/stats.json",
"2019/07/03 22:09:17 remove worker.pid",
"2019/07/03 22:09:17 exiting",
""
]
}
========================================
stress_one_lambda {'seconds': 15, 'procs': 2}
========================================
RUN ./ol worker -p=test-dir --detach
b'using existing OL directory at /root/open-lambda/test-dir\nStarting worker: pid=18564, port=5000, log=/root/open-lambda/test-dir/worker.out\nready\n'
RUN ./ol kill -p=test-dir
b'Kill worker process with PID 18564\n'
{
"test": "stress_one_lambda",
"params": {
"seconds": 15,
"procs": 2
},
"pass": true,
"seconds": 15.050872325897217,
"total_seconds": 15.290064096450806,
"stats": {
"reqs_per_sec": 272.8666666666667
},
"ol-stats": {
"Channel():ms.avg": 0,
"Channel():ms.cnt": 3,
"Create()/acquire-cgroup:ms.avg": 0,
"Create()/acquire-cgroup:ms.cnt": 4,
"Create()/acquire-mem:ms.avg": 0,
"Create()/acquire-mem:ms.cnt": 4,
"Create()/fork-proc:ms.avg": 10,
"Create()/fork-proc:ms.cnt": 3,
"Create()/fresh-proc:ms.avg": 167,
"Create()/fresh-proc:ms.cnt": 1,
"Create()/make-root-fs:ms.avg": 3,
"Create()/make-root-fs:ms.cnt": 4,
"Create():ms.avg": 53,
"Create():ms.cnt": 4,
"Destroy()/detach-root:ms.avg": 1,
"Destroy()/detach-root:ms.cnt": 4,
"Destroy()/kill-procs:ms.avg": 1,
"Destroy()/kill-procs:ms.cnt": 4,
"Destroy()/remove-root:ms.avg": 0,
"Destroy()/remove-root:ms.cnt": 4,
"Destroy():ms.avg": 2,
"Destroy():ms.cnt": 4,
"Pause():ms.avg": 0,
"Pause():ms.cnt": 3807,
"Unpause():ms.avg": 0,
"Unpause():ms.cnt": 3804,
"fork():ms.avg": 10,
"fork():ms.cnt": 3,
"forkRequest:ms.avg": 8,
"forkRequest:ms.cnt": 3,
"move-to-cg-after-fork:ms.avg": 1,
"move-to-cg-after-fork:ms.cnt": 3
},
"conf": {
"SOCK_base_path": "/root/open-lambda/test-dir/lambda",
"Skip_pull_existing": false,
"worker_dir": "/root/open-lambda/test-dir/worker",
"Pkgs_dir": "/root/open-lambda/test-dir/lambda/packages",
"import_cache_mb": 250,
"sock_cgroups": {
"max_procs": 10,
"max_mem_mb": 50
},
"server_mode": "lambda",
"pip_mirror": "",
"sandbox": "sock",
"registry_cache_ms": 5000,
"handler_cache_mb": 250,
"cluster_name": "/root/open-lambda/test-dir",
"docker_runtime": "",
"sandbox_config": {},
"registry": "/root/open-lambda/test-registry",
"worker_port": "5000"
},
"errors": [],
"worker_tail": [
"2019/07/03 22:09:33 remove /sys/fs/cgroup/freezer/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:33 remove /sys/fs/cgroup/hugetlb/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:33 remove /sys/fs/cgroup/memory/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:33 remove /sys/fs/cgroup/perf_event/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:33 remove /sys/fs/cgroup/systemd/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:33 remove /sys/fs/cgroup/pids/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:33 save stats to /root/open-lambda/test-dir/worker/stats.json",
"2019/07/03 22:09:33 remove worker.pid",
"2019/07/03 22:09:33 exiting",
""
]
}
PUSH conf: {'handler_cache_mb': 500, 'import_cache_mb': 100}
========================================
stress_one_lambda {'seconds': 15, 'procs': 8}
========================================
RUN ./ol worker -p=test-dir --detach
b'using existing OL directory at /root/open-lambda/test-dir\nStarting worker: pid=18612, port=5000, log=/root/open-lambda/test-dir/worker.out\nready\n'
RUN ./ol kill -p=test-dir
b'Kill worker process with PID 18612\n'
{
"test": "stress_one_lambda",
"params": {
"seconds": 15,
"procs": 8
},
"pass": true,
"seconds": 15.08425784111023,
"total_seconds": 15.32657527923584,
"stats": {
"reqs_per_sec": 233.93333333333334
},
"ol-stats": {
"Channel():ms.avg": 0,
"Channel():ms.cnt": 3,
"Create()/acquire-cgroup:ms.avg": 0,
"Create()/acquire-cgroup:ms.cnt": 4,
"Create()/acquire-mem:ms.avg": 0,
"Create()/acquire-mem:ms.cnt": 4,
"Create()/fork-proc:ms.avg": 10,
"Create()/fork-proc:ms.cnt": 3,
"Create()/fresh-proc:ms.avg": 212,
"Create()/fresh-proc:ms.cnt": 1,
"Create()/make-root-fs:ms.avg": 3,
"Create()/make-root-fs:ms.cnt": 4,
"Create():ms.avg": 65,
"Create():ms.cnt": 4,
"Destroy()/detach-root:ms.avg": 0,
"Destroy()/detach-root:ms.cnt": 4,
"Destroy()/kill-procs:ms.avg": 1,
"Destroy()/kill-procs:ms.cnt": 4,
"Destroy()/remove-root:ms.avg": 0,
"Destroy()/remove-root:ms.cnt": 4,
"Destroy():ms.avg": 1,
"Destroy():ms.cnt": 4,
"Pause():ms.avg": 0,
"Pause():ms.cnt": 2741,
"Unpause():ms.avg": 0,
"Unpause():ms.cnt": 2738,
"fork():ms.avg": 10,
"fork():ms.cnt": 3,
"forkRequest:ms.avg": 9,
"forkRequest:ms.cnt": 3,
"move-to-cg-after-fork:ms.avg": 0,
"move-to-cg-after-fork:ms.cnt": 3
},
"conf": {
"SOCK_base_path": "/root/open-lambda/test-dir/lambda",
"Skip_pull_existing": false,
"worker_dir": "/root/open-lambda/test-dir/worker",
"Pkgs_dir": "/root/open-lambda/test-dir/lambda/packages",
"import_cache_mb": 100,
"sock_cgroups": {
"max_procs": 10,
"max_mem_mb": 50
},
"server_mode": "lambda",
"pip_mirror": "",
"sandbox": "sock",
"registry_cache_ms": 5000,
"handler_cache_mb": 500,
"cluster_name": "/root/open-lambda/test-dir",
"docker_runtime": "",
"sandbox_config": {},
"registry": "/root/open-lambda/test-registry",
"worker_port": "5000"
},
"errors": [],
"worker_tail": [
"2019/07/03 22:09:48 remove /sys/fs/cgroup/freezer/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:48 remove /sys/fs/cgroup/hugetlb/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:48 remove /sys/fs/cgroup/memory/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:48 remove /sys/fs/cgroup/perf_event/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:48 remove /sys/fs/cgroup/systemd/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:48 remove /sys/fs/cgroup/pids/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:48 save stats to /root/open-lambda/test-dir/worker/stats.json",
"2019/07/03 22:09:48 remove worker.pid",
"2019/07/03 22:09:48 exiting",
""
]
}
POP conf: {'handler_cache_mb': 500, 'import_cache_mb': 100}
POP conf: {'handler_cache_mb': 250, 'registry': '/root/open-lambda/test-registry', 'sandbox': 'sock', 'import_cache_mb': 250}
PUSH conf: {'handler_cache_mb': 250, 'sandbox': 'sock', 'import_cache_mb': 250}
PUSH conf: {'registry': '/tmp/tmp84mssve_'}
========================================
call_each_once_exec {'lambda_count': 100, 'alloc_mb': 1}
========================================
RUN ./ol worker -p=test-dir --detach
b'using existing OL directory at /root/open-lambda/test-dir\nStarting worker: pid=18667, port=5000, log=/root/open-lambda/test-dir/worker.out\nready\n'
RUN ./ol kill -p=test-dir
b'Kill worker process with PID 18667\n'
{
"test": "call_each_once_exec",
"params": {
"lambda_count": 100,
"alloc_mb": 1
},
"pass": false,
"seconds": null,
"total_seconds": 1.2625913619995117,
"stats": null,
"ol-stats": {
"Channel():ms.avg": 0,
"Channel():ms.cnt": 30,
"Create()/acquire-cgroup:ms.avg": 0,
"Create()/acquire-cgroup:ms.cnt": 31,
"Create()/acquire-mem:ms.avg": 0,
"Create()/acquire-mem:ms.cnt": 31,
"Create()/fork-proc:ms.avg": 10,
"Create()/fork-proc:ms.cnt": 30,
"Create()/fresh-proc:ms.avg": 149,
"Create()/fresh-proc:ms.cnt": 1,
"Create()/make-root-fs:ms.avg": 0,
"Create()/make-root-fs:ms.cnt": 31,
"Create():ms.avg": 15,
"Create():ms.cnt": 31,
"Destroy()/detach-root:ms.avg": 0,
"Destroy()/detach-root:ms.cnt": 31,
"Destroy()/kill-procs:ms.avg": 2,
"Destroy()/kill-procs:ms.cnt": 31,
"Destroy()/remove-root:ms.avg": 0,
"Destroy()/remove-root:ms.cnt": 31,
"Destroy():ms.avg": 2,
"Destroy():ms.cnt": 31,
"Pause():ms.avg": 6,
"Pause():ms.cnt": 30,
"fork():ms.avg": 10,
"fork():ms.cnt": 30,
"forkRequest:ms.avg": 7,
"forkRequest:ms.cnt": 30,
"move-to-cg-after-fork:ms.avg": 2,
"move-to-cg-after-fork:ms.cnt": 30
},
"conf": {
"SOCK_base_path": "/root/open-lambda/test-dir/lambda",
"Skip_pull_existing": false,
"worker_port": "5000",
"worker_dir": "/root/open-lambda/test-dir/worker",
"Pkgs_dir": "/root/open-lambda/test-dir/lambda/packages",
"import_cache_mb": 250,
"registry_cache_ms": 5000,
"pip_mirror": "",
"sandbox": "sock",
"server_mode": "lambda",
"handler_cache_mb": 250,
"cluster_name": "/root/open-lambda/test-dir",
"sandbox_config": {},
"docker_runtime": "",
"registry": "/tmp/tmp84mssve_",
"sock_cgroups": {
"max_procs": 10,
"max_mem_mb": 50
}
},
"errors": [
[
"Traceback (most recent call last):",
" File \"test.py\", line 76, in wrapper",
" rv = fn(**kwargs)",
" File \"test.py\", line 258, in call_each_once_exec",
" r.raise_for_status()",
" File \"/usr/lib/python3/dist-packages/requests/models.py\", line 840, in raise_for_status",
" raise HTTPError(http_error_msg, response=self)",
"requests.exceptions.HTTPError: 502 Server Error: Bad Gateway for url: http://localhost:5000/run/L29",
""
]
],
"worker_tail": [
"using existing OL directory at /root/open-lambda/test-dir",
"2019/07/03 22:09:48 save PID 18667 to file /root/open-lambda/test-dir/worker/worker.pid",
"2019/07/03 22:09:48 Start Lambda Server",
"2019/07/03 22:09:48 Create SandboxPool",
"2019/07/03 22:09:48 create /sys/fs/cgroup/blkio/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:48 create /sys/fs/cgroup/cpu/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:48 create /sys/fs/cgroup/devices/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:48 create /sys/fs/cgroup/freezer/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:48 create /sys/fs/cgroup/hugetlb/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:48 create /sys/fs/cgroup/memory/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:48 create /sys/fs/cgroup/perf_event/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:48 create /sys/fs/cgroup/systemd/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:48 create /sys/fs/cgroup/pids/worker-sock-handlers [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:48 Create ModulePuller",
"2019/07/03 22:09:48 Create HandlerPuller",
"2019/07/03 22:09:48 Create ImportCache",
"2019/07/03 22:09:48 create /sys/fs/cgroup/blkio/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:09:48 create /sys/fs/cgroup/cpu/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:09:48 create /sys/fs/cgroup/devices/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:09:48 create /sys/fs/cgroup/freezer/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:09:48 create /sys/fs/cgroup/hugetlb/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:09:48 create /sys/fs/cgroup/memory/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:09:48 create /sys/fs/cgroup/perf_event/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:09:48 create /sys/fs/cgroup/systemd/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:09:48 create /sys/fs/cgroup/pids/worker-sock-cache [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:09:48 Setups Handlers",
"2019/07/03 22:09:48 Execute handler by POSTing to localhost:5000/run/",
"2019/07/03 22:09:48 Get status by sending request to localhost:5000/status",
"2019/07/03 22:09:48 start creating/serving CGs [CGROUP POOL worker-sock-handlers]",
"2019/07/03 22:09:48 start creating/serving CGs [CGROUP POOL worker-sock-cache]",
"2019/07/03 22:09:48 .Create(, false, , /root/open-lambda/test-dir/worker/scratch/import-cache-1001, )...",
"2019/07/03 22:09:48 Receive request to /pid",
"2019/07/03 22:09:48 Receive request to /run/L0",
"2019/07/03 22:09:48 debug: LambdaFunc.Task() runs on goroutine 22 [FUNC L0]",
"2019/07/03 22:09:48 increase instances to 1 [FUNC L0]",
"2019/07/03 22:09:48 ...returns &{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:48 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/1-L0, /root/open-lambda/test-dir/worker/scratch/func-L0-1002, &{[] []})...",
"2019/07/03 22:09:48 fork(&{0xc000082690 2 /root/open-lambda/test-dir/worker/sock-handlers/2 /root/open-lambda/test-dir/worker/lambda_code/1-L0 /root/open-lambda/test-dir/worker/scratch/func-L0-1002 0xc00000f260}) [SB 1]",
"2019/07/03 22:09:48 ...returns &{0xc0001c45a0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:48 Channel() [SB 2]",
"2019/07/03 22:09:48 Pause() [SB 2]",
"2019/07/03 22:09:48 Receive request to /run/L1",
"2019/07/03 22:09:48 debug: LambdaFunc.Task() runs on goroutine 33 [FUNC L1]",
"2019/07/03 22:09:48 increase instances to 1 [FUNC L1]",
"2019/07/03 22:09:48 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/2-L1, /root/open-lambda/test-dir/worker/scratch/func-L1-1003, &{[] []})...",
"2019/07/03 22:09:48 fork(&{0xc000082690 3 /root/open-lambda/test-dir/worker/sock-handlers/3 /root/open-lambda/test-dir/worker/lambda_code/2-L1 /root/open-lambda/test-dir/worker/scratch/func-L1-1003 0xc00000f280}) [SB 1]",
"2019/07/03 22:09:48 ...returns &{0xc0001c5b00 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:48 Channel() [SB 3]",
"2019/07/03 22:09:48 Pause() [SB 3]",
"2019/07/03 22:09:48 Receive request to /run/L2",
"2019/07/03 22:09:48 debug: LambdaFunc.Task() runs on goroutine 43 [FUNC L2]",
"2019/07/03 22:09:48 increase instances to 1 [FUNC L2]",
"2019/07/03 22:09:48 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/3-L2, /root/open-lambda/test-dir/worker/scratch/func-L2-1004, &{[] []})...",
"2019/07/03 22:09:48 fork(&{0xc000082690 4 /root/open-lambda/test-dir/worker/sock-handlers/4 /root/open-lambda/test-dir/worker/lambda_code/3-L2 /root/open-lambda/test-dir/worker/scratch/func-L2-1004 0xc00000f2a0}) [SB 1]",
"2019/07/03 22:09:48 ...returns &{0xc0001fb020 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:48 Channel() [SB 4]",
"2019/07/03 22:09:48 Pause() [SB 4]",
"2019/07/03 22:09:48 Receive request to /run/L3",
"2019/07/03 22:09:48 debug: LambdaFunc.Task() runs on goroutine 53 [FUNC L3]",
"2019/07/03 22:09:48 increase instances to 1 [FUNC L3]",
"2019/07/03 22:09:48 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/4-L3, /root/open-lambda/test-dir/worker/scratch/func-L3-1005, &{[] []})...",
"2019/07/03 22:09:48 fork(&{0xc000082690 5 /root/open-lambda/test-dir/worker/sock-handlers/5 /root/open-lambda/test-dir/worker/lambda_code/4-L3 /root/open-lambda/test-dir/worker/scratch/func-L3-1005 0xc00000f2c0}) [SB 1]",
"2019/07/03 22:09:48 ...returns &{0xc00022e5a0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:48 Channel() [SB 5]",
"2019/07/03 22:09:48 Pause() [SB 5]",
"2019/07/03 22:09:48 Receive request to /run/L4",
"2019/07/03 22:09:48 debug: LambdaFunc.Task() runs on goroutine 63 [FUNC L4]",
"2019/07/03 22:09:48 increase instances to 1 [FUNC L4]",
"2019/07/03 22:09:48 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/5-L4, /root/open-lambda/test-dir/worker/scratch/func-L4-1006, &{[] []})...",
"2019/07/03 22:09:48 fork(&{0xc000082690 6 /root/open-lambda/test-dir/worker/sock-handlers/6 /root/open-lambda/test-dir/worker/lambda_code/5-L4 /root/open-lambda/test-dir/worker/scratch/func-L4-1006 0xc00000f2e0}) [SB 1]",
"2019/07/03 22:09:48 ...returns &{0xc00022fa40 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:48 Channel() [SB 6]",
"2019/07/03 22:09:48 Pause() [SB 6]",
"2019/07/03 22:09:48 Receive request to /run/L5",
"2019/07/03 22:09:48 debug: LambdaFunc.Task() runs on goroutine 73 [FUNC L5]",
"2019/07/03 22:09:48 increase instances to 1 [FUNC L5]",
"2019/07/03 22:09:48 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/6-L5, /root/open-lambda/test-dir/worker/scratch/func-L5-1007, &{[] []})...",
"2019/07/03 22:09:48 fork(&{0xc000082690 7 /root/open-lambda/test-dir/worker/sock-handlers/7 /root/open-lambda/test-dir/worker/lambda_code/6-L5 /root/open-lambda/test-dir/worker/scratch/func-L5-1007 0xc00000f300}) [SB 1]",
"2019/07/03 22:09:48 ...returns &{0xc00025af60 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:48 Channel() [SB 7]",
"2019/07/03 22:09:48 Pause() [SB 7]",
"2019/07/03 22:09:48 Receive request to /run/L6",
"2019/07/03 22:09:48 debug: LambdaFunc.Task() runs on goroutine 83 [FUNC L6]",
"2019/07/03 22:09:48 increase instances to 1 [FUNC L6]",
"2019/07/03 22:09:48 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/7-L6, /root/open-lambda/test-dir/worker/scratch/func-L6-1008, &{[] []})...",
"2019/07/03 22:09:48 fork(&{0xc000082690 8 /root/open-lambda/test-dir/worker/sock-handlers/8 /root/open-lambda/test-dir/worker/lambda_code/7-L6 /root/open-lambda/test-dir/worker/scratch/func-L6-1008 0xc00000f320}) [SB 1]",
"2019/07/03 22:09:48 ...returns &{0xc000292480 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:48 Channel() [SB 8]",
"2019/07/03 22:09:48 Pause() [SB 8]",
"2019/07/03 22:09:48 Receive request to /run/L7",
"2019/07/03 22:09:48 debug: LambdaFunc.Task() runs on goroutine 93 [FUNC L7]",
"2019/07/03 22:09:48 increase instances to 1 [FUNC L7]",
"2019/07/03 22:09:48 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/8-L7, /root/open-lambda/test-dir/worker/scratch/func-L7-1009, &{[] []})...",
"2019/07/03 22:09:48 fork(&{0xc000082690 9 /root/open-lambda/test-dir/worker/sock-handlers/9 /root/open-lambda/test-dir/worker/lambda_code/8-L7 /root/open-lambda/test-dir/worker/scratch/func-L7-1009 0xc00000f340}) [SB 1]",
"2019/07/03 22:09:48 ...returns &{0xc000293980 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:48 Channel() [SB 9]",
"2019/07/03 22:09:48 Pause() [SB 9]",
"2019/07/03 22:09:48 Receive request to /run/L8",
"2019/07/03 22:09:48 debug: LambdaFunc.Task() runs on goroutine 103 [FUNC L8]",
"2019/07/03 22:09:48 increase instances to 1 [FUNC L8]",
"2019/07/03 22:09:48 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/9-L8, /root/open-lambda/test-dir/worker/scratch/func-L8-1010, &{[] []})...",
"2019/07/03 22:09:48 fork(&{0xc000082690 10 /root/open-lambda/test-dir/worker/sock-handlers/10 /root/open-lambda/test-dir/worker/lambda_code/9-L8 /root/open-lambda/test-dir/worker/scratch/func-L8-1010 0xc00000f360}) [SB 1]",
"2019/07/03 22:09:48 ...returns &{0xc0002c0ea0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:48 Channel() [SB 10]",
"2019/07/03 22:09:48 Pause() [SB 10]",
"2019/07/03 22:09:48 Receive request to /run/L9",
"2019/07/03 22:09:48 debug: LambdaFunc.Task() runs on goroutine 113 [FUNC L9]",
"2019/07/03 22:09:48 increase instances to 1 [FUNC L9]",
"2019/07/03 22:09:48 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/10-L9, /root/open-lambda/test-dir/worker/scratch/func-L9-1011, &{[] []})...",
"2019/07/03 22:09:48 fork(&{0xc000082690 11 /root/open-lambda/test-dir/worker/sock-handlers/11 /root/open-lambda/test-dir/worker/lambda_code/10-L9 /root/open-lambda/test-dir/worker/scratch/func-L9-1011 0xc00000f380}) [SB 1]",
"2019/07/03 22:09:48 ...returns &{0xc0002fa3c0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:48 Channel() [SB 11]",
"2019/07/03 22:09:48 Pause() [SB 11]",
"2019/07/03 22:09:48 Receive request to /run/L10",
"2019/07/03 22:09:48 debug: LambdaFunc.Task() runs on goroutine 123 [FUNC L10]",
"2019/07/03 22:09:48 increase instances to 1 [FUNC L10]",
"2019/07/03 22:09:48 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/11-L10, /root/open-lambda/test-dir/worker/scratch/func-L10-1012, &{[] []})...",
"2019/07/03 22:09:48 fork(&{0xc000082690 12 /root/open-lambda/test-dir/worker/sock-handlers/12 /root/open-lambda/test-dir/worker/lambda_code/11-L10 /root/open-lambda/test-dir/worker/scratch/func-L10-1012 0xc00000f3a0}) [SB 1]",
"2019/07/03 22:09:48 ...returns &{0xc0002fb8c0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:48 Channel() [SB 12]",
"2019/07/03 22:09:48 Pause() [SB 12]",
"2019/07/03 22:09:48 Receive request to /run/L11",
"2019/07/03 22:09:48 debug: LambdaFunc.Task() runs on goroutine 133 [FUNC L11]",
"2019/07/03 22:09:48 increase instances to 1 [FUNC L11]",
"2019/07/03 22:09:48 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/12-L11, /root/open-lambda/test-dir/worker/scratch/func-L11-1013, &{[] []})...",
"2019/07/03 22:09:48 fork(&{0xc000082690 13 /root/open-lambda/test-dir/worker/sock-handlers/13 /root/open-lambda/test-dir/worker/lambda_code/12-L11 /root/open-lambda/test-dir/worker/scratch/func-L11-1013 0xc00000f3c0}) [SB 1]",
"2019/07/03 22:09:48 ...returns &{0xc000322de0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:48 Channel() [SB 13]",
"2019/07/03 22:09:48 Pause() [SB 13]",
"2019/07/03 22:09:48 Receive request to /run/L12",
"2019/07/03 22:09:48 debug: LambdaFunc.Task() runs on goroutine 143 [FUNC L12]",
"2019/07/03 22:09:48 increase instances to 1 [FUNC L12]",
"2019/07/03 22:09:48 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/13-L12, /root/open-lambda/test-dir/worker/scratch/func-L12-1014, &{[] []})...",
"2019/07/03 22:09:48 fork(&{0xc000082690 14 /root/open-lambda/test-dir/worker/sock-handlers/14 /root/open-lambda/test-dir/worker/lambda_code/13-L12 /root/open-lambda/test-dir/worker/scratch/func-L12-1014 0xc00000f3e0}) [SB 1]",
"2019/07/03 22:09:48 ...returns &{0xc000352240 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:48 Channel() [SB 14]",
"2019/07/03 22:09:48 Pause() [SB 14]",
"2019/07/03 22:09:48 Receive request to /run/L13",
"2019/07/03 22:09:48 debug: LambdaFunc.Task() runs on goroutine 153 [FUNC L13]",
"2019/07/03 22:09:48 increase instances to 1 [FUNC L13]",
"2019/07/03 22:09:48 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/14-L13, /root/open-lambda/test-dir/worker/scratch/func-L13-1015, &{[] []})...",
"2019/07/03 22:09:48 fork(&{0xc000082690 15 /root/open-lambda/test-dir/worker/sock-handlers/15 /root/open-lambda/test-dir/worker/lambda_code/14-L13 /root/open-lambda/test-dir/worker/scratch/func-L13-1015 0xc00000f400}) [SB 1]",
"2019/07/03 22:09:48 ...returns &{0xc0003537a0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:48 Channel() [SB 15]",
"2019/07/03 22:09:48 Pause() [SB 15]",
"2019/07/03 22:09:48 Receive request to /run/L14",
"2019/07/03 22:09:48 debug: LambdaFunc.Task() runs on goroutine 163 [FUNC L14]",
"2019/07/03 22:09:48 increase instances to 1 [FUNC L14]",
"2019/07/03 22:09:48 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/15-L14, /root/open-lambda/test-dir/worker/scratch/func-L14-1016, &{[] []})...",
"2019/07/03 22:09:48 fork(&{0xc000082690 16 /root/open-lambda/test-dir/worker/sock-handlers/16 /root/open-lambda/test-dir/worker/lambda_code/15-L14 /root/open-lambda/test-dir/worker/scratch/func-L14-1016 0xc00000f420}) [SB 1]",
"2019/07/03 22:09:48 ...returns &{0xc00038cd20 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:48 Channel() [SB 16]",
"2019/07/03 22:09:49 Pause() [SB 16]",
"2019/07/03 22:09:49 Receive request to /run/L15",
"2019/07/03 22:09:49 debug: LambdaFunc.Task() runs on goroutine 173 [FUNC L15]",
"2019/07/03 22:09:49 increase instances to 1 [FUNC L15]",
"2019/07/03 22:09:49 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/16-L15, /root/open-lambda/test-dir/worker/scratch/func-L15-1017, &{[] []})...",
"2019/07/03 22:09:49 fork(&{0xc000082690 17 /root/open-lambda/test-dir/worker/sock-handlers/17 /root/open-lambda/test-dir/worker/lambda_code/16-L15 /root/open-lambda/test-dir/worker/scratch/func-L15-1017 0xc00000f440}) [SB 1]",
"2019/07/03 22:09:49 ...returns &{0xc0003be240 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:49 Channel() [SB 17]",
"2019/07/03 22:09:49 Pause() [SB 17]",
"2019/07/03 22:09:49 Receive request to /run/L16",
"2019/07/03 22:09:49 debug: LambdaFunc.Task() runs on goroutine 183 [FUNC L16]",
"2019/07/03 22:09:49 increase instances to 1 [FUNC L16]",
"2019/07/03 22:09:49 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/17-L16, /root/open-lambda/test-dir/worker/scratch/func-L16-1018, &{[] []})...",
"2019/07/03 22:09:49 fork(&{0xc000082690 18 /root/open-lambda/test-dir/worker/sock-handlers/18 /root/open-lambda/test-dir/worker/lambda_code/17-L16 /root/open-lambda/test-dir/worker/scratch/func-L16-1018 0xc00000f460}) [SB 1]",
"2019/07/03 22:09:49 ...returns &{0xc0003bf7a0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:49 Channel() [SB 18]",
"2019/07/03 22:09:49 Pause() [SB 18]",
"2019/07/03 22:09:49 Receive request to /run/L17",
"2019/07/03 22:09:49 debug: LambdaFunc.Task() runs on goroutine 193 [FUNC L17]",
"2019/07/03 22:09:49 increase instances to 1 [FUNC L17]",
"2019/07/03 22:09:49 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/18-L17, /root/open-lambda/test-dir/worker/scratch/func-L17-1019, &{[] []})...",
"2019/07/03 22:09:49 fork(&{0xc000082690 19 /root/open-lambda/test-dir/worker/sock-handlers/19 /root/open-lambda/test-dir/worker/lambda_code/18-L17 /root/open-lambda/test-dir/worker/scratch/func-L17-1019 0xc00000fb80}) [SB 1]",
"2019/07/03 22:09:49 ...returns &{0xc0003e0c00 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:49 Channel() [SB 19]",
"2019/07/03 22:09:49 Pause() [SB 19]",
"2019/07/03 22:09:49 Receive request to /run/L18",
"2019/07/03 22:09:49 debug: LambdaFunc.Task() runs on goroutine 203 [FUNC L18]",
"2019/07/03 22:09:49 increase instances to 1 [FUNC L18]",
"2019/07/03 22:09:49 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/19-L18, /root/open-lambda/test-dir/worker/scratch/func-L18-1020, &{[] []})...",
"2019/07/03 22:09:49 fork(&{0xc000082690 20 /root/open-lambda/test-dir/worker/sock-handlers/20 /root/open-lambda/test-dir/worker/lambda_code/19-L18 /root/open-lambda/test-dir/worker/scratch/func-L18-1020 0xc0001ec240}) [SB 1]",
"2019/07/03 22:09:49 ...returns &{0xc00041c0c0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:49 Channel() [SB 20]",
"2019/07/03 22:09:49 Pause() [SB 20]",
"2019/07/03 22:09:49 Receive request to /run/L19",
"2019/07/03 22:09:49 debug: LambdaFunc.Task() runs on goroutine 213 [FUNC L19]",
"2019/07/03 22:09:49 increase instances to 1 [FUNC L19]",
"2019/07/03 22:09:49 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/20-L19, /root/open-lambda/test-dir/worker/scratch/func-L19-1021, &{[] []})...",
"2019/07/03 22:09:49 fork(&{0xc000082690 21 /root/open-lambda/test-dir/worker/sock-handlers/21 /root/open-lambda/test-dir/worker/lambda_code/20-L19 /root/open-lambda/test-dir/worker/scratch/func-L19-1021 0xc0001ec8c0}) [SB 1]",
"2019/07/03 22:09:49 ...returns &{0xc00041d620 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:49 Channel() [SB 21]",
"2019/07/03 22:09:49 Pause() [SB 21]",
"2019/07/03 22:09:49 Receive request to /run/L20",
"2019/07/03 22:09:49 debug: LambdaFunc.Task() runs on goroutine 223 [FUNC L20]",
"2019/07/03 22:09:49 increase instances to 1 [FUNC L20]",
"2019/07/03 22:09:49 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/21-L20, /root/open-lambda/test-dir/worker/scratch/func-L20-1022, &{[] []})...",
"2019/07/03 22:09:49 fork(&{0xc000082690 22 /root/open-lambda/test-dir/worker/sock-handlers/22 /root/open-lambda/test-dir/worker/lambda_code/21-L20 /root/open-lambda/test-dir/worker/scratch/func-L20-1022 0xc0001ecf40}) [SB 1]",
"2019/07/03 22:09:49 ...returns &{0xc000450b40 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:49 Channel() [SB 22]",
"2019/07/03 22:09:49 Pause() [SB 22]",
"2019/07/03 22:09:49 Receive request to /run/L21",
"2019/07/03 22:09:49 debug: LambdaFunc.Task() runs on goroutine 233 [FUNC L21]",
"2019/07/03 22:09:49 increase instances to 1 [FUNC L21]",
"2019/07/03 22:09:49 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/22-L21, /root/open-lambda/test-dir/worker/scratch/func-L21-1023, &{[] []})...",
"2019/07/03 22:09:49 fork(&{0xc000082690 23 /root/open-lambda/test-dir/worker/sock-handlers/23 /root/open-lambda/test-dir/worker/lambda_code/22-L21 /root/open-lambda/test-dir/worker/scratch/func-L21-1023 0xc0001ed5c0}) [SB 1]",
"2019/07/03 22:09:49 ...returns &{0xc000451f80 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:49 Channel() [SB 23]",
"2019/07/03 22:09:49 Pause() [SB 23]",
"2019/07/03 22:09:49 Receive request to /run/L22",
"2019/07/03 22:09:49 debug: LambdaFunc.Task() runs on goroutine 243 [FUNC L22]",
"2019/07/03 22:09:49 increase instances to 1 [FUNC L22]",
"2019/07/03 22:09:49 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/23-L22, /root/open-lambda/test-dir/worker/scratch/func-L22-1024, &{[] []})...",
"2019/07/03 22:09:49 fork(&{0xc000082690 24 /root/open-lambda/test-dir/worker/sock-handlers/24 /root/open-lambda/test-dir/worker/lambda_code/23-L22 /root/open-lambda/test-dir/worker/scratch/func-L22-1024 0xc0001edc40}) [SB 1]",
"2019/07/03 22:09:49 ...returns &{0xc00048f4a0 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:49 Channel() [SB 24]",
"2019/07/03 22:09:49 Pause() [SB 24]",
"2019/07/03 22:09:49 Receive request to /run/L23",
"2019/07/03 22:09:49 debug: LambdaFunc.Task() runs on goroutine 253 [FUNC L23]",
"2019/07/03 22:09:49 increase instances to 1 [FUNC L23]",
"2019/07/03 22:09:49 .Create(&{0xc00019d440 {0 0} false [0x8193c0 0x81a800]}, true, /root/open-lambda/test-dir/worker/lambda_code/24-L23, /root/open-lambda/test-dir/worker/scratch/func-L23-1025, &{[] []})...",
"2019/07/03 22:09:49 fork(&{0xc000082690 25 /root/open-lambda/test-dir/worker/sock-handlers/25 /root/open-lambda/test-dir/worker/lambda_code/24-L23 /root/open-lambda/test-dir/worker/scratch/func-L23-1025 0xc0002942c0}) [SB 1]",
"2019/07/03 22:09:49 ...returns &{0xc0004b2960 {0 0} false [0x8193c0 0x81a800]}, ",
"2019/07/03 22:09:49 Channel() [SB 25]",
"2019/07/03 22:09:49 Pause() [SB 25]",
"2019/07/03 22:09:49 Receive request to /run/L24",
"2019/07/03 22:09:49 debug: LambdaFunc.Task() runs on goroutine 263 [FUNC L24]",
"2019/07/03 22:09:49 increase instances to 1 [FUNC L24]",
"2019/07/03 22:09:49