changeset 67:146d14ab15e7

Debug output: off by default, on with VAMPY_VERBOSE environment variable
author Chris Cannam
date Mon, 17 Nov 2014 10:03:44 +0000
parents 5664fe298af2
children 44d56a3d16b7
files Debug.h Example VamPy plugins/PyMFCC.py Example VamPy plugins/PySpectralFeatures.py PyExtensionManager.cpp PyExtensionModule.cpp PyPlugin.cpp PyPlugin.h README vampy-main.cpp
diffstat 9 files changed, 100 insertions(+), 99 deletions(-) [+]
line wrap: on
line diff
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/Debug.h	Mon Nov 17 10:03:44 2014 +0000
@@ -0,0 +1,30 @@
+
+#ifndef DEBUG_H_INCLUDED
+#define DEBUG_H_INCLUDED
+
+#include <iostream>
+#include <cstdlib>
+
+class MyDebug
+{
+public:
+    MyDebug() : want(std::getenv("VAMPY_VERBOSE") != 0) { }
+
+    template <typename T>
+    MyDebug &operator<<(const T &t) {
+	if (want) std::cerr << t;
+        return *this;
+    }
+    
+    MyDebug &operator<<(std::ostream &(*o)(std::ostream &)) {
+	if (want) std::cerr << o;
+        return *this;
+    }
+    
+private:
+    bool want;
+};
+
+#define DSTREAM (MyDebug())
+
+#endif
--- a/Example VamPy plugins/PyMFCC.py	Mon Nov 17 09:37:59 2014 +0000
+++ b/Example VamPy plugins/PyMFCC.py	Mon Nov 17 10:03:44 2014 +0000
@@ -52,16 +52,16 @@
 		if self.updated: return self.valid
 		self.updated = True
 		self.valid = False
-		print 'Updating parameters and recalculating filters: '
-		print 'Nyquist: ',self.NqHz
+#		print 'Updating parameters and recalculating filters: '
+#		print 'Nyquist: ',self.NqHz
 		
 		if self.maxHz > self.NqHz : 
 			raise Exception('Maximum frequency must be smaller than the Nyquist frequency')
 		
 		self.maxMel = 1000*log(1+self.maxHz/700.0)/log(1+1000.0/700.0)
 		self.minMel = 1000*log(1+self.minHz/700.0)/log(1+1000.0/700.0)
-		print 'minHz:%s\nmaxHz:%s\nminMel:%s\nmaxMel:%s\n' \
-		%(self.minHz,self.maxHz,self.minMel,self.maxMel)
+#		print 'minHz:%s\nmaxHz:%s\nminMel:%s\nmaxMel:%s\n' \
+#		%(self.minHz,self.maxHz,self.minMel,self.maxMel)
 		self.filterMatrix = self.getFilterMatrix(self.inputSize,self.numBands)
 		self.DCTMatrix = self.getDCTMatrix(self.numBands)
 		self.filterIter = self.filterMatrix.__iter__()
@@ -124,7 +124,7 @@
 	def __init__(self,inputSampleRate):
 		
 		# flags for setting some Vampy options
-		self.vampy_flags = vf_DEBUG | vf_ARRAY | vf_REALTIME
+		self.vampy_flags = vf_ARRAY | vf_REALTIME
 
 		self.m_inputSampleRate = int(inputSampleRate)
 		self.m_stepSize = 1024
--- a/Example VamPy plugins/PySpectralFeatures.py	Mon Nov 17 09:37:59 2014 +0000
+++ b/Example VamPy plugins/PySpectralFeatures.py	Mon Nov 17 10:03:44 2014 +0000
@@ -22,7 +22,7 @@
 	def __init__(self,inputSampleRate):
 
 		# flags:
-		self.vampy_flags = vf_DEBUG | vf_BUFFER | vf_REALTIME
+		self.vampy_flags = vf_BUFFER | vf_REALTIME
 
 		self.m_inputSampleRate = inputSampleRate
 		self.m_stepSize = 0
