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