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 static org.apache.maven.cli.CLIReportingUtils.formatDuration;
023import static org.apache.maven.cli.CLIReportingUtils.formatTimestamp;
024
025import org.apache.commons.lang3.Validate;
026import org.apache.maven.execution.AbstractExecutionListener;
027import org.apache.maven.execution.BuildFailure;
028import org.apache.maven.execution.BuildSuccess;
029import org.apache.maven.execution.BuildSummary;
030import org.apache.maven.execution.ExecutionEvent;
031import org.apache.maven.execution.MavenExecutionResult;
032import org.apache.maven.execution.MavenSession;
033import org.apache.maven.plugin.MojoExecution;
034import org.apache.maven.plugin.descriptor.MojoDescriptor;
035import org.apache.maven.project.MavenProject;
036import org.codehaus.plexus.util.StringUtils;
037import org.slf4j.Logger;
038import org.slf4j.LoggerFactory;
039
040/**
041 * Logs execution events to logger, eventually user-supplied.
042 *
043 * @author Benjamin Bentmann
044 */
045public class ExecutionEventLogger
046    extends AbstractExecutionListener
047{
048    private final Logger logger;
049
050    private static final int LINE_LENGTH = 72;
051    private static final int MAX_PADDED_BUILD_TIME_DURATION_LENGTH = 9;
052    private static final int MAX_PROJECT_NAME_LENGTH = 52;
053
054    public ExecutionEventLogger()
055    {
056        logger = LoggerFactory.getLogger( ExecutionEventLogger.class );
057    }
058
059    // TODO should we deprecate?
060    public ExecutionEventLogger( Logger logger )
061    {
062        this.logger = Validate.notNull( logger, "logger cannot be null" );
063    }
064
065    private static String chars( char c, int count )
066    {
067        StringBuilder buffer = new StringBuilder( count );
068
069        for ( int i = count; i > 0; i-- )
070        {
071            buffer.append( c );
072        }
073
074        return buffer.toString();
075    }
076
077    @Override
078    public void projectDiscoveryStarted( ExecutionEvent event )
079    {
080        if ( logger.isInfoEnabled() )
081        {
082            logger.info( "Scanning for projects..." );
083        }
084    }
085
086    @Override
087    public void sessionStarted( ExecutionEvent event )
088    {
089        if ( logger.isInfoEnabled() && event.getSession().getProjects().size() > 1 )
090        {
091            logger.info( chars( '-', LINE_LENGTH ) );
092
093            logger.info( "Reactor Build Order:" );
094
095            logger.info( "" );
096
097            for ( MavenProject project : event.getSession().getProjects() )
098            {
099                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}