Batch update query performance - Mailing list pgsql-performance

Summary
We are porting an application to PostgreSQL. The appplication already
runs with DB2 (LUW version) and Oracle. One query in particular executes
slower on Postgres than it does on other Database platforms, notably DB2
LUW and Oracle. (Please understand, we are not comparing databases here,
we are porting an application. We do not mean to start a flame war
here).

The table contains 9.9 million records. At start of the query, all
values of the is_grc_002 column are NULL. We perform a manual Vacuum
Analyze on the table (from PgAdmin III) immediately before running the
query.

The query is slow compared to other database products. For example, DB2
LUW completes this query in about 10 minutes. Postgres needs close to 50
minutes to process the same query on the same data. Sometimes, Postgres
needs more than 2 hours.

The application performs an update query on every row
of the table. The exact SQL of this query is:

update t67cdi_nl_cmp_descr set is_grc_002='Y'

This post contains the data of two runs of the query. the first with
explain analyze. The second run is with explain buffers. Between the
runs, an explicit Vacuum Analyze was done on the table.

Observations
We tried removing the index on the field is_grc_002. That did not have a
big impact.

We tried removing all indexes. That reduces the runtime to ~3 minutes.
When we start to put indexes back, the run time of the query increases
again with each index added.

All Postgres data is on a single disk. We know things can be optimized
further by dividing the disk load. But the other DB systems DB2, Oracle
worked in similar conditions.

Hypothesis
we have tried many things to solve this problem ourselves, but to no
avail so far. Our hypothesis is that
the Postgres creates new records for all rows and then needs to update
all 15 indexes to make them point to the new rows. There does not seem
to be a way to avoid that.

Question:
- Is our hypothesis correct?
- Can the forum please advise us on possible ways to make the query
faster?

Any insight is much appreciated.


regards,

Hans Drexler





Full Table and Index Schema
The table referenced by the troublesome query is fully specified at the
end of this post, including all indexes.


Table Metadata
- No large objects
- Many columns do have a significant amount of null values.
- The table is filled, and then used for doing queries. No updates or
deletes after the table is filled.
- All 9.9M rows are inserted in one go before the querying starts.
- There are many indexes (see schema)
- There are no triggers or functions on this table.

History
This query has always been slow. We are trying to speed up this query as
to make the product performance on PostgreSQL on par with other
databases.

Hardware
The speed difference between Postgres and other databases is experienced
on all hardware. In this case, the query runs on a laptop with 12GB ram
and SSD disk.


Output of "explain analyze" is below:
"Update on t67cdi_nl_cmp_descr  (cost=0.00..434456.10 rows=9863510
width=237) (actual time=2821074.381..2821074.381 rows=0 loops=1)"
"  ->  Seq Scan on t67cdi_nl_cmp_descr  (cost=0.00..434456.10
rows=9863510 width=237) (actual time=0.048..17104.003 rows=9863467
loops=1)"
"Total runtime: 2821078.939 ms"


Output of "explain analyze buffers" is below:
"Update on t67cdi_nl_cmp_descr  (cost=0.00..769880.31 rows=9864731
width=236) (actual time=3216741.867..3216741.867 rows=0 loops=1)"
"  Buffers: shared hit=547205289 read=23073881 written=20825900"
"  ->  Seq Scan on t67cdi_nl_cmp_descr  (cost=0.00..769880.31
rows=9864731 width=236) (actual time=2.074..29984.076 rows=9863467
loops=1)"
"        Buffers: shared hit=1013 read=670220 written=320246"
"Total runtime: 3216743.861 ms"


PostgreSQL version number you are running:

"PostgreSQL 9.1.11 on x86_64-unknown-linux-gnu, compiled by gcc
(Ubuntu/Linaro 4.8.1-10ubuntu9) 4.8.1, 64-bit"

How you installed PostgreSQL: apt-get (on Ubuntu)

Changes made to the settings in the postgresql.conf file:

shared_buffers = 512MB
work_mem = 50MB
maintenance_work_mem = 64MB
synchronous_commit = off
wal_sync_method = fdatasync
wal_buffers = -1
checkpoint_segments = 256
checkpoint_completion_target = 0.9
effective_cache_size = 4GB
default_statistics_target = 1000
track_counts = on
autovacuum = on
log_autovacuum_min_duration = 1000
autovacuum_naptime = 1min
autovacuum_vacuum_scale_factor = 0.2
autovacuum_analyze_scale_factor = 0.1


