Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Container hangs with memory usage almost the same as memory limit #35463

Open
stszap opened this issue Nov 10, 2017 · 10 comments
Open

Container hangs with memory usage almost the same as memory limit #35463

stszap opened this issue Nov 10, 2017 · 10 comments

Comments

@stszap
Copy link

stszap commented Nov 10, 2017

Description

Hello. Recently. We faced a strange problem. One of containers suddenly hung (no logs, no response to amqp requests). We monitor all containers via croups pseudo-files and our monitoring system shows that at the same time container hung it's user cpu usage went to 0% (usully it jumps between 0% and 20% constantly) but system cpu usage went to 30-40%, and the most interesting: memory suddenly jumped to 255.5mb (the memory limit is exactly 256mb) and stayed perfectly flat until the container was manually restarted. We also observed a huge increase in disk i/o activity on a whole host: read rate up to 200MBps when usually it almost 0, and write rate up to 2MBps when usually it is about 0.5MBps. It almost looks like the container was blocked while swapping but we have swap disabled on all of our machines. This also happened a few times on other machine always with the same container, but haven't happened in a while. I though that it was a problem with a specific container but it turned out it's not. We also haven't had container monitoring back then.

Steps to reproduce the issue:

Unfortunally I was unable to reproduce this. Most of the time containers that exceed memory limit just get killed, but once in a few weeks the problem with the symptoms described above happens. I also couldn't find any reports similar to our issue so I desided to create one.

Describe the results you received:
Container hangs, huge increase in i/o activity.

Describe the results you expected:
Container gets killed.

Output of docker version:
Client:
Version: 17.03.1-ce
API version: 1.27
Go version: go1.7.5
Git commit: c6d412e
Built: Fri Mar 24 00:34:45 2017
OS/Arch: linux/amd64

Server:
Version: 17.03.1-ce
API version: 1.27 (minimum version 1.12)
Go version: go1.7.5
Git commit: c6d412e
Built: Fri Mar 24 00:34:45 2017
OS/Arch: linux/amd64
Experimental: false

Output of docker info:
Containers: 123
Running: 122
Paused: 0
Stopped: 1
Images: 1360
Server Version: 17.03.1-ce
Storage Driver: aufs
Root Dir: /mnt/ssd/docker/aufs
Backing Filesystem: extfs
Dirs: 3663
Dirperm1 Supported: true
Logging Driver: gelf
Cgroup Driver: cgroupfs
Plugins:
Volume: local
Network: bridge host macvlan null overlay
Swarm: inactive
Runtimes: runc
Default Runtime: runc
Init Binary: docker-init
containerd version: 4ab9917febca54791c5f071a9d1f404867857fcc
runc version: 54296cf40ad8143b62dbcaa1d90e520a2136ddfe
init version: 949e6fa
Kernel Version: 3.16.0-4-amd64
Operating System: Debian GNU/Linux 8 (jessie)
OSType: linux
Architecture: x86_64
CPUs: 4
Total Memory: 15.63 GiB
Name: s2.teslatele.com
ID: XOC3:KLQL:ENDZ:AANM:TEA6:FAYI:LEVE:DNQX:U7NB:AA4A:RVQ3:QFD5
Docker Root Dir: /mnt/ssd/docker
Debug Mode (client): false
Debug Mode (server): false
Registry: https://index.docker.io/v1/
WARNING: No kernel memory limit support
WARNING: No cpu cfs quota support
WARNING: No cpu cfs period support
Experimental: false
Insecure Registries:
127.0.0.0/8
Live Restore Enabled: false

Additional environment details (AWS, VirtualBox, physical, etc.):
physical

@thaJeztah
Copy link
Member

If containers start to get OOM killed by the kernel, chances are as well that the host as a whole is running out of resources (in which case, other processes could be killed). Do the system logs show information about processes that were killed by the kernel?

@stszap
Copy link
Author

stszap commented Nov 10, 2017

Oh, actually the problem is exactly opposite. The hanged container wasn't oom killed, but had to be restarted manually. After that normal oom message appeared in kernel logs:

Nov  7 09:16:57 s2 kernel: [84629.739949] node invoked oom-killer: gfp_mask=0xd0, order=0, oom_score_adj=0
Nov  7 09:16:57 s2 kernel: [84629.741047] node cpuset=e97c0a5b3d6f2165f396f1d286b8e50492b1bf3a0e89b043fc907552adede85f mems_allowed=0
Nov  7 09:16:57 s2 kernel: [84629.742021] CPU: 0 PID: 23311 Comm: node Tainted: G         C    3.16.0-4-amd64 #1 Debian 3.16.39-1
Nov  7 09:16:57 s2 kernel: [84629.743278] Hardware name: Gigabyte Technology Co., Ltd. H61M-D2-B3/H61M-D2-B3, BIOS F4 03/31/2011
Nov  7 09:16:57 s2 kernel: [84629.744522]  0000000000000000 ffffffff81514c11 ffff8803cfebebe0 ffff8803c026bc00
Nov  7 09:16:57 s2 kernel: [84629.745770]  ffffffff815127e9 ffff8803cfebf0f8 0000000100000000 ffff8803002f4840
Nov  7 09:16:57 s2 kernel: [84629.747012]  ffff8803cfebebe0 ffff88041fa12f40 ffff880407ccd800 ffff8803002f4840
Nov  7 09:16:57 s2 kernel: [84629.748257] Call Trace:
Nov  7 09:16:57 s2 kernel: [84629.749497]  [<ffffffff81514c11>] ? dump_stack+0x5d/0x78
Nov  7 09:16:57 s2 kernel: [84629.750728]  [<ffffffff815127e9>] ? dump_header+0x76/0x1e8
Nov  7 09:16:57 s2 kernel: [84629.751943]  [<ffffffff8114243d>] ? find_lock_task_mm+0x3d/0x90
Nov  7 09:16:57 s2 kernel: [84629.753138]  [<ffffffff8114287d>] ? oom_kill_process+0x21d/0x370
Nov  7 09:16:57 s2 kernel: [84629.754344]  [<ffffffff8114243d>] ? find_lock_task_mm+0x3d/0x90
Nov  7 09:16:57 s2 kernel: [84629.755545]  [<ffffffff811a292a>] ? mem_cgroup_oom_synchronize+0x52a/0x590
Nov  7 09:16:57 s2 kernel: [84629.756706]  [<ffffffff811a1eb0>] ? mem_cgroup_try_charge_mm+0xa0/0xa0
Nov  7 09:16:57 s2 kernel: [84629.757838]  [<ffffffff81143030>] ? pagefault_out_of_memory+0x10/0x80
Nov  7 09:16:57 s2 kernel: [84629.758974]  [<ffffffff81058515>] ? __do_page_fault+0x3c5/0x4f0
Nov  7 09:16:57 s2 kernel: [84629.760101]  [<ffffffff8109e9e7>] ? put_prev_entity+0x57/0x350
Nov  7 09:16:57 s2 kernel: [84629.761218]  [<ffffffff8109d7f6>] ? set_next_entity+0x56/0x70
Nov  7 09:16:57 s2 kernel: [84629.762340]  [<ffffffff810a4621>] ? pick_next_task_fair+0x6e1/0x820
Nov  7 09:16:57 s2 kernel: [84629.763480]  [<ffffffff810125dc>] ? __switch_to+0x15c/0x5a0
Nov  7 09:16:57 s2 kernel: [84629.764610]  [<ffffffff8151cde8>] ? page_fault+0x28/0x30
Nov  7 09:16:57 s2 kernel: [84629.766155] Task in /docker/e97c0a5b3d6f2165f396f1d286b8e50492b1bf3a0e89b043fc907552adede85f killed as a result of limit of /docker/e97c0a5b3d6f2165f396f1d286b8e50492b1bf3a0e89b043fc907552adede85f
Nov  7 09:16:57 s2 kernel: [84629.768454] memory: usage 262116kB, limit 262144kB, failcnt 10290895
Nov  7 09:16:57 s2 kernel: [84629.769416] memory+swap: usage 262112kB, limit 524288kB, failcnt 0
Nov  7 09:16:57 s2 kernel: [84629.770413] kmem: usage 0kB, limit 18014398509481983kB, failcnt 0
Nov  7 09:16:57 s2 kernel: [84629.771308] Memory cgroup stats for /docker/e97c0a5b3d6f2165f396f1d286b8e50492b1bf3a0e89b043fc907552adede85f: cache:260KB rss:261852KB rss_huge:0KB mapped_file:0KB writeback:0KB swap:0KB inactive_anon:4KB active_anon:261960KB inactive_file:32KB active_file:56KB unevictable:0KB
Nov  7 09:16:57 s2 kernel: [84629.774874] [ pid ]   uid  tgid total_vm      rss nr_ptes swapents oom_score_adj name
Nov  7 09:16:57 s2 kernel: [84629.776246] [22103]     0 22103   149338     6534      58        0             0 npm
Nov  7 09:16:57 s2 kernel: [84629.777250] [23304]     0 23304      382        2       5        0             0 sh
Nov  7 09:16:57 s2 kernel: [84629.778045] [23311]     0 23311   205515    58895     271        0             0 node
Nov  7 09:16:58 s2 kernel: [84630.042180] docker0: port 37(vethdefd5e11) entered disabled state
Nov  7 09:16:58 s2 kernel: [84630.045036] device vethdefd5e11 left promiscuous mode
Nov  7 09:16:58 s2 kernel: [84630.045982] docker0: port 37(vethdefd5e11) entered disabled state

, docker logs show nothing around that time (but log level is "info" now) . Out of 16gb of ram 6gb were free and other containers were fine, so I wonder if docker/kernel tried to kill the container when it reached memory limit but something got stuck.

@thaJeztah
Copy link
Member

Docker won't kill containers; it sets up the root-filesystem, namespace and cgroups, and after that it's the kernel managing, so not sure what happened. It could still be a kernel issue; 3.16 has come up quite a few times in issues.

@stszap
Copy link
Author

stszap commented Dec 18, 2017

The problem happened again on another server with newer kernel. It has "debug" option enabled in docker config, but I can't find any new information in the logs. The problem started at 03:38 (GMT) and ended at 09:04 (GMT) when I tried to "exec" into the "hanged" contaner (it got oom-killed immediately). The container in question has id "8fa1efbc92a6".

docker logs during the problem start

