Received: from maia.hub.org (maia-2.hub.org [200.46.204.251]) by mail.postgresql.org (Postfix) with ESMTP id 390ECB5D95B for ; Thu, 16 Jun 2011 01:35:15 -0300 (ADT) Received: from mail.postgresql.org ([200.46.204.86]) by maia.hub.org (mx1.hub.org [200.46.204.251]) (amavisd-maia, port 10024) with ESMTP id 74869-08 for ; Thu, 16 Jun 2011 04:35:02 +0000 (UTC) X-Greylist: domain auto-whitelisted by SQLgrey-1.7.6 Received: from sam.nabble.com (sam.nabble.com [216.139.236.26]) by mail.postgresql.org (Postfix) with ESMTP id F301DB5D944 for ; Thu, 16 Jun 2011 01:35:01 -0300 (ADT) Received: from [192.168.236.26] (helo=sam.nabble.com) by sam.nabble.com with esmtp (Exim 4.72) (envelope-from ) id 1QX4IG-0006XF-Dy for pgsql-performance@postgresql.org; Wed, 15 Jun 2011 21:35:00 -0700 Date: Wed, 15 Jun 2011 21:35:00 -0700 (PDT) From: bakkiya To: pgsql-performance@postgresql.org Message-ID: <1308198900426-4493567.post@n5.nabble.com> In-Reply-To: <4DF21007.2010807@postnewspapers.com.au> References: <1307506768241-4465765.post@n5.nabble.com> <4DEF037E.9020105@postnewspapers.com.au> <1307691557007-4475458.post@n5.nabble.com> <4DF21007.2010807@postnewspapers.com.au> Subject: Re: 100% CPU Utilization when we run queries. MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable X-Virus-Scanned: Maia Mailguard 1.0.1 X-Spam-Status: No, hits=1.934 tagged_above=-10 required=5 tests=BAYES_50=0.8, FREEMAIL_FROM=0.001, RFC_ABUSE_POST=0.001, T_TO_NO_BRKTS_FREEMAIL=0.01, URI_HEX=1.122 X-Spam-Level: * X-Archive-Number: 201106/136 X-Sequence-Number: 44069 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;=20 events_rpt_v3 is a view based on partition tables. Number of rows in events_rpt_v3: 57878 =20 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= =20 0 0 1 0 632108 371476 132928 1399016 0 0 3072 36 834 788 49 1 50= =20 0 0 1 0 632108 364408 132928 1405112 0 0 3072 0 795 707 49 1 50= =20 0 0 1 0 632108 357596 132928 1411944 0 0 3584 0 797 712 50 1 50= =20 0 0 1 0 632108 351148 132928 1418540 0 0 3072 0 827 768 49 1 50= =20 0 0 1 0 632108 344700 132928 1425028 0 0 3072 0 811 725 66 1 34= =20 0 0 1 0 632108 337688 132928 1431976 0 0 3584 16 829 802 49 1 50= =20 0 0 1 0 632108 330860 132928 1438808 0 0 3072 0 804 755 50 1 50= =20 0 0 1 0 632108 323916 132928 1446032 0 0 3584 0 810 738 49 1 50= =20 0 0 1 0 632108 317344 132928 1452544 0 0 3072 0 806 736 50 1 50= =20 0 0 1 0 632108 310648 132928 1459120 0 0 3584 0 793 703 49 1 50= =20 0 0 1 0 632108 304464 132928 1465488 0 0 3072 0 811 745 49 2 50= =20 0 0 1 0 632108 297396 132936 1472068 0 0 3072 12 808 715 49 1 50= =20 0 0 1 0 632108 290468 132936 1478876 0 0 3584 0 797 714 50 1 50= =20 0 0 1 0 632108 284764 132944 1484132 0 0 3072 47284 996 776 50 2 43= =20 6 0 2 0 632108 278564 132944 1490484 0 0 3072 0 813 720 58 1 41= =20 0 0 1 0 632108 272480 132944 1496684 0 0 3072 32 822 742 56 2 43= =20 0 0 1 0 632108 265800 132944 1503420 0 0 3584 0 826 743 50 1 50= =20 0 0 1 0 632108 259592 132944 1509836 0 0 3072 0 798 742 49 1 50= =20 0 0 1 0 632108 252772 132944 1516204 0 0 3072 0 771 716 58 2 40= =20 0 0 1 0 632108 245952 132944 1523052 0 0 3584 4 785 699 50 1 50= =20 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= =20 0 0 1 0 632108 233072 132944 1535908 0 0 3072 0 773 718 50 0 50= =20 0 0 1 0 632108 226128 132944 1542780 0 0 3584 0 834 769 49 1 49= =20 0 0 2 0 632108 219556 132944 1549556 0 0 3072 0 817 757 57 1 43= =20 0 0 1 0 632108 213248 132944 1555864 0 0 3072 0 798 710 57 2 40= =20 0 0 1 0 632108 206480 132944 1562492 0 0 3584 0 841 836 50 1 49= =20 0 0 1 0 632108 200000 132944 1569012 0 0 3072 0 842 809 50 1 50= =20 0 0 1 0 632108 193684 132944 1575320 0 0 3072 0 841 749 49 1 50= =20 0 0 1 0 632108 188104 132956 1580916 0 0 3584 25540 923 772 49 3 46= =20 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= =20 0 0 2 0 632108 39420 132808 1728308 0 0 3072 0 817 747 58 1 42= =20 0 0 1 0 632108 33344 132808 1734528 0 0 3072 0 760 670 56 1 43= =20 0 0 1 0 632108 82200 132280 1685904 0 0 3584 12 751 679 49 2 49= =20 1 0 1 0 632108 76496 132280 1692268 0 0 3072 0 739 672 48 2 50= =20 0 0 1 0 632108 70172 132280 1698524 0 0 3072 28 767 691 50 1 50= =20 0 0 1 0 632108 63152 132280 1705572 0 0 3584 0 785 727 49 1 50= =20 0 0 1 0 632108 57208 132280 1711568 0 0 3072 0 784 722 49 2 49= =20 0 0 2 0 632108 50884 132280 1717956 0 0 3072 0 804 711 50 1 50= =20 0 0 1 0 632108 43956 132280 1724708 0 0 3584 0 815 779 49 1 50= =20 0 0 2 0 632108 37772 132280 1731088 0 0 3072 32 814 724 56 1 43= =20 0 0 1 0 632108 30456 132280 1738260 0 0 3584 0 790 700 60 1 40= =20 0 0 1 0 632108 80056 131640 1689212 0 0 3072 0 795 716 49 2 50= =20 0 0 1 0 632108 73740 131640 1695520 0 0 3072 0 832 803 50 1 50= =20 0 0 1 0 632108 68664 131648 1700552 0 0 3072 47356 975 713 49 2 43= =20 6 0 1 0 632108 61968 131652 1707292 0 0 3584 28 817 763 49 2 50= =20 0 0 1 0 632108 56016 131652 1713424 0 0 3072 156 795 707 49 2 50= =20 0 0 1 0 632108 49692 131652 1719764 0 0 3072 0 814 755 49 1 50= =20 0 0 1 0 632108 42864 131652 1726720 0 0 3584 0 794 691 49 1 50= =20 0 0 2 0 632108 36912 131652 1732716 0 0 3072 0 794 732 58 1 41= =20 0 0 1 0 632108 91224 130992 1678484 0 0 3584 0 822 730 57 2 42= =20 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= =20 0 0 1 0 632108 78576 130992 1691260 0 0 3072 0 843 776 49 1 50= =20 0 0 1 0 632108 71756 130992 1698284 0 0 3584 0 865 792 50 0 50= =20 0 0 1 0 632108 65308 130992 1704828 0 0 3072 0 861 770 49 2 50= =20 0 0 1 0 632108 58324 130992 1711600 0 0 3584 0 866 905 49 1 50= =20 0 0 1 0 632108 51852 130992 1718008 0 0 3072 0 813 754 49 1 50= =20 0 0 1 0 632108 45496 130992 1724524 0 0 3072 0 812 737 49 1 50= =20 0 0 4 0 632108 38560 130992 1731312 0 0 3584 0 816 737 49 2 50= =20 0 0 2 0 632108 33228 131004 1736472 0 0 3072 26356 904 727 61 3 34= =20 3 0 For small tables, it is not using 100% of CPU, but the same query with limi= t 1 is also taking 100% of CPU. Explain Analyze o/p is very big. I am pasting here: Unique (cost=3D133906741.63..133916648.38 rows=3D200 width=3D516) (actual time=3D486765.451..487236.949 rows=3D35 loops=3D1) -> Sort (cost=3D133906741.63..133911695.00 rows=3D1981350 width=3D516) = (actual time=3D486765.450..487053.139 rows=3D1979735 loops=3D1) Sort Key: events_rpt_v3.init_service_comp Sort Method: external merge Disk: 46416kB -> Subquery Scan events_rpt_v3 (cost=3D131752986.71..133238999.21 rows=3D1981350 width=3D516) (actual time=3D452529.136..472555.577 rows=3D19= 79735 loops=3D1) -> Unique (cost=3D131752986.71..133219185.71 rows=3D1981350 width=3D73436) (actual time=3D452529.128..471365.258 rows=3D1979735 loops= =3D1) -> Sort (cost=3D131752986.71..131757940.09 rows=3D198= 1350 width=3D73436) (actual time=3D452529.126..460179.820 rows=3D1979735 loops= =3D1) 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=3D0.00..7167670.80 rows=3D19813= 50 width=3D73436) (actual time=3D188.427..432870.506 rows=3D1979735 loops=3D1) -> Result (cost=3D0.00..7117927.97 rows=3D1972965 width=3D73436) (actual time=3D188.427..431513.274 rows=3D197= 1352 loops=3D1) -> Append (cost=3D0.00..212550.47 rows=3D1972965 width=3D73436) (actual time=3D4.445..19200.613 rows=3D197135= 2 loops=3D1) -> Seq Scan on events=20 (cost=3D0.00..10.00 rows=3D1 width=3D73436) (actual time=3D0.000..0.000 row= s=3D0 loops=3D1) -> Seq Scan on events_p_max events (cost=3D0.00..10.00 rows=3D1 width=3D73436) (actual time=3D0.000..0= .000 rows=3D0 loops=3D1) -> Seq Scan on events_p_20110617110000 events (cost=3D0.00..10.00 rows=3D1 width=3D73436) (actual time=3D0.000..0.000 rows=3D0 loops=3D1) -> Result (cost=3D0.00..29929.33 rows=3D8= 385 width=3D73436) (actual time=3D11.691..928.277 rows=3D8383 loops=3D1) -> Append (cost=3D0.00..581.83 rows=3D8385 width=3D73436) (actual time=3D11.194..94.103 rows=3D8383 loops= =3D1) -> Seq Scan on hist_events=20 (cost=3D0.00..10.00 rows=3D1 width=3D73436) (actual time=3D0.001..0.001 row= s=3D0 loops=3D1) -> Seq Scan on hist_events_p_max hist_events (cost=3D0.00..10.00 rows=3D1 width=3D73436) = (actual time=3D0.000..0.000 rows=3D0 loops=3D1) =1E=1F -> Seq Scan on hist_events_p_20101105112519 hist_events (cost=3D0.00..212.18 rows=3D2918 width=3D62004) (actual time=3D11.192..31.355 rows=3D2918 loops=3D1) -> Seq Scan on hist_events_p_20101107112519 hist_events (cost=3D0.00..169.64 rows=3D2764 width=3D65510) (actual time=3D7.605..24.603 rows=3D2764 loops=3D1) -> Seq Scan on hist_events_p_20101104112519 hist_events (cost=3D0.00..180.01 rows=3D2701 width=3D61827) (actual time=3D19.064..37.047 rows=3D2701 loops=3D1) 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-C= PU-Utilization-when-we-run-queries-tp4465765p4493567.html Sent from the PostgreSQL - performance mailing list archive at Nabble.com.