Thread: Re: pg_dump verbose start and stop times?
On Thu, May 29, 2025 at 08:51:49PM -0400, Ron Johnson wrote: > The non-sense of putting start and stop times in the dump file while not > putting them in stderr must have caused my brain to skip over "to the dump > file". > > Honestly, who cares if start and stop times are in the dump file? stderr > is where a DBA wants to see timings. =$ date >&2; pg_dump …; date >&2 That's all you need. Whether pg_dump does what you want, or not, is not really important given how easy it is to fix the thing yourself. And the assumption that: "it doesn't do what *I* want, so it's non-sense", is slightly exaggerating commonality of your experience. Best regards, depesz
On Fri, May 30, 2025 at 6:09 AM hubert depesz lubaczewski <depesz@depesz.com> wrote:
On Thu, May 29, 2025 at 08:51:49PM -0400, Ron Johnson wrote:
> The non-sense of putting start and stop times in the dump file while not
> putting them in stderr must have caused my brain to skip over "to the dump
> file".
>
> Honestly, who cares if start and stop times are in the dump file? stderr
> is where a DBA wants to see timings.
=$ date >&2; pg_dump …; date >&2
That's all you need.
That (poorly) tells me how long the whole dump took. Heck, it requires you to manually do the math yourself. Useful information like how long it took to dump each table (even more importantly: how long it took for pg_restore to copy each table, and create each index) is not shown.
Whether pg_dump does what you want, or not, is not really important
given how easy it is to fix the thing yourself.
And yet it's not possible to show how long it takes to copy each object . This, at least, does the math to show the grand elapsed time, and puts an easily greppable string in the cron job's stdout+stderr log file:
time_it()
{
local ActionLabel=$1
shift
date +"%n%F %T TIMEIT $ActionLabel started.%n"
START_SECS=$(date +"%s")
$@
local RC=$? ; echo "TIMEIT Return Code = $RC"
FINISH_SECS=$(date +"%s")
ET=$(echo "scale=2;(${FINISH_SECS} - ${START_SECS})/60" | bc)
date +"%n%F %T TIMEIT $ActionLabel finished. Elapsed time: ${ET} minutes."
return $RC
}
{
local ActionLabel=$1
shift
date +"%n%F %T TIMEIT $ActionLabel started.%n"
START_SECS=$(date +"%s")
$@
local RC=$? ; echo "TIMEIT Return Code = $RC"
FINISH_SECS=$(date +"%s")
ET=$(echo "scale=2;(${FINISH_SECS} - ${START_SECS})/60" | bc)
date +"%n%F %T TIMEIT $ActionLabel finished. Elapsed time: ${ET} minutes."
return $RC
}
time_it DUMP_$DB pg_dump -j ${Threads} -Z${ZLvl} -v -C -Fd --file=$DB $DB 2> ${DB}_pgdump.log
And the assumption that: "it doesn't do what *I* want, so it's
non-sense", is slightly exaggerating commonality of your experience.
The pgbackrest developer seems to think it's sensical to put timestamps in each detail line. They're right.
Death to <Redacted>, and butter sauce.
Don't boil me, I'm still alive.
<Redacted> lobster!
On Fri, May 30, 2025 at 9:48 AM hubert depesz lubaczewski <depesz@depesz.com> wrote:
On Fri, May 30, 2025 at 08:54:24AM -0400, Ron Johnson wrote:
> And yet it's not possible to show how long it takes to copy each object .
> This, at least, does the math to show the grand elapsed time, and puts an
> easily greppable string in the cron job's stdout+stderr log file:
>
> time_it()
> {
> local ActionLabel=$1
> shift
> date +"%n%F %T TIMEIT $ActionLabel started.%n"
> START_SECS=$(date +"%s")
> $@
> local RC=$? ; echo "TIMEIT Return Code = $RC"
> FINISH_SECS=$(date +"%s")
> ET=$(echo "scale=2;(${FINISH_SECS} - ${START_SECS})/60" | bc)
> date +"%n%F %T TIMEIT $ActionLabel finished. Elapsed time: ${ET}
> minutes."
> return $RC
> }
>
> time_it DUMP_$DB pg_dump -j ${Threads} -Z${ZLvl} -v -C -Fd --file=$DB $DB
> 2> ${DB}_pgdump.log
You do know that you could have just done:
time pg_dump …
without the time_it function?
Without the easily greppable string that shows what action it performed. That's why I wrote the function: to have a standard, constant string to grep.
And if you'd want to write your own function, assuming you're running
not-so-ancient bash, you could have just used $EPOCHREALTIME and not the
date +… ?
RHEL 8 is apparently ancient.
When all my RHEL 7 and 8 servers are retired, I might change it to use $EPOCHREALTIME. Or maybe not; ancient, forgotten servers lurk everywhere, and this probably works on RHEL 6.
Death to <Redacted>, and butter sauce.
Don't boil me, I'm still alive.
<Redacted> lobster!