time="2017-12-18T08:33:10.291183938Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T08:33:10.292022948Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T08:33:17.721193225Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:33:33.728139067Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:33:47.728588989Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:34:02.732094667Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:34:11.961558154Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T08:34:11.961980093Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T08:34:17.735053324Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:34:32.741169661Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:34:47.741589948Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:35:02.744570136Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:35:14.264593151Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T08:35:14.264990540Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T08:35:17.747786932Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:35:33.759340273Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:35:47.765162717Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:36:02.773646915Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:36:15.987092139Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T08:36:15.987575155Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T08:36:17.776368309Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:36:32.787502504Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:36:47.782018603Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:37:02.784606341Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:37:14.170859199Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:37:17.787677328Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:37:17.912690245Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T08:37:17.919598225Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T08:37:33.797086320Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:37:47.796450033Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:38:02.800250603Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:38:17.803203070Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:38:19.852354566Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T08:38:19.853403056Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T08:38:32.808175335Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:38:47.811166604Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:39:02.813229460Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:39:17.816127765Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:39:21.841974452Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T08:39:21.842432566Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T08:39:33.824567475Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:39:47.820922703Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:40:02.824091652Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:40:17.826363080Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:40:18.552323785Z" level=debug msg="containerd: process exited" id=3fa27d45d875541d8e52f81e2c4344501c46c1c9a3554e0b2d1b806c5b919758 pid=init status=0 systemPid=15620 
time="2017-12-18T08:40:18.560813148Z" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"3fa27d45d875541d8e52f81e2c4344501c46c1c9a3554e0b2d1b806c5b919758\", S
tatus:0x0, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc428c6c120)}" 
time="2017-12-18T08:40:18.560947818Z" level=debug msg="attach: stdout: end" 
time="2017-12-18T08:40:18.560959813Z" level=debug msg="attach: stderr: end" 
time="2017-12-18T08:40:18.561302606Z" level=debug msg="Revoking external connectivity on endpoint kind_brown (0da273b5d8a6c22d3134cb50b157052155c1792cfdda6d10d6dc5bd11cc42cc2)" 
time="2017-12-18T08:40:18.561535880Z" level=debug msg="Calling GET /v1.22/containers/3fa27d45d875541d8e52f81e2c4344501c46c1c9a3554e0b2d1b806c5b919758/json" 
time="2017-12-18T08:40:18.561827154Z" level=debug msg="Calling GET /v1.22/containers/3fa27d45d875541d8e52f81e2c4344501c46c1c9a3554e0b2d1b806c5b919758/json" 
time="2017-12-18T08:40:19.641786412Z" level=debug msg="Releasing addresses for endpoint kind_brown's interface on network bridge" 
time="2017-12-18T08:40:19.641876949Z" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.4)" 
time="2017-12-18T08:40:19.901752917Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/5332f1ac433785f4e9c54f6089ae201981462408970d2e00a7adb1eda644d986/merged" 
time="2017-12-18T08:40:19.901798043Z" level=debug msg="Tar with options on /mnt/ssd/docker/overlay2/5332f1ac433785f4e9c54f6089ae201981462408970d2e00a7adb1eda644d986/diff" 
time="2017-12-18T08:40:19.902199060Z" level=debug msg="Applying tar in /mnt/ssd/docker/overlay2/cfc74796efae2e648ab9c8e76b8e1be743c13aa19a20e8b7079c100752dfc13c/diff" 
time="2017-12-18T08:40:20.251610044Z" level=debug msg="Applied tar sha256:81e408755af462e7602b51758f00b3d2b34d10e0c0d1c946211a35e13d82ab5f to cfc74796efae2e648ab9c8e76b8e1be743c13aa19a20e8b7079c10075
2dfc13c, size: 60003359" 
time="2017-12-18T08:40:23.254312358Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T08:40:23.254790525Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T08:40:29.566734646Z" level=debug msg="Calling GET /v1.22/containers/3fa27d45d875541d8e52f81e2c4344501c46c1c9a3554e0b2d1b806c5b919758/json" 
time="2017-12-18T08:40:29.566798903Z" level=error msg="Handler for GET /v1.22/containers/3fa27d45d875541d8e52f81e2c4344501c46c1c9a3554e0b2d1b806c5b919758/json returned error: No such container: 3fa27
d45d875541d8e52f81e2c4344501c46c1c9a3554e0b2d1b806c5b919758" 
time="2017-12-18T08:40:30.295849853Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/bc006cecf06d5d55c4fc5b52b8ea6a292736189dcb0a102f78228396b82d56f1/merged" 
time="2017-12-18T08:40:30.476711641Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/bc006cecf06d5d55c4fc5b52b8ea6a292736189dcb0a102f78228396b82d56f1/merged" 
time="2017-12-18T08:40:30.506948344Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/bc006cecf06d5d55c4fc5b52b8ea6a292736189dcb0a102f78228396b82d56f1/merged" 
time="2017-12-18T08:40:30.507052019Z" level=debug msg="Tar with options on /mnt/ssd/docker/overlay2/bc006cecf06d5d55c4fc5b52b8ea6a292736189dcb0a102f78228396b82d56f1/diff" 
time="2017-12-18T08:40:30.507927702Z" level=debug msg="Applying tar in /mnt/ssd/docker/overlay2/c0ec9d16e30050cf2bfc18b8dbf88f566e93f28fc4840f15e5f6504e87ea26e6/diff" 
time="2017-12-18T08:40:30.582889439Z" level=debug msg="Applied tar sha256:b6c231aaf8ef9a11aa9391a642ff5813a863ac6141d5bbde58c50909d0ea8e7f to c0ec9d16e30050cf2bfc18b8dbf88f566e93f28fc4840f15e5f6504e8
7ea26e6, size: 0" 
time="2017-12-18T08:40:31.301084486Z" level=debug msg="Calling GET /v1.22/containers/b959f4eeca316a05f415116ca573a208541b03349bdd504c76831f52e3a84b18/json" 
time="2017-12-18T08:40:31.301137115Z" level=error msg="Handler for GET /v1.22/containers/b959f4eeca316a05f415116ca573a208541b03349bdd504c76831f52e3a84b18/json returned error: No such container: b959f
4eeca316a05f415116ca573a208541b03349bdd504c76831f52e3a84b18" 
time="2017-12-18T08:40:31.398082646Z" level=debug msg="Calling GET /v1.22/containers/json?limit=0" 
time="2017-12-18T08:40:31.405108463Z" level=debug msg="Calling GET /v1.22/containers/301bd843c853ae734a1702d36cecd3343acf7e42618fec286ed22d87944be913/json" 
time="2017-12-18T08:40:31.492206775Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/cbfa171fb85e3f587d5637e570989ccb6ff18084222cc9a8eb13d7af214bb034/merged" 
time="2017-12-18T08:40:31.623092991Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/cbfa171fb85e3f587d5637e570989ccb6ff18084222cc9a8eb13d7af214bb034/merged" 
time="2017-12-18T08:40:31.646751713Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/cbfa171fb85e3f587d5637e570989ccb6ff18084222cc9a8eb13d7af214bb034/merged" 
time="2017-12-18T08:40:31.646808540Z" level=debug msg="Tar with options on /mnt/ssd/docker/overlay2/cbfa171fb85e3f587d5637e570989ccb6ff18084222cc9a8eb13d7af214bb034/diff" 
time="2017-12-18T08:40:31.647229527Z" level=debug msg="Applying tar in /mnt/ssd/docker/overlay2/29670b50227443d213d64950645cbf87637c92927cabfd9cc5a9525224c9ab8a/diff" 
time="2017-12-18T08:40:31.730790540Z" level=debug msg="Applied tar sha256:2c9080a1fadcbae2e8c365bdd71f60574e135d0fdb0db5e1329a7cd3e47bb1b6 to 29670b50227443d213d64950645cbf87637c92927cabfd9cc5a952522
4c9ab8a, size: 0" 
time="2017-12-18T08:40:32.841584234Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T08:40:33.067761140Z" level=debug msg="Calling GET /v1.22/containers/0aa23e8d35958430998b1d2ea2ca0345e68b932986c89637c684c64a5489202c/json" 
time="2017-12-18T08:40:33.067802875Z" level=error msg="Handler for GET /v1.22/containers/0aa23e8d35958430998b1d2ea2ca0345e68b932986c89637c684c64a5489202c/json returned error: No such container: 0aa23
e8d35958430998b1d2ea2ca0345e68b932986c89637c684c64a5489202c" 
time="2017-12-18T08:40:33.339626438Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/a2d08cff28912f0769869c020e730aa0a177b68afc3e9ec06ec585a35aea161e/merged" 
time="2017-12-18T08:40:33.555473355Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/a2d08cff28912f0769869c020e730aa0a177b68afc3e9ec06ec585a35aea161e/merged" 
time="2017-12-18T08:40:33.555537699Z" level=debug msg="Creating dest directory: /mnt/ssd/docker/overlay2/a2d08cff28912f0769869c020e730aa0a177b68afc3e9ec06ec585a35aea161e/merged/opt/freeswitch/etc/fre
eswitch" 
time="2017-12-18T08:40:33.555635413Z" level=debug msg="Calling TarUntar(/mnt/ssd/docker/tmp/docker-builder370782967/config, /mnt/ssd/docker/overlay2/a2d08cff28912f0769869c020e730aa0a177b68afc3e9ec06e
c585a35aea161e/merged/opt/freeswitch/etc/freeswitch)" 
time="2017-12-18T08:40:33.555645437Z" level=debug msg="TarUntar(/mnt/ssd/docker/tmp/docker-builder370782967/config /mnt/ssd/docker/overlay2/a2d08cff28912f0769869c020e730aa0a177b68afc3e9ec06ec585a35ae
a161e/merged/opt/freeswitch/etc/freeswitch)" 
time="2017-12-18T08:40:33.675097516Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/a2d08cff28912f0769869c020e730aa0a177b68afc3e9ec06ec585a35aea161e/merged" 
time="2017-12-18T08:40:33.675176696Z" level=debug msg="Tar with options on /mnt/ssd/docker/overlay2/a2d08cff28912f0769869c020e730aa0a177b68afc3e9ec06ec585a35aea161e/diff" 
time="2017-12-18T08:40:33.675647420Z" level=debug msg="Applying tar in /mnt/ssd/docker/overlay2/a9c804e79d992fc7c6d7d7b04c98ce2c56c552f823a4e44f72885a3cfb3a6a53/diff" 
time="2017-12-18T08:40:33.779614138Z" level=debug msg="Applied tar sha256:c1127276c641520796c71d9ab72b838d69621a260b89f77be5622a777d0a9fbf to a9c804e79d992fc7c6d7d7b04c98ce2c56c552f823a4e44f72885a3cf
b3a6a53, size: 753124" 
time="2017-12-18T08:40:35.112438907Z" level=debug msg="Calling GET /v1.22/containers/7c42a2226f96125af822a311989299313a3238cfc0efad35bd8f4a1ce396b57c/json" 
time="2017-12-18T08:40:35.112482069Z" level=error msg="Handler for GET /v1.22/containers/7c42a2226f96125af822a311989299313a3238cfc0efad35bd8f4a1ce396b57c/json returned error: No such container: 7c42a
2226f96125af822a311989299313a3238cfc0efad35bd8f4a1ce396b57c" 
time="2017-12-18T08:40:35.316891194Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/185c57153cbb4f2e9964da8701eeca988d2f6db060af5eeb0e1229eb29b3af59/merged" 
time="2017-12-18T08:40:35.543211367Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/185c57153cbb4f2e9964da8701eeca988d2f6db060af5eeb0e1229eb29b3af59/merged" 
time="2017-12-18T08:40:35.543294620Z" level=debug msg="Creating dest directory: /mnt/ssd/docker/overlay2/185c57153cbb4f2e9964da8701eeca988d2f6db060af5eeb0e1229eb29b3af59/merged/opt/freeswitch/share/f
reeswitch/scripts" 
time="2017-12-18T08:40:35.543308039Z" level=debug msg="Calling TarUntar(/mnt/ssd/docker/tmp/docker-builder370782967/scripts, /mnt/ssd/docker/overlay2/185c57153cbb4f2e9964da8701eeca988d2f6db060af5eeb0
e1229eb29b3af59/merged/opt/freeswitch/share/freeswitch/scripts)" 
time="2017-12-18T08:40:35.543317566Z" level=debug msg="TarUntar(/mnt/ssd/docker/tmp/docker-builder370782967/scripts /mnt/ssd/docker/overlay2/185c57153cbb4f2e9964da8701eeca988d2f6db060af5eeb0e1229eb29
b3af59/merged/opt/freeswitch/share/freeswitch/scripts)" 
time="2017-12-18T08:40:35.654756892Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/185c57153cbb4f2e9964da8701eeca988d2f6db060af5eeb0e1229eb29b3af59/merged" 
time="2017-12-18T08:40:35.654814124Z" level=debug msg="Tar with options on /mnt/ssd/docker/overlay2/185c57153cbb4f2e9964da8701eeca988d2f6db060af5eeb0e1229eb29b3af59/diff" 
time="2017-12-18T08:40:35.655308198Z" level=debug msg="Applying tar in /mnt/ssd/docker/overlay2/c7f457c7a590883f7744711a9d57a5e7cb987da17b114510463ef9e856b8432f/diff" 
time="2017-12-18T08:40:35.746812808Z" level=debug msg="Applied tar sha256:94331a026578d70cd3f8295a179c3c376f5c5d089589ba65cf772782996374d6 to c7f457c7a590883f7744711a9d57a5e7cb987da17b114510463ef9e85
6b8432f, size: 1791" 
time="2017-12-18T08:40:36.637373374Z" level=debug msg="Calling GET /v1.22/containers/a6e0208b7dc363a16a9e5b5515bf5053e338f856005956d04fd043c790aa15ea/json" 
time="2017-12-18T08:40:36.637438334Z" level=error msg="Handler for GET /v1.22/containers/a6e0208b7dc363a16a9e5b5515bf5053e338f856005956d04fd043c790aa15ea/json returned error: No such container: a6e02
08b7dc363a16a9e5b5515bf5053e338f856005956d04fd043c790aa15ea" 
time="2017-12-18T08:40:36.880325756Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/4af6541e22e310ec508c754900b85082178131b5ee40fad576254cdaa2ac404c/merged" 
time="2017-12-18T08:40:37.325561437Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/4af6541e22e310ec508c754900b85082178131b5ee40fad576254cdaa2ac404c/merged" 
time="2017-12-18T08:40:37.325603587Z" level=debug msg="CopyFileWithTar(/mnt/ssd/docker/tmp/docker-builder370782967/start.sh, /mnt/ssd/docker/overlay2/4af6541e22e310ec508c754900b85082178131b5ee40fad57
6254cdaa2ac404c/merged/start.sh)" 
time="2017-12-18T08:40:37.415586738Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/4af6541e22e310ec508c754900b85082178131b5ee40fad576254cdaa2ac404c/merged" 
time="2017-12-18T08:40:37.415859506Z" level=debug msg="Tar with options on /mnt/ssd/docker/overlay2/4af6541e22e310ec508c754900b85082178131b5ee40fad576254cdaa2ac404c/diff" 
time="2017-12-18T08:40:37.418094547Z" level=debug msg="Applying tar in /mnt/ssd/docker/overlay2/cc7e8da9f7cf39f4ae63c4d994157c6f8a1d158eeccaf77f53a2aa592800d489/diff" 
time="2017-12-18T08:40:37.515841898Z" level=debug msg="Applied tar sha256:d74804091af4b9fad7536293cba83e55e5ba0ad817c2492c7664be6d99d2bdc0 to cc7e8da9f7cf39f4ae63c4d994157c6f8a1d158eeccaf77f53a2aa592
800d489, size: 283" 
time="2017-12-18T08:40:38.395961199Z" level=debug msg="Calling GET /v1.22/containers/15f1d3eb03e2b30d66afe1081d2fea4a89150cda43840742c42bc0626cc95555/json" 
time="2017-12-18T08:40:38.396021269Z" level=error msg="Handler for GET /v1.22/containers/15f1d3eb03e2b30d66afe1081d2fea4a89150cda43840742c42bc0626cc95555/json returned error: No such container: 15f1d
3eb03e2b30d66afe1081d2fea4a89150cda43840742c42bc0626cc95555" 
time="2017-12-18T08:40:38.664219572Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/8d6c11f7404cb0421e7d74934697ed286a74161797f8fcd54b5e40534c5d0c96/merged" 
time="2017-12-18T08:40:38.835104588Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/8d6c11f7404cb0421e7d74934697ed286a74161797f8fcd54b5e40534c5d0c96/merged" 
time="2017-12-18T08:40:38.835374863Z" level=debug msg="Tar with options on /mnt/ssd/docker/overlay2/8d6c11f7404cb0421e7d74934697ed286a74161797f8fcd54b5e40534c5d0c96/diff" 
time="2017-12-18T08:40:38.838466114Z" level=debug msg="Applying tar in /mnt/ssd/docker/overlay2/58e626581e14ffa94980479d16efe2d82c3c6f076672413b1649c54b45fe1e8d/diff" 
time="2017-12-18T08:40:38.946818955Z" level=debug msg="Applied tar sha256:5f70bf18a086007016e948b04aed3b82103a36bea41755b6cddfaf10ace3c6ef to 58e626581e14ffa94980479d16efe2d82c3c6f076672413b1649c54b4
5fe1e8d, size: 0" 
time="2017-12-18T08:40:39.353943753Z" level=info msg="Layer sha256:ebd890a56c0711ceaa4db8450ac84327d9b76c6563429f253dbee25db3bfa7e6 cleaned up" 
time="2017-12-18T08:40:39.520237429Z" level=debug msg="Calling GET /v1.22/containers/9eaef55430d6b4725461d81a6ef3741011b02554775ce441268d3b046809a824/json" 
time="2017-12-18T08:40:39.520370883Z" level=error msg="Handler for GET /v1.22/containers/9eaef55430d6b4725461d81a6ef3741011b02554775ce441268d3b046809a824/json returned error: No such container: 9eaef
55430d6b4725461d81a6ef3741011b02554775ce441268d3b046809a824" 
time="2017-12-18T08:40:39.762227034Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/af46989aee6387af77fdb39519a4576181683858bded4f0437055aab22907884/merged" 
time="2017-12-18T08:40:39.891237959Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/af46989aee6387af77fdb39519a4576181683858bded4f0437055aab22907884/merged" 
time="2017-12-18T08:40:39.891320399Z" level=debug msg="Tar with options on /mnt/ssd/docker/overlay2/af46989aee6387af77fdb39519a4576181683858bded4f0437055aab22907884/diff" 
time="2017-12-18T08:40:39.891776390Z" level=debug msg="Applying tar in /mnt/ssd/docker/overlay2/b25cd3867f82959acca1d26fd937c8eeef8475c709fd486f8c0d2bf26534ea76/diff" 
time="2017-12-18T08:40:39.967778711Z" level=debug msg="Applied tar sha256:5f70bf18a086007016e948b04aed3b82103a36bea41755b6cddfaf10ace3c6ef to b25cd3867f82959acca1d26fd937c8eeef8475c709fd486f8c0d2bf26
534ea76, size: 0" 
time="2017-12-18T08:40:41.188678982Z" level=info msg="Layer sha256:ebd890a56c0711ceaa4db8450ac84327d9b76c6563429f253dbee25db3bfa7e6 cleaned up" 
time="2017-12-18T08:40:41.524058638Z" level=debug msg="Calling GET /v1.22/containers/7c7735e47123877335e8458d25df695e99e2506247c400023829a99cb9fbc638/json" 
time="2017-12-18T08:40:41.524193024Z" level=error msg="Handler for GET /v1.22/containers/7c7735e47123877335e8458d25df695e99e2506247c400023829a99cb9fbc638/json returned error: No such container: 7c773
5e47123877335e8458d25df695e99e2506247c400023829a99cb9fbc638" 
time="2017-12-18T08:40:41.880182530Z" level=debug msg="Calling GET /_ping" 

system logs during the problem start (nothing)

Dec 17 18:59:20 s12 ntpd[1]: Deleting interface #710 veth3fb47b86, fe80::484d:1eff:feb7:d239%1129#123, interface stats: received=0, sent=0, dropped=0, active_time=43207 secs
Dec 17 18:59:22 s12 ntpd[1]: Listen normally on 717 veth7fd93734 [fe80::f8d6:38ff:fe2a:451d%1135]:123
Dec 18 00:41:51 s12 kernel: [1364717.216302] device eth0 left promiscuous mode
Dec 18 00:41:52 s12 kernel: [1364718.315791] device eth0 entered promiscuous mode
Dec 18 04:06:54 s12 kernel: [1377020.450834] e1000e: eth1 NIC Link is Down
Dec 18 04:07:36 s12 kernel: [1377062.965974] e1000e: eth1 NIC Link is Up 100 Mbps Full Duplex, Flow Control: Rx/Tx
Dec 18 04:07:36 s12 kernel: [1377062.965976] e1000e 0000:00:1f.6 eth1: 10/100 speed: disabling TSO
Dec 18 04:07:37 s12 kernel: [1377063.742537] e1000e: eth1 NIC Link is Down
Dec 18 04:08:30 s12 kernel: [1377116.085735] e1000e: eth1 NIC Link is Up 100 Mbps Full Duplex, Flow Control: Rx/Tx
Dec 18 04:08:30 s12 kernel: [1377116.085737] e1000e 0000:00:1f.6 eth1: 10/100 speed: disabling TSO
Dec 18 04:08:30 s12 kernel: [1377116.758341] e1000e: eth1 NIC Link is Down
Dec 18 04:08:54 s12 kernel: [1377140.761595] e1000e: eth1 NIC Link is Up 100 Mbps Full Duplex, Flow Control: Rx/Tx
Dec 18 04:08:54 s12 kernel: [1377140.761598] e1000e 0000:00:1f.6 eth1: 10/100 speed: disabling TSO

docker logs during the problem end

