DEV Community: Eli Yukelzon

OpenTracing for Go Projects

Eli Yukelzon — Sat, 11 Jul 2020 12:09:10 +0000

What is distributed tracing?

Large-scale cloud applications are usually built using interconnected services that can be rather hard to troubleshoot. When a service is scaled, simple logging doesn't cut it anymore and a more in-depth view into system's flow is required.
That's where distributed tracing comes into play; it allows developers and SREs to get a detailed view of a request as it travels through the system of services. With distributed tracing you can:

Trace the execution path of a single request as it goes through a complicated path inside the distributed system
Pinpoint bottlenecks and measure latency of specific parts of the execution path
Record and analyze system behavior

OpenTracing is an open standard describing how distributed tracing works.

There are a few key terms used in tracing:

Trace: A recording of the execution path of a request
Span: A named, timed operation representing a contiguous segment inside the trace
Root Span: The first span in a trace - a common ancestor to all spans in a trace
Context: Information identifying the request, required to connect spans in a distributed trace

A trace recording usually looks something like this:

We've previously explored an OpenTracing implementation in the first post of this series. Next, we want to add distributed tracing capabilities to mattermost-server. For this, we've picked OpenTracing Go.

In this article we'll discuss all the nitty-gritty details of implementing a tracing system in your Go application without littering your code with repetitive, boilerplate tracing code.

The goal

So what are we actually working on? We want to make sure that every API request that's being handled by our server will get recorded into a trace, together with context information. This gives us the ability to dive deep into the execution and allow easy problem analysis.

The resulting system trace will look like this (using Jaeger web-ui visualization):

Straightforward tracing implementation

To add tracing to any API call, we can do the following in our ServeHTTP function:


package web

import (
    // ...
    "github.com/opentracing/opentracing-go"
    "github.com/opentracing/opentracing-go/ext"
    spanlog "github.com/opentracing/opentracing-go/log"
)

func (h Handler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
    c := &Context{}
    // Start root span
    span, ctx := tracing.StartRootSpanByContext(context.Background(), "apiHandler")
    // Populate different span fields based on request headers
    carrier := opentracing.HTTPHeadersCarrier(r.Header)
    _ = opentracing.GlobalTracer().Inject(span.Context(), opentracing.HTTPHeaders, carrier)
    ext.HTTPMethod.Set(span, r.Method)
    ext.HTTPUrl.Set(span, c.App.Path())
    ext.PeerAddress.Set(span, c.App.IpAddress())
    span.SetTag("request_id", c.App.RequestId())
    span.SetTag("user_agent", c.App.UserAgent())
    // On handler exit, do the following:
    defer func() {
        // In case of an error, add it to the trace
        if c.Err != nil {
            span.LogFields(spanlog.Error(c.Err))
            ext.HTTPStatusCode.Set(span, uint16(c.Err.StatusCode))
            ext.Error.Set(span, true)
        }
        // Finish the span
        span.Finish()
    }()
    // Set current context to the one we got from root span - it will be passed down to actual API handlers
    c.App.SetContext(ctx)
    // ...
    // Execute the actual API handler
    h.HandleFunc(c, w, r)
}

