为Java日志切面增加灵活性

日志记录在软件开发中扮演着关键角色，帮助调试实时应用程序。因此，日志消息需要特别注意，并且需要精心策划才能清晰地表达出来。

大型企业应用程序通常托管不同类型的日志记录策略，并且在生产环境中可能不会记录每一个单独的、相对不重要的消息，与开发环境不同。这有助于节省存储空间并提高性能。清理旧日志遵循组织政策，并且日志记录会影响性能，尽管在低负载环境下我们可能不会明显感受到毫秒级的延迟，这相比于生产环境要小得多。

与代码和文档一样，日志记录本身通常也是样板代码和手动处理，因此容易出现人为错误。为了避免人为错误，比如遗漏日志消息，或者消除模板代码，我们经常借助Java应用程序中的Aspect来实现。在类的方法上，日志记录变得动态编织。本文深入探讨并阐述了如何加强日志记录Aspect以充分利用它。

日志中使用Aspect的简要介绍

让我们看一下代码片段[Listing-1]中显示的传统的使用SLF4J记录方法执行时间和度量的旧方法：

public void someMethod(String arg0, String arg1, int arg2) {
		long ts=System.currentTimeMillis();
		log.debug("someMethod invoked : arg0: {} arg1: {} arg2: {}",arg0,arg1,arg2);
		// business operations 
		// ...
		//.......
		log.debug("someMethod returns. Took {} millseconds",(System.currentTimeMillis()-ts));
	}

[Listing-1]

然而，上述代码片段使用了通用方法和参数名称。

日志对象可以通过以下任何一种方式获得：

1. Logger logger=Logger.getLogger("logger-1"); // 适用于Java 8或较低版本   // 不使用第三方依赖
2. java.lang.System.Logger logger=System.getLogger("sysloger"); // 适用于Java 9或更高版本，带或不带第三方依赖
3. 使用SLF4j实现，如Log4j/Log4j2 / Logback等，直接或间接地，比如通过使用我喜欢的Lombok注释，该注释通过APT生成代码。@Slf4j

无论我们如何以及我们创建日志对象的方式如何，这种方式都保持不变。

这种方式存在以下缺点：它们是手动的，因此容易出现错误，当然也是样板代码，都可通过Aspect消减。Aspect是可用于Spring框架或不可用于Spring框架的仪表触发器，尽管纵观面向方面编程，常常暗示着后者的使用。但是本文始终使用Spring Aspect，并且包括我们将很快重新讨论的示例。

我们创建一个自定义注解和一个触发器Around的Aspect用于标注它的方法。

@Documented
@Retention(RUNTIME)
@Target(ElementType.METHOD)
public @interface LogExecutionTime {
}



@Component
@Aspect
@Slf4j
public class LoggingAspect {

	
@Around("@annotation(com.somecompany.pkg.annotation.LogExecutionTime)")
	public Object aroundMethodExecution(ProceedingJoinPoint joinPoint) throws Throwable {
		long start = System.currentTimeMillis();

		Object result = joinPoint.proceed();
		long executionTime = System.currentTimeMillis() - start;
		log.info("{} took {} milliseconds to execute",jointPoint.getSignature().getName(),executionTime);
		}
       	return result;
	}

[Listing-2]

该Aspect记录了方法的执行时间和名称。迄今为止，没有新的讨论，假定读者已了解Spring框架、自定义注解和Aspect。下一节将介绍一种我们已经使用并受益的方法，我们在不同的项目中都会使用它，就像一个库。

在日志Aspect中添加复杂功能

我们在日志Aspect中添加了复杂功能，因为我们不仅满足于记录方法执行时间。我们希望在Aspect中具有日志级别。如我们在本章前面讨论的，级别在日志记录中起着至关重要的作用。因此，拥有切换日志级别的能力是不可或缺的。此外，如果有的话，拥有记录方法参数和返回值的功能将更为细致。

虽然日志记录器都带有各自的转换模式，比如log4j提供了一种基于XML的方法来配置几乎所有内容，而不仅仅是转换模式和Appenders的布局，但值得注意的是，一些项目设计为遵循预定义的消息模式，不管配置如何。这样做的原因可能是不盲目依赖配置并且机会失去通常的搜索模式。一个组织可能希望所有拥有的微服务都记录一个像"类名 ## 方法名 ## 日志消息"的消息。我们也希望在日志Aspect中，转换模式也是可定制的。

代码段[Listing-3]显示了注释LoggingAspect的增强版本：

@Retention(RUNTIME)
@Target(ElementType.METHOD)
public @interface LogExecution {

	public Class<? extends LogFormatter> formatter() default LogFormatter.class;
	public String level() default "info";
	public boolean logResult() default false;
	public boolean logParams() default false;
	
}

// The LogFormatter class looks like this:

public class LogFormatter {
	public  String format(MethodSignature methodSignature ,Object result) {
		return String.valueOf(methodSignature.getDeclaringTypeName()+" :: "+methodSignature.getName()+"[] :: "+ result);
	}
}

[Lisiting-3]

使用日志Aspect

@LogExecution(logResult = true,level ="info",logParams = true,formatter = SimpleLogFormatter.class)
	
public Object someMethod(String x,int y) {
		try {
			TimeUnit.SECONDS.sleep(3); // Intentional, NoOp delay 
		} catch (InterruptedException e) {
		}
		return "x = "+x+" y= "+y+" Now it's "+LocalDateTime.now();
}


public class SimpleLogFormatter extends LogFormatter {

@Override
public String format(MethodSignature methodSignature, Object result){
		
		return methodSignature.getName()+"---->"+result;
}

}

[Listing-4]            

    因此，我们传递了以下内容：

1. 是否记录方法的返回值
2. 日志级别
3. 是否记录传递给方法的参数
4. 最后，一个变换器类，该类是LogFormatter的子类                

以下是上述方法的示例日志：

024-01-10 01:09:27.971[0;39m [32m INFO[0;39m [35m12904[0;39m [2m---[0;39m [2m[nio-8080-exec-1][0;39m [36mio.spb.ordered.a.aspect.LoggingAspect   [0;39m [2m:[0;39m someMethod---->x = John y= Doe 现在是2024-01-10T01:09:27.961848100 

通过提供LogFromatter的相关子类并将其用作格式化程序，我们可以更新格式。

最后，我们可以不断添加功能，使其变得更加复杂。但是，完整的源代码在此提供，以便读者一起继续研究。