1

I've got some issues with a Postgres database being very slow.

To test/troubleshoot I installed Postgres on various machines:

  1. Ubuntu 14.05 32bit on ESXi, postgres 9.3 32bit
  2. Windows 7 Professional 64 bit on VMware workstation, postgres 9.3 32bit
  3. Ubuntu 14.05 64 bit on physical machine, postgres 9.3 64bit

Specs of the machines:

  1. Intel XEON E5-2620 v3 @2,4GHz (4 cores), 16GB RAM
  2. Intel i7-3520M @2,9GHz, 4GB RAM
  3. Intel XEON E3-1226 v3 @3,3Ghz, 8GB RAM

The query I'm testing with is:

SELECT *
FROM "product_template"
WHERE (("product_template"."active" = true)  AND  ("product_template"."sale_ok" = true))
ORDER BY COALESCE("product_template"."website_published", false) DESC,"product_template"."website_sequence"

This are the results on the various machines (after a vacuum and analyze on table product_template):

  1. 92151 rows in 53 seconds
  2. 92151 rows in 3 seconds
  3. 92151 rows in 53 seconds

I really have no idea why the query is so slow on the Ubuntu machines (they have the best specs).

What I've tried so far:

  • Testing the database on a physical PC (machine 3) ==> no improvement
  • Vacuum and analyze ==> only success on the Windows 7 machine (machine 2)
  • Tuning shared_buffers, effective_cache_size, work_mem, checkpoint_segments
  • Test IOPS of machine 3 with FIO

IOPS on machine 3:
Command:

./fio --randrepeat=1 --ioengine=libaio --direct=1 --gtod_reduce=1 --name=test --filename=test --bs=4k --iodepth=64 --size=4G --readwrite=randrw --rwmixread=75

Result:
IOPS Read/Write 205/68

I'm not sure what the target IOPS should be...

Does anyone have any more ideas to troubleshoot this issue?


Log of iotop while running the query:**

machine 1:

enter image description here

I think the services.exe is really strange here on an Ubuntu machine...

Why is it only writing to the disk during a SELECT query? I suppose it would read during a SELECT query and write during an UPDATE/INSERT?

Machine 2:

Windows - so no iotop

Machine 3:

enter image description here

No Postgres visible in iotop.


The query plans are the same. The I/O subsystems are all direct attached HDDs. Machine 2 and 3 no RAID, for machine 1 I'm not sure if it's RAID or not.

DDL and execution plans

