progressutil: added mutexes to make go's race detector happy #61
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| current int64 | ||
| total int64 | ||
| done bool | ||
| doneLock sync.Mutex |
There was a problem hiding this comment.
Typically lock is just above protected member
docker2aci has some race conditions, and go's race detector found some race-y accesses in progressutil, so this commit wraps some variables shared between goroutines in mutexes.
|
Let this run for an hour and a half with Go's race detector going: Found another issue, fixed it. I think this is good now. |
|
@dgonyeo to be clear, did you reproduce the issue(s) we were experiencing Derek Gonyeo notifications@github.com schrieb am Fr., 27. Mai 2016, 23:54:
|
|
This doesn't address all the issues but it's a step forward |
jonboulle
added a commit
to jonboulle/docker2aci
that referenced
this pull request
May 29, 2016
The parallel pull refactoring in 47f2cb9 introduced an unfortunate and subtle race condition. Because i) we were asynchronously starting the fetching of each layer [1][1] (which implies that the fetch is added to the progress bar asynchronously, via getLayerV2 [2][2] [3][3]), and ii) the progressutil package has no guards against calling PrintAndWait and AddCopy in indeterminate order [4][4], it was possible for us to enter the PrintAndWait loop [5][5] [6][6] before all of the layer fetches had actually been added to it. Then, in the event that the first layer was particularly fast, the CopyProgressPrinter could actually think it was done [7][7] before the other layer(s) had finished. In this situation, docker2aci would happily continue forward and try to generate an ACI from each layer [8][8], and for any layer(s) that had not actually finished downloading, the GenerateACI->writeACI->tarball.Walk call [9][9] would be operating on a partially written file and hence result in the errors we've been seeing ("unexpected EOF", "corrupt input before offset 45274", and so forth). A great case to reproduce this is the `docker:busybox` image because of its particular characteristics: two layers, one very small (32B) and one relatively larger (676KB) layer. Typical output looks like the following ``` % $(exit 0); while [ $? -eq 0 ]; do ./bin/docker2aci docker://busybox; done Downloading sha256:385e281300c [===============================] 676 KB / 676 KB Downloading sha256:a3ed95caeb0 [===============================] 32 B / 32 B Generated ACI(s): library-busybox-latest.aci Downloading sha256:a3ed95caeb0 [==============================] 32 B / 32 B Downloading sha256:385e281300c [==============================] 676 KB / 676 KB Generated ACI(s): library-busybox-latest.aci Downloading sha256:a3ed95caeb0 [===================================] 32 B / 32 B Error: conversion error: error generating ACI: error writing ACI: Error reading tar entry: unexpected EOF ``` Note that i) the order in which the layers are registered with the progress printer is indeterminate, and ii) every failure case (observed so far) is when the small layer is retrieved first, and the stdout contains no progress output at all from retrieving the other layer. This indeed suggests that the progress printer returns before realising the second layer is still being retrieved. Tragically, @dgonyeo's test case [10][10] probably gives a false sense of security (i.e. it cannot reproduce this issue), most likely because the `dgonyeo/test` image contains a number of layers (5) of varying sizes, and I suspect it's much less likely for this particular race to occur. Almost certainly fixes appc#166 - with this patch I'm unable to reproduce. [1]: https://github.com/appc/docker2aci/blob/ba503aa9b84b6c1ffbab03ec0589415ef598e5e0/lib/internal/backend/repository/repository2.go#L89 [2]: https://github.com/appc/docker2aci/blob/ba503aa9b84b6c1ffbab03ec0589415ef598e5e0/lib/internal/backend/repository/repository2.go#L115 [3]: https://github.com/appc/docker2aci/blob/ba503aa9b84b6c1ffbab03ec0589415ef598e5e0/lib/internal/backend/repository/repository2.go#L335 [4]: coreos/pkg#63 [5]: https://github.com/appc/docker2aci/blob/ba503aa9b84b6c1ffbab03ec0589415ef598e5e0/lib/internal/backend/repository/repository2.go#L123 [6]: https://github.com/coreos/pkg/blob/master/progressutil/iocopy.go#L115 [7]: https://github.com/coreos/pkg/blob/master/progressutil/iocopy.go#L144 [8]: https://github.com/appc/docker2aci/blob/ba503aa9b84b6c1ffbab03ec0589415ef598e5e0/lib/internal/backend/repository/repository2.go#L149 [9]: https://github.com/appc/docker2aci/blob/4e051449c0079ba8df59a51c14b7d310de1830b8/lib/internal/internal.go#L427 [10]: coreos/pkg#61 (comment)
jonboulle
added a commit
to jonboulle/docker2aci
that referenced
this pull request
May 29, 2016
The parallel pull refactoring in 47f2cb9 introduced an unfortunate and subtle race condition. Because i) we were asynchronously starting the fetching of each layer [1][1] (which implies that the fetch is added to the progress bar asynchronously, via getLayerV2 [2][2] [3][3]), and ii) the progressutil package has no guards against calling PrintAndWait and AddCopy in indeterminate order [4][4], it was possible for us to enter the PrintAndWait loop [5][5] [6][6] before all of the layer fetches had actually been added to it. Then, in the event that the first layer was particularly fast, the CopyProgressPrinter could actually think it was done [7][7] before the other layer(s) had finished. In this situation, docker2aci would happily continue forward and try to generate an ACI from each layer [8][8], and for any layer(s) that had not actually finished downloading, the GenerateACI->writeACI->tarball.Walk call [9][9] would be operating on a partially written file and hence result in the errors we've been seeing ("unexpected EOF", "corrupt input before offset 45274", and so forth). A great case to reproduce this is the `docker:busybox` image because of its particular characteristics: two layers, one very small (32B) and one relatively larger (676KB) layer. Typical output looks like the following ``` % $(exit 0); while [ $? -eq 0 ]; do ./bin/docker2aci docker://busybox; done Downloading sha256:385e281300c [===============================] 676 KB / 676 KB Downloading sha256:a3ed95caeb0 [===============================] 32 B / 32 B Generated ACI(s): library-busybox-latest.aci Downloading sha256:a3ed95caeb0 [==============================] 32 B / 32 B Downloading sha256:385e281300c [==============================] 676 KB / 676 KB Generated ACI(s): library-busybox-latest.aci Downloading sha256:a3ed95caeb0 [===================================] 32 B / 32 B Error: conversion error: error generating ACI: error writing ACI: Error reading tar entry: unexpected EOF ``` Note that i) the order in which the layers are registered with the progress printer is indeterminate, and ii) every failure case (observed so far) is when the small layer is retrieved first, and the stdout contains no progress output at all from retrieving the other layer. This indeed suggests that the progress printer returns before realising the second layer is still being retrieved. Tragically, @dgonyeo's test case [10][10] probably gives a false sense of security (i.e. it cannot reproduce this issue), most likely because the `dgonyeo/test` image contains a number of layers (5) of varying sizes, and I suspect it's much less likely for this particular race to occur. Almost certainly fixes appc#166 - with this patch I'm unable to reproduce. [1]: https://github.com/appc/docker2aci/blob/ba503aa9b84b6c1ffbab03ec0589415ef598e5e0/lib/internal/backend/repository/repository2.go#L89 [2]: https://github.com/appc/docker2aci/blob/ba503aa9b84b6c1ffbab03ec0589415ef598e5e0/lib/internal/backend/repository/repository2.go#L115 [3]: https://github.com/appc/docker2aci/blob/ba503aa9b84b6c1ffbab03ec0589415ef598e5e0/lib/internal/backend/repository/repository2.go#L335 [4]: coreos/pkg#63 [5]: https://github.com/appc/docker2aci/blob/ba503aa9b84b6c1ffbab03ec0589415ef598e5e0/lib/internal/backend/repository/repository2.go#L123 [6]: https://github.com/coreos/pkg/blob/master/progressutil/iocopy.go#L115 [7]: https://github.com/coreos/pkg/blob/master/progressutil/iocopy.go#L144 [8]: https://github.com/appc/docker2aci/blob/ba503aa9b84b6c1ffbab03ec0589415ef598e5e0/lib/internal/backend/repository/repository2.go#L149 [9]: https://github.com/appc/docker2aci/blob/4e051449c0079ba8df59a51c14b7d310de1830b8/lib/internal/internal.go#L427 [10]: coreos/pkg#61 (comment)
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
docker2aci has some race conditions, and go's race detector found some
race-y accesses in progressutil, so this commit wraps some variables
shared between goroutines in mutexes.