SpringBoot 统计更多Api接口SQL相关日志信息

统计(查询,更新,批量更新)SQL执行次数及用时并输出log

import com.zhangziwa.practisesvr.utils.log.LogContext;
import org.apache.ibatis.executor.statement.StatementHandler;
import org.apache.ibatis.plugin.Interceptor;
import org.apache.ibatis.plugin.Intercepts;
import org.apache.ibatis.plugin.Invocation;
import org.apache.ibatis.plugin.Signature;
import org.apache.ibatis.session.ResultHandler;
import org.springframework.stereotype.Component;

import java.sql.Statement;

@Intercepts({
        @Signature(type = StatementHandler.class, method = "query", args = {Statement.class, ResultHandler.class}),
        @Signature(type = StatementHandler.class, method = "update", args = {Statement.class}),
        @Signature(type = StatementHandler.class, method = "batch", args = {Statement.class})})
@Component
public class SqlExecuteInterceptor implements Interceptor {
    @Override
    public Object intercept(Invocation invocation) throws Throwable {
        System.err.println("***SqlExecuteInterceptor.intercept***");

        long startTime = System.currentTimeMillis();
        try {
            return invocation.proceed();
        } finally {
            long executionCost = System.currentTimeMillis() - startTime;
            LogContext.incrementSqlCount();
            LogContext.incrementSqlCost(executionCost);
        }
    }
}
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

统计查询数据量并输出log

import com.zhangziwa.practisesvr.utils.log.LogContext;
import org.apache.ibatis.executor.resultset.ResultSetHandler;
import org.apache.ibatis.plugin.Interceptor;
import org.apache.ibatis.plugin.Intercepts;
import org.apache.ibatis.plugin.Invocation;
import org.apache.ibatis.plugin.Signature;
import org.springframework.stereotype.Component;

import java.sql.Statement;
import java.util.Collection;

@Intercepts({@Signature(type = ResultSetHandler.class, method = "handleResultSets", args = {Statement.class})})
@Component
public class SqlReadRowInterceptor implements Interceptor {
    @Override
    public Object intercept(Invocation invocation) throws Throwable {
        Object proceed = invocation.proceed();
        if (proceed instanceof Collection) {
            LogContext.incrementSqlSearchedRowCount(((Collection<?>) proceed).size());
        } else {
            LogContext.incrementSqlSearchedRowCount(0);
        }
        return proceed;
    }
}

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

查询单条数据

[2024-01-24 10:52:31.365_365] [WARN ] [http-nio-8080-exec-3] [LogFilter.java:21] → [LogFilter.doFilter: Start processing request at 2024-01-24T02:52:31.365178500Z - /students/8]
***LogFilter.doFilter.start***
***RequestHeaderCheckFilter.doFilter.start***

***ResponsePostInterceptor.preHandle***
***LogInterceptor.preHandle***
[2024-01-24 10:52:31.389_389] [WARN ] [http-nio-8080-exec-3] [LogInterceptor.java:37] → [LogInterceptor.postHandle: Start processing request at 2024-01-24T02:52:31.389802500Z - /students/8]

***StudentController.queryById***
Creating a new SqlSession
SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@6ab146ea] was not registered for synchronization because synchronization is not active
[2024-01-24 10:52:31.425_425] [INFO ] [http-nio-8080-exec-3] [HikariDataSource.java:110] → [practisedb - Starting...]
[2024-01-24 10:52:31.526_526] [INFO ] [http-nio-8080-exec-3] [HikariPool.java:565] → [practisedb - Added connection com.mysql.cj.jdbc.ConnectionImpl@439142cf]
[2024-01-24 10:52:31.528_528] [INFO ] [http-nio-8080-exec-3] [HikariDataSource.java:123] → [practisedb - Start completed.]
JDBC Connection [HikariProxyConnection@1509777760 wrapping com.mysql.cj.jdbc.ConnectionImpl@439142cf] will not be managed by Spring
==>  Preparing: select id, username, password, age, height, gender, class_id, is_delete from students where id = ?
***SqlExecuteInterceptor.intercept***
==> Parameters: 8(Integer)
<==    Columns: id, username, password, age, height, gender, class_id, is_delete
<==        Row: 8, 汪子韬, lq2fks1eg5, 24, 161.84, 女, 5, 0
<==      Total: 1
Closing non transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@6ab146ea]

***ResponsePostAdvice.supports***
***ResponsePostAdvice.beforeBodyWrite***

