Re: BUG #16109: Postgres planning time is high across version - 10.6vs 10.10

Hi,

On 2019-11-12 20:34:35 +0000, PG Bug reporting form wrote:
> I am experiencing weird issue around planning time for the queries across
> couple of environments below is the sample of the execution plan


Just to confirm, these are the same queries, but executed in different
databases / environments?


> Fast Execution Plan
> transformations=> explain (analyze, buffers)
> SELECT x2.x3, x2.x4, x2.x5, x2.x6, x2.x7, x2.x8, x2.x9, x2.x10, x2.x11,
> x2.x12, x2.x13, x2.x14, x2.x15, x2.x16, x2.x17, x2.x18, x2.x19, x2.x20,
> x2.x21, x2.x22, x2.x23, x2.x24, x2.x25, x2.x26, x2.x27, x2.x28, x2.x29,
> x2.x30, x2.x31, x2.x32, x2.x33, x2.x34, x35. "provider_id", x35.
> "provider_phone_id", x35. "provider_id", x35. "address_id", x35.
> "prod_code", x35. "phone_number", x35. "phone_type", x36. "provider_id",
> x36. "provider_id", x36. "address_id", x36. "language_code", x36.
> "language_used_by" FROM ( SELECT x37.x38 AS x14, x37.x39 AS x6, x37.x40 AS
> x26, x37.x41 AS x9, x37.x42 AS x20, x37.x43 AS x16, x37.x44 AS x8, x37.x45
> AS x19, x37.x46 AS x3, x37.x47 AS x13, x37.x48 AS x12, x37.x49 AS x18,
> x37.x50 AS x17, x37.x51 AS x11, x37.x52 AS x22, x37.x53 AS x21, x37.x54 AS
> x10, x37.x55 AS x5, x37.x56 AS x4, x37.x57 AS x25, x37.x58 AS x7, x37.x59 AS
> x15, x37.x60 AS x24, x37.x61 AS x23, ( CASE WHEN (x62. "attribute_value" IS
> NULL) THEN NULL ELSE 1 END) AS x27, x62. "paid" AS x28, x62.
> "attribute_value" AS x34, x62. "attribute_id" AS x33, x62. "provider_id" AS
> x29, x62. "attribute_group_id" AS x32, x62. "parent_paid" AS x31, x62.
> "address_id" AS x30 FROM ( SELECT "provider_id" AS x46, "zip" AS x38,
> "first_name" AS x39, "provider_name_id" AS x40, "degree" AS x41,
> "preferred_flag" AS x42, "county" AS x43, "suffix" AS x44, "individual_id"
> AS x45, "state" AS x47, "city" AS x48, "latitude" AS x49, "longitude" AS
> x50, "address" AS x51, "exclusion_type_id" AS x52, "quality_score" AS x53,
> "gender" AS x54, "last_name" AS x55, "address_id" AS x56, "hi_q_hospital_id"
> AS x57, "middle_name" AS x58, "zip4" AS x59, "handicap_accessible" AS x60,
> "sour_address" AS x61 FROM "provider" WHERE "provider_id" =
> '03563735-3798-441a-aea6-4e561ea347f7') x37 LEFT OUTER JOIN
> "provider_attribute" x62 ON (x37.x46 = x62. "provider_id") AND (x37.x56 =
> x62. "address_id")) x2 LEFT OUTER JOIN "provider_phone" x35 ON (x2.x3 = x35.
> "provider_id") AND (x2.x4 = x35. "address_id") LEFT OUTER JOIN
> "provider_language" x36 ON (x2.x3 = x36. "provider_id") AND (x2.x4 = x36.
> "address_id");

This is really hard to read for a human...

Here's a automatically reformatted version:

SELECT x2.x3,
       x2.x4,
       x2.x5,
       x2.x6,
       x2.x7,
       x2.x8,
       x2.x9,
       x2.x10,
       x2.x11,
       x2.x12,
       x2.x13,
       x2.x14,
       x2.x15,
       x2.x16,
       x2.x17,
       x2.x18,
       x2.x19,
       x2.x20,
       x2.x21,
       x2.x22,
       x2.x23,
       x2.x24,
       x2.x25,
       x2.x26,
       x2.x27,
       x2.x28,
       x2.x29,
       x2.x30,
       x2.x31,
       x2.x32,
       x2.x33,
       x2.x34,
       x35. "provider_id",
       x35. "provider_phone_id",
       x35. "provider_id",
       x35. "address_id",
       x35. "prod_code",
       x35. "phone_number",
       x35. "phone_type",
       x36. "provider_id",
       x36. "provider_id",
       x36. "address_id",
       x36. "language_code",
       x36. "language_used_by"
