Horton

Thread

  1. Worse performance with higher work_mem?

    Israel Brewster <ijbrewster@alaska.edu> — 2020-01-13T23:58:58Z

    I was working on diagnosing a “slow” (about 6 second run time) query:

SELECT
            to_char(bucket,'YYYY-MM-DD"T"HH24:MI:SS') as dates,
            x_tilt,
            y_tilt,
            rot_x,
            rot_y,
            date_part('epoch', bucket) as timestamps,
            temp
        FROM
            (SELECT
              time_bucket('1 week', read_time) as bucket,
              avg(tilt_x::float) as x_tilt,
              avg(tilt_y::float) as y_tilt,
              avg(rot_x::float) as rot_x,
              avg(rot_y::float) as rot_y,
              avg(temperature::float) as temp
            FROM tilt_data
            WHERE station='c08883c0-fbe5-11e9-bd6e-aec49259cebb'
            AND read_time::date<='2020-01-13'::date    
            GROUP BY bucket) s1
        ORDER BY bucket;

In looking at the explain analyze output, I noticed that it had an “external merge Disk” sort going on, accounting for about 1 second of the runtime (explain analyze output here: https://explain.depesz.com/s/jx0q <https://explain.depesz.com/s/jx0q>). Since the machine has plenty of RAM available, I went ahead and increased the work_mem parameter. Whereupon the query plan got much simpler, and performance of said query completely tanked, increasing to about 15.5 seconds runtime (https://explain.depesz.com/s/Kl0S <https://explain.depesz.com/s/Kl0S>), most of which was in a HashAggregate.

I am running PostgreSQL 11.6 on a machine with 128GB of ram (so, like I said, plenty of RAM)

How can I fix this? Thanks.
---
Israel Brewster
Software Engineer
Alaska Volcano Observatory 
Geophysical Institute - UAF 
2156 Koyukuk Drive 
Fairbanks AK 99775-7320
Work: 907-474-5172
cell:  907-328-9145

  2. Re: Worse performance with higher work_mem?

    Tom Lane <tgl@sss.pgh.pa.us> — 2020-01-14T00:19:37Z

    Israel Brewster <ijbrewster@alaska.edu> writes:
> In looking at the explain analyze output, I noticed that it had an “external merge Disk” sort going on, accounting for about 1 second of the runtime (explain analyze output here: https://explain.depesz.com/s/jx0q <https://explain.depesz.com/s/jx0q>). Since the machine has plenty of RAM available, I went ahead and increased the work_mem parameter. Whereupon the query plan got much simpler, and performance of said query completely tanked, increasing to about 15.5 seconds runtime (https://explain.depesz.com/s/Kl0S <https://explain.depesz.com/s/Kl0S>), most of which was in a HashAggregate.
> How can I fix this? Thanks.

Well, the brute-force way not to get that plan is "set enable_hashagg =
false".  But it'd likely be a better idea to try to improve the planner's
rowcount estimates.  The problem here seems to be lack of stats for
either "time_bucket('1 week', read_time)" or "read_time::date".
In the case of the latter, do you really need a coercion to date?
If it's a timestamp column, I'd think not.  As for the former,
if the table doesn't get a lot of updates then creating an expression
index on that expression might be useful.

			regards, tom lane

  3. Re: Worse performance with higher work_mem?

    Israel Brewster <ijbrewster@alaska.edu> — 2020-01-14T00:41:41Z

    > On Jan 13, 2020, at 3:19 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> 
> Israel Brewster <ijbrewster@alaska.edu> writes:
>> In looking at the explain analyze output, I noticed that it had an “external merge Disk” sort going on, accounting for about 1 second of the runtime (explain analyze output here: https://explain.depesz.com/s/jx0q <https://explain.depesz.com/s/jx0q>). Since the machine has plenty of RAM available, I went ahead and increased the work_mem parameter. Whereupon the query plan got much simpler, and performance of said query completely tanked, increasing to about 15.5 seconds runtime (https://explain.depesz.com/s/Kl0S <https://explain.depesz.com/s/Kl0S>), most of which was in a HashAggregate.
>> How can I fix this? Thanks.
> 
> Well, the brute-force way not to get that plan is "set enable_hashagg =
> false".  But it'd likely be a better idea to try to improve the planner's
> rowcount estimates.  The problem here seems to be lack of stats for
> either "time_bucket('1 week', read_time)" or "read_time::date".
> In the case of the latter, do you really need a coercion to date?
> If it's a timestamp column, I'd think not.  As for the former,
> if the table doesn't get a lot of updates then creating an expression
> index on that expression might be useful.
> 

Thanks for the suggestions. Disabling hash aggregates actually made things even worse: (https://explain.depesz.com/s/cjDg <https://explain.depesz.com/s/cjDg>), so even if that wasn’t a brute-force option, it doesn’t appear to be a good one. Creating an index on the time_bucket expression didn’t seem to make any difference, and my data does get a lot of additions (though virtually no changes) anyway (about 1 additional record per second). As far as coercion to date, that’s so I can do queries bounded by date, and actually have all results from said date included. That said, I could of course simply make sure that when I get a query parameter of, say, 2020-1-13, I expand that into a full date-time for the end of the day. However, doing so for a test query didn’t seem to make much of a difference either: https://explain.depesz.com/s/X5VT <https://explain.depesz.com/s/X5VT>

So, to summarise:

Set enable_hasagg=off: worse
Index on time_bucket expression: no change in execution time or query plan that I can see
Get rid of coercion to date: *slight* improvement. 14.692 seconds instead of 15.5 seconds. And it looks like the row count estimates were actually worse.
Lower work_mem, forcing a disk sort and completely different query plan: Way, way better (around 6 seconds)

…so so far, it looks like the best option is to lower the work_mem, run the query, then set it back?
---
Israel Brewster
Software Engineer
Alaska Volcano Observatory 
Geophysical Institute - UAF 
2156 Koyukuk Drive 
Fairbanks AK 99775-7320
Work: 907-474-5172
cell:  907-328-9145

> 			regards, tom lane

  4. Re: Worse performance with higher work_mem?

    Rob Sargent <robjsargent@gmail.com> — 2020-01-14T00:46:26Z

    
> On Jan 13, 2020, at 5:41 PM, Israel Brewster <ijbrewster@alaska.edu> wrote:
> 
>> On Jan 13, 2020, at 3:19 PM, Tom Lane <tgl@sss.pgh.pa.us <mailto:tgl@sss.pgh.pa.us>> wrote:
>> 
>> Israel Brewster <ijbrewster@alaska.edu <mailto:ijbrewster@alaska.edu>> writes:
>>> In looking at the explain analyze output, I noticed that it had an “external merge Disk” sort going on, accounting for about 1 second of the runtime (explain analyze output here: https://explain.depesz.com/s/jx0q <https://explain.depesz.com/s/jx0q> <https://explain.depesz.com/s/jx0q <https://explain.depesz.com/s/jx0q>>). Since the machine has plenty of RAM available, I went ahead and increased the work_mem parameter. Whereupon the query plan got much simpler, and performance of said query completely tanked, increasing to about 15.5 seconds runtime (https://explain.depesz.com/s/Kl0S <https://explain.depesz.com/s/Kl0S> <https://explain.depesz.com/s/Kl0S <https://explain.depesz.com/s/Kl0S>>), most of which was in a HashAggregate.
>>> How can I fix this? Thanks.
>> 
>> Well, the brute-force way not to get that plan is "set enable_hashagg =
>> false".  But it'd likely be a better idea to try to improve the planner's
>> rowcount estimates.  The problem here seems to be lack of stats for
>> either "time_bucket('1 week', read_time)" or "read_time::date".
>> In the case of the latter, do you really need a coercion to date?
>> If it's a timestamp column, I'd think not.  As for the former,
>> if the table doesn't get a lot of updates then creating an expression
>> index on that expression might be useful.
>> 
> 
> Thanks for the suggestions. Disabling hash aggregates actually made things even worse: (https://explain.depesz.com/s/cjDg <https://explain.depesz.com/s/cjDg>), so even if that wasn’t a brute-force option, it doesn’t appear to be a good one. Creating an index on the time_bucket expression didn’t seem to make any difference, and my data does get a lot of additions (though virtually no changes) anyway (about 1 additional record per second). As far as coercion to date, that’s so I can do queries bounded by date, and actually have all results from said date included. That said, I could of course simply make sure that when I get a query parameter of, say, 2020-1-13, I expand that into a full date-time for the end of the day. However, doing so for a test query didn’t seem to make much of a difference either: https://explain.depesz.com/s/X5VT <https://explain.depesz.com/s/X5VT>
> 
> So, to summarise:
> 
> Set enable_hasagg=off: worse
> Index on time_bucket expression: no change in execution time or query plan that I can see
> Get rid of coercion to date: *slight* improvement. 14.692 seconds instead of 15.5 seconds. And it looks like the row count estimates were actually worse.
> Lower work_mem, forcing a disk sort and completely different query plan: Way, way better (around 6 seconds)
> 
> …so so far, it looks like the best option is to lower the work_mem, run the query, then set it back?
> ---

I don’t see that you’ve updated the statistics?

  5. Re: Worse performance with higher work_mem?

    Dilip Kumar <dilipbalaut@gmail.com> — 2020-01-14T03:34:47Z

    On Tue, Jan 14, 2020 at 5:29 AM Israel Brewster <ijbrewster@alaska.edu> wrote:
>
> I was working on diagnosing a “slow” (about 6 second run time) query:
>
> SELECT
>             to_char(bucket,'YYYY-MM-DD"T"HH24:MI:SS') as dates,
>             x_tilt,
>             y_tilt,
>             rot_x,
>             rot_y,
>             date_part('epoch', bucket) as timestamps,
>             temp
>         FROM
>             (SELECT
>               time_bucket('1 week', read_time) as bucket,
>               avg(tilt_x::float) as x_tilt,
>               avg(tilt_y::float) as y_tilt,
>               avg(rot_x::float) as rot_x,
>               avg(rot_y::float) as rot_y,
>               avg(temperature::float) as temp
>             FROM tilt_data
>             WHERE station='c08883c0-fbe5-11e9-bd6e-aec49259cebb'
>             AND read_time::date<='2020-01-13'::date
>             GROUP BY bucket) s1
>         ORDER BY bucket;
>
> In looking at the explain analyze output, I noticed that it had an “external merge Disk” sort going on, accounting for about 1 second of the runtime (explain analyze output here: https://explain.depesz.com/s/jx0q). Since the machine has plenty of RAM available, I went ahead and increased the work_mem parameter. Whereupon the query plan got much simpler, and performance of said query completely tanked, increasing to about 15.5 seconds runtime (https://explain.depesz.com/s/Kl0S), most of which was in a HashAggregate.
>
> I am running PostgreSQL 11.6 on a machine with 128GB of ram (so, like I said, plenty of RAM)
>
> How can I fix this? Thanks.

I have noticed that after increasing the work_mem your plan has
switched from a parallel plan to a non-parallel plan.  Basically,
earlier it was getting executed with 3 workers.  And, after it becomes
non-parallel plan execution time is 3x.  For the analysis can we just
reduce the value of parallel_tuple_cost and parallel_setup_cost and
see how it behaves?

-- 
Regards,
Dilip Kumar
EnterpriseDB: http://www.enterprisedb.com

  6. Re: Worse performance with higher work_mem?

    Israel Brewster <ijbrewster@alaska.edu> — 2020-01-14T17:02:35Z

    
> On Jan 13, 2020, at 6:34 PM, Dilip Kumar <dilipbalaut@gmail.com> wrote:
> 
> On Tue, Jan 14, 2020 at 5:29 AM Israel Brewster <ijbrewster@alaska.edu <mailto:ijbrewster@alaska.edu>> wrote:
>> 
>> I was working on diagnosing a “slow” (about 6 second run time) query:
>> 
>> SELECT
>>            to_char(bucket,'YYYY-MM-DD"T"HH24:MI:SS') as dates,
>>            x_tilt,
>>            y_tilt,
>>            rot_x,
>>            rot_y,
>>            date_part('epoch', bucket) as timestamps,
>>            temp
>>        FROM
>>            (SELECT
>>              time_bucket('1 week', read_time) as bucket,
>>              avg(tilt_x::float) as x_tilt,
>>              avg(tilt_y::float) as y_tilt,
>>              avg(rot_x::float) as rot_x,
>>              avg(rot_y::float) as rot_y,
>>              avg(temperature::float) as temp
>>            FROM tilt_data
>>            WHERE station='c08883c0-fbe5-11e9-bd6e-aec49259cebb'
>>            AND read_time::date<='2020-01-13'::date
>>            GROUP BY bucket) s1
>>        ORDER BY bucket;
>> 
>> In looking at the explain analyze output, I noticed that it had an “external merge Disk” sort going on, accounting for about 1 second of the runtime (explain analyze output here: https://explain.depesz.com/s/jx0q). Since the machine has plenty of RAM available, I went ahead and increased the work_mem parameter. Whereupon the query plan got much simpler, and performance of said query completely tanked, increasing to about 15.5 seconds runtime (https://explain.depesz.com/s/Kl0S), most of which was in a HashAggregate.
>> 
>> I am running PostgreSQL 11.6 on a machine with 128GB of ram (so, like I said, plenty of RAM)
>> 
>> How can I fix this? Thanks.
> 
> I have noticed that after increasing the work_mem your plan has
> switched from a parallel plan to a non-parallel plan.  Basically,
> earlier it was getting executed with 3 workers.  And, after it becomes
> non-parallel plan execution time is 3x.  For the analysis can we just
> reduce the value of parallel_tuple_cost and parallel_setup_cost and
> see how it behaves?

That was it. Setting the parallel_tuple_cost parameter to .05 and the parallel_setup_cost parameter to 500 (so, both to half their default values) caused this query to run in parallel again with the higher work_mem setting (and do the sorts in memory, as was the original goal). New explain output at https://explain.depesz.com/s/rX3m <https://explain.depesz.com/s/rX3m> Granted, doing the sorts in memory didn’t speed things up as much as I would have hoped - 5.58 seconds vs 5.9 - but at least the higher work_mem setting isn’t slowing down the query any more.

Would be nice if the query could run a little faster - even six seconds is a relatively long time to wait - but I can live with that at least. So thanks! Hmmm… now I wonder how things would change if I increased the max_parallel_workers value? Might be something to play around with. Maybe grab a few more cores for the VM.
---
Israel Brewster
Software Engineer
Alaska Volcano Observatory 
Geophysical Institute - UAF 
2156 Koyukuk Drive 
Fairbanks AK 99775-7320
Work: 907-474-5172
cell:  907-328-9145

> 
> -- 
> Regards,
> Dilip Kumar
> EnterpriseDB: http://www.enterprisedb.com <http://www.enterprisedb.com/>

  7. Re: Worse performance with higher work_mem?

    Israel Brewster <ijbrewster@alaska.edu> — 2020-01-14T17:08:29Z

    > 
> On Jan 13, 2020, at 3:46 PM, Rob Sargent <robjsargent@gmail.com> wrote:
> 
> 
> 
>> On Jan 13, 2020, at 5:41 PM, Israel Brewster <ijbrewster@alaska.edu <mailto:ijbrewster@alaska.edu>> wrote:
>> 
>>> On Jan 13, 2020, at 3:19 PM, Tom Lane <tgl@sss.pgh.pa.us <mailto:tgl@sss.pgh.pa.us>> wrote:
>>> 
>>> Israel Brewster <ijbrewster@alaska.edu <mailto:ijbrewster@alaska.edu>> writes:
>>>> In looking at the explain analyze output, I noticed that it had an “external merge Disk” sort going on, accounting for about 1 second of the runtime (explain analyze output here: https://explain.depesz.com/s/jx0q <https://explain.depesz.com/s/jx0q> <https://explain.depesz.com/s/jx0q <https://explain.depesz.com/s/jx0q>>). Since the machine has plenty of RAM available, I went ahead and increased the work_mem parameter. Whereupon the query plan got much simpler, and performance of said query completely tanked, increasing to about 15.5 seconds runtime (https://explain.depesz.com/s/Kl0S <https://explain.depesz.com/s/Kl0S> <https://explain.depesz.com/s/Kl0S <https://explain.depesz.com/s/Kl0S>>), most of which was in a HashAggregate.
>>>> How can I fix this? Thanks.
>>> 
>>> Well, the brute-force way not to get that plan is "set enable_hashagg =
>>> false".  But it'd likely be a better idea to try to improve the planner's
>>> rowcount estimates.  The problem here seems to be lack of stats for
>>> either "time_bucket('1 week', read_time)" or "read_time::date".
>>> In the case of the latter, do you really need a coercion to date?
>>> If it's a timestamp column, I'd think not.  As for the former,
>>> if the table doesn't get a lot of updates then creating an expression
>>> index on that expression might be useful.
>>> 
>> 
>> Thanks for the suggestions. Disabling hash aggregates actually made things even worse: (https://explain.depesz.com/s/cjDg <https://explain.depesz.com/s/cjDg>), so even if that wasn’t a brute-force option, it doesn’t appear to be a good one. Creating an index on the time_bucket expression didn’t seem to make any difference, and my data does get a lot of additions (though virtually no changes) anyway (about 1 additional record per second). As far as coercion to date, that’s so I can do queries bounded by date, and actually have all results from said date included. That said, I could of course simply make sure that when I get a query parameter of, say, 2020-1-13, I expand that into a full date-time for the end of the day. However, doing so for a test query didn’t seem to make much of a difference either: https://explain.depesz.com/s/X5VT <https://explain.depesz.com/s/X5VT>
>> 
>> So, to summarise:
>> 
>> Set enable_hasagg=off: worse
>> Index on time_bucket expression: no change in execution time or query plan that I can see
>> Get rid of coercion to date: *slight* improvement. 14.692 seconds instead of 15.5 seconds. And it looks like the row count estimates were actually worse.
>> Lower work_mem, forcing a disk sort and completely different query plan: Way, way better (around 6 seconds)
>> 
>> …so so far, it looks like the best option is to lower the work_mem, run the query, then set it back?
>> ---
> 
> I don’t see that you’ve updated the statistics?

Ummmm….no. I know nothing about that :-)

Some research tells me that a) it should happen as part of the autovacuum process, and that b) I may not be running autovacuum enough, since it is a large table and doesn’t change often. But I don’t really know.

---
Israel Brewster
Software Engineer
Alaska Volcano Observatory 
Geophysical Institute - UAF 
2156 Koyukuk Drive 
Fairbanks AK 99775-7320
Work: 907-474-5172
cell:  907-328-9145

  8. Re: Worse performance with higher work_mem?

    Justin <zzzzz.graf@gmail.com> — 2020-01-14T17:32:00Z

    Updating the stats can be done via vacuum or analyze command,

https://www.postgresql.org/docs/12/sql-analyze.html.   To just analyze a
table typically does not take much time. and can be scheduled to run so the
stats update instead of waiting on auto-vacuum to deal with it  which could
be some time on an insert only table

Seeing the difference in speed between first run with low work memory vs
high work memory with parallelization,  I suspect the temp tables never
actually got written to disk they just hung out in the OS IO cache.

The query in all examples is hung up doing Index scan and running the avg()
aggregate.

Maybe you can look at creating summary table for time periods to work
against,  maybe a Weekly or Daily summary of these values could cut down on
the number of records being processed.  It would not affect the result




On Tue, Jan 14, 2020 at 12:08 PM Israel Brewster <ijbrewster@alaska.edu>
wrote:

>
> On Jan 13, 2020, at 3:46 PM, Rob Sargent <robjsargent@gmail.com> wrote:
>
>
>
> On Jan 13, 2020, at 5:41 PM, Israel Brewster <ijbrewster@alaska.edu>
> wrote:
>
> On Jan 13, 2020, at 3:19 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>
> Israel Brewster <ijbrewster@alaska.edu> writes:
>
> In looking at the explain analyze output, I noticed that it had an
> “external merge Disk” sort going on, accounting for about 1 second of the
> runtime (explain analyze output here: https://explain.depesz.com/s/jx0q <
> https://explain.depesz.com/s/jx0q>). Since the machine has plenty of RAM
> available, I went ahead and increased the work_mem parameter. Whereupon the
> query plan got much simpler, and performance of said query completely
> tanked, increasing to about 15.5 seconds runtime (
> https://explain.depesz.com/s/Kl0S <https://explain.depesz.com/s/Kl0S>),
> most of which was in a HashAggregate.
> How can I fix this? Thanks.
>
>
> Well, the brute-force way not to get that plan is "set enable_hashagg =
> false".  But it'd likely be a better idea to try to improve the planner's
> rowcount estimates.  The problem here seems to be lack of stats for
> either "time_bucket('1 week', read_time)" or "read_time::date".
> In the case of the latter, do you really need a coercion to date?
> If it's a timestamp column, I'd think not.  As for the former,
> if the table doesn't get a lot of updates then creating an expression
> index on that expression might be useful.
>
>
> Thanks for the suggestions. Disabling hash aggregates actually made things
> even worse: (https://explain.depesz.com/s/cjDg), so even if that wasn’t a
> brute-force option, it doesn’t appear to be a good one. Creating an index
> on the time_bucket expression didn’t seem to make any difference, and my
> data does get a lot of additions (though virtually no changes) anyway
> (about 1 additional record per second). As far as coercion to date, that’s
> so I can do queries bounded by date, and actually have all results from
> said date included. That said, I could of course simply make sure that when
> I get a query parameter of, say, 2020-1-13, I expand that into a full
> date-time for the end of the day. However, doing so for a test query didn’t
> seem to make much of a difference either:
> https://explain.depesz.com/s/X5VT
>
> So, to summarise:
>
> Set enable_hasagg=off: worse
> Index on time_bucket expression: no change in execution time or query plan
> that I can see
> Get rid of coercion to date: *slight* improvement. 14.692 seconds instead
> of 15.5 seconds. And it looks like the row count estimates were actually
> worse.
> Lower work_mem, forcing a disk sort and completely different query plan:
> Way, way better (around 6 seconds)
>
> …so so far, it looks like the best option is to lower the work_mem, run
> the query, then set it back?
> ---
>
>
> I don’t see that you’ve updated the statistics?
>
>
> Ummmm….no. I know nothing about that :-)
>
> Some research tells me that a) it should happen as part of the autovacuum
> process, and that b) I may not be running autovacuum enough, since it is a
> large table and doesn’t change often. But I don’t really know.
>
> ---
> Israel Brewster
> Software Engineer
> Alaska Volcano Observatory
> Geophysical Institute - UAF
> 2156 Koyukuk Drive
> Fairbanks AK 99775-7320
> Work: 907-474-5172
> cell:  907-328-9145
>
>

  9. Re: Worse performance with higher work_mem?

    Tom Lane <tgl@sss.pgh.pa.us> — 2020-01-14T17:54:09Z

    Israel Brewster <ijbrewster@alaska.edu> writes:
> On Jan 13, 2020, at 3:46 PM, Rob Sargent <robjsargent@gmail.com> wrote:
>> I don’t see that you’ve updated the statistics?

> Ummmm….no. I know nothing about that :-)

Just do a manual ANALYZE on the table, if you don't want to wait
around for autovacuum to get to it.

			regards, tom lane