Experimental Physics and
Industrial Control System

Mark Rivers via Core-talk <core-talk at aps.anl.gov> · Sat, 21 Mar 2020 01:32:41 +0000

Hi Michael,

> While your second message cleared up some points, but I'm still confused.
> Maybe a stupid question, but when you write about "time between messages
> is about 0.115 seconds".  Is this the time between when queuing or dequeuing messages?

Time between queuing.  It is the acquire period of the detector, so the rate at which the callbacks from the vendor software are coming with new images that get queued.

> Secondly, using epicsMessageQueue in c++ code is, to me, questionable.

I think my subsequent tests, written in simple C, show that this is not the problem.

> It's also not clear to me why you need a timeout on the dequeue step
> at all.  Are you using this to detect a device error?

No, I am not using it to detect a device error.  I am using because, for example, in continuous acquisition mode the dequeue routine is being called in an infinite loop.  But when the user tells acquisition to stop that final frame will never arrive, so the dequeue function needs to time out and exit.

> Isn't this an issue with waits being too short, not too long?

Waits too short is what I am seeing, and that was the previous problem as well.  My problem with the Joerger scaler is that waits that should be 1/60 second were essentially 0, using 100% of CPU.  Andrews tests showed that epicsEventWaitWithTimeout was returning way too soon.  I see 2 timeouts within 1-2 ms when they should take 100 ms.

> It also won't explain misbehavior of message content.

I don't have a problem with message content.  I have a problem with missing messages, i.e. the ones with the correct UniqueId never get delivered.  My little C program from today shows exactly this problem.

Mark

________________________________
From: Michael Davidsaver <mdavidsaver at gmail.com>
Sent: Friday, March 20, 2020 1:16 PM
To: Mark Rivers; 'core-talk at aps.anl.gov'
Subject: Re: C++ question

Hi Mark,

While your second message cleared up some points, but I'm still confused.
Maybe a stupid question, but when you write about "time between messages
is about 0.115 seconds".  Is this the time between when queuing or
dequeuing messages?

Secondly, using epicsMessageQueue in c++ code is, to me, questionable.
With all the PV* modules I have to manage queues of smart-pointer type
objects all the time, and never with epicsMessageQueue.
If you're interested, the basic recipe for single consumer involves
std::deque, epicsMutex, and epicsEvent.

It's also not clear to me why you need a timeout on the dequeue step
at all.  Are you using this to detect a device error?

> It is making me wonder if this is related to the problem with epicsTimeMonotonic that I observed

Isn't this an issue with waits being too short, not too long?
It also won't explain misbehavior of message content.

