Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtp (Exim 4.80) (envelope-from ) id 1aIiLO-0008Sc-2r for pgsql-performance@arkaria.postgresql.org; Mon, 11 Jan 2016 19:41:34 +0000 Received: from localhost ([127.0.0.1] helo=postgresql.org) by malur.postgresql.org with smtp (Exim 4.84) (envelope-from ) id 1aIiLN-0006UJ-Lb for pgsql-performance@arkaria.postgresql.org; Mon, 11 Jan 2016 19:41:33 +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 1aIiJi-0002om-2L for pgsql-performance@postgresql.org; Mon, 11 Jan 2016 19:39:50 +0000 Received: from mail-bl2on0067.outbound.protection.outlook.com ([65.55.169.67] helo=na01-bl2-obe.outbound.protection.outlook.com) by makus.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_CBC_SHA384:256) (Exim 4.84) (envelope-from ) id 1aIiJf-0002HP-7w for pgsql-performance@postgresql.org; Mon, 11 Jan 2016 19:39:48 +0000 DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=BlueTreble.onmicrosoft.com; s=selector1-bluetreble-com; h=From:To:Date:Subject:Message-ID:Content-Type:MIME-Version; bh=p2pTMee1iNVjPtZFdFdmu2TDBKDfoDl2hFgjVAEqNb4=; b=PTIKW+I8otxg5+oi3edjLjRyqI7IAgz4pXV/fos4afZy9MYUq5FypBDCuR0Wy8pPY/2ek8B+6tnqOwfZDj3IveNloKGoU7zW184VamwWRAox1Mdxiuv0M4veyhA66Dl/S7y6hVc2THjEa4zVtkwMgHl0sX3iU7PIdIl97M0xiqY= Authentication-Results: spf=none (sender IP is ) smtp.mailfrom=Jim.Nasby@bluetreble.com; Received: from decina.attlocal.net (2602:306:ce8b:3460:88fd:6b0e:ccc3:b145) by CY1PR11MB0684.namprd11.prod.outlook.com (10.163.236.22) with Microsoft SMTP Server (TLS) id 15.1.365.19; Mon, 11 Jan 2016 19:39:43 +0000 Subject: Re: Queries getting canceled inside a proc that seems to slow down randomly To: Skarsol References: <56465B32.2070004@BlueTreble.com> CC: "pgsql-performance@postgresql.org" From: Jim Nasby Message-ID: <569404FE.10406@BlueTreble.com> Date: Mon, 11 Jan 2016 13:39:42 -0600 User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.9; rv:38.0) Gecko/20100101 Thunderbird/38.5.0 MIME-Version: 1.0 In-Reply-To: Content-Type: text/plain; charset="utf-8"; format=flowed Content-Transfer-Encoding: 7bit X-Originating-IP: [2602:306:ce8b:3460:88fd:6b0e:ccc3:b145] X-ClientProxiedBy: BY2PR11CA0084.namprd11.prod.outlook.com (25.163.150.180) To CY1PR11MB0684.namprd11.prod.outlook.com (25.163.236.22) X-Microsoft-Exchange-Diagnostics: 1; CY1PR11MB0684; 2:56akkvgUclg2REtS2BwG68k0Kw/IKKGYdKoRX2vTXuChYEPt7kDA5wDOrAQWv9CWYGfRsv2fyBmyUyVhH61aud0m/7rXYOI3q03ZYz/Vi4qIzBuQCUiB36TCurqkk3iXviuBNoV46T3Hk0Fj4ZeiOQ==; 3:TiVdQeCgFHYrlhPXqkx/KhUhZkmwTyVjBGTFemaiK8v2JyXn5uIGSFTUJmtyj0wstV/FhsYgUlTI0YsgtNeQ7qzdUe3ln5K3TrBlBomw4/C41qTgPEwAru4AdYb7OOKe; 25:kEtbipiuWC8tsCg0xqx1Jm4kXVZ14NmXT4+gvfu+3oa/LRMNAymUnpqp+05WQknkBazjT24QTRccZ1ULt/3L9olgFQ7YUkg36tKGY6wMul70A18UBUuZ/TkT+bo6vKJmONmO1AkgoSRR66Nc2OUdNh/pMrcGKdSgH/4aeC2cMcq8pLSMgyl20HVsY3hzi6ZdyXNtwqsOytWLTJb5JSrqIzsKMyH/yt/WHw7bgpp1vli5cI5riH1cVLHvmX0lUhgA; 20:3mCH3jLnnN3zpjJOl+YzU9BnouDSO0hFyn+cXUs3pPrjcNxLpohM1Cw2Q3LTTFuda0249iwEdOxm9iW5LUAsF0CSOoeBE/lwhgXbZDGJolteNyfkTRGW4iSVRholUiuEVgooWCw7lg5WjIlPDRmkR/w8usxYwOvPGOuM0JQ5Xwo= X-Microsoft-Antispam: UriScan:;BCL:0;PCL:0;RULEID:;SRVR:CY1PR11MB0684; X-MS-Office365-Filtering-Correlation-Id: d7e8f0b4-b66b-4a7a-bd67-08d31abef49a X-Microsoft-Antispam-PRVS: X-Exchange-Antispam-Report-Test: UriScan:; X-Exchange-Antispam-Report-CFA-Test: BCL:0; PCL:0; RULEID:(601004)(2401047)(5005006)(8121501046)(520078)(10201501046)(3002001); SRVR:CY1PR11MB0684; BCL:0; PCL:0; RULEID:; SRVR:CY1PR11MB0684; X-Microsoft-Exchange-Diagnostics: 1; CY1PR11MB0684; 4:anseXjkma2+OvOEqIdGIVE1NXRl4eXs0Qd3TvN2HVk4K0qXYO8PqVLYgQtgm7/q5V2iWL7yM3Fz5HBghH/kMg+6qE3E8AlD5l6uCfW/5Y41G5e0c3GYyAnaq91hOPsu3Am/nmwbOAjFLFdSChicSaBGynmcmxLE9KA859mOckoLWg8xpvcgXI7mth0i4HnwPtpwdNNdvhVLDG8/IcEom3MkG816lDWqI+JdNdQ2jBQYZPlOlZQcXSxP0wL+tLSFUq4KaOpWpsfhUO0qCqOpaGkKFF7nJruEuwsA9C+rBEkZKk7Dpe2toDQwfFJSIl3fqBg8y1A7f0FZnaowDGOKc3EMrFHf/pk3htTUCfaV0D8djjbwhKQz/ZigxQ7XuE9Xt X-Forefront-PRVS: 0818724663 X-Forefront-Antispam-Report: SFV:NSPM; SFS:(10009020)(6009001)(199003)(24454002)(377454003)(479174004)(377424004)(189002)(101416001)(81156007)(87976001)(1411001)(65956001)(106356001)(230700001)(2950100001)(586003)(23676002)(105586002)(65806001)(53416004)(19625305001)(47776003)(83506001)(92566002)(6116002)(50466002)(1096002)(2906002)(33656002)(5004730100002)(40100003)(97736004)(36756003)(122386002)(4001350100001)(50986999)(5001960100002)(64126003)(5008740100001)(4326007)(19580395003)(54356999)(76176999)(42186005)(77096005)(15975445007)(86362001)(110136002)(189998001)(69596002)(65816999)(19580405001)(3826002)(85282002)(336755003)(47845001)(18886065003); DIR:OUT; SFP:1101; SCL:1; SRVR:CY1PR11MB0684; H:decina.attlocal.net; FPR:; SPF:None; PTR:InfoNoRecords; A:1; MX:1; LANG:en; Received-SPF: None (protection.outlook.com: bluetreble.com does not designate permitted sender hosts) X-Microsoft-Exchange-Diagnostics: =?utf-8?B?MTtDWTFQUjExTUIwNjg0OzIzOk5xUEwvQTB2UG1YekFrMlNRT0N0NFB1UkZX?= =?utf-8?B?aFM2Nk1iYzR1VnZHZ2Z2NlNTSlJxL09oUW43SHBvSVRxN3hNemczNlRkRWcz?= =?utf-8?B?eHM3RE1aRm5HbDZKWVRUbkFIZUxCbjBjMjBxd0lmcXYvVHA4NE5SRldOblRr?= =?utf-8?B?TUlHekVPdkNHeSs2WC82amJoako2dlFUaEJ3aFhLZCtXTUVGdFZjWDBUYUpS?= =?utf-8?B?ZEs5dGpaTjBmNDZ2c2l5emloRHhBSzV2ZUZvOS9xbGZJOFYwOFpGZEk4M2Fp?= =?utf-8?B?VmY0U21manhtM0Zibk03TThqSjRhWEU2Z3o3VElCMVNPQngrUWxHQTM0QS82?= =?utf-8?B?ZjdaS3FuenRVbHhKcmxPQ3UvelNIYWFnNTRTbW1YUDc3cEE0ZGhTMThhZGd5?= =?utf-8?B?OU5mVGQ1WU5zVW1nK1R4eThyMnZzdjc2a1ZuN0k4WVpyYkpiVzNaVHZjbkM4?= =?utf-8?B?ajNRbDh5TW1CT29yekRGUlRjT01HcFVDUjI5bU91WGlSTElQVE05UjRsL2tL?= =?utf-8?B?YVdOMjBFTkErNjdPb21tYi8rVXEwVEJGVzhSUVlLN3diVnBFVUQ5N3RjS0c0?= =?utf-8?B?TVRqL0YwaHVTSEsxTENCOVJ0d21uWmVIc0IwYkNlUy9NazZreWJLNlV2dGlD?= =?utf-8?B?d2kvTmJKS3RXK3NVcGJIam5BR0xxcXcwT1hnU2hrOVhpK3NSdWxlMExsaEZs?= =?utf-8?B?Y1FUMFpQMVJmRjVrZkNhY2VkR3FjdUgraWkxSm9ZN2J2eEZCQ09vVnNqS1Fr?= =?utf-8?B?YUh5SEdyMWlBR0Q1MEp5ODQwbXNxN3JnWW9BeVNWUGJHTkJGQVpKUEQ2ZHpu?= =?utf-8?B?OXlxZGhVOE5WU0Qza2I1bGxReVEyUDIzY0ZjcnBvQk40b3p0a2FuU1JkbC9J?= =?utf-8?B?TTROc2hYY0p2RjROUzFiaEU2eElxNG83UFZibXVVbVJXMzJmUTd1cGoraDlB?= =?utf-8?B?Ti85dEVkU1BuNXFsMkk0S0hvd3hPNERNNnordlJpMGtCa28rTWtoWVF2b0th?= =?utf-8?B?SjQ4L0Rwa1pmNXJkRTFPZ0VtS2JYRHYzdUUxKzhiK2lSRzIwZkNtM0FxU1pq?= =?utf-8?B?YkpVM1VtNjdQajBMaUU2YkFzK3EvNUR5R2Jwd1ZLWU4reXZjeCtDQ1NhbWlo?= =?utf-8?B?bCtucmpUYldieURvQ2FSUk15d3NvN3ZtdlJuMjFSWm1OSDJKa0pVZVk0WGtE?= =?utf-8?B?dGVrNGlLREJyVGFGc0VobWpHR2ttMzB5YXRwaFExTlJPTmh1V1JhN2xoczZq?= =?utf-8?B?ZXNMdmVkc0tZOVladHJDekNKM3htU1BpL1VTTHY1M0pvVDdwS2UwYVIyQkVu?= =?utf-8?B?UEJFZUhnd1VyR3FqK3JZY0lQSkRZeS92N0daeGJqdjdMVmoxZ1NlNk1ROHBX?= =?utf-8?B?UG90TjZhOW9UbXc3TEFCQkxTZ3ByR2xROFlpd1N2cEJCZUM4Qm9KTlNzQkxu?= =?utf-8?B?RlA2eGpIeTR6UUF6Qm5NOGl1NUVJaEIrVlE0a2ZFc1JNYy8yc2dJMVVCdlJw?= =?utf-8?B?K1ZkaGJuUjV4UW5CaTFQVk9tL3VCVWhiOWwwYVRrR3drb2VxS0Q4M3dURXJy?= =?utf-8?B?YlZkdURwVHo5K0N4NDZuVkk5emRsVmtDdmowWnJoV0tHcmpnY29WZFBua1Mx?= =?utf-8?B?SUdERW9hSWZIWld1cXZaWXppS3E4dnNNQkhnc1dZR0xjREl5ZGxhejdRNCtO?= =?utf-8?B?WWdqay95eG1nNTZoUm5KMEJZdjBqVVB5VTNLdVE4TW1HZHNkd0pHR3BSdFpL?= =?utf-8?B?QXkvR2hNQUFGSDZCR2w0OS9zWU51N0lDcFBjdkYrT2JHYTRTT3Evem9oalFQ?= =?utf-8?B?UXVZSUl0VllUYisxb3E3L2JMa2dwMXJBcGhleEp2UFpSN3hQMWFLU05QbWxj?= =?utf-8?B?aGdUdWhDN05INy9wejRmSUhoa3I0a2ZuVGZjMVZFclNWbzdpSjJPMHo4bFY5?= =?utf-8?Q?IGPfY/V7rA06iWcoq3HZmn6T3cE/ZI=3D?= X-Microsoft-Exchange-Diagnostics: 1; CY1PR11MB0684; 5:kMZYBLQHJkbL8AODTgwqNDQ3ATPbIdghkjZ4gYDY1lWnfq+PaRgu+wWipcDQVcxOgwrmvajqz03eV77TO+xFPMkA5d1SeciAavBrVnfAv9mR9pyp3dxYpMwHfVDPdns+9cKzH7hBpjlTADfDVEEF8Q==; 24:FUUHzE1PlKvG7GWl7uhOUDFD0vbZUOIvQq+OTKlWlMacCncD/0tWsVLKtAgcMeYfgTSMQCzVDxKLTrx2Ub6gswsC7cbZ5/Xr9wLpU9ad628= SpamDiagnosticOutput: 1:23 SpamDiagnosticMetadata: NSPM X-OriginatorOrg: bluetreble.com X-MS-Exchange-CrossTenant-OriginalArrivalTime: 11 Jan 2016 19:39:43.5043 (UTC) X-MS-Exchange-CrossTenant-FromEntityHeader: Hosted X-MS-Exchange-Transport-CrossTenantHeadersStamped: CY1PR11MB0684 X-Pg-Spam-Score: -1.9 (-) 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 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 -- Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-performance