trigger SPI_exec count argument

Michael Nacos <m.nacos@gmail.com> writes:

I have been trying to improve the performance of a C trigger only to notice
that the real bottleneck was the SPI execution of dynamic SQL statements. I
had been using SPI_exec(sql,0) until I tried SPI_exec(sql,1), since I am
targeting exactly one row each time for writing. This simple change has made
a huge difference (2s --> 60ms in some cases), now the trigger execution
time is consistent with the response times I get if I run the same SQL
statements by hand in psql. I am happy my code performs better, but is this
something you would expect?

With no details that's an unanswerable question.

SPI_exec doesn't appear to consider the count while forming the query
plan, which was my first thought. But I have seen queries in which
the first row is returned quickly but searching for additional rows
takes a long time, even if there aren't any additional rows. It's
not clear though why that wouldn't apply to hand execution. Have
you tried comparing EXPLAIN ANALYZE outputs?

regards, tom lane

Hi Tom,

the only thing I can tell from EXPLAIN ANALYZE is how long the trigger took

Index Scan using some_pkey on sometable (cost=0.00..8.58 rows=1 width=253)
(actual time=0.046..0.050 rows=1 loops=1)
Index Cond: (pkey = 123456)
Trigger so_and_so_on_change: time=62.309 calls=1

running an equivalent query in psql, I get:

Index Scan using other_level_pri on othertable (cost=0.00..8.99 rows=1
width=24) (actual time=0.076..0.085 rows=1 loops=1)
Index Cond: ((level = 0) AND (pkey = '123456'::text))

now, the 62ms trigger execution of the fist statement used to be ~2s

The trigger updates a helper table every time a record is
inserted/updated/deleted in the original table. So, SPI_exec calls an
INSERT/UPDATE/DELETE operation, affecting exactly one record in the second
table. I don't retrieve the results of the query, I just use the return code
to raise errors if something goes wrong.

The trigger code is part of a data diffing toolkit I am hoping to release
soon.

regards, Michael

2009/9/2 Tom Lane <tgl@sss.pgh.pa.us>

Michael Nacos <m.nacos@gmail.com> writes:

the only thing I can tell from EXPLAIN ANALYZE is how long the trigger took

I was thinking of doing EXPLAIN ANALYZE via SPI_exec and seeing if you
got the same results as doing it manually.

regards, tom lane

This is from within SPI_exec:

Nested Loop  (cost=0.00..115947.18 rows=1952242 width=25) (actual
time=0.095..6425.291 rows=1952202 loops=1)
  ->  Index Scan using othertable_level_pkey on othertable
(cost=0.00..9.34 rows=1 width=25) (actual time=0.063..0.067 rows=1
loops=1)
        Index Cond: ((level = 0) AND (pkey = '123456'::text))
  ->  Seq Scan on sometable target  (cost=0.00..96415.42 rows=1952242
width=0) (actual time=0.025..2333.743 rows=1952202 loops=1)
Total runtime: 9613.094 ms

Now, there seems to be a stray FROM inside the trigger code, as in:

UPDATE %s SET key = '%s', val = '%s' FROM %s target WHERE ....

thanks to incremental change :-) removing the stray FROM has given:

Index Scan using othertable_level_pri on othertable (cost=0.00..9.34
rows=1 width=25) (actual time=0.109..0.110 rows=1 loops=1)
Index Cond: ((level = 0) AND (pkey = '123456'::text))
Total runtime: 0.162 ms

which is exactly what I got from the psql version, which did not have
the stray FROM part.

so, it turns out the sql was not identical inside the trigger -- my mistake...

The interesting thing is SQL_exec(sql,1) resulted in a different
execution plan while the stray FROM was still in place.

regards, Michael

Michael Nacos <m.nacos@gmail.com> writes:

The interesting thing is SQL_exec(sql,1) resulted in a different
execution plan while the stray FROM was still in place.

Well, the stray FROM resulted in a useless cross-join, which would
have generated a lot of extra no-op row updates. I think what the
limit was doing for you was stopping the UPDATE before it had performed
the extra updates.

regards, tom lane