changeset 408:115f60df1e4d

* Speed up spectrogram painting by releasing mutex in FFTDataServer while calculating data prior to writing it, and by adding whole-column value query methods to FFT objects * Add paint cache to Thumbwheel -- repaints of this widget were slowing down the whole spectrogram repaint * More uses of MutexLocker (named and with debug) and more profile points * Make startup much quicker some of the time, with OSC server in place
author Chris Cannam
date Thu, 08 May 2008 14:46:22 +0000
parents 88ad01799040
children 6075c90744d4
files base/Profiler.cpp base/Profiler.h base/Thread.cpp base/Thread.h data/fft/FFTCache.h data/fft/FFTDataServer.cpp data/fft/FFTDataServer.h data/fft/FFTFileCache.cpp data/fft/FFTFileCache.h data/fft/FFTMemoryCache.cpp data/fft/FFTMemoryCache.h data/fileio/FileReadThread.cpp data/fileio/MatrixFile.cpp data/model/AlignmentModel.cpp data/model/FFTModel.cpp data/model/FFTModel.h data/osc/OSCQueue.cpp plugin/DSSIPluginFactory.cpp plugin/FeatureExtractionPluginFactory.cpp plugin/LADSPAPluginFactory.cpp plugin/RealTimePluginFactory.cpp transform/FeatureExtractionModelTransformer.cpp transform/ModelTransformerFactory.cpp
diffstat 23 files changed, 454 insertions(+), 188 deletions(-) [+]
line wrap: on
line diff
--- a/base/Profiler.cpp	Tue Apr 29 15:34:17 2008 +0000
+++ b/base/Profiler.cpp	Thu May 08 14:46:22 2008 +0000
@@ -161,7 +161,7 @@
     for (TimeRMap::const_iterator i = worstmap.end(); i != worstmap.begin(); ) {
         --i;
         fprintf(stderr, "%-40s  %s ms\n", i->second,
-                (i->first * 1000).toString().c_str(), i->second);
+                (i->first * 1000).toString().c_str());
     }
 
     fprintf(stderr, "\nBy number of calls:\n");
@@ -175,9 +175,10 @@
 
 #ifndef NO_TIMING    
 
-Profiler::Profiler(const char* c, bool showOnDestruct)
-    : m_c(c),
-      m_showOnDestruct(showOnDestruct)
+Profiler::Profiler(const char* c, bool showOnDestruct) :
+    m_c(c),
+    m_showOnDestruct(showOnDestruct),
+    m_ended(false)
 {
     m_startCPU = clock();
 
@@ -202,6 +203,12 @@
 
 Profiler::~Profiler()
 {
+    if (!m_ended) end();
+}
+
+void
+Profiler::end()
+{
     clock_t elapsedCPU = clock() - m_startCPU;
 
     struct timeval tv;
@@ -214,6 +221,8 @@
         cerr << "Profiler : id = " << m_c
              << " - elapsed = " << ((elapsedCPU * 1000) / CLOCKS_PER_SEC)
 	     << "ms CPU, " << elapsedTime << " real" << endl;
+
+    m_ended = true;
 }
  
 #endif
--- a/base/Profiler.h	Tue Apr 29 15:34:17 2008 +0000
+++ b/base/Profiler.h	Thu May 08 14:46:22 2008 +0000
@@ -98,12 +98,14 @@
     ~Profiler();
 
     void update() const;
+    void end(); // same action as dtor
 
 protected:
     const char* m_c;
     clock_t m_startCPU;
     RealTime m_startTime;
     bool m_showOnDestruct;
+    bool m_ended;
 };
 
 #else
@@ -111,10 +113,11 @@
 class Profiler
 {
 public:
-    Profiler(const char *, bool) { }
+    Profiler(const char *, bool = false) { }
     ~Profiler() { }
-    
-    void update() { }
+
+    void update() const { }
+    void end() { }
 };
 
 #endif
--- a/base/Thread.cpp	Tue Apr 29 15:34:17 2008 +0000
+++ b/base/Thread.cpp	Thu May 08 14:46:22 2008 +0000
@@ -58,12 +58,14 @@
 }
 
 MutexLocker::MutexLocker(QMutex *mutex, const char *name) :
+    m_profiler(name, false),
     m_printer(name),
     m_locker(mutex)
 {
 #ifdef DEBUG_MUTEX_LOCKER
     std::cerr << "... locked mutex " << mutex << std::endl;
 #endif
+    m_profiler.end();
 }
 
 MutexLocker::~MutexLocker()
--- a/base/Thread.h	Tue Apr 29 15:34:17 2008 +0000
+++ b/base/Thread.h	Thu May 08 14:46:22 2008 +0000
@@ -19,6 +19,8 @@
 #include <QThread>
 #include <QMutexLocker>
 
+#include "Profiler.h"
+
 class Thread : public QThread
 {
 Q_OBJECT
@@ -38,7 +40,6 @@
     Type m_type;
 };
 
-
 class MutexLocker
 {
 public:
@@ -55,6 +56,7 @@
         const char *m_name;
     };
 
+    Profiler m_profiler;
     Printer m_printer;
     QMutexLocker m_locker;
 };
--- a/data/fft/FFTCache.h	Tue Apr 29 15:34:17 2008 +0000
+++ b/data/fft/FFTCache.h	Thu May 08 14:46:22 2008 +0000
@@ -49,6 +49,13 @@
 
     virtual void suspend() { }
 
+    enum StorageType {
+        Compact, // 16 bits normalized polar
+        Rectangular, // floating point real+imag
+        Polar // floating point mag+phase
+    };
+    virtual StorageType getStorageType() = 0;
+
     enum Type { MemoryCache, FileCache };
     virtual Type getType() = 0;
 
--- a/data/fft/FFTDataServer.cpp	Tue Apr 29 15:34:17 2008 +0000
+++ b/data/fft/FFTDataServer.cpp	Thu May 08 14:46:22 2008 +0000
@@ -62,7 +62,7 @@
 
     FFTDataServer *server = 0;
     
