1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19 package org.apache.maven.cling.event;
20
21 import java.io.File;
22 import java.nio.file.Path;
23 import java.time.Duration;
24 import java.time.Instant;
25 import java.time.ZoneId;
26 import java.time.ZonedDateTime;
27 import java.time.temporal.ChronoUnit;
28 import java.util.List;
29 import java.util.Objects;
30
31 import org.apache.maven.api.MonotonicClock;
32 import org.apache.maven.api.services.MessageBuilder;
33 import org.apache.maven.api.services.MessageBuilderFactory;
34 import org.apache.maven.execution.AbstractExecutionListener;
35 import org.apache.maven.execution.BuildFailure;
36 import org.apache.maven.execution.BuildSuccess;
37 import org.apache.maven.execution.BuildSummary;
38 import org.apache.maven.execution.ExecutionEvent;
39 import org.apache.maven.execution.MavenExecutionResult;
40 import org.apache.maven.execution.MavenSession;
41 import org.apache.maven.plugin.MojoExecution;
42 import org.apache.maven.plugin.descriptor.MojoDescriptor;
43 import org.apache.maven.project.MavenProject;
44 import org.slf4j.ILoggerFactory;
45 import org.slf4j.Logger;
46 import org.slf4j.LoggerFactory;
47
48 import static org.apache.maven.cling.utils.CLIReportingUtils.formatDuration;
49 import static org.apache.maven.cling.utils.CLIReportingUtils.formatTimestamp;
50
51
52
53
54
55 public class ExecutionEventLogger extends AbstractExecutionListener {
56 private static final int MAX_LOG_PREFIX_SIZE = 8;
57 private static final int PROJECT_STATUS_SUFFIX_SIZE = 20;
58 private static final int MIN_TERMINAL_WIDTH = 60;
59 private static final int DEFAULT_TERMINAL_WIDTH = 80;
60 private static final int MAX_TERMINAL_WIDTH = 130;
61 private static final int MAX_PADDED_BUILD_TIME_DURATION_LENGTH = 9;
62
63 private final MessageBuilderFactory messageBuilderFactory;
64 private final Logger logger;
65 private int terminalWidth;
66 private int lineLength;
67 private int maxProjectNameLength;
68 private int totalProjects;
69 private volatile int currentVisitedProjectCount;
70
71 public ExecutionEventLogger(MessageBuilderFactory messageBuilderFactory) {
72 this(messageBuilderFactory, LoggerFactory.getLogger(ExecutionEventLogger.class));
73 }
74
75 public ExecutionEventLogger(MessageBuilderFactory messageBuilderFactory, Logger logger) {
76 this(messageBuilderFactory, logger, -1);
77 }
78
79 public ExecutionEventLogger(MessageBuilderFactory messageBuilderFactory, Logger logger, int terminalWidth) {
80 this.logger = Objects.requireNonNull(logger, "logger cannot be null");
81 this.messageBuilderFactory = messageBuilderFactory;
82 this.terminalWidth = terminalWidth;
83 }
84
85 private static String chars(char c, int count) {
86 return String.valueOf(c).repeat(Math.max(0, count));
87 }
88
89 private void infoLine(char c) {
90 infoMain(chars(c, lineLength));
91 }
92
93 private void infoMain(String msg) {
94 logger.info(builder().strong(msg).toString());
95 }
96
97 private void init() {
98 if (maxProjectNameLength == 0) {
99 if (terminalWidth < 0) {
100 terminalWidth = messageBuilderFactory.getTerminalWidth();
101 }
102 terminalWidth = Math.min(
103 MAX_TERMINAL_WIDTH,
104 Math.max(terminalWidth <= 0 ? DEFAULT_TERMINAL_WIDTH : terminalWidth, MIN_TERMINAL_WIDTH));
105 lineLength = terminalWidth - MAX_LOG_PREFIX_SIZE;
106 maxProjectNameLength = lineLength - PROJECT_STATUS_SUFFIX_SIZE;
107 }
108 }
109
110 @Override
111 public void projectDiscoveryStarted(ExecutionEvent event) {
112 if (logger.isInfoEnabled()) {
113 init();
114 logger.info("Scanning for projects...");
115 }
116 }
117
118 @Override
119 public void sessionStarted(ExecutionEvent event) {
120 if (logger.isInfoEnabled() && event.getSession().getProjects().size() > 1) {
121 init();
122 infoLine('-');
123
124 infoMain("Reactor Build Order:");
125
126 logger.info("");
127
128 final List<MavenProject> projects = event.getSession().getProjects();
129 for (MavenProject project : projects) {
130 int len = lineLength
131 - project.getName().length()
132 - project.getPackaging().length()
133 - 2;
134 logger.info("{}{}[{}]", project.getName(), chars(' ', (len > 0) ? len : 1), project.getPackaging());
135 }
136
137 final List<MavenProject> allProjects = event.getSession().getAllProjects();
138
139 currentVisitedProjectCount = allProjects.size() - projects.size();
140 totalProjects = allProjects.size();
141 }
142 }
143
144 @Override
145 public void sessionEnded(ExecutionEvent event) {
146 if (logger.isInfoEnabled()) {
147 init();
148 if (event.getSession().getProjects().size() > 1) {
149 logReactorSummary(event.getSession());
150 }
151
152 ILoggerFactory iLoggerFactory = LoggerFactory.getILoggerFactory();
153
154 if (iLoggerFactory instanceof org.apache.maven.logging.api.LogLevelRecorder recorder
155 && recorder.hasReachedMaxLevel()) {
156 event.getSession()
157 .getResult()
158 .addException(
159 new Exception("Build failed due to log statements with a higher severity than allowed. "
160 + "Fix the logged issues or remove flag --fail-on-severity (-fos)."));
161 }
162
163 logResult(event.getSession());
164
165 logStats(event.getSession());
166
167 infoLine('-');
168 }
169 }
170
171 private boolean isSingleVersionedReactor(MavenSession session) {
172 boolean result = true;
173
174 MavenProject topProject = session.getTopLevelProject();
175 List<MavenProject> sortedProjects = session.getProjectDependencyGraph().getSortedProjects();
176 for (MavenProject mavenProject : sortedProjects) {
177 if (!topProject.getVersion().equals(mavenProject.getVersion())) {
178 result = false;
179 break;
180 }
181 }
182
183 return result;
184 }
185
186 private void logReactorSummary(MavenSession session) {
187 boolean isSingleVersion = isSingleVersionedReactor(session);
188
189 infoLine('-');
190
191 StringBuilder summary = new StringBuilder("Reactor Summary");
192 if (isSingleVersion) {
193 summary.append(" for ");
194 summary.append(session.getTopLevelProject().getName());
195 summary.append(" ");
196 summary.append(session.getTopLevelProject().getVersion());
197 }
198 summary.append(":");
199 infoMain(summary.toString());
200
201 logger.info("");
202
203 MavenExecutionResult result = session.getResult();
204
205 List<MavenProject> projects = session.getProjects();
206
207 StringBuilder buffer = new StringBuilder(128);
208
209 for (MavenProject project : projects) {
210 buffer.append(project.getName());
211 buffer.append(' ');
212
213 if (!isSingleVersion) {
214 buffer.append(project.getVersion());
215 buffer.append(' ');
216 }
217
218 if (buffer.length() <= maxProjectNameLength) {
219 while (buffer.length() < maxProjectNameLength) {
220 buffer.append('.');
221 }
222 buffer.append(' ');
223 }
224
225 BuildSummary buildSummary = result.getBuildSummary(project);
226
227 if (buildSummary == null) {
228 buffer.append(builder().warning("SKIPPED"));
229 } else if (buildSummary instanceof BuildSuccess) {
230 buffer.append(builder().success("SUCCESS"));
231 buffer.append(" [");
232 String buildTimeDuration = formatDuration(buildSummary.getExecTime());
233 int padSize = MAX_PADDED_BUILD_TIME_DURATION_LENGTH - buildTimeDuration.length();
234 if (padSize > 0) {
235 buffer.append(chars(' ', padSize));
236 }
237 buffer.append(buildTimeDuration);
238 buffer.append(']');
239 } else if (buildSummary instanceof BuildFailure) {
240 buffer.append(builder().failure("FAILURE"));
241 buffer.append(" [");
242 String buildTimeDuration = formatDuration(buildSummary.getExecTime());
243 int padSize = MAX_PADDED_BUILD_TIME_DURATION_LENGTH - buildTimeDuration.length();
244 if (padSize > 0) {
245 buffer.append(chars(' ', padSize));
246 }
247 buffer.append(buildTimeDuration);
248 buffer.append(']');
249 }
250
251 logger.info(buffer.toString());
252 buffer.setLength(0);
253 }
254 }
255
256 private void logResult(MavenSession session) {
257 infoLine('-');
258 MessageBuilder buffer = builder();
259
260 if (session.getResult().hasExceptions()) {
261 buffer.failure("BUILD FAILURE");
262 } else {
263 buffer.success("BUILD SUCCESS");
264 }
265 logger.info(buffer.toString());
266 }
267
268 private MessageBuilder builder() {
269 return messageBuilderFactory.builder();
270 }
271
272 private void logStats(MavenSession session) {
273 infoLine('-');
274
275 Instant finish = MonotonicClock.now();
276
277 Duration time = Duration.between(session.getRequest().getStartInstant(), finish);
278
279 String wallClock = session.getRequest().getDegreeOfConcurrency() > 1 ? " (Wall Clock)" : "";
280
281 logger.info("Total time: {}{}", formatDuration(time), wallClock);
282
283 ZonedDateTime rounded = finish.truncatedTo(ChronoUnit.SECONDS).atZone(ZoneId.systemDefault());
284 logger.info("Finished at: {}", formatTimestamp(rounded));
285 }
286
287 @Override
288 public void projectSkipped(ExecutionEvent event) {
289 if (logger.isInfoEnabled()) {
290 init();
291 logger.info("");
292 infoLine('-');
293 String name = event.getProject().getName();
294 infoMain("Skipping " + name);
295 logger.info("{} was not built because a module it depends on failed to build.", name);
296
297 infoLine('-');
298 }
299 }
300
301 @Override
302 public void projectStarted(ExecutionEvent event) {
303 if (logger.isInfoEnabled()) {
304 init();
305 MavenProject project = event.getProject();
306
307 logger.info("");
308
309
310 String projectKey = project.getGroupId() + ':' + project.getArtifactId();
311
312 final String preHeader = "--< ";
313 final String postHeader = " >--";
314
315 final int headerLen = preHeader.length() + projectKey.length() + postHeader.length();
316
317 String prefix = chars('-', Math.max(0, (lineLength - headerLen) / 2)) + preHeader;
318
319 String suffix =
320 postHeader + chars('-', Math.max(0, lineLength - headerLen - prefix.length() + preHeader.length()));
321
322 logger.info(
323 builder().strong(prefix).project(projectKey).strong(suffix).toString());
324
325
326 String building = "Building " + event.getProject().getName() + " "
327 + event.getProject().getVersion();
328
329 if (totalProjects <= 1) {
330 infoMain(building);
331 } else {
332
333 int number;
334 synchronized (this) {
335 number = ++currentVisitedProjectCount;
336 }
337 String progress = " [" + number + '/' + totalProjects + ']';
338
339 int pad = lineLength - building.length() - progress.length();
340
341 infoMain(building + ((pad > 0) ? chars(' ', pad) : "") + progress);
342 }
343
344
345 File currentPom = project.getFile();
346 if (currentPom != null) {
347 MavenSession session = event.getSession();
348 Path current = currentPom.toPath().toAbsolutePath().normalize();
349 Path topDirectory = session.getTopDirectory();
350 if (topDirectory != null && current.startsWith(topDirectory)) {
351 current = topDirectory.relativize(current);
352 }
353 logger.info(" from " + current);
354 }
355
356
357 prefix = chars('-', Math.max(0, (lineLength - project.getPackaging().length() - 4) / 2));
358 suffix = chars('-', Math.max(0, lineLength - project.getPackaging().length() - 4 - prefix.length()));
359 infoMain(prefix + "[ " + project.getPackaging() + " ]" + suffix);
360 }
361 }
362
363 @Override
364 public void mojoSkipped(ExecutionEvent event) {
365 if (logger.isWarnEnabled()) {
366 init();
367 logger.warn(
368 "Goal '{}' requires online mode for execution but Maven is currently offline, skipping",
369 event.getMojoExecution().getGoal());
370 }
371 }
372
373
374
375
376 @Override
377 public void mojoStarted(ExecutionEvent event) {
378 if (logger.isInfoEnabled()) {
379 init();
380 logger.info("");
381
382 MessageBuilder buffer = builder().strong("--- ");
383 append(buffer, event.getMojoExecution());
384 append(buffer, event.getProject());
385 buffer.strong(" ---");
386
387 logger.info(buffer.toString());
388 }
389 }
390
391
392
393
394
395
396
397 @Override
398 public void forkStarted(ExecutionEvent event) {
399 if (logger.isInfoEnabled()) {
400 init();
401 logger.info("");
402
403 MessageBuilder buffer = builder().strong(">>> ");
404 append(buffer, event.getMojoExecution());
405 buffer.strong(" > ");
406 appendForkInfo(buffer, event.getMojoExecution().getMojoDescriptor());
407 append(buffer, event.getProject());
408 buffer.strong(" >>>");
409
410 logger.info(buffer.toString());
411 }
412 }
413
414
415
416
417
418
419
420 @Override
421 public void forkSucceeded(ExecutionEvent event) {
422 if (logger.isInfoEnabled()) {
423 init();
424 logger.info("");
425
426 MessageBuilder buffer = builder().strong("<<< ");
427 append(buffer, event.getMojoExecution());
428 buffer.strong(" < ");
429 appendForkInfo(buffer, event.getMojoExecution().getMojoDescriptor());
430 append(buffer, event.getProject());
431 buffer.strong(" <<<");
432
433 logger.info(buffer.toString());
434
435 logger.info("");
436 }
437 }
438
439 private void append(MessageBuilder buffer, MojoExecution me) {
440 String prefix = me.getMojoDescriptor().getPluginDescriptor().getGoalPrefix();
441 if (prefix == null || prefix.isEmpty()) {
442 prefix = me.getGroupId() + ":" + me.getArtifactId();
443 }
444 buffer.mojo(prefix + ':' + me.getVersion() + ':' + me.getGoal());
445 if (me.getExecutionId() != null) {
446 buffer.a(' ').strong('(' + me.getExecutionId() + ')');
447 }
448 }
449
450 private void appendForkInfo(MessageBuilder buffer, MojoDescriptor md) {
451 StringBuilder buff = new StringBuilder();
452 if (md.getExecutePhase() != null && !md.getExecutePhase().isEmpty()) {
453
454 if (md.getExecuteLifecycle() != null && !md.getExecuteLifecycle().isEmpty()) {
455 buff.append('[');
456 buff.append(md.getExecuteLifecycle());
457 buff.append(']');
458 }
459 buff.append(md.getExecutePhase());
460 } else {
461
462 buff.append(':');
463 buff.append(md.getExecuteGoal());
464 }
465 buffer.strong(buff.toString());
466 }
467
468 private void append(MessageBuilder buffer, MavenProject project) {
469 buffer.a(" @ ").project(project.getArtifactId());
470 }
471
472 @Override
473 public void forkedProjectStarted(ExecutionEvent event) {
474 if (logger.isInfoEnabled()
475 && event.getMojoExecution().getForkedExecutions().size() > 1) {
476 init();
477 logger.info("");
478 infoLine('>');
479
480 infoMain("Forking " + event.getProject().getName() + " "
481 + event.getProject().getVersion());
482
483 infoLine('>');
484 }
485 }
486 }