Обсуждение: Worse performance with higher work_mem?
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;
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.
---
Israel Brewster
Software Engineer
Alaska Volcano Observatory
Geophysical Institute - UAF
2156 Koyukuk Drive
Fairbanks AK 99775-7320
Software Engineer
Alaska Volcano Observatory
Geophysical Institute - UAF
2156 Koyukuk Drive
Fairbanks AK 99775-7320
Work: 907-474-5172
cell: 907-328-9145
cell: 907-328-9145
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 forabout 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_memparameter. Whereupon the query plan got much simpler, and performance of said query completely tanked, increasingto about 15.5 seconds runtime (https://explain.depesz.com/s/Kl0S <https://explain.depesz.com/s/Kl0S>), most ofwhich 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
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?
---
Israel Brewster
Software Engineer
Alaska Volcano Observatory
Geophysical Institute - UAF
2156 Koyukuk Drive
Fairbanks AK 99775-7320
Software Engineer
Alaska Volcano Observatory
Geophysical Institute - UAF
2156 Koyukuk Drive
Fairbanks AK 99775-7320
Work: 907-474-5172
cell: 907-328-9145
cell: 907-328-9145
regards, tom lane
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/X5VTSo, to summarise:Set enable_hasagg=off: worseIndex on time_bucket expression: no change in execution time or query plan that I can seeGet 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?---
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
forabout 1 second of the runtime (explain analyze output here: https://explain.depesz.com/s/jx0q). Since the machine
hasplenty 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
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> 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 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
Software Engineer
Alaska Volcano Observatory
Geophysical Institute - UAF
2156 Koyukuk Drive
Fairbanks AK 99775-7320
Work: 907-474-5172
cell: 907-328-9145
cell: 907-328-9145
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/X5VTSo, to summarise:Set enable_hasagg=off: worseIndex on time_bucket expression: no change in execution time or query plan that I can seeGet 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
Software Engineer
Alaska Volcano Observatory
Geophysical Institute - UAF
2156 Koyukuk Drive
Fairbanks AK 99775-7320
Work: 907-474-5172
cell: 907-328-9145
cell: 907-328-9145
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/X5VTSo, to summarise:Set enable_hasagg=off: worseIndex on time_bucket expression: no change in execution time or query plan that I can seeGet 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-7320Work: 907-474-5172
cell: 907-328-9145
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