Padronizando Logs de uma aplicação Java 사용 Spring AOP

Em aplicações corporativas, é muito comum colocarmos logs nos métodos que criamos para indicar, por exemplo:

Os paraâmetros de entrada

실행 시간

O retorno do método

Acontece que isso, se feito de forma manual, se torna muito repetitivo e propenso a erros. O dev pode facilmente esquecer de incluir algum desses logs, além de aumentar as linhas de código e assim diminuir a legibilidade.

예를 들어, para fins didáticos, iremos demonstrar uma API simples que retorna uma mensagem juntamente com o nome que foi passado como paraâmetro.

다음 코드를 관찰하십시오.

@RestController
@RequestMapping("/api/v1")
@Slf4j
public class SpringAopExampleController {

    private final SpringAopExampleService service;

    @Autowired
    public SpringAopExampleController(SpringAopExampleService service) {
        this.service = service;
    }

    @GetMapping("/messages/users/{username}")
    public ResponseEntity<String> getMessage(@PathVariable String username){
        long startTime = System.currentTimeMillis();
        log.info("m=getMessage; c=SpringAopExampleController; username={}", username);

        String messageToReturn = service.getMessage(username);

        long endTime = System.currentTimeMillis();
        log.info("received message: {}; response time in milliseconds: {}", messageToReturn, (endTime - startTime));
        return ResponseEntity.ok(messageToReturn);
    }
}

@Service
@Slf4j
public class SpringAopExampleService {

    public String getMessage(String username){
        long startTime = System.currentTimeMillis();
        log.info("m=getMessage; c=SpringAopExampleService; username={}", username);

        String generatedMessage = "Hello World " + username + " from Spring AOP!";

        long endTime = System.currentTimeMillis();
        log.info("received message: {}; response time in milliseconds: {}", generatedMessage, (endTime - startTime));
        return generatedMessage;
    }
}

API 실행에 대한 로그 기록:

2022-05-05 14:49:02.583  INFO 21319 --- [nio-8080-exec-2] c.e.s.a.c.SpringAopExampleController     : m=getMessage; c=SpringAopExampleController; username=Victor
2022-05-05 14:49:02.583  INFO 21319 --- [nio-8080-exec-2] c.e.s.a.service.SpringAopExampleService  : m=getMessage; c=SpringAopExampleService; username=Victor
2022-05-05 14:49:02.584  INFO 21319 --- [nio-8080-exec-2] c.e.s.a.service.SpringAopExampleService  : received message: Hello World Victor from Spring AOP!; response time in milliseconds: 1
2022-05-05 14:49:02.584  INFO 21319 --- [nio-8080-exec-2] c.e.s.a.c.SpringAopExampleController     : received message: Hello World Victor from Spring AOP!; response time in milliseconds: 1

Perceba como a leitura do código fica difícil

Primeiro capturamos o início do fluxo;

Depois logamos o nome do método, nome da classe e os paraâmetros;

Chamamos o Service para armazenar a mensagem que será retornada;

Capturamos o final do fluxo;

Logamos o retorno, juntamente com o tempo de execução em milisegundos;

O mesmo se repete para a Classe de serviço.

Todas essas informações são Importantes, mas repetir esse processo para todos os métodos é inviável.

이 문제를 해결하려면 Spring AOP를 사용하는 것이 좋습니다. Com ele, podemos automatizar procedimentos repetitivos que geralmente codificamos manualmente;

Vantagens do seu nessa abordagem:

Evita redundância de código: esse processo de log descrito anteriormente não fica mais sendo manualmente repetido em todos os metodos e sim em um classe específica do Spring para tal uso.

Reaproveitamento de códgo: a classe a qual concentra a estrutura padrão dos logs pode ser reutilizada em outros projetos;

Facilidade de manutenção: ao invés de alterar um padrão de log em todos os métodos, a manutenção ou melhoria será feita apenas uma vez e será refletida em todo o sistema;

Podemos ter uma classe como a example abaixo para centralizar esse tipo de log:

@Aspect
@Component
@Slf4j
public class SpringAopInterceptor   {

    @Around("execution(* com.example.spring.aop..*.*(..))")
    public Object executionTime(ProceedingJoinPoint point) throws Throwable {
        if(hasParams(point)) {
            log.info("opening method", kv("method", point.getSignature().getName()),
                    kv("class",point.getSignature().getDeclaringTypeName()), "params",
                    kv("method-params", getParamsAndValuesFromMethod(point)));
        }
        else{
            log.info("opening method", kv("method", point.getSignature().getName()),
                    kv("class",point.getSignature().getDeclaringTypeName()));
        }

        long startTime = System.currentTimeMillis();

        Object object = point.proceed();

        long endTime = System.currentTimeMillis();
        log.info("closing method", kv("method", point.getSignature().getName()),
                kv("class",point.getSignature().getDeclaringTypeName()),
                kv("execution-time in milliseconds", endTime-startTime));
        return object;
    }

