tracing: Add initial opentracing support

Add initial support for opentracing by using the `jaeger` package.
Since opentracing uses the `context` package, add a `context.Context`
as the first parameter to all the functions that we might want to
trace. Trace "spans" (trace points) are then added by extracting the
trace details from the specified context parameter.

Notes:

- Although the tracer is created in `main()`, the "root span"
  (aka the first trace point) is not added until `beforeSubcommands()`.

  This is by design and is a compromise: by delaying the creation of the
  root span, the spans become much more readable since using the web-based
  JaegerUI, you will see traces like this:

  ```
  kata-runtime: kata-runtime create
  ------------  -------------------
       ^                ^
       |                |
  Trace name        First span name
                    (which clearly shows the CLI command that was run)
  ```

  Creating the span earlier means it is necessary to expand 'n' spans in
  the UI before you get to see the name of the CLI command that was run.
  In adding support, this became very tedious, hence my design decision to
  defer the creation of the root span until after signal handling has been
  setup and after CLI options have been parsed, but still very early in
  the code path.

  - At this stage, the tracing stops at the `virtcontainers` call
  boundary.

- Tracing is "always on" as there doesn't appear to be a way to toggle
  it. However, its resolves to a "nop" unless the tracer can talk to a
  jaeger agent.

Note that this commit required a bit of rework to `beforeSubcommands()`
to reduce the cyclomatic complexity.

Fixes #557.

Signed-off-by: James O. D. Hunt <[email protected]>

cli/config.go

