PostgreSQL 9.6 selects a wrong plan during aggregation against timestamp columns

Question

I have a simple but pretty big table “log” that has three columns: user_id, day, hours.

user_id character varying(36) COLLATE pg_catalog."default" NOT NULL,
day timestamp without time zone,
hours double precision

All columns have indexes.

The issue is that aggregation against the 'day' field works extremely slow. For example the simple query takes an eternity to complete.

select min(day) from log where user_id = 'ab056f5a-390b-41d7-ba56-897c14b679bf'

Analysis shows that Postgres makes a full scan filtering the entries that doesn’t relate to user_id = 'ab056f5a-390b-41d7-ba56-897c14b679bf' what is absolutely counter-intuitive

[
  {
    "Execution Time": 146502.05,
    "Planning Time": 0.893,
    "Plan": {
      "Startup Cost": 789.02,
      "Actual Rows": 1,
      "Plans": [
        {
          "Startup Cost": 0.44,
          "Actual Rows": 1,
          "Plans": [
            {
              "Index Cond": "(log.day IS NOT NULL)",
              "Startup Cost": 0.44,
              "Scan Direction": "Forward",
              "Plan Width": 8,
              "Rows Removed by Index Recheck": 0,
              "Actual Rows": 1,
              "Node Type": "Index Scan",
              "Total Cost": 1395792.54,
              "Plan Rows": 1770,
              "Relation Name": "log",
              "Alias": "log",
              "Parallel Aware": false,
              "Actual Total Time": 146502.015,
              "Output": [
                "log.day"
              ],
              "Parent Relationship": "Outer",
              "Actual Startup Time": 146502.015,
              "Schema": "public",
              "Filter": "((log.user_id)::text = 'ab056f5a-390b-41d7-ba56-897c14b679bf'::text)",
              "Actual Loops": 1,
              "Rows Removed by Filter": 12665610,
              "Index Name": "index_log_day"
            }
          ],
          "Node Type": "Limit",
          "Plan Rows": 1,
          "Parallel Aware": false,
          "Actual Total Time": 146502.016,
          "Output": [
            "log.day"
          ],
          "Parent Relationship": "InitPlan",
          "Actual Startup Time": 146502.016,
          "Plan Width": 8,
          "Subplan Name": "InitPlan 1 (returns $0)",
          "Actual Loops": 1,
          "Total Cost": 789.02
        }
      ],
      "Node Type": "Result",
      "Plan Rows": 1,
      "Parallel Aware": false,
      "Actual Total Time": 146502.019,
      "Output": [
        "$0"
      ],
      "Actual Startup Time": 146502.019,
      "Plan Width": 8,
      "Actual Loops": 1,
      "Total Cost": 789.03
    },
    "Triggers": []
  }
]

And what is more strange the almost similar query works perfectly.

select min(hours) from log where user_id = 'ab056f5a-390b-41d7-ba56-897c14b679bf'

Postgres selects entries for user_id = 'ab056f5a-390b-41d7-ba56-897c14b679bf' first and then aggregates among them what is obviously correct.

[
  {
    "Execution Time": 5.989,
    "Planning Time": 1.186,
    "Plan": {
      "Partial Mode": "Simple",
      "Startup Cost": 6842.66,
      "Actual Rows": 1,
      "Plans": [
        {
          "Startup Cost": 66.28,
          "Plan Width": 8,
          "Rows Removed by Index Recheck": 0,
          "Actual Rows": 745,
          "Plans": [
            {
              "Startup Cost": 0,
              "Plan Width": 0,
              "Actual Rows": 745,
              "Node Type": "Bitmap Index Scan",
              "Index Cond": "((log.user_id)::text = 'ab056f5a-390b-41d7-ba56-897c14b679bf'::text)",
              "Plan Rows": 1770,
              "Parallel Aware": false,
              "Actual Total Time": 0.25,
              "Parent Relationship": "Outer",
              "Actual Startup Time": 0.25,
              "Total Cost": 65.84,
              "Actual Loops": 1,
              "Index Name": "index_log_user_id"
            }
          ],
          "Recheck Cond": "((log.user_id)::text = 'ab056f5a-390b-41d7-ba56-897c14b679bf'::text)",
          "Exact Heap Blocks": 742,
          "Node Type": "Bitmap Heap Scan",
          "Plan Rows": 1770,
          "Relation Name": "log",
          "Alias": "log",
          "Parallel Aware": false,
          "Actual Total Time": 5.793,
          "Output": [
            "day",
            "hours",
            "user_id"
          ],
          "Lossy Heap Blocks": 0,
          "Parent Relationship": "Outer",
          "Actual Startup Time": 0.357,
          "Total Cost": 6838.23,
          "Actual Loops": 1,
          "Schema": "public"
        }
      ],
      "Node Type": "Aggregate",
      "Strategy": "Plain",
      "Plan Rows": 1,
      "Parallel Aware": false,
      "Actual Total Time": 5.946,
      "Output": [
        "min(hours)"
      ],
      "Actual Startup Time": 5.946,
      "Plan Width": 8,
      "Actual Loops": 1,
      "Total Cost": 6842.67
    },
    "Triggers": []
  }
]