time="2017-12-18T09:01:55.705616662Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:01:59.456996563Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:01:59.457327074Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:02:03.323972086Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:02:14.354313659Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:02:18.333047727Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:02:33.354474796Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:02:40.761720569Z" level=debug msg="Calling GET /v1.22/containers/8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75/json" 
time="2017-12-18T09:02:40.797047211Z" level=debug msg="Calling GET /v1.22/containers/json?limit=0" 
time="2017-12-18T09:02:41.774775377Z" level=debug msg="Calling GET /v1.22/containers/8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75/stats?stream=1" 
time="2017-12-18T09:02:43.473115244Z" level=debug msg="Calling GET /v1.22/containers/8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75/json" 
time="2017-12-18T09:02:43.475480742Z" level=debug msg="Calling GET /v1.22/containers/8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75/stats?stream=1" 
time="2017-12-18T09:02:48.353437090Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:03:00.911393681Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:03:00.911892201Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:03:03.358289928Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:03:18.364609422Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:03:31.494184786Z" level=debug msg="containerd: process exited" id=2c55603ca58b9d5f52bf70ed86f4807492b81210f5277c336deb42f4dc943e7e pid=init status=0 systemPid=26648 
time="2017-12-18T09:03:31.513277414Z" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"2c55603ca58b9d5f52bf70ed86f4807492b81210f5277c336deb42f4dc943e7e\", Status:0x0, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc4236d9a60)}" 
time="2017-12-18T09:03:31.513710884Z" level=debug msg="attach: stdout: end" 
time="2017-12-18T09:03:31.513786370Z" level=debug msg="attach: stderr: end" 
time="2017-12-18T09:03:31.514806763Z" level=debug msg="Revoking external connectivity on endpoint naughty_almeida (e4a9e4ec0d7619bc6528122078a0a4159666ac35d6dae456307622aafe86e767)" 
time="2017-12-18T09:03:31.516548282Z" level=debug msg="Calling GET /v1.22/containers/2c55603ca58b9d5f52bf70ed86f4807492b81210f5277c336deb42f4dc943e7e/json" 
time="2017-12-18T09:03:31.518092131Z" level=debug msg="Calling GET /v1.22/containers/2c55603ca58b9d5f52bf70ed86f4807492b81210f5277c336deb42f4dc943e7e/json" 
time="2017-12-18T09:03:32.779161728Z" level=debug msg="Releasing addresses for endpoint naughty_almeida's interface on network bridge" 
time="2017-12-18T09:03:32.779196562Z" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.4)" 
time="2017-12-18T09:03:34.375904726Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:03:34.860925968Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/ca7feb5f1fb9648148008f12a1ac08dae610856d8f53b454e3bfca5c60611ed9/merged" 
time="2017-12-18T09:03:34.861062578Z" level=debug msg="Tar with options on /mnt/ssd/docker/overlay2/ca7feb5f1fb9648148008f12a1ac08dae610856d8f53b454e3bfca5c60611ed9/diff" 
time="2017-12-18T09:03:34.862406518Z" level=debug msg="Applying tar in /mnt/ssd/docker/overlay2/fe9033ea6b1a3a57b36e442e8e82e44ab355c7f6dbb3995a2e8e0d55d4a14597/diff" 
time="2017-12-18T09:03:41.841087773Z" level=debug msg="Calling GET /v1.22/containers/json?limit=0" 
time="2017-12-18T09:03:48.369948969Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:04:02.380477846Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:04:02.380781581Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:04:03.373210685Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:04:18.377577808Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:04:33.645306347Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:04:41.901734011Z" level=debug msg="Calling GET /v1.22/containers/json?limit=0" 
time="2017-12-18T09:04:48.389795332Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:04:55.414531677Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:04:55.415061154Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:05:03.394572779Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:05:04.180060736Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:05:04.180587141Z" level=debug msg="Calling POST /v1.27/containers/8fa1efbc92a6/exec" 
time="2017-12-18T09:05:04.180673027Z" level=debug msg="form data: {\"AttachStderr\":true,\"AttachStdin\":true,\"AttachStdout\":true,\"Cmd\":[\"bash\"],\"Detach\":false,\"DetachKeys\":\"\",\"Env\":null,\"Privileged\":false,\"Tty\":true,\"User\":\"\"}" 
time="2017-12-18T09:05:04.181176308Z" level=debug msg="Calling POST /v1.27/exec/f4872eb5f71fed5d6d8d4d11ac361d1d21fb9e82871a570d20a937909fcddc30/start" 
time="2017-12-18T09:05:04.181255297Z" level=debug msg="form data: {\"AttachStderr\":true,\"AttachStdin\":true,\"AttachStdout\":true,\"Cmd\":[\"bash\"],\"Detach\":false,\"DetachKeys\":\"\",\"Env\":null,\"Privileged\":false,\"Tty\":true,\"User\":\"\"}" 
time="2017-12-18T09:05:04.181326943Z" level=debug msg="starting exec command f4872eb5f71fed5d6d8d4d11ac361d1d21fb9e82871a570d20a937909fcddc30 in container 8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75" 
time="2017-12-18T09:05:04.182488175Z" level=debug msg="Calling POST /v1.27/exec/f4872eb5f71fed5d6d8d4d11ac361d1d21fb9e82871a570d20a937909fcddc30/resize?h=52&w=199" 
time="2017-12-18T09:05:04.182593011Z" level=debug msg="attach: stdin: begin" 
time="2017-12-18T09:05:04.182624048Z" level=debug msg="attach: stdout: begin" 
time="2017-12-18T09:05:04.655076646Z" level=debug msg="containerd: container oom" id=8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75 
time="2017-12-18T09:05:04.655309772Z" level=error msg="Error running exec in container: rpc error: code = 2 desc = oci runtime error: exec failed: container_linux.go:247: starting container process caused \"exec: \\\"bash\\\": executable file not found in $PATH\"\n" 
time="2017-12-18T09:05:04.655399825Z" level=debug msg="Closing buffered stdin pipe" 
time="2017-12-18T09:05:04.655423380Z" level=debug msg="attach: stdin: end" 
time="2017-12-18T09:05:04.655429276Z" level=debug msg="attach: stdout: end" 
time="2017-12-18T09:05:04.656590507Z" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"oom\", Id:\"8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc420fa6960)}" 
time="2017-12-18T09:05:04.656760426Z" level=error msg="Handler for POST /v1.27/exec/f4872eb5f71fed5d6d8d4d11ac361d1d21fb9e82871a570d20a937909fcddc30/resize returned error: rpc error: code = 2 desc = containerd: process not found for container" 
time="2017-12-18T09:05:04.657079596Z" level=debug msg="Calling GET /v1.27/exec/f4872eb5f71fed5d6d8d4d11ac361d1d21fb9e82871a570d20a937909fcddc30/json" 
time="2017-12-18T09:05:06.381642725Z" level=debug msg="containerd: process exited" id=8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75 pid=init status=137 systemPid=28286 
time="2017-12-18T09:05:06.386055481Z" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75\", Status:0x89, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc42241b560)}" 
time="2017-12-18T09:05:06.386850943Z" level=debug msg="Calling GET /v1.22/containers/8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75/json" 
time="2017-12-18T09:05:06.387112005Z" level=debug msg="Calling GET /v1.22/containers/8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75/json" 
time="2017-12-18T09:05:09.107369511Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:05:09.108250599Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:05:18.401813969Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:05:25.122611534Z" level=debug msg="Applied tar sha256:7bba10b336c7e6c97b991a8230879b44a287febad2f32839c34789ee07f2938b to fe9033ea6b1a3a57b36e442e8e82e44ab355c7f6dbb3995a2e8e0d55d4a14597, size: 643949631" 
time="2017-12-18T09:05:26.994097351Z" level=debug msg="Calling GET /v1.22/containers/2c55603ca58b9d5f52bf70ed86f4807492b81210f5277c336deb42f4dc943e7e/json" 
time="2017-12-18T09:05:26.994129390Z" level=error msg="Handler for GET /v1.22/containers/2c55603ca58b9d5f52bf70ed86f4807492b81210f5277c336deb42f4dc943e7e/json returned error: No such container: 2c55603ca58b9d5f52bf70ed86f4807492b81210f5277c336deb42f4dc943e7e" 
time="2017-12-18T09:05:28.227578959Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/c3be84090c99aa255f022753a6b84c0fdb0c1dbf1c6e563d5551f3ba88fc6de0/merged" 
time="2017-12-18T09:05:28.373623236Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/c3be84090c99aa255f022753a6b84c0fdb0c1dbf1c6e563d5551f3ba88fc6de0/merged" 
time="2017-12-18T09:05:28.395286991Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/c3be84090c99aa255f022753a6b84c0fdb0c1dbf1c6e563d5551f3ba88fc6de0/merged" 
time="2017-12-18T09:05:28.395429025Z" level=debug msg="Tar with options on /mnt/ssd/docker/overlay2/c3be84090c99aa255f022753a6b84c0fdb0c1dbf1c6e563d5551f3ba88fc6de0/diff" 
time="2017-12-18T09:05:28.396791267Z" level=debug msg="Applying tar in /mnt/ssd/docker/overlay2/30e2fd0410807f2d6e772ac4421db4ddf979e3599220b87ffd2cdf3ce1187cd4/diff" 
time="2017-12-18T09:05:28.502878445Z" level=debug msg="Applied tar sha256:5f70bf18a086007016e948b04aed3b82103a36bea41755b6cddfaf10ace3c6ef to 30e2fd0410807f2d6e772ac4421db4ddf979e3599220b87ffd2cdf3ce1187cd4, size: 0" 
time="2017-12-18T09:05:29.314806970Z" level=info msg="Layer sha256:93074d184a78dc3ca19d0387883065418d182472dac028e2bd7599a4ecccd376 cleaned up" 
time="2017-12-18T09:05:29.484664530Z" level=debug msg="[BUILDER] Command to be executed: [/bin/sh -c git checkout \"99de0ad50225ee665a95d0ea1dc27bec4d015a48\"]" 
time="2017-12-18T09:05:29.485660082Z" level=debug msg="Calling GET /v1.22/containers/5e792dbcf62c5952364cf122efc441542823dc272b2e3d3fc9e164a87f575847/json" 
time="2017-12-18T09:05:29.485795192Z" level=error msg="Handler for GET /v1.22/containers/5e792dbcf62c5952364cf122efc441542823dc272b2e3d3fc9e164a87f575847/json returned error: No such container: 5e792dbcf62c5952364cf122efc441542823dc272b2e3d3fc9e164a87f575847" 
time="2017-12-18T09:05:29.722251284Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/ebec03a7c92b7ad460bee1035bf3313203c882e369225dc6a063e854f309ab1e/merged" 
time="2017-12-18T09:05:29.881089323Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/ebec03a7c92b7ad460bee1035bf3313203c882e369225dc6a063e854f309ab1e/merged" 
time="2017-12-18T09:05:29.881820410Z" level=debug msg="Assigning addresses for endpoint relaxed_curie's interface on network bridge" 
time="2017-12-18T09:05:29.881878457Z" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])" 
time="2017-12-18T09:05:29.883218634Z" level=debug msg="attach: stdout: begin" 
time="2017-12-18T09:05:29.883298660Z" level=debug msg="attach: stderr: begin" 
time="2017-12-18T09:05:29.938967696Z" level=debug msg="Assigning addresses for endpoint relaxed_curie's interface on network bridge" 
time="2017-12-18T09:05:30.171466322Z" level=debug msg="Programming external connectivity on endpoint relaxed_curie (3b1c44db38696815fc6a8c3a04b3c879226235ab6f1a5877693930ab187187e6)" 
time="2017-12-18T09:05:30.335460300Z" level=debug msg="logging driver fluentd configured" config={24224 127.0.0.1 tcp  0s 1048576 1000 1000000  true false} container=5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e 
time="2017-12-18T09:05:30.525808321Z" level=debug msg="sandbox set key processing took 92.292559ms for container 5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e" 
time="2017-12-18T09:05:30.599797118Z" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc4266e8a00)}" 
time="2017-12-18T09:05:30.749782738Z" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e\" timestamp:<seconds:1513587930 nanos:599654997 > " 
time="2017-12-18T09:05:30.750117658Z" level=debug msg="Calling GET /v1.22/containers/5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e/json" 
time="2017-12-18T09:05:30.750983411Z" level=debug msg="Calling GET /v1.22/containers/5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e/json" 
time="2017-12-18T09:05:30.767109122Z" level=debug msg="Calling GET /v1.22/containers/5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e/json" 
time="2017-12-18T09:05:31.875021301Z" level=debug msg="containerd: process exited" id=5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e pid=init status=0 systemPid=22791 
time="2017-12-18T09:05:31.879817515Z" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e\", Status:0x0, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc4266e9f70)}" 
time="2017-12-18T09:05:31.879981800Z" level=debug msg="attach: stdout: end" 
time="2017-12-18T09:05:31.879997906Z" level=debug msg="attach: stderr: end" 
time="2017-12-18T09:05:31.880306793Z" level=debug msg="Revoking external connectivity on endpoint relaxed_curie (3b1c44db38696815fc6a8c3a04b3c879226235ab6f1a5877693930ab187187e6)" 
time="2017-12-18T09:05:31.880424904Z" level=debug msg="Calling GET /v1.22/containers/5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e/json" 
time="2017-12-18T09:05:31.880694166Z" level=debug msg="Calling GET /v1.22/containers/5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e/json" 
time="2017-12-18T09:05:32.041449037Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:05:32.202514341Z" level=debug msg="Releasing addresses for endpoint relaxed_curie's interface on network bridge" 
time="2017-12-18T09:05:32.202538944Z" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.4)" 
time="2017-12-18T09:05:32.566608092Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/ebec03a7c92b7ad460bee1035bf3313203c882e369225dc6a063e854f309ab1e/merged" 
time="2017-12-18T09:05:32.566651305Z" level=debug msg="Tar with options on /mnt/ssd/docker/overlay2/ebec03a7c92b7ad460bee1035bf3313203c882e369225dc6a063e854f309ab1e/diff" 
time="2017-12-18T09:05:32.567004800Z" level=debug msg="Applying tar in /mnt/ssd/docker/overlay2/dd4cbda444adedca50751bba137c6e8fc5d0a10744e01332579df5bff96d10c2/diff" 
time="2017-12-18T09:05:32.578066290Z" level=debug msg="Calling GET /v1.22/containers/8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75/json" 
time="2017-12-18T09:05:32.578757820Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:05:32.589609832Z" level=debug msg="Calling POST /v1.22/containers/8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75/start" 
time="2017-12-18T09:05:32.593338876Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/045529259acb4c55d45960863335d2c7d5327a97626681e5f988d3f39413e7c9/merged" 
time="2017-12-18T09:05:33.281549103Z" level=debug msg="Applied tar sha256:36b738c897588ae2c485a3c33da5b03515095985a1487dcd3673bab583a41a17 to dd4cbda444adedca50751bba137c6e8fc5d0a10744e01332579df5bff96d10c2, size: 64374899" 
time="2017-12-18T09:05:33.884171773Z" level=debug msg="logging driver fluentd configured" config={24224 127.0.0.1 tcp  0s 1048576 1000 1000000  true false} container=8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75 
time="2017-12-18T09:05:34.267841577Z" level=debug msg="sandbox set key processing took 295.47834ms for container 8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75" 
time="2017-12-18T09:05:34.358540781Z" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc423442390)}" 
time="2017-12-18T09:05:34.426803124Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:05:34.630186294Z" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75\" timestamp:<seconds:1513587934 nanos:358285637 > " 
time="2017-12-18T09:05:34.636067104Z" level=debug msg="Calling GET /v1.22/containers/8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75/json" 
time="2017-12-18T09:05:34.637216310Z" level=debug msg="Calling GET /v1.22/containers/8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75/json" 
time="2017-12-18T09:05:34.655004799Z" level=debug msg="Calling GET /v1.22/containers/8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75/json" 
time="2017-12-18T09:05:34.656808882Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:05:34.685075964Z" level=debug msg="Calling GET /v1.22/containers/8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75/json" 
time="2017-12-18T09:05:34.685748477Z" level=debug msg="Calling GET /v1.22/containers/8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75/json" 
time="2017-12-18T09:05:34.946056085Z" level=debug msg="Calling GET /v1.22/images/sha256:7232e4f0a671b70ae15a2630e2ded10d5db6d2ffa2e76358d103a14913c4bc71/json" 
time="2017-12-18T09:05:35.168353291Z" level=debug msg="Calling GET /v1.22/containers/5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e/json" 
time="2017-12-18T09:05:35.168469684Z" level=error msg="Handler for GET /v1.22/containers/5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e/json returned error: No such container: 5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e" 
time="2017-12-18T09:05:41.424633665Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/1481428fd801dda6595f8a50c4667834c06ee6772308ffc95d58da7be5d47e70/merged" 
time="2017-12-18T09:05:41.569715263Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/1481428fd801dda6595f8a50c4667834c06ee6772308ffc95d58da7be5d47e70/merged" 
time="2017-12-18T09:05:41.569924276Z" level=debug msg="CopyFileWithTar(/mnt/ssd/docker/tmp/docker-builder465054075/modules.conf, /mnt/ssd/docker/overlay2/1481428fd801dda6595f8a50c4667834c06ee6772308ffc95d58da7be5d47e70/merged/usr/src/freeswitch/modules.conf)" 
time="2017-12-18T09:05:41.690685812Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:05:41.710718579Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/1481428fd801dda6595f8a50c4667834c06ee6772308ffc95d58da7be5d47e70/merged" 
time="2017-12-18T09:05:41.710778549Z" level=debug msg="CopyFileWithTar(/mnt/ssd/docker/tmp/docker-builder465054075/patches/conference_video.patch, /mnt/ssd/docker/overlay2/1481428fd801dda6595f8a50c4667834c06ee6772308ffc95d58da7be5d47e70/merged/usr/src/freeswitch/conference_video.patch)" 
time="2017-12-18T09:05:41.758661064Z" level=debug msg="Calling GET /v1.22/containers/301bd843c853ae734a1702d36cecd3343acf7e42618fec286ed22d87944be913/json" 
time="2017-12-18T09:05:41.798677954Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/1481428fd801dda6595f8a50c4667834c06ee6772308ffc95d58da7be5d47e70/merged" 
time="2017-12-18T09:05:41.798726562Z" level=debug msg="Tar with options on /mnt/ssd/docker/overlay2/1481428fd801dda6595f8a50c4667834c06ee6772308ffc95d58da7be5d47e70/diff" 
time="2017-12-18T09:05:41.799122175Z" level=debug msg="Applying tar in /mnt/ssd/docker/overlay2/4cf8bd2f48c89eaddc4a999838d6705bade066d70c1339953f9922afed5b6160/diff" 
time="2017-12-18T09:05:41.890566744Z" level=debug msg="Applied tar sha256:35979645ee40fd203e328a1eacff267d272543eceea2097e238f90a089e8abed to 4cf8bd2f48c89eaddc4a999838d6705bade066d70c1339953f9922afed5b6160, size: 4808" 
time="2017-12-18T09:05:41.984222516Z" level=debug msg="Calling GET /v1.22/containers/json?limit=0" 
time="2017-12-18T09:05:42.678133352Z" level=debug msg="[BUILDER] Command to be executed: [/bin/sh -c ./bootstrap.sh   && patch src/mod/applications/mod_conference/conference_video.c conference_video.patch   && ./configure --prefix=/opt/freeswitch   && make   && make install   && rm -r /opt/freeswitch/etc/freeswitch   && mkdir -p /opt/freeswitch/share/freeswitch/sounds/en/us/callie/   && mkdir -p /var/log/containers/voice-freeswitch-ms   && mkdir -p /tmp/records   && mkdir -p /tmp/dumps]" 
time="2017-12-18T09:05:42.678533716Z" level=debug msg="Calling GET /v1.22/containers/2c4e0becb180a53ac631c09bcb868f141c0c1481f834964ca3b23c23aba95318/json" 
time="2017-12-18T09:05:42.724235212Z" level=error msg="Handler for GET /v1.22/containers/2c4e0becb180a53ac631c09bcb868f141c0c1481f834964ca3b23c23aba95318/json returned error: No such container: 2c4e0becb180a53ac631c09bcb868f141c0c1481f834964ca3b23c23aba95318" 
time="2017-12-18T09:05:42.933402215Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/a98ced7176789266a2606190375a18668219c6e91b80f17b6650749aa85f1030/merged" 
time="2017-12-18T09:05:43.071816192Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/a98ced7176789266a2606190375a18668219c6e91b80f17b6650749aa85f1030/merged" 
time="2017-12-18T09:05:43.075185102Z" level=debug msg="attach: stdout: begin" 
time="2017-12-18T09:05:43.075572586Z" level=debug msg="attach: stderr: begin" 
time="2017-12-18T09:05:43.079138751Z" level=debug msg="Assigning addresses for endpoint blissful_wing's interface on network bridge" 
time="2017-12-18T09:05:43.079167860Z" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])" 
time="2017-12-18T09:05:43.150464098Z" level=debug msg="Assigning addresses for endpoint blissful_wing's interface on network bridge" 
time="2017-12-18T09:05:43.499569870Z" level=debug msg="Programming external connectivity on endpoint blissful_wing (df3a6f9d399c595d757092a5695ce6f3df42bb6f0e296bf1f17108d7aa998d05)" 
time="2017-12-18T09:05:43.671739137Z" level=debug msg="logging driver fluentd configured" config={24224 127.0.0.1 tcp  0s 1048576 1000 1000000  true false} container=6d0d1ced35572b7f29bc8149f09a2566de0798a7f6ba8944581a18417c7b1f5e 
time="2017-12-18T09:05:43.801158875Z" level=debug msg="sandbox set key processing took 94.28896ms for container 6d0d1ced35572b7f29bc8149f09a2566de0798a7f6ba8944581a18417c7b1f5e" 
time="2017-12-18T09:05:43.881993930Z" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"6d0d1ced35572b7f29bc8149f09a2566de0798a7f6ba8944581a18417c7b1f5e\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc425b00760)}" 
time="2017-12-18T09:05:44.027669657Z" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"6d0d1ced35572b7f29bc8149f09a2566de0798a7f6ba8944581a18417c7b1f5e\" timestamp:<seconds:1513587943 nanos:881591354 > " 
time="2017-12-18T09:05:44.028013707Z" level=debug msg="Calling GET /v1.22/containers/6d0d1ced35572b7f29bc8149f09a2566de0798a7f6ba8944581a18417c7b1f5e/json" 
time="2017-12-18T09:05:44.030167780Z" level=debug msg="Calling GET /v1.22/containers/6d0d1ced35572b7f29bc8149f09a2566de0798a7f6ba8944581a18417c7b1f5e/json" 
time="2017-12-18T09:05:44.030733419Z" level=debug msg="Calling GET /v1.22/containers/6d0d1ced35572b7f29bc8149f09a2566de0798a7f6ba8944581a18417c7b1f5e/json" 
time="2017-12-18T09:05:47.135095577Z" level=debug msg="Calling GET /v1.22/containers/301bd843c853ae734a1702d36cecd3343acf7e42618fec286ed22d87944be913/json" 
time="2017-12-18T09:05:48.412628566Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:06:03.420533650Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:06:09.399413747Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:06:09.400422494Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:06:10.830091644Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:06:10.897943350Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:06:17.775725034Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:06:17.776959424Z" level=debug msg="Calling POST /v1.27/containers/8fa1efbc92a6/exec" 
time="2017-12-18T09:06:17.777163947Z" level=debug msg="form data: {\"AttachStderr\":true,\"AttachStdin\":true,\"AttachStdout\":true,\"Cmd\":[\"bash\"],\"Detach\":false,\"DetachKeys\":\"\",\"Env\":null,\"Privileged\":false,\"Tty\":true,\"User\":\"\"}" 
time="2017-12-18T09:06:17.779044643Z" level=debug msg="Calling POST /v1.27/exec/81a040e71a800864c621fa042d057210a16b0b34204d041a1f12f2126d4bf258/start" 
time="2017-12-18T09:06:17.779287961Z" level=debug msg="form data: {\"AttachStderr\":true,\"AttachStdin\":true,\"AttachStdout\":true,\"Cmd\":[\"bash\"],\"Detach\":false,\"DetachKeys\":\"\",\"Env\":null,\"Privileged\":false,\"Tty\":true,\"User\":\"\"}" 
time="2017-12-18T09:06:17.779542487Z" level=debug msg="starting exec command 81a040e71a800864c621fa042d057210a16b0b34204d041a1f12f2126d4bf258 in container 8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75" 
time="2017-12-18T09:06:17.779748473Z" level=debug msg="attach: stdin: begin" 
time="2017-12-18T09:06:17.779991929Z" level=debug msg="attach: stdout: begin" 
time="2017-12-18T09:06:17.781244266Z" level=debug msg="Calling POST /v1.27/exec/81a040e71a800864c621fa042d057210a16b0b34204d041a1f12f2126d4bf258/resize?h=52&w=199" 
time="2017-12-18T09:06:17.899766812Z" level=error msg="Error running exec in container: rpc error: code = 2 desc = oci runtime error: exec failed: container_linux.go:247: starting container process caused \"exec: \\\"bash\\\": executable file not found in $PATH\"\n" 
time="2017-12-18T09:06:17.899938198Z" level=debug msg="Closing buffered stdin pipe" 
time="2017-12-18T09:06:17.899975981Z" level=debug msg="attach: stdin: end" 
time="2017-12-18T09:06:17.900000805Z" level=debug msg="attach: stdout: end" 
time="2017-12-18T09:06:17.900595384Z" level=error msg="Handler for POST /v1.27/exec/81a040e71a800864c621fa042d057210a16b0b34204d041a1f12f2126d4bf258/resize returned error: rpc error: code = 2 desc = containerd: process not found for container" 
time="2017-12-18T09:06:17.901416903Z" level=debug msg="Calling GET /v1.27/exec/81a040e71a800864c621fa042d057210a16b0b34204d041a1f12f2126d4bf258/json" 
time="2017-12-18T09:06:18.425528144Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:06:20.463006624Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:06:20.464219241Z" level=debug msg="Calling POST /v1.27/containers/8fa1efbc92a6/exec" 
time="2017-12-18T09:06:20.464428011Z" level=debug msg="form data: {\"AttachStderr\":true,\"AttachStdin\":true,\"AttachStdout\":true,\"Cmd\":[\"sh\"],\"Detach\":false,\"DetachKeys\":\"\",\"Env\":null,\"Privileged\":false,\"Tty\":true,\"User\":\"\"}" 
time="2017-12-18T09:06:20.465642895Z" level=debug msg="Calling POST /v1.27/exec/3882a648b32a7e1347299bb625fd190c5bbfabd960241ef567fda5a284f517f0/start" 
time="2017-12-18T09:06:20.465852850Z" level=debug msg="form data: {\"AttachStderr\":true,\"AttachStdin\":true,\"AttachStdout\":true,\"Cmd\":[\"sh\"],\"Detach\":false,\"DetachKeys\":\"\",\"Env\":null,\"Privileged\":false,\"Tty\":true,\"User\":\"\"}" 
time="2017-12-18T09:06:20.466066307Z" level=debug msg="starting exec command 3882a648b32a7e1347299bb625fd190c5bbfabd960241ef567fda5a284f517f0 in container 8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75" 
time="2017-12-18T09:06:20.466730901Z" level=debug msg="Calling POST /v1.27/exec/3882a648b32a7e1347299bb625fd190c5bbfabd960241ef567fda5a284f517f0/resize?h=52&w=199" 
time="2017-12-18T09:06:20.466865311Z" level=debug msg="attach: stdin: begin" 
time="2017-12-18T09:06:20.467118889Z" level=debug msg="attach: stdout: begin" 
time="2017-12-18T09:06:20.555311304Z" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-process\", Id:\"8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75\", Status:0x0, Pid:\"3882a648b32a7e1347299bb625fd190c5bbfabd960241ef567fda5a284f517f0\", Timestamp:(*timestamp.Timestamp)(0xc427696e50)}" 
time="2017-12-18T09:06:20.555727148Z" level=debug msg="libcontainerd: event unhandled: type:\"start-process\" id:\"8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75\" pid:\"3882a648b32a7e1347299bb625fd190c5bbfabd960241ef567fda5a284f517f0\" timestamp:<seconds:1513587980 nanos:555186472 > " 
time="2017-12-18T09:06:33.433689835Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:06:36.561542238Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:06:42.071779575Z" level=debug msg="Calling GET /v1.22/containers/json?limit=0" 
time="2017-12-18T09:06:44.492616611Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:05:26.994129390Z" level=error msg="Handler for GET /v1.22/containers/2c55603ca58b9d5f52bf70ed86f4807492b81210f5277c336deb42f4dc943e7e/json returned error: No such container: 2c556
03ca58b9d5f52bf70ed86f4807492b81210f5277c336deb42f4dc943e7e" 
time="2017-12-18T09:05:28.227578959Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/c3be84090c99aa255f022753a6b84c0fdb0c1dbf1c6e563d5551f3ba88fc6de0/merged" 
time="2017-12-18T09:05:28.373623236Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/c3be84090c99aa255f022753a6b84c0fdb0c1dbf1c6e563d5551f3ba88fc6de0/merged" 
time="2017-12-18T09:05:28.395286991Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/c3be84090c99aa255f022753a6b84c0fdb0c1dbf1c6e563d5551f3ba88fc6de0/merged" 
time="2017-12-18T09:05:28.395429025Z" level=debug msg="Tar with options on /mnt/ssd/docker/overlay2/c3be84090c99aa255f022753a6b84c0fdb0c1dbf1c6e563d5551f3ba88fc6de0/diff" 
time="2017-12-18T09:05:28.396791267Z" level=debug msg="Applying tar in /mnt/ssd/docker/overlay2/30e2fd0410807f2d6e772ac4421db4ddf979e3599220b87ffd2cdf3ce1187cd4/diff" 
time="2017-12-18T09:05:28.502878445Z" level=debug msg="Applied tar sha256:5f70bf18a086007016e948b04aed3b82103a36bea41755b6cddfaf10ace3c6ef to 30e2fd0410807f2d6e772ac4421db4ddf979e3599220b87ffd2cdf3ce
1187cd4, size: 0" 
time="2017-12-18T09:05:29.314806970Z" level=info msg="Layer sha256:93074d184a78dc3ca19d0387883065418d182472dac028e2bd7599a4ecccd376 cleaned up" 
time="2017-12-18T09:05:29.484664530Z" level=debug msg="[BUILDER] Command to be executed: [/bin/sh -c git checkout \"99de0ad50225ee665a95d0ea1dc27bec4d015a48\"]" 
time="2017-12-18T09:05:29.485660082Z" level=debug msg="Calling GET /v1.22/containers/5e792dbcf62c5952364cf122efc441542823dc272b2e3d3fc9e164a87f575847/json" 
time="2017-12-18T09:05:29.485795192Z" level=error msg="Handler for GET /v1.22/containers/5e792dbcf62c5952364cf122efc441542823dc272b2e3d3fc9e164a87f575847/json returned error: No such container: 5e792
dbcf62c5952364cf122efc441542823dc272b2e3d3fc9e164a87f575847" 
time="2017-12-18T09:05:29.722251284Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/ebec03a7c92b7ad460bee1035bf3313203c882e369225dc6a063e854f309ab1e/merged" 
time="2017-12-18T09:05:29.881089323Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/ebec03a7c92b7ad460bee1035bf3313203c882e369225dc6a063e854f309ab1e/merged" 
time="2017-12-18T09:05:29.881820410Z" level=debug msg="Assigning addresses for endpoint relaxed_curie's interface on network bridge" 
time="2017-12-18T09:05:29.881878457Z" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])" 
time="2017-12-18T09:05:29.883218634Z" level=debug msg="attach: stdout: begin" 
time="2017-12-18T09:05:29.883298660Z" level=debug msg="attach: stderr: begin" 
time="2017-12-18T09:05:29.938967696Z" level=debug msg="Assigning addresses for endpoint relaxed_curie's interface on network bridge" 
time="2017-12-18T09:05:30.171466322Z" level=debug msg="Programming external connectivity on endpoint relaxed_curie (3b1c44db38696815fc6a8c3a04b3c879226235ab6f1a5877693930ab187187e6)" 
time="2017-12-18T09:05:30.335460300Z" level=debug msg="logging driver fluentd configured" config={24224 127.0.0.1 tcp  0s 1048576 1000 1000000  true false} container=5424132a1cd94269b3279f0b77a559629
451b48ded2817634ba1670065452d4e 
time="2017-12-18T09:05:30.525808321Z" level=debug msg="sandbox set key processing took 92.292559ms for container 5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e" 
time="2017-12-18T09:05:30.599797118Z" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065
452d4e\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc4266e8a00)}" 
time="2017-12-18T09:05:30.749782738Z" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e\" timestamp:<seco
nds:1513587930 nanos:599654997 > " 
time="2017-12-18T09:05:30.750117658Z" level=debug msg="Calling GET /v1.22/containers/5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e/json" 
time="2017-12-18T09:05:30.750983411Z" level=debug msg="Calling GET /v1.22/containers/5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e/json" 
time="2017-12-18T09:05:30.767109122Z" level=debug msg="Calling GET /v1.22/containers/5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e/json" 
time="2017-12-18T09:05:31.875021301Z" level=debug msg="containerd: process exited" id=5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e pid=init status=0 systemPid=22791 
time="2017-12-18T09:05:31.879817515Z" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e\", S
tatus:0x0, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc4266e9f70)}" 
time="2017-12-18T09:05:31.879981800Z" level=debug msg="attach: stdout: end" 
time="2017-12-18T09:05:31.879997906Z" level=debug msg="attach: stderr: end" 
time="2017-12-18T09:05:31.880306793Z" level=debug msg="Revoking external connectivity on endpoint relaxed_curie (3b1c44db38696815fc6a8c3a04b3c879226235ab6f1a5877693930ab187187e6)" 
time="2017-12-18T09:05:31.880424904Z" level=debug msg="Calling GET /v1.22/containers/5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e/json" 
time="2017-12-18T09:05:31.880694166Z" level=debug msg="Calling GET /v1.22/containers/5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e/json" 
time="2017-12-18T09:05:32.041449037Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:05:32.202514341Z" level=debug msg="Releasing addresses for endpoint relaxed_curie's interface on network bridge" 
time="2017-12-18T09:05:32.202538944Z" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.4)" 
time="2017-12-18T09:05:32.566608092Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/ebec03a7c92b7ad460bee1035bf3313203c882e369225dc6a063e854f309ab1e/merged" 
time="2017-12-18T09:05:32.566651305Z" level=debug msg="Tar with options on /mnt/ssd/docker/overlay2/ebec03a7c92b7ad460bee1035bf3313203c882e369225dc6a063e854f309ab1e/diff" 
time="2017-12-18T09:05:32.567004800Z" level=debug msg="Applying tar in /mnt/ssd/docker/overlay2/dd4cbda444adedca50751bba137c6e8fc5d0a10744e01332579df5bff96d10c2/diff" 
time="2017-12-18T09:05:32.578066290Z" level=debug msg="Calling GET /v1.22/containers/8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75/json" 
time="2017-12-18T09:05:32.578757820Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:05:32.589609832Z" level=debug msg="Calling POST /v1.22/containers/8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75/start" 
time="2017-12-18T09:05:32.593338876Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/045529259acb4c55d45960863335d2c7d5327a97626681e5f988d3f39413e7c9/merged" 
time="2017-12-18T09:05:33.281549103Z" level=debug msg="Applied tar sha256:36b738c897588ae2c485a3c33da5b03515095985a1487dcd3673bab583a41a17 to dd4cbda444adedca50751bba137c6e8fc5d0a10744e01332579df5bff
96d10c2, size: 64374899" 
time="2017-12-18T09:05:33.884171773Z" level=debug msg="logging driver fluentd configured" config={24224 127.0.0.1 tcp  0s 1048576 1000 1000000  true false} container=8fa1efbc92a6db38517a5db7ba83d3671
5ab0eab7f7878157f9e3085ff1c0b75 
time="2017-12-18T09:05:34.267841577Z" level=debug msg="sandbox set key processing took 295.47834ms for container 8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75" 
time="2017-12-18T09:05:34.358540781Z" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff
1c0b75\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc423442390)}" 
time="2017-12-18T09:05:34.426803124Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:05:34.630186294Z" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75\" timestamp:<seco
nds:1513587934 nanos:358285637 > " 
time="2017-12-18T09:05:34.636067104Z" level=debug msg="Calling GET /v1.22/containers/8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75/json" 
time="2017-12-18T09:05:34.637216310Z" level=debug msg="Calling GET /v1.22/containers/8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75/json" 
time="2017-12-18T09:05:34.655004799Z" level=debug msg="Calling GET /v1.22/containers/8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75/json" 
time="2017-12-18T09:05:34.656808882Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:05:34.685075964Z" level=debug msg="Calling GET /v1.22/containers/8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75/json" 
time="2017-12-18T09:05:34.685748477Z" level=debug msg="Calling GET /v1.22/containers/8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75/json" 
time="2017-12-18T09:05:34.946056085Z" level=debug msg="Calling GET /v1.22/images/sha256:7232e4f0a671b70ae15a2630e2ded10d5db6d2ffa2e76358d103a14913c4bc71/json" 
time="2017-12-18T09:05:35.168353291Z" level=debug msg="Calling GET /v1.22/containers/5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e/json" 
time="2017-12-18T09:05:35.168469684Z" level=error msg="Handler for GET /v1.22/containers/5424132a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e/json returned error: No such container: 54241
32a1cd94269b3279f0b77a559629451b48ded2817634ba1670065452d4e" 
time="2017-12-18T09:05:41.424633665Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/1481428fd801dda6595f8a50c4667834c06ee6772308ffc95d58da7be5d47e70/merged" 
time="2017-12-18T09:05:41.569715263Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/1481428fd801dda6595f8a50c4667834c06ee6772308ffc95d58da7be5d47e70/merged" 
time="2017-12-18T09:05:41.569924276Z" level=debug msg="CopyFileWithTar(/mnt/ssd/docker/tmp/docker-builder465054075/modules.conf, /mnt/ssd/docker/overlay2/1481428fd801dda6595f8a50c4667834c06ee6772308f
fc95d58da7be5d47e70/merged/usr/src/freeswitch/modules.conf)" 
time="2017-12-18T09:05:41.690685812Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:05:41.710718579Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/1481428fd801dda6595f8a50c4667834c06ee6772308ffc95d58da7be5d47e70/merged" 
time="2017-12-18T09:05:41.710778549Z" level=debug msg="CopyFileWithTar(/mnt/ssd/docker/tmp/docker-builder465054075/patches/conference_video.patch, /mnt/ssd/docker/overlay2/1481428fd801dda6595f8a50c46
67834c06ee6772308ffc95d58da7be5d47e70/merged/usr/src/freeswitch/conference_video.patch)" 
time="2017-12-18T09:05:41.758661064Z" level=debug msg="Calling GET /v1.22/containers/301bd843c853ae734a1702d36cecd3343acf7e42618fec286ed22d87944be913/json" 
time="2017-12-18T09:05:41.798677954Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/1481428fd801dda6595f8a50c4667834c06ee6772308ffc95d58da7be5d47e70/merged" 
time="2017-12-18T09:05:41.798726562Z" level=debug msg="Tar with options on /mnt/ssd/docker/overlay2/1481428fd801dda6595f8a50c4667834c06ee6772308ffc95d58da7be5d47e70/diff" 
time="2017-12-18T09:05:41.799122175Z" level=debug msg="Applying tar in /mnt/ssd/docker/overlay2/4cf8bd2f48c89eaddc4a999838d6705bade066d70c1339953f9922afed5b6160/diff" 
time="2017-12-18T09:05:41.890566744Z" level=debug msg="Applied tar sha256:35979645ee40fd203e328a1eacff267d272543eceea2097e238f90a089e8abed to 4cf8bd2f48c89eaddc4a999838d6705bade066d70c1339953f9922afe
d5b6160, size: 4808" 
time="2017-12-18T09:05:41.984222516Z" level=debug msg="Calling GET /v1.22/containers/json?limit=0" 
time="2017-12-18T09:05:42.678133352Z" level=debug msg="[BUILDER] Command to be executed: [/bin/sh -c ./bootstrap.sh   && patch src/mod/applications/mod_conference/conference_video.c conference_video.
patch   && ./configure --prefix=/opt/freeswitch   && make   && make install   && rm -r /opt/freeswitch/etc/freeswitch   && mkdir -p /opt/freeswitch/share/freeswitch/sounds/en/us/callie/   && mkdir -p
 /var/log/containers/voice-freeswitch-ms   && mkdir -p /tmp/records   && mkdir -p /tmp/dumps]" 
