Re: Help with slow table update

On 4/9/15 6:18 PM, Pawel Veselov wrote:

Hi.

I have a plpgsql procedure that updates a few similar tables.
for some reason, updates on one of the tables take a lot longer the
updates on the other ones. The difference is, say, 7 seconds vs. 80
milliseconds.

the procedure uses cursors and record variables to do the updates. For
example:

         update r_agrio_total set
           unserved = unserved + (agrow->>'unserved')::numeric(38),
           r_brkconn = mush_brk_conn(r_brkconn, q_item.r_brkconn),
         where
           tagid = _tagid and
           unitid = (akey->>'unitid')::numeric and
           placement = (akey->>'placement')::numeric and
           device_type = (akey->>'device_type')::numeric;

There is another table (xq_agr) that is read record by record, and for
each of those records, such update is executed.

I was trying to select analyze the updates to see where the time could
be spent.
There are only 24 row in the "bad" table, and 3,400 rows in "good"
table. So, for the "bad" table, most of the updates will be on the same
rows. The times were measured on processing 100 original records.

When I'm analyzing pure update statements, I don't see anything strange.

"bad" table: explain analyze update r_agrio_total set unconfirmed =
unconfirmed +0 where tagid = 1000 and unitid = 1000 and placement = 0
and device_type = 100;

RESULT:
  Update on r_agrio_total  (cost=0.42..4.46 rows=1 width=321) (actual
time=0.253..0.253 rows=0 loops=1)
    ->  Index Scan using tag_r_agrio_total on r_agrio_total
  (cost=0.42..4.46 rows=1 width=321) (actual time=0.037..0.041 rows=1
loops=1)
          Index Cond: (tagid = 1000::numeric)
          Filter: ((unitid = 1000::numeric) AND (placement = 0::numeric)
AND (device_type = 100::numeric))
          Rows Removed by Filter: 7
  Total runtime: 0.282 ms

"good" table: explain analyze update r_agrio_hourly set unconfirmed =
unconfirmed +0 where tagid = 1000 and unitid = 1000 and placement = 0
and device_type = 100 and rowdate = '2015-02-23T13';

RESULT:
  Update on r_agrio_hourly  (cost=0.42..17.36 rows=6 width=329) (actual
time=0.102..0.102 rows=0 loops=1)
    ->  Index Scan using u_r_agrio_hourly on r_agrio_hourly
  (cost=0.42..17.36 rows=6 width=329) (actual time=0.047..0.048 rows=1
loops=1)
          Index Cond: ((tagid = 1000::numeric) AND (unitid =
1000::numeric) AND ((rowdate)::text = '2015-02-23T13'::text) AND
(device_type = 100::numeric) AND (placement = 0::numeric))
  Total runtime: 0.135 ms

When I try doing it with WITH statement (really, to apply the actual
data that the plpgsql function uses), there is something strange in the
"bad" table.

explain analyze
with SRC as (select * from xq_agr where id = 914830)
         update r_agrio_total set
           unconfirmed = unconfirmed +
(SRC.r_agrio->>'unconfirmed')::numeric(38)
         from SRC
         where
           tagid = (SRC.r_agrio->'key'->>'tagid')::numeric and
           unitid = (SRC.r_agrio->'key'->>'unit')::numeric and
           placement = (SRC.r_agrio->'key'->>'placement')::numeric and
           device_type = (SRC.r_agrio->'key'->>'device_type')::numeric;

RESULT:
  Update on r_agrio_total  (cost=8.91..32777.51 rows=19331 width=409)
(actual time=0.107..0.107 rows=0 loops=1)
    CTE src
      ->  Index Scan using xq_agr_pkey on xq_agr  (cost=0.42..8.44
rows=1 width=379) (actual time=0.026..0.027 rows=1 loops=1)
            Index Cond: (id = 914830)
    ->  Nested Loop  (cost=0.46..32769.07 rows=19331 width=409) (actual
time=0.107..0.107 rows=0 loops=1)
          ->  CTE Scan on src  (cost=0.00..0.02 rows=1 width=88) (actual
time=0.032..0.033 rows=1 loops=1)
          ->  Index Scan using u_r_agrio_total on r_agrio_total

  (*cost=0.46..32285.78 rows=19331* width=321) (actual time=0.001..0.001

rows=0 loops=1)
                Index Cond: ((tagid = (((src.r_agrio -> 'key'::text) ->>
'tagid'::text))::numeric) AND (unitid = (((src.r_agrio -> 'key'::text)
->> 'unit'::text))::numeric) AND (device_type = (((src.r_agrio ->
'key'::text) ->> 'device_type'::text))::numeric) AND (placement =
(((src.r_agrio -> 'key'::text) ->> 'placement'::text))::numeric))
  Total runtime: 0.155 ms

