如何在Spring Boot中分析复杂的HTTP请求处理？

Question

我有复杂的@RestController方法，类似这样：

@PostMapping("{id}")
@PreAuthorize("hasRole('ADMIN')")
@Transactional
public Response handleRequest(@PathVariable("id") long id, @RequestBody @Valid Request request) {
    return service.handleRequest(id, request);
}

我们的请求处理非常慢，因此我们想检查在特定的请求处理任务上花费了多少时间。不幸的是，很多事情都是在我的方法之外完成的，例如：

• 反序列化请求
• 正在验证
• 权限检查
• 开始和结束交易
• 序列化响应

是否有办法简单地测量所有这些部分？也许是一组接收跟踪消息的记录器，以便我可以在每一步结束时提取时间戳？

我现在看到的唯一方法是更改​​该方法以接受HttpServletRequest和HttpServletResponse并在方法主体中执行这些部分。但是那样一来，我将失去很多Spring Boot的好处。

Answer 1

您还可以检查一个tuto，以添加用于执行器的自定义指标，但这看起来有点复杂（但是您必须编写自己的指标Bean，并将其注入代码中，重写objectMapper进行映射，等等。 ..）

或者也许激活关于jackson，spring-security，javax.validation的日志记录信息，以检查每个操作在日志中的时间，但不是很精确

Answer 2

无需更改期望HttpServletRequest的方法。您可以使用AspectJ

使用它，您可以收集花费在每种方法上的时间，并分析其中的数据。

创建方法定时注释

@Retention(RetentionPolicy.RUNTIME)
@Target(ElementType.METHOD)
public @interface MethodTiming {
}

在您的请求中，创建一个映射，其中将保留所有方法及其花费的时间：

  public class Request {
  private Map<String, Long> methodTimings = new TreeMap<String, Long>();

  public void addMethodTiming(String classAndMethodName, long executionTimeMillis) {
        Long value = methodTimings.get(classAndMethodName);
        if (value != null) {
            executionTimeMillis += value;
        }

        methodTimings.put(classAndMethodName, executionTimeMillis);
    }
  }

比，创建将处理它的Aspect类：

@Aspect
@Component
public class MethodTimingAspect {
private static final String DOT = ".";

@Around("@annotation(MethodTiming)")
public Object timeAround(ProceedingJoinPoint joinPoint) throws Throwable  {
    Object result = null;

    StopWatch watch = new StopWatch();
    try {
        watch.start();
        result = joinPoint.proceed();
    } finally {
        watch.stop();
        long executionTime = watch.getLastTaskTimeMillis();

        String className = joinPoint.getTarget().getClass().getSimpleName();
        String methodName = joinPoint.getSignature().getName();
        String classAndMethodName = className + DOT + methodName;

        Object[] methodArgs = joinPoint.getArgs();
        if (methodArgs != null) {
            for (Object arg : methodArgs) {
                if (arg instanceof Request) {
                    // inject time back into Request
                    Request request = (Request) arg;
                    request.addMethodTiming(classAndMethodName, executionTime);

                    break;
                }
            }
        }

    }
    return result;
}

最后，只需在您要测量的方法上添加@MethodTiming：

@MethodTiming
public Request handleRequest(Request request) {
// handle the Request
return request
}

您的请求对象将比处理后的对象具有更多类似的东西

"methodTimings": {
    "RequestService.handleRequest": 2610,
    "AnotherRequestService.anotherMethod": 1351
}

Answer 3

您真正需要的是Java Thread Profiler，它将告诉您究竟出了什么问题，为此您可以使用任何APM工具，而我最喜欢的是GLOWROOT。在类似的情况下，我曾用它来衡量API的性能并确定缓慢的跟踪可以清楚地告诉您哪个方法花费时间，您可以看到从方法调用到内部所有调用方法的整个跟踪，甚至可以识别慢速查询（如果有的话）。希望这会有所帮助

此站点：https://glowroot.org/

示例跟踪：

https://demo.glowroot.org/transaction/thread-profile?transaction-type=Web&transaction-name=%2Fhot-sauces