Operating system and version:
Linux hans-think 3.11.0-15-generic #25-Ubuntu SMP Thu Jan 30 17:22:01
UTC 2014 x86_64 x86_64 x86_64 GNU/Linux

What program you're using to connect to PostgreSQL: PgAdmin III

Is there anything relevant or unusual in the PostgreSQL server logs?:

For questions about any kind of error: There is no error, just slowness.


Full Table and Index Schema

-- Table: t67cdi_nl_cmp_descr

-- DROP TABLE t67cdi_nl_cmp_descr;

CREATE TABLE t67cdi_nl_cmp_descr
(
  id_001 character varying(285),
  is_grc_002 character varying(3),
  grc_id_003 character varying(108),
  src_id_004 character varying(108),
  src_name_005 character varying(30),
  adr_type_006 character varying(30),
  name_cw1_007 character varying(45),
  name_rest_008 character varying(150),
  name_compr_009 bytea,
  name_fo1_010 character varying(30),
  name_lf_011 character varying(30),
  street_cw_012 character varying(45),
  street_hnr_013 character varying(15),
  street_hna_014 character varying(30),
  street_fo_015 character varying(30),
  place_cw_016 character varying(45),
  place_pc_017 character varying(21),
  place_pc4_018 character varying(12),
  place_fo_019 character varying(30),
  email_020 character varying(240),
  phone_021 character varying(150),
  fax_022 character varying(150),
  establ_date_023 character varying(24),
  establ_year_024 character varying(12),
  coc_no_025 character varying(90),
  vat_no_026 character varying(90),
  country_027 character varying(30),
  emaildomain_028 character varying(120),
  internal_id_029 character varying(60),
  email5_030 character varying(15),
  duns_no_031 character varying(90),
  extref_no_032 character varying(90),
  coc_dosno_033 character varying(12),
  coc_brno_034 character varying(36),
  global_id_035 character varying(75),
  filter_036 character varying(3)
)
WITH (
  OIDS=FALSE
);
ALTER TABLE t67cdi_nl_cmp_descr
  OWNER TO postgres;

-- Index: t67cdi_nl_cmp_descrs_prkey

-- DROP INDEX t67cdi_nl_cmp_descrs_prkey;

CREATE INDEX t67cdi_nl_cmp_descrs_prkey
  ON t67cdi_nl_cmp_descr
  USING btree
  (id_001 COLLATE pg_catalog."default");

-- Index: t67nl_cmp_coc

-- DROP INDEX t67nl_cmp_coc;

CREATE INDEX t67nl_cmp_coc
  ON t67cdi_nl_cmp_descr
  USING btree
  (coc_no_025 COLLATE pg_catalog."default");

-- Index: t67nl_cmp_duns

-- DROP INDEX t67nl_cmp_duns;

CREATE INDEX t67nl_cmp_duns
  ON t67cdi_nl_cmp_descr
  USING btree
  (duns_no_031 COLLATE pg_catalog."default");

-- Index: t67nl_cmp_email

-- DROP INDEX t67nl_cmp_email;

CREATE INDEX t67nl_cmp_email
  ON t67cdi_nl_cmp_descr
  USING btree
  (email5_030 COLLATE pg_catalog."default");

-- Index: t67nl_cmp_glb_id

-- DROP INDEX t67nl_cmp_glb_id;

CREATE INDEX t67nl_cmp_glb_id
  ON t67cdi_nl_cmp_descr
  USING btree
  (global_id_035 COLLATE pg_catalog."default");

-- Index: t67nl_cmp_is_grc

-- DROP INDEX t67nl_cmp_is_grc;

CREATE INDEX t67nl_cmp_is_grc
  ON t67cdi_nl_cmp_descr
  USING btree
  (is_grc_002 COLLATE pg_catalog."default");

-- Index: t67nl_cmp_n_s_h

-- DROP INDEX t67nl_cmp_n_s_h;

CREATE INDEX t67nl_cmp_n_s_h
  ON t67cdi_nl_cmp_descr
  USING btree
  (name_fo1_010 COLLATE pg_catalog."default", street_fo_015 COLLATE
pg_catalog."default", street_hnr_013 COLLATE pg_catalog."default");

-- Index: t67nl_cmp_nm_est

-- DROP INDEX t67nl_cmp_nm_est;

