sam/sfizz
1
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions

Removed cout logging and put the wait time with load times

Browse source
This commit is contained in:
Paul Ferrand 2020-01-14 01:07:15 +01:00
parent c3d5a06082
commit 24bd0d8119
4 changed files with 57 additions and 62 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

3
src/sfizz/FilePool.cpp
View file

@ -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<float>(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--;

83
src/sfizz/Logger.cpp
View file

@ -2,6 +2,7 @@
#include "absl/algorithm/container.h"
#include "ghc/fs_std.hpp"
#include <iostream>
#include <fstream>
#include <cmath>
using namespace std::chrono_literals;
@ -19,13 +20,16 @@ void printStatistics(std::vector<T>& data)
const auto sum = absl::c_accumulate(data, 0.0);
const auto size = static_cast<T>(data.size());
const auto mean = sum / size;
std::vector<T> 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<T> 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<double> loadTimesStats;
std::vector<double> 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<double>(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<double> 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<double> 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<double> value)
void sfz::Logger::logCallbackTime(std::chrono::duration<double> duration, int numVoices, int numSamples)
{
callbackTimeQueue.try_push(value);
callbackTimeQueue.try_push<CallbackTime>({ duration, numVoices, numSamples });
}
void sfz::Logger::logFileWaitTime(std::chrono::duration<double> value)
void sfz::Logger::logFileTime(std::chrono::duration<double> waitDuration, std::chrono::duration<double> loadDuration, uint32_t fileSize, absl::string_view filename)
{
fileWaitTimeQueue.try_push(value);
}
void sfz::Logger::logFileLoadTime(std::chrono::duration<double> value, uint32_t fileSize, absl::string_view filename)
{
FileLoadTime toPush { value, fileSize, filename };
fileLoadTimeQueue.try_push(toPush);
fileTimeQueue.try_push<FileTime>({ waitDuration, loadDuration, fileSize, filename });
}
void sfz::Logger::moveEvents()
{
while(keepRunning.test_and_set()) {
std::chrono::duration<double> callbackTime;
CallbackTime callbackTime;
while (callbackTimeQueue.try_pop(callbackTime))
callbackTimes.push_back(callbackTime);
std::chrono::duration<double> 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);
}

29
src/sfizz/Logger.h
View file

@ -32,29 +32,36 @@
namespace sfz
{
struct FileLoadTime
struct FileTime
{
std::chrono::duration<double> value;
std::chrono::duration<double> waitDuration;
std::chrono::duration<double> loadDuration;
uint32_t fileSize;
absl::string_view filename;
};
struct CallbackTime
{
std::chrono::duration<double> duration;
int numVoices;
int numSamples;
};
class Logger
{
public:
Logger() = default;
~Logger();
void logCallbackTime(std::chrono::duration<double> value);
void logFileWaitTime(std::chrono::duration<double> value);
void logFileLoadTime(std::chrono::duration<double> value, uint32_t fileSize, absl::string_view filename);
void logCallbackTime(std::chrono::duration<double> duration, int numVoices, int numSamples);
void logFileTime(std::chrono::duration<double> waitDuration, std::chrono::duration<double> loadDuration, uint32_t fileSize, absl::string_view filename);
private:
void moveEvents();
atomic_queue::AtomicQueue2<std::chrono::duration<double>, config::loggerQueueSize, true, true, false, true> callbackTimeQueue;
atomic_queue::AtomicQueue2<FileLoadTime, config::loggerQueueSize, true, true, false, true> fileLoadTimeQueue;
atomic_queue::AtomicQueue2<std::chrono::duration<double>, config::loggerQueueSize, true, true, false, true> fileWaitTimeQueue;
std::vector<std::chrono::duration<double>> callbackTimes;
std::vector<FileLoadTime> loadTimes;
std::vector<std::chrono::duration<double>> waitTimes;
atomic_queue::AtomicQueue2<CallbackTime, config::loggerQueueSize, true, true, false, true> callbackTimeQueue;
atomic_queue::AtomicQueue2<FileTime, config::loggerQueueSize, true, true, false, true> fileTimeQueue;
std::vector<CallbackTime> callbackTimes;
std::vector<FileTime> fileTimes;
std::atomic_flag keepRunning;
std::thread loggingThread { &Logger::moveEvents, this };
};

4
src/sfizz/Synth.cpp
View file

@ -391,8 +391,10 @@ void sfz::Synth::renderBlock(AudioSpan<float> buffer) noexcept
return;
auto tempSpan = AudioSpan<float>(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<float> 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