CREATE TABLE product_template
(
  id serial NOT NULL,
  warranty double precision, -- Warranty
  uos_id integer, -- Unit of Sale
  list_price numeric, -- Sale Price
  weight numeric, -- Gross Weight
  color integer, -- Color Index
  image bytea, -- Image
  write_uid integer, -- Last Updated by
  mes_type character varying, -- Measure Type
  uom_id integer NOT NULL, -- Unit of Measure
  description_purchase text, -- Purchase Description
  create_date timestamp without time zone, -- Created on
  uos_coeff numeric, -- Unit of Measure -> UOS Coeff
  create_uid integer, -- Created by
  sale_ok boolean, -- Can be Sold
  categ_id integer NOT NULL, -- Internal Category
  product_manager integer, -- Product Manager
  message_last_post timestamp without time zone, -- Last Message Date
  company_id integer, -- Company
  state character varying, -- Status
  uom_po_id integer NOT NULL, -- Purchase Unit of Measure
  description_sale text, -- Sale Description
  description text, -- Description
  weight_net numeric, -- Net Weight
  volume double precision, -- Volume
  write_date timestamp without time zone, -- Last Updated on
  active boolean, -- Active
  rental boolean, -- Can be Rent
  image_medium bytea, -- Medium-sized image
  name character varying NOT NULL, -- Name
  type character varying NOT NULL, -- Product Type
  image_small bytea, -- Small-sized image
  track_all boolean, -- Full Lots Traceability
  track_outgoing boolean, -- Track Outgoing Lots
  loc_rack character varying(16), -- Rack
  loc_case character varying(16), -- Case
  track_incoming boolean, -- Track Incoming Lots
  loc_row character varying(16), -- Row
  sale_delay double precision, -- Customer Lead Time
  track_production boolean, -- Track Manufacturing Lots
  produce_delay double precision, -- Manufacturing Lead Time
  purchase_ok boolean, -- Can be Purchased
  pos_categ_id integer, -- Point of Sale Category
  income_pdt boolean, -- Point of Sale Cash In
  to_weight boolean, -- To Weigh With Scale
  expense_pdt boolean, -- Point of Sale Cash Out
  available_in_pos boolean, -- Available in the Point of Sale
  website_sequence integer, -- Sequence
  website_meta_keywords character varying, -- Website meta keywords
  website_meta_description text, -- Website meta description
  website_meta_title character varying, -- Website meta title
  website_published boolean, -- Available in the website
  website_description text, -- Description for the website
  website_size_x integer, -- Size X
  website_size_y integer, -- Size Y
  nutteloosveld character varying, -- Nutteloosveld
  warehouse_id integer, -- Warehouse
  productgroep integer, -- Productgroep
  "isKortingbon" boolean, -- Iskortingbon
  do_validate boolean, -- Do validate
  waardebon integer, -- Waardebon
  werktijd numeric, -- Werktijd
  bewerking_groep integer, -- Bewerking groep
  bewerking boolean, -- Bewerking
  workcenter_id integer, -- Workcenter id
  aantallentabelsuper_id integer, -- Aantallentabelsuper id
  wachttijd numeric, -- Wachttijd
  afmetingtabelsuper_id integer, -- Afmetingtabelsuper id
  afwerkingssequentie integer, -- Afwerkingssequentie
  intrastat_id integer, -- Intrastat code
  ean_sequence_id integer, -- Barcode Sequence
  website_min_order double precision, -- Website min order
  system_record boolean, -- System record
  laatste_verkoop date, -- Laatste verkoop
  laatste_aankoop date, -- Laatste aankoop
  inactive_default_code character varying, -- Referentie (inactive producten)
  gebruikt character varying, -- Gebruikt
  inactive_ean13 character varying, -- Inactive ean13
  inactive_icodif character varying, -- Inactive icodif
  kostprijs double precision, -- Kostprijs
  gemiddeldeprijs double precision, -- Gemiddeldeprijs
  laatsteaankoopprijs double precision, -- Laatsteaankoopprijs
  CONSTRAINT product_template_pkey PRIMARY KEY (id),
  CONSTRAINT product_template_aantallentabelsuper_id_fkey FOREIGN KEY (aantallentabelsuper_id)
      REFERENCES mw_aantallentabelsuper (id) MATCH SIMPLE
      ON UPDATE NO ACTION ON DELETE SET NULL,
  CONSTRAINT product_template_afmetingtabelsuper_id_fkey FOREIGN KEY (afmetingtabelsuper_id)
      REFERENCES mw_afmetingtabelsuper (id) MATCH SIMPLE
      ON UPDATE NO ACTION ON DELETE SET NULL,
  CONSTRAINT product_template_bewerking_groep_fkey FOREIGN KEY (bewerking_groep)
      REFERENCES productgroep (id) MATCH SIMPLE
      ON UPDATE NO ACTION ON DELETE SET NULL,
  CONSTRAINT product_template_categ_id_fkey FOREIGN KEY (categ_id)
      REFERENCES product_category (id) MATCH SIMPLE
      ON UPDATE NO ACTION ON DELETE SET NULL,
  CONSTRAINT product_template_company_id_fkey FOREIGN KEY (company_id)
      REFERENCES res_company (id) MATCH SIMPLE
      ON UPDATE NO ACTION ON DELETE SET NULL,
  CONSTRAINT product_template_create_uid_fkey FOREIGN KEY (create_uid)
      REFERENCES res_users (id) MATCH SIMPLE
      ON UPDATE NO ACTION ON DELETE SET NULL,
  CONSTRAINT product_template_ean_sequence_id_fkey FOREIGN KEY (ean_sequence_id)
      REFERENCES ir_sequence (id) MATCH SIMPLE
      ON UPDATE NO ACTION ON DELETE SET NULL,
  CONSTRAINT product_template_intrastat_id_fkey FOREIGN KEY (intrastat_id)
      REFERENCES report_intrastat_code (id) MATCH SIMPLE
      ON UPDATE NO ACTION ON DELETE SET NULL,
  CONSTRAINT product_template_pos_categ_id_fkey FOREIGN KEY (pos_categ_id)
      REFERENCES pos_category (id) MATCH SIMPLE
      ON UPDATE NO ACTION ON DELETE SET NULL,
  CONSTRAINT product_template_product_manager_fkey FOREIGN KEY (product_manager)
      REFERENCES res_users (id) MATCH SIMPLE
      ON UPDATE NO ACTION ON DELETE SET NULL,
  CONSTRAINT product_template_productgroep_fkey FOREIGN KEY (productgroep)
      REFERENCES productgroep (id) MATCH SIMPLE
      ON UPDATE NO ACTION ON DELETE SET NULL,
  CONSTRAINT product_template_uom_id_fkey FOREIGN KEY (uom_id)
      REFERENCES product_uom (id) MATCH SIMPLE
      ON UPDATE NO ACTION ON DELETE SET NULL,
  CONSTRAINT product_template_uom_po_id_fkey FOREIGN KEY (uom_po_id)
      REFERENCES product_uom (id) MATCH SIMPLE
      ON UPDATE NO ACTION ON DELETE SET NULL,
  CONSTRAINT product_template_uos_id_fkey FOREIGN KEY (uos_id)
      REFERENCES product_uom (id) MATCH SIMPLE
      ON UPDATE NO ACTION ON DELETE SET NULL,
  CONSTRAINT product_template_waardebon_fkey FOREIGN KEY (waardebon)
      REFERENCES waardebonnen (id) MATCH SIMPLE
      ON UPDATE NO ACTION ON DELETE SET NULL,
  CONSTRAINT product_template_warehouse_id_fkey FOREIGN KEY (warehouse_id)
      REFERENCES stock_warehouse (id) MATCH SIMPLE
      ON UPDATE NO ACTION ON DELETE SET NULL,
  CONSTRAINT product_template_workcenter_id_fkey FOREIGN KEY (workcenter_id)
      REFERENCES mrp_workcenter (id) MATCH SIMPLE
      ON UPDATE NO ACTION ON DELETE SET NULL,
  CONSTRAINT product_template_write_uid_fkey FOREIGN KEY (write_uid)
      REFERENCES res_users (id) MATCH SIMPLE
      ON UPDATE NO ACTION ON DELETE SET NULL
)
WITH (
  OIDS=FALSE
);