--- a/PyExtensionManager.cpp	Mon Nov 17 09:37:59 2014 +0000
+++ b/PyExtensionManager.cpp	Mon Nov 17 10:03:44 2014 +0000
@@ -1,3 +1,4 @@
+/* -*- c-basic-offset: 8 indent-tabs-mode: t -*- */
 /*
 
  * Vampy : This plugin is a wrapper around the Vamp plugin API.
@@ -14,6 +15,7 @@
 #include "PyExtensionModule.h"
 #include "PyExtensionManager.h"
 #include <algorithm>
+#include "Debug.h"
 
 using std::cerr;
 using std::endl;
@@ -44,15 +46,13 @@
 
 PyExtensionManager::PyExtensionManager()
 {
-#ifdef _DEBUG	
-	cerr << "Creating extension manager." << endl;
-#endif
+	DSTREAM << "Creating extension manager." << endl;
 }
 
 bool 
 PyExtensionManager::initExtension() 
 {
-	cerr << "Initialising extension module." << endl; 
+	DSTREAM << "Initialising extension module." << endl; 
 
 	/// call the module initialiser first
 	initvampy();
@@ -70,28 +70,24 @@
     
 	/// initialise local namespaces
 	updateAllLocals();
-#ifdef _DEBUG
-	cerr << "Vampy: Extension namespaces updated." << endl; 
-#endif	
+
+	DSTREAM << "Vampy: Extension namespaces updated." << endl; 
+
 	return true;
 }
 
 
 PyExtensionManager::~PyExtensionManager()
 {
-#ifdef _DEBUG	
-	cerr << "Cleaning locals..." << endl;
-#endif	
+	DSTREAM << "Cleaning locals..." << endl;
 
 	cleanAllLocals(); 
 
-#ifdef _DEBUG	
-	cerr << "Cleaning module..." << endl;
-#endif	
+	DSTREAM << "Cleaning module..." << endl;
 
 	if (!cleanModule()) 
 		cerr << "Vampy::~PyExtensionManager: failed to clean extension module." << endl;
-	cerr << "Vampy::~PyExtensionManager: Extension module cleaned." << endl;
+	DSTREAM << "Vampy::~PyExtensionManager: Extension module cleaned." << endl;
 }
 
 
@@ -104,10 +100,7 @@
 		string tmp = modName.substr(modName.rfind(':')+1,modName.size()-1);
 		m_plugModuleNames.push_back(tmp);
 
-#ifdef _DEBUG_VALUES		
-		cerr << "Inserted module name: " << tmp << endl;
-#endif		
-
+		DSTREAM << "Inserted module name: " << tmp << endl;
 	}
 }
 
@@ -118,9 +111,8 @@
 	vector<string>::iterator it = 
 		find (m_plugModuleNames.begin(), m_plugModuleNames.end(), name);
 	if (it != m_plugModuleNames.end()) m_plugModuleNames.erase(it);
-#ifdef _DEBUG_VALUES		
-	cerr << "PyExtensionManager::deleteModuleName: Deleted module name: " << name << endl;
-#endif	
+
+	DSTREAM << "PyExtensionManager::deleteModuleName: Deleted module name: " << name << endl;
 }
 
 
@@ -160,9 +152,7 @@
 			if (PyDict_SetItem(pyPlugDict,key,Py_None) != 0)
 				cerr << "Vampy::PyExtensionManager::cleanLocalNamespace: Failed: " 
 				<< name << " of "<< plugModuleName << endl;
-#ifdef _DEBUG_VALUES
-			else cerr << "Cleaned local name: " << name << endl;
-#endif			
+			else DSTREAM << "Cleaned local name: " << name << endl;
 		}
 		Py_DECREF(key);
 	}
@@ -192,9 +182,7 @@
 			if (PyDict_SetItem(pyPlugDict,key,item) != 0)
 				cerr << "Vampy::PyExtensionManager::updateLocalNamespace: Failed: " 
 				<< name << " of "<< plugModuleName << endl;
-#ifdef _DEBUG_VALUES
-			else cerr << "Updated local name: " << name << endl;
-#endif			
+			else DSTREAM << "Updated local name: " << name << endl;
 		}
 		Py_DECREF(key);
 	}
@@ -214,7 +202,7 @@
 		PyObject *dict = PyModule_GetDict(m);
 #ifdef _DEBUG		
 		Py_ssize_t ln = PyDict_Size(dict);
-		cerr << "Vampy::PyExtensionManager::cleanModule: Size of module dict = " << (int) ln << endl;
+		DSTREAM << "Vampy::PyExtensionManager::cleanModule: Size of module dict = " << (int) ln << endl;
 #endif		
 		/// Clean the module dictionary.
 		// printDict(dict);
@@ -226,7 +214,7 @@
 		Py_XDECREF(name);
 #ifdef _DEBUG		
 	    ln = PyDict_Size(dict);
-		cerr << "Vampy::PyExtensionManager::cleanModule: Size of module dict (cleaned) = " << (int) ln << endl;
+		DSTREAM << "Vampy::PyExtensionManager::cleanModule: Size of module dict (cleaned) = " << (int) ln << endl;
 #endif
 		return true;
 	}
--- a/PyExtensionModule.cpp	Mon Nov 17 09:37:59 2014 +0000
+++ b/PyExtensionModule.cpp	Mon Nov 17 10:03:44 2014 +0000
@@ -16,6 +16,7 @@
 #include "PyFeatureSet.h"
 #include "PyParameterDescriptor.h"
 #include "PyOutputDescriptor.h"
+#include "Debug.h"
 #include "vamp/vamp.h"
 #include "vamp-sdk/Plugin.h"
 
@@ -250,9 +251,7 @@
 	Py_INCREF((PyObject*)&ParameterDescriptor_Type);
 	if (PyModule_AddObject(module,"ParameterDescriptor",(PyObject*)&ParameterDescriptor_Type) !=0) goto failure;
 	
-#ifdef _DEBUG	
-	cerr << "Vampy: extension module initialised." << endl;
-#endif
+	DSTREAM << "Vampy: extension module initialised." << endl;
 
 	return;
 	
--- a/PyPlugin.cpp	Mon Nov 17 09:37:59 2014 +0000
+++ b/PyPlugin.cpp	Mon Nov 17 10:03:44 2014 +0000
@@ -14,7 +14,7 @@
 #include "PyTypeInterface.h"
 #include <stdlib.h>
 #include "PyExtensionModule.h"
-
+#include "Debug.h"
 
 #ifdef _WIN32
 #define PATHSEP ('\\')
@@ -50,7 +50,7 @@
 {	
 	m_ti.setInputSampleRate(inputSampleRate);
 	MutexLocker locker(&m_pythonInterpreterMutex);
-	cerr << "Creating instance " << m_instcount << " of " << pluginKey << endl;
+	DSTREAM << "Creating instance " << m_instcount << " of " << pluginKey << endl;
 		
 	// Create an instance
 	Py_INCREF(m_pyClass);
@@ -82,7 +82,7 @@
 	m_useRealTimeFlag = (bool) (m_vampyFlags & vf_REALTIME);
 		
 	if (m_debugFlag) cerr << "Debug messages ON for Vampy plugin: " << m_class << endl;
-	else cerr << "Debug messages OFF for Vampy plugin: " << m_class << endl;
+	else DSTREAM << "Debug messages OFF for Vampy plugin: " << m_class << endl;
 	
 	if (m_debugFlag && m_quitOnErrorFlag) cerr << "Quit on type error ON for: " << m_class << endl;
    
@@ -103,9 +103,7 @@
 	if (m_pyClass) Py_DECREF(m_pyClass); 
 	if (m_pyProcess) Py_CLEAR(m_pyProcess);
 
-#ifdef _DEBUG
-	cerr << "PyPlugin::PyPlugin:" << m_class << " instance " << m_instcount << " deleted." << endl;
-#endif
+	DSTREAM << "PyPlugin::PyPlugin:" << m_class << " instance " << m_instcount << " deleted." << endl;
 }
 
 string
--- a/PyPlugin.h	Mon Nov 17 09:37:59 2014 +0000
+++ b/PyPlugin.h	Mon Nov 17 10:03:44 2014 +0000
@@ -49,7 +49,7 @@
 #define _CLASS_METHOD_ m_class << "::" << method
 #define PLUGIN_ERROR "ERROR: In Vampy plugin [" << _CLASS_METHOD_ << "]" << endl << "Cause: "
 #define DEBUG_NAME "[Vampy::call] " << _CLASS_METHOD_ << " "
-#define DEAFULT_RETURN "Method [" << _CLASS_METHOD_ << "] is not implemented. Returning default value."
+#define DEFAULT_RETURN "Method [" << _CLASS_METHOD_ << "] is not implemented. Returning default value."
 #define FLAG_VALUE "Flag: " << flagName << ": " << ((rValue==0)?"False":"True")
 
 #include <Python.h>
@@ -171,7 +171,7 @@
 			}
 			return rValue;
 		}
-		if (m_debugFlag) cerr << DEAFULT_RETURN << endl;
+		if (m_debugFlag) cerr << DEFAULT_RETURN << endl;
 		return rValue;
 	}
 
@@ -182,7 +182,7 @@
 		RET rValue = RET();
 		if (m_debugFlag) cerr << DEBUG_NAME << endl;
 		if (!PyObject_HasAttrString(m_pyInstance,method)) {
-			if (m_debugFlag) cerr << DEAFULT_RETURN << endl;
+			if (m_debugFlag) cerr << DEFAULT_RETURN << endl;
 			return rValue;
 		}
 		
@@ -248,7 +248,7 @@
 		RET rValue = RET();
 		if (m_debugFlag) cerr << DEBUG_NAME << endl;
 		if (!PyObject_HasAttrString(m_pyInstance,method)) {
-			if (m_debugFlag) cerr << DEAFULT_RETURN << endl;
+			if (m_debugFlag) cerr << DEFAULT_RETURN << endl;
 			return rValue;
 		}
 		
@@ -320,7 +320,7 @@
 		RET rValue = RET();
 		if (m_debugFlag) cerr << DEBUG_NAME << endl;
 		if (!PyObject_HasAttrString(m_pyInstance,method)) {
-			if (m_debugFlag) cerr << DEAFULT_RETURN << endl;
+			if (m_debugFlag) cerr << DEFAULT_RETURN << endl;
 			return rValue;
 		}
 		
--- a/README	Mon Nov 17 09:37:59 2014 +0000
+++ b/README	Mon Nov 17 10:03:44 2014 +0000
@@ -105,6 +105,9 @@
 	simple debugging (for developers):
 		_DEBUG : print more detailed messages while Vampy is in use
 		_DEBUG_VALUES : print all converted values to stderr
+		
+	(But note that basic debug messages are compiled in already, and
+	will be displayed if the environment variable VAMPY_VERBOSE is set.)
 
 
 UPDATES IN THIS VERSION (Vampy 2.0):
@@ -497,8 +500,10 @@
 
 ENVIRONMENT VARIABLES:
 
-	Vampy recognises three optional environment variables:
-	
+	Vampy recognises these optional environment variables:
+
+	VAMPY_VERBOSE if set at all, print out debug info to stderr
+
 	VAMPY_COMPILED=1 recognise byte compiled python plugins (default)
 	VAMPY_COMPILED=0 ignore them 
 
--- a/vampy-main.cpp	Mon Nov 17 09:37:59 2014 +0000
+++ b/vampy-main.cpp	Mon Nov 17 10:03:44 2014 +0000
@@ -41,6 +41,7 @@
 #include "PyPlugin.h"
 #include "PyExtensionModule.h"
 #include "PyExtensionManager.h"
+#include "Debug.h"
 #include <sstream>
 
 #ifdef _WIN32
@@ -72,7 +73,7 @@
         m_pyClass(pyClass),
 		m_failed(false)
     { 
-        cerr << "PyPluginAdapter:ctor:"<< adinstcount << ": " << m_plug << endl; 
+        DSTREAM << "PyPluginAdapter:ctor:"<< adinstcount << ": " << m_plug << endl; 
         adinstcount++;
     }
     
@@ -90,9 +91,9 @@
             PyPlugin *plugin = new PyPlugin(m_plug, inputSampleRate, m_pyClass, totinstcount, numpyInstalled);
             return plugin;
         } catch (...) {
-            cerr << "PyPluginAdapter::createPlugin: Failed to construct PyPlugin" << endl;
-			// any plugin with syntax errors will fail to construct
-			m_failed = true;
+            cerr << "ERROR: PyPluginAdapter::createPlugin: Failed to construct PyPlugin" << endl;
+	    // any plugin with syntax errors will fail to construct
+	    m_failed = true;
             return 0;
         }
     }
@@ -121,14 +122,14 @@
 	float numpyVersion;
 
 	/// attmept to test numpy version before importing the array API
-	cerr << "Numpy build information: ABI level: " << NPY_VERSION 
-	<< " Numpy version: " << NUMPY_SHORTVERSION << endl;
+	DSTREAM << "Numpy build information: ABI level: " << NPY_VERSION 
+		<< " Numpy version: " << NUMPY_SHORTVERSION << endl;
 	
 	PyObject *pyModule, *pyDict, *pyVer;
 	
 	pyModule = PyImport_ImportModule("numpy"); //numpy.core.multiarray
 	if (!pyModule) {
-		cerr << "Vampy was compiled with Numpy support but Numpy does not seem to be installed." << endl;
+		cerr << "ERROR: Vampy was compiled with Numpy support but Numpy does not seem to be installed." << endl;
 #ifdef __APPLE__
 		cerr << "Hint: Check if Numpy is installed for the particular setup of Python used by Vampy (given by Python exec prefix)." << endl;
 #endif		
@@ -137,32 +138,26 @@
 
 	pyDict = PyModule_GetDict(pyModule); // borrowed ref
 	if (!pyDict) {
-		cerr << "Can not access Numpy module dictionary." << endl;
+		cerr << "ERROR: Can not access Numpy module dictionary." << endl;
 		goto numpyFailure;
 	}
 
 	pyVer = PyDict_GetItemString(pyDict,"__version__"); //borrowed ref
 	if (!pyVer) {
-		cerr << "Can not access Numpy version information." << endl;
+		cerr << "ERROR: Can not access Numpy version information." << endl;
 		goto numpyFailure;
 	}
 
 	ver = PyString_AsString(pyVer);
 	ver = ver.substr(0,ver.rfind("."));
-	/*
-	Applied patch from here: http://vamp-plugins.org/forum/index.php/topic,162.msg387.html#msg387 to replace this:
-    if(EOF == sscanf(ver.c_str(), "%f", &numpyVersion))
-    {
-     cerr << "Could not parse Numpy version information." << endl;
-     goto numpyFailure;
-    }*/
+
 	// parse version string to float
