goroutine leak on solves

[coryb]

I don't have a lot of details yet, but we noticed goroutine leaks with our buildkit cluster after a recent upgrade. I was able to reproduce with master, following the same recipe as the last leak we noticed:
#1316 (comment)

Able to reproduce with runc and containerd workers:

INFO    [05:25:59.243]  GoRoutines: 31
INFO    [05:26:09.243]  GoRoutines: 48
INFO    [05:26:19.243]  GoRoutines: 64
INFO    [05:26:29.244]  GoRoutines: 99
INFO    [05:26:39.244]  GoRoutines: 127
INFO    [05:26:49.244]  GoRoutines: 113
INFO    [05:26:59.244]  GoRoutines: 128
INFO    [05:27:09.245]  GoRoutines: 166
INFO    [05:27:19.245]  GoRoutines: 163

I will report more details as I discover them, not sure how much time I will get this weekend.

[coryb]

Using git bisect it seems the leak started with this commit: 6a3d6e9

I dont really see how it could be leaking, but the previous commit 7f0d13f does not show this problem.

[coryb]

The leak comes from the small changes in source/containerimage/pull.go, and specifically the progress.Writer that gets created here never seems to have Close called on it which causes the leak. If we leave the progressController as nil then the leak goes away:

			var progressController *controller.Controller
			// pw, _, _ := progress.FromContext(ctx)
			// progressController := &controller.Controller{
			// 	Writer: pw,
			// }
			// if p.vtx != nil {
			// 	progressController.Digest = p.vtx.Digest()
			// 	progressController.Name = p.vtx.Name()
			// }

I don't see how the change to use flighcontrol.Group from the sync.Once could change how the progress.Writer is closed. I am guessing that the descHandlers is getting lost or overwritten somehow, but not sure.

@tonistiigi Any ideas? I am still a bit baffled by this one.

[coryb]

I think I have some idea now:
The ctx used for the progress.Writer:

buildkit/source/containerimage/pull.go

Line 203 in 70deac1

pw, _, _ := progress.FromContext(ctx)

comes from the argument to the callback:

buildkit/source/containerimage/pull.go

Line 176 in 70deac1

_, err = p.g.Do(ctx, "", func(ctx context.Context) (_ interface{}, err error) {

which is initialized as a shared context here:

buildkit/util/flightcontrol/flightcontrol.go

Line 105 in 70deac1

ctx := newContext(c) // newSharedContext

If we change the ctx used for the progress.Writer to be the one passed into the CacheKey function then the leak goes away. That matches the ctx used with the previous sync.Once usage.

No idea if that the recommended solution here or not, it is not clear to me why the shared context used by the flightcontrol.Group is never Done.

[tonistiigi]

Using outer ctx inside g.Do is not correct. I don't fully understand the ref chain logic that directly causes the leak from a quick look but not closing the progresswriter is an issue on its own. They should be closed and I'm not sure why it doesn't cause a bigger issue if they are not. If needed we may need to add an extra method that instead of initializing a new writer in progress.FromContext instead returns a function that returns writer instances when needed.

[coryb]

Can we add a defer pw.Close() after the progress.FromContext? I can't tell when the pw will no longer be used, will it be used outside of the CacheKey func?

[tonistiigi]

It looks to me that it gets saved in descHandlers cc @sipsma

[coryb]

I'm even more confused now, these are the two goroutines leaked:

goroutine 255 [select]:
github.com/moby/buildkit/util/progress.(*progressReader).Read.func1(0xc0005a4fc0, 0x1a90ca0, 0xc000124038, 0xc0000c3170)
        /go/src/github.com/moby/buildkit/util/progress/progress.go:106 +0xbd
created by github.com/moby/buildkit/util/progress.(*progressReader).Read
        /go/src/github.com/moby/buildkit/util/progress/progress.go:105 +0xdf

goroutine 308 [sync.Cond.Wait]:
github.com/moby/buildkit/util/progress.(*progressReader).Read(0xc0000c3170, 0x1a90ca0, 0xc000124038, 0x0, 0x0, 0x0, 0x0, 0x0)
        /go/src/github.com/moby/buildkit/util/progress/progress.go:132 +0x116
github.com/moby/buildkit/util/flightcontrol.(*progressState).run(0xc0000c30e0, 0x1a5fc40, 0xc0000c3170)
        /go/src/github.com/moby/buildkit/util/flightcontrol/flightcontrol.go:288 +0x176
created by github.com/moby/buildkit/util/flightcontrol.newCall
        /go/src/github.com/moby/buildkit/util/flightcontrol/flightcontrol.go:112 +0x1d8

Which corresponds to:

buildkit/util/flightcontrol/flightcontrol.go

Line 288 in 70deac1

p, err := pr.Read(context.TODO())

and:

buildkit/util/progress/progress.go

Line 106 in 70deac1

select {

It is not obvious to me how the closing the progress.Writer created in CacheKey has any relationship to closing the progress.Reader created in newCall, but it does prevent the leak.

[aaronlehmann]

It seems like forgetting to close a progress writer is a common problem. I ran into that here as well: #2043

Perhaps FromContext should return a function that closes the progress writer, so the caller has to explicitly ignore that return value to skip the closing.

[tonistiigi]

so the caller has to explicitly ignore that return value to skip the closing.

Or a logger in finalized. But I think for this case the main issue is that there is not an easy place where to close it as it is kept for later use. So I think getting the ref from context and initializing a new writer should be separated so that every place that actually writes progress can make a writer and then cleanly close it, without needing to use the same context.

It is not obvious to me how the closing the progress.Writer created in CacheKey has any relationship to closing the progress.Reader

Writers map needs to be empty for the read to return iiuc