Thread: Explain analyse with track_io_timing
Hello team,
What is the unit of I/O Timings in explain (analyze, buffers) ? There is a plan with quite a few nodes. In each case, the value of I/O Timings is much more than the time for the outer node. A few lines from the plan -
Hash Left Join (cost=14320945.22..7099974624.27 rows=194335062701 width=5511) (actual time=107913.021..108109.313 rows=759 loops=1)
Buffers: shared hit=738871 read=1549646, temp read=92710 written=92973
I/O Timings: read=228324.357
-> Hash Left Join (cost=14049069.69..246411189.41 rows=18342148438 width=5467) (actual time=96579.630..96774.534 rows=759 loops=1)
Buffers: shared hit=684314 read=1377851, temp read=92710 written=92973
I/O Timings: read=217899.233
Buffers: shared hit=738871 read=1549646, temp read=92710 written=92973
I/O Timings: read=228324.357
-> Hash Left Join (cost=14049069.69..246411189.41 rows=18342148438 width=5467) (actual time=96579.630..96774.534 rows=759 loops=1)
Buffers: shared hit=684314 read=1377851, temp read=92710 written=92973
I/O Timings: read=217899.233
At the end, there is
Execution Time: 108117.006 ms
So it takes about 108 seconds. But the I/O Timings are higher.
Best Regards,
Jay
Hi, On Thu, Mar 10, 2022 at 10:40:17AM +0530, Jayadevan M wrote: > > What is the unit of I/O Timings in explain (analyze, buffers) ? milliseconds > There is a plan with quite a few nodes. In each case, the value of I/O > Timings is much more than the time for the outer node. A few lines from the > plan - > > Hash Left Join (cost=14320945.22..7099974624.27 rows=194335062701 > width=5511) (actual time=107913.021..*108109*.313 rows=759 loops=1) > Buffers: shared hit=738871 read=1549646, temp read=92710 written=92973 > I/O Timings: read=*228324*.357 > -> Hash Left Join (cost=14049069.69..246411189.41 rows=18342148438 > width=5467) (actual time=96579.630..*96774*.534 rows=759 loops=1) > Buffers: shared hit=684314 read=1377851, temp read=92710 > written=92973 > I/O Timings: read=*217899*.233 > At the end, there is > Execution Time: 108117.006 ms > > So it takes about 108 seconds. But the I/O Timings are higher. Is it a parallel query? If yes the total time is only the time spent in the main process, and the IO time is sum of all IO time spent in main process and the parallel workers, which can obviously be a lot more than the total execution time.
Is it a parallel query? If yes the total time is only the time spent in the
main process, and the IO time is sum of all IO time spent in main process and
the parallel workers, which can obviously be a lot more than the total
execution time.
Yes, there are parallel workers, that explains it. Thank you.
Regards,
Jay