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.maven.execution.AbstractExecutionListener;
026import org.apache.maven.execution.BuildFailure;
027import org.apache.maven.execution.BuildSuccess;
028import org.apache.maven.execution.BuildSummary;
029import org.apache.maven.execution.ExecutionEvent;
030import org.apache.maven.execution.MavenExecutionResult;
031import org.apache.maven.execution.MavenSession;
032import org.apache.maven.plugin.MojoExecution;
033import org.apache.maven.plugin.descriptor.MojoDescriptor;
034import org.apache.maven.project.MavenProject;
035import org.codehaus.plexus.util.StringUtils;
036import org.slf4j.Logger;
037import org.slf4j.LoggerFactory;
038
039/**
040 * Logs execution events to logger, eventually user-supplied.
041 *
042 * @author Benjamin Bentmann
043 */
044public class ExecutionEventLogger
045    extends AbstractExecutionListener
046{
047    private final Logger logger;
048
049    private static final int LINE_LENGTH = 72;
050    private static final int MAX_PADDED_BUILD_TIME_DURATION_LENGTH = 9;
051    private static final int MAX_PROJECT_NAME_LENGTH = 52;
052
053    public ExecutionEventLogger()
054    {
055        logger = LoggerFactory.getLogger( ExecutionEventLogger.class );
056    }
057
058    // TODO should we deprecate?
059    public ExecutionEventLogger( Logger logger )
060    {
061        if ( logger == null )
062        {
063            throw new IllegalArgumentException( "logger missing" );
064        }
065
066        this.logger = logger;
067    }
068
069    private static String chars( char c, int count )
070    {
071        StringBuilder buffer = new StringBuilder( count );
072
073        for ( int i = count; i > 0; i-- )
074        {
075            buffer.append( c );
076        }
077
078        return buffer.toString();
079    }
080
081    @Override
082    public void projectDiscoveryStarted( ExecutionEvent event )
083    {
084        if ( logger.isInfoEnabled() )
085        {
086            logger.info( "Scanning for projects..." );
087        }
088    }
089
090    @Override
091    public void sessionStarted( ExecutionEvent event )
092    {
093        if ( logger.isInfoEnabled() && event.getSession().getProjects().size() > 1 )
094        {
095            logger.info( chars( '-', LINE_LENGTH ) );
096
097            logger.info( "Reactor Build Order:" );
098
099            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    // CHECKSTYLE_OFF: LineLength
307    /**
308     * <pre>&lt;&lt;&lt; mojo-artifactId:version:goal (mojo-executionId) &lt; :forked-goal @ project-artifactId &lt;&lt;&lt;</pre>
309     * <pre>&lt;&lt;&lt; mojo-artifactId:version:goal (mojo-executionId) &lt; [lifecycle]phase @ project-artifactId &lt;&lt;&lt;</pre>
310     */
311    // CHECKSTYLE_ON: LineLength
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            buffer.append( " < " );
322            appendForkInfo( buffer, event.getMojoExecution().getMojoDescriptor() );
323            append( buffer, event.getProject() );
324            buffer.append( " <<<" );
325
326            logger.info( "" );
327            logger.info( buffer.toString() );
328        }
329    }
330
331    private void append( StringBuilder buffer, MojoExecution me )
332    {
333        buffer.append( me.getArtifactId() ).append( ':' ).append( me.getVersion() );
334        buffer.append( ':' ).append( me.getGoal() );
335        if ( me.getExecutionId() != null )
336        {
337            buffer.append( " (" ).append( me.getExecutionId() ).append( ')' );
338        }
339    }
340
341    private void appendForkInfo( StringBuilder buffer, MojoDescriptor md )
342    {
343        if ( StringUtils.isNotEmpty( md.getExecutePhase() ) )
344        {
345            // forked phase
346            if ( StringUtils.isNotEmpty( md.getExecuteLifecycle() ) )
347            {
348                buffer.append( '[' );
349                buffer.append( md.getExecuteLifecycle() );
350                buffer.append( ']' );
351            }
352            buffer.append( md.getExecutePhase() );
353        }
354        else
355        {
356            // forked goal
357            buffer.append( ':' );
358            buffer.append( md.getExecuteGoal() );
359        }
360    }
361
362    private void append( StringBuilder buffer, MavenProject project )
363    {
364        buffer.append( " @ " ).append( project.getArtifactId() );
365    }
366
367    @Override
368    public void forkedProjectStarted( ExecutionEvent event )
369    {
370        if ( logger.isInfoEnabled() && event.getMojoExecution().getForkedExecutions().size() > 1 )
371        {
372            logger.info( chars( ' ', LINE_LENGTH ) );
373            logger.info( chars( '>', LINE_LENGTH ) );
374
375            logger.info( "Forking " + event.getProject().getName() + " " + event.getProject().getVersion() );
376
377            logger.info( chars( '>', LINE_LENGTH ) );
378        }
379    }
380
381}