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.execution.AbstractExecutionListener;
27  import org.apache.maven.execution.BuildFailure;
28  import org.apache.maven.execution.BuildSuccess;
29  import org.apache.maven.execution.BuildSummary;
30  import org.apache.maven.execution.ExecutionEvent;
31  import org.apache.maven.execution.MavenExecutionResult;
32  import org.apache.maven.execution.MavenSession;
33  import org.apache.maven.jline.MessageUtils;
34  import org.apache.maven.message.MessageBuilder;
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.codehaus.plexus.util.StringUtils;
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  import static org.apache.maven.jline.MessageUtils.builder;
45  
46  /**
47   * Logs execution events to logger, eventually user-supplied.
48   *
49   * @author Benjamin Bentmann
50   */
51  public class ExecutionEventLogger extends AbstractExecutionListener {
52      private final Logger logger;
53  
54      private static final int LINE_LENGTH = 72;
55      private static final int MAX_PADDED_BUILD_TIME_DURATION_LENGTH = 9;
56      private static final int MAX_PROJECT_NAME_LENGTH = 52;
57  
58      private int totalProjects;
59      private volatile int currentVisitedProjectCount;
60  
61      public ExecutionEventLogger() {
62          logger = LoggerFactory.getLogger(ExecutionEventLogger.class);
63      }
64  
65      // TODO should we deprecate?
66      public ExecutionEventLogger(Logger logger) {
67          this.logger = Objects.requireNonNull(logger, "logger cannot be null");
68      }
69  
70      private static String chars(char c, int count) {
71          StringBuilder buffer = new StringBuilder(count);
72  
73          for (int i = count; i > 0; i--) {
74              buffer.append(c);
75          }
76  
77          return buffer.toString();
78      }
79  
80      private void infoLine(char c) {
81          infoMain(chars(c, LINE_LENGTH));
82      }
83  
84      private void infoMain(String msg) {
85          logger.info(builder().strong(msg).toString());
86      }
87  
88      @Override
89      public void projectDiscoveryStarted(ExecutionEvent event) {
90          if (logger.isInfoEnabled()) {
91              logger.info("Scanning for projects...");
92          }
93      }
94  
95      @Override
96      public void sessionStarted(ExecutionEvent event) {
97          if (logger.isInfoEnabled() && event.getSession().getProjects().size() > 1) {
98              infoLine('-');
99  
100             infoMain("Reactor Build Order:");
101 
102             logger.info("");
103 
104             final List<MavenProject> projects = event.getSession().getProjects();
105             for (MavenProject project : projects) {
106                 int len = LINE_LENGTH
107                         - project.getName().length()
108                         - project.getPackaging().length()
109                         - 2;
110                 logger.info("{}{}[{}]", project.getName(), chars(' ', (len > 0) ? len : 1), project.getPackaging());
111             }
112 
113             totalProjects = projects.size();
114         }
115     }
116 
117     @Override
118     public void sessionEnded(ExecutionEvent event) {
119         if (logger.isInfoEnabled()) {
120             if (event.getSession().getProjects().size() > 1) {
121                 logReactorSummary(event.getSession());
122             }
123 
124             logResult(event.getSession());
125 
126             logStats(event.getSession());
127 
128             infoLine('-');
129         }
130     }
131 
132     private boolean isSingleVersionedReactor(MavenSession session) {
133         boolean result = true;
134 
135         MavenProject topProject = session.getTopLevelProject();
136         List<MavenProject> sortedProjects = session.getProjectDependencyGraph().getSortedProjects();
137         for (MavenProject mavenProject : sortedProjects) {
138             if (!topProject.getVersion().equals(mavenProject.getVersion())) {
139                 result = false;
140                 break;
141             }
142         }
143 
144         return result;
145     }
146 
147     private void logReactorSummary(MavenSession session) {
148         boolean isSingleVersion = isSingleVersionedReactor(session);
149 
150         infoLine('-');
151 
152         StringBuilder summary = new StringBuilder("Reactor Summary");
153         if (isSingleVersion) {
154             summary.append(" for ");
155             summary.append(session.getTopLevelProject().getName());
156             summary.append(" ");
157             summary.append(session.getTopLevelProject().getVersion());
158         }
159         summary.append(":");
160         infoMain(summary.toString());
161 
162         logger.info("");
163 
164         MavenExecutionResult result = session.getResult();
165 
166         List<MavenProject> projects = session.getProjects();
167 
168         String skippedMessage = builder().warning("SKIPPED").build();
169         String successMessage = builder().success("SUCCESS").build();
170         String failureMessage = builder().failure("FAILURE").build();
171         String unknownMessage = builder().warning("UNKNOWN").build();
172 
173         for (MavenProject project : projects) {
174             BuildSummary buildSummary = result.getBuildSummary(project);
175 
176             String statusMessage;
177             boolean shouldSkip = result.hasExceptions();
178             if (buildSummary == null) {
179                 statusMessage = skippedMessage;
180             } else if (buildSummary instanceof BuildSuccess) {
181                 statusMessage = successMessage;
182             } else if (buildSummary instanceof BuildFailure) {
183                 statusMessage = failureMessage;
184                 shouldSkip = false;
185             } else {
186                 statusMessage = unknownMessage;
187             }
188 
189             if (shouldSkip) {
190                 if (project.isExecutionRoot()) {
191                     logger.info("...");
192                 }
193                 continue;
194             }
195 
196             StringBuilder buffer = new StringBuilder(128);
197 
198             buffer.append(project.getName());
199             buffer.append(' ');
200 
201             if (!isSingleVersion) {
202                 buffer.append(project.getVersion());
203                 buffer.append(' ');
204             }
205 
206             if (buffer.length() <= MAX_PROJECT_NAME_LENGTH) {
207                 while (buffer.length() < MAX_PROJECT_NAME_LENGTH) {
208                     buffer.append('.');
209                 }
210                 buffer.append(' ');
211             }
212 
213             buffer.append(statusMessage);
214             if (buildSummary != null) {
215                 formatBuildTime(buffer, buildSummary);
216             }
217 
218             logger.info(buffer.toString());
219         }
220 
221         if (result.hasExceptions()) {
222             logger.info("...");
223         }
224     }
225 
226     private void formatBuildTime(StringBuilder buffer, BuildSummary buildSummary) {
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     }
236 
237     private void logResult(MavenSession session) {
238         infoLine('-');
239         MessageBuilder buffer = MessageUtils.builder();
240 
241         if (session.getResult().hasExceptions()) {
242             buffer.failure("BUILD FAILURE");
243         } else {
244             buffer.success("BUILD SUCCESS");
245         }
246         logger.info(buffer.toString());
247     }
248 
249     private void logStats(MavenSession session) {
250         infoLine('-');
251 
252         long finish = System.currentTimeMillis();
253 
254         long time = finish - session.getRequest().getStartTime().getTime();
255 
256         String wallClock = session.getRequest().getDegreeOfConcurrency() > 1 ? " (Wall Clock)" : "";
257 
258         logger.info("Total time:  {}{}", formatDuration(time), wallClock);
259 
260         logger.info("Finished at: {}", formatTimestamp(finish));
261     }
262 
263     @Override
264     public void projectSkipped(ExecutionEvent event) {
265         if (logger.isInfoEnabled()) {
266             logger.info("");
267             infoLine('-');
268 
269             infoMain("Skipping " + event.getProject().getName());
270             logger.info("This project has been banned from the build due to previous failures.");
271 
272             infoLine('-');
273         }
274     }
275 
276     @Override
277     public void projectStarted(ExecutionEvent event) {
278         if (logger.isInfoEnabled()) {
279             MavenProject project = event.getProject();
280 
281             logger.info("");
282 
283             // -------< groupId:artifactId >-------
284             String projectKey = project.getGroupId() + ':' + project.getArtifactId();
285 
286             final String preHeader = "--< ";
287             final String postHeader = " >--";
288 
289             final int headerLen = preHeader.length() + projectKey.length() + postHeader.length();
290 
291             String prefix = chars('-', Math.max(0, (LINE_LENGTH - headerLen) / 2)) + preHeader;
292 
293             String suffix = postHeader
294                     + chars('-', Math.max(0, LINE_LENGTH - headerLen - prefix.length() + preHeader.length()));
295 
296             logger.info(
297                     builder().strong(prefix).project(projectKey).strong(suffix).toString());
298 
299             // Building Project Name Version    [i/n]
300             String building = "Building " + event.getProject().getName() + " "
301                     + event.getProject().getVersion();
302 
303             if (totalProjects <= 1) {
304                 infoMain(building);
305             } else {
306                 // display progress [i/n]
307                 int number;
308                 synchronized (this) {
309                     number = ++currentVisitedProjectCount;
310                 }
311                 String progress = " [" + number + '/' + totalProjects + ']';
312 
313                 int pad = LINE_LENGTH - building.length() - progress.length();
314 
315                 infoMain(building + ((pad > 0) ? chars(' ', pad) : "") + progress);
316             }
317 
318             // path to pom.xml
319             File currentPom = project.getFile();
320             if (currentPom != null) {
321                 MavenSession session = event.getSession();
322                 Path topLevelBasedir = session.getTopLevelProject().getBasedir().toPath();
323                 Path current = currentPom.toPath().toAbsolutePath().normalize();
324                 if (current.startsWith(topLevelBasedir)) {
325                     current = topLevelBasedir.relativize(current);
326                 }
327                 logger.info("  from " + current);
328             }
329 
330             // ----------[ packaging ]----------
331             prefix =
332                     chars('-', Math.max(0, (LINE_LENGTH - project.getPackaging().length() - 4) / 2));
333             suffix = chars('-', Math.max(0, LINE_LENGTH - project.getPackaging().length() - 4 - prefix.length()));
334             infoMain(prefix + "[ " + project.getPackaging() + " ]" + suffix);
335         }
336     }
337 
338     @Override
339     public void mojoSkipped(ExecutionEvent event) {
340         if (logger.isWarnEnabled()) {
341             logger.warn(
342                     "Goal {} requires online mode for execution but Maven is currently offline, skipping",
343                     event.getMojoExecution().getGoal());
344         }
345     }
346 
347     /**
348      * <pre>--- mojo-artifactId:version:goal (mojo-executionId) @ project-artifactId ---</pre>
349      */
350     @Override
351     public void mojoStarted(ExecutionEvent event) {
352         if (logger.isInfoEnabled()) {
353             logger.info("");
354 
355             MessageBuilder buffer = builder().strong("--- ");
356             append(buffer, event.getMojoExecution());
357             append(buffer, event.getProject());
358             buffer.strong(" ---");
359 
360             logger.info(buffer.toString());
361         }
362     }
363 
364     // CHECKSTYLE_OFF: LineLength
365     /**
366      * <pre>&gt;&gt;&gt; mojo-artifactId:version:goal (mojo-executionId) &gt; :forked-goal @ project-artifactId &gt;&gt;&gt;</pre>
367      * <pre>&gt;&gt;&gt; mojo-artifactId:version:goal (mojo-executionId) &gt; [lifecycle]phase @ project-artifactId &gt;&gt;&gt;</pre>
368      */
369     // CHECKSTYLE_ON: LineLength
370     @Override
371     public void forkStarted(ExecutionEvent event) {
372         if (logger.isInfoEnabled()) {
373             logger.info("");
374 
375             MessageBuilder buffer = builder().strong(">>> ");
376             append(buffer, event.getMojoExecution());
377             buffer.strong(" > ");
378             appendForkInfo(buffer, event.getMojoExecution().getMojoDescriptor());
379             append(buffer, event.getProject());
380             buffer.strong(" >>>");
381 
382             logger.info(buffer.toString());
383         }
384     }
385 
386     // CHECKSTYLE_OFF: LineLength
387     /**
388      * <pre>&lt;&lt;&lt; mojo-artifactId:version:goal (mojo-executionId) &lt; :forked-goal @ project-artifactId &lt;&lt;&lt;</pre>
389      * <pre>&lt;&lt;&lt; mojo-artifactId:version:goal (mojo-executionId) &lt; [lifecycle]phase @ project-artifactId &lt;&lt;&lt;</pre>
390      */
391     // CHECKSTYLE_ON: LineLength
392     @Override
393     public void forkSucceeded(ExecutionEvent event) {
394         if (logger.isInfoEnabled()) {
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             logger.info("");
407         }
408     }
409 
410     private void append(MessageBuilder buffer, MojoExecution me) {
411         String prefix = me.getMojoDescriptor().getPluginDescriptor().getGoalPrefix();
412         if (StringUtils.isEmpty(prefix)) {
413             prefix = me.getGroupId() + ":" + me.getArtifactId();
414         }
415         buffer.mojo(prefix + ':' + me.getVersion() + ':' + me.getGoal());
416         if (me.getExecutionId() != null) {
417             buffer.a(' ').strong('(' + me.getExecutionId() + ')');
418         }
419     }
420 
421     private void appendForkInfo(MessageBuilder buffer, MojoDescriptor md) {
422         StringBuilder buff = new StringBuilder();
423         if (StringUtils.isNotEmpty(md.getExecutePhase())) {
424             // forked phase
425             if (StringUtils.isNotEmpty(md.getExecuteLifecycle())) {
426                 buff.append('[');
427                 buff.append(md.getExecuteLifecycle());
428                 buff.append(']');
429             }
430             buff.append(md.getExecutePhase());
431         } else {
432             // forked goal
433             buff.append(':');
434             buff.append(md.getExecuteGoal());
435         }
436         buffer.strong(buff.toString());
437     }
438 
439     private void append(MessageBuilder buffer, MavenProject project) {
440         buffer.a(" @ ").project(project.getArtifactId());
441     }
442 
443     @Override
444     public void forkedProjectStarted(ExecutionEvent event) {
445         if (logger.isInfoEnabled()
446                 && event.getMojoExecution().getForkedExecutions().size() > 1) {
447             logger.info("");
448             infoLine('>');
449 
450             infoMain("Forking " + event.getProject().getName() + " "
451                     + event.getProject().getVersion());
452 
453             infoLine('>');
454         }
455     }
456 }