Date: Sun, 31 May 2015 13:00:10 +0200
From: "Peter J. Holzer" <hjp-pgsql@hjp.at>
To: pgsql-performance@postgresql.org
Subject: Re: Different plan for very similar queries
Message-ID: <20150531110010.GA25173@hjp.at>
References: <20150529085544.GA15813@hjp.at> <20150529095117.GB15813@hjp.at>
 <5568FAA5.3080807@2ndquadrant.com> <29819.1433012674@sss.pgh.pa.us>
MIME-Version: 1.0
Content-Type: multipart/signed; micalg=pgp-sha1;
 protocol="application/pgp-signature"; boundary="jRHKVT23PllUwdXP"
Content-Disposition: inline
In-Reply-To: <29819.1433012674@sss.pgh.pa.us>
User-Agent: Mutt/1.5.21 (2010-09-15)
Precedence: bulk
Sender: pgsql-performance-owner@postgresql.org


--jRHKVT23PllUwdXP
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
Content-Transfer-Encoding: quoted-printable

[I've seen in -hackers that you already seem to have a fix]

On 2015-05-30 15:04:34 -0400, Tom Lane wrote:
> Tomas Vondra <tomas.vondra@2ndquadrant.com> writes:
> > Why exactly does the second query use a much slower plan I'm not sure. =
I=20
> > believe I've found an issue in planning semi joins (reported to=20
> > pgsql-hackers a few minutes ago), but may be wrong and the code is OK.
>=20
> I think you are probably right that there's a bug there: the planner is
> vastly overestimating the cost of the nestloop-with-inner-indexscan
> plan.  However, the reason why the mergejoin plan gets chosen in some
> cases seems to be that an additional estimation error is needed to make
> that happen; otherwise the nestloop still comes out looking cheaper.
> The undesirable case looks like:
>=20
> >>  Merge Semi Join  (cost=3D316864.57..319975.79 rows=3D1 width=3D81) (a=
ctual time=3D7703.917..30948.271 rows=3D2 loops=3D1)
> >>    Merge Cond: ((t.term)::text =3D (f.berechnungsart)::text)
> >>    ->  Index Scan using term_term_idx on term t  (cost=3D0.00..319880.=
73 rows=3D636 width=3D81) (actual time=3D7703.809..7703.938 rows=3D3 loops=
=3D1)
> >>          Filter: (((facttablename)::text =3D 'facttable_stat_fta4'::te=
xt) AND ((columnname)::text =3D 'berechnungsart'::text))

Just noticed that this is a bit strange, too:=20

This scans the whole index term_term_idx and for every row found it
checks the table for the filter condition. So it has to read the whole
index and the whole table, right? But the planner estimates that it will
return only 636 rows (out of 6.1E6), so using
term_facttablename_columnname_idx to extract those 636 and then sorting
them should be quite a bit faster (even just a plain full table scan
and then sorting should be faster).

> >>    ->  Index Scan using facttable_stat_fta4_berechnungsart_idx on fact=
table_stat_fta4 f  (cost=3D0.00..2545748.85 rows=3D43577940 width=3D2) (act=
ual time=3D0.089..16263.582 rows=3D21336180 loops=3D1)
> >>  Total runtime: 30948.648 ms
>=20
> Notice that it's estimating the cost of the join as significantly less
> than the cost of the inner-side indexscan.  This means it believes that
> the inner indexscan will not be run to completion.  That's not because of
> semijoin semantics; there's no stop-after-first-match benefit for mergejo=
ins.
> It must be that it thinks the range of keys on the outer side of the join
> is much less than the range of keys on the inner.  Given that it knows
> that facttable_stat_fta4.berechnungsart only contains the values "m"
> and "n", this implies that it thinks term.term only contains "m" and
> not "n".  So this estimation error presumably comes from "n" not having
> been seen in ANALYZE's last sample of term.term, and raising the stats
> target for term.term would probably be a way to fix that.

The term column has a relatively flat distribution and about 3.5 million
distinct values (in 6.1 million rows). So it's unlikely for any specific
value to be included in an ANALYZE sample, and an error to assume that a
value doesn't occur at all just because it wasn't seen by ANALYZE. OTOH,
a value which is seen by ANALYZE will have its frequency overestimated
by quite a bit. But that shouldn't influence whether the whole index
needs to be scanned or not.

Another thought: For the merge semi join postgresql doesn't actually
have to scan the whole inner index. It can skip from the first 'm' entry
to the first 'n' entry reading only a few non-leaf blocks, skipping many
leaf blocks in the process. The times (7703.917..30948.271) indicate that
it doesn't actually do this, but maybe the planner assumes it does?

I also suspected that the culprit is the "columnname" column. That one has =
a very
skewed distribution:

wdsah=3D> select columnname, count(*) from term group by columnname order b=
y count(*);
     columnname      |  count =20
---------------------+---------
 warenstrom          |       3
 einheit             |       3
 berechnungsart      |       3
 og                  |      26
 berichtsregion      |     242
 partnerregion       |     246
 sitcr4              |    4719
 kurzbezeichnung     | 1221319
 macrobondtimeseries | 1221320
                     | 3661206
(10 rows)

So random variation in the sample could throw off the estimated
frequencies of the the least frequent columnnames by quite a bit.

But given that both plans estimated the number of rows returned by the
outer index scan as 636, that was probably a red herring.

But there does seem to be a connection to this column: In one case
pg_stats contained n_distinct=3D7 and only the two most common values.
Then the plan looked like this:

