Add OTEL support (carry 4556) #4698

thaJeztah · 2023-12-06T09:08:35Z

carry / rebase of / closes Add otel support #4556
depends on Plumb contexts through commands #4700

This is broken into 2 commits:

Plumb contexts through commands
Add otel tracing as a persistent pre-run to all CLI commands.

- What I did

- How I did it

- How to verify it

- Description for the changelog

- A picture of a cute animal (not mandatory but encouraged)

thaJeztah · 2023-12-06T09:09:39Z

vendor.mod

+require (
+	github.com/grpc-ecosystem/grpc-gateway/v2 v2.11.3 // indirect
+	go.opentelemetry.io/otel/exporters/otlp/internal/retry v1.14.0 // indirect
+	go.opentelemetry.io/otel/exporters/otlp/otlptrace v1.14.0 // indirect
+	go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracegrpc v1.14.0 // indirect
+	go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracehttp v1.14.0 // indirect
+	go.opentelemetry.io/otel/sdk v1.14.0 // indirect
+	go.opentelemetry.io/proto/otlp v0.19.0 // indirect
+	google.golang.org/genproto v0.0.0-20230711160842-782d3b101e98 // indirect
+	google.golang.org/genproto/googleapis/api v0.0.0-20230711160842-782d3b101e98 // indirect
+)


We may have to double-check versions of these new ones

vendor.mod

thaJeztah · 2023-12-06T09:21:46Z

cmd/docker/docker.go

@@ -15,10 +16,14 @@ import (
 	"github.com/docker/cli/cli/version"
 	"github.com/docker/cli/cmd/docker/internal/appcontext"
 	"github.com/docker/docker/api/types/versions"
+	"github.com/moby/buildkit/util/tracing/detect"


⚠️ This is the new dependency on BuildKit; this brings in;

"github.com/moby/buildkit/util/tracing/detect"

"github.com/moby/buildkit/util/bklog"

the bklog package is used for;

detect.TracerProvider() https://github.com/moby/buildkit/blob/v0.12.4/util/tracing/detect/detect.go#L123-L125

-> detect() https://github.com/moby/buildkit/blob/v0.12.4/util/tracing/detect/detect.go#L97-L98

-> bklog. EnableLogWithTraceID() https://github.com/moby/buildkit/blob/v0.12.4/util/bklog/log.go#L23-L29

For the detect package; wondering if we can move that separate; that would (potentially) also allow for the detect package to have a matching version of OTEL, most notalbly semconv; https://github.com/moby/buildkit/blob/v0.12.4/util/tracing/detect/detect.go#L15

semconv "go.opentelemetry.io/otel/semconv/v1.17.0"

Not sure what the best solution is for the bklog package; the function we're calling sets a non-exported package variable. That variable is used in GetLogger (as an optimisation?) to return a logger with traces; https://github.com/moby/buildkit/blob/v0.12.4/util/bklog/log.go#L41-L64

func GetLogger(ctx context.Context) (l *logrus.Entry) { logger := ctx.Value(loggerKey{}) if logger != nil { l = logger.(*logrus.Entry) } else if logger := log.GetLogger(ctx); logger != nil { l = logger } else { l = L } if logWithTraceID { if spanContext := trace.SpanFromContext(ctx).SpanContext(); spanContext.IsValid() { return l.WithFields(logrus.Fields{ "traceID": spanContext.TraceID(), "spanID": spanContext.SpanID(), }) } } return l }

❓ 🤔 perhaps flip the logic, and move that to the tracing/detect package;

bklog.GetLogger() -> tracing/detect.TraceLoggingEnabled()

thaJeztah · 2023-12-06T14:04:09Z

I'll move the first commit (punching-through contexts) to a separate PR

codecov-commenter · 2023-12-12T21:24:05Z

Codecov Report

Merging #4698 (d0da194) into master (efb9206) will decrease coverage by 61.32%.
Report is 44 commits behind head on master.
The diff coverage is n/a.

❗ Current head d0da194 differs from pull request most recent head 827bead. Consider uploading reports for the commit 827bead to get more accurate results

Additional details and impacted files

@@            Coverage Diff             @@
##           master   #4698       +/-   ##
==========================================
- Coverage   61.31%       0   -61.32%     
==========================================
  Files         287       0      -287     
  Lines       20065       0    -20065     
==========================================
- Hits        12303       0    -12303     
+ Misses       6869       0     -6869     
+ Partials      893       0      -893

cli/command/container/stats.go

thaJeztah · 2024-01-04T20:51:15Z

cli/command/cli.go

+// WithContext sets the base context for the cli
+// This is used internally for operations may require a context to propagate tracing.
+func (cli *DockerCli) WithContext(ctx context.Context) {
+	cli.baseCtx = ctx
+}
+


Pushed a commit that re-implements this as a CLIOpt

thaJeztah · 2024-01-04T21:16:23Z

Thanks to @milas ❤️ I pushed a commit that swaps BuildKit detect with the OTEL SDK 🎉

thaJeztah · 2024-01-04T21:16:59Z

I'll cleanup / squash commits a bit after review; just pushing the changes here first

thaJeztah · 2024-01-04T21:27:33Z

cmd/docker/docker.go

+			name := cmd.Name()
+			for p := cmd.Parent(); p != nil && p != cmd.Root(); p = p.Parent() {
+				name = p.Name() + " " + name
+			}
+
+			ctx, _ := otel.Tracer("").Start(cmd.Context(), name)


Just discussing with @milas that we don't have a good convention yet for passing the command name; compose currently uses this;

ctx, cmdSpan := tracing.Tracer.Start( ctx, "cli/"+strings.Join(commandName(cmd), "-"), ) cmdSpan.SetAttributes(attribute.StringSlice("cli.args", args)) cmdSpan.SetAttributes(attribute.StringSlice("cli.flags", getFlags(cmd.Flags())))

that's what Compose is doing so it's slightly different, e.g. docker compose alpha publish -> cli/alpha-publish

We can keep this as-is for now, and look at improving later; I could add the flags and args if we think it's useful to add.

https://opentelemetry.io/docs/specs/semconv/attributes-registry/process/

https://opentelemetry.io/docs/specs/semconv/attributes-registry/process/

OH! That looks great, and from the looks of it that pretty much describes the things we'd want to include (and we wouldn't have to come up with our own conventions, which is a big 💯)