time="2017-12-18T09:05:42.678533716Z" level=debug msg="Calling GET /v1.22/containers/2c4e0becb180a53ac631c09bcb868f141c0c1481f834964ca3b23c23aba95318/json" 
time="2017-12-18T09:05:42.724235212Z" level=error msg="Handler for GET /v1.22/containers/2c4e0becb180a53ac631c09bcb868f141c0c1481f834964ca3b23c23aba95318/json returned error: No such container: 2c4e0
becb180a53ac631c09bcb868f141c0c1481f834964ca3b23c23aba95318" 
time="2017-12-18T09:05:42.933402215Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/a98ced7176789266a2606190375a18668219c6e91b80f17b6650749aa85f1030/merged" 
time="2017-12-18T09:05:43.071816192Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/a98ced7176789266a2606190375a18668219c6e91b80f17b6650749aa85f1030/merged" 
time="2017-12-18T09:05:43.075185102Z" level=debug msg="attach: stdout: begin" 
time="2017-12-18T09:05:43.075572586Z" level=debug msg="attach: stderr: begin" 
time="2017-12-18T09:05:43.079138751Z" level=debug msg="Assigning addresses for endpoint blissful_wing's interface on network bridge" 
time="2017-12-18T09:05:43.079167860Z" level=debug msg="RequestAddress(LocalDefault/172.17.0.0/16, <nil>, map[])" 
time="2017-12-18T09:05:43.150464098Z" level=debug msg="Assigning addresses for endpoint blissful_wing's interface on network bridge" 
time="2017-12-18T09:05:43.499569870Z" level=debug msg="Programming external connectivity on endpoint blissful_wing (df3a6f9d399c595d757092a5695ce6f3df42bb6f0e296bf1f17108d7aa998d05)" 
time="2017-12-18T09:05:43.671739137Z" level=debug msg="logging driver fluentd configured" config={24224 127.0.0.1 tcp  0s 1048576 1000 1000000  true false} container=6d0d1ced35572b7f29bc8149f09a2566d
e0798a7f6ba8944581a18417c7b1f5e 
time="2017-12-18T09:05:43.801158875Z" level=debug msg="sandbox set key processing took 94.28896ms for container 6d0d1ced35572b7f29bc8149f09a2566de0798a7f6ba8944581a18417c7b1f5e" 
time="2017-12-18T09:05:43.881993930Z" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-container\", Id:\"6d0d1ced35572b7f29bc8149f09a2566de0798a7f6ba8944581a18417c
7b1f5e\", Status:0x0, Pid:\"\", Timestamp:(*timestamp.Timestamp)(0xc425b00760)}" 
time="2017-12-18T09:05:44.027669657Z" level=debug msg="libcontainerd: event unhandled: type:\"start-container\" id:\"6d0d1ced35572b7f29bc8149f09a2566de0798a7f6ba8944581a18417c7b1f5e\" timestamp:<seco
nds:1513587943 nanos:881591354 > " 
time="2017-12-18T09:05:44.028013707Z" level=debug msg="Calling GET /v1.22/containers/6d0d1ced35572b7f29bc8149f09a2566de0798a7f6ba8944581a18417c7b1f5e/json" 
time="2017-12-18T09:05:44.030167780Z" level=debug msg="Calling GET /v1.22/containers/6d0d1ced35572b7f29bc8149f09a2566de0798a7f6ba8944581a18417c7b1f5e/json" 
time="2017-12-18T09:05:44.030733419Z" level=debug msg="Calling GET /v1.22/containers/6d0d1ced35572b7f29bc8149f09a2566de0798a7f6ba8944581a18417c7b1f5e/json" 
time="2017-12-18T09:05:47.135095577Z" level=debug msg="Calling GET /v1.22/containers/301bd843c853ae734a1702d36cecd3343acf7e42618fec286ed22d87944be913/json" 
time="2017-12-18T09:05:48.412628566Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:06:03.420533650Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:06:09.399413747Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:06:09.400422494Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:06:10.830091644Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:06:10.897943350Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:06:17.775725034Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:06:17.776959424Z" level=debug msg="Calling POST /v1.27/containers/8fa1efbc92a6/exec" 
time="2017-12-18T09:06:17.777163947Z" level=debug msg="form data: {\"AttachStderr\":true,\"AttachStdin\":true,\"AttachStdout\":true,\"Cmd\":[\"bash\"],\"Detach\":false,\"DetachKeys\":\"\",\"Env\":nul
l,\"Privileged\":false,\"Tty\":true,\"User\":\"\"}" 
time="2017-12-18T09:06:17.779044643Z" level=debug msg="Calling POST /v1.27/exec/81a040e71a800864c621fa042d057210a16b0b34204d041a1f12f2126d4bf258/start" 
time="2017-12-18T09:06:17.779287961Z" level=debug msg="form data: {\"AttachStderr\":true,\"AttachStdin\":true,\"AttachStdout\":true,\"Cmd\":[\"bash\"],\"Detach\":false,\"DetachKeys\":\"\",\"Env\":nul
l,\"Privileged\":false,\"Tty\":true,\"User\":\"\"}" 
time="2017-12-18T09:06:17.779542487Z" level=debug msg="starting exec command 81a040e71a800864c621fa042d057210a16b0b34204d041a1f12f2126d4bf258 in container 8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f78
78157f9e3085ff1c0b75" 
time="2017-12-18T09:06:17.779748473Z" level=debug msg="attach: stdin: begin" 
time="2017-12-18T09:06:17.779991929Z" level=debug msg="attach: stdout: begin" 
time="2017-12-18T09:06:17.781244266Z" level=debug msg="Calling POST /v1.27/exec/81a040e71a800864c621fa042d057210a16b0b34204d041a1f12f2126d4bf258/resize?h=52&w=199" 
time="2017-12-18T09:06:17.899766812Z" level=error msg="Error running exec in container: rpc error: code = 2 desc = oci runtime error: exec failed: container_linux.go:247: starting container process c
aused \"exec: \\\"bash\\\": executable file not found in $PATH\"\n" 
time="2017-12-18T09:06:17.899938198Z" level=debug msg="Closing buffered stdin pipe" 
time="2017-12-18T09:06:17.899975981Z" level=debug msg="attach: stdin: end" 
time="2017-12-18T09:06:17.900000805Z" level=debug msg="attach: stdout: end" 
time="2017-12-18T09:06:17.900595384Z" level=error msg="Handler for POST /v1.27/exec/81a040e71a800864c621fa042d057210a16b0b34204d041a1f12f2126d4bf258/resize returned error: rpc error: code = 2 desc = 
containerd: process not found for container" 
time="2017-12-18T09:06:17.901416903Z" level=debug msg="Calling GET /v1.27/exec/81a040e71a800864c621fa042d057210a16b0b34204d041a1f12f2126d4bf258/json" 
time="2017-12-18T09:06:18.425528144Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:06:20.463006624Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:06:20.464219241Z" level=debug msg="Calling POST /v1.27/containers/8fa1efbc92a6/exec" 
time="2017-12-18T09:06:20.464428011Z" level=debug msg="form data: {\"AttachStderr\":true,\"AttachStdin\":true,\"AttachStdout\":true,\"Cmd\":[\"sh\"],\"Detach\":false,\"DetachKeys\":\"\",\"Env\":null,
\"Privileged\":false,\"Tty\":true,\"User\":\"\"}" 
time="2017-12-18T09:06:20.465642895Z" level=debug msg="Calling POST /v1.27/exec/3882a648b32a7e1347299bb625fd190c5bbfabd960241ef567fda5a284f517f0/start" 
time="2017-12-18T09:06:20.465852850Z" level=debug msg="form data: {\"AttachStderr\":true,\"AttachStdin\":true,\"AttachStdout\":true,\"Cmd\":[\"sh\"],\"Detach\":false,\"DetachKeys\":\"\",\"Env\":null,
\"Privileged\":false,\"Tty\":true,\"User\":\"\"}" 
time="2017-12-18T09:06:20.466066307Z" level=debug msg="starting exec command 3882a648b32a7e1347299bb625fd190c5bbfabd960241ef567fda5a284f517f0 in container 8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f78
78157f9e3085ff1c0b75" 
time="2017-12-18T09:06:20.466730901Z" level=debug msg="Calling POST /v1.27/exec/3882a648b32a7e1347299bb625fd190c5bbfabd960241ef567fda5a284f517f0/resize?h=52&w=199" 
time="2017-12-18T09:06:20.466865311Z" level=debug msg="attach: stdin: begin" 
time="2017-12-18T09:06:20.467118889Z" level=debug msg="attach: stdout: begin" 
time="2017-12-18T09:06:20.555311304Z" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"start-process\", Id:\"8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c
0b75\", Status:0x0, Pid:\"3882a648b32a7e1347299bb625fd190c5bbfabd960241ef567fda5a284f517f0\", Timestamp:(*timestamp.Timestamp)(0xc427696e50)}" 
time="2017-12-18T09:06:20.555727148Z" level=debug msg="libcontainerd: event unhandled: type:\"start-process\" id:\"8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75\" pid:\"3882a648b32
a7e1347299bb625fd190c5bbfabd960241ef567fda5a284f517f0\" timestamp:<seconds:1513587980 nanos:555186472 > " 
time="2017-12-18T09:06:33.433689835Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:06:36.561542238Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:06:42.071779575Z" level=debug msg="Calling GET /v1.22/containers/json?limit=0" 
time="2017-12-18T09:06:44.492616611Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:06:44.505253189Z" level=debug msg="Calling GET /v1.22/containers/6d0d1ced35572b7f29bc8149f09a2566de0798a7f6ba8944581a18417c7b1f5e/json" 
time="2017-12-18T09:06:44.505779547Z" level=debug msg="Calling GET /v1.22/containers/6d0d1ced35572b7f29bc8149f09a2566de0798a7f6ba8944581a18417c7b1f5e/json" 
time="2017-12-18T09:06:44.506286974Z" level=debug msg="Calling GET /v1.22/images/sha256:b32ebca23798d3fd51ed374cb08184a7a6b097c446d684b82b110f2113b49175/json" 
time="2017-12-18T09:06:48.437708490Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:06:55.178560573Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:07:03.442514964Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:07:12.189632364Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:07:12.189851861Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:07:14.371973866Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:07:18.445141332Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:07:34.463937116Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:07:42.137368880Z" level=debug msg="Calling GET /v1.22/containers/json?limit=0" 
time="2017-12-18T09:07:46.495689396Z" level=debug msg="clean 2 unused exec commands" 
time="2017-12-18T09:07:48.453572554Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:08:03.460936697Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:08:13.770391244Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:08:13.818074647Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:08:18.465463212Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:08:33.479041328Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:08:42.198716231Z" level=debug msg="Calling GET /v1.22/containers/json?limit=0" 
time="2017-12-18T09:08:48.474858984Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:09:03.478803353Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:09:15.321137738Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:09:15.321478961Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:09:18.481343784Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:09:34.489907850Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:09:48.489717856Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:10:03.492941695Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:10:16.917268987Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:10:16.917727728Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:10:18.496172955Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:10:33.502580355Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:10:48.502411289Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:11:03.505376110Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:11:18.493036878Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:11:18.493340451Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:11:18.507669616Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:11:34.517478109Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:11:48.517611169Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:11:48.633705402Z" level=debug msg="containerd: process exited" id=8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75 pid=3882a648b32a7e1347299bb625fd190c5bbfabd960241ef567fda5a284f517f0 status=0 systemPid=2436 
time="2017-12-18T09:11:48.634963571Z" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75\", Status:0x0, Pid:\"3882a648b32a7e1347299bb625fd190c5bbfabd960241ef567fda5a284f517f0\", Timestamp:(*timestamp.Timestamp)(0xc427130260)}" 
time="2017-12-18T09:11:48.635259477Z" level=debug msg="attach: stdout: end" 
time="2017-12-18T09:11:48.635295338Z" level=debug msg="attach: stdin: end" 
time="2017-12-18T09:11:48.635417120Z" level=debug msg="Closing buffered stdin pipe" 
time="2017-12-18T09:11:48.636542305Z" level=debug msg="Calling GET /v1.27/exec/3882a648b32a7e1347299bb625fd190c5bbfabd960241ef567fda5a284f517f0/json" 
time="2017-12-18T09:12:03.522138119Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:12:14.414810977Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:12:18.525708489Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:12:20.112714789Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:12:20.112989620Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:12:33.533847474Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:12:48.537524690Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:13:03.537976306Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:13:18.541208742Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:13:21.660583701Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:13:21.661022700Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:13:34.552850428Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:13:40.846370873Z" level=debug msg="containerd: process exited" id=6d0d1ced35572b7f29bc8149f09a2566de0798a7f6ba8944581a18417c7b1f5e pid=init status=0 systemPid=26039 
time="2017-12-18T09:13:40.850595104Z" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"6d0d1ced35572b7f29bc8149f09a2566de0798a7f6ba8944581a18417c7b1f5e\", Status:0x0, Pid:\"init\", Timestamp:(*timestamp.Timestamp)(0xc427283b50)}" 
time="2017-12-18T09:13:40.850708100Z" level=debug msg="attach: stdout: end" 
time="2017-12-18T09:13:40.850717160Z" level=debug msg="attach: stderr: end" 
time="2017-12-18T09:13:40.851053615Z" level=debug msg="Revoking external connectivity on endpoint blissful_wing (df3a6f9d399c595d757092a5695ce6f3df42bb6f0e296bf1f17108d7aa998d05)" 
time="2017-12-18T09:13:40.851267999Z" level=debug msg="Calling GET /v1.22/containers/6d0d1ced35572b7f29bc8149f09a2566de0798a7f6ba8944581a18417c7b1f5e/json" 
time="2017-12-18T09:13:40.851296240Z" level=debug msg="Calling GET /v1.22/containers/6d0d1ced35572b7f29bc8149f09a2566de0798a7f6ba8944581a18417c7b1f5e/json" 
time="2017-12-18T09:13:41.264450446Z" level=debug msg="Releasing addresses for endpoint blissful_wing's interface on network bridge" 
time="2017-12-18T09:13:41.264533892Z" level=debug msg="ReleaseAddress(LocalDefault/172.17.0.0/16, 172.17.0.4)" 
time="2017-12-18T09:13:41.545266662Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/a98ced7176789266a2606190375a18668219c6e91b80f17b6650749aa85f1030/merged" 
time="2017-12-18T09:13:41.545335504Z" level=debug msg="Tar with options on /mnt/ssd/docker/overlay2/a98ced7176789266a2606190375a18668219c6e91b80f17b6650749aa85f1030/diff" 
time="2017-12-18T09:13:41.545736945Z" level=debug msg="Applying tar in /mnt/ssd/docker/overlay2/3db5217a8df639daf00d61c8eabed8a301810500c7752877bd7da368502fdb7d/diff" 
time="2017-12-18T09:13:42.688140555Z" level=debug msg="Calling GET /v1.22/containers/301bd843c853ae734a1702d36cecd3343acf7e42618fec286ed22d87944be913/json" 
time="2017-12-18T09:13:42.770776880Z" level=debug msg="Calling GET /v1.22/containers/json?limit=0" 
time="2017-12-18T09:13:43.455116672Z" level=debug msg="Applied tar sha256:c4ff3fb7b9e18e5aa6de6426345f33a0c313455342572d4862a3df6c2197aa1f to 3db5217a8df639daf00d61c8eabed8a301810500c7752877bd7da368502fdb7d, size: 309302722" 
time="2017-12-18T09:13:47.448560351Z" level=debug msg="Calling GET /v1.22/containers/6d0d1ced35572b7f29bc8149f09a2566de0798a7f6ba8944581a18417c7b1f5e/json" 
time="2017-12-18T09:13:47.448682124Z" level=error msg="Handler for GET /v1.22/containers/6d0d1ced35572b7f29bc8149f09a2566de0798a7f6ba8944581a18417c7b1f5e/json returned error: No such container: 6d0d1ced35572b7f29bc8149f09a2566de0798a7f6ba8944581a18417c7b1f5e" 
time="2017-12-18T09:13:47.616301996Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/2e86018bf4d374965bedd3aa2ffccd3cd4e249b34da26400d78558fc42a2df67/merged" 
time="2017-12-18T09:13:47.780781322Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/2e86018bf4d374965bedd3aa2ffccd3cd4e249b34da26400d78558fc42a2df67/merged" 
time="2017-12-18T09:13:47.780876842Z" level=debug msg="CopyFileWithTar(/mnt/ssd/docker/tmp/docker-builder465054075/mocart.wav, /mnt/ssd/docker/overlay2/2e86018bf4d374965bedd3aa2ffccd3cd4e249b34da26400d78558fc42a2df67/merged/opt/freeswitch/share/freeswitch/sounds/en/us/callie/mocart.wav)" 
time="2017-12-18T09:13:47.886800955Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/2e86018bf4d374965bedd3aa2ffccd3cd4e249b34da26400d78558fc42a2df67/merged" 
time="2017-12-18T09:13:47.886895024Z" level=debug msg="CopyFileWithTar(/mnt/ssd/docker/tmp/docker-builder465054075/gooogok1.wav, /mnt/ssd/docker/overlay2/2e86018bf4d374965bedd3aa2ffccd3cd4e249b34da26400d78558fc42a2df67/merged/opt/freeswitch/share/freeswitch/sounds/en/us/callie/gooogok1.wav)" 
time="2017-12-18T09:13:48.011421489Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/2e86018bf4d374965bedd3aa2ffccd3cd4e249b34da26400d78558fc42a2df67/merged" 
time="2017-12-18T09:13:48.011755569Z" level=debug msg="CopyFileWithTar(/mnt/ssd/docker/tmp/docker-builder465054075/test.wav, /mnt/ssd/docker/overlay2/2e86018bf4d374965bedd3aa2ffccd3cd4e249b34da26400d78558fc42a2df67/merged/opt/freeswitch/share/freeswitch/sounds/en/us/callie/test.wav)" 
time="2017-12-18T09:13:48.178938773Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/2e86018bf4d374965bedd3aa2ffccd3cd4e249b34da26400d78558fc42a2df67/merged" 
time="2017-12-18T09:13:48.179021708Z" level=debug msg="Tar with options on /mnt/ssd/docker/overlay2/2e86018bf4d374965bedd3aa2ffccd3cd4e249b34da26400d78558fc42a2df67/diff" 
time="2017-12-18T09:13:48.179743958Z" level=debug msg="Applying tar in /mnt/ssd/docker/overlay2/4171e01698bd12fe3240b82ac4f043e79794a1cf35c5fe9a775afe2fcaa1ee84/diff" 
time="2017-12-18T09:13:48.430606544Z" level=debug msg="Applied tar sha256:4eae229ab3a157cb917b5c36a824cc6f859261bfce87da695393a337516d66c3 to 4171e01698bd12fe3240b82ac4f043e79794a1cf35c5fe9a775afe2fcaa1ee84, size: 30397086" 
time="2017-12-18T09:13:48.551228920Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:13:49.158890231Z" level=debug msg="Calling GET /v1.22/containers/cb202a255f07e47787954b10873440436bc2b1a601264124e2ff6698fcfb684b/json" 
time="2017-12-18T09:13:49.158961480Z" level=error msg="Handler for GET /v1.22/containers/cb202a255f07e47787954b10873440436bc2b1a601264124e2ff6698fcfb684b/json returned error: No such container: cb202a255f07e47787954b10873440436bc2b1a601264124e2ff6698fcfb684b" 
time="2017-12-18T09:13:49.344373547Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/b6a173a28bb11e1cb30ad67362691ff7cdcc19cffacf7f94f25f90b5559cda16/merged" 
time="2017-12-18T09:13:49.488685040Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/b6a173a28bb11e1cb30ad67362691ff7cdcc19cffacf7f94f25f90b5559cda16/merged" 
time="2017-12-18T09:13:49.488915282Z" level=debug msg="Creating dest directory: /mnt/ssd/docker/overlay2/b6a173a28bb11e1cb30ad67362691ff7cdcc19cffacf7f94f25f90b5559cda16/merged/opt/freeswitch/etc/freeswitch" 
time="2017-12-18T09:13:49.489305987Z" level=debug msg="Calling TarUntar(/mnt/ssd/docker/tmp/docker-builder465054075/config, /mnt/ssd/docker/overlay2/b6a173a28bb11e1cb30ad67362691ff7cdcc19cffacf7f94f25f90b5559cda16/merged/opt/freeswitch/etc/freeswitch)" 
time="2017-12-18T09:13:49.489375901Z" level=debug msg="TarUntar(/mnt/ssd/docker/tmp/docker-builder465054075/config /mnt/ssd/docker/overlay2/b6a173a28bb11e1cb30ad67362691ff7cdcc19cffacf7f94f25f90b5559cda16/merged/opt/freeswitch/etc/freeswitch)" 
time="2017-12-18T09:13:49.680221810Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/b6a173a28bb11e1cb30ad67362691ff7cdcc19cffacf7f94f25f90b5559cda16/merged" 
time="2017-12-18T09:13:49.680443897Z" level=debug msg="Tar with options on /mnt/ssd/docker/overlay2/b6a173a28bb11e1cb30ad67362691ff7cdcc19cffacf7f94f25f90b5559cda16/diff" 
time="2017-12-18T09:13:49.682307059Z" level=debug msg="Applying tar in /mnt/ssd/docker/overlay2/9fb000ab5ef8a8968fa0e0014d460c288008f2da09fa4420c6f9d0f0e43326c3/diff" 
time="2017-12-18T09:13:49.795505544Z" level=debug msg="Applied tar sha256:ad54f309e97cc0115e8669bed2a6a4a8ef47acc7e0fef523f239609a6edbe10b to 9fb000ab5ef8a8968fa0e0014d460c288008f2da09fa4420c6f9d0f0e43326c3, size: 789195" 
time="2017-12-18T09:13:50.392830799Z" level=debug msg="Calling GET /v1.22/containers/8bc9d408d22b3c1b547ccce6f17a5702d84d0a36ffcbe3300b6ba4b997286b30/json" 
time="2017-12-18T09:13:50.392969990Z" level=error msg="Handler for GET /v1.22/containers/8bc9d408d22b3c1b547ccce6f17a5702d84d0a36ffcbe3300b6ba4b997286b30/json returned error: No such container: 8bc9d408d22b3c1b547ccce6f17a5702d84d0a36ffcbe3300b6ba4b997286b30" 
time="2017-12-18T09:13:50.504212711Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/721ff27ce8961019919618b36ed73a9fd89a9cac21a537f5cb4f9ba458bc79cb/merged" 
time="2017-12-18T09:13:50.678554775Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/721ff27ce8961019919618b36ed73a9fd89a9cac21a537f5cb4f9ba458bc79cb/merged" 
time="2017-12-18T09:13:50.678629945Z" level=debug msg="Creating dest directory: /mnt/ssd/docker/overlay2/721ff27ce8961019919618b36ed73a9fd89a9cac21a537f5cb4f9ba458bc79cb/merged/opt/freeswitch/share/freeswitch/scripts" 
time="2017-12-18T09:13:50.678643977Z" level=debug msg="Calling TarUntar(/mnt/ssd/docker/tmp/docker-builder465054075/scripts, /mnt/ssd/docker/overlay2/721ff27ce8961019919618b36ed73a9fd89a9cac21a537f5cb4f9ba458bc79cb/merged/opt/freeswitch/share/freeswitch/scripts)" 
time="2017-12-18T09:13:50.678651352Z" level=debug msg="TarUntar(/mnt/ssd/docker/tmp/docker-builder465054075/scripts /mnt/ssd/docker/overlay2/721ff27ce8961019919618b36ed73a9fd89a9cac21a537f5cb4f9ba458bc79cb/merged/opt/freeswitch/share/freeswitch/scripts)" 
time="2017-12-18T09:13:50.778710186Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/721ff27ce8961019919618b36ed73a9fd89a9cac21a537f5cb4f9ba458bc79cb/merged" 
time="2017-12-18T09:13:50.778776657Z" level=debug msg="Tar with options on /mnt/ssd/docker/overlay2/721ff27ce8961019919618b36ed73a9fd89a9cac21a537f5cb4f9ba458bc79cb/diff" 
time="2017-12-18T09:13:50.779196852Z" level=debug msg="Applying tar in /mnt/ssd/docker/overlay2/ebdfcb2438f77db5f3c6ecc3b1a714ab0ca6f921c9dc9cb849f63f0e01820974/diff" 
time="2017-12-18T09:13:50.862858915Z" level=debug msg="Applied tar sha256:ae7dfb8e9f2e1e1e28933b58156b571757913296d3e259e33e2fdcfc2a9bec94 to ebdfcb2438f77db5f3c6ecc3b1a714ab0ca6f921c9dc9cb849f63f0e01820974, size: 3245" 
time="2017-12-18T09:13:51.115370131Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:13:52.939664735Z" level=debug msg="Calling GET /v1.22/containers/79138f166f71935e7b3afb287836a276ef1d097f37eb2323feee6dc3e68c550b/json" 
time="2017-12-18T09:13:52.939697533Z" level=error msg="Handler for GET /v1.22/containers/79138f166f71935e7b3afb287836a276ef1d097f37eb2323feee6dc3e68c550b/json returned error: No such container: 79138f166f71935e7b3afb287836a276ef1d097f37eb2323feee6dc3e68c550b" 
time="2017-12-18T09:13:53.446844207Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/4d358af373b6631801f03f8d68ce2e897394b5c78b1f34e848e4a3bca70d62f2/merged" 
time="2017-12-18T09:13:53.632929074Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/4d358af373b6631801f03f8d68ce2e897394b5c78b1f34e848e4a3bca70d62f2/merged" 
time="2017-12-18T09:13:53.632964755Z" level=debug msg="CopyFileWithTar(/mnt/ssd/docker/tmp/docker-builder465054075/start.sh, /mnt/ssd/docker/overlay2/4d358af373b6631801f03f8d68ce2e897394b5c78b1f34e848e4a3bca70d62f2/merged/start.sh)" 
time="2017-12-18T09:13:53.726717586Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/4d358af373b6631801f03f8d68ce2e897394b5c78b1f34e848e4a3bca70d62f2/merged" 
time="2017-12-18T09:13:53.726779639Z" level=debug msg="Tar with options on /mnt/ssd/docker/overlay2/4d358af373b6631801f03f8d68ce2e897394b5c78b1f34e848e4a3bca70d62f2/diff" 
time="2017-12-18T09:13:53.727314672Z" level=debug msg="Applying tar in /mnt/ssd/docker/overlay2/b4e1daec1a7e199c093bc21f5d35254ba9c0709769d3d2e1a9034233a981350e/diff" 
time="2017-12-18T09:13:53.806694466Z" level=debug msg="Applied tar sha256:0fa299d6ebf21ece431feab90a2c9281017ad63d945448cae434628097e057fa to b4e1daec1a7e199c093bc21f5d35254ba9c0709769d3d2e1a9034233a981350e, size: 556" 
time="2017-12-18T09:13:54.229817432Z" level=debug msg="Calling GET /v1.22/containers/2e637589dbec1f0798903a89d75db95f2610d6d7d607b665bef093848e23dd55/json" 
time="2017-12-18T09:13:54.229851768Z" level=error msg="Handler for GET /v1.22/containers/2e637589dbec1f0798903a89d75db95f2610d6d7d607b665bef093848e23dd55/json returned error: No such container: 2e637589dbec1f0798903a89d75db95f2610d6d7d607b665bef093848e23dd55" 
time="2017-12-18T09:13:54.469626031Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/b2ba5175a28fd01d8609b96e79a6cd6f5415d03e932536e4897ae6b1e75942ae/merged" 
time="2017-12-18T09:13:54.585111189Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/b2ba5175a28fd01d8609b96e79a6cd6f5415d03e932536e4897ae6b1e75942ae/merged" 
time="2017-12-18T09:13:54.585172694Z" level=debug msg="Tar with options on /mnt/ssd/docker/overlay2/b2ba5175a28fd01d8609b96e79a6cd6f5415d03e932536e4897ae6b1e75942ae/diff" 
time="2017-12-18T09:13:54.585599336Z" level=debug msg="Applying tar in /mnt/ssd/docker/overlay2/8589656ea6ded613f4b2359199b9d10c31b0e3a24d2c3c6b2855b1fd94151652/diff" 
time="2017-12-18T09:13:54.658707495Z" level=debug msg="Applied tar sha256:5f70bf18a086007016e948b04aed3b82103a36bea41755b6cddfaf10ace3c6ef to 8589656ea6ded613f4b2359199b9d10c31b0e3a24d2c3c6b2855b1fd94151652, size: 0" 
time="2017-12-18T09:13:54.908040824Z" level=info msg="Layer sha256:fbad355edbff12251ae753c0e6105fe9179e75c9f8ff35db05d0898d955418d7 cleaned up" 
time="2017-12-18T09:13:54.976464300Z" level=debug msg="Calling GET /v1.22/containers/f2952b58116fec2179090f09d4d6dc232aa7920235423124d36135788c470d4c/json" 
time="2017-12-18T09:13:54.976506752Z" level=error msg="Handler for GET /v1.22/containers/f2952b58116fec2179090f09d4d6dc232aa7920235423124d36135788c470d4c/json returned error: No such container: f2952b58116fec2179090f09d4d6dc232aa7920235423124d36135788c470d4c" 
time="2017-12-18T09:13:55.200588534Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/e7cf11e509281588384704d2c36da7285cdb939952dfd1aad91885f6332137cf/merged" 
time="2017-12-18T09:13:55.315198606Z" level=debug msg="container mounted via layerStore: /mnt/ssd/docker/overlay2/e7cf11e509281588384704d2c36da7285cdb939952dfd1aad91885f6332137cf/merged" 
time="2017-12-18T09:13:55.315260399Z" level=debug msg="Tar with options on /mnt/ssd/docker/overlay2/e7cf11e509281588384704d2c36da7285cdb939952dfd1aad91885f6332137cf/diff" 
time="2017-12-18T09:13:55.315693489Z" level=debug msg="Applying tar in /mnt/ssd/docker/overlay2/241769c4bd3dfe6513ee727582dfc221fe272ee9384aec1280f125b189bb4fc2/diff" 
time="2017-12-18T09:13:55.382551355Z" level=debug msg="Applied tar sha256:5f70bf18a086007016e948b04aed3b82103a36bea41755b6cddfaf10ace3c6ef to 241769c4bd3dfe6513ee727582dfc221fe272ee9384aec1280f125b18time="2017-12-18T09:06:44.505779547Z" level=debug msg="Calling GET /v1.22/containers/6d0d1ced35572b7f29bc8149f09a2566de0798a7f6ba8944581a18417c7b1f5e/json" 
time="2017-12-18T09:06:44.506286974Z" level=debug msg="Calling GET /v1.22/images/sha256:b32ebca23798d3fd51ed374cb08184a7a6b097c446d684b82b110f2113b49175/json" 
time="2017-12-18T09:06:48.437708490Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:06:55.178560573Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:07:03.442514964Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:07:12.189632364Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:07:12.189851861Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:07:14.371973866Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:07:18.445141332Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:07:34.463937116Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:07:42.137368880Z" level=debug msg="Calling GET /v1.22/containers/json?limit=0" 
time="2017-12-18T09:07:46.495689396Z" level=debug msg="clean 2 unused exec commands" 
time="2017-12-18T09:07:48.453572554Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:08:03.460936697Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:08:13.770391244Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:08:13.818074647Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:08:18.465463212Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:08:33.479041328Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:08:42.198716231Z" level=debug msg="Calling GET /v1.22/containers/json?limit=0" 
time="2017-12-18T09:08:48.474858984Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:09:03.478803353Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:09:15.321137738Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:09:15.321478961Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:09:18.481343784Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:09:34.489907850Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:09:48.489717856Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:10:03.492941695Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:10:16.917268987Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:10:16.917727728Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:10:18.496172955Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:10:33.502580355Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:10:48.502411289Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:11:03.505376110Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:11:18.493036878Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:11:18.493340451Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:11:18.507669616Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:11:34.517478109Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:11:48.517611169Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:11:48.633705402Z" level=debug msg="containerd: process exited" id=8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75 pid=3882a648b32a7e1347299bb625fd190c5bbfabd96024
1ef567fda5a284f517f0 status=0 systemPid=2436 
time="2017-12-18T09:07:42.137368880Z" level=debug msg="Calling GET /v1.22/containers/json?limit=0" 
time="2017-12-18T09:07:46.495689396Z" level=debug msg="clean 2 unused exec commands" 
time="2017-12-18T09:07:48.453572554Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:08:03.460936697Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:08:13.770391244Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:08:13.818074647Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:08:18.465463212Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:08:33.479041328Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:08:42.198716231Z" level=debug msg="Calling GET /v1.22/containers/json?limit=0" 
time="2017-12-18T09:08:48.474858984Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:09:03.478803353Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:09:15.321137738Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:09:15.321478961Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:09:18.481343784Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:09:34.489907850Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:09:48.489717856Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:10:03.492941695Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:10:16.917268987Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:10:16.917727728Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:10:18.496172955Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:10:33.502580355Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:10:48.502411289Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:11:03.505376110Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:11:18.493036878Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:11:18.493340451Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:11:18.507669616Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:11:34.517478109Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:11:48.517611169Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:11:48.633705402Z" level=debug msg="containerd: process exited" id=8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75 pid=3882a648b32a7e1347299bb625fd190c5bbfabd96024
1ef567fda5a284f517f0 status=0 systemPid=2436 
time="2017-12-18T09:11:48.634963571Z" level=debug msg="libcontainerd: received containerd event: &types.Event{Type:\"exit\", Id:\"8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75\", S
tatus:0x0, Pid:\"3882a648b32a7e1347299bb625fd190c5bbfabd960241ef567fda5a284f517f0\", Timestamp:(*timestamp.Timestamp)(0xc427130260)}" 
time="2017-12-18T09:11:48.635259477Z" level=debug msg="attach: stdout: end" 
time="2017-12-18T09:11:48.635295338Z" level=debug msg="attach: stdin: end" 
time="2017-12-18T09:11:48.635417120Z" level=debug msg="Closing buffered stdin pipe" 
time="2017-12-18T09:11:48.636542305Z" level=debug msg="Calling GET /v1.27/exec/3882a648b32a7e1347299bb625fd190c5bbfabd960241ef567fda5a284f517f0/json" 
time="2017-12-18T09:12:03.522138119Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:12:14.414810977Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:12:18.525708489Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:12:20.112714789Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:12:20.112989620Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:12:33.533847474Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:12:48.537524690Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:13:03.537976306Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:13:18.541208742Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 
time="2017-12-18T09:13:21.660583701Z" level=debug msg="Calling GET /_ping" 
time="2017-12-18T09:13:21.661022700Z" level=debug msg="Calling GET /v1.27/containers/json" 
time="2017-12-18T09:13:34.552850428Z" level=debug msg="Calling GET /v1.22/containers/json?all=1&limit=0" 

