Getting a panic in the inmemory dispatcher

[lionelvillard]

Describe the bug

A cronjob sending an event to a ksvc causes this panic:

imc-dispatcher-665cddfb4f-wkmpx dispatcher panic: runtime error: invalid memory address or nil pointer dereference
imc-dispatcher-665cddfb4f-wkmpx dispatcher [signal SIGSEGV: segmentation violation code=0x1 addr=0x10 pc=0x13cc6b3]
imc-dispatcher-665cddfb4f-wkmpx dispatcher
imc-dispatcher-665cddfb4f-wkmpx dispatcher goroutine 58 [running]:
imc-dispatcher-665cddfb4f-wkmpx dispatcher knative.dev/eventing/vendor/go.opencensus.io/trace.(*Span).SetSpanID(...)
imc-dispatcher-665cddfb4f-wkmpx dispatcher 	/home/prow/go/src/knative.dev/eventing/vendor/go.opencensus.io/trace/trace.go:265
imc-dispatcher-665cddfb4f-wkmpx dispatcher knative.dev/eventing/pkg/tracing.AddSpanFromTraceparentAttribute(0x1b77180, 0xc0006e4270, 0x0, 0x0, 0x1bb89c0, 0xc000438a80, 0x1580ae0, 0xc0006ea260, 0x1, 0x4, ...)
imc-dispatcher-665cddfb4f-wkmpx dispatcher 	/home/prow/go/src/knative.dev/eventing/pkg/tracing/traceparent.go:83 +0x1f3
imc-dispatcher-665cddfb4f-wkmpx dispatcher knative.dev/eventing/pkg/channel.(*EventDispatcher).generateSendingContext(0xc0003a9860, 0xc000047ef5, 0x1, 0xc0001c87d0, 0x4a, 0xc000047ef0, 0x4, 0xc0006ee690, 0x0, 0xc000031600, ...)
imc-dispatcher-665cddfb4f-wkmpx dispatcher 	/home/prow/go/src/knative.dev/eventing/pkg/channel/event_dispatcher.go:120 +0xc9
imc-dispatcher-665cddfb4f-wkmpx dispatcher knative.dev/eventing/pkg/channel.(*EventDispatcher).executeRequest(0xc0003a9860, 0x1b77180, 0xc0006ee6c0, 0xc0001dd680, 0x1bb89c0, 0xc000438a80, 0x1580ae0, 0xc0006ea260, 0x1, 0x40c458, ...)
imc-dispatcher-665cddfb4f-wkmpx dispatcher 	/home/prow/go/src/knative.dev/eventing/pkg/channel/event_dispatcher.go:105 +0x3a7
imc-dispatcher-665cddfb4f-wkmpx dispatcher knative.dev/eventing/pkg/channel.(*EventDispatcher).DispatchEvent(0xc0003a9860, 0x1b77180, 0xc0006ee6c0, 0x1bb89c0, 0xc000438a80, 0x1580ae0, 0xc0006ea260, 0x1, 0xc0001b3980, 0x3e, ...)

Expected behavior
no panic

To Reproduce
Create a cronjob sending event to channel?

Knative release version
nightly

[grantr]

@Harwayne this looks like a tracing issue

[lionelvillard]

was working before this PR: #1972

[lionelvillard]

This is running in a cluster without tracing enabled.

[lionelvillard]

It seems more complicated than a cronjob to event-display. The failing config is this one: https://github.com/lionelvillard/knative-examples/tree/master/examples/sequence/config

[Harwayne]

/assign

[lionelvillard]

here a simpler config: https://github.com/lionelvillard/knative-examples/tree/master/issues/eventing-1986

[Harwayne]

The failing line is:

eventing/vendor/go.opencensus.io/trace/trace.go

Line 265 in ec33114

s.data.SpanID = spanID

So either s or s.data is nil.

It is being called from here

eventing/pkg/tracing/traceparent.go

Lines 82 to 83 in 3f243b5

	_, span := trace.StartSpanWithRemoteParent(ctx, name, sc)
	span.SetSpanID(sc.SpanID)

.

So either span or span.data is nil.

span is set to StartSpanWithRemoteParent.

eventing/vendor/go.opencensus.io/trace/trace.go

Lines 193 to 202 in ec33114

	func StartSpanWithRemoteParent(ctx context.Context, name string, parent SpanContext, o ...StartOption) (context.Context, *Span) {
	var opts StartOptions
	for _, op := range o {
	op(&opts)
	}
	span := startSpanInternal(name, parent != SpanContext{}, parent, true, opts)
	ctx, end := startExecutionTracerTask(ctx, name)
	span.executionTracerTaskEnd = end
	return NewContext(ctx, span), span
	}

There is only one return from that method, line 201. On line 200, span.executionTraceTaskEnd is set, so that shows that span is not nil, span.data is.

startSpanInternal is used to create the span. span.data is set on

eventing/vendor/go.opencensus.io/trace/trace.go

Line 237 in ec33114

span.data = &SpanData{

. But there is a return before that on line 234. So I think we must be returning on 234, thus span.data is nil.

I'll have a PR to fix this soon.

[Harwayne]

here a simpler config: https://github.com/lionelvillard/knative-examples/tree/master/issues/eventing-1986

Note that for this to reproduce, tracing has to be set to disabled. Or at least a request has to go through that isn't sampled.

[lionelvillard]

Can we reopen? Still not working. I'm testing against nightly, so it could an issue with the nightly image.

[Harwayne]

Can we reopen? Still not working. I'm testing against nightly, so it could an issue with the nightly image.

/reopen

Some additional details that will help.

• Is it the same stack trace?
• What image is the imc-dispatcher running as?
• What does your config-tracing ConfigMap in knative-eventing look like?

[knative-prow-robot]

@Harwayne: Reopened this issue.

In response to this:

Can we reopen? Still not working. I'm testing against nightly, so it could an issue with the nightly image.

/reopen

Can you give some more details? Is it the same stack trace? What image is the imc-dispatcher running as? What is your config-tracing configmap in knative-eventing look like?

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

[akashrv]

/milestone v0.10.0
/priority important-soon

[lionelvillard]

This is fixed in the master branch. The nightly build failed last night so I was still using the wrong image.