1 package org.apache.maven.cli.event;
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
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
44
45
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
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
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
295
296
297
298 @Override
299 public void forkStarted( ExecutionEvent event )
300 {
301 if ( logger.isInfoEnabled() )
302 {
303 logger.info( "" );
304
305 MessageBuilder buffer = buffer().strong( ">>> " );
306 append( buffer, event.getMojoExecution() );
307 buffer.strong( " > " );
308 appendForkInfo( buffer, event.getMojoExecution().getMojoDescriptor() );
309 append( buffer, event.getProject() );
310 buffer.strong( " >>>" );
311
312 logger.info( buffer.toString() );
313 }
314 }
315
316
317
318
319
320
321
322 @Override
323 public void forkSucceeded( ExecutionEvent event )
324 {
325 if ( logger.isInfoEnabled() )
326 {
327 logger.info( "" );
328
329 MessageBuilder buffer = buffer().strong( "<<< " );
330 append( buffer, event.getMojoExecution() );
331 buffer.strong( " < " );
332 appendForkInfo( buffer, event.getMojoExecution().getMojoDescriptor() );
333 append( buffer, event.getProject() );
334 buffer.strong( " <<<" );
335
336 logger.info( buffer.toString() );
337
338 logger.info( "" );
339 }
340 }
341
342 private void append( MessageBuilder buffer, MojoExecution me )
343 {
344 buffer.mojo( me.getArtifactId() + ':' + me.getVersion() + ':' + me.getGoal() );
345 if ( me.getExecutionId() != null )
346 {
347 buffer.a( ' ' ).strong( '(' + me.getExecutionId() + ')' );
348 }
349 }
350
351 private void appendForkInfo( MessageBuilder buffer, MojoDescriptor md )
352 {
353 StringBuilder buff = new StringBuilder();
354 if ( StringUtils.isNotEmpty( md.getExecutePhase() ) )
355 {
356
357 if ( StringUtils.isNotEmpty( md.getExecuteLifecycle() ) )
358 {
359 buff.append( '[' );
360 buff.append( md.getExecuteLifecycle() );
361 buff.append( ']' );
362 }
363 buff.append( md.getExecutePhase() );
364 }
365 else
366 {
367
368 buff.append( ':' );
369 buff.append( md.getExecuteGoal() );
370 }
371 buffer.strong( buff.toString() );
372 }
373
374 private void append( MessageBuilder buffer, MavenProject project )
375 {
376 buffer.a( " @ " ).project( project.getArtifactId() );
377 }
378
379 @Override
380 public void forkedProjectStarted( ExecutionEvent event )
381 {
382 if ( logger.isInfoEnabled() && event.getMojoExecution().getForkedExecutions().size() > 1 )
383 {
384 logger.info( "" );
385 infoLine( '>' );
386
387 infoMain( "Forking " + event.getProject().getName() + " " + event.getProject().getVersion() );
388
389 infoLine( '>' );
390 }
391 }
392 }