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

Logging is not implicitely handled by the synth

Browse source 
You need a call to get the callback breakdown each frame.
sfizz_render has been updated to make use of this.
This commit is contained in:
Paul Fd 2021-11-20 01:08:01 +01:00
parent fbc0e7459a
commit 7f352170a6
20 changed files with 252 additions and 422 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

37
clients/sfizz_render.cpp
View file

@ -8,6 +8,7 @@
#include <cxxopts.hpp>
#include <fmidi/fmidi.h>
#include <iostream>
#include <fstream>
#define LOG_ERROR(ostream) std::cerr << ostream << '\n'
#define LOG_INFO(ostream) if (verbose) { std::cout << ostream << '\n'; }
@ -125,8 +126,38 @@ int main(int argc, char** argv)
synth.setNumVoices(polyphony);
synth.enableFreeWheeling();
if (params.count("log") > 0)
synth.enableLogging(params["log"].as<std::string>());
bool logging = params.count("log") > 0;
std::string logFilename {};
std::ofstream callbackLogFile {};
if (logging) {
logFilename = params["log"].as<std::string>();
fs::path logPath{ fs::current_path() / logFilename };
callbackLogFile.open(logPath.string());
if (callbackLogFile.is_open()) {
callbackLogFile << "Dispatch,RenderMethod,Data,Amplitude,Filters,Panning,Effects,NumVoices,NumSamples" << '\n';
} else {
logging = false;
LOG_INFO("Error opening log file " << logPath.string() << "; logging will be disabled");
}
}
auto writeLogLine = [&] {
if (!logging)
return;
auto breakdown = synth.getCallbackBreakdown();
auto numVoices = synth.getNumActiveVoices();
callbackLogFile << breakdown.dispatch << ','
<< breakdown.renderMethod << ','
<< breakdown.data << ','
<< breakdown.amplitude << ','
<< breakdown.filters << ','
<< breakdown.panning << ','
<< breakdown.effects << ','
<< numVoices << ','
<< blockSize << '\n';
};
ERROR_IF(!synth.loadSfzFile(sfzPath), "There was an error loading the SFZ file.");
LOG_INFO(synth.getNumRegions() << " regions in the SFZ.");
@ -178,6 +209,7 @@ int main(int argc, char** argv)
sfz::writeInterleaved(audioBuffer.getConstSpan(0), audioBuffer.getConstSpan(1), absl::MakeSpan(interleavedBuffer));
drwav_f32_to_s16(interleavedPcm.data(), interleavedBuffer.data(), 2 * blockSize);
numFramesWritten += drwav_write_pcm_frames(&outputFile, blockSize, interleavedPcm.data());
writeLogLine();
}
if (!useEOT) {
@ -187,6 +219,7 @@ int main(int argc, char** argv)
sfz::writeInterleaved(audioBuffer.getConstSpan(0), audioBuffer.getConstSpan(1), absl::MakeSpan(interleavedBuffer));
drwav_f32_to_s16(interleavedPcm.data(), interleavedBuffer.data(), 2 * blockSize);
numFramesWritten += drwav_write_pcm_frames(&outputFile, blockSize, interleavedPcm.data());
writeLogLine();
averagePower = sfz::meanSquared<float>(interleavedBuffer);
}
}

1
common.mk
View file

@ -91,7 +91,6 @@ SFIZZ_SOURCES = \
src/sfizz/FlexEnvelope.cpp \
src/sfizz/Interpolators.cpp \
src/sfizz/Layer.cpp \
src/sfizz/Logger.cpp \
src/sfizz/LFO.cpp \
src/sfizz/LFODescription.cpp \
src/sfizz/Messaging.cpp \

1
scripts/run_clang_tidy.sh
View file

@ -7,7 +7,6 @@ clang-tidy \
src/sfizz/EQPool.cpp \
src/sfizz/FilePool.cpp \
src/sfizz/FilterPool.cpp \
src/sfizz/Logger.cpp \
src/sfizz/MidiState.cpp \
src/sfizz/Opcode.cpp \
src/sfizz/Oversampler.cpp \

3
src/CMakeLists.txt
View file