@@ -102,6 +102,7 @@ type proxy struct {
 
 type runtime struct {
 	Debug             bool   `toml:"enable_debug"`
+	Tracing           bool   `toml:"enable_tracing"`
 	InterNetworkModel string `toml:"internetworking_model"`
 }
 
@@ -538,6 +539,10 @@ func loadConfiguration(configPath string, ignoreLogging bool) (resolvedConfigPat
 		kataLog.Logger.Level = originalLoggerLevel
 	}
 
+	if tomlConf.Runtime.Tracing {
+		tracing = true
+	}
+
 	if tomlConf.Runtime.InterNetworkModel != "" {
 		err = config.InterNetworkModel.SetModel(tomlConf.Runtime.InterNetworkModel)
 		if err != nil {

cli/config/configuration.toml.in

@@ -189,3 +189,8 @@ path = "@SHIMPATH@"
 #     Used when the Container network interface can be bridged using
 #     macvtap.
 internetworking_model="@DEFNETWORKMODEL@"
+
+# If enabled, the runtime will create opentracing.io traces and spans.
+# (See https://www.jaegertracing.io/docs/getting-started).
+# (default: disabled)
+#enable_tracing = true

cli/create.go

@@ -7,6 +7,7 @@
 package main
 
 import (
+	"context"
 	"errors"
 	"fmt"
 	"io/ioutil"
@@ -17,6 +18,7 @@ import (
 	vc "github.com/kata-containers/runtime/virtcontainers"
 	vf "github.com/kata-containers/runtime/virtcontainers/factory"
 	"github.com/kata-containers/runtime/virtcontainers/pkg/oci"
+	opentracing "github.com/opentracing/opentracing-go"
 	"github.com/urfave/cli"
 )
 
@@ -62,6 +64,11 @@ var createCLICommand = cli.Command{
 		},
 	},
 	Action: func(context *cli.Context) error {
+		ctx, err := cliContextToContext(context)
+		if err != nil {
+			return err
+		}
+
 		runtimeConfig, ok := context.App.Metadata["runtimeConfig"].(oci.RuntimeConfig)
 		if !ok {
 			return errors.New("invalid runtime config")
@@ -72,7 +79,7 @@ var createCLICommand = cli.Command{
 			return err
 		}
 
-		return create(context.Args().First(),
+		return create(ctx, context.Args().First(),
 			context.String("bundle"),
 			console,
 			context.String("pid-file"),
@@ -85,12 +92,16 @@ var createCLICommand = cli.Command{
 // Use a variable to allow tests to modify its value
 var getKernelParamsFunc = getKernelParams
 
-func create(containerID, bundlePath, console, pidFilePath string, detach bool,
+func create(ctx context.Context, containerID, bundlePath, console, pidFilePath string, detach bool,
 	runtimeConfig oci.RuntimeConfig) error {
 	var err error
 
+	span, ctx := opentracing.StartSpanFromContext(ctx, "create")
+	defer span.Finish()
+
 	kataLog = kataLog.WithField("container", containerID)
 	setExternalLoggers(kataLog)
+	span.SetTag("container", containerID)
 
 	// Checks the MUST and MUST NOT from OCI runtime specification
 	if bundlePath, err = validCreateParams(containerID, bundlePath); err != nil {
@@ -136,12 +147,12 @@ func create(containerID, bundlePath, console, pidFilePath string, detach bool,
 	var process vc.Process
 	switch containerType {
 	case vc.PodSandbox:
-		process, err = createSandbox(ociSpec, runtimeConfig, containerID, bundlePath, console, disableOutput)
+		process, err = createSandbox(ctx, ociSpec, runtimeConfig, containerID, bundlePath, console, disableOutput)
 		if err != nil {
 			return err
 		}
 	case vc.PodContainer:
-		process, err = createContainer(ociSpec, containerID, bundlePath, console, disableOutput)
+		process, err = createContainer(ctx, ociSpec, containerID, bundlePath, console, disableOutput)
 		if err != nil {
 			return err
 		}
@@ -152,7 +163,7 @@ func create(containerID, bundlePath, console, pidFilePath string, detach bool,
 	// is shim's in our case. This is mandatory to make sure there is no one
 	// else (like Docker) trying to create those files on our behalf. We want to
 	// know those files location so that we can remove them when delete is called.
-	cgroupsPathList, err := processCgroupsPath(ociSpec, containerType.IsSandbox())
+	cgroupsPathList, err := processCgroupsPath(ctx, ociSpec, containerType.IsSandbox())
 	if err != nil {
 		return err
 	}
@@ -163,14 +174,14 @@ func create(containerID, bundlePath, console, pidFilePath string, detach bool,
 		cgroupsDirPath = ociSpec.Linux.CgroupsPath
 	}
 
-	if err := createCgroupsFiles(containerID, cgroupsDirPath, cgroupsPathList, process.Pid); err != nil {
+	if err := createCgroupsFiles(ctx, containerID, cgroupsDirPath, cgroupsPathList, process.Pid); err != nil {
 		return err
 	}
 
 	// Creation of PID file has to be the last thing done in the create
 	// because containerd considers the create complete after this file
 	// is created.
-	return createPIDFile(pidFilePath, process.Pid)
+	return createPIDFile(ctx, pidFilePath, process.Pid)
 }
 
 var systemdKernelParam = []vc.Param{
@@ -241,8 +252,10 @@ func setKernelParams(containerID string, runtimeConfig *oci.RuntimeConfig) error
 	return nil
 }
 
-func createSandbox(ociSpec oci.CompatOCISpec, runtimeConfig oci.RuntimeConfig,
+func createSandbox(ctx context.Context, ociSpec oci.CompatOCISpec, runtimeConfig oci.RuntimeConfig,
 	containerID, bundlePath, console string, disableOutput bool) (vc.Process, error) {
+	span, ctx := opentracing.StartSpanFromContext(ctx, "createSandbox")
+	defer span.Finish()
 
 	err := setKernelParams(containerID, &runtimeConfig)
 	if err != nil {
@@ -259,15 +272,17 @@ func createSandbox(ociSpec oci.CompatOCISpec, runtimeConfig oci.RuntimeConfig,
 		return vc.Process{}, err
 	}
 
-	kataLog = kataLog.WithField("sandbox", sandbox.ID())
+	sid := sandbox.ID()
+	kataLog = kataLog.WithField("sandbox", sid)
 	setExternalLoggers(kataLog)
+	span.SetTag("sandbox", sid)
 
 	containers := sandbox.GetAllContainers()
 	if len(containers) != 1 {
 		return vc.Process{}, fmt.Errorf("BUG: Container list from sandbox is wrong, expecting only one container, found %d containers", len(containers))
 	}
 
-	if err := addContainerIDMapping(containerID, sandbox.ID()); err != nil {
+	if err := addContainerIDMapping(ctx, containerID, sandbox.ID()); err != nil {
 		return vc.Process{}, err
 	}
 
@@ -288,9 +303,12 @@ func setEphemeralStorageType(ociSpec oci.CompatOCISpec) oci.CompatOCISpec {
 	return ociSpec
 }
 
-func createContainer(ociSpec oci.CompatOCISpec, containerID, bundlePath,
+func createContainer(ctx context.Context, ociSpec oci.CompatOCISpec, containerID, bundlePath,
 	console string, disableOutput bool) (vc.Process, error) {
 
+	span, ctx := opentracing.StartSpanFromContext(ctx, "createContainer")
+	defer span.Finish()
+
 	ociSpec = setEphemeralStorageType(ociSpec)
 
 	contConfig, err := oci.ContainerConfig(ociSpec, bundlePath, containerID, console, disableOutput)
@@ -305,20 +323,24 @@ func createContainer(ociSpec oci.CompatOCISpec, containerID, bundlePath,
 
 	kataLog = kataLog.WithField("sandbox", sandboxID)
 	setExternalLoggers(kataLog)
+	span.SetTag("sandbox", sandboxID)
 
 	_, c, err := vci.CreateContainer(sandboxID, contConfig)
 	if err != nil {
 		return vc.Process{}, err
 	}
 
-	if err := addContainerIDMapping(containerID, sandboxID); err != nil {
+	if err := addContainerIDMapping(ctx, containerID, sandboxID); err != nil {
 		return vc.Process{}, err
 	}
 
 	return c.Process(), nil
 }
 
-func createCgroupsFiles(containerID string, cgroupsDirPath string, cgroupsPathList []string, pid int) error {
+func createCgroupsFiles(ctx context.Context, containerID string, cgroupsDirPath string, cgroupsPathList []string, pid int) error {
+	span, _ := opentracing.StartSpanFromContext(ctx, "createCgroupsFiles")
+	defer span.Finish()
+
 	if len(cgroupsPathList) == 0 {
 		kataLog.WithField("pid", pid).Info("Cgroups files not created because cgroupsPath was empty")
 		return nil
@@ -361,7 +383,10 @@ func createCgroupsFiles(containerID string, cgroupsDirPath string, cgroupsPathLi
 	return nil
 }
 
-func createPIDFile(pidFilePath string, pid int) error {
+func createPIDFile(ctx context.Context, pidFilePath string, pid int) error {
+	span, _ := opentracing.StartSpanFromContext(ctx, "createPIDFile")
+	defer span.Finish()
+
 	if pidFilePath == "" {
 		// runtime should not fail since pid file is optional
 		return nil