logcontext-v2 does not work with Serverless / nrlambda

[mariusgrigaitis]

Description

No context is attached to log messages. No information in debug messages from agent itself on why.

Setup: go-agent + nrlambda + logcontext-v2 + https://github.com/newrelic/newrelic-lambda-extension + logrus

Steps to Reproduce

1. Run setup
2. Notice that context is not added on logs

Expected Behavior

Context is added to log messages of lambda as well.

Why?

go-agent/v3/newrelic/log_event.go

Line 189 in 72ecc0e

if md.entityGUID == "" || md.entityName == "" || md.hostname == "" {

skips adding context if EntityGUID is empty or App Name is empty which is true in case of serverless.

Also does it silently.

EntityGUID is empty because no actual agent connection happens in case of serverless

go-agent/v3/newrelic/internal_app.go

Line 453 in 72ecc0e

if app.config.ServerlessMode.Enabled {

[cojoj]

To give more context (pun intended), the whole setup is correct, and behind the scenes, it works as expected, meaning:

1. Transaction is correctly created a propagated when the lambda is invoked.
2. Distributed Tracing in UI shows all components - Logs are correctly displayed under the Trace Details UI.
3. When I'd extract the data manually it's available just fine, and I can push it to logs:

log.WithField("trace_metadata", txn.GetTraceMetadata()).Debug("testing NR trace data")

---

Additionally, I'm adding here a sample code showing how we did the integration:

package main

import (
	"context"
	"fmt"

	"github.com/aws/aws-lambda-go/events"
	"github.com/newrelic/go-agent/v3/integrations/logcontext-v2/nrlogrus"
	"github.com/newrelic/go-agent/v3/integrations/nrlambda"
	"github.com/newrelic/go-agent/v3/newrelic"
	"github.com/sirupsen/logrus"
)

func main() {
	app, err := newrelic.NewApplication(
		nrlambda.ConfigOption(),
		newrelic.ConfigAppLogDecoratingEnabled(true),
	)

	if nil != err {
		fmt.Println("error creating app (invalid config):", err)
	}

	logrus.SetFormatter(nrlogrus.NewFormatter(app, &logrus.TextFormatter{}))
	logrus.SetLevel(logrus.TraceLevel)

	nrlambda.Start(handle, app)
}

func handle(ctx context.Context, snsEvent events.SNSEvent) {
	log := logrus.WithContext(ctx)
	log.Debug("testing logging with context")
}

[iamemilio]

Yeah, so this is a bit of a documentation gap IMO. When the agent is running in server less mode, logs in context is not supported in the agent. We expect users to instead collect logs through either the newrelic-lambda-extension, or the cloud watch-log-ingestion lambda function. All agents disable their internal logs in context when running in server less mode.

[iamemilio]

Thanks for really digging into the root cause of this though, this is a very well reported issue.

[cojoj]

@iamemilio so what are our possibilities now? What's the preferred way (if you could share the links). And does it mean that by design we can't have a correlation between Logs and Transactions in case of serverless integrations?

[iamemilio]

From what I understand, I don't think logs in context is fully supported in serverless environments right now, unfortunately. It's a bit more of a complicated situation than it seem on the face of it because there is information that is essential to how logs get linked "in context" that is missing in a serverless environment. You can use the newrelic-lambda-extension, or the cloud watch ingestion function to gather logs from AWS and send them to newrelic. That does add some additional metadata, but it's not equivalent to the logs in context feature. This is something that impacts all agents, and if it's important to you, I would recommend getting in touch with New Relic Support and filing a feature request.

[iamemilio]

cc @ak-war

[cojoj]

I mean, I found a way to do it, but it requires a manual injection of Transaction metadata to the logs based on the logs in context v1. I've added those two functions to our codebase:

func WithContext(ctx context.Context) *logrus.Entry {
	log := logrus.WithContext(ctx)
	txn := newrelic.FromContext(ctx)

	return appendNewRelicFields(txn, log)
}

func appendNewRelicFields(txn *newrelic.Transaction, log *logrus.Entry) *logrus.Entry {
	md := txn.GetLinkingMetadata()
	log = log.WithFields(
		logrus.Fields{
			logcontext.KeyTraceID:    md.TraceID,
			logcontext.KeySpanID:     md.SpanID,
			logcontext.KeyEntityName: md.EntityName,
			logcontext.KeyEntityType: md.EntityType,
			logcontext.KeyEntityGUID: md.EntityGUID,
			logcontext.KeyHostname:   md.Hostname,
		},
	)

	return log
}

And that gets me wondering, why it was disabled in v2? Because I feel we're missing some background to understand the reasoning behind it 🤔

[iamemilio]

Yeah, in theory we could enable local log decoration in serverless environments, which would always append any linking transaction, entity, and span data. But when the agent is running in serverless mode, the entity is unknown to the agent. The linking to the New Relic entity is normally done during the connect process in agents, but serverless apps skip that step to save time. Instead there is a special backend pipeline that they send data to that links data and logs to New Relic entities. We would probably have to modify this backend pipeline to be able to handle decorated log lines properly. While it might be possible, it's not something the agents are allowed to do and it's pretty much 100% untested on our end. If you wanted to try it and see if the backend can accept decorated logs, you're welcome to fork the agent at your own risk, give it a go, and let us know what your findings are. I don't think it would be dangerous, but it may not work the way you want it to. Otherwise, I pinged our PM here and we can track this as a potential roadmap item in the future and hope to come back with an agent wide solution if its possible.

[mariusgrigaitis]

@iamemilio I see a few ways of resolving the issue.

1. Documenting logcontext approach.
   Currently it's not clear about if it's support or not. If you use it, it silently does not do anything. Documentation for what should be used in serverless context is unclear. These are the issues that could be fixed by documenting, improving error handling (or configuration handling) on the agent side. What I also don't like is there being two logcontext standards and not knowing what's current and what should be used. Should not be the case, one should be deprecated.

2. Treating serverless applications as first-class citizens in New Relic. Currently it's quite tricky to get it right. There is some development on the topic, I agree, but in the end there are issues in the current approach taken where it's not really production ready (timeouts) or some of the features don't work (logcontext). In the end, serverless applications are usually very similar to APM applications, apart from there being multiple dynamic backends. Therefore I don't see that there should be big differences in integrations.

I also understand that there are some complexities in terms of mapping things, knowing EntityGUIDs. However that's also a problem for short-lived processes (e.g. take console application or examples where you wait for connection to NewRelic to get EntityGUID).

What I would love to see is NewRelic taking more strategic direction:

1. Making serverless applications first-class citizens of NewRelic
2. Making NewRelic work with short-lived processes

I believe for both there are some ideas that could be pursued like for example enhancing Ingest APIs where those would infer Entity from Ingest Key as an example. It could also lead to simplifications on how NewRelic works. As an example for why it would be a simplification is look at the query NewRelic makes for Logs when it involves Serverless application. While technically it could just be a filter for trace.id and or EntityGuid, it now requires AWS RequestID, etc which does not work in more complicated cases.

Sorry for a long text, but looking forward for a more strategical approach. I will also bring this up to our Account Executive.

[iamemilio]

These are all good points. I can see if we can issue a deprecation of the outdated log context standard/packaging. In terms of company strategy on short lived processes and lambda, that is firmly out of my control. Please do bring it up with your representatives at New Relic. That helps us gauge interest, and makes issues more visible to our leadership who ultimately decide how to steer the product. That might be something @ak-war could help you with as well.

[adomaskizogian]

@iamemilio

Otherwise, I pinged our PM here and we can track this as a potential roadmap item in the future and hope to come back with an agent wide solution if its possible.

It's been quite some time. Any updates?