adservice: enable structured logging and OpenCensus log correlation (#59)

This commit enables OpenCensus log correlation using
opencensus-contrib-log-correlation-log4j2
(https://github.com/census-instrumentation/opencensus-java/tree/master/contrib/log_correlation/log4j2).
The library inserts the trace ID, span ID, and sampling decision into every
Log4j log event.  This commit includes other changes to make the tracing data
available in the logs, in a format that can be interpreted by the Stackdriver
Logging agent:

- Convert all adservice log statements from java.util.logging to Log4j.

- Specify a JSON format for Log4j output.  This is related to issue #47.

- Add the trace ID, span ID, and sampling decision to the JSON format.  Trace
  ID and span ID use special keys that the Stackdriver Logging agent uses to
  populate the tracing data fields in the LogEntry uploaded to Stackdriver
  (https://cloud.google.com/logging/docs/agent/configuration#special_fields_in_structured_payloads).
  However, Stackdriver won't be able to link the traces and log entries until
  fluent-plugin-google-cloud can automatically format the trace ID with the
  format expected by Stackdriver
  (https://github.com/GoogleCloudPlatform/fluent-plugin-google-cloud/issues/239,
  https://github.com/GoogleCloudPlatform/fluent-plugin-google-cloud/pull/260).

This commit also upgrades OpenCensus to 0.16.1 in order to use
opencensus-contrib-log-correlation-log4j2.
This commit is contained in:
sebright 2018-10-01 22:45:09 -07:00 committed by Ahmet Alp Balkan
parent dc7effd601
commit 848d4bbe90
4 changed files with 51 additions and 16 deletions

View File

@ -25,8 +25,9 @@ repositories {
group = "adservice"
version = "0.1.0-SNAPSHOT" // CURRENT_OPENCENSUS_VERSION
def opencensusVersion = "0.15.0" // LATEST_OPENCENSUS_RELEASE_VERSION
def opencensusVersion = "0.16.1" // LATEST_OPENCENSUS_RELEASE_VERSION
def grpcVersion = "1.15.0" // CURRENT_GRPC_VERSION
def jacksonVersion = "2.9.6"
def prometheusVersion = "0.3.0"
tasks.withType(JavaCompile) {
@ -52,9 +53,13 @@ dependencies {
"io.grpc:grpc-stub:${grpcVersion}",
"io.grpc:grpc-netty:${grpcVersion}",
"io.grpc:grpc-services:${grpcVersion}",
"io.prometheus:simpleclient_httpserver:${prometheusVersion}"
"io.prometheus:simpleclient_httpserver:${prometheusVersion}",
"org.apache.logging.log4j:log4j-core:2.11.1"
runtime "io.opencensus:opencensus-impl:${opencensusVersion}",
runtime "com.fasterxml.jackson.core:jackson-core:${jacksonVersion}",
"com.fasterxml.jackson.core:jackson-databind:${jacksonVersion}",
"io.opencensus:opencensus-contrib-log-correlation-log4j2:${opencensusVersion}",
"io.opencensus:opencensus-impl:${opencensusVersion}",
"io.netty:netty-tcnative-boringssl-static:2.0.8.Final"
}
}
@ -106,6 +111,8 @@ task adService(type: CreateStartScripts) {
applicationName = 'AdService'
outputDir = new File(project.buildDir, 'tmp')
classpath = jar.outputs.files + project.configurations.runtime
defaultJvmOpts =
["-Dlog4j2.contextDataInjector=io.opencensus.contrib.logcorrelation.log4j2.OpenCensusTraceContextDataInjector"]
}
task adServiceClient(type: CreateStartScripts) {
@ -113,6 +120,8 @@ task adServiceClient(type: CreateStartScripts) {
applicationName = 'AdServiceClient'
outputDir = new File(project.buildDir, 'tmp')
classpath = jar.outputs.files + project.configurations.runtime
defaultJvmOpts =
["-Dlog4j2.contextDataInjector=io.opencensus.contrib.logcorrelation.log4j2.OpenCensusTraceContextDataInjector"]
}
applicationDistribution.into('bin') {

View File

@ -50,11 +50,12 @@ import java.util.HashMap;
import java.util.List;
import java.util.Random;
import java.util.concurrent.TimeUnit;
import java.util.logging.Level;
import java.util.logging.Logger;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.LogManager;
public class AdService {
private static final Logger logger = Logger.getLogger(AdService.class.getName());
private static final Logger logger = LogManager.getLogger(AdService.class);
private static final Tracer tracer = Tracing.getTracer();
@ -139,7 +140,7 @@ public class AdService {
responseObserver.onNext(reply);
responseObserver.onCompleted();
} catch (StatusRuntimeException e) {
logger.log(Level.WARNING, "GetAds Failed", e.getStatus());
logger.log(Level.WARN, "GetAds Failed", e.getStatus());
return;
}
}
@ -218,7 +219,7 @@ public class AdService {
.build());
} catch (Exception e) {
if (i==(maxAttempts-1)) {
logger.log(Level.WARNING, "Failed to register Stackdriver Exporter." +
logger.log(Level.WARN, "Failed to register Stackdriver Exporter." +
" Tracing and Stats data will not reported to Stackdriver. Error message: " + e
.toString());
} else {
@ -226,7 +227,7 @@ public class AdService {
try {
Thread.sleep(TimeUnit.SECONDS.toMillis(sleepTime));
} catch (Exception se) {
logger.log(Level.WARNING, "Exception while sleeping" + se.toString());
logger.log(Level.WARN, "Exception while sleeping" + se.toString());
}
}
}

View File

@ -38,13 +38,14 @@ import io.opencensus.trace.Tracing;
import io.opencensus.trace.samplers.Samplers;
import java.io.IOException;
import java.util.concurrent.TimeUnit;
import java.util.logging.Level;
import java.util.logging.Logger;
import javax.annotation.Nullable;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.LogManager;
/** A simple client that requests ads from the Ads Service. */
public class AdServiceClient {
private static final Logger logger = Logger.getLogger(AdServiceClient.class.getName());
private static final Logger logger = LogManager.getLogger(AdServiceClient.class);
private static final Tracer tracer = Tracing.getTracer();
@ -90,7 +91,7 @@ public class AdServiceClient {
CanonicalCode.valueOf(e.getStatus().getCode().name())
.toStatus()
.withDescription(e.getMessage()));
logger.log(Level.WARNING, "RPC failed: {0}", e.getStatus());
logger.log(Level.WARN, "RPC failed: {0}", e.getStatus());
return;
}
for(Ad ads: response.getAdsList()) {
@ -104,7 +105,7 @@ public class AdServiceClient {
try {
portNumber = Integer.parseInt(args[index]);
} catch (NumberFormatException e) {
logger.warning(
logger.warn(
String.format("Port %s is invalid, use default port %d.", args[index], defaultPort));
}
}
@ -156,7 +157,7 @@ public class AdServiceClient {
.build());
} catch (Exception e) {
if (i==(maxAttempts-1)) {
logger.log(Level.WARNING, "Failed to register Stackdriver Exporter." +
logger.log(Level.WARN, "Failed to register Stackdriver Exporter." +
" Tracing and Stats data will not reported to Stackdriver. Error message: " + e
.toString());
} else {
@ -164,7 +165,7 @@ public class AdServiceClient {
try {
Thread.sleep(TimeUnit.SECONDS.toMillis(sleepTime));
} catch (Exception se) {
logger.log(Level.WARNING, "Exception while sleeping" + e.toString());
logger.log(Level.WARN, "Exception while sleeping" + e.toString());
}
}
}

View File

@ -0,0 +1,24 @@
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN">
<Appenders>
<Console name="STDOUT" target="SYSTEM_OUT">
<!-- This is a JSON format that can be read by the Stackdriver Logging agent. The trace and
span IDs are interpreted by Stackdriver, and "traceSampled" is a custom field. -->
<JsonLayout compact="true" eventEol="true">
<KeyValuePair key="logging.googleapis.com/trace" value="$${ctx:opencensusTraceId}"/>
<KeyValuePair key="logging.googleapis.com/spanId" value="$${ctx:opencensusSpanId}"/>
<KeyValuePair key="traceSampled" value="$${ctx:opencensusTraceSampled}"/>
</JsonLayout>
</Console>
</Appenders>
<Loggers>
<Logger name="io.grpc.netty" level="INFO"/>
<Logger name="io.netty" level="INFO"/>
<Logger name="sun.net" level="INFO"/>
<Root level="TRACE">
<AppenderRef ref="STDOUT"/>
</Root>
</Loggers>
</Configuration>