system logs during the problem end

Dec 18 09:01:14 s12 kernel: [1394680.424353] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
Dec 18 09:01:14 s12 kernel: [1394680.442486] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Dec 18 09:01:14 s12 kernel: [1394680.442730] docker0: port 72(vethc3f91004) entered blocking state
Dec 18 09:01:14 s12 kernel: [1394680.442731] docker0: port 72(vethc3f91004) entered disabled state
Dec 18 09:01:14 s12 kernel: [1394680.442862] device vethc3f91004 entered promiscuous mode
Dec 18 09:01:14 s12 kernel: [1394680.442920] docker0: port 72(vethc3f91004) entered blocking state
Dec 18 09:01:14 s12 kernel: [1394680.442920] docker0: port 72(vethc3f91004) entered forwarding state
Dec 18 09:01:14 s12 kernel: [1394680.485513] IPv6: eth0: IPv6 duplicate address fe80::10ee:cff:fe7c:d40 detected!
Dec 18 09:01:17 s12 ntpd[1]: Listen normally on 748 vethc3f91004 [fe80::5861:2dff:fe84:7cce%1175]:123
Dec 18 09:03:31 s12 kernel: [1394817.913665] docker0: port 62(veth18f9588) entered disabled state
Dec 18 09:03:31 s12 kernel: [1394817.913893] vethf40f3fa: renamed from eth0
Dec 18 09:03:32 s12 kernel: [1394818.365564] docker0: port 62(veth18f9588) entered disabled state
Dec 18 09:03:32 s12 kernel: [1394818.368450] device veth18f9588 left promiscuous mode
Dec 18 09:03:32 s12 kernel: [1394818.368452] docker0: port 62(veth18f9588) entered disabled state
Dec 18 09:03:34 s12 ntpd[1]: Deleting interface #744 veth18f9588, fe80::1c7c:77ff:fe9b:89f8%1170#123, interface stats: received=0, sent=0, dropped=0, active_time=628 secs
Dec 18 09:05:04 s12 kernel: [1394910.142160] runc:[2:INIT] invoked oom-killer: gfp_mask=0x24000c0(GFP_KERNEL), nodemask=0, order=0, oom_score_adj=0
Dec 18 09:05:04 s12 kernel: [1394910.142161] runc:[2:INIT] cpuset=8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75 mems_allowed=0
Dec 18 09:05:04 s12 kernel: [1394910.142164] CPU: 3 PID: 18947 Comm: runc:[2:INIT] Not tainted 4.9.30-rancher #1
Dec 18 09:05:04 s12 kernel: [1394910.142165] Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./Z270M-ITX/ac, BIOS P2.20 05/17/2017
Dec 18 09:05:04 s12 kernel: [1394910.142165]  ffffbe2c20d4fc78 ffffffffb8327a82 ffffbe2c20d4fd98 ffff9e89924a9d80
Dec 18 09:05:04 s12 kernel: [1394910.142167]  ffffbe2c20d4fcf0 ffffffffb81b2fa0 0000000000000000 0000000000000000
Dec 18 09:05:04 s12 kernel: [1394910.142169]  ffff9e8f77780000 ffffffffb814ae36 0000000000000206 ffffbe2c20d4fcc8
Dec 18 09:05:04 s12 kernel: [1394910.142170] Call Trace:
Dec 18 09:05:04 s12 kernel: [1394910.142174]  [<ffffffffb8327a82>] dump_stack+0x61/0x7d
Dec 18 09:05:04 s12 kernel: [1394910.142177]  [<ffffffffb81b2fa0>] dump_header+0x7b/0x1f9
Dec 18 09:05:04 s12 kernel: [1394910.142178]  [<ffffffffb814ae36>] ? oom_badness+0x12e/0x12e
Dec 18 09:05:04 s12 kernel: [1394910.142181]  [<ffffffffb86e3c5a>] ? _raw_spin_unlock_irqrestore+0x1a/0x1d
Dec 18 09:05:04 s12 kernel: [1394910.142182]  [<ffffffffb814b07e>] oom_kill_process+0x86/0x332
Dec 18 09:05:04 s12 kernel: [1394910.142183]  [<ffffffffb814b80c>] out_of_memory+0x3a5/0x3e0
Dec 18 09:05:04 s12 kernel: [1394910.142185]  [<ffffffffb81a612a>] mem_cgroup_out_of_memory+0x3c/0x50
Dec 18 09:05:04 s12 kernel: [1394910.142186]  [<ffffffffb81aa7cf>] mem_cgroup_oom_synchronize+0x25e/0x272
Dec 18 09:05:04 s12 kernel: [1394910.142187]  [<ffffffffb81a6528>] ? mem_cgroup_is_descendant+0x4e/0x4e
Dec 18 09:05:04 s12 kernel: [1394910.142189]  [<ffffffffb814b86b>] pagefault_out_of_memory+0x24/0x4f
Dec 18 09:05:04 s12 kernel: [1394910.142190]  [<ffffffffb8055d40>] mm_fault_error+0x63/0x132
Dec 18 09:05:04 s12 kernel: [1394910.142191]  [<ffffffffb80561de>] __do_page_fault+0x3cf/0x429
Dec 18 09:05:04 s12 kernel: [1394910.142192]  [<ffffffffb805625d>] do_page_fault+0x25/0x27
Dec 18 09:05:04 s12 kernel: [1394910.142193]  [<ffffffffb86e5398>] page_fault+0x28/0x30
Dec 18 09:05:04 s12 kernel: [1394910.142195] Task in /docker/c3d0a1f990f527465f77f196907b4b02b58c9d797ea70b7c82521f1ed91a950c/docker/8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878
157f9e3085ff1c0b75 killed as a result of limit of /docker/c3d0a1f990f527465f77f196907b4b02b58c9d797ea70b7c82521f1ed91a950c/docker/8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157
f9e3085ff1c0b75
Dec 18 09:05:04 s12 kernel: [1394910.142199] memory: usage 262144kB, limit 262144kB, failcnt 29877654
Dec 18 09:05:04 s12 kernel: [1394910.142199] memory+swap: usage 262144kB, limit 524288kB, failcnt 0
Dec 18 09:05:04 s12 kernel: [1394910.142200] kmem: usage 7496kB, limit 9007199254740988kB, failcnt 0
Dec 18 09:05:04 s12 kernel: [1394910.142200] Memory cgroup stats for /docker/c3d0a1f990f527465f77f196907b4b02b58c9d797ea70b7c82521f1ed91a950c/docker/8fa1efbc92a6db38517a5db7ba83d3
6715ab0eab7f7878157f9e3085ff1c0b75: cache:116KB rss:254532KB rss_huge:18432KB mapped_file:0KB dirty:0KB writeback:0KB swap:0KB inactive_anon:0KB active_anon:254532KB inactive_file
:116KB active_file:0KB unevictable:0KB
Dec 18 09:05:04 s12 kernel: [1394910.142220] [ pid ]   uid  tgid total_vm      rss nr_ptes nr_pmds swapents oom_score_adj name
Dec 18 09:05:04 s12 kernel: [1394910.142489] [28286]     0 28286   161115     4212      68      38        0             0 npm
Dec 18 09:05:04 s12 kernel: [1394910.142499] [30073]     0 30073      387        2       7       3        0             0 sh
Dec 18 09:05:04 s12 kernel: [1394910.142500] [30074]     0 30074   216626    55834     459     400        0             0 node
Dec 18 09:05:04 s12 kernel: [1394910.142564] [18947]     0 18947     1572       57       6       2        0             0 runc:[2:INIT]
Dec 18 09:05:04 s12 kernel: [1394910.142565] Memory cgroup out of memory: Kill process 30074 (node) score 865 or sacrifice child
Dec 18 09:05:04 s12 kernel: [1394910.142579] Killed process 30074 (node) total-vm:866504kB, anon-rss:223336kB, file-rss:0kB, shmem-rss:0kB
Dec 18 09:05:25 s12 kernel: [1394930.974403] docker0: port 100(veth4f6c2125) entered disabled state
Dec 18 09:05:25 s12 kernel: [1394930.979385] device veth4f6c2125 left promiscuous mode
Dec 18 09:05:25 s12 kernel: [1394930.979387] docker0: port 100(veth4f6c2125) entered disabled state
Dec 18 09:05:26 s12 ntpd[1]: Deleting interface #504 veth4f6c2125, fe80::4815:e7ff:fef9:9606%820#123, interface stats: received=0, sent=0, dropped=0, active_time=523984 secs
Dec 18 09:05:29 s12 kernel: [1394935.809690] docker0: port 62(vethdca569f) entered blocking state
Dec 18 09:05:29 s12 kernel: [1394935.809693] docker0: port 62(vethdca569f) entered disabled state
Dec 18 09:05:29 s12 kernel: [1394935.810043] device vethdca569f entered promiscuous mode
Dec 18 09:05:29 s12 kernel: [1394935.810538] IPv6: ADDRCONF(NETDEV_UP): vethdca569f: link is not ready
Dec 18 09:05:30 s12 kernel: [1394936.368543] eth0: renamed from veth9c82dd7
Dec 18 09:05:30 s12 kernel: [1394936.400351] IPv6: ADDRCONF(NETDEV_CHANGE): vethdca569f: link becomes ready
Dec 18 09:05:30 s12 kernel: [1394936.400405] docker0: port 62(vethdca569f) entered blocking state
Dec 18 09:05:30 s12 kernel: [1394936.400406] docker0: port 62(vethdca569f) entered forwarding state
Dec 18 09:05:30 s12 kernel: [1394936.512115] IPv6: eth0: IPv6 duplicate address fe80::42:acff:fe11:4 detected!
Dec 18 09:05:31 s12 kernel: [1394937.897235] docker0: port 62(vethdca569f) entered disabled state
Dec 18 09:05:31 s12 kernel: [1394937.897800] veth9c82dd7: renamed from eth0
Dec 18 09:05:32 s12 kernel: [1394938.036960] docker0: port 62(vethdca569f) entered disabled state
Dec 18 09:05:32 s12 kernel: [1394938.039755] device vethdca569f left promiscuous mode
Dec 18 09:05:32 s12 kernel: [1394938.039756] docker0: port 62(vethdca569f) entered disabled state
Dec 18 09:05:34 s12 kernel: [1394940.595745] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
Dec 18 09:05:34 s12 kernel: [1394940.616861] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Dec 18 09:05:34 s12 kernel: [1394940.617116] docker0: port 62(vethd5b7e368) entered blocking state
Dec 18 09:05:34 s12 kernel: [1394940.617117] docker0: port 62(vethd5b7e368) entered disabled state
Dec 18 09:05:34 s12 kernel: [1394940.617264] device vethd5b7e368 entered promiscuous mode
Dec 18 09:05:34 s12 kernel: [1394940.617357] docker0: port 62(vethd5b7e368) entered blocking state
Dec 18 09:05:34 s12 kernel: [1394940.617358] docker0: port 62(vethd5b7e368) entered forwarding state
Dec 18 09:05:35 s12 kernel: [1394941.032405] IPv6: eth0: IPv6 duplicate address fe80::a4b0:a8ff:fef9:8abb detected!
Dec 18 09:05:37 s12 ntpd[1]: Listen normally on 749 vethd5b7e368 [fe80::4a8:5aff:fe04:7492%1178]:123
Dec 18 09:05:43 s12 kernel: [1394949.006298] docker0: port 73(vethcfd96db) entered blocking state
Dec 18 09:05:43 s12 kernel: [1394949.006300] docker0: port 73(vethcfd96db) entered disabled state
Dec 18 09:05:43 s12 kernel: [1394949.006519] device vethcfd96db entered promiscuous mode
Dec 18 09:05:43 s12 kernel: [1394949.006753] IPv6: ADDRCONF(NETDEV_UP): vethcfd96db: link is not ready
Dec 18 09:05:43 s12 kernel: [1394949.648394] eth0: renamed from vethfa3f214
Dec 18 09:05:43 s12 kernel: [1394949.664178] IPv6: ADDRCONF(NETDEV_CHANGE): vethcfd96db: link becomes ready
Dec 18 09:05:43 s12 kernel: [1394949.664227] docker0: port 73(vethcfd96db) entered blocking state
Dec 18 09:05:43 s12 kernel: [1394949.664228] docker0: port 73(vethcfd96db) entered forwarding state
Dec 18 09:05:43 s12 kernel: [1394949.800024] IPv6: eth0: IPv6 duplicate address fe80::42:acff:fe11:4 detected!
Dec 18 09:05:45 s12 ntpd[1]: bind(97) AF_INET6 fe80::1c8d:60ff:fee5:3456%1180#123 flags 0x11 failed: Cannot assign requested address
Dec 18 09:05:45 s12 ntpd[1]: unable to create socket on vethcfd96db (750) for fe80::1c8d:60ff:fee5:3456%1180#123
Dec 18 09:05:45 s12 ntpd[1]: failed to init interface for address fe80::1c8d:60ff:fee5:3456%1180
Dec 18 09:05:47 s12 ntpd[1]: Listen normally on 751 vethcfd96db [fe80::1c8d:60ff:fee5:3456%1180]:123
Dec 18 09:11:49 s12 sshd[31249]: syslogin_perform_logout: logout() returned an error

