Hi,
I've just noticed a general delete performance issue while testing a
patch, and this can be recreated on all recent major versions.
I have 2 tables:
CREATE TABLE countries (
country text PRIMARY KEY,
continent text
);
CREATE TABLE contacts (
id serial PRIMARY KEY,
first_name text,
last_name text,
age integer,
country text REFERENCES countries (country)
);
Here's a sample of the data in the tables:
# SELECT * FROM contacts LIMIT 10;
id | first_name | last_name | age | country
---------+------------+------------+-----+----------------------------------
4873919 | Sharon | Blackburn | 45 | Indonesia
4873920 | Ila | Merrill | 3 | Zambia
4873921 | Brian | Rogers | 85 | Bahamas
4873922 | Michelle | Cunningham | 33 | Malta
4873923 | Garrett | Thompson | 17 | France
4873924 | Jemima | Holloway | 57 | Bahamas
4873925 | Hector | Walls | 82 | Kenya
4873926 | Evangeline | Copeland | 57 | Isle of Man
4873927 | Montana | Cline | 9 | Saint Vincent and The Grenadines
4873928 | Reece | Albert | 66 | Virgin Islands, United States
(10 rows)
# SELECT * FROM countries LIMIT 10;
country | continent
------------+---------------
Albania | Europe
Algeria | Africa
Andorra | Europe
Angola | Africa
Anguilla | Caribbean
Antarctica | Antarctica
Argentina | South America
Armenia | Europe
Aruba | Caribbean
Australia | Australasia
(10 rows)
"contacts" contains 5 million rows
"countries" contains 498 rows
I then ran:
INSERT INTO countries
SELECT country || '1', continent || '2' FROM countries;
to duplicate all the rows, but with a number appended to the values.
But ran into a problem with:
# DELETE FROM countries WHERE continent LIKE '%2';
^CCancel request sent
ERROR: canceling statement due to user request
CONTEXT: SQL statement "SELECT 1 FROM ONLY "public"."contacts" x
WHERE $1 OPERATOR(pg_catalog.=) "country" FOR KEY SHARE OF x"
Time: 278560.623 ms
As you can see, I ran out of patience, but before I did, I ran a stack trace:
#0 ExecScan (node=node@entry=0x1a97f40,
accessMtd=accessMtd@entry=0x661063 <SeqNext>,
recheckMtd=recheckMtd@entry=0x661050 <SeqRecheck>) at execScan.c:236
#1 0x000000000066118b in ExecSeqScan (node=node@entry=0x1a97f40) at
nodeSeqscan.c:127
#2 0x000000000063ba4a in ExecProcNode (node=node@entry=0x1a97f40) at
execProcnode.c:419
#3 0x0000000000658860 in ExecLockRows (node=node@entry=0x1a97d50) at
nodeLockRows.c:57
#4 0x000000000063bd67 in ExecProcNode (node=node@entry=0x1a97d50) at
execProcnode.c:527
#5 0x0000000000636363 in ExecutePlan (estate=estate@entry=0x1a97b70,
planstate=0x1a97d50, use_parallel_mode=0 '\000',
operation=operation@entry=CMD_SELECT,
sendTuples=sendTuples@entry=1 '\001',
numberTuples=numberTuples@entry=1,
direction=direction@entry=ForwardScanDirection,
dest=dest@entry=0xde70c0 <spi_printtupDR>)
at execMain.c:1566
#6 0x00000000006372ac in standard_ExecutorRun (queryDesc=0x1aadbf0,
direction=ForwardScanDirection, count=1) at execMain.c:338
#7 0x0000000000637350 in ExecutorRun
(queryDesc=queryDesc@entry=0x1aadbf0,
direction=direction@entry=ForwardScanDirection, count=count@entry=1)
at execMain.c:286
#8 0x000000000066cdcf in _SPI_pquery
(queryDesc=queryDesc@entry=0x1aadbf0,
fire_triggers=fire_triggers@entry=0 '\000', tcount=1) at spi.c:2404
#9 0x000000000066f7a3 in _SPI_execute_plan
(plan=plan@entry=0x1aad790, paramLI=0x1aadba0,
snapshot=snapshot@entry=0x0,
crosscheck_snapshot=crosscheck_snapshot@entry=0x0,
read_only=read_only@entry=0 '\000',
fire_triggers=fire_triggers@entry=0 '\000', tcount=tcount@entry=1)
at spi.c:2192
#10 0x000000000066fcc8 in SPI_execute_snapshot
(plan=plan@entry=0x1aad790, Values=Values@entry=0x7ffff20c8e80,
Nulls=Nulls@entry=0x7ffff20c8e40 " ",
snapshot=snapshot@entry=0x0,
crosscheck_snapshot=crosscheck_snapshot@entry=0x0,
read_only=read_only@entry=0 '\000',
fire_triggers=fire_triggers@entry=0 '\000',
tcount=tcount@entry=1) at spi.c:489
#11 0x0000000000873f1b in ri_PerformCheck
(riinfo=riinfo@entry=0x1a7cb70, qkey=qkey@entry=0x7ffff20c9360,
qplan=0x1aad790, fk_rel=fk_rel@entry=0x7fcdcde65480,
pk_rel=pk_rel@entry=0x7fcdcde5ee88,
old_tuple=old_tuple@entry=0x7ffff20c9940,
new_tuple=new_tuple@entry=0x0, detectNewRows=detectNewRows@entry=1
'\001',
expect_OK=expect_OK@entry=5) at ri_triggers.c:3142
#12 0x00000000008746e7 in ri_restrict_del (trigdata=<optimized out>,
is_no_action=is_no_action@entry=1 '\001') at ri_triggers.c:773
#13 0x0000000000875b07 in RI_FKey_noaction_del (fcinfo=0x7ffff20c9510)
at ri_triggers.c:613
#14 0x00000000006118f0 in ExecCallTriggerFunc
(trigdata=trigdata@entry=0x7ffff20c9960, tgindx=tgindx@entry=0,
finfo=finfo@entry=0x1a01630, instr=instr@entry=0x0,
per_tuple_context=per_tuple_context@entry=0x1aa5c50) at trigger.c:1910
#15 0x0000000000612fae in AfterTriggerExecute
(event=event@entry=0x1a7cea0, rel=rel@entry=0x7fcdcde5ee88,
trigdesc=trigdesc@entry=0x1a01490,
finfo=finfo@entry=0x1a01630, instr=instr@entry=0x0,
per_tuple_context=per_tuple_context@entry=0x1aa5c50,
trig_tuple_slot1=trig_tuple_slot1@entry=0x0,
trig_tuple_slot2=trig_tuple_slot2@entry=0x0) at trigger.c:3643
#16 0x00000000006132b3 in afterTriggerInvokeEvents
(events=events@entry=0x1a8d8a0, firing_id=1,
estate=estate@entry=0x1a01240, delete_ok=delete_ok@entry=1 '\001')
at trigger.c:3836
#17 0x0000000000618134 in AfterTriggerEndQuery
(estate=estate@entry=0x1a01240) at trigger.c:4008
#18 0x00000000006373d2 in standard_ExecutorFinish
(queryDesc=0x1ab33d0) at execMain.c:411
#19 0x0000000000637449 in ExecutorFinish
(queryDesc=queryDesc@entry=0x1ab33d0) at execMain.c:379
#20 0x00000000007af5c6 in ProcessQuery (plan=plan@entry=0x1aaa3b8,
sourceText=0x1a4dda0 "delete from countries where continent like
'%2';", params=0x0,
dest=dest@entry=0x1aaa498,
completionTag=completionTag@entry=0x7ffff20c9d20 "DELETE 249") at
pquery.c:225
#21 0x00000000007af73d in PortalRunMulti
(portal=portal@entry=0x1aa7720, isTopLevel=isTopLevel@entry=1 '\001',
dest=dest@entry=0x1aaa498,
altdest=altdest@entry=0x1aaa498,
completionTag=completionTag@entry=0x7ffff20c9d20 "DELETE 249") at
pquery.c:1275
#22 0x00000000007b077e in PortalRun (portal=portal@entry=0x1aa7720,
count=count@entry=9223372036854775807, isTopLevel=isTopLevel@entry=1
'\001',
dest=dest@entry=0x1aaa498, altdest=altdest@entry=0x1aaa498,
completionTag=completionTag@entry=0x7ffff20c9d20 "DELETE 249") at
pquery.c:812
#23 0x00000000007ad433 in exec_simple_query
(query_string=query_string@entry=0x1a4dda0 "delete from countries
where continent like '%2';") at postgres.c:1094
#24 0x00000000007ae029 in PostgresMain (argc=<optimized out>,
argv=argv@entry=0x19e7b98, dbname=0x19e7a48 "postgres",
username=<optimized out>) at postgres.c:4021
#25 0x0000000000730091 in BackendRun (port=port@entry=0x1a08150) at
postmaster.c:4258
#26 0x000000000073272c in BackendStartup (port=port@entry=0x1a08150)
at postmaster.c:3932
#27 0x0000000000732af2 in ServerLoop () at postmaster.c:1690
#28 0x00000000007345c1 in PostmasterMain (argc=argc@entry=3,
argv=argv@entry=0x19e6c70) at postmaster.c:1298
#29 0x0000000000689943 in main (argc=3, argv=0x19e6c70) at main.c:223
Then another:
#0 ExecQual (qual=qual@entry=0x1a98b60,
econtext=econtext@entry=0x1a98050, resultForNull=resultForNull@entry=0
'\000') at execQual.c:5263
#1 0x0000000000645821 in ExecScan (node=node@entry=0x1a97f40,
accessMtd=accessMtd@entry=0x661063 <SeqNext>,
recheckMtd=recheckMtd@entry=0x661050 <SeqRecheck>)
at execScan.c:208
#2 0x000000000066118b in ExecSeqScan (node=node@entry=0x1a97f40) at
nodeSeqscan.c:127
#3 0x000000000063ba4a in ExecProcNode (node=node@entry=0x1a97f40) at
execProcnode.c:419
#4 0x0000000000658860 in ExecLockRows (node=node@entry=0x1a97d50) at
nodeLockRows.c:57
#5 0x000000000063bd67 in ExecProcNode (node=node@entry=0x1a97d50) at
execProcnode.c:527
#6 0x0000000000636363 in ExecutePlan (estate=estate@entry=0x1a97b70,
planstate=0x1a97d50, use_parallel_mode=0 '\000',
operation=operation@entry=CMD_SELECT,
sendTuples=sendTuples@entry=1 '\001',
numberTuples=numberTuples@entry=1,
direction=direction@entry=ForwardScanDirection,
dest=dest@entry=0xde70c0 <spi_printtupDR>)
at execMain.c:1566
#7 0x00000000006372ac in standard_ExecutorRun (queryDesc=0x1aadbf0,
direction=ForwardScanDirection, count=1) at execMain.c:338
#8 0x0000000000637350 in ExecutorRun
(queryDesc=queryDesc@entry=0x1aadbf0,
direction=direction@entry=ForwardScanDirection, count=count@entry=1)
at execMain.c:286
#9 0x000000000066cdcf in _SPI_pquery
(queryDesc=queryDesc@entry=0x1aadbf0,
fire_triggers=fire_triggers@entry=0 '\000', tcount=1) at spi.c:2404
#10 0x000000000066f7a3 in _SPI_execute_plan
(plan=plan@entry=0x1aad790, paramLI=0x1aadba0,
snapshot=snapshot@entry=0x0,
crosscheck_snapshot=crosscheck_snapshot@entry=0x0,
read_only=read_only@entry=0 '\000',
fire_triggers=fire_triggers@entry=0 '\000', tcount=tcount@entry=1)
at spi.c:2192
#11 0x000000000066fcc8 in SPI_execute_snapshot
(plan=plan@entry=0x1aad790, Values=Values@entry=0x7ffff20c8e80,
Nulls=Nulls@entry=0x7ffff20c8e40 " ",
snapshot=snapshot@entry=0x0,
crosscheck_snapshot=crosscheck_snapshot@entry=0x0,
read_only=read_only@entry=0 '\000',
fire_triggers=fire_triggers@entry=0 '\000',
tcount=tcount@entry=1) at spi.c:489
#12 0x0000000000873f1b in ri_PerformCheck
(riinfo=riinfo@entry=0x1a7cb70, qkey=qkey@entry=0x7ffff20c9360,
qplan=0x1aad790, fk_rel=fk_rel@entry=0x7fcdcde65480,
pk_rel=pk_rel@entry=0x7fcdcde5ee88,
old_tuple=old_tuple@entry=0x7ffff20c9940,
new_tuple=new_tuple@entry=0x0, detectNewRows=detectNewRows@entry=1
'\001',
expect_OK=expect_OK@entry=5) at ri_triggers.c:3142
#13 0x00000000008746e7 in ri_restrict_del (trigdata=<optimized out>,
is_no_action=is_no_action@entry=1 '\001') at ri_triggers.c:773
#14 0x0000000000875b07 in RI_FKey_noaction_del (fcinfo=0x7ffff20c9510)
at ri_triggers.c:613
#15 0x00000000006118f0 in ExecCallTriggerFunc
(trigdata=trigdata@entry=0x7ffff20c9960, tgindx=tgindx@entry=0,
finfo=finfo@entry=0x1a01630, instr=instr@entry=0x0,
per_tuple_context=per_tuple_context@entry=0x1aa5c50) at trigger.c:1910
#16 0x0000000000612fae in AfterTriggerExecute
(event=event@entry=0x1a7ceb8, rel=rel@entry=0x7fcdcde5ee88,
trigdesc=trigdesc@entry=0x1a01490,
finfo=finfo@entry=0x1a01630, instr=instr@entry=0x0,
per_tuple_context=per_tuple_context@entry=0x1aa5c50,
trig_tuple_slot1=trig_tuple_slot1@entry=0x0,
trig_tuple_slot2=trig_tuple_slot2@entry=0x0) at trigger.c:3643
#17 0x00000000006132b3 in afterTriggerInvokeEvents
(events=events@entry=0x1a8d8a0, firing_id=1,
estate=estate@entry=0x1a01240, delete_ok=delete_ok@entry=1 '\001')
at trigger.c:3836
#18 0x0000000000618134 in AfterTriggerEndQuery
(estate=estate@entry=0x1a01240) at trigger.c:4008
#19 0x00000000006373d2 in standard_ExecutorFinish
(queryDesc=0x1ab33d0) at execMain.c:411
#20 0x0000000000637449 in ExecutorFinish
(queryDesc=queryDesc@entry=0x1ab33d0) at execMain.c:379
#21 0x00000000007af5c6 in ProcessQuery (plan=plan@entry=0x1aaa3b8,
sourceText=0x1a4dda0 "delete from countries where continent like
'%2';", params=0x0,
dest=dest@entry=0x1aaa498,
completionTag=completionTag@entry=0x7ffff20c9d20 "DELETE 249") at
pquery.c:225
#22 0x00000000007af73d in PortalRunMulti
(portal=portal@entry=0x1aa7720, isTopLevel=isTopLevel@entry=1 '\001',
dest=dest@entry=0x1aaa498,
altdest=altdest@entry=0x1aaa498,
completionTag=completionTag@entry=0x7ffff20c9d20 "DELETE 249") at
pquery.c:1275
#23 0x00000000007b077e in PortalRun (portal=portal@entry=0x1aa7720,
count=count@entry=9223372036854775807, isTopLevel=isTopLevel@entry=1
'\001',
dest=dest@entry=0x1aaa498, altdest=altdest@entry=0x1aaa498,
completionTag=completionTag@entry=0x7ffff20c9d20 "DELETE 249") at
pquery.c:812
#24 0x00000000007ad433 in exec_simple_query
(query_string=query_string@entry=0x1a4dda0 "delete from countries
where continent like '%2';") at postgres.c:1094
#25 0x00000000007ae029 in PostgresMain (argc=<optimized out>,
argv=argv@entry=0x19e7b98, dbname=0x19e7a48 "postgres",
username=<optimized out>) at postgres.c:4021
#26 0x0000000000730091 in BackendRun (port=port@entry=0x1a08150) at
postmaster.c:4258
#27 0x000000000073272c in BackendStartup (port=port@entry=0x1a08150)
at postmaster.c:3932
#28 0x0000000000732af2 in ServerLoop () at postmaster.c:1690
#29 0x00000000007345c1 in PostmasterMain (argc=argc@entry=3,
argv=argv@entry=0x19e6c70) at postmaster.c:1298
#30 0x0000000000689943 in main (argc=3, argv=0x19e6c70) at main.c:223
Then another:
#0 SeqNext (node=node@entry=0x1a97f40) at nodeSeqscan.c:62
#1 0x00000000006457a6 in ExecScanFetch (recheckMtd=0x661050
<SeqRecheck>, accessMtd=0x661063 <SeqNext>, node=0x1a97f40) at
execScan.c:95
#2 ExecScan (node=node@entry=0x1a97f40,
accessMtd=accessMtd@entry=0x661063 <SeqNext>,
recheckMtd=recheckMtd@entry=0x661050 <SeqRecheck>) at execScan.c:180
#3 0x000000000066118b in ExecSeqScan (node=node@entry=0x1a97f40) at
nodeSeqscan.c:127
#4 0x000000000063ba4a in ExecProcNode (node=node@entry=0x1a97f40) at
execProcnode.c:419
#5 0x0000000000658860 in ExecLockRows (node=node@entry=0x1a97d50) at
nodeLockRows.c:57
#6 0x000000000063bd67 in ExecProcNode (node=node@entry=0x1a97d50) at
execProcnode.c:527
#7 0x0000000000636363 in ExecutePlan (estate=estate@entry=0x1a97b70,
planstate=0x1a97d50, use_parallel_mode=0 '\000',
operation=operation@entry=CMD_SELECT,
sendTuples=sendTuples@entry=1 '\001',
numberTuples=numberTuples@entry=1,
direction=direction@entry=ForwardScanDirection,
dest=dest@entry=0xde70c0 <spi_printtupDR>)
at execMain.c:1566
#8 0x00000000006372ac in standard_ExecutorRun (queryDesc=0x1aadbf0,
direction=ForwardScanDirection, count=1) at execMain.c:338
#9 0x0000000000637350 in ExecutorRun
(queryDesc=queryDesc@entry=0x1aadbf0,
direction=direction@entry=ForwardScanDirection, count=count@entry=1)
at execMain.c:286
#10 0x000000000066cdcf in _SPI_pquery
(queryDesc=queryDesc@entry=0x1aadbf0,
fire_triggers=fire_triggers@entry=0 '\000', tcount=1) at spi.c:2404
#11 0x000000000066f7a3 in _SPI_execute_plan
(plan=plan@entry=0x1aad790, paramLI=0x1aadba0,
snapshot=snapshot@entry=0x0,
crosscheck_snapshot=crosscheck_snapshot@entry=0x0,
read_only=read_only@entry=0 '\000',
fire_triggers=fire_triggers@entry=0 '\000', tcount=tcount@entry=1)
at spi.c:2192
#12 0x000000000066fcc8 in SPI_execute_snapshot
(plan=plan@entry=0x1aad790, Values=Values@entry=0x7ffff20c8e80,
Nulls=Nulls@entry=0x7ffff20c8e40 " ",
snapshot=snapshot@entry=0x0,
crosscheck_snapshot=crosscheck_snapshot@entry=0x0,
read_only=read_only@entry=0 '\000',
fire_triggers=fire_triggers@entry=0 '\000',
tcount=tcount@entry=1) at spi.c:489
#13 0x0000000000873f1b in ri_PerformCheck
(riinfo=riinfo@entry=0x1a7cb70, qkey=qkey@entry=0x7ffff20c9360,
qplan=0x1aad790, fk_rel=fk_rel@entry=0x7fcdcde65480,
pk_rel=pk_rel@entry=0x7fcdcde5ee88,
old_tuple=old_tuple@entry=0x7ffff20c9940,
new_tuple=new_tuple@entry=0x0, detectNewRows=detectNewRows@entry=1
'\001',
expect_OK=expect_OK@entry=5) at ri_triggers.c:3142
#14 0x00000000008746e7 in ri_restrict_del (trigdata=<optimized out>,
is_no_action=is_no_action@entry=1 '\001') at ri_triggers.c:773
#15 0x0000000000875b07 in RI_FKey_noaction_del (fcinfo=0x7ffff20c9510)
at ri_triggers.c:613
#16 0x00000000006118f0 in ExecCallTriggerFunc
(trigdata=trigdata@entry=0x7ffff20c9960, tgindx=tgindx@entry=0,
finfo=finfo@entry=0x1a01630, instr=instr@entry=0x0,
per_tuple_context=per_tuple_context@entry=0x1aa5c50) at trigger.c:1910
#17 0x0000000000612fae in AfterTriggerExecute
(event=event@entry=0x1a7d050, rel=rel@entry=0x7fcdcde5ee88,
trigdesc=trigdesc@entry=0x1a01490,
finfo=finfo@entry=0x1a01630, instr=instr@entry=0x0,
per_tuple_context=per_tuple_context@entry=0x1aa5c50,
trig_tuple_slot1=trig_tuple_slot1@entry=0x0,
trig_tuple_slot2=trig_tuple_slot2@entry=0x0) at trigger.c:3643
#18 0x00000000006132b3 in afterTriggerInvokeEvents
(events=events@entry=0x1a8d8a0, firing_id=1,
estate=estate@entry=0x1a01240, delete_ok=delete_ok@entry=1 '\001')
at trigger.c:3836
#19 0x0000000000618134 in AfterTriggerEndQuery
(estate=estate@entry=0x1a01240) at trigger.c:4008
#20 0x00000000006373d2 in standard_ExecutorFinish
(queryDesc=0x1ab33d0) at execMain.c:411
#21 0x0000000000637449 in ExecutorFinish
(queryDesc=queryDesc@entry=0x1ab33d0) at execMain.c:379
#22 0x00000000007af5c6 in ProcessQuery (plan=plan@entry=0x1aaa3b8,
sourceText=0x1a4dda0 "delete from countries where continent like
'%2';", params=0x0,
dest=dest@entry=0x1aaa498,
completionTag=completionTag@entry=0x7ffff20c9d20 "DELETE 249") at
pquery.c:225
#23 0x00000000007af73d in PortalRunMulti
(portal=portal@entry=0x1aa7720, isTopLevel=isTopLevel@entry=1 '\001',
dest=dest@entry=0x1aaa498,
altdest=altdest@entry=0x1aaa498,
completionTag=completionTag@entry=0x7ffff20c9d20 "DELETE 249") at
pquery.c:1275
#24 0x00000000007b077e in PortalRun (portal=portal@entry=0x1aa7720,
count=count@entry=9223372036854775807, isTopLevel=isTopLevel@entry=1
'\001',
dest=dest@entry=0x1aaa498, altdest=altdest@entry=0x1aaa498,
completionTag=completionTag@entry=0x7ffff20c9d20 "DELETE 249") at
pquery.c:812
#25 0x00000000007ad433 in exec_simple_query
(query_string=query_string@entry=0x1a4dda0 "delete from countries
where continent like '%2';") at postgres.c:1094
#26 0x00000000007ae029 in PostgresMain (argc=<optimized out>,
argv=argv@entry=0x19e7b98, dbname=0x19e7a48 "postgres",
username=<optimized out>) at postgres.c:4021
#27 0x0000000000730091 in BackendRun (port=port@entry=0x1a08150) at
postmaster.c:4258
#28 0x000000000073272c in BackendStartup (port=port@entry=0x1a08150)
at postmaster.c:3932
#29 0x0000000000732af2 in ServerLoop () at postmaster.c:1690
#30 0x00000000007345c1 in PostmasterMain (argc=argc@entry=3,
argv=argv@entry=0x19e6c70) at postmaster.c:1298
#31 0x0000000000689943 in main (argc=3, argv=0x19e6c70) at main.c:223
I was curious how long this would take to run to completion, and it
turned out to be 5m 8s.
This is just trying to delete rows from a table which aren't
referenced by any rows on the other end of the foreign key constraint.
So what this is doing is, for each country matched, it's running a
query on the contacts table like so:
SELECT 1 FROM ONLY "public"."contacts" x WHERE 'Albania1'
OPERATOR(pg_catalog.=) "country" FOR KEY SHARE OF x;
This individual query takes 850ms, and it has to do this 249 times (as
it will only match half the table because of LIKE '%2'.
Is there something that can be done to improve this? If the
referenced table had tens of thousands of rows in, the query might as
well never complete. Even with an index, it still requires running a
query for every matched row in the referenced table.
Thom
--
Sent via pgsql-general mailing list (pgsql-general@xxxxxxxxxxxxxx)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general
