Received: from magus.postgresql.org (magus.postgresql.org [87.238.57.229]) by mail.postgresql.org (Postfix) with ESMTP id 9F337C4CD77 for ; Thu, 3 May 2012 07:21:01 -0300 (ADT) Received: from rs133.luxsci.com ([72.32.115.26]) by magus.postgresql.org with esmtp (Exim 4.72) (envelope-from ) id 1SPt9e-0000EN-6Y for pgsql-admin@postgresql.org; Thu, 03 May 2012 10:21:00 +0000 Received: from GNANAM (NSG-Static-236.156.72.182.airtel.in [182.72.156.236] (may be forged)) (authenticated bits=0) by rs133.luxsci.com (8.13.8/8.13.8) with ESMTP id q43AJtBS021289; Thu, 3 May 2012 05:20:42 -0500 Reply-To: From: "Gnanakumar" To: Subject: Very long " in transaction" query Date: Thu, 3 May 2012 15:48:35 +0530 Organization: Zoniac Software Private Limited Message-ID: <008101cd2916$1c023b20$5406b160$@com> MIME-Version: 1.0 Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: 7bit X-Mailer: Microsoft Office Outlook 12.0 Thread-Index: Ac0pFhRfqWvBF5BbRGy7dyqTUWSSyg== Content-Language: en-us x-cr-hashedpuzzle: AD/T Akul A1lE BDWA DnpY EeLR FBXm FkxM FmRg Fn4e G0Nc HFa6 HKQf Hz4c I+sE Jhtt; 1; cABnAHMAcQBsAC0AYQBkAG0AaQBuAEAAcABvAHMAdABnAHIAZQBzAHEAbAAuAG8AcgBnAA==; Sosha1_v1; 7; {D27AFC65-C3A4-4D4B-A48C-4738F9B491F7}; ZwBuAGEAbgBhAG0AQAB6AG8AbgBpAGEAYwAuAGMAbwBtAA==; Thu, 03 May 2012 10:18:27 GMT; VgBlAHIAeQAgAGwAbwBuAGcAIAAiADwASQBEAEwARQA+ACAAaQBuACAAdAByAGEAbgBzAGEAYwB0AGkAbwBuACIAIABxAHUAZQByAHkA x-cr-puzzleid: {D27AFC65-C3A4-4D4B-A48C-4738F9B491F7} X-Lux-Comment: Message q43AJtBS021289 sent by user #22393 X-Pg-Spam-Score: -0.7 (/) X-Archive-Number: 201205/13 X-Sequence-Number: 39502 Hi, Recently, in our Production server, we found a "single query" being held up in " in transaction" for more than 19 hours using the following query: select date_trunc('second', current_timestamp - query_start) as runtime, datname as database_name, current_query from pg_stat_activity where current_query != '' order by 1 desc but we're clueless which was the root cause of this issue and still hunting. As we know, query output doesn't show up the actual query/statement. We then ran the 3rd query available from PostgreSQL Wiki - Lock Monitoring http://wiki.postgresql.org/wiki/Lock_Monitoring From query result output, I could infer only the following but still not able to find out the real root cause: 1) 2 tables are involved (table1 and table2) 2) Mostly table1's indexes are appearing in the output. Pasted below result output containing only " in transaction". For security reasons, I've masked/renamed table names and index names in "relname" column. Though all index names are renamed to as "table1_xxxxx_indx", all are different index names and not the same index. Yes, we do have more than 30 indexes in table1. Can somebody help me out what is going wrong/causing these " in transaction"? datname | relname | transactionid | mode | granted | usename | substr | query_start | age | procpid ---------+-------------------------------+---------------+-----------------+ ---------+---------+--------------------------------+----------------------- --------+------------------+--------- prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table2 | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_pk | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_idx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx_indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx__indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1 | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | | 668748028 | ExclusiveLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx__indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 prodndb | table1_xxxxx__indx | | AccessShareLock | t | dbuser | in transaction | 2012-05-01 14:56:53.617912-04 | 19:20:59.644261 | 14740 But no rows were returned for the 2nd query available in PostgreSQL Wiki - Lock Monitoring. We're running PostgreSQL v8.2.22 and pgpool v3.1.1 (only connection pooling feature is used). Regards, Gnanam