Zerolog WithContext

Reference for zerolog context.Context logging.
Correlating Logs (filipnikolovski.com)

Hi,
Would you be aware of any zerolog extensions that understand temporal contexts.
In my case I have my x-correlation-id propagated to tworkflow.Context and activities context.Context
I would like to be able to get a contextual logger in the workflow the same way I can when I have a context.Context.
i.e. something like this.
logger := log.TemporalWorkflowCtx(ctx), where ctx is a tworkflowContext

Are you already including the x-correlation-id into the context using ContextPropagator? Can log.TemporalWorkflowCtx(ctx) rely on it?

I have it propagated as map[string][]string, to workflow and the activity. At the moment, it’s a full dump of the headers that came into my grpc endpoint. My grpc handler is responsible for injecting it into the ExecuteWorkflow calls. Right out of your propagation example.

I currently am getting it to work by calling the following method at the start of my workflow func

func FetchZerologContextWF(ctx temporalWorkflow.Context) context.Context {
	logger := log.With().Logger()
	loggerCtx := context.Background()
	loggerCtx = logger.WithContext(loggerCtx)
	logger2 := log.Ctx(loggerCtx)

	if val := ctx.Value(servicesTemporal.PropagateKey); val != nil {
		md := val.(servicesTemporal.Values)
		items := md["X-Correlation-Id"]
		if items != nil && len(items) > 0 {
			logger2.UpdateContext(func(c zerolog.Context) zerolog.Context {
				return c.Str("correlation_id", items[0])
			})
		}
	}
	return loggerCtx
}
func GreetingWorkflow(ctx temporalWorkflow.Context, name string) (string, error) {
	loggerCtx := FetchZerologContextWF(ctx)
	logger := log.Ctx(loggerCtx)
	logger.Info().Msg("hi")
...
}

And for my activities.

func FetchZerologContextAct(ctx context.Context) context.Context {
	logger := log.With().Logger()
	ctx = logger.WithContext(ctx)
	logger2 := log.Ctx(ctx)

	if val := ctx.Value(servicesTemporal.PropagateKey); val != nil {
		values := val.(servicesTemporal.Values)
		items := values["X-Correlation-Id"]
		if items != nil && len(items) > 0 {
			logger2.UpdateContext(func(c zerolog.Context) zerolog.Context {
				return c.Str("correlation_id", items[0])
			})
		}
	}
	return ctx
}

I need to research what form the propagated data needs to take to work with log.TemporalWorkflowCtx(ctx)

I’m not sure I understand the question. You have to copy code from log.Ctx to log.TemporalWorkflowCtx and replace the context type with workflow.Context.

If I want zerolog contextual logging, I set that up in my grpc middleware to put a logger into the context and then another middleware to harvest or create an x-correlation-id and associate it that logger.

After that, you can pull the logger from the context.Context and it will automatically log the correlationID.

What temporal context gives me with propagation is just the header values, but no logger. I was speculating that I could have a custom propagator that puts an instance of zerolog into the workflow context.

The code I posted is a hacked-up version of what I have going on in plain grpc middleware services.
I would rather pull the logger from temporalWorkflow.Context

Any reason you cannot insert the logger itself from the context propagator into the workflow context?

doing that experiment as we speak, and it works
Progator code.

// ExtractToWorkflow extracts values from headers and puts them into context
func (s *propagator) ExtractToWorkflow(ctx workflow.Context, reader workflow.HeaderReader) (workflow.Context, error) {
	if value, ok := reader.Get(propagationKey); ok {
		var values Values
		if err := converter.GetDefaultDataConverter().FromPayload(value, &values); err != nil {
			return ctx, nil
		}
		ctx = workflow.WithValue(ctx, PropagateKey, values)

		items := values["X-Correlation-Id"]
		logger := log.With().Logger()
		if items != nil && len(items) > 0 {
			logger.UpdateContext(func(c zerolog.Context) zerolog.Context {
				return c.Str("correlation_id", items[0])
			})
		}
		ctx = workflow.WithValue(ctx, ZerologKey, &logger)
	}
	return ctx, nil
}
 

In the workflow func

func contextLogger(ctx temporalWorkflow.Context) *zerolog.Logger {
	if val := ctx.Value(servicesTemporal.ZerologKey); val != nil {
		logger := val.(*zerolog.Logger)
		return logger
	}
	logger := log.With().Logger()
	return &logger
}
func GreetingWorkflow(ctx temporalWorkflow.Context, name string) (string, error) {
	logger := contextLogger(ctx)
 	logger.Info().Msg("hi")
...
}

Output:

{"level":"info","correlation_id":"58074078-3eec-4800-a8c5-7ec9c51fb00f","time":"2021-05-11T11:56:35-07:00","message":"hi"}

Note that the workflow.GetLogger returns a logger instance that doesn’t log on replay. If you are not OK with duplicated log entries then you have to add logic related to this.

btw: Hooking up the zerolog to the activity’s context is nice, as I can use the zerolog helpers and it makes my activites look like a normal grcp func. I guess in temporal speak, the propagators are middleware.

the ctx = logger.WithContext(ctx) is the zerolog helper and what I use in my grcp middleware.

// Extract extracts values from headers and puts them into context
func (s *propagator) Extract(ctx context.Context, reader workflow.HeaderReader) (context.Context, error) {
	if value, ok := reader.Get(propagationKey); ok {
		var values Values
		if err := converter.GetDefaultDataConverter().FromPayload(value, &values); err != nil {
			return ctx, nil
		}
		ctx = context.WithValue(ctx, PropagateKey, values)
		items := values["X-Correlation-Id"]
		logger := log.With().Logger()
		if items != nil && len(items) > 0 {
			logger.UpdateContext(func(c zerolog.Context) zerolog.Context {
				return c.Str("correlation_id", items[0])
			})
		}
		ctx = logger.WithContext(ctx)

	}

	return ctx, nil
}

my Activity

func ComposeGreeting(ctx context.Context, name string) (string, error) {
	logger := log.Ctx(ctx)
	logger.Info().Msg("hi ")

	greeting := fmt.Sprintf("Hello %s!", name)

	return greeting, nil
}
1 Like