1 package org.imageconverter.util.performance;
2
3 import static java.lang.Long.MAX_VALUE;
4 import static java.time.temporal.ChronoUnit.MILLIS;
5 import static java.util.Objects.isNull;
6 import static java.util.stream.Collectors.joining;
7 import static java.util.stream.IntStream.range;
8 import static org.apache.commons.lang3.StringUtils.LF;
9 import static org.apache.commons.lang3.StringUtils.substringBefore;
10 import static org.springframework.boot.logging.LogLevel.DEBUG;
11 import static org.springframework.boot.logging.LogLevel.ERROR;
12 import static org.springframework.boot.logging.LogLevel.FATAL;
13 import static org.springframework.boot.logging.LogLevel.INFO;
14 import static org.springframework.boot.logging.LogLevel.OFF;
15 import static org.springframework.boot.logging.LogLevel.TRACE;
16 import static org.springframework.boot.logging.LogLevel.WARN;
17
18 import java.lang.StackWalker.StackFrame;
19 import java.lang.reflect.Parameter;
20 import java.time.Instant;
21 import java.util.AbstractMap;
22 import java.util.AbstractMap.SimpleEntry;
23 import java.util.List;
24 import java.util.Objects;
25 import java.util.stream.Stream;
26
27 import org.aopalliance.intercept.MethodInterceptor;
28 import org.aopalliance.intercept.MethodInvocation;
29 import org.apache.commons.lang3.Range;
30 import org.apache.commons.lang3.StringUtils;
31 import org.apache.commons.text.StringEscapeUtils;
32 import org.slf4j.Logger;
33 import org.slf4j.LoggerFactory;
34 import org.springframework.beans.factory.annotation.Value;
35 import org.springframework.boot.logging.LogLevel;
36 import org.springframework.stereotype.Component;
37
38 @Component
39 public class PerformanceMonitor implements MethodInterceptor {
40
41 private static final Logger LOGGER = LoggerFactory.getLogger(PerformanceMonitor.class);
42
43 @Value("${spring.application.name:undefined}")
44 private String applicationName;
45
46 @Override
47 public Object invoke(final MethodInvocation invocation) throws Throwable {
48
49 final var start = Instant.now();
50
51 try {
52
53 return invocation.proceed();
54
55 } finally {
56
57 final var end = Instant.now();
58
59 final var duration = MILLIS.between(start, end);
60
61 final var logLevel = getLevel(duration);
62
63 if (isLogging(logLevel)) {
64
65 final var message = "Performance duration [{}] milliseconds, project [{}], threadId [{}], class [{}], method [{}] with parameters [{}], returnType [{}], caller [{}], stackTrace {}";
66
67 final var threadId = Thread.currentThread().getId();
68
69 final var method = invocation.getMethod();
70
71 final var clazz = invocation.getThis().getClass();
72 final var declaredClazz = method.getDeclaringClass();
73
74 final var methodName = method.getName();
75
76 final var methodArgs = Stream.of(invocation.getArguments())
77 .map(p -> isNull(p) ? "null" : p.toString())
78 .toList();
79
80 final var methodArgsType = Stream.of(method.getParameters())
81 .map(Parameter::getType)
82 .map(Class::getSimpleName)
83 .toList();
84
85 final var parameters = range(0, methodArgs.size())
86 .boxed()
87 .map(i -> methodArgsType.get(i) + ":" + methodArgs.get(i)).collect(joining(","));
88
89 final var methodReturnType = method.getReturnType();
90
91 final var callerAndStack = findCallerAndStack();
92
93 final var clazzString = Objects.equals(clazz, declaredClazz)
94 ? clazz.getName()
95 : declaredClazz.getSimpleName() + ":" + clazz.getName();
96
97 final Object[] params = { duration, applicationName, threadId, clazzString, methodName, parameters, methodReturnType, callerAndStack.getKey(), LF.concat(callerAndStack.getValue()) };
98
99 executeLog(logLevel, message, params);
100 }
101 }
102 }
103
104 private AbstractMap.SimpleEntry<String, String> findCallerAndStack() {
105
106 final var stackList = StackWalker.getInstance()
107 .walk(this::walkThroughStack)
108 .stream()
109 .filter(this::filterNonMatter)
110 .map(trace -> substringBefore(trace.getClassName(), "$$EnhancerBySpringCGLIB") + "." + trace.getMethodName() + ":" + trace.getLineNumber())
111 .toList();
112
113 final var stackListNoTrap = stackList.stream()
114 .filter(s -> !StringUtils.containsAnyIgnoreCase(s, ".filter."))
115 .toList();
116
117 final var caller = stackListNoTrap.isEmpty()
118 ? this.getClass().getSimpleName()
119 : stackListNoTrap.get(stackListNoTrap.size() - 1);
120
121 final var stackTrace = stackList.stream().collect(joining(LF));
122
123 return new AbstractMap.SimpleEntry<>(caller, stackTrace);
124 }
125
126 private boolean filterNonMatter(final StackFrame stackFrame) {
127 return !StringUtils.containsAnyIgnoreCase(stackFrame.getClassName(), this.getClass().getSimpleName())
128 && !StringUtils.containsAnyIgnoreCase(stackFrame.getClassName(), "$$FastClassBySpringCGLIB");
129 }
130
131 private List<StackFrame> walkThroughStack(final Stream<StackFrame> stackFrameStream) {
132 return stackFrameStream
133 .filter(frame -> frame.getClassName().contains("org.imageconverter"))
134 .toList();
135 }
136
137 private void executeLog(final LogLevel level, final String message, final Object... arguments) {
138
139 final var finalMsg = StringEscapeUtils.escapeJava(message);
140
141 switch (level) {
142 case TRACE -> LOGGER.trace(finalMsg, arguments);
143 case DEBUG -> LOGGER.debug(finalMsg, arguments);
144 case INFO -> LOGGER.info(finalMsg, arguments);
145 case WARN -> LOGGER.warn(finalMsg, arguments);
146 case ERROR, FATAL -> LOGGER.error(finalMsg, arguments);
147 default -> LOGGER.debug(finalMsg, arguments);
148 }
149 }
150
151 private LogLevel getLevel(final long duration) {
152
153 final var offRange = Range.between(0L, 500L);
154 final var traceRange = Range.between(501L, 1000L);
155 final var debugRange = Range.between(1001L, 2000L);
156 final var infoRange = Range.between(2001L, 3000L);
157 final var warnRange = Range.between(3001L, 10000L);
158 final var errorRange = Range.between(10001L, MAX_VALUE);
159
160 final var ranges = List.of(
161 new SimpleEntry<>(offRange, OFF),
162 new SimpleEntry<>(traceRange, TRACE),
163 new SimpleEntry<>(debugRange, DEBUG),
164 new SimpleEntry<>(infoRange, INFO),
165 new SimpleEntry<>(warnRange, WARN),
166 new SimpleEntry<>(errorRange, ERROR)
167 );
168
169 return ranges.stream()
170 .filter(entry -> entry.getKey().contains(duration))
171 .map(SimpleEntry::getValue)
172 .findFirst()
173 .orElse(FATAL);
174 }
175
176 public String createExpression(final Class<?> clazz, final Class<?>... parentClazzes) {
177
178 final var pointCut = new StringBuilder();
179
180 pointCut.append("execution ( public * ").append(clazz.getName()).append(".*(..))");
181
182 for (final var parentClazz : parentClazzes) {
183 pointCut.append(" || (").append("execution ( public * ").append(parentClazz.getName()).append(".*(..))").append(" && target (").append(clazz.getName()).append(")").append(")");
184 }
185
186 return pointCut.toString();
187 }
188
189 private boolean isLogging(final LogLevel logLevel) {
190
191 if (logLevel == OFF) {
192 return false;
193 }
194
195 if (logLevel == FATAL) {
196 return true;
197 }
198
199 return (logLevel == TRACE && LOGGER.isTraceEnabled())
200 || (logLevel == DEBUG && LOGGER.isDebugEnabled())
201 || (logLevel == INFO && LOGGER.isInfoEnabled())
202 || (logLevel == WARN && LOGGER.isWarnEnabled())
203 || (logLevel == ERROR && LOGGER.isErrorEnabled());
204 }
205 }