CREATE INDEX t67nl_cmp_nm_est
  ON t67cdi_nl_cmp_descr
  USING btree
  (name_fo1_010 COLLATE pg_catalog."default", establ_year_024 COLLATE
pg_catalog."default");

-- Index: t67nl_cmp_nm_p_s

-- DROP INDEX t67nl_cmp_nm_p_s;

CREATE INDEX t67nl_cmp_nm_p_s
  ON t67cdi_nl_cmp_descr
  USING btree
  (name_fo1_010 COLLATE pg_catalog."default", place_pc_017 COLLATE
pg_catalog."default", street_fo_015 COLLATE pg_catalog."default");

-- Index: t67nl_cmp_nm_pl

-- DROP INDEX t67nl_cmp_nm_pl;

CREATE INDEX t67nl_cmp_nm_pl
  ON t67cdi_nl_cmp_descr
  USING btree
  (name_fo1_010 COLLATE pg_catalog."default", place_fo_019 COLLATE
pg_catalog."default");

-- Index: t67nl_cmp_p_s_h

-- DROP INDEX t67nl_cmp_p_s_h;

CREATE INDEX t67nl_cmp_p_s_h
  ON t67cdi_nl_cmp_descr
  USING btree
  (place_pc_017 COLLATE pg_catalog."default", street_fo_015 COLLATE
pg_catalog."default", street_hnr_013 COLLATE pg_catalog."default");

-- Index: t67nl_cmp_pc6

-- DROP INDEX t67nl_cmp_pc6;

CREATE INDEX t67nl_cmp_pc6
  ON t67cdi_nl_cmp_descr
  USING btree
  (place_pc_017 COLLATE pg_catalog."default");

-- Index: t67nl_cmp_pc_hnr

-- DROP INDEX t67nl_cmp_pc_hnr;

CREATE INDEX t67nl_cmp_pc_hnr
  ON t67cdi_nl_cmp_descr
  USING btree
  (place_pc_017 COLLATE pg_catalog."default", street_hnr_013 COLLATE
pg_catalog."default");

-- Index: t67nl_cmp_pl_st

-- DROP INDEX t67nl_cmp_pl_st;

CREATE INDEX t67nl_cmp_pl_st
  ON t67cdi_nl_cmp_descr
  USING btree
  (place_fo_019 COLLATE pg_catalog."default", street_fo_015 COLLATE
pg_catalog."default");

-- Index: t67nl_cmp_src_id

-- DROP INDEX t67nl_cmp_src_id;

CREATE INDEX t67nl_cmp_src_id
  ON t67cdi_nl_cmp_descr
  USING btree
  (src_id_004 COLLATE pg_catalog."default");



