[MNG-5176] Print build times in an ISO 8601-style manner

This commit is contained in:
Michael Osipov 2014-02-09 12:14:43 +01:00
parent d266733f04
commit be19ddb6d9
5 changed files with 104 additions and 102 deletions

View File

@ -194,7 +194,7 @@
<goal>create-timestamp</goal> <goal>create-timestamp</goal>
</goals> </goals>
<configuration> <configuration>
<timestampFormat>'NON-CANONICAL_'yyyy-MM-dd_HH-mm_'${user.name}'</timestampFormat> <timestampFormat>'NON-CANONICAL_'yyyy-MM-dd'T'HH:mm:ss_'${user.name}'</timestampFormat>
<timestampPropertyName>nonCanonicalRevision</timestampPropertyName> <timestampPropertyName>nonCanonicalRevision</timestampPropertyName>
</configuration> </configuration>
</execution> </execution>

View File

@ -25,6 +25,7 @@
import java.util.Date; import java.util.Date;
import java.util.Locale; import java.util.Locale;
import java.util.Properties; import java.util.Properties;
import java.util.TimeZone;
import org.codehaus.plexus.util.IOUtil; import org.codehaus.plexus.util.IOUtil;
import org.codehaus.plexus.util.Os; import org.codehaus.plexus.util.Os;
@ -41,9 +42,10 @@ public final class CLIReportingUtils
public static final long MB = 1024 * 1024; public static final long MB = 1024 * 1024;
public static final int MS_PER_SEC = 1000; private static final long ONE_SECOND = 1000L;
private static final long ONE_MINUTE = 60 * ONE_SECOND;
public static final int SEC_PER_MIN = 60; private static final long ONE_HOUR = 60 * ONE_MINUTE;
private static final long ONE_DAY = 24 * ONE_HOUR;
public static final String BUILD_VERSION_PROPERTY = "version"; public static final String BUILD_VERSION_PROPERTY = "version";
@ -87,8 +89,7 @@ static String createMavenVersionString( Properties buildProperties )
msg += ( rev != null ? rev : "" ); msg += ( rev != null ? rev : "" );
if ( timestamp != null ) if ( timestamp != null )
{ {
SimpleDateFormat fmt = new SimpleDateFormat( "yyyy-MM-dd HH:mm:ssZ" ); String ts = formatTimestamp( Long.valueOf( timestamp ) );
String ts = fmt.format( new Date( Long.valueOf( timestamp ) ) );
msg += ( rev != null ? "; " : "" ) + ts; msg += ( rev != null ? "; " : "" ) + ts;
} }
msg += ")"; msg += ")";
@ -148,4 +149,47 @@ public static void showError( Logger logger, String message, Throwable e, boolea
} }
} }
public static String formatTimestamp( long timestamp )
{
// Manual construction of the tz offset because only Java 7 understands 'ZZ' replacement
TimeZone tz = TimeZone.getDefault();
int offset = tz.getRawOffset();
long m = Math.abs( ( offset / ONE_MINUTE ) % 60 );
long h = Math.abs( ( offset / ONE_HOUR ) % 24 );
int offsetDir = (int) Math.signum( (float) offset );
char offsetSign = offsetDir >= 0 ? '+' : '-';
return String.format( "%tFT%<tT%s%02d:%02d", timestamp, offsetSign, h, m );
}
public static String formatDuration( long duration )
{
long ms = duration % 1000;
long s = ( duration / ONE_SECOND ) % 60;
long m = ( duration / ONE_MINUTE ) % 60;
long h = ( duration / ONE_HOUR ) % 24;
long d = duration / ONE_DAY;
String format;
if ( d > 0 )
{
format = "%d d %02d:%02d h";
}
else if ( h > 0 )
{
format = "%2$02d:%3$02d h";
}
else if ( m > 0 )
{
format = "%3$02d:%4$02d min";
}
else
{
format = "%4$d.%5$03d s";
}
return String.format( format, d, h, m, s, ms );
}
} }

