Re: pg_upgrade --logfile option documentation

The documentation of the pg_upgrade -l/--logfile option never made much
sense to me:

-l, --logfile=FILENAME log session activity to file

I don't know what "session" means for pg_upgrade, so I never used it.

What it actually does is log the output of all the programs that
pg_upgrade calls internally, such as pg_ctl, psql, vacuumdb,
pg_resetxlog, to the specified file, which is quite useful for analyzing
errors such as

unable to connect to new postmaster started with the command: "/usr/lib/postgresql/9.1/bin/pg_ctl" -w -l "/dev/null" -D "/var/lib/postgresql/9.1/main" -o "-p 5433 -b" start >> "/dev/null" 2>&1

where -l would have put something in the place of /dev/null.

So what might be a better wording for this option? Something like "log
output of internally called programs to file"?

On Sun, Feb 19, 2012 at 6:13 AM, Peter Eisentraut <peter_e(at)gmx(dot)net> wrote:
> The documentation of the pg_upgrade -l/--logfile option never made much
> sense to me:
>
>  -l, --logfile=FILENAME        log session activity to file
>
> I don't know what "session" means for pg_upgrade, so I never used it.
>
> What it actually does is log the output of all the programs that
> pg_upgrade calls internally, such as pg_ctl, psql, vacuumdb,
> pg_resetxlog, to the specified file, which is quite useful for analyzing
> errors such as
>
> unable to connect to new postmaster started with the command: "/usr/lib/postgresql/9.1/bin/pg_ctl" -w -l "/dev/null" -D "/var/lib/postgresql/9.1/main" -o "-p 5433 -b" start >> "/dev/null" 2>&1
>
> where -l would have put something in the place of /dev/null.
>
> So what might be a better wording for this option?  Something like "log
> output of internally called programs to file"?

I don't think we should be that specific, because we might someday
want pg_upgrade itself to write messages to that file as well, even if
it doesn't today. I agree that the phrase "session activity" is a bit
misleading.

As a more general comment, I think that the way pg_upgrade does
logging right now is absolutely terrible. IME, it is utterly
impossible to understand what has gone wrong with pg_upgrade without
looking at the log file. And by default, no log file is created. So
typically what happens is:

- I run pg_upgrade. It fails.
- I rename the control file from the old cluster back to its original name.
- I rerun pg_upgrade, this time with -l. It fails again.
- I read the log file, figure out what the problem is, and correct it.
- I rename the control file from the old cluster back to its original
name, again.
- I run pg_upgrade a third time.
- On a good day, it works, else go to step 5.

One pretty obvious improvement would be: if pg_upgrade fails after
renaming the control file for the old cluster out of the way - say,
while loading the schema dump into the new cluster - have it RENAME
THE OLD CONTROL FILE BACK before exiting. But I also think the
logging needs improvement. Right now, we studiously redirect both
stdout and stderr to /dev/null; maybe it would be better to redirect
stdout to /dev/null and NOT redirect stderr. If that generates too
much chatter in non-failure cases, then let's adjust the output of the
commands pg_upgrade is invoking until it doesn't. The actual cause of
the failure, rather than pg_upgrade's fairly-useless gloss on it,
ought to be visible right away, at least IMHO.

--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

On Sun, Feb 19, 2012 at 01:13:10PM +0200, Peter Eisentraut wrote:
> The documentation of the pg_upgrade -l/--logfile option never made much
> sense to me:
>
> -l, --logfile=FILENAME log session activity to file
>
> I don't know what "session" means for pg_upgrade, so I never used it.
>
> What it actually does is log the output of all the programs that
> pg_upgrade calls internally, such as pg_ctl, psql, vacuumdb,
> pg_resetxlog, to the specified file, which is quite useful for analyzing
> errors such as
>
> unable to connect to new postmaster started with the command: "/usr/lib/postgresql/9.1/bin/pg_ctl" -w -l "/dev/null" -D "/var/lib/postgresql/9.1/main" -o "-p 5433 -b" start >> "/dev/null" 2>&1
>
> where -l would have put something in the place of /dev/null.
>
> So what might be a better wording for this option? Something like "log
> output of internally called programs to file"?

How about?

-l, --logfile=FILENAME log internal activity to file

--
Bruce Momjian <bruce(at)momjian(dot)us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ It's impossible for everything to be true. +

On Sun, Feb 19, 2012 at 01:24:34PM -0500, Robert Haas wrote:
> As a more general comment, I think that the way pg_upgrade does
> logging right now is absolutely terrible. IME, it is utterly
> impossible to understand what has gone wrong with pg_upgrade without
> looking at the log file. And by default, no log file is created. So
> typically what happens is:
>
> - I run pg_upgrade. It fails.
> - I rename the control file from the old cluster back to its original name.
> - I rerun pg_upgrade, this time with -l. It fails again.
> - I read the log file, figure out what the problem is, and correct it.
> - I rename the control file from the old cluster back to its original
> name, again.
> - I run pg_upgrade a third time.
> - On a good day, it works, else go to step 5.
>
> One pretty obvious improvement would be: if pg_upgrade fails after
> renaming the control file for the old cluster out of the way - say,
> while loading the schema dump into the new cluster - have it RENAME
> THE OLD CONTROL FILE BACK before exiting. But I also think the

The behavior you are seeing now is the paranoia inherent in pg_upgrade's
design. Now that pg_upgrade is being used more, perhaps that needs to
be relaxed.

However, remember we rename that control file to prevent the old cluster
from being run accidentally, which is particular important in link mode.
There might be some error cases that still would not restore the
location of that file if we have a revert behavior on error. A more
normal behavior would be for pg_upgrade to rename the control file only
when the upgrade completes successfully.

