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