Merge from branch logger

meson.build

@@ -42,10 +42,11 @@ library_sources = [
   'src/faster/R2Stretcher.cpp',
   'src/faster/StretcherChannelData.cpp',
   'src/faster/StretcherProcess.cpp',
+  'src/common/Allocators.cpp',
+  'src/common/FFT.cpp',
+  'src/common/Log.cpp',
   'src/common/Profiler.cpp',
   'src/common/Resampler.cpp',
-  'src/common/FFT.cpp',
-  'src/common/Allocators.cpp',
   'src/common/StretchCalculator.cpp',
   'src/common/sysutils.cpp',
   'src/common/Thread.cpp',

rubberband/RubberBandStretcher.h

@@ -37,6 +37,8 @@
 
 #include <vector>
 #include <map>
+#include <string>
+#include <memory>
 #include <cstddef>
 
 /**
@@ -277,7 +279,6 @@ public:
      * provided for backward compatibility only. They are ignored by
      * the stretcher.
      */
-    
     enum Option {
 
         OptionProcessOffline       = 0x00000000,
@@ -331,6 +332,13 @@ public:
         PercussiveOptions          = 0x00102000
     };
 
+    struct Logger {
+        virtual void log(const char *) = 0;
+        virtual void log(const char *, double) = 0;
+        virtual void log(const char *, double, double) = 0;
+        virtual ~Logger() { }
+    };
+    
     /**
      * Construct a time and pitch stretcher object to run at the given
      * sample rate, with the given number of channels.
@@ -361,6 +369,30 @@ public:
                         Options options = DefaultOptions,
                         double initialTimeRatio = 1.0,
                         double initialPitchScale = 1.0);
+
+    /**
+     * Construct a time and pitch stretcher object with a custom debug
+     * logger. This may be useful for debugging if the default logger
+     * output (which simply goes to cout) is not visible in the
+     * runtime environment, or if the application has a standard or
+     * more realtime-appropriate logging mechanism.
+     *
+     * See the documentation for the other constructor above for
+     * details of the arguments other than the logger.
+     *
+     * Note that although the supplied logger gets to decide what to
+     * do with log messages, the separately-set debug level (see
+     * setDebugLevel() and setDefaultDebugLevel()) still determines
+     * whether any given debug message is sent to the logger in the
+     * first place.
+     */
+    RubberBandStretcher(size_t sampleRate,
+                        size_t channels,
+                        std::shared_ptr<Logger> logger,
+                        Options options = DefaultOptions,
+                        double initialTimeRatio = 1.0,
+                        double initialPitchScale = 1.0);
+    
     ~RubberBandStretcher();
 
     /**

src/RubberBandStretcher.cpp

@@ -24,24 +24,68 @@
 #include "faster/R2Stretcher.h"
 #include "finer/R3Stretcher.h"
 
+#include <iostream>
+
 namespace RubberBand {
 
 class RubberBandStretcher::Impl
 {
     R2Stretcher *m_r2;
     R3Stretcher *m_r3;
-    
+
+    class CerrLogger : public RubberBandStretcher::Logger {
+    public:
+        void log(const char *message) override {
+            std::cerr << "RubberBand: " << message << "\n";
+        }
+        void log(const char *message, double arg0) override {
+            auto prec = std::cerr.precision();
+            std::cerr.precision(10);
+            std::cerr << "RubberBand: " << message << ": " << arg0 << "\n";
+            std::cerr.precision(prec);
+        }
+        void log(const char *message, double arg0, double arg1) override {
+            auto prec = std::cerr.precision();
+            std::cerr.precision(10);
+            std::cerr << "RubberBand: " << message
+                      << ": (" << arg0 << ", " << arg1 << ")" << "\n";
+            std::cerr.precision(prec);
+        }
+    };
+
+    Log makeRBLog(std::shared_ptr<RubberBandStretcher::Logger> logger) {
+        if (logger) {
+            return Log(
+                [=](const char *message) {
+                    logger->log(message);
+                },
+                [=](const char *message, double arg0) {
+                    logger->log(message, arg0);
+                },
+                [=](const char *message, double arg0, double arg1) {
+                    logger->log(message, arg0, arg1);
+                }
+                );
+        } else {
+            return makeRBLog(std::shared_ptr<RubberBandStretcher::Logger>
+                             (new CerrLogger()));
+        }
+    }
+
 public:
     Impl(size_t sampleRate, size_t channels, Options options,
+         std::shared_ptr<RubberBandStretcher::Logger> logger,
          double initialTimeRatio, double initialPitchScale) :
         m_r2 (!(options & OptionEngineFiner) ?
               new R2Stretcher(sampleRate, channels, options,
-                              initialTimeRatio, initialPitchScale)
+                              initialTimeRatio, initialPitchScale,
+                              makeRBLog(logger))
               : nullptr),
         m_r3 ((options & OptionEngineFiner) ?
               new R3Stretcher(R3Stretcher::Parameters
                               (double(sampleRate), channels, options),
-                              initialTimeRatio, initialPitchScale)
+                              initialTimeRatio, initialPitchScale,
+                              makeRBLog(logger))
               : nullptr)
     {
     }
@@ -272,13 +316,13 @@ public:
     setDebugLevel(int level)
     {
         if (m_r2) m_r2->setDebugLevel(level);
+        else m_r3->setDebugLevel(level);
     }
 
     static void
     setDefaultDebugLevel(int level)
     {
-        R2Stretcher::setDefaultDebugLevel(level);
+        Log::setDefaultDebugLevel(level);
-//!!!        R3Stretcher::setDefaultDebugLevel(level);
     }
 };
 
@@ -287,7 +331,18 @@ RubberBandStretcher::RubberBandStretcher(size_t sampleRate,
                                          Options options,
                                          double initialTimeRatio,
                                          double initialPitchScale) :
-    m_d(new Impl(sampleRate, channels, options,
+    m_d(new Impl(sampleRate, channels, options, nullptr,
+                 initialTimeRatio, initialPitchScale))
+{
+}
+
+RubberBandStretcher::RubberBandStretcher(size_t sampleRate,
+                                         size_t channels,
+                                         std::shared_ptr<Logger> logger,
+                                         Options options,
+                                         double initialTimeRatio,
+                                         double initialPitchScale) :
+    m_d(new Impl(sampleRate, channels, options, logger,
                  initialTimeRatio, initialPitchScale))
 {
 }

src/common/Log.cpp

@@ -0,0 +1,31 @@
+/* -*- c-basic-offset: 4 indent-tabs-mode: nil -*-  vi:set ts=8 sts=4 sw=4: */
+
+/*
+    Rubber Band Library
+    An audio time-stretching and pitch-shifting library.
+    Copyright 2007-2022 Particular Programs Ltd.
+
+    This program is free software; you can redistribute it and/or
+    modify it under the terms of the GNU General Public License as
+    published by the Free Software Foundation; either version 2 of the
+    License, or (at your option) any later version.  See the file
+    COPYING included with this distribution for more information.
+
+    Alternatively, if you have a valid commercial licence for the
+    Rubber Band Library obtained by agreement with the copyright
+    holders, you may redistribute and/or modify it under the terms
+    described in that licence.
+
+    If you wish to distribute code using the Rubber Band Library
+    under terms other than those of the GNU General Public License,
+    you must obtain a valid commercial licence before doing so.
+*/
+
+#include "Log.h"
+
+namespace RubberBand
+{
+
+int Log::m_defaultDebugLevel = 0;
+
+}

src/common/Log.h

@@ -0,0 +1,72 @@
+/* -*- c-basic-offset: 4 indent-tabs-mode: nil -*-  vi:set ts=8 sts=4 sw=4: */
+
+/*
+    Rubber Band Library
+    An audio time-stretching and pitch-shifting library.
+    Copyright 2007-2022 Particular Programs Ltd.
+
+    This program is free software; you can redistribute it and/or
+    modify it under the terms of the GNU General Public License as
+    published by the Free Software Foundation; either version 2 of the
+    License, or (at your option) any later version.  See the file
+    COPYING included with this distribution for more information.
+
+    Alternatively, if you have a valid commercial licence for the
+    Rubber Band Library obtained by agreement with the copyright
+    holders, you may redistribute and/or modify it under the terms
+    described in that licence.
+
+    If you wish to distribute code using the Rubber Band Library
+    under terms other than those of the GNU General Public License,
+    you must obtain a valid commercial licence before doing so.
+*/
+
+#ifndef RUBBERBAND_LOG_H
+#define RUBBERBAND_LOG_H
+
+#include <functional>
+#include <iostream>
+
+namespace RubberBand {
+
+class Log {
+public:
+    Log(std::function<void(const char *)> _log0,
+        std::function<void(const char *, double)> _log1,
+        std::function<void(const char *, double, double)> _log2) :
+        m_log0(_log0),
+        m_log1(_log1),
+        m_log2(_log2),
+        m_debugLevel(m_defaultDebugLevel) { }
+
+    Log(const Log &other) =default;
+    Log(Log &&other) =default;
+    Log &operator=(const Log &other) =default;
+    Log &operator=(Log &&other) =default;
+
+    void setDebugLevel(int level) { m_debugLevel = level; }
+    int getDebugLevel() const { return m_debugLevel; }
+
+    static void setDefaultDebugLevel(int level) { m_defaultDebugLevel = level; }
+    
+    void log(int level, const char *message) const {
+        if (level <= m_debugLevel) m_log0(message);
+    }
+    void log(int level, const char *message, double arg0) const {
+        if (level <= m_debugLevel) m_log1(message, arg0);
+    }
+    void log(int level, const char *message, double arg0, double arg1) const {
+        if (level <= m_debugLevel) m_log2(message, arg0, arg1);
+    }
+
+private:
+    std::function<void(const char *)> m_log0;
+    std::function<void(const char *, double)> m_log1;
+    std::function<void(const char *, double, double)> m_log2;
+    int m_debugLevel;
+    static int m_defaultDebugLevel;
+};
+
+}
+
+#endif

src/common/StretchCalculator.cpp

@@ -29,6 +29,7 @@
 #include <set>
 #include <cassert>
 #include <algorithm>
+#include <sstream>
 
 #include "sysutils.h"
 
@@ -37,7 +38,8 @@ namespace RubberBand
 	
 StretchCalculator::StretchCalculator(size_t sampleRate,
                                      size_t inputIncrement,
-                                     bool useHardPeaks) :
+                                     bool useHardPeaks,
+                                     Log log) :
     m_sampleRate(sampleRate),
     m_increment(inputIncrement),
     m_prevDf(0),
