Re: 9.4 regression - Mailing list pgsql-hackers

On 8 August 2013 04:05, Andres Freund <andres@2ndquadrant.com> wrote:
> On 2013-08-07 20:23:55 +0100, Thom Brown wrote:
>> >>> 269e78 was the commit immediately after 8800d8, so it appears that
>> >>> introduced the regression.
>> >>>
>> >>> "Use posix_fallocate() for new WAL files, where available."
>> >>
>> >> This is curious. Could you either run a longer test before/after the
>> >> commit or reduce checkpoint_timeout to something like 3min?
>> >
>> > Okay, I'll rerun the test for both those commits at 1 hour each with
>> > checkpoint_timeout set at 3mins, but with all other configuration
>> > settings the same
>>
>> Results
>> (checkpoint_timeout = 3min)
>>
>> pgbench -j 80 -c 80 -T 3600
>>
>> 269e78: 606.268013
>> 8800d8: 779.583129
>
> Ok, so the performance difference is lower. But, it seems to be still to
> high to be explaineable by performance differences during
> initialization/fallocate.
> In a very quick test, I don't see the same on my laptop. I am currently
> travelling and I don't have convenient access to anything else.
>
> Could you:
> - run filefrag on a couple of wal segments of both clusters after the
>   test and post the results here?

I ran a benchmark for 10 minutes.  I ran filefrag against all files in pg_xlog and they all say "1 extent found"

> - enable log_checkpoints, post the lines spat out together with the results

LOG:  database system was shut down at 2013-08-08 16:38:28 BST
LOG:  database system is ready to accept connections
LOG:  autovacuum launcher started
LOG:  checkpoint starting: immediate force wait
LOG:  checkpoint complete: wrote 3 buffers (0.0%); 0 transaction log file(s) added, 0 removed, 0 recycled; write=0.041 s, sync=0.034 s, total=0.132 s; sync files=3, longest=0.017 s, average=0.011 s
LOG:  checkpoint starting: immediate force wait
LOG:  checkpoint complete: wrote 0 buffers (0.0%); 0 transaction log file(s) added, 0 removed, 0 recycled; write=0.015 s, sync=0.000 s, total=0.071 s; sync files=0, longest=0.000 s, average=0.000 s
LOG:  checkpoint starting: time
LOG:  checkpoint complete: wrote 39137 buffers (7.5%); 0 transaction log file(s) added, 0 removed, 0 recycled; write=143.757 s, sync=5.659 s, total=149.620 s; sync files=44, longest=3.814 s, average=0.128 s
LOG:  checkpoint starting: time
LOG:  checkpoint complete: wrote 21141 buffers (4.0%); 0 transaction log file(s) added, 0 removed, 15 recycled; write=143.082 s, sync=13.144 s, total=156.421 s; sync files=13, longest=10.336 s, average=1.011 s
LOG:  checkpoint starting: time
LOG:  checkpoint complete: wrote 27702 buffers (5.3%); 0 transaction log file(s) added, 0 removed, 15 recycled; write=143.739 s, sync=4.470 s, total=148.337 s; sync files=12, longest=2.545 s, average=0.372 s
LOG:  checkpoint starting: time

> - run pgbench without reinitializing the cluster/pgbench tables
>   inbetween?

Set 1 (10 mins each):
First run after initialisation: 289.410795