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 java.io.File;
27 import java.util.List;
28 import java.util.Objects;
29
30 import org.apache.maven.execution.AbstractExecutionListener;
31 import org.apache.maven.execution.BuildFailure;
32 import org.apache.maven.execution.BuildSuccess;
33 import org.apache.maven.execution.BuildSummary;
34 import org.apache.maven.execution.ExecutionEvent;
35 import org.apache.maven.execution.MavenExecutionResult;
36 import org.apache.maven.execution.MavenSession;
37 import org.apache.maven.logwrapper.LogLevelRecorder;
38 import org.apache.maven.logwrapper.MavenSlf4jWrapperFactory;
39 import org.apache.maven.plugin.MojoExecution;
40 import org.apache.maven.plugin.descriptor.MojoDescriptor;
41 import org.apache.maven.project.MavenProject;
42 import org.apache.maven.shared.utils.logging.MessageBuilder;
43 import org.apache.maven.shared.utils.logging.MessageUtils;
44 import org.codehaus.plexus.util.StringUtils;
45 import org.slf4j.ILoggerFactory;
46 import org.slf4j.Logger;
47 import org.slf4j.LoggerFactory;
48
49
50
51
52
53
54 public class ExecutionEventLogger extends AbstractExecutionListener
55 {
56 private final Logger logger;
57
58 private static final int MAX_LOG_PREFIX_SIZE = 8;
59 private static final int PROJECT_STATUS_SUFFIX_SIZE = 20;
60 private static final int MIN_TERMINAL_WIDTH = 60;
61 private static final int DEFAULT_TERMINAL_WIDTH = 80;
62 private static final int MAX_TERMINAL_WIDTH = 130;
63 private static final int MAX_PADDED_BUILD_TIME_DURATION_LENGTH = 9;
64
65 private final int terminalWidth;
66 private final int lineLength;
67 private final int maxProjectNameLength;
68 private int totalProjects;
69 private volatile int currentVisitedProjectCount;
70
71 public ExecutionEventLogger()
72 {
73 this( LoggerFactory.getLogger( ExecutionEventLogger.class ) );
74 }
75
76 public ExecutionEventLogger( int terminalWidth )
77 {
78 this( LoggerFactory.getLogger( ExecutionEventLogger.class ), terminalWidth );
79 }
80
81 public ExecutionEventLogger( Logger logger )
82 {
83 this( logger, MessageUtils.getTerminalWidth() );
84 }
85
86 public ExecutionEventLogger( Logger logger, int terminalWidth )
87 {
88 this.logger = Objects.requireNonNull( logger, "logger cannot be null" );
89 this.terminalWidth = Math.min( MAX_TERMINAL_WIDTH,
90 Math.max( terminalWidth < 0 ? DEFAULT_TERMINAL_WIDTH : terminalWidth,
91 MIN_TERMINAL_WIDTH ) );
92 this.lineLength = this.terminalWidth - MAX_LOG_PREFIX_SIZE;
93 this.maxProjectNameLength = this.lineLength - PROJECT_STATUS_SUFFIX_SIZE;
94 }
95
96 private static String chars( char c, int count )
97 {
98 StringBuilder buffer = new StringBuilder( count );
99
100 for ( int i = count; i > 0; i-- )
101 {
102 buffer.append( c );
103 }
104
105 return buffer.toString();
106 }
107
108 private void infoLine( char c )
109 {
110 infoMain( chars( c, lineLength ) );
111 }
112
113 private void infoMain( String msg )
114 {
115 logger.info( buffer().strong( msg ).toString() );
116 }
117
118 @Override
119 public void projectDiscoveryStarted( ExecutionEvent event )
120 {
121 if ( logger.isInfoEnabled() )
122 {
123 logger.info( "Scanning for projects..." );
124 }
125 }
126
127 @Override
128 public void sessionStarted( ExecutionEvent event )
129 {
130 if ( logger.isInfoEnabled() && event.getSession().getProjects().size() > 1 )
131 {
132 infoLine( '-' );
133
134 infoMain( "Reactor Build Order:" );
135
136 logger.info( "" );
137
138 final List<MavenProject> projects = event.getSession().getProjects();
139 for ( MavenProject project : projects )
140 {
141 int len = lineLength - project.getName().length() - project.getPackaging().length() - 2;
142 logger.info( "{}{}[{}]",
143 project.getName(), chars( ' ', ( len > 0 ) ? len : 1 ), project.getPackaging() );
144 }
145
146 final List<MavenProject> allProjects = event.getSession().getAllProjects();
147 final int projectsSkipped = allProjects.size() - projects.size();
148
149 currentVisitedProjectCount = projectsSkipped;
150 totalProjects = allProjects.size();
151 }
152 }
153
154 @Override
155 public void sessionEnded( ExecutionEvent event )
156 {
157 if ( logger.isInfoEnabled() )
158 {
159 if ( event.getSession().getProjects().size() > 1 )
160 {
161 logReactorSummary( event.getSession() );
162 }
163
164 ILoggerFactory iLoggerFactory = LoggerFactory.getILoggerFactory();
165
166 if ( iLoggerFactory instanceof MavenSlf4jWrapperFactory )
167 {
168 MavenSlf4jWrapperFactory loggerFactory = (MavenSlf4jWrapperFactory) iLoggerFactory;
169 loggerFactory.getLogLevelRecorder()
170 .filter( LogLevelRecorder::metThreshold )
171 .ifPresent( recorder ->
172 event.getSession().getResult().addException( new Exception(
173 "Build failed due to log statements with a higher severity than allowed. "
174 + "Fix the logged issues or remove flag --fail-on-severity (-fos)." ) )
175 );
176 }
177
178 logResult( event.getSession() );
179
180 logStats( event.getSession() );
181
182 infoLine( '-' );
183 }
184 }
185
186 private boolean isSingleVersionedReactor( MavenSession session )
187 {
188 boolean result = true;
189
190 MavenProject topProject = session.getTopLevelProject();
191 List<MavenProject> sortedProjects = session.getProjectDependencyGraph().getSortedProjects();
192 for ( MavenProject mavenProject : sortedProjects )
193 {
194 if ( !topProject.getVersion().equals( mavenProject.getVersion() ) )
195 {
196 result = false;
197 break;
198 }
199 }
200
201 return result;
202 }
203
204 private void logReactorSummary( MavenSession session )
205 {
206 boolean isSingleVersion = isSingleVersionedReactor( session );
207
208 infoLine( '-' );
209
210 StringBuilder summary = new StringBuilder( "Reactor Summary" );
211 if ( isSingleVersion )
212 {
213 summary.append( " for " );
214 summary.append( session.getTopLevelProject().getName() );
215 summary.append( " " );
216 summary.append( session.getTopLevelProject().getVersion() );
217 }
218 summary.append( ":" );
219 infoMain( summary.toString() );
220
221 logger.info( "" );
222
223 MavenExecutionResult result = session.getResult();
224
225 List<MavenProject> projects = session.getProjects();
226
227 for ( MavenProject project : projects )
228 {
229 StringBuilder buffer = new StringBuilder( 128 );
230
231 buffer.append( project.getName() );
232 buffer.append( ' ' );
233
234 if ( !isSingleVersion )
235 {
236 buffer.append( project.getVersion() );
237 buffer.append( ' ' );
238 }
239
240 if ( buffer.length() <= maxProjectNameLength )
241 {
242 while ( buffer.length() < maxProjectNameLength )
243 {
244 buffer.append( '.' );
245 }
246 buffer.append( ' ' );
247 }
248
249 BuildSummary buildSummary = result.getBuildSummary( project );
250
251 if ( buildSummary == null )
252 {
253 buffer.append( buffer().warning( "SKIPPED" ) );
254 }
255 else if ( buildSummary instanceof BuildSuccess )
256 {
257 buffer.append( buffer().success( "SUCCESS" ) );
258 buffer.append( " [" );
259 String buildTimeDuration = formatDuration( buildSummary.getTime() );
260 int padSize = MAX_PADDED_BUILD_TIME_DURATION_LENGTH - buildTimeDuration.length();
261 if ( padSize > 0 )
262 {
263 buffer.append( chars( ' ', padSize ) );
264 }
265 buffer.append( buildTimeDuration );
266 buffer.append( ']' );
267 }
268 else if ( buildSummary instanceof BuildFailure )
269 {
270 buffer.append( buffer().failure( "FAILURE" ) );
271 buffer.append( " [" );
272 String buildTimeDuration = formatDuration( buildSummary.getTime() );
273 int padSize = MAX_PADDED_BUILD_TIME_DURATION_LENGTH - buildTimeDuration.length();
274 if ( padSize > 0 )
275 {
276 buffer.append( chars( ' ', padSize ) );
277 }
278 buffer.append( buildTimeDuration );
279 buffer.append( ']' );
280 }
281
282 logger.info( buffer.toString() );
283 }
284 }
285
286 private void logResult( MavenSession session )
287 {
288 infoLine( '-' );
289 MessageBuilder buffer = buffer();
290
291 if ( session.getResult().hasExceptions() )
292 {
293 buffer.failure( "BUILD FAILURE" );
294 }
295 else
296 {
297 buffer.success( "BUILD SUCCESS" );
298 }
299 logger.info( buffer.toString() );
300 }
301
302 private void logStats( MavenSession session )
303 {
304 infoLine( '-' );
305
306 long finish = System.currentTimeMillis();
307
308 long time = finish - session.getRequest().getStartTime().getTime();
309
310 String wallClock = session.getRequest().getDegreeOfConcurrency() > 1 ? " (Wall Clock)" : "";
311
312 logger.info( "Total time: {}{}", formatDuration( time ), wallClock );
313
314 logger.info( "Finished at: {}", formatTimestamp( finish ) );
315 }
316
317 @Override
318 public void projectSkipped( ExecutionEvent event )
319 {
320 if ( logger.isInfoEnabled() )
321 {
322 logger.info( "" );
323 infoLine( '-' );
324
325 infoMain( "Skipping " + event.getProject().getName() );
326 logger.info( "This project has been banned from the build due to previous failures." );
327
328 infoLine( '-' );
329 }
330 }
331
332 @Override
333 public void projectStarted( ExecutionEvent event )
334 {
335 if ( logger.isInfoEnabled() )
336 {
337 MavenProject project = event.getProject();
338
339 logger.info( "" );
340
341
342 String projectKey = project.getGroupId() + ':' + project.getArtifactId();
343
344 final String preHeader = "--< ";
345 final String postHeader = " >--";
346
347 final int headerLen = preHeader.length() + projectKey.length() + postHeader.length();
348
349 String prefix = chars( '-', Math.max( 0, ( lineLength - headerLen ) / 2 ) ) + preHeader;
350
351 String suffix = postHeader + chars( '-',
352 Math.max( 0, lineLength - headerLen - prefix.length() + preHeader.length() ) );
353
354 logger.info( buffer().strong( prefix ).project( projectKey ).strong( suffix ).toString() );
355
356
357 String building = "Building " + event.getProject().getName() + " " + event.getProject().getVersion();
358
359 if ( totalProjects <= 1 )
360 {
361 infoMain( building );
362 }
363 else
364 {
365
366 int number;
367 synchronized ( this )
368 {
369 number = ++currentVisitedProjectCount;
370 }
371 String progress = " [" + number + '/' + totalProjects + ']';
372
373 int pad = lineLength - building.length() - progress.length();
374
375 infoMain( building + ( ( pad > 0 ) ? chars( ' ', pad ) : "" ) + progress );
376 }
377
378
379 File currentPom = project.getFile();
380 if ( currentPom != null )
381 {
382 MavenSession session = event.getSession();
383 File rootBasedir = session.getTopLevelProject().getBasedir();
384 logger.info( " from " + rootBasedir.toPath().relativize( currentPom.toPath() ) );
385 }
386
387
388 prefix = chars( '-', Math.max( 0, ( lineLength - project.getPackaging().length() - 4 ) / 2 ) );
389 suffix = chars( '-', Math.max( 0, lineLength - project.getPackaging().length() - 4 - prefix.length() ) );
390 infoMain( prefix + "[ " + project.getPackaging() + " ]" + suffix );
391 }
392 }
393
394 @Override
395 public void mojoSkipped( ExecutionEvent event )
396 {
397 if ( logger.isWarnEnabled() )
398 {
399 logger.warn( "Goal '{}' requires online mode for execution but Maven is currently offline, skipping",
400 event.getMojoExecution().getGoal() );
401 }
402 }
403
404
405
406
407 @Override
408 public void mojoStarted( ExecutionEvent event )
409 {
410 if ( logger.isInfoEnabled() )
411 {
412 logger.info( "" );
413
414 MessageBuilder buffer = buffer().strong( "--- " );
415 append( buffer, event.getMojoExecution() );
416 append( buffer, event.getProject() );
417 buffer.strong( " ---" );
418
419 logger.info( buffer.toString() );
420 }
421 }
422
423
424
425
426
427
428
429 @Override
430 public void forkStarted( ExecutionEvent event )
431 {
432 if ( logger.isInfoEnabled() )
433 {
434 logger.info( "" );
435
436 MessageBuilder buffer = buffer().strong( ">>> " );
437 append( buffer, event.getMojoExecution() );
438 buffer.strong( " > " );
439 appendForkInfo( buffer, event.getMojoExecution().getMojoDescriptor() );
440 append( buffer, event.getProject() );
441 buffer.strong( " >>>" );
442
443 logger.info( buffer.toString() );
444 }
445 }
446
447
448
449
450
451
452
453 @Override
454 public void forkSucceeded( ExecutionEvent event )
455 {
456 if ( logger.isInfoEnabled() )
457 {
458 logger.info( "" );
459
460 MessageBuilder buffer = buffer().strong( "<<< " );
461 append( buffer, event.getMojoExecution() );
462 buffer.strong( " < " );
463 appendForkInfo( buffer, event.getMojoExecution().getMojoDescriptor() );
464 append( buffer, event.getProject() );
465 buffer.strong( " <<<" );
466
467 logger.info( buffer.toString() );
468
469 logger.info( "" );
470 }
471 }
472
473 private void append( MessageBuilder buffer, MojoExecution me )
474 {
475 buffer.mojo( me.getArtifactId() + ':' + me.getVersion() + ':' + me.getGoal() );
476 if ( me.getExecutionId() != null )
477 {
478 buffer.a( ' ' ).strong( '(' + me.getExecutionId() + ')' );
479 }
480 }
481
482 private void appendForkInfo( MessageBuilder buffer, MojoDescriptor md )
483 {
484 StringBuilder buff = new StringBuilder();
485 if ( StringUtils.isNotEmpty( md.getExecutePhase() ) )
486 {
487
488 if ( StringUtils.isNotEmpty( md.getExecuteLifecycle() ) )
489 {
490 buff.append( '[' );
491 buff.append( md.getExecuteLifecycle() );
492 buff.append( ']' );
493 }
494 buff.append( md.getExecutePhase() );
495 }
496 else
497 {
498
499 buff.append( ':' );
500 buff.append( md.getExecuteGoal() );
501 }
502 buffer.strong( buff.toString() );
503 }
504
505 private void append( MessageBuilder buffer, MavenProject project )
506 {
507 buffer.a( " @ " ).project( project.getArtifactId() );
508 }
509
510 @Override
511 public void forkedProjectStarted( ExecutionEvent event )
512 {
513 if ( logger.isInfoEnabled() && event.getMojoExecution().getForkedExecutions().size() > 1 )
514 {
515 logger.info( "" );
516 infoLine( '>' );
517
518 infoMain( "Forking " + event.getProject().getName() + " " + event.getProject().getVersion() );
519
520 infoLine( '>' );
521 }
522 }
523 }