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.util.List;
23 import java.util.Objects;
24
25 import org.apache.maven.execution.AbstractExecutionListener;
26 import org.apache.maven.execution.BuildFailure;
27 import org.apache.maven.execution.BuildSuccess;
28 import org.apache.maven.execution.BuildSummary;
29 import org.apache.maven.execution.ExecutionEvent;
30 import org.apache.maven.execution.MavenExecutionResult;
31 import org.apache.maven.execution.MavenSession;
32 import org.apache.maven.logwrapper.LogLevelRecorder;
33 import org.apache.maven.logwrapper.MavenSlf4jWrapperFactory;
34 import org.apache.maven.plugin.MojoExecution;
35 import org.apache.maven.plugin.descriptor.MojoDescriptor;
36 import org.apache.maven.project.MavenProject;
37 import org.apache.maven.shared.utils.logging.MessageBuilder;
38 import org.apache.maven.shared.utils.logging.MessageUtils;
39 import org.codehaus.plexus.util.StringUtils;
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 import static org.apache.maven.shared.utils.logging.MessageUtils.buffer;
47
48
49
50
51
52
53 public class ExecutionEventLogger extends AbstractExecutionListener {
54 private final Logger logger;
55
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 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() {
70 this(LoggerFactory.getLogger(ExecutionEventLogger.class));
71 }
72
73 public ExecutionEventLogger(int terminalWidth) {
74 this(LoggerFactory.getLogger(ExecutionEventLogger.class), terminalWidth);
75 }
76
77 public ExecutionEventLogger(Logger logger) {
78 this(logger, MessageUtils.getTerminalWidth());
79 }
80
81 public ExecutionEventLogger(Logger logger, int terminalWidth) {
82 this.logger = Objects.requireNonNull(logger, "logger cannot be null");
83 this.terminalWidth = Math.min(
84 MAX_TERMINAL_WIDTH,
85 Math.max(terminalWidth < 0 ? DEFAULT_TERMINAL_WIDTH : terminalWidth, MIN_TERMINAL_WIDTH));
86 this.lineLength = this.terminalWidth - MAX_LOG_PREFIX_SIZE;
87 this.maxProjectNameLength = this.lineLength - PROJECT_STATUS_SUFFIX_SIZE;
88 }
89
90 private static String chars(char c, int count) {
91 StringBuilder buffer = new StringBuilder(count);
92
93 for (int i = count; i > 0; i--) {
94 buffer.append(c);
95 }
96
97 return buffer.toString();
98 }
99
100 private void infoLine(char c) {
101 infoMain(chars(c, lineLength));
102 }
103
104 private void infoMain(String msg) {
105 logger.info(buffer().strong(msg).toString());
106 }
107
108 @Override
109 public void projectDiscoveryStarted(ExecutionEvent event) {
110 if (logger.isInfoEnabled()) {
111 logger.info("Scanning for projects...");
112 }
113 }
114
115 @Override
116 public void sessionStarted(ExecutionEvent event) {
117 if (logger.isInfoEnabled() && event.getSession().getProjects().size() > 1) {
118 infoLine('-');
119
120 infoMain("Reactor Build Order:");
121
122 logger.info("");
123
124 final List<MavenProject> projects = event.getSession().getProjects();
125 for (MavenProject project : projects) {
126 int len = lineLength
127 - project.getName().length()
128 - project.getPackaging().length()
129 - 2;
130 logger.info("{}{}[{}]", project.getName(), chars(' ', (len > 0) ? len : 1), project.getPackaging());
131 }
132
133 final List<MavenProject> allProjects = event.getSession().getAllProjects();
134 final int projectsSkipped = allProjects.size() - projects.size();
135
136 currentVisitedProjectCount = projectsSkipped;
137 totalProjects = allProjects.size();
138 }
139 }
140
141 @Override
142 public void sessionEnded(ExecutionEvent event) {
143 if (logger.isInfoEnabled()) {
144 if (event.getSession().getProjects().size() > 1) {
145 logReactorSummary(event.getSession());
146 }
147
148 ILoggerFactory iLoggerFactory = LoggerFactory.getILoggerFactory();
149
150 if (iLoggerFactory instanceof MavenSlf4jWrapperFactory) {
151 MavenSlf4jWrapperFactory loggerFactory = (MavenSlf4jWrapperFactory) iLoggerFactory;
152 loggerFactory
153 .getLogLevelRecorder()
154 .filter(LogLevelRecorder::metThreshold)
155 .ifPresent(recorder -> event.getSession()
156 .getResult()
157 .addException(new Exception(
158 "Build failed due to log statements with a higher severity than allowed. "
159 + "Fix the logged issues or remove flag --fail-on-severity (-fos).")));
160 }
161
162 logResult(event.getSession());
163
164 logStats(event.getSession());
165
166 infoLine('-');
167 }
168 }
169
170 private boolean isSingleVersionedReactor(MavenSession session) {
171 boolean result = true;
172
173 MavenProject topProject = session.getTopLevelProject();
174 List<MavenProject> sortedProjects = session.getProjectDependencyGraph().getSortedProjects();
175 for (MavenProject mavenProject : sortedProjects) {
176 if (!topProject.getVersion().equals(mavenProject.getVersion())) {
177 result = false;
178 break;
179 }
180 }
181
182 return result;
183 }
184
185 private void logReactorSummary(MavenSession session) {
186 boolean isSingleVersion = isSingleVersionedReactor(session);
187
188 infoLine('-');
189
190 StringBuilder summary = new StringBuilder("Reactor Summary");
191 if (isSingleVersion) {
192 summary.append(" for ");
193 summary.append(session.getTopLevelProject().getName());
194 summary.append(" ");
195 summary.append(session.getTopLevelProject().getVersion());
196 }
197 summary.append(":");
198 infoMain(summary.toString());
199
200 logger.info("");
201
202 MavenExecutionResult result = session.getResult();
203
204 List<MavenProject> projects = session.getProjects();
205
206 for (MavenProject project : projects) {
207 StringBuilder buffer = new StringBuilder(128);
208
209 buffer.append(project.getName());
210 buffer.append(' ');
211
212 if (!isSingleVersion) {
213 buffer.append(project.getVersion());
214 buffer.append(' ');
215 }
216
217 if (buffer.length() <= maxProjectNameLength) {
218 while (buffer.length() < maxProjectNameLength) {
219 buffer.append('.');
220 }
221 buffer.append(' ');
222 }
223
224 BuildSummary buildSummary = result.getBuildSummary(project);
225
226 if (buildSummary == null) {
227 buffer.append(buffer().warning("SKIPPED"));
228 } else if (buildSummary instanceof BuildSuccess) {
229 buffer.append(buffer().success("SUCCESS"));
230 buffer.append(" [");
231 String buildTimeDuration = formatDuration(buildSummary.getTime());
232 int padSize = MAX_PADDED_BUILD_TIME_DURATION_LENGTH - buildTimeDuration.length();
233 if (padSize > 0) {
234 buffer.append(chars(' ', padSize));
235 }
236 buffer.append(buildTimeDuration);
237 buffer.append(']');
238 } else if (buildSummary instanceof BuildFailure) {
239 buffer.append(buffer().failure("FAILURE"));
240 buffer.append(" [");
241 String buildTimeDuration = formatDuration(buildSummary.getTime());
242 int padSize = MAX_PADDED_BUILD_TIME_DURATION_LENGTH - buildTimeDuration.length();
243 if (padSize > 0) {
244 buffer.append(chars(' ', padSize));
245 }
246 buffer.append(buildTimeDuration);
247 buffer.append(']');
248 }
249
250 logger.info(buffer.toString());
251 }
252 }
253
254 private void logResult(MavenSession session) {
255 infoLine('-');
256 MessageBuilder buffer = buffer();
257
258 if (session.getResult().hasExceptions()) {
259 buffer.failure("BUILD FAILURE");
260 } else {
261 buffer.success("BUILD SUCCESS");
262 }
263 logger.info(buffer.toString());
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 buffer().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 File rootBasedir = session.getTopLevelProject().getBasedir();
340 logger.info(" from " + rootBasedir.toPath().relativize(currentPom.toPath()));
341 }
342
343
344 prefix = chars('-', Math.max(0, (lineLength - project.getPackaging().length() - 4) / 2));
345 suffix = chars('-', Math.max(0, lineLength - project.getPackaging().length() - 4 - prefix.length()));
346 infoMain(prefix + "[ " + project.getPackaging() + " ]" + suffix);
347 }
348 }
349
350 @Override
351 public void mojoSkipped(ExecutionEvent event) {
352 if (logger.isWarnEnabled()) {
353 logger.warn(
354 "Goal '{}' requires online mode for execution but Maven is currently offline, skipping",
355 event.getMojoExecution().getGoal());
356 }
357 }
358
359
360
361
362 @Override
363 public void mojoStarted(ExecutionEvent event) {
364 if (logger.isInfoEnabled()) {
365 logger.info("");
366
367 MessageBuilder buffer = buffer().strong("--- ");
368 append(buffer, event.getMojoExecution());
369 append(buffer, event.getProject());
370 buffer.strong(" ---");
371
372 logger.info(buffer.toString());
373 }
374 }
375
376
377
378
379
380
381
382 @Override
383 public void forkStarted(ExecutionEvent event) {
384 if (logger.isInfoEnabled()) {
385 logger.info("");
386
387 MessageBuilder buffer = buffer().strong(">>> ");
388 append(buffer, event.getMojoExecution());
389 buffer.strong(" > ");
390 appendForkInfo(buffer, event.getMojoExecution().getMojoDescriptor());
391 append(buffer, event.getProject());
392 buffer.strong(" >>>");
393
394 logger.info(buffer.toString());
395 }
396 }
397
398
399
400
401
402
403
404 @Override
405 public void forkSucceeded(ExecutionEvent event) {
406 if (logger.isInfoEnabled()) {
407 logger.info("");
408
409 MessageBuilder buffer = buffer().strong("<<< ");
410 append(buffer, event.getMojoExecution());
411 buffer.strong(" < ");
412 appendForkInfo(buffer, event.getMojoExecution().getMojoDescriptor());
413 append(buffer, event.getProject());
414 buffer.strong(" <<<");
415
416 logger.info(buffer.toString());
417
418 logger.info("");
419 }
420 }
421
422 private void append(MessageBuilder buffer, MojoExecution me) {
423 String prefix = me.getMojoDescriptor().getPluginDescriptor().getGoalPrefix();
424 if (StringUtils.isEmpty(prefix)) {
425 prefix = me.getGroupId() + ":" + me.getArtifactId();
426 }
427 buffer.mojo(prefix + ':' + me.getVersion() + ':' + me.getGoal());
428 if (me.getExecutionId() != null) {
429 buffer.a(' ').strong('(' + me.getExecutionId() + ')');
430 }
431 }
432
433 private void appendForkInfo(MessageBuilder buffer, MojoDescriptor md) {
434 StringBuilder buff = new StringBuilder();
435 if (StringUtils.isNotEmpty(md.getExecutePhase())) {
436
437 if (StringUtils.isNotEmpty(md.getExecuteLifecycle())) {
438 buff.append('[');
439 buff.append(md.getExecuteLifecycle());
440 buff.append(']');
441 }
442 buff.append(md.getExecutePhase());
443 } else {
444
445 buff.append(':');
446 buff.append(md.getExecuteGoal());
447 }
448 buffer.strong(buff.toString());
449 }
450
451 private void append(MessageBuilder buffer, MavenProject project) {
452 buffer.a(" @ ").project(project.getArtifactId());
453 }
454
455 @Override
456 public void forkedProjectStarted(ExecutionEvent event) {
457 if (logger.isInfoEnabled()
458 && event.getMojoExecution().getForkedExecutions().size() > 1) {
459 logger.info("");
460 infoLine('>');
461
462 infoMain("Forking " + event.getProject().getName() + " "
463 + event.getProject().getVersion());
464
465 infoLine('>');
466 }
467 }
468 }