Fix concurrent writes during image cleanup #743

vsiddharth · 2017-03-28T16:31:04Z

This patch inspects the cleanup and resolves the inherent concurrent map write
issue reported. An unit test has been added to increase confidence in the fix.

Fixes #707

Signed-off-by: Vinothkumar Siddharth sidvin@amazon.com

Summary

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:

Description for the changelog

Licensing

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

richardpen · 2017-03-28T17:18:17Z

agent/engine/docker_image_manager_test.go

@@ -951,3 +953,68 @@ func TestGetImageStateFromImageNameNoImageState(t *testing.T) {
 		t.Error("Incorrect image state retrieved by image name")
 	}
 }
+
+func TestConcurrentRemoveUnusedImages(t *testing.T) {
+	// NOTE: Test would fail without the corresponding fix


It's better to put this line into the description of PR.

richardpen · 2017-03-28T17:19:41Z

agent/engine/docker_image_manager_test.go

+	}
+	require.Equal(t, 1, len(imageManager.imageStates))
+
+	err = imageManager.RemoveContainerReferenceFromImageState(container)


Can you add a comment here to explain why this is needed?

This is part of the standard setup in tests of similar nature here.
They help trigger the use-case under test.

@vsiddharth Please add a comment in code to describe the same

richardpen · 2017-03-28T17:20:18Z

agent/engine/docker_image_manager_test.go

+	}
+
+	imageState, _ := imageManager.getImageState(imageInspected.ID)
+	imageState.RemoveImageName(container.Image)


Also why this line is required?

You can get rid of this line by changing client.EXPECT().RemoveImage(sourceImage.ImageID, removeImageTimeout).Return(nil) to client.EXPECT().RemoveImage(container.Image, removeImageTimeout).Return(nil). Because image manager will try to delete the image by name first, if there is no name then it will delete by id.

aaithal · 2017-03-31T16:32:40Z

agent/engine/docker_image_manager.go

