agent icon indicating copy to clipboard operation
agent copied to clipboard
verified publisher icon convox

cgroup race condition

Open rgarcia opened this issue 9 years ago • 0 comments

Running on Amazon ECS AMI 2015.09.e, I see convox/agent more often than not fail to set the cgroup on container launch. Here is some terminal output trying to launch a container with SWAP=1, while also running a tail of the agent logs in the background. convox/agent fails 5 times before succeeding at writing the cgroup file:

[ec2-user@ip-10-0-0-84 ~]$ docker run -d -e SWAP=1 redis
Feb 17 21:19:23 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor event id=3c68aed5d9b9 status=create time=1455743963
3c68aed5d9b9c3207ee10eaae972ae06862a2cb01c17190e1790611769255e5a
Feb 17 21:19:23 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor event id=3c68aed5d9b9 status=start time=1455743963
Feb 17 21:19:23 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor cgroups id=3c68aed5d9b9 cgroup=memory.memsw.limit_in_bytes value=18446744073709551615
Feb 17 21:19:23 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor cgroups id=3c68aed5d9b9 cgroup=memory.soft_limit_in_bytes value=18446744073709551615
Feb 17 21:19:23 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor cgroups id=3c68aed5d9b9 cgroup=memory.limit_in_bytes value=18446744073709551615
Feb 17 21:19:23 ip-10-0-0-84 docker/7570b06838c2[6818]: container subscribeLogs at=skip instanceId=i-da9a4902 id=3c68aed5d9b9c3207ee10eaae972ae06862a2cb01c17190e1790611769255e5a kinesis= logGroup= process=
Feb 17 21:19:23 ip-10-0-0-84 docker/7570b06838c2[6818]: error: open /cgroup/memory/docker/3c68aed5d9b9c3207ee10eaae972ae06862a2cb01c17190e1790611769255e5a/memory.memsw.limit_in_bytes: no such file or directory
Feb 17 21:19:23 ip-10-0-0-84 docker/7570b06838c2[6818]: error: open /cgroup/memory/docker/3c68aed5d9b9c3207ee10eaae972ae06862a2cb01c17190e1790611769255e5a/memory.soft_limit_in_bytes: no such file or directory
Feb 17 21:19:23 ip-10-0-0-84 docker/7570b06838c2[6818]: error: open /cgroup/memory/docker/3c68aed5d9b9c3207ee10eaae972ae06862a2cb01c17190e1790611769255e5a/memory.limit_in_bytes: no such file or directory
Feb 17 21:19:23 ip-10-0-0-84 docker/7570b06838c2[6818]: container streamLogs instanceId=i-da9a4902 stream= count#Kinesis.PutRecords.error=1 err="InvalidParameter: 1 validation errors:\n- field too short, minimum length 1: StreamName"
Feb 17 21:19:23 ip-10-0-0-84 docker/7570b06838c2[6818]: container streamLogs instanceId=i-da9a4902 stream= count#Kinesis.PutRecords.records=0 count#Kinesis.PutRecords.errors=0 err=""
[ec2-user@ip-10-0-0-84 ~]$ docker run -d -e SWAP=1 redis
Feb 17 21:19:32 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor event id=170dca14d71c status=create time=1455743972
170dca14d71cdd3bfaa8053c429aa64f12a32394cb78636752396ebd4527fd47
Feb 17 21:19:32 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor event id=170dca14d71c status=start time=1455743972
Feb 17 21:19:32 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor cgroups id=170dca14d71c cgroup=memory.memsw.limit_in_bytes value=18446744073709551615
Feb 17 21:19:32 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor cgroups id=170dca14d71c cgroup=memory.soft_limit_in_bytes value=18446744073709551615
Feb 17 21:19:32 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor cgroups id=170dca14d71c cgroup=memory.limit_in_bytes value=18446744073709551615
Feb 17 21:19:32 ip-10-0-0-84 docker/7570b06838c2[6818]: container subscribeLogs at=skip instanceId=i-da9a4902 id=170dca14d71cdd3bfaa8053c429aa64f12a32394cb78636752396ebd4527fd47 kinesis= logGroup= process=
Feb 17 21:19:32 ip-10-0-0-84 docker/7570b06838c2[6818]: container streamLogs instanceId=i-da9a4902 stream= count#Kinesis.PutRecords.error=1 err="InvalidParameter: 1 validation errors:\n- field too short, minimum length 1: StreamName"
Feb 17 21:19:32 ip-10-0-0-84 docker/7570b06838c2[6818]: container streamLogs instanceId=i-da9a4902 stream= count#Kinesis.PutRecords.records=0 count#Kinesis.PutRecords.errors=0 err=""
[ec2-user@ip-10-0-0-84 ~]$ docker run -d -e SWAP=1 redis
Feb 17 21:19:34 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor event id=af052dbbd4de status=create time=1455743974
af052dbbd4de970c92cf8185b995fa23f1aa1f772a4e6c7a00960066ba2ac349
Feb 17 21:19:35 ip-10-0-0-84 docker/7570b06838c2[6818]: error: open /cgroup/memory/docker/af052dbbd4de970c92cf8185b995fa23f1aa1f772a4e6c7a00960066ba2ac349/memory.memsw.limit_in_bytes: no such file or directory
Feb 17 21:19:35 ip-10-0-0-84 docker/7570b06838c2[6818]: error: open /cgroup/memory/docker/af052dbbd4de970c92cf8185b995fa23f1aa1f772a4e6c7a00960066ba2ac349/memory.soft_limit_in_bytes: no such file or directory
Feb 17 21:19:35 ip-10-0-0-84 docker/7570b06838c2[6818]: error: open /cgroup/memory/docker/af052dbbd4de970c92cf8185b995fa23f1aa1f772a4e6c7a00960066ba2ac349/memory.limit_in_bytes: no such file or directory
Feb 17 21:19:35 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor event id=af052dbbd4de status=start time=1455743975
Feb 17 21:19:35 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor cgroups id=af052dbbd4de cgroup=memory.memsw.limit_in_bytes value=18446744073709551615
Feb 17 21:19:35 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor cgroups id=af052dbbd4de cgroup=memory.soft_limit_in_bytes value=18446744073709551615
Feb 17 21:19:35 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor cgroups id=af052dbbd4de cgroup=memory.limit_in_bytes value=18446744073709551615
Feb 17 21:19:35 ip-10-0-0-84 docker/7570b06838c2[6818]: container subscribeLogs at=skip instanceId=i-da9a4902 id=af052dbbd4de970c92cf8185b995fa23f1aa1f772a4e6c7a00960066ba2ac349 kinesis= logGroup= process=
Feb 17 21:19:35 ip-10-0-0-84 docker/7570b06838c2[6818]: container streamLogs instanceId=i-da9a4902 stream= count#Kinesis.PutRecords.error=1 err="InvalidParameter: 1 validation errors:\n- field too short, minimum length 1: StreamName"
Feb 17 21:19:35 ip-10-0-0-84 docker/7570b06838c2[6818]: container streamLogs instanceId=i-da9a4902 stream= count#Kinesis.PutRecords.records=0 count#Kinesis.PutRecords.errors=0 err=""
[ec2-user@ip-10-0-0-84 ~]$ docker run -d -e SWAP=1 redis
Feb 17 21:19:40 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor event id=17be7c9406e0 status=create time=1455743980
17be7c9406e0da41960d2cceb4ca3f5e1bd25c46cbd6fe2c2f50642c5b8a2a4e
Feb 17 21:19:40 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor event id=17be7c9406e0 status=start time=1455743980
Feb 17 21:19:40 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor cgroups id=17be7c9406e0 cgroup=memory.memsw.limit_in_bytes value=18446744073709551615
Feb 17 21:19:40 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor cgroups id=17be7c9406e0 cgroup=memory.soft_limit_in_bytes value=18446744073709551615
Feb 17 21:19:40 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor cgroups id=17be7c9406e0 cgroup=memory.limit_in_bytes value=18446744073709551615
Feb 17 21:19:40 ip-10-0-0-84 docker/7570b06838c2[6818]: container subscribeLogs at=skip instanceId=i-da9a4902 id=17be7c9406e0da41960d2cceb4ca3f5e1bd25c46cbd6fe2c2f50642c5b8a2a4e kinesis= logGroup= process=
Feb 17 21:19:40 ip-10-0-0-84 docker/7570b06838c2[6818]: error: open /cgroup/memory/docker/17be7c9406e0da41960d2cceb4ca3f5e1bd25c46cbd6fe2c2f50642c5b8a2a4e/memory.memsw.limit_in_bytes: no such file or directory
Feb 17 21:19:40 ip-10-0-0-84 docker/7570b06838c2[6818]: error: open /cgroup/memory/docker/17be7c9406e0da41960d2cceb4ca3f5e1bd25c46cbd6fe2c2f50642c5b8a2a4e/memory.soft_limit_in_bytes: no such file or directory
Feb 17 21:19:40 ip-10-0-0-84 docker/7570b06838c2[6818]: error: open /cgroup/memory/docker/17be7c9406e0da41960d2cceb4ca3f5e1bd25c46cbd6fe2c2f50642c5b8a2a4e/memory.limit_in_bytes: no such file or directory
Feb 17 21:19:40 ip-10-0-0-84 docker/7570b06838c2[6818]: container streamLogs instanceId=i-da9a4902 stream= count#Kinesis.PutRecords.error=1 err="InvalidParameter: 1 validation errors:\n- field too short, minimum length 1: StreamName"
Feb 17 21:19:40 ip-10-0-0-84 docker/7570b06838c2[6818]: container streamLogs instanceId=i-da9a4902 stream= count#Kinesis.PutRecords.records=0 count#Kinesis.PutRecords.errors=0 err=""
[ec2-user@ip-10-0-0-84 ~]$ docker run -d -e SWAP=1 redis
Feb 17 21:19:42 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor event id=bd5e1185bbf3 status=create time=1455743982
bd5e1185bbf33a3f904582de64324513e71012c4ad658a44a60f65a4f59f9f04
Feb 17 21:19:42 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor event id=bd5e1185bbf3 status=start time=1455743982
Feb 17 21:19:42 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor cgroups id=bd5e1185bbf3 cgroup=memory.memsw.limit_in_bytes value=18446744073709551615
Feb 17 21:19:42 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor cgroups id=bd5e1185bbf3 cgroup=memory.soft_limit_in_bytes value=18446744073709551615
Feb 17 21:19:42 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor cgroups id=bd5e1185bbf3 cgroup=memory.limit_in_bytes value=18446744073709551615
Feb 17 21:19:42 ip-10-0-0-84 docker/7570b06838c2[6818]: container subscribeLogs at=skip instanceId=i-da9a4902 id=bd5e1185bbf33a3f904582de64324513e71012c4ad658a44a60f65a4f59f9f04 kinesis= logGroup= process=
Feb 17 21:19:42 ip-10-0-0-84 docker/7570b06838c2[6818]: error: open /cgroup/memory/docker/bd5e1185bbf33a3f904582de64324513e71012c4ad658a44a60f65a4f59f9f04/memory.memsw.limit_in_bytes: no such file or directory
Feb 17 21:19:42 ip-10-0-0-84 docker/7570b06838c2[6818]: error: open /cgroup/memory/docker/bd5e1185bbf33a3f904582de64324513e71012c4ad658a44a60f65a4f59f9f04/memory.soft_limit_in_bytes: no such file or directory
Feb 17 21:19:42 ip-10-0-0-84 docker/7570b06838c2[6818]: error: open /cgroup/memory/docker/bd5e1185bbf33a3f904582de64324513e71012c4ad658a44a60f65a4f59f9f04/memory.limit_in_bytes: no such file or directory
Feb 17 21:19:42 ip-10-0-0-84 docker/7570b06838c2[6818]: container streamLogs instanceId=i-da9a4902 stream= count#Kinesis.PutRecords.error=1 err="InvalidParameter: 1 validation errors:\n- field too short, minimum length 1: StreamName"
Feb 17 21:19:42 ip-10-0-0-84 docker/7570b06838c2[6818]: container streamLogs instanceId=i-da9a4902 stream= count#Kinesis.PutRecords.records=0 count#Kinesis.PutRecords.errors=0 err=""
[ec2-user@ip-10-0-0-84 ~]$ docker run -d -e SWAP=1 redis
Feb 17 21:19:44 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor event id=448b19f81948 status=create time=1455743984
448b19f81948be5fcd645c4af7f7961bdc7555500f191858de1016dbf1d73f25
Feb 17 21:19:44 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor event id=448b19f81948 status=start time=1455743984
Feb 17 21:19:44 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor cgroups id=448b19f81948 cgroup=memory.memsw.limit_in_bytes value=18446744073709551615
Feb 17 21:19:44 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor cgroups id=448b19f81948 cgroup=memory.soft_limit_in_bytes value=18446744073709551615
Feb 17 21:19:44 ip-10-0-0-84 docker/7570b06838c2[6818]: monitor cgroups id=448b19f81948 cgroup=memory.limit_in_bytes value=18446744073709551615
Feb 17 21:19:44 ip-10-0-0-84 docker/7570b06838c2[6818]: container subscribeLogs at=skip instanceId=i-da9a4902 id=448b19f81948be5fcd645c4af7f7961bdc7555500f191858de1016dbf1d73f25 kinesis= logGroup= process=
Feb 17 21:19:44 ip-10-0-0-84 docker/7570b06838c2[6818]: container streamLogs instanceId=i-da9a4902 stream= count#Kinesis.PutRecords.error=1 err="InvalidParameter: 1 validation errors:\n- field too short, minimum length 1: StreamName"
Feb 17 21:19:44 ip-10-0-0-84 docker/7570b06838c2[6818]: container streamLogs instanceId=i-da9a4902 stream= count#Kinesis.PutRecords.records=0 count#Kinesis.PutRecords.errors=0 err=""

Checking on the no such file or directory errors, all of the directories appear to exist, so this feels like a race condition.

rgarcia avatar Feb 17 '16 21:02 rgarcia