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  
25  import org.apache.commons.lang3.Validate;
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.codehaus.plexus.util.StringUtils;
37  import org.slf4j.Logger;
38  import org.slf4j.LoggerFactory;
39  
40  /**
41   * Logs execution events to logger, eventually user-supplied.
42   *
43   * @author Benjamin Bentmann
44   */
45  public class ExecutionEventLogger
46      extends AbstractExecutionListener
47  {
48      private final Logger logger;
49  
50      private static final int LINE_LENGTH = 72;
51      private static final int MAX_PADDED_BUILD_TIME_DURATION_LENGTH = 9;
52      private static final int MAX_PROJECT_NAME_LENGTH = 52;
53  
54      public ExecutionEventLogger()
55      {
56          logger = LoggerFactory.getLogger( ExecutionEventLogger.class );
57      }
58  
59      // TODO should we deprecate?
60      public ExecutionEventLogger( Logger logger )
61      {
62          this.logger = Validate.notNull( logger, "logger cannot be null" );
63      }
64  
65      private static String chars( char c, int count )
66      {
67          StringBuilder buffer = new StringBuilder( count );
68  
69          for ( int i = count; i > 0; i-- )
70          {
71              buffer.append( c );
72          }
73  
74          return buffer.toString();
75      }
76  
77      @Override
78      public void projectDiscoveryStarted( ExecutionEvent event )
79      {
80          if ( logger.isInfoEnabled() )
81          {
82              logger.info( "Scanning for projects..." );
83          }
84      }
85  
86      @Override
87      public void sessionStarted( ExecutionEvent event )
88      {
89          if ( logger.isInfoEnabled() && event.getSession().getProjects().size() > 1 )
90          {
91              logger.info( chars( '-', LINE_LENGTH ) );
92  
93              logger.info( "Reactor Build Order:" );
94  
95              logger.info( "" );
96  
97              for ( MavenProject project : event.getSession().getProjects() )
98              {
99                  logger.info( project.getName() );
100             }
101         }
102     }
103 
104     @Override
105     public void sessionEnded( ExecutionEvent event )
106     {
107         if ( logger.isInfoEnabled() )
108         {
109             if ( event.getSession().getProjects().size() > 1 )
110             {
111                 logReactorSummary( event.getSession() );
112             }
113 
114             logResult( event.getSession() );
115 
116             logStats( event.getSession() );
117 
118             logger.info( chars( '-', LINE_LENGTH ) );
119         }
120     }
121 
122     private void logReactorSummary( MavenSession session )
123     {
124         logger.info( chars( '-', LINE_LENGTH ) );
125 
126         logger.info( "Reactor Summary:" );
127 
128         logger.info( "" );
129 
130         MavenExecutionResult result = session.getResult();
131 
132         for ( MavenProject project : session.getProjects() )
133         {
134             StringBuilder buffer = new StringBuilder( 128 );
135 
136             buffer.append( project.getName() );
137             buffer.append( ' ' );
138 
139             if ( buffer.length() <= MAX_PROJECT_NAME_LENGTH )
140             {
141                 while ( buffer.length() < MAX_PROJECT_NAME_LENGTH )
142                 {
143                     buffer.append( '.' );
144                 }
145                 buffer.append( ' ' );
146             }
147 
148             BuildSummary buildSummary = result.getBuildSummary( project );
149 
150             if ( buildSummary == null )
151             {
152                 buffer.append( "SKIPPED" );
153             }
154             else if ( buildSummary instanceof BuildSuccess )
155             {
156                 buffer.append( "SUCCESS [" );
157                 String buildTimeDuration = formatDuration( buildSummary.getTime() );
158                 int padSize = MAX_PADDED_BUILD_TIME_DURATION_LENGTH - buildTimeDuration.length();
159                 if ( padSize > 0 )
160                 {
161                     buffer.append( chars( ' ', padSize ) );
162                 }
163                 buffer.append( buildTimeDuration );
164                 buffer.append( "]" );
165             }
166             else if ( buildSummary instanceof BuildFailure )
167             {
168                 buffer.append( "FAILURE [" );
169                 String buildTimeDuration = formatDuration( buildSummary.getTime() );
170                 int padSize = MAX_PADDED_BUILD_TIME_DURATION_LENGTH - buildTimeDuration.length();
171                 if ( padSize > 0 )
172                 {
173                     buffer.append( chars( ' ', padSize ) );
174                 }
175                 buffer.append( buildTimeDuration );
176                 buffer.append( "]" );
177             }
178 
179             logger.info( buffer.toString() );
180         }
181     }
182 
183     private void logResult( MavenSession session )
184     {
185         logger.info( chars( '-', LINE_LENGTH ) );
186 
187         if ( session.getResult().hasExceptions() )
188         {
189             logger.info( "BUILD FAILURE" );
190         }
191         else
192         {
193             logger.info( "BUILD SUCCESS" );
194         }
195     }
196 
197     private void logStats( MavenSession session )
198     {
199         logger.info( chars( '-', LINE_LENGTH ) );
200 
201         long finish = System.currentTimeMillis();
202 
203         long time = finish - session.getRequest().getStartTime().getTime();
204 
205         String wallClock = session.getRequest().getDegreeOfConcurrency() > 1 ? " (Wall Clock)" : "";
206 
207         logger.info( "Total time: " + formatDuration( time ) + wallClock );
208 
209         logger.info( "Finished at: " + formatTimestamp( finish ) );
210 
211         System.gc();
212 
213         Runtime r = Runtime.getRuntime();
214 
215         long mb = 1024 * 1024;
216 
217         logger.info( "Final Memory: " + ( r.totalMemory() - r.freeMemory() ) / mb + "M/" + r.totalMemory() / mb + "M" );
218     }
219 
220     @Override
221     public void projectSkipped( ExecutionEvent event )
222     {
223         if ( logger.isInfoEnabled() )
224         {
225             logger.info( chars( ' ', LINE_LENGTH ) );
226             logger.info( chars( '-', LINE_LENGTH ) );
227 
228             logger.info( "Skipping " + event.getProject().getName() );
229             logger.info( "This project has been banned from the build due to previous failures." );
230 
231             logger.info( chars( '-', LINE_LENGTH ) );
232         }
233     }
234 
235     @Override
236     public void projectStarted( ExecutionEvent event )
237     {
238         if ( logger.isInfoEnabled() )
239         {
240             logger.info( chars( ' ', LINE_LENGTH ) );
241             logger.info( chars( '-', LINE_LENGTH ) );
242 
243             logger.info( "Building " + event.getProject().getName() + " " + event.getProject().getVersion() );
244 
245             logger.info( chars( '-', LINE_LENGTH ) );
246         }
247     }
248 
249     @Override
250     public void mojoSkipped( ExecutionEvent event )
251     {
252         if ( logger.isWarnEnabled() )
253         {
254             logger.warn( "Goal " + event.getMojoExecution().getGoal()
255                 + " requires online mode for execution but Maven is currently offline, skipping" );
256         }
257     }
258 
259     /**
260      * <pre>--- mojo-artifactId:version:goal (mojo-executionId) @ project-artifactId ---</pre>
261      */
262     @Override
263     public void mojoStarted( ExecutionEvent event )
264     {
265         if ( logger.isInfoEnabled() )
266         {
267             StringBuilder buffer = new StringBuilder( 128 );
268 
269             buffer.append( "--- " );
270             append( buffer, event.getMojoExecution() );
271             append( buffer, event.getProject() );
272             buffer.append( " ---" );
273 
274             logger.info( "" );
275             logger.info( buffer.toString() );
276         }
277     }
278 
279     /**
280      * <pre>>>> mojo-artifactId:version:goal (mojo-executionId) > :forked-goal @ project-artifactId >>></pre>
281      * <pre>>>> mojo-artifactId:version:goal (mojo-executionId) > [lifecycle]phase @ project-artifactId >>></pre>
282      */
283     @Override
284     public void forkStarted( ExecutionEvent event )
285     {
286         if ( logger.isInfoEnabled() )
287         {
288             StringBuilder buffer = new StringBuilder( 128 );
289 
290             buffer.append( ">>> " );
291             append( buffer, event.getMojoExecution() );
292             buffer.append( " > " );
293             appendForkInfo( buffer, event.getMojoExecution().getMojoDescriptor() );
294             append( buffer, event.getProject() );
295             buffer.append( " >>>" );
296 
297             logger.info( "" );
298             logger.info( buffer.toString() );
299         }
300     }
301 
302     // CHECKSTYLE_OFF: LineLength
303     /**
304      * <pre>&lt;&lt;&lt; mojo-artifactId:version:goal (mojo-executionId) &lt; :forked-goal @ project-artifactId &lt;&lt;&lt;</pre>
305      * <pre>&lt;&lt;&lt; mojo-artifactId:version:goal (mojo-executionId) &lt; [lifecycle]phase @ project-artifactId &lt;&lt;&lt;</pre>
306      */
307     // CHECKSTYLE_ON: LineLength
308     @Override
309     public void forkSucceeded( ExecutionEvent event )
310     {
311         if ( logger.isInfoEnabled() )
312         {
313             StringBuilder buffer = new StringBuilder( 128 );
314 
315             buffer.append( "<<< " );
316             append( buffer, event.getMojoExecution() );
317             buffer.append( " < " );
318             appendForkInfo( buffer, event.getMojoExecution().getMojoDescriptor() );
319             append( buffer, event.getProject() );
320             buffer.append( " <<<" );
321 
322             logger.info( "" );
323             logger.info( buffer.toString() );
324         }
325     }
326 
327     private void append( StringBuilder buffer, MojoExecution me )
328     {
329         buffer.append( me.getArtifactId() ).append( ':' ).append( me.getVersion() );
330         buffer.append( ':' ).append( me.getGoal() );
331         if ( me.getExecutionId() != null )
332         {
333             buffer.append( " (" ).append( me.getExecutionId() ).append( ')' );
334         }
335     }
336 
337     private void appendForkInfo( StringBuilder buffer, MojoDescriptor md )
338     {
339         if ( StringUtils.isNotEmpty( md.getExecutePhase() ) )
340         {
341             // forked phase
342             if ( StringUtils.isNotEmpty( md.getExecuteLifecycle() ) )
343             {
344                 buffer.append( '[' );
345                 buffer.append( md.getExecuteLifecycle() );
346                 buffer.append( ']' );
347             }
348             buffer.append( md.getExecutePhase() );
349         }
350         else
351         {
352             // forked goal
353             buffer.append( ':' );
354             buffer.append( md.getExecuteGoal() );
355         }
356     }
357 
358     private void append( StringBuilder buffer, MavenProject project )
359     {
360         buffer.append( " @ " ).append( project.getArtifactId() );
361     }
362 
363     @Override
364     public void forkedProjectStarted( ExecutionEvent event )
365     {
366         if ( logger.isInfoEnabled() && event.getMojoExecution().getForkedExecutions().size() > 1 )
367         {
368             logger.info( chars( ' ', LINE_LENGTH ) );
369             logger.info( chars( '>', LINE_LENGTH ) );
370 
371             logger.info( "Forking " + event.getProject().getName() + " " + event.getProject().getVersion() );
372 
373             logger.info( chars( '>', LINE_LENGTH ) );
374         }
375     }
376 
377 }