Обсуждение: BUG #13908: Query returns too few rows
The following bug has been logged on the website: Bug reference: 13908 Logged by: Seth Email address: seth-p@outlook.com PostgreSQL version: 9.5.0 Operating system: Windows 10 Description: Below is a copy of a long-ish email I wrote detailing the problem. If it doesn't come through in a reasonable format, please let me know where I can email it. Thanks --Seth I've only recently started using Postgresql, and have encountered what I believe to be a bug in Postgresql 9.5 on Windows 10. Below are 6 queries that are identical except for (a) the date range in the WHERE clause, and (b) whether or not they include DISTINCT. This is as simple as I could get the queries while still reproducing the bug. The following table summarizes the number of rows returned by each query: ----------------------------------------------------------------------------------------------------------------------------------- -- Date Range | # rows without DISTINCT | # rows with DISTINCT | Notes | ------------------------------------------------------------------------------|---------------------------------------------------- -- 2005-03-01 - 2005-07-30 | (A) 415,983 | (A-D) 416,075 | DISTINCT *increases* the number of rows returned! | -- 2005-03-01 - 2005-04-30 | (B) 168,886 | (B-D) 168,886 | DISTINCT has no effect | -- 2005-05-01 - 2005-07-30 | (C) 247,189 | (C-D) 247,189 | DISTINCT has no effect | -- sum of sub-range queries | (B) + (C) 416,075 | (B-D) + (C-D) 416,075 | In both cases, sum of 2 queries equals (A-D) | ----------------------------------------------------------------------------------------------------------------------------------- Query (A-D) (with DISTINCT) should not return more rows than query (A) (the identical query without DISTINCT), so clearly something is wrong there. Looking at the results of the queries over the two sub-ranges strongly suggests that it is query (A) that is returning too few rows. Beneath the queries below I also show the EXPLAIN results for queries (A), (A-D), (B), and (B-D). Notice that the plan for query (A) differs from the other three -- it appears to have an extra "Hash" (highlighted with asterisks) that the others do not. I'm afraid I am unable to share the data, but can provide table statistics, index descriptinos, or anything else that might be useful. Any suggestions for how to proceed? Seth -- (A) 2005-03-01 - 2005-07-30 returns 415,983 rows select count(*) from ( SELECT rrr.* FROM files.models_direct_row_asset_data rrr INNER JOIN files.models_direct_file fff ON fff.idx = rrr.barra_file_idx INNER JOIN files.temp_universe_instruments uuu ON uuu.universe_hash = 5188205190738336870 AND uuu.barrid = rrr.barrid WHERE fff.file_name_model_ver = '100' AND fff.file_name_date BETWEEN '2005-03-01' AND '2005-07-30' ) a -- (A-D) 2005-03-01 - 2005-07-30 DISTNICT returns 416,075 rows select count(*) from ( SELECT DISTINCT rrr.* FROM files.models_direct_row_asset_data rrr INNER JOIN files.models_direct_file fff ON fff.idx = rrr.barra_file_idx INNER JOIN files.temp_universe_instruments uuu ON uuu.universe_hash = 5188205190738336870 AND uuu.barrid = rrr.barrid WHERE fff.file_name_model_ver = '100' AND fff.file_name_date BETWEEN '2005-03-01' AND '2005-07-30' ) ad -- (B) 2005-03-01 - 2005-04-30 returns 168,886 rows select count(*) from ( SELECT rrr.* FROM files.models_direct_row_asset_data rrr INNER JOIN files.models_direct_file fff ON fff.idx = rrr.barra_file_idx INNER JOIN files.temp_universe_instruments uuu ON uuu.universe_hash = 5188205190738336870 AND uuu.barrid = rrr.barrid WHERE fff.file_name_model_ver = '100' AND fff.file_name_date BETWEEN '2005-03-01' AND '2005-04-30' ) b -- (B-D) 2005-03-01 - 2005-04-30 DISTINCT returns 168,886 rows select count(*) from ( SELECT DISTINCT rrr.* FROM files.models_direct_row_asset_data rrr INNER JOIN files.models_direct_file fff ON fff.idx = rrr.barra_file_idx INNER JOIN files.temp_universe_instruments uuu ON uuu.universe_hash = 5188205190738336870 AND uuu.barrid = rrr.barrid WHERE fff.file_name_model_ver = '100' AND fff.file_name_date BETWEEN '2005-03-01' AND '2005-04-30' ) bd -- (C) 2005-05-01 - 2005-07-30 returns 247,189 rows select count(*) from ( SELECT rrr.* FROM files.models_direct_row_asset_data rrr INNER JOIN files.models_direct_file fff ON fff.idx = rrr.barra_file_idx INNER JOIN files.temp_universe_instruments uuu ON uuu.universe_hash = 5188205190738336870 AND uuu.barrid = rrr.barrid WHERE fff.file_name_model_ver = '100' AND fff.file_name_date BETWEEN '2005-05-01' AND '2005-07-30' ) c -- (C-D) 2005-05-01 - 2005-07-30 DISTINCT returns 247,189 rows select count(*) from ( SELECT DISTINCT rrr.* FROM files.models_direct_row_asset_data rrr INNER JOIN files.models_direct_file fff ON fff.idx = rrr.barra_file_idx INNER JOIN files.temp_universe_instruments uuu ON uuu.universe_hash = 5188205190738336870 AND uuu.barrid = rrr.barrid WHERE fff.file_name_model_ver = '100' AND fff.file_name_date BETWEEN '2005-05-01' AND '2005-07-30' ) cd EPXLAIN of queries (A) "Aggregate (cost=1821781.18..1821781.19 rows=1 width=0)" " -> Hash Join (cost=1811365.12..1821096.53 rows=273861 width=0)" " Hash Cond: ((uuu.barrid)::text = (rrr.barrid)::text)" " -> Bitmap Heap Scan on temp_universe_instruments uuu (cost=231.25..932.60 rows=8108 width=8)" " Recheck Cond: (universe_hash = '5188205190738336870'::bigint)" " -> Bitmap Index Scan on pk_temp_universe_instruments (cost=0.00..229.23 rows=8108 width=0)" " Index Cond: (universe_hash = '5188205190738336870'::bigint)" " -> Hash (cost=1796474.21..1796474.21 rows=893492 width=8)" ********************************************************** " -> Hash Join (cost=2341.15..1796474.21 rows=893492 width=8)" " Hash Cond: (rrr.barra_file_idx = fff.idx)" " -> Seq Scan on models_direct_row_asset_data rrr (cost=0.00..1518763.74 rows=71049174 width=12)" " -> Hash (cost=2329.00..2329.00 rows=972 width=4)" " -> Bitmap Heap Scan on models_direct_file fff (cost=35.33..2329.00 rows=972 width=4)" " Recheck Cond: ((file_name_date >= '2005-03-01'::date) AND (file_name_date <= '2005-07-30'::date))" " Filter: ((file_name_model_ver)::text = '100'::text)" " -> Bitmap Index Scan on ix_models_direct_file_file_name_date (cost=0.00..35.08 rows=1479 width=0)" " Index Cond: ((file_name_date >= '2005-03-01'::date) AND (file_name_date <= '2005-07-30'::date))" (A-D) "Aggregate (cost=1886439.23..1886439.24 rows=1 width=0)" " -> Unique (cost=1875484.79..1883015.97 rows=273861 width=64)" " -> Sort (cost=1875484.79..1876169.44 rows=273861 width=64)" " Sort Key: rrr.idx, rrr.row_number, rrr.barrid, rrr.yield_pct, rrr.total_risk_pct, rrr.spec_risk_pct, rrr.hist_beta, rrr.pred_beta, rrr.data_date, rrr.barra_file_idx" " -> Hash Join (cost=3375.10..1840453.92 rows=273861 width=64)" " Hash Cond: ((rrr.barrid)::text = (uuu.barrid)::text)" " -> Hash Join (cost=2341.15..1796474.21 rows=893492 width=64)" " Hash Cond: (rrr.barra_file_idx = fff.idx)" " -> Seq Scan on models_direct_row_asset_data rrr (cost=0.00..1518763.74 rows=71049174 width=64)" " -> Hash (cost=2329.00..2329.00 rows=972 width=4)" " -> Bitmap Heap Scan on models_direct_file fff (cost=35.33..2329.00 rows=972 width=4)" " Recheck Cond: ((file_name_date >= '2005-03-01'::date) AND (file_name_date <= '2005-07-30'::date))" " Filter: ((file_name_model_ver)::text = '100'::text)" " -> Bitmap Index Scan on ix_models_direct_file_file_name_date (cost=0.00..35.08 rows=1479 width=0)" " Index Cond: ((file_name_date >= '2005-03-01'::date) AND (file_name_date <= '2005-07-30'::date))" " -> Hash (cost=932.60..932.60 rows=8108 width=8)" " -> Bitmap Heap Scan on temp_universe_instruments uuu (cost=231.25..932.60 rows=8108 width=8)" " Recheck Cond: (universe_hash = '5188205190738336870'::bigint)" " -> Bitmap Index Scan on pk_temp_universe_instruments (cost=0.00..229.23 rows=8108 width=0)" " Index Cond: (universe_hash = '5188205190738336870'::bigint)" (B) "Aggregate (cost=1809368.84..1809368.85 rows=1 width=0)" " -> Hash Join (cost=2484.83..1809086.39 rows=112981 width=0)" " Hash Cond: ((rrr.barrid)::text = (uuu.barrid)::text)" " -> Hash Join (cost=1450.88..1790335.13 rows=368611 width=8)" " Hash Cond: (rrr.barra_file_idx = fff.idx)" " -> Seq Scan on models_direct_row_asset_data rrr (cost=0.00..1518763.74 rows=71049174 width=12)" " -> Hash (cost=1445.87..1445.87 rows=401 width=4)" " -> Bitmap Heap Scan on models_direct_file fff (cost=14.49..1445.87 rows=401 width=4)" " Recheck Cond: ((file_name_date >= '2005-03-01'::date) AND (file_name_date <= '2005-04-30'::date))" " Filter: ((file_name_model_ver)::text = '100'::text)" " -> Bitmap Index Scan on ix_models_direct_file_file_name_date (cost=0.00..14.39 rows=610 width=0)" " Index Cond: ((file_name_date >= '2005-03-01'::date) AND (file_name_date <= '2005-04-30'::date))" " -> Hash (cost=932.60..932.60 rows=8108 width=8)" " -> Bitmap Heap Scan on temp_universe_instruments uuu (cost=231.25..932.60 rows=8108 width=8)" " Recheck Cond: (universe_hash = '5188205190738336870'::bigint)" " -> Bitmap Index Scan on pk_temp_universe_instruments (cost=0.00..229.23 rows=8108 width=0)" " Index Cond: (universe_hash = '5188205190738336870'::bigint)" (B-D) "Aggregate (cost=1827336.97..1827336.98 rows=1 width=0)" " -> Unique (cost=1822817.73..1825924.71 rows=112981 width=64)" " -> Sort (cost=1822817.73..1823100.18 rows=112981 width=64)" " Sort Key: rrr.idx, rrr.row_number, rrr.barrid, rrr.yield_pct, rrr.total_risk_pct, rrr.spec_risk_pct, rrr.hist_beta, rrr.pred_beta, rrr.data_date, rrr.barra_file_idx" " -> Hash Join (cost=2484.83..1809086.39 rows=112981 width=64)" " Hash Cond: ((rrr.barrid)::text = (uuu.barrid)::text)" " -> Hash Join (cost=1450.88..1790335.13 rows=368611 width=64)" " Hash Cond: (rrr.barra_file_idx = fff.idx)" " -> Seq Scan on models_direct_row_asset_data rrr (cost=0.00..1518763.74 rows=71049174 width=64)" " -> Hash (cost=1445.87..1445.87 rows=401 width=4)" " -> Bitmap Heap Scan on models_direct_file fff (cost=14.49..1445.87 rows=401 width=4)" " Recheck Cond: ((file_name_date >= '2005-03-01'::date) AND (file_name_date <= '2005-04-30'::date))" " Filter: ((file_name_model_ver)::text = '100'::text)" " -> Bitmap Index Scan on ix_models_direct_file_file_name_date (cost=0.00..14.39 rows=610 width=0)" " Index Cond: ((file_name_date >= '2005-03-01'::date) AND (file_name_date <= '2005-04-30'::date))" " -> Hash (cost=932.60..932.60 rows=8108 width=8)" " -> Bitmap Heap Scan on temp_universe_instruments uuu (cost=231.25..932.60 rows=8108 width=8)" " Recheck Cond: (universe_hash = '5188205190738336870'::bigint)" " -> Bitmap Index Scan on pk_temp_universe_instruments (cost=0.00..229.23 rows=8108 width=0)" " Index Cond: (universe_hash = '5188205190738336870'::bigint)"
seth-p@outlook.com wrote: > The following bug has been logged on the website: > > Bug reference: 13908 > Logged by: Seth > Email address: seth-p@outlook.com > PostgreSQL version: 9.5.0 > Operating system: Windows 10 > Description: > > Below is a copy of a long-ish email I wrote detailing the problem. If it > doesn't come through in a reasonable format, please let me know where I can > email it. Thanks --Seth Here's the copy Seth sent with better formatting. -------------------------- I've only recently started using Postgresql, and have encountered what I believe to be a bug in Postgresql 9.5 on Windows10. Below are 6 queries that are identical except for (a) the date range in the WHERE clause, and (b) whether or not they includeDISTINCT. This is as simple as I could get the queries while still reproducing the bug. The following table summarizesthe number of rows returned by each query: ----------------------------------------------------------------------------------------------------------------------------------- -- Date Range | # rows without DISTINCT | # rows with DISTINCT | Notes | ------------------------------------------------------------------------------|---------------------------------------------------- -- 2005-03-01 - 2005-07-30 | (A) 415,983 | (A-D) 416,075 | DISTINCT *increases* the number of rows returned!| -- 2005-03-01 - 2005-04-30 | (B) 168,886 | (B-D) 168,886 | DISTINCT has no effect | -- 2005-05-01 - 2005-07-30 | (C) 247,189 | (C-D) 247,189 | DISTINCT has no effect | -- sum of sub-range queries | (B) + (C) 416,075 | (B-D) + (C-D) 416,075 | In both cases, sum of 2 queries equals (A-D) | ----------------------------------------------------------------------------------------------------------------------------------- Query (A-D) (with DISTINCT) should not return more rows than query (A) (the identical query without DISTINCT), so clearlysomething is wrong there. Looking at the results of the queries over the two sub-ranges strongly suggests that it is query (A) that is returning toofew rows. Beneath the queries below I also show the EXPLAIN results for queries (A), (A-D), (B), and (B-D). Notice that the plan forquery (A) differs from the other three -- it appears to have an extra "Hash" (highlighted with asterisks) that the othersdo not. I'm afraid I am unable to share the data, but can provide table statistics, index descriptions, or anything else that mightbe useful. Any suggestions for how to proceed? Seth -- (A) 2005-03-01 - 2005-07-30 returns 415,983 rows select count(*) from ( SELECT rrr.* FROM files.models_direct_row_asset_data rrr INNER JOIN files.models_direct_file fff ON fff.idx = rrr.barra_file_idx INNER JOIN files.temp_universe_instruments uuu ON uuu.universe_hash = 5188205190738336870 AND uuu.barrid = rrr.barrid WHERE fff.file_name_model_ver = '100' AND fff.file_name_date BETWEEN '2005-03-01' AND '2005-07-30' ) a -- (A-D) 2005-03-01 - 2005-07-30 DISTNICT returns 416,075 rows select count(*) from ( SELECT DISTINCT rrr.* FROM files.models_direct_row_asset_data rrr INNER JOIN files.models_direct_file fff ON fff.idx = rrr.barra_file_idx INNER JOIN files.temp_universe_instruments uuu ON uuu.universe_hash = 5188205190738336870 AND uuu.barrid = rrr.barrid WHERE fff.file_name_model_ver = '100' AND fff.file_name_date BETWEEN '2005-03-01' AND '2005-07-30' ) ad -- (B) 2005-03-01 - 2005-04-30 returns 168,886 rows select count(*) from ( SELECT rrr.* FROM files.models_direct_row_asset_data rrr INNER JOIN files.models_direct_file fff ON fff.idx = rrr.barra_file_idx INNER JOIN files.temp_universe_instruments uuu ON uuu.universe_hash = 5188205190738336870 AND uuu.barrid = rrr.barrid WHERE fff.file_name_model_ver = '100' AND fff.file_name_date BETWEEN '2005-03-01' AND '2005-04-30' ) b -- (B-D) 2005-03-01 - 2005-04-30 DISTINCT returns 168,886 rows select count(*) from ( SELECT DISTINCT rrr.* FROM files.models_direct_row_asset_data rrr INNER JOIN files.models_direct_file fff ON fff.idx = rrr.barra_file_idx INNER JOIN files.temp_universe_instruments uuu ON uuu.universe_hash = 5188205190738336870 AND uuu.barrid = rrr.barrid WHERE fff.file_name_model_ver = '100' AND fff.file_name_date BETWEEN '2005-03-01' AND '2005-04-30' ) bd -- (C) 2005-05-01 - 2005-07-30 returns 247,189 rows select count(*) from ( SELECT rrr.* FROM files.models_direct_row_asset_data rrr INNER JOIN files.models_direct_file fff ON fff.idx = rrr.barra_file_idx INNER JOIN files.temp_universe_instruments uuu ON uuu.universe_hash = 5188205190738336870 AND uuu.barrid = rrr.barrid WHERE fff.file_name_model_ver = '100' AND fff.file_name_date BETWEEN '2005-05-01' AND '2005-07-30' ) c -- (C-D) 2005-05-01 - 2005-07-30 DISTINCT returns 247,189 rows select count(*) from ( SELECT DISTINCT rrr.* FROM files.models_direct_row_asset_data rrr INNER JOIN files.models_direct_file fff ON fff.idx = rrr.barra_file_idx INNER JOIN files.temp_universe_instruments uuu ON uuu.universe_hash = 5188205190738336870 AND uuu.barrid = rrr.barrid WHERE fff.file_name_model_ver = '100' AND fff.file_name_date BETWEEN '2005-05-01' AND '2005-07-30' ) cd EPXLAIN of queries (A) "Aggregate (cost=1821781.18..1821781.19 rows=1 width=0)" " -> Hash Join (cost=1811365.12..1821096.53 rows=273861 width=0)" " Hash Cond: ((uuu.barrid)::text = (rrr.barrid)::text)" " -> Bitmap Heap Scan on temp_universe_instruments uuu (cost=231.25..932.60 rows=8108 width=8)" " Recheck Cond: (universe_hash = '5188205190738336870'::bigint)" " -> Bitmap Index Scan on pk_temp_universe_instruments (cost=0.00..229.23 rows=8108 width=0)" " Index Cond: (universe_hash = '5188205190738336870'::bigint)" " -> Hash (cost=1796474.21..1796474.21 rows=893492 width=8)" ********************************************************** " -> Hash Join (cost=2341.15..1796474.21 rows=893492 width=8)" " Hash Cond: (rrr.barra_file_idx = fff.idx)" " -> Seq Scan on models_direct_row_asset_data rrr (cost=0.00..1518763.74 rows=71049174 width=12)" " -> Hash (cost=2329.00..2329.00 rows=972 width=4)" " -> Bitmap Heap Scan on models_direct_file fff (cost=35.33..2329.00 rows=972 width=4)" " Recheck Cond: ((file_name_date >= '2005-03-01'::date) AND (file_name_date <= '2005-07-30'::date))" " Filter: ((file_name_model_ver)::text = '100'::text)" " -> Bitmap Index Scan on ix_models_direct_file_file_name_date (cost=0.00..35.08 rows=1479width=0)" " Index Cond: ((file_name_date >= '2005-03-01'::date) AND (file_name_date <= '2005-07-30'::date))" (A-D) "Aggregate (cost=1886439.23..1886439.24 rows=1 width=0)" " -> Unique (cost=1875484.79..1883015.97 rows=273861 width=64)" " -> Sort (cost=1875484.79..1876169.44 rows=273861 width=64)" " Sort Key: rrr.idx, rrr.row_number, rrr.barrid, rrr.yield_pct, rrr.total_risk_pct, rrr.spec_risk_pct, rrr.hist_beta,rrr.pred_beta, rrr.data_date, rrr.barra_file_idx" " -> Hash Join (cost=3375.10..1840453.92 rows=273861 width=64)" " Hash Cond: ((rrr.barrid)::text = (uuu.barrid)::text)" " -> Hash Join (cost=2341.15..1796474.21 rows=893492 width=64)" " Hash Cond: (rrr.barra_file_idx = fff.idx)" " -> Seq Scan on models_direct_row_asset_data rrr (cost=0.00..1518763.74 rows=71049174 width=64)" " -> Hash (cost=2329.00..2329.00 rows=972 width=4)" " -> Bitmap Heap Scan on models_direct_file fff (cost=35.33..2329.00 rows=972 width=4)" " Recheck Cond: ((file_name_date >= '2005-03-01'::date) AND (file_name_date <= '2005-07-30'::date))" " Filter: ((file_name_model_ver)::text = '100'::text)" " -> Bitmap Index Scan on ix_models_direct_file_file_name_date (cost=0.00..35.08 rows=1479width=0)" " Index Cond: ((file_name_date >= '2005-03-01'::date) AND (file_name_date <= '2005-07-30'::date))" " -> Hash (cost=932.60..932.60 rows=8108 width=8)" " -> Bitmap Heap Scan on temp_universe_instruments uuu (cost=231.25..932.60 rows=8108 width=8)" " Recheck Cond: (universe_hash = '5188205190738336870'::bigint)" " -> Bitmap Index Scan on pk_temp_universe_instruments (cost=0.00..229.23 rows=8108 width=0)" " Index Cond: (universe_hash = '5188205190738336870'::bigint)" (B) "Aggregate (cost=1809368.84..1809368.85 rows=1 width=0)" " -> Hash Join (cost=2484.83..1809086.39 rows=112981 width=0)" " Hash Cond: ((rrr.barrid)::text = (uuu.barrid)::text)" " -> Hash Join (cost=1450.88..1790335.13 rows=368611 width=8)" " Hash Cond: (rrr.barra_file_idx = fff.idx)" " -> Seq Scan on models_direct_row_asset_data rrr (cost=0.00..1518763.74 rows=71049174 width=12)" " -> Hash (cost=1445.87..1445.87 rows=401 width=4)" " -> Bitmap Heap Scan on models_direct_file fff (cost=14.49..1445.87 rows=401 width=4)" " Recheck Cond: ((file_name_date >= '2005-03-01'::date) AND (file_name_date <= '2005-04-30'::date))" " Filter: ((file_name_model_ver)::text = '100'::text)" " -> Bitmap Index Scan on ix_models_direct_file_file_name_date (cost=0.00..14.39 rows=610 width=0)" " Index Cond: ((file_name_date >= '2005-03-01'::date) AND (file_name_date <= '2005-04-30'::date))" " -> Hash (cost=932.60..932.60 rows=8108 width=8)" " -> Bitmap Heap Scan on temp_universe_instruments uuu (cost=231.25..932.60 rows=8108 width=8)" " Recheck Cond: (universe_hash = '5188205190738336870'::bigint)" " -> Bitmap Index Scan on pk_temp_universe_instruments (cost=0.00..229.23 rows=8108 width=0)" " Index Cond: (universe_hash = '5188205190738336870'::bigint)" (B-D) "Aggregate (cost=1827336.97..1827336.98 rows=1 width=0)" " -> Unique (cost=1822817.73..1825924.71 rows=112981 width=64)" " -> Sort (cost=1822817.73..1823100.18 rows=112981 width=64)" " Sort Key: rrr.idx, rrr.row_number, rrr.barrid, rrr.yield_pct, rrr.total_risk_pct, rrr.spec_risk_pct, rrr.hist_beta,rrr.pred_beta, rrr.data_date, rrr.barra_file_idx" " -> Hash Join (cost=2484.83..1809086.39 rows=112981 width=64)" " Hash Cond: ((rrr.barrid)::text = (uuu.barrid)::text)" " -> Hash Join (cost=1450.88..1790335.13 rows=368611 width=64)" " Hash Cond: (rrr.barra_file_idx = fff.idx)" " -> Seq Scan on models_direct_row_asset_data rrr (cost=0.00..1518763.74 rows=71049174 width=64)" " -> Hash (cost=1445.87..1445.87 rows=401 width=4)" " -> Bitmap Heap Scan on models_direct_file fff (cost=14.49..1445.87 rows=401 width=4)" " Recheck Cond: ((file_name_date >= '2005-03-01'::date) AND (file_name_date <= '2005-04-30'::date))" " Filter: ((file_name_model_ver)::text = '100'::text)" " -> Bitmap Index Scan on ix_models_direct_file_file_name_date (cost=0.00..14.39 rows=610width=0)" " Index Cond: ((file_name_date >= '2005-03-01'::date) AND (file_name_date <= '2005-04-30'::date))" " -> Hash (cost=932.60..932.60 rows=8108 width=8)" " -> Bitmap Heap Scan on temp_universe_instruments uuu (cost=231.25..932.60 rows=8108 width=8)" " Recheck Cond: (universe_hash = '5188205190738336870'::bigint)" " -> Bitmap Index Scan on pk_temp_universe_instruments (cost=0.00..229.23 rows=8108 width=0)" " Index Cond: (universe_hash = '5188205190738336870'::bigint)" -- Álvaro Herrera http://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
seth-p@outlook.com writes: > Query (A-D) (with DISTINCT) should not return more rows than query (A) (the > identical query without DISTINCT), so clearly something is wrong there. That does seem fishy, but unless you can provide a self-contained test case, it's unlikely that we are going to be able to magically locate the problem. I'd suggest seeing if you can reproduce the issue with some obfuscated or randomly-generated data. regards, tom lane
On Tue, Feb 2, 2016 at 3:52 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote: > seth-p@outlook.com writes: > > Query (A-D) (with DISTINCT) should not return more rows than query (A) > (the > > identical query without DISTINCT), so clearly something is wrong there. > > That does seem fishy, but unless you can provide a self-contained test > case, it's unlikely that we are going to be able to magically locate > the problem. I'd suggest seeing if you can reproduce the issue with > some obfuscated or randomly-generated data. > =E2=80=8BWhile Tom is correct I'd like to make a couple of points... It apparently isn't the DISTINCT query that is increasing the count of rows but rather than the non-DISTINCT version fails to return/count as many as are actually present - but only when dealing with the entire range... =E2=80=8BLacking a reproducible test case you really need to at least suppl= y an EXPLAIN ANALYZE so that actual row counts at each node can be observed. The note about the apparent extra HASH first made me think that there must be some kind of hash collision involved in the data - apparently one that occurs between data points in B and C but not within B or within C...but I fear this might be a red herring. But if it is a collision then the odds of random data exhibiting the problem are quite slim... David J.
On Tue, Feb 2, 2016 at 7:05 PM, Seth P <seth-p@outlook.com> wrote: > Below are the EXPLAIN ANALYZE results. I will try to reproduce the problem > with isolated/toy data, but that may take a while. > Nothing obvious...what type of column is "barrid" and, if it is indeed textual, can you provide some example values? David J.
Below are the EXPLAIN ANALYZE results. I will try to reproduce the problem = with isolated/toy data, but that may take a while. Query A (results believed to be incorrect) "Aggregate (cost=3D1821781.18..1821781.19 rows=3D1 width=3D0) (actual time= =3D15887.259..15887.259 rows=3D1 loops=3D1)" " -> Hash Join (cost=3D1811365.12..1821096.53 rows=3D273861 width=3D0) (= actual time=3D15562.422..15871.122 rows=3D415983 loops=3D1)" " Hash Cond: ((uuu.barrid)::text =3D (rrr.barrid)::text)" " -> Bitmap Heap Scan on temp_universe_instruments uuu (cost=3D231= .25..932.60 rows=3D8108 width=3D8) (actual time=3D0.445..1.281 rows=3D7993 = loops=3D1)" " Recheck Cond: (universe_hash =3D '5188205190738336870'::bigi= nt)" " Heap Blocks: exact=3D44" " -> Bitmap Index Scan on pk_temp_universe_instruments (cost= =3D0.00..229.23 rows=3D8108 width=3D0) (actual time=3D0.436..0.436 rows=3D7= 993 loops=3D1)" " Index Cond: (universe_hash =3D '5188205190738336870'::= bigint)" " -> Hash (cost=3D1796474.21..1796474.21 rows=3D893492 width=3D8) = (actual time=3D15556.367..15556.367 rows=3D1275138 loops=3D1)" " Buckets: 131072 (originally 131072) Batches: 32 (originally= 16) Memory Usage: 3073kB" " -> Hash Join (cost=3D2341.15..1796474.21 rows=3D893492 wid= th=3D8) (actual time=3D5761.544..15363.787 rows=3D1275138 loops=3D1)" " Hash Cond: (rrr.barra_file_idx =3D fff.idx)" " -> Seq Scan on models_direct_row_asset_data rrr (cos= t=3D0.00..1518763.74 rows=3D71049174 width=3D12) (actual time=3D0.002..6316= .855 rows=3D71098547 loops=3D1)" " -> Hash (cost=3D2329.00..2329.00 rows=3D972 width=3D= 4) (actual time=3D0.613..0.613 rows=3D964 loops=3D1)" " Buckets: 1024 Batches: 1 Memory Usage: 42kB" " -> Bitmap Heap Scan on models_direct_file fff = (cost=3D35.33..2329.00 rows=3D972 width=3D4) (actual time=3D0.092..0.516 ro= ws=3D964 loops=3D1)" " Recheck Cond: ((file_name_date >=3D '2005-= 03-01'::date) AND (file_name_date <=3D '2005-07-30'::date))" " Filter: ((file_name_model_ver)::text =3D '= 100'::text)" " Rows Removed by Filter: 540" " Heap Blocks: exact=3D66" " -> Bitmap Index Scan on ix_models_direct_= file_file_name_date (cost=3D0.00..35.08 rows=3D1479 width=3D0) (actual tim= e=3D0.082..0.082 rows=3D1504 loops=3D1)" " Index Cond: ((file_name_date >=3D '2= 005-03-01'::date) AND (file_name_date <=3D '2005-07-30'::date))" "Planning time: 0.866 ms" "Execution time: 15887.534 ms" Query A-D "Aggregate (cost=3D1886439.23..1886439.24 rows=3D1 width=3D0) (actual time= =3D15927.999..15927.999 rows=3D1 loops=3D1)" " -> Unique (cost=3D1875484.79..1883015.97 rows=3D273861 width=3D64) (ac= tual time=3D15745.902..15911.374 rows=3D416075 loops=3D1)" " -> Sort (cost=3D1875484.79..1876169.44 rows=3D273861 width=3D64)= (actual time=3D15745.901..15794.280 rows=3D416075 loops=3D1)" " Sort Key: rrr.idx, rrr.row_number, rrr.barrid, rrr.yield_pct= , rrr.total_risk_pct, rrr.spec_risk_pct, rrr.hist_beta, rrr.pred_beta, rrr.= data_date, rrr.barra_file_idx" " Sort Method: external sort Disk: 30080kB" " -> Hash Join (cost=3D3375.10..1840453.92 rows=3D273861 wid= th=3D64) (actual time=3D5718.845..15502.041 rows=3D416075 loops=3D1)" " Hash Cond: ((rrr.barrid)::text =3D (uuu.barrid)::text)= " " -> Hash Join (cost=3D2341.15..1796474.21 rows=3D8934= 92 width=3D64) (actual time=3D5716.653..15310.931 rows=3D1275138 loops=3D1)= " " Hash Cond: (rrr.barra_file_idx =3D fff.idx)" " -> Seq Scan on models_direct_row_asset_data rrr= (cost=3D0.00..1518763.74 rows=3D71049174 width=3D64) (actual time=3D0.002= ..6262.125 rows=3D71098547 loops=3D1)" " -> Hash (cost=3D2329.00..2329.00 rows=3D972 wi= dth=3D4) (actual time=3D0.630..0.630 rows=3D964 loops=3D1)" " Buckets: 1024 Batches: 1 Memory Usage: 4= 2kB" " -> Bitmap Heap Scan on models_direct_file= fff (cost=3D35.33..2329.00 rows=3D972 width=3D4) (actual time=3D0.101..0.= 535 rows=3D964 loops=3D1)" " Recheck Cond: ((file_name_date >=3D = '2005-03-01'::date) AND (file_name_date <=3D '2005-07-30'::date))" " Filter: ((file_name_model_ver)::text= =3D '100'::text)" " Rows Removed by Filter: 540" " Heap Blocks: exact=3D66" " -> Bitmap Index Scan on ix_models_d= irect_file_file_name_date (cost=3D0.00..35.08 rows=3D1479 width=3D0) (actu= al time=3D0.092..0.092 rows=3D1504 loops=3D1)" " Index Cond: ((file_name_date >= =3D '2005-03-01'::date) AND (file_name_date <=3D '2005-07-30'::date))" " -> Hash (cost=3D932.60..932.60 rows=3D8108 width=3D8= ) (actual time=3D2.085..2.085 rows=3D7993 loops=3D1)" " Buckets: 8192 Batches: 1 Memory Usage: 377kB" " -> Bitmap Heap Scan on temp_universe_instrument= s uuu (cost=3D231.25..932.60 rows=3D8108 width=3D8) (actual time=3D0.463..= 1.255 rows=3D7993 loops=3D1)" " Recheck Cond: (universe_hash =3D '51882051= 90738336870'::bigint)" " Heap Blocks: exact=3D44" " -> Bitmap Index Scan on pk_temp_universe_= instruments (cost=3D0.00..229.23 rows=3D8108 width=3D0) (actual time=3D0.4= 50..0.450 rows=3D7993 loops=3D1)" " Index Cond: (universe_hash =3D '5188= 205190738336870'::bigint)" "Planning time: 0.889 ms" "Execution time: 15932.735 ms" Query B "Aggregate (cost=3D1809368.84..1809368.85 rows=3D1 width=3D0) (actual time= =3D15031.329..15031.330 rows=3D1 loops=3D1)" " -> Hash Join (cost=3D2484.83..1809086.39 rows=3D112981 width=3D0) (act= ual time=3D5653.925..15024.207 rows=3D168886 loops=3D1)" " Hash Cond: ((rrr.barrid)::text =3D (uuu.barrid)::text)" " -> Hash Join (cost=3D1450.88..1790335.13 rows=3D368611 width=3D8= ) (actual time=3D5651.724..14946.845 rows=3D533241 loops=3D1)" " Hash Cond: (rrr.barra_file_idx =3D fff.idx)" " -> Seq Scan on models_direct_row_asset_data rrr (cost=3D0.= 00..1518763.74 rows=3D71049174 width=3D12) (actual time=3D0.002..6188.050 r= ows=3D71098547 loops=3D1)" " -> Hash (cost=3D1445.87..1445.87 rows=3D401 width=3D4) (ac= tual time=3D0.261..0.261 rows=3D391 loops=3D1)" " Buckets: 1024 Batches: 1 Memory Usage: 22kB" " -> Bitmap Heap Scan on models_direct_file fff (cost= =3D14.49..1445.87 rows=3D401 width=3D4) (actual time=3D0.043..0.218 rows=3D= 391 loops=3D1)" " Recheck Cond: ((file_name_date >=3D '2005-03-01'= ::date) AND (file_name_date <=3D '2005-04-30'::date))" " Filter: ((file_name_model_ver)::text =3D '100'::= text)" " Rows Removed by Filter: 219" " Heap Blocks: exact=3D34" " -> Bitmap Index Scan on ix_models_direct_file_f= ile_name_date (cost=3D0.00..14.39 rows=3D610 width=3D0) (actual time=3D0.0= 36..0.036 rows=3D610 loops=3D1)" " Index Cond: ((file_name_date >=3D '2005-03= -01'::date) AND (file_name_date <=3D '2005-04-30'::date))" " -> Hash (cost=3D932.60..932.60 rows=3D8108 width=3D8) (actual ti= me=3D2.108..2.108 rows=3D7993 loops=3D1)" " Buckets: 8192 Batches: 1 Memory Usage: 377kB" " -> Bitmap Heap Scan on temp_universe_instruments uuu (cost= =3D231.25..932.60 rows=3D8108 width=3D8) (actual time=3D0.460..1.280 rows= =3D7993 loops=3D1)" " Recheck Cond: (universe_hash =3D '5188205190738336870'= ::bigint)" " Heap Blocks: exact=3D44" " -> Bitmap Index Scan on pk_temp_universe_instruments = (cost=3D0.00..229.23 rows=3D8108 width=3D0) (actual time=3D0.452..0.452 ro= ws=3D7993 loops=3D1)" " Index Cond: (universe_hash =3D '5188205190738336= 870'::bigint)" "Planning time: 0.850 ms" "Execution time: 15031.386 ms" Query B-D "Aggregate (cost=3D1827336.97..1827336.98 rows=3D1 width=3D0) (actual time= =3D15193.952..15193.952 rows=3D1 loops=3D1)" " -> Unique (cost=3D1822817.73..1825924.71 rows=3D112981 width=3D64) (ac= tual time=3D15122.057..15187.357 rows=3D168886 loops=3D1)" " -> Sort (cost=3D1822817.73..1823100.18 rows=3D112981 width=3D64)= (actual time=3D15122.056..15141.047 rows=3D168886 loops=3D1)" " Sort Key: rrr.idx, rrr.row_number, rrr.barrid, rrr.yield_pct= , rrr.total_risk_pct, rrr.spec_risk_pct, rrr.hist_beta, rrr.pred_beta, rrr.= data_date, rrr.barra_file_idx" " Sort Method: external sort Disk: 12208kB" " -> Hash Join (cost=3D2484.83..1809086.39 rows=3D112981 wid= th=3D64) (actual time=3D5655.552..15024.729 rows=3D168886 loops=3D1)" " Hash Cond: ((rrr.barrid)::text =3D (uuu.barrid)::text)= " " -> Hash Join (cost=3D1450.88..1790335.13 rows=3D3686= 11 width=3D64) (actual time=3D5653.397..14944.115 rows=3D533241 loops=3D1)" " Hash Cond: (rrr.barra_file_idx =3D fff.idx)" " -> Seq Scan on models_direct_row_asset_data rrr= (cost=3D0.00..1518763.74 rows=3D71049174 width=3D64) (actual time=3D0.002= ..6210.401 rows=3D71098547 loops=3D1)" " -> Hash (cost=3D1445.87..1445.87 rows=3D401 wi= dth=3D4) (actual time=3D0.268..0.268 rows=3D391 loops=3D1)" " Buckets: 1024 Batches: 1 Memory Usage: 2= 2kB" " -> Bitmap Heap Scan on models_direct_file= fff (cost=3D14.49..1445.87 rows=3D401 width=3D4) (actual time=3D0.053..0.= 236 rows=3D391 loops=3D1)" " Recheck Cond: ((file_name_date >=3D = '2005-03-01'::date) AND (file_name_date <=3D '2005-04-30'::date))" " Filter: ((file_name_model_ver)::text= =3D '100'::text)" " Rows Removed by Filter: 219" " Heap Blocks: exact=3D34" " -> Bitmap Index Scan on ix_models_d= irect_file_file_name_date (cost=3D0.00..14.39 rows=3D610 width=3D0) (actua= l time=3D0.047..0.047 rows=3D610 loops=3D1)" " Index Cond: ((file_name_date >= =3D '2005-03-01'::date) AND (file_name_date <=3D '2005-04-30'::date))" " -> Hash (cost=3D932.60..932.60 rows=3D8108 width=3D8= ) (actual time=3D2.050..2.050 rows=3D7993 loops=3D1)" " Buckets: 8192 Batches: 1 Memory Usage: 377kB" " -> Bitmap Heap Scan on temp_universe_instrument= s uuu (cost=3D231.25..932.60 rows=3D8108 width=3D8) (actual time=3D0.467..= 1.239 rows=3D7993 loops=3D1)" " Recheck Cond: (universe_hash =3D '51882051= 90738336870'::bigint)" " Heap Blocks: exact=3D44" " -> Bitmap Index Scan on pk_temp_universe_= instruments (cost=3D0.00..229.23 rows=3D8108 width=3D0) (actual time=3D0.4= 57..0.457 rows=3D7993 loops=3D1)" " Index Cond: (universe_hash =3D '5188= 205190738336870'::bigint)" "Planning time: 0.883 ms" "Execution time: 15197.640 ms" Query C "Aggregate (cost=3D1818525.28..1818525.29 rows=3D1 width=3D0) (actual time= =3D15181.269..15181.269 rows=3D1 loops=3D1)" " -> Hash Join (cost=3D2826.27..1818128.02 rows=3D158907 width=3D0) (act= ual time=3D5814.662..15170.804 rows=3D247189 loops=3D1)" " Hash Cond: ((rrr.barrid)::text =3D (uuu.barrid)::text)" " -> Hash Join (cost=3D1792.32..1792174.92 rows=3D518446 width=3D8= ) (actual time=3D5812.495..15061.248 rows=3D741897 loops=3D1)" " Hash Cond: (rrr.barra_file_idx =3D fff.idx)" " -> Seq Scan on models_direct_row_asset_data rrr (cost=3D0.= 00..1518763.74 rows=3D71049174 width=3D12) (actual time=3D0.002..6233.423 r= ows=3D71098547 loops=3D1)" " -> Hash (cost=3D1785.27..1785.27 rows=3D564 width=3D4) (ac= tual time=3D0.367..0.367 rows=3D573 loops=3D1)" " Buckets: 1024 Batches: 1 Memory Usage: 29kB" " -> Bitmap Heap Scan on models_direct_file fff (cost= =3D21.01..1785.27 rows=3D564 width=3D4) (actual time=3D0.058..0.305 rows=3D= 573 loops=3D1)" " Recheck Cond: ((file_name_date >=3D '2005-05-01'= ::date) AND (file_name_date <=3D '2005-07-30'::date))" " Filter: ((file_name_model_ver)::text =3D '100'::= text)" " Rows Removed by Filter: 321" " Heap Blocks: exact=3D43" " -> Bitmap Index Scan on ix_models_direct_file_f= ile_name_date (cost=3D0.00..20.87 rows=3D858 width=3D0) (actual time=3D0.0= 51..0.051 rows=3D894 loops=3D1)" " Index Cond: ((file_name_date >=3D '2005-05= -01'::date) AND (file_name_date <=3D '2005-07-30'::date))" " -> Hash (cost=3D932.60..932.60 rows=3D8108 width=3D8) (actual ti= me=3D2.066..2.066 rows=3D7993 loops=3D1)" " Buckets: 8192 Batches: 1 Memory Usage: 377kB" " -> Bitmap Heap Scan on temp_universe_instruments uuu (cost= =3D231.25..932.60 rows=3D8108 width=3D8) (actual time=3D0.463..1.228 rows= =3D7993 loops=3D1)" " Recheck Cond: (universe_hash =3D '5188205190738336870'= ::bigint)" " Heap Blocks: exact=3D44" " -> Bitmap Index Scan on pk_temp_universe_instruments = (cost=3D0.00..229.23 rows=3D8108 width=3D0) (actual time=3D0.454..0.454 ro= ws=3D7993 loops=3D1)" " Index Cond: (universe_hash =3D '5188205190738336= 870'::bigint)" "Planning time: 0.866 ms" "Execution time: 15181.330 ms" Query C-D "Aggregate (cost=3D1844190.13..1844190.14 rows=3D1 width=3D0) (actual time= =3D15495.232..15495.233 rows=3D1 loops=3D1)" " -> Unique (cost=3D1837833.85..1842203.79 rows=3D158907 width=3D64) (ac= tual time=3D15388.762..15485.467 rows=3D247189 loops=3D1)" " -> Sort (cost=3D1837833.85..1838231.12 rows=3D158907 width=3D64)= (actual time=3D15388.761..15416.951 rows=3D247189 loops=3D1)" " Sort Key: rrr.idx, rrr.row_number, rrr.barrid, rrr.yield_pct= , rrr.total_risk_pct, rrr.spec_risk_pct, rrr.hist_beta, rrr.pred_beta, rrr.= data_date, rrr.barra_file_idx" " Sort Method: external sort Disk: 17880kB" " -> Hash Join (cost=3D2826.27..1818128.02 rows=3D158907 wid= th=3D64) (actual time=3D5832.453..15240.599 rows=3D247189 loops=3D1)" " Hash Cond: ((rrr.barrid)::text =3D (uuu.barrid)::text)= " " -> Hash Join (cost=3D1792.32..1792174.92 rows=3D5184= 46 width=3D64) (actual time=3D5830.312..15121.828 rows=3D741897 loops=3D1)" " Hash Cond: (rrr.barra_file_idx =3D fff.idx)" " -> Seq Scan on models_direct_row_asset_data rrr= (cost=3D0.00..1518763.74 rows=3D71049174 width=3D64) (actual time=3D0.002= ..6244.816 rows=3D71098547 loops=3D1)" " -> Hash (cost=3D1785.27..1785.27 rows=3D564 wi= dth=3D4) (actual time=3D0.360..0.360 rows=3D573 loops=3D1)" " Buckets: 1024 Batches: 1 Memory Usage: 2= 9kB" " -> Bitmap Heap Scan on models_direct_file= fff (cost=3D21.01..1785.27 rows=3D564 width=3D4) (actual time=3D0.055..0.= 310 rows=3D573 loops=3D1)" " Recheck Cond: ((file_name_date >=3D = '2005-05-01'::date) AND (file_name_date <=3D '2005-07-30'::date))" " Filter: ((file_name_model_ver)::text= =3D '100'::text)" " Rows Removed by Filter: 321" " Heap Blocks: exact=3D43" " -> Bitmap Index Scan on ix_models_d= irect_file_file_name_date (cost=3D0.00..20.87 rows=3D858 width=3D0) (actua= l time=3D0.048..0.048 rows=3D894 loops=3D1)" " Index Cond: ((file_name_date >= =3D '2005-05-01'::date) AND (file_name_date <=3D '2005-07-30'::date))" " -> Hash (cost=3D932.60..932.60 rows=3D8108 width=3D8= ) (actual time=3D2.043..2.043 rows=3D7993 loops=3D1)" " Buckets: 8192 Batches: 1 Memory Usage: 377kB" " -> Bitmap Heap Scan on temp_universe_instrument= s uuu (cost=3D231.25..932.60 rows=3D8108 width=3D8) (actual time=3D0.466..= 1.240 rows=3D7993 loops=3D1)" " Recheck Cond: (universe_hash =3D '51882051= 90738336870'::bigint)" " Heap Blocks: exact=3D44" " -> Bitmap Index Scan on pk_temp_universe_= instruments (cost=3D0.00..229.23 rows=3D8108 width=3D0) (actual time=3D0.4= 56..0.456 rows=3D7993 loops=3D1)" " Index Cond: (universe_hash =3D '5188= 205190738336870'::bigint)" "Planning time: 0.876 ms" "Execution time: 15499.128 ms" ________________________________ From: David G. Johnston <david.g.johnston@gmail.com> Sent: Tuesday, February 2, 2016 6:27 PM To: Tom Lane Cc: seth-p@outlook.com; pgsql-bugs@postgresql.org Subject: Re: [BUGS] BUG #13908: Query returns too few rows On Tue, Feb 2, 2016 at 3:52 PM, Tom Lane <tgl@sss.pgh.pa.us<mailto:tgl@sss.= pgh.pa.us>> wrote: seth-p@outlook.com<mailto:seth-p@outlook.com> writes: > Query (A-D) (with DISTINCT) should not return more rows than query (A) (t= he > identical query without DISTINCT), so clearly something is wrong there. That does seem fishy, but unless you can provide a self-contained test case, it's unlikely that we are going to be able to magically locate the problem. I'd suggest seeing if you can reproduce the issue with some obfuscated or randomly-generated data. ?While Tom is correct I'd like to make a couple of points... It apparently isn't the DISTINCT query that is increasing the count of rows= but rather than the non-DISTINCT version fails to return/count as many as = are actually present - but only when dealing with the entire range... ?Lacking a reproducible test case you really need to at least supply an EXP= LAIN ANALYZE so that actual row counts at each node can be observed. The note about the apparent extra HASH first made me think that there must = be some kind of hash collision involved in the data - apparently one that o= ccurs between data points in B and C but not within B or within C...but I f= ear this might be a red herring. But if it is a collision then the odds of= random data exhibiting the problem are quite slim... David J.
On Tue, Feb 2, 2016 at 9:41 PM, Seth P <seth-p@outlook.com> wrote: > "barrid" is "character varying(8) NOT NULL", and some examples are > 'CANCEJ1' and 'USA06Z1'. > Consider... =E2=80=8BCREATE TABLE "rrr_temp" AS SELECT =E2=80=8Bidx, barrid FROM "rrr" = AND ...; --see note below CREATE TABLE "uuu_temp" AS SELECT barrid FROM "uuu" WHERE universe_hash =3D #; -- should get 7,993 record modify the WHERE clause for "rrr_temp" so you copy in the same records into rrr_temp as matched in the full query: # 1,275,138 from the explain analyze for A (and A-D too) Now run simple join sub-queries inside your count(*) If it repeats you should be able to supply the temporary table data as unless barrid values are somehow super-secret. You do not have to send the data to the public list either - you can send it privately to someone (not me, Tom should be good but confirm before sending). Hope that helps. David J.
"barrid" is "character varying(8) NOT NULL", and some examples are 'CANCEJ1= ' and 'USA06Z1'. In case it helps, the following are the table definitions and all the const= raints and indices I have on the three tables: files.models_direct_file ("fff") CREATE TABLE files.models_direct_file ( idx serial NOT NULL, file_class character varying(32) NOT NULL, file_name character varying(64) NOT NULL, file_name_data character varying(32) NOT NULL, file_name_date date, header_columns character varying(32)[], file_created timestamp without time zone, file_imported_to_db timestamp without time zone, num_rows integer, file_name_model character varying(8) NOT NULL, file_name_model_horizon character varying(1) NOT NULL, file_name_exchange character varying(8) NOT NULL, file_name_etf character varying(12) NOT NULL, file_name_model_forecast_horizon character varying(1) NOT NULL, file_name_model_speed character varying(1) NOT NULL, file_name_model_ver character varying(3) NOT NULL, header_vendor character varying(16), header_model_ver character varying(3), header_release_date date, header_release_datetime timestamp without time zone, header_last_modified_date date, header_bim_ver character varying(4), header_bimef_ver character varying(4), CONSTRAINT pk_models_direct_file PRIMARY KEY (idx) ) WITH ( OIDS=3DFALSE ); CREATE INDEX ix_models_direct_file_file_name_date ON files.models_direct_file USING btree (file_name_date); CREATE UNIQUE INDEX ix_models_direct_file_unique ON files.models_direct_file USING btree (file_name COLLATE pg_catalog."default"); files.models_direct_row_asset_data ("rrr") CREATE TABLE files.models_direct_row_asset_data ( idx serial NOT NULL, row_number integer NOT NULL, barrid character varying(8) NOT NULL, yield_pct double precision, total_risk_pct double precision, spec_risk_pct double precision, hist_beta double precision, pred_beta double precision, data_date date NOT NULL, barra_file_idx integer NOT NULL, CONSTRAINT pk_models_direct_row_asset_data PRIMARY KEY (idx), CONSTRAINT fk_models_direct_row_asset_data_barra_file_idx_models_direct_f= i FOREIGN KEY (barra_file_idx) REFERENCES files.models_direct_file (idx) MATCH SIMPLE ON UPDATE CASCADE ON DELETE CASCADE DEFERRABLE INITIALLY IMMEDIATE ) WITH ( OIDS=3DFALSE ); CREATE INDEX ix_models_direct_row_asset_data_barrid ON files.models_direct_row_asset_data USING btree (barrid COLLATE pg_catalog."default"); CREATE INDEX ix_models_direct_row_asset_data_data_date ON files.models_direct_row_asset_data USING btree (data_date); CREATE UNIQUE INDEX ix_models_direct_row_asset_data_unique ON files.models_direct_row_asset_data USING btree (barra_file_idx, row_number); temp_universe_instruments ("uuu") CREATE TABLE files.temp_universe_instruments ( universe_hash bigserial NOT NULL, barrid character varying(8) NOT NULL, CONSTRAINT pk_temp_universe_instruments PRIMARY KEY (universe_hash, barri= d) ) WITH ( OIDS=3DFALSE ); no indices ________________________________ From: David G. Johnston <david.g.johnston@gmail.com> Sent: Tuesday, February 2, 2016 10:04 PM To: Seth P Cc: Tom Lane; pgsql-bugs@postgresql.org Subject: Re: [BUGS] BUG #13908: Query returns too few rows On Tue, Feb 2, 2016 at 7:05 PM, Seth P <seth-p@outlook.com<mailto:seth-p@ou= tlook.com>> wrote: Below are the EXPLAIN ANALYZE results. I will try to reproduce the problem = with isolated/toy data, but that may take a while. Nothing obvious...what type of column is "barrid" and, if it is indeed text= ual, can you provide some example values? David J.
Adding back the list so that everyone can see the latest finding. Adding in the original bug block too... =E2=80=8B The following bug has been logged on the website: Bug reference: 13908 Logged by: Seth Email address: seth-p@outlook.com PostgreSQL version: 9.5.0 Operating system: Windows 10 Description: *=E2=80=8BNext request, Seth*: please restore your dump into a clean databa= se and see what results you get. Also, please run: SELECT version(); and provide the results.=E2=80=8B =E2=80=8BMy findings =E2=80=8B- there is=E2=80=8B a smaller count for =E2=80=8Bthe =E2=80=8B DISTINCT than without.=E2=80=8B =E2=80=8B I successfully restored your pg_dump file=E2=80=8B, vacuum analyzed it, the= n ran the two counting queries. Here are my results. The DISTINCT plan has an actual count of 415,874 while the non-DISTINCT plan resulted in 415,967; *thus DISTINCT removed 93 duplicates.* Looking back at your most recent email your numbers are 415,983 and 416,009; an increase of 26 by adding DISTINCT...and not matching either of these numbers. *version* PostgreSQL 9.5.0 on x86_64-pc-linux-gnu, compiled by gcc (Ubuntu 4.8.2-19ubuntu1) 4.8.2, 64-bit =E2=80=8BInstalled into the default postgres database which has an encoding= of en_US.UTF-8 (NB: had to use pg_database as I couldn't located a psql meta-command to list databases...am I missing something here?) =E2=80=8B The follow are the results of my EXPLAIN ANALYZE confirmed by running the actual count queries. QUERY PLAN Aggregate (cost=3D1464939.22..1464939.23 rows=3D1 width=3D0) (actual time=3D151609.418..151609.419 rows=3D1 loops=3D1) * -> Hash Join (cost=3D1454885.92..1464269.54 rows=3D267870 width=3D0) (= actual time=3D150567.030..151188.740 rows=3D415967 loops=3D1)* Hash Cond: ((uuu.bababa)::text =3D (rrr.bababa)::text) -> Index Only Scan using pk_uuu on uuu (cost=3D0.42..270.01 rows=3D8091 width=3D8) (actual time=3D0.019..9.337 rows=3D7993 loops=3D1) Index Cond: (universe_hash =3D '5188205190738336870'::bigint) Heap Fetches: 0 -> Hash (cost=3D1440572.59..1440572.59 rows=3D872393 width=3D8) (= actual time=3D150566.397..150566.397 rows=3D1275138 loops=3D1) Buckets: 131072 (originally 131072) Batches: 32 (originally 16) Memory Usage: 3073kB -> Hash Join (cost=3D819.47..1440572.59 rows=3D872393 width= =3D8) (actual time=3D11865.529..149038.533 rows=3D1275138 loops=3D1) Hash Cond: (rrr.fff_idx =3D fff.idx) -> Seq Scan on rrr (cost=3D0.00..1164409.32 rows=3D71098632 width=3D12) (actual time=3D0.006..73136.366 rows=3D71098547= loops=3D1) -> Hash (cost=3D807.58..807.58 rows=3D951 width=3D4) (actual time=3D3.458..3.458 rows=3D964 loops=3D1) Buckets: 1024 Batches: 1 Memory Usage: 42kB -> Bitmap Heap Scan on fff (cost=3D30.98..807.5= 8 rows=3D951 width=3D4) (actual time=3D0.133..1.843 rows=3D964 loops=3D1) Recheck Cond: ((file_name_date >=3D '2005-03-01'::date) AND (file_name_date <=3D '2005-07-30'::date)) Filter: ((file_name_model_ver)::text =3D '100'::text) Rows Removed by Filter: 540 Heap Blocks: exact=3D30 -> Bitmap Index Scan on ix_fff_file_name_date (cost=3D0.00..30.74 rows=3D1445 width=3D0) (actual time=3D0.117..0.117 rows=3D1504 loops=3D1) Index Cond: ((file_name_date >=3D '2005-03-01'::date) AND (file_name_date <=3D '2005-07-30'::date)) Planning time: 1.727 ms Execution time: 151609.494 ms QUERY PLAN Aggregate (cost=3D1504689.02..1504689.03 rows=3D1 width=3D0) (actual time=3D155253.758..155253.759 rows=3D1 loops=3D1) * -> Unique (cost=3D1497322.60..1501340.65 rows=3D267870 width=3D24) (ac= tual time=3D153375.583..154829.461 rows=3D415874 loops=3D1)* -> Sort (cost=3D1497322.60..1497992.27 rows=3D267870 width=3D24) (actual time=3D153375.578..153919.245 rows=3D415874 loops=3D1) Sort Key: rrr.idx, rrr.row_number, rrr.bababa, rrr.data_date, rrr.fff_idx Sort Method: external merge Disk: 13784kB -> Hash Join (cost=3D1456589.92..1467677.54 rows=3D267870 width=3D24) (actual time=3D151982.289..152665.099 rows=3D415874 loops=3D1) Hash Cond: ((uuu.bababa)::text =3D (rrr.bababa)::text) -> Index Only Scan using pk_uuu on uuu (cost=3D0.42..270.01 rows=3D8091 width=3D8) (actual time=3D0.012..9.359 ro= ws=3D7993 loops=3D1) Index Cond: (universe_hash =3D '5188205190738336870'::bigint) Heap Fetches: 0 -> Hash (cost=3D1440572.59..1440572.59 rows=3D872393 width=3D24) (actual time=3D151981.919..151981.919 rows=3D1275138 loops=3D1) Buckets: 65536 (originally 65536) Batches: 32 (originally 16) Memory Usage: 3585kB -> Hash Join (cost=3D819.47..1440572.59 rows=3D872393 width=3D24) (actual time=3D12037.549..150408.756 rows=3D12751= 38 loops=3D1) Hash Cond: (rrr.fff_idx =3D fff.idx) -> Seq Scan on rrr (cost=3D0.00..1164409.= 32 rows=3D71098632 width=3D24) (actual time=3D0.004..73673.708 rows=3D71098547= loops=3D1) -> Hash (cost=3D807.58..807.58 rows=3D951 width=3D4) (actual time=3D2.360..2.360 rows=3D964 loops=3D1) Buckets: 1024 Batches: 1 Memory Usage: 42kB -> Bitmap Heap Scan on fff (cost=3D30.98..807.58 rows=3D951 width=3D4) (actual time=3D0.123..1.293 ro= ws=3D964 loops=3D1) Recheck Cond: ((file_name_date >=3D '2005-03-01'::date) AND (file_name_date <=3D '2005-07-30'::date)) Filter: ((file_name_model_ver)::text =3D '100'::text) Rows Removed by Filter: 540 Heap Blocks: exact=3D30 -> Bitmap Index Scan on ix_fff_file_name_date (cost=3D0.00..30.74 rows=3D1445 width=3D0) (actual time=3D0.111..0.111 rows=3D1504 loops=3D1) Index Cond: ((file_name_date >=3D '2005-03-01'::date) AND (file_name_date <=3D '2005-07-30'::date)) Planning time: 0.668 ms Execution time: 155255.933 ms
Tom, we really need you to chime in here. On Thu, Feb 4, 2016 at 2:58 PM, David G. Johnston < david.g.johnston@gmail.com> wrote: > Adding back the list so that everyone can see the latest finding. Adding > in the original bug block too... > =E2=80=8B > > The following bug has been logged on the website: > > Bug reference: 13908 > Logged by: Seth > Email address: seth-p@outlook.com > PostgreSQL version: 9.5.0 > Operating system: Windows 10 > Description: > > > * -> Unique (cost=3D1497322.60..1501340.65 rows=3D267870 width=3D24) (= actual > time=3D153375.583..154829.461 rows=3D415874 loops=3D1)* > > =E2=80=8BWithout running any DML I just got this result on the DISTINCT que= ry...=E2=80=8B *=E2=80=8B -> Unique (cost=3D1519634.64..1520973.99 rows=3D200 width=3D4= 8) (actual time=3D161695.425..163174.422 rows=3D416075 loops=3D1)* =E2=80=8B There is nothing in the SQL=E2=80=8B itself that would invoke an order depe= ndency... The query, the explain analyze on the first pass and the explain analyze on the second pass. *The second-level Hash Join combines/sees, in both cases, 7,993 and 1,275,138 records but depending on the LEFT/RIGHT order of the sub-nodes appears to provide a different result.* EXPLAIN ANALYZE select count(*) from ( SELECT DISTINCT rrr FROM public.rrr INNER JOIN public.fff ON fff.idx =3D rrr.fff_idx INNER JOIN public.uuu ON uuu.universe_hash =3D 5188205190738336870 AND uuu.bababa =3D rrr.bababa WHERE fff.file_name_model_ver =3D '100' AND fff.file_name_date BETWEEN '2005-03-01' AND '2005-07-30' ) ad QUERY PLAN Aggregate (cost=3D1504689.02..1504689.03 rows=3D1 width=3D0) (actual time=3D155253.758..155253.759 rows=3D1 loops=3D1) -> Unique (cost=3D1497322.60..1501340.65 rows=3D267870 width=3D24) *(ac= tual time=3D153375.583..154829.461 rows=3D415874 loops=3D1)* -> Sort (cost=3D1497322.60..1497992.27 rows=3D267870 width=3D24) (actual time=3D153375.578..153919.245 rows=3D415874 loops=3D1) Sort Key: rrr.idx, rrr.row_number, rrr.bababa, rrr.data_date, rrr.fff_idx Sort Method: external merge Disk: 13784kB -> Hash Join (cost=3D1456589.92..1467677.54 rows=3D267870 width=3D24) (actual time=3D151982.289..152665.099 rows=3D415874 loops=3D1) Hash Cond: ((uuu.bababa)::text =3D (rrr.bababa)::text) -> Index Only Scan using pk_uuu on uuu (cost=3D0.42..270.01 rows=3D8091 width=3D8) (actual time=3D0.012..9.359 ro= ws=3D*7993* loops=3D1) Index Cond: (universe_hash =3D '5188205190738336870'::bigint) Heap Fetches: 0 -> Hash (cost=3D1440572.59..1440572.59 rows=3D872393 width=3D24) (actual time=3D151981.919..151981.919 rows=3D*1275138* loops=3D= 1) Buckets: 65536 (originally 65536) Batches: 32 (originally 16) Memory Usage: 3585kB -> Hash Join (cost=3D819.47..1440572.59 rows=3D872393 width=3D24) (actual time=3D12037.549..150408.756 rows=3D12751= 38 loops=3D1) Hash Cond: (rrr.fff_idx =3D fff.idx) -> Seq Scan on rrr (cost=3D0.00..1164409.= 32 rows=3D71098632 width=3D24) (actual time=3D0.004..73673.708 rows=3D71098547= loops=3D1) -> Hash (cost=3D807.58..807.58 rows=3D951 width=3D4) (actual time=3D2.360..2.360 rows=3D964 loops=3D1) Buckets: 1024 Batches: 1 Memory Usage: 42kB -> Bitmap Heap Scan on fff (cost=3D30.98..807.58 rows=3D951 width=3D4) (actual time=3D0.123..1.293 ro= ws=3D964 loops=3D1) Recheck Cond: ((file_name_date >=3D '2005-03-01'::date) AND (file_name_date <=3D '2005-07-30'::date)) Filter: ((file_name_model_ver)::text =3D '100'::text) Rows Removed by Filter: 540 Heap Blocks: exact=3D30 -> Bitmap Index Scan on ix_fff_file_name_date (cost=3D0.00..30.74 rows=3D1445 width=3D0) (actual time=3D0.111..0.111 rows=3D1504 loops=3D1) Index Cond: ((file_name_date >=3D '2005-03-01'::date) AND (file_name_date <=3D '2005-07-30'::date)) Planning time: 0.668 ms Execution time: 155255.933 ms QUERY PLAN Aggregate (cost=3D1520976.49..1520976.50 rows=3D1 width=3D0) (actual time=3D163603.573..163603.574 rows=3D1 loops=3D1) -> Unique (cost=3D1519634.64..1520973.99 rows=3D200 width=3D48) *(actua= l time=3D161695.425..163174.422 rows=3D416075 loops=3D1)* -> Sort (cost=3D1519634.64..1520304.32 rows=3D267870 width=3D48) (actual time=3D161695.393..162157.673 rows=3D416075 loops=3D1) Sort Key: rrr.* Sort Method: external sort Disk: 22376kB -> Hash Join (cost=3D1190.62..1487242.09 rows=3D267870 width=3D48) (actual time=3D12556.229..158035.711 rows=3D416075 loops=3D1) Hash Cond: ((rrr.bababa)::text =3D (uuu.bababa)::text) -> Hash Join (cost=3D819.47..1440572.59 rows=3D872393 width=3D56) (actual time=3D12538.212..156077.489 rows=3D*1275138 *loops=3D1= ) Hash Cond: (rrr.fff_idx =3D fff.idx) -> Seq Scan on rrr (cost=3D0.00..1164409.32 rows=3D71098632 width=3D60) (actual time=3D0.008..82185.329 rows=3D71098547= loops=3D1) -> Hash (cost=3D807.58..807.58 rows=3D951 width= =3D4) (actual time=3D2.351..2.351 rows=3D964 loops=3D1) Buckets: 1024 Batches: 1 Memory Usage: 42kB -> Bitmap Heap Scan on fff (cost=3D30.98..807.58 rows=3D951 width=3D4) (actual time=3D0.097..1.307 ro= ws=3D964 loops=3D1) Recheck Cond: ((file_name_date >=3D '2005-03-01'::date) AND (file_name_date <=3D '2005-07-30'::date)) Filter: ((file_name_model_ver)::text =3D '100'::text) Rows Removed by Filter: 540 Heap Blocks: exact=3D30 -> Bitmap Index Scan on ix_fff_file_name_date (cost=3D0.00..30.74 rows=3D1445 width=3D0) (actual time=3D0.086..0.086 rows=3D1504 loops=3D1) Index Cond: ((file_name_date >= =3D '2005-03-01'::date) AND (file_name_date <=3D '2005-07-30'::date)) -> Hash (cost=3D270.01..270.01 rows=3D8091 width=3D8) (actual time=3D17.233..17.233 rows=3D7993 loops=3D1) Buckets: 8192 Batches: 1 Memory Usage: 377kB -> Index Only Scan using pk_uuu on uuu (cost=3D0.42..270.01 rows=3D8091 width=3D8) (actual time=3D0.012..8.525 ro= ws=3D*7993 *loops=3D1) Index Cond: (universe_hash =3D '5188205190738336870'::bigint) Heap Fetches: 0 Planning time: 0.642 ms Execution time: 163606.571 ms
On Thu, Feb 4, 2016 at 2:56 PM, Seth P <seth-p@outlook.com> wrote: > Meanwhile, your results are curious not just because they differ from > mine, but because you observe the DISTINCT removing *any* duplicates. > There shouldn't be any, since rrr.idx is a unique serial (idx integer NOT > NULL DEFAULT nextval('rrr_idx_seq'::regclass)). In particular, the > following query returns no rows: > > SELECT rrr.idx FROM public.rrr GROUP BY rrr.idx HAVING count(*)>1 > > Put another way, in your database, can you find the duplicates being > removed by DISTINCT > B =E2=80=8But the query is written as a series of INNER JOINs against "rrr" a= nd so its output is not constrained by UNIQUE(rrr.idx). So it very well may return multiple rows for a given rrr.idx but when you restrict the output to "rrr.*" and add DISTINCT the result is fewer records since now you only have one of each rrr.idx. =E2=80=8B =E2=80=8B =E2=80=8BI made one possibly meaningful change when I reported my discrepan= cy earlier. The query with the =E2=80=8B416,075 DISTINCT row count uses "SELE= CT DISTINCT rrr" while the one returning 415,874 uses "SELECT DISTINCT rrr.*". =E2=80=8BThat said, running the following returns zero records: =E2=80=8BSELECT rrr.idx, count(*) FROM public.rrr INNER JOIN public.fff ON fff.idx =3D rrr.fff_idx INNER JOIN public.uuu ON uuu.universe_hash =3D 5188205190738336870 AND uuu.bababa =3D rrr.bababa WHERE fff.file_name_model_ver =3D '100' AND fff.file_name_date BETWEEN '2005-03-01' AND '2005-07-30' GROUP BY rrr.idx HAVING count(*) > 1 =E2=80=8BSo indeed the query does not result in multiple rrr.idx values bei= ng output for the DISTINCT to remove. =E2=80=8BDavid J.=E2=80=8B
"David G. Johnston" <david.g.johnston@gmail.com> writes: > *The second-level Hash Join combines/sees, in both cases, 7,993 and > 1,275,138 records but depending on the LEFT/RIGHT order of the sub-nodes > appears to provide a different result.* Hmm, that's pretty fishy; and given all the hacking that's gone on lately on hash join, 9.5 introducing a bug there wouldn't be all that astonishing. But I decline to try to find it without a self-contained test case. regards, tom lane
On Thu, Feb 4, 2016 at 3:13 PM, David G. Johnston < david.g.johnston@gmail.com> wrote: > Tom, we really need you to chime in here. > > On Thu, Feb 4, 2016 at 2:58 PM, David G. Johnston < > david.g.johnston@gmail.com> wrote: > >> Adding back the list so that everyone can see the latest finding. Addin= g >> in the original bug block too... >> =E2=80=8B >> >> The following bug has been logged on the website: >> >> Bug reference: 13908 >> Logged by: Seth >> Email address: seth-p@outlook.com >> PostgreSQL version: 9.5.0 >> Operating system: Windows 10 >> Description: >> >> >> * -> Unique (cost=3D1497322.60..1501340.65 rows=3D267870 width=3D24) = (actual >> time=3D153375.583..154829.461 rows=3D415874 loops=3D1)* >> >> > > =E2=80=8BWithout running any DML I just got this result on the DISTINCT q= uery...=E2=80=8B > > *=E2=80=8B -> Unique (cost=3D1519634.64..1520973.99 rows=3D200 width= =3D48) (actual > time=3D161695.425..163174.422 rows=3D416075 loops=3D1)* > =E2=80=8B > =E2=80=8BAccording to 9.3 this 416,075 count is the correct one - and I got= the same count with and without distinct executed multiple times each. =E2=80=8BMy next thought is to see which 300 or so rows that are being left= out in 9.5 appear in 9.3....=E2=80=8B =E2=80=8BDavid J.=E2=80=8B
On Thu, Feb 4, 2016 at 4:28 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote: > "David G. Johnston" <david.g.johnston@gmail.com> writes: > > *The second-level Hash Join combines/sees, in both cases, 7,993 and > > 1,275,138 records but depending on the LEFT/RIGHT order of the sub-node= s > > appears to provide a different result.* > > Hmm, that's pretty fishy; and given all the hacking that's gone on lately > on hash join, 9.5 introducing a bug there wouldn't be all that astonishin= g. > But I decline to try to find it without a self-contained test case. > > =E2=80=8BSo, one of the tables involved has 70M-ish rows of which only mayb= e 2M-ish of them are necessary to fulfill the query in terms of getting the right answer. Realizing this I deleted the other 68M records and then immediately (same transaction) run the counting query and find that I still get an incorrect result. I ran a count instead of an explain analyze so I'm not sure exactly what it did behind the scenes. Regardless, I got the under-counting behavior. I then commit the transaction, run vacuum analyze, and the re-run the counting query and that completes I now get the correct count. Do you expect that some portion of the 68M records that were deleted would be required to diagnose the problem or can knobs be twiddled in some way to get similar behavior exhibited without them actually being present. The fact that the records were deleted, but not vacuumed, and a wrong result was returned makes me think it should be possible but I don't know enough to say for sure or to make informed decisions as to which knobs to turn (if indeed such knobs are exposed since I do not have source-editing or debugging capabilities). David J =E2=80=8B =E2=80=8B
On Thu, Feb 4, 2016 at 8:57 PM, David G. Johnston < david.g.johnston@gmail.com> wrote: > On Thu, Feb 4, 2016 at 4:28 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote: > >> "David G. Johnston" <david.g.johnston@gmail.com> writes: >> > *The second-level Hash Join combines/sees, in both cases, 7,993 and >> > 1,275,138 records but depending on the LEFT/RIGHT order of the sub-nod= es >> > appears to provide a different result.* >> >> Hmm, that's pretty fishy; and given all the hacking that's gone on latel= y >> on hash join, 9.5 introducing a bug there wouldn't be all that >> astonishing. >> But I decline to try to find it without a self-contained test case. >> >> > =E2=80=8BSo, one of the tables involved has 70M-ish rows of which only ma= ybe > 2M-ish of them are necessary to fulfill the query in terms of getting the > right answer. Realizing this I deleted the other 68M records and then > immediately (same transaction) run the counting query and find that I sti= ll > get an incorrect result. I ran a count instead of an explain analyze so > I'm not sure exactly what it did behind the scenes. Regardless, I got th= e > under-counting behavior. I then commit the transaction, run vacuum > analyze, and the re-run the counting query and that completes I now get t= he > correct count. > > Do you expect that some portion of the 68M records that were deleted woul= d > be required to diagnose the problem or can knobs be twiddled in some way = to > get similar behavior exhibited without them actually being present. The > fact that the records were deleted, but not vacuumed, and a wrong result > was returned makes me think it should be possible but I don't know enough > to say for sure or to make informed decisions as to which knobs to turn (= if > indeed such knobs are exposed since I do not have source-editing or > debugging capabilities). > > =E2=80=8BSome more observations... On this node's detail (the rows seems to appear consistently regardless of node ordering in the plan...) Hash (cost=3D1440572.59..1440572.59 rows=3D872393 width=3D24) (actual time=3D151981.919..151981.919 rows=3D*1275138* loops=3D1) Bad Plan: =E2=80=8B =E2=80=8B =E2=80=8B Buckets: 131072 (originally 131072) Batches: 32 (originally 16) Memory Usage: 3073kB =E2=80=8BBad Plan: =E2=80=8B Buckets: 65536 (originally 65536) Batches: = 32 (originally 16) Memory Usage: 3585kB Good Plan: Buckets: 1024 Batches: 1 Memory Usage: 42kB Good Plan: Buckets: 8192 Batches: 1 Memory Usage: 439kB (see below) 9.3 Plan: Buckets: 4096 Batches: 64 Memory Usage: 889kB 9.5 Made Up Good Plan (see below): Buckets: 131072 (originally 1024) Batches: 16 (originally 1) Memory Usage: 3227kB *The difference on this last one is that the original bucket count is considerably smaller than the seemingly important 2^16-1 boundary even though the final count is greater.* I was able to force a Hash Join between the 1,275,138 node and the 7,993 node using CTEs BEGIN; SET LOCAL enable_mergejoin =3D off; EXPLAIN ANALYZE WITH first_join AS ( SELECT * FROM rrr JOIN fff ON fff.idx =3D rrr.fff_idx WHERE fff.file_name_model_ver =3D '100' AND fff.file_name_date BETWEEN '2005-03-01' AND '2005-07-30' ), second_join AS ( SELECT * FROM uuu WHERE universe_hash =3D 5188205190738336870 ), combined AS ( SELECT * FROM first_join JOIN second_join USING (bababa) ) SELECT count(*) FROM combined; The result was the following explain analyze and a good count. QUERY PLAN Aggregate (cost=3D320276.69..320276.70 rows=3D1 width=3D0) (actual time=3D23126.200..23126.201 rows=3D1 loops=3D1) CTE first_join -> Hash Join (cost=3D820.88..228772.40 rows=3D38783 width=3D68) (actu= al time=3D8573.804..15931.271 rows=3D1275138 loops=3D1) Hash Cond: (rrr.fff_idx =3D fff.idx) -> Seq Scan on rrr (cost=3D0.00..216302.86 rows=3D3002886 width= =3D24) (actual time=3D7499.001..10979.666 rows=3D3007454 loops=3D1) -> Hash (cost=3D808.37..808.37 rows=3D1001 width=3D44) (actual time=3D2.616..2.616 rows=3D964 loops=3D1) Buckets: 1024 Batches: 1 Memory Usage: 87kB -> Bitmap Heap Scan on fff (cost=3D35.75..808.37 rows=3D1= 001 width=3D44) (actual time=3D0.122..1.438 rows=3D964 loops=3D1) Recheck Cond: ((file_name_date >=3D '2005-03-01'::dat= e) AND (file_name_date <=3D '2005-07-30'::date)) Filter: ((file_name_model_ver)::text =3D '100'::text) Rows Removed by Filter: 540 Heap Blocks: exact=3D30 -> Bitmap Index Scan on ix_fff_file_name_date (cost=3D0.00..35.50 rows=3D1521 width=3D0) (actual time=3D0.100..0.100 row= s=3D1504 loops=3D1) Index Cond: ((file_name_date >=3D '2005-03-01'::date) AND (file_name_date <=3D '2005-07-30'::date)) CTE second_join -> Index Only Scan using pk_uuu on uuu (cost=3D0.42..269.84 rows=3D80= 81 width=3D16) (actual time=3D0.019..9.372 rows=3D7993 loops=3D1) Index Cond: (universe_hash =3D '5188205190738336870'::bigint) Heap Fetches: 0 CTE combined -> Hash Join (cost=3D262.63..55976.35 rows=3D1567027 width=3D228) (ac= tual time=3D8612.493..21535.488 rows=3D416075 loops=3D1) Hash Cond: ((first_join.bababa)::text =3D (second_join.bababa)::text) -> CTE Scan on first_join (cost=3D0.00..775.66 rows=3D38783 width=3D220) (actual time=3D8573.810..19343.262 rows=3D1275138 loops=3D1) -> Hash (cost=3D161.62..161.62 rows=3D8081 width=3D42) (actual time=3D37.346..37.346 rows=3D7993 loops=3D1) * Buckets: 8192 Batches: 1 Memory Usage: 439kB* -> CTE Scan on second_join (cost=3D0.00..161.62 rows=3D80= 81 width=3D42) (actual time=3D0.023..27.642 rows=3D7993 loops=3D1) -> CTE Scan on combined (cost=3D0.00..31340.54 rows=3D1567027 width=3D0= ) (actual time=3D8612.498..22664.354 rows=3D416075 loops=3D1) Planning time: 0.137 ms Execution time: 23145.303 ms And below is the 9.3 non-Distinct plan QUERY PLAN Aggregate (cost=3D1467123.37..1467123.38 rows=3D1 width=3D0) (actual time=3D165954.407..165954.409 rows=3D1 loops=3D1) -> Hash Join (cost=3D1456877.26..1466434.87 rows=3D275399 width=3D0) (a= ctual time=3D164885.552..165504.698 rows=3D416075 loops=3D1) Hash Cond: ((uuu.bababa)::text =3D (rrr.bababa)::text) -> Index Only Scan using pk_uuu on uuu (cost=3D0.42..260.48 rows=3D7775 width=3D8) (actual time=3D0.011..9.630 rows=3D7993 loops=3D1) Index Cond: (universe_hash =3D 5188205190738336870::bigint) Heap Fetches: 0 -> Hash (cost=3D1441329.64..1441329.64 rows=3D947616 width=3D8) (= actual time=3D164884.922..164884.922 rows=3D1275138 loops=3D1) *Buckets: 4096 Batches: 64 Memory Usage: 889kB* -> Hash Join (cost=3D822.75..1441329.64 rows=3D947616 width= =3D8) (actual time=3D60770.116..163253.376 rows=3D1275138 loops=3D1) Hash Cond: (rrr.fff_idx =3D fff.idx) -> Seq Scan on rrr (cost=3D0.00..1164410.44 rows=3D71098744 width=3D12) (actual time=3D0.036..79440.276 rows=3D71098547= loops=3D1) -> Hash (cost=3D809.84..809.84 rows=3D1033 width=3D4) (actual time=3D2.577..2.577 rows=3D964 loops=3D1) Buckets: 1024 Batches: 1 Memory Usage: 34kB -> Bitmap Heap Scan on fff (cost=3D36.29..809.8= 4 rows=3D1033 width=3D4) (actual time=3D0.110..1.418 rows=3D964 loops=3D1) Recheck Cond: ((file_name_date >=3D '2005-03-01'::date) AND (file_name_date <=3D '2005-07-30'::date)) Filter: ((file_name_model_ver)::text =3D '100'::text) Rows Removed by Filter: 540 -> Bitmap Index Scan on ix_fff_file_name_date (cost=3D0.00..36.03 rows=3D1574 width=3D0) (actual time=3D0.098..0.098 rows=3D1504 loops=3D1) Index Cond: ((file_name_date >=3D '2005-03-01'::date) AND (file_name_date <=3D '2005-07-30'::date)) Total runtime: 165954.463 ms Though it doesn't seem simply a function bug bucket count since: EXPLAIN ANALYZE WITH first_join AS ( SELECT * FROM generate_series(1, 1000000) gs (i) ), second_join AS ( SELECT * FROM generate_series(1, 1000000) gs (i) ), combined AS ( SELECT * FROM first_join JOIN second_join USING (i) ) SELECT count(*) FROM combined; QUERY PLAN Aggregate (cost=3D362.50..362.51 rows=3D1 width=3D0) (actual time=3D13842.652..13842.653 rows=3D1 loops=3D1) CTE first_join -> Function Scan on generate_series gs (cost=3D0.00..10.00 rows=3D100= 0 width=3D4) (actual time=3D88.464..1186.923 rows=3D1000000 loops=3D1) CTE second_join -> Function Scan on generate_series gs_1 (cost=3D0.00..10.00 rows=3D1= 000 width=3D4) (actual time=3D88.287..1187.215 rows=3D1000000 loops=3D1) CTE combined -> Hash Join (cost=3D32.50..230.00 rows=3D5000 width=3D4) (actual time=3D4668.961..10530.299 *rows=3D1000000* loops=3D1) Hash Cond: (first_join.i =3D second_join.i) -> CTE Scan on first_join (cost=3D0.00..20.00 rows=3D1000 width= =3D4) (actual time=3D88.468..3333.798 rows=3D1000000 loops=3D1) -> Hash (cost=3D20.00..20.00 rows=3D1000 width=3D4) (actual time=3D4580.247..4580.247 rows=3D1000000 loops=3D1) * Buckets: 131072 (originally 1024) Batches: 16 (originally 1) Memory Usage: 3227kB* -> CTE Scan on second_join (cost=3D0.00..20.00 rows=3D100= 0 width=3D4) (actual time=3D88.294..3320.363 rows=3D1000000 loops=3D1) -> CTE Scan on combined (cost=3D0.00..100.00 rows=3D5000 width=3D0) (ac= tual time=3D4668.966..12787.652 rows=3D1000000 loops=3D1) Planning time: 0.071 ms Execution time: 13853.714 ms Though maybe because the original was only 1024 while the Bad plans above had original sizes greater than 2^16-1... David J.
On Thu, Feb 4, 2016 at 9:47 PM, David G. Johnston < david.g.johnston@gmail.com> wrote: > On this node's detail (the rows seems to appear consistently regardless o= f > node ordering in the plan...) > Hash (cost=3D1440572.59..1440572.59 rows=3D872393 width=3D24) (actual > time=3D151981.919..151981.919 rows=3D*1275138* loops=3D1) > > Bad Plan: =E2=80=8B > > =E2=80=8B =E2=80=8B > Buckets: 131072 (originally 131072) Batches: 32 (originally 16) Memory > Usage: 3073kB > Final result: =E2=80=8B415,967 / =E2=80=8B416,075 (108 missing) > =E2=80=8BBad Plan: =E2=80=8B Buckets: 65536 (originally 65536) Batches= : 32 (originally > 16) Memory Usage: 3585kB > =E2=80=8BFinal result: 415,874 / 416,075 (201 missing)=E2=80=8B =E2=80=8BDavid J.=E2=80=8B
On Thu, Feb 4, 2016 at 10:17 PM, David G. Johnston < david.g.johnston@gmail.com> wrote: > On Thu, Feb 4, 2016 at 9:47 PM, David G. Johnston < > david.g.johnston@gmail.com> wrote: > >> On this node's detail (the rows seems to appear consistently regardless >> of node ordering in the plan...) >> Hash (cost=3D1440572.59..1440572.59 rows=3D872393 width=3D24) (actual >> time=3D151981.919..151981.919 rows=3D*1275138* loops=3D1) >> > > >> Bad Plan: =E2=80=8B >> >> =E2=80=8B =E2=80=8B >> Buckets: 131072 (originally 131072) Batches: 32 (originally 16) Memory >> Usage: 3073kB >> > > Final result: =E2=80=8B415,967 / =E2=80=8B416,075 (108 missing) > =E2=80=8BSo just over 3 output records per bucket and 32 batches =E2=80=8Bg= ives 96+ > >> =E2=80=8BBad Plan: =E2=80=8B Buckets: 65536 (originally 65536) Batche= s: 32 (originally >> 16) Memory Usage: 3585kB >> > > =E2=80=8BFinal result: 415,874 / 416,075 (201 missing)=E2=80=8B > > =E2=80=8BJust over 6 output records per bucket and 32 batches yields 192+ Didn't notice any obvious numeric equalities using =E2=80=8B 1,275,138 David J.
"David G. Johnston" <david.g.johnston@gmail.com> writes: > Didn't notice any obvious numeric equalities using â > 1,275,138 I've committed a patch for this. Thanks for all the legwork! regards, tom lane
From: Tom Lane <tgl@sss.pgh.pa.us> > I've committed a patch for this. Thanks for all the legwork! Indeed, I no longer see this problem in 9.5.1. Thank you for the quick diag= nosis and fix.=