spring-boot aop 打印 http 日志

本文项目已发布到github,后续学习项目也会添加到此工程下,欢迎fork点赞。
https://github.com/wangyuheng/spring-boot-sample

需要具备少量aop基础,通过springboot构建项目方便演示。

AOP-面向切面编程

一句话描述,在java对象增加切点,在不改变对象的前提下通过代理扩展功能。

http日志打印拦截器

restful api

通过springboot快速搭建一个RestController接口。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
import org.springframework.web.bind.annotation.*;
import wang.crick.study.httplog.annotation.HttpLog;
import wang.crick.study.httplog.domain.User;

import java.util.Random;

@RestController
@RequestMapping("/user")
public class UserApi {

@GetMapping("/log/{id}")
public RestApiResponse<User> getInfo(@PathVariable("id") int id,
@RequestParam("age") int age){
User user = new User();
user.setId(id);
user.setUsername(String.valueOf(new Random().nextLong()));
user.setAge(age);
return RestApiResponse.success(user);
}

@GetMapping("/log/pwd/{id}")
public RestApiResponse<User> getInfoWithPwd(@PathVariable("id") int id,
@RequestHeader("username") String username,
@RequestHeader("password") String password){
User user = new User();
user.setId(id);
user.setUsername(username);
user.setPassword(password);
return RestApiResponse.success(user);
}

@GetMapping("/log/pwdExcludeResponse/{id}")
public RestApiResponse<User> getInfoWithPwd(@PathVariable("id") int id,
@RequestParam("age") int age,
@RequestHeader("password") String password){
User user = new User();
user.setId(id);
user.setPassword(password);
user.setAge(age);
return RestApiResponse.success(user);
}

}

切面选择

一般教程会选择拦截所有http请求,并打印request.parameters。但是存在问题:

  1. 不够灵活,部分参数不想打印,如文件数据(过大)、敏感数据(身份证)等。
  2. 显式的标注日志输出,避免给维护人员造成疑惑。
  3. 部分参数通过header传输

因此,自定义日志输出@annotation HttpLog

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
public @interface HttpLog {
/**
* 忽略参数,避免文件or无意义参数打印
*
* @return 忽略参数数组
*/
String[] exclude() default {};

/**
* 需要打印的header参数
*
* @return header参数名数组
*/
String[] headerParams() default {};

boolean ignoreResponse() default false;
}

获取HttpServletRequest

spring通过ThreadLocal持有request参数。

1
2
3
4
5
private HttpServletRequest getRequest() {
RequestAttributes ra = RequestContextHolder.getRequestAttributes();
ServletRequestAttributes sra = (ServletRequestAttributes) ra;
return sra.getRequest();
}

获取uri

根据拦截规则不同,getServletPath()和request.getPathInfo()可能为空,简单的做一次健壮性判断。

1
2
3
4
5
private String getRequestPath(HttpServletRequest request) {
return (null != request.getServletPath() && request.getServletPath().length() > 0)
? request.getServletPath() : request.getPathInfo();

}

aop日志输出

  1. Pointcut自定义@annotation HttpLog
  2. 拿到@annotation,读取自定义属性,如忽略response、打印headers等
  3. 遍历request & headers中需打印参数
  4. 定制日志格式并打印log
  5. 拦截返回值并打印log

Aspect代码如下

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.Signature;
import org.aspectj.lang.annotation.AfterReturning;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.aspectj.lang.annotation.Pointcut;
import org.aspectj.lang.reflect.MethodSignature;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint;
import org.springframework.web.context.request.RequestAttributes;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;
import wang.crick.study.httplog.annotation.HttpLog;
import wang.crick.study.httplog.api.RestApiResponse;

import javax.servlet.http.HttpServletRequest;
import java.lang.reflect.Method;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.List;
import java.util.Optional;

