* added debug interface from Extended C++ Device Servers project

* added debug messages to Espia Dev, Acq and SerialLine classes



git-svn-id: https://scm.blissgarden.org/svn/lima/trunk@177 45c4679d-1946-429d-baad-37912b19538b

camera/common/espia/include/Espia.h

@@ -3,6 +3,7 @@
 
 #include "espia_lib.h"
 #include "Exceptions.h"
+#include "Debug.h"
 
 #include <string>
 

camera/common/espia/include/EspiaAcq.h

@@ -15,6 +15,8 @@ class Acq;
 
 class AcqEndCallback
 {
+	DEB_CLASS_NAMESPC(DebModEspia, "AcqEndCallback", "Espia");
+
  public:
 	AcqEndCallback();
 	virtual ~AcqEndCallback();
@@ -35,6 +37,8 @@ class AcqEndCallback
 
 class Acq : public HwFrameCallbackGen
 {
+	DEB_CLASS_NAMESPC(DebModEspia, "Acq", "Espia");
+
  public:
 	Acq(Dev& dev);
 	~Acq();
@@ -145,9 +149,11 @@ inline AutoMutex Acq::acqLock()
 	return m_dev.acqLock();
 }
 
-
 } // namespace Espia
 
+std::ostream& operator <<(std::ostream& os, 
+			  const Espia::Acq::StatusType& status);
+
 } // namespace lima
 
 

camera/common/espia/include/EspiaDev.h

@@ -22,12 +22,15 @@ extern std::map<std::string, int> EspiaDrvOptMap;
 
 class Dev
 {
+	DEB_CLASS_NAMESPC(DebModEspia, "Dev", "Espia");
+
  public:
 	Dev(int dev_nb);
 	~Dev();
 
 	operator espia_t();
 
+	int getDevNb();
 	bool isMeta();
 
 	void registerCallback(struct espia_cb_data& cb_data, int& cb_nr);
@@ -38,8 +41,8 @@ class Dev
 
 	AutoMutex acqLock();
 
-	void getDrvOption( const std::string &opt_name, int &val );
-	void setDrvOption( const std::string &opt_name, int val );
+	void getDrvOption(const std::string& opt_name, int& val);
+	void setDrvOption(const std::string& opt_name, int  val);
 
  private:
 	static const double ResetLinkTime;
@@ -65,6 +68,11 @@ inline bool Dev::isMeta()
 	return (m_dev_nb == MetaDev);
 }
 
