From 820b9b94a17e2f307d871f350595c523cd17b1f2 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Vladim=C3=ADr=20Vondru=C5=A1?= Date: Mon, 27 Apr 2020 23:40:24 +0200 Subject: [PATCH] DebugTools: initial implementation of a new frame profiler. Replaces the old & extremely useless Profiler. Doesn't have everything I want yet (missing stddev and fancier GPU queries), that'll come later. --- doc/changelog.dox | 1 + doc/snippets/CMakeLists.txt | 6 + doc/snippets/MagnumDebugTools-gl.cpp | 40 + doc/snippets/MagnumDebugTools.cpp | 63 +- doc/snippets/debugtools-frameprofiler.ansi | 6 + doc/snippets/debugtools-frameprofiler.cpp | 112 ++ src/Magnum/DebugTools/CMakeLists.txt | 4 +- src/Magnum/DebugTools/FrameProfiler.cpp | 665 +++++++++++ src/Magnum/DebugTools/FrameProfiler.h | 704 +++++++++++ src/Magnum/DebugTools/Test/CMakeLists.txt | 8 + .../DebugTools/Test/FrameProfilerGLTest.cpp | 242 ++++ .../DebugTools/Test/FrameProfilerTest.cpp | 1057 +++++++++++++++++ 12 files changed, 2905 insertions(+), 3 deletions(-) create mode 100644 doc/snippets/debugtools-frameprofiler.ansi create mode 100644 doc/snippets/debugtools-frameprofiler.cpp create mode 100644 src/Magnum/DebugTools/FrameProfiler.cpp create mode 100644 src/Magnum/DebugTools/FrameProfiler.h create mode 100644 src/Magnum/DebugTools/Test/FrameProfilerGLTest.cpp create mode 100644 src/Magnum/DebugTools/Test/FrameProfilerTest.cpp diff --git a/doc/changelog.dox b/doc/changelog.dox index 192d5bf67..865853496 100644 --- a/doc/changelog.dox +++ b/doc/changelog.dox @@ -72,6 +72,7 @@ See also: - New @ref DebugTools::ColorMap namespace containing a few presets for gradient visualization +- New @ref DebugTools::FrameProfiler utility for CPU and GPU profiling @subsubsection changelog-latest-new-gl GL library diff --git a/doc/snippets/CMakeLists.txt b/doc/snippets/CMakeLists.txt index b38d4c5da..aac0b6ca9 100644 --- a/doc/snippets/CMakeLists.txt +++ b/doc/snippets/CMakeLists.txt @@ -119,6 +119,12 @@ if(WITH_DEBUGTOOLS) target_link_libraries(snippets-MagnumDebugTools PRIVATE MagnumDebugTools) set_target_properties(snippets-MagnumDebugTools PROPERTIES FOLDER "Magnum/doc/snippets") + if(BUILD_GL_TESTS AND NOT MAGNUM_TARGET_GLES) + add_executable(debugtools-frameprofiler debugtools-frameprofiler.cpp) + target_link_libraries(debugtools-frameprofiler PRIVATE + MagnumDebugTools MagnumOpenGLTester) + endif() + # TODO: causes spurious linker errors on Travis iOS build, so I'm disabling it if(NOT CORRADE_TARGET_IOS) set(SNIPPETS_DIR ${CMAKE_CURRENT_SOURCE_DIR}) diff --git a/doc/snippets/MagnumDebugTools-gl.cpp b/doc/snippets/MagnumDebugTools-gl.cpp index dce0d4d4e..a4544b275 100644 --- a/doc/snippets/MagnumDebugTools-gl.cpp +++ b/doc/snippets/MagnumDebugTools-gl.cpp @@ -32,6 +32,7 @@ #include "Magnum/DebugTools/ColorMap.h" #include "Magnum/DebugTools/CompareImage.h" #include "Magnum/DebugTools/ForceRenderer.h" +#include "Magnum/DebugTools/FrameProfiler.h" #include "Magnum/DebugTools/ResourceManager.h" #include "Magnum/DebugTools/ObjectRenderer.h" #include "Magnum/DebugTools/TextureImage.h" @@ -44,6 +45,9 @@ #include "Magnum/SceneGraph/Object.h" #include "Magnum/SceneGraph/MatrixTransformation3D.h" +#ifndef MAGNUM_TARGET_GLES +#include "Magnum/GL/SampleQuery.h" +#endif #ifndef MAGNUM_TARGET_GLES2 #include "Magnum/GL/BufferImage.h" #endif @@ -103,6 +107,33 @@ new DebugTools::ForceRenderer3D(manager, *object, {0.3f, 1.5f, -0.7f}, force, /* [ForceRenderer] */ } +#ifndef MAGNUM_TARGET_GLES +{ +/* [FrameProfiler-setup-delayed] */ +GL::SampleQuery queries[3]{ + GL::SampleQuery{GL::SampleQuery::Target::SamplesPassed}, + GL::SampleQuery{GL::SampleQuery::Target::SamplesPassed}, + GL::SampleQuery{GL::SampleQuery::Target::SamplesPassed} +}; +DebugTools::FrameProfiler profiler{{ + DebugTools::FrameProfiler::Measurement{"Samples", + DebugTools::FrameProfiler::Units::Count, + UnsignedInt(Containers::arraySize(queries)), + [](void* state, UnsignedInt current) { + static_cast(state)[current].begin(); + }, + [](void* state, UnsignedInt current) { + static_cast(state)[current].end(); + }, + [](void* state, UnsignedInt previous, UnsignedInt) { + return static_cast(state)[previous] + .result(); + }, queries} +}, 50}; +/* [FrameProfiler-setup-delayed] */ +} +#endif + { SceneGraph::Object* object{}; /* [ObjectRenderer] */ @@ -116,6 +147,15 @@ manager.set("my", DebugTools::ObjectRendererOptions{}.setSize(0.3f)); new DebugTools::ObjectRenderer3D{manager, *object, "my", &debugDrawables}; /* [ObjectRenderer] */ } + +{ +/* [GLFrameProfiler-usage] */ +DebugTools::GLFrameProfiler profiler{ + DebugTools::GLFrameProfiler::Value::FrameTime| + DebugTools::GLFrameProfiler::Value::GpuDuration, 50}; +/* [GLFrameProfiler-usage] */ +} + { GL::Texture2D texture; Range2Di rect; diff --git a/doc/snippets/MagnumDebugTools.cpp b/doc/snippets/MagnumDebugTools.cpp index a6a5ae09e..027fcbb9a 100644 --- a/doc/snippets/MagnumDebugTools.cpp +++ b/doc/snippets/MagnumDebugTools.cpp @@ -23,6 +23,7 @@ DEALINGS IN THE SOFTWARE. */ +#include #include #include #include @@ -31,6 +32,7 @@ #include "Magnum/ImageView.h" #include "Magnum/PixelFormat.h" #include "Magnum/DebugTools/CompareImage.h" +#include "Magnum/DebugTools/FrameProfiler.h" #include "Magnum/Math/Color.h" #include "Magnum/Trade/AbstractImporter.h" @@ -101,5 +103,62 @@ CORRADE_COMPARE_WITH(actual.pixels().flipped<0>(), expected, } }; -/* To prevent macOS ranlib complaining that there are no symbols */ -int main() {} +struct MyApp { + void drawEvent(); + void drawEventAgain(); + void swapBuffers(); + void redraw(); + + DebugTools::FrameProfiler _profiler; +}; + +/* [FrameProfiler-usage] */ +void MyApp::drawEvent() { + _profiler.beginFrame(); + + // actual drawing code … + + _profiler.endFrame(); + + // possibly other code (such as UI) you don't want to have included in the + // measurements … + + swapBuffers(); + redraw(); +} +/* [FrameProfiler-usage] */ + +void MyApp::drawEventAgain() { +/* [FrameProfiler-usage-console] */ + _profiler.endFrame(); + _profiler.printStatistics(10); + + swapBuffers(); + if(_profiler.isEnabled()) redraw(); +} +/* [FrameProfiler-usage-console] */ + +int main() { +{ +/* [FrameProfiler-setup-immediate] */ +using std::chrono::high_resolution_clock; + +high_resolution_clock::time_point frameBeginTime; +DebugTools::FrameProfiler profiler{{ + DebugTools::FrameProfiler::Measurement{"CPU time", + DebugTools::FrameProfiler::Units::Nanoseconds, + [](void* state) { + *static_cast(state) + = high_resolution_clock::now(); + }, + [](void* state) { + return UnsignedLong( + std::chrono::duration_cast( + *static_cast(state) + - high_resolution_clock::now()).count()); + }, &frameBeginTime} +}, 50}; +/* [FrameProfiler-setup-immediate] */ +} + +} diff --git a/doc/snippets/debugtools-frameprofiler.ansi b/doc/snippets/debugtools-frameprofiler.ansi new file mode 100644 index 000000000..ebd265f26 --- /dev/null +++ b/doc/snippets/debugtools-frameprofiler.ansi @@ -0,0 +1,6 @@ +Last 50 frames: +  Frame time: 16.65 ms +  CPU duration: 14.72 ms +  GPU duration: 10.89 ms +  Vertex fetch ratio: 0.24 +  Primitives clipped: 59.67 % diff --git a/doc/snippets/debugtools-frameprofiler.cpp b/doc/snippets/debugtools-frameprofiler.cpp new file mode 100644 index 000000000..4f4ffb81b --- /dev/null +++ b/doc/snippets/debugtools-frameprofiler.cpp @@ -0,0 +1,112 @@ +/* + This file is part of Magnum. + + Copyright © 2010, 2011, 2012, 2013, 2014, 2015, 2016, 2017, 2018, 2019 + Vladimír Vondruš + + Permission is hereby granted, free of charge, to any person obtaining a + copy of this software and associated documentation files (the "Software"), + to deal in the Software without restriction, including without limitation + the rights to use, copy, modify, merge, publish, distribute, sublicense, + and/or sell copies of the Software, and to permit persons to whom the + Software is furnished to do so, subject to the following conditions: + + The above copyright notice and this permission notice shall be included + in all copies or substantial portions of the Software. + + THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR + IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, + FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL + THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER + LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING + FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER + DEALINGS IN THE SOFTWARE. +*/ + +#include +#include + +#include "Magnum/DebugTools/FrameProfiler.h" + +/* Hacking around the fugly windowlessapp setup by including OpenGLTester */ +#include "Magnum/GL/OpenGLTester.h" + +using namespace Magnum; + +class FrameProfiler: public Platform::WindowlessApplication { + public: + explicit FrameProfiler(const Arguments& arguments); + + int exec() override { return 0; } +}; + +FrameProfiler::FrameProfiler(const Arguments& arguments): Platform::WindowlessApplication{arguments} { + /* Enable everything in the GL profiler and then introspect it to fake + its output 1:1 */ + DebugTools::GLFrameProfiler glProfiler{ + DebugTools::GLFrameProfiler::Value::FrameTime| + DebugTools::GLFrameProfiler::Value::CpuDuration| + DebugTools::GLFrameProfiler::Value::GpuDuration| + DebugTools::GLFrameProfiler::Value::VertexFetchRatio| + DebugTools::GLFrameProfiler::Value::PrimitiveClipRatio + , 50}; + + DebugTools::FrameProfiler profiler{{ + DebugTools::FrameProfiler::Measurement{ + glProfiler.measurementName(0), + glProfiler.measurementUnits(0), + glProfiler.measurementDelay(2), + [](void*, UnsignedInt) {}, + [](void*, UnsignedInt) {}, + [](void*, UnsignedInt, UnsignedInt) { + return UnsignedLong{16651567}; + }, nullptr}, + DebugTools::FrameProfiler::Measurement{ + glProfiler.measurementName(1), + glProfiler.measurementUnits(1), + glProfiler.measurementDelay(2), + [](void*, UnsignedInt) {}, + [](void*, UnsignedInt) {}, + [](void*, UnsignedInt, UnsignedInt) { + return UnsignedLong{14720000}; + }, nullptr}, + DebugTools::FrameProfiler::Measurement{ + glProfiler.measurementName(2), + glProfiler.measurementUnits(2), + glProfiler.measurementDelay(2), + [](void*, UnsignedInt) {}, + [](void*, UnsignedInt) {}, + [](void*, UnsignedInt, UnsignedInt) { + return UnsignedLong{10890000}; + }, nullptr}, + DebugTools::FrameProfiler::Measurement{ + glProfiler.measurementName(3), + glProfiler.measurementUnits(3), + glProfiler.measurementDelay(3), + [](void*, UnsignedInt) {}, + [](void*, UnsignedInt) {}, + [](void*, UnsignedInt, UnsignedInt) { + return UnsignedLong{240}; + }, nullptr}, + DebugTools::FrameProfiler::Measurement{ + glProfiler.measurementName(4), + glProfiler.measurementUnits(4), + glProfiler.measurementDelay(4), + [](void*, UnsignedInt) {}, + [](void*, UnsignedInt) {}, + [](void*, UnsignedInt, UnsignedInt) { + return UnsignedLong{59670}; + }, nullptr}, + }, 50}; + + for(std::size_t i = 0; i != 100; ++i) { + profiler.beginFrame(); + profiler.endFrame(); + } + + std::ostringstream out; /* we don't want a TTY */ + profiler.printStatistics(Debug{&out}, 1); + Debug{Debug::Flag::NoNewlineAtTheEnd} << out.str(); +} + +MAGNUM_WINDOWLESSAPPLICATION_MAIN(FrameProfiler) diff --git a/src/Magnum/DebugTools/CMakeLists.txt b/src/Magnum/DebugTools/CMakeLists.txt index 767d5d0af..b831a583d 100644 --- a/src/Magnum/DebugTools/CMakeLists.txt +++ b/src/Magnum/DebugTools/CMakeLists.txt @@ -27,11 +27,13 @@ set(MagnumDebugTools_SRCS ColorMap.cpp Profiler.cpp) -set(MagnumDebugTools_GracefulAssert_SRCS ) +set(MagnumDebugTools_GracefulAssert_SRCS + FrameProfiler.cpp) set(MagnumDebugTools_HEADERS ColorMap.h DebugTools.h + FrameProfiler.h Profiler.h visibility.h) diff --git a/src/Magnum/DebugTools/FrameProfiler.cpp b/src/Magnum/DebugTools/FrameProfiler.cpp new file mode 100644 index 000000000..48077e881 --- /dev/null +++ b/src/Magnum/DebugTools/FrameProfiler.cpp @@ -0,0 +1,665 @@ +/* + This file is part of Magnum. + + Copyright © 2010, 2011, 2012, 2013, 2014, 2015, 2016, 2017, 2018, 2019 + Vladimír Vondruš + + Permission is hereby granted, free of charge, to any person obtaining a + copy of this software and associated documentation files (the "Software"), + to deal in the Software without restriction, including without limitation + the rights to use, copy, modify, merge, publish, distribute, sublicense, + and/or sell copies of the Software, and to permit persons to whom the + Software is furnished to do so, subject to the following conditions: + + The above copyright notice and this permission notice shall be included + in all copies or substantial portions of the Software. + + THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR + IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, + FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL + THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER + LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING + FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER + DEALINGS IN THE SOFTWARE. +*/ + +#include "FrameProfiler.h" + +#include +#include +#include +#include +#include +#include + +#include "Magnum/Math/Functions.h" +#ifdef MAGNUM_TARGET_GL +#include "Magnum/GL/TimeQuery.h" +#ifndef MAGNUM_TARGET_GLES +#include "Magnum/GL/PipelineStatisticsQuery.h" +#endif +#endif + +namespace Magnum { namespace DebugTools { + +FrameProfiler::Measurement::Measurement(const std::string& name, const Units units, void(*const begin)(void*), UnsignedLong(*const end)(void*), void* const state): _name{name}, _end{nullptr}, _state{state}, _units{units}, _delay{0} { + _begin.immediate = begin; + _query.immediate = end; +} + +FrameProfiler::Measurement::Measurement(const std::string& name, const Units units, const UnsignedInt delay, void(*const begin)(void*, UnsignedInt), void(*const end)(void*, UnsignedInt), UnsignedLong(*const query)(void*, UnsignedInt, UnsignedInt), void* const state): _name{name}, _state{state}, _units{units}, _delay{delay} { + CORRADE_ASSERT(delay >= 1, "DebugTools::FrameProfiler::Measurement: delay can't be zero", ); + _begin.delayed = begin; + _end = end; + _query.delayed = query; +} + +FrameProfiler::FrameProfiler() noexcept = default; + +FrameProfiler::FrameProfiler(Containers::Array&& measurements, std::size_t maxFrameCount) noexcept { + setup(std::move(measurements), maxFrameCount); +} + +FrameProfiler::FrameProfiler(const std::initializer_list measurements, const std::size_t maxFrameCount): FrameProfiler{Containers::array(measurements), maxFrameCount} {} + +FrameProfiler::FrameProfiler(FrameProfiler&& other) noexcept: + _enabled{other._enabled}, + #ifndef CORRADE_NO_ASSERT + _beginFrameCalled{other._beginFrameCalled}, + #endif + _currentData{other._currentData}, + _maxFrameCount{other._maxFrameCount}, + _measuredFrameCount{other._measuredFrameCount}, + _measurements{std::move(other._measurements)}, + _data{std::move(other._data)} +{ + /* For all state pointers that point to &other patch them to point to this + instead, to account for 90% of use cases of derived classes */ + for(Measurement& measurement: _measurements) + if(measurement._state == &other) measurement._state = this; +} + +FrameProfiler& FrameProfiler::operator=(FrameProfiler&& other) noexcept { + using std::swap; + swap(_enabled, other._enabled); + #ifndef CORRADE_NO_ASSERT + swap(_beginFrameCalled, other._beginFrameCalled); + #endif + swap(_currentData, other._currentData); + swap(_maxFrameCount, other._maxFrameCount); + swap(_measuredFrameCount, other._measuredFrameCount); + swap(_measurements, other._measurements); + swap(_data, other._data); + + /* For all state pointers that point to &other patch them to point to this + instead, to account for 90% of use cases of derived classes */ + for(Measurement& measurement: _measurements) + if(measurement._state == &other) measurement._state = this; + + /* And the same the other way to avoid the other instance accidentally + affecting out measurements */ + for(Measurement& measurement: other._measurements) + if(measurement._state == this) measurement._state = &other; + + return *this; +} + +void FrameProfiler::setup(Containers::Array&& measurements, const std::size_t maxFrameCount) { + CORRADE_ASSERT(maxFrameCount >= 1, "DebugTools::FrameProfiler::setup(): max frame count can't be zero", ); + + _maxFrameCount = maxFrameCount; + _measurements = std::move(measurements); + arrayReserve(_data, maxFrameCount*_measurements.size()); + + /* Calculate the max delay, which signalizes when data will be available. + Non-delayed measurements are distinguished by _delay set to 0, so start + with 1 to exclude these. */ + for(const Measurement& measurement: _measurements) { + /* Max frame count is always >= 1, so even if _delay is 0 the condition + makes sense and we don't need to do a max() */ + CORRADE_ASSERT(maxFrameCount >= measurement._delay, + "DebugTools::FrameProfiler::setup(): max delay" << measurement._delay << "is larger than max frame count" << maxFrameCount, ); + } + + /* Reset to have a clean slate in case we did some other measurements + before */ + enable(); +} + +void FrameProfiler::setup(const std::initializer_list measurements, const std::size_t maxFrameCount) { + setup(Containers::array(measurements), maxFrameCount); +} + +void FrameProfiler::enable() { + _enabled = true; + #ifndef CORRADE_NO_ASSERT + _beginFrameCalled = false; + #endif + _currentData = 0; + _measuredFrameCount = 0; + arrayResize(_data, 0); + + /* Wipe out no longer relevant moving sums from all measurements, and + delayed measurement indices as well (tho for these it's not so + important) */ + for(Measurement& measurement: _measurements) { + measurement._movingSum = 0; + measurement._current = 0; + } +} + +void FrameProfiler::disable() { + _enabled = false; +} + +void FrameProfiler::beginFrame() { + if(!_enabled) return; + + CORRADE_ASSERT(!_beginFrameCalled, "DebugTools::FrameProfiler::beginFrame(): expected end of frame", ); + #ifndef CORRADE_NO_ASSERT + _beginFrameCalled = true; + #endif + + /* For all measurements call the begin function */ + for(const Measurement& measurement: _measurements) { + if(!measurement._delay) + measurement._begin.immediate(measurement._state); + else + measurement._begin.delayed(measurement._state, measurement._current); + } +} + +/* For delay = 1 returns _currentData */ +std::size_t FrameProfiler::delayedCurrentData(UnsignedInt delay) const { + CORRADE_INTERNAL_ASSERT(delay >= 1); + + /* The delayed frame is current or before current */ + if(_currentData >= delay - 1) + return _currentData - delay + 1; + + /* If we have all data, wrap around. If we don't have all data yet, such + value doesn't exist and thus this will return an OOB index. If + everything is implemented correctly, it won't be accessed in any way. */ + return _maxFrameCount + _currentData - delay + 1; +} + +void FrameProfiler::endFrame() { + if(!_enabled) return; + + CORRADE_ASSERT(_beginFrameCalled, "DebugTools::FrameProfiler::endFrame(): expected begin of frame", ); + #ifndef CORRADE_NO_ASSERT + _beginFrameCalled = false; + #endif + + /* If we don't have all frames yet, enlarge the array */ + if(++_measuredFrameCount <= _maxFrameCount) { + CORRADE_INTERNAL_ASSERT(_measurements.empty() || _currentData == _data.size()/_measurements.size()); + arrayAppend(_data, Containers::NoInit, _measurements.size()); + } + + /* Wrap up measurements for this frame */ + for(std::size_t i = 0; i != _measurements.size(); ++i) { + Measurement& measurement = _measurements[i]; + const UnsignedInt measurementDelay = Math::max(1u, measurement._delay); + + /* Where to save currently queried data. For _delay of 0 or 1, + delayedCurrentData(Math::max(1u, measurement._delay)) is equal to + _currentData. */ + UnsignedLong& currentMeasurementData = _data[delayedCurrentData(measurementDelay)*_measurements.size() + i]; + + /* If we're wrapping around, subtract the oldest data from the moving + average so we can reuse the memory for currently queried data */ + if(_measuredFrameCount > _maxFrameCount + measurementDelay - 1) { + CORRADE_INTERNAL_ASSERT(measurement._movingSum >= currentMeasurementData); + measurement._movingSum -= currentMeasurementData; + } + + /* Simply save the data if not delayed */ + if(!measurement._delay) + currentMeasurementData = measurement._query.immediate(measurement._state); + + /* For delayed measurements call the end function for current frame and + then save the data for the delayed frame */ + else { + measurement._end(measurement._state, measurement._current); + + /* The slot from which we just retrieved a delayed value will be + reused for a a new value next frame */ + const UnsignedInt previous = (measurement._current + 1) % measurement._delay; + if(_measuredFrameCount >= measurement._delay) { + currentMeasurementData = + measurement._query.delayed(measurement._state, previous, measurement._current); + } + measurement._current = previous; + } + } + + /* Process the new data if we have enough frames even for the largest + delay */ + for(std::size_t i = 0; i != _measurements.size(); ++i) { + Measurement& measurement = _measurements[i]; + const UnsignedInt measurementDelay = Math::max(1u, measurement._delay); + + /* If we have enough frames, add the new measurement to the moving sum. + For _delay of 0 or 1, delayedCurrentData(Math::max(1u, measurement._delay)) + is equal to _currentData. */ + if(_measuredFrameCount >= measurementDelay) + _measurements[i]._movingSum += _data[delayedCurrentData(measurementDelay)*_measurements.size() + i]; + } + + /* Advance & wraparound the index where data will be saved for the next + frame */ + _currentData = (_currentData + 1) % _maxFrameCount; +} + +std::string FrameProfiler::measurementName(const std::size_t id) const { + CORRADE_ASSERT(id < _measurements.size(), + "DebugTools::FrameProfiler::measurementName(): index" << id << "out of range for" << _measurements.size() << "measurements", {}); + return _measurements[id]._name; +} + +FrameProfiler::Units FrameProfiler::measurementUnits(const std::size_t id) const { + CORRADE_ASSERT(id < _measurements.size(), + "DebugTools::FrameProfiler::measurementUnits(): index" << id << "out of range for" << _measurements.size() << "measurements", {}); + return _measurements[id]._units; +} + +UnsignedInt FrameProfiler::measurementDelay(const std::size_t id) const { + CORRADE_ASSERT(id < _measurements.size(), + "DebugTools::FrameProfiler::measurementDelay(): index" << id << "out of range for" << _measurements.size() << "measurements", {}); + return Math::max(_measurements[id]._delay, 1u); +} + +bool FrameProfiler::isMeasurementAvailable(const std::size_t id) const { + CORRADE_ASSERT(id < _measurements.size(), + "DebugTools::FrameProfiler::measurementDelay(): index" << id << "out of range for" << _measurements.size() << "measurements", {}); + return _measuredFrameCount >= Math::max(_measurements[id]._delay, 1u); +} + +Double FrameProfiler::measurementDataInternal(const Measurement& measurement) const { + return Double(measurement._movingSum)/ + Math::min(_measuredFrameCount - Math::max(measurement._delay, 1u) + 1, _maxFrameCount); +} + +Double FrameProfiler::measurementMean(const std::size_t id) const { + CORRADE_ASSERT(id < _measurements.size(), + "DebugTools::FrameProfiler::measurementMean(): index" << id << "out of range for" << _measurements.size() << "measurements", {}); + CORRADE_ASSERT(_measuredFrameCount >= Math::max(_measurements[id]._delay, 1u), "DebugTools::FrameProfiler::measurementMean(): measurement data available after" << Math::max(_measurements[id]._delay, 1u) - _measuredFrameCount << "more frames", {}); + + return measurementDataInternal(_measurements[id]); +} + +namespace { + +/* Based on Corrade/TestSuite/Implementation/BenchmarkStats.h */ + +void printValue(Utility::Debug& out, const Double mean, const Double divisor, const char* const unitPrefix, const char* const units) { + out << Debug::boldColor(Debug::Color::Green) + << Utility::formatString("{:.2f}", mean/divisor) << Debug::resetColor + << Debug::nospace << unitPrefix << Debug::nospace << units; +} + +void printTime(Utility::Debug& out, const Double mean) { + if(mean >= 1000000000.0) + printValue(out, mean, 1000000000.0, " ", "s"); + else if(mean >= 1000000.0) + printValue(out, mean, 1000000.0, " m", "s"); + else if(mean >= 1000.0) + printValue(out, mean, 1000.0, " µ", "s"); + else + printValue(out, mean, 1.0, " n", "s"); +} + +void printCount(Utility::Debug& out, const Double mean, Double multiplier, const char* const units) { + if(mean >= multiplier*multiplier*multiplier) + printValue(out, mean, multiplier*multiplier*multiplier, " G", units); + else if(mean >= multiplier*multiplier) + printValue(out, mean, multiplier*multiplier, " M", units); + else if(mean >= multiplier) + printValue(out, mean, multiplier, " k", units); + else + printValue(out, mean, 1.0, std::strlen(units) ? " " : "", units); +} + +} + +void FrameProfiler::printStatisticsInternal(Debug& out) const { + out << Debug::boldColor(Debug::Color::Default) << "Last" + << Debug::boldColor(Debug::Color::Cyan) + << Math::min(_measuredFrameCount, _maxFrameCount) + << Debug::boldColor(Debug::Color::Default) << "frames:"; + + for(const Measurement& measurement: _measurements) { + out << Debug::newline << " " << Debug::boldColor(Debug::Color::Default) + << measurement._name << Debug::nospace << ":" << Debug::resetColor; + + /* If this measurement is not available yet, print a placeholder */ + if(_measuredFrameCount < Math::max(measurement._delay, 1u)) { + const char* units = nullptr; + switch(measurement._units) { + case Units::Count: + case Units::RatioThousandths: + units = ""; + break; + case Units::Nanoseconds: + units = "s"; + break; + case Units::Bytes: + units = "B"; + break; + case Units::PercentageThousandths: + units = "%"; + break; + } + CORRADE_INTERNAL_ASSERT(units); + + out << Debug::color(Debug::Color::Blue) << "-.--" + << Debug::resetColor; + if(units[0] != '\0') out << units; + + /* Otherwise format the value */ + } else { + const Double mean = measurementDataInternal(measurement); + switch(measurement._units) { + case Units::Nanoseconds: + printTime(out, mean); + continue; + case Units::Bytes: + printCount(out, mean, 1024.0, "B"); + continue; + case Units::Count: + printCount(out, mean, 1000.0, ""); + continue; + case Units::RatioThousandths: + printCount(out, mean/1000.0, 1000.0, ""); + continue; + case Units::PercentageThousandths: + printValue(out, mean, 1000.0, " ", "%"); + continue; + } + + CORRADE_INTERNAL_ASSERT_UNREACHABLE(); /* LCOV_EXCL_LINE */ + } + } +} + +std::string FrameProfiler::statistics() const { + std::ostringstream out; + Debug d{&out, Debug::Flag::NoNewlineAtTheEnd|Debug::Flag::DisableColors}; + printStatisticsInternal(d); + return out.str(); +} + +void FrameProfiler::printStatistics(const std::size_t frequency) const { + Debug::Flags flags; + if(!Debug::isTty()) flags |= Debug::Flag::DisableColors; + printStatistics(Debug{flags}, frequency); +} + +void FrameProfiler::printStatistics(Debug& out, const std::size_t frequency) const { + if(!isEnabled() || _measuredFrameCount % frequency != 0) return; + + /* If on a TTY and we printed at least something already, scroll back up to + overwrite previous output */ + if(out.isTty() && _measuredFrameCount > frequency) + out << Debug::nospace << "\033[" << Debug::nospace + << _measurements.size() + 1 << Debug::nospace << "A\033[J" + << Debug::nospace; + + printStatisticsInternal(out); + + /* Unconditionally finish with a newline so the TTY scrollback works + correctly */ + if(out.flags() & Debug::Flag::NoNewlineAtTheEnd) + out << Debug::newline; +} + +Debug& operator<<(Debug& debug, const FrameProfiler::Units value) { + debug << "DebugTools::FrameProfiler::Units" << Debug::nospace; + + switch(value) { + /* LCOV_EXCL_START */ + #define _c(v) case FrameProfiler::Units::v: return debug << "::" #v; + _c(Nanoseconds) + _c(Bytes) + _c(Count) + _c(RatioThousandths) + _c(PercentageThousandths) + #undef _c + /* LCOV_EXCL_STOP */ + } + + return debug << "(" << Debug::nospace << reinterpret_cast(UnsignedByte(value)) << Debug::nospace << ")"; +} + +#ifdef MAGNUM_TARGET_GL +struct GLFrameProfiler::State { + UnsignedShort cpuDurationIndex = 0xffff, + gpuDurationIndex = 0xffff, + frameTimeIndex = 0xffff; + #ifndef MAGNUM_TARGET_GLES + UnsignedShort vertexFetchRatioIndex = 0xffff, + primitiveClipRatioIndex = 0xffff; + #endif + UnsignedLong frameTimeStartFrame[2]; + UnsignedLong cpuDurationStartFrame; + GL::TimeQuery timeQueries[3]{GL::TimeQuery{NoCreate}, GL::TimeQuery{NoCreate}, GL::TimeQuery{NoCreate}}; + #ifndef MAGNUM_TARGET_GLES + GL::PipelineStatisticsQuery verticesSubmittedQueries[3]{GL::PipelineStatisticsQuery{NoCreate}, GL::PipelineStatisticsQuery{NoCreate}, GL::PipelineStatisticsQuery{NoCreate}}; + GL::PipelineStatisticsQuery vertexShaderInvocationsQueries[3]{GL::PipelineStatisticsQuery{NoCreate}, GL::PipelineStatisticsQuery{NoCreate}, GL::PipelineStatisticsQuery{NoCreate}}; + GL::PipelineStatisticsQuery clippingInputPrimitivesQueries[3]{GL::PipelineStatisticsQuery{NoCreate}, GL::PipelineStatisticsQuery{NoCreate}, GL::PipelineStatisticsQuery{NoCreate}}; + GL::PipelineStatisticsQuery clippingOutputPrimitivesQueries[3]{GL::PipelineStatisticsQuery{NoCreate}, GL::PipelineStatisticsQuery{NoCreate}, GL::PipelineStatisticsQuery{NoCreate}}; + #endif +}; + +GLFrameProfiler::GLFrameProfiler(): _state{Containers::InPlaceInit} {} + +GLFrameProfiler::GLFrameProfiler(const Values values, const std::size_t maxFrameCount): GLFrameProfiler{} +{ + setup(values, maxFrameCount); +} + +GLFrameProfiler::GLFrameProfiler(GLFrameProfiler&&) noexcept = default; + +GLFrameProfiler& GLFrameProfiler::operator=(GLFrameProfiler&&) noexcept = default; + +GLFrameProfiler::~GLFrameProfiler() = default; + +void GLFrameProfiler::setup(const Values values, const std::size_t maxFrameCount) { + UnsignedShort index = 0; + Containers::Array measurements; + if(values & Value::FrameTime) { + /* Fucking hell, STL. When I first saw std::chrono back in 2010 I + should have flipped the table and learn carpentry instead. BUT NO, + I'm still suffering this abomination a decade later! */ + arrayAppend(measurements, Containers::InPlaceInit, + "Frame time", Units::Nanoseconds, UnsignedInt(Containers::arraySize(_state->frameTimeStartFrame)), + [](void* state, UnsignedInt current) { + static_cast(state)->frameTimeStartFrame[current] = std::chrono::duration_cast(std::chrono::high_resolution_clock::now().time_since_epoch()).count(); + }, + [](void*, UnsignedInt) {}, + [](void* state, UnsignedInt previous, UnsignedInt current) { + auto& self = *static_cast(state); + return self.frameTimeStartFrame[current] - + self.frameTimeStartFrame[previous]; + }, _state.get()); + _state->frameTimeIndex = index++; + } + if(values & Value::CpuDuration) { + arrayAppend(measurements, Containers::InPlaceInit, + "CPU duration", Units::Nanoseconds, + [](void* state) { + static_cast(state)->cpuDurationStartFrame = std::chrono::duration_cast(std::chrono::high_resolution_clock::now().time_since_epoch()).count(); + }, + [](void* state) { + return std::chrono::duration_cast(std::chrono::high_resolution_clock::now().time_since_epoch()).count() - static_cast(state)->cpuDurationStartFrame; + }, _state.get()); + _state->cpuDurationIndex = index++; + } + if(values & Value::GpuDuration) { + for(GL::TimeQuery& q: _state->timeQueries) + q = GL::TimeQuery{GL::TimeQuery::Target::TimeElapsed}; + arrayAppend(measurements, Containers::InPlaceInit, + "GPU duration", Units::Nanoseconds, + UnsignedInt(Containers::arraySize(_state->timeQueries)), + [](void* state, UnsignedInt current) { + static_cast(state)->timeQueries[current].begin(); + }, + [](void* state, UnsignedInt current) { + static_cast(state)->timeQueries[current].end(); + }, + [](void* state, UnsignedInt previous, UnsignedInt) { + return static_cast(state)->timeQueries[previous].result(); + }, _state.get()); + _state->gpuDurationIndex = index++; + } + #ifndef MAGNUM_TARGET_GLES + if(values & Value::VertexFetchRatio) { + for(GL::PipelineStatisticsQuery& q: _state->verticesSubmittedQueries) + q = GL::PipelineStatisticsQuery{GL::PipelineStatisticsQuery::Target::VerticesSubmitted}; + for(GL::PipelineStatisticsQuery& q: _state->vertexShaderInvocationsQueries) + q = GL::PipelineStatisticsQuery{GL::PipelineStatisticsQuery::Target::VertexShaderInvocations}; + arrayAppend(measurements, Containers::InPlaceInit, + "Vertex fetch ratio", Units::RatioThousandths, + UnsignedInt(Containers::arraySize(_state->verticesSubmittedQueries)), + [](void* state, UnsignedInt current) { + static_cast(state)->verticesSubmittedQueries[current].begin(); + static_cast(state)->vertexShaderInvocationsQueries[current].begin(); + }, + [](void* state, UnsignedInt current) { + static_cast(state)->verticesSubmittedQueries[current].end(); + static_cast(state)->vertexShaderInvocationsQueries[current].end(); + }, + [](void* state, UnsignedInt previous, UnsignedInt) { + /* Avoid division by zero if a frame doesn't have any draws */ + const auto submitted = static_cast(state)->verticesSubmittedQueries[previous].result(); + if(!submitted) return UnsignedLong{}; + + return static_cast(state)->vertexShaderInvocationsQueries[previous].result()*1000/submitted; + }, _state.get()); + _state->vertexFetchRatioIndex = index++; + } + if(values & Value::PrimitiveClipRatio) { + for(GL::PipelineStatisticsQuery& q: _state->clippingInputPrimitivesQueries) + q = GL::PipelineStatisticsQuery{GL::PipelineStatisticsQuery::Target::ClippingInputPrimitives}; + for(GL::PipelineStatisticsQuery& q: _state->clippingOutputPrimitivesQueries) + q = GL::PipelineStatisticsQuery{GL::PipelineStatisticsQuery::Target::ClippingOutputPrimitives}; + arrayAppend(measurements, Containers::InPlaceInit, + "Primitives clipped", Units::PercentageThousandths, + UnsignedInt(Containers::arraySize(_state->clippingInputPrimitivesQueries)), + [](void* state, UnsignedInt current) { + static_cast(state)->clippingInputPrimitivesQueries[current].begin(); + static_cast(state)->clippingOutputPrimitivesQueries[current].begin(); + }, + [](void* state, UnsignedInt current) { + static_cast(state)->clippingInputPrimitivesQueries[current].end(); + static_cast(state)->clippingOutputPrimitivesQueries[current].end(); + }, + [](void* state, UnsignedInt previous, UnsignedInt) { + /* Avoid division by zero if a frame doesn't have any draws */ + const auto input = static_cast(state)->clippingInputPrimitivesQueries[previous].result(); + if(!input) return UnsignedLong{}; + + return 100000 - static_cast(state)->clippingOutputPrimitivesQueries[previous].result()*100000/input; + }, _state.get()); + _state->primitiveClipRatioIndex = index++; + } + #endif + setup(std::move(measurements), maxFrameCount); +} + +auto GLFrameProfiler::values() const -> Values { + Values values; + if(_state->frameTimeIndex != 0xffff) values |= Value::FrameTime; + if(_state->cpuDurationIndex != 0xffff) values |= Value::CpuDuration; + if(_state->gpuDurationIndex != 0xffff) values |= Value::GpuDuration; + #ifndef MAGNUM_TARGET_GLES + if(_state->vertexFetchRatioIndex != 0xffff) values |= Value::VertexFetchRatio; + if(_state->primitiveClipRatioIndex != 0xffff) values |= Value::PrimitiveClipRatio; + #endif + return values; +} + +bool GLFrameProfiler::isMeasurementAvailable(const Value value) const { + const UnsignedShort* index = nullptr; + switch(value) { + case Value::FrameTime: index = &_state->frameTimeIndex; break; + case Value::CpuDuration: index = &_state->cpuDurationIndex; break; + case Value::GpuDuration: index = &_state->gpuDurationIndex; break; + #ifndef MAGNUM_TARGET_GLES + case Value::VertexFetchRatio: index = &_state->vertexFetchRatioIndex; break; + case Value::PrimitiveClipRatio: index = &_state->primitiveClipRatioIndex; break; + #endif + } + CORRADE_INTERNAL_ASSERT(index); + CORRADE_ASSERT(*index < measurementCount(), + "DebugTools::GLFrameProfiler::isMeasurementAvailable():" << value << "not enabled", {}); + return isMeasurementAvailable(*index); +} + +Double GLFrameProfiler::frameTimeMean() const { + CORRADE_ASSERT(_state->frameTimeIndex < measurementCount(), + "DebugTools::GLFrameProfiler::frameTimeMean(): not enabled", {}); + return measurementMean(_state->frameTimeIndex); +} + +Double GLFrameProfiler::cpuDurationMean() const { + CORRADE_ASSERT(_state->cpuDurationIndex < measurementCount(), + "DebugTools::GLFrameProfiler::cpuDurationMean(): not enabled", {}); + return measurementMean(_state->cpuDurationIndex); +} + +Double GLFrameProfiler::gpuDurationMean() const { + CORRADE_ASSERT(_state->gpuDurationIndex < measurementCount(), + "DebugTools::GLFrameProfiler::gpuDurationMean(): not enabled", {}); + return measurementMean(_state->gpuDurationIndex); +} + +#ifndef MAGNUM_TARGET_GLES +Double GLFrameProfiler::vertexFetchRatioMean() const { + CORRADE_ASSERT(_state->vertexFetchRatioIndex < measurementCount(), + "DebugTools::GLFrameProfiler::vertexFetchRatioMean(): not enabled", {}); + return measurementMean(_state->vertexFetchRatioIndex); +} + +Double GLFrameProfiler::primitiveClipRatioMean() const { + CORRADE_ASSERT(_state->primitiveClipRatioIndex < measurementCount(), + "DebugTools::GLFrameProfiler::primitiveClipRatioMean(): not enabled", {}); + return measurementMean(_state->primitiveClipRatioIndex); +} +#endif + +Debug& operator<<(Debug& debug, const GLFrameProfiler::Value value) { + debug << "DebugTools::GLFrameProfiler::Value" << Debug::nospace; + + switch(value) { + /* LCOV_EXCL_START */ + #define _c(v) case GLFrameProfiler::Value::v: return debug << "::" #v; + _c(FrameTime) + _c(CpuDuration) + _c(GpuDuration) + #ifndef MAGNUM_TARGET_GLES + _c(VertexFetchRatio) + _c(PrimitiveClipRatio) + #endif + #undef _c + /* LCOV_EXCL_STOP */ + } + + return debug << "(" << Debug::nospace << reinterpret_cast(UnsignedShort(value)) << Debug::nospace << ")"; +} + +Debug& operator<<(Debug& debug, const GLFrameProfiler::Values value) { + return Containers::enumSetDebugOutput(debug, value, "DebugTools::GLFrameProfiler::Values{}", { + GLFrameProfiler::Value::FrameTime, + GLFrameProfiler::Value::CpuDuration, + GLFrameProfiler::Value::GpuDuration, + #ifndef MAGNUM_TARGET_GLES + GLFrameProfiler::Value::VertexFetchRatio, + GLFrameProfiler::Value::PrimitiveClipRatio + #endif + }); +} +#endif + +}} diff --git a/src/Magnum/DebugTools/FrameProfiler.h b/src/Magnum/DebugTools/FrameProfiler.h new file mode 100644 index 000000000..c5fc55e71 --- /dev/null +++ b/src/Magnum/DebugTools/FrameProfiler.h @@ -0,0 +1,704 @@ +#ifndef Magnum_DebugTools_FrameProfiler_h +#define Magnum_DebugTools_FrameProfiler_h +/* + This file is part of Magnum. + + Copyright © 2010, 2011, 2012, 2013, 2014, 2015, 2016, 2017, 2018, 2019 + Vladimír Vondruš + + Permission is hereby granted, free of charge, to any person obtaining a + copy of this software and associated documentation files (the "Software"), + to deal in the Software without restriction, including without limitation + the rights to use, copy, modify, merge, publish, distribute, sublicense, + and/or sell copies of the Software, and to permit persons to whom the + Software is furnished to do so, subject to the following conditions: + + The above copyright notice and this permission notice shall be included + in all copies or substantial portions of the Software. + + THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR + IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, + FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL + THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER + LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING + FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER + DEALINGS IN THE SOFTWARE. +*/ + +/** @file + * @brief Class @ref Magnum::DebugTools::FrameProfiler, @ref Magnum::DebugTools::GLFrameProfiler + * @m_since_latest + */ + +#include +#include +#include + +#include "Magnum/Magnum.h" +#include "Magnum/DebugTools/visibility.h" + +namespace Magnum { namespace DebugTools { + +/** +@brief Frame profiler +@m_since_latest + +A generic implementation of a frame profiler supporting a moving average over +a set of frames as well as delayed measurements to avoid stalls when querying +the results. This class alone doesn't provide any pre-defined measurements, see +for example @ref GLFrameProfiler that provides common measurements like CPU and +GPU time. + +@experimental + +@section DebugTools-FrameProfiler-usage Basic usage + +Measurements are performed by calling @ref beginFrame() and @ref endFrame() at +designated points in the frame: + +@snippet MagnumDebugTools.cpp FrameProfiler-usage + +In order to have stable profiling results, the application needs to redraw +constantly. However for applications that otherwise redraw only on change it +might be wasteful --- to account for this, it's possible to toggle the profiler +operation using @ref enable() / @ref disable() and then +@ref Platform::Sdl2Application::redraw() "redraw()" can be called only if +@ref isEnabled() returns @cpp true @ce. + +Data for all measurements is then available through @ref measurementName(), +@ref measurementUnits() and @ref measurementMean(). For a convenient overview +of all measured values you can call @ref statistics() and feed its output to a +UI library or something that can render text. Alternatively, if you don't want +to bother with text rendering, call @ref printStatistics() to have the output +periodically printed to the console. If an interactive terminal is detected, +the output will be colored and refreshing itself in place. Together with the +on-demand profiling, it could look like this, refreshing the output every 10 +frames: + +@snippet MagnumDebugTools.cpp FrameProfiler-usage-console + +And here's a sample output on the terminal --- using a fully configured +@link GLFrameProfiler @endlink: + +@include debugtools-frameprofiler.ansi + +@section DebugTools-FrameProfiler-setup Setting up measurements + +Unless you're using this class through @ref GLFrameProfiler, measurements +have to be set up by passing @ref Measurement instances to the @ref setup() +function or to the constructor, together with specifying count of frames for +the moving average. A CPU duration measurements using the @ref std::chrono APIs +over last 50 frames can be done like this: + +@snippet MagnumDebugTools.cpp FrameProfiler-setup-immediate + +In the above case, the measurement result is available immediately on frame +end. That's not always the case, and for example GPU queries need a few frames +delay to avoid stalls from CPU/GPU synchronization. The following snippet sets +up sample count measurement with a delay, using three separate +@ref GL::SampleQuery instances that are cycled through each frame and retrieved +two frames later. The profiler automatically takes care of choosing one of the +three instances for each measurement via additional `current` / `previous` +parameters passed to each callback: + +@snippet MagnumDebugTools-gl.cpp FrameProfiler-setup-delayed + + + +@m_class{m-block m-warning} + +@par Move construction and state pointers in callbacks + The @ref FrameProfiler class is movable, which could potentially mean that + state pointers passed to callback functions become dangling. It's not a + problem in the above snippets because the state is always external to the + instance, but care has to be taken when passing pointers to subclasses. +@par + When setting up measurements from a subclass, it's recommended to always + pass @cpp this @ce as the state pointer. The base class recognizes it + during a move and patches the state to point to the new instance instead. + If you don't or can't use @cpp this @ce as a state pointer, you need to + either provide a dedicated move constructor and assignment to do the + required patching or disable moves altogether to avoid accidents. +*/ +class MAGNUM_DEBUGTOOLS_EXPORT FrameProfiler { + public: + /** + * @brief Measurement units + * + * @see @ref Measurement + */ + enum class Units: UnsignedByte { + /** + * Nanoseconds, measuring for example elapsed time. Depending on + * the magnitude, @ref statistics() can show them as microseconds, + * milliseconds or seconds. + */ + Nanoseconds, + + /** + * Bytes, measuring for example memory usage, bandwidth. Depending + * on the magnitude, @ref statistics() can show them as kB, MB, GB + * (with a multiplier of 1024). + */ + Bytes, + + /** + * Generic count. For discrete values that don't fit any of the + * above. Depending on the magnitude, @ref statistics() can show + * the value as k, M or G (with a multiplier of 1000). + */ + Count, + + /** + * Ratio expressed in 1/1000s. @ref statistics() divides the value + * by 1000 and depending on the magnitude it can show it also as k, + * M or G (with a multiplier of 1000). + */ + RatioThousandths, + + /** + * Percentage expressed in 1/1000s. @ref statistics() divides the + * value by 1000 and appends a % sign. + */ + PercentageThousandths + }; + + class Measurement; + + /** + * @brief Default constructor + * + * Call @ref setup() to populate the profiler with measurements. + */ + explicit FrameProfiler() noexcept; + + /** + * @brief Constructor + * + * Equivalent to default-constructing an instance and calling + * @ref setup() afterwards. + */ + explicit FrameProfiler(Containers::Array&& measurements, std::size_t maxFrameCount) noexcept; + + /** @overload */ + explicit FrameProfiler(std::initializer_list measurements, std::size_t maxFrameCount); + + /** @brief Copying is not allowed */ + FrameProfiler(const FrameProfiler&) = delete; + + /** @brief Move constructor */ + FrameProfiler(FrameProfiler&&) noexcept; + + /** @brief Copying is not allowed */ + FrameProfiler& operator=(const FrameProfiler&) = delete; + + /** @brief Move assignment */ + FrameProfiler& operator=(FrameProfiler&&) noexcept; + + /** + * @brief Setup measurements + * @param measurements List of measurements + * @param maxFrameCount Max frame count over which to calculate a + * moving average. Expected to be at least @cpp 1 @ce. + * + * Calling @ref setup() on an already set up profiler will replace + * existing measurements with @p measurements and reset + * @ref measuredFrameCount() back to @cpp 0 @ce. + */ + void setup(Containers::Array&& measurements, std::size_t maxFrameCount); + + /** @overload */ + void setup(std::initializer_list measurements, std::size_t maxFrameCount); + + /** @brief Whether the profiling is enabled */ + bool isEnabled() const { return _enabled; } + + /** + * @brief Enable the profiler + * + * The profiler is enabled implicitly after construction. When this + * function is called, it discards all measured data, effectively + * making @ref measuredFrameCount() zero. If you want to reset the + * profiler to measure different values as well, call @ref setup(). + */ + void enable(); + + /** + * @brief Disable the profiler + * + * Disabling the profiler will make @ref beginFrame() and + * @ref endFrame() a no-op, effectively freezing all reported + * measurements until the profiler is enabled again. + */ + void disable(); + + /** + * @brief Begin a frame + * + * Has to be called at the beginning of a frame and be paired with a + * corresponding @ref endFrame(). Calls @p begin functions in all + * @ref Measurement instances passed to @ref setup(). If the profiler + * is disabled, the function is a no-op. + * @see @ref isEnabled() + */ + void beginFrame(); + + /** + * @brief End a frame + * + * Has to be called at the end of frame, before buffer swap, and be + * paired with a corresponding @ref beginFrame(). Calls @p end + * functions in all @ref Measurement instances passed to @ref setup() + * and @p query functions on all measurements that are sufficiently + * delayed, saving their output. If the profiler is disabled, the + * function is a no-op. + * @see @ref isEnabled() + */ + void endFrame(); + + /** + * @brief Max count of measured frames + * + * How many frames to calculate a moving average from. At the beginning + * of a measurement when there's not enough frames, the average is + * calculated only from @ref measuredFrameCount(). Always at least + * @cpp 1 @ce. + */ + std::size_t maxFrameCount() const { return _maxFrameCount; } + + /** + * @brief Count of measured frames + * + * Count of times @ref endFrame() was called, but at most + * @ref maxFrameCount(), after which the profiler calculates a moving + * average over last @ref maxFrameCount() frames only. Actual data + * availability depends on @ref measurementDelay(). + */ + std::size_t measuredFrameCount() const { return _measuredFrameCount; } + + /** + * @brief Measurement count + * + * Count of @ref Measurement instances passed to @ref setup(). If + * @ref setup() was not called yet, returns @cpp 0 @ce. + */ + std::size_t measurementCount() const { return _measurements.size(); } + + /** + * @brief Measurement name + * + * The @p id corresponds to the index of the measurement in the list + * passed to @ref setup(). Expects that @p id is less than + * @ref measurementCount(). + */ + std::string measurementName(std::size_t id) const; + + /** + * @brief Measurement units + * + * The @p id corresponds to the index of the measurement in the list + * passed to @ref setup(). Expects that @p id is less than + * @ref measurementCount(). + */ + Units measurementUnits(std::size_t id) const; + + /** + * @brief Measurement delay + * + * How many @ref beginFrame() / @ref endFrame() call pairs needs to be + * performed before a value for given measurement is available. Always + * at least @cpp 1 @ce. The @p id corresponds to the index of the + * measurement in the list passed to @ref setup(). Expects that @p id + * is less than @ref measurementCount(). + */ + UnsignedInt measurementDelay(std::size_t id) const; + + /** + * @brief Whether given measurement is available + * + * Returns @cpp true @ce if @ref measuredFrameCount() is at least + * @ref measurementDelay() for given @p id, @cpp false @ce otherwise. + * The @p id corresponds to the index of the measurement in the list + * passed to @ref setup(). Expects that @p id is less than + * @ref measurementCount(). + */ + bool isMeasurementAvailable(std::size_t id) const; + + /** + * @brief Measurement mean + * + * Returns a moving average of @f$ n @f$ previous measurements out of + * the total @f$ M @f$ values: @f[ + * \bar{x}_\text{SM} = \dfrac{1}{n} \sum\limits_{i=0}^{n-1} x_{M -i} + * @f] + * + * The @p id corresponds to the index of the measurement in the list + * passed to @ref setup(). Expects that @p id is less than + * @ref measurementCount() and that the measurement is available. + * @see @ref isMeasurementAvailable() + */ + Double measurementMean(std::size_t id) const; + + /** + * @brief Overview of all measurements + * + * Returns a formatted string with names, means and units of all + * measurements in the order they were added. If some measurement data + * is available yet, prints placeholder values for these; if the + * @see @ref isMeasurementAvailable(), @ref isEnabled() + */ + std::string statistics() const; + + /** + * @brief Print an overview of all measurements to a console at given rate + * + * Expected to be called every frame. On every `frequency`th frame + * prints the same information as @ref statistics(), but in addition, + * if the output is a TTY, it's colored and overwrites itself instead + * of filling up the terminal history. + * @see @ref isMeasurementAvailable(), @ref isEnabled() + * @ref Corrade::Utility::Debug::isTty() + */ + void printStatistics(std::size_t frequency) const; + + /** + * @brief Print an overview of all measurements to given output at given rate + * + * Compared to @ref printStatistics(std::size_t) const prints to given + * @p out (which can be also @ref Corrade::Utility::Warning or + * @ref Corrade::Utility::Error) and uses it to decide whether the + * output is a TTY and whether to print colors. + * @see @ref Corrade::Utility::Debug::isTty(), + * @ref Corrade::Utility::Debug::Flag::DisableColors + */ + void printStatistics(Debug& out, std::size_t frequency) const; + + /** @overload */ + void printStatistics(Debug&& out, std::size_t frequency) const { + printStatistics(out, frequency); + } + + private: + std::size_t delayedCurrentData(UnsignedInt delay) const; + Double measurementDataInternal(const Measurement& measurement) const; + void printStatisticsInternal(Debug& out) const; + + bool _enabled = true; + #ifndef CORRADE_NO_ASSERT + /* Here it shouldn't cause the class to have a different size when + asserts get disabled */ + bool _beginFrameCalled{}; + #endif + std::size_t _currentData{}, _maxFrameCount{1}, _measuredFrameCount{}; + Containers::Array _measurements; + Containers::Array _data; +}; + +/** +@brief Measurement + +Describes a single measurement passed to @ref FrameProfiler::setup(). See +@ref DebugTools-FrameProfiler-setup for introduction and examples. +*/ +class MAGNUM_DEBUGTOOLS_EXPORT FrameProfiler::Measurement { + public: + /** + * @brief Construct an immediate measurement + * @param name Measurement name, used in + * @ref FrameProfiler::measurementName() and + * @ref FrameProfiler::statistics() + * @param units Measurement units, used in + * @ref FrameProfiler::measurementUnits() and + * @ref FrameProfiler::statistics() + * @param begin Function to call at the beginning of a frame + * @param end Function to call at the end of a frame, returning + * the measured value + * @param state State pointer passed to both @p begin and @p end + * as a first argument + */ + explicit Measurement(const std::string& name, Units units, void(*begin)(void*), UnsignedLong(*end)(void*), void* state); + + /** + * @brief Construct a delayed measurement + * @param name Measurement name, used in + * @ref FrameProfiler::measurementName() and + * @ref FrameProfiler::statistics() + * @param units Measurement units, used in + * @ref FrameProfiler::measurementUnits() and + * @ref FrameProfiler::statistics() + * @param delay How many @ref FrameProfiler::endFrame() calls has + * to happen before a measured value can be retrieved using + * @p query. Has to be at least @cpp 1 @ce, delay of @cpp 1 @ce is + * equal in behavior to immediate measurements. + * @param begin Function to call at the beginning of a frame. + * Second argument is a `current` index that's guaranteed to be + * less than @p delay and always different in each consecutive + * call. + * @param end Function to call at the end of a frame. + * Second argument is a `current` index that's guaranteed to be + * less than @p delay and always different in each consecutive + * call. + * @param query Function to call to get the measured value. Called + * after @p delay frames. First argument is a `previous` index + * that is the same as the `current` argument passed to a + * corresponding @p begin / @p end function of the measurement to + * query the value of. Second argument is a `current` index that + * corresponds to current frame. + * @param state State pointer passed to both @p begin and @p end + * as a first argument + */ + explicit Measurement(const std::string& name, Units units, UnsignedInt delay, void(*begin)(void*, UnsignedInt), void(*end)(void*, UnsignedInt), UnsignedLong(*query)(void*, UnsignedInt, UnsignedInt), void* state); + + private: + friend FrameProfiler; + + std::string _name; + union { + void(*immediate)(void*); + void(*delayed)(void*, UnsignedInt); + } _begin; + void(*_end)(void*, UnsignedInt); + union { + UnsignedLong(*immediate)(void*); + UnsignedLong(*delayed)(void*, UnsignedInt, UnsignedInt); + } _query; + void* _state; + Units _units; + /* Set to 0 to distinguish immediate measurements (first + constructor), however always used as max(_delay, 1) */ + UnsignedInt _delay; + + UnsignedInt _current{}; + UnsignedLong _movingSum{}; +}; + +/** +@debugoperatorclassenum{FrameProfiler,FrameProfiler::Units} +@m_since_latest +*/ +MAGNUM_DEBUGTOOLS_EXPORT Debug& operator<<(Debug& debug, FrameProfiler::Units value); + +#ifdef MAGNUM_TARGET_GL +/** +@brief OpenGL frame profiler +@m_since_latest + +A @ref FrameProfiler with OpenGL-specific measurements. Instantiate with a +desired subset of measured values and then continue the same way as described +in the @ref DebugTools-FrameProfiler-usage "FrameProfiler usage documentation": + +@snippet MagnumDebugTools-gl.cpp GLFrameProfiler-usage + +If none if @ref Value::GpuDuration, @ref Value::VertexFetchRatio and +@ref Value::PrimitiveClipRatio is not enabled, the class can operate without an +active OpenGL context. + +@experimental +*/ +class MAGNUM_DEBUGTOOLS_EXPORT GLFrameProfiler: public FrameProfiler { + public: + /** + * @brief Measured value + * + * @see @ref Values, @ref GLFrameProfiler(Values, std::size_t), + * @ref setup() + */ + enum class Value: UnsignedShort { + /** + * Measure total frame time (i.e., time between consecutive + * @ref beginFrame() calls). Reported in @ref Units::Nanoseconds + * with a delay of 2 frames. When converted to seconds, the value + * is an inverse of FPS. + */ + FrameTime = 1 << 0, + + /** + * Measure CPU frame duration (i.e., CPU time spent between + * @ref beginFrame() and @ref endFrame()). Reported in + * @ref Units::Nanoseconds with a delay of 1 frame. + */ + CpuDuration = 1 << 1, + + /** + * Measure GPU frame duration (i.e., time between @ref beginFrame() + * and @ref endFrame()). Reported in @ref Units::Nanoseconds + * with a delay of 3 frames. This value requires an active OpenGL + * context. + * @requires_gl33 Extension @gl_extension{ARB,timer_query} + * @requires_es_extension Extension @gl_extension{EXT,disjoint_timer_query} + * @requires_webgl_extension Extension @webgl_extension{EXT,disjoint_timer_query} + * on WebGL 1, @gl_extension{EXT,disjoint_timer_query_webgl2} + * on WebGL 2 + */ + GpuDuration = 1 << 2, + + #ifndef MAGNUM_TARGET_GLES + /** + * Ratio of vertex shader invocations to count of vertices + * submitted. For a non-indexed draw the ratio will be 1, for + * indexed draws ratio is less than 1. The lower the value is, the + * better a mesh is optimized for post-transform vertex cache. + * Reported in @ref Units::RatioThousandths with a delay of 3 + * frames. This value requires an active OpenGL context. + * @requires_gl46 Extension @gl_extension{ARB,pipeline_statistics_query} + */ + VertexFetchRatio = 1 << 3, + + /** + * Ratio of primitives discarded by the clipping stage to count of + * primitives submitted. The ratio is 0 when all primitives pass + * the clipping stage and 1 when all are discarded. Can be used to + * measure efficiency of a frustum culling algorithm. Reported in + * @ref Units::PercentageThousandths with a delay of 3 frames. This + * value requires an active OpenGL context. + * @requires_gl46 Extension @gl_extension{ARB,pipeline_statistics_query} + */ + PrimitiveClipRatio = 1 << 4 + #endif + }; + + /** + * @brief Measured values + * + * @see @ref GLFrameProfiler(Values, std::size_t), @ref setup() + */ + typedef Containers::EnumSet Values; + + /** + * @brief Default constructor + * + * Call @ref setup() to populate the profiler with measurements. + */ + explicit GLFrameProfiler(); + + /** + * @brief Constructor + * + * Equivalent to default-constructing an instance and calling + * @ref setup() afterwards. + */ + explicit GLFrameProfiler(Values values, std::size_t maxFrameCount); + + /** @brief Copying is not allowed */ + GLFrameProfiler(const GLFrameProfiler&) = delete; + + /** @brief Move constructor */ + GLFrameProfiler(GLFrameProfiler&&) noexcept; + + /** @brief Copying is not allowed */ + GLFrameProfiler& operator=(const GLFrameProfiler&) = delete; + + /** @brief Move assignment */ + GLFrameProfiler& operator=(GLFrameProfiler&&) noexcept; + + ~GLFrameProfiler(); + + /** + * @brief Setup measured values + * @param values List of measuremed values + * @param maxFrameCount Max frame count over which to calculate a + * moving average. Expected to be at least @cpp 1 @ce. + * + * Calling @ref setup() on an already set up profiler will replace + * existing measurements with @p measurements and reset + * @ref measuredFrameCount() back to @cpp 0 @ce. + */ + void setup(Values values, std::size_t maxFrameCount); + + /** + * @brief Measured values + * + * Corresponds to the @p values parameter passed to + * @ref GLFrameProfiler(Values, std::size_t) or @ref setup(). + */ + Values values() const; + + /** + * @brief Whether given measurement is available + * + * Returns @cpp true @ce if enough frames was captured to calculate + * given @p value, @cpp false @ce otherwise. Expects that @p value was + * enabled. + */ + bool isMeasurementAvailable(Value value) const; + + using FrameProfiler::isMeasurementAvailable; + + /** + * @brief Mean frame time in nanoseconds + * + * Expects that @ref Value::FrameTime was enabled, and that measurement + * data is available. See the flag documentation for more information. + * @see @ref isMeasurementAvailable(), @ref measurementMean() + */ + Double frameTimeMean() const; + + /** + * @brief Mean CPU frame duration in nanoseconds + * + * Expects that @ref Value::CpuDuration was enabled, and that + * measurement data is available. See the flag documentation for more + * information. + * @see @ref isMeasurementAvailable(), @ref measurementMean() + */ + Double cpuDurationMean() const; + + /** + * @brief Mean GPU frame duration in nanoseconds + * + * Expects that @ref Value::GpuDuration was enabled, and that + * measurement data is available. See the flag documentation for more + * information. + * @see @ref isMeasurementAvailable(), @ref measurementMean() + */ + Double gpuDurationMean() const; + + #ifndef MAGNUM_TARGET_GLES + /** + * @brief Mean vertex fetch ratio in thousandths + * + * Expects that @ref Value::VertexFetchRatio was enabled, and that + * measurement data is available. See the flag documentation for more + * information. + * @requires_gl46 Extension @gl_extension{ARB,pipeline_statistics_query} + * @see @ref isMeasurementAvailable(), @ref measurementMean() + */ + Double vertexFetchRatioMean() const; + + /** + * @brief Mean primitive clip ratio in percentage thousandths + * + * Expects that @ref Value::PrimitiveClipRatio was enabled, and that + * measurement data is available. See the flag documentation for more + * information. + * @requires_gl46 Extension @gl_extension{ARB,pipeline_statistics_query} + * @see @ref isMeasurementAvailable(), @ref measurementMean() + */ + Double primitiveClipRatioMean() const; + #endif + + private: + using FrameProfiler::setup; + + struct State; + Containers::Pointer _state; +}; + +CORRADE_ENUMSET_OPERATORS(GLFrameProfiler::Values) + +/** +@debugoperatorclassenum{GLFrameProfiler,GLFrameProfiler::Value} +@m_since_latest +*/ +MAGNUM_DEBUGTOOLS_EXPORT Debug& operator<<(Debug& debug, GLFrameProfiler::Value value); + +/** +@debugoperatorclassenum{GLFrameProfiler,GLFrameProfiler::Values} +@m_since_latest +*/ +MAGNUM_DEBUGTOOLS_EXPORT Debug& operator<<(Debug& debug, GLFrameProfiler::Values value); +#endif + +}} + +#endif diff --git a/src/Magnum/DebugTools/Test/CMakeLists.txt b/src/Magnum/DebugTools/Test/CMakeLists.txt index fab9805af..9e7df9b00 100644 --- a/src/Magnum/DebugTools/Test/CMakeLists.txt +++ b/src/Magnum/DebugTools/Test/CMakeLists.txt @@ -23,6 +23,10 @@ # DEALINGS IN THE SOFTWARE. # +corrade_add_test(DebugToolsFrameProfilerTest FrameProfilerTest.cpp + LIBRARIES MagnumDebugToolsTestLib) +set_target_properties(DebugToolsFrameProfilerTest PROPERTIES FOLDER "Magnum/DebugTools/Test") + if(WITH_TRADE) # Otherwise CMake complains that Corrade::PluginManager is not found, wtf find_package(Corrade REQUIRED PluginManager) @@ -94,6 +98,10 @@ if(TARGET_GL) endif() if(BUILD_GL_TESTS) + corrade_add_test(DebugToolsFrameProfilerGLTest FrameProfilerGLTest.cpp + LIBRARIES MagnumDebugTools MagnumOpenGLTester) + set_target_properties(DebugToolsFrameProfilerTest PROPERTIES FOLDER "Magnum/DebugTools/Test") + corrade_add_test(DebugToolsTextureImageGLTest TextureImageGLTest.cpp LIBRARIES MagnumDebugTools MagnumOpenGLTester) set_target_properties(DebugToolsTextureImageGLTest PROPERTIES FOLDER "Magnum/DebugTools/Test") diff --git a/src/Magnum/DebugTools/Test/FrameProfilerGLTest.cpp b/src/Magnum/DebugTools/Test/FrameProfilerGLTest.cpp new file mode 100644 index 000000000..2cf573f74 --- /dev/null +++ b/src/Magnum/DebugTools/Test/FrameProfilerGLTest.cpp @@ -0,0 +1,242 @@ +/* + This file is part of Magnum. + + Copyright © 2010, 2011, 2012, 2013, 2014, 2015, 2016, 2017, 2018, 2019 + Vladimír Vondruš + + Permission is hereby granted, free of charge, to any person obtaining a + copy of this software and associated documentation files (the "Software"), + to deal in the Software without restriction, including without limitation + the rights to use, copy, modify, merge, publish, distribute, sublicense, + and/or sell copies of the Software, and to permit persons to whom the + Software is furnished to do so, subject to the following conditions: + + The above copyright notice and this permission notice shall be included + in all copies or substantial portions of the Software. + + THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR + IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, + FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL + THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER + LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING + FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER + DEALINGS IN THE SOFTWARE. +*/ + +#include +#include + +#include "Magnum/DebugTools/FrameProfiler.h" +#include "Magnum/GL/Context.h" +#include "Magnum/GL/Extensions.h" +#include "Magnum/GL/Framebuffer.h" +#include "Magnum/GL/Mesh.h" +#include "Magnum/GL/OpenGLTester.h" +#include "Magnum/GL/Renderbuffer.h" +#include "Magnum/GL/RenderbufferFormat.h" +#include "Magnum/MeshTools/Compile.h" +#include "Magnum/Primitives/Cube.h" +#include "Magnum/Shaders/Flat.h" +#include "Magnum/Trade/MeshData.h" + +namespace Magnum { namespace DebugTools { namespace Test { namespace { + +struct FrameProfilerGLTest: GL::OpenGLTester { + explicit FrameProfilerGLTest(); + + void test(); + #ifndef MAGNUM_TARGET_GLES + void vertexFetchRatioDivisionByZero(); + void primitiveClipRatioDivisionByZero(); + #endif +}; + +struct { + const char* name; + GLFrameProfiler::Values values; +} Data[]{ + {"gpu duration", GLFrameProfiler::Value::GpuDuration}, + {"cpu duration + gpu duration", GLFrameProfiler::Value::CpuDuration|GLFrameProfiler::Value::GpuDuration}, + {"frame time + gpu duration", GLFrameProfiler::Value::FrameTime|GLFrameProfiler::Value::GpuDuration}, + #ifndef MAGNUM_TARGET_GLES + {"gpu duration + vertex fetch ratio", GLFrameProfiler::Value::GpuDuration|GLFrameProfiler::Value::VertexFetchRatio}, + {"vertex fetch ratio + primitive clip ratio", GLFrameProfiler::Value::VertexFetchRatio|GLFrameProfiler::Value::PrimitiveClipRatio} + #endif +}; + +FrameProfilerGLTest::FrameProfilerGLTest() { + addInstancedTests({&FrameProfilerGLTest::test}, + Containers::arraySize(Data)); + + #ifndef MAGNUM_TARGET_GLES + addTests({&FrameProfilerGLTest::vertexFetchRatioDivisionByZero, + &FrameProfilerGLTest::primitiveClipRatioDivisionByZero}); + #endif +} + +void FrameProfilerGLTest::test() { + auto&& data = Data[testCaseInstanceId()]; + setTestCaseDescription(data.name); + + if(data.values & GLFrameProfiler::Value::GpuDuration) { + #ifndef MAGNUM_TARGET_GLES + if(!GL::Context::current().isExtensionSupported()) + CORRADE_SKIP(GL::Extensions::ARB::timer_query::string() + std::string(" is not available")); + #elif defined(MAGNUM_TARGET_WEBGL) && !defined(MAGNUM_TARGET_GLES2) + if(!GL::Context::current().isExtensionSupported()) + CORRADE_SKIP(GL::Extensions::EXT::disjoint_timer_query_webgl2::string() + std::string(" is not available")); + #else + if(!GL::Context::current().isExtensionSupported()) + CORRADE_SKIP(GL::Extensions::EXT::disjoint_timer_query::string() + std::string(" is not available")); + #endif + } + + #ifndef MAGNUM_TARGET_GLES + if((data.values & GLFrameProfiler::Value::VertexFetchRatio) && !GL::Context::current().isExtensionSupported()) + CORRADE_SKIP(GL::Extensions::ARB::pipeline_statistics_query::string() + std::string(" is not available")); + #endif + + /* Bind some FB to avoid errors on contexts w/o default FB */ + GL::Renderbuffer color; + color.setStorage( + #if !(defined(MAGNUM_TARGET_WEBGL) && defined(MAGNUM_TARGET_GLES2)) + GL::RenderbufferFormat::RGBA8, + #else + GL::RenderbufferFormat::RGBA4, + #endif + Vector2i{32}); + GL::Framebuffer fb{{{}, Vector2i{32}}}; + fb.attachRenderbuffer(GL::Framebuffer::ColorAttachment{0}, color) + .bind(); + + Shaders::Flat3D shader; + GL::Mesh mesh = MeshTools::compile(Primitives::cubeSolid()); + + GLFrameProfiler profiler{data.values, 4}; + CORRADE_COMPARE(profiler.maxFrameCount(), 4); + + for(auto value: {GLFrameProfiler::Value::CpuDuration, + GLFrameProfiler::Value::GpuDuration, + #ifndef MAGNUM_TARGET_GLES + GLFrameProfiler::Value::VertexFetchRatio, + GLFrameProfiler::Value::PrimitiveClipRatio + #endif + }) + if(data.values & value) + CORRADE_VERIFY(!profiler.isMeasurementAvailable(value)); + + profiler.beginFrame(); + shader.draw(mesh); + Utility::System::sleep(1); + profiler.endFrame(); + + profiler.beginFrame(); + shader.draw(mesh); + profiler.endFrame(); + + Utility::System::sleep(10); + + profiler.beginFrame(); + shader.draw(mesh); + Utility::System::sleep(1); + profiler.endFrame(); + + profiler.beginFrame(); + shader.draw(mesh); + Utility::System::sleep(1); + profiler.endFrame(); + + MAGNUM_VERIFY_NO_GL_ERROR(); + + /* The GPU time should not be a total zero. Can't test upper bound because + (especially on overloaded CIs) it all takes a magnitude more than + expected. */ + if(data.values & GLFrameProfiler::Value::GpuDuration) { + CORRADE_VERIFY(profiler.isMeasurementAvailable(GLFrameProfiler::Value::GpuDuration)); + CORRADE_COMPARE_AS(profiler.gpuDurationMean(), 100, + TestSuite::Compare::Greater); + } + + /* 3/4 frames took 1 ms, the ideal average is 0.75 ms. Can't test upper + bound because (especially on overloaded CIs) it all takes a magnitude + more than expected. */ + if(data.values & GLFrameProfiler::Value::CpuDuration) { + CORRADE_VERIFY(profiler.isMeasurementAvailable(GLFrameProfiler::Value::CpuDuration)); + CORRADE_COMPARE_AS(profiler.cpuDurationMean(), 0.70*1000*1000, + TestSuite::Compare::GreaterOrEqual); + } + + #ifndef MAGNUM_TARGET_GLES + /* 24 unique vertices in 12 triangles, ideal ratio is 24/36 */ + if(data.values & GLFrameProfiler::Value::VertexFetchRatio) { + CORRADE_VERIFY(profiler.isMeasurementAvailable(GLFrameProfiler::Value::VertexFetchRatio)); + CORRADE_COMPARE_WITH(profiler.vertexFetchRatioMean()/1000, 0.6667, + TestSuite::Compare::around(0.1)); + } + + /* We use a default transformation, which means the whole cube should be + visible, nothing clipped */ + if(data.values & GLFrameProfiler::Value::PrimitiveClipRatio) { + CORRADE_VERIFY(profiler.isMeasurementAvailable(GLFrameProfiler::Value::PrimitiveClipRatio)); + CORRADE_COMPARE(profiler.primitiveClipRatioMean()/1000, 0.0); + } + #endif +} + +#ifndef MAGNUM_TARGET_GLES +void FrameProfilerGLTest::vertexFetchRatioDivisionByZero() { + if(!GL::Context::current().isExtensionSupported()) + CORRADE_SKIP(GL::Extensions::ARB::pipeline_statistics_query::string() + std::string(" is not available")); + + GLFrameProfiler profiler{GLFrameProfiler::Value::VertexFetchRatio, 4}; + + profiler.beginFrame(); + profiler.endFrame(); + + profiler.beginFrame(); + profiler.endFrame(); + + profiler.beginFrame(); + profiler.endFrame(); + + profiler.beginFrame(); + profiler.endFrame(); + + MAGNUM_VERIFY_NO_GL_ERROR(); + + /* No draws happened, so the ratio should be 0 (and not crashing with a + division by zero) */ + CORRADE_VERIFY(profiler.isMeasurementAvailable(GLFrameProfiler::Value::VertexFetchRatio)); + CORRADE_COMPARE(profiler.vertexFetchRatioMean(), 0.0); +} + +void FrameProfilerGLTest::primitiveClipRatioDivisionByZero() { + if(!GL::Context::current().isExtensionSupported()) + CORRADE_SKIP(GL::Extensions::ARB::pipeline_statistics_query::string() + std::string(" is not available")); + + GLFrameProfiler profiler{GLFrameProfiler::Value::PrimitiveClipRatio, 4}; + + profiler.beginFrame(); + profiler.endFrame(); + + profiler.beginFrame(); + profiler.endFrame(); + + profiler.beginFrame(); + profiler.endFrame(); + + profiler.beginFrame(); + profiler.endFrame(); + + MAGNUM_VERIFY_NO_GL_ERROR(); + + /* No draws happened, so the ratio should be 0 (and not crashing with a + division by zero) */ + CORRADE_VERIFY(profiler.isMeasurementAvailable(GLFrameProfiler::Value::PrimitiveClipRatio)); + CORRADE_COMPARE(profiler.primitiveClipRatioMean(), 0.0); +} +#endif + +}}}} + +CORRADE_TEST_MAIN(Magnum::DebugTools::Test::FrameProfilerGLTest) diff --git a/src/Magnum/DebugTools/Test/FrameProfilerTest.cpp b/src/Magnum/DebugTools/Test/FrameProfilerTest.cpp new file mode 100644 index 000000000..900e5e06c --- /dev/null +++ b/src/Magnum/DebugTools/Test/FrameProfilerTest.cpp @@ -0,0 +1,1057 @@ +/* + This file is part of Magnum. + + Copyright © 2010, 2011, 2012, 2013, 2014, 2015, 2016, 2017, 2018, 2019 + Vladimír Vondruš + + Permission is hereby granted, free of charge, to any person obtaining a + copy of this software and associated documentation files (the "Software"), + to deal in the Software without restriction, including without limitation + the rights to use, copy, modify, merge, publish, distribute, sublicense, + and/or sell copies of the Software, and to permit persons to whom the + Software is furnished to do so, subject to the following conditions: + + The above copyright notice and this permission notice shall be included + in all copies or substantial portions of the Software. + + THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR + IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, + FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL + THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER + LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING + FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER + DEALINGS IN THE SOFTWARE. +*/ + +#include +#include +#include +#include +#include +#include + +#include "Magnum/DebugTools/FrameProfiler.h" + +namespace Magnum { namespace DebugTools { namespace Test { namespace { + +struct FrameProfilerTest: TestSuite::Tester { + explicit FrameProfilerTest(); + + void defaultConstructed(); + void noMeasurements(); + + void singleFrame(); + void multipleFrames(); + + void enableDisable(); + void reSetup(); + + void copy(); + void move(); + + void frameCountZero(); + void delayZero(); + void delayTooLittleFrames(); + void startStopFrameUnexpected(); + void measurementOutOfBounds(); + void dataNotAvailableYet(); + + void statistics(); + + #ifdef MAGNUM_TARGET_GL + void gl(); + void glNotEnabled(); + #endif + + void debugUnits(); + #ifdef MAGNUM_TARGET_GL + void debugGLValue(); + void debugGLValues(); + #endif +}; + +struct { + const char* name; + bool delayed; +} SingleFrameData[]{ + {"", false}, + {"delayed by 1", true} +}; + +struct { + const char* name; + bool delayed; + UnsignedInt delay; +} MultipleFramesData[]{ + {"", false, 1}, + {"delayed by 1", true, 1}, + {"delayed by 2", true, 2}, + {"delayed by 3", true, 3} +}; + +#ifdef MAGNUM_TARGET_GL +struct { + const char* name; + GLFrameProfiler::Values values; + UnsignedInt measurementCount; + UnsignedInt measurementDelay; +} GLData[]{ + {"empty", {}, 0, 1}, + {"frame time", GLFrameProfiler::Value::FrameTime, 1, 2}, + {"cpu duration", GLFrameProfiler::Value::CpuDuration, 1, 1}, + {"frame time + cpu duration", GLFrameProfiler::Value::FrameTime|GLFrameProfiler::Value::CpuDuration, 2, 2} +}; +#endif + +FrameProfilerTest::FrameProfilerTest() { + addTests({&FrameProfilerTest::defaultConstructed, + &FrameProfilerTest::noMeasurements}); + + addInstancedTests({&FrameProfilerTest::singleFrame}, + Containers::arraySize(SingleFrameData)); + addInstancedTests({&FrameProfilerTest::multipleFrames}, + Containers::arraySize(MultipleFramesData)); + + addTests({&FrameProfilerTest::enableDisable, + &FrameProfilerTest::reSetup, + + &FrameProfilerTest::copy, + &FrameProfilerTest::move, + + &FrameProfilerTest::frameCountZero, + &FrameProfilerTest::delayZero, + &FrameProfilerTest::delayTooLittleFrames, + &FrameProfilerTest::startStopFrameUnexpected, + &FrameProfilerTest::measurementOutOfBounds, + &FrameProfilerTest::dataNotAvailableYet, + + &FrameProfilerTest::statistics}); + + #ifdef MAGNUM_TARGET_GL + addInstancedTests({&FrameProfilerTest::gl}, + Containers::arraySize(GLData)); + #endif + + addTests({ + #ifdef MAGNUM_TARGET_GL + &FrameProfilerTest::glNotEnabled, + #endif + + &FrameProfilerTest::debugUnits, + #ifdef MAGNUM_TARGET_GL + &FrameProfilerTest::debugGLValue, + &FrameProfilerTest::debugGLValues, + #endif + }); +} + +void FrameProfilerTest::defaultConstructed() { + FrameProfiler profiler; + CORRADE_COMPARE(profiler.maxFrameCount(), 1); + CORRADE_COMPARE(profiler.measuredFrameCount(), 0); + CORRADE_COMPARE(profiler.measurementCount(), 0); + CORRADE_COMPARE(profiler.statistics(), "Last 0 frames:"); + + profiler.beginFrame(); + profiler.endFrame(); + CORRADE_COMPARE(profiler.measuredFrameCount(), 1); + + /* Shouldn't crash on any silly division by zero even when called a second + time */ + profiler.beginFrame(); + profiler.endFrame(); + CORRADE_COMPARE(profiler.measuredFrameCount(), 2); +} + +void FrameProfilerTest::noMeasurements() { + FrameProfiler profiler{{}, 3}; + CORRADE_COMPARE(profiler.maxFrameCount(), 3); + CORRADE_COMPARE(profiler.measuredFrameCount(), 0); + CORRADE_COMPARE(profiler.measurementCount(), 0); + CORRADE_COMPARE(profiler.statistics(), "Last 0 frames:"); + + profiler.beginFrame(); + profiler.endFrame(); + CORRADE_COMPARE(profiler.measuredFrameCount(), 1); + + /* Shouldn't crash on any silly division by zero even after a wraparound */ + profiler.beginFrame(); + profiler.endFrame(); + CORRADE_COMPARE(profiler.measuredFrameCount(), 2); + + profiler.beginFrame(); + profiler.endFrame(); + CORRADE_COMPARE(profiler.measuredFrameCount(), 3); + + profiler.beginFrame(); + profiler.endFrame(); + CORRADE_COMPARE(profiler.measuredFrameCount(), 4); + + profiler.beginFrame(); + profiler.endFrame(); + CORRADE_COMPARE(profiler.measuredFrameCount(), 5); + + profiler.beginFrame(); + profiler.endFrame(); + CORRADE_COMPARE(profiler.measuredFrameCount(), 6); +} + +void FrameProfilerTest::singleFrame() { + auto&& data = SingleFrameData[testCaseInstanceId()]; + setTestCaseDescription(data.name); + + UnsignedLong time = 0, memory = 50; + FrameProfiler profiler; + if(!data.delayed) { + profiler.setup({ + FrameProfiler::Measurement{ + "Lag", FrameProfiler::Units::Nanoseconds, + [](void* state) { + *static_cast(state) += 15; + }, + [](void* state) { + return *static_cast(state) - 15; + }, &time}, + FrameProfiler::Measurement{ + "Bloat", FrameProfiler::Units::Bytes, + [](void* state) { + *static_cast(state) *= 2; + }, + [](void* state) { + return *static_cast(state) - 100; + }, &memory}, + FrameProfiler::Measurement{ + "Constant", FrameProfiler::Units::Count, + [](void*) {}, + [](void*) { + return UnsignedLong{100000}; + }, nullptr} + }, 1); + } else { + profiler.setup({ + FrameProfiler::Measurement{ + "Lag", FrameProfiler::Units::Nanoseconds, 1, + [](void* state, UnsignedInt current) { + CORRADE_COMPARE(current, 0); + static_cast(state)[current] += 30; + }, + [](void* state, UnsignedInt current) { + CORRADE_COMPARE(current, 0); + static_cast(state)[current] -= 15; + }, + [](void* state, UnsignedInt previous, UnsignedInt current) { + CORRADE_COMPARE(previous, 0); + CORRADE_COMPARE(current, 0); + return static_cast(state)[previous] - 15; + }, &time}, + FrameProfiler::Measurement{ + "Bloat", FrameProfiler::Units::Bytes, 1, + [](void* state, UnsignedInt current) { + CORRADE_COMPARE(current, 0); + static_cast(state)[current] *= 4; + }, + [](void* state, UnsignedInt current) { + CORRADE_COMPARE(current, 0); + static_cast(state)[current] /= 2; + }, + [](void* state, UnsignedInt previous, UnsignedInt current) { + CORRADE_COMPARE(previous, 0); + CORRADE_COMPARE(current, 0); + return static_cast(state)[previous] - 100; + }, &memory}, + FrameProfiler::Measurement{ + "Constant", FrameProfiler::Units::Count, 1, + [](void*, UnsignedInt) {}, + [](void*, UnsignedInt) {}, + [](void*, UnsignedInt, UnsignedInt) { + return UnsignedLong{100000}; + }, nullptr} + }, 1); + } + CORRADE_COMPARE(profiler.maxFrameCount(), 1); + CORRADE_COMPARE(profiler.measuredFrameCount(), 0); + CORRADE_COMPARE(profiler.measurementCount(), 3); + + CORRADE_COMPARE(profiler.measurementName(0), "Lag"); + CORRADE_COMPARE(profiler.measurementUnits(0), FrameProfiler::Units::Nanoseconds); + CORRADE_COMPARE(profiler.measurementDelay(0), 1); + + CORRADE_COMPARE(profiler.measurementName(1), "Bloat"); + CORRADE_COMPARE(profiler.measurementUnits(1), FrameProfiler::Units::Bytes); + CORRADE_COMPARE(profiler.measurementDelay(1), 1); + + CORRADE_COMPARE(profiler.measurementName(2), "Constant"); + CORRADE_COMPARE(profiler.measurementUnits(2), FrameProfiler::Units::Count); + CORRADE_COMPARE(profiler.measurementDelay(2), 1); + + CORRADE_VERIFY(!profiler.isMeasurementAvailable(0)); + CORRADE_VERIFY(!profiler.isMeasurementAvailable(1)); + CORRADE_VERIFY(!profiler.isMeasurementAvailable(2)); + + profiler.beginFrame(); + CORRADE_COMPARE(time, data.delayed ? 30 : 15); + CORRADE_COMPARE(memory, data.delayed ? 200 : 100); + CORRADE_COMPARE(profiler.measuredFrameCount(), 0); + CORRADE_VERIFY(!profiler.isMeasurementAvailable(0)); + CORRADE_VERIFY(!profiler.isMeasurementAvailable(1)); + CORRADE_VERIFY(!profiler.isMeasurementAvailable(2)); + + profiler.endFrame(); + CORRADE_COMPARE(time, 15); + CORRADE_COMPARE(memory, 100); + CORRADE_COMPARE(profiler.measuredFrameCount(), 1); + CORRADE_VERIFY(profiler.isMeasurementAvailable(0)); + CORRADE_VERIFY(profiler.isMeasurementAvailable(1)); + CORRADE_VERIFY(profiler.isMeasurementAvailable(2)); + CORRADE_COMPARE(profiler.measurementMean(0), 0.0); + CORRADE_COMPARE(profiler.measurementMean(1), 0.0); + CORRADE_COMPARE(profiler.measurementMean(2), 100000.0); + + profiler.beginFrame(); + profiler.endFrame(); + CORRADE_COMPARE(time, 30); + CORRADE_COMPARE(memory, 200); + CORRADE_COMPARE(profiler.measuredFrameCount(), 2); + CORRADE_COMPARE(profiler.measurementMean(0), 15.0); + CORRADE_COMPARE(profiler.measurementMean(1), 100.0); + CORRADE_COMPARE(profiler.measurementMean(2), 100000.0); + + profiler.beginFrame(); + profiler.endFrame(); + CORRADE_COMPARE(time, 45); + CORRADE_COMPARE(memory, 400); + CORRADE_COMPARE(profiler.measurementMean(0), 30.0); + CORRADE_COMPARE(profiler.measurementMean(1), 300.0); + CORRADE_COMPARE(profiler.measurementMean(2), 100000.0); + + profiler.beginFrame(); + profiler.endFrame(); + CORRADE_COMPARE(time, 60); + CORRADE_COMPARE(memory, 800); + CORRADE_COMPARE(profiler.measurementMean(0), 45.0); + CORRADE_COMPARE(profiler.measurementMean(1), 700.0); + CORRADE_COMPARE(profiler.measurementMean(2), 100000.0); +} + +void FrameProfilerTest::multipleFrames() { + auto&& data = MultipleFramesData[testCaseInstanceId()]; + setTestCaseDescription(data.name); + + struct State { + UnsignedLong currentTime, currentMemory; + UnsignedLong time[3]; + UnsignedLong memory[3]; + UnsignedInt delay; + } state {0, 50, {0, 0, 0}, {50, 0, 0}, data.delay}; + FrameProfiler profiler; + if(!data.delayed) { + profiler.setup({ + FrameProfiler::Measurement{ + "Lag", FrameProfiler::Units::Nanoseconds, + [](void* state) { + *static_cast(state) += 15; + }, + [](void* state) { + return *static_cast(state) - 15; + }, &state.time[0]}, + FrameProfiler::Measurement{ + "Bloat", FrameProfiler::Units::Bytes, + [](void* state) { + *static_cast(state) *= 2; + }, + [](void* state) { + return *static_cast(state) - 100; + }, &state.memory[0]}, + FrameProfiler::Measurement{ + "Constant", FrameProfiler::Units::Count, + [](void*) {}, + [](void*) { + return UnsignedLong{100000}; + }, nullptr} + }, 3); + } else { + profiler.setup({ + FrameProfiler::Measurement{ + "Lag", FrameProfiler::Units::Nanoseconds, data.delay, + [](void* state, UnsignedInt current) { + auto& s = *static_cast(state); + CORRADE_COMPARE_AS(current, s.delay, TestSuite::Compare::Less); + s.time[current] = (s.currentTime += 15) + 15; + }, + [](void* state, UnsignedInt current) { + auto& s = *static_cast(state); + CORRADE_COMPARE_AS(current, s.delay, TestSuite::Compare::Less); + s.time[current] -= 15; + }, + [](void* state, UnsignedInt previous, UnsignedInt current) { + auto& s = *static_cast(state); + CORRADE_COMPARE_AS(previous, s.delay, TestSuite::Compare::Less); + CORRADE_COMPARE_AS(current, s.delay, TestSuite::Compare::Less); + CORRADE_VERIFY(current + 1 == previous || (current == s.delay - 1 && previous == 0)); + return s.time[previous] - 15; + }, &state}, + FrameProfiler::Measurement{ + "Bloat", FrameProfiler::Units::Bytes, data.delay, + [](void* state, UnsignedInt current) { + auto& s = *static_cast(state); + CORRADE_COMPARE_AS(current, s.delay, TestSuite::Compare::Less); + s.memory[current] = (s.currentMemory *= 2)*2; + }, + [](void* state, UnsignedInt current) { + auto& s = *static_cast(state); + CORRADE_COMPARE_AS(current, s.delay, TestSuite::Compare::Less); + s.memory[current] /= 2; + }, + [](void* state, UnsignedInt previous, UnsignedInt current) { + auto& s = *static_cast(state); + CORRADE_COMPARE_AS(previous, s.delay, TestSuite::Compare::Less); + CORRADE_COMPARE_AS(current, s.delay, TestSuite::Compare::Less); + CORRADE_VERIFY(current + 1 == previous || (current == s.delay - 1 && previous == 0)); + return s.memory[previous] - 100; + }, &state}, + FrameProfiler::Measurement{ + "Undelayed constant", FrameProfiler::Units::Count, 1, + [](void*, UnsignedInt) {}, + [](void*, UnsignedInt) {}, + [](void*, UnsignedInt, UnsignedInt) { + return UnsignedLong{100000}; + }, nullptr} + }, 3); + } + CORRADE_COMPARE(profiler.maxFrameCount(), 3); + CORRADE_COMPARE(profiler.measuredFrameCount(), 0); + CORRADE_COMPARE(profiler.measurementDelay(0), data.delay); + CORRADE_COMPARE(profiler.measurementDelay(1), data.delay); + CORRADE_COMPARE(profiler.measurementDelay(2), 1); + + for(std::size_t i = 0; i != data.delay - 1; ++i) { + profiler.beginFrame(); + profiler.endFrame(); + CORRADE_COMPARE(state.time[i], 15*(i + 1)); + CORRADE_COMPARE(state.memory[i], 100*(i + 1)); + CORRADE_VERIFY(!profiler.isMeasurementAvailable(0)); + CORRADE_VERIFY(!profiler.isMeasurementAvailable(1)); + CORRADE_VERIFY(profiler.isMeasurementAvailable(2)); + } + + profiler.beginFrame(); + profiler.endFrame(); + CORRADE_COMPARE(state.time[0 % data.delay], 15); + CORRADE_COMPARE(state.memory[0 % data.delay], 100); + CORRADE_VERIFY(profiler.isMeasurementAvailable(0)); + CORRADE_VERIFY(profiler.isMeasurementAvailable(1)); + CORRADE_VERIFY(profiler.isMeasurementAvailable(2)); + CORRADE_COMPARE(profiler.measuredFrameCount(), 0 + data.delay); + CORRADE_COMPARE(profiler.measurementMean(0), 0.0); + CORRADE_COMPARE(profiler.measurementMean(1), 0.0); + CORRADE_COMPARE(profiler.measurementMean(2), 100000.0); + + profiler.beginFrame(); + profiler.endFrame(); + CORRADE_COMPARE(state.time[1 % data.delay], 30); + CORRADE_COMPARE(state.memory[1 % data.delay], 200); + CORRADE_COMPARE(profiler.measuredFrameCount(), 1 + data.delay); + CORRADE_COMPARE(profiler.measurementMean(0), (15.0 + 0.0)/2); + CORRADE_COMPARE(profiler.measurementMean(1), (100.0 + 0.0)/2); + CORRADE_COMPARE(profiler.measurementMean(2), 100000.0); + + profiler.beginFrame(); + profiler.endFrame(); + CORRADE_COMPARE(state.time[2 % data.delay], 45); + CORRADE_COMPARE(state.memory[2 % data.delay], 400); + CORRADE_COMPARE(profiler.measuredFrameCount(), 2 + data.delay); + CORRADE_COMPARE(profiler.measurementMean(0), (30.0 + 15.0)/3); + CORRADE_COMPARE(profiler.measurementMean(1), (300.0 + 100.0)/3); + CORRADE_COMPARE(profiler.measurementMean(2), 100000.0); + + /* At this point it wraps around and should be evicting old values from the + moving average */ + + profiler.beginFrame(); + profiler.endFrame(); + CORRADE_COMPARE(state.time[3 % data.delay], 60); + CORRADE_COMPARE(state.memory[3 % data.delay], 800); + CORRADE_COMPARE(profiler.measuredFrameCount(), 3 + data.delay); + CORRADE_COMPARE(profiler.measurementMean(0), (45.0 + 30.0 + 15.0)/3); + CORRADE_COMPARE(profiler.measurementMean(1), (700.0 + 300.0 + 100.0)/3); + CORRADE_COMPARE(profiler.measurementMean(2), 100000.0); + + profiler.beginFrame(); + profiler.endFrame(); + CORRADE_COMPARE(state.time[4 % data.delay], 75); + CORRADE_COMPARE(state.memory[4 % data.delay], 1600); + CORRADE_COMPARE(profiler.measuredFrameCount(), 4 + data.delay); + CORRADE_COMPARE(profiler.measurementMean(0), (60 + 45.0 + 30.0)/3); + CORRADE_COMPARE(profiler.measurementMean(1), (1500.0 + 700.0 + 300.0)/3); + CORRADE_COMPARE(profiler.measurementMean(2), 100000.0); + + profiler.beginFrame(); + profiler.endFrame(); + CORRADE_COMPARE(state.time[5 % data.delay], 90); + CORRADE_COMPARE(state.memory[5 % data.delay], 3200); + CORRADE_COMPARE(profiler.measuredFrameCount(), 5 + data.delay); + CORRADE_COMPARE(profiler.measurementMean(0), (75.0 + 60.0 + 45.0)/3); + CORRADE_COMPARE(profiler.measurementMean(1), (3100.0 + 1500.0 + 700.0)/3); + CORRADE_COMPARE(profiler.measurementMean(2), 100000.0); +} + +void FrameProfilerTest::enableDisable() { + UnsignedLong i = 15; + FrameProfiler profiler{{ + FrameProfiler::Measurement{"", FrameProfiler::Units::Count, 2, + [](void*, UnsignedInt) {}, + [](void*, UnsignedInt) {}, + [](void* state, UnsignedInt, UnsignedInt) { + return (*static_cast(state))++; + }, &i}, + }, 5}; + + profiler.beginFrame(); + profiler.endFrame(); + profiler.beginFrame(); + profiler.endFrame(); + profiler.beginFrame(); + profiler.endFrame(); + CORRADE_COMPARE(profiler.measurementCount(), 1); + CORRADE_COMPARE(profiler.measuredFrameCount(), 3); + CORRADE_COMPARE(profiler.measurementDelay(0), 2); + CORRADE_VERIFY(profiler.isMeasurementAvailable(0)); + CORRADE_COMPARE(profiler.measurementMean(0), 15.5); + + /* It should only freeze everything, not wipe out any data */ + profiler.disable(); + CORRADE_COMPARE(profiler.measurementCount(), 1); + CORRADE_COMPARE(profiler.measuredFrameCount(), 3); + CORRADE_COMPARE(profiler.measurementDelay(0), 2); + CORRADE_VERIFY(profiler.isMeasurementAvailable(0)); + CORRADE_COMPARE(profiler.measurementMean(0), 15.5); + + /* These are a no-op now */ + profiler.beginFrame(); + profiler.endFrame(); + profiler.beginFrame(); + CORRADE_COMPARE(profiler.measurementCount(), 1); + CORRADE_COMPARE(profiler.measuredFrameCount(), 3); + CORRADE_COMPARE(profiler.measurementDelay(0), 2); + CORRADE_VERIFY(profiler.isMeasurementAvailable(0)); + CORRADE_COMPARE(profiler.measurementMean(0), 15.5); + + /* Enabling should reset the data to have a clean slate, but not the + measurements */ + profiler.enable(); + CORRADE_COMPARE(profiler.measurementCount(), 1); + CORRADE_COMPARE(profiler.maxFrameCount(), 5); + CORRADE_COMPARE(profiler.measuredFrameCount(), 0); + CORRADE_COMPARE(profiler.measurementDelay(0), 2); + CORRADE_VERIFY(!profiler.isMeasurementAvailable(0)); + + /* Even though there was no call to endFrame() before, reset() should make + beginFrame() expected again */ + i = 0; + profiler.beginFrame(); + profiler.endFrame(); + profiler.beginFrame(); + profiler.endFrame(); + profiler.beginFrame(); + profiler.endFrame(); + CORRADE_COMPARE(profiler.measurementCount(), 1); + CORRADE_COMPARE(profiler.measuredFrameCount(), 3); + CORRADE_COMPARE(profiler.measurementDelay(0), 2); + CORRADE_VERIFY(profiler.isMeasurementAvailable(0)); + /* The per-measurement moving sum should be reset by enable() as well, so + the 15s from before won't contribute to the mean anymore */ + CORRADE_COMPARE(profiler.measurementMean(0), 0.5); +} + +void FrameProfilerTest::reSetup() { + FrameProfiler profiler{{ + FrameProfiler::Measurement{"", FrameProfiler::Units::Count, 3, + [](void*, UnsignedInt) {}, + [](void*, UnsignedInt) {}, + [](void*, UnsignedInt, UnsignedInt) { return UnsignedLong{}; }, nullptr}, + }, 5}; + + profiler.beginFrame(); + profiler.endFrame(); + profiler.beginFrame(); + + /* Setup should replace everything */ + profiler.setup({ + FrameProfiler::Measurement{ + "Lag", FrameProfiler::Units::Nanoseconds, + [](void*) {}, + [](void*) { return UnsignedLong{}; }, + nullptr}, + FrameProfiler::Measurement{ + "Bloat", FrameProfiler::Units::Bytes, + [](void*) {}, + [](void*) { return UnsignedLong{}; }, + nullptr}, + }, 10); + CORRADE_COMPARE(profiler.measurementCount(), 2); + CORRADE_COMPARE(profiler.maxFrameCount(), 10); + CORRADE_COMPARE(profiler.measuredFrameCount(), 0); + CORRADE_COMPARE(profiler.measurementDelay(0), 1); + CORRADE_COMPARE(profiler.measurementDelay(1), 1); + CORRADE_VERIFY(!profiler.isMeasurementAvailable(0)); + CORRADE_VERIFY(!profiler.isMeasurementAvailable(1)); + + /* Even though there was no call to endFrame() before, setup() should make + beginFrame() expected again */ + profiler.beginFrame(); + profiler.endFrame(); +} + +void FrameProfilerTest::copy() { + CORRADE_VERIFY(!(std::is_constructible{})); + CORRADE_VERIFY(!(std::is_assignable{})); +} + +void FrameProfilerTest::move() { + /* Have two state variables, one in a subclass, one outside. On move the + pointer to a subclass should get patched but the outside not */ + + UnsignedLong i = 15; + struct MyProfiler: FrameProfiler { + UnsignedLong j = 30; + } a; + a.setup({ + FrameProfiler::Measurement{"", FrameProfiler::Units::Count, + [](void*) {}, + [](void* state) { + return (*static_cast(state))++; + }, &i}, + FrameProfiler::Measurement{"", FrameProfiler::Units::Count, 2, + [](void*, UnsignedInt) {}, + [](void*, UnsignedInt) {}, + [](void* state, UnsignedInt, UnsignedInt) { + return static_cast(state)->j++; + }, &a}, + }, 5); + + /* Move construction */ + MyProfiler b{std::move(a)}; + a.j = 100; /* This shouldn't affect b's measurements anymore */ + b.beginFrame(); + b.endFrame(); + b.beginFrame(); + b.endFrame(); + b.beginFrame(); + b.endFrame(); + CORRADE_COMPARE(b.measurementCount(), 2); + CORRADE_COMPARE(b.measuredFrameCount(), 3); + CORRADE_COMPARE(b.measurementDelay(0), 1); + CORRADE_COMPARE(b.measurementDelay(1), 2); + CORRADE_COMPARE(b.measurementMean(0), 16.0); + CORRADE_COMPARE(b.measurementMean(1), 30.5); + + /* Another fully populated instance */ + UnsignedLong k = 45; + MyProfiler c; + c.j = 60; + c.setup({ + FrameProfiler::Measurement{"", FrameProfiler::Units::Count, + [](void*) {}, + [](void* state) { + return (*static_cast(state))++; + }, &k}, + FrameProfiler::Measurement{"", FrameProfiler::Units::Count, 3, + [](void*, UnsignedInt) {}, + [](void*, UnsignedInt) {}, + [](void* state, UnsignedInt, UnsignedInt) { + return static_cast(state)->j++; + }, &c}, + }, 5); + c.beginFrame(); + c.endFrame(); + c.beginFrame(); + c.endFrame(); + c.beginFrame(); + c.endFrame(); + c.beginFrame(); + c.endFrame(); + CORRADE_COMPARE(c.measurementCount(), 2); + CORRADE_COMPARE(c.measuredFrameCount(), 4); + CORRADE_COMPARE(c.measurementDelay(0), 1); + CORRADE_COMPARE(c.measurementDelay(1), 3); + CORRADE_COMPARE(c.measurementMean(0), 46.5); + CORRADE_COMPARE(c.measurementMean(1), 60.5); + + /* Move assignment */ + CORRADE_COMPARE(c.j, 62); + c = std::move(b); + b.j = 62; /* std::move() didn't swap this one, so we do; this shouldn't + affect c's measurements anymore */ + c.beginFrame(); + c.endFrame(); + c.beginFrame(); + c.endFrame(); + CORRADE_COMPARE(c.measurementCount(), 2); + CORRADE_COMPARE(c.measuredFrameCount(), 5); + CORRADE_COMPARE(c.measurementDelay(0), 1); + CORRADE_COMPARE(c.measurementDelay(1), 2); + CORRADE_COMPARE(c.measurementMean(0), 17.0); + CORRADE_COMPARE(c.measurementMean(1), 31.5); + + /* Calling these on the swapped instance should affect only itself */ + b.beginFrame(); + b.endFrame(); + CORRADE_COMPARE(b.measurementMean(0), 47.0); /* originally c */ + CORRADE_COMPARE(b.measurementMean(1), 61.0); /* originally c */ + CORRADE_COMPARE(c.measurementCount(), 2); + CORRADE_COMPARE(c.measuredFrameCount(), 5); + CORRADE_COMPARE(c.measurementDelay(0), 1); + CORRADE_COMPARE(c.measurementDelay(1), 2); + CORRADE_COMPARE(c.measurementMean(0), 17.0); + CORRADE_COMPARE(c.measurementMean(1), 31.5); + + CORRADE_VERIFY(std::is_nothrow_move_constructible::value); + CORRADE_VERIFY(std::is_nothrow_move_assignable::value); +} + +void FrameProfilerTest::delayZero() { + #ifdef CORRADE_NO_ASSERT + CORRADE_SKIP("CORRADE_NO_ASSERT defined, can't test assertions"); + #endif + + std::ostringstream out; + Error redirectError{&out}; + FrameProfiler::Measurement{"", FrameProfiler::Units::Count, 0, + nullptr, nullptr, nullptr, nullptr}; + CORRADE_COMPARE(out.str(), "DebugTools::FrameProfiler::Measurement: delay can't be zero\n"); +} + +void FrameProfilerTest::frameCountZero() { + #ifdef CORRADE_NO_ASSERT + CORRADE_SKIP("CORRADE_NO_ASSERT defined, can't test assertions"); + #endif + + std::ostringstream out; + Error redirectError{&out}; + FrameProfiler{{}, 0}; + CORRADE_COMPARE(out.str(), "DebugTools::FrameProfiler::setup(): max frame count can't be zero\n"); +} + +void FrameProfilerTest::delayTooLittleFrames() { + #ifdef CORRADE_NO_ASSERT + CORRADE_SKIP("CORRADE_NO_ASSERT defined, can't test assertions"); + #endif + + std::ostringstream out; + Error redirectError{&out}; + FrameProfiler profiler{{ + FrameProfiler::Measurement{"", FrameProfiler::Units::Count, 3, + nullptr, nullptr, nullptr, nullptr} + }, 2}; + CORRADE_COMPARE(out.str(), "DebugTools::FrameProfiler::setup(): max delay 3 is larger than max frame count 2\n"); +} + +void FrameProfilerTest::startStopFrameUnexpected() { + #ifdef CORRADE_NO_ASSERT + CORRADE_SKIP("CORRADE_NO_ASSERT defined, can't test assertions"); + #endif + + FrameProfiler profiler; + + std::ostringstream out; + { + Error redirectError{&out}; + profiler.endFrame(); + } + profiler.beginFrame(); /* this is not an error */ + { + Error redirectError{&out}; + profiler.beginFrame(); + } + CORRADE_COMPARE(out.str(), + "DebugTools::FrameProfiler::endFrame(): expected begin of frame\n" + "DebugTools::FrameProfiler::beginFrame(): expected end of frame\n"); +} + +void FrameProfilerTest::measurementOutOfBounds() { + #ifdef CORRADE_NO_ASSERT + CORRADE_SKIP("CORRADE_NO_ASSERT defined, can't test assertions"); + #endif + + FrameProfiler profiler{{ + FrameProfiler::Measurement{"", FrameProfiler::Units::Count, + nullptr, nullptr, nullptr}, + FrameProfiler::Measurement{"", FrameProfiler::Units::Count, + nullptr, nullptr, nullptr} + }, 1}; + + std::ostringstream out; + Error redirectError{&out}; + profiler.measurementName(2); + profiler.measurementUnits(2); + profiler.measurementDelay(2); + profiler.measurementMean(2); + CORRADE_COMPARE(out.str(), + "DebugTools::FrameProfiler::measurementName(): index 2 out of range for 2 measurements\n" + "DebugTools::FrameProfiler::measurementUnits(): index 2 out of range for 2 measurements\n" + "DebugTools::FrameProfiler::measurementDelay(): index 2 out of range for 2 measurements\n" + "DebugTools::FrameProfiler::measurementMean(): index 2 out of range for 2 measurements\n"); +} + +void FrameProfilerTest::dataNotAvailableYet() { + #ifdef CORRADE_NO_ASSERT + CORRADE_SKIP("CORRADE_NO_ASSERT defined, can't test assertions"); + #endif + + FrameProfiler profiler{{ + FrameProfiler::Measurement{"", FrameProfiler::Units::Count, 3, + [](void*, UnsignedInt) {}, + [](void*, UnsignedInt) {}, + [](void*, UnsignedInt, UnsignedInt) { return UnsignedLong{}; }, nullptr}, + }, 5}; + + profiler.beginFrame(); + profiler.endFrame(); + CORRADE_COMPARE(profiler.measurementDelay(0), 3); + CORRADE_COMPARE(profiler.measuredFrameCount(), 1); + CORRADE_VERIFY(!profiler.isMeasurementAvailable(0)); + + std::ostringstream out; + Error redirectError{&out}; + profiler.measurementMean(0); + CORRADE_COMPARE(out.str(), + "DebugTools::FrameProfiler::measurementMean(): measurement data available after 2 more frames\n"); +} + +void FrameProfilerTest::statistics() { + UnsignedLong time = 0; + FrameProfiler profiler{{ + FrameProfiler::Measurement{ + "Lag", FrameProfiler::Units::Nanoseconds, 2, + [](void*, UnsignedInt) {}, + [](void*, UnsignedInt) {}, + [](void* state, UnsignedInt, UnsignedInt) { + return *static_cast(state) += 15; + }, &time}, + FrameProfiler::Measurement{ + "Bloat", FrameProfiler::Units::Bytes, + [](void*) {}, + [](void*) { + return UnsignedLong{1007300*1024*1024ull}; + }, nullptr}, + FrameProfiler::Measurement{ + "Age", FrameProfiler::Units::Nanoseconds, + [](void*) {}, + [](void*) { + return UnsignedLong{273*1000*1000}; + }, nullptr}, + FrameProfiler::Measurement{ + "GC", FrameProfiler::Units::Nanoseconds, 3, + [](void*, UnsignedInt) {}, + [](void*, UnsignedInt) {}, + [](void*, UnsignedInt, UnsignedInt) { + return UnsignedLong{52660}; + }, nullptr}, + FrameProfiler::Measurement{ + "Optimizations", FrameProfiler::Units::Count, + [](void*) {}, + [](void*) { + return UnsignedLong{0}; + }, nullptr}, + FrameProfiler::Measurement{ + "Frame time", FrameProfiler::Units::Nanoseconds, + [](void*) {}, + [](void*) { + return UnsignedLong{1000*1000*1000ull}; + }, nullptr}, + FrameProfiler::Measurement{ + "Sanity ratio", FrameProfiler::Units::RatioThousandths, + [](void*) {}, + [](void*) { + return UnsignedLong{855}; + }, nullptr}, + FrameProfiler::Measurement{ + "CPU usage", FrameProfiler::Units::PercentageThousandths, + [](void*) {}, + [](void*) { + return UnsignedLong{98655}; + }, nullptr} + }, 3}; + + CORRADE_COMPARE(profiler.statistics(), + "Last 0 frames:\n" + " Lag: -.-- s\n" + " Bloat: -.-- B\n" + " Age: -.-- s\n" + " GC: -.-- s\n" + " Optimizations: -.--\n" + " Frame time: -.-- s\n" + " Sanity ratio: -.--\n" + " CPU usage: -.-- %"); + + profiler.beginFrame(); + profiler.endFrame(); + + CORRADE_COMPARE(profiler.statistics(), + "Last 1 frames:\n" + " Lag: -.-- s\n" + " Bloat: 983.69 GB\n" + " Age: 273.00 ms\n" + " GC: -.-- s\n" + " Optimizations: 0.00\n" + " Frame time: 1.00 s\n" + " Sanity ratio: 0.85\n" + " CPU usage: 98.66 %"); + + profiler.beginFrame(); + profiler.endFrame(); + profiler.beginFrame(); + profiler.endFrame(); + profiler.beginFrame(); + profiler.endFrame(); + profiler.beginFrame(); + profiler.endFrame(); + profiler.beginFrame(); + profiler.endFrame(); + + CORRADE_COMPARE(profiler.statistics(), + "Last 3 frames:\n" + " Lag: 60.00 ns\n" + " Bloat: 983.69 GB\n" + " Age: 273.00 ms\n" + " GC: 52.66 µs\n" + " Optimizations: 0.00\n" + " Frame time: 1.00 s\n" + " Sanity ratio: 0.85\n" + " CPU usage: 98.66 %"); + + /* Disabling should print the last known state */ + profiler.disable(); + CORRADE_COMPARE(profiler.statistics(), + "Last 3 frames:\n" + " Lag: 60.00 ns\n" + " Bloat: 983.69 GB\n" + " Age: 273.00 ms\n" + " GC: 52.66 µs\n" + " Optimizations: 0.00\n" + " Frame time: 1.00 s\n" + " Sanity ratio: 0.85\n" + " CPU usage: 98.66 %"); + + /* Enabling again should go back to initial state */ + profiler.enable(); + CORRADE_COMPARE(profiler.statistics(), + "Last 0 frames:\n" + " Lag: -.-- s\n" + " Bloat: -.-- B\n" + " Age: -.-- s\n" + " GC: -.-- s\n" + " Optimizations: -.--\n" + " Frame time: -.-- s\n" + " Sanity ratio: -.--\n" + " CPU usage: -.-- %"); +} + +#ifdef MAGNUM_TARGET_GL +void FrameProfilerTest::gl() { + auto&& data = GLData[testCaseInstanceId()]; + setTestCaseDescription(data.name); + + /* Test that we use the right state pointers to survive a move */ + Containers::Pointer profiler_{Containers::InPlaceInit, + data.values, 4u}; + GLFrameProfiler profiler = std::move(*profiler_); + profiler_ = nullptr; + CORRADE_COMPARE(profiler.values(), data.values); + CORRADE_COMPARE(profiler.maxFrameCount(), 4); + CORRADE_COMPARE(profiler.measurementCount(), data.measurementCount); + + for(auto value: {GLFrameProfiler::Value::CpuDuration, + GLFrameProfiler::Value::FrameTime}) + if(data.values & value) + CORRADE_VERIFY(!profiler.isMeasurementAvailable(value)); + + profiler.beginFrame(); + Utility::System::sleep(1); + profiler.endFrame(); + + profiler.beginFrame(); + profiler.endFrame(); + + Utility::System::sleep(10); + + profiler.beginFrame(); + Utility::System::sleep(1); + profiler.endFrame(); + + profiler.beginFrame(); + Utility::System::sleep(1); + profiler.endFrame(); + + for(std::size_t i = 0; i != data.measurementCount; ++i) + CORRADE_VERIFY(profiler.isMeasurementAvailable(i)); + + /* 3/4 frames took 1 ms, the ideal average is 0.75 ms. Can't test upper + bound because (especially on overloaded CIs) it all takes a magnitude + more than expected. Emscripten builds have it as low as 0.5, account for + that. */ + if(data.values & GLFrameProfiler::Value::CpuDuration) { + CORRADE_VERIFY(profiler.isMeasurementAvailable(GLFrameProfiler::Value::CpuDuration)); + CORRADE_COMPARE_AS(profiler.cpuDurationMean(), 0.50*1000*1000, + TestSuite::Compare::GreaterOrEqual); + } + + /* 3/4 frames took 1 ms, and one 10 ms, the ideal average is 3.25 ms. Can't + test upper bound because (especially on overloaded CIs) it all takes a + magnitude more than expected. */ + if(data.values & GLFrameProfiler::Value::FrameTime) { + CORRADE_VERIFY(profiler.isMeasurementAvailable(GLFrameProfiler::Value::FrameTime)); + CORRADE_COMPARE_AS(profiler.frameTimeMean(), 3.20*1000*1000, + TestSuite::Compare::GreaterOrEqual); + } + + /* GPU time tested separately */ +} + +void FrameProfilerTest::glNotEnabled() { + #ifdef CORRADE_NO_ASSERT + CORRADE_SKIP("CORRADE_NO_ASSERT defined, can't test assertions"); + #endif + + GLFrameProfiler profiler{{}, 5}; + + std::ostringstream out; + Error redirectError{&out}; + profiler.isMeasurementAvailable(GLFrameProfiler::Value::CpuDuration); + profiler.frameTimeMean(); + profiler.cpuDurationMean(); + profiler.gpuDurationMean(); + CORRADE_COMPARE(out.str(), + "DebugTools::GLFrameProfiler::isMeasurementAvailable(): DebugTools::GLFrameProfiler::Value::CpuDuration not enabled\n" + "DebugTools::GLFrameProfiler::frameTimeMean(): not enabled\n" + "DebugTools::GLFrameProfiler::cpuDurationMean(): not enabled\n" + "DebugTools::GLFrameProfiler::gpuDurationMean(): not enabled\n"); +} +#endif + +void FrameProfilerTest::debugUnits() { + std::ostringstream out; + + Debug{&out} << FrameProfiler::Units::Nanoseconds << FrameProfiler::Units(0xf0); + CORRADE_COMPARE(out.str(), "DebugTools::FrameProfiler::Units::Nanoseconds DebugTools::FrameProfiler::Units(0xf0)\n"); +} + +#ifdef MAGNUM_TARGET_GL +void FrameProfilerTest::debugGLValue() { + std::ostringstream out; + + Debug{&out} << GLFrameProfiler::Value::GpuDuration << GLFrameProfiler::Value(0xfff0); + CORRADE_COMPARE(out.str(), "DebugTools::GLFrameProfiler::Value::GpuDuration DebugTools::GLFrameProfiler::Value(0xfff0)\n"); +} + +void FrameProfilerTest::debugGLValues() { + std::ostringstream out; + + Debug{&out} << (GLFrameProfiler::Value::CpuDuration|GLFrameProfiler::Value::FrameTime) << GLFrameProfiler::Values{}; + CORRADE_COMPARE(out.str(), "DebugTools::GLFrameProfiler::Value::FrameTime|DebugTools::GLFrameProfiler::Value::CpuDuration DebugTools::GLFrameProfiler::Values{}\n"); +} +#endif + +}}}} + +CORRADE_TEST_MAIN(Magnum::DebugTools::Test::FrameProfilerTest)