Next, we'll modify the actual business logic function that's called by the API handler to nest it inside the parent span (we'll use SearchUsers as an example):

func (a *App) SearchUsers(props *model.UserSearch, options *model.UserSearchOptions) ([]*model.User, *model.AppError) {
    // Save previous context
    origCtx := a.ctx
    // Generate new span, nested inside the parent span
    span, newCtx := tracing.StartSpanWithParentByContext(a.ctx, "app.SearchUsers")
    // Set new context
    a.ctx = newCtx

    // Log some parameters
    span.SetTag("searchProps", props)

    // On function exit, restore context and finish the span
    defer func() {
        a.ctx = origCtx
        span.Finish()
    }()

    // ...
    // Perform actual work
    // ...

    // In case of an error, add it to the span
    if err != nil {
        span.LogFields(spanlog.Error(err))
        ext.Error.Set(span, true)
    }

    // Return results
}

Rather straightforward, right? We marked our "entry-point" by creating a root span, populated it with useful context information, passed the context down the stack, and created a new span underneath it.

We could stop right here, because this is all you need to have a working trace! But for a large application like mattermost-server wrapping all of the 900+ API handlers in tracing code would be incredibly labor intensive and will create a lot of noise in the source code.

So, can we do better?

Decorator pattern

Before diving into our solution, I want to first introduce the decorator pattern.

To quote Wikipedia:

In object-oriented programming, the decorator pattern is a design pattern that allows behavior to be added to an individual object, dynamically, without affecting the behavior of other objects from the same class. The decorator pattern is often useful for adhering to the Single Responsibility Principle, as it allows functionality to be divided between classes with unique areas of concern. The decorator pattern is structurally nearly identical to the chain of responsibility pattern, the difference being that in a chain of responsibility, exactly one of the classes handles the request, while for the decorator, all classes handle the request.

In simpler terms, let's say we have an object called Cow that has some methods:

We want to introduce additional functionality on top of what Cow already does, without modifying the actual code of the Cow object. For example, we want to measure performance of each method and log the parameters that are being passed to each method. Here's how it would look if we apply the decorator pattern:

We wrapped each method of Cow in a chain of additional functions: f(x) = y became f(x) = a(b(y)), with each function having its own responsibility.

If we apply the same pattern to our problem, we can decorate all of mattermost-server API calls with OpenTracing, without actually modifying the functions themselves!

Implementing such functionality in other, dynamic, languages is rather trivial. For example, here's how JavaScript handles it given a simple Cow object:

const cow = {
  feed: function(x) {
    return `Ate for ${x} seconds!`
  },
  speak: function(x) {
    return `${"Moo ".repeat(x)}!`
  }
}

console.log(cow.feed(20))
console.log(cow.speak(3))

We can wrap it in a proxy:

const tracerHandler = {
  get: function(target, prop, receiver) {
    if (typeof target[prop] === "function") {
      return function(...args) {
        console.log(`'${prop} 'called with arguments: `, ...arguments);
        return target[prop](...arguments);
      };
    }
  }
};

const timerHandler = {
  get: function(target, prop, receiver) {
    if (typeof target[prop] === "function") {
      return function(...args) {
        console.log(`starting '${prop}'`);
        const t1 = window.performance.now();

        const res = target[prop](...arguments);
        const t2 = window.performance.now();

        console.log(`'${prop}' took ${t2 - t1}ns`);
        return res;
      };
    }
  }
};

const proxy = new Proxy(cow, tracerHandler);
const proxy2 = new Proxy(proxy, timerHandler);
console.log(proxy2.feed(20));
console.log(proxy2.speak(3));

Unfortunately, in Go, there's no way to do this in a performant manner, and the regular approach would involve using reflection which can seriously impact performance on the underlying code.

Our solution

The implementation of the decorator pattern we chose involved three parts:

Struct embedding
Code parsing using AST
Code generation using templates

Struct embedding

Quoting Go FAQ

Although Go has types and methods and allows an object-oriented style of programming, there is no type hierarchy. The concept of "interface" in Go provides a different approach that we believe is easy to use and in some ways more general. There are also ways to embed types in other types to provide something analogous but not identical to subclassing.

type Animal struct{
    Name string
}

type Cow struct{
    Animal
}

func (c Cow) Speak() {
    fmt.Printf("Moo, I am a %s", c.Animal.Name)
}

func main() {
    a := Animal{Name:"Cow"}
    c := Cow{Animal:a}
    c.Speak()
}

How does struct embedding help us in the implementation of a decorator pattern?


type Speaker interface {
    Speak(x int)
}

type Animal struct {
    Name string
}

type TraceAnimal struct {
    Speaker
}

type MeasureAnimal struct {
    Speaker
}

func (c Animal ) Speak(x int) {
    fmt.Println(strings.Repeat("I am a " + c.Name + " ",x))
}

func (c TraceAnimal) Speak(x int) {
    fmt.Printf("Running Speak(x) function with x=%d!\n",x)
    c.Speaker.Speak(x)
}

func (c MeasureAnimal) Speak(x int) {
    fmt.Println("Timing Speak() function...")
    t := time.Now()
    c.Speaker.Speak(x)

    fmt.Printf("Speak(%d) took %s\n", x, time.Since(t))
}

func main() {
    a := Animal{Name: "Cow"}
    c := TraceAnimal {Speaker: a}
    d := MeasureAnimal{Speaker: c}
    d.Speak(2)
}

Running the following code will yield:

Timing Speak() function...
Running Speak(x) function with x=2!
I am a Cow I am a Cow 
Speak(2) took 0s

So we've basically implemented two decorators over the original Speak() method. First we started timing the execution in MeasureAnimal, then passed it to TraceAnimal, which in turn called the actual Speak() implementation.

This works great and stays performant since we don't use any dynamic techniques such as reflection. However this is very verbose and requires us to write a lot of wrapper code - and that's no fun at all.

We can do better!

Code parsing using AST

Using the methods we've discussed in parts 1 and 2 of this series we can scan the interface of the struct we want to wrap and collect all the information needed to generate the decorators/wrappers automatically. Let's dig in.

First of all, we kick off the AST parser on our input file that contains the interface and start walking through the found nodes:

package main

import (
    "bytes"
    "flag"
    "fmt"
    "go/ast"
    "go/parser"
    "go/token"
    "io/ioutil"
    "log"
    "os"
    "path"
    "strings"
    "text/template"

    "golang.org/x/tools/imports"
)

func main() {
    fset := token.NewFileSet() // Positions are relative to fset

    file, err := os.Open("animal.go")
    if err != nil {
        return nil, fmt.Errorf("Unable to open %s file: %w", inputFile, err)
    }
    defer file.Close()

    src, err := ioutil.ReadAll(file)
    if err != nil {
        return nil, err
    }
    f, err := parser.ParseFile(fset, "animal.go", src, parser.AllErrors|parser.ParseComments)
    if err != nil {
        return nil, err
    }

    ast.Inspect(f, func(n ast.Node) bool {
        // ... Handle the found nodes
    })
}

To differentiate interface methods from other AST nodes, we can do the following:

    ast.Inspect(f, func(n ast.Node) bool {
        switch x := n.(type) {
        case *ast.TypeSpec:
            if x.Name.Name == "Speaker" {
                for _, method := range x.Type.(*ast.InterfaceType).Methods.List {
                    methodName := method.Names[0].Name
                    // Here we can parse all the required information about the method
                    methods[methodName] = extractMethodMetadata(method, src)
                }
            }
        }
        return true
    })

Let's define a couple of structs to help us collect information about methods:

type methodParam struct {
    Name string
    Type string
}

type methodData struct {
    Params        []methodParam
    Results       []string
}


// For each found method we'll store its name, params with their types, and return types in methods := map[string]methodData {}

Now let's write a short function to populate these structs with metadata about a method:

func formatNode(src []byte, node ast.Expr) string {
    return string(src[node.Pos()-1 : node.End()-1])
}

func extractMethodMetadata(method *ast.Field, src []byte) methodData {
    params := []methodParam{}
    results := []string{}
    e := method.Type.(*ast.FuncType)
    if e.Params != nil {
        for _, param := range e.Params.List {
            for _, paramName := range param.Names {
                paramType := formatNode(src, param.Type)
                params = append(params, methodParam{Name: paramName.Name, Type: paramType})
            }
        }
    }

    if e.Results != nil {
        for _, r := range e.Results.List {
            typeStr := formatNode(src, r.Type)
            if len(r.Names) > 0 {
                for _, k := range r.Names {
                    results = append(results, fmt.Sprintf("%s %s", k.Name, typeStr))
                }
            } else {
                results = append(results, typeStr)
            }
        }
    }
    return methodData{Params: params, Results: results}
}

Now we can run the parser on our interface and we'll get something like: map[Speak:{Params:[{Name:x Type:int}] Results:[]}].
As you can see, we collected all the information needed about interface methods and we can now move on to generating the decorator with this data.

Code generation using templates

Let's get to it! We'll start by defining a few helper functions that will be useful during code generation. They will operate on the metadata we've collected before.

    helperFuncs := template.FuncMap{
        "joinResults": func(results []string) string {
            return strings.Join(results, ", ")
        },
        "joinResultsForSignature": func(results []string) string {
            return fmt.Sprintf("(%s)", strings.Join(results, ", "))
        },
        "joinParams": func(params []methodParam) string {
            paramsNames := []string{}
            for _, param := range params {
                s := param.Name
                if strings.HasPrefix(param.Type, "...") {
                    s += "..."
                }
                paramsNames = append(paramsNames, s)
            }
            return strings.Join(paramsNames, ", ")
        },
        "joinParamsWithType": func(params []methodParam) string {
            paramsWithType := []string{}
            for _, param := range params {
                paramsWithType = append(paramsWithType, fmt.Sprintf("%s %s", param.Name, param.Type))
            }
            return strings.Join(paramsWithType, ", ")
        },
    }

Next we'll create a Go Template for both our decorators:

1   tracerTemplate := `
2   // Generated code; DO NOT EDIT.
3   package animals
4
5   type AnimalTracer struct {
6       Speaker
7   }
8   {{range $index, $element := .}}
9   func (a *AnimalTracer) {{$index}}({{$element.Params | joinParamsWithType}}) {{$element.Results | joinResultsForSignature}} {
10      fmt.Printf("Running {{$index}}({{$element.Params | joinParams}}) with {{range $paramIdx, $param := $element.Params}}'{{$param.Name}}'=%v {{end}}",{{$element.Params | joinParams}})
11      {{- if $element.Results | len | eq 0}}
12          a.Speaker.{{$index}}({{$element.Params | joinParams}})
13      {{else}}
14          return a.Speaker.{{$index}}({{$element.Params | joinParams}})
15      {{end}} 
16  }
17  {{end}}
18  `

I know it looks a little scary, but the premise is rather simple. Given the following metadata: map[Speak:{Params:[{Name:x Type:int}] Results:[]}] we want to generate a new struct that embeds our Animal and wraps its calls in additional functionality.

I'll go through the template line by line:

2 - 6: Define the new struct
7: Iterate over methods in our metadata
8: Define a function on the new struct that has exactly the same signature as original one
9: Print all function parameters by iterating on $element.Params using the helper functions defined above
10 - 14: Run the actual code and either exit the function or return the results, depending on function signature

For the Timer decorator, we'll write the following template:

    timerTemplate := `
    // Generated code; DO NOT EDIT.
    package animals

    type AnimalTimer struct {
        Speaker
    }
    {{range $index, $element := .}}
    func (a *AnimalTimer) {{$index}}({{$element.Params | joinParamsWithType}}) {{$element.Results | joinResultsForSignature}} {
        fmt.Println("Timing {{$index}} function...")
        __t := time.Now()
        {{- if $element.Results | len | eq 0}}
            a.Speaker.{{$index}}({{$element.Params | joinParams}})
        {{else}}
            ret := a.Speaker.{{$index}}({{$element.Params | joinParams}})
        {{end}} 
        fmt.Printf("{{$index}} took %s\n", x, time.Since(__t))
        {{- if not ($element.Results | len | eq 0)}}
        return ret
        {{end}} 

    }
    {{end}}
    `

This is very similar to the template above, only this time we record the start time of the function and print the elapsed time on exit.

With these templates in hand, we can now generate the decorators!

    // Create output buffer
    out := bytes.NewBufferString("")
    // Parse the template and pass it the helper functions
    t := template.Must(template.New("my.go.tmpl").Funcs(helperFuncs).Parse(tracerTemplate))
    // Execute the template and pass it the metadata we collected before
    t.Execute(out, metadata)
    // Add needed imports and format the code before printing
    formattedCode, err := imports.Process("animal_tracer.go", out.Bytes(), &imports.Options{Comments: true})
    if err != nil {
        fmt.Printf("cannot format source code, might be an error in template: %s\n", err)
        return err
    }
    // print it out!
    fmt.Println(string(formattedCode))

The result will be:

package animals

import "fmt"

type AnimalTracer struct {
    Speaker
}

func (a *AnimalTracer) Speak(x int) {
    fmt.Printf("Running Speak(x) with 'x'=%v ", x)
    a.Speaker.Speak(x)
}

Beautiful!

Similarly, running the generator over the timerTemplate will yield:

package animals

import (
    "fmt"
    "time"
)

type AnimalTimer struct {
    Speaker
}

func (a *AnimalTimer) Speak(x int) {
    fmt.Println("Timing Speak function...")
    __t := time.Now()
    a.Speaker.Speak(x)
    fmt.Printf("Speak took %s\n", x, time.Since(__t))
}

Finishing up

Using the techniques from the previous section, we can now generate the OpenTracing decorator we want by using the following template:

{{range $index, $element := .Methods}}
func (a *{{$.Name}}) {{$index}}({{$element.Params | joinParamsWithType}}) {{$element.Results | joinResultsForSignature}} {
    origCtx := a.ctx
    span, newCtx := tracing.StartSpanWithParentByContext(a.ctx, "app.{{$index}}")

    a.ctx = newCtx
    a.app.Srv().Store.SetContext(newCtx)
    defer func() { 
        a.app.Srv().Store.SetContext(origCtx)
        a.ctx = origCtx 
    }()
    {{range $paramIdx, $param := $element.Params}}
        {{ shouldTrace $element.ParamsToTrace $param.Name }}
    {{end}}
    defer span.Finish()
    {{- if $element.Results | len | eq 0}}
        a.app.{{$index}}({{$element.Params | joinParams}})
    {{else}}
        {{$element.Results | genResultsVars}} := a.app.{{$index}}({{$element.Params | joinParams}})
        {{if $element.Results | errorPresent}}
            if {{$element.Results | errorVar}} != nil {
                span.LogFields(spanlog.Error({{$element.Results | errorVar}}))
                ext.Error.Set(span, true)
            }
        {{end}}     
        return {{$element.Results | genResultsVars -}}
    {{end}}}
{{end}}

Phew, this was quite a trip, huh? I hope you found it interesting. You can see the actual generator implementation inside mattermost-server in /app/layer_generators/main.go.

Side note: This is just one way of handling this problem. Not everyone wants to rely on using code-generation too much since it hides a lot of implementation and complicates the build process (you have to re-run the generators each time your interface changes). We've settled on this approach due to its flexibility and performance.

If you have any notes or ideas on how this could be implemented in a cleaner way - please stop by the Mattermost Community server - I'll be very glad to discuss it further.

Instrumenting Go code via AST, Part 2

Eli Yukelzon — Sat, 11 Jul 2020 11:57:31 +0000

Welcome!

This is the second part of our AST blog post series, expanding on the subject of utilizing Go AST libraries to automate and improve your workflow.

In this post I'll discuss a rather common problem that comes up while working with Go code and the way we've solved it by sprinkling a little bit of AST magic dust. Let's dive in.

Problem: A `struct` with no `interface`

Let's say you are working on a large code base that was not built with interfaces in mind, meaning, there are structs and methods attached to those structs, but there is no interface describing it. This is a perfectly valid approach when you don't need to mock/stub the method implementations provided by that struct, or there's only one implementation of the same 'contract'.

However, when these things are required we need to provide an interface.

Here's a small code snippet to demonstrate:


type Person struct {
    Name string
}

func (p Person) Hello() string {
    return "Hello: " + p.Name
}

type Animal struct {
    Legs int
}

func (a Animal) Hello() string {
    return fmt.Sprintf("I have %d legs!", a.Legs)
}

func main() {
    p := Person{Name: "Fred"}
    a := Animal{Legs: 4}
    // ...  
}

In this example both Person and Animal have the same Hello() method. If we wanted to store a list of both the Person and Animal structs, we would have to define it as:

list := []interface{}{p,a}

But this way we lose the type information of the list elements.
This is where interfaces come in. Since both Person and Animal implement a method with the same signature, we can extract that signature into an interface and use it for storing items in a list:

type interface Hello {
    Hello() string
}
// ...
list := []Hello{p,a}
fmt.Printf("Person: [%v] Animal: [%v]\n", list[0].Hello(), list[1].Hello())

Awesome. Now let's say the struct you are extracting the interface from is a big one. A really big one. With lots and lots of methods spread out in different .go files. Creating such an interface manually would be very laborious.

This problem is itching to get an AST treatment. Let's get to it!

AST to the rescue!

Let's break down the task at hand into smaller, digestable parts:

Scan the source code for all methods implemented on a specific struct
Collect all those methods (and their comments, for clarity)
Create a new file that will contain an interface with all the collected methods inside
...
Profit?

Note: Usually the interface doesn't contain all of the struct methods, but we'll leave the topics of abstraction and better code organization for another blog post.

Scanning the source code for all `struct` methods

Here's a short piece of code that scans a folder of .go source code to first find a package by name and then search for all methods that are bound to the struct we're interested in.

fset := token.NewFileSet()
// 1. scan source code folder
pkgs, err := parser.ParseDir(fset, folder, nil, parser.AllErrors|parser.ParseComments)
if err != nil {
    log.Fatalf("Unable to parse %s folder", folder)
}
// 2. find the required package by name
var appPkg *ast.Package
for _, pkg := range pkgs {
    if pkg.Name == pkgName {
        appPkg = pkg
        break
    }
}
if appPkg == nil {
    log.Fatalf("Unable to find package %s", pkgName)
}

// 3. find all methods that are bound to the specific struct
for _, file := range appPkg.Files {
    ast.Inspect(file, func(n ast.Node) bool {
        if fun, ok := n.(*ast.FuncDecl); ok {
            // 4. Validate that method is exported and has a receiver
            if fun.Name.IsExported() && fun.Recv != nil && len(fun.Recv.List) == 1 {
                    // 5. Check that the receiver is actually the struct we want
                    if r, rok := fun.Recv.List[0].Type.(*ast.StarExpr); rok && r.X.(*ast.Ident).Name == structName {
                        // we found it!
                    }
                }
            }

        }
        return true
    })
}

