Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtp (Exim 4.80) (envelope-from ) id 1ZxMGs-0004SF-Sa for pgsql-performance@arkaria.postgresql.org; Fri, 13 Nov 2015 21:52:38 +0000 Received: from localhost ([127.0.0.1] helo=postgresql.org) by malur.postgresql.org with smtp (Exim 4.84) (envelope-from ) id 1ZxMGs-0005TJ-9i for pgsql-performance@arkaria.postgresql.org; Fri, 13 Nov 2015 21:52:38 +0000 Received: from magus.postgresql.org ([2a02:c0:301:0:ffff::29]) by malur.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_CBC_SHA384:256) (Exim 4.84) (envelope-from ) id 1ZxMFD-0003dt-85 for pgsql-performance@postgresql.org; Fri, 13 Nov 2015 21:50:55 +0000 Received: from mail-bn1on0066.outbound.protection.outlook.com ([157.56.110.66] helo=na01-bn1-obe.outbound.protection.outlook.com) by magus.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_CBC_SHA384:256) (Exim 4.84) (envelope-from ) id 1ZxMF9-0008WF-Gg for pgsql-performance@postgresql.org; Fri, 13 Nov 2015 21:50:54 +0000 Authentication-Results: spf=none (sender IP is ) smtp.mailfrom=Jim.Nasby@bluetreble.com; Received: from decina.local (70.113.16.71) by CY1PR11MB0682.namprd11.prod.outlook.com (10.163.236.20) with Microsoft SMTP Server (TLS) id 15.1.325.17; Fri, 13 Nov 2015 21:50:47 +0000 Subject: Re: Queries getting canceled inside a proc that seems to slow down randomly To: Skarsol , "pgsql-performance@postgresql.org" References: From: Jim Nasby Message-ID: <56465B32.2070004@BlueTreble.com> Date: Fri, 13 Nov 2015 15:50:42 -0600 User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.9; rv:38.0) Gecko/20100101 Thunderbird/38.3.0 MIME-Version: 1.0 In-Reply-To: Content-Type: text/plain; charset="utf-8"; format=flowed Content-Transfer-Encoding: 7bit X-Originating-IP: [70.113.16.71] X-ClientProxiedBy: CY1PR20CA0125.namprd20.prod.outlook.com (25.164.213.179) To CY1PR11MB0682.namprd11.prod.outlook.com (25.163.236.20) X-Microsoft-Exchange-Diagnostics: 1; CY1PR11MB0682; 2:75jQtzkw6H8qf2ehd8OtH29p9ng/NW3dSRNdihdoC/IGc6SSwWgzcjAeo9rB/4bqII/rVeS6PWmOdyRqbGc/sTFvMk15x8KUdZjOhkf/14GctUDlHmTjVer1rgGE8bAjq6/IGrxmYLjSNgrW4i+IQmoqrqgpdt7GXArCPchJ8nc=; 3:THTS9gk8nl7wyrB24r9JwuA2kriolijXQXVO2ZhMmwhLI6+7+g2qMJqfK+RhI9hiBelPLL+JAK+HAsRXkg5DHIZRz2FdS1hd8WNBGY9P2MjfgQsc8/idLq2CXLTNWUkfoviKKPgi23pSx+453b2B/A==; 25:kHov1JM9o7WMdLH3yqUAOD5yEc8vUjuTSpxinFtVV0Og7bEi2eEP5zUcQVfAnwmQTbW7xwptPXzcJdiERl8HS69vTnhCUMeUaekNUdKNX/uXbFcqPOK1dUNp7cP2QMcqrsuJP1VjDIib6s5qBHbZgb52Mm12iAtFIpPjhWpyLA4MvEa+AWffpgPO5y22mbOs/X5PGpcSRGxXKU2f0mGX/ImdKhQA8USwLDMeLxUWUT4Lp8cwG2JI9i9nyMrK7f85uketmZVWGfBoBHOGKooI8g==; 20:3SNT6T8wAdEWkdLnwmeKfa9QerjHSrX+504o262i7n3DDVPNYVcKFCs6Wl7k2pYEH2sibG7cICLL1g2swjYP9iOgg4951sKsYuFKBVwesL07i5XCS3kyTM6O2v0THgT3Mji/wxBHoZR/jiwTlyWNZQJum20XF2cI7vq9ETgMf/8= X-Microsoft-Antispam: UriScan:;BCL:0;PCL:0;RULEID:;SRVR:CY1PR11MB0682; X-Microsoft-Antispam-PRVS: X-Exchange-Antispam-Report-Test: UriScan:; X-Exchange-Antispam-Report-CFA-Test: BCL:0; PCL:0; RULEID:(601004)(2401047)(8121501046)(5005006)(520078)(3002001)(10201501046); SRVR:CY1PR11MB0682; BCL:0; PCL:0; RULEID:; SRVR:CY1PR11MB0682; X-Microsoft-Exchange-Diagnostics: 1; CY1PR11MB0682; 4:HXrdytvmQ4rKdCEY0HK5xy8ikinPogvGXN7gSKigBf5jW7mTPyo7lQ74fi1LDL5my07wnI7LY0xjSqusKWDNdsrxX8IXwa4QW0e7nD6XbtEUjuSYFi7Q+Bn+saTE0Kuc+O6/g3HwieaC6+9m8qtFecTqIlsxiyQTQdw2OipCyO68jZ/fHo0SeKdKKbjvwzlCTq571YDobnNKyGLjQUR3RXS1HupXhLtKOPRY2mRu7gsXmL5aThH735gSPw08+JGE/qyj5StsjlzdKIfZ1xa72F3YSPo+taCDQV0CjYQGjoL4vffxe1WiSRhqhjhbw6uK3pLF7GKsc7AvtCqs4/xsLisbjqw9Uw0jkM02oAHjLQogipOt4M99Toz4hvpcu+Bp X-Forefront-PRVS: 0759F7A50A X-Forefront-Antispam-Report: SFV:NSPM; SFS:(10009020)(6009001)(199003)(24454002)(377454003)(479174004)(189002)(54356999)(101416001)(65806001)(5001920100001)(2950100001)(65956001)(107886002)(5001960100002)(81156007)(64126003)(5001770100001)(230700001)(50986999)(86362001)(66066001)(5004730100002)(33656002)(586003)(97736004)(5007970100001)(47776003)(76176999)(59896002)(40100003)(5008740100001)(77096005)(23676002)(87266999)(105586002)(36756003)(106356001)(50466002)(19580395003)(92566002)(87976001)(4001350100001)(189998001)(80316001)(65816999)(99136001)(2501003)(15975445007)(42186005)(83506001)(122386002)(85282002)(336755003)(18886065003); DIR:OUT; SFP:1101; SCL:1; SRVR:CY1PR11MB0682; H:decina.local; 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?MTtDWTFQUjExTUIwNjgyOzIzOmhIZlluNURvcEFtTWRSNUhIcG90OGY1Q2RB?= =?utf-8?B?d0UxWVR5Q3QvN2FOTlBBc2g1ZVJVTXllRjllbW54UkxwaWMya3RSZmRvbG80?= =?utf-8?B?WTB3UndnZFRDeGRuTGVINTAwMndTeGJFb1JxWVRpQ1hYL2dzZ3k0djR6S0Rq?= =?utf-8?B?YlhwcnVSc1lEMkhxTUx3Y0tMZEplTmRHVzljaFFYTkhvMXpxNXdUZC84VHZa?= =?utf-8?B?QVY5aUQwRjhhb3p5S3dYNGlud3ZmK0JnRm9PZjBXR2tvaHUwekVjVjhrdUww?= =?utf-8?B?SXpqdmxRcVFBc09zK0pCY09DVVE1N25hRDVlTnFUaGg2a0dTbWVNbVkyWUFw?= =?utf-8?B?bXpsbW11bi93RHpQLzFxZWVHcVBxaGt5SFdEOGtrTWNDSEZ4MWgzamgxNTVS?= =?utf-8?B?VmtMbWh0bmg0STJQMW1BQ1VycmlWbi9hTkRxaktlMkJpT3EvMWdhVHBzL2dE?= =?utf-8?B?V05Ta2JIUTlNeU1VQTZibnQ1SXNaOXVXYit5MzJiWUY2Tmt5V1BOc3ZxSWo1?= =?utf-8?B?QTZLZ0RaS01wOUF2QUhpOUJXVnpDMTdHZFZVc3RtaXFScGc0bit4QjB6eW0v?= =?utf-8?B?eUh0cnZJSmlHeEJDNElUVGhMU0pDVUFKUElZV05SVlZIdzZOdjZEb0xKSjhM?= =?utf-8?B?SUhNWUFwNXVLWHpiYjhtZmlGbUhLOWVQVktPU25EUjZLNVhiMW1RMnRKK0tW?= =?utf-8?B?NEJPVmJFNTl0UlJsZmttNGo1OXF6R3J1dXp3NW1lTHBRUlpwc0c2S3FDNWpa?= =?utf-8?B?N2xrWXZpQkUrdThFdkhwUVI0OFNXZFBYTmtxRWRlSzQ5YUJlNWdGcGlnYVlC?= =?utf-8?B?SzMrUUhjQWFIQUtqeU5VYVNhTkNxdFZHSS9ScGI1cHNDNi9mRGFYTWlCY3Jq?= =?utf-8?B?QktDdkUvM1dCSVl3LzR0ZWJ6bFFkRXdmcEdQZERaQ2FkcGNXMFVXY0EvcjR2?= =?utf-8?B?YUVrTHh6Nlp0RVN5OGcrZzYwY2REWXNlZnZ6OFVwMUY0QSs1TXlZbGc1czFN?= =?utf-8?B?Nmpuc3MrYXlqYWNyUVpvaW1KVGdpK2VISmpKRXhWR1RQLzR6U3J0eVMxdUR0?= =?utf-8?B?b1FyR3d4dGFzMkYwbzh1Z09WWnY4ZTJlQ0hNOS90a0FTdjVBVUhvUE5CRVFu?= =?utf-8?B?VUNON05GcHowTDhEaXdLN0dXQXBMNXRRZDVXdUZ3bnFZUUdoOW9sKzhxYUVy?= =?utf-8?B?MERTeE0vUVdRc0ZiNkJMbFRrckl2b2tkSmpkMGx6eEU3Ti9WY2ZPdnc3d1VH?= =?utf-8?B?cXhSQlRIOWV0NXRKbVdaREdXalFaa1dPNU54L1pRUnJrM2g3RjhqWEdBUXN6?= =?utf-8?B?Q2RtMUliSkE1RHRobWN2c2w1c1J0TEw1RnRDa2pOK1dEd3J3WmYvR0VvRHhP?= =?utf-8?B?YU5XMi9TME1LdytCellJeXU5M0FjUzdSSFowZEF0eWVEWWNFMzdnUkNiWEY3?= =?utf-8?B?V3orU3dxVGNaMTcvWFlRcUlxM0NYa1JvOUY5YjJON3QrMmlFMTZOUVZ2Q0gy?= =?utf-8?B?ZnRyZlN4UG9XcFNzVlBuNUs0bkpzQVhCV2RERjJ4UDhGTjFzWDhibTZocGpw?= =?utf-8?B?Z0pOQm9Za2dCK2pzcFNGOWpTV2U1VDA5YmgxZDBvdmtUUzNidWZRMUNaN0Zx?= =?utf-8?B?RnNKSjM4UVorSS9OR0xpOTN4bDhUSXF0cStYTVo1WkJPb01NRmxvZDAvaGln?= =?utf-8?B?OWJMNlVoZXpOMkQyODJwNHJob3gwbCtNS1JsSWJuL0RXWVZ2MmQ1WkQvWGRt?= =?utf-8?B?SDh0Um1QMERDNlk2SzY0aUh3L1kvWnVMOGNkRWpSUTRRb1htVk9nc3dhY0hI?= =?utf-8?B?ZGpwcmJsbGQxb0JLR1BKY0ZEQzhQQndXaXhuL01ucmQrZ0hsUjZKbFhjWVJU?= =?utf-8?B?U1R6c0J6aHRETVRIeGlOQkZLbXZpbDZ4STVBajlFYkpMZ3dqUHFkcGlzZ1dU?= =?utf-8?B?SXFqcUZ0UHl3PT0=?= X-Microsoft-Exchange-Diagnostics: 1; CY1PR11MB0682; 5:7jho2op0v5P6V3RhMcw8+3iWAoskTG9KnywXp5RCcNG57N467AQXMW7rWc+/VQbe4cNkv7aIFtIUIb1pQwhPVEcucGU0yRfncX74tFHWRg3Ray8ZVPamUx0sd/8+4KrPwLI+TaVbS8dMTuJirw7ofg==; 24:MbdA3s4lyfxCfZ63CM9PY+POcN/mWkZgw53DXQ4IddAdJHzk7fnKEPDYewTy0yM+De9mSlQ5xgaB56o5FxNvLuaM9m2TQdLWd+G/cUd1olg=; 20:wuVJZyX17O6hf9pUKh9Frw5UoznPvIBa/eJFliEnneXKqu8ui5KHhHkGtsGb+RnyMBvqAH3h6WpXaiI5KjI4sA== SpamDiagnosticOutput: 1:23 SpamDiagnosticMetadata: NSPM X-OriginatorOrg: bluetreble.com X-MS-Exchange-CrossTenant-OriginalArrivalTime: 13 Nov 2015 21:50:47.0837 (UTC) X-MS-Exchange-CrossTenant-FromEntityHeader: Hosted X-MS-Exchange-Transport-CrossTenantHeadersStamped: CY1PR11MB0682 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 11/11/15 11:57 AM, Skarsol wrote: > Are we doing anything weird with this procedure? Is there anything more > I can do to get more info as to why/how the cancellation is happening or > why the function would slow down seemingly randomly? > > ERROR: canceling statement due to user request > CONTEXT: PL/pgSQL function chooselast(character varying,character > varying) line 1 at IF > SQL statement "INSERT INTO partition_2015 VALUES (NEW.*)" > PL/pgSQL function table1_insert_trigger() line 4 at SQL statement > STATEMENT: INSERT into table1 (create_time,cusid,last1) Values > ('NOW','8175','ROBERT'') The error tells you what's causing this; it's a client-side interrupt. Actually, looking at the code, you might get the same request if someone sent a signal to the relevant backend, either at the OS level or via pg_cancel_backend(). You can test that and see what error you get. A statement_timeout expiration would give you a different error. As for the hang, maybe someone is ALTERing or replacing the function? BTW, you could write that function in the SQL language, which might allow the optimizer to inline it. Even if it couldn't, you'd probably still see a performance gain from not firing up plpgsql on every row. Though, if you didn't allow empty strings in last1, you could also just replace that whole function with coalesce(). I see the function is marked IMMUTABLE, which is good. -- 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