explain analyze
with SRC as (select * from xq_agr where id = 914830)
         update r_agrio_hourly set
           unconfirmed = unconfirmed +
(SRC.r_agrio->>'unconfirmed')::numeric(38)
         from SRC
         where
           tagid = (SRC.r_agrio->'key'->>'tagid')::numeric and
           unitid = (SRC.r_agrio->'key'->>'unit')::numeric and
           placement = (SRC.r_agrio->'key'->>'placement')::numeric and
           device_type = (SRC.r_agrio->'key'->>'device_type')::numeric and
           rowdate = (SRC.r_agrio->'key'->>'rowdate');

RESULT:
  Update on r_agrio_hourly  (cost=8.91..52.91 rows=20 width=417) (actual
time=0.123..0.123 rows=0 loops=1)
    CTE src
      ->  Index Scan using xq_agr_pkey on xq_agr  (cost=0.42..8.44
rows=1 width=379) (actual time=0.023..0.024 rows=1 loops=1)
            Index Cond: (id = 914830)
    ->  Nested Loop  (cost=0.47..44.47 rows=20 width=417) (actual
time=0.121..0.121 rows=0 loops=1)
          ->  CTE Scan on src  (cost=0.00..0.02 rows=1 width=88) (actual
time=0.030..0.031 rows=1 loops=1)
          ->  Index Scan using u_r_agrio_hourly on r_agrio_hourly

  (*cost=0.47..43.95 rows=20* width=329) (actual time=0.000..0.000

rows=0 loops=1)
                Index Cond: ((tagid = (((src.r_agrio -> 'key'::text) ->>
'tagid'::text))::numeric) AND (unitid = (((src.r_agrio -> 'key'::text)
->> 'unit'::text))::numeric) AND ((rowdate)::text = ((src.r_agrio ->
'key'::text) ->> 'rowdate'::text)) AND (device_type = (((src.r_agrio ->
'key'::text) ->> 'device_type'::text))::numeric) AND (placement =
(((src.r_agrio -> 'key'::text) ->> 'placement'::text))::numeric))
  Total runtime: 0.176 ms

I've tried doing vacuum full analyze, rebuilding indexes. Vacuum did
help somewhat, but the time differential is still huge (that 7sec vs. 80ms)

The table structure (some fields thrown out just to save output length):

=> \d r_agrio_total
       Column       |     Type      |                         Modifiers
-------------------+---------------+------------------------------------------------------------
  id                | bigint        | not null default
nextval('r_agrio_total_id_seq'::regclass)
  tagid             | numeric(38,0) | not null
  unitid            | numeric(38,0) | not null
  device_type       | numeric(38,0) | not null
  placement         | numeric(38,0) | not null default 0
  unserved          | numeric(38,0) | not null default 0
  r_brkconn         | json          |
Indexes:
     "r_agrio_total_pkey" PRIMARY KEY, btree (id)
     "u_r_agrio_total" UNIQUE, btree (tagid, unitid, device_type, placement)
     "unit_r_agrio_total" btree (unitid)
     "tag_r_agrio_total" btree (tagid)

=> \d r_agrio_hourly
       Column       |         Type          |
  Modifiers
-------------------+-----------------------+-------------------------------------------------------------
  id                | bigint                | not null default
nextval('r_agrio_hourly_id_seq'::regclass)
  tagid             | numeric(38,0)         | not null
  unitid            | numeric(38,0)         | not null
  rowdate           | character varying(15) | not null
  device_type       | numeric(38,0)         | not null
  placement         | numeric(38,0)         | not null default 0
  unserved          | numeric(38,0)         | not null default 0
  unconfirmed       | numeric(38,0)         | not null default 0
  r_brkconn         | json                  |
Indexes:
     "r_agrio_hourly_pkey" PRIMARY KEY, btree (id)
     "u_r_agrio_hourly" UNIQUE, btree (tagid, unitid, rowdate,
device_type, placement)
     "unit_r_agrio_hourly" btree (unitid)
     "rowdate_r_agrio_hourly" btree (rowdate)
     "tag_r_agrio_hourly" btree (tagid)

Would appreciate any help on this, thank you!

What is the ->> operator? I'm not familiar with it.

numeric is FAR slower than int/bigint. Unless you *really* need 38 digits, use one of the other types.

Cursors tend to make things slow. Avoid them if you can.

As for your specific question, I suggest you modify the plpgsql function so that it's doing an EXPLAIN ANALYZE on the slow table. EXPLAIN ANALYZE actually returns a recordset the same way a SELECT would, with a single column of type text. So you just need to do something with that output. The easiest thing would be to replace this in your function:

UPDATE slow_table SET ...

to this (untested)

RETURN QUERY EXPLAIN ANALYZE UPDATE slow_table SET ...

and change the function so it returns SETOF text instead of whatever it returns now.