Engine seelog #1208

aaithal · 2018-01-23T00:52:33Z

Summary

Removed module logger and switched to seelog in engine package

Implementation details

Testing

Builds on Linux (make release)
Builds on Windows (go build -out amazon-ecs-agent.exe ./agent)
Unit tests on Linux (make test) pass
Unit tests on Windows (go test -timeout=25s ./agent/...) pass
Integration tests on Linux (make run-integ-tests) pass
Integration tests on Windows (.\scripts\run-integ-tests.ps1) pass
Functional tests on Linux (make run-functional-tests) pass
Functional tests on Windows (.\scripts\run-functional-tests.ps1) pass

New tests cover the changes: yes

Description for the changelog

None

Licensing

This contribution is under the terms of the Apache 2.0 License: Yes

richardpen

Looks like all the changes are related to naming, I'm assuming all the tests will pass.

adnxn

code lgtm, mostly nits about formatting, naming.

adnxn · 2018-01-23T18:23:22Z

agent/engine/docker_container_engine.go

@@ -658,7 +665,7 @@ func (dg *dockerGoClient) stopContainer(ctx context.Context, dockerID string) Do
 	err = client.StopContainerWithContext(dockerID, uint(dg.config.DockerStopTimeout/time.Second), ctx)
 	metadata := dg.containerMetadata(dockerID)
 	if err != nil {
-		log.Debug("Error stopping container", "err", err, "id", dockerID)
+		seelog.Infof("Error stopping container %s: %v", dockerID, err)


DockerGoClient: tag for this line

adnxn · 2018-01-23T18:26:27Z

agent/engine/docker_task_engine.go

@@ -221,7 +221,7 @@ func (engine *DockerTaskEngine) MustInit(ctx context.Context) {
 		err := engine.Init(ctx)
 		if err != nil {
 			errorOnce.Do(func() {
-				log.Error("Could not connect to docker daemon", "err", err)
+				seelog.Errorf("Task engine: could not connect to docker daemon: %v", err)


nit: should we tag these as DockerTaskEngine to keep parity with naming style as we have for DockerGoClient?

TL;DR I don't think so. Let me know what you think.

I used DockerGoClient as I couldn't think of a better name for this. "Task engine" distinguishes this from things like "Stats engine". I don't know if we need very strict rules about this.

Okay that's fine with me. I don't feel strongly either way. I'm guessing we'll have a better idea after a couple of weeks of log diving and debugging with these new changes 😛

adnxn · 2018-01-23T18:32:25Z

agent/engine/docker_task_engine.go

@@ -863,11 +906,13 @@ func (engine *DockerTaskEngine) buildCNIConfigFromTaskContainer(task *api.Task,
 }

 func (engine *DockerTaskEngine) stopContainer(task *api.Task, container *api.Container) DockerContainerMetadata {
-	seelog.Infof("Stopping container, container: %s, task: %s", container.String(), task.String())
+	seelog.Infof("Task engine[ %s]: stopping container [%s]", task.Arn, container.Name)


spacing: Task engine[ %s]

adnxn · 2018-01-23T18:32:52Z

agent/engine/docker_task_engine.go

@@ -882,16 +927,17 @@ func (engine *DockerTaskEngine) stopContainer(task *api.Task, container *api.Con
 	if container.Type == api.ContainerCNIPause {
 		err := engine.cleanupPauseContainerNetwork(task, container)
 		if err != nil {
-			seelog.Errorf("Engine: cleanup pause container network namespace error, task: %s", task.String())
+			seelog.Errorf("Task engine[%s]: unable to cleanup pause container network namespace: %v",


spacing: Task engine[%s]

adnxn · 2018-01-23T18:33:08Z

agent/engine/docker_task_engine.go

 		}
-		seelog.Infof("Cleaned pause container network namespace, task: %s", task.String())
+		seelog.Infof("Task engine[%s]: cleaned pause container network namespace", task.Arn)


spacing: Task engine[%s]

adnxn · 2018-01-23T18:35:06Z

agent/engine/task_manager.go

@@ -165,17 +168,19 @@ func (mtask *managedTask) overseeTask() {
 		if !mtask.GetKnownStatus().Terminal() {
 			// If we aren't terminal and we aren't steady state, we should be
 			// able to move some containers along.
-			llog.Debug("Task not steady state or terminal; progressing it")
+			seelog.Debugf("Managed task [%s]: task not steady state or terminal; progressing it",


nit: again to keep parity, should we make the tags ManagedTask?

adnxn · 2018-01-23T18:38:31Z

agent/engine/task_manager.go

@@ -358,16 +366,17 @@ func (mtask *managedTask) handleContainerChange(containerChange dockerContainerC
 		now := mtask.time().Now()
 		ok := mtask.Task.SetExecutionStoppedAt(now)
 		if ok {
-			seelog.Infof("Recording execution stopped time for a task, essential container in task stopped, task %s, time: %s",
-				mtask.Task.String(), now.String())
+			seelog.Infof("Managed task [%s]: recording execution stopped time. Essential container %s stopped at: %s",


nit: container [%s], I think there are few of these where formatting varies from line to line. Not sure if this was intentional.

adnxn

oops meant to approve since mostly nits. thanks for going through this and making these changes. =]

sharanyad

👍 for tags in logs

sharanyad · 2018-01-23T19:18:45Z

agent/engine/dependencygraph/graph.go

+	DependentContainerNotResolvedErr = errors.New("dependency graph: dependent container not in expected state")
+	// ContainerPastDesiredStatusErr is the error where the container status is bigger than desired status
+	ContainerPastDesiredStatusErr = errors.New("container transition: container status is equal or greater than desired status")
+	volumeUnresolvedErr           = errors.New("dependency graph: container volume dependency not resolved")


nit: missing comments

sharanyad · 2018-01-23T19:23:20Z

agent/engine/docker_task_engine.go

@@ -336,7 +339,7 @@ func (engine *DockerTaskEngine) synchronizeContainerStatus(container *api.Docker
 func (engine *DockerTaskEngine) CheckTaskState(task *api.Task) {
 	taskContainers, ok := engine.state.ContainerMapByArn(task.Arn)
 	if !ok {
-		seelog.Warnf("Could not check task state for task; no task in state: %s", task.Arn)
+		seelog.Warnf("Task engine [%s]: could not check task state for task; no task in state", task.Arn)


rewording suggestion: could not check task state; no task in state

sharanyad · 2018-01-23T19:50:36Z

agent/engine/task_manager.go

 		return
 	}

-	seelog.Infof("Managed task: sending container change event: %s", event.String())
+	seelog.Infof("Managed task [%s]: sending container change event [%s]: %s",
+		mtask.Arn, container.Name, event.String())


Seems this should be cont.Name

Move to seelog and a uniform logging structure in the task manager code

Switch logger to seelog for container and task engine files.

Added a mock for StopContainer in TestBatchContainerHappyPath. On slower machines, if the cleanup takes long, the task engine could invoke StopContainer and this would cause the unit test to fail. Example: https://travis-ci.org/aws/amazon-ecs-agent/builds/332087012?utm_source=github_status&utm_medium=notification

Renamed docker_container_engine.go to docker_client.go

richardpen approved these changes Jan 23, 2018

View reviewed changes

adnxn reviewed Jan 23, 2018

View reviewed changes

adnxn approved these changes Jan 23, 2018

View reviewed changes

yhlee-aws approved these changes Jan 23, 2018

View reviewed changes

aaithal force-pushed the engineSeelog branch from aaf5575 to 2f84e11 Compare January 23, 2018 19:11

sharanyad approved these changes Jan 23, 2018

View reviewed changes

sharanyad reviewed Jan 23, 2018

View reviewed changes

aaithal force-pushed the engineSeelog branch from 2f84e11 to 0b7ec2f Compare January 23, 2018 20:24

aaithal mentioned this pull request Jan 23, 2018

Fix container metadata information missing during agent restart #1183

Merged

12 tasks

aaithal added 4 commits January 23, 2018 14:58

task manager: switch to seelog

0339078

Move to seelog and a uniform logging structure in the task manager code

engine seelog: task engine and container manager

ab03935

Switch logger to seelog for container and task engine files.

task engine: mv container engine -> docker client

90ee2ed

Renamed docker_container_engine.go to docker_client.go

aaithal force-pushed the engineSeelog branch from 0b7ec2f to 90ee2ed Compare January 23, 2018 22:58

aaithal merged commit 2d66bfd into aws:dev Jan 23, 2018

aaithal mentioned this pull request Jan 26, 2018

Better logging of tasks and containers in agent logs #758

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Engine seelog #1208

Engine seelog #1208

aaithal commented Jan 23, 2018 •

edited

Loading

richardpen left a comment

adnxn left a comment

adnxn Jan 23, 2018

adnxn Jan 23, 2018

aaithal Jan 23, 2018

adnxn Jan 23, 2018

adnxn Jan 23, 2018

adnxn Jan 23, 2018

adnxn Jan 23, 2018

adnxn Jan 23, 2018

adnxn Jan 23, 2018

adnxn left a comment

sharanyad left a comment

sharanyad Jan 23, 2018

sharanyad Jan 23, 2018 •

edited

Loading

sharanyad Jan 23, 2018

Engine seelog #1208

Engine seelog #1208

Conversation

aaithal commented Jan 23, 2018 • edited Loading

Summary

Implementation details

Testing

Description for the changelog

Licensing

richardpen left a comment

Choose a reason for hiding this comment

adnxn left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

adnxn left a comment

Choose a reason for hiding this comment

sharanyad left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

sharanyad Jan 23, 2018 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

aaithal commented Jan 23, 2018 •

edited

Loading

sharanyad Jan 23, 2018 •

edited

Loading