Start reworking log output

This commit is contained in:
Chris Cannam
2022-06-21 16:06:16 +01:00
parent e546767a6d
commit 35653f3a86
13 changed files with 258 additions and 71 deletions

View File

@@ -24,6 +24,8 @@
#ifndef RUBBERBAND_GUIDE_H
#define RUBBERBAND_GUIDE_H
#include "../common/Log.h"
#include <functional>
#include <sstream>
@@ -102,15 +104,12 @@ public:
struct Parameters {
double sampleRate;
std::function<void(const std::string &)> logger;
Parameters(double _sampleRate,
std::function<void(const std::string &)> _log) :
sampleRate(_sampleRate),
logger(_log) { }
Parameters(double _sampleRate) : sampleRate(_sampleRate) { }
};
Guide(Parameters parameters) :
Guide(Parameters parameters, Log log) :
m_parameters(parameters),
m_log(log),
m_configuration(roundUp(int(ceil(parameters.sampleRate / 16.0))),
roundUp(int(ceil(parameters.sampleRate / 64.0))),
roundUp(int(ceil(parameters.sampleRate / 32.0)))),
@@ -334,6 +333,7 @@ public:
protected:
Parameters m_parameters;
Log m_log;
Configuration m_configuration;
double m_minLower;

View File

@@ -26,6 +26,7 @@
#include "Guide.h"
#include "../common/Log.h"
#include "../common/mathmisc.h"
#include <sstream>
@@ -41,15 +42,13 @@ public:
int fftSize;
double sampleRate;
int channels;
std::function<void(const std::string &)> logger;
Parameters(int _fftSize, double _sampleRate, int _channels,
std::function<void(const std::string &)> _log) :
fftSize(_fftSize), sampleRate(_sampleRate),
channels(_channels), logger(_log) { }
Parameters(int _fftSize, double _sampleRate, int _channels) :
fftSize(_fftSize), sampleRate(_sampleRate), channels(_channels) { }
};
GuidedPhaseAdvance(Parameters parameters) :
GuidedPhaseAdvance(Parameters parameters, Log log) :
m_parameters(parameters),
m_log(log),
m_binCount(parameters.fftSize / 2 + 1),
m_peakPicker(m_binCount),
m_reported(false) {
@@ -111,7 +110,7 @@ public:
int lowest = configuration.fftBandLimits[myFftBand].b0min;
int highest = configuration.fftBandLimits[myFftBand].b1max;
if (!m_reported) {
if (m_log.getDebugLevel() > 0 && !m_reported) {
std::ostringstream ostr;
ostr << "PhaseAdvance: fftSize = " << m_parameters.fftSize
<< ": bins = " << bs << ", channels = " << channels
@@ -122,7 +121,7 @@ public:
<< "Hz), highest = " << highest
<< " (" << configuration.fftBandLimits[myFftBand].f1max
<< "Hz)" << std::endl;
m_parameters.logger(ostr.str());
m_log.log0(1, ostr.str().c_str());
m_reported = true;
}
@@ -231,8 +230,13 @@ public:
}
}
void setDebugLevel(int debugLevel) {
m_log.setDebugLevel(debugLevel);
}
protected:
Parameters m_parameters;
Log m_log;
int m_binCount;
Peak<double> m_peakPicker;
int **m_currentPeaks;

View File

