Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_CBC_SHA1:256) (Exim 4.89) (envelope-from ) id 1iczZS-00022D-DU for pgsql-performance@arkaria.postgresql.org; Thu, 05 Dec 2019 22:26:02 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.89) (envelope-from ) id 1iczZQ-00050E-L7 for pgsql-performance@arkaria.postgresql.org; Thu, 05 Dec 2019 22:26:00 +0000 Received: from makus.postgresql.org ([2001:4800:3e1:1::229]) by malur.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_CBC_SHA1:256) (Exim 4.89) (envelope-from ) id 1icvCx-0001M7-Mp for pgsql-performance@lists.postgresql.org; Thu, 05 Dec 2019 17:46:31 +0000 Received: from mails1.kns.com ([199.171.180.11]) by makus.postgresql.org with esmtp (Exim 4.92) (envelope-from ) id 1icvCt-0005oj-1b for pgsql-performance@postgresql.org; Thu, 05 Dec 2019 17:46:29 +0000 X-ASG-Debug-ID: 1575567984-0a96b62acb2aa1f0001-c4zXsc Received: from USEPRDEX1.corp.kns.com (useprdex1.corp.kns.com [10.40.10.30]) by Mails1.kns.com with ESMTP id srxy8r5OQRvapy7r for ; Thu, 05 Dec 2019 12:46:24 -0500 (EST) X-Barracuda-Envelope-From: mschanne@kns.com Received: from USEPRDEX1.corp.kns.com (10.40.10.30) by USEPRDEX1.corp.kns.com (10.40.10.30) with Microsoft SMTP Server (TLS) id 15.0.1263.5; Thu, 5 Dec 2019 12:46:20 -0500 Received: from USEPRDEX1.corp.kns.com ([fe80::8902:ecdb:4dc3:cfac]) by USEPRDEX1.corp.kns.com ([fe80::8902:ecdb:4dc3:cfac%22]) with mapi id 15.00.1263.000; Thu, 5 Dec 2019 12:46:20 -0500 From: Mike Schanne To: "'pgsql-performance@postgresql.org'" Subject: autovacuum locking question Thread-Topic: autovacuum locking question X-ASG-Orig-Subj: autovacuum locking question Thread-Index: AdWrk9FDgtFqZFXdQdakcThlRxUbIQ== Date: Thu, 5 Dec 2019 17:46:19 +0000 Message-ID: <0871fcf35ceb4caa8a2204ca9c38e330@USEPRDEX1.corp.kns.com> Accept-Language: en-US Content-Language: en-US X-MS-Has-Attach: X-MS-TNEF-Correlator: x-ms-exchange-transport-fromentityheader: Hosted x-originating-ip: [10.40.22.174] Content-Type: multipart/alternative; boundary="_000_0871fcf35ceb4caa8a2204ca9c38e330USEPRDEX1corpknscom_" MIME-Version: 1.0 X-Barracuda-Connect: useprdex1.corp.kns.com[10.40.10.30] X-Barracuda-Start-Time: 1575567984 X-Barracuda-URL: https://Mails1.kns.com:443/cgi-mod/mark.cgi X-Virus-Scanned: by bsmtpd at kns.com X-Barracuda-Scan-Msg-Size: 6207 X-Barracuda-BRTS-Status: 1 X-Barracuda-Spam-Score: 2.80 X-Barracuda-Spam-Status: No, SCORE=2.80 using global scores of TAG_LEVEL=1000.0 QUARANTINE_LEVEL=1000.0 KILL_LEVEL=1000.0 tests=HTML_MESSAGE, WEIRD_QUOTING, WEIRD_QUOTING_2 X-Barracuda-Spam-Report: Code version 3.2, rules version 3.2.3.78474 Rule breakdown below pts rule name description ---- ---------------------- -------------------------------------------------- 0.00 WEIRD_QUOTING BODY: Weird repeated double-quotation marks 0.00 HTML_MESSAGE BODY: HTML included in message 2.80 WEIRD_QUOTING_2 Weird repeated double-quotation marks List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Precedence: bulk --_000_0871fcf35ceb4caa8a2204ca9c38e330USEPRDEX1corpknscom_ Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: quoted-printable Hi, I am investigating a performance problem in our application and am seeing s= omething unexpected in the postgres logs regarding the autovacuum. 2019-12-01 13:05:39.029 UTC,"wb","postgres",6966,"127.0.0.1:53976",5ddbd990= .1b36,17099,"INSERT waiting",2019-11-25 13:39:28 UTC,12/1884256,12615023,LO= G,00000,"process 6966 still waiting for RowExclusiveLock on relation 32938 = of database 32768 after 1000.085 ms","Process holding the lock: 6045. Wait = queue: 6966.",,,,,"INSERT INTO myschema.mytable (...) VALUES (...) RETURNIN= G process.mytable.mytable_id",13,,"" 2019-12-01 13:05:39.458 UTC,,,6045,,5de3b800.179d,1,,2019-12-01 12:54:24 UT= C,10/417900,0,ERROR,57014,"canceling autovacuum task",,,,,"automatic vacuum= of table ""postgres.myschema.mytable""",,,,"" My understanding from reading the documentation was that a vacuum can run c= oncurrently with table inserts/updates, but from reading the logs it appear= s they are conflicting over a row lock. This particular table gets very fr= equent inserts/updates (10-100 inserts / sec) so I am concerned that if the= autovacuum is constantly canceled, then the table never gets cleaned and i= ts performance will continue to degrade over time. Is it expected for the = vacuum to be canceled by an insert in this way? We are using postgres 9.6.10. Thanks, Mike ________________________________ This email is non-binding, is subject to contract, and neither Kulicke and = Soffa Industries, Inc. nor its subsidiaries (each and collectively "K&S") s= hall have any obligation to you to consummate the transactions herein or to= enter into any agreement, other than in accordance with the terms and cond= itions of a definitive agreement if and when negotiated, finalized and exec= uted between the parties. This email and all its contents are protected by = International and United States copyright laws. Any reproduction or use of = all or any part of this email without the express written consent of K&S is= prohibited. --_000_0871fcf35ceb4caa8a2204ca9c38e330USEPRDEX1corpknscom_ Content-Type: text/html; charset="us-ascii" Content-Transfer-Encoding: quoted-printable

