Re: 100% CPU Utilization when we run queries. - Mailing list pgsql-performance

From bakkiya
Subject Re: 100% CPU Utilization when we run queries.
Date
Msg-id 1308198900426-4493567.post@n5.nabble.com
Whole thread Raw
In response to Re: 100% CPU Utilization when we run queries.  (Craig Ringer <craig@postnewspapers.com.au>)
Responses Re: 100% CPU Utilization when we run queries.
List pgsql-performance
Hi,
Sorry. I am posting the query details below.
Query:
SELECT DISTINCT events_rpt_v3.init_service_comp FROM public.events_rpt_v3
events_rpt_v3;
events_rpt_v3 is a view based on partition tables.
Number of rows in events_rpt_v3: 57878

vmstat o/p:
procs -----------memory---------- ---swap-- -----io---- -system--
-----cpu------
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id
wa st
 1  0 632108 377948 132928 1392996    1    1    10    33    2    2  1  0 99
0  0
 1  0 632108 371476 132928 1399016    0    0  3072    36  834  788 49  1 50
0  0
 1  0 632108 364408 132928 1405112    0    0  3072     0  795  707 49  1 50
0  0
 1  0 632108 357596 132928 1411944    0    0  3584     0  797  712 50  1 50
0  0
 1  0 632108 351148 132928 1418540    0    0  3072     0  827  768 49  1 50
0  0
 1  0 632108 344700 132928 1425028    0    0  3072     0  811  725 66  1 34
0  0
 1  0 632108 337688 132928 1431976    0    0  3584    16  829  802 49  1 50
0  0
 1  0 632108 330860 132928 1438808    0    0  3072     0  804  755 50  1 50
0  0
 1  0 632108 323916 132928 1446032    0    0  3584     0  810  738 49  1 50
0  0
 1  0 632108 317344 132928 1452544    0    0  3072     0  806  736 50  1 50
0  0
 1  0 632108 310648 132928 1459120    0    0  3584     0  793  703 49  1 50
0  0
 1  0 632108 304464 132928 1465488    0    0  3072     0  811  745 49  2 50
0  0
 1  0 632108 297396 132936 1472068    0    0  3072    12  808  715 49  1 50
0  0
 1  0 632108 290468 132936 1478876    0    0  3584     0  797  714 50  1 50
0  0
 1  0 632108 284764 132944 1484132    0    0  3072 47284  996  776 50  2 43
6  0
 2  0 632108 278564 132944 1490484    0    0  3072     0  813  720 58  1 41
0  0
 1  0 632108 272480 132944 1496684    0    0  3072    32  822  742 56  2 43
0  0
 1  0 632108 265800 132944 1503420    0    0  3584     0  826  743 50  1 50
0  0
 1  0 632108 259592 132944 1509836    0    0  3072     0  798  742 49  1 50
0  0
 1  0 632108 252772 132944 1516204    0    0  3072     0  771  716 58  2 40
0  0
 1  0 632108 245952 132944 1523052    0    0  3584     4  785  699 50  1 50
0  0
procs -----------memory---------- ---swap-- -----io---- -system--
-----cpu------
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id
wa st
 1  0 632108 239380 132944 1529576    0    0  3072 21796  832  649 49  2 49
0  0
 1  0 632108 233072 132944 1535908    0    0  3072     0  773  718 50  0 50
0  0
 1  0 632108 226128 132944 1542780    0    0  3584     0  834  769 49  1 49
0  0
 2  0 632108 219556 132944 1549556    0    0  3072     0  817  757 57  1 43
0  0
 1  0 632108 213248 132944 1555864    0    0  3072     0  798  710 57  2 40
0  0
 1  0 632108 206480 132944 1562492    0    0  3584     0  841  836 50  1 49
0  0
 1  0 632108 200000 132944 1569012    0    0  3072     0  842  809 50  1 50
0  0
 1  0 632108 193684 132944 1575320    0    0  3072     0  841  749 49  1 50
0  0
 1  0 632108 188104 132956 1580916    0    0  3584 25540  923  772 49  3 46
3  0

