I am trying to enable Trace ID and Span ID for every application log. I am using opentelemtry APIs to inject and logrus labrary for logging. Below is an example code where i am able to enable trace/span entried to all logs but the trace and span id values are always 0's.
#Server.go#
package main
import (
log "github.com/sirupsen/logrus"
"fmt"
"context"
"os"
"net/http"
"go.opentelemetry.io/otel/trace"
stdout "go.opentelemetry.io/otel/exporters/stdout/stdouttrace"
sdktrace "go.opentelemetry.io/otel/sdk/trace"
"go.opentelemetry.io/otel/sdk/resource"
semconv "go.opentelemetry.io/otel/semconv/v1.10.0"
"go.opentelemetry.io/otel"
"go.opentelemetry.io/contrib/propagators/b3"
"go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp"
)
func init() {
log.SetFormatter(customLogger{
formatter: log.JSONFormatter{FieldMap: log.FieldMap{
"msg": "message",
}},
})
log.SetOutput(os.Stdout)
log.SetLevel(log.InfoLevel)
}
func initTracer() (*sdktrace.TracerProvider, error) {
exporter, err := stdout.New(stdout.WithPrettyPrint())
if err != nil {
return nil, err
}
tp := sdktrace.NewTracerProvider(
sdktrace.WithSampler(sdktrace.AlwaysSample()),
sdktrace.WithBatcher(exporter),
sdktrace.WithResource(resource.NewWithAttributes(semconv.SchemaURL, semconv.ServiceNameKey.String("PreferencesService"))),
)
otel.SetTracerProvider(tp)
b3 := b3.New()
otel.SetTextMapPropagator(b3)
return tp, err
}
func main() {
ctx := context.Background()
tp, err := initTracer()
if err != nil {
log.Error(err)
}
defer func() {
if err := tp.Shutdown(ctx); err != nil {
log.Error("Error shutting down tracer provider: %v", err)
}
}()
otelHandler := otelhttp.NewHandler(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
log.Info("About End Point Printning...")
fmt.Fprintln(w, "about page")
}),"About")
http.Handle("/about", otelHandler)
log.Info("Listening...")
log.Fatal(http.ListenAndServe(":8080", nil))
}
type customLogger struct {
formatter log.JSONFormatter
}
func (l customLogger) Format(entry *log.Entry) ([]byte, error) {
span := trace.SpanFromContext(entry.Context)
entry.Data["trace_id"] = span.SpanContext().TraceID().String()
entry.Data["span_id"] = span.SpanContext().SpanID().String()
//Below injection is Just to understand what Context has
entry.Data["Context"] = span.SpanContext()
return l.formatter.Format(entry)
}
#Client.go#
package main
import (
"fmt"
"io/ioutil"
"log"
"net/http"
)
func main() {
resp, err := http.Get("http://localhost:8080/about")
if err != nil {
log.Fatal(err)
}
defer resp.Body.Close()
body, err := ioutil.ReadAll(resp.Body)
if err != nil {
log.Fatal(err)
}
fmt.Println(string(body))
}
#Output :#
{"Context":{"TraceID":"00000000000000000000000000000000","SpanID":"0000000000000000","TraceFlags":"00","TraceState":"","Remote":false},"level":"info","message":"Listening...","span_id":"0000000000000000","time":"2022-06-30T12:34:21+05:30","trace_id":"00000000000000000000000000000000"}
{"Context":
**Below Line Should have Proper Trace ID and Span ID**
{"TraceID":"00000000000000000000000000000000","SpanID":"0000000000000000","TraceFlags":"00","TraceState":"","Remote":false},"level":"info","message":"About End Point Printning...","span_id":"0000000000000000","time":"2022-06-30T12:34:28+05:30","trace_id":"00000000000000000000000000000000"}
{
"Name": "About",
"SpanContext": {
"TraceID": "cb4dc4953a633fbe9b41c19a0870e9d6",
"SpanID": "b7346b7aba15e074",
"TraceFlags": "01",
"TraceState": "",
"Remote": false
},
"Parent": {
"TraceID": "00000000000000000000000000000000",
"SpanID": "0000000000000000",
"TraceFlags": "00",
"TraceState": "",
"Remote": false
},
"SpanKind": 2,
"StartTime": "2022-06-30T12:34:28.838523497+05:30",
"EndTime": "2022-06-30T12:34:28.838858989+05:30",
"Attributes": [
{
"Key": "net.transport",
"Value": {
"Type": "STRING",
"Value": "ip_tcp"
}
},
{
"Key": "net.peer.ip",
"Value": {
"Type": "STRING",
"Value": "127.0.0.1"
}
},
{
"Key": "net.peer.port",
"Value": {
"Type": "INT64",
"Value": 41900
}
},
{
"Key": "net.host.name",
"Value": {
"Type": "STRING",
"Value": "localhost"
}
},
{
"Key": "net.host.port",
"Value": {
"Type": "INT64",
"Value": 8080
}
},
{
"Key": "http.method",
"Value": {
"Type": "STRING",
"Value": "GET"
}
},
{
"Key": "http.target",
"Value": {
"Type": "STRING",
"Value": "/about"
}
},
{
"Key": "http.server_name",
"Value": {
"Type": "STRING",
"Value": "About"
}
},
{
"Key": "http.user_agent",
"Value": {
"Type": "STRING",
"Value": "Go-http-client/1.1"
}
},
{
"Key": "http.scheme",
"Value": {
"Type": "STRING",
"Value": "http"
}
},
{
"Key": "http.host",
"Value": {
"Type": "STRING",
"Value": "localhost:8080"
}
},
{
"Key": "http.flavor",
"Value": {
"Type": "STRING",
"Value": "1.1"
}
},
{
"Key": "http.wrote_bytes",
"Value": {
"Type": "INT64",
"Value": 11
}
},
{
"Key": "http.status_code",
"Value": {
"Type": "INT64",
"Value": 200
}
}
],
"Events": null,
"Links": null,
"Status": {
"Code": "Unset",
"Description": ""
},
"DroppedAttributes": 0,
"DroppedEvents": 0,
"DroppedLinks": 0,
"ChildSpanCount": 0,
"Resource": [
{
"Key": "service.name",
"Value": {
"Type": "STRING",
"Value": "PreferencesService"
}
}
],
"InstrumentationLibrary": {
"Name": "go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp",
"Version": "semver:0.32.0",
"SchemaURL": ""
}
}
Not Sure where/what is the mistake but it will be helpful if someone route me to the right direction, how i can inject Trace ID and Span ID to all logs..
Note: I don't want to pass request context to all the functions. Looking for other options
the problem is span := trace.SpanFromContext(entry.Context) can not get span context.
maybe you should inject req.Context() to logrus then print log
otelHandler := otelhttp.NewHandler(http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) {
//log.Info("About End Point Printning...")
// inject req.Context
log.WithContext(req.Context()).Info("About End Point Printning...")
fmt.Fprintln(w, "about page")
}), "About")
run the server.go, and then run client.go, the output is
{"Context":{"TraceID":"00000000000000000000000000000000","SpanID":"0000000000000000","TraceFlags":"00","TraceState":"","Remote":false},"level":"info","message":"Listening...","span_id":"0000000000000000","time":"2022-07-02T21:39:49+08:00","trace_id":"00000000000000000000000000000000"}
{"Context":{"TraceID":"7cab2739ea2c5b2d3e6a08cfb57858a9","SpanID":"ec5ba151b6823658","TraceFlags":"01","TraceState":"","Remote":false},"level":"info","message":"About End Point Printning...","span_id":"ec5ba151b6823658","time":"2022-07-02T21:39:54+08:00","trace_id":"7cab2739ea2c5b2d3e6a08cfb57858a9"}
notice: the first line not print traceId is because there is no request
hope it is helpful for you.