1

I have a rather structurally "simple" query that consists basically in these clauses:

SELECT
  [650 columns here]
FROM
   MAIN_TABLE
   (Several Joins)
WHERE
   (Some conditions in MAIN_TABLE plus some others)

As someone can tell, the column projection is rather large. When I say the query is "simple", I mean it has few (3) sub-queries in SELECT clause that are pretty straightforward. Other than that, it doesn't have CTE's, sub-select's in Join clauses, grouping, sorting and so on.

This query is bouncing between 20s-25s to complete.

Now, if I randomly start pulling some of these columns off, at some point, the query performance improves sudden and significantly (from 20s to 1-2s).

If I export the database (which is small now, new deployment, ~1Gb size total) and run the same query on my dev machine, it runs even faster: 0.5s

I suppose, to some point, the engine must use some disk buffer as intermediate storage before fetching the results. What bugs me, is that this column selection modification changes the inner most performance of the query plan (that is, the query start tables per se) so much for no apparent reason.

How can I correctly diagnose what's going on and tackle this issue - any advice?

More Info

  • PostgreSQL Version 14.5
  • OS: Rocky Linux 9.0 (Blue Onyx)
  • Parameters are followed based pgTune suggestion - the server has much more CPU/RAM than needed by now
  • I've already set the WORK_MEM parameter to a large value (100x the original) for a session, same result.

Slow Query Plan

Fast Query Plan (Added 10000 rows limit)

Fast Query Plan (removed some columns)

Improve this question
8
  • This is generated by my ORM. I fill all the entities so the user can choose what to analyze without lazy-loading (that is, avoiding "N+1" sort of problems).
    – J.Hudler
    Jan 11 at 21:08
  • 2
    Seems like the interesting bits are all behind ellipses.
    – jjanes
    Jan 11 at 23:46
  • @jjanes Could you please clarify? See that the start of the query (I preserved the inner most, between the ellipsis) already has all the actual time taken (in the long query version). As it goes further to the outer steps, neglectable time is added. I needed to trim these infos so it could fit the question character limit...
    – J.Hudler
    Jan 12 at 0:27
  • 1
    Could you please share the full plans e.g. through explain.depesz.com
    – a_horse_with_no_name
    Jan 12 at 6:40
  • 1
    The time in the slow plan is consumed by the index scan of idx_pedven_06, which reports to have returned 307 rows and didn't hit the disk at all. This is just bizarre, there is no way that that should take 33 seconds. (That is also where the time is spent in the fast plan with fewer columns, it is just not nearly as slow, despite apparently doing identical work). It this is reproducible, I would run the slow query in a loop, and capture a profile of it using perf. Or before that, sample from the pg_stat_activity while it is running, and see if there is a pattern of values for wait_event.
    – jjanes
    Jan 12 at 17:53

1 Answer 1

Reset to default
1

It turns out that the almost the whole processing time in this case is related to JIT the query.

Setting both session or system-wide postgres.conf flag jit=off solved the issue.

Special thanks to @jjanes who guided towards the use of a profiler (which I was skeptical, I confess).

The perf report top 3 lines were:

Overhead  Command     Shared Object         Symbol
  39.31%  postmaster  libLLVM-13.so         [.] llvm::SUnit::addPred
   7.80%  postmaster  libLLVM-13.so         [.] llvm::ScheduleDAGInstrs::addChainDependencies
   6.90%  postmaster  libLLVM-13.so         [.] llvm::MachineInstr::mayAlias
Improve this answer

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge that you have read and understand our privacy policy and code of conduct.

Not the answer you're looking for? Browse other questions tagged or ask your own question.