On Tue, Aug 13, 2019 at 1:16 PM Kasahara Tatsuhito <kasahara.tatsuh...@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