Output of manual vacuum just before running the query
=====================================================
INFO:  vacuuming "public.t67cdi_nl_cmp_descr"
INFO:  index "t67cdi_nl_cmp_descrs_prkey" now contains 9863467 row
versions in 48895 pages
DETAIL:  0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.08s/0.00u sec elapsed 0.09 sec.
INFO:  index "t67nl_cmp_coc" now contains 9863467 row versions in 27047
pages
DETAIL:  0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.04s/0.00u sec elapsed 0.05 sec.
INFO:  index "t67nl_cmp_duns" now contains 9863467 row versions in 27047
pages
DETAIL:  0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.04s/0.00u sec elapsed 0.05 sec.
INFO:  index "t67nl_cmp_email" now contains 9863467 row versions in
27047 pages
DETAIL:  0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.06s/0.00u sec elapsed 0.05 sec.
INFO:  index "t67nl_cmp_glb_id" now contains 9863467 row versions in
27047 pages
DETAIL:  0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.05s/0.00u sec elapsed 0.05 sec.
INFO:  index "t67nl_cmp_is_grc" now contains 9863467 row versions in
27047 pages
DETAIL:  0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.06s/0.00u sec elapsed 0.05 sec.
INFO:  index "t67nl_cmp_n_s_h" now contains 9863467 row versions in
43444 pages
DETAIL:  0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.05s/0.01u sec elapsed 0.08 sec.
INFO:  index "t67nl_cmp_nm_est" now contains 9863467 row versions in
32855 pages
DETAIL:  0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.04s/0.02u sec elapsed 0.06 sec.
INFO:  index "t67nl_cmp_nm_p_s" now contains 9863467 row versions in
49318 pages
DETAIL:  0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.09s/0.00u sec elapsed 0.09 sec.
INFO:  index "t67nl_cmp_nm_pl" now contains 9863467 row versions in
40094 pages
DETAIL:  0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.04s/0.03u sec elapsed 0.08 sec.
INFO:  index "t67nl_cmp_p_s_h" now contains 9863467 row versions in
43500 pages
DETAIL:  0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.06s/0.01u sec elapsed 0.08 sec.
INFO:  index "t67nl_cmp_pc6" now contains 9863467 row versions in 27047
pages
DETAIL:  0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.04s/0.00u sec elapsed 0.05 sec.
INFO:  index "t67nl_cmp_pc_hnr" now contains 9863467 row versions in
37978 pages
DETAIL:  0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.02s/0.05u sec elapsed 0.07 sec.
INFO:  index "t67nl_cmp_pl_st" now contains 9863467 row versions in
39741 pages
DETAIL:  0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.05s/0.02u sec elapsed 0.07 sec.
INFO:  index "t67nl_cmp_src_id" now contains 9863467 row versions in
37981 pages
DETAIL:  0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.05s/0.02u sec elapsed 0.07 sec.
INFO:  "t67cdi_nl_cmp_descr": found 0 removable, 9863467 nonremovable
row versions in 335821 out of 335821 pages
DETAIL:  0 dead row versions cannot be removed yet.
There were 0 unused item pointers.
0 pages are entirely empty.
CPU 2.31s/0.87u sec elapsed 8.13 sec.
INFO:  vacuuming "pg_toast.pg_toast_18470"
INFO:  index "pg_toast_18470_index" now contains 0 row versions in 1
pages
DETAIL:  0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO:  "pg_toast_18470": found 0 removable, 0 nonremovable row versions
in 0 out of 0 pages
DETAIL:  0 dead row versions cannot be removed yet.
There were 0 unused item pointers.
0 pages are entirely empty.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO:  analyzing "public.t67cdi_nl_cmp_descr"
INFO:  "t67cdi_nl_cmp_descr": scanned 300000 of 335821 pages, containing
8811404 live rows and 0 dead rows; 300000 rows in sample, 9863510
estimated total rows
Total query runtime: 41066 ms.

