这里的 web系统操作日志，指的是和业务紧密相关的，记录用户一些关键性的操作。比如 case 的创建、状态变更、删除等。有别于，log.info() 输出的代码日志。各有侧重，互相配合使用。
- 操作日志，结构化、精炼、关键，存储时间久（写表的，没有删除策略会一直存在）。
log.info，灵活随意，内容庞杂凌乱，一般输出到统一的日志中心，保留时长短。
我希望操作日志能有哪些功能?
-
能记录我想要记录的关键数据
-
排查问题时, 能够很方便的查询
-
请求纷乱嘈杂, 尽量减少干扰信息, 能快速定位我想要的信息
-
能够一目了然的呈现一次请求链路上的关键节点及其信息
-
一目了然的呈现某个关键业务case的链路节点及其信息
-
当然, api 使用要简单咯
-
...
- 两条链：
- 系统调用链路。微服务技术体系中有 traceId，可以用来串联单次调用的链路。 --traceId
- 业务 case 操作链路。使用业务 case 主键串联。 --自定义 key
-
数据变更快照。写操作必会涉及到数据变更，所以，希望记录变更前和变更后的数据快照，便于事后排查或故障恢复。
-
操作人信息。操作人、操作时间。
-
其他运行时信息，如当时执行指令的机器环境信息（机器名、IP）。
-
日志组。
当关键节点方法有嵌套调用和方法复用同时存在时，输出的日志链路可能会有歧义。
比如有个「任务删除」操作，同时在「人工删除」和「定时任务自动删除」里被嵌套调用了。这样，单丛输出的日志看，并不能一眼看出是人工删除场景使用的，还是自动任务删除场景使用的。假设任务被误删除了，这时候，谁的锅？如果时人工删除的，找谁删的，如果时自动任务删的，找研发了。这时候，就需要拿着 traceId 去日志中心进一步查询详细信息了。
当然，这个问题如果觉得没有必要解决也是可以的，本人还是觉得解决它还是挺有意思的。所以，引出 日志组 的概念。日志组可嵌套，比如人工删除/删除任务信息/删除详情。
表设计
CREATE TABLE `operate_log` (
`id` bigint(20) unsigned NOT NULL AUTO_INCREMENT COMMENT 'auto',
`trace_id` varchar(255) NOT NULL DEFAULT '' COMMENT 'trace ID',
`log_group` varchar(255) NOT NULL DEFAULT '' COMMENT '日志组',
`operate_name` varchar(255) NOT NULL DEFAULT '' COMMENT '操作名',
`key1` varchar(255) NOT NULL DEFAULT '' COMMENT '关键词1',
`key2` varchar(255) NOT NULL DEFAULT '' COMMENT '关键词2',
`key3` varchar(255) NOT NULL DEFAULT '' COMMENT '关键词2',
`old_content` text COMMENT '修改前内容',
`new_content` text COMMENT '修改后内容',
`remark` varchar(255) DEFAULT NULL COMMENT '备注',
`octo` varchar(255) DEFAULT NULL COMMENT 'octo信息',
`status` int(2) NOT NULL DEFAULT '0' COMMENT '0-正常,1-失败',
`operator` varchar(100) NOT NULL DEFAULT '' COMMENT '操作人',
`operate_time` datetime(3) NOT NULL DEFAULT CURRENT_TIMESTAMP(3) COMMENT '操作时间',
PRIMARY KEY (`id`),
KEY `ix_trace_id` (`trace_id`),
KEY `ix_operate_name` (`operate_name`),
KEY `ix_key1` (`key1`),
KEY `ix_key2` (`key2`),
KEY `ix_key3` (`key3`),
KEY `ix_operator` (`operator`),
KEY `ix_operate_time` (`operate_time`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4;
- trace_id 和 key_i 对应两条链，前者是系统层面的调用链路，后者是业务层面的 case 操作链路，预留三个关键词。
- log_group 和 operate_name 记录操作名和所在的日志组。
- old_content 和 new_content 分别记录修改前后的内容，具体内容，依据情况灵活设置，比如接口请求时，我会在 old_content 里放入参，new_content 里放出参。
- remark 其他你觉得需要记录的内容。
- octo 指一些运行时环境信息，我这里会放
环境名.机器名.ip。 - status 可选，实际用处不大。
- operator、operate_time 操作人和操作时间。
- 索引方面，实际使用发现，一般使用 operate_name、key1、key2 就够了，所以为了可以节省空间，可以只设置三个索引就可以了。
PS：可以考虑设置成分区表，按天分区，这样后续清理历史日志时也会方便很多。
工具代码
代码不全，仅分享我的思路。可根据自己的使用场景改造成自己需要的。
PS：可先看 使用示例 后回头阅读。
定义 LogGoup 日志组实例规范，用于存储日志组上下文相关信息，和输出日志。具体实现，可以自由发挥。
/**
* <p>
*
* @author L&J
* @version 0.1
* @since 2023/3/2 16:21
*/
public interface LogGroup extends AutoCloseable {
LogGroup getParent();
void setParent(LogGroup parent);
String getName();
void setName(String name);
int getDepth();
void setDepth(int depth);
void addChild(LogGroup child);
boolean isCompleted();
void setCompleted(boolean completed);
void complete();
boolean isSuccess();
void setSuccess(boolean success);
default void close() {
complete();
}
default void addData(String pairs, Object... args) {
// NOP
}
/**
* 输出日志
*
* @param operateName 操作名
* @param fresh 修改后数据
* @param old 修改前数据
* @param keys 业务key
*/
void log(String operateName, Object fresh, Object old, Serializable... keys);
}
日志工具 LogGroupUtil，构建日志组实例、处理线程上下文、日志组父子关系等事情。
/**
* <p>
*
* @author L&J
* @version 0.1
* @since 2022/8/14 8:18 下午
*/
public class LogGroupUtil {
private static boolean inited;
/**
* maxGroupNameLength 依据表字段长度设计而定
*/
private static int maxGroupNameLength = 255;
/**
* 日志组嵌套层级限制, 最终拼接字符长度受 maxGroupNameLength 限制.
*/
private static int maxDepth = 100;
private static final TransmittableThreadLocal<LogGroup> contextHolder = new TransmittableThreadLocal<>();
private static Supplier logGroupSupplier = () -> new LogGroupImpl();
public static <T extends LogGroup> void init(Supplier<T> logGroupSupplier) {
init(logGroupSupplier, 255, 100);
}
public static void init(int maxGroupNameLength, int maxDepth) {
// 默认使用 LogGroup
init(LogGroupImpl::new, maxGroupNameLength, maxDepth);
}
public static <T extends LogGroup> void init(Supplier<T> logGroupSupplier, int maxGroupNameLength, int maxDepth) {
if (inited) {
return;
}
if (logGroupSupplier != null) {
LogGroupUtil.logGroupSupplier = logGroupSupplier;
}
LogGroupUtil.maxGroupNameLength = maxGroupNameLength;
LogGroupUtil.maxDepth = maxDepth;
inited = true;
}
/**
* Root LogGroup
* <p>
* 忽略上线文中读取到的 parent LogGroup (如有).
* 始终以当前组名为起点拼接最终的日志组拼接字符串.
* 比如在请求的开始 Controller 层可以使用.
* 无需担心 LogGroup 线程污染的问题 (未正常关闭)
*/
public static LogGroup newRootLogGroup(String name) {
return newLogGroupInner(name, true);
}
/**
* 自动判断是构建 root Group 还是 嵌套 Group.
* 但没有关闭, 线程复用会受影响.
*/
public static LogGroup newLogGroup(String name) {
return newLogGroupInner(name, !hasLogGroup());
}
private static LogGroup newLogGroupInner(String name, boolean isRoot) {
// 同线程内开启新Group前, 必须手动将上一个Group完成掉. 否则, 预期和上个是并列兄弟, 结果, 被当成了父亲.
// 子线程内开启, parent 自然是真正父亲. 父亲可以帮儿子完成, 如果儿子没有显示完成.
LogGroup parent = contextHolder.get();
// root 忘了关闭呢? 没有父亲, 谁帮我关闭? 线程复用时, 就错了
if (isRoot && parent != null) {
// 明确制定了新建root, 则忽略已有 parent
parent = null;
contextHolder.remove();
}
LogGroup logGroup = (LogGroup) logGroupSupplier.get();
if (parent != null) {
int currDepth = parent.getDepth() + 1;
// 如果超出最大深度, 则当前新建的作为 root, 即使它在 100 层
if (currDepth >= maxDepth) {
} else {
logGroup.setDepth(currDepth);
logGroup.setParent(parent);
name = parent.getName() + "/" + name;
// '一级G/二级G/三级G'
// name 长度限制 truncate
name = truncateHead(name);
parent.addChild(logGroup);
}
}
logGroup.setName(name);
contextHolder.set(logGroup);
return logGroup;
}
private static String truncateHead(String pathName) {
if (pathName.length() <= maxGroupNameLength) {
return pathName;
}
int i = pathName.length() - maxGroupNameLength;
return pathName.substring(i);
}
// 当前所在 Group, 没有, 自动 new 一个 root Group
public static LogGroup current() {
LogGroup logGroup = contextHolder.get();
if (logGroup == null) {
logGroup = LogGroupUtil.newLogGroup("");
}
return logGroup;
}
public static boolean hasLogGroup() {
return contextHolder.get() != null;
}
static void complete(LogGroup logGroup) {
if (logGroup.isCompleted()) {
return;
}
// 为保证每个 LogGroup At-Most Once compete() 调用.
// 嵌套 LogGroup 可能没有显示调用 complete(),
// for (LogGroup child : children) {
// // 保证子线程(多个) 里的 Group 都关闭了
// child.complete();
// }
// 可保证同线程内嵌套 Group 够关闭
// 则, 当前就不是我自己, 此时, 需要帮嵌套 LogGroup 调用 complete().
LogGroup curr;
// ? 同线程嵌套的帮其关闭能够做到, 但, 子线程不行.
// ! 子线程就得必须关闭, 因为外层线程父亲虽然可以做到将子关闭(children记录子信息), 但, 子线程还没有正常运行结束呢, 就错了 !
while ((curr = contextHolder.get()) != logGroup && curr != null) {
curr.complete();
}
logGroup.setCompleted(true);
contextHolder.remove();
// 恢复为 parent
contextHolder.set(logGroup.getParent());
}
}
使用示例
LogGroup logGroup = LogGroupUtil.newRootLogGroup("自定义任务");
//调用方法
addTask(tasks);
logGroup.complete();
public List<VTask> addTask(List<ClueDto> tasks) {
LogGroup logGroup = LogGroupUtil.newLogGroup("新增任务");
Task task = new Task();
// ... 写表
// 输出日志
// 日志名：张飞添加的
// 更改前数据：无
// 更改后数据：刚插入的 task 实例
// 业务key1：任务 id
LogGroupUtil.current().log("张飞添加的", task, null, task.getId());
// 如果记得，就掉下关闭方法，忘了影响也不大，父 group 会帮你关闭
logGroup.complete();
}
日志表会有对应记录，类似：
| id | trace_id | log_group | operate_name | key1 | ... |
|---|---|---|---|---|---|
| 1 | xxx | 自定义任务/新增任务 | 张飞添加的 | 123 |
后续
可能有人会发现，日志组的维护有点费劲，一是要手动 new，二是，要想着调用关闭方法。不关闭的话，可能在线程复用时，可能会有脏数据，引起日志组嵌套层级错误。
总结两个问题：
-
手动创建、关闭有点费劲。使用注解切面可一定程度解决，参见 SysLog 注解切面
-
线程数据污染问题。这个问题，有点棘手。
理论上，这类涉及使用线程上下文数据的轮子，都需要在结束后，清理现场。比如某水厂的日志打点工具Cat组件，它有Transaction的概念，类似我这里的LogGroup，一个Transaction结束后，需要调用complete方法，否则，该Transaction不会正常上报。当然它也有类似LogGroup的优化操作，父级会帮子级完成。
更重要的是，由于它在该水厂内部属于「一等公民」，享受着别人拥趸的地位，所以，一些脚手架工具，会在线程池层面做优化，线程结束后，会自动调用complete方法。这我就没法比咯 🐶！
SysLog 注解切面
/**
* @author L&J
*/
@Target({ElementType.METHOD})
@Retention(RetentionPolicy.RUNTIME)
@Inherited
@Documented
public @interface SysLog {
/**
* 日志组, 默认 类简单名.方法名
*/
String group() default "";
/**
* 默认 "SysLog"
*/
String name() default "SysLog";
/**
* 是否记录入参
*/
boolean in() default true;
/**
* 是否记录出参
*/
boolean out() default true;
/**
* 是否 root log group
*/
boolean rootGroup() default false;
}
/**
* @author L&J
* @since 2023-02-24 14:28:25
*/
@Slf4j
@Aspect
@Component
public class SysLogAspect {
private final static String TAG = "SysLogAspect";
private static final JsonFilterUtil.FilterConfig FILTER_CONFIG = new JsonFilterUtil.FilterConfig()
.arrayMaxSize(100)
.b64ImageMaxLen(10);
private static final String VOID = "void";
@Pointcut(
"@annotation(com.xxx.annotation.SysLog)"
)
public void pointcut() {
}
@SneakyThrows
@Around("pointcut()")
public Object doAround(ProceedingJoinPoint pjp) {
MethodSignature signature = (MethodSignature) pjp.getSignature();
Method method = signature.getMethod();
SysLog sysLogAnnt = AnnotationUtils.findAnnotation(method, SysLog.class);
if (sysLogAnnt == null) {
return pjp.proceed();
}
VOperateLogV2 logEntity = OperateLogUtil.createLogInstance();
String group = StrUtil.emptyToDefault(sysLogAnnt.group(), method.getDeclaringClass().getSimpleName() + "." + method.getName());
String name = sysLogAnnt.name();
logEntity.setLogGroup(group);
logEntity.setOperateName(name);
if (sysLogAnnt.in()) {
// 解析入参
Object[] args = ObjectUtil.defaultIfNull(pjp.getArgs(), new Object[]{});
LinkedHashMap<String, Object> argMap = SpElAssist.getArgMap(method, args);
// 入参放 old 里
if (argMap.isEmpty() == false) {
logEntity.setOldContent(JsonFilterUtil.toJSONString(argMap));
}
}
Object result = null;
LogGroup logGroup = sysLogAnnt.rootGroup() ? LogGroupUtil.newRootLogGroup(group) : LogGroupUtil.newLogGroup(group);
long start = System.currentTimeMillis();
try {
return result = pjp.proceed();
} catch (Exception e) {
// 特殊异常, 不是错误
if (e instanceof DialogException || e instanceof SignalException) {
logEntity.setRemark(Utils.truncate(e.getMessage(), 255, ""));
} else {
logEntity.setRemark(ExceptionUtil.stacktraceToString(e, 255));
logEntity.setStatus(1);
logGroup.setSuccess(false);
}
throw e;
} finally {
if (sysLogAnnt.out() && !VOID.equals(signature.getReturnType().getName())) {
logEntity.setNewContent(JsonFilterUtil.toJSONString(result));
}
String remark = logEntity.getRemark();
String costMs = (System.currentTimeMillis() - start) + "ms";
if (remark != null) {
remark = costMs + " " + remark;
} else {
remark = costMs;
}
remark = Utils.truncate(remark, 255, "");
logEntity.setRemark(remark);
OperateLogUtil.logAsync(logEntity);
logGroup.complete();
}
}
}
