Skip to content

[core] Implementation of the tracing package#2

Merged
palazzem merged 38 commits intomasterfrom
palazzem/trace-span-structs
Sep 15, 2016
Merged

[core] Implementation of the tracing package#2
palazzem merged 38 commits intomasterfrom
palazzem/trace-span-structs

Conversation

@palazzem
Copy link
Copy Markdown
Contributor

@palazzem palazzem commented Sep 9, 2016

Core implementation to handle spans and the tracer objects. The following is a working example of our tracer package:

package main

import (
    "fmt"
    "time"

    "golang.org/x/net/context"

    // import the Datadog tracer
    "github.com/DataDog/dd-trace-go/pkg/tracer"
)

var smallWait = time.Millisecond * 30

func main() {
    fmt.Println("Starting the fake application")
    for {
        // creation of the context object is delegated to the user
        ctx := context.Background()

        // main request
        span := tracer.NewSpan("pylons.request", "pylons", "/")
        time.Sleep(smallWait)

        ctx = tracer.ContextWithSpan(ctx, span)
        generateTemplate(ctx)

        // cache stuff
        cacheSpan := tracer.NewChildSpan("redis.command", span)
        time.Sleep(smallWait)
        cacheSpan.Finish()

        // close the parent span
        span.Finish()
    }
}

func generateTemplate(ctx context.Context) {
    parent, ok := tracer.SpanFromContext(ctx)

    // template stuff
    templateSpan := tracer.NewChildSpan("pylons.template", parent)
    defer templateSpan.Finish()
    templateSpan.Resource = "something"
    time.Sleep(smallWait)
}

What is missing?

  • tests are not pushed until this approach is accepted
  • the dispatch implementation
  • remove some parameters from the NewChildSpan() signature. We may just:
child := NewChildSpan("something", parent)
  • handling the context.Context object so that the ctx can be passed as argument between functions. A ctx must be used to retrieve a span if a parent is available.

