testing: TestDockerStopTimeout

[suneyz]

Summary

Flaky integ test

Description

Expected Behavior

Observed Behavior

Environment Details

Supporting Log Snippets

=== RUN TestDockerStopTimeout
2019-02-14T20:44:42Z [INFO] Image excluded from cleanup: amazon/amazon-ecs-agent:latest
2019-02-14T20:44:42Z [INFO] Image excluded from cleanup: amazon/amazon-ecs-pause:0.1.0
2019-02-14T20:44:42Z [WARN] Unable to fetch user data: blackholed
2019-02-14T20:44:42Z [CRITICAL] Unable to communicate with EC2 Metadata service to infer region: blackholed
2019-02-14T20:44:42Z [CRITICAL] Configuration key not set, key: AWSRegion
2019-02-14T20:44:42Z [INFO] Managed task [TestDockerStopTimeout]: unable to create task state change event []: create task state change event api: status not recognized by ECS: NONE
2019-02-14T20:44:42Z [INFO] Task engine [TestDockerStopTimeout]: pulling image 127.0.0.1:51670/busybox:latest for container test-docker-timeout concurrently
2019-02-14T20:44:42Z [INFO] Task engine [TestDockerStopTimeout]: recording timestamp for starting image pulltime: 2019-02-14 20:44:42.274798022 +0000 UTC m=+540.366548819
2019-02-14T20:44:42Z [INFO] Adding image name- 127.0.0.1:51670/busybox:latest to Image state- sha256:669f9b20ccd59ba113166e6eb7782e87d701cb57f8b64bece7269b0a4c20d1c4
2019-02-14T20:44:42Z [INFO] Updating container reference test-docker-timeout in Image State - sha256:669f9b20ccd59ba113166e6eb7782e87d701cb57f8b64bece7269b0a4c20d1c4
2019-02-14T20:44:42Z [INFO] Task engine [TestDockerStopTimeout]: finished pulling image 127.0.0.1:51670/busybox:latest for container test-docker-timeout in 11.806917ms
2019-02-14T20:44:42Z [WARN] Managed task [TestDockerStopTimeout]: failed to write container [test-docker-timeout] change event to tcs event stream: Event stream is closed
2019-02-14T20:44:42Z [INFO] Task engine [TestDockerStopTimeout]: creating container: test-docker-timeout
2019-02-14T20:44:42Z [INFO] Task engine [TestDockerStopTimeout]: created container name mapping for task: test-docker-timeout -> ecs-family-1-test-docker-timeout-f0b2c4dfa29ef9dbb001
2019-02-14T20:44:42Z [INFO] Task engine [TestDockerStopTimeout]: created docker container for task: test-docker-timeout -> 6d318d647297b59d6cddaa8b94a01fecc70cca6517d8f2b60d0556d8030ff49b
2019-02-14T20:44:42Z [INFO] Task engine [TestDockerStopTimeout]: created docker container for task: test-docker-timeout -> 6d318d647297b59d6cddaa8b94a01fecc70cca6517d8f2b60d0556d8030ff49b, took 493.896289ms
2019-02-14T20:44:42Z [WARN] Managed task [TestDockerStopTimeout]: failed to write container [test-docker-timeout] change event to tcs event stream: Event stream is closed
2019-02-14T20:44:42Z [INFO] Managed task [TestDockerStopTimeout]: unable to create task state change event []: create task state change event api: status not recognized by ECS: CREATED
2019-02-14T20:44:42Z [INFO] Task engine [TestDockerStopTimeout]: starting container: test-docker-timeout
2019-02-14T20:44:43Z [INFO] Task engine [TestDockerStopTimeout]: started docker container for task: test-docker-timeout -> 6d318d647297b59d6cddaa8b94a01fecc70cca6517d8f2b60d0556d8030ff49b, took 677.265694ms
2019-02-14T20:44:43Z [WARN] Managed task [TestDockerStopTimeout]: failed to write container [test-docker-timeout] change event to tcs event stream: Event stream is closed
2019-02-14T20:44:43Z [INFO] Managed task [TestDockerStopTimeout]: sending container change event [test-docker-timeout]: TestDockerStopTimeout test-docker-timeout -> RUNNING, Known Sent: NONE
2019-02-14T20:44:43Z [INFO] Managed task [TestDockerStopTimeout]: sent container change event [test-docker-timeout]: TestDockerStopTimeout test-docker-timeout -> RUNNING, Known Sent: NONE
2019-02-14T20:44:43Z [INFO] Managed task [TestDockerStopTimeout]: sending task change event [TestDockerStopTimeout -> RUNNING, Known Sent: NONE, PullStartedAt: 2019-02-14 20:44:42.274798022 +0000 UTC m=+540.366548819, PullStoppedAt: 2019-02-14 20:44:42.286619183 +0000 UTC m=+540.378369956, ExecutionStoppedAt: 0001-01-01 00:00:00 +0000 UTC]
2019-02-14T20:44:43Z [INFO] Task engine [TestDockerStopTimeout]: stopping container [test-docker-timeout]
2019-02-14T20:44:43Z [INFO] Managed task [TestDockerStopTimeout]: sent task change event [TestDockerStopTimeout -> RUNNING, Known Sent: NONE, PullStartedAt: 2019-02-14 20:44:42.274798022 +0000 UTC m=+540.366548819, PullStoppedAt: 2019-02-14 20:44:42.286619183 +0000 UTC m=+540.378369956, ExecutionStoppedAt: 0001-01-01 00:00:00 +0000 UTC]
2019-02-14T20:44:43Z [INFO] Managed task [TestDockerStopTimeout]: task at steady state: RUNNING
2019-02-14T20:44:43Z [INFO] Managed task [TestDockerStopTimeout]: redundant container state change. test-docker-timeout to RUNNING, but already RUNNING
2019-02-14T20:44:43Z [INFO] Managed task [TestDockerStopTimeout]: task at steady state: RUNNING
2019-02-14T20:44:46Z [INFO] Task [TestDockerStopTimeout]: recording execution stopped time. Essential container [test-docker-timeout] stopped at: 2019-02-14 20:44:46.593734803 +0000 UTC m=+544.685485924
2019-02-14T20:44:46Z [WARN] Managed task [TestDockerStopTimeout]: failed to write container [test-docker-timeout] change event to tcs event stream: Event stream is closed
2019-02-14T20:44:46Z [INFO] Managed task [TestDockerStopTimeout]: sending container change event [test-docker-timeout]: TestDockerStopTimeout test-docker-timeout -> STOPPED, Exit 137, , Known Sent: NONE
--- FAIL: TestDockerStopTimeout (4.33s)
engine_unix_integ_test.go:1354: Container should have stopped eariler, but stopped after 3.135738056s

[ubhattacharjya]

closing this issue

PR for this change:
#1889