Re: Trying to track down weird query stalls

> On Mon, Mar 30, 2009 at 2:42 PM, <dan(at)sidhe(dot)org> wrote:
>>> On Mon, Mar 30, 2009 at 1:50 PM,  <dan(at)sidhe(dot)org> wrote:
>> I'm not executing any of the EXPLAINs by hand, because I didn't want to
>> have to worry about typos or filling in temp tables with test data.
>> Inside
>> the app the SQL for the problematic query's stored in a variable -- when
>> the task runs with debugging enabled it first executes the query with
>> EXPLAIN ANALYZE prepended and dumps the output, then it executes the
>> query
>> itself. It's possible something's going wrong in that, but the code's
>> pretty simple.
>>
>> Arguably in this case the actual query should run faster than the
>> EXPLAIN
>> ANALYZE version, since the cache is hot. (Though that'd only likely
>> shave
>> a few dozen ms off the runtime)
>
> Well... yeah. Also EXPLAIN ANALYZE has a non-trivial amount of
> overhead, so that is quite bizarre. I have to suspect there is some
> subtle difference between the way the EXPLAIN ANALYZE is done and the
> way the actual query is done... like maybe one uses parameter
> substitution and the other doesn't or, well, I don't know. But I
> don't see how turning on debugging (which is essentially what EXPLAIN
> ANALYZE is) can prevent the query from being slow.

Hence the query to the list. *Something* is going on, and beats me what.
I'm assuming I'm triggering some bug in the postgres back end, or there's
some completely bizarre edge case that this tickles. (The massive
kread/kwrite activity that truss showed me when I checked seemed rather
unusual, to say the least)

EXPLAIN ANALYZE is my normal means of diagnosing performance problems, but
that isn't helping as it shows perfectly sane results. That leaves
abnormal means, and outside of trussing the back end or attaching with dbx
to get a stack trace I just don't have any of those. I'm not even sure
what I should be looking for when I do get a stack trace.

-Dan