Troubleshoot Java asynchronous instrumentation

If you are having problems using the Java agent API for async tokens and segments, use these techniques to help you find answers and solve problems.

Verify your instrumentation

The API has a number of built-in safety mechanisms to prevent issues caused by incorrect API usage, but you can use these techniques to verify that your application’s instrumentation is correct:

After instrumenting your code, verify that the logs show that an equal number of tokens have been created and expired. For more information on which log messages to look for, see Use logs to troubleshoot.
Check the garbage collection statistics under APM's JVMs page to determine whether or not your changes have significantly altered garbage collection patterns.
Check if any segments or tokens are timing out by reviewing your transaction traces for a timed_out attribute. If so, you can change the limit with token_timeout and segment_timeout.

Use logs to troubleshoot

To customize your Java agent logging, see Generating logs. Then, you can examine your logs for these common messages:

To view created tokens, check logs at FINEST for:
```
Transaction com.newrelic.agent.Transaction@5a7cc8e: created active token com.newrelic.agent.TokenImpl@7db8d0e8
```

To view expired tokens and the time that they expired, check logs at FINEST for:

Transaction com.newrelic.agent.Transaction@5a7cc8e: expired token com.newrelic.agent.TokenImpl@7db8d0e8

To view created segments, check logs at FINEST for:

Transaction com.newrelic.agent.Transaction@486b7f04: startSegment(): com.newrelic.agent.Segment@2b7fdad3 created and started with tracer com.newrelic.agent.tracers.OtherRootTracer@4df4a953

To view ended segments and the time that they ended, check logs at FINEST for:

com.newrelic.agent.Transaction@486b7f04--finish segment(): com.newrelic.agent.Segment@2b7fdad3 async finish with tracer com.newrelic.agent.tracers.OtherRootTracer@4df4a953

Problem: Transaction times are too long

Make sure to expire tokens and end or ignore segments; otherwise transactions may take longer to report to New Relic. The Java agent has a timeout mechanism for tokens and segments that are not ended correctly. For more information, see token_timeout and segment_timeout.

Problem: No transaction trace data

Inspect transaction traces to make sure expected asynchronous work is reported. If you do not see any transaction traces, make sure your transaction duration exceeds the transaction trace threshold set in transaction_threshold.

Problem: Too few async calls

If too few calls are being reported:

In the faulty example below, a parallel stream is being used, which means that the work done inside the lambda in the call to map() can be scheduled on a different thread than the thread handling the request. Without creating a token to link all this work together, you will not see any of the work that gets scheduled on a different thread inside of your transaction.

@RequestMapping("parallel_stream_bad")
@Trace(dispatcher = true)
public ResponseEntity parallelStreamBad(@RequestParam("ids") List<long> ids) {
    List<item> results = ids
            .parallelStream()
            .map(i -> requestItem(i))
            .filter(item -> item != null)
            .collect(Collectors.toList());
    return formattedResponse("parallel_stream_bad", results);  
}

The example below will report only a subset of the calls to requestItem() because it is impossible to put @Trace(async = true) around blocks of anonymous work inside the call to map(). Instead, you should pass the token into requestItem() and link it, and then add @Trace(async=true) around it. Or use a helper function like requestItemAsync() to do this without changing your existing methods.

@RequestMapping("parallel_stream_bad2")
@Trace(dispatcher = true)
public ResponseEntity parallelStreamBad2(@RequestParam("ids") List<long> ids) {
    final Token token = NewRelic.getAgent().getTransaction().getToken();
    List<item> results = ids
            .parallelStream()
            .map(id -> {
                token.link();
                return requestItem(id);
            })
            .filter(item -> item != null)
            .collect(Collectors.toList());
    return formattedResponse("parallel_stream_bad2", results);
}

Compare this to the correct example below, in which the lambda expression is wrapped by the wrapper class InstrumentedCallable. This class accepts a token and a lambda, then wraps asynchronous work in @Trace(async = true) and uses a token to link the work to the request thread.

@RequestMapping("parallel_stream_wrap")
@Trace(dispatcher = true)
public ResponseEntity parallelStreamWrap(@RequestParam("ids") List<long> ids) {
    final Token token = NewRelic.getAgent().getTransaction().getToken();
    List<item> results = ids
            .parallelStream()
            .map(id -> InstrumentedCallable.instrumentCallable(token, () -> requestItem(id)))
            .map(c -> c.call())
            .filter(item -> item != null)
            .collect(Collectors.toList());
    token.expire();
    return formattedResponse("parallel_stream_wrap", results);
}

Troubleshoot Java asynchronous instrumentation

Verify your instrumentation

Use logs to troubleshoot

Problem: Transaction times are too long

Problem: No transaction trace data

Problem: Too few async calls

Ensure that each activity you monitor is appropriately linked

Check if you are missing required annotations

Troubleshoot Java asynchronous instrumentation

Verify your instrumentation .css-21sua1{background:none;border:none;width:0;padding:0;}

Use logs to troubleshoot

Problem: Transaction times are too long

Problem: No transaction trace data

Problem: Too few async calls

Check if you are missing required annotations

Verify your instrumentation