machine 1

explain (analyze, verbose, buffers):

"Sort  (cost=79832.83..80063.96 rows=92452 width=786) (actual time=6891.354..7022.217 rows=92123 loops=1)"
"  Output: id, warranty, uos_id, list_price, weight, color, image, write_uid, mes_type, uom_id, description_purchase, create_date, uos_coeff, create_uid, sale_ok, categ_id, product_manager, message_last_post, company_id, state, uom_po_id, description_sale,  (...)"
"  Sort Key: (COALESCE(product_template.website_published, false)), product_template.website_sequence"
"  Sort Method: external sort  Disk: 21112kB"
"  Buffers: shared hit=3979 read=2216, temp read=2639 written=2639"
"  ->  Seq Scan on public.product_template  (cost=0.00..8059.20 rows=92452 width=786) (actual time=0.101..297.410 rows=92123 loops=1)"
"        Output: id, warranty, uos_id, list_price, weight, color, image, write_uid, mes_type, uom_id, description_purchase, create_date, uos_coeff, create_uid, sale_ok, categ_id, product_manager, message_last_post, company_id, state, uom_po_id, description_ (...)"
"        Filter: (product_template.active AND product_template.sale_ok)"
"        Rows Removed by Filter: 94373"
"        Buffers: shared hit=3971 read=2216"
"Total runtime: 7159.301 ms"