> logging needs improvement. Right now, we studiously redirect both
> stdout and stderr to /dev/null; maybe it would be better to redirect
> stdout to /dev/null and NOT redirect stderr. If that generates too
> much chatter in non-failure cases, then let's adjust the output of the
> commands pg_upgrade is invoking until it doesn't. The actual cause of
> the failure, rather than pg_upgrade's fairly-useless gloss on it,
> ought to be visible right away, at least IMHO.

Well, we have a -d option for debug; we could modify that to have debug
levels. Also, from the command line, it is difficult to have multiple
process write into a single file, so that isn't going work to have
pg_upgrade and the server logging to the same file on Windows.

--
Bruce Momjian <bruce(at)momjian(dot)us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ It's impossible for everything to be true. +

Excerpts from Bruce Momjian's message of mié feb 22 17:01:10 -0300 2012:
> On Sun, Feb 19, 2012 at 01:24:34PM -0500, Robert Haas wrote:

> > One pretty obvious improvement would be: if pg_upgrade fails after
> > renaming the control file for the old cluster out of the way - say,
> > while loading the schema dump into the new cluster - have it RENAME
> > THE OLD CONTROL FILE BACK before exiting. But I also think the
>
> The behavior you are seeing now is the paranoia inherent in pg_upgrade's
> design. Now that pg_upgrade is being used more, perhaps that needs to
> be relaxed.
>
> However, remember we rename that control file to prevent the old cluster
> from being run accidentally, which is particular important in link mode.

... but if the upgrade failed, clearly this shouldn't be a problem. I
agree with Robert, and was bit by this last week -- in case of any error
during the procedure, the control file should be renamed back to its
original name.

> There might be some error cases that still would not restore the
> location of that file if we have a revert behavior on error. A more
> normal behavior would be for pg_upgrade to rename the control file only
> when the upgrade completes successfully.

Not sure about this. If the upgrades completes successfully and the
file is not renamed at the last minute due to some error, that would be
a problem as well, because now the old cluster would happily run and
perhaps corrupt the data files from under the new cluster.

--
Álvaro Herrera <alvherre(at)commandprompt(dot)com>
The PostgreSQL Company - Command Prompt, Inc.
PostgreSQL Replication, Consulting, Custom Development, 24x7 support

On Wed, Feb 22, 2012 at 05:22:29PM -0300, Alvaro Herrera wrote:
>
> Excerpts from Bruce Momjian's message of mié feb 22 17:01:10 -0300 2012:
> > On Sun, Feb 19, 2012 at 01:24:34PM -0500, Robert Haas wrote:
>
> > > One pretty obvious improvement would be: if pg_upgrade fails after
> > > renaming the control file for the old cluster out of the way - say,
> > > while loading the schema dump into the new cluster - have it RENAME
> > > THE OLD CONTROL FILE BACK before exiting. But I also think the
> >
> > The behavior you are seeing now is the paranoia inherent in pg_upgrade's
> > design. Now that pg_upgrade is being used more, perhaps that needs to
> > be relaxed.
> >
> > However, remember we rename that control file to prevent the old cluster
> > from being run accidentally, which is particular important in link mode.
>
> ... but if the upgrade failed, clearly this shouldn't be a problem. I
> agree with Robert, and was bit by this last week -- in case of any error
> during the procedure, the control file should be renamed back to its
> original name.
>
> > There might be some error cases that still would not restore the
> > location of that file if we have a revert behavior on error. A more
> > normal behavior would be for pg_upgrade to rename the control file only
> > when the upgrade completes successfully.
>
> Not sure about this. If the upgrades completes successfully and the
> file is not renamed at the last minute due to some error, that would be
> a problem as well, because now the old cluster would happily run and
> perhaps corrupt the data files from under the new cluster.

Well, the basic problem is that the user, before pg_upgrade started,
installed a new cluster that works. If we rename the old control, but
rename it back on failure, there are cases we will miss, kill like -9 or
a server crash, and it will not be obvious to them that the control file
was renamed.

Of course, if we only rename on success, and there is kill -9 or server
crash, the old cluster is still start-able, like the new one.

One good argument for the rename early is that on a server crash, the
system is probably going to restart the database automatically, and that
means the old server.

Right now we have a clear message that they need to rename the control
file to start the old server. Not sure what the new wording would look
like --- let me try.

--
Bruce Momjian <bruce(at)momjian(dot)us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ It's impossible for everything to be true. +

On ons, 2012-02-22 at 14:38 -0500, Bruce Momjian wrote:
> How about?
>
> -l, --logfile=FILENAME log internal activity to file

That sounds better.

On sön, 2012-02-19 at 13:24 -0500, Robert Haas wrote:
> But I also think the
> logging needs improvement. Right now, we studiously redirect both
> stdout and stderr to /dev/null; maybe it would be better to redirect
> stdout to /dev/null and NOT redirect stderr. If that generates too
> much chatter in non-failure cases, then let's adjust the output of the
> commands pg_upgrade is invoking until it doesn't.

That should be achievable for calls to psql and vacuumdb, say, but what
would you do with the server logs?

On Wed, Feb 22, 2012 at 3:51 PM, Peter Eisentraut <peter_e(at)gmx(dot)net> wrote:
> On sön, 2012-02-19 at 13:24 -0500, Robert Haas wrote:
>> But I also think the
>> logging needs improvement.  Right now, we studiously redirect both
>> stdout and stderr to /dev/null; maybe it would be better to redirect
>> stdout to /dev/null and NOT redirect stderr.  If that generates too
>> much chatter in non-failure cases, then let's adjust the output of the
>> commands pg_upgrade is invoking until it doesn't.
>
> That should be achievable for calls to psql and vacuumdb, say, but what
> would you do with the server logs?