docker version

Client:
 Version:      17.03.1-ce
 API version:  1.27
 Go version:   go1.7.5
 Git commit:   c6d412e
 Built:        Tue Mar 28 00:40:02 2017
 OS/Arch:      linux/amd64

Server:
 Version:      17.03.1-ce
 API version:  1.27 (minimum version 1.12)
 Go version:   go1.7.5
 Git commit:   c6d412e
 Built:        Tue Mar 28 00:40:02 2017
 OS/Arch:      linux/amd64
 Experimental: false

docker info

Containers: 119
 Running: 118
 Paused: 0
 Stopped: 1
Images: 1565
Server Version: 17.03.1-ce
Storage Driver: overlay2
 Backing Filesystem: extfs
 Supports d_type: true
 Native Overlay Diff: true
Logging Driver: fluentd
Cgroup Driver: cgroupfs
Plugins: 
 Volume: local
 Network: bridge host macvlan null overlay
Swarm: inactive
Runtimes: runc
Default Runtime: runc
Init Binary: docker-init
containerd version: 4ab9917febca54791c5f071a9d1f404867857fcc
runc version: 54296cf40ad8143b62dbcaa1d90e520a2136ddfe
init version: 949e6fa
Security Options:
 seccomp
  Profile: default
Kernel Version: 4.9.30-rancher
Operating System: RancherOS v1.0.2-rc3
OSType: linux
Architecture: x86_64
CPUs: 4
Total Memory: 31.14 GiB
Name: s12.teslatele.com
ID: C26P:WBPL:43Q6:IWJ3:Z6AG:Q2IM:QU3L:6UAJ:D6KN:LAVG:BVW6:KOPS
Docker Root Dir: /mnt/ssd/docker
Debug Mode (client): false
Debug Mode (server): true
 File Descriptors: 879
 Goroutines: 586
 System Time: 2017-12-18T12:36:43.977814381Z
 EventsListeners: 2