-    verStream.str(ver);
-    verStream >> numpyVersion;
+	verStream.str(ver);
+	verStream >> numpyVersion;
 
-	cerr << "Numpy runtime version: " << numpyVersion << endl;
+	DSTREAM << "Numpy runtime version: " << numpyVersion << endl;
 	if (numpyVersion < (float) NUMPY_SHORTVERSION) {
-		cerr << "Incompatible Numpy version found: " << numpyVersion << endl;
+		cerr << "ERROR: Incompatible Numpy version found: " << numpyVersion << endl;
 		goto numpyFailure;
 	}
 
@@ -173,21 +168,11 @@
 	// However, we should never get to this point now anyway.
 	import_array();
 	if (PyErr_Occurred()) { 
-		cerr << "Import error while loading the Numpy Array API." << endl;
+		cerr << "ERROR: Import error while loading the Numpy Array API." << endl;
 		PyErr_Print(); PyErr_Clear(); 
 		goto numpyFailure;
 	}
 	else {
-
-#ifdef _DEBUG		
-		if (NPY_VERSION != PyArray_GetNDArrayCVersion()) {  
-			// the Import function does this check already.
-			cerr << "Warning: Numpy version mismatch. (Build version: " 
-				<< NPY_VERSION << " Runtime version: " << PyArray_GetNDArrayCVersion() << ")" << endl;
-			goto numpyFailure; 
-		}
-#endif
-
 		numpyInstalled = true;
 		arrayApiInitialised = true;
 		return;
@@ -229,7 +214,7 @@
         return false;
     }
 #endif
