Re: high CPU usage for stats collector in 8.2 - Mailing list pgsql-hackers

Darcy Buskermolen wrote:
> I'm observing high CPU usage (95%) of a 2.6GHz opteron by the stats collector 
> on an 8.2.3 box  investigation has lead me to belive that the stats file is 
> written a lot more often that once every 500ms  the following shows this 
> behavior.

Any thoughts on the below?

> 
> PostgreSQL 8.2.3 on x86_64-redhat-linux-gnu, compiled by GCC gcc (GCC) 3.4.6 
> 20060404 (Red Hat 3.4.6-3)
> 
> I ran a 
> time for i in `psql -qtc "select generate_series(1,10000)"`; do psql  -qtc 
> "select 1 from test where msg_id=$i" ; done
> 
> which took
> real    1m23.288s
> user    0m24.142s
> sys     0m21.536s
> 
> 
> to execute, during which time I ran a strace on the stats collector which 
> produces the following output.  From this it looks like the stats file is 
> getting rewritten for each connection teardown, not just every 500ms.
> 
> Process 10061 attached - interrupt to quit
> Process 10061 detached
> % time     seconds  usecs/call     calls    errors syscall
> ------ ----------- ----------- --------- --------- ----------------
>  68.14   28.811963          17   1663827           write
>  18.22    7.701885         123     62808     12793 poll
>  11.31    4.783082         365     13101           rename
>   0.58    0.246169           5     50006           recvfrom
>   0.57    0.241073          18     13101           open
>   0.43    0.182816          14     13101           munmap
>   0.18    0.076176           6     13101           mmap
>   0.17    0.072746           6     13101           close
>   0.14    0.060483           5     13101           setitimer
>   0.10    0.041344           3     13101     12793 rt_sigreturn
>   0.09    0.039240           3     13101           fstat
>   0.06    0.024041           2     13110           getppid
> ------ ----------- ----------- --------- --------- ----------------
> 100.00   42.281018               1894559     25586 total
> 
> As you can see rename was called more than the theroitcal 167  times for 500ms 
> slices that elapsed during the test
> 
> Compared to  PostgreSQL 8.1.8 on x86_64-pc-linux-gnu, compiled by GCC 
> gcc-4.0.gcc-opt (GCC) 4.0.3 (Ubuntu 4.0.3-1ubuntu5) 
> [All be it this is slower hardware..]
> 
> time for i in `psql -qtc "select generate_series(1,10000)"`; do psql  -qtc 
> "select 1 from test where msg_id=$i" ; done
> 
> which took
> real    9m25.380s
> user    6m51.254s
> sys     1m47.687s
> (and therefor should be about 1130 stat write cycles)
> 
> and yielded the following strace
> 
> % time     seconds  usecs/call     calls    errors syscall
> ------ ----------- ----------- --------- --------- ----------------
>  93.64   20.422006         334     61212           select
>   3.49    0.760963           7    110192           read
>   1.82    0.396654          19     21128           write
>   0.64    0.139679         126      1112           rename
>   0.27    0.057970          52      1112           open
>   0.06    0.012177          11      1112           munmap
>   0.04    0.008901           8      1112           mmap
>   0.03    0.006402           6      1112           close
>   0.02    0.004282           4      1112           fstat
> ------ ----------- ----------- --------- --------- ----------------
> 100.00   21.809034                199204           total
> 
> 
> 
> During this run the stats collector does not even show and CPU usage according 
> to top.
> 
> 
> both 8.1 and 8.2 have the following postgresql.conf parameters
> 
> stats_command_string =  off
> stats_start_collector = on
> stats_block_level = on
> stats_row_level = on
> 
> 
> 


-- 
     === The PostgreSQL Company: Command Prompt, Inc. ===
Sales/Support: +1.503.667.4564 || 24x7/Emergency: +1.800.492.2240
Providing the most comprehensive  PostgreSQL solutions since 1997            http://www.commandprompt.com/

Donate to the PostgreSQL Project: http://www.postgresql.org/about/donate
PostgreSQL Replication: http://www.commandprompt.com/products/