Skip to content

Go Auto Instrumentation : Unrelated Traces coming for single request  #1519

Open
@Priyanka-CKT

Description

Describe the bug

Upon hitting a single request to the instrumented Go application , it is creating 2 traces.
Call flow

Postman GRPC call -> Yoren (UserInsightsService/GetuserInsightsForecast) -> DB (mysql) and Aeron(pb.UserSubscriptionService/GetUserSubscriptions)

Receiving 2 traces(with one span in each) for the single request

  1. yoren: /pb.UserSubscriptionsService/GetUserSubscriptions 01bdabc
  2. yoren: DB aca81a0

Environment

OS : Kind K8s cluster with docker (image with golang:1.21.13-alpine) on Mac OSX
Go version : 1.21
Version : Kernel version : 5.15
OTEL Image : otel/autoinstrumentation-go:v0.19.0-alpha
Screenshot 2024-12-24 at 11 55 58 PM

Expected behavior

One trace id with 3 spans for below was expected.
a. UserInsightsService/GetuserInsightsForecast
b. DB
c. pb.UserSubscriptionService/GetUserSubscriptions

Additional context

LOGS

{
  "time": "2024-12-24T16:33:41.14576938Z",
  "level": "INFO",
  "source": {
    "function": "main.main",
    "file": "/app/cli/main.go",
    "line": 103
  },
  "msg": "building OpenTelemetry Go instrumentation...",
  "globalImpl": false,
  "version": {
    "Release": "v0.19.0-alpha",
    "Revision": "unknown",
    "Go": {
      "Version": "go1.23.4",
      "OS": "linux",
      "Arch": "arm64"
    }
  }
}
{
  "time": "2024-12-24T16:33:43.148639965Z",
  "level": "INFO",
  "source": {
    "function": "go.opentelemetry.io/auto/internal/pkg/process.(*Analyzer).DiscoverProcessID",
    "file": "/app/internal/pkg/process/discover.go",
    "line": 64
  },
  "msg": "found process",
  "pid": 7
}
{
  "time": "2024-12-24T16:33:43.149643715Z",
  "level": "ERROR",
  "source": {
    "function": "go.opentelemetry.io/auto/internal/pkg/process.(*Analyzer).Analyze",
    "file": "/app/internal/pkg/process/analyze.go",
    "line": 83
  },
  "msg": "parsing dependency version",
  "error": "Malformed version: (devel)",
  "dependency": {
    "Path": "github.com/tix/yoren",
    "Version": "(devel)",
    "Sum": "",
    "Replace": null
  }
}
{
  "time": "2024-12-24T16:33:43.15799334Z",
  "level": "INFO",
  "source": {
    "function": "go.opentelemetry.io/auto/internal/pkg/process.remoteAllocate.func1",
    "file": "/app/internal/pkg/process/allocate.go",
    "line": 70
  },
  "msg": "Detaching from process",
  "pid": 7
}
{
  "time": "2024-12-24T16:33:43.158248923Z",
  "level": "INFO",
  "source": {
    "function": "go.opentelemetry.io/auto.NewInstrumentation",
    "file": "/app/instrumentation.go",
    "line": 113
  },
  "msg": "target process analysis completed",
  "pid": 7,
  "go_version": "1.21.13",
  "dependencies": {
    "filippo.io/edwards25519": "1.1.0",
    "github.com/fsnotify/fsnotify": "1.7.0",
    "github.com/go-sql-driver/mysql": "1.8.1",
    "github.com/hashicorp/hcl": "1.0.0",
    "github.com/magiconair/properties": "1.8.7",
    "github.com/mitchellh/mapstructure": "1.5.0",
    "github.com/pelletier/go-toml/v2": "2.2.2",
    "github.com/sagikazarmark/slog-shim": "0.1.0",
    "github.com/spf13/afero": "1.11.0",
    "github.com/spf13/cast": "1.6.0",
    "github.com/spf13/pflag": "1.0.5",
    "github.com/spf13/viper": "1.19.0",
    "github.com/subosito/gotenv": "1.6.0",
    "golang.org/x/net": "0.25.0",
    "golang.org/x/sys": "0.20.0",
    "golang.org/x/text": "0.15.0",
    "google.golang.org/genproto/googleapis/rpc": "0.0.0-20240528184218-531527333157",
    "google.golang.org/grpc": "1.65.0",
    "google.golang.org/protobuf": "1.34.2",
    "gopkg.in/ini.v1": "1.67.0",
    "gopkg.in/yaml.v3": "3.0.1",
    "std": "1.21.13"
  },
  "total_functions_found": 10
}
{
  "time": "2024-12-24T16:33:43.160130631Z",
  "level": "INFO",
  "source": {
    "function": "go.opentelemetry.io/auto/internal/pkg/instrumentation.(*Manager).loadProbes",
    "file": "/app/internal/pkg/instrumentation/manager.go",
    "line": 374
  },
  "msg": "loading probe",
  "name": {
    "SpanKind": 3,
    "InstrumentedPkg": "net/http"
  }
}
{
  "time": "2024-12-24T16:33:43.239399298Z",
  "level": "INFO",
  "source": {
    "function": "go.opentelemetry.io/auto/internal/pkg/instrumentation.(*Manager).loadProbes",
    "file": "/app/internal/pkg/instrumentation/manager.go",
    "line": 374
  },
  "msg": "loading probe",
  "name": {
    "SpanKind": 3,
    "InstrumentedPkg": "database/sql"
  }
}
{
  "time": "2024-12-24T16:33:43.26831909Z",
  "level": "INFO",
  "source": {
    "function": "go.opentelemetry.io/auto/internal/pkg/instrumentation.(*Manager).loadProbes",
    "file": "/app/internal/pkg/instrumentation/manager.go",
    "line": 374
  },
  "msg": "loading probe",
  "name": {
    "SpanKind": 3,
    "InstrumentedPkg": "google.golang.org/grpc"
  }
}
{
  "time": "2024-12-24T16:33:43.318468673Z",
  "level": "INFO",
  "source": {
    "function": "go.opentelemetry.io/auto/internal/pkg/instrumentation.(*Manager).loadProbes",
    "file": "/app/internal/pkg/instrumentation/manager.go",
    "line": 374
  },
  "msg": "loading probe",
  "name": {
    "SpanKind": 2,
    "InstrumentedPkg": "google.golang.org/grpc"
  }
}
{
  "time": "2024-12-24T16:33:43.354612423Z",
  "level": "INFO",
  "source": {
    "function": "main.main",
    "file": "/app/cli/main.go",
    "line": 129
  },
  "msg": "instrumentation loaded successfully, starting..."
}
{
  "time": "2024-12-24T16:33:43.355024631Z",
  "level": "INFO",
  "source": {
    "function": "go.opentelemetry.io/auto/internal/pkg/instrumentation.(*Manager).ConfigLoop",
    "file": "/app/internal/pkg/instrumentation/manager.go",
    "line": 240
  },
  "msg": "Configuration provider closed, configuration updates will no longer be received"
}

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't workingresponse neededA response from the author is required

    Type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions