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