How can I automatically create span in every function in go?

Question

I want to use Otel to log every request's exec line with Jaeger. But I found that if I want to calc every function's exec time I must create a span for it. Just like this:

func ATestFunction(ctx context.Context, username string) {
    span, _ := opentracing.StartSpanFromContext(ctx, "operation name")
    defer span.Finish()

   // do something
}

It means every function that I want to log exec time I must add two line fixed codes. How can I solve such a problem with adding fixed codes.

Answer 1

It's a reasonable question. Instrumentation is already something that seems like overhead and busy work, clutter that should be elegant to write.

The good news is that by starting with tracing you can (in principle) also cover logging (add an event to the span), and metrics (tie them to specific events or metrics of spans, or use a tool like Honeycomb.io or Jaeger which are built around traces). So you're already on a good path to a low clutter instrumentation system.

Also, you should not throw away the second value returned by StartSpanFromContext. It is very important to keep the new context; that context has the new span in it! It must be passed to subfunctions to work correctly.

The other general point worth making is that the block added is meaningful. Not every function you write is worth instrumenting. The span should represent the start of a function that an expert application user or system administrator might understand, but you should not have to be intimately familiar with the source code.

If you want a zero–coding overhead approach to understanding application performance, you are probably looking for PProf. This one lets you just include the module and start an HTTP server in a goroutine, and then you can connect to it on the command line to get PProf output. It works by stopping every goroutine at 100Hz and examining the call stack for each goroutine, adding 1 to each line found. It's surprisingly low overhead and lets you create decent flame graphs that you can use to figure out where time is being spent for a slow operation or what code a mixed use server is the hottest.

So, once you accept that starting a span is introducing a useful thing—it's connecting the code's internals, with the applications "core logic" / "business logic" concepts (also, backend services)—then you can see that it's not just droll code: it should be useful, well chosen words to describe something significant occuring. Sometimes it will be there, mostly not. You're communicating with the people running the application, what is going on. They're not "notes to self".

For what it's worth, it's OK to write an abstraction around the library that you're using. Making a wrapper that lets you keep the code as clean as possible is fine, and an important part of application architecture. Eg, you could keep the span variable inside the ctx, using:

ctx = instrumentation.StartSpan(ctx, "operation name")
defer instrumentation.EndSpan(ctx)

// something that uses the span
instrumentation.Log(ctx, "eventID", log.String("foo", "bar"))

You're still left with 2 lines, that's pretty unavoidable because you've got an assignment, and a defer, and defer must happen in the same function. So while the abstraction did not reduce the line count, it did eliminate a variable not always needed, and perhaps you can see how this style of using context.Context can simplify cross–cutting concerns such as configuration and instrumentation.

Those two functions would look like this (in an instrumentation module):

type spanTag int
// special tag for getting the span out.  Impossible for other modules to
// do this without going through public functions in this module.
var contextSpanTag = spanTag(42)

func StartSpan(ctx context.Context) context.Context {
    span, newCtx := opentracing.StartSpanFromContext(ctx, "operation name")
    // this might be redundant; opentracing may have already put the
    // span inside `newCtx` and provided a way to get it out again.
    // If so, the internals of this code would change or maybe the
    // whole abstraction become moot.
    return newCtx.WithValue(contextSpanTag, span)
}

func EndSpan(ctx context.Context, operationName string) context.Context {
    ctx.Value(contextSpanTag).(*opentracing.Span).Finish()
}

func Span(ctx context.Context) *opentracing.Span {
    return ctx.Value(contextSpanTag)
}

Generally Go code is not written for minimal line count. The important thing is that the code is easy to read and reckon with. So it's best to just work with what it gives you, or if you have ideas about improving it, submit those to the "go-nuts" mailing list.

Answer 2

How can I solve such a problem with adding fixed codes.

You cannot.

If you want to instrument every function you have to do that: Either manually or via code generation/rewriting.