I don't understand that EXPLAIN PLAN timings

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hello,

This EXPLAIN ANALYZE tells me the actual time was 11.xxx ms but the final Execution time says 493.xxx ms (this last one is true : about 1/2 second).

I would like to optimize this query but with this inconsistency, it will be difficult. This query is really a function so I added the "params" CTE to do the tests.

Thanks for your help,

JC

PS: PostgreSQL 14.10 (Ubuntu 14.10-1.pgdg23.10+1) on x86_64-pc-linux-gnu, compiled by gcc (Ubuntu 13.2.0-4ubuntu3) 13.2.0, 64-bit

and JIT is disabled


Nested Loop Left Join  (cost=36411048684.11..36411051002.22 rows=54228 width=116) (actual time=11.609..11.620 rows=0 loops=1)
  Join Filter: (u_g_internalvalidation.idinternalvalidation IS NOT NULL)
  CTE params
    ->  Result  (cost=0.00..0.01 rows=1 width=41) (actual time=0.001..0.001 rows=1 loops=1)
  CTE u
    ->  Nested Loop  (cost=0.25..12.77 rows=250 width=368) (never executed)
          ->  CTE Scan on params  (cost=0.00..0.02 rows=1 width=41) (never executed)           ->  Function Scan on get_user  (cost=0.25..10.25 rows=250 width=327) (never executed)
                Filter: ((NOT isgroup) AND (NOT istemplate))
  CTE internalvalidation
    ->  Hash Join  (cost=13988.95..14336.16 rows=436 width=42) (actual time=11.601..11.606 rows=0 loops=1)
          Hash Cond: (files.idfile = i_1.idfile)
          ->  HashAggregate  (cost=13929.87..14039.58 rows=10971 width=4) (actual time=11.480..11.527 rows=243 loops=1)
                Group Key: files.idfile
                Batches: 1  Memory Usage: 417kB
                ->  Append  (cost=0.00..13902.45 rows=10971 width=4) (actual time=6.593..11.423 rows=243 loops=1)                       ->  Nested Loop  (cost=0.00..10139.01 rows=10766 width=4) (actual time=5.143..5.145 rows=0 loops=1)                             Join Filter: ((files.idfile = (unnest(params_2.fn_idfile))) OR ((params_1.fn_idrealm = files.idrealminitial) AND params_1.fn_canseesubfiles))                             ->  Seq Scan on files (cost=0.00..2985.74 rows=40874 width=8) (actual time=0.002..2.396 rows=40766 loops=1)                             ->  Materialize  (cost=0.00..0.35 rows=10 width=9) (actual time=0.000..0.000 rows=0 loops=40766)                                   ->  Nested Loop (cost=0.00..0.30 rows=10 width=9) (actual time=0.003..0.003 rows=0 loops=1)                                         ->  CTE Scan on params params_1  (cost=0.00..0.02 rows=1 width=5) (actual time=0.002..0.003 rows=0 loops=1)                                               Filter: (fn_idfile IS NOT NULL)
                                              Rows Removed by Filter: 1
                                        ->  ProjectSet (cost=0.00..0.08 rows=10 width=4) (never executed)                                               ->  CTE Scan on params params_2  (cost=0.00..0.02 rows=1 width=32) (never executed)                       ->  Nested Loop  (cost=0.00..3598.87 rows=205 width=4) (actual time=1.448..6.267 rows=243 loops=1)                             Join Filter: (((params_3.fn_idfile IS NULL) AND (files_1.idrealm = params_3.fn_idrealm)) OR ((files_1.idrealminitial = params_3.fn_idrealm) AND params_3.fn_canseesubfiles))
                            Rows Removed by Join Filter: 40523
                            ->  CTE Scan on params params_3 (cost=0.00..0.02 rows=1 width=37) (actual time=0.001..0.001 rows=1 loops=1)                                   Filter: ((fn_idfile IS NULL) OR fn_canseesubfiles)                             ->  Seq Scan on files files_1 (cost=0.00..2985.74 rows=40874 width=12) (actual time=0.002..1.946 rows=40766 loops=1)           ->  Hash  (cost=58.94..58.94 rows=11 width=42) (actual time=0.059..0.060 rows=6 loops=1)
                Buckets: 1024  Batches: 1  Memory Usage: 9kB
                ->  Nested Loop Left Join  (cost=0.29..58.94 rows=11 width=42) (actual time=0.031..0.055 rows=6 loops=1)                       ->  Seq Scan on internalvalidations i_1 (cost=0.00..9.81 rows=11 width=26) (actual time=0.012..0.033 rows=6 loops=1)
                            Filter: isvisible
                            Rows Removed by Filter: 453
                      ->  Memoize  (cost=0.29..7.58 rows=1 width=20) (actual time=0.003..0.003 rows=1 loops=6)
                            Cache Key: i_1.idclaimer
                            Cache Mode: logical
                            Hits: 5  Misses: 1  Evictions: 0 Overflows: 0  Memory Usage: 1kB                             ->  Index Scan using users_pkey on users users_1  (cost=0.28..7.57 rows=1 width=20) (actual time=0.012..0.013 rows=1 loops=1)
                                  Index Cond: (iduser = i_1.idclaimer)
  CTE u_g_internalvalidation_without_u_status
    ->  Recursive Union  (cost=23.65..7914563.16 rows=220606936 width=19) (never executed)           ->  Nested Loop  (cost=23.65..9280.10 rows=1936 width=19) (never executed)
                Join Filter: (uhi.iduser = gu.iduser)
                ->  Nested Loop  (cost=23.40..80.70 rows=733 width=15) (never executed)                       ->  Hash Join  (cost=23.11..42.43 rows=733 width=10) (never executed)                             Hash Cond: (internalvalidation.idinternalvalidation = uhi.idinternalvalidation)                             ->  CTE Scan on internalvalidation (cost=0.00..8.72 rows=436 width=4) (never executed)                             ->  Hash  (cost=13.05..13.05 rows=805 width=10) (never executed)                                   ->  Seq Scan on users_has_internalvalidations uhi  (cost=0.00..13.05 rows=805 width=10) (never executed)                       ->  Memoize  (cost=0.29..1.67 rows=1 width=5) (never executed)
                            Cache Key: uhi.iduser
                            Cache Mode: logical
                            ->  Index Scan using users_pkey on users v  (cost=0.28..1.66 rows=1 width=5) (never executed)
                                  Index Cond: (iduser = uhi.iduser)
                ->  Function Scan on get_user gu (cost=0.25..12.75 rows=4 width=5) (never executed)                       Filter: ((canvalidate OR v.isgroup) AND (v.iduser = iduser))           ->  Nested Loop  (cost=750.89..349314.43 rows=22060500 width=19) (never executed)                 ->  Merge Join  (cost=750.63..1200.96 rows=29414 width=18) (never executed)
                      Merge Cond: (uhg.idgroup = ugiwus.idusergroup)
                      ->  Sort  (cost=126.96..131.52 rows=1823 width=8) (never executed)
                            Sort Key: uhg.idgroup
                            ->  Seq Scan on users_has_groups uhg  (cost=0.00..28.23 rows=1823 width=8) (never executed)                       ->  Sort  (cost=623.67..631.74 rows=3227 width=18) (never executed)
                            Sort Key: ugiwus.idusergroup
                            ->  WorkTable Scan on u_g_internalvalidation_without_u_status ugiwus  (cost=0.00..435.60 rows=3227 width=18) (never executed)
                                  Filter: (isgroup AND (level < 25))
                ->  Memoize  (cost=0.26..10.26 rows=750 width=5) (never executed)
                      Cache Key: uhg.iduser
                      Cache Mode: binary
                      ->  Function Scan on get_user gu_1 (cost=0.25..10.25 rows=750 width=5) (never executed)
                            Filter: (canvalidate OR isgroup)
  ->  Hash Join  (cost=36403119772.02..36403120996.38 rows=436 width=120) (actual time=11.609..11.611 rows=0 loops=1)
        Hash Cond: (ug1.idinternalvalidation = i.idinternalvalidation)
        ->  Merge Left Join (cost=36403119757.85..36403120966.35 rows=200 width=75) (never executed)               Merge Cond: (ug1.idinternalvalidation = u_g_internalvalidation.idinternalvalidation)               ->  GroupAggregate (cost=36397604572.80..36397605775.80 rows=200 width=70) (never executed)
                    Group Key: ug1.idinternalvalidation
                    ->  Sort (cost=36397604572.80..36397604772.80 rows=80000 width=27) (never executed)
                          Sort Key: ug1.idinternalvalidation
                          ->  Hash Left Join (cost=36397596247.48..36397598057.72 rows=80000 width=27) (never executed)
                                Hash Cond: (ug1.idusergroup = users.iduser)
                                ->  HashAggregate (cost=36397595908.85..36397596708.85 rows=80000 width=43) (never executed)                                       Group Key: ug1.idinternalvalidation, ug1.idusergroup, ug1.atleastonemustvalidate                                       ->  Merge Left Join (cost=77330317.34..21265069958.96 rows=1210602075991 width=13) (never executed)                                             Merge Cond: ((ug1.idinternalvalidation = ug2.idinternalvalidation) AND (ug1.iduser = ug2.iduser))                                             ->  Sort (cost=38754984.35..39306501.69 rows=220606936 width=15) (never executed)                                                   Sort Key: ug1.idinternalvalidation, ug1.iduser                                                   ->  CTE Scan on u_g_internalvalidation_without_u_status ug1 (cost=0.00..4412138.72 rows=220606936 width=15) (never executed)                                             ->  Materialize (cost=38575332.99..39672852.50 rows=219503901 width=10) (never executed)                                                   ->  Sort (cost=38575332.99..39124092.74 rows=219503901 width=10) (never executed)                                                         Sort Key: ug2.idinternalvalidation, ug2.iduser                                                         ->  CTE Scan on u_g_internalvalidation_without_u_status ug2 (cost=0.00..4412138.72 rows=219503901 width=10) (never executed)
