Thread: How can sort performance be so different
The following is output from analyzing a simple query on a table of 13436 rows on postgresql 10, ubuntu 18.04. explain analyze select * from chart order by name; QUERY PLAN ----------------------------------------------------------------------------------------------------------------- Sort (cost=1470.65..1504.24 rows=13436 width=725) (actual time=224340.949..224343.499 rows=13436 loops=1) Sort Key: name Sort Method: quicksort Memory: 4977kB -> Seq Scan on chart (cost=0.00..549.36 rows=13436 width=725) (actual time=0.015..1.395 rows=13436 loops=1) Planning time: 0.865 ms Execution time: 224344.281 ms (6 rows) The planner has predictably done a sequential scan followed by a sort. Though it might have wished it hadn't and just used the index (there is an index on name). The sort is taking a mind boggling 224 seconds, nearly 2 minutes. This is on a cloud vps server. Interesting when I run the same query on my laptop it completes in well under one second. I wonder what can cause such a massive discrepancy in the sort time. Can it be that the VPS server has heavily over committed CPU. Note I have tried this with 2 different company's servers with similar results. I am baffled. The sort seems to be all done in memory (only 5MB). Tested when nothing else was going on at the time. I can expect some difference between the VPS and my laptop, but almost 1000x seems odd. The CPUs are different but not that different. Any theories? Regards Bob
út 29. 1. 2019 v 19:29 odesílatel Bob Jolliffe <bobjolliffe@gmail.com> napsal:
The following is output from analyzing a simple query on a table of
13436 rows on postgresql 10, ubuntu 18.04.
explain analyze select * from chart order by name;
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------
Sort (cost=1470.65..1504.24 rows=13436 width=725) (actual
time=224340.949..224343.499 rows=13436 loops=1)
Sort Key: name
Sort Method: quicksort Memory: 4977kB
-> Seq Scan on chart (cost=0.00..549.36 rows=13436 width=725)
(actual time=0.015..1.395 rows=13436 loops=1)
Planning time: 0.865 ms
Execution time: 224344.281 ms
(6 rows)
The planner has predictably done a sequential scan followed by a sort.
Though it might have wished it hadn't and just used the index (there
is an index on name). The sort is taking a mind boggling 224 seconds,
nearly 2 minutes.
This is on a cloud vps server.
Interesting when I run the same query on my laptop it completes in
well under one second.
I wonder what can cause such a massive discrepancy in the sort time.
Can it be that the VPS server has heavily over committed CPU. Note I
have tried this with 2 different company's servers with similar
results.
I am baffled. The sort seems to be all done in memory (only 5MB).
Tested when nothing else was going on at the time. I can expect some
difference between the VPS and my laptop, but almost 1000x seems odd.
The CPUs are different but not that different.
Any theories?
I am sure so sort of 10K rows cannot be 224sec. Really looks like VPS issue.
Regards
Pavel
Regards
Bob
Run https://github.com/n-st/nench and benchmark the underlying vps first.
On Tue 29 Jan, 2019, 11:59 PM Bob Jolliffe <bobjolliffe@gmail.com wrote:
The following is output from analyzing a simple query on a table of
13436 rows on postgresql 10, ubuntu 18.04.
explain analyze select * from chart order by name;
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------
Sort (cost=1470.65..1504.24 rows=13436 width=725) (actual
time=224340.949..224343.499 rows=13436 loops=1)
Sort Key: name
Sort Method: quicksort Memory: 4977kB
-> Seq Scan on chart (cost=0.00..549.36 rows=13436 width=725)
(actual time=0.015..1.395 rows=13436 loops=1)
Planning time: 0.865 ms
Execution time: 224344.281 ms
(6 rows)
The planner has predictably done a sequential scan followed by a sort.
Though it might have wished it hadn't and just used the index (there
is an index on name). The sort is taking a mind boggling 224 seconds,
nearly 2 minutes.
This is on a cloud vps server.
Interesting when I run the same query on my laptop it completes in
well under one second.
I wonder what can cause such a massive discrepancy in the sort time.
Can it be that the VPS server has heavily over committed CPU. Note I
have tried this with 2 different company's servers with similar
results.
I am baffled. The sort seems to be all done in memory (only 5MB).
Tested when nothing else was going on at the time. I can expect some
difference between the VPS and my laptop, but almost 1000x seems odd.
The CPUs are different but not that different.
Any theories?
Regards
Bob
Bob Jolliffe <bobjolliffe@gmail.com> writes: > I wonder what can cause such a massive discrepancy in the sort time. Are you using the same locale (LC_COLLATE) setting on both machines? Some locales sort way slower than C locale does. That's not enough to explain a 1000X discrepancy --- I concur with the other opinions that there's something wrong with your VPS --- but it might account for something like 10X of it. regards, tom lane
Hi Tom After much performance measuring of VPS I believe you are right in your suspicion about locale. The database is full of Laos characters (it is a government system in Laos). When I tested on my VPS (en_US.UTF-8) I get the crazy slow performance, whereas my laptop postgresql is C.UTF-8. Modifying the query from : explain analyze select * from chart order by name; to explain analyze select * from chart order by name COLLATE "C"; and the same query runs like a rocket. Amazing, yes 1000 times faster. What I don't know yet is (i) whether the sort order makes sense for the Laos names; and (ii) what the locale settings are on the production server where the problem was first reported. There will be some turnaround before I get this information. I am guessing that the database is using "en_US" rather than anything Laos specific. In which case "C" would probably be no worse re sort order. But will know better soon. This has been a long but very fruitful investigation. Thank you all for input. Regards Bob On Tue, 29 Jan 2019 at 18:47, Tom Lane <tgl@sss.pgh.pa.us> wrote: > > Bob Jolliffe <bobjolliffe@gmail.com> writes: > > I wonder what can cause such a massive discrepancy in the sort time. > > Are you using the same locale (LC_COLLATE) setting on both machines? > Some locales sort way slower than C locale does. That's not enough > to explain a 1000X discrepancy --- I concur with the other opinions > that there's something wrong with your VPS --- but it might account > for something like 10X of it. > > regards, tom lane
On Wed, Jan 30, 2019 at 3:57 AM Bob Jolliffe <bobjolliffe@gmail.com> wrote: > (i) whether the sort order makes sense for the Laos names; and > (ii) what the locale settings are on the production server where the > problem was first reported. > > There will be some turnaround before I get this information. I am > guessing that the database is using "en_US" rather than anything Laos > specific. In which case "C" would probably be no worse re sort order. > But will know better soon. > > This has been a long but very fruitful investigation. Thank you all for input. If you can find a way to use an ICU collation, it may be possible to get Laotian sort order with performance that's a lot closer to the performance you see with the C locale. The difference that you're seeing is obviously explainable in large part by the C locale using the abbreviated keys technique. The system glibc's collations cannot use this optimization. I believe that some locales have inherently more expensive normalization processes (comparisons) than others, but if you can effective amortize the cost per key by building an abbreviated key, it may not matter that much. And, ICU may be faster than glibc anyway. -- Peter Geoghegan
Hi Peter I did check out using ICU and the performance does indeed seem comparable with C locale: EXPLAIN ANALYZE select * from chart order by name COLLATE "lo-x-icu"; QUERY PLAN ------------------------------------------------------------------------------------------------------------------- Sort (cost=1470.65..1504.24 rows=13436 width=1203) (actual time=82.752..85.723 rows=13436 loops=1) Sort Key: name COLLATE "lo-x-icu" Sort Method: quicksort Memory: 6253kB -> Seq Scan on chart (cost=0.00..549.36 rows=13436 width=1203) (actual time=0.043..12.634 rows=13436 loops=1) Planning time: 1.610 ms Execution time: 96.060 ms (6 rows) The Laos folk have confirmed that the sort order with C locale was not correct. So setting the ICU locale seems to be the way forward. The problem is that this is a large java application with a great number of tables and queries. Also it is used in 60+ countries not just Laos. So we cannot simply modify the queries or table creation scripts directly such as in the manner above. I was hoping the solution would just be to set a default locale on the database (perhaps even und-x-icu) but I see now that this doesn't seem to be currently possible with postgresql 10 ie. set the locale on database creation to a *-icu locale. Is this also a limitation on postgresql 11? (Upgrading would be possible) Any other workarounds worth trying? The magnitude of this issue is significant - 1000x slower on these basic sorts is crippling the application, probably also in a number of other queries. Regards Bob On Wed, 30 Jan 2019 at 23:54, Peter Geoghegan <pg@bowt.ie> wrote: > > On Wed, Jan 30, 2019 at 3:57 AM Bob Jolliffe <bobjolliffe@gmail.com> wrote: > > (i) whether the sort order makes sense for the Laos names; and > > (ii) what the locale settings are on the production server where the > > problem was first reported. > > > > There will be some turnaround before I get this information. I am > > guessing that the database is using "en_US" rather than anything Laos > > specific. In which case "C" would probably be no worse re sort order. > > But will know better soon. > > > > This has been a long but very fruitful investigation. Thank you all for input. > > If you can find a way to use an ICU collation, it may be possible to > get Laotian sort order with performance that's a lot closer to the > performance you see with the C locale. The difference that you're > seeing is obviously explainable in large part by the C locale using > the abbreviated keys technique. The system glibc's collations cannot > use this optimization. > > I believe that some locales have inherently more expensive > normalization processes (comparisons) than others, but if you can > effective amortize the cost per key by building an abbreviated key, it > may not matter that much. And, ICU may be faster than glibc anyway. > > -- > Peter Geoghegan
On Thu, Jan 31, 2019 at 7:30 AM Bob Jolliffe <bobjolliffe@gmail.com> wrote: > > Hi Peter > > I did check out using ICU and the performance does indeed seem > comparable with C locale: > > EXPLAIN ANALYZE select * from chart order by name COLLATE "lo-x-icu"; > QUERY PLAN > ------------------------------------------------------------------------------------------------------------------- > Sort (cost=1470.65..1504.24 rows=13436 width=1203) (actual > time=82.752..85.723 rows=13436 loops=1) > Sort Key: name COLLATE "lo-x-icu" > Sort Method: quicksort Memory: 6253kB > -> Seq Scan on chart (cost=0.00..549.36 rows=13436 width=1203) > (actual time=0.043..12.634 rows=13436 loops=1) > Planning time: 1.610 ms > Execution time: 96.060 ms > (6 rows) > > The Laos folk have confirmed that the sort order with C locale was not > correct. So setting the ICU locale seems to be the way forward. > > The problem is that this is a large java application with a great > number of tables and queries. Also it is used in 60+ countries not > just Laos. So we cannot simply modify the queries or table creation > scripts directly such as in the manner above. I was hoping the > solution would just be to set a default locale on the database > (perhaps even und-x-icu) but I see now that this doesn't seem to be > currently possible with postgresql 10 ie. set the locale on database > creation to a *-icu locale. > > Is this also a limitation on postgresql 11? (Upgrading would be possible) yeah, probably. Having said that, I'm really struggling that it can take take several minutes to sort such a small number of rows even with location issues. I can sort rocks faster than that :-). Switching between various european collations, I'm seeing subsecond sort responses for 44k records on my test box. I don't have the laos collation installed unfortunately. Are you seeing kind of penalty in other conversions? merlin
Merlin Moncure wrote: > yeah, probably. Having said that, I'm really struggling that it can > take take several minutes to sort such a small number of rows even > with location issues. I can sort rocks faster than that :-). > > Switching between various european collations, I'm seeing subsecond > sort responses for 44k records on my test box. I don't have the laos > collation installed unfortunately. Are you seeing kind of penalty in > other conversions? I find that it makes a lot of difference what you sort: CREATE TABLE sort(t text); INSERT INTO sort SELECT 'ຕົວອັກສອນລາວ... ງ່າຍຂື້ນ' || i FROM generate_series(1, 100000) AS i; SET work_mem = '1GB'; EXPLAIN (ANALYZE, BUFFERS) SELECT t FROM sort ORDER BY t COLLATE "C"; [...] Execution Time: 288.752 ms EXPLAIN (ANALYZE, BUFFERS) SELECT t FROM sort ORDER BY t COLLATE "lo_LA.utf8"; [...] Execution Time: 47006.683 ms EXPLAIN (ANALYZE, BUFFERS) SELECT t FROM sort ORDER BY t COLLATE "en_US.utf8"; [...] Execution Time: 73962.934 ms CREATE TABLE sort2(t text); INSERT INTO sort2 SELECT 'this is plain old English' || i FROM generate_series(1, 100000) AS i; SET work_mem = '1GB'; EXPLAIN (ANALYZE, BUFFERS) SELECT t FROM sort2 ORDER BY t COLLATE "C"; [...] Execution Time: 237.615 ms EXPLAIN (ANALYZE, BUFFERS) SELECT t FROM sort2 ORDER BY t COLLATE "lo_LA.utf8"; [...] Execution Time: 2467.848 ms EXPLAIN (ANALYZE, BUFFERS) SELECT t FROM sort2 ORDER BY t COLLATE "en_US.utf8"; [...] Execution Time: 2927.667 ms This is on my x86_64 Fedora 29 system, kernel 4.20.6, glibc 2.28. Yours, Laurenz Albe -- Cybertec | https://www.cybertec-postgresql.com
Sorry Merlin for not replying earlier. The difference is indeed hard to understand but it is certainly there. We altered the collation to use on the name field in that table and the problem has gone. Having having solved the immediate problem we haven't investigated much further yet. Not sure what exactly you mean by "other conversions"? On Tue, 5 Feb 2019 at 20:28, Merlin Moncure <mmoncure@gmail.com> wrote: > > On Thu, Jan 31, 2019 at 7:30 AM Bob Jolliffe <bobjolliffe@gmail.com> wrote: > > > > Hi Peter > > > > I did check out using ICU and the performance does indeed seem > > comparable with C locale: > > > > EXPLAIN ANALYZE select * from chart order by name COLLATE "lo-x-icu"; > > QUERY PLAN > > ------------------------------------------------------------------------------------------------------------------- > > Sort (cost=1470.65..1504.24 rows=13436 width=1203) (actual > > time=82.752..85.723 rows=13436 loops=1) > > Sort Key: name COLLATE "lo-x-icu" > > Sort Method: quicksort Memory: 6253kB > > -> Seq Scan on chart (cost=0.00..549.36 rows=13436 width=1203) > > (actual time=0.043..12.634 rows=13436 loops=1) > > Planning time: 1.610 ms > > Execution time: 96.060 ms > > (6 rows) > > > > The Laos folk have confirmed that the sort order with C locale was not > > correct. So setting the ICU locale seems to be the way forward. > > > > The problem is that this is a large java application with a great > > number of tables and queries. Also it is used in 60+ countries not > > just Laos. So we cannot simply modify the queries or table creation > > scripts directly such as in the manner above. I was hoping the > > solution would just be to set a default locale on the database > > (perhaps even und-x-icu) but I see now that this doesn't seem to be > > currently possible with postgresql 10 ie. set the locale on database > > creation to a *-icu locale. > > > > Is this also a limitation on postgresql 11? (Upgrading would be possible) > > yeah, probably. Having said that, I'm really struggling that it can > take take several minutes to sort such a small number of rows even > with location issues. I can sort rocks faster than that :-). > > Switching between various european collations, I'm seeing subsecond > sort responses for 44k records on my test box. I don't have the laos > collation installed unfortunately. Are you seeing kind of penalty in > other conversions? > > merlin
On Mon, Feb 18, 2019 at 9:49 AM Bob Jolliffe <bobjolliffe@gmail.com> wrote: > > Sorry Merlin for not replying earlier. The difference is indeed hard > to understand but it is certainly there. We altered the collation to > use on the name field in that table and the problem has gone. Having > having solved the immediate problem we haven't investigated much > further yet. > > Not sure what exactly you mean by "other conversions"? I hand tested similar query for other (generally western) collations. Did not observe anything nearly so bad. What I'm hoping is that this is some kind of weird performance issue specific to your installation; in the worst (unfortunately likely) case we are looking at something specific to your specific sort collation :(. merlin
On Wed, 20 Feb 2019 at 21:35, Merlin Moncure <mmoncure@gmail.com> wrote: > > On Mon, Feb 18, 2019 at 9:49 AM Bob Jolliffe <bobjolliffe@gmail.com> wrote: > > > > Sorry Merlin for not replying earlier. The difference is indeed hard > > to understand but it is certainly there. We altered the collation to > > use on the name field in that table and the problem has gone. Having > > having solved the immediate problem we haven't investigated much > > further yet. > > > > Not sure what exactly you mean by "other conversions"? > > > I hand tested similar query for other (generally western) collations. > Did not observe anything nearly so bad. What I'm hoping is that this > is some kind of weird performance issue specific to your installation; > in the worst (unfortunately likely) case we are looking at something > specific to your specific sort collation :(. > It seems not to be (completely) particular to the installation. Testing on different platforms we found variable speed difference between 100x and 1000x slower, but always a considerable order of magnitiude. The very slow performance comes from sorting Lao characters using en_US.UTF-8 collation.
On Wed, Feb 20, 2019 at 1:42 PM Bob Jolliffe <bobjolliffe@gmail.com> wrote: > It seems not to be (completely) particular to the installation. > Testing on different platforms we found variable speed difference > between 100x and 1000x slower, but always a considerable order of > magnitiude. The very slow performance comes from sorting Lao > characters using en_US.UTF-8 collation. I knew that some collations were slower, generally for reasons that make some sense. For example, I was aware that ICU's use of Japanese standard JIS X 4061 is particularly complicated and expensive, but produces the most useful possible result from the point of view of a Japanese speaker. Apparently glibc does not use that algorithm, and so offers less useful sort order (though it may actually be faster in that particular case). I suspect that the reasons why the Lao locale sorts so much slower may also have something to do with the intrinsic cost of supporting more complicated rules. However, it's such a ridiculously large difference that it also seems likely that somebody was disinclined to go to the effort of optimizing it. The ICU people found that to be a tractable goal, but they may have had to work at it. I also have a vague notion that there are special cases that are more or less only useful for sorting French. These complicate the implementation of UCA style algorithms. I am only speculating, based on what I've heard about other cases -- perhaps this explanation is totally wrong. I know a lot more about this stuff than most people on this mailing list, but I'm still far from being an expert. -- Peter Geoghegan
On Wed, Feb 20, 2019 at 2:25 PM Peter Geoghegan <pg@bowt.ie> wrote: > I suspect that the reasons why the Lao locale sorts so much slower may > also have something to do with the intrinsic cost of supporting more > complicated rules. I strongly suspect that it has something to do with the issue described here specifically: http://userguide.icu-project.org/collation/concepts#TOC-Thai-Lao-reordering -- Peter Geoghegan