Re: add timing information to pg_upgrade

On Sat, Jul 29, 2023 at 12:17 AM Nathan Bossart
<nathandbossart@gmail.com> wrote:
>
> On Fri, Jul 28, 2023 at 10:38:14AM -0700, Nathan Bossart wrote:
> > I'm okay with simply adding the time.  However, I wonder if we want to
> > switch to seconds, minutes, hours, etc. if the step takes longer.  This
> > would add a bit of complexity, but it would improve human readability.
> > Alternatively, we could keep the code simple and machine readable by always
> > using milliseconds.
>
> ... or maybe we show both like psql does.  Attached іs a new version of the
> patch in which I've made use of the INSTR_TIME_* macros and enhanced the
> output formatting (largely borrowed from PrintTiming() in
> src/bin/psql/common.c).

The v2 patch LGTM. I tested it with an upgrade of the 22GB database,
the output is here [1].

While on this, I noticed a thing unrelated to your patch that there's
no space between the longest status message of size 60 bytes and ok -
'Checking for incompatible "aclitem" data type in user tablesok
23.932 ms'. I think MESSAGE_WIDTH needs to be bumped up - 64 or more.

[1]
Performing Consistency Checks
-----------------------------
Checking cluster versions                                   ok  0.000 ms
Checking database user is the install user                  ok  1.767 ms
Checking database connection settings                       ok  2.210 ms
Checking for prepared transactions                          ok  1.411 ms
Checking for system-defined composite types in user tables  ok  29.471 ms
Checking for reg* data types in user tables                 ok  26.251 ms
Checking for contrib/isn with bigint-passing mismatch       ok  0.000 ms
Checking for incompatible "aclitem" data type in user tablesok  23.932 ms
Checking for user-defined encoding conversions              ok  8.350 ms
Checking for user-defined postfix operators                 ok  8.229 ms
Checking for incompatible polymorphic functions             ok  15.271 ms
Checking for tables WITH OIDS                               ok  6.120 ms
Checking for invalid "sql_identifier" user columns          ok  24.509 ms
Creating dump of global objects                             ok  14.007 ms
Creating dump of database schemas
                                                            ok  176.690 ms
Checking for presence of required libraries                 ok  0.011 ms
Checking database user is the install user                  ok  2.566 ms
Checking for prepared transactions                          ok  2.065 ms
Checking for new cluster tablespace directories             ok  0.000 ms

If pg_upgrade fails after this point, you must re-initdb the
new cluster before continuing.

Performing Upgrade
------------------
Setting locale and encoding for new cluster                 ok  3.014 ms
Analyzing all rows in the new cluster                       ok  373.270 ms
Freezing all rows in the new cluster                        ok  81.064 ms
Deleting files from new pg_xact                             ok  0.089 ms
Copying old pg_xact to new server                           ok  2.204 ms
Setting oldest XID for new cluster                          ok  38.314 ms
Setting next transaction ID and epoch for new cluster       ok  111.503 ms
Deleting files from new pg_multixact/offsets                ok  0.078 ms
Copying old pg_multixact/offsets to new server              ok  1.790 ms
Deleting files from new pg_multixact/members                ok  0.050 ms
Copying old pg_multixact/members to new server              ok  1.532 ms
Setting next multixact ID and offset for new cluster        ok  36.770 ms
Resetting WAL archives                                      ok  37.182 ms
Setting frozenxid and minmxid counters in new cluster       ok  47.879 ms
Restoring global objects in the new cluster                 ok  11.615 ms
Restoring database schemas in the new cluster
                                                            ok  141.839 ms
Copying user relation files
                                                            ok
151308.601 ms (02:31.309)
Setting next OID for new cluster                            ok  44.800 ms
Sync data directory to disk                                 ok
4461.213 ms (00:04.461)
Creating script to delete old cluster                       ok  0.059 ms
Checking for extension updates                              ok  66.899 ms

Upgrade Complete
----------------
Optimizer statistics are not transferred by pg_upgrade.
Once you start the new server, consider running:
    /home/ubuntu/postgres/HEAD/bin/vacuumdb --all --analyze-in-stages
Running this script will delete the old cluster's data files:
    ./delete_old_cluster.sh

real    2m38.133s
user    0m0.151s
sys     0m21.556s

--
Bharath Rupireddy
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com