***LogInterceptor.postHandle***
***ResponsePostInterceptor.postHandle***
***LogInterceptor.afterCompletion***
[2024-01-24 10:52:34.193_193] [WARN ] [http-nio-8080-exec-3] [LogInterceptor.java:57] → [LogInterceptor.postHandle: Finished processing request at 2024-01-24T02:52:34.193563200Z - /students/8 in 2804 ms. Status code: 200]
[2024-01-24 10:52:34.965_965] [INFO ] [http-nio-8080-exec-3] [LogInterceptor.java:61] → [{"traceId":"372050c0aed44614aa5912323cfcc836","end_date":"2024-01-24T10:52:34.9545052+08:00[Asia/Shanghai]","cost":2804,"remoteHost":"0:0:0:0:0:0:0:1","remoteAddr":"0:0:0:0:0:0:0:1","remotePort":5905,"method":"GET","requestURI":"/students/8","status":200,"requestContentLength":-1,"sql_count":1,"sql_cost":367,"sql_searched_row_count":1,"currentThreadTime":62,"currentThreadUserTime":31,"currentThreadAllocatedBytes":24682920}]
[2024-01-24 10:52:34.968_968] [WARN ] [http-nio-8080-exec-3] [LogFilter.java:30] → [LogFilter.doFilter: Finished processing request at 2024-01-24T02:52:34.968452Z - /students/8 in 3602 ms. Status code: 200]
***ResponsePostInterceptor.afterCompletion***

***RequestHeaderCheckFilter.doFilter.end***
***LogFilter.doFilter.end***
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

更新数据

***LogFilter.doFilter.start***
***RequestHeaderCheckFilter.doFilter.start***
[2024-01-24 11:24:34.918_918] [WARN ] [http-nio-8080-exec-1] [LogFilter.java:21] → [LogFilter.doFilter: Start processing request at 2024-01-24T03:24:34.917981600Z - /students]

***ResponsePostInterceptor.preHandle***
***LogInterceptor.preHandle***
[2024-01-24 11:24:34.947_947] [WARN ] [http-nio-8080-exec-1] [LogInterceptor.java:37] → [LogInterceptor.postHandle: Start processing request at 2024-01-24T03:24:34.947520700Z - /students]

***StudentController.edit***
Creating a new SqlSession
SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@207e0209] was not registered for synchronization because synchronization is not active
[2024-01-24 11:24:38.701_701] [INFO ] [http-nio-8080-exec-1] [HikariDataSource.java:110] → [practisedb - Starting...]
[2024-01-24 11:24:38.831_831] [INFO ] [http-nio-8080-exec-1] [HikariPool.java:565] → [practisedb - Added connection com.mysql.cj.jdbc.ConnectionImpl@5fb7095]
[2024-01-24 11:24:38.834_834] [INFO ] [http-nio-8080-exec-1] [HikariDataSource.java:123] → [practisedb - Start completed.]
JDBC Connection [HikariProxyConnection@637086707 wrapping com.mysql.cj.jdbc.ConnectionImpl@5fb7095] will not be managed by Spring
==>  Preparing: update students SET username = ?, password = ?, age = ?, height = ?, gender = ?, is_delete = ? where id = ?

***SqlExecuteInterceptor.intercept***
==> Parameters: 杜云(String), RVUY6MDXdu(String), 19(Integer), 173(Integer), 男(String), false(Boolean), 83(Integer)
<==    Updates: 1
Closing non transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@207e0209]
Creating a new SqlSession
SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@56251da2] was not registered for synchronization because synchronization is not active
JDBC Connection [HikariProxyConnection@1108439486 wrapping com.mysql.cj.jdbc.ConnectionImpl@5fb7095] will not be managed by Spring
==>  Preparing: select id, username, password, age, height, gender, class_id, is_delete from students where id = ?

***SqlExecuteInterceptor.intercept***
***SqlReadRowInterceptor.intercept***
==> Parameters: 83(Integer)
<==    Columns: id, username, password, age, height, gender, class_id, is_delete
<==        Row: 83, 杜云, RVUY6MDXdu, 19, 173.00, 男, 5, 0
<==      Total: 1
Closing non transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@56251da2]

***ResponsePostAdvice.supports***
***ResponsePostAdvice.beforeBodyWrite***

***LogInterceptor.postHandle***
***ResponsePostInterceptor.postHandle***
***LogInterceptor.afterCompletion***
[2024-01-24 11:24:39.549_549] [WARN ] [http-nio-8080-exec-1] [LogInterceptor.java:57] → [LogInterceptor.postHandle: Finished processing request at 2024-01-24T03:24:39.549151300Z - /students in 4602 ms. Status code: 200]
[2024-01-24 11:24:39.728_728] [INFO ] [http-nio-8080-exec-1] [LogInterceptor.java:61] → [{"traceId":"1f8722c261494ebf822c8fad242c63be","end_date":"2024-01-24T11:24:39.7205245+08:00[Asia/Shanghai]","cost":4602,"remoteHost":"0:0:0:0:0:0:0:1","remoteAddr":"0:0:0:0:0:0:0:1","remotePort":8335,"method":"PUT","requestURI":"/students","status":200,"requestContentLength":180,"sql_count":2,"sql_cost":338,"sql_searched_row_count":1,"currentThreadTime":125,"currentThreadUserTime":109,"currentThreadAllocatedBytes":30771024}]
[2024-01-24 11:24:39.731_731] [WARN ] [http-nio-8080-exec-1] [LogFilter.java:30] → [LogFilter.doFilter: Finished processing request at 2024-01-24T03:24:39.731376500Z - /students in 4814 ms. Status code: 200]
***ResponsePostInterceptor.afterCompletion***

***RequestHeaderCheckFilter.doFilter.end***
***LogFilter.doFilter.end***
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