@@ -277,6 +275,8 @@ func (imageManager *dockerImageManager) performPeriodicImageCleanup(ctx context.
 }

 func (imageManager *dockerImageManager) removeUnusedImages() {
+	imageManager.updateLock.Lock()


Can you document if you've observed any slowness because of this in task launch latencies on an instance where there are at least 5 images to clean?

I did not observe any significant latencies

Github does not let me add comments on code that needs to modified outside this PR, so commenting here instead. It'd be a lot better if we could add some logging here because this method acquires at least 3 locks during its lifetime. Specifically, a log line to indicate that we are cleaning all tracking information for the image name because it has 0 references to it at line num 351 (after the if loop)

samuelkarp

I think this mostly looks good, though it's hard to see the codepath in the diff (I had to open an editor and trace through it). Please address @richardpen's comment as well as mine.

samuelkarp · 2017-04-23T04:58:58Z

agent/engine/docker_image_manager_test.go

+	require.Equal(t, 1, len(imageManager.imageStates))
+
+	err = imageManager.RemoveContainerReferenceFromImageState(container)
+	if err != nil {


Can you change this to assert.NoError?

samuelkarp · 2017-04-23T04:59:49Z

agent/engine/docker_image_manager_test.go

+	client.EXPECT().RemoveImage(container.Image, removeImageTimeout).Return(nil)
+	require.Equal(t, 1, len(imageManager.imageStates))
+
+	numRoutines := 1000


Any particular reason you picked 1000?

There isn't a significant reason for this choice. Its something used to recreate the problem.

Please add a comment to that effect. Right now 1000 is just a magic number in the source code.

samuelkarp · 2017-05-04T01:13:01Z

@vsiddharth Do you plan to address the comments here? @richardpen still has one requested change and both @aaithal and I have asked questions.

vsiddharth · 2017-05-10T16:54:03Z

@richardpen @aaithal @samuelkarp I've responded to most of the comments a few days back. Please let me know if you have any further questions.

Thanks

aaithal · 2017-05-10T18:55:01Z

agent/engine/docker_image_manager.go

@@ -277,6 +275,8 @@ func (imageManager *dockerImageManager) performPeriodicImageCleanup(ctx context.
 }

 func (imageManager *dockerImageManager) removeUnusedImages() {
+	imageManager.updateLock.Lock()


Github does not let me add comments on code that needs to modified outside this PR, so commenting here instead. It'd be a lot better if we could add some logging here because this method acquires at least 3 locks during its lifetime. Specifically, a log line to indicate that we are cleaning all tracking information for the image name because it has 0 references to it at line num 351 (after the if loop)

aaithal · 2017-05-23T21:46:42Z

agent/engine/docker_image_manager.go

@@ -348,6 +349,7 @@ func (imageManager *dockerImageManager) deleteImage(imageID string, imageState *
 	seelog.Infof("Image removed: %v", imageID)
 	imageState.RemoveImageName(imageID)
 	if len(imageState.Image.Names) == 0 {
+		seelog.Infof("Cleaning up all tracking information for image %v as it has zero references", imageID)


nit: Please change %v to %s before merging this.

This patch inspects the cleanup and resolves the inherent concurrent map write issue reported. An unit test has been added to increase confidence in the fix. Fixes aws#707 Signed-off-by: Vinothkumar Siddharth <sidvin@amazon.com>

vsiddharth · 2017-05-24T17:13:30Z

@samuelkarp Could you have another look at this PR ?

samuelkarp · 2017-05-24T23:01:17Z

@vsiddharth What's failing in the integration tests on Windows?

vsiddharth · 2017-05-24T23:09:39Z

@samuelkarp I've observed the windows failures and that is due to a flaky test that we already track.
The test usually succeeds on rerun or when run manually.

adnxn · 2017-05-24T23:24:35Z

@vsiddharth which test is it exactly?

vsiddharth · 2017-05-25T16:30:15Z

The test that failed was TestImageWithSameNameAndDifferentID but this has already been addressed in the dev branch

adnxn · 2017-05-26T17:23:13Z

Merged with this commit

richardpen reviewed Mar 28, 2017

View reviewed changes

aaithal reviewed Mar 31, 2017

View reviewed changes

richardpen approved these changes Apr 12, 2017

View reviewed changes

samuelkarp suggested changes Apr 23, 2017

View reviewed changes

aaithal requested changes May 10, 2017

View reviewed changes

aaithal reviewed May 23, 2017

View reviewed changes

aaithal approved these changes May 23, 2017

View reviewed changes

Fix concurrent writes during image cleanup

b019dfb

This patch inspects the cleanup and resolves the inherent concurrent map write issue reported. An unit test has been added to increase confidence in the fix. Fixes aws#707 Signed-off-by: Vinothkumar Siddharth <sidvin@amazon.com>

vsiddharth force-pushed the imageManager-concurrent-map-write branch from ac820c5 to b019dfb Compare May 23, 2017 22:12

samuelkarp approved these changes May 25, 2017

View reviewed changes

adnxn closed this May 26, 2017

adnxn mentioned this pull request May 26, 2017

V1.14.2 release #821

Merged

tejasmanohar mentioned this pull request Jun 8, 2017

Use go test -race #834

Closed

samuelkarp mentioned this pull request Jun 8, 2017

1.14.2 causing container instances to grind to a halt #833

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fix concurrent writes during image cleanup #743

Fix concurrent writes during image cleanup #743

vsiddharth commented Mar 28, 2017 •

edited

Loading

richardpen Mar 28, 2017

richardpen Mar 28, 2017

vsiddharth May 10, 2017

aaithal May 10, 2017

richardpen Mar 28, 2017

richardpen Apr 6, 2017

aaithal Mar 31, 2017

vsiddharth Apr 28, 2017

aaithal May 10, 2017 •

edited

Loading

samuelkarp left a comment

samuelkarp Apr 23, 2017

samuelkarp Apr 23, 2017

vsiddharth Apr 28, 2017

samuelkarp May 11, 2017

samuelkarp commented May 4, 2017

vsiddharth commented May 10, 2017

aaithal May 10, 2017 •

edited

Loading

aaithal May 23, 2017

vsiddharth commented May 24, 2017

samuelkarp commented May 24, 2017

vsiddharth commented May 24, 2017

adnxn commented May 24, 2017

vsiddharth commented May 25, 2017

adnxn commented May 26, 2017

Fix concurrent writes during image cleanup #743

Fix concurrent writes during image cleanup #743

Conversation

vsiddharth commented Mar 28, 2017 • edited Loading

Summary

Implementation details

Testing

Description for the changelog

Licensing

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

aaithal May 10, 2017 • edited Loading

Choose a reason for hiding this comment

samuelkarp 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

samuelkarp commented May 4, 2017

vsiddharth commented May 10, 2017

aaithal May 10, 2017 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

vsiddharth commented May 24, 2017

samuelkarp commented May 24, 2017

vsiddharth commented May 24, 2017

adnxn commented May 24, 2017

vsiddharth commented May 25, 2017

adnxn commented May 26, 2017

vsiddharth commented Mar 28, 2017 •

edited

Loading

aaithal May 10, 2017 •

edited

Loading

aaithal May 10, 2017 •

edited

Loading