Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtp (Exim 4.80) (envelope-from ) id 1aIiMs-0008Uh-K1 for pgsql-performance@arkaria.postgresql.org; Mon, 11 Jan 2016 19:43:06 +0000 Received: from localhost ([127.0.0.1] helo=postgresql.org) by malur.postgresql.org with smtp (Exim 4.84) (envelope-from ) id 1aIiMs-0001LX-6N for pgsql-performance@arkaria.postgresql.org; Mon, 11 Jan 2016 19:43:06 +0000 Received: from makus.postgresql.org ([2001:4800:1501:1::229]) by malur.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_CBC_SHA384:256) (Exim 4.84) (envelope-from ) id 1aIiLD-0005w2-BS for pgsql-performance@postgresql.org; Mon, 11 Jan 2016 19:41:23 +0000 Received: from mail-yk0-x22b.google.com ([2607:f8b0:4002:c07::22b]) by makus.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_CBC_SHA1:256) (Exim 4.84) (envelope-from ) id 1aIiLA-0002NT-Rg for pgsql-performance@postgresql.org; Mon, 11 Jan 2016 19:41:22 +0000 Received: by mail-yk0-x22b.google.com with SMTP id a85so365403385ykb.1 for ; Mon, 11 Jan 2016 11:41:20 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:in-reply-to:references:date:message-id:subject:from:to :cc:content-type; bh=setwIfBEtDU8qK2GUStbTJyA8qPkNAnZa9XPAKjk5gE=; b=0t3n5+2HQxy+wu3u4iEQ8jviizjQIKqaW0Bnk5PZdMzlt7Nfqq2YYmYs46XGI7t3Hp YvuE3ID2AO5mWRAlWqFhfE2GVzvw8tzHWrmsUS4M/qWvm8Ty0XJJMuQlmfQkW11uPCkD qYs1EMh8t22bK+zAS3ChL/wSCzyDAzGhnC3Oz+dDatZNQdAJPhz1ZxUlI6fTEy4OC5M6 X+j22T3OfuZODFNqf3jWslmIKPg8ZtIhNjkKtLuCqwKzZFJG4NoXPT6HtdiNxOoZtvFw ChbqEBclc9XU+SK/tKnedwoFlVnpa4cNTy5OHGpywcoOZW3mQzR8OtMErbgYjfYBL5nd 3O7g== MIME-Version: 1.0 X-Received: by 10.13.213.193 with SMTP id x184mr108666716ywd.339.1452541279922; Mon, 11 Jan 2016 11:41:19 -0800 (PST) Received: by 10.37.110.130 with HTTP; Mon, 11 Jan 2016 11:41:19 -0800 (PST) In-Reply-To: <569404FE.10406@BlueTreble.com> References: <56465B32.2070004@BlueTreble.com> <569404FE.10406@BlueTreble.com> Date: Mon, 11 Jan 2016 13:41:19 -0600 Message-ID: Subject: Re: Queries getting canceled inside a proc that seems to slow down randomly From: Skarsol To: Jim Nasby Cc: "pgsql-performance@postgresql.org" Content-Type: multipart/alternative; boundary=001a114fd4da02f1160529141ffb X-Pg-Spam-Score: -2.7 (--) List-Archive: List-Help: List-ID: List-Owner: List-Post: List-Subscribe: List-Unsubscribe: X-Mailing-List: pgsql-performance Precedence: bulk Sender: pgsql-performance-owner@postgresql.org --001a114fd4da02f1160529141ffb Content-Type: text/plain; charset=UTF-8 On Mon, Jan 11, 2016 at 1:39 PM, Jim Nasby wrote: > On 1/11/16 1:32 PM, Skarsol wrote: > >> pgbouncer (S-0x17fd780 entries): >> 2016-01-11 12:21:46.600 32905 LOG S-0x17fd780: >> edi01/editor@127.0.0.1:6432 closing >> because: server idle timeout (age=612) >> 2016-01-11 12:23:28.142 32905 LOG S-0x17fd780: >> edi01/editor@127.0.0.1:6432 new >> connection to server >> 2016-01-11 12:23:28.143 32905 LOG S-0x17fd780: >> edi01/editor@127.0.0.1:6432 closing >> because: sent cancel req (age=0) >> 2016-01-11 12:26:31.510 32905 LOG S-0x17fd780: >> edi01/editor@127.0.0.1:6432 new >> connection to server >> > > This makes me think there's a race condition in pgBouncer, or that their > logging is just confusing. > > -- > Jim Nasby, Data Architect, Blue Treble Consulting, Austin TX > Experts in Analytics, Data Architecture and PostgreSQL > Data in Trouble? Get it in Treble! http://BlueTreble.com > Okay, I'll go visit the pgbouncer guys and see if they can shed any light. Thanks. --001a114fd4da02f1160529141ffb Content-Type: text/html; charset=UTF-8 Content-Transfer-Encoding: quoted-printable
On M= on, Jan 11, 2016 at 1:39 PM, Jim Nasby <Jim.Nasby@bluetreble.com> wrote:
On 1/11/16 1:32 PM, Skarsol wrote:
pgbouncer (S-0x17fd780 entries):
2016-01-11 12:21:46.600 32905 LOG S-0x17fd780:
 edi01/editor@127.0.0.1:6432 <http://editor@127.0.0.1:6432&= gt; closing
because: server idle timeout (age=3D612)
2016-01-11 12:23:28.142 32905 LOG S-0x17fd780:
 edi01/editor@127.0.0.1:6432 <http://editor@127.0.0.1:6432&= gt; new
connection to server
2016-01-11 12:23:28.143 32905 LOG S-0x17fd780:
 edi01/editor@127.0.0.1:6432 <http://editor@127.0.0.1:6432&= gt; closing
because: sent cancel req (age=3D0)
2016-01-11 12:26:31.510 32905 LOG S-0x17fd780:
 edi01/editor@127.0.0.1:6432 <http://editor@127.0.0.1:6432&= gt; new
connection to server

This makes me think there's a race condition in pgBouncer, or that thei= r logging is just confusing.

--
Jim Nasby, Data Architect, Blue Treble Consulting, Austin TX
Experts in Analytics, Data Architecture and PostgreSQL
Data in Trouble? Get it in Treble! http://BlueTreble.com

Okay, I'll go visit the pgbouncer guys and see if they c= an shed any light. Thanks.

--001a114fd4da02f1160529141ffb--