@milas @jsternberg You'll probably be interested in this (if you didn't know about these).

From the looks of it; most of these we could set using a generic helper (if none exists for it). We MAY have to consider if we should sanitise arguments though (i.e. do we want --env MYSQL_ROOT_PASSWORD=<pass> (or --build-arg) to end up in traces? 😬)

If we decide to sanitise, perhaps we need an option to opt-out of sanitising (for those that DO want to include all of that in their traces).

Let me add a screenshot to save others from having to follow the link, and to add context to my comment;

milas

LGTM but you will need to add a call to tp.Shutdown() to ensure the spans get flushed out when the process exits

See:

otel: flush spans on shutdown & remove duplicate resource name set thaJeztah/cli#4

milas · 2024-01-04T21:51:54Z

cmd/docker/docker.go

+	// create a default resource but specify the service name explicitly, or
+	// it will be `unknown_service:<name_of_exe>`
+	//
+	// N.B. a schemaless resource is used with the STABLE semconv value of
+	// `service.name` to avoid https://github.com/open-telemetry/opentelemetry-go/issues/2341
+	res, err := resource.Merge(
+		resource.Default(),
+		resource.NewSchemaless(
+			attribute.String("service.name", "docker-cli"),
+		),
+	)
+	if err != nil {
+		return fmt.Errorf("merging resource: %w", err)
+	}


I realized this is actually redundant because we do os.SetEnv("OTEL_SERVICE_NAME", cmd.Name()) if it's not set

You can just res := resource.Default()

Ah, nice! Just pushed a commit (to be squash) with what I think you meant 👍

milas · 2024-01-04T22:24:49Z

Using my branch off your PR 🎉

(also notice I snuck in some new attributes for the CLI version metadata 👀)

Start a Jaeger instance:

docker run --rm --name jaeger \
  -p 16686:16686 \
  -p 4317:4317 \
  -p 4318:4318 \
  jaegertracing/all-in-one:1.52

(adapted from https://www.jaegertracing.io/docs/latest/getting-started/#all-in-one)

Open web UI @ http://localhost:16686/

make -f docker.Makefile build
OTEL_EXPORTER_OTLP_ENDPOINT=http://localhost:4318 ./build/docker --debug version

cpuguy83 · 2024-01-04T22:29:01Z

cmd/docker/docker.go

@@ -58,6 +82,10 @@ func newDockerCommand(dockerCli *command.DockerCli) *cli.TopLevelCommand {
 	cmd.SetOut(dockerCli.Out())
 	cmd.SetErr(dockerCli.Err())

+	// Cobra's context may be nil in some cases, so initialize it here.


Cobra's context should never be nil.
A context should never be nil, ever.
Did something change upstream in cobra?
I remember specifically discussing this when contexts were added.

Ha! This was from your original PR, but we were discussing this as well in #4599 (comment)

I can remove this part 👍

Ugh... maybe I hit a case where it was nil.

cpuguy83 · 2024-01-04T22:30:41Z

cmd/docker/docker.go

+	// This is the same as on the dockerd side.
+	// This can be removed after buildkit's detect package is updated.
+	if os.Getenv("OTEL_EXPORTER_OTLP_TRACES_PROTOCOL") == "" && os.Getenv("OTEL_EXPORTER_OTLP_PROTOCOL") == "" {
+		os.Setenv("OTEL_EXPORTER_OTLP_TRACES_PROTOCOL", "http/protobuf")


This probably is not needed since we aren't using detect anymore?

Yeah, it should go away - I verified things are still good without it

(@thaJeztah I deleted it over in https://github.com/thaJeztah/cli/pull/4/files#diff-3dcd6325b70a5f5db393a3ecc08060b69007fcef371fb4dabf3164da95646fb6L305-L312 )

thaJeztah · 2024-01-04T22:34:03Z

cmd/docker/docker.go

@@ -357,6 +353,39 @@ func runDocker(dockerCli *command.DockerCli) error {
 	return cmd.Execute()
 }

+func initializeTracing() error {


Should we pass the context here that was set on the command?

If we have a context.Context available, it's probably worth passing through.

That said...I stepped through the source - neither otlphttp or otlpgrpc actually use it 🙃

thaJeztah · 2024-01-04T22:34:40Z

cmd/docker/docker.go

+			cmd.SetContext(ctx)
+			_ = dockerCli.Apply(command.WithContext(ctx))


I.e. this one

corhere

Needs more spans. And I suggest splitting up the instrumentation and propagation work (with the OTEL API go.opentelemetry.io/otel/...) into separate commits from the exporter work (with the OTEL SDK go.opentelemetry.io/otel/sdk/...).

corhere · 2024-01-04T22:31:48Z

cli/command/container/stats.go

@@ -123,6 +125,8 @@ func RunStats(ctx context.Context, dockerCLI command.Cli, options *StatsOptions)

 	showAll := len(options.Containers) == 0
 	if showAll {
+		span := trace.SpanFromContext(ctx)


When in doubt, create a nested span. It provides more detailed tracing insights than reusing a single top-level span for the entire lifetime of the process.

thaJeztah · 2024-01-04T22:42:56Z

Thanks all! I pushed a couple of commits (to be squashed if ok)

I'll be calling it a day for now, but if someone wants to push to this branch; feel free to.

Pushing additional commits should be fine; we can cleanup / squash later (I didn't bother cleaning up commits yet while we're moving this still)

thaJeztah · 2024-01-04T22:44:22Z

cmd/docker/docker.go

@@ -309,6 +348,22 @@ func runDocker(dockerCli *command.DockerCli) error {
 	return cmd.Execute()
 }

+func initializeTracing(ctx context.Context) error {


I added a context here

thaJeztah · 2024-01-04T22:45:10Z

cmd/docker/docker.go

+		os.Setenv("OTEL_SERVICE_NAME", cmd.Root().Name())
+	}
+
+	if err := initializeTracing(cmd.Context()); err != nil {


And passed cmd.Context() here, but double check if that's indeed the correct thing to do, or if it was deliberately a separate context 🙈

Docs on it are minimal - it appears to be intended for exporter setup, e.g. if it needs to dial a connection up-front or something I guess? [see my other comment though, it's actually unused currently by both the HTTP/gRPC exporters]

thaJeztah · 2024-01-04T22:47:58Z

HA!

#19 53.89 === FAIL: cmd/docker TestClientDebugEnabled (0.00s)
#19 53.89 panic: cannot create context from nil parent [recovered]
#19 53.89 	panic: cannot create context from nil parent

cli/command/cli_options.go

corhere · 2024-01-04T23:12:08Z

cmd/docker/docker.go

+			// TODO: There doesn't seem to be a way to determine if the command returned an error, so we can set the span status here.
+			trace.SpanFromContext(cmd.Context()).End()


You're fighting an uphill trying to use cobra lifecycle hooks for this. See below.

corhere · 2024-01-04T23:15:01Z

cmd/docker/docker.go

+		os.Setenv("OTEL_SERVICE_NAME", cmd.Root().Name())
+	}
+
+	if err := initializeTracing(cmd.Context()); err != nil {


Initialize tracing in main(). Here's too late to be able to export traces from early in the process lifecycle.

corhere · 2024-01-04T23:21:56Z

cmd/docker/docker.go

+	otel.SetTracerProvider(sdktrace.NewTracerProvider(
+		sdktrace.WithSpanProcessor(sdktrace.NewBatchSpanProcessor(exporter)),
+		sdktrace.WithResource(resource.Default()),
+	))


The tracer provider needs to be shut down before the process exits to ensure the recorded spans are flushed to the exporter.

corhere · 2024-01-04T23:22:32Z

cmd/docker/docker.go

@@ -309,6 +348,22 @@ func runDocker(dockerCli *command.DockerCli) error {
 	return cmd.Execute()


Suggested change

return cmd.Execute()

ctx, span := otel.Tracer("github.com/docker/docker/cli/cmd/docker").Start(

cmd.Context(),

"runDocker",

)

defer span.End()

err = cmd.ExecuteContext(ctx)

if err != nil {

span.SetStatus(codes.Error, "command errored")

span.RecordError(err)

}

return err

It'd be even better to start the span at the top of the function, so the latency before the command is executed gets captured in the traces.

- Add otel tracing support - switch to use OTEL sdk instead of buildkit - use default resource We already set os.SetEnv("OTEL_SERVICE_NAME", cmd.Name()) if it's not set, so don't have to do the merge here. - pass the cmd.Context() - Cobra's context should never be nil Co-authored-by: Milas Bowman <[email protected]> Co-authored-by: Sebastiaan van Stijn <[email protected]> Signed-off-by: Brian Goff <[email protected]>

see docker#4698 (comment) Signed-off-by: Sebastiaan van Stijn <[email protected]>

thaJeztah added impact/changelog status/2-code-review labels Dec 6, 2023

thaJeztah requested a review from silvin-lubecki as a code owner December 6, 2023 09:08

thaJeztah changed the title ~~Add otel support (carry 4556)~~ Add OTEL support (carry 4556) Dec 6, 2023

thaJeztah commented Dec 6, 2023

View reviewed changes

thaJeztah mentioned this pull request Dec 6, 2023

util/tracing/detect: separate from bklog package moby/buildkit#4469

Draft

thaJeztah force-pushed the carry_otel branch from 7b5e8da to 69a3eb5 Compare December 6, 2023 14:04

This was referenced Dec 6, 2023

Plumb contexts through commands #4700

Merged

Add otel support #4556

Open

thaJeztah force-pushed the carry_otel branch from 69a3eb5 to 77f2f0f Compare December 6, 2023 17:05

thaJeztah mentioned this pull request Dec 11, 2023

cli-plugins: terminate plugin when CLI exits #4599

Merged

thaJeztah force-pushed the carry_otel branch from 77f2f0f to 85e51f0 Compare December 12, 2023 21:22

thaJeztah force-pushed the carry_otel branch 3 times, most recently from a6fc3d8 to e615d3e Compare December 14, 2023 10:06

thaJeztah commented Dec 19, 2023

View reviewed changes

cli/command/container/stats.go Outdated Show resolved Hide resolved

thaJeztah commented Dec 19, 2023

View reviewed changes

cli/command/container/stats.go Outdated Show resolved Hide resolved

thaJeztah force-pushed the carry_otel branch from e615d3e to 6d73f29 Compare January 4, 2024 20:45

thaJeztah commented Jan 4, 2024

View reviewed changes

thaJeztah force-pushed the carry_otel branch from 8091302 to 11d878c Compare January 4, 2024 20:53

thaJeztah commented Jan 4, 2024

View reviewed changes

milas reviewed Jan 4, 2024

View reviewed changes

cpuguy83 reviewed Jan 4, 2024

View reviewed changes

thaJeztah commented Jan 4, 2024

View reviewed changes

thaJeztah force-pushed the carry_otel branch from baabb79 to 549c6a2 Compare January 4, 2024 22:35

corhere suggested changes Jan 4, 2024

View reviewed changes

thaJeztah commented Jan 4, 2024

View reviewed changes

corhere reviewed Jan 4, 2024

View reviewed changes

cli/command/cli_options.go Outdated Show resolved Hide resolved

corhere suggested changes Jan 4, 2024

View reviewed changes

thaJeztah force-pushed the carry_otel branch from 3108083 to 7eba434 Compare January 8, 2024 17:08

thaJeztah mentioned this pull request Jan 11, 2024

improve passing context #4774

Merged

thaJeztah force-pushed the carry_otel branch from 7eba434 to d0da194 Compare February 26, 2024 15:57

thaJeztah force-pushed the carry_otel branch from d0da194 to f8850d6 Compare February 27, 2024 13:57

cmd/docker: remove handling for BuildKit's detect package

827bead

see docker#4698 (comment) Signed-off-by: Sebastiaan van Stijn <[email protected]>

Benehiko mentioned this pull request Mar 6, 2024

feat: more context on docker client moby/moby#47518

Closed

krissetto mentioned this pull request Mar 8, 2024

Remove OTEL stuff from "compose wrapper" #4927

Closed

7 tasks

thaJeztah added area/metrics area/metrics/otel labels Mar 16, 2024

		cmd.SetContext(ctx)
		_ = dockerCli.Apply(command.WithContext(ctx))

		// TODO: There doesn't seem to be a way to determine if the command returned an error, so we can set the span status here.
		trace.SpanFromContext(cmd.Context()).End()

		@@ -309,6 +348,22 @@ func runDocker(dockerCli *command.DockerCli) error {
		return cmd.Execute()

-	return cmd.Execute()
+	ctx, span := otel.Tracer("github.com/docker/docker/cli/cmd/docker").Start(
+		cmd.Context(),
+		"runDocker",
+	)
+	defer span.End()
+	err = cmd.ExecuteContext(ctx)
+	if err != nil {
+		span.SetStatus(codes.Error, "command errored")
+		span.RecordError(err)
+	}
+	return err

Add OTEL support (carry 4556) #4698

Are you sure you want to change the base?

Add OTEL support (carry 4556) #4698

Uh oh!

Conversation

thaJeztah commented Dec 6, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

thaJeztah commented Dec 6, 2023

Uh oh!

codecov-commenter commented Dec 12, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Codecov Report

Uh oh!

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

thaJeztah commented Jan 4, 2024

Uh oh!

thaJeztah commented Jan 4, 2024

Uh oh!

thaJeztah Jan 4, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

milas left a comment • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

milas commented Jan 4, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

corhere left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

thaJeztah commented Jan 4, 2024

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

thaJeztah commented Jan 4, 2024

Uh oh!

Uh oh!

thaJeztah commented Dec 6, 2023 •

edited

Loading

codecov-commenter commented Dec 12, 2023 •

edited

Loading

thaJeztah Jan 4, 2024 •

edited

Loading

milas left a comment •

edited

Loading

milas commented Jan 4, 2024 •

edited

Loading