Filter: (hasvalidate IS NOT NULL)
                                ->  Hash  (cost=289.95..289.95 rows=3895 width=20) (never executed)                                       ->  Seq Scan on users (cost=0.00..289.95 rows=3895 width=20) (never executed)               ->  Sort  (cost=5515185.04..5515185.54 rows=200 width=5) (never executed)
                    Sort Key: u_g_internalvalidation.idinternalvalidation
                    ->  Subquery Scan on u_g_internalvalidation  (cost=5515173.40..5515177.40 rows=200 width=5) (never executed)                           ->  HashAggregate (cost=5515173.40..5515175.40 rows=200 width=5) (never executed)
                                Group Key: ugi.idinternalvalidation
                                ->  CTE Scan on u_g_internalvalidation_without_u_status ugi (cost=0.00..4412138.72 rows=220606936 width=5) (never executed)         ->  Hash  (cost=8.72..8.72 rows=436 width=49) (actual time=11.603..11.603 rows=0 loops=1)
              Buckets: 1024  Batches: 1  Memory Usage: 8kB
              ->  CTE Scan on internalvalidation i (cost=0.00..8.72 rows=436 width=49) (actual time=11.603..11.603 rows=0 loops=1)
  ->  CTE Scan on u  (cost=0.00..5.00 rows=125 width=4) (never executed)
        Filter: canvalidate