@@ -31,12 +31,14 @@ namespace RubberBand {
R3Stretcher::R3Stretcher(Parameters parameters,
double initialTimeRatio,
double initialPitchScale) :
double initialPitchScale,
Log log) :
m_parameters(parameters),
m_log(log),
m_timeRatio(initialTimeRatio),
m_pitchScale(initialPitchScale),
m_formantScale(0.0),
m_guide(Guide::Parameters(m_parameters.sampleRate, parameters.logger)),
m_guide(Guide::Parameters(m_parameters.sampleRate), m_log),
m_guideConfiguration(m_guide.getConfiguration()),
m_channelAssembly(m_parameters.channels),
m_inhop(1),
@@ -83,18 +85,19 @@ R3Stretcher::R3Stretcher(Parameters parameters,
(fftSize, m_guideConfiguration.longestFftSize);
}
}
for (auto band: m_guideConfiguration.fftBandLimits) {
int fftSize = band.fftSize;
GuidedPhaseAdvance::Parameters guidedParameters
(fftSize, m_parameters.sampleRate, m_parameters.channels,
m_parameters.logger);
m_scaleData[fftSize] = std::make_shared<ScaleData>(guidedParameters);
(fftSize, m_parameters.sampleRate, m_parameters.channels);
m_scaleData[fftSize] = std::make_shared<ScaleData>(guidedParameters,
m_log);
}
m_calculator = std::unique_ptr<StretchCalculator>
(new StretchCalculator(int(round(m_parameters.sampleRate)), //!!! which is a double...
1, false)); // no fixed inputIncrement
1, false, // no fixed inputIncrement
m_log));
Resampler::Parameters resamplerParameters;
resamplerParameters.quality = Resampler::FastestTolerable;
@@ -119,10 +122,10 @@ R3Stretcher::R3Stretcher(Parameters parameters,
m_prevOuthop = int(round(m_inhop * getEffectiveRatio()));
if (!m_inhop.is_lock_free()) {
m_parameters.logger("WARNING: std::atomic<int> is not lock-free");
m_log.log0(0, "WARNING: std::atomic<int> is not lock-free");
}
if (!m_timeRatio.is_lock_free()) {
m_parameters.logger("WARNING: std::atomic<double> is not lock-free");
m_log.log0(0, "WARNING: std::atomic<double> is not lock-free");
}
// Pad to half of the longest frame. As with R2, in real-time mode
@@ -131,7 +134,7 @@ R3Stretcher::R3Stretcher(Parameters parameters,
// changes.
if (!isRealTime()) {
m_parameters.logger("Offline mode: pre-padding");
m_log.log0(1, "Offline mode: pre-padding");
int pad = m_guideConfiguration.longestFftSize / 2;
for (int c = 0; c < m_parameters.channels; ++c) {
m_channelData[c]->inbuf->zero(pad);
@@ -139,7 +142,7 @@ R3Stretcher::R3Stretcher(Parameters parameters,
// By the time we skip this later we will have resampled
m_startSkip = int(round(pad / m_pitchScale));
} else {
m_parameters.logger("RT mode: no internal pre-pad");
m_log.log0(1, "RT mode: no internal pre-pad");
}
}
@@ -176,7 +179,7 @@ R3Stretcher::setTimeRatio(double ratio)
if (!isRealTime()) {
if (m_mode == ProcessMode::Studying ||
m_mode == ProcessMode::Processing) {
m_parameters.logger("R3Stretcher::setTimeRatio: Cannot set time ratio while studying or processing in non-RT mode");
m_log.log0(0, "R3Stretcher::setTimeRatio: Cannot set time ratio while studying or processing in non-RT mode");
return;
}
}
@@ -192,7 +195,7 @@ R3Stretcher::setPitchScale(double scale)
if (!isRealTime()) {
if (m_mode == ProcessMode::Studying ||
m_mode == ProcessMode::Processing) {
m_parameters.logger("R3Stretcher::setTimeRatio: Cannot set pitch scale while studying or processing in non-RT mode");
m_log.log0(0, "R3Stretcher::setTimeRatio: Cannot set pitch scale while studying or processing in non-RT mode");
return;
}
}
@@ -208,7 +211,7 @@ R3Stretcher::setFormantScale(double scale)
if (!isRealTime()) {
if (m_mode == ProcessMode::Studying ||
m_mode == ProcessMode::Processing) {
m_parameters.logger("R3Stretcher::setTimeRatio: Cannot set formant scale while studying or processing in non-RT mode");
m_log.log0(0, "R3Stretcher::setTimeRatio: Cannot set formant scale while studying or processing in non-RT mode");
return;
}
}
@@ -230,11 +233,11 @@ void
R3Stretcher::setKeyFrameMap(const std::map<size_t, size_t> &mapping)
{
if (isRealTime()) {
m_parameters.logger("R3Stretcher::setKeyFrameMap: Cannot specify key frame map in RT mode");
m_log.log0(0, "R3Stretcher::setKeyFrameMap: Cannot specify key frame map in RT mode");
return;
}
if (m_mode == ProcessMode::Processing || m_mode == ProcessMode::Finished) {
m_parameters.logger("R3Stretcher::setKeyFrameMap: Cannot specify key frame map after process() has begun");
m_log.log0(0, "R3Stretcher::setKeyFrameMap: Cannot specify key frame map after process() has begun");
return;
}
@@ -266,22 +269,21 @@ R3Stretcher::calculateHop()
if (proposedOuthop > 512.0) proposedOuthop = 512.0;
if (proposedOuthop < 128.0) proposedOuthop = 128.0;
std::cout << "calculateHop: for ratio " << ratio << " proposedOuthop = "
<< proposedOuthop << std::endl;
m_log.log2(1, "calculateHop: ratio and proposed outhop", ratio, proposedOuthop);
double inhop = proposedOuthop / ratio;
if (inhop < 1.0) {
m_parameters.logger("WARNING: Extreme ratio yields ideal inhop < 1, results may be suspect");
m_log.log2(0, "WARNING: Extreme ratio yields ideal inhop < 1, results may be suspect", ratio, inhop);
inhop = 1.0;
}
if (inhop > 768.0) {
m_parameters.logger("WARNING: Extreme ratio yields ideal inhop > 768, results may be suspect");
m_log.log2(0, "WARNING: Extreme ratio yields ideal inhop > 768, results may be suspect", ratio, inhop);
inhop = 768.0;
}
m_inhop = int(floor(inhop));
std::cout << "R3Stretcher::calculateHop: inhop = " << m_inhop << ", proposed outhop = " << proposedOuthop << ", mean outhop = " << m_inhop * ratio << std::endl;
m_log.log2(1, "calculateHop: inhop and mean outhop", m_inhop, m_inhop * ratio);
}
void
@@ -409,12 +411,12 @@ void
R3Stretcher::study(const float *const *, size_t samples, bool)
{
if (isRealTime()) {
m_parameters.logger("R3Stretcher::study: Not meaningful in realtime mode");
m_log.log0(0, "R3Stretcher::study: Not meaningful in realtime mode");
return;
}
if (m_mode == ProcessMode::Processing || m_mode == ProcessMode::Finished) {
m_parameters.logger("R3Stretcher::study: Cannot study after processing");
m_log.log0(0, "R3Stretcher::study: Cannot study after processing");
return;
}
@@ -443,7 +445,7 @@ void
R3Stretcher::process(const float *const *input, size_t samples, bool final)
{
if (m_mode == ProcessMode::Finished) {
m_parameters.logger("R3Stretcher::process: Cannot process again after final chunk");
m_log.log0(0, "R3Stretcher::process: Cannot process again after final chunk");
return;
}
@@ -468,7 +470,7 @@ R3Stretcher::process(const float *const *input, size_t samples, bool final)
size_t ws = m_channelData[0]->inbuf->getWriteSpace();
if (samples > ws) {
//!!! check this
m_parameters.logger("R3Stretcher::process: WARNING: Forced to increase input buffer size. Either setMaxProcessSize was not properly called or process is being called repeatedly without retrieve.");
m_log.log0(0, "R3Stretcher::process: WARNING: Forced to increase input buffer size. Either setMaxProcessSize was not properly called or process is being called repeatedly without retrieve.");
size_t newSize = m_channelData[0]->inbuf->getSize() - ws + samples;
for (int c = 0; c < m_parameters.channels; ++c) {
auto newBuf = m_channelData[c]->inbuf->resized(newSize);
@@ -505,7 +507,7 @@ R3Stretcher::retrieve(float *const *output, size_t samples) const
int gotHere = m_channelData[c]->outbuf->read(output[c], got);
if (gotHere < got) {
if (c > 0) {
m_parameters.logger("R3Stretcher::retrieve: WARNING: channel imbalance detected");
m_log.log0(0, "R3Stretcher::retrieve: WARNING: channel imbalance detected");
}
got = std::min(got, std::max(gotHere, 0));
}

View File

@@ -36,12 +36,12 @@
#include "../common/Allocators.h"
#include "../common/Window.h"
#include "../common/VectorOpsComplex.h"
#include "../common/Log.h"
#include "../../rubberband/RubberBandStretcher.h"
#include <map>
#include <memory>
#include <functional>
namespace RubberBand
{
@@ -53,17 +53,15 @@ public:
double sampleRate;
int channels;
RubberBandStretcher::Options options;
std::function<void(const std::string &)> logger;
Parameters(double _sampleRate, int _channels,
RubberBandStretcher::Options _options,
std::function<void(const std::string &)> _log = &logCout) :
sampleRate(_sampleRate), channels(_channels), options(_options),
logger(_log) { }
RubberBandStretcher::Options _options) :
sampleRate(_sampleRate), channels(_channels), options(_options) { }
};
R3Stretcher(Parameters parameters,
double initialTimeRatio,
double initialPitchScale);
double initialPitchScale,
Log log);
~R3Stretcher() { }
void reset();
@@ -89,6 +87,10 @@ public:
size_t getLatency() const;
size_t getChannelCount() const;
void setDebugLevel(int level) {
m_log.setDebugLevel(level); //!!! +others
}
protected:
struct ClassificationReadaheadData {
FixedVector<double> timeDomain;
@@ -242,7 +244,8 @@ protected:
Window<double> synthesisWindow;
double windowScaleFactor;
GuidedPhaseAdvance guided;
ScaleData(GuidedPhaseAdvance::Parameters guidedParameters) :
ScaleData(GuidedPhaseAdvance::Parameters guidedParameters,
Log log) :
fftSize(guidedParameters.fftSize),
fft(fftSize),
analysisWindow(analysisWindowShape(fftSize),
@@ -250,7 +253,7 @@ protected:
synthesisWindow(synthesisWindowShape(fftSize),
synthesisWindowLength(fftSize)),
windowScaleFactor(0.0),
guided(guidedParameters)
guided(guidedParameters, log)
{
int asz = analysisWindow.getSize(), ssz = synthesisWindow.getSize();
int off = (asz - ssz) / 2;
@@ -267,6 +270,7 @@ protected:
};
Parameters m_parameters;
Log m_log;
std::atomic<double> m_timeRatio;
std::atomic<double> m_pitchScale;
@@ -347,10 +351,6 @@ protected:
return m_parameters.options &
RubberBandStretcher::OptionProcessRealTime;
}
static void logCout(const std::string &message) {
std::cout << "RubberBandStretcher: " << message << std::endl;
}
};
}