        @AfterReturning(pointcut = "execution(* com.example.spring.aop..*.*(..))", returning = "result")
    public void logAfter(JoinPoint point, Object result) {
        if(result!=null){
            log.info("method-response", kv("method", point.getSignature().getName()),
                    kv("class", point.getSignature().getDeclaringTypeName()),
                    kv("response", result));
        }
    }

    private Boolean hasParams(ProceedingJoinPoint point){
        if(point.getArgs()!= null && point.getArgs().length != 0){
            MethodSignature methodSignature = (MethodSignature) point.getSignature();
            Map<String, Object> paramsAndValues = new HashMap<>();
            String[] parameterNames = methodSignature.getParameterNames();
            return parameterNames != null;
        }
        else return false;

    }

    private Map<String, Object> getParamsAndValuesFromMethod(ProceedingJoinPoint point){
        MethodSignature methodSignature = (MethodSignature) point.getSignature();
        Map<String, Object> paramsAndValues = new HashMap<>();
        String[] parameterNames = methodSignature.getParameterNames();
        Object[] args = point.getArgs();

        for(int i=0; i<args.length; i++){
            paramsAndValues.put(parameterNames[i], args[i]);
        }

        return paramsAndValues;
    }
}

Nessa estrutura, Estamos usando o Logback e o Logstash. 파일에 logback.xml 파일을 저장하고 파스타 리소스를 보관할 필요가 있습니다.

OBS: os 로그는 JSON 형식이 아닌 형식으로 전달됩니다. Irei explicar com detalhes no proximo artigo. Por hora, bista copyar esse arquivo xml e incluir as dependsências. Você pode Consultar tudo que precisa no código fonte que irei disponibilizar no final do artigo.

como ficaram os 로그를 관찰하십시오.

{"@timestamp":"2022-05-05T15:09:52.346-03:00","@version":"1","message":"opening method","logger_name":"com.example.spring.aop.config.SpringAopInterceptor","thread_name":"http-nio-8080-exec-1","level":"INFO","level_value":20000,"method":"getMessage","class":"com.example.spring.aop.controller.SpringAopExampleController","method-params":{"username":"Victor"}}
{"@timestamp":"2022-05-05T15:09:52.389-03:00","@version":"1","message":"opening method","logger_name":"com.example.spring.aop.config.SpringAopInterceptor","thread_name":"http-nio-8080-exec-1","level":"INFO","level_value":20000,"method":"getMessage","class":"com.example.spring.aop.service.SpringAopExampleService","method-params":{"username":"Victor"}}
{"@timestamp":"2022-05-05T15:09:52.404-03:00","@version":"1","message":"method-response","logger_name":"com.example.spring.aop.config.SpringAopInterceptor","thread_name":"http-nio-8080-exec-1","level":"INFO","level_value":20000,"method":"getMessage","class":"com.example.spring.aop.service.SpringAopExampleService","response":"Hello World Victor from Spring AOP!"}
{"@timestamp":"2022-05-05T15:09:52.404-03:00","@version":"1","message":"closing method","logger_name":"com.example.spring.aop.config.SpringAopInterceptor","thread_name":"http-nio-8080-exec-1","level":"INFO","level_value":20000,"method":"getMessage","class":"com.example.spring.aop.service.SpringAopExampleService","execution-time in milliseconds":15}
{"@timestamp":"2022-05-05T15:09:52.413-03:00","@version":"1","message":"method-response","logger_name":"com.example.spring.aop.config.SpringAopInterceptor","thread_name":"http-nio-8080-exec-1","level":"INFO","level_value":20000,"method":"getMessage","class":"com.example.spring.aop.controller.SpringAopExampleController","response":{"headers":{},"body":"Hello World Victor from Spring AOP!","statusCode":"OK","statusCodeValue":200}}
{"@timestamp":"2022-05-05T15:09:52.473-03:00","@version":"1","message":"closing method","logger_name":"com.example.spring.aop.config.SpringAopInterceptor","thread_name":"http-nio-8080-exec-1","level":"INFO","level_value":20000,"method":"getMessage","class":"com.example.spring.aop.controller.SpringAopExampleController","execution-time in milliseconds":101}

Com isso, temos uma classe centralizada focada em logar nossa aplicação, refletindo para todos os métodos dentro do package especificado. Perceba também que temos muito mais riqueza de detalhes.

Agora veja como as classes de Controller e Service ficaram muito mais simples sem aquela repetição de código manual:

@GetMapping("/messages/users/{username}")
    public ResponseEntity<String> getMessage(@PathVariable String username){
        return ResponseEntity.ok(service.getMessage(username));
    }

public class SpringAopExampleService {

    public String getMessage(String username){
        return "Hello World " + username + " from Spring AOP!";
    }
}

Em um próximo artigo, irei explicar sobre como deixar os logs da aplicação em JSON formato, o qual ajuda bastante no throubleshooting e até na criação de dashboards e monitoramentos.

Espero que tenha contribuído em algo e até mais!

Github에서 프로젝트를 시작하는 방법: