Re: big select is resulting in a large amount of disk writing by kjournald

Hint bit I/O?

Ken

On Wed, Dec 09, 2009 at 01:29:00PM -0500, Joseph S wrote:
> I just installed a shiny new database server with pg 8.4.1 running on
> CentOS 5.4. After using slony to replicate over my database I decided to
> do some basic performance tests to see how spiffy my shiny new server is.
> This machine has 32G ram, over 31 of which is used for the system file
> cache.
>
> So I run "select count(*) from large_table" and I see in xosview a solid
> block of write activity. Runtime is 28125.644 ms for the first run. The
> second run does not show a block of write activity and takes 3327.441 ms
>
> top shows that this writing is being done by kjournald. What is going on
> here? There is not a lot of write activity on this server so there should
> not be a significant number of dirty cache pages that kjournald would need
> to write out before it could read in my table. Certainly in the 31G being
> used for file cache there should be enough non-dirty pages that could be
> dropped to read in my table w/o having to flush anything to disk. My table
> size is 2,870,927,360 bytes.
>
> # cat /proc/sys/vm/dirty_expire_centisecs
> 2999
>
> I restarted postgres and ran a count(*) on an even larger table.
>
> [local]=> explain analyze select count(*) from et;
> QUERY PLAN
> -----------------------------------------------------------------------------------------------------------------------------------
> Aggregate (cost=6837051.82..6837051.83 rows=1 width=0) (actual
> time=447240.157..447240.157 rows=1 loops=1)
> -> Seq Scan on et (cost=0.00..6290689.25 rows=218545025 width=0)
> (actual time=5.971..400326.911 rows=218494524 loops=1)
> Total runtime: 447240.402 ms
> (3 rows)
>
> Time: 447258.525 ms
> [local]=> explain analyze select count(*) from et;
> QUERY PLAN
> ----------------------------------------------------------------------------------------------------------------------------------
> Aggregate (cost=6837113.44..6837113.45 rows=1 width=0) (actual
> time=103011.724..103011.724 rows=1 loops=1)
> -> Seq Scan on et (cost=0.00..6290745.95 rows=218546995 width=0)
> (actual time=9.844..71629.497 rows=218496012 loops=1)
> Total runtime: 103011.832 ms
> (3 rows)
>
> Time: 103012.523 ms
>
> [local]=> select pg_relation_size('et');
> pg_relation_size
> ------------------
> 33631543296
> (1 row)
>
>
> I posted xosview snapshots from the two runs at:
> http://www.tupari.net/2009-12-9/ This time the first run showed a mix of
> read/write activity instead of the solid write I saw before.
>
> --
> Sent via pgsql-performance mailing list (pgsql-performance(at)postgresql(dot)org)
> To make changes to your subscription:
> http://www.postgresql.org/mailpref/pgsql-performance
>