Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Panic during shutdown due to sending on a nil channel #1850

Closed
ellismg opened this issue Aug 30, 2018 · 12 comments
Closed

Panic during shutdown due to sending on a nil channel #1850

ellismg opened this issue Aug 30, 2018 · 12 comments
Assignees
@swgillespie
Labels
area/cli UX of using the CLI (args, output, logs) kind/bug Some behavior is incorrect or out of spec p1 A bug severe enough to be the next item assigned to an engineer
Milestone
0.20

Comments

@ellismg
Copy link
Contributor

ellismg commented Aug 30, 2018

We hit this in CI earlier today, in a single leg:

[ ynamic-provider/derived-inputs ] Previewing update of stack 'pulumi/p-it-traviss-ma-derived-in-2286c43a'
[ ynamic-provider/derived-inputs ] Previewing changes:
[ ynamic-provider/derived-inputs ] 
[ ynamic-provider/derived-inputs ]  *  pulumi:pulumi:Stack derived-inputs-p-it-traviss-ma-derived-in-2286c43a running 
[ ynamic-provider/derived-inputs ]  *  pulumi-nodejs:dynamic:Resource a no change 
[ ynamic-provider/derived-inputs ]  *  pulumi-nodejs:dynamic:Resource b no change 
[ ynamic-provider/derived-inputs ]  
[ ynamic-provider/derived-inputs ] info: no changes required:
[ ynamic-provider/derived-inputs ]       3 resources unchanged
[ ynamic-provider/derived-inputs ] 
[ ynamic-provider/derived-inputs ] panic: send on closed channel
[ ynamic-provider/derived-inputs ] 
[ ynamic-provider/derived-inputs ] goroutine 459 [running]:
[ ynamic-provider/derived-inputs ] github.com/pulumi/pulumi/vendor/github.com/uber/jaeger-client-go.(*remoteReporter).Report(0xc420097140, 0xc42154a0f0)
[ ynamic-provider/derived-inputs ] 	/Users/travis/gopath/src/github.com/pulumi/pulumi/vendor/github.com/uber/jaeger-client-go/reporter.go:209 +0x47
[ ynamic-provider/derived-inputs ] github.com/pulumi/pulumi/vendor/github.com/uber/jaeger-client-go.(*Tracer).reportSpan(0xc4200d65a0, 0xc42154a0f0)
[ ynamic-provider/derived-inputs ] 	/Users/travis/gopath/src/github.com/pulumi/pulumi/vendor/github.com/uber/jaeger-client-go/tracer.go:356 +0xd0
[ ynamic-provider/derived-inputs ] github.com/pulumi/pulumi/vendor/github.com/uber/jaeger-client-go.(*Span).FinishWithOptions(0xc42154a0f0, 0xbeda24b804126b60, 0x4482efc89, 0x21434c0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
[ ynamic-provider/derived-inputs ] 	/Users/travis/gopath/src/github.com/pulumi/pulumi/vendor/github.com/uber/jaeger-client-go/span.go:217 +0x524
[ ynamic-provider/derived-inputs ] github.com/pulumi/pulumi/vendor/github.com/uber/jaeger-client-go.(*Span).Finish(0xc42154a0f0)
[ ynamic-provider/derived-inputs ] 	/Users/travis/gopath/src/github.com/pulumi/pulumi/vendor/github.com/uber/jaeger-client-go/span.go:195 +0x56
[ ynamic-provider/derived-inputs ] github.com/pulumi/pulumi/vendor/github.com/grpc-ecosystem/grpc-opentracing/go/otgrpc.OpenTracingClientInterceptor.func1(0x2086000, 0xc4202fa690, 0x1afe1e6, 0x25, 0x1a63b00, 0xc4202fa5a0, 0x1a64a00, 0xc420905ae0, 0xc420200f00, 0x1b1f1d0, ...)
[ ynamic-provider/derived-inputs ] 	/Users/travis/gopath/src/github.com/pulumi/pulumi/vendor/github.com/grpc-ecosystem/grpc-opentracing/go/otgrpc/client.go:81 +0x636
[ ynamic-provider/derived-inputs ] github.com/pulumi/pulumi/vendor/google.golang.org/grpc.(*ClientConn).Invoke(0xc420200f00, 0x2086000, 0xc4202fa570, 0x1afe1e6, 0x25, 0x1a63b00, 0xc4202fa5a0, 0x1a64a00, 0xc420905ae0, 0x0, ...)
[ ynamic-provider/derived-inputs ] 	/Users/travis/gopath/src/github.com/pulumi/pulumi/vendor/google.golang.org/grpc/call.go:35 +0x109
[ ynamic-provider/derived-inputs ] github.com/pulumi/pulumi/vendor/google.golang.org/grpc.Invoke(0x2086000, 0xc4202fa570, 0x1afe1e6, 0x25, 0x1a63b00, 0xc4202fa5a0, 0x1a64a00, 0xc420905ae0, 0xc420200f00, 0x0, ...)
[ ynamic-provider/derived-inputs ] 	/Users/travis/gopath/src/github.com/pulumi/pulumi/vendor/google.golang.org/grpc/call.go:60 +0xc1
[ ynamic-provider/derived-inputs ] github.com/pulumi/pulumi/sdk/proto/go.(*resourceProviderClient).Configure(0xc4200906f8, 0x2086000, 0xc4202fa570, 0xc4202fa5a0, 0x0, 0x0, 0x0, 0x1010bc8, 0x19c2e80, 0x1a0f760)
[ ynamic-provider/derived-inputs ] 	/Users/travis/gopath/src/github.com/pulumi/pulumi/sdk/proto/go/provider.pb.go:1021 +0xd2
[ ynamic-provider/derived-inputs ] github.com/pulumi/pulumi/pkg/resource/plugin.(*provider).Configure.func1(0xc4208ae3c0, 0xc42188fa70, 0xc4203fdd00, 0x31)
[ ynamic-provider/derived-inputs ] 	/Users/travis/gopath/src/github.com/pulumi/pulumi/pkg/resource/plugin/provider_plugin.go:194 +0xd3
[ ynamic-provider/derived-inputs ] created by github.com/pulumi/pulumi/pkg/resource/plugin.(*provider).Configure
[ ynamic-provider/derived-inputs ] 	/Users/travis/gopath/src/github.com/pulumi/pulumi/pkg/resource/plugin/provider_plugin.go:193 +0x5f3
@lukehoban
Copy link
Member

Hit twice more in nightly test in the last few hours.

@lukehoban lukehoban added this to the 0.17 milestone Sep 2, 2018
@joeduffy joeduffy added kind/bug Some behavior is incorrect or out of spec area/cli UX of using the CLI (args, output, logs) labels Sep 2, 2018
@lukehoban
Copy link
Member

Let's at least turn off the jaeger reporting for now, that may not fully fix this - but we should do it as a first step.

@lukehoban lukehoban assigned lukehoban and unassigned pgavlin Sep 4, 2018
@lukehoban lukehoban modified the milestones: 0.17, 0.18 Sep 6, 2018
@lukehoban lukehoban assigned swgillespie and unassigned lukehoban Sep 13, 2018
@swgillespie
Copy link
Contributor

Is the intention here to turn off Jaeger reporting entirely?

@joeduffy
Copy link
Member

joeduffy commented Oct 9, 2018

I believe so, yes. Nobody is actively using it and it's a pretty intrusive hammer.

Are we still hitting this issue.

@swgillespie
Copy link
Contributor

I don't think so? I haven't heard about it in a while, and looking at our CI our builds have been green for a while.

@lukehoban
Copy link
Member

We had another user report seeing a panic sending on nil channel. Seems like a different path to get here - but ultimately similar failure on shutdown which may be from the same root cause?

Update duration: 1m5.254728905s

panic: send on closed channel

goroutine 204 [running]:
github.com/pulumi/pulumi/pkg/backend/httpstate.(*cloudBackend).runEngineAction.func1(0xc420971bc0, 0xc420971b00, 0x0, 0xc420971d40)
/home/travis/gopath/src/github.com/pulumi/pulumi/pkg/backend/httpstate/backend.go:780 +0xff
created by github.com/pulumi/pulumi/pkg/backend/httpstate.(*cloudBackend).runEngineAction
/home/travis/gopath/src/github.com/pulumi/pulumi/pkg/backend/httpstate/backend.go:777 +0x447

@swgillespie
Copy link
Contributor

@lukehoban ah, I think I know what went wrong there. I'll have a fix for that shortly.

@swgillespie
Copy link
Contributor

Fix for that panic: #2050

@swgillespie
Copy link
Contributor

Is there anything actionable remaining for this issue?

@lukehoban
Copy link
Member

I think we can close this out and we’ll reopen if we see any more cases of the original issue in Travis.

@CyrusNajmabadi
Copy link
Contributor

Getting this again: https://travis-ci.com/pulumi/pulumi-aws/builds/94274638

Has failed two builds in a row.

@swgillespie swgillespie modified the milestones: 0.18, 0.20 Dec 11, 2018
@ellismg
Copy link
Contributor Author

ellismg commented Dec 12, 2018

I've been seeing this more and more with the latest CLI across our CI systems. One such stack trace:

[ i/examples/azure-ts-appservice ] Invoke '/home/travis/.pulumi/bin/pulumi preview --non-interactive --tracing https://tracing.pulumi-engineering.com/collector/api/v1/spans' failed: exit status 2
[ i/examples/azure-ts-appservice ] Previewing update ([secure]/p-it-travis-job-azure-ts-a-aaa6f9c7):
[ i/examples/azure-ts-appservice ] 
[ i/examples/azure-ts-appservice ]  +  pulumi:pulumi:Stack azure-appservice-p-it-travis-job-azure-ts-a-aaa6f9c7 create 
[ i/examples/azure-ts-appservice ]  +  pulumi:pulumi:Stack azure-appservice-p-it-travis-job-azure-ts-a-aaa6f9c7 create flag provided but not defined: -tracing
[ i/examples/azure-ts-appservice ]  +  pulumi:pulumi:Stack azure-appservice-p-it-travis-job-azure-ts-a-aaa6f9c7 create Usage of tf-provider-flags:
[ i/examples/azure-ts-appservice ]  +  pulumi:pulumi:Stack azure-appservice-p-it-travis-job-azure-ts-a-aaa6f9c7 create   -get-provider-info
[ i/examples/azure-ts-appservice ]  +  pulumi:pulumi:Stack azure-appservice-p-it-travis-job-azure-ts-a-aaa6f9c7 create     	dump provider info as JSON to stdout
[ i/examples/azure-ts-appservice ] @ Previewing update....
[ i/examples/azure-ts-appservice ]  +  azure:core:ResourceGroup p-it-trav-rg create 
[ i/examples/azure-ts-appservice ]  +  azure:appservice:Plan p-it-trav-asp create 
[ i/examples/azure-ts-appservice ]  +  azure:appinsights:Insights p-it-trav-ai create 
[ i/examples/azure-ts-appservice ]  +  azure:storage:Account pittravsa create 
[ i/examples/azure-ts-appservice ]  +  azure:sql:SqlServer p-it-trav-sql create 
[ i/examples/azure-ts-appservice ]  +  azure:storage:Container p-it-trav-c create 
[ i/examples/azure-ts-appservice ]  +  azure:sql:Database p-it-trav-db create 
[ i/examples/azure-ts-appservice ]  +  azure:storage:ZipBlob p-it-trav-b create 
[ i/examples/azure-ts-appservice ]  +  azure:appservice:AppService p-it-trav-as create 
[ i/examples/azure-ts-appservice ]  
[ i/examples/azure-ts-appservice ] Diagnostics:
[ i/examples/azure-ts-appservice ]   pulumi:pulumi:Stack (azure-appservice-p-it-travis-job-azure-ts-a-aaa6f9c7):
[ i/examples/azure-ts-appservice ]     flag provided but not defined: -tracing
[ i/examples/azure-ts-appservice ]     Usage of tf-provider-flags:
[ i/examples/azure-ts-appservice ]       -get-provider-info
[ i/examples/azure-ts-appservice ]         	dump provider info as JSON to stdout
[ i/examples/azure-ts-appservice ]  
[ i/examples/azure-ts-appservice ] Resources:
[ i/examples/azure-ts-appservice ]     + 10 to create
[ i/examples/azure-ts-appservice ] 
[ i/examples/azure-ts-appservice ] Permalink: https://app.pulumi.com/[secure]/p-it-travis-job-azure-ts-a-aaa6f9c7/previews/8cc8d986-781c-45eb-b1cf-525f26ee8562
[ i/examples/azure-ts-appservice ] panic: send on closed channel
[ i/examples/azure-ts-appservice ] 
[ i/examples/azure-ts-appservice ] goroutine 64 [running]:
[ i/examples/azure-ts-appservice ] github.com/pulumi/pulumi/vendor/github.com/uber/jaeger-client-go.(*remoteReporter).Report(0xc00008d320, 0xc00036a960)
[ i/examples/azure-ts-appservice ] 	/home/travis/gopath/src/github.com/pulumi/pulumi/vendor/github.com/uber/jaeger-client-go/reporter.go:209 +0x47
[ i/examples/azure-ts-appservice ] github.com/pulumi/pulumi/vendor/github.com/uber/jaeger-client-go.(*Tracer).reportSpan(0xc0002ea3c0, 0xc00036a960)
[ i/examples/azure-ts-appservice ] 	/home/travis/gopath/src/github.com/pulumi/pulumi/vendor/github.com/uber/jaeger-client-go/tracer.go:356 +0xd7
[ i/examples/azure-ts-appservice ] github.com/pulumi/pulumi/vendor/github.com/uber/jaeger-client-go.(*Span).FinishWithOptions(0xc00036a960, 0xbefc4b4a46843467, 0x6befe63ac, 0x1968820, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
[ i/examples/azure-ts-appservice ] 	/home/travis/gopath/src/github.com/pulumi/pulumi/vendor/github.com/uber/jaeger-client-go/span.go:217 +0x439
[ i/examples/azure-ts-appservice ] github.com/pulumi/pulumi/vendor/github.com/uber/jaeger-client-go.(*Span).Finish(0xc00036a960)
[ i/examples/azure-ts-appservice ] 	/home/travis/gopath/src/github.com/pulumi/pulumi/vendor/github.com/uber/jaeger-client-go/span.go:195 +0x67
[ i/examples/azure-ts-appservice ] github.com/pulumi/pulumi/pkg/backend/httpstate/client.pulumiAPICall(0xff3e00, 0xc000e3e420, 0xff85a0, 0xc0001da1e0, 0xc00015e240, 0x16, 0xeb1e95, 0x4, 0xc001326d90, 0x6a, ...)
[ i/examples/azure-ts-appservice ] 	/home/travis/gopath/src/github.com/pulumi/pulumi/pkg/backend/httpstate/client/api.go:234 +0x129f
[ i/examples/azure-ts-appservice ] github.com/pulumi/pulumi/pkg/backend/httpstate/client.pulumiRESTCall(0xff3e00, 0xc000e3e420, 0xff85a0, 0xc0001da1e0, 0xc00015e240, 0x16, 0xeb1e95, 0x4, 0xc001326d90, 0x6a, ...)
[ i/examples/azure-ts-appservice ] 	/home/travis/gopath/src/github.com/pulumi/pulumi/pkg/backend/httpstate/client/api.go:268 +0x180
[ i/examples/azure-ts-appservice ] github.com/pulumi/pulumi/pkg/backend/httpstate/client.(*Client).updateRESTCall(0xc0012d4200, 0xff3e00, 0xc000e3e420, 0xeb1e95, 0x4, 0xc001326d90, 0x6a, 0x0, 0x0, 0xe74bc0, ...)
[ i/examples/azure-ts-appservice ] 	/home/travis/gopath/src/github.com/pulumi/pulumi/pkg/backend/httpstate/client/client.go:82 +0x1af
[ i/examples/azure-ts-appservice ] github.com/pulumi/pulumi/pkg/backend/httpstate/client.(*Client).RecordEngineEvent(0xc0012d4200, 0xff3e00, 0xc000e3e420, 0xc000e5a1b6, 0x7, 0xc001302150, 0x23, 0xeb5ee7, 0x7, 0xc0013023f0, ...)
[ i/examples/azure-ts-appservice ] 	/home/travis/gopath/src/github.com/pulumi/pulumi/pkg/backend/httpstate/client/client.go:514 +0x19d
[ i/examples/azure-ts-appservice ] github.com/pulumi/pulumi/pkg/backend/httpstate.(*cloudUpdate).recordEvent(0xc00012d480, 0xeb5ee7, 0x7, 0xeb4166, 0x6, 0x0, 0x0, 0x139, 0xc0001f3a08, 0xeb347b, ...)
[ i/examples/azure-ts-appservice ] 	/home/travis/gopath/src/github.com/pulumi/pulumi/pkg/backend/httpstate/state.go:160 +0x2b1
[ i/examples/azure-ts-appservice ] github.com/pulumi/pulumi/pkg/backend/httpstate.(*cloudUpdate).RecordAndDisplayEvents(0xc00012d480, 0xc000d61620, 0x11, 0xeb5ee7, 0x7, 0xfedd40, 0xc0010087b0, 0xc00012c280, 0xc000e0cb40, 0x32, ...)
[ i/examples/azure-ts-appservice ] 	/home/travis/gopath/src/github.com/pulumi/pulumi/pkg/backend/httpstate/state.go:187 +0x319
[ i/examples/azure-ts-appservice ] created by github.com/pulumi/pulumi/pkg/backend/httpstate.(*cloudBackend).runEngineAction
[ i/examples/azure-ts-appservice ] 	/home/travis/gopath/src/github.com/pulumi/pulumi/pkg/backend/httpstate/backend.go:749 +0x2b1

@joeduffy joeduffy added the p1 A bug severe enough to be the next item assigned to an engineer label Dec 12, 2018
pgavlin added a commit that referenced this issue Dec 13, 2018
@pgavlin
Fix synchronization with the event renderer
fda5b3c 
The event rendering goroutine in the remote backend was not properly
synchronizing with the goroutine that created it, and could continue
executing after its creator finished. I believe that this is the root
cause of #1850.
@pgavlin pgavlin mentioned this issue Dec 13, 2018
Merged
pgavlin added a commit that referenced this issue Dec 14, 2018
@pgavlin
Fix synchronization with the event renderer (#2290)
ded3882 
The event rendering goroutine in the remote backend was not properly
synchronizing with the goroutine that created it, and could continue
executing after its creator finished. I believe that this is the root
cause of #1850.
@pgavlin pgavlin closed this as completed Dec 14, 2018
ellismg added a commit that referenced this issue Dec 14, 2018
@ellismg
Fix synchronization with the event renderer (#2290)
d2bd696 
The event rendering goroutine in the remote backend was not properly
synchronizing with the goroutine that created it, and could continue
executing after its creator finished. I believe that this is the root
cause of #1850.

(cherry picked from commit ded3882)
@lukehoban lukehoban mentioned this issue Dec 24, 2018
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@swgillespie swgillespie

Labels
area/cli UX of using the CLI (args, output, logs) kind/bug Some behavior is incorrect or out of spec p1 A bug severe enough to be the next item assigned to an engineer
Projects
None yet
Milestone
0.20
Development

No branches or pull requests
6 participants
@lukehoban @pgavlin @swgillespie @joeduffy @CyrusNajmabadi @ellismg