Re: Async queries pretending to be synchronous

On Mon, Mar 4, 2019 at 10:18 AM Khushboo Vashi <
khushboo(dot)vashi(at)enterprisedb(dot)com> wrote:

>
>
> On Mon, Mar 4, 2019 at 3:43 PM Dave Page <dpage(at)pgadmin(dot)org> wrote:
>
>> Hi
>>
>> On Mon, Mar 4, 2019 at 5:43 AM Khushboo Vashi <
>> khushboo(dot)vashi(at)enterprisedb(dot)com> wrote:
>>
>>>
>>>
>>> On Fri, Mar 1, 2019 at 10:01 PM Dave Page <dpage(at)pgadmin(dot)org> wrote:
>>>
>>>> In investigating #3656 I found the initial problem to be that when
>>>> running in a container, Gunicorn will kill the worker process if a thread
>>>> doesn't respond for 30 seconds by default. I fixed that by making the
>>>> timeout match the application session timeout, but it revealed another
>>>> issue.
>>>>
>>>> Given the function below (from the ticket), if you open the query tool
>>>> and run:
>>>>
>>>> SELECT 1; SELECT fails_after(30);
>>>>
>>>> the async query actually blocks for 30 seconds in the cur.execute()
>>>> call in execute_async() in connection.py (line 968). This causes the entire
>>>> app to hang (watch the dashboard requests pile up in pending state in the
>>>> network tab of the browser dev tools).
>>>>
>>>> If you run just the second SELECT, it works as expected, as does
>>>> running something like:
>>>>
>>>> SELECT 1; SELECT pg_sleep(30);
>>>>
>>>> Anyone have any idea what's going on?
>>>>
>>>
>>> Connection.poll() blocking the call here. ( connection.py - _wait_timeout
>>> function line #1378 state = conn.poll() )
>>> In the asynchronous connection, after executing the query, the
>>> conn.poll() is being called to fetch the connection status.
>>> It gives the status accordingly but in this case, it is blocking and not
>>> giving the status.
>>>
>>
>> If I put a breakpoint on the _wait_timeout call (line 969 in
>> execute_async), it hits it *after* the 30 seconds has passed (during which
>> time all other queries for cancel or dashboards and status etc don't get
>> processed).
>>
>> Put the breakpoint in the _wait_timeout function itself. The line no
> 1378 (state = conn.poll()) is blocking the execution 30 seconds.
>
>> If I walk down the call stack, it returns from the _cursor.execute call
>> in cursor.py and then hangs right before it goes into _wait_timeout.
>>
>
Hmm, yeah - my debugger is doing some weird off-by-one thing. If I put the
break point on the while 1, it blocks there! If I put it on the poll()
call, then it does do as you describe.

So, any idea why it's blocking, before I spend more time digging in?

Thanks!

--
Dave Page
Blog: http://pgsnake.blogspot.com
Twitter: @pgsnake

EnterpriseDB UK: http://www.enterprisedb.com
The Enterprise PostgreSQL Company