First draft of (experimental) benchmarking support

CMakeLists.txt

@@ -164,6 +164,7 @@ set(INTERNAL_HEADERS
         ${HEADER_DIR}/internal/catch_result_builder.h
         ${HEADER_DIR}/internal/catch_result_type.h
         ${HEADER_DIR}/internal/catch_run_context.hpp
+        ${HEADER_DIR}/internal/catch_benchmark.h
         ${HEADER_DIR}/internal/catch_section.h
         ${HEADER_DIR}/internal/catch_section_info.h
         ${HEADER_DIR}/internal/catch_startup_exception_registry.h
@@ -197,6 +198,7 @@ set(INTERNAL_HEADERS
 set(IMPL_SOURCES
         ${HEADER_DIR}/internal/catch_approx.cpp
         ${HEADER_DIR}/internal/catch_assertionresult.cpp
+        ${HEADER_DIR}/internal/catch_benchmark.cpp
         ${HEADER_DIR}/internal/catch_commandline.cpp
         ${HEADER_DIR}/internal/catch_common.cpp
         ${HEADER_DIR}/internal/catch_config.cpp

include/catch.hpp

@@ -33,6 +33,7 @@
 #include "internal/catch_test_registry.hpp"
 #include "internal/catch_capture.hpp"
 #include "internal/catch_section.h"
+#include "internal/catch_benchmark.h"
 #include "internal/catch_interfaces_exception.h"
 #include "internal/catch_approx.hpp"
 #include "internal/catch_matchers_string.h"

include/internal/catch_benchmark.cpp

@@ -0,0 +1,30 @@
+/*
+ *  Created by Phil on 04/07/2017.
+ *  Copyright 2017 Two Blue Cubes Ltd. All rights reserved.
+ *
+ *  Distributed under the Boost Software License, Version 1.0. (See accompanying
+ *  file LICENSE_1_0.txt or copy at http://www.boost.org/LICENSE_1_0.txt)
+ */
+
+#include "catch_benchmark.h"
+#include "catch_capture.hpp"
+
+namespace Catch {
+
+    void BenchmarkLooper::reportStart() const {
+        getResultCapture().benchmarkStarting( { m_name } );
+    }
+    auto BenchmarkLooper::needsMoreIterations() -> bool {
+        auto elapsed = m_timer.getElapsedNanoseconds();
+
+        // Exponentially increasing iterations until we're confident in our timer resolution
+        if( elapsed < m_resolution ) {
+            m_iterationsToRun *= 10;
+            return true;
+        }
+
+        getResultCapture().benchmarkEnded( { { m_name }, m_count, elapsed } );
+        return false;
+    }
+
+} // end namespace Catch

include/internal/catch_benchmark.h

@@ -0,0 +1,55 @@
+/*
+ *  Created by Phil on 04/07/2017.
+ *  Copyright 2017 Two Blue Cubes Ltd. All rights reserved.
+ *
+ *  Distributed under the Boost Software License, Version 1.0. (See accompanying
+ *  file LICENSE_1_0.txt or copy at http://www.boost.org/LICENSE_1_0.txt)
+ */
+#ifndef TWOBLUECUBES_CATCH_BENCHMARK_H_INCLUDED
+#define TWOBLUECUBES_CATCH_BENCHMARK_H_INCLUDED
+
+#include "catch_stringref.h"
+#include "catch_timer.h"
+
+#include <cstdint>
+#include <string>
+
+namespace Catch {
+
+    class BenchmarkLooper {
+
+        std::string m_name;
+        size_t m_count = 0;
+        size_t m_iterationsToRun = 1;
+        uint64_t m_resolution;
+        Timer m_timer;
+    public:
+        // Keep most of this inline as it's on the code path that is being timed
+        BenchmarkLooper( StringRef name )
+        :   m_name( name.c_str() ),
+            m_resolution( getEstimatedClockResolution()*10 )
+        {
+            reportStart();
+            m_timer.start();
+        }
+
+        explicit operator bool() {
+            if( m_count < m_iterationsToRun )
+                return true;
+            return needsMoreIterations();
+        }
+
+        void increment() {
+            ++m_count;
+        }
+
+        void reportStart() const;
+        auto needsMoreIterations() -> bool;
+    };
+
+} // end namespace Catch
+
+#define BENCHMARK( name ) \
+    for( Catch::BenchmarkLooper looper( name ); looper; looper.increment() )
+
+#endif // TWOBLUECUBES_CATCH_BENCHMARK_H_INCLUDED

include/internal/catch_interfaces_capture.h

@@ -11,6 +11,7 @@
 #include <string>
 #include "catch_result_type.h"
 #include "catch_common.h"
+#include "catch_interfaces_reporter.h"
 
 namespace Catch {
 
@@ -27,11 +28,16 @@ namespace Catch {
 
         virtual ~IResultCapture();
 
+        virtual void assertionStarting( AssertionInfo const& info ) = 0;
         virtual void assertionEnded( AssertionResult const& result ) = 0;
         virtual bool sectionStarted(    SectionInfo const& sectionInfo,
                                         Counts& assertions ) = 0;
         virtual void sectionEnded( SectionEndInfo const& endInfo ) = 0;
         virtual void sectionEndedEarly( SectionEndInfo const& endInfo ) = 0;
+
+        virtual void benchmarkStarting( BenchmarkInfo const& info ) = 0;
+        virtual void benchmarkEnded( BenchmarkStats const& stats ) = 0;
+
         virtual void pushScopedMessage( MessageInfo const& message ) = 0;
         virtual void popScopedMessage( MessageInfo const& message ) = 0;
 

include/internal/catch_interfaces_reporter.h

@@ -158,6 +158,14 @@ namespace Catch {
         bool aborting;
     };
 
+    struct BenchmarkInfo {
+        std::string name;
+    };
+    struct BenchmarkStats {
+        BenchmarkInfo info;
+        size_t iterations;
+        uint64_t elapsedTimeInNanoseconds;
+    };
     class MultipleReporters;
 
     struct IStreamingReporter {
@@ -177,11 +185,17 @@ namespace Catch {
         virtual void testCaseStarting( TestCaseInfo const& testInfo ) = 0;
         virtual void sectionStarting( SectionInfo const& sectionInfo ) = 0;
 
+        // *** experimental ***
+        virtual void benchmarkStarting( BenchmarkInfo const& ) {}
+
         virtual void assertionStarting( AssertionInfo const& assertionInfo ) = 0;
 
         // The return value indicates if the messages buffer should be cleared:
         virtual bool assertionEnded( AssertionStats const& assertionStats ) = 0;
 
+        // *** experimental ***
+        virtual void benchmarkEnded( BenchmarkStats const& ) {}
+
         virtual void sectionEnded( SectionStats const& sectionStats ) = 0;
         virtual void testCaseEnded( TestCaseStats const& testCaseStats ) = 0;
         virtual void testGroupEnded( TestGroupStats const& testGroupStats ) = 0;

include/internal/catch_result_builder.cpp

@@ -34,7 +34,9 @@ namespace Catch {
                                     char const* capturedExpression,
                                     ResultDisposition::Flags resultDisposition )
     :   m_assertionInfo( macroName, lineInfo, capturedExpression, resultDisposition)
-    {}
+    {
+        getCurrentContext().getResultCapture()->assertionStarting( m_assertionInfo );
+    }
 
     ResultBuilder::~ResultBuilder() {
 #if defined(CATCH_CONFIG_FAST_COMPILE)

include/internal/catch_run_context.cpp

@@ -90,6 +90,9 @@ namespace Catch {
         return *m_reporter;
     }
 
+    void RunContext::assertionStarting(AssertionInfo const& info) {
+        m_reporter->assertionStarting( info );
+    }
     void RunContext::assertionEnded(AssertionResult const & result) {
         if (result.getResultType() == ResultWas::Ok) {
             m_totals.assertions.passed++;
@@ -155,6 +158,12 @@ namespace Catch {
 
         m_unfinishedSections.push_back(endInfo);
     }
+    void RunContext::benchmarkStarting( BenchmarkInfo const& info ) {
+        m_reporter->benchmarkStarting( info );
+    }
+    void RunContext::benchmarkEnded( BenchmarkStats const& stats ) {
+        m_reporter->benchmarkEnded( stats );
+    }
 
     void RunContext::pushScopedMessage(MessageInfo const & message) {
         m_messages.push_back(message);

include/internal/catch_run_context.hpp

@@ -63,17 +63,19 @@ namespace Catch {
     private: // IResultCapture
 
 
+        void assertionStarting(AssertionInfo const& info) override;
         void assertionEnded(AssertionResult const& result) override;
 
         bool sectionStarted( SectionInfo const& sectionInfo, Counts& assertions ) override;
         bool testForMissingAssertions(Counts& assertions);
 
         void sectionEnded(SectionEndInfo const& endInfo) override;
-
         void sectionEndedEarly(SectionEndInfo const& endInfo) override;
 
-        void pushScopedMessage(MessageInfo const& message) override;
+        void benchmarkStarting( BenchmarkInfo const& info ) override;
+        void benchmarkEnded( BenchmarkStats const& stats ) override;
 
+        void pushScopedMessage(MessageInfo const& message) override;
         void popScopedMessage(MessageInfo const& message) override;
 
         std::string getCurrentTestName() const override;

include/internal/catch_section.cpp

@@ -8,7 +8,6 @@
 
 #include "catch_section.h"
 #include "catch_capture.hpp"
-#include "catch_compiler_capabilities.h"
 
 namespace Catch {
 

include/internal/catch_timer.cpp

@@ -16,21 +16,47 @@ namespace Catch {
         return std::chrono::duration_cast<std::chrono::nanoseconds>( std::chrono::high_resolution_clock::now().time_since_epoch() ).count();
     }
 
-        void Timer::start() {
+    auto estimateClockResolution() -> double {
-           m_nanoseconds = getCurrentNanosecondsSinceEpoch();
+        uint64_t sum = 0;
-        }
+        static const uint64_t iterations = 1000000;
-        auto Timer::getElapsedNanoseconds() const -> unsigned int {
+
-            return static_cast<unsigned int>(getCurrentNanosecondsSinceEpoch() - m_nanoseconds);
+        for( size_t i = 0; i < iterations; ++i ) {
-        }
+
-        auto Timer::getElapsedMicroseconds() const -> unsigned int {
+            uint64_t ticks;
-            return static_cast<unsigned int>(getElapsedNanoseconds()/1000);
+            uint64_t baseTicks = getCurrentNanosecondsSinceEpoch();
-        }
+            do {
-        auto Timer::getElapsedMilliseconds() const -> unsigned int {
+                ticks = getCurrentNanosecondsSinceEpoch();
-            return static_cast<unsigned int>(getElapsedMicroseconds()/1000);
+            }
-        }
+            while( ticks == baseTicks );
-        auto Timer::getElapsedSeconds() const -> double {
+
-            return getElapsedMicroseconds()/1000000.0;
+            auto delta = ticks - baseTicks;
+            sum += delta;
         }
 
+        // We're just taking the mean, here. To do better we could take the std. dev and exclude outliers
+        // - and potentially do more iterations if there's a high variance.
+        return sum/(double)iterations;
+    }
+    auto getEstimatedClockResolution() -> double {
+        static auto s_resolution = estimateClockResolution();
+        return s_resolution;
+    }
+
+    void Timer::start() {
+       m_nanoseconds = getCurrentNanosecondsSinceEpoch();
+    }
+    auto Timer::getElapsedNanoseconds() const -> unsigned int {
+        return static_cast<unsigned int>(getCurrentNanosecondsSinceEpoch() - m_nanoseconds);
+    }
+    auto Timer::getElapsedMicroseconds() const -> unsigned int {
+        return static_cast<unsigned int>(getElapsedNanoseconds()/1000);
+    }
+    auto Timer::getElapsedMilliseconds() const -> unsigned int {
+        return static_cast<unsigned int>(getElapsedMicroseconds()/1000);
+    }
+    auto Timer::getElapsedSeconds() const -> double {
+        return getElapsedMicroseconds()/1000000.0;
+    }
+
 
 } // namespace Catch

include/internal/catch_timer.h

@@ -13,6 +13,7 @@
 namespace Catch {
 
     auto getCurrentNanosecondsSinceEpoch() -> uint64_t;
+    auto getEstimatedClockResolution() -> double;
 
     class Timer {
         uint64_t m_nanoseconds = 0;

include/reporters/catch_reporter_bases.hpp

@@ -259,6 +259,16 @@ namespace Catch {
         }
         return line;
     }
+    inline char const* getBoxCharsAcross() {
+        static char line[CATCH_CONFIG_CONSOLE_WIDTH] = {0};
+        if( !*line ) {
+            std::memset( line, '-', CATCH_CONFIG_CONSOLE_WIDTH-1 );
+            line[CATCH_CONFIG_CONSOLE_WIDTH-1] = 0;
+            line[0] = '+';
+            line[CATCH_CONFIG_CONSOLE_WIDTH-2] = '+';
+        }
+        return line;
+    }
 
 
     struct TestEventListenerBase : StreamingReporterBase<TestEventListenerBase> {

include/reporters/catch_reporter_console.cpp

@@ -34,9 +34,19 @@ namespace {
 
 namespace Catch {
 
+    template<typename T>
+    auto leftPad( const T& value, int width ) -> std::string {
+        // !TBD: could do with being optimised
+        std::ostringstream oss;
+        oss << value;
+        std::string converted = oss.str();
+        return std::string( width - converted.size(), ' ' ) + converted;
+    }
+
+
     struct ConsoleReporter : StreamingReporterBase<ConsoleReporter> {
         using StreamingReporterBase::StreamingReporterBase;
-
+        bool m_benchmarkTableOpen = false;
 
         ~ConsoleReporter() override;
         static std::string getDescription() {
@@ -47,7 +57,9 @@ namespace Catch {
             stream << "No test cases matched '" << spec << '\'' << std::endl;
         }
 
-        void assertionStarting( AssertionInfo const& ) override {}
+        void assertionStarting( AssertionInfo const& ) override {
+            closeBenchmarkTable();
+        }
 
         bool assertionEnded( AssertionStats const& _assertionStats ) override {
             AssertionResult const& result = _assertionStats.assertionResult;
@@ -71,6 +83,7 @@ namespace Catch {
             StreamingReporterBase::sectionStarting( _sectionInfo );
         }
         void sectionEnded( SectionStats const& _sectionStats ) override {
+            closeBenchmarkTable();
             if( _sectionStats.missingAssertions ) {
                 lazyPrint();
                 Colour colour( Colour::ResultError );
@@ -89,7 +102,44 @@ namespace Catch {
             StreamingReporterBase::sectionEnded( _sectionStats );
         }
 
+        void benchmarkStarting( BenchmarkInfo const& info ) override {
+            lazyPrint();
+            auto nameColWidth = CATCH_CONFIG_CONSOLE_WIDTH-40;
+            auto nameCol = Column( info.name ).width( nameColWidth );
+            if( !m_benchmarkTableOpen ) {
+                stream
+                    << getBoxCharsAcross() << "\n"
+                    << "| benchmark name" << std::string( nameColWidth-14, ' ' ) << " |  it'ns | elapsed ns |    average |\n"
+                    << getBoxCharsAcross() << "\n";
+                m_benchmarkTableOpen = true;
+            }
+            bool firstLine = true;
+            for( auto line : nameCol ) {
+                if( !firstLine )
+                    stream << "        |            |            |" << "\n";
+                else
+                    firstLine = false;
+
+                stream << "| " << line << std::string( nameColWidth-line.size(), ' ' ) << " |";
+            }
+        }
+        void benchmarkEnded( BenchmarkStats const& stats ) override {
+            // !TBD: report average times in natural units?
+            stream
+                << " " << leftPad( stats.iterations, 6 )
+                << " | " << leftPad( stats.elapsedTimeInNanoseconds, 10 )
+                << " | " << leftPad( stats.elapsedTimeInNanoseconds/stats.iterations, 7 )
+                << " ns |" << std::endl;
+        }
+        void closeBenchmarkTable() {
+            if( m_benchmarkTableOpen ) {
+                stream << getBoxCharsAcross() << "\n" << std::endl;
+                m_benchmarkTableOpen = false;
+            }
+        }
+
         void testCaseEnded( TestCaseStats const& _testCaseStats ) override {
+            closeBenchmarkTable();
             StreamingReporterBase::testCaseEnded( _testCaseStats );
             m_headerPrinted = false;
         }