Planning Time: 1.037 ms
Execution Time: 493.815 ms


And here is the query in case it can help :


explain analyze
WITH RECURSIVE
    params AS (
        SELECT
            4 AS fn_iduser
            , 1 AS fn_idrealm
            , NULL::INT[] AS fn_idfile
            , TRUE AS fn_canseesubfiles
    ),
    r AS (
    SELECT realms.*
    FROM realms
    CROSS JOIN params
    WHERE idrealm=fn_idrealm
)
,u AS (
    SELECT *
    FROM PARAMS
    CROSS JOIN get_user(fn_iduser)
    WHERE NOT isgroup
    AND NOT istemplate
)
,allfiles AS (
    SELECT files.idfile --idfile devrait suffire
    FROM params
    CROSS JOIN (
        SELECT UNNEST(fn_idfile) as idfile FROM params
    ) AS unnestedfiles
    JOIN files ON files.idfile = unnestedfiles.idfile OR (
        -- see sub files
        fn_idrealm = files.idrealminitial
        AND
        fn_canseesubfiles
    )
    WHERE fn_idfile IS NOT NULL

    UNION

    SELECT files.idfile --idfile devrait suffire
    FROM files
    CROSS JOIN params
    WHERE fn_idfile IS NULL
    AND files.idrealm = fn_idrealm OR ( files.idrealminitial = fn_idrealm AND fn_canseesubfiles )
)
,internalvalidation as (
    SELECT i.*, users.name
    FROM allfiles pfu
    JOIN internalvalidations i ON i.idfile = pfu.idfile AND i.isvisible
    LEFT JOIN users ON users.iduser = i.idclaimer
)
,u_g_internalvalidation_without_u_status AS (
    SELECT uhi.idinternalvalidation
            ,uhi.iduser as idusergroup
            ,uhi.hasvalidate
            ,uhi.atleastonemustvalidate
            ,v.iduser
            ,v.isgroup
            , 0 level
    FROM internalvalidation
    JOIN users_has_internalvalidations uhi ON uhi.idinternalvalidation = internalvalidation.idinternalvalidation
    JOIN users v on uhi.iduser = v.iduser
    JOIN get_user(v.iduser) gu ON gu.iduser = v.iduser AND ( gu.canvalidate OR v.isgroup )

    UNION

    SELECT
        ugiwus.idinternalvalidation
        ,ugiwus.iduser as idusergroup
        ,ugiwus.hasvalidate
        ,ugiwus.atleastonemustvalidate
        ,gu.iduser
        ,gu.isgroup
        , ugiwus.level + 1
    FROM u_g_internalvalidation_without_u_status ugiwus
    JOIN users_has_groups uhg ON uhg.idgroup = ugiwus.idusergroup AND ugiwus.isgroup
    JOIN get_user(uhg.iduser) gu ON ( gu.canvalidate OR gu.isgroup )
    WHERE ugiwus.level < 25
)
--    SELECT * FROM u_g_internalvalidation_without_u_status;
,u_g_internalvalidation AS (
    SELECT ugi.idinternalvalidation, bool_or(COALESCE(ugi.hasvalidate,false)) currentuserhasvalidate--, bool_or( ugi.iduser = u.iduser ) /* à quoi sert ce champ ? */
    FROM u_g_internalvalidation_without_u_status ugi
--    CROSS JOIN u /* et donc à quoi sert cette table ? */
--    WHERE u.iduser = ugi.iduser
    GROUP BY ugi.idinternalvalidation
)
,regroup_users as (
    SELECT -- regroup users by group etc ...
        ug1.idinternalvalidation
        ,ug1.idusergroup
        ,BOOL_OR( COALESCE( ug2.hasvalidate, ug1.hasvalidate,false)) FILTER ( WHERE NOT ug1.isgroup OR ug2.isgroup ) AS atleastoneuserhasvalidate         ,BOOL_AND( COALESCE( ug2.hasvalidate, ug1.hasvalidate,false)) FILTER ( WHERE NOT ug1.isgroup OR ug2.isgroup ) AS everyuserhasvalidate
        ,ARRAY_AGG( DISTINCT ug1.iduser) AS iduser
        ,ug1.atleastonemustvalidate
    FROM u_g_internalvalidation_without_u_status ug1
    LEFT JOIN u_g_internalvalidation_without_u_status ug2 ON ug2.idinternalvalidation = ug1.idinternalvalidation AND ug2.iduser = ug1.iduser AND ug2.hasvalidate IS NOT NULL     GROUP BY ug1.idinternalvalidation,ug1.idusergroup,ug1.atleastonemustvalidate
)
,regroup_internvalvalidations AS (
    SELECT
        r.idinternalvalidation
        ,ARRAY_AGG(r.idusergroup) AS iduser
        ,ARRAY_AGG(users.name) AS name
        ,BOOL_OR(v.validate) AS atleastoneuserhasvalidate
        ,BOOL_AND(v.validate) AS everyusershasvalidate
    FROM regroup_users r
    LEFT JOIN users ON users.iduser = r.idusergroup
    CROSS JOIN LATERAL (
        SELECT CASE
            WHEN r.atleastonemustvalidate THEN r.atleastoneuserhasvalidate
            ELSE r.everyuserhasvalidate
        END AS validate
    ) AS v
    GROUP BY r.idinternalvalidation
)
SELECT
    ri.idinternalvalidation
    ,ri.iduser
    ,ri.name
    ,ri.atleastoneuserhasvalidate
    ,ri.everyusershasvalidate
    ,i.ttl
    ,i.idfile
    ,i.idclaimer
    ,i.name AS claimername
    ,CASE WHEN i.atleastonemustvalidate THEN ri.atleastoneuserhasvalidate ELSE ri.everyusershasvalidate END AS internalvalidationisdone     ,CASE WHEN u.iduser IS NULL THEN NULL::BOOLEAN ELSE u_g_internalvalidation.currentuserhasvalidate END AS currentuserhasvalidate
FROM regroup_internvalvalidations ri
JOIN internalvalidation i ON i.idinternalvalidation = ri.idinternalvalidation LEFT JOIN u_g_internalvalidation ON u_g_internalvalidation.idinternalvalidation = ri.idinternalvalidation LEFT JOIN u ON u_g_internalvalidation.idinternalvalidation IS NOT NULL AND u.canvalidate






[Postgresql General]     [Postgresql PHP]     [PHP Users]     [PHP Home]     [PHP on Windows]     [Kernel Newbies]     [PHP Classes]     [PHP Books]     [PHP Databases]     [Yosemite]

  Powered by Linux