I found following mail in my mail archive and tried the same test with
7.4 current.  Contrary to my expectation 7.4 showed some performance
degration with continuous pgbench runs:

$ pgbench -c 5 -t 1000 -n test
tps = 57.444037 (including connections establishing)
tps = 57.455300 (excluding connections establishing)

$ pgbench -c 5 -t 1000 -n test
tps = 54.125785 (including connections establishing)
tps = 54.134871 (excluding connections establishing)

$pgbench -c 5 -t 1000 -n test
tps = 51.116465 (including connections establishing)
tps = 51.124878 (excluding connections establishing)

$ pgbench -c 5 -t 1000 -n test
tps = 50.410659 (including connections establishing)
tps = 50.420215 (excluding connections establishing)

$ pgbench -c 5 -t 1000 test
tps = 46.791980 (including connections establishing)
tps = 46.799837 (excluding connections establishing)

Any idea?

data is initialized by pgbench -i -s 10.
--
Tatsuo Ishii

> From: Tom Lane <tgl@sss.pgh.pa.us>
> To: pgsql-hackers@postgresql.org
> Date: Fri, 24 May 2002 16:42:55 -0400
>
> Per previous discussion, I have committed changes that cause the btree
> and hash index methods to mark index tuples "killed" the first time they
> are fetched after becoming globally dead.  Subsequently the killed
> entries are not returned out of indexscans, saving useless heap fetches.
> (I haven't changed rtree and gist yet; they will need some internal
> restructuring to do this efficiently.  Perhaps Oleg or Teodor would like
> to take that on.)
> 
> This seems to make a useful improvement in pgbench results.  Yesterday's
> CVS tip gave me these results:
> 
> (Running postmaster with "-i -F -B 1024", other parameters at defaults,
> and pgbench initialized with "pgbench -i -s 10 bench")
> 
> $ time pgbench -c 5 -t 1000 -n bench
> tps = 26.428787(including connections establishing)
> tps = 26.443410(excluding connections establishing)
> real    3:09.74
> $ time pgbench -c 5 -t 1000 -n bench
> tps = 18.838304(including connections establishing)
> tps = 18.846281(excluding connections establishing)
> real    4:26.41
> $ time pgbench -c 5 -t 1000 -n bench
> tps = 13.541641(including connections establishing)
> tps = 13.545646(excluding connections establishing)
> real    6:10.19
> 
> Note the "-n" switches here to prevent vacuums between runs; the point
> is to observe the degradation as more and more dead tuples accumulate.
> 
> With the just-committed changes I get (starting from a fresh start):
> 
> $ time pgbench -c 5 -t 1000 -n bench
> tps = 28.393271(including connections establishing)
> tps = 28.410117(excluding connections establishing)
> real    2:56.53
> $ time pgbench -c 5 -t 1000 -n bench
> tps = 23.498645(including connections establishing)
> tps = 23.510134(excluding connections establishing)
> real    3:33.89
> $ time pgbench -c 5 -t 1000 -n bench
> tps = 18.773239(including connections establishing)
> tps = 18.780936(excluding connections establishing)
> real    4:26.84
> 
> The remaining degradation is actually in seqscan performance, not
> indexscan --- unless one uses a much larger -s setting, the planner will
> think it ought to use seqscans for updating the "branches" and "tellers"
> tables, since those nominally have just a few rows; and there's no way
> to avoid scanning lots of dead tuples in a seqscan.  Forcing indexscans
> helps some in the former CVS tip:
> 
> $ PGOPTIONS="-fs" time pgbench -c 5 -t 1000 -n bench
> tps = 28.840678(including connections establishing)
> tps = 28.857442(excluding connections establishing)
> real     2:53.9
> $ PGOPTIONS="-fs" time pgbench -c 5 -t 1000 -n bench
> tps = 25.670674(including connections establishing)
> tps = 25.684493(excluding connections establishing)
> real     3:15.7
> $ PGOPTIONS="-fs" time pgbench -c 5 -t 1000 -n bench
> tps = 22.593429(including connections establishing)
> tps = 22.603928(excluding connections establishing)
> real     3:42.7
> 
> and with the changes I get:
> 
> $ PGOPTIONS=-fs time pgbench -c 5 -t 1000 -n bench
> tps = 29.445004(including connections establishing)
> tps = 29.463948(excluding connections establishing)
> real     2:50.3
> $ PGOPTIONS=-fs time pgbench -c 5 -t 1000 -n bench
> tps = 30.277968(including connections establishing)
> tps = 30.301363(excluding connections establishing)
> real     2:45.6
> $ PGOPTIONS=-fs time pgbench -c 5 -t 1000 -n bench
> tps = 30.209377(including connections establishing)
> tps = 30.230646(excluding connections establishing)
> real     2:46.0
> 
> 
> This is the first time I have ever seen repeated pgbench runs without
> substantial performance degradation.  Not a bad result for a Friday
> afternoon...
> 
> 			regards, tom lane
> 

