View Javadoc
1   package org.apache.maven.cli.event;
2   
3   /*
4    * Licensed to the Apache Software Foundation (ASF) under one
5    * or more contributor license agreements.  See the NOTICE file
6    * distributed with this work for additional information
7    * regarding copyright ownership.  The ASF licenses this file
8    * to you under the Apache License, Version 2.0 (the
9    * "License"); you may not use this file except in compliance
10   * with the License.  You may obtain a copy of the License at
11   *
12   *   http://www.apache.org/licenses/LICENSE-2.0
13   *
14   * Unless required by applicable law or agreed to in writing,
15   * software distributed under the License is distributed on an
16   * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
17   * KIND, either express or implied.  See the License for the
18   * specific language governing permissions and limitations
19   * under the License.
20   */
21  
22  import static org.apache.maven.cli.CLIReportingUtils.formatDuration;
23  import static org.apache.maven.cli.CLIReportingUtils.formatTimestamp;
24  import static org.apache.maven.shared.utils.logging.MessageUtils.buffer;
25  
26  import java.util.List;
27  import java.util.Objects;
28  
29  import org.apache.maven.execution.AbstractExecutionListener;
30  import org.apache.maven.execution.BuildFailure;
31  import org.apache.maven.execution.BuildSuccess;
32  import org.apache.maven.execution.BuildSummary;
33  import org.apache.maven.execution.ExecutionEvent;
34  import org.apache.maven.execution.MavenExecutionResult;
35  import org.apache.maven.execution.MavenSession;
36  import org.apache.maven.plugin.MojoExecution;
37  import org.apache.maven.plugin.descriptor.MojoDescriptor;
38  import org.apache.maven.project.MavenProject;
39  import org.apache.maven.shared.utils.logging.MessageBuilder;
40  import org.codehaus.plexus.util.StringUtils;
41  import org.slf4j.Logger;
42  import org.slf4j.LoggerFactory;
43  
44  /**
45   * Logs execution events to logger, eventually user-supplied.
46   *
47   * @author Benjamin Bentmann
48   */
49  public class ExecutionEventLogger
50      extends AbstractExecutionListener
51  {
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      {
63          logger = LoggerFactory.getLogger( ExecutionEventLogger.class );
64      }
65  
66      // TODO should we deprecate?
67      public ExecutionEventLogger( Logger logger )
68      {
69          this.logger = Objects.requireNonNull( logger, "logger cannot be null" );
70      }
71  
72      private static String chars( char c, int count )
73      {
74          StringBuilder buffer = new StringBuilder( count );
75  
76          for ( int i = count; i > 0; i-- )
77          {
78              buffer.append( c );
79          }
80  
81          return buffer.toString();
82      }
83  
84      private void infoLine( char c )
85      {
86          infoMain( chars( c, LINE_LENGTH ) );
87      }
88  
89      private void infoMain( String msg )
90      {
91          logger.info( buffer().strong( msg ).toString() );
92      }
93  
94      @Override
95      public void projectDiscoveryStarted( ExecutionEvent event )
96      {
97          if ( logger.isInfoEnabled() )
98          {
99              logger.info( "Scanning for projects..." );
100         }
101     }
102 
103     @Override
104     public void sessionStarted( ExecutionEvent event )
105     {
106         if ( logger.isInfoEnabled() && event.getSession().getProjects().size() > 1 )
107         {
108             infoLine( '-' );
109 
110             infoMain( "Reactor Build Order:" );
111 
112             logger.info( "" );
113 
114             final List<MavenProject> projects = event.getSession().getProjects();
115             for ( MavenProject project : projects )
116             {
117                 int len = LINE_LENGTH - project.getName().length() - project.getPackaging().length() - 2;
118                 logger.info( project.getName() + chars( ' ', ( len > 0 ) ? len : 1 ) + '[' + project.getPackaging()
119                     + ']' );
120             }
121 
122             totalProjects = projects.size();
123         }
124     }
125 
126     @Override
127     public void sessionEnded( ExecutionEvent event )
128     {
129         if ( logger.isInfoEnabled() )
130         {
131             if ( event.getSession().getProjects().size() > 1 )
132             {
133                 logReactorSummary( event.getSession() );
134             }
135 
136             logResult( event.getSession() );
137 
138             logStats( event.getSession() );
139 
140             infoLine( '-' );
141         }
142     }
143 
144     private boolean isSingleVersionedReactor( MavenSession session )
145     {
146         boolean result = true;
147 
148         MavenProject topProject = session.getTopLevelProject();
149         List<MavenProject> sortedProjects = session.getProjectDependencyGraph().getSortedProjects();
150         for ( MavenProject mavenProject : sortedProjects )
151         {
152             if ( !topProject.getVersion().equals( mavenProject.getVersion() ) )
153             {
154                 result = false;
155                 break;
156             }
157         }
158 
159         return result;
160     }
161 
162     private void logReactorSummary( MavenSession session )
163     {
164         boolean isSingleVersion = isSingleVersionedReactor( session );
165 
166         infoLine( '-' );
167 
168         StringBuilder summary = new StringBuilder( "Reactor Summary" );
169         if ( isSingleVersion )
170         {
171             summary.append( " for " );
172             summary.append( session.getTopLevelProject().getName() );
173             summary.append( " " );
174             summary.append( session.getTopLevelProject().getVersion() );
175         }
176         summary.append( ":" );
177         infoMain( summary.toString() );
178 
179         logger.info( "" );
180 
181         MavenExecutionResult result = session.getResult();
182 
183         List<MavenProject> projects = session.getProjects();
184 
185         for ( MavenProject project : projects )
186         {
187             StringBuilder buffer = new StringBuilder( 128 );
188 
189             buffer.append( project.getName() );
190             buffer.append( ' ' );
191 
192             if ( !isSingleVersion )
193             {
194                 buffer.append( project.getVersion() );
195                 buffer.append( ' ' );
196             }
197 
198             if ( buffer.length() <= MAX_PROJECT_NAME_LENGTH )
199             {
200                 while ( buffer.length() < MAX_PROJECT_NAME_LENGTH )
201                 {
202                     buffer.append( '.' );
203                 }
204                 buffer.append( ' ' );
205             }
206 
207             BuildSummary buildSummary = result.getBuildSummary( project );
208 
209             if ( buildSummary == null )
210             {
211                 buffer.append( buffer().warning( "SKIPPED" ) );
212             }
213             else if ( buildSummary instanceof BuildSuccess )
214             {
215                 buffer.append( buffer().success( "SUCCESS" ) );
216                 buffer.append( " [" );
217                 String buildTimeDuration = formatDuration( buildSummary.getTime() );
218                 int padSize = MAX_PADDED_BUILD_TIME_DURATION_LENGTH - buildTimeDuration.length();
219                 if ( padSize > 0 )
220                 {
221                     buffer.append( chars( ' ', padSize ) );
222                 }
223                 buffer.append( buildTimeDuration );
224                 buffer.append( ']' );
225             }
226             else if ( buildSummary instanceof BuildFailure )
227             {
228                 buffer.append( buffer().failure( "FAILURE" ) );
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                 {
234                     buffer.append( chars( ' ', padSize ) );
235                 }
236                 buffer.append( buildTimeDuration );
237                 buffer.append( ']' );
238             }
239 
240             logger.info( buffer.toString() );
241         }
242     }
243 
244     private void logResult( MavenSession session )
245     {
246         infoLine( '-' );
247         MessageBuilder buffer = buffer();
248 
249         if ( session.getResult().hasExceptions() )
250         {
251             buffer.failure( "BUILD FAILURE" );
252         }
253         else
254         {
255             buffer.success( "BUILD SUCCESS" );
256         }
257         logger.info( buffer.toString() );
258     }
259 
260     private void logStats( MavenSession session )
261     {
262         infoLine( '-' );
263 
264         long finish = System.currentTimeMillis();
265 
266         long time = finish - session.getRequest().getStartTime().getTime();
267 
268         String wallClock = session.getRequest().getDegreeOfConcurrency() > 1 ? " (Wall Clock)" : "";
269 
270         logger.info( "Total time:  " + formatDuration( time ) + wallClock );
271 
272         logger.info( "Finished at: " + formatTimestamp( finish ) );
273     }
274 
275     @Override
276     public void projectSkipped( ExecutionEvent event )
277     {
278         if ( logger.isInfoEnabled() )
279         {
280             logger.info( "" );
281             infoLine( '-' );
282 
283             infoMain( "Skipping " + event.getProject().getName() );
284             logger.info( "This project has been banned from the build due to previous failures." );
285 
286             infoLine( '-' );
287         }
288     }
289 
290     @Override
291     public void projectStarted( ExecutionEvent event )
292     {
293         if ( logger.isInfoEnabled() )
294         {
295             MavenProject project = event.getProject();
296 
297             logger.info( "" );
298 
299             // -------< groupId:artifactId >-------
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, ( LINE_LENGTH - headerLen ) / 2 ) ) + preHeader;
308 
309             String suffix = postHeader
310                 + chars( '-', Math.max( 0, LINE_LENGTH - headerLen - prefix.length() + preHeader.length() ) );
311 
312             logger.info( buffer().strong( prefix ).project( projectKey ).strong( suffix ).toString() );
313 
314             // Building Project Name Version    [i/n]
315             String building = "Building " + event.getProject().getName() + " " + event.getProject().getVersion();
316 
317             if ( totalProjects <= 1 )
318             {
319                 infoMain( building );
320             }
321             else
322             {
323                 // display progress [i/n]
324                 int number;
325                 synchronized ( this )
326                 {
327                     number = ++currentVisitedProjectCount;
328                 }
329                 String progress = " [" + number + '/' + totalProjects + ']';
330 
331                 int pad = LINE_LENGTH - building.length() - progress.length();
332 
333                 infoMain( building + ( ( pad > 0 ) ? chars( ' ', pad ) : "" ) + progress );
334             }
335 
336             // ----------[ packaging ]----------
337             prefix = chars( '-', Math.max( 0, ( LINE_LENGTH - project.getPackaging().length() - 4 ) / 2 ) );
338             suffix = chars( '-', Math.max( 0, LINE_LENGTH - project.getPackaging().length() - 4 - prefix.length() ) );
339             infoMain( prefix + "[ " + project.getPackaging() + " ]" + suffix );
340         }
341     }
342 
343     @Override
344     public void mojoSkipped( ExecutionEvent event )
345     {
346         if ( logger.isWarnEnabled() )
347         {
348             logger.warn( "Goal " + event.getMojoExecution().getGoal()
349                 + " requires online mode for execution but Maven is currently offline, skipping" );
350         }
351     }
352 
353     /**
354      * <pre>--- mojo-artifactId:version:goal (mojo-executionId) @ project-artifactId ---</pre>
355      */
356     @Override
357     public void mojoStarted( ExecutionEvent event )
358     {
359         if ( logger.isInfoEnabled() )
360         {
361             logger.info( "" );
362 
363             MessageBuilder buffer = buffer().strong( "--- " );
364             append( buffer, event.getMojoExecution() );
365             append( buffer, event.getProject() );
366             buffer.strong( " ---" );
367 
368             logger.info( buffer.toString() );
369         }
370     }
371 
372     // CHECKSTYLE_OFF: LineLength
373     /**
374      * <pre>&gt;&gt;&gt; mojo-artifactId:version:goal (mojo-executionId) &gt; :forked-goal @ project-artifactId &gt;&gt;&gt;</pre>
375      * <pre>&gt;&gt;&gt; mojo-artifactId:version:goal (mojo-executionId) &gt; [lifecycle]phase @ project-artifactId &gt;&gt;&gt;</pre>
376      */
377     // CHECKSTYLE_ON: LineLength
378     @Override
379     public void forkStarted( ExecutionEvent event )
380     {
381         if ( logger.isInfoEnabled() )
382         {
383             logger.info( "" );
384 
385             MessageBuilder buffer = buffer().strong( ">>> " );
386             append( buffer, event.getMojoExecution() );
387             buffer.strong( " > " );
388             appendForkInfo( buffer, event.getMojoExecution().getMojoDescriptor() );
389             append( buffer, event.getProject() );
390             buffer.strong( " >>>" );
391 
392             logger.info( buffer.toString() );
393         }
394     }
395 
396     // CHECKSTYLE_OFF: LineLength
397     /**
398      * <pre>&lt;&lt;&lt; mojo-artifactId:version:goal (mojo-executionId) &lt; :forked-goal @ project-artifactId &lt;&lt;&lt;</pre>
399      * <pre>&lt;&lt;&lt; mojo-artifactId:version:goal (mojo-executionId) &lt; [lifecycle]phase @ project-artifactId &lt;&lt;&lt;</pre>
400      */
401     // CHECKSTYLE_ON: LineLength
402     @Override
403     public void forkSucceeded( ExecutionEvent event )
404     {
405         if ( logger.isInfoEnabled() )
406         {
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     {
424         buffer.mojo( me.getArtifactId() + ':' + me.getVersion() + ':' + me.getGoal() );
425         if ( me.getExecutionId() != null )
426         {
427             buffer.a( ' ' ).strong( '(' + me.getExecutionId() + ')' );
428         }
429     }
430 
431     private void appendForkInfo( MessageBuilder buffer, MojoDescriptor md )
432     {
433         StringBuilder buff = new StringBuilder();
434         if ( StringUtils.isNotEmpty( md.getExecutePhase() ) )
435         {
436             // forked phase
437             if ( StringUtils.isNotEmpty( md.getExecuteLifecycle() ) )
438             {
439                 buff.append( '[' );
440                 buff.append( md.getExecuteLifecycle() );
441                 buff.append( ']' );
442             }
443             buff.append( md.getExecutePhase() );
444         }
445         else
446         {
447             // forked goal
448             buff.append( ':' );
449             buff.append( md.getExecuteGoal() );
450         }
451         buffer.strong( buff.toString() );
452     }
453 
454     private void append( MessageBuilder buffer, MavenProject project )
455     {
456         buffer.a( " @ " ).project( project.getArtifactId() );
457     }
458 
459     @Override
460     public void forkedProjectStarted( ExecutionEvent event )
461     {
462         if ( logger.isInfoEnabled() && event.getMojoExecution().getForkedExecutions().size() > 1 )
463         {
464             logger.info( "" );
465             infoLine( '>' );
466 
467             infoMain( "Forking " + event.getProject().getName() + " " + event.getProject().getVersion() );
468 
469             infoLine( '>' );
470         }
471     }
472 }