Get hands-on experience with 20+ free Google Cloud products and $300 in free credit for new customers.

Structured in Logging in AppEngine Flexible

Hi there,

I asked a question earlier today about Cloud Tracing in AppEngine Flex, so I thought I would offer an answer in return, also related to GCP Operations in AppEngine Flex, which hasn't been completely obvious.

I wanted to write out structured application logs from our Java application via java.util.Logging, and to link these logs to the nginx.request log, so that we can look at application logs per request, as we are used to doing with AppEngine Standard.

We use the java 11 runtime, declared in app.yaml. It might be different with other runtimes.

env: flex
runtime: java
runtime_config:
operating_system: "ubuntu18"
runtime_version: "11"

We use Jersey 2 and Jetty 9. We use the Gradle Shadow Jar plugin to create a single Jar that starts Jetty together with a JettyHttpContainer. 

I added the cloud logging client to the classpath:

dependencies {
implementation 'com.google.cloud:google-cloud-logging:3.15.14'
}

And created a logging.properties, in the classpath root. (src/main/resources)

The logging.properties file sets the LoggingHandler to use the version provided by the Google Cloud Logging client library:

.level=INFO
handlers=com.google.cloud.logging.LoggingHandler

com.google.cloud.logging.LoggingHandler.log=acme
com.google.cloud.logging.LoggingHandler.level=FINE
com.google.cloud.logging.LoggingHandler.flushLevel=ERROR

# Show only message and stack trace, all other details are included in the structured
# logging
com.google.cloud.logging.LoggingHandler.formatter=org.acme.server.CloudLoggingFormatter

# Enable verbose logging for our app itself
org.acme.level=FINE

I tried to specify the logging file in app.yaml file but couldn't find a way to load it from the classpath. So I add this static method to our main class:

private static void initLogging() {
try(InputStream inputStream = AppEngineFlexibleMain.class.getResourceAsStream("/logging.properties")) {
LogManager.getLogManager().readConfiguration(inputStream);
} catch (Exception e) {
System.err.println("Failed to load logging properties:");
e.printStackTrace(System.err);
}
}

And wrote a simple formatter that includes only the message and stacktrace:

public class CloudLoggingFormatter extends Formatter {

@Override
public String format(LogRecord logRecord) {
// Just include message: the rest should be included in the structured logging
String message = logRecord.getMessage();
if (logRecord.getThrown() != null) {
message = message + "\n" + Throwables.getStackTraceAsString(logRecord.getThrown());
}
return message;
}
}

This might be possible to do from logging.properties but it wasn't obvious. Sometimes code is simpler than cryptic formatting strings!

This gives us pretty nice output into the Cloud Logging console, but still doesn't link to the nginx.request logs, at least as far as I could tell.

So the last thing I needed was a Filter which read the traceId from the request header and set the thread local property of Google's LoggingHandler. The class below is a JAX-RS Request filter, but other frameworks have similar constructs:

 

@Priority(Integer.MIN_VALUE)
public class CloudLoggingFilter implements ContainerRequestFilter {

private final String tracePrefix;

public CloudLoggingFilter() {
tracePrefix = "projects/" +
ServiceOptions.getDefaultProjectId() +
"/traces/";
}

@Override
public void filter(ContainerRequestContext requestContext) throws IOException {
String context = requestContext.getHeaderString("X-Cloud-Trace-Context");
String traceId = traceIdFromContext(context);
TraceLoggingEnhancer.setCurrentTraceId(traceId);
}


private String traceIdFromContext(String context) {
if(Strings.isNullOrEmpty(context)) {
return null;
}
// The header has the following format, as documented in https://cloud.google.com/trace/docs/setup
// "X-Cloud-Trace-Context: TRACE_ID/SPAN_ID;o=TRACE_TRUE"
int traceEnd = context.indexOf('/');
if(traceEnd == -1) {
return null;
}
return tracePrefix + context.substring(0, traceEnd);
}

}

Note the use of `@Priority` to ensure it runs before other filters.

Phew. All this together gives us a way to view request application logs, nested by requests. 

 

akbertram_0-1702558745191.png

Curious if anyone has found an easier way!

Best,

Alex

0 1 533
1 REPLY 1

Top Solution Authors