View Javadoc
1   package org.imageconverter.util.logging;
2   
3   import static java.lang.String.format;
4   import static java.util.Locale.ROOT;
5   import static java.util.Objects.nonNull;
6   import static java.util.Optional.ofNullable;
7   import static org.apache.commons.lang3.StringUtils.containsAny;
8   import static org.apache.commons.lang3.exception.ExceptionUtils.getRootCauseMessage;
9   import static org.springframework.boot.logging.LogLevel.OFF;
10  
11  import java.lang.reflect.Field;
12  import java.time.Instant;
13  import java.util.Arrays;
14  import java.util.HashMap;
15  import java.util.StringJoiner;
16  
17  import org.apache.commons.lang3.reflect.FieldUtils;
18  import org.apache.commons.text.StringEscapeUtils;
19  import org.aspectj.lang.ProceedingJoinPoint;
20  import org.aspectj.lang.annotation.Around;
21  import org.aspectj.lang.annotation.Aspect;
22  import org.aspectj.lang.annotation.Pointcut;
23  import org.aspectj.lang.reflect.CodeSignature;
24  import org.aspectj.lang.reflect.MethodSignature;
25  import org.slf4j.Logger;
26  import org.slf4j.LoggerFactory;
27  import org.springframework.boot.logging.LogLevel;
28  import org.springframework.stereotype.Component;
29  
30  /**
31   * The Aspect to log the method enters and method exists.
32   * 
33   * @author Fernando Romulo da Silva
34   */
35  @Aspect
36  @Component
37  public class LoggableAspect {
38  
39      /**
40       * The pointcut to annotated class.
41       */
42      @Pointcut("@annotation(org.imageconverter.util.logging.Loggable)")
43      public void annotatedMethod() {
44  	// just to execute the Around
45      }
46  
47      /**
48       * The pointcut to annotated method.
49       */
50      @Pointcut("@within(org.imageconverter.util.logging.Loggable)")
51      public void annotatedClass() {
52  	// just to execute the Around
53      }
54  
55      /**
56       * Execute the wrap method.
57       * 
58       * @param point The object that support around advice in @AJ aspects
59       * @return The methot's return
60       * @throws Throwable If something wrong happens
61       */
62      @Around("execution(* *(..)) && (annotatedMethod() || annotatedClass())")
63      public Object log(final ProceedingJoinPoint point) throws Throwable {
64  
65  	final var codeSignature = (CodeSignature) point.getSignature();
66  	final var methodSignature = (MethodSignature) point.getSignature();
67  	final var method = methodSignature.getMethod();
68  
69  	final var declaringClass = method.getDeclaringClass();
70  	
71  	final var target = point.getTarget();
72  
73  	final var logger = getLogger(declaringClass, target);
74  
75  	final var annotation = ofNullable(method.getAnnotation(Loggable.class)) //
76  			.orElse(declaringClass.getAnnotation(Loggable.class));
77  
78  	final var level = annotation.value();
79  	final var errorLevel = annotation.errorValue();
80  	
81  	final var unit = annotation.unit();
82  	final var showArgs = annotation.showArgs();
83  	final var showResult = annotation.showResult();
84  	final var showExecutionTime = annotation.showExecutionTime();
85  
86  	final var methodName = method.getName();
87  	final var methodArgs = point.getArgs();
88  	final var methodParams = codeSignature.getParameterNames();
89  
90  	executeLog(logger, level, entryMessage(methodName, showArgs, methodParams, methodArgs));
91  
92  	final var start = Instant.now();
93  
94  	final var lowerCaseUnit = unit.name().toLowerCase(ROOT);
95  
96  	try {
97  
98  	    final var response = ofNullable(point.proceed()) //
99  			    .orElse("void");
100 
101 	    final var end = Instant.now();
102 
103 	    final var duration = format("%s %s", unit.between(start, end), lowerCaseUnit);
104 
105 	    executeLog(logger, level, exitMessage(methodName, duration, response, showResult, showExecutionTime));
106 
107 	    return response;
108 
109 	} catch (final Exception ex) { // NOPMD - point.proceed() throw it
110 
111 	    final var end = Instant.now();
112 
113 	    final var duration = format("%s %s", unit.between(start, end), lowerCaseUnit);
114 
115 	    executeLog(logger, errorLevel, errorMessage(methodName, duration, ex, showExecutionTime));
116 
117 	    throw ex;
118 	}
119 
120     }
121 
122     private String entryMessage(final String methodName, final boolean showArgs, final String[] params, final Object... args) {
123 	final var message = new StringJoiner(" ").add("Started").add(methodName).add("method");
124 
125 	if (showArgs && nonNull(params) && nonNull(args) && params.length == args.length) {
126 
127 	    final var values = new HashMap<String, Object>(params.length);
128 
129 	    for (int i = 0; i < params.length; i++) {
130 		values.put(params[i], args[i]);
131 	    }
132 
133 	    message.add("with args:").add(values.toString());
134 	}
135 
136 	return message.toString();
137     }
138 
139     private String exitMessage(final String methodName, final String duration, final Object result, final boolean showResult, final boolean showExecutionTime) {
140 	final var message = new StringJoiner(" ").add("Finished").add(methodName).add("method");
141 
142 	if (showExecutionTime) {
143 	    message.add("in").add(duration);
144 	}
145 
146 	if (showResult) {
147 	    message.add("with return:").add(result.toString());
148 	}
149 
150 	return message.toString();
151     }
152 
153     private String errorMessage(final String methodName, final String duration, final Throwable ex, final boolean showExecutionTime) {
154 
155 	final var message = new StringJoiner(" ").add("Finished").add(methodName).add("method").add("with").add("error").add(getRootCauseMessage(ex));
156 
157 	if (showExecutionTime) {
158 	    message.add("in").add(duration);
159 	}
160 
161 	return message.toString();
162     }
163 
164     private void executeLog(final Logger logger, final LogLevel level, final String message) {
165 	
166 	if (OFF.equals(level)) {
167 	    return;
168 	}
169 	
170 	final var finalMsg = StringEscapeUtils.escapeJava(message);
171 	
172 	switch (level) { // NOPMD - SwitchStmtsShouldHaveDefault: Actually we have a 'default'
173 		case TRACE -> logger.trace(finalMsg);
174 		case DEBUG -> logger.debug(finalMsg);
175 		case INFO -> logger.info(finalMsg);
176 		case WARN -> logger.warn(finalMsg);
177 		case ERROR, FATAL -> logger.error(finalMsg);
178 		default -> logger.debug(finalMsg);
179 	}
180     }
181     
182     private Logger getLogger(final Class<?> clazz, final Object object) {
183 	
184 	try {
185 	    
186 	    final var fields = clazz.getDeclaredFields();
187 			    
188 	    final var fieldOptional = Arrays.stream(fields)
189 			    .map(Field::getName)
190 			    .filter(field -> containsAny(field, "logger", "LOGGER", "log", "LOG"))
191 			    .findFirst();
192 	    
193 	    if (fieldOptional.isEmpty()) {
194 		return LoggerFactory.getLogger(clazz);
195 	    }
196 	    
197 	    return (Logger) FieldUtils.readDeclaredField(object, fieldOptional.get(), true);
198 	    
199 	} catch (final IllegalAccessException | SecurityException ex) {
200 	    return LoggerFactory.getLogger(clazz);
201 	}
202     }
203 }