Subject: Reading execution plan - first row time vs last row time

From: Pecsök Ján <[email-masked]>
Date: Tue, 1 Oct 2024 13:53:18 +0000

Dear community,

We see significant difference in explain analyze Actual time in the first line of execution plan and Execution time in the last line of execution plan. What can be the reason?

For example, first line of execution plan:
Gather  (cost=1038.49..257627100.42 rows=7943222226 width=104) (actual time=531.925..3673159.806 rows=7943221053 loops=1)

This is 3673159/1000/60 = 61 minutes

And last 2 lines of execution plan:
Planning Time: 3000.399 ms
Execution Time: 21208130.602 ms

This is : 21208130/1000/60= 353 minutes

What happened in 353 - 61 = 292 minutes? We speculate that disk writes. Query possibly written cca 0,75TB of data, by create table as select query.

S pozdravem
Ján Pecsők

Tychonova 2, 160 00 Praha
Mobil: +420 775 942 871
[email-masked]<mailto:[email-masked]>
www.profinit.eu<https://www.profinit.eu/>
<https://www.profinit.eu/>

---

From: Adrian Klaver <[email-masked]>
Date: Tue, 1 Oct 2024 07:15:47 -0700

On 10/1/24 06:53, Pecsök Ján wrote:
> Dear community,
> 
> We see significant difference in explain analyze Actual time in the 
> first line of execution plan and Execution time in the last line of 
> execution plan. What can be the reason?
> 
> Gather  (cost=1038.49..257627100.42 rows=7943222226 width=104) (actual 
> time=531.925..3673159.806 rows=7943221053 loops=1)
> 
> What happened in 353 – 61 = 292 minutes? We speculate that disk writes. 
> Query possibly written cca 0,75TB of data, by create table as select query.

You will need to show the complete EXPLAIN ANALYZE output as well as query.

> *Ján Pecsők*
> [email-masked] <mailto:[email-masked]>
> www.profinit.eu <https://www.profinit.eu/>
> 

-- 
Adrian Klaver
[email-masked]

---

From: Greg Sabino Mullane <[email-masked]>
Date: Tue, 1 Oct 2024 10:39:11 -0400

On Tue, Oct 1, 2024 at 9:53 AM Pecsök Ján <[email-masked]> wrote:

> We see significant difference in explain analyze Actual time in the first
> line of execution plan and Execution time in the last line of execution
> plan. What can be the reason?
>
>
>

It takes an hour for Postgres to gather up 7.9 BILLION (!) rows, but then
it is going to take additional time to do something with all of those rows.
That's where the rest of your time is going. Seeing your actual query would
be a help. If this is a CTAS (Create Table As Select), then you have an
hour for the 'Select' part, and the rest of your time is in the 'Create
Table' part.

Cheers,
Greg