public inbox for [email protected]  
help / color / mirror / Atom feed
pg_dump verbose start and stop times?
9+ messages / 4 participants
[nested] [flat]

* pg_dump verbose start and stop times?
@ 2025-05-29 20:37 Ron Johnson <[email protected]>
  2025-05-29 20:42 ` Re: pg_dump verbose start and stop times? David G. Johnston <[email protected]>
  0 siblings, 1 reply; 9+ messages in thread

From: Ron Johnson @ 2025-05-29 20:37 UTC (permalink / raw)
  To: pgsql-admin

https://www.postgresql.org/docs/15/app-pgdump.html
"
Specifies verbose mode. This will cause pg_dump to output detailed object
comments and start/stop times to the dump file, and progress messages to
standard error.
"

But I don't see any timing messages.  What am I misunderstanding in the
docs?

$ pg_dump -V
pg_dump (PostgreSQL) 16.9
$ postgres -V
postgres (PostgreSQL) 16.9
$ pg_dump -Fp -v ccoremultid > ~/ccoremultid.sql
pg_dump: last built-in OID is 16383
pg_dump: reading extensions
pg_dump: identifying extension members
pg_dump: reading schemas
pg_dump: reading user-defined tables
pg_dump: reading user-defined functions
pg_dump: reading user-defined types
pg_dump: reading procedural languages
pg_dump: reading user-defined aggregate functions
pg_dump: reading user-defined operators
pg_dump: reading user-defined access methods
pg_dump: reading user-defined operator classes
pg_dump: reading user-defined operator families
pg_dump: reading user-defined text search parsers
pg_dump: reading user-defined text search templates
pg_dump: reading user-defined text search dictionaries
pg_dump: reading user-defined text search configurations
pg_dump: reading user-defined foreign-data wrappers
pg_dump: reading user-defined foreign servers
pg_dump: reading default privileges
pg_dump: reading user-defined collations
pg_dump: reading user-defined conversions
pg_dump: reading type casts
pg_dump: reading transforms
pg_dump: reading table inheritance information
pg_dump: reading event triggers
pg_dump: finding extension tables
pg_dump: finding inheritance relationships
pg_dump: reading column info for interesting tables
pg_dump: flagging inherited columns in subtables
pg_dump: reading partitioning data
pg_dump: reading indexes
pg_dump: flagging indexes in partitioned tables
pg_dump: reading extended statistics
pg_dump: reading constraints
pg_dump: reading triggers
pg_dump: reading rewrite rules
pg_dump: reading policies
pg_dump: reading row-level security policies
pg_dump: reading publications
pg_dump: reading publication membership of tables
pg_dump: reading publication membership of schemas
pg_dump: reading subscriptions
pg_dump: reading large objects
pg_dump: reading dependency data
pg_dump: saving encoding = UTF8
pg_dump: saving standard_conforming_strings = on
pg_dump: saving search_path =
pg_dump: creating SCHEMA "dba"
pg_dump: creating EXTENSION "pgstattuple"
pg_dump: creating COMMENT "EXTENSION pgstattuple"
pg_dump: creating FUNCTION "dba.get_fk_referenced_by(text)"
pg_dump: creating FUNCTION "dba.get_fk_references(text)"
pg_dump: creating VIEW "dba.aggregate_cache_hits"
pg_dump: creating VIEW "dba.all_indices"
pg_dump: creating VIEW "dba.all_indices_types"
pg_dump: creating VIEW "dba.latest_vacuum_and_analyze"
pg_dump: creating VIEW "dba.analyze_levels"
pg_dump: creating TABLE "dba.index_bloat_1stg"
pg_dump: creating TABLE "dba.index_bloat_2stg"
pg_dump: creating VIEW "dba.index_cache_hits"
pg_dump: creating VIEW "dba.latest_toast_vacuum"
pg_dump: creating TABLE "dba.pre_analyze_hot"
pg_dump: creating VIEW "dba.statio_tables"
pg_dump: creating TABLE "dba.table_bloat_1stg"
pg_dump: creating TABLE "dba.table_bloat_2stg"
pg_dump: creating VIEW "dba.table_cache_hits"
pg_dump: creating VIEW "dba.toast_cache_hits"
pg_dump: creating TABLE "dba.track_analyze_hot"
pg_dump: creating VIEW "dba.v_parents_and_loners"
pg_dump: creating VIEW "dba.v_relations"
pg_dump: creating VIEW "dba.v_table_size"
pg_dump: processing data for table "dba.index_bloat_1stg"
pg_dump: dumping contents of table "dba.index_bloat_1stg"
pg_dump: processing data for table "dba.index_bloat_2stg"
pg_dump: dumping contents of table "dba.index_bloat_2stg"
pg_dump: processing data for table "dba.pre_analyze_hot"
pg_dump: dumping contents of table "dba.pre_analyze_hot"
pg_dump: processing data for table "dba.table_bloat_1stg"
pg_dump: dumping contents of table "dba.table_bloat_1stg"
pg_dump: processing data for table "dba.table_bloat_2stg"
pg_dump: dumping contents of table "dba.table_bloat_2stg"
pg_dump: processing data for table "dba.track_analyze_hot"
pg_dump: dumping contents of table "dba.track_analyze_hot"
pg_dump: creating CONSTRAINT "dba.index_bloat_1stg index_bloat_1stg_pkey"
pg_dump: creating CONSTRAINT "dba.index_bloat_2stg index_bloat_2stg_pkey"
pg_dump: creating CONSTRAINT "dba.pre_analyze_hot pre_analyze_hot_pkey"
pg_dump: creating CONSTRAINT "dba.table_bloat_1stg table_bloat_1stg_pkey"
pg_dump: creating CONSTRAINT "dba.table_bloat_2stg table_bloat_2stg_pkey"
pg_dump: creating CONSTRAINT "dba.track_analyze_hot track_analyze_hot_pkey"
pg_dump: creating ACL "SCHEMA dba"
pg_dump: creating ACL "dba.TABLE all_indices"
pg_dump: creating ACL "dba.TABLE all_indices_types"
pg_dump: creating ACL "dba.TABLE latest_vacuum_and_analyze"
pg_dump: creating ACL "dba.TABLE analyze_levels"
pg_dump: creating ACL "dba.TABLE latest_toast_vacuum"
pg_dump: creating ACL "dba.TABLE v_relations"

-- 
Death to <Redacted>, and butter sauce.
Don't boil me, I'm still alive.
<Redacted> lobster!


^ permalink  raw  reply  [nested|flat] 9+ messages in thread

* Re: pg_dump verbose start and stop times?
  2025-05-29 20:37 pg_dump verbose start and stop times? Ron Johnson <[email protected]>
@ 2025-05-29 20:42 ` David G. Johnston <[email protected]>
  2025-05-30 00:51   ` Re: pg_dump verbose start and stop times? Ron Johnson <[email protected]>
  0 siblings, 1 reply; 9+ messages in thread

From: David G. Johnston @ 2025-05-29 20:42 UTC (permalink / raw)
  To: Ron Johnson <[email protected]>; +Cc: pgsql-admin

On Thursday, May 29, 2025, Ron Johnson <[email protected]> wrote:

>
> https://www.postgresql.org/docs/15/app-pgdump.html
> "
> Specifies verbose mode. This will cause pg_dump to output detailed object
> comments and start/stop times to the dump file, and progress messages to
> standard error.
> "
>
> But I don't see any timing messages.  What am I misunderstanding in the
> docs?
>

It says there the times end up in the dump file, which you redirected and
didn’t show the contents of.

David J.


^ permalink  raw  reply  [nested|flat] 9+ messages in thread

* Re: pg_dump verbose start and stop times?
  2025-05-29 20:37 pg_dump verbose start and stop times? Ron Johnson <[email protected]>
  2025-05-29 20:42 ` Re: pg_dump verbose start and stop times? David G. Johnston <[email protected]>
@ 2025-05-30 00:51   ` Ron Johnson <[email protected]>
  2025-05-30 05:45     ` Re: pg_dump verbose start and stop times? Laurenz Albe <[email protected]>
  2025-05-30 10:09     ` Re: pg_dump verbose start and stop times? hubert depesz lubaczewski <[email protected]>
  0 siblings, 2 replies; 9+ messages in thread

From: Ron Johnson @ 2025-05-30 00:51 UTC (permalink / raw)
  To: pgsql-admin

On Thu, May 29, 2025 at 4:42 PM David G. Johnston <
[email protected]> wrote:

> On Thursday, May 29, 2025, Ron Johnson <[email protected]> wrote:
>
>>
>> https://www.postgresql.org/docs/15/app-pgdump.html
>> "
>> Specifies verbose mode. This will cause pg_dump to output detailed
>> object comments and start/stop times to the dump file, and progress
>> messages to standard error.
>> "
>>
>> But I don't see any timing messages.  What am I misunderstanding in the
>> docs?
>>
>
> It says there the times end up in the dump file, which you redirected and
> didn’t show the contents of.
>

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.

-- 
Death to <Redacted>, and butter sauce.
Don't boil me, I'm still alive.
<Redacted> lobster!


^ permalink  raw  reply  [nested|flat] 9+ messages in thread

* Re: pg_dump verbose start and stop times?
  2025-05-29 20:37 pg_dump verbose start and stop times? Ron Johnson <[email protected]>
  2025-05-29 20:42 ` Re: pg_dump verbose start and stop times? David G. Johnston <[email protected]>
  2025-05-30 00:51   ` Re: pg_dump verbose start and stop times? Ron Johnson <[email protected]>
@ 2025-05-30 05:45     ` Laurenz Albe <[email protected]>
  2025-05-30 12:39       ` Re: pg_dump verbose start and stop times? Ron Johnson <[email protected]>
  1 sibling, 1 reply; 9+ messages in thread

From: Laurenz Albe @ 2025-05-30 05:45 UTC (permalink / raw)
  To: Ron Johnson <[email protected]>; pgsql-admin

On Thu, 2025-05-29 at 20:51 -0400, Ron Johnson wrote:
> Honestly, who cares if start and stop times are in the dump file?  stderr is where a DBA wants to see timings.

I guess everybody has different preferences.
These days, few DBAs stare at the screen, waiting for a report on the console
when the job is done.

Yours,
Laurenz Albe





^ permalink  raw  reply  [nested|flat] 9+ messages in thread

* Re: pg_dump verbose start and stop times?
  2025-05-29 20:37 pg_dump verbose start and stop times? Ron Johnson <[email protected]>
  2025-05-29 20:42 ` Re: pg_dump verbose start and stop times? David G. Johnston <[email protected]>
  2025-05-30 00:51   ` Re: pg_dump verbose start and stop times? Ron Johnson <[email protected]>
  2025-05-30 05:45     ` Re: pg_dump verbose start and stop times? Laurenz Albe <[email protected]>
@ 2025-05-30 12:39       ` Ron Johnson <[email protected]>
  0 siblings, 0 replies; 9+ messages in thread

From: Ron Johnson @ 2025-05-30 12:39 UTC (permalink / raw)
  To: Pgsql-admin <[email protected]>

On Fri, May 30, 2025 at 1:45 AM Laurenz Albe <[email protected]>
wrote:

> On Thu, 2025-05-29 at 20:51 -0400, Ron Johnson wrote:
> > Honestly, who cares if start and stop times are in the dump file?
> stderr is where a DBA wants to see timings.
>
> I guess everybody has different preferences.
> These days, few DBAs stare at the screen, waiting for a report on the
> console
> when the job is done.
>

Unix has had stderr redirection for 35(?) years. Mailing lists are for
small reproducers, not for 2MB of output from "real" backups.

-- 
Death to <Redacted>, and butter sauce.
Don't boil me, I'm still alive.
<Redacted> lobster!


^ permalink  raw  reply  [nested|flat] 9+ messages in thread

* Re: pg_dump verbose start and stop times?
  2025-05-29 20:37 pg_dump verbose start and stop times? Ron Johnson <[email protected]>
  2025-05-29 20:42 ` Re: pg_dump verbose start and stop times? David G. Johnston <[email protected]>
  2025-05-30 00:51   ` Re: pg_dump verbose start and stop times? Ron Johnson <[email protected]>
@ 2025-05-30 10:09     ` hubert depesz lubaczewski <[email protected]>
  2025-05-30 12:54       ` Re: pg_dump verbose start and stop times? Ron Johnson <[email protected]>
  1 sibling, 1 reply; 9+ messages in thread

From: hubert depesz lubaczewski @ 2025-05-30 10:09 UTC (permalink / raw)
  To: Ron Johnson <[email protected]>; +Cc: pgsql-admin

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






^ permalink  raw  reply  [nested|flat] 9+ messages in thread

* Re: pg_dump verbose start and stop times?
  2025-05-29 20:37 pg_dump verbose start and stop times? Ron Johnson <[email protected]>
  2025-05-29 20:42 ` Re: pg_dump verbose start and stop times? David G. Johnston <[email protected]>
  2025-05-30 00:51   ` Re: pg_dump verbose start and stop times? Ron Johnson <[email protected]>
  2025-05-30 10:09     ` Re: pg_dump verbose start and stop times? hubert depesz lubaczewski <[email protected]>