@ -29,6 +29,7 @@ set(SFIZZ_HEADERS
sfizz/utility/NumericId.h
sfizz/utility/StringViewHelpers.h
sfizz/utility/SwapAndPop.h
sfizz/utility/Timing.h
sfizz/utility/XmlHelpers.h
sfizz/modulations/ModId.h
sfizz/modulations/ModKey.h
@ -76,7 +77,6 @@ set(SFIZZ_HEADERS
sfizz/Interpolators.h
sfizz/Interpolators.hpp
sfizz/Layer.h
sfizz/Logger.h
sfizz/LFO.h
sfizz/LFOCommon.h
sfizz/LFOCommon.hpp
@ -137,7 +137,6 @@ set(SFIZZ_SOURCES
sfizz/MidiState.cpp
sfizz/Oversampler.cpp
sfizz/ADSREnvelope.cpp
sfizz/Logger.cpp
sfizz/SfzFilter.cpp
sfizz/Curve.cpp
sfizz/Smoothers.cpp

37
src/sfizz.h
View file

@ -971,6 +971,7 @@ SFIZZ_EXPORTED_API bool sfizz_should_reload_scala(sfizz_synth_t* synth);
* @since 0.3.0
*
* @note This can produce many outputs so use with caution.
* Deprecated since 1.2.0.
*
* @param synth The synth.
* @param prefix The prefix.
@ -978,24 +979,26 @@ SFIZZ_EXPORTED_API bool sfizz_should_reload_scala(sfizz_synth_t* synth);
* @par Thread-safety constraints
* - TBD ?
*/
SFIZZ_EXPORTED_API void sfizz_enable_logging(sfizz_synth_t* synth, const char* prefix);
SFIZZ_EXPORTED_API SFIZZ_DEPRECATED_API void sfizz_enable_logging(sfizz_synth_t* synth, const char* prefix);
/**
* @brief Disable logging.
* @since 0.3.0
*
* @param synth The synth.
* Deprecated since 1.2.0.
*
* @par Thread-safety constraints
* - TBD ?
*/
SFIZZ_EXPORTED_API void sfizz_disable_logging(sfizz_synth_t* synth);
SFIZZ_EXPORTED_API SFIZZ_DEPRECATED_API void sfizz_disable_logging(sfizz_synth_t* synth);
/**
* @brief Enable logging of timings to sidecar CSV files.
* @since 0.3.2
*
* @note This can produce many outputs so use with caution.
* Deprecated since 1.2.0.
*
* @param synth The synth.
* @param prefix The prefix.
@ -1005,6 +1008,36 @@ SFIZZ_EXPORTED_API void sfizz_disable_logging(sfizz_synth_t* synth);
*/
SFIZZ_EXPORTED_API SFIZZ_DEPRECATED_API void sfizz_set_logging_prefix(sfizz_synth_t* synth, const char* prefix);
/**
* @brief The callback breakdown structure.
* @note Times are in seconds.
*/
typedef struct
{
double dispatch;
double renderMethod;
double data;
double amplitude;
double filters;
double panning;
double effects;
} sfizz_callback_breakdown_t;
/**
* @brief Get the last callback breakdown. Call after a render method.
*
* @since 1.2.0
*
* @param synth
* @param breakdown
*
* @return CallbackBreakdown
*
* @par Thread-safety constraints
* - @b RT: the function must be invoked from the Real-time thread
*/
SFIZZ_EXPORTED_API void sfizz_get_callback_breakdown(sfizz_synth_t* synth, sfizz_callback_breakdown_t* breakdown);
/**
* @brief Shuts down the current processing, clear buffers and reset the voices.
* @since 0.3.2

31
src/sfizz.hpp
View file

@ -910,21 +910,24 @@ public:
* @since 0.3.2
*
* @note This can produce many outputs so use with caution.
* Deprecated since 1.2.0
*
* @param prefix the file prefix to use for logging.
*
* @par Thread-safety constraints
* - TBD ?
*/
void enableLogging(const std::string& prefix) noexcept;
SFIZZ_DEPRECATED_API void enableLogging(const std::string& prefix) noexcept;
/**
* @brief Set the logging prefix.
*
* @since 0.3.2
* @note Deprecated since 1.2.0
*
* @param prefix
*
*
* @par Thread-safety constraints
* - TBD ?
*/
@ -934,11 +937,35 @@ public:
* @brief Disable logging of timings to sidecar CSV files.
*
* @since 0.3.0
* @note Deprecated since 1.2.0
*
* @par Thread-safety constraints
* - TBD ?
*/
void disableLogging() noexcept;
SFIZZ_DEPRECATED_API void disableLogging() noexcept;
struct CallbackBreakdown
{
double dispatch;
double renderMethod;
double data;
double amplitude;
double filters;
double panning;
double effects;
};
/**
* @brief Get the last callback breakdown. Call after a render method.
*
* @since 1.2.0
*
* @par Thread-safety constraints
* - @b RT: the function must be invoked from the Real-time thread
*
* @return CallbackBreakdown
*/
CallbackBreakdown getCallbackBreakdown() noexcept;
/**
* @brief Shuts down the current processing, clear buffers and reset the voices.

12
src/sfizz/FilePool.cpp
View file

@ -140,9 +140,8 @@ void streamFromFile(sfz::AudioReader& reader, sfz::FileAudioBuffer& output, std:
}
}
sfz::FilePool::FilePool(sfz::Logger& logger)
: logger(logger),
filesToLoad(alignedNew<FileQueue>()),
sfz::FilePool::FilePool()
: filesToLoad(alignedNew<FileQueue>()),
threadPool(globalThreadPool())
{
loadingJobs.reserve(config::maxVoices);
@ -396,7 +395,7 @@ sfz::FileDataHolder sfz::FilePool::getFilePromise(const std::shared_ptr<FileId>&
DBG("[sfizz] File not found in the preloaded files: " << fileId->filename());
return {};
}
QueuedFileData queuedData { fileId, &preloaded->second, std::chrono::high_resolution_clock::now() };
QueuedFileData queuedData { fileId, &preloaded->second };
if (!filesToLoad->try_push(queuedData)) {
DBG("[sfizz] Could not enqueue the file to load for " << fileId << " (queue capacity " << filesToLoad->capacity() << ")");
return {};
@ -434,8 +433,6 @@ void sfz::FilePool::loadingJob(const QueuedFileData& data) noexcept
return;
}
const auto loadStartTime = std::chrono::high_resolution_clock::now();
const auto waitDuration = loadStartTime - data.queuedTime;
const fs::path file { rootDirectory / id->filename() };
std::error_code readError;
AudioReaderPtr reader = createAudioReader(file, id->isReverse(), &readError);
@ -468,10 +465,7 @@ void sfz::FilePool::loadingJob(const QueuedFileData& data) noexcept
if (!data.data->status.compare_exchange_strong(currentStatus, FileData::Status::Streaming))
return;
const auto frames = static_cast<uint32_t>(reader->frames());
streamFromFile(*reader, data.data->fileData, &data.data->availableFrames);
const auto loadDuration = std::chrono::high_resolution_clock::now() - loadStartTime;
logger.logFileTime(waitDuration, loadDuration, frames, id->filename());
data.data->status = FileData::Status::Done;

13
src/sfizz/FilePool.h
View file

@ -32,8 +32,8 @@
#include "FileId.h"
#include "FileMetadata.h"
#include "SIMDHelpers.h"
#include "Logger.h"
#include "SpinMutex.h"
#include "utility/Timing.h"
#include "utility/LeakDetector.h"
#include "utility/MemoryHelpers.h"
#include <ghc/fs_std.hpp>
@ -148,7 +148,7 @@ public:
return;
data->readerCount -= 1;
data->lastViewerLeftAt = std::chrono::high_resolution_clock::now();
data->lastViewerLeftAt = highResNow();
data = nullptr;
}
~FileDataHolder()
@ -192,7 +192,7 @@ public:
* This creates the background threads based on config::numBackgroundThreads
* as well as the garbage collection thread.
*/
FilePool(Logger& logger);
FilePool();
~FilePool();
/**
@ -325,7 +325,6 @@ public:
*/
void triggerGarbageCollection() noexcept;
private:
Logger& logger;
fs::path rootDirectory;
bool loadInRam { config::loadInRam };
@ -340,13 +339,11 @@ private:
// Structures for the background loaders
struct QueuedFileData
{
using TimePoint = std::chrono::time_point<std::chrono::high_resolution_clock>;
QueuedFileData() noexcept {}
QueuedFileData(std::weak_ptr<FileId> id, FileData* data, TimePoint queuedTime) noexcept
: id(id), data(data), queuedTime(queuedTime) {}
QueuedFileData(std::weak_ptr<FileId> id, FileData* data) noexcept
: id(id), data(data) {}
std::weak_ptr<FileId> id;
FileData* data { nullptr };
TimePoint queuedTime {};
};
using FileQueue = atomic_queue::AtomicQueue2<QueuedFileData, config::maxVoices>;

186
src/sfizz/Logger.cpp
View file

@ -1,186 +0,0 @@
// SPDX-License-Identifier: BSD-2-Clause
// This code is part of the sfizz library and is licensed under a BSD 2-clause
// license. You should have receive a LICENSE.md file along with the code.
// If not, contact the sfizz maintainers at https://github.com/sfztools/sfizz
#include "Logger.h"
#include "utility/Debug.h"
#include <ghc/fs_std.hpp>
#include <absl/algorithm/container.h>
#include <iostream>
#include <fstream>
#include <sstream>
#include <cmath>
template<class T>
void printStatistics(std::vector<T>& data)
{
absl::c_sort(data);
const auto maxToTake = std::min(data.size(), size_t(10));
std::vector<T> maxValues;
auto it = data.rbegin();
for (size_t i = 0; i < maxToTake; ++i)
maxValues.push_back(*it++);
const auto sum = absl::c_accumulate(data, 0.0);
const auto size = static_cast<T>(data.size());
const auto mean = sum / size;
std::cout << "Mean: " << mean << '\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 << ' ';
std::cout << '\n';
}
sfz::Logger::Logger()
: callbackTimeQueue(alignedNew<CallbackTimeQueue>()),
fileTimeQueue(alignedNew<FileTimeQueue>())
{
keepRunning.test_and_set();
clearFlag.test_and_set();
loggingThread = std::thread(&Logger::moveEvents, this);
}
sfz::Logger::~Logger()
{
keepRunning.clear();
loggingThread.join();
if (!loggingEnabled)
return;
if (!fileTimes.empty()) {
std::stringstream fileLogFilename;
fileLogFilename << this << "_"
<< prefix
<< "_file_log.csv";
fs::path fileLogPath{ fs::current_path() / fileLogFilename.str() };
std::cout << "Logging " << fileTimes.size() << " file times to " << fileLogPath.filename() << '\n';
std::ofstream loadLogFile { fileLogPath.string() };
loadLogFile << "WaitDuration,LoadDuration,FileSize,FileName" << '\n';
for (auto& time: fileTimes)
loadLogFile << time.waitDuration.count() << ','
<< time.loadDuration.count() << ','
<< time.fileSize << ','
<< "disabled" << '\n';
// << time.filename << '\n';
}
if (!callbackTimes.empty()) {
std::stringstream callbackLogFilename;
callbackLogFilename << this << "_"
<< prefix
<< "_callback_log.csv";
fs::path callbackLogPath{ fs::current_path() / callbackLogFilename.str() };
std::cout << "Logging " << callbackTimes.size() << " callback times to " << callbackLogPath.filename() << '\n';
std::ofstream callbackLogFile { callbackLogPath.string() };
callbackLogFile << "Dispatch,RenderMethod,Data,Amplitude,Filters,Panning,Effects,NumVoices,NumSamples" << '\n';
for (auto& time: callbackTimes)
callbackLogFile << time.breakdown.dispatch.count() << ','
<< time.breakdown.renderMethod.count() << ','
<< time.breakdown.data.count() << ','
<< time.breakdown.amplitude.count() << ','
<< time.breakdown.filters.count() << ','
<< time.breakdown.panning.count() << ','
<< time.breakdown.effects.count() << ','
<< time.numVoices << ','
<< time.numSamples << '\n';
}
}
void sfz::Logger::logCallbackTime(const CallbackBreakdown& breakdown, int numVoices, size_t numSamples)
{
if (!loggingEnabled)
return;
CallbackTime callbackTime;
callbackTime.breakdown = breakdown;
callbackTime.numVoices = numVoices;
callbackTime.numSamples = numSamples;
callbackTimeQueue->try_push(callbackTime);
}
void sfz::Logger::logFileTime(std::chrono::duration<double> waitDuration, std::chrono::duration<double> loadDuration, uint32_t fileSize, absl::string_view filename)
{
if (!loggingEnabled)
return;
FileTime fileTime;
fileTime.waitDuration = waitDuration;
fileTime.loadDuration = loadDuration;
fileTime.fileSize = fileSize;
fileTime.filename = filename;
fileTimeQueue->try_push(fileTime);
}
void sfz::Logger::setPrefix(absl::string_view prefix)
{
this->prefix = std::string(prefix);
}
void sfz::Logger::clear()
{
clearFlag.clear();
}
void sfz::Logger::moveEvents() noexcept
{
while(keepRunning.test_and_set()) {
CallbackTime callbackTime;
while (callbackTimeQueue->try_pop(callbackTime))
callbackTimes.push_back(callbackTime);
FileTime fileTime;
while (fileTimeQueue->try_pop(fileTime))
fileTimes.push_back(fileTime);
if (!clearFlag.test_and_set()) {
fileTimes.clear();
callbackTimes.clear();
}
std::this_thread::sleep_for(std::chrono::milliseconds(10));
}
}
void sfz::Logger::enableLogging(absl::string_view prefix)
{
setPrefix(prefix);
loggingEnabled = true;
}
void sfz::Logger::disableLogging()
{
loggingEnabled = false;
clearFlag.clear();
}
sfz::ScopedTiming::ScopedTiming(Duration& targetDuration, Operation operation)
: targetDuration(targetDuration), operation(operation)
{
}
sfz::ScopedTiming::~ScopedTiming()
{
switch(operation)
{
case(Operation::replaceDuration):
targetDuration = std::chrono::high_resolution_clock::now() - creationTime;
break;
case(Operation::addToDuration):
targetDuration += std::chrono::high_resolution_clock::now() - creationTime;
break;
}
}

150
src/sfizz/Logger.h
View file

@ -1,150 +0,0 @@
// SPDX-License-Identifier: BSD-2-Clause
// This code is part of the sfizz library and is licensed under a BSD 2-clause
// license. You should have receive a LICENSE.md file along with the code.
// If not, contact the sfizz maintainers at https://github.com/sfztools/sfizz
#pragma once
#include "Config.h"
#include "utility/LeakDetector.h"
#include "utility/MemoryHelpers.h"
#include <atomic_queue/atomic_queue.h>
#include <absl/strings/string_view.h>
#include <vector>
#include <string>
#include <chrono>
#include <functional>
#include <thread>
#include <memory>
namespace sfz
{
using Duration = std::chrono::duration<double>;
/**
* @brief Creates an RAII logger which fills or adds to a duration on destruction
*
*/
struct ScopedTiming
{
using TimePoint = std::chrono::time_point<std::chrono::high_resolution_clock>;
enum class Operation
{
addToDuration,
replaceDuration
};
ScopedTiming() = delete;
/**
* @brief Construct a new Scoped Logger object
*
* @param targetDuration
* @param op
*/
ScopedTiming(Duration& targetDuration, Operation op = Operation::replaceDuration);
~ScopedTiming();
Duration& targetDuration;
const Operation operation;
const TimePoint creationTime { std::chrono::high_resolution_clock::now() };
};
struct FileTime
{
Duration waitDuration { 0 };
Duration loadDuration { 0 };
uint32_t fileSize { 0 };
absl::string_view filename {};
LEAK_DETECTOR(FileTime);
};
struct CallbackBreakdown
{
Duration dispatch { 0 };
Duration renderMethod { 0 };
Duration data { 0 };
Duration amplitude { 0 };
Duration filters { 0 };
Duration panning { 0 };
Duration effects { 0 };
LEAK_DETECTOR(CallbackBreakdown);
};
struct CallbackTime
{
CallbackBreakdown breakdown {};
int numVoices { 0 };
size_t numSamples { 0 };
LEAK_DETECTOR(CallbackTime);
};
class Logger
{
public:
Logger();
~Logger();
/**
* @brief Set the prefix for the output log files
*
* @param prefix
*/
void setPrefix(absl::string_view prefix);
/**
* @brief Removes all logged data
*
*/
void clear();
/**
* @brief Enables logging and writing to log files on destruction
*
*/
void enableLogging(absl::string_view prefix);
/**
* @brief Disables logging and writing to log files on destruction
*
*/
void disableLogging();
/**
* @brief Logs the callback duration, with breakdown per operations
*
* @param breakdown The different timings for the callback
* @param numVoices The number of active voices
* @param numSamples The number of samples in the callback
*/
void logCallbackTime(const CallbackBreakdown& breakdown, int numVoices, size_t numSamples);
/**
* @brief Log a file loading and waiting duration
*
* @param waitDuration The time spent waiting before loading the file
* @param loadDuration The time it took to load the file
* @param fileSize The file size
* @param filename The file name
*/
void logFileTime(Duration waitDuration, Duration loadDuration, uint32_t fileSize, absl::string_view filename);
private:
/**
* @brief Move all events from the real time queues to the non-realtime vectors
*/
void moveEvents() noexcept;
bool loggingEnabled { config::loggingEnabled };
std::string prefix { "" };
using CallbackTimeQueue = atomic_queue::AtomicQueue2<CallbackTime, config::loggerQueueSize, true, true, false, true>;
using FileTimeQueue = atomic_queue::AtomicQueue2<FileTime, config::loggerQueueSize, true, true, false, true>;
aligned_unique_ptr<CallbackTimeQueue> callbackTimeQueue;
aligned_unique_ptr<FileTimeQueue> fileTimeQueue;
std::vector<CallbackTime> callbackTimes;
std::vector<FileTime> fileTimes;
std::atomic_flag keepRunning;
std::atomic_flag clearFlag;
std::thread loggingThread;
LEAK_DETECTOR(Logger);
};
}

9
src/sfizz/Resources.cpp
View file

@ -9,7 +9,6 @@
#include "MidiState.h"
#include "FilePool.h"
#include "BufferPool.h"
#include "Logger.h"
#include "Wavetables.h"
#include "Curve.h"
#include "Tuning.h"
@ -23,9 +22,8 @@ struct Resources::Impl {
SynthConfig synthConfig;
BufferPool bufferPool;
MidiState midiState;
Logger logger;
CurveSet curves;
FilePool filePool { logger };
FilePool filePool;
WavetablePool wavePool;
Tuning tuning;
absl::optional<StretchTuning> stretch;
@ -67,7 +65,6 @@ void Resources::clearNonState()
impl.curves = CurveSet::createPredefined();
impl.filePool.clear();
impl.wavePool.clearFileWaves();
impl.logger.clear();
impl.modMatrix.clear();
impl.metronome.clear();
}
@ -95,10 +92,6 @@ const MidiState& Resources::getMidiState() const noexcept
return impl_->midiState;
}
const Logger& Resources::getLogger() const noexcept
{
return impl_->logger;
}
const CurveSet& Resources::getCurves() const noexcept
{

2
src/sfizz/Resources.h
View file

@ -13,7 +13,6 @@ namespace sfz {
struct SynthConfig;
class BufferPool;
class MidiState;
class Logger;
class CurveSet;
class FilePool;
struct WavetablePool;
@ -50,7 +49,6 @@ public:
ACCESSOR_RW(getSynthConfig, SynthConfig);
ACCESSOR_RW(getBufferPool, BufferPool);
ACCESSOR_RW(getMidiState, MidiState);
ACCESSOR_RW(getLogger, Logger);
ACCESSOR_RW(getCurves, CurveSet);
ACCESSOR_RW(getFilePool, FilePool);
ACCESSOR_RW(getWavePool, WavetablePool);

34
src/sfizz/Synth.cpp
View file

@ -25,6 +25,7 @@
#include "SynthConfig.h"
#include "ScopedFTZ.h"
#include "utility/StringViewHelpers.h"
#include "utility/Timing.h"
#include "utility/XmlHelpers.h"
#include "Voice.h"
#include "Interpolators.h"
@ -1037,7 +1038,10 @@ void Synth::renderBlock(AudioSpan<float> buffer) noexcept
{
Impl& impl = *impl_;
ScopedFTZ ftz;
CallbackBreakdown callbackBreakdown;
auto& callbackBreakdown = impl.callbackBreakdown_;
impl.resetCallbackBreakdown();
callbackBreakdown.dispatch = impl.dispatchDuration_;
impl.dispatchDuration_ = 0.0;
{ // Silence buffer
ScopedTiming logger { callbackBreakdown.renderMethod };
@ -1057,7 +1061,7 @@ void Synth::renderBlock(AudioSpan<float> buffer) noexcept
if (synthConfig.freeWheeling)
filePool.waitForBackgroundLoading();
const auto now = std::chrono::high_resolution_clock::now();
const auto now = highResNow();
const auto timeSinceLastCollection =
std::chrono::duration_cast<std::chrono::seconds>(now - impl.lastGarbageCollection_);
@ -1179,18 +1183,10 @@ void Synth::renderBlock(AudioSpan<float> buffer) noexcept
impl.changedCCsThisCycle_.clear();
{ // Clear events and advance midi time
ScopedTiming logger { impl.dispatchDuration_, ScopedTiming::Operation::addToDuration };
ScopedTiming logger { impl.callbackBreakdown_.dispatch, ScopedTiming::Operation::addToDuration };
midiState.advanceTime(buffer.getNumFrames());
}
callbackBreakdown.dispatch = impl.dispatchDuration_;
Logger& logger = impl.resources_.getLogger();
logger.logCallbackTime(
callbackBreakdown, impl.voiceManager_.getNumActiveVoices(), numFrames);
// Reset the dispatch counter
impl.dispatchDuration_ = Duration(0);
ASSERT(!hasNanInf(buffer.getConstSpan(0)));
ASSERT(!hasNanInf(buffer.getConstSpan(1)));
SFIZZ_CHECK(isReasonableAudio(buffer.getConstSpan(0)));
@ -1410,7 +1406,7 @@ void Synth::Impl::performHdcc(int delay, int ccNumber, float normValue, bool asM
ASSERT(ccNumber < config::numCCs);
ASSERT(ccNumber >= 0);
ScopedTiming logger { dispatchDuration_, ScopedTiming::Operation::addToDuration };
ScopedTiming logger { callbackBreakdown_.dispatch, ScopedTiming::Operation::addToDuration };
changedCCsThisCycle_.set(ccNumber);
@ -1906,6 +1902,11 @@ void Synth::Impl::resetVoices(int numVoices)
applySettingsPerVoice();
}
void Synth::Impl::resetCallbackBreakdown()
{
callbackBreakdown_ = CallbackBreakdown();
}
void Synth::Impl::applySettingsPerVoice()
{
for (auto& voice : voiceManager_) {
@ -2093,17 +2094,12 @@ bool Synth::shouldReloadScala()
return impl.resources_.getTuning().shouldReloadScala();
}
void Synth::enableLogging(absl::string_view prefix) noexcept
const Synth::CallbackBreakdown& Synth::getCallbackBreakdown() const noexcept
{
Impl& impl = *impl_;
impl.resources_.getLogger().enableLogging(prefix);
return impl.callbackBreakdown_;
}
void Synth::disableLogging() noexcept
{
Impl& impl = *impl_;
impl.resources_.getLogger().disableLogging();
}
void Synth::allSoundOff() noexcept
{

22
src/sfizz/Synth.h
View file

@ -634,17 +634,23 @@ public:
*/
bool shouldReloadScala();
struct CallbackBreakdown
{
double dispatch { 0 };
double renderMethod { 0 };
double data { 0 };
double amplitude { 0 };
double filters { 0 };
double panning { 0 };
double effects { 0 };
};
/**
* @brief Enable logging of timings to sidecar CSV files. This can produce
* many outputs so use with caution.
* @brief View the callback breakdown for the last frame.
* Call from the real-time thread after a renderBlock call.
*
* @return const CallbackBreakdown&
*/
void enableLogging(absl::string_view prefix = "") noexcept;
/**
* @brief Disable logging;
*
*/
void disableLogging() noexcept;
const CallbackBreakdown& getCallbackBreakdown() const noexcept;
/**
* @brief Shuts down the current processing, clear buffers and reset the voices.

8
src/sfizz/SynthPrivate.h
View file

@ -247,6 +247,11 @@ struct Synth::Impl final: public Parser::Listener {
*/
void checkOffGroups(const Region* region, int delay, int number);
/**
* @brief Resets the callback duration breakdown to 0
*/
void resetCallbackBreakdown();
int numGroups_ { 0 };
int numMasters_ { 0 };
int numOutputs_ { 1 };
@ -340,7 +345,8 @@ struct Synth::Impl final: public Parser::Listener {
bool haveFilterLFO { false };
} settingsPerVoice_;
Duration dispatchDuration_ { 0 };
CallbackBreakdown callbackBreakdown_;
double dispatchDuration_ { 0 };
std::chrono::time_point<std::chrono::high_resolution_clock> lastGarbageCollection_;

17
src/sfizz/Voice.cpp
View file

@ -33,6 +33,7 @@
#include "BufferPool.h"
#include "SynthConfig.h"
#include "utility/Macros.h"
#include "utility/Timing.h"
#include <absl/algorithm/container.h>
#include <absl/types/span.h>
#include <random>
@ -285,10 +286,10 @@ struct Voice::Impl
float waveLeftGain_[config::oscillatorsPerVoice] {};
float waveRightGain_[config::oscillatorsPerVoice] {};
Duration dataDuration_;
Duration amplitudeDuration_;
Duration panningDuration_;
Duration filterDuration_;
double dataDuration_;
double amplitudeDuration_;
double panningDuration_;
double filterDuration_;
fast_real_distribution<float> uniformNoiseDist_ { -config::uniformNoiseBounds, config::uniformNoiseBounds };
fast_gaussian_generator<float> gaussianNoiseDist_ { 0.0f, config::noiseVariance };
@ -2091,25 +2092,25 @@ int Voice::getAge() const noexcept
return impl.age_;
}
Duration Voice::getLastDataDuration() const noexcept
double Voice::getLastDataDuration() const noexcept
{
Impl& impl = *impl_;
return impl.dataDuration_;
}
Duration Voice::getLastAmplitudeDuration() const noexcept
double Voice::getLastAmplitudeDuration() const noexcept
{
Impl& impl = *impl_;
return impl.amplitudeDuration_;
}
Duration Voice::getLastFilterDuration() const noexcept
double Voice::getLastFilterDuration() const noexcept
{
Impl& impl = *impl_;
return impl.filterDuration_;
}
Duration Voice::getLastPanningDuration() const noexcept
double Voice::getLastPanningDuration() const noexcept
{
Impl& impl = *impl_;
return impl.panningDuration_;

9
src/sfizz/Voice.h
View file

@ -10,7 +10,6 @@
#include "Region.h"
#include "Resources.h"
#include "AudioSpan.h"
#include "Logger.h"
#include "utility/NumericId.h"
#include "utility/LeakDetector.h"
#include <memory>
@ -382,10 +381,10 @@ public:
*/
int getAge() const noexcept;
Duration getLastDataDuration() const noexcept;
Duration getLastAmplitudeDuration() const noexcept;
Duration getLastFilterDuration() const noexcept;
Duration getLastPanningDuration() const noexcept;
double getLastDataDuration() const noexcept;
double getLastAmplitudeDuration() const noexcept;
double getLastFilterDuration() const noexcept;
double getLastPanningDuration() const noexcept;
/**
* @brief Get the SFZv1 amplitude LFO, if existing

18
src/sfizz/sfizz.cpp
View file

@ -334,12 +334,11 @@ bool sfz::Sfizz::shouldReloadScala()
void sfz::Sfizz::enableLogging() noexcept
{
synth->synth.enableLogging();
}
void sfz::Sfizz::enableLogging(const std::string& prefix) noexcept
{
synth->synth.enableLogging(prefix);
(void)prefix;
}
void sfz::Sfizz::setLoggingPrefix(const std::string& prefix) noexcept
@ -349,7 +348,20 @@ void sfz::Sfizz::setLoggingPrefix(const std::string& prefix) noexcept
void sfz::Sfizz::disableLogging() noexcept
{
synth->synth.disableLogging();
}
sfz::Sfizz::CallbackBreakdown sfz::Sfizz::getCallbackBreakdown() noexcept
{
CallbackBreakdown breakdown;
const auto& bd = synth->synth.getCallbackBreakdown();
breakdown.amplitude = bd.amplitude;
breakdown.panning = bd.panning;
breakdown.renderMethod = bd.renderMethod;
breakdown.data = bd.data;
breakdown.dispatch = bd.dispatch;
breakdown.filters = bd.filters;
breakdown.effects = bd.effects;
return breakdown;
}
void sfz::Sfizz::allSoundOff() noexcept

20
src/sfizz/sfizz_wrapper.cpp
View file

@ -314,10 +314,8 @@ bool sfizz_should_reload_scala(sfizz_synth_t* synth)
void sfizz_enable_logging(sfizz_synth_t* synth, const char* prefix)
{
if (prefix)
synth->synth.enableLogging(prefix);
else
synth->synth.enableLogging();
(void)synth;
(void)prefix;
}
void sfizz_set_logging_prefix(sfizz_synth_t* synth, const char* prefix)
@ -328,7 +326,19 @@ void sfizz_set_logging_prefix(sfizz_synth_t* synth, const char* prefix)
void sfizz_disable_logging(sfizz_synth_t* synth)
{
synth->synth.disableLogging();
(void)synth;
}
void sfizz_get_callback_breakdown(sfizz_synth_t* synth, sfizz_callback_breakdown_t* breakdown)
{
const auto& bd = synth->synth.getCallbackBreakdown();
breakdown->amplitude = bd.amplitude;
breakdown->panning = bd.panning;
breakdown->renderMethod = bd.renderMethod;
breakdown->data = bd.data;
breakdown->dispatch = bd.dispatch;
breakdown->filters = bd.filters;
breakdown->effects = bd.effects;
}
void sfizz_all_sound_off(sfizz_synth_t* synth)

64
src/sfizz/utility/Timing.h Normal file
View file

@ -0,0 +1,64 @@
// SPDX-License-Identifier: BSD-2-Clause
// This code is part of the sfizz library and is licensed under a BSD 2-clause
// license. You should have receive a LICENSE.md file along with the code.
// If not, contact the sfizz maintainers at https://github.com/sfztools/sfizz
#pragma once
#include <chrono>
#include <type_traits>
namespace sfz
{
using Duration = std::chrono::duration<double>;
using TimePoint = std::chrono::time_point<std::chrono::high_resolution_clock>;
static TimePoint highResNow()
{
#ifdef EMSCRIPTEN
return {};
#else
return std::chrono::high_resolution_clock::now();
#endif
}
/**
* @brief Creates an RAII logger which fills or adds to a duration on destruction
*
*/
struct ScopedTiming
{
enum class Operation
{
addToDuration,
replaceDuration
};
ScopedTiming() = delete;
/**
* @brief Construct a new Scoped Logger object
*
* @param targetDuration
* @param op
*/
ScopedTiming(double& targetDuration, Operation op = Operation::replaceDuration)
: targetDuration(targetDuration), operation(op) {}
~ScopedTiming()
{
switch(operation)
{
case(Operation::replaceDuration):
targetDuration = (highResNow() - creationTime).count();
break;
case(Operation::addToDuration):
targetDuration += (highResNow() - creationTime).count();
break;
}
}
double& targetDuration;
const Operation operation;
const TimePoint creationTime { highResNow() };
};
}