Hi,

I am investigating a performance problem in our appl= ication and am seeing something unexpected in the postgres logs regarding t= he autovacuum.

 

2019-12-01 13:05:39.029 UTC,"wb","pos= tgres",6966,"127.0.0.1:53976",5ddbd990.1b36,17099,"INSE= RT waiting",2019-11-25 13:39:28 UTC,12/1884256,12615023,LOG,00000,&quo= t;process 6966 still waiting for RowExclusiveLock on relation 32938 of data= base 32768 after 1000.085 ms","Process holding the lock: 6045. Wait q= ueue: 6966.",,,,,"INSERT INTO myschema.mytable (...) VALUES (...)= RETURNING process.mytable.mytable_id",13,,""

2019-12-01 13:05:39.458 UTC,,,6045,,5de3b800.179d,1,= ,2019-12-01 12:54:24 UTC,10/417900,0,ERROR,57014,"canceling autovacuum= task",,,,,"automatic vacuum of table ""postgres.mysche= ma.mytable""",,,,""

 

My understanding from reading the documentation was = that a vacuum can run concurrently with table inserts/updates, but from rea= ding the logs it appears they are conflicting over a row lock.  This p= articular table gets very frequent inserts/updates (10-100 inserts / sec) so I am concerned that if the autovacuum is constan= tly canceled, then the table never gets cleaned and its performance will co= ntinue to degrade over time.  Is it expected for the vacuum to be canc= eled by an insert in this way?

 

We are using postgres 9.6.10.

 

Thanks,

Mike



This email is non-binding, is subject to contract, and neither Kulicke and = Soffa Industries, Inc. nor its subsidiaries (each and collectively “K= &S”) shall have any obligation to you to consummate the transacti= ons herein or to enter into any agreement, other than in accordance with the terms and conditions of a definitive agreement= if and when negotiated, finalized and executed between the parties. This e= mail and all its contents are protected by International and United States = copyright laws. Any reproduction or use of all or any part of this email without the express written consen= t of K&S is prohibited.
 --_000_0871fcf35ceb4caa8a2204ca9c38e330USEPRDEX1corpknscom_--