@ 2025-05-30 12:54       ` Ron Johnson <[email protected]>
  2025-05-30 13:48         ` Re: pg_dump verbose start and stop times? hubert depesz lubaczewski <[email protected]>
  0 siblings, 1 reply; 9+ messages in thread

From: Ron Johnson @ 2025-05-30 12:54 UTC (permalink / raw)
  To: Pgsql-admin <[email protected]>

On Fri, May 30, 2025 at 6:09 AM hubert depesz lubaczewski <[email protected]>
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
}

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!


^ permalink  raw  reply  [nested|flat] 9+ messages in thread

* Re: pg_dump verbose start and stop times?
  2025-05-29 20:37 pg_dump verbose start and stop times? Ron Johnson <[email protected]>
  2025-05-29 20:42 ` Re: pg_dump verbose start and stop times? David G. Johnston <[email protected]>
  2025-05-30 00:51   ` Re: pg_dump verbose start and stop times? Ron Johnson <[email protected]>
  2025-05-30 10:09     ` Re: pg_dump verbose start and stop times? hubert depesz lubaczewski <[email protected]>
  2025-05-30 12:54       ` Re: pg_dump verbose start and stop times? Ron Johnson <[email protected]>
@ 2025-05-30 13:48         ` hubert depesz lubaczewski <[email protected]>
  2025-05-30 15:02           ` Re: pg_dump verbose start and stop times? Ron Johnson <[email protected]>
  0 siblings, 1 reply; 9+ messages in thread

From: hubert depesz lubaczewski @ 2025-05-30 13:48 UTC (permalink / raw)
  To: Ron Johnson <[email protected]>; +Cc: Pgsql-admin <[email protected]>

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?

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 +… ?

Best regards,

depesz






^ permalink  raw  reply  [nested|flat] 9+ messages in thread

* Re: pg_dump verbose start and stop times?
  2025-05-29 20:37 pg_dump verbose start and stop times? Ron Johnson <[email protected]>
  2025-05-29 20:42 ` Re: pg_dump verbose start and stop times? David G. Johnston <[email protected]>
  2025-05-30 00:51   ` Re: pg_dump verbose start and stop times? Ron Johnson <[email protected]>
  2025-05-30 10:09     ` Re: pg_dump verbose start and stop times? hubert depesz lubaczewski <[email protected]>
  2025-05-30 12:54       ` Re: pg_dump verbose start and stop times? Ron Johnson <[email protected]>
  2025-05-30 13:48         ` Re: pg_dump verbose start and stop times? hubert depesz lubaczewski <[email protected]>
@ 2025-05-30 15:02           ` Ron Johnson <[email protected]>
  0 siblings, 0 replies; 9+ messages in thread

From: Ron Johnson @ 2025-05-30 15:02 UTC (permalink / raw)
  To: Pgsql-admin <[email protected]>

On Fri, May 30, 2025 at 9:48 AM hubert depesz lubaczewski <[email protected]>
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!


^ permalink  raw  reply  [nested|flat] 9+ messages in thread


end of thread, other threads:[~2025-05-30 15:02 UTC | newest]

Thread overview: 9+ messages (download: mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2025-05-29 20:37 pg_dump verbose start and stop times? Ron Johnson <[email protected]>
2025-05-29 20:42 ` David G. Johnston <[email protected]>
2025-05-30 00:51   ` Ron Johnson <[email protected]>
2025-05-30 05:45     ` Laurenz Albe <[email protected]>
2025-05-30 12:39       ` Ron Johnson <[email protected]>
2025-05-30 10:09     ` hubert depesz lubaczewski <[email protected]>
2025-05-30 12:54       ` Ron Johnson <[email protected]>
2025-05-30 13:48         ` hubert depesz lubaczewski <[email protected]>
2025-05-30 15:02           ` Ron Johnson <[email protected]>

This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox