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