On 3/20/20 9:59 AM, Mark Rivers via Core-talk wrote:
> I should have said that this is windows-x86_64-static with base 7.0.3.1.
>
>
>
>
>
> *From:* Mark Rivers
> *Sent:* Friday, March 20, 2020 11:56 AM
> *To:* 'core-talk at aps.anl.gov' <core-talk at aps.anl.gov>
> *Subject:* RE: C++ question
>
>
>
> Folks,
>
>
>
> I have added debugging print statements when sending a message on the epicsMessageQueue and when receiving the message on the epicsMessageQueue.  Each time a message is sent I print the UniqueID of the image that was sent.  When the message is received I also print the UniqueID of the message that was received.  The time between message is about 0.115 seconds, while the epicsMessageQueue receive timeout is 0.1 seconds.
>
>
>
> Here is what I observed:
>
>
>
> 2020/03/20 11:37:37.098 ImageEventHandler::OnImageEvent sending uniqueId=85
>
> 2020/03/20 11:37:37.098 ADSpinnaker::grabImage received uniqueID 85 from message queue
>
> 2020/03/20 11:37:37.213 ImageEventHandler::OnImageEvent sending uniqueId=86
>
> 2020/03/20 11:37:37.213 ADSpinnaker::grabImage timeout receiving from message queue
>
> 2020/03/20 11:37:37.214 ADSpinnaker::grabImage received uniqueID 86 from message queue
>
> 2020/03/20 11:37:37.328 ImageEventHandler::OnImageEvent sending uniqueId=87
>
> 2020/03/20 11:37:37.328 ADSpinnaker::grabImage received uniqueID 87 from message queue
>
> 2020/03/20 11:37:37.443 ImageEventHandler::OnImageEvent sending uniqueId=88
>
> 2020/03/20 11:37:37.443 ADSpinnaker::grabImage timeout receiving from message queue
>
> 2020/03/20 11:37:37.445 ADSpinnaker::grabImage timeout receiving from message queue
>
> 2020/03/20 11:37:37.546 ADSpinnaker::grabImage timeout receiving from message queue
>
> 2020/03/20 11:37:37.557 ImageEventHandler::OnImageEvent sending uniqueId=89
>
> 2020/03/20 11:37:37.558 ADSpinnaker::grabImage received uniqueID 89 from message queue
>
> 2020/03/20 11:37:37.672 ImageEventHandler::OnImageEvent sending uniqueId=90
>
> 2020/03/20 11:37:37.672 ADSpinnaker::grabImage received uniqueID 90 from message queue
>
> 2020/03/20 11:37:37.784 ADSpinnaker::grabImage timeout receiving from message queue
>
> 2020/03/20 11:37:37.787 ImageEventHandler::OnImageEvent sending uniqueId=91
>
> 2020/03/20 11:37:37.787 ADSpinnaker::grabImage received uniqueID 91 from message queue
>
>
>
> Messages with UniqueID 85, 86, and 87 were received fine.  When reading messages 85 and 87 there was no timeout, but when reading 86 there was a timeout.  However,  0.001 second after that timeout the receive succeeded.
>
>
>
> The problem is message 88.
>
>
>
> 2020/03/20 11:37:37.443 ImageEventHandler::OnImageEvent sending uniqueId=88
>
> 2020/03/20 11:37:37.443 ADSpinnaker::grabImage timeout receiving from message queue
>
> 2020/03/20 11:37:37.445 ADSpinnaker::grabImage timeout receiving from message queue
>
> 2020/03/20 11:37:37.546 ADSpinnaker::grabImage timeout receiving from message queue
>
> 2020/03/20 11:37:37.557 ImageEventHandler::OnImageEvent sending uniqueId=89
>
> 2020/03/20 11:37:37.558 ADSpinnaker::grabImage received uniqueID 89 from message queue
>
>
>
> Note that it was sent at 37.443.  There were then 3 timeouts trying to read that message, at 37.443, 37.445, and 37.546.  Message 88 was never received!
>
>
>
> Something seems seriously wrong here.  It is making me wonder if this is related to the problem with epicsTimeMonotonic that I observed with callbackRequestDelay and Andrew observed with epicsEventWaitWithTimeout?  What could cause that message #88 to never be received from the message queue?  Why are there 2 timeouts within 0.002 seconds, when the timeout is 0.1 second?
>
>
>
> Thanks,
>
> Mark
>
>
>
>
>
>
>
> *From:* Mark Rivers
> *Sent:* Friday, March 20, 2020 9:52 AM
> *To:* core-talk at aps.anl.gov <mailto:core-talk at aps.anl.gov>
> *Subject:* C++ question
>
>
>
> Folks,
>
>
>
> I am having a problem with the areaDetector ADSpinnaker driver.  I am quite sure the problem is that I am doing something wrong in my C++ callback code.
>
>
>
> The code in question is quite simple.
>
>
>
> The following is a class that implements callbacks from the vendor library when a new image is available.  It inherits from the vendor’s ImageEvent class, and implments a method they define called OnImageEvent.  That method is passed a smart pointer of type ImagePtr.  I made a copy of that smart pointer and pass its address on an epicsMessageQueue.  The copy is deleted in the receiving function.
>
>
>
> ***************************************
>
> class ImageEventHandler : public ImageEvent
>
> {
>
> public:
>
>
>
>     ImageEventHandler(epicsMessageQueue *pMsgQ)
>
>      : pMsgQ_(pMsgQ)
>
>     {}
>
>     ~ImageEventHandler() {}
>
>
>
>     void OnImageEvent(ImagePtr image) {
>
>         ImagePtr *imagePtrAddr = new ImagePtr(image);
>
>
>
>         if (pMsgQ_->send(&imagePtrAddr, sizeof(imagePtrAddr)) != 0) {
>
>             printf("OnImageEvent error calling pMsgQ_->send()\n");
>
>         }
>
>     }
>
>
>
> private:
>
>     epicsMessageQueue *pMsgQ_;
>
>
>
> };
>
> ***************************************
>
>
>
> This is the receiving function.
>
>
>
> ***************************************
>
> asynStatus ADSpinnaker::grabImage()
>
> {
>
>     asynStatus status = asynSuccess;
>
>     size_t nRows, nCols;
>
>     NDDataType_t dataType;
>
>     NDColorMode_t colorMode;
>
>     int timeStampMode;
>
>     int uniqueIdMode;
>
>     int convertPixelFormat;
>
>     bool imageConverted = false;
>
>     int numColors;
>
>     size_t dims[3];
>
>     ImageStatus imageStatus;
>
>     PixelFormatEnums pixelFormat;
>
>     int pixelSize;
>
>     size_t dataSize, dataSizePG;
>
>     void *pData;
>
>     int nDims;
>
>     ImagePtr pImage;
>
>     ImagePtr *imagePtrAddr=0;
>
>     static const char *functionName = "grabImage";
>
>
>
>     try {
>
>         while(1) {
>
>             unlock();
>
>             int recvSize = pCallbackMsgQ_->receive(&imagePtrAddr, sizeof(imagePtrAddr), 0.1);
>
>             lock();
>
>             if (recvSize == sizeof(imagePtrAddr)) {
>
>                 break;
>
>             } else if (recvSize == -1) {
>
>                 // Timeout
>
>                 int acquire;
>
>                 getIntegerParam(ADAcquire, &acquire);
>
>                 if (acquire == 0) {
>
>                     return asynError;
>
>                 } else {
>
>                     continue;
>
>                 }
>
>             } else {
>
>                 asynPrint(pasynUserSelf, ASYN_TRACE_ERROR,
>
>                         "%s::%s error receiving from message queue\n",
>
>                         driverName, functionName);
>
>                 return asynError;
>
>             }
>
>         }
>
>         pImage = *imagePtrAddr;
>
>         // Delete the ImagePtr that was passed to us
>
>         delete imagePtrAddr;
>
> …
>
> Finishing processing pImage …
>
> ***************************************
>
>
>
> Note that I have a timeout of 0.1 second on the msgQ->receive() call.  if the call times out it tries again if it is still acquiring.  This allows the function to return quickly if acquisition is stopped after it is called.
>
>
>
> This code generally works fine when the time between images is 0.1 second or less, or 0.12 seconds or more.  However, if the time between images is 0.115 seconds, for example, I “lose” about 2-3% of the images.  There are no error messages.  If I increase the 0.1 second timeout to 0.2 seconds, then images are lost if the time between images is about 0.215 seconds.
>
>
>
> It seems to me that the problem must be that another callback happens before the previous image has been processed.  I thought that making a copy of the smart pointer on the stack would prevent this, but I must be doing something wrong.  Perhaps I am deleting the smart pointer too soon, or perhaps the whole approach I am using is unsafe?
>
>
>
> Any advice is much appreciated!
>
>
>
> Thanks,
>
> Mark
>
>
>

Experimental Physics and Industrial Control System

Experimental Physics and
Industrial Control System