-    cerr << "Preloaded Python from " << name << endl;
+    DSTREAM << "Preloaded Python from " << name << endl;
     return true;
 }
 
@@ -251,14 +236,14 @@
             }
         }
     }
-    cerr << "Short version: " << shortver << endl;
-	// this is useful to find out where the loaded library might be loaded from
-	cerr << "Python exec prefix: " << Py_GetExecPrefix() << endl;
+    DSTREAM << "Short version: " << shortver << endl;
+    // this is useful to find out where the loaded library might be loaded from
+    DSTREAM << "Python exec prefix: " << Py_GetExecPrefix() << endl;
 
     char *pylib = getenv("VAMPY_PYLIB");
     if (pylib && *pylib) {
-        cerr << "Trying to preload Python from specified location " << pylib
-	    << "..." << endl;
+        DSTREAM << "Trying to preload Python from specified location " << pylib
+		<< "..." << endl;
         return tryPreload(string(pylib));
     } 
 
@@ -305,8 +290,8 @@
     if (version < 1) return 0;
 
 	int isPythonInitialized = Py_IsInitialized();
-	cerr << "# isPythonInitialized: " << isPythonInitialized << endl;
-	cerr << "# haveScannedPlugins: " << haveScannedPlugins << endl;
+	DSTREAM << "# isPythonInitialized: " << isPythonInitialized << endl;
+	DSTREAM << "# haveScannedPlugins: " << haveScannedPlugins << endl;
 
 	if (!haveScannedPlugins) {
 
@@ -319,9 +304,7 @@
 			Py_Initialize();
 			array_API_initialiser();
 			initvampy();
-#ifdef _DEBUG			
-		    cerr << "# isPythonInitialized after initialize: " << Py_IsInitialized() << endl;
-#endif		
+			DSTREAM << "# isPythonInitialized after initialize: " << Py_IsInitialized() << endl;
 		}
 
 		vector<string> pyPlugs;