I don't know. It might be less of an issue, though. I mean, IME,
what typically happens is that psql fails to restore the dump, either
because it can't connect to the new database or because it's confused
by some stupid case that isn't handled well. So even if we could just
improve the error handling to report those types of failures more
transparently, I think it would be a big improvement.

--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

On Wed, Feb 22, 2012 at 05:49:26PM -0500, Robert Haas wrote:
> On Wed, Feb 22, 2012 at 3:51 PM, Peter Eisentraut <peter_e(at)gmx(dot)net> wrote:
> > On sön, 2012-02-19 at 13:24 -0500, Robert Haas wrote:
> >> But I also think the
> >> logging needs improvement.  Right now, we studiously redirect both
> >> stdout and stderr to /dev/null; maybe it would be better to redirect
> >> stdout to /dev/null and NOT redirect stderr.  If that generates too
> >> much chatter in non-failure cases, then let's adjust the output of the
> >> commands pg_upgrade is invoking until it doesn't.
> >
> > That should be achievable for calls to psql and vacuumdb, say, but what
> > would you do with the server logs?
>
> I don't know. It might be less of an issue, though. I mean, IME,
> what typically happens is that psql fails to restore the dump, either
> because it can't connect to the new database or because it's confused
> by some stupid case that isn't handled well. So even if we could just
> improve the error handling to report those types of failures more
> transparently, I think it would be a big improvement.

Well, on Unix, it is easy to redirect the server logs to the same place
as the pg_upgrade logs. That doesn't help? How would we improve the
reporting of SQL restore failures?

--
Bruce Momjian <bruce(at)momjian(dot)us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ It's impossible for everything to be true. +

On Wed, Feb 22, 2012 at 10:50:07PM +0200, Peter Eisentraut wrote:
> On ons, 2012-02-22 at 14:38 -0500, Bruce Momjian wrote:
> > How about?
> >
> > -l, --logfile=FILENAME log internal activity to file
>
> That sounds better.

Done.

--
Bruce Momjian <bruce(at)momjian(dot)us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ It's impossible for everything to be true. +

On Wed, Feb 22, 2012 at 03:37:29PM -0500, Bruce Momjian wrote:
> On Wed, Feb 22, 2012 at 05:22:29PM -0300, Alvaro Herrera wrote:
> > Not sure about this. If the upgrades completes successfully and the
> > file is not renamed at the last minute due to some error, that would be
> > a problem as well, because now the old cluster would happily run and
> > perhaps corrupt the data files from under the new cluster.
>
> Well, the basic problem is that the user, before pg_upgrade started,
> installed a new cluster that works. If we rename the old control, but
> rename it back on failure, there are cases we will miss, kill like -9 or
> a server crash, and it will not be obvious to them that the control file
> was renamed.
>
> Of course, if we only rename on success, and there is kill -9 or server
> crash, the old cluster is still start-able, like the new one.
>
> One good argument for the rename early is that on a server crash, the
> system is probably going to restart the database automatically, and that
> means the old server.
>
> Right now we have a clear message that they need to rename the control
> file to start the old server. Not sure what the new wording would look
> like --- let me try.

I have thought about this, and feel that it would be odd to lock the old
cluster at the start of the upgrade, and then unlock it on a failure,
particularly because we can't always unlock it, e.g. operating system
crash.

A cleaner solution would be to lock it when we complete the upgrade,
which I have done in the attached patch. I have also added a warning
about restarting the old server when link mode is used, and updated the
documentation to match the new behavior.

Patch attached. I would like to apply this to 9.2/HEAD.

---------------------------------------------------------------------------

Performing Consistency Checks
-----------------------------
Checking current, bin, and data directories ok
Checking cluster versions ok
Checking database user is a superuser ok
Checking for prepared transactions ok
Checking for reg* system OID user data types ok
Checking for contrib/isn with bigint-passing mismatch ok
Creating catalog dump ok
Checking for prepared transactions ok
Checking for presence of required libraries ok

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

Performing Upgrade
------------------
Analyzing all rows in the new cluster ok
Freezing all rows on the new cluster ok
Deleting new commit clogs ok
Copying old commit clogs to new server ok
Setting next transaction ID for new cluster ok
Resetting WAL archives ok
Setting frozenxid counters in new cluster ok
Creating databases in the new cluster ok
Adding support functions to new cluster ok
Restoring database schema to new cluster ok
Removing support functions from new cluster ok
Linking user relation files
ok
Setting next OID for new cluster ok
Creating script to delete old cluster ok
Adding ".old" suffix to old global/pg_control ok

If you want to start the old cluster, you will need to remove
the ".old" suffix from /u/pgsql.old/data/global/pg_control.old.
Because "link" mode was used, the old cluster cannot be safely
started once the new cluster has been started.

Upgrade complete
----------------
Optimizer statistics are not transferred by pg_upgrade so
consider running:
vacuumdb --all --analyze-only
on the newly-upgraded cluster.

Running this script will delete the old cluster's data files:
/usr/local/pgdev/pg_upgrade/delete_old_cluster.sh

--
Bruce Momjian <bruce(at)momjian(dot)us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ It's impossible for everything to be true. +