Wed, 03 Sep 2003 00:13:17 +0900 (JST)
Tatsuo Ishii <t-ishii@sra.co.jp>
Re: Index tuple killing code committed
Forgot to mention an important thing: I set enable_seqscan = off in
postgresql.conf.

> I found following mail in my mail archive and tried the same test with
> 7.4 current.  Contrary to my expectation 7.4 showed some performance
> degration with continuous pgbench runs:
> 
> $ pgbench -c 5 -t 1000 -n test
> tps = 57.444037 (including connections establishing)
> tps = 57.455300 (excluding connections establishing)
> 
> $ pgbench -c 5 -t 1000 -n test
> tps = 54.125785 (including connections establishing)
> tps = 54.134871 (excluding connections establishing)
> 
> $pgbench -c 5 -t 1000 -n test
> tps = 51.116465 (including connections establishing)
> tps = 51.124878 (excluding connections establishing)
> 
> $ pgbench -c 5 -t 1000 -n test
> tps = 50.410659 (including connections establishing)
> tps = 50.420215 (excluding connections establishing)
> 
> $ pgbench -c 5 -t 1000 test
> tps = 46.791980 (including connections establishing)
> tps = 46.799837 (excluding connections establishing)
> 
> Any idea?
> 
> data is initialized by pgbench -i -s 10.
> --
> Tatsuo Ishii
> 
> > From: Tom Lane <tgl@sss.pgh.pa.us>
> > To: pgsql-hackers@postgresql.org
> > Date: Fri, 24 May 2002 16:42:55 -0400
> >
> > Per previous discussion, I have committed changes that cause the btree
> > and hash index methods to mark index tuples "killed" the first time they
> > are fetched after becoming globally dead.  Subsequently the killed
> > entries are not returned out of indexscans, saving useless heap fetches.
> > (I haven't changed rtree and gist yet; they will need some internal
> > restructuring to do this efficiently.  Perhaps Oleg or Teodor would like
> > to take that on.)
> > 
> > This seems to make a useful improvement in pgbench results.  Yesterday's
> > CVS tip gave me these results:
> > 
> > (Running postmaster with "-i -F -B 1024", other parameters at defaults,
> > and pgbench initialized with "pgbench -i -s 10 bench")
> > 
> > $ time pgbench -c 5 -t 1000 -n bench
> > tps = 26.428787(including connections establishing)
> > tps = 26.443410(excluding connections establishing)
> > real    3:09.74
> > $ time pgbench -c 5 -t 1000 -n bench
> > tps = 18.838304(including connections establishing)
> > tps = 18.846281(excluding connections establishing)
> > real    4:26.41
> > $ time pgbench -c 5 -t 1000 -n bench
> > tps = 13.541641(including connections establishing)
> > tps = 13.545646(excluding connections establishing)
> > real    6:10.19
> > 
> > Note the "-n" switches here to prevent vacuums between runs; the point
> > is to observe the degradation as more and more dead tuples accumulate.
> > 
> > With the just-committed changes I get (starting from a fresh start):
> > 
> > $ time pgbench -c 5 -t 1000 -n bench
> > tps = 28.393271(including connections establishing)
> > tps = 28.410117(excluding connections establishing)
> > real    2:56.53
> > $ time pgbench -c 5 -t 1000 -n bench
> > tps = 23.498645(including connections establishing)
> > tps = 23.510134(excluding connections establishing)
> > real    3:33.89
> > $ time pgbench -c 5 -t 1000 -n bench
> > tps = 18.773239(including connections establishing)
> > tps = 18.780936(excluding connections establishing)
> > real    4:26.84
> > 
> > The remaining degradation is actually in seqscan performance, not
> > indexscan --- unless one uses a much larger -s setting, the planner will
> > think it ought to use seqscans for updating the "branches" and "tellers"
> > tables, since those nominally have just a few rows; and there's no way
> > to avoid scanning lots of dead tuples in a seqscan.  Forcing indexscans
> > helps some in the former CVS tip:
> > 
> > $ PGOPTIONS="-fs" time pgbench -c 5 -t 1000 -n bench
> > tps = 28.840678(including connections establishing)
> > tps = 28.857442(excluding connections establishing)
> > real     2:53.9
> > $ PGOPTIONS="-fs" time pgbench -c 5 -t 1000 -n bench
> > tps = 25.670674(including connections establishing)
> > tps = 25.684493(excluding connections establishing)
> > real     3:15.7
> > $ PGOPTIONS="-fs" time pgbench -c 5 -t 1000 -n bench
> > tps = 22.593429(including connections establishing)
> > tps = 22.603928(excluding connections establishing)
> > real     3:42.7
> > 
> > and with the changes I get:
> > 
> > $ PGOPTIONS=-fs time pgbench -c 5 -t 1000 -n bench
> > tps = 29.445004(including connections establishing)
> > tps = 29.463948(excluding connections establishing)
> > real     2:50.3
> > $ PGOPTIONS=-fs time pgbench -c 5 -t 1000 -n bench
> > tps = 30.277968(including connections establishing)
> > tps = 30.301363(excluding connections establishing)
> > real     2:45.6
> > $ PGOPTIONS=-fs time pgbench -c 5 -t 1000 -n bench
> > tps = 30.209377(including connections establishing)
> > tps = 30.230646(excluding connections establishing)
> > real     2:46.0
> > 
> > 
> > This is the first time I have ever seen repeated pgbench runs without
> > substantial performance degradation.  Not a bad result for a Friday
> > afternoon...
> > 
> > 			regards, tom lane
> > 
> 
> ---------------------------(end of broadcast)---------------------------
> TIP 3: if posting/reading through Usenet, please send an appropriate
>       subscribe-nomail command to majordomo@postgresql.org so that your
>       message can get through to the mailing list cleanly
> 

Wed, 03 Sep 2003 00:16:21 +0900 (JST)
Tatsuo Ishii <t-ishii@sra.co.jp>
Re: Index tuple killing code committed
Tatsuo Ishii <t-ishii@sra.co.jp> writes:
> I found following mail in my mail archive and tried the same test with
> 7.4 current.  Contrary to my expectation 7.4 showed some performance
> degration with continuous pgbench runs:

I did some profiling and found that with repeated runs, an increasing
amount of time was being spent in _bt_check_unique, verifying that
updates aren't inserting duplicate keys.  This is not real surprising
when running without vacuums between runs --- the number of dead tuples
will increase from run to run.  I am not sure why the effect was not
visible in my old post that you quote.  Perhaps it was masked by some
other inefficiency and is now visible in 7.4.

I was able to reduce the cost somewhat by changing the order of tests
in _bt_check_unique.  With CVS tip, using default postmaster settings
(except fsync off) and "pgbench -i -s 10 bench" followed by a manual
CHECKPOINT command, I get this for repeated runs of
	PGOPTIONS=-fs time pgbench -c 5 -t 1000 -n bench

tps = 113.387182 (including connections establishing)
tps = 113.433897 (excluding connections establishing)
0.95user 0.86system 0:44.51elapsed 4%CPU (0avgtext+0avgdata 0maxresident)k

tps = 72.989851 (including connections establishing)
tps = 73.010209 (excluding connections establishing)
0.86user 0.89system 1:09.17elapsed 2%CPU (0avgtext+0avgdata 0maxresident)k

tps = 88.848571 (including connections establishing)
tps = 88.878369 (excluding connections establishing)
0.82user 0.92system 0:57.19elapsed 3%CPU (0avgtext+0avgdata 0maxresident)k

tps = 89.156320 (including connections establishing)
tps = 89.186299 (excluding connections establishing)
0.88user 0.92system 0:57.08elapsed 3%CPU (0avgtext+0avgdata 0maxresident)k

tps = 92.708733 (including connections establishing)
tps = 92.742335 (excluding connections establishing)
0.85user 0.83system 0:54.76elapsed 3%CPU (0avgtext+0avgdata 0maxresident)k

tps = 93.533412 (including connections establishing)
tps = 93.566385 (excluding connections establishing)
0.92user 0.87system 0:54.33elapsed 3%CPU (0avgtext+0avgdata 0maxresident)k

tps = 94.987538 (including connections establishing)
tps = 95.021715 (excluding connections establishing)
0.91user 0.88system 0:53.44elapsed 3%CPU (0avgtext+0avgdata 0maxresident)k

tps = 98.119179 (including connections establishing)
tps = 98.157492 (excluding connections establishing)
0.93user 0.94system 0:51.58elapsed 3%CPU (0avgtext+0avgdata 0maxresident)k

tps = 108.404186 (including connections establishing)
tps = 108.448242 (excluding connections establishing)
0.85user 0.90system 0:47.30elapsed 3%CPU (0avgtext+0avgdata 0maxresident)k

tps = 102.725845 (including connections establishing)
tps = 102.767392 (excluding connections establishing)
0.91user 0.90system 0:49.93elapsed 3%CPU (0avgtext+0avgdata 0maxresident)k

Not sure why the apparent up-trend in performance after the second run.
Maybe we've done about as much btree index splitting as we need, after
a few runs?  Odd.

Same conditions, but with a vacuum between runs, ie no "-n":

tps = 112.266969 (including connections establishing)
tps = 112.314017 (excluding connections establishing)
0.91user 0.89system 0:44.62elapsed 4%CPU (0avgtext+0avgdata 0maxresident)k

tps = 77.936183 (including connections establishing)
tps = 77.959810 (excluding connections establishing)
0.90user 0.92system 1:07.20elapsed 2%CPU (0avgtext+0avgdata 0maxresident)k

tps = 81.669010 (including connections establishing)
tps = 81.694586 (excluding connections establishing)
0.88user 0.87system 1:02.23elapsed 2%CPU (0avgtext+0avgdata 0maxresident)k

tps = 86.493578 (including connections establishing)
tps = 86.522430 (excluding connections establishing)
0.87user 0.83system 0:59.61elapsed 2%CPU (0avgtext+0avgdata 0maxresident)k

tps = 100.759980 (including connections establishing)
tps = 100.797922 (excluding connections establishing)
0.90user 0.89system 0:50.10elapsed 3%CPU (0avgtext+0avgdata 0maxresident)k

tps = 77.215387 (including connections establishing)
tps = 77.238131 (excluding connections establishing)
0.95user 0.88system 1:06.35elapsed 2%CPU (0avgtext+0avgdata 0maxresident)k

tps = 83.298182 (including connections establishing)
tps = 83.324866 (excluding connections establishing)
0.88user 0.89system 1:01.23elapsed 2%CPU (0avgtext+0avgdata 0maxresident)k

tps = 90.534451 (including connections establishing)
tps = 90.566022 (excluding connections establishing)
0.95user 0.86system 0:56.40elapsed 3%CPU (0avgtext+0avgdata 0maxresident)k

tps = 84.085577 (including connections establishing)
tps = 84.113060 (excluding connections establishing)
0.93user 0.89system 1:05.35elapsed 2%CPU (0avgtext+0avgdata 0maxresident)k

tps = 95.637302 (including connections establishing)
tps = 95.672293 (excluding connections establishing)
0.92user 0.85system 0:52.80elapsed 3%CPU (0avgtext+0avgdata 0maxresident)k

Same with vacuum and checkpoint between runs:

tps = 107.715226 (including connections establishing)
tps = 107.758258 (excluding connections establishing)
0.86user 0.88system 0:46.51elapsed 3%CPU (0avgtext+0avgdata 0maxresident)k

tps = 78.816549 (including connections establishing)
tps = 78.839575 (excluding connections establishing)
0.87user 0.87system 1:03.68elapsed 2%CPU (0avgtext+0avgdata 0maxresident)k

tps = 90.150489 (including connections establishing)
tps = 90.184264 (excluding connections establishing)
0.90user 0.89system 0:55.74elapsed 3%CPU (0avgtext+0avgdata 0maxresident)k

tps = 81.648951 (including connections establishing)
tps = 81.674276 (excluding connections establishing)
0.93user 0.94system 1:01.54elapsed 3%CPU (0avgtext+0avgdata 0maxresident)k

tps = 86.850517 (including connections establishing)
tps = 86.879127 (excluding connections establishing)
0.84user 0.88system 0:57.86elapsed 2%CPU (0avgtext+0avgdata 0maxresident)k

tps = 85.776988 (including connections establishing)
tps = 85.809491 (excluding connections establishing)
0.83user 0.94system 0:58.53elapsed 3%CPU (0avgtext+0avgdata 0maxresident)k

tps = 80.293178 (including connections establishing)
tps = 80.317318 (excluding connections establishing)
0.90user 0.86system 1:02.49elapsed 2%CPU (0avgtext+0avgdata 0maxresident)k

tps = 80.691960 (including connections establishing)
tps = 80.716409 (excluding connections establishing)
0.84user 0.93system 1:02.19elapsed 2%CPU (0avgtext+0avgdata 0maxresident)k

tps = 85.067751 (including connections establishing)
tps = 85.095110 (excluding connections establishing)
0.92user 0.91system 0:59.02elapsed 3%CPU (0avgtext+0avgdata 0maxresident)k

tps = 80.134553 (including connections establishing)
tps = 80.158595 (excluding connections establishing)
0.87user 0.97system 1:02.61elapsed 2%CPU (0avgtext+0avgdata 0maxresident)k

It appears that much of the run-to-run variability is accounted for by
background checkpoints; forcing a checkpoint between runs helps but
doesn't eliminate the noise.  (Probably if I'd changed the checkpoint
frequency settings to prevent intra-run checkpoints from happening,
I could get stable numbers.  I'm out of time to play with it for now
though.)

			regards, tom lane

Tue, 02 Sep 2003 19:16:42 -0400
Tom Lane <tgl@sss.pgh.pa.us>
Re: Index tuple killing code committed 