Logging Aspect to log methods at start and finish, exceptions, configurable.

 package com.darkona.awesome.tools;


import lombok.extern.slf4j.Slf4j;
import org.apache.commons.lang3.StringUtils;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.reflect.MethodSignature;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.event.Level;

import java.time.Duration;
import java.time.Instant;
import java.util.Arrays;
import java.util.HashMap;
import java.util.List;
import java.util.Map;
import java.util.stream.Collectors;

@Aspect
@Slf4j
public class LoggedAspect {

private static final String METHOD_NAME = "methodName";
private static final String METHOD_TYPE = "methodType";
private static final String CLASS_NAME = "className";
private static final String RETURN_VALUE = "returnValue";
private static final String THROWABLES = "throwables";
private static final String DURATION = "duration";
private static final String LINE = "line";



private record Data(Map<String, String> map, Arg[] args, List<String> throwables, Instant start) {}

@Around("@annotation(options)")
public Object logMethod(ProceedingJoinPoint point, Logged options) throws Throwable {

Data data = assembleData(point);
Logger log = LoggerFactory.getLogger(point.getClass());
Level level = getLoggingLevel(options);

logCall(log, level, data, options);
try {
Object o = point.proceed();
data.map.put(DURATION, String.valueOf(Duration.between(data.start, Instant.now()).toMillis()));
if(!StringUtils.isEmpty(options.exitMsg() )|| options.logReturnValue()){
data.map.put(RETURN_VALUE, objectString(o));
}else{
data.map.put(RETURN_VALUE, "undefined");
}

logExit(log, level, data, options);
return o;
} catch (Throwable e) {
// log exception
throw e;
}
}

private Data assembleData(ProceedingJoinPoint point) {

MethodSignature method = (MethodSignature) point.getSignature();
int paramCount = method.getMethod().getParameterCount();
Arg[] params = new Arg[paramCount];
int index = 0;
while (index < paramCount) {
params[index] = new Arg(method.getParameterTypes()[index].getSimpleName(), method.getParameterNames()[index],
objectString(point.getArgs()[index].toString()));
index++;
}

Map<String, String> data = new HashMap<>() {{
put(CLASS_NAME, point.getSignature().getDeclaringType().getName());
put(METHOD_TYPE, method.getDeclaringTypeName());
put(METHOD_NAME, method.getName());
put(LINE, String.valueOf(point.getSourceLocation().getLine()));
}};

return new Data(data, params, Arrays.stream(method.getExceptionTypes()).map(Class::getSimpleName).toList(), Instant.now());
}


private Level getLoggingLevel(Logged options) {
try {
for (Level lvl : Level.values()) {
if (lvl.toString().equals(options.logLevel())) {
return Level.valueOf(options.logLevel());
}
}
return Level.INFO;
} catch (IllegalArgumentException e) {
log.warn("Incorrect log level set, using info.");
return Level.INFO;
}
}

private void logCall(Logger log, Level level, Data data, Logged options) {
String message;
if (!StringUtils.isEmpty(options.callMsg()) || options.logCall()) {
StringBuilder builder = initialMessage(data.map).append(" called ");
if (options.logArgs()) builder.append("with args: (").append(makePrintableArgs(data.args, options.logArgValues())).append(")");
message = builder.toString();
log.atLevel(level).log(message);
} else {
message = applyPattern(options.callMsg(), data);
log.atLevel(level).log(message);
}
}

private void logExit(Logger log, Level level, Data data, Logged options) {

String message;

if (!StringUtils.isEmpty(options.exitMsg()) || options.logExit()) {
StringBuilder builder = initialMessage(data.map).append(" returned ");
if (options.logTime()) {
builder.append("in ").append(data.map.get(DURATION)).append("ms ");
}
if (options.logReturnValue()) {
builder.append("|| Value= ").append(data.map.get(RETURN_VALUE));
}
message = builder.toString();
log.atLevel(level).log(message);
} else {
message = applyPattern(options.exitMsg(), data);
log.atLevel(level).log(message);
}

}

private StringBuilder initialMessage(Map<String, String> map) {
return new StringBuilder(map.get(METHOD_TYPE)).append(" ").append(map.get(METHOD_NAME));
}

private String applyPattern(String message, Data data) {

String[] tokenKeys = {"%c", "%t", "%m", "%d", "%r", "%e", "%r"};
String[] tokenValues = {
data.map.get(CLASS_NAME),
data.map.get(METHOD_TYPE),
data.map.get(METHOD_NAME),
data.map.get(DURATION),
data.map.get(RETURN_VALUE),
String.join(", ", data.throwables),
data.map.get(RETURN_VALUE)
};


String pass = StringUtils.replaceEach(message, tokenKeys, tokenValues);

for (int i = 0; i < data.args.length; i++) {
String[] keys= {"%k[" + i + "]", "%a[" + i + "]", "%w[" + i + "]"};
String[] vals = {data.args[i].className, data.args[i].name, data.args[i].value};
pass = StringUtils.replaceEach(message, keys, vals);
}
return pass;
}

private record Arg(String className, String name, String value) {
public String toString(boolean values) {
String out = "(" + className + ")" + name;
return values ? (out + " = " + value) : out;
}
}

private String objectString(Object object) {
return object != null ? object.toString() : "NULL";
}

public String makePrintableArgs(Arg[] params, boolean values) {
return Arrays.stream(params).map(p -> p.toString(values)).collect(Collectors.joining(", "));
}


}

Comments