On Tue, Feb 28, 2012 at 11:21 AM, Bruce Momjian <bruce(at)momjian(dot)us> wrote:
> On Wed, Feb 22, 2012 at 03:37:29PM -0500, Bruce Momjian wrote:
>> On Wed, Feb 22, 2012 at 05:22:29PM -0300, Alvaro Herrera wrote:
>> > Not sure about this.  If the upgrades completes successfully and the
>> > file is not renamed at the last minute due to some error, that would be
>> > a problem as well, because now the old cluster would happily run and
>> > perhaps corrupt the data files from under the new cluster.
>>
>> Well, the basic problem is that the user, before pg_upgrade started,
>> installed a new cluster that works.  If we rename the old control, but
>> rename it back on failure, there are cases we will miss, kill like -9 or
>> a server crash, and it will not be obvious to them that the control file
>> was renamed.
>>
>> Of course, if we only rename on success, and there is kill -9 or server
>> crash, the old cluster is still start-able, like the new one.
>>
>> One good argument for the rename early is that on a server crash, the
>> system is probably going to restart the database automatically, and that
>> means the old server.
>>
>> Right now we have a clear message that they need to rename the control
>> file to start the old server.  Not sure what the new wording would look
>> like --- let me try.
>
> I have thought about this, and feel that it would be odd to lock the old
> cluster at the start of the upgrade, and then unlock it on a failure,
> particularly because we can't always unlock it, e.g. operating system
> crash.
>
> A cleaner solution would be to lock it when we complete the upgrade,
> which I have done in the attached patch.  I have also added a warning
> about restarting the old server when link mode is used, and updated the
> documentation to match the new behavior.
>
> Patch attached.  I would like to apply this to 9.2/HEAD.
>
> ---------------------------------------------------------------------------
>
> Performing Consistency Checks
> -----------------------------
> Checking current, bin, and data directories                 ok
> Checking cluster versions                                   ok
> Checking database user is a superuser                       ok
> Checking for prepared transactions                          ok
> Checking for reg* system OID user data types                ok
> Checking for contrib/isn with bigint-passing mismatch       ok
> Creating catalog dump                                       ok
> Checking for prepared transactions                          ok
> Checking for presence of required libraries                 ok
>
> If pg_upgrade fails after this point, you must re-initdb the
> new cluster before continuing.
>
> Performing Upgrade
> ------------------
> Analyzing all rows in the new cluster                       ok
> Freezing all rows on the new cluster                        ok
> Deleting new commit clogs                                   ok
> Copying old commit clogs to new server                      ok
> Setting next transaction ID for new cluster                 ok
> Resetting WAL archives                                      ok
> Setting frozenxid counters in new cluster                   ok
> Creating databases in the new cluster                       ok
> Adding support functions to new cluster                     ok
> Restoring database schema to new cluster                    ok
> Removing support functions from new cluster                 ok
> Linking user relation files
>                                                            ok
> Setting next OID for new cluster                            ok
> Creating script to delete old cluster                       ok
> Adding ".old" suffix to old global/pg_control               ok
>
> If you want to start the old cluster, you will need to remove
> the ".old" suffix from /u/pgsql.old/data/global/pg_control.old.
> Because "link" mode was used, the old cluster cannot be safely
> started once the new cluster has been started.
>
> Upgrade complete
> ----------------
> Optimizer statistics are not transferred by pg_upgrade so
> consider running:
>    vacuumdb --all --analyze-only
> on the newly-upgraded cluster.
>
> Running this script will delete the old cluster's data files:
>    /usr/local/pgdev/pg_upgrade/delete_old_cluster.sh

I think you should rename the old control file just before the step
that says "linking user relation files". That's the point after which
it becomes unsafe to start the old cluster, right?

--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

Excerpts from Robert Haas's message of mar feb 28 15:24:45 -0300 2012:

> I think you should rename the old control file just before the step
> that says "linking user relation files". That's the point after which
> it becomes unsafe to start the old cluster, right?

Also, if it's not using link mode, what is the point in doing the rename
in the first place? I was using copy mode when I did my tests and yet
it got renamed (unless link mode is now the default, which I doubt?)

--
Álvaro Herrera <alvherre(at)commandprompt(dot)com>
The PostgreSQL Company - Command Prompt, Inc.
PostgreSQL Replication, Consulting, Custom Development, 24x7 support

On Tue, Feb 28, 2012 at 01:24:45PM -0500, Robert Haas wrote:
> > Running this script will delete the old cluster's data files:
> >    /usr/local/pgdev/pg_upgrade/delete_old_cluster.sh
>
> I think you should rename the old control file just before the step
> that says "linking user relation files". That's the point after which
> it becomes unsafe to start the old cluster, right?

Yes, it is true that that is the danger point, and also it is much less
likely to fail at that point --- it usually happens during the schema
creation. I would have to add some more conditional wording without
clearly stating if the old suffix is present.

--
Bruce Momjian <bruce(at)momjian(dot)us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ It's impossible for everything to be true. +

On Tue, Feb 28, 2012 at 03:48:03PM -0300, Alvaro Herrera wrote:
>
> Excerpts from Robert Haas's message of mar feb 28 15:24:45 -0300 2012:
>
> > I think you should rename the old control file just before the step
> > that says "linking user relation files". That's the point after which
> > it becomes unsafe to start the old cluster, right?
>
> Also, if it's not using link mode, what is the point in doing the rename
> in the first place? I was using copy mode when I did my tests and yet
> it got renamed (unless link mode is now the default, which I doubt?)

You are right that we lock unconditionally. We can certainly only lock
in link mode.

--
Bruce Momjian <bruce(at)momjian(dot)us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ It's impossible for everything to be true. +

On Tue, Feb 28, 2012 at 02:15:30PM -0500, Bruce Momjian wrote:
> On Tue, Feb 28, 2012 at 01:24:45PM -0500, Robert Haas wrote:
> > > Running this script will delete the old cluster's data files:
> > >    /usr/local/pgdev/pg_upgrade/delete_old_cluster.sh
> >
> > I think you should rename the old control file just before the step
> > that says "linking user relation files". That's the point after which
> > it becomes unsafe to start the old cluster, right?
>
> Yes, it is true that that is the danger point, and also it is much less
> likely to fail at that point --- it usually happens during the schema
> creation. I would have to add some more conditional wording without
> clearly stating if the old suffix is present.

