View Javadoc
1   /*
2    * Licensed to the Apache Software Foundation (ASF) under one
3    * or more contributor license agreements.  See the NOTICE file
4    * distributed with this work for additional information
5    * regarding copyright ownership.  The ASF licenses this file
6    * to you under the Apache License, Version 2.0 (the
7    * "License"); you may not use this file except in compliance
8    * with the License.  You may obtain a copy of the License at
9    *
10   *   http://www.apache.org/licenses/LICENSE-2.0
11   *
12   * Unless required by applicable law or agreed to in writing,
13   * software distributed under the License is distributed on an
14   * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
15   * KIND, either express or implied.  See the License for the
16   * specific language governing permissions and limitations
17   * under the License.
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.plugin.MojoExecution;
36  import org.apache.maven.plugin.descriptor.MojoDescriptor;
37  import org.apache.maven.project.MavenProject;
38  import org.slf4j.ILoggerFactory;
39  import org.slf4j.Logger;
40  import org.slf4j.LoggerFactory;
41  
42  import static org.apache.maven.cli.CLIReportingUtils.formatDuration;
43  import static org.apache.maven.cli.CLIReportingUtils.formatTimestamp;
44  
45  /**
46   * Logs execution events to logger, eventually user-supplied.
47   *
48   */
49  @Deprecated
50  public class ExecutionEventLogger extends AbstractExecutionListener {
51      private static final int MAX_LOG_PREFIX_SIZE = 8; // "[ERROR] "
52      private static final int PROJECT_STATUS_SUFFIX_SIZE = 20; // "SUCCESS [  0.000 s]"
53      private static final int MIN_TERMINAL_WIDTH = 60;
54      private static final int DEFAULT_TERMINAL_WIDTH = 80;
55      private static final int MAX_TERMINAL_WIDTH = 130;
56      private static final int MAX_PADDED_BUILD_TIME_DURATION_LENGTH = 9;
57  
58      private final MessageBuilderFactory messageBuilderFactory;
59      private final Logger logger;
60      private int terminalWidth;
61      private int lineLength;
62      private int maxProjectNameLength;
63      private int totalProjects;
64      private volatile int currentVisitedProjectCount;
65  
66      public ExecutionEventLogger(MessageBuilderFactory messageBuilderFactory) {
67          this(messageBuilderFactory, LoggerFactory.getLogger(ExecutionEventLogger.class));
68      }
69  
70      public ExecutionEventLogger(MessageBuilderFactory messageBuilderFactory, Logger logger) {
71          this(messageBuilderFactory, logger, -1);
72      }
73  
74      public ExecutionEventLogger(MessageBuilderFactory messageBuilderFactory, Logger logger, int terminalWidth) {
75          this.logger = Objects.requireNonNull(logger, "logger cannot be null");
76          this.messageBuilderFactory = messageBuilderFactory;
77          this.terminalWidth = terminalWidth;
78      }
79  
80      private static String chars(char c, int count) {
81          return String.valueOf(c).repeat(Math.max(0, count));
82      }
83  
84      private void infoLine(char c) {
85          infoMain(chars(c, lineLength));
86      }
87  
88      private void infoMain(String msg) {
89          logger.info(builder().strong(msg).toString());
90      }
91  
92      private void init() {
93          if (maxProjectNameLength == 0) {
94              if (terminalWidth < 0) {
95                  terminalWidth = messageBuilderFactory.getTerminalWidth();
96              }
97              terminalWidth = Math.min(
98                      MAX_TERMINAL_WIDTH,
99                      Math.max(terminalWidth <= 0 ? DEFAULT_TERMINAL_WIDTH : terminalWidth, MIN_TERMINAL_WIDTH));
100             lineLength = terminalWidth - MAX_LOG_PREFIX_SIZE;
101             maxProjectNameLength = lineLength - PROJECT_STATUS_SUFFIX_SIZE;
102         }
103     }
104 
105     @Override
106     public void projectDiscoveryStarted(ExecutionEvent event) {
107         if (logger.isInfoEnabled()) {
108             init();
109             logger.info("Scanning for projects...");
110         }
111     }
112 
113     @Override
114     public void sessionStarted(ExecutionEvent event) {
115         if (logger.isInfoEnabled() && event.getSession().getProjects().size() > 1) {
116             init();
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 
134             currentVisitedProjectCount = allProjects.size() - projects.size();
135             totalProjects = allProjects.size();
136         }
137     }
138 
139     @Override
140     public void sessionEnded(ExecutionEvent event) {
141         if (logger.isInfoEnabled()) {
142             init();
143             if (event.getSession().getProjects().size() > 1) {
144                 logReactorSummary(event.getSession());
145             }
146 
147             ILoggerFactory iLoggerFactory = LoggerFactory.getILoggerFactory();
148 
149             if (iLoggerFactory instanceof org.apache.maven.logging.api.LogLevelRecorder recorder
150                     && recorder.hasReachedMaxLevel()) {
151                 event.getSession()
152                         .getResult()
153                         .addException(
154                                 new Exception("Build failed due to log statements with a higher severity than allowed. "
155                                         + "Fix the logged issues or remove flag --fail-on-severity (-fos)."));
156             }
157 
158             logResult(event.getSession());
159 
160             logStats(event.getSession());
161 
162             infoLine('-');
163         }
164     }
165 
166     private boolean isSingleVersionedReactor(MavenSession session) {
167         boolean result = true;
168 
169         MavenProject topProject = session.getTopLevelProject();
170         List<MavenProject> sortedProjects = session.getProjectDependencyGraph().getSortedProjects();
171         for (MavenProject mavenProject : sortedProjects) {
172             if (!topProject.getVersion().equals(mavenProject.getVersion())) {
173                 result = false;
174                 break;
175             }
176         }
177 
178         return result;
179     }
180 
181     private void logReactorSummary(MavenSession session) {
182         boolean isSingleVersion = isSingleVersionedReactor(session);
183 
184         infoLine('-');
185 
186         StringBuilder summary = new StringBuilder("Reactor Summary");
187         if (isSingleVersion) {
188             summary.append(" for ");
189             summary.append(session.getTopLevelProject().getName());
190             summary.append(" ");
191             summary.append(session.getTopLevelProject().getVersion());
192         }
193         summary.append(":");
194         infoMain(summary.toString());
195 
196         logger.info("");
197 
198         MavenExecutionResult result = session.getResult();
199 
200         List<MavenProject> projects = session.getProjects();
201 
202         StringBuilder buffer = new StringBuilder(128);
203 
204         for (MavenProject project : projects) {
205             buffer.append(project.getName());
206             buffer.append(' ');
207 
208             if (!isSingleVersion) {
209                 buffer.append(project.getVersion());
210                 buffer.append(' ');
211             }
212 
213             if (buffer.length() <= maxProjectNameLength) {
214                 while (buffer.length() < maxProjectNameLength) {
215                     buffer.append('.');
216                 }
217                 buffer.append(' ');
218             }
219 
220             BuildSummary buildSummary = result.getBuildSummary(project);
221 
222             if (buildSummary == null) {
223                 buffer.append(builder().warning("SKIPPED"));
224             } else if (buildSummary instanceof BuildSuccess) {
225                 buffer.append(builder().success("SUCCESS"));
226                 buffer.append(" [");
227                 String buildTimeDuration = formatDuration(buildSummary.getTime());
228                 int padSize = MAX_PADDED_BUILD_TIME_DURATION_LENGTH - buildTimeDuration.length();
229                 if (padSize > 0) {
230                     buffer.append(chars(' ', padSize));
231                 }
232                 buffer.append(buildTimeDuration);
233                 buffer.append(']');
234             } else if (buildSummary instanceof BuildFailure) {
235                 buffer.append(builder().failure("FAILURE"));
236                 buffer.append(" [");
237                 String buildTimeDuration = formatDuration(buildSummary.getTime());
238                 int padSize = MAX_PADDED_BUILD_TIME_DURATION_LENGTH - buildTimeDuration.length();
239                 if (padSize > 0) {
240                     buffer.append(chars(' ', padSize));
241                 }
242                 buffer.append(buildTimeDuration);
243                 buffer.append(']');
244             }
245 
246             logger.info(buffer.toString());
247             buffer.setLength(0);
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             init();
285             logger.info("");
286             infoLine('-');
287             String name = event.getProject().getName();
288             infoMain("Skipping " + name);
289             logger.info("{} was not built because a module it depends on failed to build.", name);
290 
291             infoLine('-');
292         }
293     }
294 
295     @Override
296     public void projectStarted(ExecutionEvent event) {
297         if (logger.isInfoEnabled()) {
298             init();
299             MavenProject project = event.getProject();
300 
301             logger.info("");
302 
303             // -------< groupId:artifactId >-------
304             String projectKey = project.getGroupId() + ':' + project.getArtifactId();
305 
306             final String preHeader = "--< ";
307             final String postHeader = " >--";
308 
309             final int headerLen = preHeader.length() + projectKey.length() + postHeader.length();
310 
311             String prefix = chars('-', Math.max(0, (lineLength - headerLen) / 2)) + preHeader;
312 
313             String suffix =
314                     postHeader + chars('-', Math.max(0, lineLength - headerLen - prefix.length() + preHeader.length()));
315 
316             logger.info(
317                     builder().strong(prefix).project(projectKey).strong(suffix).toString());
318 
319             // Building Project Name Version    [i/n]
320             String building = "Building " + event.getProject().getName() + " "
321                     + event.getProject().getVersion();
322 
323             if (totalProjects <= 1) {
324                 infoMain(building);
325             } else {
326                 // display progress [i/n]
327                 int number;
328                 synchronized (this) {
329                     number = ++currentVisitedProjectCount;
330                 }
331                 String progress = " [" + number + '/' + totalProjects + ']';
332 
333                 int pad = lineLength - building.length() - progress.length();
334 
335                 infoMain(building + ((pad > 0) ? chars(' ', pad) : "") + progress);
336             }
337 
338             // path to pom.xml
339             File currentPom = project.getFile();
340             if (currentPom != null) {
341                 MavenSession session = event.getSession();
342                 Path current = currentPom.toPath().toAbsolutePath().normalize();
343                 Path topDirectory = session.getTopDirectory();
344                 if (topDirectory != null && current.startsWith(topDirectory)) {
345                     current = topDirectory.relativize(current);
346                 }
347                 logger.info("  from " + current);
348             }
349 
350             // ----------[ packaging ]----------
351             prefix = chars('-', Math.max(0, (lineLength - project.getPackaging().length() - 4) / 2));
352             suffix = chars('-', Math.max(0, lineLength - project.getPackaging().length() - 4 - prefix.length()));
353             infoMain(prefix + "[ " + project.getPackaging() + " ]" + suffix);
354         }
355     }
356 
357     @Override
358     public void mojoSkipped(ExecutionEvent event) {
359         if (logger.isWarnEnabled()) {
360             init();
361             logger.warn(
362                     "Goal '{}' requires online mode for execution but Maven is currently offline, skipping",
363                     event.getMojoExecution().getGoal());
364         }
365     }
366 
367     /**
368      * <pre>--- mojo-artifactId:version:goal (mojo-executionId) @ project-artifactId ---</pre>
369      */
370     @Override
371     public void mojoStarted(ExecutionEvent event) {
372         if (logger.isInfoEnabled()) {
373             init();
374             logger.info("");
375 
376             MessageBuilder buffer = builder().strong("--- ");
377             append(buffer, event.getMojoExecution());
378             append(buffer, event.getProject());
379             buffer.strong(" ---");
380 
381             logger.info(buffer.toString());
382         }
383     }
384 
385     // CHECKSTYLE_OFF: LineLength
386     /**
387      * <pre>&gt;&gt;&gt; mojo-artifactId:version:goal (mojo-executionId) &gt; :forked-goal @ project-artifactId &gt;&gt;&gt;</pre>
388      * <pre>&gt;&gt;&gt; mojo-artifactId:version:goal (mojo-executionId) &gt; [lifecycle]phase @ project-artifactId &gt;&gt;&gt;</pre>
389      */
390     // CHECKSTYLE_ON: LineLength
391     @Override
392     public void forkStarted(ExecutionEvent event) {
393         if (logger.isInfoEnabled()) {
394             init();
395             logger.info("");
396 
397             MessageBuilder buffer = builder().strong(">>> ");
398             append(buffer, event.getMojoExecution());
399             buffer.strong(" > ");
400             appendForkInfo(buffer, event.getMojoExecution().getMojoDescriptor());
401             append(buffer, event.getProject());
402             buffer.strong(" >>>");
403 
404             logger.info(buffer.toString());
405         }
406     }
407 
408     // CHECKSTYLE_OFF: LineLength
409     /**
410      * <pre>&lt;&lt;&lt; mojo-artifactId:version:goal (mojo-executionId) &lt; :forked-goal @ project-artifactId &lt;&lt;&lt;</pre>
411      * <pre>&lt;&lt;&lt; mojo-artifactId:version:goal (mojo-executionId) &lt; [lifecycle]phase @ project-artifactId &lt;&lt;&lt;</pre>
412      */
413     // CHECKSTYLE_ON: LineLength
414     @Override
415     public void forkSucceeded(ExecutionEvent event) {
416         if (logger.isInfoEnabled()) {
417             init();
418             logger.info("");
419 
420             MessageBuilder buffer = builder().strong("<<< ");
421             append(buffer, event.getMojoExecution());
422             buffer.strong(" < ");
423             appendForkInfo(buffer, event.getMojoExecution().getMojoDescriptor());
424             append(buffer, event.getProject());
425             buffer.strong(" <<<");
426 
427             logger.info(buffer.toString());
428 
429             logger.info("");
430         }
431     }
432 
433     private void append(MessageBuilder buffer, MojoExecution me) {
434         String prefix = me.getMojoDescriptor().getPluginDescriptor().getGoalPrefix();
435         if (prefix == null || prefix.isEmpty()) {
436             prefix = me.getGroupId() + ":" + me.getArtifactId();
437         }
438         buffer.mojo(prefix + ':' + me.getVersion() + ':' + me.getGoal());
439         if (me.getExecutionId() != null) {
440             buffer.a(' ').strong('(' + me.getExecutionId() + ')');
441         }
442     }
443 
444     private void appendForkInfo(MessageBuilder buffer, MojoDescriptor md) {
445         StringBuilder buff = new StringBuilder();
446         if (md.getExecutePhase() != null && !md.getExecutePhase().isEmpty()) {
447             // forked phase
448             if (md.getExecuteLifecycle() != null && !md.getExecuteLifecycle().isEmpty()) {
449                 buff.append('[');
450                 buff.append(md.getExecuteLifecycle());
451                 buff.append(']');
452             }
453             buff.append(md.getExecutePhase());
454         } else {
455             // forked goal
456             buff.append(':');
457             buff.append(md.getExecuteGoal());
458         }
459         buffer.strong(buff.toString());
460     }
461 
462     private void append(MessageBuilder buffer, MavenProject project) {
463         buffer.a(" @ ").project(project.getArtifactId());
464     }
465 
466     @Override
467     public void forkedProjectStarted(ExecutionEvent event) {
468         if (logger.isInfoEnabled()
469                 && event.getMojoExecution().getForkedExecutions().size() > 1) {
470             init();
471             logger.info("");
472             infoLine('>');
473 
474             infoMain("Forking " + event.getProject().getName() + " "
475                     + event.getProject().getVersion());
476 
477             infoLine('>');
478         }
479     }
480 }