-    MutexLocker locker(&m_serverMapMutex, "FFTDataServer::m_serverMapMutex[getInstance]");
+    MutexLocker locker(&m_serverMapMutex, "FFTDataServer::getInstance::m_serverMapMutex");
 
     if ((server = findServer(n))) {
         return server;
@@ -139,7 +139,7 @@
     // or 1536, the model doesn't support this).
 
     {
-        MutexLocker locker(&m_serverMapMutex, "FFTDataServer::m_serverMapMutex[getFuzzyInstance]");
+        MutexLocker locker(&m_serverMapMutex, "FFTDataServer::getFuzzyInstance::m_serverMapMutex");
 
         ServerMap::iterator best = m_servers.end();
         int bestdist = -1;
@@ -258,7 +258,7 @@
 FFTDataServer::claimInstance(FFTDataServer *server, bool needLock)
 {
     MutexLocker locker(needLock ? &m_serverMapMutex : 0,
-                       "FFTDataServer::m_serverMapMutex[claimInstance]");
+                       "FFTDataServer::claimInstance::m_serverMapMutex");
 
 #ifdef DEBUG_FFT_SERVER
     std::cerr << "FFTDataServer::claimInstance(" << server << ")" << std::endl;
@@ -303,7 +303,7 @@
 FFTDataServer::releaseInstance(FFTDataServer *server, bool needLock)
 {    
     MutexLocker locker(needLock ? &m_serverMapMutex : 0,
-                       "FFTDataServer::m_serverMapMutex[releaseInstance]");
+                       "FFTDataServer::releaseInstance::m_serverMapMutex");
 
 #ifdef DEBUG_FFT_SERVER
     std::cerr << "FFTDataServer::releaseInstance(" << server << ")" << std::endl;
@@ -431,7 +431,7 @@
 FFTDataServer::modelAboutToBeDeleted(Model *model)
 {
     MutexLocker locker(&m_serverMapMutex,
-                       "FFTDataServer::m_serverMapMutex[modelAboutToBeDeleted]");
+                       "FFTDataServer::modelAboutToBeDeleted::m_serverMapMutex");
 
 #ifdef DEBUG_FFT_SERVER
     std::cerr << "FFTDataServer::modelAboutToBeDeleted(" << model << ")"
@@ -598,7 +598,7 @@
     }
 
     MutexLocker locker(&m_writeMutex,
-                       "FFTDataServer::m_writeMutex[~FFTDataServer]");
+                       "FFTDataServer::~FFTDataServer::m_writeMutex");
 
     for (CacheVector::iterator i = m_caches.begin(); i != m_caches.end(); ++i) {
 
@@ -634,7 +634,7 @@
     Profiler profiler("FFTDataServer::suspend", false);
 
     MutexLocker locker(&m_writeMutex,
-                       "FFTDataServer::m_writeMutex[suspend]");
+                       "FFTDataServer::suspend::m_writeMutex");
     m_suspended = true;
     for (CacheVector::iterator i = m_caches.begin(); i != m_caches.end(); ++i) {
         if (*i) (*i)->suspend();
@@ -740,7 +740,7 @@
 #endif
 
     MutexLocker locker(&m_writeMutex,
-                       "FFTDataServer::m_writeMutex[getCacheAux]");
+                       "FFTDataServer::getCacheAux::m_writeMutex");
 
     if (m_lastUsedCache == -1) {
         m_fillThread->start();
@@ -875,15 +875,51 @@
     if (!cache) return 0;
 
     if (!cache->haveSetColumnAt(col)) {
+        Profiler profiler("FFTDataServer::getMagnitudeAt: filling");
 #ifdef DEBUG_FFT_SERVER
         std::cerr << "FFTDataServer::getMagnitudeAt: calling fillColumn(" 
                   << x << ")" << std::endl;
 #endif
-        fillColumn(x);
+        // hold mutex so that write thread doesn't mess with class
+        // member data in fillColumn
+        MutexLocker locker(&m_writeMutex,
+                           "FFTDataServer::getMagnitudeAt: m_writeMutex");
+        fillColumn(x, true);
     }
     return cache->getMagnitudeAt(col, y);
 }
 
+bool
+FFTDataServer::getMagnitudesAt(size_t x, float *values, size_t minbin, size_t count, size_t step)
+{
+    Profiler profiler("FFTDataServer::getMagnitudesAt", false);
+
+    if (x >= m_width) return false;
+
+    if (minbin >= m_height) minbin = m_height - 1;
+    if (count == 0) count = (m_height - minbin) / step;
+    else if (minbin + count * step > m_height) {
+        count = (m_height - minbin) / step;
+    }
+
+    size_t col;
+    FFTCache *cache = getCache(x, col);
+    if (!cache) return false;
+
+    if (!cache->haveSetColumnAt(col)) {
+        Profiler profiler("FFTDataServer::getMagnitudesAt: filling");
+        MutexLocker locker(&m_writeMutex,
+                           "FFTDataServer::getMagnitudesAt: m_writeMutex");
+        fillColumn(x, true);
+    }
+
+    for (size_t i = 0; i < count; ++i) {
+        values[i] = cache->getMagnitudeAt(col, i * step + minbin);
+    }
+
+    return true;
+}
+
 float
 FFTDataServer::getNormalizedMagnitudeAt(size_t x, size_t y)
 {
@@ -896,11 +932,47 @@
     if (!cache) return 0;
 
     if (!cache->haveSetColumnAt(col)) {
-        fillColumn(x);
+        Profiler profiler("FFTDataServer::getNormalizedMagnitudeAt: filling");
+        // hold mutex so that write thread doesn't mess with class
+        // member data in fillColumn
+        MutexLocker locker(&m_writeMutex,
+                           "FFTDataServer::getNormalizedMagnitudeAt: m_writeMutex");
+        fillColumn(x, true);
     }
     return cache->getNormalizedMagnitudeAt(col, y);
 }
 
+bool
+FFTDataServer::getNormalizedMagnitudesAt(size_t x, float *values, size_t minbin, size_t count, size_t step)
+{
+    Profiler profiler("FFTDataServer::getNormalizedMagnitudesAt", false);
+
+    if (x >= m_width) return false;
+
+    if (minbin >= m_height) minbin = m_height - 1;
+    if (count == 0) count = (m_height - minbin) / step;
+    else if (minbin + count * step > m_height) {
+        count = (m_height - minbin) / step;
+    }
+
+    size_t col;
+    FFTCache *cache = getCache(x, col);
+    if (!cache) return false;
+
+    if (!cache->haveSetColumnAt(col)) {
+        Profiler profiler("FFTDataServer::getNormalizedMagnitudesAt: filling");
+        MutexLocker locker(&m_writeMutex,
+                           "FFTDataServer::getNormalizedMagnitudesAt: m_writeMutex");
+        fillColumn(x, true);
+    }
+
+    for (size_t i = 0; i < count; ++i) {
+        values[i] = cache->getNormalizedMagnitudeAt(col, i * step + minbin);
+    }
+
+    return true;
+}
+
 float
 FFTDataServer::getMaximumMagnitudeAt(size_t x)
 {
@@ -913,7 +985,12 @@
     if (!cache) return 0;
 
     if (!cache->haveSetColumnAt(col)) {
-        fillColumn(x);
+        Profiler profiler("FFTDataServer::getMaximumMagnitudeAt: filling");
+        // hold mutex so that write thread doesn't mess with class
+        // member data in fillColumn
+        MutexLocker locker(&m_writeMutex,
+                           "FFTDataServer::getMaximumMagnitudeAt: m_writeMutex");
+        fillColumn(x, true);
     }
     return cache->getMaximumMagnitudeAt(col);
 }
@@ -930,11 +1007,47 @@
     if (!cache) return 0;
 
     if (!cache->haveSetColumnAt(col)) {
-        fillColumn(x);
+        Profiler profiler("FFTDataServer::getPhaseAt: filling");
+        // hold mutex so that write thread doesn't mess with class
+        // member data in fillColumn
+        MutexLocker locker(&m_writeMutex,
+                           "FFTDataServer::getPhaseAt: m_writeMutex");
+        fillColumn(x, true);
     }
     return cache->getPhaseAt(col, y);
 }
 