OK, I have implemented both Roberts and Àlvaro's ideas in my patch.
I only add the .old suffix to pg_controldata when link mode is used, and
I now do it after the schema has been created (the most common failure
case for pg_upgrade), and just before we actually link files --- both
very good ideas.

Patch attached; new pg_upgrade output with link mode below.

---------------------------------------------------------------------------

Performing Consistency Checks
-----------------------------
Checking current, bin, and data directories ok
Checking cluster versions ok
Checking database user is a superuser ok
Checking for prepared transactions ok
Checking for reg* system OID user data types ok
Checking for contrib/isn with bigint-passing mismatch ok
Creating catalog dump ok
Checking for prepared transactions ok
Checking for presence of required libraries ok

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

Performing Upgrade
------------------
Analyzing all rows in the new cluster ok
Freezing all rows on the new cluster ok
Deleting new commit clogs ok
Copying old commit clogs to new server ok
Setting next transaction ID for new cluster ok
Resetting WAL archives ok
Setting frozenxid counters in new cluster ok
Creating databases in the new cluster ok
Adding support functions to new cluster ok
Restoring database schema to new cluster ok
Removing support functions from new cluster ok
Adding ".old" suffix to old global/pg_control ok

If you want to start the old cluster, you will need to remove
the ".old" suffix from /u/pgsql.old/data/global/pg_control.old.
Because "link" mode was used, the old cluster cannot be safely
started once the new cluster has been started.

Linking user relation files
ok
Setting next OID for new cluster ok
Creating script to delete old cluster ok

Upgrade complete
----------------
Optimizer statistics are not transferred by pg_upgrade so
consider running:
vacuumdb --all --analyze-only
on the newly-upgraded cluster.

Running this script will delete the old cluster's data files:
/usr/local/pgdev/pg_upgrade/delete_old_cluster.sh

--
Bruce Momjian <bruce(at)momjian(dot)us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ It's impossible for everything to be true. +

On Tue, Feb 28, 2012 at 9:45 PM, Bruce Momjian <bruce(at)momjian(dot)us> wrote:
> OK, I have implemented both Roberts and Àlvaro's ideas in my patch.
> I only add the .old suffix to pg_controldata when link mode is used, and
> I now do it after the schema has been created (the most common failure
> case for pg_upgrade), and just before we actually link files --- both
> very good ideas.

Thanks for working on this. I think this will be a significant
usability improvement.

Any ideas about improving the error reporting more generally, so that
when reloading the dump fails, the user can easily see what went
belly-up, even if they didn't use -l?

--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

On Wed, Feb 29, 2012 at 04:34:24PM -0500, Robert Haas wrote:
> On Tue, Feb 28, 2012 at 9:45 PM, Bruce Momjian <bruce(at)momjian(dot)us> wrote:
> > OK, I have implemented both Roberts and Àlvaro's ideas in my patch.
> > I only add the .old suffix to pg_controldata when link mode is used, and
> > I now do it after the schema has been created (the most common failure
> > case for pg_upgrade), and just before we actually link files --- both
> > very good ideas.
>
> Thanks for working on this. I think this will be a significant
> usability improvement.

Glad I got such good feedback and ideas.

> Any ideas about improving the error reporting more generally, so that
> when reloading the dump fails, the user can easily see what went
> belly-up, even if they didn't use -l?

The only idea I have is to write the psql log to a temporary file and
report the last X lines from the file in case of failure. Does that
help?

--
Bruce Momjian <bruce(at)momjian(dot)us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ It's impossible for everything to be true. +

On Feb 29, 2012, at 6:02 PM, Bruce Momjian wrote:

> On Wed, Feb 29, 2012 at 04:34:24PM -0500, Robert Haas wrote:
>> On Tue, Feb 28, 2012 at 9:45 PM, Bruce Momjian <bruce(at)momjian(dot)us> wrote:
>>> OK, I have implemented both Roberts and Àlvaro's ideas in my patch.
>>> I only add the .old suffix to pg_controldata when link mode is used, and
>>> I now do it after the schema has been created (the most common failure
>>> case for pg_upgrade), and just before we actually link files --- both
>>> very good ideas.
>>
>> Thanks for working on this. I think this will be a significant
>> usability improvement.
>
> Glad I got such good feedback and ideas.
>
>> Any ideas about improving the error reporting more generally, so that
>> when reloading the dump fails, the user can easily see what went
>> belly-up, even if they didn't use -l?
>
> The only idea I have is to write the psql log to a temporary file and
> report the last X lines from the file in case of failure. Does that
> help?
>

Perhaps pg_upgrade can print the path to the temp file containing the log and instruct the user to look there for more detail.

Cheers,
M

On Wed, Feb 29, 2012 at 06:22:27PM -0500, A.M. wrote:
>
> On Feb 29, 2012, at 6:02 PM, Bruce Momjian wrote:
>
> > On Wed, Feb 29, 2012 at 04:34:24PM -0500, Robert Haas wrote:
> >> On Tue, Feb 28, 2012 at 9:45 PM, Bruce Momjian <bruce(at)momjian(dot)us> wrote:
> >>> OK, I have implemented both Roberts and Àlvaro's ideas in my patch.
> >>> I only add the .old suffix to pg_controldata when link mode is used, and
> >>> I now do it after the schema has been created (the most common failure
> >>> case for pg_upgrade), and just before we actually link files --- both
> >>> very good ideas.
> >>
> >> Thanks for working on this. I think this will be a significant
> >> usability improvement.
> >
> > Glad I got such good feedback and ideas.
> >
> >> Any ideas about improving the error reporting more generally, so that
> >> when reloading the dump fails, the user can easily see what went
> >> belly-up, even if they didn't use -l?
> >
> > The only idea I have is to write the psql log to a temporary file and
> > report the last X lines from the file in case of failure. Does that
> > help?
> >
>
>
> Perhaps pg_upgrade can print the path to the temp file containing the
> log and instruct the user to look there for more detail.

