Re: Query hitting empty tables taking 48 minutes - Mailing list pgsql-general

From Robert Creager
Subject Re: Query hitting empty tables taking 48 minutes
Date
Msg-id 2AC21858-383E-434E-8676-CEB9684F9B8E@logicalchaos.org
Whole thread Raw
In response to Re: Query hitting empty tables taking 48 minutes  ("David G. Johnston" <david.g.johnston@gmail.com>)
List pgsql-general


On Jun 7, 2018, at 4:58 PM, David G. Johnston <david.g.johnston@gmail.com> wrote:

On Thu, Jun 7, 2018 at 3:02 PM, Robert Creager <robert@logicalchaos.org> wrote:
​[...]​
 
 job_id      | f         |          1 | cc54ca5d-0dca-4b35-acd9-e0fe69c6b247

IIUC, the system believes​ your job_entry table has 300k records ALL of them having the UUID value ending in "*b247" - so it is unsurprising that it chooses to sequentially scan job_entry when its given that ID to search for.  And if its given a different ID is realizes it can accurately confirm the absence of the supplied value in the table by using the index.

Yes, I agree. And this explain execution time is fine.  It’s the ’same’ query running in the app for 43 minutes at a shot on the same tables that’s giving me heartburn.

I would suspect that vacuuming these tables would solve your problem.  Whether there is an issue beyond a lack of vacuuming, or related to auto-vacuum, I am unsure.  Though at this point it may take a vacuum full to recover back to a sane state.  Though ANALYZE by itself should clear up the statistical discrepancy.

Auto-vacuum is on, and I was thinking the same re VACUUM fixing it, but, it seems there may be a deeper problem here, hence calling in the people who know things :-)

autovacuum_vacuum_threshold = 5000      # min number of row updates before vacuum
autovacuum_analyze_threshold = 5000     # min number of row updates before
autovacuum_vacuum_scale_factor = 0.1    # fraction of table size before vacuum
autovacuum_analyze_scale_factor = 0.05  # fraction of table size before analyze

(Auto)Vacuum was run (no analyze) ~4.5 hours ago (if this query is correct), but maybe another should of been triggered?

SELECT
  *,
  n_dead_tup > av_threshold AS "av_needed",
  CASE WHEN reltuples > 0
    THEN round(100.0 * n_dead_tup / (reltuples))
  ELSE 0 END AS pct_dead
FROM (SELECT
        N.nspname,
        C.relname,
        pg_stat_get_tuples_inserted(C.oid) AS n_tup_ins,
        pg_stat_get_tuples_updated(C.oid) AS n_tup_upd,
        pg_stat_get_tuples_deleted(C.oid) AS n_tup_del,
        pg_stat_get_live_tuples(C.oid) AS n_live_tup,
        pg_stat_get_dead_tuples(C.oid) AS n_dead_tup,
        C.reltuples AS reltuples,
        round(current_setting('autovacuum_vacuum_threshold') :: INTEGER + current_setting('autovacuum_vacuum_scale_factor') :: NUMERIC * C.reltuples) AS av_threshold,
        date_trunc('minute', greatest(pg_stat_get_last_vacuum_time(C.oid), pg_stat_get_last_autovacuum_time(C.oid))) AS last_vacuum,
        date_trunc('minute', greatest(pg_stat_get_last_analyze_time(C.oid), pg_stat_get_last_analyze_time(C.oid))) AS last_analyze
      FROM pg_class C LEFT JOIN pg_namespace N ON (N.oid = C.relnamespace)
      WHERE C.relkind IN ('r', 't') AND N.nspname NOT IN ('pg_catalog', 'information_schema') AND N.nspname !~ '^pg_toast') AS av
WHERE reltuples > 0
ORDER BY av_needed DESC, n_dead_tup DESC;

nspnamerelnamen_tup_insn_tup_updn_tup_deln_live_tupn_dead_tupreltuplesav_thresholdlast_vacuumlast_analyzeav_neededpct_dead
ds3job_entry3036588153036580300022300022350022018-06-07 23:09:00.000000NULLtrue100

But, I may be missing something, my experience and skill here is somewhat limited.

Ditto, at this level.

Best,
Robert

pgsql-general by date:

Previous
From: "David G. Johnston"
Date:
Subject: Re: Query hitting empty tables taking 48 minutes
Next
From: Christophe Pettus
Date:
Subject: Re: Code of Conduct plan