Skip to content

Initial tracing #15

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 6 commits into from
Aug 7, 2020
Merged
Show file tree
Hide file tree
Changes from 4 commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
49 changes: 48 additions & 1 deletion example/HelloWorldFunction/src/main/java/helloworld/App.java
Original file line number Diff line number Diff line change
Expand Up @@ -12,10 +12,17 @@
import com.amazonaws.services.lambda.runtime.RequestHandler;
import com.amazonaws.services.lambda.runtime.events.APIGatewayProxyRequestEvent;
import com.amazonaws.services.lambda.runtime.events.APIGatewayProxyResponseEvent;
import com.amazonaws.xray.AWSXRay;
import com.amazonaws.xray.entities.Entity;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import software.aws.lambda.logging.PowerLogger;
import software.aws.lambda.logging.PowerToolsLogging;
import software.aws.lambda.tracing.PowerToolTracing;
import software.aws.lambda.tracing.PowerTracer;

import static software.aws.lambda.tracing.PowerTracer.putMetadata;
import static software.aws.lambda.tracing.PowerTracer.withEntitySubsegment;

/**
* Handler for requests to Lambda function.
Expand All @@ -25,6 +32,7 @@ public class App implements RequestHandler<APIGatewayProxyRequestEvent, APIGatew
Logger log = LogManager.getLogger();

@PowerToolsLogging(logEvent = true)
@PowerToolTracing
public APIGatewayProxyResponseEvent handleRequest(final APIGatewayProxyRequestEvent input, final Context context) {
Map<String, String> headers = new HashMap<>();
headers.put("Content-Type", "application/json");
Expand All @@ -37,21 +45,60 @@ public APIGatewayProxyResponseEvent handleRequest(final APIGatewayProxyRequestEv
try {
final String pageContents = this.getPageContents("https://checkip.amazonaws.com");
log.info(pageContents);
PowerTracer.putAnnotation("Test", "New");
String output = String.format("{ \"message\": \"hello world\", \"location\": \"%s\" }", pageContents);

PowerTracer.withSubsegment("loggingResponse", subsegment -> {
String sampled = "log something out";
log.info(sampled);
log.info(output);
});

threadOption1();

threadOption2();

log.info("After output");
return response
.withStatusCode(200)
.withBody(output);
} catch (IOException e) {
} catch (IOException | InterruptedException e) {
return response
.withBody("{}")
.withStatusCode(500);
}
}

private void threadOption1() throws InterruptedException {
Entity traceEntity = AWSXRay.getTraceEntity();
Thread thread = new Thread(() -> {
AWSXRay.setTraceEntity(traceEntity);
log();
});
thread.start();
thread.join();
}

private void threadOption2() throws InterruptedException {
Entity traceEntity = AWSXRay.getTraceEntity();
Thread anotherThread = new Thread(() -> withEntitySubsegment("inlineLog", traceEntity, subsegment -> {
String var = "somethingToProcess";
log.info("inside threaded logging inline {}", var);
}));
anotherThread.start();
anotherThread.join();
}

@PowerToolTracing
private void log() {
log.info("inside threaded logging for function");
}


@PowerToolTracing(namespace = "getPageContents", captureResponse = false, captureError = false)
private String getPageContents(String address) throws IOException {
URL url = new URL(address);
putMetadata("getPageContents", address);
try (BufferedReader br = new BufferedReader(new InputStreamReader(url.openStream()))) {
return br.lines().collect(Collectors.joining(System.lineSeparator()));
}
Expand Down
4 changes: 3 additions & 1 deletion example/template.yaml
Original file line number Diff line number Diff line change
Expand Up @@ -20,7 +20,8 @@ Resources:
MemorySize: 512
Environment: # More info about Env Vars: https://github.com/awslabs/serverless-application-model/blob/master/versions/2016-10-31.md#environment-object
Variables:
PARAM1: VALUE
POWERTOOLS_SERVICE_NAME: SAILING
Tracing: Active
Events:
HelloWorld:
Type: Api # More info about API Event Source: https://github.com/awslabs/serverless-application-model/blob/master/versions/2016-10-31.md#api
Expand All @@ -35,6 +36,7 @@ Resources:
Handler: helloworld.AppStream::handleRequest
Runtime: java8
MemorySize: 512
Tracing: Active
Environment:
Variables:
PARAM1: VALUE
Expand Down
26 changes: 26 additions & 0 deletions pom.xml
Original file line number Diff line number Diff line change
Expand Up @@ -42,6 +42,7 @@
<log4j.version>2.13.3</log4j.version>
<jackson.version>2.11.0</jackson.version>
<aspectj.version>1.9.6</aspectj.version>
<aws.xray.recorder.version>2.4.0</aws.xray.recorder.version>
<project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
</properties>

Expand Down Expand Up @@ -83,6 +84,31 @@
<artifactId>aspectjrt</artifactId>
<version>${aspectj.version}</version>
</dependency>
<dependency>
<groupId>com.amazonaws</groupId>
<artifactId>aws-xray-recorder-sdk-core</artifactId>
<version>${aws.xray.recorder.version}</version>
</dependency>
<dependency>
<groupId>com.amazonaws</groupId>
<artifactId>aws-xray-recorder-sdk-aws-sdk</artifactId>
<version>${aws.xray.recorder.version}</version>
</dependency>
<dependency>
<groupId>com.amazonaws</groupId>
<artifactId>aws-xray-recorder-sdk-aws-sdk-instrumentor</artifactId>
<version>${aws.xray.recorder.version}</version>
</dependency>
<dependency>
<groupId>com.amazonaws</groupId>
<artifactId>aws-xray-recorder-sdk-aws-sdk-v2</artifactId>
<version>${aws.xray.recorder.version}</version>
</dependency>
<dependency>
<groupId>com.amazonaws</groupId>
<artifactId>aws-xray-recorder-sdk-aws-sdk-v2-instrumentor</artifactId>
<version>${aws.xray.recorder.version}</version>
</dependency>

<!-- Test dependencies -->
<dependency>
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,29 @@
package software.aws.lambda.internal;

import java.io.InputStream;
import java.io.OutputStream;

import com.amazonaws.services.lambda.runtime.Context;
import com.amazonaws.services.lambda.runtime.RequestHandler;
import com.amazonaws.services.lambda.runtime.RequestStreamHandler;
import org.aspectj.lang.ProceedingJoinPoint;

public final class LambdaHandlerProcessor {
public static boolean isHandlerMethod(ProceedingJoinPoint pjp) {
return "handleRequest".equals(pjp.getSignature().getName());
}

public static boolean placedOnRequestHandler(ProceedingJoinPoint pjp) {
return RequestHandler.class.isAssignableFrom(pjp.getSignature().getDeclaringType())
&& pjp.getArgs().length == 2
&& pjp.getArgs()[1] instanceof Context;
}

public static boolean placedOnStreamHandler(ProceedingJoinPoint pjp) {
return RequestStreamHandler.class.isAssignableFrom(pjp.getSignature().getDeclaringType())
&& pjp.getArgs().length == 3
&& pjp.getArgs()[0] instanceof InputStream
&& pjp.getArgs()[1] instanceof OutputStream
&& pjp.getArgs()[2] instanceof Context;
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -10,8 +10,6 @@
import java.util.Optional;

import com.amazonaws.services.lambda.runtime.Context;
import com.amazonaws.services.lambda.runtime.RequestHandler;
import com.amazonaws.services.lambda.runtime.RequestStreamHandler;
import com.fasterxml.jackson.databind.ObjectMapper;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
Expand All @@ -25,6 +23,9 @@

import static java.util.Optional.empty;
import static java.util.Optional.of;
import static software.aws.lambda.internal.LambdaHandlerProcessor.isHandlerMethod;
import static software.aws.lambda.internal.LambdaHandlerProcessor.placedOnRequestHandler;
import static software.aws.lambda.internal.LambdaHandlerProcessor.placedOnStreamHandler;

@Aspect
public final class LambdaAspect {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can this be renamed to LambdaLoggingAspect

Expand All @@ -35,7 +36,7 @@ public final class LambdaAspect {
public void callAt(PowerToolsLogging powerToolsLogging) {
}

@Around(value = "callAt(powerToolsLogging)", argNames = "pjp,powerToolsLogging")
@Around(value = "callAt(powerToolsLogging) && execution(@PowerToolsLogging * *.*(..))", argNames = "pjp,powerToolsLogging")
public Object around(ProceedingJoinPoint pjp,
PowerToolsLogging powerToolsLogging) throws Throwable {
Object[] proceedArgs = pjp.getArgs();
Expand Down Expand Up @@ -113,19 +114,4 @@ private Object[] logFromInputStream(ProceedingJoinPoint pjp) {
private Logger logger(ProceedingJoinPoint pjp) {
return LogManager.getLogger(pjp.getSignature().getDeclaringType());
}

private boolean isHandlerMethod(ProceedingJoinPoint pjp) {
return "handleRequest".equals(pjp.getSignature().getName());
}

private boolean placedOnRequestHandler(ProceedingJoinPoint pjp) {
return RequestHandler.class.isAssignableFrom(pjp.getSignature().getDeclaringType())
&& pjp.getArgs().length == 2 && pjp.getArgs()[1] instanceof Context;
}

private boolean placedOnStreamHandler(ProceedingJoinPoint pjp) {
return RequestStreamHandler.class.isAssignableFrom(pjp.getSignature().getDeclaringType())
&& pjp.getArgs().length == 3 && pjp.getArgs()[0] instanceof InputStream
&& pjp.getArgs()[2] instanceof Context;
}
}
14 changes: 14 additions & 0 deletions src/main/java/software/aws/lambda/tracing/PowerToolTracing.java
Original file line number Diff line number Diff line change
@@ -0,0 +1,14 @@
package software.aws.lambda.tracing;

import java.lang.annotation.ElementType;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;

@Retention(RetentionPolicy.RUNTIME)
@Target(ElementType.METHOD)
public @interface PowerToolTracing {
String namespace() default "";
boolean captureResponse() default true;
boolean captureError() default true;
}
43 changes: 43 additions & 0 deletions src/main/java/software/aws/lambda/tracing/PowerTracer.java
Original file line number Diff line number Diff line change
@@ -0,0 +1,43 @@
package software.aws.lambda.tracing;

import java.util.function.Consumer;

import com.amazonaws.xray.AWSXRay;
import com.amazonaws.xray.entities.Entity;
import com.amazonaws.xray.entities.Subsegment;

public final class PowerTracer {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Helper utils for setting annotation and metadata on current segment

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can we directly do a good Javadoc documentation?
for info, we will extract all javadoc in order to generate our own documentation website and make it publicly available

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I belive its too early to spend effort on writing java docs. IMO we can delay it a bit until we have a but more structure

public static final String SERVICE_NAME = null != System.getenv("POWERTOOLS_SERVICE_NAME")
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In the python impl this is "service_undefined" by default. Might be worth matching their project for consistency.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Xray recorder lib by default uses:

private static final String DEFAULT_METADATA_NAMESPACE = "default";

But i can update it to match with that of powertools.

? System.getenv("POWERTOOLS_SERVICE_NAME") : "service_undefined";

public static void putAnnotation(String key, String value) {
AWSXRay.getCurrentSubsegmentOptional()
.ifPresent(segment -> segment.putAnnotation(key, value));
}

public static void putMetadata(String key, Object value) {
String namespace = AWSXRay.getCurrentSubsegmentOptional()
.map(Subsegment::getNamespace).orElse(SERVICE_NAME);

putMetadata(namespace, key, value);
}

public static void putMetadata(String namespace, String key, Object value) {
AWSXRay.getCurrentSubsegmentOptional()
.ifPresent(segment -> segment.putMetadata(namespace, key, value));
}

public static void withEntitySubsegment(String name, Entity entity, Consumer<Subsegment> subsegment) {
AWSXRay.setTraceEntity(entity);
withSubsegment(name, subsegment);
}

public static void withSubsegment(String name, Consumer<Subsegment> subsegment) {
Subsegment segment = AWSXRay.beginSubsegment("## " + name);
try {
subsegment.accept(segment);
} finally {
AWSXRay.endSubsegment();
}
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,76 @@
package software.aws.lambda.tracing.internal;

import com.amazonaws.xray.AWSXRay;
import com.amazonaws.xray.entities.Subsegment;
import com.fasterxml.jackson.databind.ObjectMapper;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;
import software.aws.lambda.tracing.PowerToolTracing;

import static software.aws.lambda.internal.LambdaHandlerProcessor.isHandlerMethod;
import static software.aws.lambda.internal.LambdaHandlerProcessor.placedOnRequestHandler;
import static software.aws.lambda.internal.LambdaHandlerProcessor.placedOnStreamHandler;
import static software.aws.lambda.tracing.PowerTracer.SERVICE_NAME;

@Aspect
public final class LambdaTracingAspect {
static Boolean IS_COLD_START = null;
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can we have the cold start logic in a single place?

private static final ObjectMapper mapper = new ObjectMapper();

@Pointcut("@annotation(powerToolsTracing)")
public void callAt(PowerToolTracing powerToolsTracing) {
}

@Around(value = "callAt(powerToolsTracing) && execution(@PowerToolTracing * *.*(..))", argNames = "pjp,powerToolsTracing")
public Object around(ProceedingJoinPoint pjp,
PowerToolTracing powerToolsTracing) throws Throwable {
Object[] proceedArgs = pjp.getArgs();
Subsegment segment;

segment = AWSXRay.beginSubsegment("## " + pjp.getSignature().getName());
segment.setNamespace(namespace(powerToolsTracing));

boolean placedOnHandlerMethod = placedOnHandlerMethod(pjp);

if (placedOnHandlerMethod) {
segment.putAnnotation("ColdStart", IS_COLD_START == null);
}

IS_COLD_START = false;

try {
Object methodReturn = pjp.proceed(proceedArgs);
if (powerToolsTracing.captureResponse()) {
segment.putMetadata(namespace(powerToolsTracing), pjp.getSignature().getName() + " response", response(pjp, methodReturn));
}
return methodReturn;
} catch (Exception e) {
if (powerToolsTracing.captureError()) {
segment.putMetadata(namespace(powerToolsTracing), pjp.getSignature().getName() + " error", e);
}
throw e;
} finally {
AWSXRay.endSubsegment();
}
}

private Object response(ProceedingJoinPoint pjp, Object methodReturn) {
// TODO should we try to parse output stream? or just not support it?
if (placedOnStreamHandler(pjp)) {

}

return methodReturn;
}

private String namespace(PowerToolTracing powerToolsTracing) {
return powerToolsTracing.namespace().isEmpty() ? SERVICE_NAME : powerToolsTracing.namespace();
}

private boolean placedOnHandlerMethod(ProceedingJoinPoint pjp) {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We can enrich this further like its done in logging part, but we can do that once we agree on approach here.

return isHandlerMethod(pjp)
&& (placedOnRequestHandler(pjp) || placedOnStreamHandler(pjp));
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -55,7 +55,7 @@ void shouldSetLambdaContextWhenEnabled() {
void shouldSetLambdaContextForStreamHandlerWhenEnabled() throws IOException {
requestStreamHandler = new PowerLogToolEnabledForStream();

requestStreamHandler.handleRequest(new ByteArrayInputStream(new byte[]{}), null, context);
requestStreamHandler.handleRequest(new ByteArrayInputStream(new byte[]{}), new ByteArrayOutputStream(), context);

assertThat(ThreadContext.getImmutableContext())
.hasSize(5)
Expand All @@ -68,13 +68,13 @@ void shouldSetLambdaContextForStreamHandlerWhenEnabled() throws IOException {

@Test
void shouldSetColdStartFlag() throws IOException {
requestStreamHandler.handleRequest(new ByteArrayInputStream(new byte[]{}), null, context);
requestStreamHandler.handleRequest(new ByteArrayInputStream(new byte[]{}), new ByteArrayOutputStream(), context);

assertThat(ThreadContext.getImmutableContext())
.hasSize(5)
.containsEntry("coldStart", "true");

requestStreamHandler.handleRequest(new ByteArrayInputStream(new byte[]{}), null, context);
requestStreamHandler.handleRequest(new ByteArrayInputStream(new byte[]{}), new ByteArrayOutputStream(), context);

assertThat(ThreadContext.getImmutableContext())
.hasSize(5)
Expand Down