Further work on end state with long process sizes in R2. This passes tests but is not the minimal necessary change I think - review.

src/faster/R2Stretcher.cpp

@@ -307,7 +307,10 @@ R2Stretcher::setExpectedInputDuration(size_t samples)
 void
 R2Stretcher::setMaxProcessSize(size_t samples)
 {
+    m_log.log(2, "R2Stretcher::setMaxProcessSize", samples);
     if (samples <= m_maxProcessSize) return;
+
+    m_log.log(2, "R2Stretcher::setMaxProcessSize: increasing from, to", m_maxProcessSize, samples);
     m_maxProcessSize = samples;
 
     reconfigure();
@@ -1232,6 +1235,8 @@ R2Stretcher::process(const float *const *input, size_t samples, bool final)
 {
     Profiler profiler("R2Stretcher::process");
 
+    m_log.log(2, "process entering, samples and final", samples, final);
+
     if (m_mode == Finished) {
         m_log.log(0, "R2Stretcher::process: Cannot process again after final chunk");
         return;
@@ -1294,10 +1299,16 @@ R2Stretcher::process(const float *const *input, size_t samples, bool final)
                                           consumed[c],
                                           samples - consumed[c],
                                           final);
+            if (c == 0) {
+                m_log.log(2, "consumed channel 0, consumed and samples now", consumed[c], samples);
+            }
             if (consumed[c] < samples) {
                 allConsumed = false;
             } else {
                 if (final) {
+                    if (c == 0) {
+                        m_log.log(2, "final is true, setting input size", m_channelData[c]->inCount);
+                    }
                     m_channelData[c]->inputSize = m_channelData[c]->inCount;
                 }
             }

src/faster/StretcherProcess.cpp

@@ -224,6 +224,7 @@ R2Stretcher::consumeChannel(size_t c,
 
     if (writable < toWrite) {
         if (resampling) {
+            m_log.log(1, "consumeChannel: resampler produced too much output, cannot use", toWrite, writable);
             return 0;
         }
         toWrite = writable;
@@ -323,6 +324,8 @@ R2Stretcher::processOneChunk()
 {
     Profiler profiler("R2Stretcher::processOneChunk");
 
+    m_log.log(2, "R2Stretcher::processOneChunk");
+
     // Process a single chunk for all channels, provided there is
     // enough data on each channel for at least one chunk.  This is
     // able to calculate increments as it goes along.
@@ -335,6 +338,7 @@ R2Stretcher::processOneChunk()
             return false;
         }
         ChannelData &cd = *m_channelData[c];
+        m_log.log(2, "read space and draining", cd.inbuf->getReadSpace(), cd.draining);
         if (!cd.draining) {
             size_t ready = cd.inbuf->getReadSpace();
             assert(ready >= m_aWindowSize || cd.inputSize >= 0);
@@ -356,6 +360,7 @@ R2Stretcher::processOneChunk()
         m_channelData[c]->chunkCount++;
     }
 
+    m_log.log(2, "R2Stretcher::processOneChunk returning", last);
     return last;
 }
 
@@ -395,7 +400,9 @@ R2Stretcher::testInbufReadSpace(size_t c)
             m_log.log(2, "read space = 0, giving up");
             return false;
         } else if (rs < m_aWindowSize/2) {
-            m_log.log(2, "setting draining true with read space", rs);
+            m_log.log(2, "setting draining true with read space and window size", rs, m_aWindowSize);
+            m_log.log(2, "outbuf read space is", cd.outbuf->getReadSpace());
+            m_log.log(2, "accumulator fill is", cd.accumulatorFill);
             cd.draining = true;
         }
     }
@@ -454,6 +461,11 @@ R2Stretcher::processChunkForChannel(size_t c,
 
     if (cd.draining) {
         m_log.log(2, "draining: accumulator fill and shift increment", cd.accumulatorFill, shiftIncrement);
+        m_log.log(2, "outbuf read space is", cd.outbuf->getReadSpace());
+        if (cd.accumulatorFill == 0) {
+            m_log.log(2, "draining: accumulator empty");
+            return true;
+        }
         if (shiftIncrement == 0) {
             m_log.log(0, "WARNING: draining: shiftIncrement == 0, can't handle that in this context: setting to", m_increment);
             shiftIncrement = m_increment;
@@ -494,6 +506,7 @@ R2Stretcher::processChunkForChannel(size_t c,
     }
 
     writeChunk(c, shiftIncrement, last);
+    m_log.log(2, "processChunkForChannel: accumulatorFill now; returning", cd.accumulatorFill, last);
     return last;
 }
 
@@ -1095,10 +1108,12 @@ R2Stretcher::writeChunk(size_t channel, size_t shiftIncrement, bool last)
     } else {
         cd.accumulatorFill = 0;
         if (cd.draining) {
-            m_log.log(2, "processChunks: setting outputComplete to true");
+            m_log.log(2, "writeChunk: setting outputComplete to true");
             cd.outputComplete = true;
         }
     }
+
+    m_log.log(2, "writeChunk: accumulatorFill now", cd.accumulatorFill);
 }
 
 void
@@ -1134,7 +1149,7 @@ R2Stretcher::writeOutput(RingBuffer<float> &to,
             }
         }
 
