Raphael/redigo #51

raphaelgavache · 2017-04-11T19:23:01Z

Summary

Adding a redigo contrib that traces all redis calls via a the redigo library (https://github.com/garyburd/redigo)

Exemple span:

Name:
- redis.command
Meta:
- redis.raw_command: "SET fleet truck "
- redis.args_length: 2
- out.host: 127.0.0.1
- out.port: 6379
- out.db: 0
- out.network: tcp

Patching guide:

using Dial()/DialURL() and Do

Instead of

client, err := redis.Dial("tcp", "127.0.0.1:6379", ...)
client.Do("SET", key, value, ...)

You use

client, err := tracedredis.TracedDial(service_name, tracer, "tcp", "127.0.0.1:6379", ...)
If you have a context:
client.Do("SET", key, value, ...,`context`)
Else same command as usual:
client.Do("SET", key, value, ...)

Using Pools

Instead of

pool :=  pool := &redis.Pool{
                (...)
                Dial: func() (redis.Conn, error) {
                        return Dial("tcp", "127.0.0.1:6379")
                },
        }
c := pool.Get()
c.Do(cmds)

Use

pool :=  pool := &redis.Pool{
                (...)
                Dial: func() (redis.Conn, error) {
                        return tracedredis.Dial(service_name, tracer"tcp", "127.0.0.1:6379")
                },
        }
c:= pools.Get()
c.Do(cmds,..., context)

Conflicts: circle.yml

…redigo

talwai · 2017-04-18T19:31:35Z

tracer/contrib/redigo/tracedredis.go

+	host, port, err := net.SplitHostPort(u.Host)
+	if err != nil {
+		host = u.Host
+		port = "6379"


this seems incorrect, shouldn't we only do this if port is ""?

We set port to 6379 only when can't get the port via net.SplitHostPort (this is the err that gets in the if) https://github.com/garyburd/redigo/blob/master/redis/conn.go#L226

ok add a comment with that link

talwai · 2017-04-18T19:32:34Z

tracer/contrib/redigo/tracedredis.go

+
+func (tc TracedConn) Do(commandName string, args ...interface{}) (reply interface{}, err error) {
+	ctx := context.Background()
+	ok := false


don't need this line. just do a declaration on Line 62 ctx, ok := ...

talwai · 2017-04-18T19:34:05Z

tracer/contrib/redigo/tracedredis.go

+	}
+	span.SetMeta("redis.raw_command", raw_command)
+	ret, err := tc.Conn.Do(commandName, args...)
+	return ret, err


just return tc.Conn.Do(...)

talwai · 2017-04-18T19:43:07Z

tracer/contrib/redigo/tracedredis.go

+		span.Resource = "redigo.Conn.Flush"
+	}
+	raw_command := commandName
+	for _, arg := range args {


this can be slow and create a lot of garbage. use a bytes.Buffer

talwai · 2017-04-18T19:54:13Z

tracer/contrib/redigo/tracedredis.go

+		span.Resource = commandName
+	} else {
+		// According to redigo doc: when the command argument to the Do method is "",
+		// then the Do method will flush the output buffer


add a link to the doc please

talwai · 2017-04-18T20:01:49Z

tracer/contrib/redigo/tracedredis.go

+	}
+
+	span := tc.tracer.NewChildSpanFromContext("redis.command", ctx)
+	defer func() {


actually we have a more idiomatic way to do this: defer span.FinishWithErr(err) https://github.com/DataDog/dd-trace-go/blob/master/tracer/span.go#L171

This reverts commit 67d4077.

talwai · 2017-04-19T21:49:37Z

tracer/contrib/redigo/tracedredis.go

+
+type TracedConn struct {
+	redis.Conn
+	tracer  *tracer.Tracer


wrap host, port, network, service, tracer in a TraceParams struct and pass it to TracedConn . avoids conflicts in field names

talwai · 2017-04-24T14:18:24Z

tracer/contrib/redigo/tracedredis.go

+	var ctx context.Context
+	var ok bool
+	if len(args) > 0 {
+		ctx, ok = args[len(args)-1].(context.Context)


I think it would be more idiomatic to use the sql style ExecContext https://golang.org/pkg/database/sql/#DB.ExecContext

so maybe another function DoContext that takes a context as the first arg. Thoughts?

I'm not familiar with that API but indeed having ctx as a last optional arg can lead to surprising behaviors. The reason for doing this is keeping the API unchanged when using or not using tracing, right ? Because this would work one way -> if you replace the Conn by a TracedConn, code is still going to work. But then all redis traces are lone traces, not related to their parents. So you have to put an extra arg. But if you do so, it does not work the other way, the day you go backwards and replace the TracedConn by a Conn, the code will fail because the Redis lib is going to receive an extra param it does not know what to do with. Dig into it, but probably DoContext suggested by @talwai would be fine, it would cost some extra typing/refactor from people instrumenting the code, but would make it safer. Just my 2c.

ufoot

Good approach, yet some little fixes to do for general stability I think.

ufoot · 2017-04-24T14:29:01Z

docker-compose.yml

+ddagent:
+        image: datadog/docker-dd-agent
+        environment:
+                - DD_APM_ENABLED=true


could be useless now I think, since trace agent should be running by default: DataDog/datadog-trace-agent@a51dd0e#diff-b7db7d3e3d014cfcce344902b2d07a78

ufoot · 2017-04-24T14:30:42Z

tracer/contrib/redigo/tracedredis.go

+	c, err := redis.Dial(network, address)
+	addr := strings.Split(address, ":")
+	host := addr[0]
+	port := addr[1]


Beware here, you might need to check if there's no : in the string (no port given, and I think this is a real world case, just letting the lib pick up the default port) else we're going to have a panic() in our code and interrupt use code.

ufoot · 2017-04-24T15:30:09Z

tracer/contrib/redigo/tracedredis_test.go

+	assert.Equal(span.GetMeta("redis.args_length"), "2")
+}
+
+func TestError(t *testing.T) {


You probably need another test that yields an error when connecting to the service, making sure if the underlying library can not connect to redis (bad credentials, bad host, whatever) it bubbles up to the caller.

ufoot · 2017-04-25T08:22:14Z

tracer/contrib/redigo/tracedredis.go

+	if len(addr) == 2 && addr[1] != "" {
+		port = addr[1]
+	} else {
+		port = "6379"


ufoot · 2017-04-25T08:48:58Z

tracer/contrib/redigo/tracedredis.go

+	var ctx context.Context
+	var ok bool
+	if len(args) > 0 {
+		ctx, ok = args[len(args)-1].(context.Context)


I'm not familiar with that API but indeed having ctx as a last optional arg can lead to surprising behaviors. The reason for doing this is keeping the API unchanged when using or not using tracing, right ? Because this would work one way -> if you replace the Conn by a TracedConn, code is still going to work. But then all redis traces are lone traces, not related to their parents. So you have to put an extra arg. But if you do so, it does not work the other way, the day you go backwards and replace the TracedConn by a Conn, the code will fail because the Redis lib is going to receive an extra param it does not know what to do with. Dig into it, but probably DoContext suggested by @talwai would be fine, it would cost some extra typing/refactor from people instrumenting the code, but would make it safer. Just my 2c.

ufoot · 2017-04-25T08:54:44Z

tracer/contrib/redigo/tracedredis_test.go

+
+	_, err := TracedDial("redis-service", testTracer, "tcp", "000.0.0:1111")
+
+	assert.Contains(err.Error(), "dial tcp: lookup 000.0.0:")


raphaelgavache · 2017-04-25T13:56:49Z

About the DoContext suggestion:
TracedConn struct is encapsulated in other structures within redigo library. Those structures implement Conn interface and if you try to apply a DoContext to them it won’t work.
For exemple we use redigo pools for our dd-go redis connections, if I add the TracedDial function those pools are traced but the TracedConn is encapsulated in this struct https://github.com/garyburd/redigo/blob/master/redis/pool.go#L324 that implements Conn. Can’t call DoContext on that struct, nor can we get the TracedConn from it to call DoContext.

I guess we should add a warning message to people adding Context, they have to make sure that they've used TracedDial before using a Do with context in the args

ufoot · 2017-04-26T14:47:57Z

OK @furmmon I see your point with pools & co. What about writing a func that would maked a traced redis.Conn out of anything implementing redis.Conn. Like func TracedConn(ctx context.Context, conn redis.Conn) redis.Conn. The example:

c := pool.Get()
c.Do(cmds, ...)

Becomes:

c := tracedredis.TracedConn(ctx, pool.Get())
c.Do(cmds, ...)

@talwai does this make sense?

raphaelgavache · 2017-04-27T21:59:09Z

Problem raised

With current code, to pass the context for the creation of the redigo span we use the fact that redis.Conn Do method has the following args: commandName string, args ...interface{}. If a context is slipped in at the end of the args the spans created will inherit of it.
The risk of that is that if you stop using a TracedConn and keep the context at the end of the Do call you will make redis call crash. The redigo library doesn't implement context yet and Do isn't supposed to receive one in it's args

The ideal solution would be to have a DoContext(ctx context.Context, commandName string, args ...interface{} function.

In our back-end we use alot of redis.Pool for our redigo transactions, so let's dig into this use case.

General overview of redigo patching

Data we want:

connection metadata (host, port, ...)
commands to be executed and info about their args
inheritance (who executed that command)

Where to get those:

all data related to connection is in the Dial function and they are not accessible from Pools
commands appear at the Do function
for inheritance we have to pass the context at the span creation time so that it has parents (if exists)

Transactions with redis are made in the Do function, so this is the place where we want our spans to be created and complete themselves.

Current state

By using TracedDial or TracedDialURL function we get a TracedConn structure inside redigo.
this structure contains all the connection metadata from Dial parameters and it implements the redis.Conn interface. func (tc TracedConn) Do overwrites the Do function so that the redis transaction is traced.

About the proposed solutions

1. Add a DoWithContext function for TracedConn

When we do

connection := pool.Get()
connection.Do(cmds, ..)

pool.Get() returns a pooledConnection. Our TracedConn is encapsulated in that pooledConnection in a private variable c. We can't cast that back to a TracedConn so adding a method DoContext is impossible at that level.

2. Insert context upstream

We can easily set the context at the pool creation level without messing with the Do args. But then parent spans will be irrelevant. We usually create a pool then do various calls on it, and those calls can't be reasonably all linked in the same trace

raphaelgavache · 2017-04-27T22:01:05Z

I'm open to any solution to the original problem, I didn't find any better then the current one

raphaelgavache and others added 14 commits April 11, 2017 19:19

Redigo patchin Dial with tests

7df6db9

Taking docker-compose from go-redis PR for tests

70cedda

Conflicts: circle.yml

casting redis.Error to string for tests

a9f44ec

Rewriting Do instead of TraceDo

a6e8ec7

Testing patch on pool and patching DialUrl

6d3aa4e

Adding test for TracedDialURL and changing resource

c949951

Creating rootspans if no context

cd2a054

bug fix, int in command

cd6570e

Changing raw_command display

3f274da

Merge branch 'master' of github.com:DataDog/dd-trace-go into raphael/…

90c07e3

…redigo

setting service the right way

219b274

adding a function to set service on Conn

7dd678e

Case no commandName in conn.Do()

2e9fbc3

updated with Aaditya (defer, ctx..)

57e2bf1

talwai reviewed Apr 18, 2017

View reviewed changes

raphaelgavache added 3 commits April 18, 2017 20:03

Addressing comments

3c46b89

using FinishWithError and making this function usable

67d4077

Revert "using FinishWithError and making this function usable"

1fc375f

This reverts commit 67d4077.

talwai reviewed Apr 19, 2017

View reviewed changes

Adding TraceParams + comments

501b4c4

talwai reviewed Apr 24, 2017

View reviewed changes

ufoot reviewed Apr 24, 2017

View reviewed changes

ufoot mentioned this pull request Apr 24, 2017

Raphael/go redis #47

Merged

raphaelgavache added 2 commits April 24, 2017 17:48

After Christian's review

d655319

docker-compose agent correction

a3ba515

CircleCI flaky test correction

e9ab51b

ufoot reviewed Apr 25, 2017

View reviewed changes

returning same signature, removing SetService

be1e653

raphaelgavache and others added 6 commits April 27, 2017 22:34

Adding an example file

df7df68

Example name go convention fix (CircleCi fix_

1211b3d

redigo: improve example

6cbe3be

redigo: rename files

c50f001

redigo: bolster examples

912f305

lint fix

bef84db

talwai approved these changes May 1, 2017

View reviewed changes

talwai merged commit c1aa041 into master May 1, 2017

raphaelgavache deleted the raphael/redigo branch June 20, 2017 15:19

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Raphael/redigo #51

Raphael/redigo #51

raphaelgavache commented Apr 11, 2017 •

edited

Loading

talwai Apr 18, 2017

raphaelgavache Apr 18, 2017

talwai Apr 18, 2017

talwai Apr 18, 2017

talwai Apr 18, 2017

talwai Apr 18, 2017

talwai Apr 18, 2017

talwai Apr 18, 2017

talwai Apr 19, 2017 •

edited

Loading

talwai Apr 24, 2017

ufoot Apr 25, 2017

ufoot left a comment

ufoot Apr 24, 2017

ufoot Apr 24, 2017

ufoot Apr 24, 2017

ufoot Apr 25, 2017

ufoot Apr 25, 2017

ufoot Apr 25, 2017

raphaelgavache commented Apr 25, 2017

ufoot commented Apr 26, 2017 •

edited

Loading

raphaelgavache commented Apr 27, 2017 •

edited

Loading

raphaelgavache commented Apr 27, 2017


		_, err := TracedDial("redis-service", testTracer, "tcp", "000.0.0:1111")

		assert.Contains(err.Error(), "dial tcp: lookup 000.0.0:")

Raphael/redigo #51

Raphael/redigo #51

Conversation

raphaelgavache commented Apr 11, 2017 • edited Loading

Summary

Exemple span:

Patching guide:

using Dial()/DialURL() and Do

Using Pools

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

talwai Apr 19, 2017 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ufoot left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

raphaelgavache commented Apr 25, 2017

ufoot commented Apr 26, 2017 • edited Loading

raphaelgavache commented Apr 27, 2017 • edited Loading

Problem raised

General overview of redigo patching

Data we want:

Where to get those:

Current state

About the proposed solutions

1. Add a DoWithContext function for TracedConn

2. Insert context upstream

raphaelgavache commented Apr 27, 2017

raphaelgavache commented Apr 11, 2017 •

edited

Loading

talwai Apr 19, 2017 •

edited

Loading

ufoot commented Apr 26, 2017 •

edited

Loading

raphaelgavache commented Apr 27, 2017 •

edited

Loading