There are two possible work arounds:

1) rewrite query into:

select user_id, min(day) from log where user_id = 'ac43a155-4fbb-49eb-a670-02c307eb3d4f' group by user_id

2) Introduce pair indexes like it was suggested in finding MAX(db_timestamp) query

They could look good but I consider both ways exactly as work arounds (first one is even a hack). Logically if Postgres can select a proper plan for ‘hours’ it have to do it for ‘day’ but it doesn’t. So it looks like a Postgres bug that is occurred during aggregate of timestamp fields, however I admit that I can miss something. Could somebody please advise if something can be done here without using WAs or it’s really a Postgres bug and I have to report it?

UPD: I've reported this as a bug to the PostgreSQL bugs mailing list. I'll let everybody know if it's accepted.

I have the default settings for the statistics collection and believe that it should be collected automatically. So I need to do something explicit about statistics? — Sogawa-sps, Aug 15 '17 at 20:22

Daniel Vidić · Answer 1 · 2017-08-16T19:39:06.263

1

Min is aggregate function, not operator. Function must be executed on all records that match. Fields in select part does not affect plan. From ... join ... where ... group by ... order by - all of this is considered in plan. Try:

select day from log where user_id = 'ab056f5a-390b-41d7-ba56-897c14b679bf'
order by user_id, day
limit 1

edited Aug 16 '17 at 19:39

answered Aug 16 '17 at 06:08

Daniel Vidić

164
2
11

Thank you for suggestion! I tried it but unfortunately got the same poor plan. However WA that I found previously works: select user_id, min(day) from log where user_id = 'ac43a155-4fbb-49eb-a670-02c307eb3d4f' group by user_id So I used it for my solution. I understand the limitation of aggregate function and it would be ok but the question is why Postrgres didn't limit rows by user_id first like it did when I aggregate by double field? I've submitted a bug to Postgres team (#14780), it's on premoderation now. Let's see what they tell. – Sogawa-sps Aug 16 '17 at 20:05

score 1 · Accepted Answer · answered Oct 02 '17 at 13:09

I've got a reply from PostgreSQL. They do not consider it as a bug. There are possible WAs in this case, many of them are mentioned in the original post and later in the comments. My personal selection is first option mentioned originally because it doesn't require indexes manipulation (it's far not always possible). So the solution is to rewrite query into:

select user_id, min(day) from log where user_id = 'ac43a155-4fbb-49eb-a670-02c307eb3d4f' group by user_id

score 0 · Answer 3 · answered Aug 15 '17 at 20:15

0

see this articles there're some playing with order of index - PostgreSQL index not used for query on range

https://dba.stackexchange.com/questions/39589/optimizing-queries-on-a-range-of-timestamps-two-columns

and one more idea is

select min(day) from (
   select day from log 
      where user_id = 'ac43a155-4fbb-49eb-a670-02c307eb3d4f'
) q

p.s. additionally can you confirm that autovacuum (verbose, analyze) was executed for the table?

answered Aug 15 '17 at 20:15

are

2,535
2
22
27

Thank you! I din't perform autovacuum . Database is pretty new so it should be fine but still please let me try it. – Sogawa-sps Aug 15 '17 at 20:23
Did the vacuum. No effect. It even became a bit worse :) – Sogawa-sps Aug 15 '17 at 20:42
try create index with order...not sure if it's help `CREATE INDEX my_idx ON my_table (day ASC);` and then make autovacuum with analyze – are Aug 15 '17 at 22:09
I've tried: select min(day) from ( select day from log where user_id = 'ac43a155-4fbb-49eb-a670-02c307eb3d4f' ) q Still had the same plan. – Sogawa-sps Aug 16 '17 at 20:11

PostgreSQL 9.6 selects a wrong plan during aggregation against timestamp columns

3 Answers3