Hey, that's a good idea. I would always write the pg_dump output to a
log file. If the dump succeeds, I remove the file, if not, I tell users
to read the log file for details about the failure --- good idea.

--
Bruce Momjian <bruce(at)momjian(dot)us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ It's impossible for everything to be true. +

On Wed, Feb 29, 2012 at 6:02 PM, Bruce Momjian <bruce(at)momjian(dot)us> wrote:
>> Any ideas about improving the error reporting more generally, so that
>> when reloading the dump fails, the user can easily see what went
>> belly-up, even if they didn't use -l?
>
> The only idea I have is to write the psql log to a temporary file and
> report the last X lines from the file in case of failure.  Does that
> help?

Why not just redirect stdout but not stderr? If there are error
messages, surely we want the user to just see those.

--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

On ons, 2012-02-29 at 22:47 -0500, Bruce Momjian wrote:
> Hey, that's a good idea. I would always write the pg_dump output to a
> log file. If the dump succeeds, I remove the file, if not, I tell
> users to read the log file for details about the failure --- good
> idea.

But we also need the server log output somewhere. So I think this temp
file would need to cover everything that -l covers.

On Thu, Mar 01, 2012 at 08:45:26AM -0500, Robert Haas wrote:
> On Wed, Feb 29, 2012 at 6:02 PM, Bruce Momjian <bruce(at)momjian(dot)us> wrote:
> >> Any ideas about improving the error reporting more generally, so that
> >> when reloading the dump fails, the user can easily see what went
> >> belly-up, even if they didn't use -l?
> >
> > The only idea I have is to write the psql log to a temporary file and
> > report the last X lines from the file in case of failure.  Does that
> > help?
>
> Why not just redirect stdout but not stderr? If there are error
> messages, surely we want the user to just see those.

Well, I think sending the error messages to the user but stdout to a
file will leave users confused because it will be unclear which SQL
statement generated the error.

--
Bruce Momjian <bruce(at)momjian(dot)us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ It's impossible for everything to be true. +

On Thu, Mar 01, 2012 at 10:17:04PM +0200, Peter Eisentraut wrote:
> On ons, 2012-02-29 at 22:47 -0500, Bruce Momjian wrote:
> > Hey, that's a good idea. I would always write the pg_dump output to a
> > log file. If the dump succeeds, I remove the file, if not, I tell
> > users to read the log file for details about the failure --- good
> > idea.
>
> But we also need the server log output somewhere. So I think this temp
> file would need to cover everything that -l covers.

OK, combining your and Robert's ideas, how about I have pg_upgrade write
the server log to a file, and the pg_dump output to a file (with its
stderr), and if pg_upgrade fails, I report the failure and mention those
files. If pg_upgrade succeeds, I remove the files? pg_upgrade already
creates temporary files that it removes on completion.

--
Bruce Momjian <bruce(at)momjian(dot)us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ It's impossible for everything to be true. +

On Tue, Feb 28, 2012 at 09:45:41PM -0500, Bruce Momjian wrote:
> On Tue, Feb 28, 2012 at 02:15:30PM -0500, Bruce Momjian wrote:
> > On Tue, Feb 28, 2012 at 01:24:45PM -0500, Robert Haas wrote:
> > > > Running this script will delete the old cluster's data files:
> > > >    /usr/local/pgdev/pg_upgrade/delete_old_cluster.sh
> > >
> > > I think you should rename the old control file just before the step
> > > that says "linking user relation files". That's the point after which
> > > it becomes unsafe to start the old cluster, right?
> >
> > Yes, it is true that that is the danger point, and also it is much less
> > likely to fail at that point --- it usually happens during the schema
> > creation. I would have to add some more conditional wording without
> > clearly stating if the old suffix is present.
>
> OK, I have implemented both Roberts and Àlvaro's ideas in my patch.
> I only add the .old suffix to pg_controldata when link mode is used, and
> I now do it after the schema has been created (the most common failure
> case for pg_upgrade), and just before we actually link files --- both
> very good ideas.
>
> Patch attached; new pg_upgrade output with link mode below.

Patch applied. I will now work on the change to keep the schema restore
and server logs around in case of a failure.

--
Bruce Momjian <bruce(at)momjian(dot)us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ It's impossible for everything to be true. +

On Thu, Mar 01, 2012 at 09:06:10PM -0500, Bruce Momjian wrote:
> OK, combining your and Robert's ideas, how about I have pg_upgrade write
> the server log to a file, and the pg_dump output to a file (with its
> stderr), and if pg_upgrade fails, I report the failure and mention those
> files. If pg_upgrade succeeds, I remove the files? pg_upgrade already
> creates temporary files that it removes on completion.

