Re: Odd timeout behavior

[Jens Axboe <axboe@kernel.dk>]

On 4/12/20 3:15 AM, Pavel Begunkov wrote:
> On 4/12/2020 5:07 AM, Jens Axboe wrote:
>> On 4/11/20 5:00 PM, Hrvoje Zeba wrote:
>>> Hi,
>>>
>>> I've been looking at timeouts and found a case I can't wrap my head around.
>>>
>>> Basically, If you submit OPs in a certain order, timeout fires before
>>> time elapses where I wouldn't expect it to. The order is as follows:
>>>
>>> poll(listen_socket, POLLIN) <- this never fires
>>> nop(async)
>>> timeout(1s, count=X)
>>>
>>> If you set X to anything but 0xffffffff/(unsigned)-1, the timeout does
>>> not fire (at least not immediately). This is expected apart from maybe
>>> setting X=1 which would potentially allow the timeout to fire if nop
>>> executes after the timeout is setup.
>>>
>>> If you set it to 0xffffffff, it will always fire (at least on my
>>> machine). Test program I'm using is attached.
>>>
>>> The funny thing is that, if you remove the poll, timeout will not fire.
>>>
>>> I'm using Linus' tree (v5.6-12604-gab6f762f0f53).
>>>
>>> Could anybody shine a bit of light here?
>>
>> Thinking about this, I think the mistake here is using the SQ side for
>> the timeouts. Let's say you queue up N requests that are waiting, like
>> the poll. Then you arm a timeout, it'll now be at N + count before it
>> fires. We really should be using the CQ side for the timeouts.
> 
> As I get it, the problem is that timeout(off=0xffffffff, 1s) fires
> __immediately__ (i.e. not waiting 1s). Currently, it should work more
> like "fire after N events *submitted after the timeout* completed", so
> SQ vs CQ is another topic, but IMHO is not related.
> 
> And still, the described behaviour is out of the definition. It's sounds
> like int overflow. Ok, I'll debug it, rest assured. I already see a
> couple of flaws anyway.

Yeah agree it's two separate issues, the -1U must be a simple overflow.
So probably not that tricky to fix. 

Reason I bring up the other part is that Hrvoje's test case had other
cases as well, and the SQ vs CQ trigger is worth looking into. For
example, if we do:

enqueue N polls
enqueue timeout, count == 2, t = 10s
enqueue 2 nops

I'd logically expect the timeout to trigger when nop #2 is completed.
But it won't be, because we still have N polls waiting. What the count
== 2 is really saying (right now) is "trigger timeout when CQ passes SQ
by 2", which seems a bit odd.

-- 
Jens Axboe