diff --git a/CMakeLists.txt b/CMakeLists.txt index 05cc5c8e..37111da0 100644 --- a/CMakeLists.txt +++ b/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 diff --git a/include/catch.hpp b/include/catch.hpp index 0acd25da..00a49956 100644 --- a/include/catch.hpp +++ b/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" diff --git a/include/internal/catch_benchmark.cpp b/include/internal/catch_benchmark.cpp new file mode 100644 index 00000000..34af42a5 --- /dev/null +++ b/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 diff --git a/include/internal/catch_benchmark.h b/include/internal/catch_benchmark.h new file mode 100644 index 00000000..7b01507a --- /dev/null +++ b/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 +#include + +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 diff --git a/include/internal/catch_interfaces_capture.h b/include/internal/catch_interfaces_capture.h index 54cf0e4d..4d8766dd 100644 --- a/include/internal/catch_interfaces_capture.h +++ b/include/internal/catch_interfaces_capture.h @@ -11,6 +11,7 @@ #include #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; diff --git a/include/internal/catch_interfaces_reporter.h b/include/internal/catch_interfaces_reporter.h index 0aa2d241..def3684b 100644 --- a/include/internal/catch_interfaces_reporter.h +++ b/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; diff --git a/include/internal/catch_result_builder.cpp b/include/internal/catch_result_builder.cpp index 8cc624c7..8670136f 100644 --- a/include/internal/catch_result_builder.cpp +++ b/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) diff --git a/include/internal/catch_run_context.cpp b/include/internal/catch_run_context.cpp index bfde432b..b54742ff 100644 --- a/include/internal/catch_run_context.cpp +++ b/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); diff --git a/include/internal/catch_run_context.hpp b/include/internal/catch_run_context.hpp index 0619816b..ee923e88 100644 --- a/include/internal/catch_run_context.hpp +++ b/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; diff --git a/include/internal/catch_section.cpp b/include/internal/catch_section.cpp index 4f192446..c2572d5e 100644 --- a/include/internal/catch_section.cpp +++ b/include/internal/catch_section.cpp @@ -8,7 +8,6 @@ #include "catch_section.h" #include "catch_capture.hpp" -#include "catch_compiler_capabilities.h" namespace Catch { diff --git a/include/internal/catch_timer.cpp b/include/internal/catch_timer.cpp index ca09d7bc..9635ccea 100644 --- a/include/internal/catch_timer.cpp +++ b/include/internal/catch_timer.cpp @@ -16,21 +16,47 @@ namespace Catch { return std::chrono::duration_cast( std::chrono::high_resolution_clock::now().time_since_epoch() ).count(); } - void Timer::start() { - m_nanoseconds = getCurrentNanosecondsSinceEpoch(); - } - auto Timer::getElapsedNanoseconds() const -> unsigned int { - return static_cast(getCurrentNanosecondsSinceEpoch() - m_nanoseconds); - } - auto Timer::getElapsedMicroseconds() const -> unsigned int { - return static_cast(getElapsedNanoseconds()/1000); - } - auto Timer::getElapsedMilliseconds() const -> unsigned int { - return static_cast(getElapsedMicroseconds()/1000); - } - auto Timer::getElapsedSeconds() const -> double { - return getElapsedMicroseconds()/1000000.0; + auto estimateClockResolution() -> double { + uint64_t sum = 0; + static const uint64_t iterations = 1000000; + + for( size_t i = 0; i < iterations; ++i ) { + + uint64_t ticks; + uint64_t baseTicks = getCurrentNanosecondsSinceEpoch(); + do { + ticks = getCurrentNanosecondsSinceEpoch(); + } + while( ticks == baseTicks ); + + 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(getCurrentNanosecondsSinceEpoch() - m_nanoseconds); + } + auto Timer::getElapsedMicroseconds() const -> unsigned int { + return static_cast(getElapsedNanoseconds()/1000); + } + auto Timer::getElapsedMilliseconds() const -> unsigned int { + return static_cast(getElapsedMicroseconds()/1000); + } + auto Timer::getElapsedSeconds() const -> double { + return getElapsedMicroseconds()/1000000.0; + } + } // namespace Catch diff --git a/include/internal/catch_timer.h b/include/internal/catch_timer.h index 09182866..1871c24a 100644 --- a/include/internal/catch_timer.h +++ b/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; diff --git a/include/reporters/catch_reporter_bases.hpp b/include/reporters/catch_reporter_bases.hpp index 5e86e7c2..37cc4e00 100644 --- a/include/reporters/catch_reporter_bases.hpp +++ b/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 { diff --git a/include/reporters/catch_reporter_console.cpp b/include/reporters/catch_reporter_console.cpp index 3b08d353..d99415f7 100644 --- a/include/reporters/catch_reporter_console.cpp +++ b/include/reporters/catch_reporter_console.cpp @@ -34,9 +34,19 @@ namespace { namespace Catch { + template + 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 { 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; }