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