Output of manual vacuum after running the query
===============================================
INFO:  vacuuming "public.t67cdi_nl_cmp_descr"
INFO:  scanned index "t67cdi_nl_cmp_descrs_prkey" to remove 9863467 row
versions
DETAIL:  CPU 1.57s/5.19u sec elapsed 46.73 sec.
INFO:  scanned index "t67nl_cmp_coc" to remove 9863467 row versions
DETAIL:  CPU 0.31s/4.31u sec elapsed 6.38 sec.
INFO:  scanned index "t67nl_cmp_duns" to remove 9863467 row versions
DETAIL:  CPU 0.28s/4.44u sec elapsed 6.52 sec.
INFO:  scanned index "t67nl_cmp_email" to remove 9863467 row versions
DETAIL:  CPU 0.58s/4.69u sec elapsed 16.53 sec.
INFO:  scanned index "t67nl_cmp_glb_id" to remove 9863467 row versions
DETAIL:  CPU 0.38s/4.31u sec elapsed 7.79 sec.
INFO:  scanned index "t67nl_cmp_is_grc" to remove 9863467 row versions
DETAIL:  CPU 0.42s/2.44u sec elapsed 5.46 sec.
INFO:  scanned index "t67nl_cmp_n_s_h" to remove 9863467 row versions
DETAIL:  CPU 1.27s/9.19u sec elapsed 43.46 sec.
INFO:  scanned index "t67nl_cmp_nm_est" to remove 9863467 row versions
DETAIL:  CPU 1.05s/7.71u sec elapsed 34.34 sec.
INFO:  scanned index "t67nl_cmp_nm_p_s" to remove 9863467 row versions
DETAIL:  CPU 1.37s/9.27u sec elapsed 47.96 sec.
INFO:  scanned index "t67nl_cmp_nm_pl" to remove 9863467 row versions
DETAIL:  CPU 1.17s/8.97u sec elapsed 40.85 sec.
INFO:  scanned index "t67nl_cmp_p_s_h" to remove 9863467 row versions
DETAIL:  CPU 1.21s/6.30u sec elapsed 41.02 sec.
INFO:  scanned index "t67nl_cmp_pc6" to remove 9863467 row versions
DETAIL:  CPU 0.75s/5.46u sec elapsed 29.20 sec.
INFO:  scanned index "t67nl_cmp_pc_hnr" to remove 9863467 row versions
DETAIL:  CPU 1.20s/5.88u sec elapsed 37.26 sec.
INFO:  scanned index "t67nl_cmp_pl_st" to remove 9863467 row versions
DETAIL:  CPU 1.12s/6.54u sec elapsed 39.78 sec.
INFO:  scanned index "t67nl_cmp_src_id" to remove 9863467 row versions
DETAIL:  CPU 1.09s/4.32u sec elapsed 33.92 sec.
INFO:  "t67cdi_nl_cmp_descr": removed 9863467 row versions in 335821
pages
DETAIL:  CPU 4.26s/1.85u sec elapsed 95.42 sec.
INFO:  index "t67cdi_nl_cmp_descrs_prkey" now contains 9863467 row
versions in 106595 pages
DETAIL:  9863467 index row versions were removed.
7 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO:  index "t67nl_cmp_coc" now contains 9863467 row versions in 61281
pages
DETAIL:  9863467 index row versions were removed.
26947 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO:  index "t67nl_cmp_duns" now contains 9863467 row versions in 61334
pages
DETAIL:  9863467 index row versions were removed.
26948 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO:  index "t67nl_cmp_email" now contains 9863467 row versions in
62651 pages
DETAIL:  9863467 index row versions were removed.
20427 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO:  index "t67nl_cmp_glb_id" now contains 9863467 row versions in
61337 pages
DETAIL:  9863467 index row versions were removed.
26947 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO:  index "t67nl_cmp_is_grc" now contains 9863467 row versions in
61324 pages
DETAIL:  9863467 index row versions were removed.
26949 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO:  index "t67nl_cmp_n_s_h" now contains 9863467 row versions in
91727 pages
DETAIL:  9863467 index row versions were removed.
45 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO:  index "t67nl_cmp_nm_est" now contains 9863467 row versions in
81825 pages
DETAIL:  9863467 index row versions were removed.
8666 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO:  index "t67nl_cmp_nm_p_s" now contains 9863467 row versions in
107385 pages
DETAIL:  9863467 index row versions were removed.
54 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO:  index "t67nl_cmp_nm_pl" now contains 9863467 row versions in
89118 pages
DETAIL:  9863467 index row versions were removed.
989 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO:  index "t67nl_cmp_p_s_h" now contains 9863467 row versions in
97583 pages
DETAIL:  9863467 index row versions were removed.
1801 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO:  index "t67nl_cmp_pc6" now contains 9863467 row versions in 63184
pages
DETAIL:  9863467 index row versions were removed.
1446 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO:  index "t67nl_cmp_pc_hnr" now contains 9863467 row versions in
85071 pages
DETAIL:  9863467 index row versions were removed.
1609 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO:  index "t67nl_cmp_pl_st" now contains 9863467 row versions in
97723 pages
DETAIL:  9863467 index row versions were removed.
4957 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO:  index "t67nl_cmp_src_id" now contains 9863467 row versions in
80756 pages
DETAIL:  9863467 index row versions were removed.
4 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO:  "t67cdi_nl_cmp_descr": found 471832 removable, 9863467
nonremovable row versions in 671233 out of 671233 pages
DETAIL:  0 dead row versions cannot be removed yet.
There were 0 unused item pointers.
0 pages are entirely empty.
CPU 20.83s/92.41u sec elapsed 555.37 sec.
INFO:  vacuuming "pg_toast.pg_toast_18470"
INFO:  index "pg_toast_18470_index" now contains 0 row versions in 1
pages
DETAIL:  0 index row versions were removed.
0 index pages have been deleted, 0 are currently reusable.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO:  "pg_toast_18470": found 0 removable, 0 nonremovable row versions
in 0 out of 0 pages
DETAIL:  0 dead row versions cannot be removed yet.
There were 0 unused item pointers.
0 pages are entirely empty.
CPU 0.00s/0.00u sec elapsed 0.00 sec.
INFO:  analyzing "public.t67cdi_nl_cmp_descr"
INFO:  "t67cdi_nl_cmp_descr": scanned 300000 of 671233 pages, containing
4409629 live rows and 0 dead rows; 300000 rows in sample, 9864731
estimated total rows
Total query runtime: 598517 ms.