Registry: https://index.docker.io/v1/
Experimental: false
Insecure Registries:
 127.0.0.0/8
Live Restore Enabled: false

Here is a screenshot from our monitoring system. It shows memory and cpu usage for the "hanged" container (we collect data from cgroups files). Also it's in GMT+5
moby-35463-example

@thaJeztah
Copy link
Member

Yes, so looks like the kernel started OOM killing processes;

Dec 18 09:05:04 s12 kernel: [1394910.142195] Task in /docker/c3d0a1f990f527465f77f196907b4b02b58c9d797ea70b7c82521f1ed91a950c/docker/8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878
157f9e3085ff1c0b75 killed as a result of limit of /docker/c3d0a1f990f527465f77f196907b4b02b58c9d797ea70b7c82521f1ed91a950c/docker/8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157
f9e3085ff1c0b75

...

Dec 18 09:05:04 s12 kernel: [1394910.142200] Memory cgroup stats for /docker/c3d0a1f990f527465f77f196907b4b02b58c9d797ea70b7c82521f1ed91a950c/docker/8fa1efbc92a6db38517a5db7ba83d3
6715ab0eab7f7878157f9e3085ff1c0b75: cache:116KB rss:254532KB rss_huge:18432KB mapped_file:0KB dirty:0KB writeback:0KB swap:0KB inactive_anon:0KB active_anon:254532KB inactive_file
:116KB active_file:0KB unevictable:0KB