Steps 1 and 2 are pretty straightforward, the interesting bits start at step 3: For each file in the package, we execute ast.Inspect to get all the AST nodes. For every node that is actually a function (checked by n.(*ast.FuncDecl)), we check if that function is:

Exported (we are not interested in private methods)
Has a receiver (it's bound to a struct)
Receiver's type matches the struct we are interested in

Collecting functions and their comments

Now that we can get a *ast.FuncDecl (let's call it fun) for each function, we can collect all the information about it and reconstruct it:

Name: fun.Name.Name
Comments: fun.Doc.List
Parameters: fun.Type.Params.List
Return values: fun.Type.Results.List

Generate the `interface` file

To generate the output interface, we'll use Go's template package. Let's define a simple template:

const outputTemplate = `
// DO NOT EDIT, auto generated

package {{.Package}}

type {{.Name}} interface {
    {{.Content}}
}
`

And populate it:

sort.Strings(funcs)
out := bytes.NewBufferString("")

t := template.Must(template.New("").Parse(outputTemplate))
err = t.Execute(out, map[string]interface{}{
    "Content": strings.Join(funcs, "\n"),
    "Name":    ifName,
    "Package": pkgName,
})

We're almost done! Our interface file is ready, but it's missing a crucial part - imports. Luckily, there is a package for that™ - https://pkg.go.dev/golang.org/x/tools/imports.

Let's give it whirl:

formatted, err := imports.Process(outputFile, out.Bytes(), &imports.Options{Comments: true})
if err != nil {
    log.Panic(err)
}
err = ioutil.WriteFile(outputFile, formatted, 0644)

Voila! You have an interface file that contains all the methods implemented on the struct.

`struct2interface`

The process I've described is a rather generic one, so to make it fully repeatable, I've extracted it into a separate CLI utility called struct2interface. It can be found at https://github.com/reflog/struct2interface.

Conclusion

Once again, AST came to the rescue and saved us lots and lots of manual labor. Hurray! In the next post of this series, I'll describe how we combined our layers approach with AST to create a clean opentracing instrumentation we've started in the first part of these series.

Instrumenting Go code via AST

Eli Yukelzon — Sat, 11 Jul 2020 11:54:45 +0000

At Mattermost We've been working on integrating call tracing in the server to provide exact measurements of all API and DB calls.
We've picked OpenTracing - a lovely open source project that allows you to setup trace reporting and enables you to support Distributed tracing.

Instrumenting your API handler in Go is very straightforward - setup a connection to a collection server supporting the OpenTracing spec (we've decided to use Jaeger) and wrap your code in spans.

To simplify this, we've added a simple tracing module:

package tracing

import (
    "context"

    opentracing "github.com/opentracing/opentracing-go"
    "github.com/uber/jaeger-client-go"
    jaegercfg "github.com/uber/jaeger-client-go/config"
    jaegerlog "github.com/uber/jaeger-client-go/log"
    "github.com/uber/jaeger-lib/metrics"
)

var initialized = false

func Initialize() error {
    cfg := jaegercfg.Configuration{
        Sampler: &jaegercfg.SamplerConfig{
                Type:  jaeger.SamplerTypeConst,
                Param: 1,
        },
        Reporter: &jaegercfg.ReporterConfig{
                LogSpans: true,
        },
    }

    _, err := cfg.InitGlobalTracer(
        "mattermost",
        jaegercfg.Logger(jaegerlog.StdLogger),
        jaegercfg.Metrics(metrics.NullFactory),
    )
    if err != nil {
        return err
    }

    initialized = true

    return nil
}

func StartRootSpanByContext(ctx context.Context, operationName string) (opentracing.Span, context.Context) {
    return opentracing.StartSpanFromContext(ctx, operationName)
}

func StartSpanWithParentByContext(ctx context.Context, operationName string) (opentracing.Span, context.Context) {
    parentSpan := opentracing.SpanFromContext(ctx)

    if parentSpan == nil {
        return StartRootSpanByContext(ctx, operationName)
    }

    return opentracing.StartSpanFromContext(ctx, operationName, opentracing.ChildOf(parentSpan.Context()))
}

Now, wrapping an API call in a span is very easy:


func apiCall(c *Context, w http.ResponseWriter, r *http.Request) {
    span, ctx := tracing.StartSpanWithParentByContext(c.App.Context, "api4:apiCall")
    c.App.Context = ctx
    defer span.Finish()

    // perform actual request handling
}

Now, each time the apiCall handler is invoked, it will be measured and traced on Jaeger.

The problem is that we have a rather large API surface (around 300+ handlers) and it would be a really tough task to instrument all the handlers by hand. That's where our story begins.

Go AST

So what is an AST really? Well, to quote Wikipedia:

In computer science, an abstract syntax tree (AST), or just syntax tree, is a tree representation of the abstract syntactic structure of source code written in a programming language. Each node of the tree denotes a construct occurring in the source code.

Basically, an AST is a tree-like representation of your source code.

Why do we need it?

Parsing the code into an AST allows us to refactor code on a statement level, meaning, instead of finding methods and fields using string search, we can find them by their actual structure. This gives us incredible flexibility in writing custom go refactoring tools.

Let's see a small example for a 'Hello World' program:

package main

import (
    "fmt"
)

func main() {
    fmt.Printf("Hello, Golang\n")
}

After passing it through go/parser, we get the following structure (image generated using: http://goast.yuroyoro.net/):

So given this structure, we can easily find, for example, the Printf statement by looking at File.Decls[1].Body.List[0].

Now that we understand the basic idea behind ASTs, let's go ahead and try to solve the issue at hand - instrumenting our handlers with tracing code.

Analyzing existing code

Finding the pattern

The first thing we need is to identify the methods that we want to instrument. In our code base, all of the API handlers sit in the api4 folder and each method that handles a certain API has the same signature:

func apiCall(c *Context, w http.ResponseWriter, r *http.Request) {
    // perform actual request handling
}

So we are looking at a function that has exactly 3 arguments, with specific names and types.

Let's write some AST walker boilerplate that will go through all the files in the api4 folder and parse them:

package main

import (
    "bytes"
    "fmt"
    "go/ast"
    "go/format"
    "go/parser"
    "go/token"
    "io/ioutil"
)

func fix(dir string) {
    fset := token.NewFileSet()
    pkgs, err := parser.ParseDir(fset, dir, nil, parser.ParseComments)
    if err != nil {
        panic(err)
    }

    for _, pkg := range pkgs {
        for fileName, file := range pkg.Files {
            fmt.Printf("working on file %v\n", fileName)
            ast.Inspect(file, func(n ast.Node) bool {
                // perform analysis here
                return true
            })

            buf := new(bytes.Buffer)
            err := format.Node(buf, fset, file)
            if err != nil {
                fmt.Printf("error: %v\n", err)
            } else if fileName[len(fileName)-8:] != "_test.go" {
                ioutil.WriteFile(fileName, buf.Bytes(), 0664)
            }
        }
    }
}

func main() {
    fix("./api4")
}

ast.Inspect visits all AST nodes in each file and provides us with a parsed token.
To only operate on specific nodes in the AST, we try to cast to the type we are interested in and only then proceed:

fn, ok  := n.(*ast.FuncDecl)
if ok {
  // current node is a function!
}

Next we need to extract and analyze the parameters to the function (we'll also add a small helper function to get a node as a string):

func FormatNode(node ast.Node) string {
    buf := new(bytes.Buffer)
    _ = format.Node(buf, token.NewFileSet(), node)
    return buf.String()
}
// retreive function's parameter list
params  := fn.Type.Params.List
// we are only interested in functions with exactly 3 parameters
if  len(params) ==  3 {
    first_parameter_is_c := FormatNode(params[0].Names[0]) ==  "c"  &&  FormatNode(params[0].Type) ==  "*Context"
    second_parameter_is_w := FormatNode(params[1].Names[0]) ==  "w"  &&  FormatNode(params[1].Type) ==  "http.ResponseWriter"  
    third_parameters_is_r := FormatNode(params[2].Names[0]) ==  "r"  &&  FormatNode(params[2].Type) ==  "*http.Request"
    if first_parameter_is_c && second_parameter_is_w && third_parameters_is_r {
        // this is an API handler!
    }
}

Now that we've found our function, the fun begins! We want to add a couple of statements as described in the introduction and a relevant import.

Instrumenting the code

As a reminder, this is the piece of code we want to inject at the beginning of every API handler to instrument the code:

    span, ctx := tracing.StartSpanWithParentByContext(c.App.Context, "api4:apiCall")
    c.App.Context = ctx
    defer span.Finish()

First of all - we need to take care of imports. We are using the 'tracing' module so we need to add just one line (utilizing the golang.org/x/tools/go/ast/astutil module):

astutil.AddImport(fset, file, "github.com/mattermost/mattermost-server/services/tracing")

Now we are ready to inject the code. To do that, we need to convert it from its textual representation into a set of AST nodes.
To help us do that, we can feed that code to http://goast.yuroyoro.net/ to receive the parsed tree. With that in hand, we are ready to write our instrumentation code:

// first statement is the assignment:
// span, ctx := tracing.StartSpanWithParentByContext(c.App.Context, "api4:apiCall")
a1 := ast.AssignStmt{
    // token.DEFINE is := 
    Tok: token.DEFINE,
    // left hand side has two identifiers, span and ctx
    Lhs: []ast.Expr{
        &ast.Ident{Name: "span"},
        &ast.Ident{Name: "ctx"},
    },
    // right hand is a call to function
    Rhs: []ast.Expr{
        &ast.CallExpr{
            // function is taken from a module 'tracing' by it's name
            Fun: &ast.SelectorExpr{
                X:   &ast.Ident{Name: "tracing"},
                Sel: &ast.Ident{Name: "StartSpanWithParentByContext"},
            },
            // function has two arguments
            Args: []ast.Expr{
                // c.App.Context
                &ast.SelectorExpr{
                    X: &ast.SelectorExpr{
                        X:   &ast.Ident{Name: "c"},
                        Sel: &ast.Ident{Name: "App"},
                    },
                    Sel: &ast.Ident{Name: "Context"},
                },
                // handler identifier, a basic string which we prepare based on current moduleName and function name
                &ast.BasicLit{Kind: token.STRING, Value: fmt.Sprintf("\"api4:%s:%s\"", moduleName, fn.Name.Name)},
            },
        },
    },
}
// second statement is a simple assignment
// c.App.Context = ctx                          
a2 := ast.AssignStmt{
    // token.ASSIGN is =
    Tok: token.ASSIGN,
    Lhs: []ast.Expr{
        &ast.SelectorExpr{
            X: &ast.SelectorExpr{
                X:   &ast.Ident{Name: "c"},
                Sel: &ast.Ident{Name: "App"},
            },
            Sel: &ast.Ident{Name: "Context"},
        },
    },
    Rhs: []ast.Expr{
        &ast.Ident{Name: "ctx"},
    },
}
// last statement is 'defer'                            
a3 := ast.DeferStmt{
    // what function call should be deferred?
    Call: &ast.CallExpr{
        // Finish from 'span' identifier
        Fun: &ast.SelectorExpr{
            X:   &ast.Ident{Name: "span"},
            Sel: &ast.Ident{Name: "Finish"},
        },
    },
}
// now we prepend the three statements before the rest of function body                         
fn.Body.List = append([]ast.Stmt{&a1, &a2, &a3}, fn.Body.List...)

And that's it! We have our custom refactoring/instrumentation tool that we can tweak however we want.

Go2AST

Since the process of writing AST code by hand based on go/printer or http://goast.yuroyoro.net/ is rather tedious, I've taken the code of go/printer and converted it into a reusable CLI command that does all the work for you! Just feed it some Go code and it'll spit out a ready-to-paste AST tree.

Take a look here: https://github.com/reflog/go2ast.

Conclusion

Writing refactoring tools is fun and the possibilities are endless. The Go standard library contains everything you need to create your own little tools for every repeatable task.
Seeing code as an AST for the first time can be a little daunting, but once you get this knowledge in your tool-belt, you'll look for other places to apply it immediately!

Cerebral - Part 4, Tags and operators

Eli Yukelzon — Mon, 08 May 2017 12:31:31 +0000

In the previous part of this tutorial I've discussed how to update application state using actions.

We've implemented a simple function that used state's get and set methods to change the count variable.

function changeCounter({props, state}){
  state.set("count", state.get("count") + props.param);
}

But doing this repeatedly for each state variable is incredibly redundant and I've been saying that Cerebral helps us write cleaner and more DRY code.

Let's say we add another variable to the state that tracks the previous counter value. Do we need to write another action to update it? Nope. There's a very clean solution for this.

Tags and operators

Since alot of operations on state are common, i.e. update, delete, splice, check condition, etc, Cerebral provides a set of operators to simplify your code.

Let's see how we can use them.

We'll add a state variable called 'prevCount' and will copy the 'count' to it before each operation.

Here's how it's done (showing only the changes):

import {set} from 'cerebral/operators'
import {state} from 'cerebral/tags'

...

state: {
    prevCount: 0,
    count: 0
  },
  signals: {
     changeCounter: 
     [
       set(state`prevCount`, state`count`),
       changeCounter, 
       logAction
     ]
  }

Let's break down what we see here:

No new functions were written
We import set operator and state tag
We add set to our signal chain and use the state tag to a) fetch current count b) set it to prevCount

Isn't that nice and clean?

(full code here)

Anyone who's reading this file will have an immidiate understanding of what's going on, because the code reads like English:

When signal changeCounter is fired, do the following: set state prevCount to value of state count, then change counter and call the logAction.

This is what makes action chains with operators great.

And this is just scratching the surface.

Here are some examples of stuff you can do using operators and tags:

Update lists

import {merge, push, pop} from 'cerebral/operators'
import {state, props} from 'cerebral/tags'

export default [
  merge(state`some.object`, props`newObj`),
  push(state`some.list`, props`newItem`),
  pop(state`some.otherList`)
]

Debounce queries

import {set, debounce} from 'cerebral/operators'
import {state, props} from 'cerebral/tags'
import makeQueryRequest from '../chains/makeQueryRequest'

export default [
  set(state`query`, props`query`),
  debounce(500), {
    continue: makeQueryRequest,
    discard: []
  }
]

Perform conditional execution

import {when, equals} from 'cerebral/operators'
import {state, props} from 'cerebral/tags'

export default [
  when(state`app.isAwesome`), {
    true: [],
    false: []
  },
  equals(state`user.role`), {
    admin: [],
    user: [],
    otherwise: []
  }
]

In it's guts, an operator is actually an 'action factory', meaning, it's a function returning an action. So you can easily write your own operators to clearly express your intentions and make your code clean.

For a full list of built-in operators, see: http://cerebraljs.com/docs/api/operators.html

Cerebral - Part 3, Signals and Actions

Eli Yukelzon — Mon, 01 May 2017 14:15:08 +0000

Refactoring

In this post we'll extend our previous counter example by refactoring it a little bit.

Let's recall how the main controller looked before:


import {Controller} from 'cerebral'

function increase ({state}) {
  state.set('count', state.get('count') + 1)
}

function decrease ({state}) {
  state.set('count', state.get('count') - 1)
}

const controller = Controller({
  state: {
    count: 0
  },
  signals: {
     onIncrease: [increase],
     onDecrease: [decrease]
  }
})

Let's try to understand what's happening here exactly.

a. Inside the controller we define two signals: onIncrease and onDecrease.
b. For each signal, we reference a function that will handle that signal
c. That function (increase/decrease) will receive a parameter called 'context'. It will contain all sorts of useful information, but since all we need from it is our 'state', we do ES6 'desctructuring' by applying {state} as it's parameter

Now, let's refactor this code a little bit, since both increase and decrease functions basically have the same code. How can we do that?

Here's one way: Let's pass a parameter to the signal, which will select the direction of counter change. This way we'll be able to use the same function for both cases.

Now our code will look like this:


import {Controller} from 'cerebral'

function changeCounter({props, state}){
  state.set("count", state.get("count") + props.param);
}

const controller = Controller({
  state: {
    count: 0
  },
  signals: {
     changeCounter
  }
})

export default controller

There's two things to notice here:
a. We now destructure two parameters to our handler: {state, props}. The props parameter is an object containing all paramers passed down to the signal
b. We no longer need two signals!

Now that we changed the controller, here's how the component will look:


import React from 'react'
import {connect} from 'cerebral/react'
import {state, signal} from 'cerebral/tags'
export default connect({
  count: state`count`,
  changeCounter: signal`changeCounter`
},
function App ({ changeCounter, count }) {
  return (
   <div>
    <button onClick={() => changeCounter({param:1})}>+</button>
    {count}
    <button onClick={() => changeCounter({param:-1})}>-</button>
  </div>
  )
})

Nice and clean!

Signal Chains

Did you notice that when we defined the signal handlers, they were initially passed as an array? The reason for that is a neat one - Cerebral's signals trigger chains of actions.

This awesome feature allows you to group together several actions that need to happen one after the other when a certain signal is triggered.

Let's see a small example of how it's done.

I'm going to add a log action that will write to console the new value of the counter on each change.


import {Controller} from 'cerebral'

function changeCounter({props, state}){
  state.set("count", state.get("count") + props.param);
}

function logAction({state}){
  console.log(`counter changed to ${state.get("count")}`)
}

const controller = Controller({
  state: {
    count: 0
  },
  signals: {
     changeCounter: 
     [
       changeCounter, 
       logAction
     ]
  }
})

export default controller

Now, each time you trigger a change - you'll see a nice log message!

The nice thing about actions, signals and chains is that they are all visible in the Debugger. Take a look:

Here's the full project on WebpackBin

In the next part of these series, I'll discuss the next amazing Cerebral feature - 'tags'.

CerebralJS Part 2 - Debugger

Eli Yukelzon — Tue, 25 Apr 2017 08:49:33 +0000

In the previous post we've seen how to create a simple counter application using Cerebral.

Now let's start introducing some fun stuff.

First up - Debugger

Just like you have Devtools in Redux, you have a similar tool in Cerebral.

It's supplied with the main cerebral package and in order to use it, you need to add the following code to your controller:


import {Controller} from 'cerebral'
import Devtools from 'cerebral/devtools'

const controller = Controller({
  // You do not want to run the devtools in production as it
  // requires a bit of processing and memory to send data from
  // your application
  devtools: (
    process.env.NODE_ENV === 'production' ?
      null
    :
      Devtools({
        // If running standalone debugger. Some environments
        // might require 127.0.0.1 or computer IP address
        remoteDebugger: 'localhost:8585',

        // By default the devtools tries to reconnect
        // to debugger when it can not be reached, but
        // you can turn it off
        reconnect: true
      })
  )
})

export default controller

Here's the link to the code

Then, go to debugger download page and download the UI for your operating system, run it and select the port 8585.

After your app is refreshed, it'll connect to the debugger over WebSockets and will keep it updated on every state change and on every signal that is being fired.

Let's see how it happens. Select the "STATE-TREE" tab:

As our state has only 'count' variable and its initial value is zero - there are no surprises here.

Now, let's try clicking the plus button in our component a few times and go to the "SIGNALS" tab to see what happens:

Now that's pretty cool! We have a timeline of all events, each event shows how the state was modified, what operators were called and what signals fired.

We can also visit the "COMPONENTS" tab to see which components were re-rendered as the result of these state modifications:

It also shows the render times, which is very useful when you start optimizing your application.

That's it for now. In next post, I'm going to discuss another core Cerebral concept: chains and operators.

Thanks for reading!

CerebralJS

Eli Yukelzon — Tue, 25 Apr 2017 08:45:57 +0000

I want to preface this post with the following disclaimer:

I am not a fan of Redux. It became a de-facto standard in state management of React apps and seems to be working great for a lot of people, but I find it to be very verbose and hard to work with.

Ok. Now that it's out of the way, let's see what else exists in the world today that can help us maintain our application state and keep our sanity.

The project I'm going to discuss is called Cerebral and it was created byÂ Christian Alfoni,Â Aleksey Guryanov and many others specifically to address the downsides of Flux and Redux.

I highly recommend reading Christian's introduction article to Cerebral 2 to get a sense of the main differences between the frameworks.

In this post I'm going to make a small introduction to Cerebral by comparing the basic Counter example written using Redux to one in Cerebral.

In upcoming posts I'll start introducing more advanced concepts and that's where things will start getting really fun :)

Redux Counter

A simple Redux application consists of:

Entry point



import React from 'react'
import { render } from 'react-dom'
import { Provider } from 'react-redux'
import { createStore } from 'redux'
import counterApp from './reducer'
import Counter from './Counter'

let store = createStore(counterApp)

render(
  <Provider store={store}>
    <Counter />
  </Provider>,
  document.getElementById('root')
)

Reducer



export default (state = 0, action) => {
  switch (action.type) {
    case 'INCREASE':
      return state + 1
    case 'DECREASE':
      return state - 1
    default:
      return state
  }
}

Main component



import React, { PropTypes } from 'react'
import { connect } from 'react-redux'
import { increase, decrease } from './actions'

const mapStateToProps = (state) => {
  return {
    count: state
  }
}

const mapDispatchToProps = (dispatch) => {
  return {
    onIncrease: () => {
      dispatch(increase())
    },
    onDecrease: () => {
      dispatch(decrease())
    }
  }
}

const Counter = ({ onIncrease, onDecrease, count }) => (
  <div>
    <button onClick={onIncrease}>+</button>
    {count}
    <button onClick={onDecrease}>-</button>
  </div>
)

Counter.propTypes = {
  onIncrease: PropTypes.func.isRequired,
  onDecrease: PropTypes.bool.isRequired,
  count: PropTypes.string.isRequired
}


export default connect(
  mapStateToProps,
  mapDispatchToProps
)(Counter)

Actions



export const increase = () => {
  return {
    type: 'INCREASE'
  }
}

export const decrease = () => {
  return {
    type: 'DECREASE'
  }
}

And it works like follows: you define your actions separately, then define the 'reaction' to those actions in the reducer, i.e. how the state will be affected. Then you connect the component to the state.

Here's the full project on WebpackBin

Cerebral Counter

A simple Cerebral application consists of:

Entry point



import React from 'react'
import {render} from 'react-dom'
import {Container} from 'cerebral/react'
import controller from './controller'
import App from './App'

render((
  <Container controller={controller}>
    <App />
  </Container>
), document.querySelector('#app'))

Controller



import {Controller} from 'cerebral'
import {set} from 'cerebral/operators'
import {state, string} from 'cerebral/tags'

function increase ({state}) {
  state.set('count', state.get('count') + 1)
}

function decrease ({state}) {
  state.set('count', state.get('count') - 1)
}

const controller = Controller({
  state: {
    count: 0
  },
  signals: {
     onIncrease: [increase],
     onDecrease: [decrease]
  }
})

export default controller

Main component



import React from 'react'
import {connect} from 'cerebral/react'
import {state, signal} from 'cerebral/tags'
export default connect({
  count: state`count`,
  onIncrease: signal`onIncrease`,
  onDecrease: signal`onDecrease`
},
function App ({ onIncrease, onDecrease, count }) {
  return (
   <div>
    <button onClick={() => onIncrease()}>+</button>
    {count}
    <button onClick={() => onDecrease()}>-</button>
  </div>
  )
})

And it works like follows: you define a controller that contains a state and a list of signals that are handled by it. Then you connect a component to specific state elements and signals and use them directly.

Here's the full project on WebpackBin

As you can see there are quite a few differences here:

You don't need to pre-define actions.
There is no "string" magic
Code is much less verbose

And what you've seen here is just the absolute tip of the iseberg. Cerebral provides so much more! I hope to get into all of it in upcoming posts.

DEV Community: Eli Yukelzon

OpenTracing for Go Projects

What is distributed tracing?

The goal

Straightforward tracing implementation

Decorator pattern

Our solution

Struct embedding

Code parsing using AST

Code generation using templates

Finishing up

Instrumenting Go code via AST, Part 2

Welcome!

Problem: A struct with no interface

AST to the rescue!

Scanning the source code for all struct methods

Collecting functions and their comments

Generate the interface file

struct2interface

Conclusion

Instrumenting Go code via AST

Go AST

Analyzing existing code

Finding the pattern

Instrumenting the code

Go2AST

Conclusion

Cerebral - Part 4, Tags and operators

Tags and operators

Update lists

Debounce queries

Perform conditional execution

Cerebral - Part 3, Signals and Actions

Refactoring

Signal Chains

CerebralJS Part 2 - Debugger

CerebralJS

Redux Counter

Entry point

Reducer

Main component

Actions

Cerebral Counter

Entry point

Controller

Main component

Problem: A `struct` with no `interface`

Scanning the source code for all `struct` methods

Generate the `interface` file

`struct2interface`