@@ -330,7 +313,7 @@
 		static PyPlugScanner *scanner;
 		
 		//Scanning Plugins
-		cerr << "Scanning Vampy Plugins" << endl;
+		DSTREAM << "Scanning Vampy Plugins" << endl;
 		scanner = PyPlugScanner::getInstance();
 
 		// added env. varable support VAMPY_EXTPATH
@@ -341,10 +324,10 @@
 		// VAMPY_COMPILED=1 to recognise .pyc files (default is 1)
 		pyPlugs = scanner->getPyPlugs();
 
-		cerr << "Found " << pyPlugs.size() << " Scripts." << endl;
+		DSTREAM << "Found " << pyPlugs.size() << " Scripts." << endl;
 		//TODO: should this support multiple classes per script (?)
 		pyClasses = scanner->getPyClasses();
-		cerr << "Found " << pyClasses.size() << " Classes." << endl;
+		DSTREAM << "Found " << pyClasses.size() << " Classes." << endl;
 
 		for (size_t i = 0; i < pyPlugs.size(); ++i) {
 			adapters.push_back( new PyPluginAdapter(pyPlugs[i],pyClasses[i]));
@@ -355,9 +338,7 @@
 		haveScannedPlugins=true;
 	}
 
-#ifdef _DEBUG
-	cerr << "Accessing adapter index: " << index << " (adapters: " << adapters.size() << ")" << endl;
-#endif	
+	DSTREAM << "Accessing adapter index: " << index << " (adapters: " << adapters.size() << ")" << endl;
 
 	if (index<adapters.size()) {