novell@wdhsen01:~> vmstat 1 30
procs -----------memory---------- ---swap-- -----io---- -system--
-----cpu------
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id
wa st
 1  0 632108  45496 132808 1721868    1    1    10    33    2    2  1  0 99
0  0
 2  0 632108  39420 132808 1728308    0    0  3072     0  817  747 58  1 42
0  0
 1  0 632108  33344 132808 1734528    0    0  3072     0  760  670 56  1 43
0  0
 1  0 632108  82200 132280 1685904    0    0  3584    12  751  679 49  2 49
1  0
 1  0 632108  76496 132280 1692268    0    0  3072     0  739  672 48  2 50
0  0
 1  0 632108  70172 132280 1698524    0    0  3072    28  767  691 50  1 50
0  0
 1  0 632108  63152 132280 1705572    0    0  3584     0  785  727 49  1 50
0  0
 1  0 632108  57208 132280 1711568    0    0  3072     0  784  722 49  2 49
0  0
 2  0 632108  50884 132280 1717956    0    0  3072     0  804  711 50  1 50
0  0
 1  0 632108  43956 132280 1724708    0    0  3584     0  815  779 49  1 50
0  0
 2  0 632108  37772 132280 1731088    0    0  3072    32  814  724 56  1 43
0  0
 1  0 632108  30456 132280 1738260    0    0  3584     0  790  700 60  1 40
0  0
 1  0 632108  80056 131640 1689212    0    0  3072     0  795  716 49  2 50
0  0
 1  0 632108  73740 131640 1695520    0    0  3072     0  832  803 50  1 50
0  0
 1  0 632108  68664 131648 1700552    0    0  3072 47356  975  713 49  2 43
6  0
 1  0 632108  61968 131652 1707292    0    0  3584    28  817  763 49  2 50
0  0
 1  0 632108  56016 131652 1713424    0    0  3072   156  795  707 49  2 50
0  0
 1  0 632108  49692 131652 1719764    0    0  3072     0  814  755 49  1 50
0  0
 1  0 632108  42864 131652 1726720    0    0  3584     0  794  691 49  1 50
0  0
 2  0 632108  36912 131652 1732716    0    0  3072     0  794  732 58  1 41
0  0
 1  0 632108  91224 130992 1678484    0    0  3584     0  822  730 57  2 42
0  0
procs -----------memory---------- ---swap-- -----io---- -system--
-----cpu------
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id
wa st
 1  0 632108  84900 130992 1685028    0    0  3072 22412  924  761 49  1 50
0  0
 1  0 632108  78576 130992 1691260    0    0  3072     0  843  776 49  1 50
0  0
 1  0 632108  71756 130992 1698284    0    0  3584     0  865  792 50  0 50
0  0
 1  0 632108  65308 130992 1704828    0    0  3072     0  861  770 49  2 50
0  0
 1  0 632108  58324 130992 1711600    0    0  3584     0  866  905 49  1 50
0  0
 1  0 632108  51852 130992 1718008    0    0  3072     0  813  754 49  1 50
0  0
 1  0 632108  45496 130992 1724524    0    0  3072     0  812  737 49  1 50
0  0
 4  0 632108  38560 130992 1731312    0    0  3584     0  816  737 49  2 50
0  0
 2  0 632108  33228 131004 1736472    0    0  3072 26356  904  727 61  3 34
3  0

For small tables, it is not using 100% of CPU, but the same query with limit
1 is also taking 100% of CPU.
 Explain Analyze o/p is very big. I am pasting here:

Unique  (cost=133906741.63..133916648.38 rows=200 width=516) (actual
time=486765.451..487236.949 rows=35 loops=1)
  ->  Sort  (cost=133906741.63..133911695.00 rows=1981350 width=516) (actual
time=486765.450..487053.139 rows=1979735 loops=1)
        Sort Key: events_rpt_v3.init_service_comp
        Sort Method:  external merge  Disk: 46416kB
        ->  Subquery Scan events_rpt_v3  (cost=131752986.71..133238999.21
rows=1981350 width=516) (actual time=452529.136..472555.577 rows=1979735
loops=1)
              ->  Unique  (cost=131752986.71..133219185.71 rows=1981350
width=73436) (actual time=452529.128..471365.258 rows=1979735 loops=1)
                    ->  Sort  (cost=131752986.71..131757940.09 rows=1981350
width=73436) (actual time=452529.126..460179.820 rows=1979735 loops=1)

                        Sort Key: public.events.evt_id, public.events.res,
