Queries getting canceled inside a proc that seems to slow down randomly

From: Skarsol <skarsol(at)gmail(dot)com>
To: "pgsql-performance(at)postgresql(dot)org" <pgsql-performance(at)postgresql(dot)org>
Subject: Queries getting canceled inside a proc that seems to slow down randomly
Date: 2015-11-11 17:57:18
Message-ID: CAMt8e=FdOU682kP86A0eSw-Fnf-XWd6YMiJZeS2ifSRR22UOVw@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

We're using postgres 9.2.5. Every couple of days we'll have a query get
cancelled and it is always at the start of one of our custom procedures.
The query is typically part of a php loop that runs in less than a second,
however when the issue occurs, that pass through the loop takes multiple
seconds (~3-4) before the query cancels. The loop continues to run after
the issue occurs, so the php script itself is not terminating. We also see
it in non-loop based updates and selects, so it's not tied to that
particular script. It's possible that some of the selects are actually
cancelled by the user, but the inserts have no interaction with the users.
The updates are triggered by the user, but there's no way for them to
cancel it short of killing their client, and the timeframe for them to do
that would (normally) be minuscule.

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'')

ERROR: canceling statement due to user request
CONTEXT: PL/pgSQL function chooselast(character varying,character varying)
line 1 at IF
STATEMENT: SELECT * FROM table2 WHERE (cusid = 2521) AND
LOWER(chooselast(last1,last2)) LIKE LOWER('87092%')

ERROR: canceling statement due to user request
CONTEXT: PL/pgSQL function chooselast(character varying,character varying)
line 1 at IF
STATEMENT: update table1 set status='DELETE' where id=200498919

partition_2015 (on table 1) has one index that references chooselast:
"pik_last_2015" btree (cusid, lower(chooselast(last1, last2)::text))

I'm not sure why an update on table1 that does not change last1 or last2
would touch the index, so why would we even call the chooselast procedure?

table2 has no indexes that reference chooselast, but is also partitioned
(by year as well).

db01=# select * from pg_proc where proname='chooselast';
-[ RECORD 1
]---+----------------------------------------------------------------------------------------------------------------
proname | chooselast
pronamespace | 2200
proowner | 10
prolang | 12599
procost | 100
prorows | 0
provariadic | 0
protransform | -
proisagg | f
proiswindow | f
prosecdef | f
proleakproof | f
proisstrict | f
proretset | f
provolatile | i
pronargs | 2
pronargdefaults | 0
prorettype | 1043
proargtypes | 1043 1043
proallargtypes |
proargmodes |
proargnames |
proargdefaults |
prosrc | DECLARE t text; BEGIN IF (character_length($1) > 0)
THEN t = $1; ELSE t = $2; END IF; RETURN t; END;
probin |
proconfig |
proacl |

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Massalin Yerzhan 2015-11-11 19:09:36 Simple delete query is taking too long (never ends)
Previous Message David Osborne 2015-11-11 10:04:41 Re: Slow 3 Table Join with v bad row estimate