Source code

001package org.apache.maven.cli.event;
002
003/*
004 * Licensed to the Apache Software Foundation (ASF) under one
005 * or more contributor license agreements.  See the NOTICE file
006 * distributed with this work for additional information
007 * regarding copyright ownership.  The ASF licenses this file
008 * to you under the Apache License, Version 2.0 (the
009 * "License"); you may not use this file except in compliance
010 * with the License.  You may obtain a copy of the License at
011 *
012 *   http://www.apache.org/licenses/LICENSE-2.0
013 *
014 * Unless required by applicable law or agreed to in writing,
015 * software distributed under the License is distributed on an
016 * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
017 * KIND, either express or implied.  See the License for the
018 * specific language governing permissions and limitations
019 * under the License.
020 */
021
022import java.util.Date;
023
024import org.apache.maven.execution.AbstractExecutionListener;
025import org.apache.maven.execution.BuildFailure;
026import org.apache.maven.execution.BuildSuccess;
027import org.apache.maven.execution.BuildSummary;
028import org.apache.maven.execution.ExecutionEvent;
029import org.apache.maven.execution.MavenExecutionResult;
030import org.apache.maven.execution.MavenSession;
031import org.apache.maven.plugin.MojoExecution;
032import org.apache.maven.project.MavenProject;
033import org.slf4j.Logger;
034import org.slf4j.LoggerFactory;
035
036/**
037 * Logs execution events to logger, eventually user-supplied.
038 *
039 * @author Benjamin Bentmann
040 */
041public class ExecutionEventLogger
042    extends AbstractExecutionListener
043{
044    private final Logger logger;
045
046    private static final int LINE_LENGTH = 72;
047
048    public ExecutionEventLogger()
049    {
050        logger = LoggerFactory.getLogger( ExecutionEventLogger.class );
051    }
052
053    // TODO should we deprecate?
054    public ExecutionEventLogger( Logger logger )
055    {
056        if ( logger == null )
057        {
058            throw new IllegalArgumentException( "logger missing" );
059        }
060
061        this.logger = logger;
062    }
063
064    private static String chars( char c, int count )
065    {
066        StringBuilder buffer = new StringBuilder( count );
067
068        for ( int i = count; i > 0; i-- )
069        {
070            buffer.append( c );
071        }
072
073        return buffer.toString();
074    }
075
076    private static String getFormattedTime( long time )
077    {
078        // NOTE: DateFormat is not suitable to format timespans of 24h+
079
080        long h = time / ( 60 * 60 * 1000 );
081        long m = ( time - h * 60 * 60 * 1000 ) / ( 60 * 1000 );
082        long s = ( time - h * 60 * 60 * 1000 - m * 60 * 1000 ) / 1000;
083        long ms = time % 1000;
084
085        String format;
086        if ( h > 0 )
087        {
088            format = "%1$d:%2$02d:%3$02d.%4$03ds";
089        }
090        else if ( m > 0 )
091        {
092            format = "%2$d:%3$02d.%4$03ds";
093        }
094        else
095        {
096            format = "%3$d.%4$03ds";
097        }
098
099        return String.format( format, h, m, s, ms );
100    }
101
102    @Override
103    public void projectDiscoveryStarted( ExecutionEvent event )
104    {
105        if ( logger.isInfoEnabled() )
106        {
107            logger.info( "Scanning for projects..." );
108        }
109    }
110
111    @Override
112    public void sessionStarted( ExecutionEvent event )
113    {
114        if ( logger.isInfoEnabled() && event.getSession().getProjects().size() > 1 )
115        {
116            logger.info( chars( '-', LINE_LENGTH ) );
117
118            logger.info( "Reactor Build Order:" );
119
120            logger.info( "" );
121
122            for ( MavenProject project : event.getSession().getProjects() )
123            {
124                logger.info( project.getName() );
125            }
126        }
127    }
128
129    @Override
130    public void sessionEnded( ExecutionEvent event )
131    {
132        if ( logger.isInfoEnabled() )
133        {
134            if ( event.getSession().getProjects().size() > 1 )
135            {
136                logReactorSummary( event.getSession() );
137            }
138
139            logResult( event.getSession() );
140
141            logStats( event.getSession() );
142
143            logger.info( chars( '-', LINE_LENGTH ) );
144        }
145    }
146
147    private void logReactorSummary( MavenSession session )
148    {
149        logger.info( chars( '-', LINE_LENGTH ) );
150
151        logger.info( "Reactor Summary:" );
152
153        logger.info( "" );
154
155        MavenExecutionResult result = session.getResult();
156
157        for ( MavenProject project : session.getProjects() )
158        {
159            StringBuilder buffer = new StringBuilder( 128 );
160
161            buffer.append( project.getName() );
162
163            buffer.append( ' ' );
164            while ( buffer.length() < LINE_LENGTH - 21 )
165            {
166                buffer.append( '.' );
167            }
168            buffer.append( ' ' );
169
170            BuildSummary buildSummary = result.getBuildSummary( project );
171
172            if ( buildSummary == null )
173            {
174                buffer.append( "SKIPPED" );
175            }
176            else if ( buildSummary instanceof BuildSuccess )
177            {
178                buffer.append( "SUCCESS [" );
179                buffer.append( getFormattedTime( buildSummary.getTime() ) );
180                buffer.append( "]" );
181            }
182            else if ( buildSummary instanceof BuildFailure )
183            {
184                buffer.append( "FAILURE [" );
185                buffer.append( getFormattedTime( buildSummary.getTime() ) );
186                buffer.append( "]" );
187            }
188
189            logger.info( buffer.toString() );
190        }
191    }
192
193    private void logResult( MavenSession session )
194    {
195        logger.info( chars( '-', LINE_LENGTH ) );
196
197        if ( session.getResult().hasExceptions() )
198        {
199            logger.info( "BUILD FAILURE" );
200        }
201        else
202        {
203            logger.info( "BUILD SUCCESS" );
204        }
205    }
206
207    private void logStats( MavenSession session )
208    {
209        logger.info( chars( '-', LINE_LENGTH ) );
210
211        Date finish = new Date();
212
213        long time = finish.getTime() - session.getRequest().getStartTime().getTime();
214
215        String wallClock = session.getRequest().isThreadConfigurationPresent() ? " (Wall Clock)" : "";
216
217        logger.info( "Total time: " + getFormattedTime( time ) + wallClock );
218
219        logger.info( "Finished at: " + finish );
220
221        System.gc();
222
223        Runtime r = Runtime.getRuntime();
224
225        long MB = 1024 * 1024;
226
227        logger.info( "Final Memory: " + ( r.totalMemory() - r.freeMemory() ) / MB + "M/" + r.totalMemory() / MB + "M" );
228    }
229
230    @Override
231    public void projectSkipped( ExecutionEvent event )
232    {
233        if ( logger.isInfoEnabled() )
234        {
235            logger.info( chars( ' ', LINE_LENGTH ) );
236            logger.info( chars( '-', LINE_LENGTH ) );
237
238            logger.info( "Skipping " + event.getProject().getName() );
239            logger.info( "This project has been banned from the build due to previous failures." );
240
241            logger.info( chars( '-', LINE_LENGTH ) );
242        }
243    }
244
245    @Override
246    public void projectStarted( ExecutionEvent event )
247    {
248        if ( logger.isInfoEnabled() )
249        {
250            logger.info( chars( ' ', LINE_LENGTH ) );
251            logger.info( chars( '-', LINE_LENGTH ) );
252
253            logger.info( "Building " + event.getProject().getName() + " " + event.getProject().getVersion() );
254
255            logger.info( chars( '-', LINE_LENGTH ) );
256        }
257    }
258
259    @Override
260    public void mojoSkipped( ExecutionEvent event )
261    {
262        if ( logger.isWarnEnabled() )
263        {
264            logger.warn( "Goal " + event.getMojoExecution().getGoal()
265                + " requires online mode for execution but Maven is currently offline, skipping" );
266        }
267    }
268
269    /**
270     * <pre>--- mojo-artifactId:version:goal (mojo-executionId) @ project-artifactId ---</pre>
271     */
272    @Override
273    public void mojoStarted( ExecutionEvent event )
274    {
275        if ( logger.isInfoEnabled() )
276        {
277            StringBuilder buffer = new StringBuilder( 128 );
278
279            buffer.append( "--- " );
280            append( buffer, event.getMojoExecution() );
281            append( buffer, event.getProject() );
282            buffer.append( " ---" );
283
284            logger.info( "" );
285            logger.info( buffer.toString() );
286        }
287    }
288
289    /**
290     * <pre>>>> mojo-artifactId:version:goal (mojo-executionId) @ project-artifactId >>></pre>
291     */
292    @Override
293    public void forkStarted( ExecutionEvent event )
294    {
295        if ( logger.isInfoEnabled() )
296        {
297            StringBuilder buffer = new StringBuilder( 128 );
298
299            buffer.append( ">>> " );
300            append( buffer, event.getMojoExecution() );
301            append( buffer, event.getProject() );
302            buffer.append( " >>>" );
303
304            logger.info( "" );
305            logger.info( buffer.toString() );
306        }
307    }
308
309    /**
310     * <pre>&lt;&lt;&lt; mojo-artifactId:version:goal (mojo-executionId) @ project-artifactId &lt;&lt;&lt;</pre>
311     */
312    @Override
313    public void forkSucceeded( ExecutionEvent event )
314    {
315        if ( logger.isInfoEnabled() )
316        {
317            StringBuilder buffer = new StringBuilder( 128 );
318
319            buffer.append( "<<< " );
320            append( buffer, event.getMojoExecution() );
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 append( StringBuilder buffer, MavenProject project )
340    {
341        buffer.append( " @ " ).append( project.getArtifactId() );
342    }
343
344    @Override
345    public void forkedProjectStarted( ExecutionEvent event )
346    {
347        if ( logger.isInfoEnabled() && event.getMojoExecution().getForkedExecutions().size() > 1 )
348        {
349            logger.info( chars( ' ', LINE_LENGTH ) );
350            logger.info( chars( '>', LINE_LENGTH ) );
351
352            logger.info( "Forking " + event.getProject().getName() + " " + event.getProject().getVersion() );
353
354            logger.info( chars( '>', LINE_LENGTH ) );
355        }
356    }
357
358}