Re: Bug in epicsMessageQueue?

[Michael Davidsaver via Core-talk <core-talk at aps.anl.gov>]

On 3/20/20 7:01 PM, Michael Davidsaver wrote:
> On 3/20/20 5:00 PM, Mark Rivers wrote:
>> Here is the code:
>>
>>  
>>
>> if (threadNode.eventSent && (threadNode.size <= size) &&
>>
>>         status == epicsEventOK)
>>
>>         return threadNode.size;
>>
>>     return -1;
>>
>>  
>>
>> So it can return -1 if the allocated size for the message is wrong, but I believe that is impossible in this case.
>>
>>  
>>
>> It can fail if status is not epicsEventOK, which means epicsEventWaitWithTimeout returned something other than epicsEventOK, i.e. timeout.
>>
>>  
>>
>> I am not sure when threadNode.evenSent would be null.
> 
> It looks like door number three.  I'm not sure how the eventSent flag is meant to be used,
> but your events are being lost when the epicsEvent is signaled and it is not set.
> 
>> $ gdb --args ./testMessageQueue 200 0.1
>> (gdb) b osdMessageQueue.cpp:358 if status==0
>> (gdb) r
> ... wait until breakpoint hit
>> (gdb) p status
>> $1 = epicsEventOK
>> (gdb) p threadNode.size <= size
>> $2 = true
>> (gdb) p threadNode.eventSent
>> $3 = false

I think I see the logic error in how the eventSent flag is handled,
specifically related to the fact that epicsEvent is a semaphore as
opposed to a condition variable.

This allows a "race" to occur if the first/only waiting receiver
times out, and epicsEventWaitWithTimeout() returns, while a sender
is in epicsMessageQueueSend() preparing to wake up a receiver.

This results in a situation where the sender has set the eventSent,
and indeed copied a message to the buffer of, a thread which has
decided to abort.

After timing out, the receiver sees the timeout and returns -1
even through eventSent has been set.  This can be trapped with:

> b osdMessageQueue.cpp:358 if status!=0 && threadNode.eventSent

So here is your lost message.

Now when epicsMessageQueueReceiveWithTimeout() is called again, no message
is waiting in the queue, so epicsEventWaitWithTimeout() is called.
Since the semaphore is already set, this returns immediately with status==0,
but this is a spurious wakeup and the eventSent flag is not set.

And here is the second "timeout".


There hasn't been any significant change to this logic since it was added
in 2003, so I think this issue has been present since day 0.