Comment thread pkg/tracer/span.go Outdated
if !s.IsFinished() {
s.Duration = Now() - s.Start

go func() {
Copy link
Copy Markdown
Contributor

@clutchski clutchski Sep 9, 2016

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

two issues with this:

  • spawning a goroutine per finished span tons of overhead.
  • as you commented, this could block forever, which is completely unacceptable for client side code. a channel is not the right tool for this because if a reader crashes a customer app will lock up forever.

i'd much prefer if we took this bit of code from dd-go/dogtrace. this is already running on high traffic production systems, so let's just use it instead of inventing something new. (except for the onFinish stuff, that's completely unnecessary)

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

OK it was a proposal. I can update this code with the delivery process that we're using in the dogtrace

Copy link
Copy Markdown
Contributor Author

@palazzem palazzem Sep 10, 2016

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Reading some stuff around, it seems I can easily solve the point 2 (blocked go-routine) with a timeout so that if the reader crashes (the reader is the one that sends all spans to the locale/remote agent) the span is lost and the go-routine is killed. I think it makes sense because if the go-routine that sends data is dead, it's OK to lose the span because no one is capable to send it somewhere.

On the other hand, if we're using the current approach in dogtrace (without a go-routine), our code will block as you describe because it should obtain a lock and it will surely add some delay (maybe it should wait for another Span that has the lock?). Furthermore if the sender dies, the shared data structures (the children []*Span in the Span or a common global outgoingSpans []*Span) will grow without control causing a memory leak.

About the go-routine overhead, I think I can profile it because it's a built-in functionality and reading to golang.org blog posts, they were created for similar cases.

By the way I have a free weekend so I want to play a little bit with this stuff 😄
If you agree, I prefer to revert this part at the end so that I can spend some time with benchmarks and experiments.

@clutchski
Copy link
Copy Markdown
Contributor

clutchski commented Sep 9, 2016

i think we should only create spans from a tracer. and never from other spans. we've had APIs like this before and it's more confusing (when do i call span.Nest or tracer.NewSpan?)

i think something like this is simpler:

tracer := datadog.NewTracer()

// create a new root span with some info
span := tracer.NewSpan("whatever")
defer span.Finish()
span.Service = "foo"
span.Resource = "whatever"

// create a span from another
child := tracer.NewChildSpan("another", span)
defer child.Finish()

// or from a special `datadog_trace` variable in context
child2 := tracer.NewSpanFromContext("yahoo", context)
child2.Finish()

@palazzem
Copy link
Copy Markdown
Contributor Author

Yeah I agree. Having an API where developers must always use the tracer default (or custom) instance is better. I've changed the high-level API according to your suggestions.

Comment thread pkg/tracer/tracer.go
import (
"sync"

log "github.com/cihub/seelog"
Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

just a remark, but we definitely don't want to pull this dep in the final package. Also, seelog is madness, it often shows up in a top 30 cpu profile in our apps 😱

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ah OK.... I've seen that in a lot of our projects. There is something else I can use?

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I wonder if we should use a logging lib at all, or just use the primitive "log" package in Go. Do we need the user to pull another dependency for logging if he already has one?
Also we should try to keep our logging at a minimum (except if the user toggles debug mode).

Copy link
Copy Markdown
Contributor Author

@palazzem palazzem Sep 12, 2016

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes, totally agree about limit our logging to warnings/errors. About the logging lib I don't know... I mean if the primitive log package provides all that we need, I think we can replace everything with that.

@palazzem palazzem added the core label Sep 10, 2016
@palazzem palazzem force-pushed the palazzem/trace-span-structs branch from ab40cc4 to c975ff8 Compare September 10, 2016 14:59
Comment thread pkg/tracer/span.go Outdated
"math/rand"
"time"

log "github.com/cihub/seelog"
Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@LeoCavaille what do you think about that library (https://github.com/op/go-logging)? Have you ever used it?

Comment thread pkg/tracer/span.go Outdated
Start int64 `json:"start"` // span start time expressed in nanoseconds since epoch
Duration int64 `json:"duration"` // duration of the span expressed in nanoseconds
Error int32 `json:"error"` // error status of the span; 0 means no errors
Meta map[string]string `json:"meta"` // arbitrary map of metadata
Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@LeoCavaille may I add the omitempty for Meta and Metrics? the agent is expecting the meta field in any case even if it's nil?

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

if it's not in the payload, it will just set it to nil when decoding, so yea.

@palazzem
Copy link
Copy Markdown
Contributor Author

Side note: as a last step I'll implement a kind of tracer.Disable() and tracer.Enable() so that customers that have a huge instrumented codebase, can easily disable the tracer (with one line) if something bad happens.

Comment thread pkg/tracer/context.go
func SpanFromContext(ctx context.Context) (*Span, bool) {
// TODO[manu]: split the return just for clarity of the review; one-liner later
span, ok := ctx.Value(datadogActiveSpanKey).(*Span)
return span, ok
Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

A working example is:

func generateTemplate(ctx context.Context) {
    parent, ok := tracer.SpanFromContext(ctx)
    if !ok {
        parent = tracer.NewSpan("pylons.template", "pylons", "index.html")
    }

    // template stuff
    templateSpan := tracer.NewChildSpan("pylons.template", parent)
    defer templateSpan.Finish()
    templateSpan.Resource = "something"
    time.Sleep(smallWait)
}

Copy link
Copy Markdown
Contributor

@talwai talwai Sep 15, 2016

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

On a second look, I don't like the idea of initializing a parent span when SpanFromContext returns nil. Whose responsibility is it to finish the parent span in this case? The below example is closer to how I think this should be used:

func generateTemplate(ctx context.Context) {
    parent, ok := tracer.SpanFromContext(ctx)
    if !ok {
        templateSpan := tracer.NewSpan("pylons.template", "pylons", "index.html")
    } else {
        templateSpan := tracer.NewChildSpan("pylons.template", parent)
    }
    // template stuff
    defer templateSpan.Finish()
    templateSpan.Resource = "something"
    time.Sleep(smallWait)
}

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah, totally agree.

Copy link
Copy Markdown
Contributor

@talwai talwai left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I have reviewed this PR and contributed my humble feedback

// the child is finished but it's not recorded in
// the tracer buffer
assert.True(child.Duration > 0)
assert.Equal(len(tracer.finishedSpans), 0)
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

👍

Comment thread go.rb Outdated
def go_benchmark(path)
sh "go test -run=NONE -bench=. -memprofile=mem.out #{path}"
sh "go test -run=NONE -bench=. -cpuprofile=cpu.out #{path}"
sh "go test -run=NONE -bench=. -blockprofile=block.out #{path}"
Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

or run them all together ?
go test ... -memprofile=mem.out -cpuprofile=cpu.out -blockprofile=block.out ...

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah, I don't have a lot of experience on that. I split them because I've found in The Go programming language book such sentence:

Gathering a profile for code under test is as easy as enabling one fo the flags below [-cpuprofile, etc...]. Be careful when using more than one flag at a time, however: the machinery for gathering one kind of profile may skew the results of others.

Do you have more info on that? It could be possible that the info is outdated or that this kind of benchmark may be executed just once.

Comment thread pkg/tracer/tracer.go Outdated
// initialize the Tracer
t := &Tracer{
transport: NewHTTPTransport(defaultDeliveryURL),
flushTicker: time.NewTicker(flushInterval),
Copy link
Copy Markdown
Member

@LeoCavaille LeoCavaille Sep 15, 2016

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

you just use the ticker in one method, not sure it's necessary to make it an attribute of the Tracer? Just instantiate and use it in that method?

for range time.Tick()

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah, totally correct and thanks for catching that. Totally forget to remove that because it was related to the previous approach (multiple channels and go routines that can be stopped). Furthermore our goroutine never stops so there isn't any kind of "leak" for loosing the reference.

@palazzem palazzem force-pushed the palazzem/trace-span-structs branch from c0b1074 to 78989e1 Compare September 15, 2016 12:56
@palazzem palazzem changed the title [WIP] tracer, span and the high-level API [core] Implementation of the tracing package Sep 15, 2016
@palazzem palazzem merged commit 7b3a665 into master Sep 15, 2016
@palazzem palazzem deleted the palazzem/trace-span-structs branch September 15, 2016 14:02
Comment thread pkg/tracer/span.go
@@ -0,0 +1,121 @@
package tracer
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

rm the pkg directory

Comment thread pkg/tracer/tracer.go

// Tracer is the common struct we use to collect, buffer
type Tracer struct {
enabled int32 // acts as bool to define if the Tracer is enabled or not
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

use a bool here

Comment thread glide.yaml
import:
- package: github.com/stretchr/testify
version: ^1.1.3
- package: github.com/cihub/seelog
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

drop this dependency

Comment thread pkg/tracer/tracer_test.go
// Mock Transport
type DummyTransport struct{}

func (t *DummyTransport) Send(spans []*Span) error { return nil }
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

the dummy transport should encode the spans to make sure the test data in sane

Comment thread pkg/tracer/tracer_test.go
parent := tracer.NewSpan("pylons.request", "pylons", "/")
child := tracer.NewChildSpan("redis.command", parent)
assert.Equal(child.ParentID, parent.SpanID)
assert.Equal(child.TraceID, parent.TraceID)
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

please test the right thigs are inherited

Comment thread pkg/tracer/tracer.go
}

// child that is correctly configured
return newSpan(name, parent.Service, parent.Resource, spanID, parent.TraceID, parent.SpanID, parent.tracer)
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

it shouldn't be inheriting the resource. only the service & ids (see python client)

Comment thread pkg/tracer/context.go

type datadogContextKey struct{}

var datadogActiveSpanKey = datadogContextKey{}
Copy link
Copy Markdown
Contributor

@clutchski clutchski Sep 15, 2016

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

using an empty struct as the key is kinda crazy. is this idiomatic? why not "datadog_trace_span"

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Found that in the opentracing-go client. I'm not an expert here but yes.... think a string is enough?

Comment thread pkg/tracer/encoder.go
// Encode returns a byte array related to the marshalling
// of a list of spans.
func (e *JSONEncoder) Encode(spans []*Span) ([]byte, error) {
return json.Marshal(spans)
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this is really slow let's use the encoder pool from dogtrace. been down this road :)

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

👍

Comment thread pkg/tracer/transport.go
return err
}

defer response.Body.Close()
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

no need to defer at the end of a function. needless perf cost. you're already at the end

@palazzem palazzem restored the palazzem/trace-span-structs branch September 15, 2016 16:18
gh-worker-dd-mergequeue-cf854d Bot pushed a commit that referenced this pull request Jan 27, 2026
This PR updates the behavior of `WithMaxQuerySize` when `max=0` to avoid attaching the query tag entirely. This is more intuitive ("max query size of zero") and gives folks a way to disable serializing the command entirely.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Projects

None yet

Development

Successfully merging this pull request may close these issues.

5 participants