View File

@ -19,8 +19,8 @@
* under the License. * under the License.
*/ */
import java.util.Date; import static org.apache.maven.cli.CLIReportingUtils.formatDuration;
import static org.apache.maven.cli.CLIReportingUtils.formatTimestamp;
import org.apache.maven.execution.AbstractExecutionListener; import org.apache.maven.execution.AbstractExecutionListener;
import org.apache.maven.execution.BuildFailure; import org.apache.maven.execution.BuildFailure;
import org.apache.maven.execution.BuildSuccess; import org.apache.maven.execution.BuildSuccess;
@ -44,6 +44,7 @@ public class ExecutionEventLogger
private final Logger logger; private final Logger logger;
private static final int LINE_LENGTH = 72; private static final int LINE_LENGTH = 72;
private static final int BUILD_TIME_DURATION_LENGTH = 9;
public ExecutionEventLogger() public ExecutionEventLogger()
{ {
@ -73,32 +74,6 @@ private static String chars( char c, int count )
return buffer.toString(); return buffer.toString();
} }
private static String getFormattedTime( long time )
{
// NOTE: DateFormat is not suitable to format timespans of 24h+
long h = time / ( 60 * 60 * 1000 );
long m = ( time - h * 60 * 60 * 1000 ) / ( 60 * 1000 );
long s = ( time - h * 60 * 60 * 1000 - m * 60 * 1000 ) / 1000;
long ms = time % 1000;
String format;
if ( h > 0 )
{
format = "%1$d:%2$02d:%3$02d.%4$03ds";
}
else if ( m > 0 )
{
format = "%2$d:%3$02d.%4$03ds";
}
else
{
format = "%3$d.%4$03ds";
}
return String.format( format, h, m, s, ms );
}
@Override @Override
public void projectDiscoveryStarted( ExecutionEvent event ) public void projectDiscoveryStarted( ExecutionEvent event )
{ {
@ -176,13 +151,17 @@ private void logReactorSummary( MavenSession session )
else if ( buildSummary instanceof BuildSuccess ) else if ( buildSummary instanceof BuildSuccess )
{ {
buffer.append( "SUCCESS [" ); buffer.append( "SUCCESS [" );
buffer.append( getFormattedTime( buildSummary.getTime() ) ); String buildTimeDuration = formatDuration( buildSummary.getTime() );
buffer.append( chars( ' ', BUILD_TIME_DURATION_LENGTH - buildTimeDuration.length() ) );
buffer.append( buildTimeDuration );
buffer.append( "]" ); buffer.append( "]" );
} }
else if ( buildSummary instanceof BuildFailure ) else if ( buildSummary instanceof BuildFailure )
{ {
buffer.append( "FAILURE [" ); buffer.append( "FAILURE [" );
buffer.append( getFormattedTime( buildSummary.getTime() ) ); String buildTimeDuration = formatDuration( buildSummary.getTime() );
buffer.append( chars( ' ', BUILD_TIME_DURATION_LENGTH - buildTimeDuration.length() ) );
buffer.append( buildTimeDuration );
buffer.append( "]" ); buffer.append( "]" );
} }
@ -208,15 +187,15 @@ private void logStats( MavenSession session )
{ {
logger.info( chars( '-', LINE_LENGTH ) ); logger.info( chars( '-', LINE_LENGTH ) );
Date finish = new Date(); long finish = System.currentTimeMillis();
long time = finish.getTime() - session.getRequest().getStartTime().getTime(); long time = finish - session.getRequest().getStartTime().getTime();
String wallClock = session.getRequest().getDegreeOfConcurrency() > 1 ? " (Wall Clock)" : ""; String wallClock = session.getRequest().getDegreeOfConcurrency() > 1 ? " (Wall Clock)" : "";
logger.info( "Total time: " + getFormattedTime( time ) + wallClock ); logger.info( "Total time: " + formatDuration( time ) + wallClock );
logger.info( "Finished at: " + finish ); logger.info( "Finished at: " + formatTimestamp( finish ) );
System.gc(); System.gc();

View File

@ -0,0 +1,40 @@
package org.apache.maven.cli;
/*
* Licensed to the Apache Software Foundation (ASF) under one
* or more contributor license agreements. See the NOTICE file
* distributed with this work for additional information
* regarding copyright ownership. The ASF licenses this file
* to you under the Apache License, Version 2.0 (the
* "License"); you may not use this file except in compliance
* with the License. You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing,
* software distributed under the License is distributed on an
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
* KIND, either express or implied. See the License for the
* specific language governing permissions and limitations
* under the License.
*/
import junit.framework.TestCase;
public class CLIReportingUtilsTest
extends TestCase
{
public void testFormatDuration()
{
assertEquals( "0.001 s", CLIReportingUtils.formatDuration( 1 ) );
assertEquals( "0.999 s", CLIReportingUtils.formatDuration( 1000 - 1 ) );
assertEquals( "1.000 s", CLIReportingUtils.formatDuration( 1000 ) );
assertEquals( "59.999 s", CLIReportingUtils.formatDuration( 60 * 1000 - 1 ) );
assertEquals( "01:00 min", CLIReportingUtils.formatDuration( 60 * 1000 ) );
assertEquals( "59:59 min", CLIReportingUtils.formatDuration( 60 * 60 * 1000 - 1 ) );
assertEquals( "01:00 h", CLIReportingUtils.formatDuration( 60 * 60 * 1000 ) );
assertEquals( "23:59 h", CLIReportingUtils.formatDuration( 24 * 60 * 60 * 1000 - 1 ) );
assertEquals( "1 d 00:00 h", CLIReportingUtils.formatDuration( 24 * 60 * 60 * 1000 ) );
}
}

View File

@ -1,61 +0,0 @@
package org.apache.maven.cli.event;
/*
* Licensed to the Apache Software Foundation (ASF) under one
* or more contributor license agreements. See the NOTICE file
* distributed with this work for additional information
* regarding copyright ownership. The ASF licenses this file
* to you under the Apache License, Version 2.0 (the
* "License"); you may not use this file except in compliance
* with the License. You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing,
* software distributed under the License is distributed on an
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
* KIND, either express or implied. See the License for the
* specific language governing permissions and limitations
* under the License.
*/
import java.lang.reflect.InvocationTargetException;
import java.lang.reflect.Method;
import junit.framework.TestCase;
public class ExecutionEventLoggerTest
extends TestCase
{
private static String getFormattedTime( long time )
throws SecurityException, NoSuchMethodException, IllegalArgumentException, IllegalAccessException,
InvocationTargetException
{
Method method = ExecutionEventLogger.class.getDeclaredMethod( "getFormattedTime", long.class );
boolean accessible = method.isAccessible();
try
{
method.setAccessible( true );
return (String) method.invoke( null, time );
}
finally
{
method.setAccessible( accessible );
}
}
public void testGetFormattedTime()
throws Exception
{
assertEquals( "0.001s", getFormattedTime( 1 ) );
assertEquals( "0.999s", getFormattedTime( 1000 - 1 ) );
assertEquals( "1.000s", getFormattedTime( 1000 ) );
assertEquals( "59.999s", getFormattedTime( 60 * 1000 - 1 ) );
assertEquals( "1:00.000s", getFormattedTime( 60 * 1000 ) );
assertEquals( "59:59.999s", getFormattedTime( 60 * 60 * 1000 - 1 ) );
assertEquals( "1:00:00.000s", getFormattedTime( 60 * 60 * 1000 ) );
assertEquals( "23:59:59.999s", getFormattedTime( 24 * 60 * 60 * 1000 - 1 ) );
assertEquals( "24:00:00.000s", getFormattedTime( 24 * 60 * 60 * 1000 ) );
}
}