+bool
+FFTDataServer::getPhasesAt(size_t x, float *values, size_t minbin, size_t count, size_t step)
+{
+    Profiler profiler("FFTDataServer::getPhasesAt", false);
+
+    if (x >= m_width) return false;
+
+    if (minbin >= m_height) minbin = m_height - 1;
+    if (count == 0) count = (m_height - minbin) / step;
+    else if (minbin + count * step > m_height) {
+        count = (m_height - minbin) / step;
+    }
+
+    size_t col;
+    FFTCache *cache = getCache(x, col);
+    if (!cache) return false;
+
+    if (!cache->haveSetColumnAt(col)) {
+        Profiler profiler("FFTDataServer::getPhasesAt: filling");
+        MutexLocker locker(&m_writeMutex,
+                           "FFTDataServer::getPhasesAt: m_writeMutex");
+        fillColumn(x, true);
+    }
+
+    for (size_t i = 0; i < count; ++i) {
+        values[i] = cache->getPhaseAt(col, i * step + minbin);
+    }
+
+    return true;
+}
+
 void
 FFTDataServer::getValuesAt(size_t x, size_t y, float &real, float &imaginary)
 {
@@ -956,10 +1069,15 @@
     }
 
     if (!cache->haveSetColumnAt(col)) {
+        Profiler profiler("FFTDataServer::getValuesAt: filling");
 #ifdef DEBUG_FFT_SERVER
         std::cerr << "FFTDataServer::getValuesAt(" << x << ", " << y << "): filling" << std::endl;
 #endif
-        fillColumn(x);
+        // hold mutex so that write thread doesn't mess with class
+        // member data in fillColumn
+        MutexLocker locker(&m_writeMutex,
+                           "FFTDataServer::getValuesAt: m_writeMutex");
+        fillColumn(x, true);
     }        
 
     cache->getValuesAt(col, y, real, imaginary);
@@ -991,7 +1109,7 @@
 }    
 
 void
