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