...

Dec 18 09:05:04 s12 kernel: [1394910.142565] Memory cgroup out of memory: Kill process 30074 (node) score 865 or sacrifice child
Dec 18 09:05:04 s12 kernel: [1394910.142579] Killed process 30074 (node) total-vm:866504kB, anon-rss:223336kB, file-rss:0kB, shmem-rss:0kB

@stszap
Copy link
Author

stszap commented Dec 19, 2017

Yes, but only after I tried to exec into the container. Before that it was "stuck" for more than 5 hours.

time="2017-12-18T09:05:04.180587141Z" level=debug msg="Calling POST /v1.27/containers/8fa1efbc92a6/exec" 
time="2017-12-18T09:05:04.180673027Z" level=debug msg="form data: {\"AttachStderr\":true,\"AttachStdin\":true,\"AttachStdout\":true,\"Cmd\":[\"bash\"],\"Detach\":false,\"DetachKeys\":\"\",\"Env\":null,\"Privileged\":false,\"Tty\":true,\"User\":\"\"}" 
time="2017-12-18T09:05:04.181176308Z" level=debug msg="Calling POST /v1.27/exec/f4872eb5f71fed5d6d8d4d11ac361d1d21fb9e82871a570d20a937909fcddc30/start" 
time="2017-12-18T09:05:04.181255297Z" level=debug msg="form data: {\"AttachStderr\":true,\"AttachStdin\":true,\"AttachStdout\":true,\"Cmd\":[\"bash\"],\"Detach\":false,\"DetachKeys\":\"\",\"Env\":null,\"Privileged\":false,\"Tty\":true,\"User\":\"\"}" 
time="2017-12-18T09:05:04.181326943Z" level=debug msg="starting exec command f4872eb5f71fed5d6d8d4d11ac361d1d21fb9e82871a570d20a937909fcddc30 in container 8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75" 
time="2017-12-18T09:05:04.182488175Z" level=debug msg="Calling POST /v1.27/exec/f4872eb5f71fed5d6d8d4d11ac361d1d21fb9e82871a570d20a937909fcddc30/resize?h=52&w=199" 
time="2017-12-18T09:05:04.182593011Z" level=debug msg="attach: stdin: begin" 
time="2017-12-18T09:05:04.182624048Z" level=debug msg="attach: stdout: begin" 
time="2017-12-18T09:05:04.655076646Z" level=debug msg="containerd: container oom" id=8fa1efbc92a6db38517a5db7ba83d36715ab0eab7f7878157f9e3085ff1c0b75 

The problem is that oom killer is NOT triggered automatically, but only after some interference. I suppose that it has something to do with swap, but I can not test it because I have not reliable way to reproduce.

@thaJeztah
Copy link
Member

I'm not sure there's much we can do about that (given that it's the kernel deciding when to act). Perhaps @mlaventure has some thoughts on this.

@mlaventure
Copy link
Contributor

Looks like an issue on the kernel level. I was going to suggest it may be a 3.16 issue but looks like you also got the isse on a 4.x kernel on rancher.

But from the description, I would definitely think of a kernel issue given that doing a docker exec succeeds and immediately causes the oom to trigger. Maybe a wrong condition if the memory usage is exactly equal to the limit?

@stszap
Copy link
Author

stszap commented Dec 21, 2017

Maybe a wrong condition if the memory usage is exactly equal to the limit?
I thought so too and even tried to gradually increment used memory inside container but with no luck. I will try again.

But from the description, I would definitely think of a kernel issue given that doing a docker exec succeeds and immediately causes the oom to trigger.
Ok, thanks. I will try to investigate in that direction.

@brat002
Copy link

brat002 commented Dec 26, 2017

Confirmed

# uname -a
Linux hostname 4.14.9-1.el7.elrepo.x86_64 #1 SMP Mon Dec 25 11:49:55 EST 2017 x86_64 x86_64 x86_64 GNU/Linux
# docker version
Client:
 Version:      17.09.0-ce
 API version:  1.32
 Go version:   go1.8.3
 Git commit:   afdb6d4
 Built:        Tue Sep 26 22:41:23 2017
 OS/Arch:      linux/amd64

Server:
 Version:      17.09.0-ce
 API version:  1.32 (minimum version 1.12)
 Go version:   go1.8.3
 Git commit:   afdb6d4
 Built:        Tue Sep 26 22:42:49 2017
 OS/Arch:      linux/amd64
 Experimental: false

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

5 participants