Received: from makus.postgresql.org ([98.129.198.125]) by malur.postgresql.org with esmtp (Exim 4.72) (envelope-from ) id 1TWlaw-00025e-2C for pgsql-admin@postgresql.org; Fri, 09 Nov 2012 10:13:50 +0000 Received: from mx0.network-studio.com ([62.93.225.99]) by makus.postgresql.org with esmtp (Exim 4.72) (envelope-from ) id 1TWlat-0004IS-Sg for pgsql-admin@postgresql.org; Fri, 09 Nov 2012 10:13:48 +0000 Received: from zimbra-ne01.network-studio.com (zimbra-admin.network-studio.com [192.168.101.80]) by mx0.network-studio.com (Postfix) with ESMTP id BD07A4080D1; Fri, 9 Nov 2012 11:13:45 +0100 (CET) Received: from localhost (localhost [127.0.0.1]) by zimbra-ne01.network-studio.com (Postfix) with ESMTP id B7141DA1EA0; Fri, 9 Nov 2012 11:13:45 +0100 (CET) X-Virus-Scanned: amavisd-new at zimbra-ne01.network-studio.com Received: from zimbra-ne01.network-studio.com ([127.0.0.1]) by localhost (zimbra-ne01.network-studio.com [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id ZiRRbnOqhaqJ; Fri, 9 Nov 2012 11:13:45 +0100 (CET) Received: from zimbra-ne01.network-studio.com (zimbra-ne01.network-studio.com [192.168.101.80]) by zimbra-ne01.network-studio.com (Postfix) with ESMTP id 5054BDA1D17; Fri, 9 Nov 2012 11:13:45 +0100 (CET) Date: Fri, 9 Nov 2012 11:13:45 +0100 (CET) From: Baptiste LHOSTE To: pgsql-admin@postgresql.org Cc: cedric@2ndquadrant.com Message-ID: <494101763.9904770.1352456025242.JavaMail.root@alaloop.com> In-Reply-To: <1564515179.9216202.1352364859841.JavaMail.root@alaloop.com> Subject: Re: Autoanalyze of the autovacuum daemon ... MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-Originating-IP: [192.168.101.82] X-Mailer: Zimbra 7.2.1_GA_2790 (ZimbraWebClient - GC22 (Linux)/7.2.1_GA_2790) X-Pg-Spam-Score: -0.5 (/) X-Archive-Number: 201211/57 X-Sequence-Number: 40302 Hi, Today I consulted the log of my PostgreSQL server and I saw that autovacuum tasks took to much time to do their work. I thought that ANALYZE was a fast operation ? 2012-11-09 10:52:33 CET LOG: automatic analyze of table "flows.public.agg_t20_outgoing_a41_src_net_and_dst_net_f5" system usage: CPU 0.20s/0.63u sec elapsed 137.12 sec 2012-11-09 10:52:58 CET LOG: automatic vacuum of table "flows.public.agg_t20_outgoing_a51_src_port_and_proto_f5": index scans: 0 pages: 0 removed, 36044 remain tuples: 0 removed, 3495897 remain system usage: CPU 0.53s/0.62u sec elapsed 307.28 sec 2012-11-09 10:53:33 CET LOG: automatic analyze of table "flows.public.agg_t387_incoming_a44_dst_port_and_proto_f5" system usage: CPU 0.24s/0.46u sec elapsed 174.73 sec 2012-11-09 10:55:50 CET LOG: automatic analyze of table "flows.public.agg_t20_outgoing_a51_src_port_and_proto_f5" system usage: CPU 0.20s/0.48u sec elapsed 152.16 sec 2012-11-09 10:55:55 CET LOG: automatic vacuum of table "flows.public.agg_t387_incoming_a41_src_net_and_dst_net_f5": index scans: 0 pages: 0 removed, 29849 remain tuples: 0 removed, 1349327 remain system usage: CPU 0.35s/0.28u sec elapsed 141.52 sec 2012-11-09 10:58:18 CET LOG: automatic vacuum of table "flows.public.agg_t205_incoming_a41_src_net_and_dst_net_f5": index scans: 0 pages: 0 removed, 34435 remain tuples: 0 removed, 3339035 remain system usage: CPU 0.66s/0.55u sec elapsed 340.06 sec 2012-11-09 10:59:32 CET LOG: automatic analyze of table "flows.public.agg_t387_incoming_a41_src_net_and_dst_net_f5" system usage: CPU 0.26s/0.54u sec elapsed 216.95 sec 2012-11-09 10:59:45 CET LOG: automatic vacuum of table "flows.public.agg_t387_incoming_a44_dst_port_and_proto_f5": index scans: 0 pages: 0 removed, 28733 remain tuples: 0 removed, 1327333 remain system usage: CPU 0.24s/0.23u sec elapsed 234.73 sec 2012-11-09 11:01:24 CET LOG: automatic analyze of table "flows.public.agg_t205_incoming_a41_src_net_and_dst_net_f5" system usage: CPU 0.22s/0.55u sec elapsed 186.27 sec 2012-11-09 11:01:50 CET LOG: automatic vacuum of table "flows.public.agg_t387_incoming_a41_src_net_and_dst_net_f5": index scans: 0 pages: 0 removed, 29849 remain tuples: 0 removed, 1349527 remain system usage: CPU 0.24s/0.23u sec elapsed 124.28 sec 2012-11-09 11:02:04 CET LOG: automatic vacuum of table "flows.public.agg_t205_incoming_a40_dst_net_f5": index scans: 0 pages: 0 removed, 19817 remain tuples: 0 removed, 2008020 remain system usage: CPU 0.33s/0.40u sec elapsed 151.76 sec 2012-11-09 11:03:22 CET LOG: automatic analyze of table "flows.public.agg_t205_incoming_a40_dst_net_f5" system usage: CPU 0.14s/0.37u sec elapsed 78.40 sec 2012-11-09 11:04:11 CET LOG: automatic vacuum of table "flows.public.agg_t387_incoming_a40_dst_net_f5": index scans: 0 pages: 0 removed, 26294 remain tuples: 0 removed, 1316071 remain system usage: CPU 0.25s/0.28u sec elapsed 140.99 sec 2012-11-09 11:05:08 CET LOG: automatic vacuum of table "flows.public.agg_t20_outgoing_a39_src_net_f5": index scans: 0 pages: 0 removed, 26821 remain tuples: 0 removed, 2869526 remain system usage: CPU 0.46s/0.42u sec elapsed 223.09 sec 2012-11-09 11:05:57 CET LOG: automatic analyze of table "flows.public.agg_t387_incoming_a40_dst_net_f5" system usage: CPU 0.28s/0.43u sec elapsed 105.64 sec 2012-11-09 11:06:39 CET LOG: automatic analyze of table "flows.public.agg_t20_outgoing_a39_src_net_f5" system usage: CPU 0.27s/0.44u sec elapsed 90.82 sec Regards, Baptiste.