wdsah=3D> explain analyze select facttablename, columnname, term, concept_i=
d, t.hidden, language, register
        from term t where facttablename=3D'facttable_stat_fta4' and columnn=
ame=3D'warenstrom' and exists (select 1 from facttable_stat_fta4 f where f.=
warenstrom=3Dt.term );
                                                                           =
      QUERY PLAN                                                           =
                     =20
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
----------------------
 Nested Loop Semi Join  (cost=3D0.00..386141.13 rows=3D1 width=3D81) (actua=
l time=3D0.202..0.253 rows=3D2 loops=3D1)
   ->  Index Scan using term_facttablename_columnname_idx on term t  (cost=
=3D0.00..264.03 rows=3D437 width=3D81) (actual time=3D0.097..0.099 rows=3D3=
 loops=3D1)
         Index Cond: (((facttablename)::text =3D 'facttable_stat_fta4'::tex=
t) AND ((columnname)::text =3D 'warenstrom'::text))
   ->  Index Scan using facttable_stat_fta4_warenstrom_idx on facttable_sta=
t_fta4 f  (cost=3D0.00..385869.36 rows=3D21787688 width=3D2) (actual time=
=3D0.033..0.033 rows=3D1 loops=3D3)
         Index Cond: ((warenstrom)::text =3D (t.term)::text)
 Total runtime: 0.314 ms

But after another analye, pg_stats contained n_distinct=3D5 and the 5 most
common values. And now the plan looks like this (after disabling
bitmapscan and hashagg):

wdsah=3D> explain analyze select facttablename, columnname, term, concept_i=
d, t.hidden, language, register
        from term t where facttablename=3D'facttable_stat_fta4' and columnn=
ame=3D'warenstrom' and exists (select 1 from facttable_stat_fta4 f where f.=
warenstrom=3Dt.term );
                                                                           =
      QUERY PLAN                                                           =
                      =20
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
-----------------------
 Nested Loop Semi Join  (cost=3D0.00..2124104.23 rows=3D1 width=3D81) (actu=
al time=3D0.080..0.129 rows=3D2 loops=3D1)
   ->  Index Scan using term_facttablename_columnname_idx on term t  (cost=
=3D0.00..3.23 rows=3D1 width=3D81) (actual time=3D0.030..0.031 rows=3D3 loo=
ps=3D1)
         Index Cond: (((facttablename)::text =3D 'facttable_stat_fta4'::tex=
t) AND ((columnname)::text =3D 'warenstrom'::text))
   ->  Index Scan using facttable_stat_fta4_warenstrom_idx on facttable_sta=
t_fta4 f  (cost=3D0.00..2124100.90 rows=3D21787688 width=3D2) (actual time=
=3D0.029..0.029 rows=3D1 loops=3D3)
         Index Cond: ((warenstrom)::text =3D (t.term)::text)
 Total runtime: 0.180 ms
(6 rows)

The estimated number of rows in the outer scan is way more accurate in
the second plan (1 instead of 437), but for some reason the cost for the
inner scan is higher (2124100.90 instead of 385869.36) although it
should be lower (we only need to search for 1 value, not 437)

(There was no analyze on facttable_stat_fta4 (automatic or manual) on
facttable_stat_fta4 between those two tests, so the statistics on
facttable_stat_fta4 shouldn't have changed - only those for term.)

	hp

--=20
   _  | Peter J. Holzer    | I want to forget all about both belts and
|_|_) |                    | suspenders; instead, I want to buy pants=20
| |   | hjp@hjp.at         | that actually fit.
__/   | http://www.hjp.at/ |   -- http://noncombatant.org/

--jRHKVT23PllUwdXP
Content-Type: application/pgp-signature; name="signature.asc"
Content-Description: Digital signature

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.12 (GNU/Linux)

iQIVAwUBVWrpufIOSFES/ihdAQItaA//d9WqgutJTq6Ob/VugOUMAXCSH8TYJjYo
4o1uMhwTvCu7hdc5awjQ9zsqYQPZK7N2snX3lf3nQPLILByxm1xELlpfOw9AgvB9
egKqHoM8nhVOrKOhP0go6ACCeiHfEh/Vsu9dH8eJQESaYbv8QtE/jxKstZfShBA+
fX7n+BLYKpyavUYPV1ty9t00fIw4ez0l3AC0AL2+dBQb934tpqd5x0xaSmfdJE0P
O2A2O7Nu6uj1a5LaXcfRxTPW6loqBc2aFyuz7IQRRV+aBsbG6CHHgCMpBAY5MK2s
0HaNvWt10ATTub7JNSamE3Zf23RBs7hZIvRCxWrm0h2lT4avosMEIHIzxEhiOZLG
BJIeQBa9vmTPO5I3tbBPC1SgnHd9sqsYruvR7622LHtHvujLkWTys9qx7HDFnq6U
SdujbXNq284zbTWTdIk9MBsMNrK6LqQHcLs382ZBDfOCP79fdDZ48cYFhB5OzCKb
QkNd3Hg6IpYFvj1HuDK1onvKRVLwjEoa6lTF7jIYsRof+EEkBRC7xZa/+iwPLZ7N
yKIzaMJT5SwAMq9hENFXE9JwRQXaq20fKHWbzc1/s2iUOoFI+kgLBbwg+4cm5Ja3
t18pHTnz6Tcwi0LHxTTrOP1EqEeD0WPJ/eu1iklf7mzYcGOWy+oo3IEajhztdOyc
qJLuVbXc+PA=
=JEwM
-----END PGP SIGNATURE-----

--jRHKVT23PllUwdXP--