Re: Worse performance with higher work_mem?
Justin <[email protected]> Tue, 14 Jan 2020 12:32:00 -0500
| Newsgroups | gmane.comp.db.postgresql.general |
|---|---|
| Message-ID | <CALL-XeNfQH9eCU=KOSe592ij36HY_XWQL4OkzpT7m8FVTJJzmA@mail.gmail.com> |
--000000000000d755a4059c1cf8a5 Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: quoted-printable 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 <[email protected]> wrote: > > On Jan 13, 2020, at 3:46 PM, Rob Sargent <[email protected]> wrote: > > > > On Jan 13, 2020, at 5:41 PM, Israel Brewster <[email protected]> > wrote: > > On Jan 13, 2020, at 3:19 PM, Tom Lane <[email protected]> wrote: > > Israel Brewster <[email protected]> writes: > > In looking at the explain analyze output, I noticed that it had an > =E2=80=9Cexternal merge Disk=E2=80=9D 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 t= he > 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 =3D > 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 thing= s > even worse: (https://explain.depesz.com/s/cjDg), so even if that wasn=E2= =80=99t a > brute-force option, it doesn=E2=80=99t appear to be a good one. Creating = an index > on the time_bucket expression didn=E2=80=99t 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= =E2=80=99s > 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 wh= en > 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= =E2=80=99t > seem to make much of a difference either: > https://explain.depesz.com/s/X5VT > > So, to summarise: > > Set enable_hasagg=3Doff: worse > Index on time_bucket expression: no change in execution time or query pla= n > 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) > > =E2=80=A6so so far, it looks like the best option is to lower the work_me= m, run > the query, then set it back? > --- > > > I don=E2=80=99t see that you=E2=80=99ve updated the statistics? > > > Ummmm=E2=80=A6.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=E2=80=99t change often. But I don=E2=80=99t 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 > > --000000000000d755a4059c1cf8a5 Content-Type: text/html; charset="UTF-8" Content-Transfer-Encoding: quoted-printable <div dir=3D"ltr"><div>Updating the stats can be done via vacuum or analyze = command, =C2=A0<br></div><div><br></div><div><a href=3D"https://www.postgre= sql.org/docs/12/sql-analyze.html">https://www.postgresql.org/docs/12/sql-an= alyze.html</a>.=C2=A0=C2=A0 To just analyze a table typically does not take= much time. and can be scheduled to run so the stats update instead of wait= ing on auto-vacuum to deal with it=C2=A0 which could be some time on an ins= ert only table <br></div><div><br></div><div>Seeing the difference in speed= between first run with low work memory vs high work memory with paralleliz= ation,=C2=A0 I suspect the temp tables never actually got written to disk t= hey just hung out in the OS IO cache.</div><div><br></div><div>The query in= all examples is hung up doing Index scan and running the avg() aggregate.= =C2=A0 <br></div><div><br></div><div>Maybe you can look at creating summary= table for time periods to work against,=C2=A0 maybe a Weekly or Daily summ= ary of these values could cut down on the number of records being processed= .=C2=A0 It would not affect the result=C2=A0 =C2=A0=C2=A0 <br></div><div><b= r></div><div><br></div><div> =C2=A0 <br></div></div><br><div class=3D"gmail= _quote"><div dir=3D"ltr" class=3D"gmail_attr">On Tue, Jan 14, 2020 at 12:08= PM Israel Brewster <<a href=3D"mailto:[email protected]">ijbrewster= @alaska.edu</a>> wrote:<br></div><blockquote class=3D"gmail_quote" style= =3D"margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding= -left:1ex"><div style=3D"overflow-wrap: break-word;"><div><blockquote type= =3D"cite"><div><br>On Jan 13, 2020, at 3:46 PM, Rob Sargent <<a href=3D"= mailto:[email protected]" target=3D"_blank">[email protected]</a>&g= t; wrote:</div><br><div><br><br style=3D"font-family:Helvetica;font-size:12= px;font-style:normal;font-variant-caps:normal;font-weight:normal;letter-spa= cing:normal;text-align:start;text-indent:0px;text-transform:none;white-spac= e:normal;word-spacing:0px;text-decoration:none"><blockquote type=3D"cite" s= tyle=3D"font-family:Helvetica;font-size:12px;font-style:normal;font-variant= -caps:normal;font-weight:normal;letter-spacing:normal;text-align:start;text= -indent:0px;text-transform:none;white-space:normal;word-spacing:0px;text-de= coration:none"><div>On Jan 13, 2020, at 5:41 PM, Israel Brewster <<a hre= f=3D"mailto:[email protected]" target=3D"_blank">[email protected]<= /a>> wrote:</div><br><div><div style=3D"font-family:CourierNewPSMT;font-= size:14px;font-style:normal;font-variant-caps:normal;font-weight:normal;let= ter-spacing:normal;text-align:start;text-indent:0px;text-transform:none;whi= te-space:normal;word-spacing:0px;text-decoration:none"><blockquote type=3D"= cite"><div>On Jan 13, 2020, at 3:19 PM, Tom Lane <<a href=3D"mailto:tgl@= sss.pgh.pa.us" target=3D"_blank">[email protected]</a>> wrote:</div><br>= <div><div>Israel Brewster <<a href=3D"mailto:[email protected]" targ= et=3D"_blank">[email protected]</a>> writes:<br><blockquote type=3D"= cite">In looking at the explain analyze output, I noticed that it had an = =E2=80=9Cexternal merge Disk=E2=80=9D sort going on, accounting for about 1= second of the runtime (explain analyze output here:<span>=C2=A0</span><a h= ref=3D"https://explain.depesz.com/s/jx0q" target=3D"_blank">https://explain= .depesz.com/s/jx0q</a><span>=C2=A0</span><<a href=3D"https://explain.dep= esz.com/s/jx0q" target=3D"_blank">https://explain.depesz.com/s/jx0q</a>>= ). Since the machine has plenty of RAM available, I went ahead and increase= d the work_mem parameter. Whereupon the query plan got much simpler, and pe= rformance of said query completely tanked, increasing to about 15.5 seconds= runtime (<a href=3D"https://explain.depesz.com/s/Kl0S" target=3D"_blank">h= ttps://explain.depesz.com/s/Kl0S</a><span>=C2=A0</span><<a href=3D"https= ://explain.depesz.com/s/Kl0S" target=3D"_blank">https://explain.depesz.com/= s/Kl0S</a>>), most of which was in a HashAggregate.<br>How can I fix thi= s? Thanks.<br></blockquote><br>Well, the brute-force way not to get that pl= an is "set enable_hashagg =3D<br>false".=C2=A0 But it'd likel= y be a better idea to try to improve the planner's<br>rowcount estimate= s.=C2=A0 The problem here seems to be lack of stats for<br>either "tim= e_bucket('1 week', read_time)" or "read_time::date".= <br>In the case of the latter, do you really need a coercion to date?<br>If= it's a timestamp column, I'd think not.=C2=A0 As for the former,<b= r>if the table doesn't get a lot of updates then creating an expression= <br>index on that expression might be useful.<br><br></div></div></blockquo= te><div><br></div><div>Thanks for the suggestions. Disabling hash aggregate= s actually made things even worse: (<a href=3D"https://explain.depesz.com/s= /cjDg" target=3D"_blank">https://explain.depesz.com/s/cjDg</a>), so even if= that wasn=E2=80=99t a brute-force option, it doesn=E2=80=99t appear to be = a good one. Creating an index on the time_bucket expression didn=E2=80=99t = seem to make any difference, and my data does get a lot of additions (thoug= h virtually no changes) anyway (about 1 additional record per second). As f= ar as coercion to date, that=E2=80=99s 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=E2=80=99t seem to make much of a difference = either:=C2=A0<a href=3D"https://explain.depesz.com/s/X5VT" target=3D"_blank= ">https://explain.depesz.com/s/X5VT</a></div><div><br></div><div>So, to sum= marise:</div><div><br></div><div>Set enable_hasagg=3Doff: worse</div><div>I= ndex on time_bucket expression: no change in execution time or query plan t= hat I can see</div><div>Get rid of coercion to date: *slight* improvement. = 14.692 seconds instead of 15.5 seconds. And it looks like the row count est= imates were actually worse.</div><div>Lower work_mem, forcing a disk sort a= nd completely different query plan: Way, way better (around 6 seconds)</div= ><div><br></div><div>=E2=80=A6so so far, it looks like the best option is t= o lower the work_mem, run the query, then set it back?</div><div><div>---</= div></div></div></div></blockquote><div style=3D"font-family:Helvetica;font= -size:12px;font-style:normal;font-variant-caps:normal;font-weight:normal;le= tter-spacing:normal;text-align:start;text-indent:0px;text-transform:none;wh= ite-space:normal;word-spacing:0px;text-decoration:none"><br></div><span sty= le=3D"font-family:Helvetica;font-size:12px;font-style:normal;font-variant-c= aps:normal;font-weight:normal;letter-spacing:normal;text-align:start;text-i= ndent:0px;text-transform:none;white-space:normal;word-spacing:0px;text-deco= ration:none;float:none;display:inline">I don=E2=80=99t see that you=E2=80= =99ve updated the statistics?</span></div></blockquote><br></div><div>Ummmm= =E2=80=A6.no. I know nothing about that :-)</div><div><br></div><div>Some r= esearch 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 t= able and doesn=E2=80=99t change often. But I don=E2=80=99t really know.</di= v><div><br></div><div><div>---</div><div>Israel Brewster<br>Software Engine= er<br>Alaska Volcano Observatory=C2=A0<br>Geophysical Institute - UAF=C2=A0= <br>2156 Koyukuk Drive=C2=A0<br>Fairbanks AK 99775-7320</div><div>Work: 907= -474-5172<br>cell: =C2=A0907-328-9145</div></div><br></div></blockquote></d= iv> --000000000000d755a4059c1cf8a5--