Обсуждение: small improvement of the elapsed time for truncating heap in vacuum
Hi, I got following log messages when measured the heap truncating duration in a vacuum. ===================================================== INFO: "dst": suspending truncate due to conflicting lock request INFO: "dst": truncated 550073 to 101472 pages DETAIL: CPU: user: 0.35 s, system: 4.92 s, elapsed: 6.96 s INFO: "dst": truncated 101472 to 164 pages DETAIL: CPU: user: 0.35 s, system: 11.02 s, elapsed: 13.46 s ===================================================== Above message shows that postgres detected a access to the table during heap truncating so suspend the truncating, and then resumed truncating after the access finish. The messages were no-problem. But "usage" and "elapsed (time)" were bit confusing. Total truncating duration was about 13.5s, but log said 6.96s (before suspend) + 13.46s (remain). # I confirmed the total truncating duration by elog debugging. In lazy_truncate_heap() pg_rusage_init is only called once at the truncating start. So the last-truncating-phase-log shows the total truncating-phase usages and elapsed time. Attached patch make pg_rusage_init would be called after each ereport() of heap-truncating, so log messages will change like following. ===================================================== INFO: "dst": suspending truncate due to conflicting lock request INFO: "dst": truncated 550073 to 108288 pages DETAIL: CPU: user: 0.20 s, system: 4.88 s, elapsed: 7.41 s INFO: "dst": truncated 108288 to 164 pages DETAIL: CPU: user: 0.00 s, system: 7.36 s, elapsed: 7.92 s ===================================================== (Total truncating time was about 15.3s in above case) Any thoughts ? Best regards, -- Tatsuhito Kasahara NTT Open Source Software Center
Вложения
On Tue, Aug 13, 2019 at 1:16 PM Kasahara Tatsuhito <kasahara.tatsuhito@gmail.com> wrote: > > Hi, > > I got following log messages when measured the heap truncating > duration in a vacuum. > > ===================================================== > INFO: "dst": suspending truncate due to conflicting lock request > INFO: "dst": truncated 550073 to 101472 pages > DETAIL: CPU: user: 0.35 s, system: 4.92 s, elapsed: 6.96 s > INFO: "dst": truncated 101472 to 164 pages > DETAIL: CPU: user: 0.35 s, system: 11.02 s, elapsed: 13.46 s > ===================================================== > > Above message shows that postgres detected a access to the table > during heap truncating so suspend the truncating, > and then resumed truncating after the access finish. The messages were > no-problem. > But "usage" and "elapsed (time)" were bit confusing. > Total truncating duration was about 13.5s, but log said 6.96s (before > suspend) + 13.46s (remain). > # I confirmed the total truncating duration by elog debugging. > > In lazy_truncate_heap() pg_rusage_init is only called once at the > truncating start. > So the last-truncating-phase-log shows the total truncating-phase > usages and elapsed time. > Attached patch make pg_rusage_init would be called after each > ereport() of heap-truncating, > so log messages will change like following. > > ===================================================== > INFO: "dst": suspending truncate due to conflicting lock request > INFO: "dst": truncated 550073 to 108288 pages > DETAIL: CPU: user: 0.20 s, system: 4.88 s, elapsed: 7.41 s > INFO: "dst": truncated 108288 to 164 pages > DETAIL: CPU: user: 0.00 s, system: 7.36 s, elapsed: 7.92 s > ===================================================== > (Total truncating time was about 15.3s in above case) > > Any thoughts ? +1. I observed this issue and found this thread. Regarding the patch, isn't it better to put pg_rusage_init() at the top of do loop block? If we do this, as a side-effect, we can get rid of pg_rusage_init() at the top of lazy_truncate_heap(). Regards, -- Fujii Masao
Hi, On Fri, Feb 14, 2020 at 4:50 PM Fujii Masao <masao.fujii@gmail.com> wrote: > Regarding the patch, isn't it better to put pg_rusage_init() at the > top of do loop block? If we do this, as a side-effect, we can get > rid of pg_rusage_init() at the top of lazy_truncate_heap(). Thanks for your reply. Yeah, it makes sense. Attached patch moves pg_rusage_init() to the top of do-loop-block. Best regards, -- Tatsuhito Kasahara kasahara.tatsuhito _at_ gmail.com
Вложения
On Mon, 17 Feb 2020 at 12:44, Kasahara Tatsuhito <kasahara.tatsuhito@gmail.com> wrote: > > Hi, > > On Fri, Feb 14, 2020 at 4:50 PM Fujii Masao <masao.fujii@gmail.com> wrote: > > Regarding the patch, isn't it better to put pg_rusage_init() at the > > top of do loop block? If we do this, as a side-effect, we can get > > rid of pg_rusage_init() at the top of lazy_truncate_heap(). > Thanks for your reply. > Yeah, it makes sense. > > Attached patch moves pg_rusage_init() to the top of do-loop-block. +1 to reset for each truncation loops. For the patch, we can put also the declaration of ru0 into the loop. Regards, -- Masahiko Sawada http://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
Hi, On Mon, Feb 17, 2020 at 1:07 PM Masahiko Sawada <masahiko.sawada@2ndquadrant.com> wrote: > For the patch, we can put also the declaration of ru0 into the loop. Thanks for your reply. Hmm, certainly that it may be better. Fix the v2 patch and attached. Best regards, -- Tatsuhito Kasahara kasahara.tatsuhito _at_ gmail.com
Вложения
On 2020/02/17 14:28, Kasahara Tatsuhito wrote: > Hi, > > On Mon, Feb 17, 2020 at 1:07 PM Masahiko Sawada > <masahiko.sawada@2ndquadrant.com> wrote: >> For the patch, we can put also the declaration of ru0 into the loop. > Thanks for your reply. > Hmm, certainly that it may be better. > > Fix the v2 patch and attached. Thanks for updating the patch! Barring any objection, I will commit this. As far as I check the back branches, ISTM that this patch needs to be back-patch to v9.5. Regards, -- Fujii Masao NTT DATA CORPORATION Advanced Platform Technology Group Research and Development Headquarters
On 2020/02/17 17:52, Fujii Masao wrote: > > > On 2020/02/17 14:28, Kasahara Tatsuhito wrote: >> Hi, >> >> On Mon, Feb 17, 2020 at 1:07 PM Masahiko Sawada >> <masahiko.sawada@2ndquadrant.com> wrote: >>> For the patch, we can put also the declaration of ru0 into the loop. >> Thanks for your reply. >> Hmm, certainly that it may be better. >> >> Fix the v2 patch and attached. > > Thanks for updating the patch! > Barring any objection, I will commit this. > > As far as I check the back branches, ISTM that > this patch needs to be back-patch to v9.5. Pushed. Thanks! Regards, -- Fujii Masao NTT DATA CORPORATION Advanced Platform Technology Group Research and Development Headquarters