+inline int Dev::getDevNb()
+{
+	return m_dev_nb;
+}
+
 inline AutoMutex Dev::acqLock()
 {
 	return AutoMutex(m_acq_mutex, AutoMutex::Locked);

camera/common/espia/include/EspiaSerialLine.h

@@ -27,26 +27,28 @@ namespace Espia
  *******************************************************************/
 class SerialLine : public HwSerialLine
 {
+	DEB_CLASS_NAMESPC(DebModEspiaSerial, "SerialLine", "Espia");
+
   public :
-	SerialLine( Dev& edev, const std::string& line_term="\r", 
-		    double timeout=1.0, int block_size=0, 
-		    double block_delay=0 );
+	SerialLine(Dev& edev, const std::string& line_term="\r", 
+		   double timeout=1.0, int block_size=0, 
+		   double block_delay=0);
 	~SerialLine();
 
 	Dev& getDev();
 
-	virtual void write( const std::string& buffer, bool no_wait=false );
+	virtual void write(const std::string& buffer, bool no_wait=false);
 
-	virtual void read( std::string& buffer, int max_len, 
-	                   double timeout=TimeoutDefault );
+	virtual void read(std::string& buffer, int max_len, 
+	                   double timeout=TimeoutDefault);
 
-	virtual void readStr( std::string& buffer, int max_len, 
-	                      const std::string& term, 
-	                      double timeout=TimeoutDefault );
+	virtual void readStr(std::string& buffer, int max_len, 
+			     const std::string& term, 
+			     double timeout=TimeoutDefault);
 
 	virtual void flush();
 
-	virtual void getNbAvailBytes( int &avail_bytes );
+	virtual void getNbAvailBytes(int& avail_bytes);
 
   private :
 	Dev& m_dev;  /// Reference to Espia::Dev object

camera/common/espia/sip/EspiaDev.sip

@@ -12,6 +12,7 @@ using namespace lima;
 	Dev(int dev_nb);
 	~Dev();
 
+	int getDevNb();
 	bool isMeta();
 
 	void resetLink();

camera/common/espia/src/EspiaAcq.cpp

 #include "EspiaAcq.h"
 #include "MemUtils.h"
 
+#include <sstream>
+
 using namespace lima;
 using namespace lima::Espia;
+using namespace std;
 
 #define CHECK_CALL(ret)		ESPIA_CHECK_CALL(ret)
 
@@ -11,12 +14,17 @@ using namespace lima::Espia;
 AcqEndCallback::AcqEndCallback()
 	: m_acq(NULL)
 {
+	DEB_CONSTRUCTOR();
 }
 
 AcqEndCallback::~AcqEndCallback()
 {
-	if (m_acq)
+	DEB_DESTRUCTOR();
+
+	if (m_acq) {
+		DEB_TRACE() << "Unregistering from Acq";
 		m_acq->unregisterAcqEndCallback(*this);
+	}
 }
 
 Acq *AcqEndCallback::getAcq() const
@@ -26,10 +34,16 @@ Acq *AcqEndCallback::getAcq() const
 
 void AcqEndCallback::setAcq(Acq *acq)
 {
-	if (acq && m_acq)
+	DEB_MEMBER_FUNCT();
+	DEB_PARAM_VAR1(acq);
+
+	if (acq && m_acq) {
+		DEB_ERROR() << "Acquisition already set";
 		throw LIMA_HW_EXC(InvalidValue, "Acq already set");
-	else if (!acq && !m_acq)
+	} else if (!acq && !m_acq) {
+		DEB_ERROR() << "Acquisition already reset";
 		throw LIMA_HW_EXC(InvalidValue, "Acq already reset");
+	}
 
 	m_acq = acq;
 }
@@ -38,6 +52,16 @@ void AcqEndCallback::setAcq(Acq *acq)
 Acq::Acq(Dev& dev)
 	: m_dev(dev)
 {
+	DEB_CONSTRUCTOR();
+	DEB_PARAM_VAR1(dev.getDevNb());
+
+	ostringstream os;
+	if (dev.isMeta())
+		os << "MetaAcq";
+	else
+		os << "Acq#" << dev.getDevNb();
+	DEB_SET_OBJ_NAME(os.str());
+
 	m_nb_buffers = m_nb_buffer_frames = 0;
 	m_real_frame_factor = m_real_frame_size = 0;
 	
@@ -55,6 +79,8 @@ Acq::Acq(Dev& dev)
 
 Acq::~Acq()
 {
+	DEB_DESTRUCTOR();
+
 	if (m_acq_end_cb)
 		unregisterAcqEndCallback(*m_acq_end_cb);
 
@@ -64,19 +90,27 @@ Acq::~Acq()
 
 int Acq::dispatchFrameCallback(struct espia_cb_data *cb_data)
 {
+	DEB_STATIC_FUNCT();
+	DEB_PARAM_VAR1(cb_data->cb_nr);
+
 	Acq *espia = (Acq *) cb_data->data;
+	DEB_TRACE_VAR1(espia->getDebObjName());
 
 	void (Acq::*method)(struct espia_cb_data *cb_data) = NULL;
 
 	int& cb_nb = cb_data->cb_nr;
-	if (cb_nb == espia->m_frame_cb_nb)
+	if (cb_nb == espia->m_frame_cb_nb) {
+		DEB_TRACE() << "Processing FrameCallback";
 		method = &Acq::processFrameCallback;
-	
+	}
+
 	if (method) {
 		try {
 			(espia->*method)(cb_data);
+		} catch (Exception& e) {
+			DEB_ERROR() << e.getErrMsg();
 		} catch (...) {
-			
+			DEB_ERROR() << "Unknown Error in frame callback";
 		}
 	}
 	
@@ -85,9 +119,13 @@ int Acq::dispatchFrameCallback(struct espia_cb_data *cb_data)
 
 void Acq::enableFrameCallback()
 {
+	DEB_MEMBER_FUNCT();
+
 	int& cb_nb = m_frame_cb_nb;
-	if (cb_nb != Invalid)
+	if (cb_nb != Invalid) {
+		DEB_TRACE() << "Callback already enabled";
 		return;
+	}
 
 	struct espia_cb_data cb_data;
 	cb_data.type    = ESPIA_CB_ACQ;
@@ -101,25 +139,35 @@ void Acq::enableFrameCallback()
 	req_finfo.round_count  = ESPIA_ACQ_ANY;
 	req_finfo.acq_frame_nr = ESPIA_ACQ_EACH;
 
+	DEB_TRACE() << "Registering frame callback";
 	m_dev.registerCallback(cb_data, cb_nb);
 }
 
 void Acq::disableFrameCallback()
 {
+	DEB_MEMBER_FUNCT();
+
 	int& cb_nb = m_frame_cb_nb;
-	if (cb_nb == Invalid)
+	if (cb_nb == Invalid) {
+		DEB_TRACE() << "Callback already disabled";
 		return;
+	}
 
+	DEB_TRACE() << "Unregistering frame callback";
 	m_dev.unregisterCallback(cb_nb);
 }
 
 void Acq::setFrameCallbackActive(bool cb_active)
 {
+	DEB_MEMBER_FUNCT();
+	DEB_PARAM_VAR1(cb_active);
 	m_user_frame_cb_act = cb_active;
 }
 
 void Acq::processFrameCallback(struct espia_cb_data *cb_data)
 {
+	DEB_MEMBER_FUNCT();
+
 	AutoMutex l = acqLock();
 
 	struct img_frame_info& cb_finfo = cb_data->info.acq.cb_finfo;
@@ -132,6 +180,8 @@ void Acq::processFrameCallback(struct espia_cb_data *cb_data)
 		finished = (!endless && (cb_finfo.acq_frame_nr == last_frame));
 	}
 
+	DEB_TRACE_VAR2(aborted, finished);
+
 	if (finished)
 		m_started = false;
 
@@ -141,24 +191,37 @@ void Acq::processFrameCallback(struct espia_cb_data *cb_data)
 	if (!aborted)
 		real2virtFrameInfo(cb_finfo, hw_finfo);
 
-	if (m_user_frame_cb_act)
+	DEB_TRACE_VAR1(hw_finfo);
+
+	if (m_user_frame_cb_act) {
+		DEB_TRACE() << "Calling user FrameCallback";
 		newFrameReady(hw_finfo);
+	}
 
-	if ((m_acq_end_cb != NULL) && finished)
+	if ((m_acq_end_cb != NULL) && finished) {
+		DEB_TRACE() << "Calling AcqEndCallback";
 		m_acq_end_cb->acqFinished(hw_finfo);
+	}
 }
 
 void Acq::bufferAlloc(int& nb_buffers, int nb_buffer_frames,
 		      const FrameDim& frame_dim)
 {
+	DEB_MEMBER_FUNCT();
+	DEB_PARAM_VAR3(nb_buffers, nb_buffer_frames, frame_dim);
+
 	if (!frame_dim.isValid() || (nb_buffers <= 0) || 
-	    (nb_buffer_frames <= 0))
+	    (nb_buffer_frames <= 0)) {
+		DEB_ERROR() << "Invalid parameters";
 		throw LIMA_HW_EXC(InvalidValue, "Invalid frame_dim, "
 				  "nb_buffers and/or nb_buffer_frames");
+	}
 
 	if ((frame_dim == m_frame_dim) && (nb_buffers == m_nb_buffers) &&
-	    (nb_buffer_frames == m_nb_buffer_frames))
+	    (nb_buffer_frames == m_nb_buffer_frames)) {
+		DEB_TRACE() << "Requested buffers already allocated";
 		return;
+	}
 
 	bufferFree();
 
@@ -183,8 +246,12 @@ void Acq::bufferAlloc(int& nb_buffers, int nb_buffer_frames,
 		real_buffers += frame_factor - 1;
 		real_buffers /= frame_factor;
 		virt_buffers  = real_buffers * frame_factor;
+
+		DEB_TRACE_VAR3(frame_factor, virt_buffers, virt_frames);
 	}
 
+	DEB_TRACE() << "Calling espia_buffer_alloc";
+	DEB_TRACE_VAR3(real_buffers, real_frames, real_frame_size); 
 	CHECK_CALL(espia_buffer_alloc(m_dev, real_buffers, real_frames,
 				      real_frame_size));
 
@@ -193,15 +260,22 @@ void Acq::bufferAlloc(int& nb_buffers, int nb_buffer_frames,
 	m_nb_buffer_frames  = virt_frames;
 	m_real_frame_factor = frame_factor;
 	m_real_frame_size   = real_frame_size;
+
+	DEB_RETURN_VAR1(nb_buffers);
 }
 
 void Acq::bufferFree()
 {
-	if ((m_nb_buffers == 0) || (m_nb_buffer_frames == 0))
+	DEB_MEMBER_FUNCT();
+
+	if ((m_nb_buffers == 0) || (m_nb_buffer_frames == 0)) {
+		DEB_TRACE() << "Buffers already freed";
 		return;
+	}
 
 	stop();
 
+	DEB_TRACE() << "Calling espia_buffer_free";
 	CHECK_CALL(espia_buffer_free(m_dev));
 
 	m_frame_dim = FrameDim();
@@ -211,57 +285,81 @@ void Acq::bufferFree()
 
 const FrameDim& Acq::getFrameDim()
 {
+	DEB_MEMBER_FUNCT();
+	DEB_RETURN_VAR1(m_frame_dim);
 	return m_frame_dim;
 }
 
 void Acq::getNbBuffers(int& nb_buffers)
 {
+	DEB_MEMBER_FUNCT();
+	DEB_RETURN_VAR1(nb_buffers);
 	nb_buffers = m_nb_buffers;
 }
 
 void Acq::getNbBufferFrames(int& nb_buffer_frames)
 {
+	DEB_MEMBER_FUNCT();
+	DEB_RETURN_VAR1(nb_buffer_frames);
 	nb_buffer_frames = m_nb_buffer_frames;
 }
 
 void *Acq::getBufferFramePtr(int buffer_nb, int frame_nb)
 {
+	DEB_MEMBER_FUNCT();
+	DEB_PARAM_VAR2(buffer_nb, frame_nb);
+
 	int real_buffer = realBufferNb(buffer_nb, frame_nb);
 	int real_frame  = realFrameNb(buffer_nb, frame_nb);
 	void *ptr;
+	DEB_TRACE() << "Calling espia_frame_address";
 	CHECK_CALL(espia_frame_address(m_dev, real_buffer, real_frame, &ptr));
+	DEB_RETURN_VAR1(ptr);
 	return ptr;
 }
 
 void *Acq::getAcqFramePtr(int acq_frame_nb)
 {
+	DEB_MEMBER_FUNCT();
+	DEB_PARAM_VAR1(acq_frame_nb);
+
 	unsigned long buffer_nb = ESPIA_ACQ_ANY;
 	void *ptr;
+	DEB_TRACE() << "Calling espia_frame_address";
 	CHECK_CALL(espia_frame_address(m_dev, buffer_nb, acq_frame_nb, &ptr));
+	DEB_RETURN_VAR1(ptr);
 	return ptr;
 }
 
 void Acq::getFrameInfo(int acq_frame_nb, HwFrameInfoType& info)
 {
+	DEB_MEMBER_FUNCT();
+	DEB_PARAM_VAR1(acq_frame_nb);
+
 	struct img_frame_info finfo;
 	finfo.buffer_nr    = ESPIA_ACQ_ANY;
 	finfo.frame_nr     = ESPIA_ACQ_ANY;
 	finfo.round_count  = ESPIA_ACQ_ANY;
 	finfo.acq_frame_nr = acq_frame_nb;
 
+	DEB_TRACE() << "Calling espia_get_frame";
 	int ret = espia_get_frame(m_dev, &finfo, SCDXIPCI_NO_BLOCK);
 	if (ret == SCDXIPCI_ERR_NOTREADY) {
+		DEB_TRACE() << "Frame not ready yet";
 		info = HwFrameInfo();
 		return;
 	}
 	CHECK_CALL(ret);
 
 	real2virtFrameInfo(finfo, info);
+	DEB_RETURN_VAR1(info);
 }
 
 void Acq::real2virtFrameInfo(const struct img_frame_info& real_info, 
 			     HwFrameInfoType& virt_info)
 {
+	DEB_MEMBER_FUNCT();
+
 	char *buffer_ptr = (char *) real_info.buffer_ptr;
 	int frame_offset = real_info.frame_nr * m_real_frame_size;
 
@@ -274,6 +372,8 @@ void Acq::real2virtFrameInfo(const struct img_frame_info& real_info,
 
 void Acq::resetFrameInfo(struct img_frame_info& frame_info)
 {
+	DEB_MEMBER_FUNCT();
+
 	frame_info.buffer_ptr   = NULL;
 	frame_info.buffer_nr    = SCDXIPCI_INVALID;
 	frame_info.frame_nr     = SCDXIPCI_INVALID;
@@ -285,26 +385,38 @@ void Acq::resetFrameInfo(struct img_frame_info& frame_info)
 
 void Acq::setNbFrames(int nb_frames)
 {
-	if (nb_frames < 0)
+	DEB_MEMBER_FUNCT();
+	DEB_PARAM_VAR1(nb_frames);
+
+	if (nb_frames < 0) {
+		DEB_ERROR() << "Invalid nb_frames=" << nb_frames;
 		throw LIMA_HW_EXC(InvalidValue, "Invalid nb of frames");
+	}
 
 	m_nb_frames = nb_frames;
 }
 
 void Acq::getNbFrames(int& nb_frames)
 {
+	DEB_MEMBER_FUNCT();
 	nb_frames = m_nb_frames;
+	DEB_RETURN_VAR1(nb_frames);
 }
 
 void Acq::start()
 {
+	DEB_MEMBER_FUNCT();
+
 	AutoMutex l = acqLock();
 
-	if (m_started)
+	if (m_started) {
+		DEB_ERROR() << "Acquisition already running";
 		throw LIMA_HW_EXC(Error, "Acquisition already running");
+	}
 
 	resetFrameInfo(m_last_frame_info);
 
+	DEB_TRACE() << "Calling espia_start_acq, m_nb_frames=" << m_nb_frames;
 	CHECK_CALL(espia_start_acq(m_dev, 0, m_nb_frames, SCDXIPCI_NO_BLOCK));
 
 	m_start_ts = Timestamp::now();
@@ -313,11 +425,14 @@ void Acq::start()
 
 void Acq::stop()
 {
+	DEB_MEMBER_FUNCT();
+
 	AutoMutex l = acqLock();
 	if (!m_started)
 		return;
 
 	l.unlock();
+	DEB_TRACE() << "Calling espia_stop_acq";
 	CHECK_CALL(espia_stop_acq(m_dev));
 	l.lock();
 
@@ -326,8 +441,11 @@ void Acq::stop()
 
 void Acq::getStatus(StatusType& status)
 {
+	DEB_MEMBER_FUNCT();
+
 	AutoMutex l = acqLock();
 
+	DEB_TRACE() << "Calling espia_acq_active";
 	unsigned long acq_run_nb;
 	int acq_running = espia_acq_active(m_dev, &acq_run_nb);
 	CHECK_CALL(acq_running);
@@ -335,10 +453,14 @@ void Acq::getStatus(StatusType& status)
 	status.running = m_started;
 	status.run_nb  = acq_run_nb;
 	status.last_frame_nb = m_last_frame_info.acq_frame_nr;
+
+	DEB_RETURN_VAR1(status);
 }
 
 void Acq::registerAcqEndCallback(AcqEndCallback& acq_end_cb)
 {
+	DEB_MEMBER_FUNCT();
+
 	if (m_acq_end_cb)
 		throw LIMA_HW_EXC(InvalidValue, 
 				  "AcqEndCallback already registered");
@@ -349,6 +471,8 @@ void Acq::registerAcqEndCallback(AcqEndCallback& acq_end_cb)
 
 void Acq::unregisterAcqEndCallback(AcqEndCallback& acq_end_cb)
 {
+	DEB_MEMBER_FUNCT();
+
 	if (m_acq_end_cb != &acq_end_cb)
 		throw LIMA_HW_EXC(InvalidValue, 
 				  "Specified AcqEndCallback not registered");
@@ -358,3 +482,16 @@ void Acq::unregisterAcqEndCallback(AcqEndCallback& acq_end_cb)
 	m_acq_end_cb = NULL;
 	acq_end_cb.setAcq(NULL);
 }
+
+
+ostream& lima::operator <<(ostream& os, const Acq::StatusType& status)
+{
+	os << "<"
+	   << "running=" << status.running << ", "
+	   << "run_nb=" << status.run_nb << ", "
+	   << "last_frame_nb=" << status.last_frame_nb
+	   << ">";
+
+	return os;
+
+}

camera/common/espia/src/EspiaDev.cpp

@@ -16,6 +16,16 @@ map<string, int> lima::Espia::EspiaDrvOptMap;
 
 Dev::Dev(int dev_nb)
 {
+	DEB_CONSTRUCTOR();
+	DEB_PARAM_VAR1(dev_nb);
+
+	ostringstream os;
+	if (dev_nb == MetaDev)
+		os << "MetaDev";
+	else
+		os << "Dev#" << dev_nb;
+	DEB_SET_OBJ_NAME(os.str());
+
 	m_dev_nb = Invalid;
 	m_dev = ESPIA_DEV_INVAL;
 
@@ -26,25 +36,35 @@ Dev::Dev(int dev_nb)
 
 Dev::~Dev()
 {
+	DEB_DESTRUCTOR();
 	close();
 }
 
 void Dev::open(int dev_nb)
 {
-	if (dev_nb == m_dev_nb)
+	DEB_MEMBER_FUNCT();
+	DEB_PARAM_VAR1(dev_nb);
+
+	if (dev_nb == m_dev_nb) {
+		DEB_TRACE() << "Device already opened";
 		return;
+	}
 
 	close();
 
+	DEB_TRACE() << "Calling espia_open";
 	CHECK_CALL(espia_open(dev_nb, &m_dev));
 	m_dev_nb = dev_nb;
 }
 
 void Dev::close()
 {
+	DEB_MEMBER_FUNCT();
+
 	if (m_dev_nb == Invalid)
 		return;
 
+	DEB_TRACE() << "Calling espia_close";
 	CHECK_CALL(espia_close(m_dev));
 
 	m_dev = ESPIA_DEV_INVAL;
@@ -53,20 +73,30 @@ void Dev::close()
 
 void Dev::registerCallback(struct espia_cb_data& cb_data, int& cb_nr)
 {
+	DEB_MEMBER_FUNCT();