Query-frontend will occasionally panic when under sustained load

[kvrhdn]

Describe the bug

Query-frontend will occasionally panic:

panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x47ad05]
goroutine 302 [running]:
errors.(*errorString).Error(0x0, 0x209c7e0, 0x0)
	/usr/local/go/src/errors/errors.go:68 +0x5
github.com/opentracing/opentracing-go/log.Field.Marshal(0x2485b37, 0xc, 0x9, 0x0, 0x0, 0x0, 0x209c7e0, 0x0, 0x2995038, 0xc06a0b00d8)
	/drone/src/vendor/github.com/opentracing/opentracing-go/log/field.go:231 +0x309
github.com/uber/jaeger-client-go.ConvertLogsToJaegerTags(0xc000a68780, 0x3, 0x3, 0xc06984e008, 0x39c7248, 0xc000cfbd78)
	/drone/src/vendor/github.com/uber/jaeger-client-go/jaeger_tag.go:31 +0x13f
github.com/uber/jaeger-client-go.buildLogs(0xc06975e480, 0x1, 0x1, 0x100, 0x39c7248, 0x0)
	/drone/src/vendor/github.com/uber/jaeger-client-go/jaeger_thrift_span.go:82 +0x145
github.com/uber/jaeger-client-go.BuildJaegerThrift(0xc0697586c0, 0x0)
	/drone/src/vendor/github.com/uber/jaeger-client-go/jaeger_thrift_span.go:43 +0x16c
github.com/uber/jaeger-client-go.(*udpSender).Append(0xc000ccad80, 0xc0697586c0, 0x0, 0x0, 0x2)
	/drone/src/vendor/github.com/uber/jaeger-client-go/transport_udp.go:129 +0x45
github.com/uber/jaeger-client-go.(*remoteReporter).processQueue(0xc000533f80)
	/drone/src/vendor/github.com/uber/jaeger-client-go/reporter.go:304 +0x1c2
created by github.com/uber/jaeger-client-go.NewRemoteReporter
	/drone/src/vendor/github.com/uber/jaeger-client-go/reporter.go:237 +0x1a5

We observed this while receiving a constant load of about 23 queries per second.

To Reproduce
Steps to reproduce the behavior:

1. Run Tempo
2. Send a ton of queries

Expected behavior
Tempo should not panic.

Environment:

• Infrastructure: Kubernetes
• Deployment tool: jsonnet

Additional Context

[kvrhdn]

The panic originates from these lines:

if err, ok := lf.interfaceVal.(error); ok {
	visitor.EmitString(lf.key, err.Error())
} else {
	visitor.EmitString(lf.key, "<nil>")
}

https:/opentracing/opentracing-go/blob/bdbb7cc3a1c08db5cc8b3296ec4447544fb43fe3/log/field.go#L230-L234

I'm guessing we are somewhere logging aƒ span field with log.Error(...). Its value implements the error interface, but when we call .Error() it panics.

Implementation of errorString.Error():

func (e *errorString) Error() string {
	return e.s
}

https://golang.org/src/errors/errors.go

This can only panic if e is nil, but how can it implement the error interface then?

---

It's possible to pass a nil value with a non-nil interface:

func method() error {
    var myerr *myError
    return myerr
}

But errorString is a private struct from the go std library?

[kvrhdn]

Looking at when these panics started appearing, I believe this was introduced between 5ad92c9 and 3638caa. The only change in the query-frontend is the #814...

[kvrhdn]

Example of how you can cause this: https://play.golang.org/p/K4rrupMiAYt

package main

import (
	"fmt"
)

func main() {
	err := badError()

	// safe way to print
	fmt.Println(err)

	// nil check fails to catch this
	if err != nil {
		fmt.Println(err.Error()) // this still panics!
	}
}

func badError() error {
	var m *myErr
	return m
}

type myErr struct {
	s string
}

func (m *myErr) Error() string {
	return fmt.Sprintf("%s\n", m.s)
}

[kvrhdn]

Closing in favour of #857