@Aspect
public class HttpLogAspect {

private Logger log = LoggerFactory.getLogger(HttpLogAspect.class);

@Pointcut("@annotation(wang.crick.study.httplog.annotation.HttpLog)")
public void logAnnotation() {
}

private Optional<HttpLog> getLogAnnotation(JoinPoint joinPoint) {
if (joinPoint instanceof MethodInvocationProceedingJoinPoint) {
Signature signature = joinPoint.getSignature();
if (signature instanceof MethodSignature) {
MethodSignature methodSignature = (MethodSignature) signature;
Method method = methodSignature.getMethod();
if (method.isAnnotationPresent(HttpLog.class)) {
return Optional.of(method.getAnnotation(HttpLog.class));
}
}
}
return Optional.empty();
}

private HttpServletRequest getRequest() {
RequestAttributes ra = RequestContextHolder.getRequestAttributes();
ServletRequestAttributes sra = (ServletRequestAttributes) ra;
return sra.getRequest();
}

private String getRequestPath(HttpServletRequest request) {
return (null != request.getServletPath() && request.getServletPath().length() > 0)
? request.getServletPath() : request.getPathInfo();

}

@Before("logAnnotation()")
public void requestLog(JoinPoint joinPoint) {
try {
Optional<HttpLog> httpLog = getLogAnnotation(joinPoint);
httpLog.ifPresent(anno -> {
HttpServletRequest request = getRequest();
List<String> excludes = Arrays.asList(anno.exclude());
List<Object> params = new ArrayList<>();
StringBuilder logMsg = new StringBuilder();
logMsg.append("REQUEST_LOG. sessionId:{}. ")
.append("requestUrl: ")
.append(getRequestPath(request))
.append(" -PARAMS- ");
params.add(request.getSession().getId());
request.getParameterMap().forEach((k, v) -> {
if (!excludes.contains(k)) {
logMsg.append(k).append(": {}, ");
params.add(v);
}
});
if (anno.headerParams().length > 0) {
logMsg.append(" -HEADER_PARAMS- ");
Arrays.asList(anno.headerParams()).forEach(param -> {
logMsg.append(param).append(": {}, ");
params.add(request.getHeader(param));
});
}
log.info(logMsg.toString(), params.toArray());
});
} catch (Exception ignore) {
log.warn("print request log fail!", ignore);
}
}


@AfterReturning(returning = "restApiResponse", pointcut = "logAnnotation()")
public void response(JoinPoint joinPoint, RestApiResponse restApiResponse) {
try {
Optional<HttpLog> httpLog = getLogAnnotation(joinPoint);
httpLog.ifPresent(anno -> {
if (!anno.ignoreResponse()) {
log.info("RESPONSE_LOG. sessionId:{}. result:{}", getRequest().getSession().getId(), restApiResponse);
}
});
} catch (Exception ignore) {
log.warn("print response log fail!", ignore);
}
}

}

使用

在RestController中增加自定义注解HttpLog

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
import org.springframework.web.bind.annotation.*;
import wang.crick.study.httplog.annotation.HttpLog;
import wang.crick.study.httplog.domain.User;

import java.util.Random;

@RestController
@RequestMapping("/user")
public class UserApi {


/**
* curl -H 'username:12b4' -H 'password:34ndd' -v 'http://localhost:8080/user/log/123?age=32'
*/
@GetMapping("/log/{id}")
@HttpLog()
public RestApiResponse<User> getInfo(@PathVariable("id") int id,
@RequestParam("age") int age){
User user = new User();
user.setId(id);
user.setUsername(String.valueOf(new Random().nextLong()));
user.setAge(age);
return RestApiResponse.success(user);
}

/**
* curl -H 'username:12b4' -H 'password:34ndd' -v 'http://localhost:8080/user/log/pwd/123?age=32'
*/
@GetMapping("/log/pwd/{id}")
@HttpLog(headerParams="password")
public RestApiResponse<User> getInfoWithPwd(@PathVariable("id") int id,
@RequestHeader("username") String username,
@RequestHeader("password") String password){
User user = new User();
user.setId(id);
user.setUsername(username);
user.setPassword(password);
return RestApiResponse.success(user);
}

/**
* curl -H 'username:12b4' -H 'password:34ndd' -v 'http://localhost:8080/user/log/pwdExcludeResponse/123?age=32'
*/
@GetMapping("/log/pwdExcludeResponse/{id}")
@HttpLog(headerParams="username", ignoreResponse = true)
public RestApiResponse<User> getInfoWithPwd(@PathVariable("id") int id,
@RequestParam("age") int age,
@RequestHeader("password") String password){
User user = new User();
user.setId(id);
user.setPassword(password);
user.setAge(age);
return RestApiResponse.success(user);
}

}

加载HttpLogAspect对象

可以在@SpringBootApplication类下直接加在,也可以在HttpLogAspect中增加@Component注解,推荐前者,更清晰。不需要增加@EnableAspectJAutoProxy类 (注:1)

1
2
3
4
@Bean
public HttpLogAspect httpLogAspect(){
return new HttpLogAspect();
}

启动容器并访问

header参数可以通过curl验证。**(注:2)**

测试

可测试的代码才是好代码。所以其实我没写过几行好代码。。。

日志输出到控制台,可以通过获取控制台中内容进行contains验证

获取控制台输出字符

