From 24bd0d81196113579184dea6dbbe4dab68f0eb8b Mon Sep 17 00:00:00 2001 From: Paul Ferrand Date: Tue, 14 Jan 2020 01:07:15 +0100 Subject: [PATCH] Removed cout logging and put the wait time with load times --- src/sfizz/FilePool.cpp | 3 +- src/sfizz/Logger.cpp | 83 ++++++++++++++++++------------------------ src/sfizz/Logger.h | 29 +++++++++------ src/sfizz/Synth.cpp | 4 +- 4 files changed, 57 insertions(+), 62 deletions(-) diff --git a/src/sfizz/FilePool.cpp b/src/sfizz/FilePool.cpp index b8b2f81b..f4717755 100644 --- a/src/sfizz/FilePool.cpp +++ b/src/sfizz/FilePool.cpp @@ -247,7 +247,6 @@ void sfz::FilePool::loadingThread() noexcept threadsLoading++; const auto loadStartTime = std::chrono::high_resolution_clock::now(); const auto waitDuration = loadStartTime - promise->creationTime; - logger.logFileWaitTime(waitDuration); fs::path file { rootDirectory / std::string(promise->filename) }; SndfileHandle sndFile(file.string().c_str()); @@ -259,7 +258,7 @@ void sfz::FilePool::loadingThread() noexcept streamFromFile(sndFile, frames, oversamplingFactor, promise->fileData, &promise->availableFrames); promise->dataReady = true; const auto loadDuration = std::chrono::high_resolution_clock::now() - loadStartTime; - logger.logFileLoadTime(loadDuration, frames, promise->filename); + logger.logFileTime(waitDuration, loadDuration, frames, promise->filename); threadsLoading--; diff --git a/src/sfizz/Logger.cpp b/src/sfizz/Logger.cpp index 451b84f9..1e3bc157 100644 --- a/src/sfizz/Logger.cpp +++ b/src/sfizz/Logger.cpp @@ -2,6 +2,7 @@ #include "absl/algorithm/container.h" #include "ghc/fs_std.hpp" #include +#include #include using namespace std::chrono_literals; @@ -19,13 +20,16 @@ void printStatistics(std::vector& data) const auto sum = absl::c_accumulate(data, 0.0); const auto size = static_cast(data.size()); const auto mean = sum / size; - std::vector squares; - absl::c_transform(data, std::back_inserter(squares), [mean](T x) { return x * x; }); - const auto sumOfSquares = absl::c_accumulate(squares, 0.0); - const auto variance = sumOfSquares / (size - 1.0) - (mean * mean) / size / (size - 1.0); std::cout << "Mean: " << mean << '\n'; - std::cout << "Variance: " << variance << '\n'; - std::cout << "(Biased) deviation: " << std::sqrt(variance) << '\n'; + if (data.size() > 1) { + std::vector squares; + absl::c_transform(data, std::back_inserter(squares), [mean](T x) { return x * x; }); + const auto sumOfSquares = absl::c_accumulate(squares, 0.0); + const auto variance = sumOfSquares / (size - 1.0) - (mean * mean) / size / (size - 1.0); + std::cout << "Variance: " << variance << '\n'; + std::cout << "(Biased) deviation: " << std::sqrt(variance) << '\n'; + } + std::cout << "Maximum values:"; for (auto& value: maxValues) std::cout << value << ' '; @@ -37,66 +41,49 @@ sfz::Logger::~Logger() keepRunning.clear(); loggingThread.join(); - if (!loadTimes.empty()) { - std::vector loadTimesStats; - std::vector normLoadTimesStats; - absl::c_transform(loadTimes, std::back_inserter(loadTimesStats), [](auto x) { return x.value.count(); }); - absl::c_transform(loadTimes, std::back_inserter(normLoadTimesStats), [](auto x) { - if (x.fileSize == 0) - return x.value.count(); - - return x.value.count() / static_cast(x.fileSize); - }); - std::cout << "\nFile load times" << '\n'; - printStatistics(loadTimesStats); - std::cout << "\nNormalized file load times (per sample)" << '\n'; - printStatistics(normLoadTimesStats); - } - - if (!waitTimes.empty()) { - std::vector waitTimesStats; - absl::c_transform(waitTimes, std::back_inserter(waitTimesStats), [](auto x) { return x.count(); }); - std::cout << "\nWaiting times" << '\n'; - printStatistics(waitTimesStats); + if (!fileTimes.empty()) { + fs::path loadLogPath{ fs::current_path() / "file_times.csv" }; + std::ofstream loadLogFile { loadLogPath.string() }; + loadLogFile << "WaitDuration,LoadDuration,FileSize,FileName" << '\n'; + for (auto& time: fileTimes) + loadLogFile << time.waitDuration.count() << ',' + << time.loadDuration.count() << ',' + << time.fileSize << ',' + << time.filename << '\n'; } if (!callbackTimes.empty()) { - std::vector callbackTimesStats; - absl::c_transform(callbackTimes, std::back_inserter(callbackTimesStats), [](auto x) { return x.count(); }); - std::cout << "\nCallback times" << '\n'; - printStatistics(callbackTimesStats); + fs::path callbackLogPath{ fs::current_path() / "callback_times.csv" }; + std::ofstream callbackLogFile { callbackLogPath.string() }; + callbackLogFile << "Duration,NumVoices,NumSamples" << '\n'; + for (auto& time: callbackTimes) + callbackLogFile << time.duration.count() << ',' + << time.numVoices << ',' + << time.numSamples << '\n'; } } -void sfz::Logger::logCallbackTime(std::chrono::duration value) +void sfz::Logger::logCallbackTime(std::chrono::duration duration, int numVoices, int numSamples) { - callbackTimeQueue.try_push(value); + callbackTimeQueue.try_push({ duration, numVoices, numSamples }); } -void sfz::Logger::logFileWaitTime(std::chrono::duration value) + +void sfz::Logger::logFileTime(std::chrono::duration waitDuration, std::chrono::duration loadDuration, uint32_t fileSize, absl::string_view filename) { - fileWaitTimeQueue.try_push(value); -} -void sfz::Logger::logFileLoadTime(std::chrono::duration value, uint32_t fileSize, absl::string_view filename) -{ - FileLoadTime toPush { value, fileSize, filename }; - fileLoadTimeQueue.try_push(toPush); + fileTimeQueue.try_push({ waitDuration, loadDuration, fileSize, filename }); } void sfz::Logger::moveEvents() { while(keepRunning.test_and_set()) { - std::chrono::duration callbackTime; + CallbackTime callbackTime; while (callbackTimeQueue.try_pop(callbackTime)) callbackTimes.push_back(callbackTime); - std::chrono::duration waitTime; - while (fileWaitTimeQueue.try_pop(waitTime)) - waitTimes.push_back(waitTime); - - sfz::FileLoadTime loadTime; - while (fileLoadTimeQueue.try_pop(loadTime)) - loadTimes.push_back(loadTime); + sfz::FileTime fileTime; + while (fileTimeQueue.try_pop(fileTime)) + fileTimes.push_back(fileTime); std::this_thread::sleep_for(50ms); } diff --git a/src/sfizz/Logger.h b/src/sfizz/Logger.h index 2fe6cc31..b6a5c142 100644 --- a/src/sfizz/Logger.h +++ b/src/sfizz/Logger.h @@ -32,29 +32,36 @@ namespace sfz { -struct FileLoadTime +struct FileTime { - std::chrono::duration value; + std::chrono::duration waitDuration; + std::chrono::duration loadDuration; uint32_t fileSize; absl::string_view filename; }; +struct CallbackTime +{ + std::chrono::duration duration; + int numVoices; + int numSamples; +}; + class Logger { public: Logger() = default; ~Logger(); - void logCallbackTime(std::chrono::duration value); - void logFileWaitTime(std::chrono::duration value); - void logFileLoadTime(std::chrono::duration value, uint32_t fileSize, absl::string_view filename); + void logCallbackTime(std::chrono::duration duration, int numVoices, int numSamples); + void logFileTime(std::chrono::duration waitDuration, std::chrono::duration loadDuration, uint32_t fileSize, absl::string_view filename); private: void moveEvents(); - atomic_queue::AtomicQueue2, config::loggerQueueSize, true, true, false, true> callbackTimeQueue; - atomic_queue::AtomicQueue2 fileLoadTimeQueue; - atomic_queue::AtomicQueue2, config::loggerQueueSize, true, true, false, true> fileWaitTimeQueue; - std::vector> callbackTimes; - std::vector loadTimes; - std::vector> waitTimes; + + atomic_queue::AtomicQueue2 callbackTimeQueue; + atomic_queue::AtomicQueue2 fileTimeQueue; + std::vector callbackTimes; + std::vector fileTimes; + std::atomic_flag keepRunning; std::thread loggingThread { &Logger::moveEvents, this }; }; diff --git a/src/sfizz/Synth.cpp b/src/sfizz/Synth.cpp index b8e75aed..7fd285d4 100644 --- a/src/sfizz/Synth.cpp +++ b/src/sfizz/Synth.cpp @@ -391,8 +391,10 @@ void sfz::Synth::renderBlock(AudioSpan buffer) noexcept return; auto tempSpan = AudioSpan(tempBuffer).first(buffer.getNumFrames()); + int numActiveVoices { 0 }; for (auto& voice : voices) { if (!voice->isFree()) { + numActiveVoices++; voice->renderBlock(tempSpan); buffer.add(tempSpan); } @@ -401,7 +403,7 @@ void sfz::Synth::renderBlock(AudioSpan buffer) noexcept buffer.applyGain(db2mag(volume)); const auto callbackDuration = std::chrono::high_resolution_clock::now() - callbackStartTime; - resources.logger.logCallbackTime(callbackDuration); + resources.logger.logCallbackTime(callbackDuration, numActiveVoices, buffer.getNumFrames()); } void sfz::Synth::noteOn(int delay, int noteNumber, uint8_t velocity) noexcept