-FFTDataServer::fillColumn(size_t x)
+FFTDataServer::fillColumn(size_t x, bool lockHeld)
 {
     Profiler profiler("FFTDataServer::fillColumn", false);
 
@@ -1022,28 +1140,37 @@
     FFTCache *cache = getCache(x, col);
     if (!cache) return;
 
-    MutexLocker locker(&m_writeMutex,
-                       "FFTDataServer::m_writeMutex[fillColumn]");
+    {
+        MutexLocker locker(lockHeld ? 0 : &m_writeMutex,
+                           "FFTDataServer::fillColumn::m_writeMutex [1]");
 
-    if (cache->haveSetColumnAt(col)) return;
+        if (cache->haveSetColumnAt(col)) return;
+    }
+
+    int winsize = m_windowSize;
+    int fftsize = m_fftSize;
+    int hs = fftsize/2;
+
+    int pfx = 0;
+    int off = (fftsize - winsize) / 2;
 
     int startFrame = m_windowIncrement * x;
     int endFrame = startFrame + m_windowSize;
 
-    startFrame -= int(m_windowSize) / 2;
-    endFrame   -= int(m_windowSize) / 2;
-    size_t pfx = 0;
+    startFrame -= winsize / 2;
+    endFrame   -= winsize / 2;
 
-    size_t off = (m_fftSize - m_windowSize) / 2;
+    for (int i = 0; i < off; ++i) {
+        m_fftInput[i] = 0.0;
+    }
 
-    for (size_t i = 0; i < off; ++i) {
-        m_fftInput[i] = 0.0;
-        m_fftInput[m_fftSize - i - 1] = 0.0;
+    for (int i = 0; i < off; ++i) {
+        m_fftInput[fftsize - i - 1] = 0.0;
     }
 
     if (startFrame < 0) {
-	pfx = size_t(-startFrame);
-	for (size_t i = 0; i < pfx; ++i) {
+	pfx = -startFrame;
+	for (int i = 0; i < pfx; ++i) {
 	    m_fftInput[off + i] = 0.0;
 	}
     }
@@ -1057,13 +1184,13 @@
               << " from channel " << m_channel << std::endl;
 #endif
 
-    size_t count = 0;
+    int count = 0;
     if (endFrame > startFrame + pfx) count = endFrame - (startFrame + pfx);
 
-    size_t got = m_model->getData(m_channel, startFrame + pfx,
-                                  count, m_fftInput + off + pfx);
+    int got = m_model->getData(m_channel, startFrame + pfx,
+                               count, m_fftInput + off + pfx);
 
-    while (got + pfx < m_windowSize) {
+    while (got + pfx < winsize) {
 	m_fftInput[off + got + pfx] = 0.0;
 	++got;
     }
@@ -1071,7 +1198,7 @@
     if (m_channel == -1) {
 	int channels = m_model->getChannelCount();
 	if (channels > 1) {
-	    for (size_t i = 0; i < m_windowSize; ++i) {
+	    for (int i = 0; i < winsize; ++i) {
 		m_fftInput[off + i] /= channels;
 	    }
 	}
@@ -1079,25 +1206,60 @@
 
     m_windower.cut(m_fftInput + off);
 
-    for (size_t i = 0; i < m_fftSize/2; ++i) {
+    for (int i = 0; i < hs; ++i) {
 	fftsample temp = m_fftInput[i];
-	m_fftInput[i] = m_fftInput[i + m_fftSize/2];
-	m_fftInput[i + m_fftSize/2] = temp;
+	m_fftInput[i] = m_fftInput[i + hs];
+	m_fftInput[i + hs] = temp;
     }
 
     fftf_execute(m_fftPlan);
 
-    fftsample factor = 0.0;
+    // If our cache uses polar storage, it's more friendly for us to
+    // do the conversion before taking the write mutex
 
-    for (size_t i = 0; i <= m_fftSize/2; ++i) {
+    float factor = 0.f;
 
-        m_workbuffer[i] = m_fftOutput[i][0];
-        m_workbuffer[i + m_fftSize/2 + 1] = m_fftOutput[i][1];
+    if (cache->getStorageType() == FFTCache::Compact ||
+        cache->getStorageType() == FFTCache::Polar) {
+
+        for (int i = 0; i <= hs; ++i) {
+            fftsample real = m_fftOutput[i][0];
+            fftsample imag = m_fftOutput[i][1];
+            float mag = sqrtf(real * real + imag * imag);
+            m_workbuffer[i] = mag;
+            m_workbuffer[i + hs + 1] = atan2f(imag, real);
+            if (mag > factor) factor = mag;
+        }
+
+    } else {
+
+        for (int i = 0; i <= hs; ++i) {
+            m_workbuffer[i] = m_fftOutput[i][0];
+            m_workbuffer[i + hs + 1] = m_fftOutput[i][1];
+        }
     }
 
-    cache->setColumnAt(col,
-                       m_workbuffer,
-                       m_workbuffer + m_fftSize/2+1);
+    Profiler subprof("FFTDataServer::fillColumn: set to cache");
+
+    {
+        MutexLocker locker(lockHeld ? 0 : &m_writeMutex,
+                           "FFTDataServer::fillColumn: m_writeMutex [2]");
+
+        if (cache->getStorageType() == FFTCache::Compact ||
+            cache->getStorageType() == FFTCache::Polar) {
+            
+            cache->setColumnAt(col,
+                               m_workbuffer,
+                               m_workbuffer + hs + 1,
+                               factor);
+
+        } else {
+
+            cache->setColumnAt(col,
+                               m_workbuffer,
+                               m_workbuffer + hs + 1);
+        }
+    }
 
     if (m_suspended) {
 //        std::cerr << "FFTDataServer::fillColumn(" << x << "): calling resume" << std::endl;
@@ -1174,7 +1336,8 @@
 
         for (size_t f = m_fillFrom; f < end; f += m_server.m_windowIncrement) {
 	    
-            m_server.fillColumn(int((f - start) / m_server.m_windowIncrement));
+            m_server.fillColumn(int((f - start) / m_server.m_windowIncrement),
+                                false);
 
             if (m_server.m_exiting) return;
 
@@ -1184,7 +1347,7 @@
 #endif
                 {
                     MutexLocker locker(&m_server.m_writeMutex,
-                                       "FFTDataServer::m_writeMutex[run/1]");
+                                       "FFTDataServer::run::m_writeMutex [1]");
                     m_server.m_condition.wait(&m_server.m_writeMutex, 10000);
                 }
 #ifdef DEBUG_FFT_SERVER
@@ -1214,7 +1377,8 @@
 
     for (size_t f = start; f < remainingEnd; f += m_server.m_windowIncrement) {
 
-        m_server.fillColumn(int((f - start) / m_server.m_windowIncrement));
+        m_server.fillColumn(int((f - start) / m_server.m_windowIncrement),
+                            false);
 
         if (m_server.m_exiting) return;
 
@@ -1224,7 +1388,7 @@
 #endif
             {
                 MutexLocker locker(&m_server.m_writeMutex,
-                                   "FFTDataServer::m_writeMutex[run/2]");
+                                   "FFTDataServer::run::m_writeMutex [2]");
                 m_server.m_condition.wait(&m_server.m_writeMutex, 10000);
             }
             if (m_server.m_exiting) return;
--- a/data/fft/FFTDataServer.h	Tue Apr 29 15:34:17 2008 +0000
+++ b/data/fft/FFTDataServer.h	Thu May 08 14:46:22 2008 +0000
@@ -81,6 +81,10 @@
     void       getValuesAt(size_t x, size_t y, float &real, float &imaginary);
     bool       isColumnReady(size_t x);
 
+    bool       getMagnitudesAt(size_t x, float *values, size_t minbin = 0, size_t count = 0, size_t step = 1);
+    bool       getNormalizedMagnitudesAt(size_t x, float *values, size_t minbin = 0, size_t count = 0, size_t step = 1);
+    bool       getPhasesAt(size_t x, float *values, size_t minbin = 0, size_t count = 0, size_t step = 1);
+
     void       suspend();
     void       suspendWrites();
     void       resume(); // also happens automatically if new data needed
@@ -194,7 +198,7 @@
     FillThread *m_fillThread;
 
     void deleteProcessingData();
-    void fillColumn(size_t x);
+    void fillColumn(size_t x, bool lockHeld);
 
     QString generateFileBasename() const;
     static QString generateFileBasename(const DenseTimeValueModel *model,
--- a/data/fft/FFTFileCache.cpp	Tue Apr 29 15:34:17 2008 +0000
+++ b/data/fft/FFTFileCache.cpp	Thu May 08 14:46:22 2008 +0000
@@ -18,11 +18,10 @@
 #include "fileio/MatrixFile.h"
 
 #include "base/Profiler.h"
+#include "base/Thread.h"
 
 #include <iostream>
 
-#include <QMutexLocker>
-
 
 // The underlying matrix has height (m_height * 2 + 1).  In each
 // column we store magnitude at [0], [2] etc and phase at [1], [3]
@@ -69,7 +68,7 @@
 void
 FFTFileCache::resize(size_t width, size_t height)
 {
-    QMutexLocker locker(&m_writeMutex);
+    MutexLocker locker(&m_writeMutex, "FFTFileCache::resize::m_writeMutex");
 
     m_mfc->resize(width, height * 2 + m_factorSize);
     if (m_readbuf) {
@@ -163,7 +162,7 @@
     {
         float real, imag;
         getValuesAt(x, y, real, imag);
-        value = princargf(atan2f(imag, real));
+        value = atan2f(imag, real);
         break;
     }
 
@@ -203,7 +202,7 @@
 void
 FFTFileCache::setColumnAt(size_t x, float *mags, float *phases, float factor)
 {
-    QMutexLocker locker(&m_writeMutex);
+    MutexLocker locker(&m_writeMutex, "FFTFileCache::setColumnAt::m_writeMutex");
 
     size_t h = getHeight();
 
@@ -243,7 +242,7 @@
 void
 FFTFileCache::setColumnAt(size_t x, float *real, float *imag)
 {
-    QMutexLocker locker(&m_writeMutex);
+    MutexLocker locker(&m_writeMutex, "FFTFileCache::setColumnAt::m_writeMutex");
 
     size_t h = getHeight();
 
@@ -258,7 +257,7 @@
         }
         for (size_t y = 0; y < h; ++y) {
             float mag = sqrtf(real[y] * real[y] + imag[y] * imag[y]);
-            float phase = princargf(atan2f(imag[y], real[y]));
+            float phase = atan2f(imag[y], real[y]);
             ((uint16_t *)m_writebuf)[y * 2] = uint16_t((mag / factor) * 65535.0);
             ((uint16_t *)m_writebuf)[y * 2 + 1] = uint16_t(int16_t((phase * 32767) / M_PI));
         }
@@ -278,7 +277,7 @@
             float mag = sqrtf(real[y] * real[y] + imag[y] * imag[y]);
             if (mag > factor) factor = mag;
             ((float *)m_writebuf)[y * 2] = mag;
-            float phase = princargf(atan2f(imag[y], real[y]));
+            float phase = atan2f(imag[y], real[y]);
             ((float *)m_writebuf)[y * 2 + 1] = phase;
         }
         break;
--- a/data/fft/FFTFileCache.h	Tue Apr 29 15:34:17 2008 +0000
+++ b/data/fft/FFTFileCache.h	Thu May 08 14:46:22 2008 +0000
@@ -24,12 +24,6 @@
 class FFTFileCache : public FFTCache
 {
 public:
-    enum StorageType {
-        Compact, // 16 bits normalized polar
-        Rectangular, // floating point real+imag
-        Polar, // floating point mag+phase
-    };
-
     FFTFileCache(QString fileBase, MatrixFile::Mode mode,
                  StorageType storageType);
     virtual ~FFTFileCache();
@@ -58,6 +52,7 @@
 
     static size_t getCacheSize(size_t width, size_t height, StorageType type);
 
+    virtual StorageType getStorageType() { return m_storageType; }
     virtual Type getType() { return FileCache; }
 
 protected:
--- a/data/fft/FFTMemoryCache.cpp	Tue Apr 29 15:34:17 2008 +0000
+++ b/data/fft/FFTMemoryCache.cpp	Thu May 08 14:46:22 2008 +0000
@@ -65,6 +65,8 @@
 void
 FFTMemoryCache::resize(size_t width, size_t height)
 {
+    Profiler profiler("FFTMemoryCache::resize");
+
 #ifdef DEBUG_FFT_MEMORY_CACHE
     std::cerr << "FFTMemoryCache[" << this << "]::resize(" << width << "x" << height << " = " << width*height << ")" << std::endl;
 #endif
@@ -182,9 +184,12 @@
 void
 FFTMemoryCache::setColumnAt(size_t x, float *mags, float *phases, float factor)
 {
+    Profiler profiler("FFTMemoryCache::setColumnAt: from polar");
+
     setNormalizationFactor(x, factor);
 
     if (m_storageType == Rectangular) {
+        Profiler subprof("FFTMemoryCache::setColumnAt: polar to cart");
         for (size_t y = 0; y < m_height; ++y) {
             m_freal[x][y] = mags[y] * cosf(phases[y]);
             m_fimag[x][y] = mags[y] * sinf(phases[y]);
@@ -202,6 +207,8 @@
 void
 FFTMemoryCache::setColumnAt(size_t x, float *reals, float *imags)
 {
+    Profiler profiler("FFTMemoryCache::setColumnAt: from cart");
+
     float max = 0.0;
 
     switch (m_storageType) {
@@ -217,15 +224,17 @@
 
     case Compact:
     case Polar:
+    {
+        Profiler subprof("FFTMemoryCache::setColumnAt: cart to polar");
         for (size_t y = 0; y < m_height; ++y) {
             float mag = sqrtf(reals[y] * reals[y] + imags[y] * imags[y]);
             float phase = atan2f(imags[y], reals[y]);
-            phase = princargf(phase);
             reals[y] = mag;
             imags[y] = phase;
             if (mag > max) max = mag;
         }
         break;
+    }
     };
 
     if (m_storageType == Rectangular) {
--- a/data/fft/FFTMemoryCache.h	Tue Apr 29 15:34:17 2008 +0000
+++ b/data/fft/FFTMemoryCache.h	Thu May 08 14:46:22 2008 +0000
@@ -19,6 +19,7 @@
 #include "FFTCache.h"
 
 #include "base/ResizeableBitset.h"
+#include "base/Profiler.h"
 
 /**
  * In-memory FFT cache.  For this we want to cache magnitude with
@@ -42,12 +43,6 @@
 class FFTMemoryCache : public FFTCache
 {
 public:
-    enum StorageType {
-        Compact, // 16 bits normalized polar
-        Rectangular, // floating point real+imag
-        Polar // floating point mag+phase
-    };
-
     FFTMemoryCache(StorageType storageType); // of size zero, call resize() before using
     virtual ~FFTMemoryCache();
 	
@@ -59,6 +54,7 @@
     
     virtual float getMagnitudeAt(size_t x, size_t y) const {
         if (m_storageType == Rectangular) {
+            Profiler profiler("FFTMemoryCache::getMagnitudeAt: cart to polar");
             return sqrt(m_freal[x][y] * m_freal[x][y] +
                         m_fimag[x][y] * m_fimag[x][y]);
         } else {
@@ -78,6 +74,7 @@
     
     virtual float getPhaseAt(size_t x, size_t y) const {
         if (m_storageType == Rectangular) {
+            Profiler profiler("FFTMemoryCache::getValuesAt: cart to polar");
             return atan2f(m_fimag[x][y], m_freal[x][y]);
         } else if (m_storageType == Polar) {
             return m_fphase[x][y];
@@ -92,6 +89,7 @@
             real = m_freal[x][y];
             imag = m_fimag[x][y];
         } else {
+            Profiler profiler("FFTMemoryCache::getValuesAt: polar to cart");
             float mag = getMagnitudeAt(x, y);
             float phase = getPhaseAt(x, y);
             real = mag * cosf(phase);
@@ -109,6 +107,7 @@
 
     static size_t getCacheSize(size_t width, size_t height, StorageType type);
 
+    virtual StorageType getStorageType() { return m_storageType; }
     virtual Type getType() { return MemoryCache; }
 
 private:
--- a/data/fileio/FileReadThread.cpp	Tue Apr 29 15:34:17 2008 +0000
+++ b/data/fileio/FileReadThread.cpp	Thu May 08 14:46:22 2008 +0000
@@ -16,6 +16,7 @@
 #include "FileReadThread.h"
 
 #include "base/Profiler.h"
+#include "base/Thread.h"
 
 #include <iostream>
 #include <unistd.h>
@@ -31,7 +32,7 @@
 void
 FileReadThread::run()
 {
-    m_mutex.lock();
+    MutexLocker locker(&m_mutex, "FileReadThread::run::m_mutex");
 
     while (!m_exiting) {
         if (m_queue.empty()) {
@@ -43,7 +44,6 @@
     }
 
     notifyCancelled();
-    m_mutex.unlock();
 
 #ifdef DEBUG_FILE_READ_THREAD
     std::cerr << "FileReadThread::run() exiting" << std::endl;
@@ -57,16 +57,18 @@
     std::cerr << "FileReadThread::finish()" << std::endl;
 #endif
 
-    m_mutex.lock();
-    while (!m_queue.empty()) {
-        m_cancelledRequests[m_queue.begin()->first] = m_queue.begin()->second;
-        m_newlyCancelled.insert(m_queue.begin()->first);
-        m_queue.erase(m_queue.begin());
+    {
+        MutexLocker locker(&m_mutex, "FileReadThread::finish::m_mutex");
+
+        while (!m_queue.empty()) {
+            m_cancelledRequests[m_queue.begin()->first] = m_queue.begin()->second;
+            m_newlyCancelled.insert(m_queue.begin()->first);
+            m_queue.erase(m_queue.begin());
+        }
+        
+        m_exiting = true;
     }
 
-    m_exiting = true;
-    m_mutex.unlock();
-
     m_condition.wakeAll();
 
 #ifdef DEBUG_FILE_READ_THREAD
@@ -77,12 +79,15 @@
 int
 FileReadThread::request(const Request &request)
 {
-    m_mutex.lock();
+    int token;
+
+    {
+        MutexLocker locker(&m_mutex, "FileReadThread::request::m_mutex");
     
-    int token = m_nextToken++;
-    m_queue[token] = request;
+        token = m_nextToken++;
+        m_queue[token] = request;
+    }
 
-    m_mutex.unlock();
     m_condition.wakeAll();
 
     return token;
@@ -91,21 +96,21 @@
 void
 FileReadThread::cancel(int token)
 {
-    m_mutex.lock();
+    {
+        MutexLocker locker(&m_mutex, "FileReadThread::cancel::m_mutex");
 
-    if (m_queue.find(token) != m_queue.end()) {
-        m_cancelledRequests[token] = m_queue[token];
-        m_queue.erase(token);
-        m_newlyCancelled.insert(token);
-    } else if (m_readyRequests.find(token) != m_readyRequests.end()) {
-        m_cancelledRequests[token] = m_readyRequests[token];
-        m_readyRequests.erase(token);
-    } else {
-        std::cerr << "WARNING: FileReadThread::cancel: token " << token << " not found" << std::endl;
+        if (m_queue.find(token) != m_queue.end()) {
+            m_cancelledRequests[token] = m_queue[token];
+            m_queue.erase(token);
+            m_newlyCancelled.insert(token);
+        } else if (m_readyRequests.find(token) != m_readyRequests.end()) {
+            m_cancelledRequests[token] = m_readyRequests[token];
+            m_readyRequests.erase(token);
+        } else {
+            std::cerr << "WARNING: FileReadThread::cancel: token " << token << " not found" << std::endl;
+        }
     }
 
-    m_mutex.unlock();
-
 #ifdef DEBUG_FILE_READ_THREAD
     std::cerr << "FileReadThread::cancel(" << token << ") waking condition" << std::endl;
 #endif
@@ -116,31 +121,29 @@
 bool
 FileReadThread::isReady(int token)
 {
-    m_mutex.lock();
+    MutexLocker locker(&m_mutex, "FileReadThread::isReady::m_mutex");
 
     bool ready = m_readyRequests.find(token) != m_readyRequests.end();
 
-    m_mutex.unlock();
     return ready;
 }
 
 bool
 FileReadThread::isCancelled(int token)
 {
-    m_mutex.lock();
+    MutexLocker locker(&m_mutex, "FileReadThread::isCancelled::m_mutex");
 
     bool cancelled = 
         m_cancelledRequests.find(token) != m_cancelledRequests.end() &&
         m_newlyCancelled.find(token) == m_newlyCancelled.end();
 
-    m_mutex.unlock();
     return cancelled;
 }
 
 bool
 FileReadThread::getRequest(int token, Request &request)
 {
-    m_mutex.lock();
+    MutexLocker locker(&m_mutex, "FileReadThread::getRequest::m_mutex");
 
     bool found = false;
 
@@ -155,15 +158,13 @@
         found = true;
     }
 
-    m_mutex.unlock();
-    
     return found;
 }
 
 void
 FileReadThread::done(int token)
 {
-    m_mutex.lock();
+    MutexLocker locker(&m_mutex, "FileReadThread::done::m_mutex");
 
     bool found = false;
 
@@ -178,8 +179,6 @@
         std::cerr << "WARNING: FileReadThread::done(" << token << "): request is still in queue (wait or cancel it)" << std::endl;
     }
 
-    m_mutex.unlock();
-
     if (!found) {
         std::cerr << "WARNING: FileReadThread::done(" << token << "): request not found" << std::endl;
     }
@@ -190,9 +189,7 @@
 {
     // entered with m_mutex locked and m_queue non-empty
 
-#ifdef DEBUG_FILE_READ_THREAD
-    Profiler profiler("FileReadThread::process()", true);
-#endif
+    Profiler profiler("FileReadThread::process", true);
 
     int token = m_queue.begin()->first;
     Request request = m_queue.begin()->second;
@@ -207,38 +204,38 @@
     bool seekFailed = false;
     ssize_t r = 0;
 
-    if (request.mutex) request.mutex->lock();
+    { 
+        MutexLocker rlocker(request.mutex, "FileReadThread::process::request.mutex");
 
-    if (::lseek(request.fd, request.start, SEEK_SET) == (off_t)-1) {
-        seekFailed = true;
-    } else {
+        if (::lseek(request.fd, request.start, SEEK_SET) == (off_t)-1) {
+            seekFailed = true;
+        } else {
         
-        // if request.size is large, we want to avoid making a single
-        // system call to read it all as it may block too much
-
-        static const size_t blockSize = 256 * 1024;
-        
-        size_t size = request.size;
-        char *destination = request.data;
-
-        while (size > 0) {
-            size_t readSize = size;
-            if (readSize > blockSize) readSize = blockSize;
-            ssize_t br = ::read(request.fd, destination, readSize);
-            if (br < 0) { 
-                r = br;
-                break;
-            } else {
-                r += br;
-                if (br < ssize_t(readSize)) break;
+            // if request.size is large, we want to avoid making a single
+            // system call to read it all as it may block too much
+            
+            static const size_t blockSize = 256 * 1024;
+            
+            size_t size = request.size;
+            char *destination = request.data;
+            
+            while (size > 0) {
+                size_t readSize = size;
+                if (readSize > blockSize) readSize = blockSize;
+                ssize_t br = ::read(request.fd, destination, readSize);
+                if (br < 0) { 
+                    r = br;
+                    break;
+                } else {
+                    r += br;
+                    if (br < ssize_t(readSize)) break;
+                }
+                destination += readSize;
+                size -= readSize;
             }
-            destination += readSize;
-            size -= readSize;
         }
     }
 
-    if (request.mutex) request.mutex->unlock();
-
     if (seekFailed) {
         ::perror("Seek failed");
         std::cerr << "ERROR: FileReadThread::process: seek to "
--- a/data/fileio/MatrixFile.cpp	Tue Apr 29 15:34:17 2008 +0000
+++ b/data/fileio/MatrixFile.cpp	Thu May 08 14:46:22 2008 +0000
@@ -18,6 +18,7 @@
 #include "system/System.h"
 #include "base/Profiler.h"
 #include "base/Exceptions.h"
+#include "base/Thread.h"
 
 #include <sys/types.h>
 #include <sys/stat.h>
@@ -149,16 +150,19 @@
 
     m_fileName = fileName;
 
-    m_columnBitsetWriteMutex.lock();
+    {
+        MutexLocker locker
+            (&m_columnBitsetWriteMutex,
+             "MatrixFile::MatrixFile::m_columnBitsetWriteMutex");
 
-    if (m_columnBitsets.find(m_fileName) == m_columnBitsets.end()) {
-        m_columnBitsets[m_fileName] = new ResizeableBitset;
+        if (m_columnBitsets.find(m_fileName) == m_columnBitsets.end()) {
+            m_columnBitsets[m_fileName] = new ResizeableBitset;
+        }
+        m_columnBitset = m_columnBitsets[m_fileName];
     }
-    m_columnBitset = m_columnBitsets[m_fileName];
 
-    m_columnBitsetWriteMutex.unlock();
-
-    QMutexLocker locker(&m_refcountMutex);
+    MutexLocker locker(&m_refcountMutex,
+                       "MatrixFile::MatrixFile::m_refcountMutex");
     ++m_refcount[fileName];
 
 //    std::cerr << "MatrixFile(" << this << "): fd " << m_fd << ", file " << fileName.toStdString() << ", ref " << m_refcount[fileName] << std::endl;
@@ -193,7 +197,8 @@
 
     if (m_fileName != "") {
 
-        QMutexLocker locker(&m_refcountMutex);
+        MutexLocker locker(&m_refcountMutex,
+                           "MatrixFile::~MatrixFile::m_refcountMutex");
 
         if (--m_refcount[m_fileName] == 0) {
 
@@ -204,7 +209,9 @@
 //                std::cerr << "deleted " << m_fileName.toStdString() << std::endl;
             }
 
-            QMutexLocker locker2(&m_columnBitsetWriteMutex);
+            MutexLocker locker2
+                (&m_columnBitsetWriteMutex,
+                 "MatrixFile::~MatrixFile::m_columnBitsetWriteMutex");
             m_columnBitsets.erase(m_fileName);
             delete m_columnBitset;
         }
@@ -227,7 +234,7 @@
 
     assert(m_mode == ReadWrite);
 
-    QMutexLocker locker(&m_fdMutex);
+    MutexLocker locker(&m_fdMutex, "MatrixFile::resize::m_fdMutex");
     
     totalStorage -= (m_headerSize + (m_width * m_height * m_cellSize));
     totalMemory -= (2 * m_defaultCacheWidth * m_height * m_cellSize);
@@ -272,7 +279,8 @@
     }
 
     if (m_columnBitset) {
-        QMutexLocker locker(&m_columnBitsetWriteMutex);
+        MutexLocker locker(&m_columnBitsetWriteMutex,
+                           "MatrixFile::resize::m_columnBitsetWriteMutex");
         m_columnBitset->resize(w);
     }
 
@@ -319,7 +327,8 @@
     }
     
     if (m_columnBitset) {
-        QMutexLocker locker(&m_columnBitsetWriteMutex);
+        MutexLocker locker(&m_columnBitsetWriteMutex,
+                           "MatrixFile::reset::m_columnBitsetWriteMutex");
         m_columnBitset->resize(m_width);
     }
 }
@@ -327,13 +336,13 @@
 void
 MatrixFile::getColumnAt(size_t x, void *data)
 {
-//    Profiler profiler("MatrixFile::getColumnAt");
+    Profiler profiler("MatrixFile::getColumnAt");
 
 //    assert(haveSetColumnAt(x));
 
     if (getFromCache(x, 0, m_height, data)) return;
 
-//    Profiler profiler2("MatrixFile::getColumnAt (uncached)");
+    Profiler profiler2("MatrixFile::getColumnAt (uncached)");
 
     ssize_t r = 0;
 
@@ -351,13 +360,13 @@
     std::cerr << std::endl;
 #endif
 
-    m_fdMutex.lock();
+    {
+        MutexLocker locker(&m_fdMutex, "MatrixFile::getColumnAt::m_fdMutex");
 
-    if (seekTo(x, 0)) {
-        r = ::read(m_fd, data, m_height * m_cellSize);
+        if (seekTo(x, 0)) {
+            r = ::read(m_fd, data, m_height * m_cellSize);
+        }
     }
-
-    m_fdMutex.unlock();
     
     if (r < 0) {
         ::perror("MatrixFile::getColumnAt: read failed");
@@ -373,22 +382,29 @@
 bool
 MatrixFile::getFromCache(size_t x, size_t ystart, size_t ycount, void *data)
 {
-    m_cacheMutex.lock();
+    bool fail = false;
+    bool primeLeft = false;
 
-    if (!m_cache.data || x < m_cache.x || x >= m_cache.x + m_cache.width) {
-        bool left = (m_cache.data && x < m_cache.x);
-        m_cacheMutex.unlock();
-        primeCache(x, left); // this doesn't take effect until a later callback
+    {
+        MutexLocker locker(&m_cacheMutex,
+                           "MatrixFile::getFromCache::m_cacheMutex");
+
+        if (!m_cache.data || x < m_cache.x || x >= m_cache.x + m_cache.width) {
+            fail = true;
+            primeLeft = (m_cache.data && x < m_cache.x);
+        } else {
+            memcpy(data,
+                   m_cache.data + m_cellSize * ((x - m_cache.x) * m_height + ystart),
+                   ycount * m_cellSize);
+        }            
+    }
+
+    if (fail) {
+        primeCache(x, primeLeft); // this doesn't take effect until a later callback
         m_prevX = x;
         return false;
     }
 
-    memcpy(data,
-           m_cache.data + m_cellSize * ((x - m_cache.x) * m_height + ystart),
-           ycount * m_cellSize);
-
-    m_cacheMutex.unlock();
-
     if (m_cache.x > 0 && x < m_prevX && x < m_cache.x + m_cache.width/4) {
         primeCache(x, true);
     }
@@ -414,24 +430,26 @@
 
     ssize_t w = 0;
     bool seekFailed = false;
+    
+    {
+        MutexLocker locker(&m_fdMutex, "MatrixFile::setColumnAt::m_fdMutex");
 
-    m_fdMutex.lock();
-
-    if (seekTo(x, 0)) {
-        w = ::write(m_fd, data, m_height * m_cellSize);
-    } else {
-        seekFailed = true;
+        if (seekTo(x, 0)) {
+            w = ::write(m_fd, data, m_height * m_cellSize);
+        } else {
+            seekFailed = true;
+        }
     }
 
-    m_fdMutex.unlock();
-
     if (!seekFailed && w != ssize_t(m_height * m_cellSize)) {
         ::perror("WARNING: MatrixFile::setColumnAt: write failed");
         throw FileOperationFailed(m_fileName, "write");
     } else if (seekFailed) {
         throw FileOperationFailed(m_fileName, "seek");
     } else {
-        QMutexLocker locker(&m_columnBitsetWriteMutex);
+        MutexLocker locker
+            (&m_columnBitsetWriteMutex,
+             "MatrixFile::setColumnAt::m_columnBitsetWriteMutex");
         m_columnBitset->set(x);
     }
 }
@@ -439,8 +457,8 @@
 void
 MatrixFile::suspend()
 {
-    QMutexLocker locker(&m_fdMutex);
-    QMutexLocker locker2(&m_cacheMutex);
+    MutexLocker locker(&m_fdMutex, "MatrixFile::suspend::m_fdMutex");
+    MutexLocker locker2(&m_cacheMutex, "MatrixFile::suspend::m_cacheMutex");
 
     if (m_fd < 0) return; // already suspended
 
@@ -539,7 +557,7 @@
         if (rw < 10 || rx + rw <= x) return;
     }
 
-    QMutexLocker locker(&m_cacheMutex);
+    MutexLocker locker(&m_cacheMutex, "MatrixFile::primeCache::m_cacheMutex");
 
     FileReadThread::Request request;
 
@@ -601,9 +619,8 @@
     }
 
     if (m_fd < 0) {
-        m_fdMutex.lock();
+        MutexLocker locker(&m_fdMutex, "MatrixFile::primeCache::m_fdMutex");
         if (m_fd < 0) resume();
-        m_fdMutex.unlock();
     }
 
     request.fd = m_fd;
--- a/data/model/AlignmentModel.cpp	Tue Apr 29 15:34:17 2008 +0000
+++ b/data/model/AlignmentModel.cpp	Thu May 08 14:46:22 2008 +0000
@@ -17,7 +17,7 @@
 
 #include "SparseTimeValueModel.h"
 
-//#define DEBUG_ALIGNMENT_MODEL 1
+#define DEBUG_ALIGNMENT_MODEL 1
 
 AlignmentModel::AlignmentModel(Model *reference,
                                Model *aligned,
--- a/data/model/FFTModel.cpp	Tue Apr 29 15:34:17 2008 +0000
+++ b/data/model/FFTModel.cpp	Thu May 08 14:46:22 2008 +0000
@@ -167,9 +167,15 @@
     Profiler profiler("FFTModel::getColumn", false);
 
     result.clear();
-    size_t height(getHeight());
-    for (size_t y = 0; y < height; ++y) {
-        result.push_back(const_cast<FFTModel *>(this)->getMagnitudeAt(x, y));
+    size_t h = getHeight();
+
+    float magnitudes[h];
+    if (m_server->getMagnitudesAt(x << m_xshift, magnitudes)) {
+        for (size_t y = 0; y < h; ++y) {
+            result.push_back(magnitudes[h]);
+        }
+    } else {
+        for (size_t i = 0; i < h; ++i) result.push_back(0.f);
     }
 }
 
--- a/data/model/FFTModel.h	Tue Apr 29 15:34:17 2008 +0000
+++ b/data/model/FFTModel.h	Thu May 08 14:46:22 2008 +0000
@@ -85,6 +85,16 @@
         return m_server->isColumnReady(x << m_xshift);
     }
 
+    float getMagnitudesAt(size_t x, float *values, size_t minbin = 0, size_t count = 0) {
+        return m_server->getMagnitudesAt(x << m_xshift, values, minbin << m_yshift, count, getYRatio());
+    }
+    float getNormalizedMagnitudesAt(size_t x, float *values, size_t minbin = 0, size_t count = 0) {
+        return m_server->getNormalizedMagnitudesAt(x << m_xshift, values, minbin << m_yshift, count, getYRatio());
+    }
+    float getPhasesAt(size_t x, float *values, size_t minbin = 0, size_t count = 0) {
+        return m_server->getPhasesAt(x << m_xshift, values, minbin << m_yshift, count, getYRatio());
+    }
+
     size_t getFillExtent() const { return m_server->getFillExtent(); }
 
     // DenseThreeDimensionalModel and Model methods:
@@ -186,6 +196,13 @@
 
     size_t getPeakPickWindowSize(PeakPickType type, size_t sampleRate,
                                  size_t bin, float &percentile) const;
+
+    size_t getYRatio() {
+        size_t ys = m_yshift;
+        size_t r = 1;
+        while (ys) { --ys; r <<= 1; }
+        return r;
+    }
 };
 
 #endif
--- a/data/osc/OSCQueue.cpp	Tue Apr 29 15:34:17 2008 +0000
+++ b/data/osc/OSCQueue.cpp	Thu May 08 14:46:22 2008 +0000
@@ -20,6 +20,8 @@
 
 #include "OSCQueue.h"
 
+#include "base/Profiler.h"
+
 #include <iostream>
 
 #define OSC_MESSAGE_QUEUE_SIZE 1023
@@ -91,6 +93,8 @@
 #endif
     m_buffer(OSC_MESSAGE_QUEUE_SIZE)
 {
+    Profiler profiler("OSCQueue::OSCQueue");
+
 #ifdef HAVE_LIBLO
     m_thread = lo_server_thread_new(NULL, oscError);
 
--- a/plugin/DSSIPluginFactory.cpp	Tue Apr 29 15:34:17 2008 +0000
+++ b/plugin/DSSIPluginFactory.cpp	Thu May 08 14:46:22 2008 +0000
@@ -28,6 +28,8 @@
 
 #include <cstdlib>
 
+#include "base/Profiler.h"
+
 //!!!
 #include "plugin/plugins/SamplePlayer.h"
 
@@ -56,6 +58,8 @@
 void
 DSSIPluginFactory::enumeratePlugins(std::vector<QString> &list)
 {
+    Profiler profiler("DSSIPluginFactory::enumeratePlugins");
+
     for (std::vector<QString>::iterator i = m_identifiers.begin();
 	 i != m_identifiers.end(); ++i) {
 
@@ -113,6 +117,8 @@
 				     unsigned int blockSize,
 				     unsigned int channels)
 {
+    Profiler profiler("DSSIPluginFactory::instantiatePlugin");
+
     const DSSI_Descriptor *descriptor = getDSSIDescriptor(identifier);
 
     if (descriptor) {
@@ -277,6 +283,8 @@
 void
 DSSIPluginFactory::discoverPlugins(QString soname)
 {
+    Profiler profiler("DSSIPluginFactory::discoverPlugins");
+
     // Note that soname is expected to be a full path at this point,
     // of a file that is known to exist
 
--- a/plugin/FeatureExtractionPluginFactory.cpp	Tue Apr 29 15:34:17 2008 +0000
+++ b/plugin/FeatureExtractionPluginFactory.cpp	Thu May 08 14:46:22 2008 +0000
@@ -29,6 +29,8 @@
 
 #include <iostream>
 
+#include "base/Profiler.h"
+
 //#define DEBUG_PLUGIN_SCAN_AND_INSTANTIATE 1
 
 class PluginDeletionNotifyAdapter : public Vamp::HostExt::PluginWrapper {
@@ -108,6 +110,8 @@
 std::vector<QString>
 FeatureExtractionPluginFactory::getPluginIdentifiers()
 {
+    Profiler profiler("FeatureExtractionPluginFactory::getPluginIdentifiers");
+
     std::vector<QString> rv;
     std::vector<QString> path = getPluginPath();
     
@@ -296,6 +300,8 @@
 FeatureExtractionPluginFactory::instantiatePlugin(QString identifier,
 						  float inputSampleRate)
 {
+    Profiler profiler("FeatureExtractionPluginFactory::instantiatePlugin");
+
     Vamp::Plugin *rv = 0;
     Vamp::PluginHostAdapter *plugin = 0;
 
--- a/plugin/LADSPAPluginFactory.cpp	Tue Apr 29 15:34:17 2008 +0000
+++ b/plugin/LADSPAPluginFactory.cpp	Thu May 08 14:46:22 2008 +0000
@@ -32,6 +32,7 @@
 
 #include "system/System.h"
 #include "base/Preferences.h"
+#include "base/Profiler.h"
 
 //#define DEBUG_LADSPA_PLUGIN_FACTORY 1
 
@@ -71,6 +72,8 @@
 void
 LADSPAPluginFactory::enumeratePlugins(std::vector<QString> &list)
 {
+    Profiler profiler("LADSPAPluginFactory::enumeratePlugins");
+
     for (std::vector<QString>::iterator i = m_identifiers.begin();
 	 i != m_identifiers.end(); ++i) {
 
@@ -332,6 +335,8 @@
 				       unsigned int blockSize,
 				       unsigned int channels)
 {
+    Profiler profiler("LADSPAPluginFactory::instantiatePlugin");
+
     const LADSPA_Descriptor *descriptor = getLADSPADescriptor(identifier);
 
     if (descriptor) {
@@ -358,6 +363,8 @@
 LADSPAPluginFactory::releasePlugin(RealTimePluginInstance *instance,
 				   QString identifier)
 {
+    Profiler profiler("LADSPAPluginFactory::releasePlugin");
+
     if (m_instances.find(instance) == m_instances.end()) {
 	std::cerr << "WARNING: LADSPAPluginFactory::releasePlugin: Not one of mine!"
 		  << std::endl;
@@ -622,6 +629,8 @@
 void
 LADSPAPluginFactory::discoverPlugins()
 {
+    Profiler profiler("LADSPAPluginFactory::discoverPlugins");
+
     std::vector<QString> pathList = getPluginPath();
 
 //    std::cerr << "LADSPAPluginFactory::discoverPlugins - "
--- a/plugin/RealTimePluginFactory.cpp	Tue Apr 29 15:34:17 2008 +0000
+++ b/plugin/RealTimePluginFactory.cpp	Thu May 08 14:46:22 2008 +0000
@@ -26,6 +26,7 @@
 #include "DSSIPluginFactory.h"
 
 #include "system/System.h"
+#include "base/Profiler.h"
 
 #include <iostream>
 
@@ -73,6 +74,8 @@
 std::vector<QString>
 RealTimePluginFactory::getAllPluginIdentifiers()
 {
+    Profiler profiler("RealTimePluginFactory::getAllPluginIdentifiers");
+
     RealTimePluginFactory *factory;
     std::vector<QString> rv;
     
@@ -108,6 +111,8 @@
 void
 RealTimePluginFactory::enumerateAllPlugins(std::vector<QString> &list)
 {
+    Profiler profiler("RealTimePluginFactory::enumerateAllPlugins");
+
     RealTimePluginFactory *factory;
 
     // Query DSSI plugins before LADSPA ones.
--- a/transform/FeatureExtractionModelTransformer.cpp	Tue Apr 29 15:34:17 2008 +0000
+++ b/transform/FeatureExtractionModelTransformer.cpp	Thu May 08 14:46:22 2008 +0000
@@ -278,6 +278,8 @@
 DenseTimeValueModel *
 FeatureExtractionModelTransformer::getConformingInput()
 {
+//    std::cerr << "FeatureExtractionModelTransformer::getConformingInput: input model is " << getInputModel() << std::endl;
+
     DenseTimeValueModel *dtvm =
 	dynamic_cast<DenseTimeValueModel *>(getInputModel());
     if (!dtvm) {
--- a/transform/ModelTransformerFactory.cpp	Tue Apr 29 15:34:17 2008 +0000
+++ b/transform/ModelTransformerFactory.cpp	Thu May 08 14:46:22 2008 +0000
@@ -361,6 +361,8 @@
                                    const ModelTransformer::Input &input,
                                    QString &message)
 {
+    std::cerr << "ModelTransformerFactory::transform: Constructing transformer with input model " << input.getModel() << std::endl;
+
     ModelTransformer *t = createTransformer(transform, input);
     if (!t) return 0;