Measure duration of steps, cases, and scenarios (Issue-#13)

TNG · Sep 7, 2014 · f0c8fd5 · f0c8fd5
1 parent 34cbe84
commit f0c8fd5
Show file tree

Hide file tree

Showing 31 changed files with 327 additions and 83 deletions.
diff --git a/jgiven-core/src/main/java/com/tngtech/jgiven/exception/JGivenInternalDefectException.java b/jgiven-core/src/main/java/com/tngtech/jgiven/exception/JGivenInternalDefectException.java
@@ -0,0 +1,14 @@
+package com.tngtech.jgiven.exception;
+
+/**
+ * If this exception is thrown there is most likely a bug in JGiven.
+ */
+public class JGivenInternalDefectException extends RuntimeException {
+    private static final long serialVersionUID = 1L;
+
+    public JGivenInternalDefectException( String msg ) {
+        super( msg
+                + ". This is most propably due to an internal defect in JGiven and was not your fault. "
+                + "Please consider writing a bug report on github.com/TNG/JGiven" );
+    }
+}
diff --git a/jgiven-core/src/main/java/com/tngtech/jgiven/impl/ScenarioExecutor.java b/jgiven-core/src/main/java/com/tngtech/jgiven/impl/ScenarioExecutor.java
@@ -94,7 +94,8 @@ static class StageState {
 
     class MethodHandler implements StepMethodHandler {
         @Override
-        public void handleMethod( Object stageInstance, Method paramMethod, Object[] arguments, InvocationMode mode ) throws Throwable {
+        public void handleMethod( Object stageInstance, Method paramMethod, Object[] arguments, InvocationMode mode )
+                throws Throwable {
             if( paramMethod.isSynthetic() ) {
                 return;
             }
@@ -122,6 +123,11 @@ public void handleThrowable( Throwable t ) throws Throwable {
             failed( t );
         }
 
+        @Override
+        public void handleMethodFinished( long durationInNanos ) {
+            listener.stepMethodFinished( durationInNanos );
+        }
+
     }
 
     @SuppressWarnings( "unchecked" )
@@ -289,6 +295,14 @@ public void finished() throws Throwable {
         state = FINISHED;
         methodInterceptor.enableMethodHandling( false );
 
+        try {
+            callFinishLifeCycleMethods();
+        } finally {
+            listener.scenarioFinished();
+        }
+    }
+
+    private void callFinishLifeCycleMethods() throws Throwable {
         Throwable firstThrownException = failedException;
         if( beforeStepsWereExecuted ) {
             if( currentStage != null ) {

diff --git a/jgiven-core/src/main/java/com/tngtech/jgiven/impl/intercept/NoOpScenarioListener.java b/jgiven-core/src/main/java/com/tngtech/jgiven/impl/intercept/NoOpScenarioListener.java
@@ -24,4 +24,10 @@ public void introWordAdded( String word ) {}
 
     @Override
     public void stepMethodFailed( Throwable t ) {}
+
+    @Override
+    public void stepMethodFinished( long durationInNanos ) {}
+
+    @Override
+    public void scenarioFinished() {}
 }
diff --git a/jgiven-core/src/main/java/com/tngtech/jgiven/impl/intercept/ScenarioListener.java b/jgiven-core/src/main/java/com/tngtech/jgiven/impl/intercept/ScenarioListener.java
@@ -19,4 +19,8 @@ public interface ScenarioListener {
 
     void stepMethodFailed( Throwable t );
 
+    void stepMethodFinished( long durationInNanos );
+
+    void scenarioFinished();
+
 }
diff --git a/jgiven-core/src/main/java/com/tngtech/jgiven/impl/intercept/StepMethodHandler.java b/jgiven-core/src/main/java/com/tngtech/jgiven/impl/intercept/StepMethodHandler.java
@@ -3,7 +3,10 @@
 import java.lang.reflect.Method;
 
 public interface StepMethodHandler {
-    void handleMethod( Object targetObject, Method paramMethod, Object[] arguments, InvocationMode mode ) throws Throwable;
+    void handleMethod( Object targetObject, Method paramMethod, Object[] arguments, InvocationMode mode )
+            throws Throwable;
 
     void handleThrowable( Throwable t ) throws Throwable;
+
+    void handleMethodFinished( long durationInNanos );
 }
diff --git a/jgiven-core/src/main/java/com/tngtech/jgiven/impl/intercept/StepMethodInterceptor.java b/jgiven-core/src/main/java/com/tngtech/jgiven/impl/intercept/StepMethodInterceptor.java
@@ -30,10 +30,11 @@ public StepMethodInterceptor( StepMethodHandler scenarioMethodHandler, AtomicInt
 
     @Override
     public Object intercept( Object receiver, Method method, Object[] parameters, MethodProxy methodProxy ) throws Throwable {
-
+        long started = System.nanoTime();
         InvocationMode mode = getInvocationMode( receiver, method );
 
-        if( methodHandlingEnabled && stackDepth.get() == 0 && !method.getDeclaringClass().equals( Object.class ) ) {
+        boolean handleMethod = methodHandlingEnabled && stackDepth.get() == 0 && !method.getDeclaringClass().equals( Object.class );
+        if( handleMethod ) {
             scenarioMethodHandler.handleMethod( receiver, method, parameters, mode );
         }
 
@@ -45,15 +46,18 @@ public Object intercept( Object receiver, Method method, Object[] parameters, Me
             stackDepth.incrementAndGet();
             return methodProxy.invokeSuper( receiver, parameters );
         } catch( Exception t ) {
-            return handleThrowable( receiver, method, t );
+            return handleThrowable( receiver, method, t, System.nanoTime() - started );
         } catch( AssertionError e ) {
-            return handleThrowable( receiver, method, e );
+            return handleThrowable( receiver, method, e, System.nanoTime() - started );
         } finally {
             stackDepth.decrementAndGet();
+            if( handleMethod ) {
+                scenarioMethodHandler.handleMethodFinished( System.nanoTime() - started );
+            }
         }
     }
 
-    private Object handleThrowable( Object receiver, Method method, Throwable t ) throws Throwable {
+    private Object handleThrowable( Object receiver, Method method, Throwable t, long durationInNanos ) throws Throwable {
         if( methodHandlingEnabled ) {
             scenarioMethodHandler.handleThrowable( t );
             return returnReceiverOrNull( receiver, method );

diff --git a/jgiven-core/src/main/java/com/tngtech/jgiven/impl/util/AssertionUtil.java b/jgiven-core/src/main/java/com/tngtech/jgiven/impl/util/AssertionUtil.java
@@ -0,0 +1,27 @@
+package com.tngtech.jgiven.impl.util;
+
+import com.tngtech.jgiven.exception.JGivenInternalDefectException;
+
+/**
+ * A collection of methods to assert certain conditions.
+ * If an asserted condition is false a {@link JGivenInternalDefectException} is thrown.
+ */
+public class AssertionUtil {
+
+    public static void assertNotNull( Object o ) {
+        assertNotNull( "Expected a value to not be null, but it apparently was null" );
+    }
+
+    public static void assertNotNull( Object o, String msg ) {
+        if( o == null ) {
+            throw new JGivenInternalDefectException( msg );
+        }
+    }
+
+    public static void assertTrue( boolean condition, String msg ) {
+        if( !condition ) {
+            throw new JGivenInternalDefectException( msg );
+        }
+    }
+
+}
diff --git a/jgiven-core/src/main/java/com/tngtech/jgiven/report/html/DataTableScenarioHtmlWriter.java b/jgiven-core/src/main/java/com/tngtech/jgiven/report/html/DataTableScenarioHtmlWriter.java
@@ -47,12 +47,14 @@ public void visitEnd( ScenarioCaseModel scenarioCase ) {
         }
         writer.print( "<td>" );
 
-        if( scenarioCase.success ) {
-            writer.println( "<div class='passed'>Passed</div>" );
-        } else {
+        writeStatusIcon( scenarioCase.success );
+
+        if( !scenarioCase.success ) {
             writer.println( "<div class='failed'>Failed: " + scenarioCase.errorMessage + "</div>" );
         }
 
+        writeDuration( scenarioCase.durationInNanos );
+
         writer.print( "</td>" );
 
         writer.println( "</tr>" );

diff --git a/jgiven-core/src/main/java/com/tngtech/jgiven/report/html/HtmlWriter.java b/jgiven-core/src/main/java/com/tngtech/jgiven/report/html/HtmlWriter.java
@@ -50,6 +50,10 @@ public void writeHtmlFooter() {
     private void writeJGivenFooter() {
         writer.print( "<div id='footer'>Generated by <a href='http://github.com/TNG/JGiven'>JGiven</a> - on " );
         writer.print( DateFormat.getDateTimeInstance().format( new Date() ) );
+        closeDiv();
+    }
+
+    private void closeDiv() {
         writer.println( "</div>" );
     }
 
@@ -60,7 +64,7 @@ public void write( ScenarioModel model ) {
     }
 
     public void write( ReportModel model, HtmlTocWriter htmlTocWriter ) {
-        writeHtmlHeader( model.className );
+        writeHtmlHeader( model.getClassName() );
         if( htmlTocWriter != null ) {
             htmlTocWriter.writeToc( writer );
         }
@@ -70,14 +74,14 @@ public void write( ReportModel model, HtmlTocWriter htmlTocWriter ) {
     }
 
     private void writeStatistics( ReportModel model ) {
-        if( !model.scenarios.isEmpty() ) {
+        if( !model.getScenarios().isEmpty() ) {
             ReportStatistics statistics = new StatisticsCalculator().getStatistics( model );
             writer.print( "<div class='statistics'>" );
             writer.print( statistics.numScenarios + " scenarios, "
                     + statistics.numCases + " cases, "
                     + statistics.numSteps + " steps, "
                     + statistics.numFailedCases + " failed cases" );
-            writer.println( "</div>" );
+            closeDiv();
         }
     }
 
@@ -139,10 +143,10 @@ void writeHeader( ReportModel reportModel ) {
         writer.println( "<div id='header'>" );
 
         String packageName = "";
-        String className = reportModel.className;
-        if( reportModel.className.contains( "." ) ) {
-            packageName = Files.getNameWithoutExtension( reportModel.className );
-            className = Files.getFileExtension( reportModel.className );
+        String className = reportModel.getClassName();
+        if( reportModel.getClassName().contains( "." ) ) {
+            packageName = Files.getNameWithoutExtension( reportModel.getClassName() );
+            className = Files.getFileExtension( reportModel.getClassName() );
         }
 
         if( !Strings.isNullOrEmpty( packageName ) ) {
@@ -151,11 +155,11 @@ void writeHeader( ReportModel reportModel ) {
 
         writer.println( format( "<h2>%s</h2>", className ) );
 
-        if( !Strings.isNullOrEmpty( reportModel.description ) ) {
-            writer.println( format( "<div class='description'>%s</div>", reportModel.description ) );
+        if( !Strings.isNullOrEmpty( reportModel.getDescription() ) ) {
+            writer.println( format( "<div class='description'>%s</div>", reportModel.getDescription() ) );
         }
 
-        writer.println( "</div>" );
+        closeDiv();
     }
 
     @Override

diff --git a/jgiven-core/src/main/java/com/tngtech/jgiven/report/html/ScenarioHtmlWriter.java b/jgiven-core/src/main/java/com/tngtech/jgiven/report/html/ScenarioHtmlWriter.java
@@ -1,8 +1,12 @@
 package com.tngtech.jgiven.report.html;
 
+import static com.tngtech.jgiven.report.model.ExecutionStatus.FAILED;
+import static com.tngtech.jgiven.report.model.ExecutionStatus.SUCCESS;
 import static java.lang.String.format;
 
 import java.io.PrintWriter;
+import java.util.Formatter;
+import java.util.Locale;
 
 import com.google.common.html.HtmlEscapers;
 import com.tngtech.jgiven.impl.util.WordUtil;
@@ -32,19 +36,34 @@ public void visit( ScenarioModel scenarioModel ) {
         writer.println( "<div class='scenario'>" );
 
         String id = scenarioModel.className + ":" + scenarioModel.description;
-        ExecutionStatus executionStatus = scenarioModel.getExecutionStatus();
+
+        writer.print( format( "<h3 onclick='toggle(\"%s\")'>", id ) );
+
+        writeStatusIcon( scenarioModel.getExecutionStatus() );
+
+        writer.print( " " + WordUtil.capitalize( scenarioModel.description ) );
+
+        writeDuration( scenarioModel.getDurationInNanos() );
+        writer.println( "</h3>" );
+
+        writeTagLine( scenarioModel );
+        writer.println( "<div class='scenario-body' id='" + id + "'>" );
+        writer.println( "<div class='scenario-content'>" );
+    }
+
+    public void writeStatusIcon( boolean success ) {
+        writeStatusIcon( success ? SUCCESS : FAILED );
+    }
+
+    public void writeStatusIcon( ExecutionStatus executionStatus ) {
         String iconClass = "";
         if( executionStatus == ExecutionStatus.FAILED ) {
             iconClass = "icon-cancel";
         } else if( executionStatus == ExecutionStatus.SUCCESS ) {
             iconClass = "icon-ok";
         }
 
-        writer.println( format( "<h3 onclick='toggle(\"%s\")'><i class='%s'></i> %s</h3>",
-            id, iconClass, WordUtil.capitalize( scenarioModel.description ) ) );
-        writeTagLine( scenarioModel );
-        writer.println( "<div class='scenario-body' id='" + id + "'>" );
-        writer.println( "<div class='scenario-content'>" );
+        writer.print( format( "<i class='%s'></i>", iconClass ) );
     }
 
     private void writeTagLine( ScenarioModel scenarioModel ) {
@@ -89,7 +108,9 @@ private String getCaseId() {
     void printCaseHeader( ScenarioCaseModel scenarioCase ) {
         writer.println( format( "<div class='case %sCase'>", scenarioCase.success ? "passed" : "failed" ) );
         if( !scenarioCase.arguments.isEmpty() ) {
-            writer.print( format( "<h4 onclick='toggle(\"%s\")'>Case %d: ", getCaseId(), scenarioCase.caseNr ) );
+            writer.print( format( "<h4 onclick='toggle(\"%s\")'>", getCaseId() ) );
+            writeStatusIcon( scenarioCase.success );
+            writer.print( format( " Case %d: ", scenarioCase.caseNr ) );
 
             for( int i = 0; i < scenarioCase.arguments.size(); i++ ) {
                 if( scenarioModel.parameterNames.size() > i ) {
@@ -102,15 +123,15 @@ void printCaseHeader( ScenarioCaseModel scenarioCase ) {
                     writer.print( ", " );
                 }
             }
+
+            writeDuration( scenarioCase.durationInNanos );
             writer.println( "</h4>" );
         }
     }
 
     @Override
     public void visitEnd( ScenarioCaseModel scenarioCase ) {
-        if( scenarioCase.success ) {
-            writer.println( "<div class='topRight passed'>Passed</div>" );
-        } else {
+        if( !scenarioCase.success ) {
             writer.println( "<div class='failed'>Failed: " + scenarioCase.errorMessage + "</div>" );
         }
         writer.println( "</ul>" );
@@ -137,14 +158,26 @@ public void visit( StepModel stepModel ) {
             }
             firstWord = false;
         }
+
         StepStatus status = stepModel.getStatus();
         if( status != StepStatus.PASSED ) {
             String lowerCase = status.toString().toLowerCase();
             writer.print( format( " <span class='badge %s'>%s</span>", WordUtil.camelCase( lowerCase ), lowerCase.replace( '_', ' ' ) ) );
         }
+
+        writeDuration( stepModel.getDurationInNanos() );
+
         writer.println( "</li>" );
     }
 
+    protected void writeDuration( long durationInNanos ) {
+        // TODO: provide a configuration value to configure the locale
+        double durationInMs = ( (double) durationInNanos ) / 1000000;
+        Formatter usFormatter = new Formatter( Locale.US );
+        writer.print( usFormatter.format( " <span class='duration'>(%.2f ms)</span>", durationInMs ) );
+        usFormatter.close();
+    }
+
     private void printArg( Word word ) {
         String value = word.getArgumentInfo().isCaseArg() ? formatCaseArgument( word ) : HtmlEscapers.htmlEscaper().escape( word.value );
         value = escapeToHtml( value );

diff --git a/jgiven-core/src/main/java/com/tngtech/jgiven/report/html/StaticHtmlReportGenerator.java b/jgiven-core/src/main/java/com/tngtech/jgiven/report/html/StaticHtmlReportGenerator.java
@@ -75,7 +75,7 @@ public void handleReportModel( ReportModel model, File file ) {
             modelFile.file = targetFile;
             models.add( modelFile );
 
-            for( ScenarioModel scenario : model.scenarios ) {
+            for( ScenarioModel scenario : model.getScenarios() ) {
                 for( Tag tag : scenario.tags ) {
                     addToMap( tag, scenario );
                 }
@@ -107,7 +107,7 @@ private void writeIndexFile( HtmlTocWriter tocWriter ) {
             htmlWriter.writeHtmlHeader( "Scenarios" );
 
             ReportModel reportModel = new ReportModel();
-            reportModel.className = ".Scenarios";
+            reportModel.setClassName( ".Scenarios" );
 
             tocWriter.writeToc( printWriter );
             htmlWriter.visit( reportModel );
@@ -135,12 +135,12 @@ private void writeTagFiles( HtmlTocWriter tocWriter ) {
     private void writeTagFile( Tag tag, List<ScenarioModel> value, HtmlTocWriter tocWriter ) {
         try {
             ReportModel reportModel = new ReportModel();
-            reportModel.className = tag.getName();
+            reportModel.setClassName( tag.getName() );
             if( tag.getValue() != null ) {
-                reportModel.className += "." + tag.getValueString();
+                reportModel.setClassName( reportModel.getClassName() + "." + tag.getValueString() );
             }
-            reportModel.scenarios = value;
-            reportModel.description = tag.getDescription();
+            reportModel.setScenarios( value );
+            reportModel.setDescription( tag.getDescription() );
 
             String fileName = HtmlTocWriter.tagToFilename( tag );
             File targetFile = new File( toDir, fileName );

diff --git a/jgiven-core/src/main/java/com/tngtech/jgiven/report/impl/CaseArgumentAnalyser.java b/jgiven-core/src/main/java/com/tngtech/jgiven/report/impl/CaseArgumentAnalyser.java
@@ -25,7 +25,7 @@ public class CaseArgumentAnalyser {
     private static final Logger log = LoggerFactory.getLogger( CaseArgumentAnalyser.class );
 
     public void analyze( ReportModel model ) {
-        for( ScenarioModel scenarioModel : model.scenarios ) {
+        for( ScenarioModel scenarioModel : model.getScenarios() ) {
             analyze( scenarioModel );
         }
     }

diff --git a/jgiven-core/src/main/java/com/tngtech/jgiven/report/impl/CommonReportHelper.java b/jgiven-core/src/main/java/com/tngtech/jgiven/report/impl/CommonReportHelper.java
@@ -33,7 +33,7 @@ public void finishReport( ReportModel model ) {
             if( !reportDir.exists() && !reportDir.mkdirs() ) {
                 log.error( "Could not create report directory " + reportDir );
             }
-            File reportFile = new File( reportDir, model.className + ".json" );
+            File reportFile = new File( reportDir, model.getClassName() + ".json" );
             log.info( "Writing scenario report to file " + reportFile.getAbsolutePath() );
             new ScenarioJsonWriter( model ).write( reportFile );
         }