culebrón culebrón - 7 months ago 18
SQL Question

How to debug common table expressions in PostgreSQL?

I had a problem in a query, where one of CTEs returned no rows. But this was hard to notice, and debugging lastet quite a while.

Is it possible to output all CTEs in Postgres without commenting out the main query?

create or replace function generate_grid(
poly geometry, step double precision)
returns setof geometry as
$$ */

with
initial as (select st_xmin(poly) x0, st_ymin(poly) y0),
...(another 3 CTE skipped here)...
grid as (select point from points where st_intersects(point, poly)),
centroid as (select st_centroid(poly) point from grid where (select count(*)=0 from grid))
select * from grid
union all
select * from centroid;
$$ language sql;


In the example, CTE
centroid
was incrementally added to the function which worked well before. It should return rows in case
grid
is empty. The bug (which I have fixed) was that it didn't, because it selected from the empty CTE
grid
. Now when I described the problem it's obvious why it failed, but when you write it and debug, all sorts of things may happen, like mixed geometries SRID, wrong SRID, etc.

Answer

EXPLAIN ANALYZE looks to report the CTEs separately.

When I run that (Postgresql 9.4) it is showing the CTEs separately, and in the result section it does show that the actual number of rows returned from "CTE Scan on x" was 0.

explain analyze
with x as (select 1 where false),
     y as (select 2 where true)
select * from x, y;

Returns:

Nested Loop  (cost=0.02..0.07 rows=1 width=8) (actual time=0.002..0.002 rows=0 loops=1)
  Output: x."?column?", y."?column?"
  CTE x
    ->  Result  (cost=0.00..0.01 rows=1 width=0) (actual time=0.000..0.000 rows=0 loops=1)
          Output: 1
          One-Time Filter: false
  CTE y
    ->  Result  (cost=0.00..0.01 rows=1 width=0) (never executed)
          Output: 2
  ->  CTE Scan on x  (cost=0.00..0.02 rows=1 width=4) (actual time=0.002..0.002 rows=0 loops=1)
        Output: x."?column?"
  ->  CTE Scan on y  (cost=0.00..0.02 rows=1 width=4) (never executed)
        Output: y."?column?"
Planning time: 0.034 ms
Execution time: 0.018 ms

I don't know the explain would always display data like this, I suspect it depends on how Postgresql decides to optimize the query, but it should be a good start point.

Explain documentation at http://www.postgresql.org/docs/current/static/sql-explain.html

Comments