Internal logger.Emit delegate never gets loaded

[zergeborg]

Internal logger.Emit delegate never gets loaded

[MrAlias]

Can you provide a minimal example to reproduce the issue?

[zergeborg]

I tried to put an example together. I created a completely new go project and the symptom is the same:

package main

import (
	"context"
	"errors"
	"net/http"
	"time"

	texporter "github.com/GoogleCloudPlatform/opentelemetry-operations-go/exporter/trace"
	"github.com/labstack/echo/v4"
	"github.com/labstack/echo/v4/middleware"
	"github.com/uptrace/opentelemetry-go-extra/otelzap"
	"go.opentelemetry.io/contrib/detectors/gcp"
	"go.opentelemetry.io/contrib/instrumentation/github.com/labstack/echo/otelecho"
	"go.opentelemetry.io/otel"
	"go.opentelemetry.io/otel/attribute"
	"go.opentelemetry.io/otel/sdk/resource"
	sdktrace "go.opentelemetry.io/otel/sdk/trace"
	semconv "go.opentelemetry.io/otel/semconv/v1.4.0"
	"go.opentelemetry.io/otel/trace"
	"go.uber.org/zap"
)

var otellogger *otelzap.Logger

func main() {

	ctx, _ := context.WithCancel(context.Background())

	logger := zap.NewNop()

	exporter, err := texporter.New(texporter.WithProjectID("YOUR-GCP-PROJECT-ID"))
	if err != nil {
		logger.Fatal("texporter.New: ", zap.Error(err))
	}

	// Identify your application using resource detection
	res, err := resource.New(ctx,
		// Use the GCP resource detector to detect information about the GCP platform
		resource.WithDetectors(gcp.NewDetector()),
		// Keep the default detectors
		resource.WithTelemetrySDK(),
		// Add your own custom attributes to identify your application
		resource.WithAttributes(
			semconv.ServiceNameKey.String("any-service"),
		),
	)
	if errors.Is(err, resource.ErrPartialResource) || errors.Is(err, resource.ErrSchemaURLConflict) {
		logger.Info("error: ", zap.Error(err))
	} else if err != nil {
		logger.Fatal("resource.New: ", zap.Error(err))
	}

	// Create trace provider with the exporter.
	//
	// By default it uses AlwaysSample() which samples all traces.
	// In a production environment or high QPS setup please use
	// probabilistic sampling.
	// Example:
	//   tp := sdktrace.NewTracerProvider(sdktrace.WithSampler(sdktrace.TraceIDRatioBased(0.0001)), ...)
	tp := sdktrace.NewTracerProvider(
		sdktrace.WithBatcher(exporter),
		sdktrace.WithResource(res),
	)
	defer tp.Shutdown(ctx) // flushes any pending spans, and closes connections.
	otel.SetTracerProvider(tp)

	otellogger = otelzap.New(logger,
		otelzap.WithMinLevel(zap.DebugLevel),
		otelzap.WithErrorStatusLevel(zap.ErrorLevel),
	)

	server := echo.New()

	server.Use(middleware.Logger())
	server.Use(otelecho.Middleware("any-service-echo"))

	server.Use(middleware.RequestID())

	server.Use(func(next echo.HandlerFunc) echo.HandlerFunc {
		return func(c echo.Context) error {
			timeoutCtx, cancel := context.WithTimeout(c.Request().Context(), time.Duration(600)*time.Second)
			c.SetRequest(c.Request().WithContext(timeoutCtx))
			defer cancel()
			return next(c)
		}
	})

	server.POST("/", HandleRequest)

	defer server.Close()

	server.Start(":8080")
}

func HandleRequest(c echo.Context) error {
	requestTrackingID := c.Response().Header().Get(echo.HeaderXRequestID)

	tracer := otel.GetTracerProvider().Tracer("any-service-trace")

	origCtx := c.Request().Context()

	ctx, span := tracer.Start(origCtx, "HandleRequest",
		trace.WithAttributes(attribute.String(echo.HeaderXRequestID, requestTrackingID)),
		trace.WithNewRoot(),
	)
	defer span.End()

	otellogger.Ctx(ctx).Info("Handling request")

	return c.Blob(http.StatusOK, "text/plain", []byte("Here is a result...."))
}

You can test this locally by sending any POST request to port 8080. I hope this helps

[pellared]

You have forgotten to set the https://pkg.go.dev/github.com/uptrace/opentelemetry-go-extra/otelzap#WithLoggerProvider option.

[zergeborg]

@pellared Thank you for your quick response.

I tried your suggestion, but it didn't change anything. Now my code creates the zap logger as follows:

	otellogger = otelzap.New(logger,
		otelzap.WithMinLevel(zap.DebugLevel),
		otelzap.WithErrorStatusLevel(zap.ErrorLevel),
		otelzap.WithLoggerProvider(global.GetLoggerProvider()),
	)

But the bug remains the same. The delegate stays unloaded and the logger never emits

[dmathieu]

otelzap.WithLoggerProvider(global.GetLoggerProvider())

This does nothing. It uses the global logger provided, which is not set.
Also, if you look at the doc for WithLoggerProvider, you will see that this option defaults to the global logger provider already.

You need to create and configure a logger provider.

opentelemetry-go/example/dice/otel.go

Lines 114 to 124 in 91a8c5f

	func newLoggerProvider() (*log.LoggerProvider, error) {
	logExporter, err := stdoutlog.New()
	if err != nil {
	return nil, err
	}
	loggerProvider := log.NewLoggerProvider(
	log.WithProcessor(log.NewBatchProcessor(logExporter)),
	)
	return loggerProvider, nil
	}

The provider is this example is configured to send its data to stdout, but you will be able to configure the otlp exporter once it is available if you wish.

And then, either set it as global, or pass it to otelzap with WithLoggerProvider.

opentelemetry-go/example/dice/otel.go

Line 73 in 91a8c5f

global.SetLoggerProvider(loggerProvider)

[zergeborg]

Thank you @dmathieu Indeed that was the problem. After I applied your suggestion, the logs started working, I can see the output in stdout, so I will close the issue.