public.events.sres, public.events.sev, public.events.evt_time,
public.events.evt_time, public.events.device_evt_time,
public.events.sentinel_process_time, public.events.begin_time,
public.events.end_time, public.events.repeat_cnt, public.events.dp_int,
public.events.sp_int, public.events.msg, public.events.evt,
public.events.et, public.events.cust_id, public.events.src_asset_id,
public.events.dest_asset_id, public.events.agent_id, public.events.prtcl_id,
public.events.arch_id, public.events.sip, (to_ip_char(public.events.sip)),
public.events.shn, public.events.sp, public.events.dip,
(to_ip_char(public.events.dip)), public.events.dhn, public.events.dp,
public.events.sun, public.events.dun, public.events.fn, public.events.ei,
public.events.init_usr_sys_id, public.events.init_usr_identity_guid,
public.events.trgt_usr_sys_id, public.events.trgt_usr_identity_guid,

                         Sort Method:  external merge  Disk: 1504224kB
                          ->  Append  (cost=0.00..7167670.80 rows=1981350
width=73436) (actual time=188.427..432870.506 rows=1979735 loops=1)
                                ->  Result  (cost=0.00..7117927.97
rows=1972965 width=73436) (actual time=188.427..431513.274 rows=1971352
loops=1)
                                      ->  Append  (cost=0.00..212550.47
rows=1972965 width=73436) (actual time=4.445..19200.613 rows=1971352
loops=1)
                                            ->  Seq Scan on events
(cost=0.00..10.00 rows=1 width=73436) (actual time=0.000..0.000 rows=0
loops=1)
                                            ->  Seq Scan on events_p_max
events  (cost=0.00..10.00 rows=1 width=73436) (actual time=0.000..0.000
rows=0 loops=1)
                                            ->  Seq Scan on
events_p_20110617110000 events  (cost=0.00..10.00 rows=1 width=73436)
(actual time=0.000..0.000 rows=0 loops=1)
                                ->  Result  (cost=0.00..29929.33 rows=8385
width=73436) (actual time=11.691..928.277 rows=8383 loops=1)
                                      ->  Append  (cost=0.00..581.83
rows=8385 width=73436) (actual time=11.194..94.103 rows=8383 loops=1)
                                            ->  Seq Scan on hist_events
(cost=0.00..10.00 rows=1 width=73436) (actual time=0.001..0.001 rows=0
loops=1)
                                            ->  Seq Scan on
hist_events_p_max hist_events  (cost=0.00..10.00 rows=1 width=73436) (actual
time=0.000..0.000 rows=0 loops=1)

                                            ->  Seq Scan on
hist_events_p_20101105112519 hist_events  (cost=0.00..212.18 rows=2918
width=62004) (actual time=11.192..31.355 rows=2918 loops=1)
                                            ->  Seq Scan on
hist_events_p_20101107112519 hist_events  (cost=0.00..169.64 rows=2764
width=65510) (actual time=7.605..24.603 rows=2764 loops=1)
                                            ->  Seq Scan on
hist_events_p_20101104112519 hist_events  (cost=0.00..180.01 rows=2701
width=61827) (actual time=19.064..37.047 rows=2701 loops=1)
Total runtime: 487423.797 ms

I have started vaccuum analyzing all the partitions, I will run the query
and post the results once it is done.



--
View this message in context:
http://postgresql.1045698.n5.nabble.com/100-CPU-Utilization-when-we-run-queries-tp4465765p4493567.html
Sent from the PostgreSQL - performance mailing list archive at Nabble.com.

pgsql-performance by date:

Previous
From: Svetlin Manavski
Date:
Subject: Re: need to repeat the same condition on joined tables in order to choose the proper plan
Next
From: Haestan
Date:
Subject: Performance advice for a new low(er)-power server