Received: from localhost (maia-2.hub.org [200.46.204.187]) by postgresql.org (Postfix) with ESMTP id 3F1569FB3E6 for ; Tue, 5 Jun 2007 11:16:43 -0300 (ADT) Received: from postgresql.org ([200.46.204.71]) by localhost (mx1.hub.org [200.46.204.187]) (amavisd-maia, port 10024) with ESMTP id 21844-05-3 for ; Tue, 5 Jun 2007 11:16:31 -0300 (ADT) X-Greylist: from auto-whitelisted by SQLgrey-1.7.4 Received: from nabagan.bluegap.ch (nabagan.bluegap.ch [88.198.58.248]) by postgresql.org (Postfix) with ESMTP id BB1599FB4F0 for ; Tue, 5 Jun 2007 11:16:36 -0300 (ADT) Received: from [192.168.77.28] (p54bd8ae4.dip0.t-ipconnect.de [::ffff:84.189.138.228]) (AUTH: CRAM-MD5 markus@bluegap.ch, TLS: TLSv1/SSLv3, 256bits, AES256-SHA) by nabagan.bluegap.ch with esmtp; Tue, 05 Jun 2007 17:10:43 +0200 id 00604446.46657CF3.00000F19 Message-ID: <4665703E.3040905@bluegap.ch> Date: Tue, 05 Jun 2007 16:16:30 +0200 From: Markus Schiltknecht User-Agent: Icedove 1.5.0.10 (X11/20070329) MIME-Version: 1.0 To: Heikki Linnakangas CC: pgsql-performance@postgresql.org Subject: Re: dbt2 NOTPM numbers References: <466428F7.5010808@bluegap.ch> <46642B33.6030101@enterprisedb.com> <46642F2E.3080509@bluegap.ch> <4664748B.2060304@enterprisedb.com> In-Reply-To: <4664748B.2060304@enterprisedb.com> Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit X-Virus-Scanned: Maia Mailguard 1.0.1 X-Archive-Number: 200706/65 X-Sequence-Number: 25098 Hi, Heikki Linnakangas wrote: > I still suspect there's something wrong with plans, I doubt you can get > that bad performance unless it's doing something really stupid. Agreed, but I'm still looking for that really stupid thing... AFAICT, there are really no seqscans..., see the pg_stat_user_tables below. > I'd > suggest setting log_min_duration_statement = 5000, and seeing what you > get. Also check pg_stat_user_table.seq_scan just to be extra sure > there's no seq scans. I've also added some of the log messages for min_duration_statement below. Both were taken after two or three test runs. I'm really wondering, if the RAID 6 of the ARECA 1260 hurts so badly. That would be disappointing, IMO. I'll try if I can reconfigure it to do RAID 1+0, and then test again. (Unfortunately the box has already been shipped to the customer, so that's getting tricky to do via ssh..:-( ). Regards Markus *** pg_stat_user_tables *** relid | schemaname | relname | seq_scan | seq_tup_read | idx_scan | idx_tup_fetch | n_tup_ins | n_tup_upd | n_tup_del | last_vacuum | last_autovacuum | last_analyze | last_autoanalyze -------+------------+------------+----------+--------------+----------+---------------+-----------+-----------+-----------+-------------+-------------------------------+--------------+------------------------------- 16390 | public | district | 0 | 0 | 206335 | 206335 | 0 | 100771 | 0 | | 2007-06-05 15:40:44.39573+02 | | 2007-06-05 15:39:41.636736+02 16396 | public | new_order | 0 | 0 | 91860 | 41402317 | 51372 | 0 | 45844 | | | | 16400 | public | order_line | 0 | 0 | 101195 | 933197 | 538442 | 436140 | 0 | | | | 16402 | public | item | 0 | 0 | 538942 | 538442 | 0 | 0 | 0 | | | | 16404 | public | stock | 0 | 0 | 1093528 | 1077782 | 0 | 538442 | 0 | | | | 16394 | public | history | 0 | 0 | | | 49399 | 0 | 0 | | | | 16388 | public | warehouse | 0 | 0 | 150170 | 150170 | 0 | 49399 | 0 | | 2007-06-05 15:39:41.059572+02 | | 2007-06-05 15:38:39.976122+02 16398 | public | orders | 0 | 0 | 96490 | 96519 | 51372 | 45930 | 0 | | | | 16392 | public | customer | 0 | 0 | 233263 | 599917 | 0 | 95329 | 0 | | | | *** database log snippet *** 2007-06-05 15:42:09 CEST LOG: duration: 6020.820 ms statement: SELECT * FROM order_status(1747, 291, 3, '') 2007-06-05 15:42:09 CEST LOG: duration: 688.730 ms statement: SELECT payment(47, 2, 1533, 47, 2, '', 4295.460000) 2007-06-05 15:42:09 CEST LOG: duration: 5923.518 ms statement: SELECT payment(319, 8, 0, 319, 8, 'OUGHTATIONEING', 2331.470000) 2007-06-05 15:42:09 CEST LOG: duration: 6370.433 ms statement: FETCH ALL IN mycursor 2007-06-05 15:42:09 CEST LOG: duration: 6463.583 ms statement: FETCH ALL IN mycursor 2007-06-05 15:42:09 CEST LOG: duration: 6358.047 ms statement: FETCH ALL IN mycursor 2007-06-05 15:42:09 CEST LOG: duration: 6114.972 ms statement: FETCH ALL IN mycursor 2007-06-05 15:42:09 CEST LOG: duration: 6193.684 ms statement: SELECT payment(96, 10, 0, 96, 10, 'ESEOUGHTBAR', 997.050000) 2007-06-05 15:42:09 CEST LOG: duration: 6375.163 ms statement: FETCH ALL IN mycursor 2007-06-05 15:42:09 CEST LOG: duration: 6139.613 ms statement: SELECT payment(454, 8, 0, 454, 8, 'ANTIOUGHTEING', 1575.110000) 2007-06-05 15:42:09 CEST LOG: duration: 6336.462 ms statement: FETCH ALL IN mycursor 2007-06-05 15:42:09 CEST LOG: duration: 6420.227 ms statement: FETCH ALL IN mycursor 2007-06-05 15:42:09 CEST LOG: duration: 6447.025 ms statement: FETCH ALL IN mycursor 2007-06-05 15:42:09 CEST LOG: duration: 15549.277 ms statement: SELECT delivery(124, 7) 2007-06-05 15:42:09 CEST LOG: duration: 1432.199 ms statement: FETCH ALL IN mycursor 2007-06-05 15:42:09 CEST LOG: duration: 6478.086 ms statement: FETCH ALL IN mycursor 2007-06-05 15:42:09 CEST LOG: duration: 1405.925 ms statement: FETCH ALL IN mycursor 2007-06-05 15:42:09 CEST LOG: duration: 8399.567 ms statement: SELECT delivery(374, 4) 2007-06-05 15:42:10 CEST LOG: duration: 657.939 ms statement: FETCH ALL IN mycursor 2007-06-05 15:42:10 CEST LOG: duration: 1159.131 ms statement: FETCH ALL IN mycursor 2007-06-05 15:42:10 CEST LOG: duration: 840.907 ms statement: FETCH ALL IN mycursor 2007-06-05 15:42:10 CEST LOG: duration: 616.234 ms statement: FETCH ALL IN mycursor 2007-06-05 15:42:10 CEST LOG: duration: 1115.098 ms statement: FETCH ALL IN mycursor 2007-06-05 15:42:10 CEST LOG: duration: 1332.445 ms statement: SELECT payment(465, 6, 0, 465, 6, 'ABLEESEESE', 4660.790000) 2007-06-05 15:42:10 CEST LOG: duration: 855.661 ms statement: SELECT payment(267, 6, 0, 267, 6, 'OUGHTEINGOUGHT', 4214.080000) 2007-06-05 15:42:10 CEST LOG: duration: 580.983 ms statement: FETCH ALL IN mycursor 2007-06-05 15:42:10 CEST LOG: duration: 883.528 ms statement: FETCH ALL IN mycursor 2007-06-05 15:42:10 CEST LOG: duration: 7757.581 ms statement: SELECT delivery(126, 6) 2007-06-05 15:42:10 CEST LOG: duration: 537.642 ms statement: SELECT payment(493, 2, 0, 493, 2, 'BARBARANTI', 2881.500000) 2007-06-05 15:42:10 CEST LOG: duration: 1035.529 ms statement: FETCH ALL IN mycursor 2007-06-05 15:42:10 CEST LOG: duration: 1007.521 ms statement: FETCH ALL IN mycursor 2007-06-05 15:42:11 CEST LOG: duration: 1088.356 ms statement: FETCH ALL IN mycursor 2007-06-05 15:42:11 CEST LOG: duration: 1749.507 ms statement: SELECT delivery(442, 5)