machine 2

"Sort  (cost=113071.35..113303.48 rows=92851 width=786) (actual time=1002.909..1090.470 rows=92151 loops=1)"
"  Output: id, warranty, uos_id, list_price, weight, color, image, write_uid, mes_type, uom_id, description_purchase, create_date, uos_coeff, create_uid, sale_ok, categ_id, product_manager, message_last_post, company_id, state, uom_po_id, description_sale,  (...)"
"  Sort Key: (COALESCE(product_template.website_published, false)), product_template.website_sequence"
"  Sort Method: external sort  Disk: 22192kB"
"  Buffers: shared hit=8 read=6432, temp read=2774 written=2774"
"  ->  Seq Scan on public.product_template  (cost=0.00..8295.42 rows=92851 width=786) (actual time=0.514..445.079 rows=92151 loops=1)"
"        Output: id, warranty, uos_id, list_price, weight, color, image, write_uid, mes_type, uom_id, description_purchase, create_date, uos_coeff, create_uid, sale_ok, categ_id, product_manager, message_last_post, company_id, state, uom_po_id, description_ (...)"
"        Filter: (product_template.active AND product_template.sale_ok)"
"        Rows Removed by Filter: 94191"
"        Buffers: shared read=6432"
"Total runtime: 1178.815 ms"

machine 3

"Sort  (cost=118174.77..118407.61 rows=93134 width=828) (actual time=312.594..340.652 rows=92123 loops=1)"
"  Output: id, warranty, uos_id, list_price, weight, color, image, write_uid, mes_type, uom_id, description_purchase, create_date, uos_coeff, create_uid, sale_ok, categ_id, product_manager, message_last_post, company_id, state, uom_po_id, description_sale,  (...)"
"  Sort Key: (COALESCE(product_template.website_published, false)), product_template.website_sequence"
"  Sort Method: external sort  Disk: 22192kB"
"  Buffers: shared hit=168 read=6277, temp read=2774 written=2774"
"  ->  Seq Scan on public.product_template  (cost=0.00..8301.95 rows=93134 width=828) (actual time=0.057..95.145 rows=92123 loops=1)"
"        Output: id, warranty, uos_id, list_price, weight, color, image, write_uid, mes_type, uom_id, description_purchase, create_date, uos_coeff, create_uid, sale_ok, categ_id, product_manager, message_last_post, company_id, state, uom_po_id, description_ (...)"
"        Filter: (product_template.active AND product_template.sale_ok)"
"        Rows Removed by Filter: 94372"
"        Buffers: shared hit=160 read=6277"
"Total runtime: 374.587 ms"
  • According to the plans the query runs in 7 seconds (7159 milliseconds) on machine one, 1 second (1178 milliseconds) on machine two and only 374 milliseconds on machine three. None of the "slow ones" take 53 seconds. The 7 seconds are mainly taken by the sort on disk on machine one which indicates poor random access for the disk (which is not surprising as it is a VM). The Windows VM is a bit faster with the random access but a lot slower with the seq scan. And machine three is the fastest - which would be expected. – a_horse_with_no_name Jun 6 '17 at 6:21
  • @a_horse_with_no_name: I see, the total runtime in the execution plans is indeed much less than the 53 seconds in the actual queries. Could you explain why in the actual query, it takes 53 seconds to retrieve all the rows? Could pgAdmin be the issue? – RobbeM Jun 6 '17 at 6:38
  • pgAdmin is know to be extremely slow when display many rows – a_horse_with_no_name Jun 6 '17 at 6:39
  • I see, but the results show up in 3 seconds for the windows VM? – RobbeM Jun 6 '17 at 6:58

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Browse other questions tagged or ask your own question.