OK, I have completed a rework of pg_upgrade logging. pg_upgrade had 4
logging options, -g, -G, -l, and -v, and still it wasn't possible to get
useful logging. :-(

What I have done with this patch is to remove -g, -G, and -l, and
unconditionally write to 4 log files in the current directory (in
addition to the 3 SQL files I already create).

If pg_upgrade succeeds, the files are removed, but if it fails (or if
the new -r/retain option is used), the files remain. Here is a sample
failure when I create a plpgsql function in the old server, but truncate
plpgsql.so in the new server:

Performing Upgrade
------------------
Analyzing all rows in the new cluster ok
Freezing all rows on the new cluster ok
Deleting new commit clogs ok
Copying old commit clogs to new server ok
Setting next transaction ID for new cluster ok
Resetting WAL archives ok
Setting frozenxid counters in new cluster ok
Creating databases in the new cluster ok
Adding support functions to new cluster ok
Restoring database schema to new cluster
Consult the last few lines of "pg_upgrade_restore.log" for
the probable cause of the failure.
Failure, exiting

$ tail pg_upgrade_restore.log
COMMENT ON LANGUAGE plpythonu IS 'PL/PythonU untrusted procedural language';
COMMENT
SET search_path = public, pg_catalog;
SET
CREATE FUNCTION x() RETURNS integer
LANGUAGE plpgsql
AS $$begin
select pg_sleep(1);
end$$;
psql:/usr/local/pgdev/pg_upgrade/pg_upgrade_dump_db.sql:233:
ERROR: could not load library
"/usr/local/pgsql/lib/plpgsql.so":
/usr/local/pgsql/lib/plpgsql.so: file too short

That seems quite clear; I enabled --echo-queries in psql so you can see
the query that generated the error.

These changes should make pg_upgrade errors much easier to diagnose. I
hope to apply this for PG 9.2.

--
Bruce Momjian <bruce(at)momjian(dot)us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ It's impossible for everything to be true. +

On Mar 7, 2012, at 11:39 PM, Bruce Momjian wrote:

> On Thu, Mar 01, 2012 at 09:06:10PM -0500, Bruce Momjian wrote:
>> OK, combining your and Robert's ideas, how about I have pg_upgrade write
>> the server log to a file, and the pg_dump output to a file (with its
>> stderr), and if pg_upgrade fails, I report the failure and mention those
>> files. If pg_upgrade succeeds, I remove the files? pg_upgrade already
>> creates temporary files that it removes on completion.
>
> OK, I have completed a rework of pg_upgrade logging. pg_upgrade had 4
> logging options, -g, -G, -l, and -v, and still it wasn't possible to get
> useful logging. :-(
>
> What I have done with this patch is to remove -g, -G, and -l, and
> unconditionally write to 4 log files in the current directory (in
> addition to the 3 SQL files I already create).
>
> If pg_upgrade succeeds, the files are removed, but if it fails (or if
> the new -r/retain option is used), the files remain. Here is a sample
> failure when I create a plpgsql function in the old server, but truncate
> plpgsql.so in the new server:

It looks like the patch will overwrite the logs in the current working directory, for example, if pg_upgrade is run twice in the same place. Is that intentional? I had imagined that the logs would have been dumped in the /tmp directory so that one can compare results if the first pg_upgrade run had been errant.

Cheers,
M

On Thu, Mar 08, 2012 at 08:34:53AM -0500, A.M. wrote:
>
> On Mar 7, 2012, at 11:39 PM, Bruce Momjian wrote:
>
> > On Thu, Mar 01, 2012 at 09:06:10PM -0500, Bruce Momjian wrote:
> >> OK, combining your and Robert's ideas, how about I have pg_upgrade write
> >> the server log to a file, and the pg_dump output to a file (with its
> >> stderr), and if pg_upgrade fails, I report the failure and mention those
> >> files. If pg_upgrade succeeds, I remove the files? pg_upgrade already
> >> creates temporary files that it removes on completion.
> >
> > OK, I have completed a rework of pg_upgrade logging. pg_upgrade had 4
> > logging options, -g, -G, -l, and -v, and still it wasn't possible to get
> > useful logging. :-(
> >
> > What I have done with this patch is to remove -g, -G, and -l, and
> > unconditionally write to 4 log files in the current directory (in
> > addition to the 3 SQL files I already create).
> >
> > If pg_upgrade succeeds, the files are removed, but if it fails (or if
> > the new -r/retain option is used), the files remain. Here is a sample
> > failure when I create a plpgsql function in the old server, but truncate
> > plpgsql.so in the new server:
>
> It looks like the patch will overwrite the logs in the current working
> directory, for example, if pg_upgrade is run twice in the same place. Is
> that intentional? I had imagined that the logs would have been dumped in

Yes. I was afraid that continually appending to a log file on every run
would be too confusing. I could do only appends, or number the log
files, that those seemed confusing.

> the /tmp directory so that one can compare results if the first pg_upgrade
> run had been errant.

You would have to copy the file to a new name before re-running
pg_upgrade.

The only reason I truncate them on start is that I am appending to them
in many places in the code, and it was easier to just truncate them on
start rather than to remember where I first write to them.

--
Bruce Momjian <bruce(at)momjian(dot)us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ It's impossible for everything to be true. +

On Mar 8, 2012, at 10:00 AM, Bruce Momjian wrote:
>
> Yes. I was afraid that continually appending to a log file on every run
> would be too confusing. I could do only appends, or number the log
> files, that those seemed confusing.
>
>> the /tmp directory so that one can compare results if the first pg_upgrade
>> run had been errant.
>
> You would have to copy the file to a new name before re-running
> pg_upgrade.
>
> The only reason I truncate them on start is that I am appending to them
> in many places in the code, and it was easier to just truncate them on
> start rather than to remember where I first write to them.
>

mktemps?

Bruce Momjian <bruce(at)momjian(dot)us> writes:
> On Thu, Mar 08, 2012 at 08:34:53AM -0500, A.M. wrote:
>> It looks like the patch will overwrite the logs in the current working
>> directory, for example, if pg_upgrade is run twice in the same place. Is
>> that intentional? I had imagined that the logs would have been dumped in

> Yes. I was afraid that continually appending to a log file on every run
> would be too confusing. I could do only appends, or number the log
> files, that those seemed confusing.

Use one (set of) files, and always append, but at the beginning of each
run print "\npg_upgrade starting at [timestamp]\n\n". Should make it
reasonably clear, while not losing information.

regards, tom lane

On Thu, Mar 01, 2012 at 08:45:26AM -0500, Robert Haas wrote:
> On Wed, Feb 29, 2012 at 6:02 PM, Bruce Momjian <bruce(at)momjian(dot)us> wrote:
> >> Any ideas about improving the error reporting more generally, so that
> >> when reloading the dump fails, the user can easily see what went
> >> belly-up, even if they didn't use -l?
> >
> > The only idea I have is to write the psql log to a temporary file and
> > report the last X lines from the file in case of failure.  Does that
> > help?
>
> Why not just redirect stdout but not stderr? If there are error
> messages, surely we want the user to just see those.

See my patch; the problem with splitting stdout and stderr is that you
lose the correspondence between the SQL queries and the error messages.
With my patch, they will all be right next to each other at the end of
the log file.

--
Bruce Momjian <bruce(at)momjian(dot)us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ It's impossible for everything to be true. +

On tor, 2012-03-08 at 10:06 -0500, A.M. wrote:
> > The only reason I truncate them on start is that I am appending to
> them
> > in many places in the code, and it was easier to just truncate them
> on
> > start rather than to remember where I first write to them.
> >

> mktemps?

I don't want to see some tool unconditionally writing files (log or
otherwise) with unpredictable names. That would make it impossible to
clean up in a wrapper script.

On Mar 8, 2012, at 4:37 PM, Peter Eisentraut wrote:

> On tor, 2012-03-08 at 10:06 -0500, A.M. wrote:
>>> The only reason I truncate them on start is that I am appending to
>> them
>>> in many places in the code, and it was easier to just truncate them
>> on
>>> start rather than to remember where I first write to them.
>>>
>
>> mktemps?
>
> I don't want to see some tool unconditionally writing files (log or
> otherwise) with unpredictable names. That would make it impossible to
> clean up in a wrapper script.

The point of writing temp files to the /tmp/ directory is that they don't need to be cleaned up.

You really prefer having log files written to your current working directory? I don't know of any utility that pollutes the cwd like that- it seems like an easy way to forget where one left the log files.

Cheers,
M

On tor, 2012-03-08 at 16:44 -0500, A.M. wrote:
> The point of writing temp files to the /tmp/ directory is that they
> don't need to be cleaned up.

I don't think so. If everyone just left their junk lying around
in /tmp, it would fill up just like any other partition.

On Thu, Mar 08, 2012 at 10:19:05AM -0500, Tom Lane wrote:
> Bruce Momjian <bruce(at)momjian(dot)us> writes:
> > On Thu, Mar 08, 2012 at 08:34:53AM -0500, A.M. wrote:
> >> It looks like the patch will overwrite the logs in the current working
> >> directory, for example, if pg_upgrade is run twice in the same place. Is
> >> that intentional? I had imagined that the logs would have been dumped in
>
> > Yes. I was afraid that continually appending to a log file on every run
> > would be too confusing. I could do only appends, or number the log
> > files, that those seemed confusing.
>
> Use one (set of) files, and always append, but at the beginning of each
> run print "\npg_upgrade starting at [timestamp]\n\n". Should make it
> reasonably clear, while not losing information.

OK, it seems people do care about keeping log files from multiple runs
so I went with Tom's idea and have:

-----------------------------------------------------------------
pg_upgrade run on Thu Mar 8 19:30:12 2012
-----------------------------------------------------------------

Performing Consistency Checks
-----------------------------

Updated patch attached.

FYI, in retain mode, these are the files left in the current directory:

delete_old_cluster.sh
pg_upgrade_dump_all.sql
pg_upgrade_dump_db.sql
pg_upgrade_dump_globals.sql
pg_upgrade_internal.log
pg_upgrade_restore.log
pg_upgrade_server.log
pg_upgrade_utility.log

I will address the idea of using /tmp in another email.

--
Bruce Momjian <bruce(at)momjian(dot)us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ It's impossible for everything to be true. +

On Thu, Mar 08, 2012 at 11:59:59PM +0200, Peter Eisentraut wrote:
> On tor, 2012-03-08 at 16:44 -0500, A.M. wrote:
> > The point of writing temp files to the /tmp/ directory is that they
> > don't need to be cleaned up.
>
> I don't think so. If everyone just left their junk lying around
> in /tmp, it would fill up just like any other partition.

/tmp has a larger problem; see:

http://lwn.net/Articles/390323/

The only proper fix is to create a directory in /tmp and write into
there.

pg_upgrade has been writing into the current directory since it was
started, and no one has complained, and it leaves these files in the
current directory only if it fails, or --retain is used, so it will
clean up after itself. Actually, I think it originally write into the
user's home directory, but that caused problems.

--
Bruce Momjian <bruce(at)momjian(dot)us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ It's impossible for everything to be true. +

On Thu, Mar 08, 2012 at 08:33:48PM -0500, Bruce Momjian wrote:
> OK, it seems people do care about keeping log files from multiple runs
> so I went with Tom's idea and have:
>
> -----------------------------------------------------------------
> pg_upgrade run on Thu Mar 8 19:30:12 2012
> -----------------------------------------------------------------
>
> Performing Consistency Checks
> -----------------------------
>
> Updated patch attached.
>
> FYI, in retain mode, these are the files left in the current directory:
>
> delete_old_cluster.sh
> pg_upgrade_dump_all.sql
> pg_upgrade_dump_db.sql
> pg_upgrade_dump_globals.sql
> pg_upgrade_internal.log
> pg_upgrade_restore.log
> pg_upgrade_server.log
> pg_upgrade_utility.log
>
> I will address the idea of using /tmp in another email.

OK, attached pg_upgrade patch applied, with this list of improvements in
logging:

add ability to control permissions of created files
have psql echo its queries for easier debugging
output four separate log files, and delete them on success
add -r/--retain option to keep log files after success
make log files append-only
remove -g/-G/-l logging options
sugggest tailing appropriate log file on failure
enhance -v/--verbose behavior

Thanks for all the feedback.

--
Bruce Momjian <bruce(at)momjian(dot)us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ It's impossible for everything to be true. +