On 2019/01/22 09:47, David Rowley wrote: > On Tue, 22 Jan 2019 at 20:01, Imai, Yoshikazu > <imai.yoshik...@jp.fujitsu.com> wrote: >> I didn't use it yet, but I just used perf to clarify the difference of >> before and after the creation of the generic plan, and I noticed that usage >> of hash_seq_search() is increased about 3% in EXECUTE queries after the >> creation of the generic plan. >> >> What I understand so far is about 10,000 while loops at total >> (4098+4098+some extra) is needed in hash_seq_search() in EXECUTE query after >> the creation of the generic plan. >> 10,000 while loops takes about 10 microsec (of course, we can't estimate >> correct time), and the difference of the latency between 5th and 7th EXECUTE >> is about 8 microsec, I currently think this causes the difference. > > >> I don't know this problem relates to Amit-san's patch, but I'll continue to >> investigate it. > > I had another thought... when you're making a custom plan you're only > grabbing locks on partitions that were not pruned (just 1 partition in > your case), but when making the generic plan, locks will be acquired > on all partitions (all 4000 of them). This likely means that when > building the generic plan for the first time that the > LockMethodLocalHash table is expanded to fit all those locks, and > since we never shrink those down again, it'll remain that size for the > rest of your run. I imagine the reason for the slowdown is that > during LockReleaseAll(), a sequential scan is performed over the > entire > hash table. I see from looking at the hash_seq_search() code > that the value of max_bucket is pretty critical to how it'll perform. > The while ((curElem = segp[segment_ndx]) == NULL) loop will need to > run fewer times with a lower max_bucket.
Really thanks to giving the detail explanation. Yes, 10,000 while loops I mentioned is exactly scanning entire hash table in hash_seq_search() which is called in LockReleaseAll(). And I also checked expand_table() is called during building the generic plan which increases max_bucket. > > I just did a quick and crude test by throwing the following line into > the end of hash_seq_init(): > > elog(NOTICE, "%s %u", hashp->tabname, hashp->hctl->max_bucket); > > With a 5000 partition table I see: > > postgres=# set plan_cache_mode = 'auto'; > postgres=# prepare q1 (int) as select * from listp where a = $1; > postgres=# explain analyze execute q1(1); > NOTICE: Portal hash 15 > NOTICE: LOCALLOCK hash 15 > NOTICE: LOCALLOCK hash 15 > ... > <skip forward to the 6th execution> > > postgres=# explain analyze execute q1(1); > NOTICE: LOCALLOCK hash 5002 > NOTICE: Portal hash 15 > NOTICE: LOCALLOCK hash 5002 > NOTICE: LOCALLOCK hash 5002 > QUERY PLAN > -------------------------------------------------------------------------------------------------------- > Append (cost=0.00..41.94 rows=13 width=4) (actual time=0.005..0.005 > rows=0 loops=1) > -> Seq Scan on listp1 (cost=0.00..41.88 rows=13 width=4) (actual > time=0.005..0.005 rows=0 loops=1) > Filter: (a = 1) > Planning Time: 440.822 ms > Execution Time: 0.017 ms > (5 rows) > > I've not gone as far to try to recreate the performance drop you've > mentioned but I believe there's a very high chance that this is the > cause, and if so it's not for Amit to do anything with on this patch. Since expand_table() is called if we need locks more than max_bucket, I think the performance would also drop after executing the query like "select * from listp where a >= 1 and a <= 5000", but I've not tried it neither. > cause, and if so it's not for Amit to do anything with on this patch. +1 One concern I have is force_custom_plan is slower than auto in master, which is opposite result in patched. I am investigating about it, but its causes would be also in another place from Amit's patch. Thanks -- Yoshikazu Imai