FROM
  (SELECT x37.x38 AS x14,
          x37.x39 AS x6,
          x37.x40 AS x26,
          x37.x41 AS x9,
          x37.x42 AS x20,
          x37.x43 AS x16,
          x37.x44 AS x8,
          x37.x45 AS x19,
          x37.x46 AS x3,
          x37.x47 AS x13,
          x37.x48 AS x12,
          x37.x49 AS x18,
          x37.x50 AS x17,
          x37.x51 AS x11,
          x37.x52 AS x22,
          x37.x53 AS x21,
          x37.x54 AS x10,
          x37.x55 AS x5,
          x37.x56 AS x4,
          x37.x57 AS x25,
          x37.x58 AS x7,
          x37.x59 AS x15,
          x37.x60 AS x24,
          x37.x61 AS x23,
          (CASE
               WHEN (x62. "attribute_value" IS NULL) THEN NULL
               ELSE 1
           END) AS x27,
          x62. "paid" AS x28,
          x62. "attribute_value" AS x34,
          x62. "attribute_id" AS x33,
          x62. "provider_id" AS x29,
          x62. "attribute_group_id" AS x32,
          x62. "parent_paid" AS x31,
          x62. "address_id" AS x30
   FROM
     (SELECT "provider_id" AS x46,
             "zip" AS x38,
             "first_name" AS x39,
             "provider_name_id" AS x40,
             "degree" AS x41,
             "preferred_flag" AS x42,
             "county" AS x43,
             "suffix" AS x44,
             "individual_id" AS x45,
             "state" AS x47,
             "city" AS x48,
             "latitude" AS x49,
             "longitude" AS x50,
             "address" AS x51,
             "exclusion_type_id" AS x52,
             "quality_score" AS x53,
             "gender" AS x54,
             "last_name" AS x55,
             "address_id" AS x56,
             "hi_q_hospital_id" AS x57,
             "middle_name" AS x58,
             "zip4" AS x59,
             "handicap_accessible" AS x60,
             "sour_address" AS x61
      FROM "provider"
      WHERE "provider_id" = '03563735-3798-441a-aea6-4e561ea347f7') x37
   LEFT OUTER JOIN "provider_attribute" x62 ON (x37.x46 = x62. "provider_id")
   AND (x37.x56 = x62. "address_id")) x2
LEFT OUTER JOIN "provider_phone" x35 ON (x2.x3 = x35. "provider_id")
AND (x2.x4 = x35. "address_id")
LEFT OUTER JOIN "provider_language" x36 ON (x2.x3 = x36. "provider_id")
AND (x2.x4 = x36. "address_id");


> Slow Execution Plan
> transformations_uhc_medicaid=> explain (analyze, buffers)
> SELECT x2.x3, x2.x4, x2.x5, x2.x6, x2.x7, x2.x8, x2.x9, x2.x10, x2.x11,
> x2.x12, x2.x13, x2.x14, x2.x15, x2.x16, x2.x17, x2.x18, x2.x19, x2.x20,
> x2.x21, x2.x22, x2.x23, x2.x24, x2.x25, x2.x26, x2.x27, x2.x28, x2.x29,
> x2.x30, x2.x31, x2.x32, x2.x33, x2.x34, x35. "provider_id", x35.
> "provider_phone_id", x35. "provider_id", x35. "address_id", x35.
> "prod_code", x35. "phone_number", x35. "phone_type", x36. "provider_id",
> x36. "provider_id", x36. "address_id", x36. "language_code", x36.
> "language_used_by" FROM ( SELECT x37.x38 AS x14, x37.x39 AS x6, x37.x40 AS
> x26, x37.x41 AS x9, x37.x42 AS x20, x37.x43 AS x16, x37.x44 AS x8, x37.x45
> AS x19, x37.x46 AS x3, x37.x47 AS x13, x37.x48 AS x12, x37.x49 AS x18,
> x37.x50 AS x17, x37.x51 AS x11, x37.x52 AS x22, x37.x53 AS x21, x37.x54 AS
> x10, x37.x55 AS x5, x37.x56 AS x4, x37.x57 AS x25, x37.x58 AS x7, x37.x59 AS
> x15, x37.x60 AS x24, x37.x61 AS x23, ( CASE WHEN (x62. "attribute_value" IS
> NULL) THEN NULL ELSE 1 END) AS x27, x62. "paid" AS x28, x62.
> "attribute_value" AS x34, x62. "attribute_id" AS x33, x62. "provider_id" AS
> x29, x62. "attribute_group_id" AS x32, x62. "parent_paid" AS x31, x62.
> "address_id" AS x30 FROM ( SELECT "provider_id" AS x46, "zip" AS x38,
> "first_name" AS x39, "provider_name_id" AS x40, "degree" AS x41,
> "preferred_flag" AS x42, "county" AS x43, "suffix" AS x44, "individual_id"
> AS x45, "state" AS x47, "city" AS x48, "latitude" AS x49, "longitude" AS
> x50, "address" AS x51, "exclusion_type_id" AS x52, "quality_score" AS x53,
> "gender" AS x54, "last_name" AS x55, "address_id" AS x56, "hi_q_hospital_id"
> AS x57, "middle_name" AS x58, "zip4" AS x59, "handicap_accessible" AS x60,
> "sour_address" AS x61 FROM "provider" WHERE "provider_id" =
> '03563735-3798-441a-aea6-4e561ea347f7') x37 LEFT OUTER JOIN
> "provider_attribute" x62 ON (x37.x46 = x62. "provider_id") AND (x37.x56 =
> x62. "address_id")) x2 LEFT OUTER JOIN "provider_phone" x35 ON (x2.x3 = x35.
> "provider_id") AND (x2.x4 = x35. "address_id") LEFT OUTER JOIN
> "provider_language" x36 ON (x2.x3 = x36. "provider_id") AND (x2.x4 = x36.
> "address_id");

Based on a quick skim, this is the same query as before.


> I have tried to vacuum analyze the whole database still queries are slow in
> 1 of the environment while faster in another environment.

Is there a chance that one database has longrunning queries, slow
replication, or something like that, leading to a very bloated database?
Even if you VACUUM FULL, if there's still long-running sessions, the
bloat could not necessarily be removed, because those sessions might
still need to see the already superseded data.

Do the table / index sizes differ between the environment? Are the
databases expected to have the same content?


This last point is more oriented towards other PG developers: I wonder
if we ought to display buffer statistics for plan time, for EXPLAIN
(BUFFERS). That'd surely make it easier to discern cases where we
e.g. access the index and scan a lot of the index from cases where we
hit some CPU time issue. We should easily be able to get that data, I
think, we already maintain it, we'd just need to compute the diff
between pgBufferUsage before / after planning.

Greetings,

Andres Freund