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