@@ -49,9 +51,10 @@ StretchCalculator::StretchCalculator(size_t sampleRate,
     m_useHardPeaks(useHardPeaks),
     m_inFrameCounter(0),
     m_frameCheckpoint(0, 0),
-    m_outFrameCounter(0)
+    m_outFrameCounter(0),
+    m_log(log)
 {
-//    std::cerr << "StretchCalculator::StretchCalculator: useHardPeaks = " << useHardPeaks << std::endl;
+    m_log.log(2, "StretchCalculator: useHardPeaks", useHardPeaks);
 }    
 
 StretchCalculator::~StretchCalculator()
@@ -83,25 +86,18 @@ StretchCalculator::calculate(double ratio, size_t inputDuration,
 
     size_t outputDuration = lrint(inputDuration * ratio);
 
-    if (m_debugLevel > 0) {
+    m_log.log(1, "StretchCalculator::calculate: inputDuration and ratio", inputDuration, ratio);
-        std::cerr << "StretchCalculator::calculate(): inputDuration " << inputDuration << ", ratio " << ratio << ", outputDuration " << outputDuration;
-    }
 
     outputDuration = lrint((phaseResetDf.size() * m_increment) * ratio);
 
-    if (m_debugLevel > 0) {
+    m_log.log(1, "StretchCalculator::calculate: outputDuration rounds up from and to", inputDuration * ratio, outputDuration);
-        std::cerr << " (rounded up to " << outputDuration << ")";
+    m_log.log(1, "StretchCalculator::calculate: df size and increment", phaseResetDf.size(), m_increment);
-        std::cerr << ", df size " << phaseResetDf.size() << ", increment "
+    
-                  << m_increment << std::endl;
-    }
-
     std::vector<Peak> peaks; // peak position (in chunks) and hardness
     std::vector<size_t> targets; // targets for mapping peaks (in samples)
     mapPeaks(peaks, targets, outputDuration, totalCount);
 
-    if (m_debugLevel > 1) {
+    m_log.log(2, "have fixed positions", peaks.size());
-        std::cerr << "have " << peaks.size() << " fixed positions" << std::endl;
-    }
 
     size_t totalInput = 0, totalOutput = 0;
 
@@ -122,7 +118,6 @@ StretchCalculator::calculate(double ratio, size_t inputDuration,
         }
 
         if (i == peaks.size()) {
-//            std::cerr << "note: i (=" << i << ") == peaks.size(); regionEndChunk " << regionEndChunk << " -> " << totalCount << ", regionEnd " << regionEnd << " -> " << outputDuration << std::endl;
             regionEndChunk = totalCount;
             regionEnd = outputDuration;
         } else {
@@ -141,15 +136,12 @@ StretchCalculator::calculate(double ratio, size_t inputDuration,
         size_t regionDuration = regionEnd - regionStart;
 
         size_t nchunks = regionEndChunk - regionStartChunk;
- 
+
-        if (m_debugLevel > 1) {
+        m_log.log(2, "region from and to (chunks)", regionStartChunk, regionEndChunk);
-            std::cerr << "region from " << regionStartChunk << " to " << regionEndChunk << " (samples " << regionStart << " to " << regionEnd << ")" << std::endl;
+        m_log.log(2, "region from and to (samples)", regionStart, regionEnd);
-        }
 
         if (nchunks == 0) {
-            if (m_debugLevel > 1) {
+            m_log.log(2, "note: nchunks == 0");
-                std::cerr << "note: nchunks == 0" << std::endl;
-            }
             continue;
         }
 
@@ -195,10 +187,10 @@ StretchCalculator::calculate(double ratio, size_t inputDuration,
         totalOutput += totalForRegion;
     }
 
-    if (m_debugLevel > 0) {
+    m_log.log(1, "total input (frames, chunks)", totalInput, totalInput / m_increment);
-        std::cerr << "total input increment = " << totalInput << " (= " << totalInput / m_increment << " chunks), output = " << totalOutput << ", ratio = " << double(totalOutput)/double(totalInput) << ", ideal output " << size_t(ceil(totalInput * ratio)) << std::endl;
+    m_log.log(1, "total output and achieved ratio", totalOutput, double(totalOutput)/double(totalInput));
-    }
+    m_log.log(1, "ideal output", totalInput * ratio);
-
+    
     return increments;
 }
 
@@ -237,8 +229,6 @@ StretchCalculator::mapPeaks(std::vector<Peak> &peaks,
 
     while (mi != m_keyFrameMap.end()) {
 
-//        std::cerr << "mi->first is " << mi->first << ", second is " << mi->second <<std::endl;
-
         // The map we've been given is from sample to sample, but
         // we can only map from chunk to sample.  We should perhaps
         // adjust the target sample to compensate for the discrepancy
@@ -261,7 +251,8 @@ StretchCalculator::mapPeaks(std::vector<Peak> &peaks,
             sourceStartChunk >= sourceEndChunk ||
             targetStartSample >= outputDuration ||
             targetStartSample >= targetEndSample) {
-            std::cerr << "NOTE: ignoring mapping from chunk " << sourceStartChunk << " to sample " << targetStartSample << "\n(source or target chunk exceeds total count, or end is not later than start)" << std::endl;
+            m_log.log(0, "NOTE: ignoring key-frame mapping from chunk to sample", sourceStartChunk, targetStartSample);
+            m_log.log(0, "(source or target chunk exceeds total count, or end is not later than start)");
             continue;
         }
         
@@ -274,9 +265,7 @@ StretchCalculator::mapPeaks(std::vector<Peak> &peaks,
         peaks.push_back(p);
         targets.push_back(targetStartSample);
 
-        if (m_debugLevel > 1) {
+        m_log.log(2, "mapped key-frame chunk to frame", sourceStartChunk, targetStartSample);
-            std::cerr << "mapped chunk " << sourceStartChunk << " (frame " << sourceStartChunk * m_increment << ") -> " << targetStartSample << std::endl;
-        }
 
         while (peakidx < m_peaks.size()) {
 
@@ -316,9 +305,7 @@ StretchCalculator::mapPeaks(std::vector<Peak> &peaks,
                 continue;
             }
 
-            if (m_debugLevel > 1) {
+            m_log.log(2, "mapped peak chunk to frame", pchunk, target);
-                std::cerr << "  peak chunk " << pchunk << " (frame " << pchunk * m_increment << ") -> " << target << std::endl;
-            }
 
             peaks.push_back(p);
             targets.push_back(target);
@@ -389,9 +376,7 @@ StretchCalculator::calculateSingle(double timeRatio,
         // this function, which normally precedes resampling - hence
         // the use of timeRatio rather than ratio here
 
-        if (m_debugLevel > 1) {
+        m_log.log(2, "StretchCalculator: ratio changed from and to", m_prevRatio, ratio);
-            std::cerr << "StretchCalculator: ratio changed from " << m_prevRatio << " to " << ratio << std::endl;
-        }
 
         int64_t toCheckpoint = expectedOutFrame
             (m_inFrameCounter, m_prevTimeRatio);
@@ -402,23 +387,25 @@ StretchCalculator::calculateSingle(double timeRatio,
     m_prevRatio = ratio;
     m_prevTimeRatio = timeRatio;
 
-    if (m_debugLevel > 2) {
+    if (m_log.getDebugLevel() > 2) {
-        std::cerr << "StretchCalculator::calculateSingle: timeRatio = "
+        std::ostringstream os;
-                  << timeRatio << ", effectivePitchRatio = "
+        os << "StretchCalculator::calculateSingle: timeRatio = "
-                  << effectivePitchRatio << " (that's 1.0 / "
+           << timeRatio << ", effectivePitchRatio = "
-                  << (1.0 / effectivePitchRatio)
+           << effectivePitchRatio << " (that's 1.0 / "
-                  << "), ratio = " << ratio << ", df = " << df
+           << (1.0 / effectivePitchRatio)
-                  << ", inIncrement = " << inIncrement
+           << "), ratio = " << ratio << ", df = " << df
-                  << ", default outIncrement = " << outIncrement
+           << ", inIncrement = " << inIncrement
-                  << ", analysisWindowSize = " << analysisWindowSize
+           << ", default outIncrement = " << outIncrement
-                  << ", synthesisWindowSize = " << synthesisWindowSize
+           << ", analysisWindowSize = " << analysisWindowSize
-                  << std::endl;
+           << ", synthesisWindowSize = " << synthesisWindowSize
+           << "\n";
 
-        std::cerr << "inFrameCounter = " << m_inFrameCounter
+        os << "inFrameCounter = " << m_inFrameCounter
-                  << ", outFrameCounter = " << m_outFrameCounter
+           << ", outFrameCounter = " << m_outFrameCounter
-                  << std::endl;
+           << "\n";
 
-        std::cerr << "The next sample out is input sample " << m_inFrameCounter << std::endl;
+        os << "The next sample out is input sample " << m_inFrameCounter << "\n";
+        m_log.log(3, os.str().c_str());
     }
 
     int64_t intended, projected;
@@ -436,9 +423,8 @@ StretchCalculator::calculateSingle(double timeRatio,
 
     int64_t divergence = projected - intended;
 
-    if (m_debugLevel > 2) {
+    m_log.log(3, "for current frame + quarter frame: intended vs projected", intended, projected);
-        std::cerr << "for current frame + quarter frame: intended " << intended << ", projected " << projected << ", divergence " << divergence << std::endl;
+    m_log.log(3, "divergence", divergence);
-    }
     
     // In principle, the threshold depends on chunk size: larger chunk
     // sizes need higher thresholds.  Since chunk size depends on
@@ -451,35 +437,26 @@ StretchCalculator::calculateSingle(double timeRatio,
 
     if (m_useHardPeaks && df > m_prevDf * 1.1f && df > transientThreshold) {
         if (divergence > 1000 || divergence < -1000) {
-            if (m_debugLevel > 1) {
+            m_log.log(2, "StretchCalculator::calculateSingle: transient, but we're not permitting it because the divergence is too great", divergence);
-                std::cerr << "StretchCalculator::calculateSingle: transient, but we're not permitting it because the divergence (" << divergence << ") is too great" << std::endl;
-            }
         } else {
             isTransient = true;
         }
     }
 
-    if (m_debugLevel > 2) {
+    m_log.log(3, "df and prevDf", df, m_prevDf);
-        std::cerr << "df = " << df << ", prevDf = " << m_prevDf
-                  << ", thresh = " << transientThreshold << std::endl;
-    }
 
     m_prevDf = df;
 
     if (m_transientAmnesty > 0) {
         if (isTransient) {
-            if (m_debugLevel > 1) {
+            m_log.log(2, "StretchCalculator::calculateSingle: transient, but we have an amnesty: df and threshold", df, transientThreshold);
-                std::cerr << "StretchCalculator::calculateSingle: transient, but we have an amnesty (df " << df << ", threshold " << transientThreshold << ")" << std::endl;
-            }
             isTransient = false;
         }
         --m_transientAmnesty;
     }
             
     if (isTransient) {
-        if (m_debugLevel > 1) {
+        m_log.log(2, "StretchCalculator::calculateSingle: transient: df and threshold", df, transientThreshold);
-            std::cerr << "StretchCalculator::calculateSingle: transient at (df " << df << ", threshold " << transientThreshold << ")" << std::endl;
-        }
 
         // as in offline mode, 0.05 sec approx min between transients
         m_transientAmnesty =
@@ -499,9 +476,10 @@ StretchCalculator::calculateSingle(double timeRatio,
         }
 
         int incr = lrint(outIncrement - recovery);
-        if (m_debugLevel > 2 || (m_debugLevel > 1 && divergence != 0)) {
+
-            std::cerr << "divergence = " << divergence << ", recovery = " << recovery << ", incr = " << incr << ", ";
+        int level = (divergence != 0 ? 2 : 3);
-        }
+        m_log.log(level, "divergence and recovery", divergence, recovery);
+        m_log.log(level, "outIncrement and adjusted incr", outIncrement, incr);
 
         int minIncr = lrint(increment * ratio * 0.3);
         int maxIncr = lrint(increment * ratio * 2);
@@ -512,25 +490,18 @@ StretchCalculator::calculateSingle(double timeRatio,
             incr = maxIncr;
         }
 
-        if (m_debugLevel > 2 || (m_debugLevel > 1 && divergence != 0)) {
+        m_log.log(level, "clamped into", minIncr, maxIncr);
-            std::cerr << "clamped into [" << minIncr << ", " << maxIncr
+        m_log.log(level, "giving incr", incr);
-                      << "] becomes " << incr << std::endl;
-        }
 
         if (incr < 0) {
-            std::cerr << "WARNING: internal error: incr < 0 in calculateSingle"
+            m_log.log(0, "WARNING: internal error: incr < 0 in calculateSingle");
-                      << std::endl;
             outIncrement = 0;
         } else {
             outIncrement = incr;
         }
     }
 
-    if (m_debugLevel > 1) {
+    m_log.log(2, "StretchCalculator::calculateSingle: returning isTransient and outIncrement", isTransient, outIncrement);
-        std::cerr << "StretchCalculator::calculateSingle: returning isTransient = "
-                  << isTransient << ", outIncrement = " << outIncrement
-                  << std::endl;
-    }
 
     m_inFrameCounter += inIncrement;
     m_outFrameCounter += outIncrement * effectivePitchRatio;
@@ -584,9 +555,7 @@ StretchCalculator::findPeaks(const std::vector<float> &rawDf)
                                             (20 * double(m_increment))));
         size_t prevHardPeak = 0;
 
-        if (m_debugLevel > 1) {
+        m_log.log(2, "hardPeakAmnesty", hardPeakAmnesty);
-            std::cerr << "hardPeakAmnesty = " << hardPeakAmnesty << std::endl;
-        }
 
         for (size_t i = 1; i + 1 < df.size(); ++i) {
 
@@ -600,20 +569,16 @@ StretchCalculator::findPeaks(const std::vector<float> &rawDf)
             }
 
             bool hard = (df[i] > 0.4);
-            
+
-            if (hard && (m_debugLevel > 1)) {
+            if (hard) {
-                std::cerr << "hard peak at " << i << ": " << df[i] 
+                m_log.log(2, "hard peak, df > absolute 0.4: chunk and df", i, df[i]);
-                          << " > absolute " << 0.4
-                          << std::endl;
             }
 
             if (!hard) {
                 hard = (df[i] > df[i-1] * 1.4);
 
-                if (hard && (m_debugLevel > 1)) {
+                if (hard) {
-                    std::cerr << "hard peak at " << i << ": " << df[i] 
+                    m_log.log(2, "hard peak, single rise of 40%: chunk and df", i, df[i]);
-                              << " > prev " << df[i-1] << " * 1.4"
-                              << std::endl;
                 }
             }
 
@@ -621,11 +586,8 @@ StretchCalculator::findPeaks(const std::vector<float> &rawDf)
                 hard = (df[i]   > df[i-1] * 1.2 &&
                         df[i-1] > df[i-2] * 1.2);
 
-                if (hard && (m_debugLevel > 1)) {
+                if (hard) {
-                    std::cerr << "hard peak at " << i << ": " << df[i] 
+                    m_log.log(2, "hard peak, two rises of 20%: chunk and df", i, df[i]);
-                              << " > prev " << df[i-1] << " * 1.2 and "
-                              << df[i-1] << " > prev " << df[i-2] << " * 1.2"
-                              << std::endl;
                 }
             }
 
@@ -635,20 +597,13 @@ StretchCalculator::findPeaks(const std::vector<float> &rawDf)
                         df[i-1] > df[i-2] * 1.1 &&
                         df[i-2] > df[i-3] * 1.1);
 
-                if (hard && (m_debugLevel > 1)) {
+                if (hard) {
-                    std::cerr << "hard peak at " << i << ": " << df[i] 
+                    m_log.log(2, "hard peak, three rises of 10%: chunk and df", i, df[i]);
-                              << " > prev " << df[i-1] << " * 1.1 and "
-                              << df[i-1] << " > prev " << df[i-2] << " * 1.1 and "
-                              << df[i-2] << " > prev " << df[i-3] << " * 1.1"
-                              << std::endl;
                 }
             }
 
             if (!hard) continue;
 
-//            (df[i+1] > df[i] && df[i+1] > df[i-1] * 1.8) ||
-//                df[i] > 0.4) {
-
             size_t peakLocation = i;
 
             if (i + 1 < rawDf.size() &&
@@ -656,9 +611,7 @@ StretchCalculator::findPeaks(const std::vector<float> &rawDf)
 
                 ++peakLocation;
 
-                if (m_debugLevel > 1) {
+                m_log.log(2, "big rise next, pushing hard peak forward to", peakLocation);
-                    std::cerr << "pushing hard peak forward to " << peakLocation << ": " << df[peakLocation] << " > " << df[peakLocation-1] << " * " << 1.4 << std::endl;
-                }
             }
 
             hardPeakCandidates.insert(peakLocation);
@@ -669,14 +622,10 @@ StretchCalculator::findPeaks(const std::vector<float> &rawDf)
     size_t medianmaxsize = lrint(ceil(double(m_sampleRate) /
                                  double(m_increment))); // 1 sec ish
 
-    if (m_debugLevel > 1) {
+    m_log.log(2, "mediansize", medianmaxsize);
-        std::cerr << "mediansize = " << medianmaxsize << std::endl;
-    }
     if (medianmaxsize < 7) {
         medianmaxsize = 7;
-        if (m_debugLevel > 1) {
+        m_log.log(2, "adjusted mediansize", medianmaxsize);
-            std::cerr << "adjusted mediansize = " << medianmaxsize << std::endl;
-        }
     }
 
     int minspacing = lrint(ceil(double(m_sampleRate) /
@@ -720,10 +669,6 @@ StretchCalculator::findPeaks(const std::vector<float> &rawDf)
             continue;
         }
 
-        if (m_debugLevel > 2) {
-//            std::cerr << "have " << mediansize << " in median buffer" << std::endl;
-        }
-
         sorted.clear();
         for (size_t j = 0; j < mediansize; ++j) {
             sorted.push_back(medianwin[j]);
@@ -736,17 +681,6 @@ StretchCalculator::findPeaks(const std::vector<float> &rawDf)
         if (index == sorted.size()-1 && index > 0) --index;
         float thresh = sorted[index];
 
-//        if (m_debugLevel > 2) {
-//            std::cerr << "medianwin[" << middle << "] = " << medianwin[middle] << ", thresh = " << thresh << std::endl;
-//            if (medianwin[middle] == 0.f) {
-//                std::cerr << "contents: ";
-//                for (size_t j = 0; j < medianwin.size(); ++j) {
-//                    std::cerr << medianwin[j] << " ";
-//                }
-//                std::cerr << std::endl;
-//            }
-//        }
-
         if (medianwin[middle] > thresh &&
             medianwin[middle] > medianwin[middle-1] &&
             medianwin[middle] > medianwin[middle+1] &&
@@ -766,26 +700,10 @@ StretchCalculator::findPeaks(const std::vector<float> &rawDf)
 
             size_t peak = i + maxindex - middle;
 
-//            std::cerr << "i = " << i << ", maxindex = " << maxindex << ", middle = " << middle << ", so peak at " << peak << std::endl;
-
             if (softPeakCandidates.empty() || lastSoftPeak != peak) {
-
+                m_log.log(2, "soft peak: chunk and median df", peak, medianwin[middle]);
-                if (m_debugLevel > 1) {
-                    std::cerr << "soft peak at " << peak << " ("
-                              << peak * m_increment << "): "
-                              << medianwin[middle] << " > "
-                              << thresh << " and "
-                              << medianwin[middle]
-                              << " > " << medianwin[middle-1] << " and "
-                              << medianwin[middle]
-                              << " > " << medianwin[middle+1]
-                              << std::endl;
-                }
-
                 if (peak >= df.size()) {
-                    if (m_debugLevel > 2) {
+                    m_log.log(2, "peak is beyond end");
-                        std::cerr << "peak is beyond end"  << std::endl;
-                    }
                 } else {
                     softPeakCandidates.insert(peak);
                     lastSoftPeak = peak;
@@ -793,9 +711,7 @@ StretchCalculator::findPeaks(const std::vector<float> &rawDf)
             }
 
             softPeakAmnesty = minspacing + maxindex - middle;
-            if (m_debugLevel > 2) {
+            m_log.log(3, "amnesty", softPeakAmnesty);
-                std::cerr << "amnesty = " << softPeakAmnesty << std::endl;
-            }
 
         } else if (softPeakAmnesty > 0) --softPeakAmnesty;
 
@@ -827,26 +743,16 @@ StretchCalculator::findPeaks(const std::vector<float> &rawDf)
 
         if (haveHardPeak &&
             (!haveSoftPeak || hardPeak <= softPeak)) {
-
+            m_log.log(3, "hard peak", hardPeak);
-            if (m_debugLevel > 2) {
-                std::cerr << "Hard peak: " << hardPeak << std::endl;
-            }
-
             peak.hard = true;
             peak.chunk = hardPeak;
             hardPeakCandidates.erase(hardPeakCandidates.begin());
-
         } else {
-            if (m_debugLevel > 2) {
+            m_log.log(3, "soft peak", softPeak);
-                std::cerr << "Soft peak: " << softPeak << std::endl;
-            }
             if (!peaks.empty() &&
                 peaks[peaks.size()-1].hard &&
                 peaks[peaks.size()-1].chunk + 3 >= softPeak) {
-                if (m_debugLevel > 2) {
+                m_log.log(3, "ignoring, as we just had a hard peak");
-                    std::cerr << "(ignoring, as we just had a hard peak)"
-                              << std::endl;
-                }
                 ignore = true;
             }
         }            

src/common/StretchCalculator.h

@@ -30,13 +30,18 @@
 #include <map>
 #include <cstdint>
 
+#include "Log.h"
+
 namespace RubberBand
 {
 
 class StretchCalculator
 {
 public:
-    StretchCalculator(size_t sampleRate, size_t inputIncrement, bool useHardPeaks);
+    StretchCalculator(size_t sampleRate,
+                      size_t inputIncrement,
+                      bool useHardPeaks,
+                      Log log);
     virtual ~StretchCalculator();
 
     /**
@@ -107,6 +112,7 @@ protected:
     std::pair<int64_t, int64_t> m_frameCheckpoint;
     int64_t expectedOutFrame(int64_t inFrame, double timeRatio);
     double m_outFrameCounter;
+    Log m_log;
 
     std::map<size_t, size_t> m_keyFrameMap;
     std::vector<Peak> m_peaks;

src/faster/R2Stretcher.cpp

@@ -40,8 +40,6 @@
 #include <map>
 #include <algorithm>
 
-using std::cerr;
-using std::endl;
 using std::vector;
 using std::map;
 using std::set;
@@ -56,16 +54,14 @@ R2Stretcher::m_defaultIncrement = 256;
 const size_t
 R2Stretcher::m_defaultFftSize = 2048;
 
-int
-R2Stretcher::m_defaultDebugLevel = 0;
-
 static bool _initialised = false;
 
 R2Stretcher::R2Stretcher(size_t sampleRate,
                          size_t channels,
                          RubberBandStretcher::Options options,
                          double initialTimeRatio,
-                         double initialPitchScale) :
+                         double initialPitchScale,
+                         Log log) :
     m_sampleRate(sampleRate),
     m_channels(channels),
     m_timeRatio(initialTimeRatio),
@@ -82,7 +78,7 @@ R2Stretcher::R2Stretcher(size_t sampleRate,
 #endif
     m_realtime(false),
     m_options(options),
-    m_debugLevel(m_defaultDebugLevel),
+    m_log(log),
     m_mode(JustCreated),
     m_awindow(0),
     m_afilter(0),
@@ -110,9 +106,10 @@ R2Stretcher::R2Stretcher(size_t sampleRate,
         _initialised = true;
     }
 
-    if (m_debugLevel > 0) {
+    m_log.log(1, "R2Stretcher::R2Stretcher: rate, options",
-        cerr << "R2Stretcher::R2Stretcher: rate = " << m_sampleRate << ", options = " << options << endl;
+              m_sampleRate, options);
-    }
+    m_log.log(1, "R2Stretcher::R2Stretcher: initial time ratio and pitch scale",
+              m_timeRatio, m_pitchScale);
 
     // Window size will vary according to the audio sample rate, but
     // we don't let it drop below the 48k default
@@ -124,17 +121,13 @@ R2Stretcher::R2Stretcher(size_t sampleRate,
         (options & RubberBandStretcher::OptionWindowLong)) {
         if ((options & RubberBandStretcher::OptionWindowShort) &&
             (options & RubberBandStretcher::OptionWindowLong)) {
-            cerr << "R2Stretcher::R2Stretcher: Cannot specify OptionWindowLong and OptionWindowShort together; falling back to OptionWindowStandard" << endl;
+            m_log.log(0, "R2Stretcher::R2Stretcher: Cannot specify OptionWindowLong and OptionWindowShort together; falling back to OptionWindowStandard");
         } else if (options & RubberBandStretcher::OptionWindowShort) {
             m_baseFftSize = m_baseFftSize / 2;
-            if (m_debugLevel > 0) {
+            m_log.log(1, "setting baseFftSize", m_baseFftSize);
-                cerr << "setting baseFftSize to " << m_baseFftSize << endl;
-            }
         } else if (options & RubberBandStretcher::OptionWindowLong) {
             m_baseFftSize = m_baseFftSize * 2;
-            if (m_debugLevel > 0) {
+            m_log.log(1, "setting baseFftSize", m_baseFftSize);
-                cerr << "setting baseFftSize to " << m_baseFftSize << endl;
-            }
         }
         m_fftSize = m_baseFftSize;
         m_aWindowSize = m_baseFftSize;
@@ -161,8 +154,8 @@ R2Stretcher::R2Stretcher(size_t sampleRate,
             m_threaded = false;
         }
 
-        if (m_threaded && m_debugLevel > 0) {
+        if (m_threaded) {
-            cerr << "Going multithreaded..." << endl;
+            m_log.log(1, "Going multithreaded...");
         }
     }
 #endif
@@ -177,9 +170,7 @@ R2Stretcher::~R2Stretcher()
         MutexLocker locker(&m_threadSetMutex);
         for (set<ProcessThread *>::iterator i = m_threadSet.begin();
              i != m_threadSet.end(); ++i) {
-            if (m_debugLevel > 0) {
+            m_log.log(1, "RubberBandStretcher::~RubberBandStretcher: joining for channel", (*i)->channel());
-                cerr << "RubberBandStretcher::~RubberBandStretcher: joining (channel " << *i << ")" << endl;
-            }
             (*i)->abandon();
             (*i)->wait();
             delete *i;
@@ -214,9 +205,7 @@ R2Stretcher::reset()
         m_threadSetMutex.lock();
         for (set<ProcessThread *>::iterator i = m_threadSet.begin();
              i != m_threadSet.end(); ++i) {
-            if (m_debugLevel > 0) {
+            m_log.log(1, "RubberBandStretcher::~RubberBandStretcher: joining for channel", (*i)->channel());
-                cerr << "RubberBandStretcher::~RubberBandStretcher: joining (channel " << *i << ")" << endl;
-            }
             (*i)->abandon();
             (*i)->wait();
             delete *i;
@@ -253,7 +242,7 @@ R2Stretcher::setTimeRatio(double ratio)
 {
     if (!m_realtime) {
         if (m_mode == Studying || m_mode == Processing) {
-            cerr << "R2Stretcher::setTimeRatio: Cannot set ratio while studying or processing in non-RT mode" << endl;
+            m_log.log(0, "R2Stretcher::setTimeRatio: Cannot set ratio while studying or processing in non-RT mode");
             return;
         }
     }
@@ -269,7 +258,7 @@ R2Stretcher::setPitchScale(double fs)
 {
     if (!m_realtime) {
         if (m_mode == Studying || m_mode == Processing) {
-            cerr << "R2Stretcher::setPitchScale: Cannot set ratio while studying or processing in non-RT mode" << endl;
+            m_log.log(0, "R2Stretcher::setPitchScale: Cannot set ratio while studying or processing in non-RT mode");
             return;
         }
     }
@@ -331,11 +320,11 @@ R2Stretcher::setKeyFrameMap(const std::map<size_t, size_t> &
                                           mapping)
 {
     if (m_realtime) {
-        cerr << "R2Stretcher::setKeyFrameMap: Cannot specify key frame map in RT mode" << endl;
+        m_log.log(0, "R2Stretcher::setKeyFrameMap: Cannot specify key frame map in RT mode");
         return;
     }
     if (m_mode == Processing) {
-        cerr << "R2Stretcher::setKeyFrameMap: Cannot specify key frame map after process() has begun" << endl;
+        m_log.log(0, "R2Stretcher::setKeyFrameMap: Cannot specify key frame map after process() has begun");
         return;
     }
 
@@ -403,12 +392,12 @@ R2Stretcher::calculateSizes()
         // This special case is likelier than one might hope, because
         // of naive initialisations in programs that set it from a
         // variable
-        std::cerr << "RubberBandStretcher: WARNING: Pitch scale must be greater than zero!\nResetting it from " << m_pitchScale << " to the default of 1.0: no pitch change will occur" << std::endl;
+        m_log.log(0, "WARNING: Pitch scale must be greater than zero! Resetting it to default, no pitch shift will happen", m_pitchScale);
         m_pitchScale = 1.0;
     }
     if (m_timeRatio <= 0.0) {
         // Likewise
-        std::cerr << "RubberBandStretcher: WARNING: Time ratio must be greater than zero!\nResetting it from " << m_timeRatio << " to the default of 1.0: no time stretch will occur" << std::endl;
+        m_log.log(0, "WARNING: Time ratio must be greater than zero! Resetting it to default, no time stretch will happen", m_timeRatio);
         m_timeRatio = 1.0;
     }
 
@@ -461,7 +450,7 @@ R2Stretcher::calculateSizes()
             if (windowSize < minwin) windowSize = minwin;
 
             if (rsb) {
-//                cerr << "adjusting window size from " << windowSize;
+                size_t oldWindowSize = windowSize;
                 size_t newWindowSize = roundUp(lrint(windowSize / m_pitchScale));
                 if (newWindowSize < 512) newWindowSize = 512;
                 size_t div = windowSize / newWindowSize;
@@ -470,7 +459,8 @@ R2Stretcher::calculateSizes()
                     outputIncrement /= div;
                     windowSize /= div;
                 }
-//                cerr << " to " << windowSize << " (inputIncrement = " << inputIncrement << ", outputIncrement = " << outputIncrement << ")" << endl;
+                m_log.log(2, "adjusting window size from/to", oldWindowSize, windowSize);
+                m_log.log(2, "input and output increments", inputIncrement, outputIncrement);
             }
         }
 
@@ -530,10 +520,11 @@ R2Stretcher::calculateSizes()
     // twice the basic output increment (i.e. input increment times
     // ratio) for any chunk.
 
-    if (m_debugLevel > 0) {
+    m_log.log(1, "calculateSizes: time ratio and pitch scale", m_timeRatio, m_pitchScale);
-        cerr << "calculateSizes: time ratio = " << m_timeRatio << ", pitch scale = " << m_pitchScale << ", effective ratio = " << getEffectiveRatio() << endl;
+    m_log.log(1, "effective ratio", getEffectiveRatio());
-        cerr << "calculateSizes: analysis window size = " << m_aWindowSize << ", synthesis window size = " << m_sWindowSize << ", fft size = " << m_fftSize << ", increment = " << m_increment << " (approx output increment = " << int(lrint(m_increment * getEffectiveRatio())) << ")" << endl;
+    m_log.log(1, "analysis and synthesis window sizes", m_aWindowSize, m_sWindowSize);
-    }
+    m_log.log(1, "fft size", m_fftSize);
+    m_log.log(1, "input increment and mean output increment", m_increment, m_increment * getEffectiveRatio());
 
     if (std::max(m_aWindowSize, m_sWindowSize) > m_maxProcessSize) {
         m_maxProcessSize = std::max(m_aWindowSize, m_sWindowSize);
@@ -561,18 +552,19 @@ R2Stretcher::calculateSizes()
 #endif
     }
 
-    if (m_debugLevel > 0) {
+    m_log.log(1, "calculateSizes: outbuf size", m_outbufSize);
-        cerr << "calculateSizes: outbuf size = " << m_outbufSize << endl;
-    }
 }
 
 void
 R2Stretcher::configure()
 {
-    if (m_debugLevel > 0) {
+    if (m_realtime) {
-        std::cerr << "configure[" << this << "]: realtime = " << m_realtime << ", pitch scale = "
+        m_log.log(1, "configure, realtime: pitch scale and channels",
-                  << m_pitchScale << ", channels = " << m_channels << std::endl;
+                  m_pitchScale, m_channels);
-    }
+    } else {
+        m_log.log(1, "configure, offline: pitch scale and channels",
+                  m_pitchScale, m_channels);
+    }              
 
     size_t prevFftSize = m_fftSize;
     size_t prevAWindowSize = m_aWindowSize;
@@ -626,9 +618,8 @@ R2Stretcher::configure()
         m_afilter = m_sincs[m_aWindowSize];
         m_swindow = m_windows[m_sWindowSize];
 
-        if (m_debugLevel > 0) {
+        m_log.log(1, "analysis and synthesis window areas",
-            cerr << "Window area: " << m_awindow->getArea() << "; synthesis window area: " << m_swindow->getArea() << endl;
+                  m_awindow->getArea(), m_swindow->getArea());
-        }
     }
 
     if (windowSizeChanged || outbufSizeChanged) {
@@ -649,7 +640,7 @@ R2Stretcher::configure()
 
     if (!m_realtime && fftSizeChanged) {
         delete m_studyFFT;
-        m_studyFFT = new FFT(m_fftSize, m_debugLevel);
+        m_studyFFT = new FFT(m_fftSize, m_log.getDebugLevel());
         m_studyFFT->initFloat();
     }
 
@@ -674,7 +665,8 @@ R2Stretcher::configure()
             }
             
             params.maxBufferSize = 4096 * 16;
-            params.debugLevel = (m_debugLevel > 0 ? m_debugLevel-1 : 0);
+            int myLevel = m_log.getDebugLevel();
+            params.debugLevel = (myLevel > 0 ? myLevel-1 : 0);
             
             m_channelData[c]->resampler = new Resampler(params, 1);
 
@@ -700,9 +692,10 @@ R2Stretcher::configure()
     delete m_stretchCalculator;
     m_stretchCalculator = new StretchCalculator
         (m_sampleRate, m_increment,
-         !(m_options & RubberBandStretcher::OptionTransientsSmooth));
+         !(m_options & RubberBandStretcher::OptionTransientsSmooth),
+         m_log);
 
-    m_stretchCalculator->setDebugLevel(m_debugLevel);
+    m_stretchCalculator->setDebugLevel(m_log.getDebugLevel());
     m_inputDuration = 0;
 
     // Prepare the inbufs with half a chunk of emptiness.  The centre
@@ -717,17 +710,16 @@ R2Stretcher::configure()
     // want gaps when the ratio changes.
 
     if (!m_realtime) {
-        if (m_debugLevel > 1) {
+        m_log.log(1, "offline mode: prefilling with", m_aWindowSize/2);
-            cerr << "Not real time mode: prefilling with " << m_aWindowSize/2 << " samples" << endl;
-        }
         for (size_t c = 0; c < m_channels; ++c) {
             m_channelData[c]->reset();
             m_channelData[c]->inbuf->zero(m_aWindowSize/2);
         }
+    } else {
+        m_log.log(1, "realtime mode: no prefill");
     }
 }
 
-
 void
 R2Stretcher::reconfigure()
 {
@@ -763,7 +755,7 @@ R2Stretcher::reconfigure()
         m_sWindowSize != prevSWindowSize) {
 
         if (m_windows.find(m_aWindowSize) == m_windows.end()) {
-            std::cerr << "WARNING: reconfigure(): window allocation (size " << m_aWindowSize << ") required in RT mode" << std::endl;
+            m_log.log(0, "WARNING: reconfigure(): window allocation required in realtime mode, size", m_aWindowSize);
             m_windows[m_aWindowSize] = new Window<float>
                 (HannWindow, m_aWindowSize);
             m_sincs[m_aWindowSize] = new SincWindow<float>
@@ -771,7 +763,7 @@ R2Stretcher::reconfigure()
         }
 
         if (m_windows.find(m_sWindowSize) == m_windows.end()) {
-            std::cerr << "WARNING: reconfigure(): window allocation (size " << m_sWindowSize << ") required in RT mode" << std::endl;
+            m_log.log(0, "WARNING: reconfigure(): window allocation required in realtime mode, size", m_sWindowSize);
             m_windows[m_sWindowSize] = new Window<float>
                 (HannWindow, m_sWindowSize);
             m_sincs[m_sWindowSize] = new SincWindow<float>
@@ -802,14 +794,15 @@ R2Stretcher::reconfigure()
 
             if (m_channelData[c]->resampler) continue;
 
-            std::cerr << "WARNING: reconfigure(): resampler construction required in RT mode" << std::endl;
+            m_log.log(0, "WARNING: reconfigure(): resampler construction required in RT mode");
 
             Resampler::Parameters params;
             params.quality = Resampler::FastestTolerable;
             params.dynamism = Resampler::RatioOftenChanging;
             params.ratioChange = Resampler::SmoothRatioChange;
             params.maxBufferSize = m_sWindowSize;
-            params.debugLevel = (m_debugLevel > 0 ? m_debugLevel-1 : 0);
+            int myLevel = m_log.getDebugLevel();
+            params.debugLevel = (myLevel > 0 ? myLevel-1 : 0);
             
             m_channelData[c]->resampler = new Resampler(params, 1);
 
@@ -828,12 +821,10 @@ R2Stretcher::reconfigure()
         somethingChanged = true;
     }
 
-    if (m_debugLevel > 0) {
+    if (somethingChanged) {
-        if (somethingChanged) {
+        m_log.log(1, "reconfigure: at least one parameter changed");
-            std::cerr << "reconfigure: at least one parameter changed" << std::endl;
+    } else {
-        } else {
+        m_log.log(1, "reconfigure: nothing changed");
-            std::cerr << "reconfigure: nothing changed" << std::endl;
-        }
     }
 }
 
@@ -848,7 +839,7 @@ void
 R2Stretcher::setTransientsOption(RubberBandStretcher::Options options)
 {
     if (!m_realtime) {
-        cerr << "R2Stretcher::setTransientsOption: Not permissible in non-realtime mode" << endl;
+        m_log.log(0, "R2Stretcher::setTransientsOption: Not permissible in non-realtime mode");
         return;
     }
     int mask = (RubberBandStretcher::OptionTransientsMixed |
@@ -866,7 +857,7 @@ void
 R2Stretcher::setDetectorOption(RubberBandStretcher::Options options)
 {
     if (!m_realtime) {
-        cerr << "R2Stretcher::setDetectorOption: Not permissible in non-realtime mode" << endl;
+        m_log.log(0, "R2Stretcher::setDetectorOption: Not permissible in non-realtime mode");
         return;
     }
     int mask = (RubberBandStretcher::OptionDetectorPercussive |
@@ -915,7 +906,7 @@ void
 R2Stretcher::setPitchOption(RubberBandStretcher::Options options)
 {
     if (!m_realtime) {
-        cerr << "R2Stretcher::setPitchOption: Pitch option is not used in non-RT mode" << endl;
+        m_log.log(0, "R2Stretcher::setPitchOption: Pitch option is not used in non-RT mode");
         return;
     }
 
@@ -937,14 +928,12 @@ R2Stretcher::study(const float *const *input, size_t samples, bool final)
     Profiler profiler("R2Stretcher::study");
 
     if (m_realtime) {
-        if (m_debugLevel > 1) {
+        m_log.log(0, "R2Stretcher::study: Not meaningful in realtime mode");
-            cerr << "R2Stretcher::study: Not meaningful in realtime mode" << endl;
-        }
         return;
     }
 
     if (m_mode == Processing || m_mode == Finished) {
-        cerr << "R2Stretcher::study: Cannot study after processing" << endl;
+        m_log.log(0, "R2Stretcher::study: Cannot study after processing");
         return;
     }
     m_mode = Studying;
@@ -987,7 +976,8 @@ R2Stretcher::study(const float *const *input, size_t samples, bool final)
 
 	if (writable == 0) {
             // warn
-            cerr << "WARNING: writable == 0 (consumed = " << consumed << ", samples = " << samples << ")" << endl;
+            m_log.log(0, "WARNING: writable == 0: consumed, samples",
+                      consumed, samples);
 	} else {
             inbuf.write(mixdown + consumed, writable);
             consumed += writable;
@@ -1048,8 +1038,8 @@ R2Stretcher::study(const float *const *input, size_t samples, bool final)
 
             df = m_silentAudioCurve->processFloat(cd.fltbuf, m_increment);
             bool silent = (df > 0.f);
-            if (silent && m_debugLevel > 1) {
+            if (silent) {
-                cerr << "silence found at " << m_inputDuration << endl;
+                m_log.log(2, "silence at", m_inputDuration);
             }
             m_silence.push_back(silent);
 
@@ -1063,7 +1053,6 @@ R2Stretcher::study(const float *const *input, size_t samples, bool final)
             // extra afterwards.
 
             m_inputDuration += m_increment;
-//                cerr << "incr input duration by increment: " << m_increment << " -> " << m_inputDuration << endl;
             inbuf.skip(m_increment);
 	}
     }
@@ -1071,8 +1060,6 @@ R2Stretcher::study(const float *const *input, size_t samples, bool final)
     if (final) {
         int rs = inbuf.getReadSpace();
         m_inputDuration += rs;
-//        cerr << "incr input duration by read space: " << rs << " -> " << m_inputDuration << endl;
-
         if (m_inputDuration > m_aWindowSize/2) { // deducting the extra
             m_inputDuration -= m_aWindowSize/2;
         }
@@ -1132,7 +1119,7 @@ R2Stretcher::calculateStretch()
 
     if (!m_realtime && m_expectedInputDuration > 0) {
         if (m_expectedInputDuration != inputDuration) {
-            std::cerr << "RubberBandStretcher: WARNING: Actual study() duration differs from duration set by setExpectedInputDuration (" << m_inputDuration << " vs " << m_expectedInputDuration << ", diff = " << (m_expectedInputDuration - m_inputDuration) << "), using the latter for calculation" << std::endl;
+            m_log.log(0, "WARNING: Actual study() duration differs from duration set by setExpectedInputDuration - using the latter for calculation", m_inputDuration, m_expectedInputDuration);
             inputDuration = m_expectedInputDuration;
         }
     }
@@ -1149,10 +1136,7 @@ R2Stretcher::calculateStretch()
         else history = 0;
         if (history >= int(m_aWindowSize / m_increment) && increments[i] >= 0) {
             increments[i] = -increments[i];
-            if (m_debugLevel > 1) {
+            m_log.log(2, "phase reset on silence: silent history", history);
-                std::cerr << "phase reset on silence (silent history == "
-                          << history << ")" << std::endl;
-            }
         }
     }
 
@@ -1169,8 +1153,10 @@ R2Stretcher::calculateStretch()
 void
 R2Stretcher::setDebugLevel(int level)
 {
-    m_debugLevel = level;
+    m_log.setDebugLevel(level);
-    if (m_stretchCalculator) m_stretchCalculator->setDebugLevel(level);
+    if (m_stretchCalculator) {
+        m_stretchCalculator->setDebugLevel(level);
+    }
 }	
 
 size_t
@@ -1191,9 +1177,7 @@ R2Stretcher::getSamplesRequired() const
         size_t rs = inbuf.getReadSpace();
         size_t ws = outbuf.getReadSpace();
 
-        if (m_debugLevel > 2) {
+        m_log.log(3, "getSamplesRequired: ws and rs ", ws, rs);
-            cerr << "getSamplesRequired: ws = " << ws << ", rs = " << rs << ", m_aWindowSize = " << m_aWindowSize << endl;
-        }
 
         // We should never return zero in non-threaded modes if
         // available() would also return zero, i.e. if ws == 0.  If we
@@ -1230,7 +1214,7 @@ R2Stretcher::process(const float *const *input, size_t samples, bool final)
     Profiler profiler("R2Stretcher::process");
 
     if (m_mode == Finished) {
-        cerr << "R2Stretcher::process: Cannot process again after final chunk" << endl;
+        m_log.log(0, "R2Stretcher::process: Cannot process again after final chunk");
         return;
     }
 
@@ -1243,9 +1227,7 @@ R2Stretcher::process(const float *const *input, size_t samples, bool final)
             if (!m_realtime) {
                 // See note in configure() above. Of course, we should
                 // never enter Studying unless we are non-RT anyway
-                if (m_debugLevel > 1) {
+                m_log.log(1, "offline mode: prefilling with", m_aWindowSize/2);
-                    cerr << "Not real time mode: prefilling" << endl;
-                }
                 for (size_t c = 0; c < m_channels; ++c) {
                     m_channelData[c]->reset();
                     m_channelData[c]->inbuf->zero(m_aWindowSize/2);
@@ -1262,10 +1244,8 @@ R2Stretcher::process(const float *const *input, size_t samples, bool final)
                 m_threadSet.insert(thread);
                 thread->start();
             }
-            
+
-            if (m_debugLevel > 0) {
+            m_log.log(1, "created threads", m_channels);
-                cerr << m_channels << " threads created" << endl;
-            }
         }
 #endif
         
@@ -1297,12 +1277,10 @@ R2Stretcher::process(const float *const *input, size_t samples, bool final)
                                           final);
             if (consumed[c] < samples) {
                 allConsumed = false;
-//                cerr << "process: waiting on input consumption for channel " << c << endl;
             } else {
                 if (final) {
                     m_channelData[c]->inputSize = m_channelData[c]->inCount;
                 }
-//                cerr << "process: happy with channel " << c << endl;
             }
             if (
 #ifndef NO_THREADING
@@ -1335,14 +1313,10 @@ R2Stretcher::process(const float *const *input, size_t samples, bool final)
         }
 #endif
 
-        if (m_debugLevel > 1) {
+        m_log.log(2, "process looping");
-            if (!allConsumed) cerr << "process looping" << endl;
-        }
     }
 
-    if (m_debugLevel > 1) {
+    m_log.log(2, "process returning");
-        cerr << "process returning" << endl;
-    }
 
     if (final) m_mode = Finished;
 }

src/faster/R2Stretcher.h

@@ -31,6 +31,7 @@
 #include "../common/RingBuffer.h"
 #include "../common/Scavenger.h"
 #include "../common/Thread.h"
+#include "../common/Log.h"
 #include "../common/sysutils.h"
 
 #include "SincWindow.h"
@@ -50,7 +51,8 @@ class R2Stretcher
 public:
     R2Stretcher(size_t sampleRate, size_t channels,
                 RubberBandStretcher::Options options,
-                double initialTimeRatio, double initialPitchScale);
+                double initialTimeRatio, double initialPitchScale,
+                Log log);
     ~R2Stretcher();
     
     void reset();
@@ -98,7 +100,6 @@ public:
     void calculateStretch();
 
     void setDebugLevel(int level);
-    static void setDefaultDebugLevel(int level) { m_defaultDebugLevel = level; }
 
 protected:
     size_t m_sampleRate;
@@ -174,7 +175,7 @@ protected:
 
     bool m_realtime;
     RubberBandStretcher::Options m_options;
-    int m_debugLevel;
+    Log m_log;
 
     enum ProcessMode {
         JustCreated,
@@ -202,6 +203,7 @@ protected:
         void run();
         void signalDataAvailable();
         void abandon();
+        size_t channel() { return m_channel; }
     private:
         R2Stretcher *m_s;
         size_t m_channel;
@@ -251,7 +253,6 @@ protected:
     void writeOutput(RingBuffer<float> &to, float *from,
                      size_t qty, size_t &outCount, size_t theoreticalOut);
 
-    static int m_defaultDebugLevel;
     static const size_t m_defaultIncrement;
     static const size_t m_defaultFftSize;
 };

src/faster/StretcherChannelData.cpp

@@ -56,8 +56,6 @@ R2Stretcher::ChannelData::construct(const std::set<size_t> &sizes,
     size_t maxSize = initialWindowSize * 2;
     if (initialFftSize > maxSize) maxSize = initialFftSize;
 
-//    std::cerr << "ChannelData::construct: initialWindowSize = " << initialWindowSize << ", initialFftSize = " << initialFftSize << ", outbufSize = " << outbufSize << std::endl;
-
     // std::set is ordered by value
     std::set<size_t>::const_iterator i = sizes.end();
     if (i != sizes.begin()) {
@@ -68,8 +66,6 @@ R2Stretcher::ChannelData::construct(const std::set<size_t> &sizes,
     // max possible size of the real "half" of freq data
     size_t realSize = maxSize / 2 + 1;
 
-//    std::cerr << "ChannelData::construct([" << sizes.size() << "], " << maxSize << ", " << realSize << ", " << outbufSize << ")" << std::endl;
-    
     if (outbufSize < maxSize) outbufSize = maxSize;
 
     inbuf = new RingBuffer<float>(maxSize);
@@ -117,8 +113,6 @@ void
 R2Stretcher::ChannelData::setSizes(size_t windowSize,
                                                  size_t fftSize)
 {
-//    std::cerr << "ChannelData::setSizes: windowSize = " << windowSize << ", fftSize = " << fftSize << std::endl;
-
     size_t maxSize = 2 * std::max(windowSize, fftSize);
     size_t realSize = maxSize / 2 + 1;
     size_t oldMax = inbuf->getSize();
@@ -210,8 +204,6 @@ R2Stretcher::ChannelData::setOutbufSize(size_t outbufSize)
 {
     size_t oldSize = outbuf->getSize();
 
-//    std::cerr << "ChannelData::setOutbufSize(" << outbufSize << ") [from " << oldSize << "]" << std::endl;
-
     if (oldSize < outbufSize) {
 
         //!!! at this point we need a lock in case a different client

src/faster/StretcherProcess.cpp

@@ -40,9 +40,6 @@
 
 using namespace RubberBand;
 
-using std::cerr;
-using std::endl;
-
 namespace RubberBand {
 
 #ifndef NO_THREADING
@@ -57,20 +54,13 @@ R2Stretcher::ProcessThread::ProcessThread(R2Stretcher *s, size_t c) :
 void
 R2Stretcher::ProcessThread::run()
 {
-    if (m_s->m_debugLevel > 1) {
+    m_s->m_log.log(2, "thread getting going for channel", m_channel);
-        cerr << "thread " << m_channel << " getting going" << endl;
-    }
 
     ChannelData &cd = *m_s->m_channelData[m_channel];
 
     while (cd.inputSize == -1 ||
            cd.inbuf->getReadSpace() > 0) {
 
-//        if (cd.inputSize != -1) {
-//            cerr << "inputSize == " << cd.inputSize
-//                 << ", readSpace == " << cd.inbuf->getReadSpace() << endl;
-//        }
-        
         bool any = false, last = false;
         m_s->processChunks(m_channel, any, last);
 
@@ -89,9 +79,7 @@ R2Stretcher::ProcessThread::run()
         m_dataAvailable.unlock();
 
         if (m_abandoning) {
-            if (m_s->m_debugLevel > 1) {
+            m_s->m_log.log(2, "thread abandoning for channel", m_channel);
-                cerr << "thread " << m_channel << " abandoning" << endl;
-            }
             return;
         }
     }
@@ -102,9 +90,7 @@ R2Stretcher::ProcessThread::run()
     m_s->m_spaceAvailable.signal();
     m_s->m_spaceAvailable.unlock();
     
-    if (m_s->m_debugLevel > 1) {
+    m_s->m_log.log(2, "thread done for channel", m_channel);
-        cerr << "thread " << m_channel << " done" << endl;
-    }
 }
 
 void
@@ -205,8 +191,7 @@ R2Stretcher::consumeChannel(size_t c,
 
         size_t reqSize = int(ceil(samples / m_pitchScale));
         if (reqSize > cd.resamplebufSize) {
-            cerr << "WARNING: R2Stretcher::consumeChannel: resizing resampler buffer from "
+            m_log.log(0, "WARNING: R2Stretcher::consumeChannel: resizing resampler buffer from and to", cd.resamplebufSize, reqSize);
-                 << cd.resamplebufSize << " to " << reqSize << endl;
             cd.setResampleBufSize(reqSize);
         }
 
@@ -286,9 +271,7 @@ R2Stretcher::processChunks(size_t c, bool &any, bool &last)
     while (!last) {
 
         if (!testInbufReadSpace(c)) {
-            if (m_debugLevel > 1) {
+            m_log.log(2, "processChunks: out of input");
-                cerr << "processChunks: out of input" << endl;
-            }
             break;
         }
 
@@ -311,9 +294,7 @@ R2Stretcher::processChunks(size_t c, bool &any, bool &last)
                 (c, phaseIncrement, shiftIncrement, phaseReset);
         } else {
             size_t bit = m_aWindowSize/4;
-            if (m_debugLevel > 1) {
+            m_log.log(2, "breaking down overlong increment into chunks from and to", shiftIncrement, bit);
-                cerr << "channel " << c << " breaking down overlong increment " << shiftIncrement << " into " << bit << "-size bits" << endl;
-            }
             if (!tmp) tmp = allocate<float>(m_aWindowSize);
             analyseChunk(c);
             v_copy(tmp, cd.fltbuf, m_aWindowSize);
@@ -330,9 +311,8 @@ R2Stretcher::processChunks(size_t c, bool &any, bool &last)
         }
 
         cd.chunkCount++;
-        if (m_debugLevel > 2) {
+        m_log.log(3, "channel/last", c, last);
-            cerr << "channel " << c << ": last = " << last << ", chunkCount = " << cd.chunkCount << endl;
+        m_log.log(3, "channel/chunkCount", c, cd.chunkCount);
-        }
     }
 
     if (tmp) deallocate(tmp);
@@ -351,9 +331,7 @@ R2Stretcher::processOneChunk()
 
     for (size_t c = 0; c < m_channels; ++c) {
         if (!testInbufReadSpace(c)) {
-            if (m_debugLevel > 1) {
+            m_log.log(2, "processOneChunk: out of input");
-                cerr << "processOneChunk: out of input" << endl;
-            }
             return false;
         }
         ChannelData &cd = *m_channelData[c];
@@ -405,11 +383,7 @@ R2Stretcher::testInbufReadSpace(size_t c)
 #ifndef NO_THREADING
             if (!m_threaded) {
 #endif
-                if (m_debugLevel > 1) {
+                m_log.log(2, "Note: read space < chunk size when not all input written", inbuf.getReadSpace(), m_aWindowSize);
-                    cerr << "Note: RubberBandStretcher: read space < chunk size ("
-                         << inbuf.getReadSpace() << " < " << m_aWindowSize
-                         << ") when not all input written, on processChunks for channel " << c << endl;
-                }
 
 #ifndef NO_THREADING
             }
@@ -418,18 +392,10 @@ R2Stretcher::testInbufReadSpace(size_t c)
         }
         
         if (rs == 0) {
-
+            m_log.log(2, "read space = 0, giving up");
-            if (m_debugLevel > 1) {
-                cerr << "read space = 0, giving up" << endl;
-            }
             return false;
-
         } else if (rs < m_aWindowSize/2) {
-
+            m_log.log(2, "setting draining true with read space", rs);
-            if (m_debugLevel > 1) {
-                cerr << "read space = " << rs << ", setting draining true" << endl;
-            }
-            
             cd.draining = true;
         }
     }
@@ -450,9 +416,9 @@ R2Stretcher::processChunkForChannel(size_t c,
     // using e.g. testInbufReadSpace first.  Return true if this is
     // the last chunk on the channel.
 
-    if (phaseReset && (m_debugLevel > 1)) {
+    if (phaseReset) {
-        cerr << "processChunkForChannel: phase reset found, incrs "
+        m_log.log(2, "processChunkForChannel: phase reset found, increments",
-             << phaseIncrement << ":" << shiftIncrement << endl;
+                  phaseIncrement, shiftIncrement);
     }
 
     ChannelData &cd = *m_channelData[c];
@@ -475,7 +441,7 @@ R2Stretcher::processChunkForChannel(size_t c,
         modifyChunk(c, phaseIncrement, phaseReset);
         synthesiseChunk(c, shiftIncrement); // reads from cd.mag, cd.phase
 
-        if (m_debugLevel > 2) {
+        if (m_log.getDebugLevel() > 2) {
             if (phaseReset) {
                 for (int i = 0; i < 10; ++i) {
                     cd.accumulator[i] = 1.2f - (i % 3) * 1.2f;
@@ -487,19 +453,13 @@ R2Stretcher::processChunkForChannel(size_t c,
     bool last = false;
 
     if (cd.draining) {
-        if (m_debugLevel > 1) {
+        m_log.log(2, "draining: accumulator fill and shift increment", cd.accumulatorFill, shiftIncrement);
-            cerr << "draining: accumulator fill = " << cd.accumulatorFill << " (shiftIncrement = " << shiftIncrement << ")" <<  endl;
-        }
         if (shiftIncrement == 0) {
-            cerr << "WARNING: draining: shiftIncrement == 0, can't handle that in this context: setting to " << m_increment << endl;
+            m_log.log(0, "WARNING: draining: shiftIncrement == 0, can't handle that in this context: setting to", m_increment);
             shiftIncrement = m_increment;
         }
         if (cd.accumulatorFill <= shiftIncrement) {
-            if (m_debugLevel > 1) {
+            m_log.log(2, "draining: marking as last and reducing shift increment from and to", shiftIncrement, cd.accumulatorFill);
-                cerr << "reducing shift increment from " << shiftIncrement
-                          << " to " << cd.accumulatorFill
-                          << " and marking as last" << endl;
-            }
             shiftIncrement = cd.accumulatorFill;
             last = true;
         }
@@ -513,9 +473,7 @@ R2Stretcher::processChunkForChannel(size_t c,
 
     int ws = cd.outbuf->getWriteSpace();
     if (ws < required) {
-        if (m_debugLevel > 0) {
+        m_log.log(1, "Buffer overrun on output for channel", c);
-            cerr << "Buffer overrun on output for channel " << c << endl;
-        }
 
         // The only correct thing we can do here is resize the buffer.
         // We can't wait for the client thread to read some data out
@@ -528,12 +486,10 @@ R2Stretcher::processChunkForChannel(size_t c,
         RingBuffer<float> *oldbuf = cd.outbuf;
         cd.outbuf = oldbuf->resized(oldbuf->getSize() * 2);
 
-        if (m_debugLevel > 1) {
+        m_log.log(2, "write space and space needed", ws, required);
-            cerr << "(Write space was " << ws << ", needed " << required
+        m_log.log(2, "resized output buffer from and to", oldbuf->getSize(),
-                 << ": resized output buffer from " << oldbuf->getSize()
+                  cd.outbuf->getSize());
-                 << " to " << cd.outbuf->getSize() << ")" << endl;
+        
-        }
-
         m_emergencyScavenger.claim(oldbuf);
     }
 
@@ -548,8 +504,6 @@ R2Stretcher::calculateIncrements(size_t &phaseIncrementRtn,
 {
     Profiler profiler("R2Stretcher::calculateIncrements");
 
-//    cerr << "calculateIncrements" << endl;
-    
     // Calculate the next upcoming phase and shift increment, on the
     // basis that both channels are in sync.  This is in contrast to
     // getIncrements, which requires that all the increments have been
@@ -572,7 +526,7 @@ R2Stretcher::calculateIncrements(size_t &phaseIncrementRtn,
     size_t bc = cd.chunkCount;
     for (size_t c = 1; c < m_channels; ++c) {
         if (m_channelData[c]->chunkCount != bc) {
-            cerr << "ERROR: R2Stretcher::calculateIncrements: Channels are not in sync" << endl;
+            m_log.log(0, "ERROR: R2Stretcher::calculateIncrements: Channels are not in sync");
             return;
         }
     }
@@ -669,10 +623,7 @@ R2Stretcher::calculateIncrements(size_t &phaseIncrementRtn,
 
     if (m_silentHistory >= int(m_aWindowSize / m_increment) && !phaseReset) {
         phaseReset = true;
-        if (m_debugLevel > 1) {
+        m_log.log(2, "calculateIncrements: phase reset on silence: silent history", m_silentHistory);
-            cerr << "calculateIncrements: phase reset on silence (silent history == "
-                 << m_silentHistory << ")" << endl;
-        }
     }
 }
 
@@ -711,9 +662,6 @@ R2Stretcher::getIncrements(size_t channel,
     bool gotData = true;
 
     if (cd.chunkCount >= m_outputIncrements.size()) {
-//        cerr << "WARNING: R2Stretcher::getIncrements:"
-//             << " chunk count " << cd.chunkCount << " >= "
-//             << m_outputIncrements.size() << endl;
         if (m_outputIncrements.size() == 0) {
             phaseIncrementRtn = m_increment;
             shiftIncrementRtn = m_increment;
@@ -740,12 +688,12 @@ R2Stretcher::getIncrements(size_t channel,
     if (shiftIncrement < 0) {
         shiftIncrement = -shiftIncrement;
     }
-    /*
+
-    if (shiftIncrement >= int(m_windowSize)) {
+    if (shiftIncrement >= int(m_aWindowSize)) {
-        cerr << "*** ERROR: R2Stretcher::processChunks: shiftIncrement " << shiftIncrement << " >= windowSize " << m_windowSize << " at " << cd.chunkCount << " (of " << m_outputIncrements.size() << ")" << endl;
+        m_log.log(1, "WARNING: shiftIncrement >= analysis window size", shiftIncrement, m_aWindowSize);
-        shiftIncrement = m_windowSize;
+        m_log.log(1, "at chunk of total", cd.chunkCount, m_outputIncrements.size());
     }
-    */
+
     phaseIncrementRtn = phaseIncrement;
     shiftIncrementRtn = shiftIncrement;
     if (cd.chunkCount == 0) phaseReset = true; // don't mess with the first chunk
@@ -782,8 +730,8 @@ R2Stretcher::modifyChunk(size_t channel,
 
     ChannelData &cd = *m_channelData[channel];
 
-    if (phaseReset && m_debugLevel > 1) {
+    if (phaseReset) {
-        cerr << "phase reset: leaving phases unmodified" << endl;
+        m_log.log(2, "phase reset: leaving phases unmodified");
     }
 
     const process_t rate = process_t(m_sampleRate);
@@ -904,15 +852,13 @@ R2Stretcher::modifyChunk(size_t channel,
         cd.unwrappedPhase[i] = outphase;
     }
 
-    if (m_debugLevel > 2) {
+    m_log.log(3, "mean inheritance distance", distacc / count);
-        cerr << "mean inheritance distance = " << distacc / count << endl;
-    }
 
     if (fullReset) unchanged = true;
     cd.unchanged = unchanged;
 
-    if (unchanged && m_debugLevel > 1) {
+    if (unchanged) {
-        cerr << "frame unchanged on channel " << channel << endl;
+        m_log.log(2, "frame unchanged on channel", channel);
     }
 }    
 
@@ -936,8 +882,6 @@ R2Stretcher::formantShiftChunk(size_t channel)
 
     const int cutoff = m_sampleRate / 700;
 
-//    cerr <<"cutoff = "<< cutoff << ", m_sampleRate/cutoff = " << m_sampleRate/cutoff << endl;
-
     dblbuf[0] /= 2;
     dblbuf[cutoff-1] /= 2;
 
@@ -1061,8 +1005,10 @@ R2Stretcher::writeChunk(size_t channel, size_t shiftIncrement, bool last)
     const int sz = cd.accumulatorFill;
     const int si = shiftIncrement;
 
-    if (m_debugLevel > 2) {
+    m_log.log(3, "writeChunk: channel and shiftIncrement",
-        cerr << "writeChunk(" << channel << ", " << shiftIncrement << ", " << last << ")" << endl;
+              channel, shiftIncrement);
+    if (last) {
+        m_log.log(3, "writeChunk: last true");
     }
 
     v_divide(accumulator, windowAccumulator, si);
@@ -1090,12 +1036,10 @@ R2Stretcher::writeChunk(size_t channel, size_t shiftIncrement, bool last)
             // first place.  But we retain this check in case the
             // pitch scale has changed since then, or the stretch
             // calculator has gone mad, or something.
-            cerr << "WARNING: R2Stretcher::writeChunk: resizing resampler buffer from "
+            m_log.log(0, "WARNING: R2Stretcher::writeChunk: resizing resampler buffer from and to", cd.resamplebufSize, reqSize);
-                      << cd.resamplebufSize << " to " << reqSize << endl;
             cd.setResampleBufSize(reqSize);
         }
 
-
 #if defined(STRETCHER_IMPL_RESAMPLER_MUTEX_REQUIRED)
         if (m_threaded) {
             m_resamplerMutex.lock();
@@ -1134,9 +1078,7 @@ R2Stretcher::writeChunk(size_t channel, size_t shiftIncrement, bool last)
     } else {
         cd.accumulatorFill = 0;
         if (cd.draining) {
-            if (m_debugLevel > 1) {
+            m_log.log(2, "processChunks: setting outputComplete to true");
-                cerr << "R2Stretcher::processChunks: setting outputComplete to true" << endl;
-            }
             cd.outputComplete = true;
         }
     }
@@ -1162,31 +1104,23 @@ R2Stretcher::writeOutput(RingBuffer<float> &to, float *from, size_t qty, size_t
         // this is the normal case
 
         if (theoreticalOut > 0) {
-            if (m_debugLevel > 1) {
+            m_log.log(2, "theoreticalOut and outCount",
-                cerr << "theoreticalOut = " << theoreticalOut
+                      theoreticalOut, outCount);
-                     << ", outCount = " << outCount
+            m_log.log(2, "startSkip and qty",
-                     << ", startSkip = " << startSkip
+                      startSkip, qty);
-                     << ", qty = " << qty << endl;
-            }
             if (outCount - startSkip <= theoreticalOut &&
                 outCount - startSkip + qty > theoreticalOut) {
                 qty = theoreticalOut - (outCount - startSkip);
-                if (m_debugLevel > 1) {
+                m_log.log(2, "reducing qty to", qty);
-                    cerr << "reduce qty to " << qty << endl;
-                }
             }
         }
 
-        if (m_debugLevel > 2) {
+        m_log.log(3, "writing", qty);
-            cerr << "writing " << qty << endl;
-        }
 
         size_t written = to.write(from, qty);
 
         if (written < qty) {
-            cerr << "WARNING: R2Stretcher::writeOutput: "
+            m_log.log(0, "WARNING: writeOutput: buffer overrun: wanted to write and able to write", qty, written);
-                 << "Buffer overrun on output: wrote " << written
-                 << " of " << qty << " samples" << endl;
         }
 
         outCount += written;
@@ -1196,22 +1130,16 @@ R2Stretcher::writeOutput(RingBuffer<float> &to, float *from, size_t qty, size_t
     // the rest of this is only used during the first startSkip samples
 
     if (outCount + qty <= startSkip) {
-        if (m_debugLevel > 1) {
+        m_log.log(2, "discarding with startSkip", startSkip);
-            cerr << "qty = " << qty << ", startSkip = "
+        m_log.log(2, "qty and outCount", qty, outCount);
-                 << startSkip << ", outCount = " << outCount
-                 << ", discarding" << endl;
-        }
         outCount += qty;
         return;
     }
 
     size_t off = startSkip - outCount;
-    if (m_debugLevel > 1) {
+    m_log.log(2, "shortening with startSkip", startSkip);
-        cerr << "qty = " << qty << ", startSkip = "
+    m_log.log(2, "qty and outCount", qty, outCount);
-             << startSkip << ", outCount = " << outCount
+    m_log.log(2, "start offset and number written", off, qty - off);
-             << ", writing " << qty - off
-             << " from start offset " << off << endl;
-    }
     to.write(from + off, qty - off);
     outCount += qty;
 }
@@ -1235,11 +1163,8 @@ R2Stretcher::available() const
 #endif
         for (size_t c = 0; c < m_channels; ++c) {
             if (m_channelData[c]->inputSize >= 0) {
-//                cerr << "available: m_done true" << endl;
                 if (m_channelData[c]->inbuf->getReadSpace() > 0) {
-                    if (m_debugLevel > 1) {
+                    m_log.log(2, "calling processChunks from available, channel" , c);
-                        cerr << "calling processChunks(" << c << ") from available" << endl;
-                    }
                     //!!! do we ever actually do this? if so, this method should not be const
                     // ^^^ yes, we do sometimes -- e.g. when fed a very short file
                     bool any = false, last = false;
@@ -1258,9 +1183,7 @@ R2Stretcher::available() const
     for (size_t i = 0; i < m_channels; ++i) {
         size_t availIn = m_channelData[i]->inbuf->getReadSpace();
         size_t availOut = m_channelData[i]->outbuf->getReadSpace();
-        if (m_debugLevel > 2) {
+        m_log.log(3, "available in and out", availIn, availOut);
-            cerr << "available on channel " << i << ": " << availOut << " (waiting: " << availIn << ")" << endl;
-        }
         if (i == 0 || availOut < min) min = availOut;
         if (!m_channelData[i]->outputComplete) consumed = false;
         if (m_channelData[i]->resampler) haveResamplers = true;
@@ -1284,9 +1207,7 @@ R2Stretcher::retrieve(float *const *output, size_t samples) const
         size_t gotHere = m_channelData[c]->outbuf->read(output[c], got);
         if (gotHere < got) {
             if (c > 0) {
-                if (m_debugLevel > 0) {
+                m_log.log(0, "R2Stretcher::retrieve: WARNING: channel imbalance detected");
-                    cerr << "R2Stretcher::retrieve: WARNING: channel imbalance detected" << endl;
-                }
             }
             got = gotHere;
         }

src/finer/Guide.h

@@ -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) : sampleRate(_sampleRate) { }
-        Parameters(double _sampleRate,
-                   std::function<void(const std::string &)> _log) :
-            sampleRate(_sampleRate),
-            logger(_log) { }
     };
 
-    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)))),
@@ -120,10 +119,12 @@ public:
     {
         double rate = m_parameters.sampleRate;
 
+        m_log.log(1, "Guide: rate", rate);
+        
         int bandFftSize = roundUp(int(ceil(rate/16.0)));
         m_configuration.fftBandLimits[0] =
             BandLimits(bandFftSize, rate, 0.0, m_maxLower);
-
+        
         // This is the classification and fallback FFT: we need it to
         // go up to Nyquist so we can seamlessly switch to it for
         // longer stretches
@@ -134,6 +135,9 @@ public:
         bandFftSize = roundUp(int(ceil(rate/64.0)));
         m_configuration.fftBandLimits[2] =
             BandLimits(bandFftSize, rate, m_minHigher, rate/2.0);
+
+        m_log.log(1, "Guide: classification FFT size",
+                  m_configuration.classificationFftSize);
     }
 
     const Configuration &getConfiguration() const {
@@ -332,8 +336,13 @@ public:
         */
     }
 
+    void setDebugLevel(int level) {
+        m_log.setDebugLevel(level);
+    }
+    
 protected:
     Parameters m_parameters;
+    Log m_log;
     Configuration m_configuration;
 
     double m_minLower;

src/finer/PhaseAdvance.h

@@ -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) :
-        Parameters(int _fftSize, double _sampleRate, int _channels,
+            fftSize(_fftSize), sampleRate(_sampleRate), channels(_channels) { }
-                   std::function<void(const std::string &)> _log) :
-            fftSize(_fftSize), sampleRate(_sampleRate),
-            channels(_channels), logger(_log) { }
     };
     
-    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,18 +110,18 @@ 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;
+            m_log.log(1, "PhaseAdvance: for fftSize and bins",
-            ostr << "PhaseAdvance: fftSize = " << m_parameters.fftSize
+                      m_parameters.fftSize, bs);
-                 << ": bins = " << bs << ", channels = " << channels
+            m_log.log(1, "PhaseAdvance: channels", channels);
-                 << ", inhop = "<< inhop << ", outhop = " << outhop
+            m_log.log(1, "PhaseAdvance: widest bin range for this size",
-                 << ", ratio = " << ratio << std::endl;
+                      lowest, highest);
-            ostr << "PhaseAdvance: lowest possible bin = " << lowest
+            m_log.log(1, "PhaseAdvance: widest freq range for this size",
-                 << " (" << configuration.fftBandLimits[myFftBand].f0min
+                      configuration.fftBandLimits[myFftBand].f0min,
-                 << "Hz), highest = " << highest
+                      configuration.fftBandLimits[myFftBand].f1max);
-                 << " (" << configuration.fftBandLimits[myFftBand].f1max
+            m_log.log(1, "PhaseAdvance: initial inhop and outhop",
-                 << "Hz)" << std::endl;
+                      inhop, outhop);
-            m_parameters.logger(ostr.str());
+            m_log.log(1, "PhaseAdvance: initial ratio", ratio);
             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;

src/finer/R3Stretcher.cpp

@@ -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),
@@ -51,6 +53,11 @@ R3Stretcher::R3Stretcher(Parameters parameters,
     m_totalOutputDuration(0),
     m_mode(ProcessMode::JustCreated)
 {
+    m_log.log(1, "R3Stretcher::R3Stretcher: rate, options",
+              m_parameters.sampleRate, m_parameters.options);
+    m_log.log(1, "R3Stretcher::R3Stretcher: initial time ratio and pitch scale",
+              m_timeRatio, m_pitchScale);
+
     double maxClassifierFrequency = 16000.0;
     if (maxClassifierFrequency > m_parameters.sampleRate/2) {
         maxClassifierFrequency = m_parameters.sampleRate/2;
@@ -83,18 +90,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,
+            (fftSize, m_parameters.sampleRate, m_parameters.channels);
-             m_parameters.logger);
+        m_scaleData[fftSize] = std::make_shared<ScaleData>
-        m_scaleData[fftSize] = std::make_shared<ScaleData>(guidedParameters);
+            (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 +127,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.log(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.log(0, "WARNING: std::atomic<double> is not lock-free");
     }
 
     // Pad to half of the longest frame. As with R2, in real-time mode
@@ -131,15 +139,15 @@ R3Stretcher::R3Stretcher(Parameters parameters,
     // changes.
     
     if (!isRealTime()) {
-        m_parameters.logger("Offline mode: pre-padding");
         int pad = m_guideConfiguration.longestFftSize / 2;
+        m_log.log(1, "offline mode: prefilling with", pad);
         for (int c = 0; c < m_parameters.channels; ++c) {
             m_channelData[c]->inbuf->zero(pad);
         }
         // 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.log(1, "realtime mode: no prefill");
     }
 }
 
@@ -176,7 +184,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.log(0, "R3Stretcher::setTimeRatio: Cannot set time ratio while studying or processing in non-RT mode");
             return;
         }
     }
@@ -192,7 +200,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.log(0, "R3Stretcher::setTimeRatio: Cannot set pitch scale while studying or processing in non-RT mode");
             return;
         }
     }
@@ -208,7 +216,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.log(0, "R3Stretcher::setTimeRatio: Cannot set formant scale while studying or processing in non-RT mode");
             return;
         }
     }
@@ -230,11 +238,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.log(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.log(0, "R3Stretcher::setKeyFrameMap: Cannot specify key frame map after process() has begun");
         return;
     }
 
@@ -266,22 +274,21 @@ R3Stretcher::calculateHop()
     if (proposedOuthop > 512.0) proposedOuthop = 512.0;
     if (proposedOuthop < 128.0) proposedOuthop = 128.0;
 
-    std::cout << "calculateHop: for ratio " << ratio << " proposedOuthop = "
+    m_log.log(1, "calculateHop: ratio and proposed outhop", ratio, proposedOuthop);
-              << proposedOuthop << std::endl;
     
     double inhop = proposedOuthop / ratio;
     if (inhop < 1.0) {
-        m_parameters.logger("WARNING: Extreme ratio yields ideal inhop < 1, results may be suspect");
+        m_log.log(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.log(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.log(1, "calculateHop: inhop and mean outhop", m_inhop, m_inhop * ratio);
 }
 
 void
@@ -292,7 +299,12 @@ R3Stretcher::updateRatioFromMap()
     if (m_processInputDuration == 0) {
         m_timeRatio = double(m_keyFrameMap.begin()->second) /
             double(m_keyFrameMap.begin()->first);
-        std::cout << "initial key-frame map entry " << m_keyFrameMap.begin()->first << " -> " << m_keyFrameMap.begin()->second << " gives initial ratio " << m_timeRatio << std::endl;
+
+        m_log.log(1, "initial key-frame map entry ",
+                   double(m_keyFrameMap.begin()->first),
+                   double(m_keyFrameMap.begin()->second));
+        m_log.log(1, "giving initial ratio ", m_timeRatio);
+        
         calculateHop();
         m_lastKeyFrameSurpassed = 0;
         return;
@@ -306,7 +318,8 @@ R3Stretcher::updateRatioFromMap()
 
     if (m_processInputDuration >= i0->first) {
 
-        std::cout << "at " << m_processInputDuration << " (output = " << m_totalOutputDuration << ") we have passed " << i0->first << ", looking ahead to next key frame" << std::endl;
+        m_log.log(2, "input duration surpasses pending key frame",
+                   double(m_processInputDuration), double(i0->first));
         
         auto i1 = m_keyFrameMap.upper_bound(m_processInputDuration);
 
@@ -331,10 +344,13 @@ R3Stretcher::updateRatioFromMap()
 
         double ratio = double(toKeyFrameAtOutput) / double(toKeyFrameAtInput);
 
-        std::cout << "keyFrameAtInput = " << keyFrameAtInput << ", keyFrameAtOutput = " << keyFrameAtOutput << std::endl;
+        m_log.log(2, "next key frame input and output",
-        std::cout << "currently at input = " << m_processInputDuration << ", currently at output = " << m_totalOutputDuration << std::endl;
+                   double(keyFrameAtInput), double(keyFrameAtOutput));
-        std::cout << "toKeyFrameAtInput = " << toKeyFrameAtInput << ", toKeyFrameAtOutput = " << toKeyFrameAtOutput << std::endl;
+        m_log.log(2, "current input and output",
-        std::cout << "ratio = " << ratio << std::endl;
+                   double(m_processInputDuration), double(m_totalOutputDuration));
+        m_log.log(2, "to next key frame input and output",
+                   double(toKeyFrameAtInput), double(toKeyFrameAtOutput));
+        m_log.log(2, "new ratio", ratio);
     
         m_timeRatio = ratio;
         calculateHop();
@@ -409,12 +425,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.log(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.log(0, "R3Stretcher::study: Cannot study after processing");
         return;
     }
     
@@ -443,7 +459,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.log(0, "R3Stretcher::process: Cannot process again after final chunk");
         return;
     }
 
@@ -468,7 +484,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.log(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 +521,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.log(0, "R3Stretcher::retrieve: WARNING: channel imbalance detected");
             }
             got = std::min(got, std::max(gotHere, 0));
         }
@@ -550,16 +566,14 @@ R3Stretcher::consume()
     // advanced the input and output since the previous frame, not the
     // distances we are about to advance them, so they use the m_prev
     // values.
-/*
+
     if (inhop != m_prevInhop) {
-        std::cout << "Note: inhop has changed from " << m_prevInhop
+        m_log.log(2, "change in inhop", double(m_prevInhop), double(inhop));
-                  << " to " << inhop << std::endl;
     }
     if (outhop != m_prevOuthop) {
-        std::cout << "Note: outhop has changed from " << m_prevOuthop
+        m_log.log(2, "change in outhop", double(m_prevOuthop), double(outhop));
-                  << " to " << outhop << std::endl;
     }
-*/
+    
     while (m_channelData.at(0)->outbuf->getWriteSpace() >= outhop) {
 
         // NB our ChannelData, ScaleData, and ChannelScaleData maps

src/finer/R3Stretcher.h

@@ -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,
+                   RubberBandStretcher::Options _options) :
-                   std::function<void(const std::string &)> _log = &logCout) :
+            sampleRate(_sampleRate), channels(_channels), options(_options) { }
-            sampleRate(_sampleRate), channels(_channels), options(_options),
-            logger(_log) { }
     };
     
     R3Stretcher(Parameters parameters,
                 double initialTimeRatio,
-                double initialPitchScale);
+                double initialPitchScale,
+                Log log);
     ~R3Stretcher() { }
 
     void reset();
@@ -89,6 +87,15 @@ public:
     size_t getLatency() const;
     size_t getChannelCount() const;
     
+    void setDebugLevel(int level) {
+        m_log.setDebugLevel(level);
+        for (auto &sd : m_scaleData) {
+            sd.second->guided.setDebugLevel(level);
+        }
+        m_guide.setDebugLevel(level);
+        m_calculator->setDebugLevel(level);
+    }
+
 protected:
     struct ClassificationReadaheadData {
         FixedVector<double> timeDomain;
@@ -242,7 +249,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 +258,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 +275,7 @@ protected:
     };
     
     Parameters m_parameters;
+    Log m_log;
 
     std::atomic<double> m_timeRatio;
     std::atomic<double> m_pitchScale;
@@ -347,10 +356,6 @@ protected:
         return m_parameters.options &
             RubberBandStretcher::OptionProcessRealTime;
     }
-    
-    static void logCout(const std::string &message) {
-        std::cout << "RubberBandStretcher: " << message << std::endl;
-    }
 };
 
 }

vamp/RubberBandVampPlugin.cpp

@@ -454,6 +454,28 @@ RubberBandVampPlugin::Impl::processOffline(const float *const *inputBuffers,
     return FeatureSet();
 }
 
+static RubberBand::Log makeCerrLog()
+{
+    auto log0 = [](const char *message) {
+        std::cerr << "RubberBand: " << message << "\n";
+    };
+    auto log1 = [](const char *message, double arg0) {
+        auto prec = std::cerr.precision();
+        std::cerr.precision(10);
+        std::cerr << "RubberBand: " << message << ": " << arg0 << "\n";
+        std::cerr.precision(prec);
+    };
+    auto log2 = [](const char *message, double arg0, double arg1) {
+        auto prec = std::cerr.precision();
+        std::cerr.precision(10);
+        std::cerr << "RubberBand: " << message
+                  << ": (" << arg0 << ", " << arg1 << ")" << "\n";
+        std::cerr.precision(prec);
+    };
+
+    return RubberBand::Log(log0, log1, log2);
+}
+
 RubberBandVampPlugin::FeatureSet
 RubberBandVampPlugin::Impl::getRemainingFeaturesOffline()
 {
@@ -463,7 +485,8 @@ RubberBandVampPlugin::Impl::getRemainingFeaturesOffline()
 
     int rate = m_sampleRate;
 
-    RubberBand::StretchCalculator sc(rate, m_stretcher->getInputIncrement(), true);
+    RubberBand::StretchCalculator sc
+        (rate, m_stretcher->getInputIncrement(), true, makeCerrLog());
 
     size_t inputIncrement = m_stretcher->getInputIncrement();
     std::vector<int> outputIncrements = m_stretcher->getOutputIncrements();