Received: from maia.hub.org (maia-2.hub.org [200.46.204.251]) by mail.postgresql.org (Postfix) with ESMTP id AC9CFB5DEFC for ; Thu, 26 May 2011 15:46:37 -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 08064-02-5 for ; Thu, 26 May 2011 18:46:30 +0000 (UTC) X-Greylist: delayed 00:25:50.032546 by SQLgrey-1.7.6 Received: from out1.mail.amis.hr (out1.mail.amis.hr [188.129.0.4]) by mail.postgresql.org (Postfix) with ESMTP id B723CB5DD77 for ; Thu, 26 May 2011 15:45:20 -0300 (ADT) Received: from out.fsec.sm.srv.amis.hr (out.fsec.sm.srv.amis.hr [192.168.106.22]) by out1.mail.amis.hr (Postfix) with ESMTP id A676221742 for ; Thu, 26 May 2011 20:19:28 +0200 (CEST) Received: from pps.filterd (out [127.0.0.1]) by out.fsec.sm.srv.amis.hr (8.14.3/8.14.3) with SMTP id p4QHWlkm011020 for ; Thu, 26 May 2011 20:19:28 +0200 Received: from smtp.amis.hr (smtp.sm.srv.amis.hr [192.168.106.39]) by out.fsec.sm.srv.amis.hr with ESMTP id whq4k05mn-1 for ; Thu, 26 May 2011 20:19:28 +0200 A-Original-Client-UID: 188.129.68.234 splivalo Received: from [192.168.10.1] (cpe-188-129-68-234.dynamic.amis.hr [188.129.68.234]) (using TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)) (No client certificate requested) (Authenticated sender: splivalo) by smtp.amis.hr (Postfix) with ESMTPSA id 3C3F7265 for ; Thu, 26 May 2011 20:19:28 +0200 (CEST) Message-ID: <4DDE99B1.6010402@megafon.hr> Date: Thu, 26 May 2011 20:19:29 +0200 From: Mario Splivalo User-Agent: Mozilla/5.0 (X11; U; Linux x86_64; en-US; rv:1.9.2.17) Gecko/20110424 Thunderbird/3.1.10 MIME-Version: 1.0 To: pgsql-admin@postgresql.org Subject: COMMIT takes long time for read only transaction Content-Type: text/plain; charset=UTF-8; format=flowed Content-Transfer-Encoding: 7bit X-Proofpoint-Virus-Version: vendor=fsecure engine=2.50.10432:5.4.6813, 1.0.148, 0.0.0000 definitions=2011-05-26_03:2011-05-26, 2011-05-26, 1970-01-01 signatures=0 X-Proofpoint-Spam-Details: rule=notspam policy=default score=1 spamscore=1 ipscore=0 suspectscore=1 phishscore=0 bulkscore=0 adultscore=0 classifier=spam adjust=0 reason=mlx engine=6.0.2-1012030000 definitions=main-1105260078 X-Virus-Scanned: Maia Mailguard 1.0.1 X-Spam-Status: No, hits=-1.9 tagged_above=-10 required=5 tests=BAYES_00=-1.9 X-Spam-Level: X-Archive-Number: 201105/170 X-Sequence-Number: 37607 Hi, all. Postgres 8.4.4, quite often I have situation like this: 011-05-26 18:25:38.842 CEST [16163] [192.168.1.5(32431)] SET LOG: duration: 0.029 ms statement: BEGIN; SET TRANSACTION ISOLATION LEVEL READ COMMITTED 2011-05-26 18:25:38.843 CEST [16163] [192.168.1.5(32431)] SELECT LOG: duration: 0.259 ms statement: SELECT 2011-05-26 18:25:38.847 CEST [16163] [192.168.1.5(32431)] SELECT LOG: duration: 2.205 ms statement: SELECT 2011-05-26 18:25:38.850 CEST [16163] [192.168.1.5(32431)] SELECT LOG: duration: 0.185 ms statement: SELECT 2011-05-26 18:25:39.250 CEST [16163] [192.168.1.5(32431)] SELECT LOG: duration: 0.232 ms statement: SELECT 2011-05-26 18:25:39.252 CEST [16163] [192.168.1.5(32431)] SELECT LOG: duration: 0.289 ms statement: SELECT 2011-05-26 18:25:39.255 CEST [16163] [192.168.1.5(32431)] SELECT LOG: duration: 0.639 ms statement: SELECT 2011-05-26 18:25:39.257 CEST [16163] [192.168.1.5(32431)] SELECT LOG: duration: 0.135 ms statement: SELECT 2011-05-26 18:25:39.258 CEST [16163] [192.168.1.5(32431)] SELECT LOG: duration: 0.156 ms statement: SELECT 2011-05-26 18:25:51.624 CEST [16163] [192.168.1.5(32431)] COMMIT LOG: duration: 11159.202 ms statement: COMMIT 2011-05-26 18:26:05.788 CEST [16163] [192.168.1.5(32431)] COMMIT LOG: duration: 326.856 ms statement: COMMIT This is a grep from a postgres log when I had logging of all statements enabled. I did grep by the local pid (16163), and what I don't understand is: - why is first COMMIT taking 11 seconds, when there are only SELECTs in the transaction? SELECTS don't call any user defined functions, just plain reads from the tables. - what is that second COMMIT? If I issue COMMIT without 'BEGIN' shouldn't I get: "COMMIT WARNING: there is no transaction in progress" Mario