-        m_log.log(3, "writing", qty);
+        m_log.log(2, "writing", qty);
 
         size_t written = to.write(from, qty);
 
@@ -1143,6 +1158,8 @@ R2Stretcher::writeOutput(RingBuffer<float> &to,
         }
 
         outCount += written;
+
+        m_log.log(2, "written and new outCount", written, outCount);
         return;
     }
 
@@ -1168,6 +1185,8 @@ R2Stretcher::available() const
 {
     Profiler profiler("R2Stretcher::available");
 
+    m_log.log(2, "R2Stretcher::available");
+    
 #ifndef NO_THREADING
     if (m_threaded) {
         MutexLocker locker(&m_threadSetMutex);
@@ -1180,14 +1199,24 @@ R2Stretcher::available() const
 #ifndef NO_THREADING
     if (!m_threaded) {
 #endif
-        for (size_t c = 0; c < m_channels; ++c) {
+        if (m_channelData[0]->inputSize >= 0) {
-            if (m_channelData[c]->inputSize >= 0) {
+            //!!! do we ever actually do this? if so, this method should not be const
-                if (m_channelData[c]->inbuf->getReadSpace() > 0) {
+            // ^^^ yes, we do sometimes -- e.g. when fed a very short file
-                    m_log.log(2, "calling processChunks from available, channel" , c);
+            if (m_realtime) {
-                    //!!! do we ever actually do this? if so, this method should not be const
+                while (m_channelData[0]->inbuf->getReadSpace() > 0 ||
-                    // ^^^ yes, we do sometimes -- e.g. when fed a very short file
+                       (m_channelData[0]->accumulatorFill > 0 && m_channelData[0]->draining)) {
-                    bool any = false, last = false;
+                    m_log.log(2, "calling processOneChunk from available");
-                    ((R2Stretcher *)this)->processChunks(c, any, last);
+                    if (((R2Stretcher *)this)->processOneChunk()) {
+                        break;
+                    }
+                }
+            } else {
+                for (size_t c = 0; c < m_channels; ++c) {
+                    if (m_channelData[c]->inbuf->getReadSpace() > 0) {
+                        m_log.log(2, "calling processChunks from available, channel" , c);
+                        bool any = false, last = false;
+                        ((R2Stretcher *)this)->processChunks(c, any, last);
+                    }
                 }
             }
         }
@@ -1202,17 +1231,29 @@ 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();
-        m_log.log(3, "available in and out", availIn, availOut);
+        m_log.log(2, "available in and out", availIn, availOut);
         if (i == 0 || availOut < min) min = availOut;
         if (!m_channelData[i]->outputComplete) consumed = false;
         if (m_channelData[i]->resampler) haveResamplers = true;
     }
 
-    if (min == 0 && consumed) return -1;
+    if (min == 0 && consumed) {
-    if (m_pitchScale == 1.0) return min;
+        m_log.log(2, "R2Stretcher::available: end of stream");
+        return -1;
+    }
+    if (m_pitchScale == 1.0) {
+        m_log.log(2, "R2Stretcher::available (not shifting): returning", min);
+        return min;
+    }
 
-    if (haveResamplers) return min; // resampling has already happened
+    int rv;
-    return int(floor(min / m_pitchScale));
+    if (haveResamplers) {
+        rv = min; // resampling has already happened
+    } else {
+        rv = int(floor(min / m_pitchScale));
+    }
+    m_log.log(2, "R2Stretcher::available (shifting): returning", rv);
+    return rv;
 }
 
 size_t
@@ -1220,6 +1261,8 @@ R2Stretcher::retrieve(float *const *output, size_t samples) const
 {
     Profiler profiler("R2Stretcher::retrieve");
 
+    m_log.log(2, "R2Stretcher::retrieve", samples);
+    
     size_t got = samples;
 
     for (size_t c = 0; c < m_channels; ++c) {
@@ -1244,6 +1287,8 @@ R2Stretcher::retrieve(float *const *output, size_t samples) const
         }
     }            
 
+    m_log.log(2, "R2Stretcher::retrieve returning", got);
+    
     return got;
 }
 

src/test/TestStretcher.cpp

@@ -233,6 +233,7 @@ static vector<float> process_realtime(RubberBandStretcher &stretcher,
                                       const vector<float> &in,
                                       int nOut,
                                       int bs,
+                                      bool roundUpProcessSize,
                                       bool printDebug)
 {
     int n = in.size();
@@ -270,14 +271,20 @@ static vector<float> process_realtime(RubberBandStretcher &stretcher,
             } else if (available == 0) { // need to provide more input
                 int required = stretcher.getSamplesRequired();
                 BOOST_TEST(required > 0); // because available == 0
-                if (required < bs) {
+                int toProcess = required;
-                    // Because we sometimes want to explicitly test
+                if (roundUpProcessSize) {
-                    // passing large blocks to process
+                    // We sometimes want to explicitly test passing
-                    required = bs;
+                    // large blocks to process, longer than
+                    // getSamplesRequired indicates
+                    toProcess = std::max(required, bs);
+                }
+                bool final = false;
+                if (toProcess >= n - inOffset) {
+                    toProcess = n - inOffset;
+                    final = true;
                 }
-                int toProcess = std::min(required, n - inOffset);
                 const float *const source = in.data() + inOffset;
-                bool final = (toProcess < required);
+//                cerr << "toProcess = " << toProcess << ", inOffset = " << inOffset << ", n = " << n << ", required = " << required << ", outOffset = " << outOffset << ", obtained = " << obtained << ", bs = " << bs << ", final = " << final << endl;
                 stretcher.process(&source, toProcess, final);
                 inOffset += toProcess;
                 BOOST_TEST(stretcher.available() > 0);
@@ -316,6 +323,7 @@ static void sinusoid_realtime(RubberBandStretcher::Options options,
                               double timeRatio,
                               double pitchScale,
                               int bs = 512,
+                              bool roundUpProcessSize = false,
                               bool printDebug = false)
 {
     int n = (timeRatio < 1.0 ? 80000 : 40000);
@@ -348,7 +356,8 @@ static void sinusoid_realtime(RubberBandStretcher::Options options,
         in[i] = sample;
     }
 
-    vector<float> out = process_realtime(stretcher, in, nOut, bs, printDebug);
+    vector<float> out = process_realtime(stretcher, in, nOut, bs,
+                                         roundUpProcessSize, printDebug);
         
     // Step through the output signal in chunk of 1/20 of its duration
     // (i.e. a rather arbitrary two per expected 0.1 increment in
@@ -671,8 +680,48 @@ BOOST_AUTO_TEST_CASE(sinusoid_realtime_long_blocksize_faster)
 {
     sinusoid_realtime(RubberBandStretcher::OptionEngineFaster |
                       RubberBandStretcher::OptionProcessRealTime,
-                      8.0, 0.5,
+                      4.0, 0.5,
-                      80000);
+                      80000, true);
+}
+
+BOOST_AUTO_TEST_CASE(sinusoid_realtime_long_blocksize_faster_stretch)
+{
+    sinusoid_realtime(RubberBandStretcher::OptionEngineFaster |
+                      RubberBandStretcher::OptionProcessRealTime,
+                      2.0, 1.0,
+                      80000, true);
+}
+
+BOOST_AUTO_TEST_CASE(sinusoid_realtime_long_blocksize_faster_shrink)
+{
+    sinusoid_realtime(RubberBandStretcher::OptionEngineFaster |
+                      RubberBandStretcher::OptionProcessRealTime,
+                      0.8, 1.0,
+                      80000, true);
+}
+
+BOOST_AUTO_TEST_CASE(sinusoid_realtime_long_blocksize_faster_higher)
+{
+    sinusoid_realtime(RubberBandStretcher::OptionEngineFaster |
+                      RubberBandStretcher::OptionProcessRealTime,
+                      1.0, 2.0,
+                      80000, true);
+}
+
+BOOST_AUTO_TEST_CASE(sinusoid_realtime_long_blocksize_faster_lower)
+{
+    sinusoid_realtime(RubberBandStretcher::OptionEngineFaster |
+                      RubberBandStretcher::OptionProcessRealTime,
+                      1.0, 0.5,
+                      80000, true);
+}
+
+BOOST_AUTO_TEST_CASE(sinusoid_realtime_long_blocksize_finer)
+{
+    sinusoid_realtime(RubberBandStretcher::OptionEngineFiner |
+                      RubberBandStretcher::OptionProcessRealTime,
+                      4.0, 0.5,
+                      80000, true);
 }
 
 BOOST_AUTO_TEST_CASE(sinusoid_realtime_long_blocksize_finer_stretch)
@@ -680,7 +729,7 @@ BOOST_AUTO_TEST_CASE(sinusoid_realtime_long_blocksize_finer_stretch)
     sinusoid_realtime(RubberBandStretcher::OptionEngineFiner |
                       RubberBandStretcher::OptionProcessRealTime,
                       2.0, 1.0,
-                      80000);
+                      80000, true);
 }
 
 BOOST_AUTO_TEST_CASE(sinusoid_realtime_long_blocksize_finer_shift)
@@ -688,7 +737,7 @@ BOOST_AUTO_TEST_CASE(sinusoid_realtime_long_blocksize_finer_shift)
     sinusoid_realtime(RubberBandStretcher::OptionEngineFiner |
                       RubberBandStretcher::OptionProcessRealTime,
                       1.0, 0.5,
-                      80000);
+                      80000, true);
 }
 
 BOOST_AUTO_TEST_CASE(impulses_2x_offline_faster)
@@ -926,7 +975,8 @@ static void impulses_realtime(RubberBandStretcher::Options options,
     in[9900] = 1.f;
     in[9901] = -1.f;
 
-    vector<float> out = process_realtime(stretcher, in, nOut, bs, printDebug);
+    vector<float> out = process_realtime(stretcher, in, nOut, bs,
+                                         false, printDebug);
 
     int peak0 = -1, peak1 = -1, peak2 = -1;
     float max;