1
2
ByteArrayOutputStream outContent = new ByteArrayOutputStream();
System.setOut(new PrintStream(outContent));

执行request请求

基于spring test提供的mockMvc方法,测试代码如下:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
import org.junit.Before;
import org.junit.Test;
import org.junit.runner.RunWith;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.test.context.SpringBootTest;
import org.springframework.http.MediaType;
import org.springframework.test.context.junit4.SpringRunner;
import org.springframework.test.web.servlet.MockMvc;
import org.springframework.test.web.servlet.RequestBuilder;
import org.springframework.test.web.servlet.request.MockMvcRequestBuilders;
import org.springframework.test.web.servlet.result.MockMvcResultHandlers;
import org.springframework.test.web.servlet.result.MockMvcResultMatchers;
import org.springframework.test.web.servlet.setup.MockMvcBuilders;
import org.springframework.web.context.WebApplicationContext;

import java.io.ByteArrayOutputStream;
import java.io.PrintStream;
import java.util.Random;

import static org.junit.Assert.assertFalse;
import static org.junit.Assert.assertTrue;

@RunWith(SpringRunner.class)
@SpringBootTest
public class UserApiTest {

private MockMvc mockMvc;

@Autowired
private UserApi userApi;

@Autowired
private WebApplicationContext context;

private ByteArrayOutputStream outContent;
private int userId = new Random().nextInt(10);
private int age = new Random().nextInt(10);
private long username = new Random().nextLong();
private long password = new Random().nextLong();

@Before
public void setup() {
// 坚挺控制台输出
outContent = new ByteArrayOutputStream();
System.setOut(new PrintStream(outContent));

//项目拦截器有效
mockMvc = MockMvcBuilders.webAppContextSetup(context).build();
//单个类,拦截器无效
// mockMvc = MockMvcBuilders.standaloneSteup(userApi).build();
}


@Test
public void test_log() throws Exception {
String path = "/user/log/" + userId;
String uri = path + "?age=" + age;
RequestBuilder request = MockMvcRequestBuilders.get(uri)
.contentType(MediaType.APPLICATION_JSON_UTF8)
.accept(MediaType.APPLICATION_JSON);

mockMvc.perform(request).andExpect(MockMvcResultMatchers.status().isOk());
String console = outContent.toString();
assertTrue(console.contains("REQUEST_LOG"));
assertFalse(console.contains("HEADER_PARAMS"));
assertTrue(console.contains("RESPONSE_LOG"));
assertTrue(console.contains(path));
assertTrue(console.contains(String.valueOf(age)));
assertFalse(console.contains(String.valueOf(username)));
assertFalse(console.contains(String.valueOf(password)));
}

@Test
public void test_log_header() throws Exception {
String path = "/user/log/pwd/" + userId;
String uri = path + "?age=" + age;
RequestBuilder request = MockMvcRequestBuilders.get(uri)
.header("username", username)
.header("password", password)
.contentType(MediaType.APPLICATION_JSON_UTF8)
.accept(MediaType.APPLICATION_JSON);

mockMvc.perform(request).andExpect(MockMvcResultMatchers.status().isOk());

String console = outContent.toString();
assertTrue(console.contains("REQUEST_LOG"));
assertTrue(console.contains("HEADER_PARAMS"));
assertTrue(console.contains("RESPONSE_LOG"));
assertTrue(console.contains(path));
assertTrue(console.contains(String.valueOf(age)));
assertFalse(console.contains(String.valueOf(username)));
assertTrue(console.contains(String.valueOf(password)));
}

@Test
public void test_log_header_excludeResponse() throws Exception {
String path = "/user/log/pwdExcludeResponse/" + userId;
String uri = path + "?age=" + age;
RequestBuilder request = MockMvcRequestBuilders.get(uri)
.header("username", username)
.header("password", password)
.contentType(MediaType.APPLICATION_JSON_UTF8)
.accept(MediaType.APPLICATION_JSON);

mockMvc.perform(request).andExpect(MockMvcResultMatchers.status().isOk());

String console = outContent.toString();
assertTrue(console.contains("REQUEST_LOG"));
assertTrue(console.contains("HEADER_PARAMS"));
assertFalse(console.contains("RESPONSE_LOG"));
assertTrue(console.contains(path));
assertTrue(console.contains(String.valueOf(age)));
assertTrue(console.contains(String.valueOf(username)));
assertFalse(console.contains(String.valueOf(password)));
}

}

注:1 @EnableAspectJAutoProxy

注:2 curl增加header参数

1
curl -H 'username:123' -H 'password:345'