Thread: 9.2 pg_upgrade regression tests on WIndows
The attached very small patch allows pg_upgrade's "make check" to succeed on REL9_2_STABLE on my Mingw system. However, I consider the issue I mentioned earlier regarding use of forward slashes in the argument to rmdir to be a significant blocker, so I'm going to go and fix that and then pull this all together. cheers andrew
Attachment
Andrew Dunstan <andrew@dunslane.net> writes:
> The attached very small patch allows pg_upgrade's "make check" to
> succeed on REL9_2_STABLE on my Mingw system.
> However, I consider the issue I mentioned earlier regarding use of
> forward slashes in the argument to rmdir to be a significant blocker, so
> I'm going to go and fix that and then pull this all together.
My intentions over the next hour or two are to commit the
unix-socket-directory fix and then sync 9.2 pg_upgrade with HEAD
(ie, back-patch everything that's in HEAD except the int64-XLogRecPtr
changes). Will that cause any problems for what you're doing?
regards, tom lane
On 09/03/2012 12:58 PM, Tom Lane wrote: > Andrew Dunstan <andrew@dunslane.net> writes: >> The attached very small patch allows pg_upgrade's "make check" to >> succeed on REL9_2_STABLE on my Mingw system. >> However, I consider the issue I mentioned earlier regarding use of >> forward slashes in the argument to rmdir to be a significant blocker, so >> I'm going to go and fix that and then pull this all together. > My intentions over the next hour or two are to commit the > unix-socket-directory fix and then sync 9.2 pg_upgrade with HEAD > (ie, back-patch everything that's in HEAD except the int64-XLogRecPtr > changes). Will that cause any problems for what you're doing? > > No, go for it. I can sync up without difficulty. Does that include backpatching the exec_prog changes to 9.2? cheers andrew
Andrew Dunstan <andrew@dunslane.net> writes:
> On 09/03/2012 12:58 PM, Tom Lane wrote:
>> My intentions over the next hour or two are to commit the
>> unix-socket-directory fix and then sync 9.2 pg_upgrade with HEAD
>> (ie, back-patch everything that's in HEAD except the int64-XLogRecPtr
>> changes). Will that cause any problems for what you're doing?
> No, go for it. I can sync up without difficulty. Does that include
> backpatching the exec_prog changes to 9.2?
Yes, nobody objected, so I'll do that too.
regards, tom lane
I wrote:
> Andrew Dunstan <andrew@dunslane.net> writes:
>> No, go for it. I can sync up without difficulty. Does that include
>> backpatching the exec_prog changes to 9.2?
> Yes, nobody objected, so I'll do that too.
And done. Please apply the other open fixes to both HEAD and 9.2.
Should be easy at this point.
regards, tom lane
On Mon, Sep 3, 2012 at 12:44:09PM -0400, Andrew Dunstan wrote: > The attached very small patch allows pg_upgrade's "make check" to > succeed on REL9_2_STABLE on my Mingw system. > > However, I consider the issue I mentioned earlier regarding use of > forward slashes in the argument to rmdir to be a significant > blocker, so I'm going to go and fix that and then pull this all > together. > > cheers > > andrew > diff --git a/contrib/pg_upgrade/exec.c b/contrib/pg_upgrade/exec.c > index 6f993df..57ca1df 100644 > --- a/contrib/pg_upgrade/exec.c > +++ b/contrib/pg_upgrade/exec.c > @@ -91,10 +91,12 @@ exec_prog(bool throw_error, bool is_priv, const char *log_file, > else > retval = 0; > > +#ifndef WIN32 > if ((log = fopen_priv(log_file, "a+")) == NULL) > pg_log(PG_FATAL, "cannot write to log file %s\n", log_file); > fprintf(log, "\n\n"); > fclose(log); > +#endif > > return retval; > } I am confused by this fix. If pg_ctl was keeping that log file open, wouldn't the log write fail when pg_dump or psql was run later? I am trying to understand how a later commands would not also trigger an error. Is it a timing thing? If that is it, I would like to know and have that documented. -- Bruce Momjian <bruce@momjian.us> http://momjian.us EnterpriseDB http://enterprisedb.com + It's impossible for everything to be true. +
On 09/04/2012 09:47 AM, Bruce Momjian wrote: > On Mon, Sep 3, 2012 at 12:44:09PM -0400, Andrew Dunstan wrote: >> The attached very small patch allows pg_upgrade's "make check" to >> succeed on REL9_2_STABLE on my Mingw system. >> >> However, I consider the issue I mentioned earlier regarding use of >> forward slashes in the argument to rmdir to be a significant >> blocker, so I'm going to go and fix that and then pull this all >> together. >> >> cheers >> >> andrew >> diff --git a/contrib/pg_upgrade/exec.c b/contrib/pg_upgrade/exec.c >> index 6f993df..57ca1df 100644 >> --- a/contrib/pg_upgrade/exec.c >> +++ b/contrib/pg_upgrade/exec.c >> @@ -91,10 +91,12 @@ exec_prog(bool throw_error, bool is_priv, const char *log_file, >> else >> retval = 0; >> >> +#ifndef WIN32 >> if ((log = fopen_priv(log_file, "a+")) == NULL) >> pg_log(PG_FATAL, "cannot write to log file %s\n", log_file); >> fprintf(log, "\n\n"); >> fclose(log); >> +#endif >> >> return retval; >> } > I am confused by this fix. If pg_ctl was keeping that log file open, > wouldn't the log write fail when pg_dump or psql was run later? I am > trying to understand how a later commands would not also trigger an > error. Is it a timing thing? If that is it, I would like to know and > have that documented. Oh, hmm. I thought it was the postmaster holding the log, but now I see that we are giving it a different log file. Maybe it is a timing thing. I'll experiment and see if a sleep cures the problem. ... Nope, still getting this after a sleep(5): cannot write to log file pg_upgrade_server_start.log Failure, exiting ... [try some more] Nope, even in a loop lasting 60s I still got this. So I'm a bit confused too. Seeing if I can narrow it down using ProcMon ... cheers andrew
On Mon, Sep 3, 2012 at 12:44:09PM -0400, Andrew Dunstan wrote: > The attached very small patch allows pg_upgrade's "make check" to > succeed on REL9_2_STABLE on my Mingw system. > > However, I consider the issue I mentioned earlier regarding use of > forward slashes in the argument to rmdir to be a significant > blocker, so I'm going to go and fix that and then pull this all > together. > > cheers > > andrew > diff --git a/contrib/pg_upgrade/exec.c b/contrib/pg_upgrade/exec.c > index 6f993df..57ca1df 100644 > --- a/contrib/pg_upgrade/exec.c > +++ b/contrib/pg_upgrade/exec.c > @@ -91,10 +91,12 @@ exec_prog(bool throw_error, bool is_priv, const char *log_file, > else > retval = 0; > > +#ifndef WIN32 > if ((log = fopen_priv(log_file, "a+")) == NULL) > pg_log(PG_FATAL, "cannot write to log file %s\n", log_file); > fprintf(log, "\n\n"); > fclose(log); > +#endif > > return retval; > } OK, I worked with Andrew on this issue, and have applied the attached patch which explains what is happening in this case. Andrew's #ifndef WIN32 was the correct fix. I consider this issue closed. -- Bruce Momjian <bruce@momjian.us> http://momjian.us EnterpriseDB http://enterprisedb.com + It's impossible for everything to be true. +
Attachment
On 09/05/2012 12:02 AM, Bruce Momjian wrote: > On Mon, Sep 3, 2012 at 12:44:09PM -0400, Andrew Dunstan wrote: >> The attached very small patch allows pg_upgrade's "make check" to >> succeed on REL9_2_STABLE on my Mingw system. >> >> However, I consider the issue I mentioned earlier regarding use of >> forward slashes in the argument to rmdir to be a significant >> blocker, so I'm going to go and fix that and then pull this all >> together. >> >> cheers >> >> andrew >> diff --git a/contrib/pg_upgrade/exec.c b/contrib/pg_upgrade/exec.c >> index 6f993df..57ca1df 100644 >> --- a/contrib/pg_upgrade/exec.c >> +++ b/contrib/pg_upgrade/exec.c >> @@ -91,10 +91,12 @@ exec_prog(bool throw_error, bool is_priv, const char *log_file, >> else >> retval = 0; >> >> +#ifndef WIN32 >> if ((log = fopen_priv(log_file, "a+")) == NULL) >> pg_log(PG_FATAL, "cannot write to log file %s\n", log_file); >> fprintf(log, "\n\n"); >> fclose(log); >> +#endif >> >> return retval; >> } > OK, I worked with Andrew on this issue, and have applied the attached > patch which explains what is happening in this case. Andrew's #ifndef > WIN32 was the correct fix. I consider this issue closed. > It looks like we still have problems in this area :-( see <http://www.pgbuildfarm.org/cgi-bin/show_log.pl?nm=pitta&dt=2012-09-05%2023%3A05%3A16> Now it looks like somehow the fopen on the log file that isn't commented out is failing. But the identical code worked on the same machine on HEAD. SO this does rather look like a timing issue. Investigating ... cheers andrew
On Wed, Sep 5, 2012 at 09:07:05PM -0400, Andrew Dunstan wrote: > >OK, I worked with Andrew on this issue, and have applied the attached > >patch which explains what is happening in this case. Andrew's #ifndef > >WIN32 was the correct fix. I consider this issue closed. > > > > > It looks like we still have problems in this area :-( see <http://www.pgbuildfarm.org/cgi-bin/show_log.pl?nm=pitta&dt=2012-09-05%2023%3A05%3A16> > > Now it looks like somehow the fopen on the log file that isn't > commented out is failing. But the identical code worked on the same > machine on HEAD. SO this does rather look like a timing issue. > > Investigating ... Yes, that is very odd. It is also right after the code we just changed to use binary mode to split the pg_dumpall file, split_old_dump(). The code is doing pg_ctl -w stop, then starting a new postmaster with pg_ctl -w start. Looking at the pg_ctl.c code (that you wrote), what pg_ctl -w stop does is to wait for the postmaster.pid file to disappear, then it returns complete. I suppose it is possible that the pid file is getting removed, pg_ctl is returning done, but the pg_ctl binary is still running, holding open those log files. I guess the buildfarm is showing us the problems in pg_upgrade, as it should. I think you might be right that we need to add a sleep(1) at the end of stop_postmaster on Windows, and document it is to give the postmaster time to release its log files. -- Bruce Momjian <bruce@momjian.us> http://momjian.us EnterpriseDB http://enterprisedb.com + It's impossible for everything to be true. +
On 09/05/2012 09:42 PM, Bruce Momjian wrote: > On Wed, Sep 5, 2012 at 09:07:05PM -0400, Andrew Dunstan wrote: >>> OK, I worked with Andrew on this issue, and have applied the attached >>> patch which explains what is happening in this case. Andrew's #ifndef >>> WIN32 was the correct fix. I consider this issue closed. >>> >> >> It looks like we still have problems in this area :-( see <http://www.pgbuildfarm.org/cgi-bin/show_log.pl?nm=pitta&dt=2012-09-05%2023%3A05%3A16> >> >> Now it looks like somehow the fopen on the log file that isn't >> commented out is failing. But the identical code worked on the same >> machine on HEAD. SO this does rather look like a timing issue. >> >> Investigating ... > Yes, that is very odd. It is also right after the code we just changed > to use binary mode to split the pg_dumpall file, split_old_dump(). > > The code is doing pg_ctl -w stop, then starting a new postmaster with > pg_ctl -w start. Looking at the pg_ctl.c code (that you wrote), what > pg_ctl -w stop does is to wait for the postmaster.pid file to disappear, > then it returns complete. I suppose it is possible that the pid file is > getting removed, pg_ctl is returning done, but the pg_ctl binary is > still running, holding open those log files. > > I guess the buildfarm is showing us the problems in pg_upgrade, as it > should. I think you might be right that we need to add a sleep(1) at > the end of stop_postmaster on Windows, and document it is to give the > postmaster time to release its log files. Icky. I wish there were some nice portable flock() mechanism we could use. I just re-ran the test on the same machine, same code, same everything as the reporte3d failure, and it passed, so it definitely looks like it's a timing issue. I'd be inclined to put a loop around that fopen() to try it once every second for, say, 5 seconds. cheers andrew
On Wed, Sep 5, 2012 at 10:04:07PM -0400, Andrew Dunstan wrote: > > On 09/05/2012 09:42 PM, Bruce Momjian wrote: > >On Wed, Sep 5, 2012 at 09:07:05PM -0400, Andrew Dunstan wrote: > >>>OK, I worked with Andrew on this issue, and have applied the attached > >>>patch which explains what is happening in this case. Andrew's #ifndef > >>>WIN32 was the correct fix. I consider this issue closed. > >>> > >> > >>It looks like we still have problems in this area :-( see <http://www.pgbuildfarm.org/cgi-bin/show_log.pl?nm=pitta&dt=2012-09-05%2023%3A05%3A16> > >> > >>Now it looks like somehow the fopen on the log file that isn't > >>commented out is failing. But the identical code worked on the same > >>machine on HEAD. SO this does rather look like a timing issue. > >> > >>Investigating ... > >Yes, that is very odd. It is also right after the code we just changed > >to use binary mode to split the pg_dumpall file, split_old_dump(). > > > >The code is doing pg_ctl -w stop, then starting a new postmaster with > >pg_ctl -w start. Looking at the pg_ctl.c code (that you wrote), what > >pg_ctl -w stop does is to wait for the postmaster.pid file to disappear, > >then it returns complete. I suppose it is possible that the pid file is > >getting removed, pg_ctl is returning done, but the pg_ctl binary is > >still running, holding open those log files. > > > >I guess the buildfarm is showing us the problems in pg_upgrade, as it > >should. I think you might be right that we need to add a sleep(1) at > >the end of stop_postmaster on Windows, and document it is to give the > >postmaster time to release its log files. > > > > Icky. I wish there were some nice portable flock() mechanism we could use. > > I just re-ran the test on the same machine, same code, same > everything as the reporte3d failure, and it passed, so it definitely > looks like it's a timing issue. > > I'd be inclined to put a loop around that fopen() to try it once > every second for, say, 5 seconds. Yes, good idea. -- Bruce Momjian <bruce@momjian.us> http://momjian.us EnterpriseDB http://enterprisedb.com + It's impossible for everything to be true. +
On 09/05/2012 10:07 PM, Bruce Momjian wrote: > On Wed, Sep 5, 2012 at 10:04:07PM -0400, Andrew Dunstan wrote: >> On 09/05/2012 09:42 PM, Bruce Momjian wrote: >>> On Wed, Sep 5, 2012 at 09:07:05PM -0400, Andrew Dunstan wrote: >>>>> OK, I worked with Andrew on this issue, and have applied the attached >>>>> patch which explains what is happening in this case. Andrew's #ifndef >>>>> WIN32 was the correct fix. I consider this issue closed. >>>>> >>>> It looks like we still have problems in this area :-( see <http://www.pgbuildfarm.org/cgi-bin/show_log.pl?nm=pitta&dt=2012-09-05%2023%3A05%3A16> >>>> >>>> Now it looks like somehow the fopen on the log file that isn't >>>> commented out is failing. But the identical code worked on the same >>>> machine on HEAD. SO this does rather look like a timing issue. >>>> >>>> Investigating ... >>> Yes, that is very odd. It is also right after the code we just changed >>> to use binary mode to split the pg_dumpall file, split_old_dump(). >>> >>> The code is doing pg_ctl -w stop, then starting a new postmaster with >>> pg_ctl -w start. Looking at the pg_ctl.c code (that you wrote), what >>> pg_ctl -w stop does is to wait for the postmaster.pid file to disappear, >>> then it returns complete. I suppose it is possible that the pid file is >>> getting removed, pg_ctl is returning done, but the pg_ctl binary is >>> still running, holding open those log files. >>> >>> I guess the buildfarm is showing us the problems in pg_upgrade, as it >>> should. I think you might be right that we need to add a sleep(1) at >>> the end of stop_postmaster on Windows, and document it is to give the >>> postmaster time to release its log files. >> >> >> Icky. I wish there were some nice portable flock() mechanism we could use. >> >> I just re-ran the test on the same machine, same code, same >> everything as the reporte3d failure, and it passed, so it definitely >> looks like it's a timing issue. >> >> I'd be inclined to put a loop around that fopen() to try it once >> every second for, say, 5 seconds. > Yes, good idea. > Suggested patch attached. cheers andrew
Attachment
On Wed, Sep 5, 2012 at 10:35:26PM -0400, Andrew Dunstan wrote:
> >>Icky. I wish there were some nice portable flock() mechanism we could use.
> >>
> >>I just re-ran the test on the same machine, same code, same
> >>everything as the reporte3d failure, and it passed, so it definitely
> >>looks like it's a timing issue.
> >>
> >>I'd be inclined to put a loop around that fopen() to try it once
> >>every second for, say, 5 seconds.
> >Yes, good idea.
> >
>
> Suggested patch attached.
>
> cheers
>
> andrew
>
> diff --git a/contrib/pg_upgrade/exec.c b/contrib/pg_upgrade/exec.c
> index 99f5006..f84d857 100644
> --- a/contrib/pg_upgrade/exec.c
> +++ b/contrib/pg_upgrade/exec.c
> @@ -63,7 +63,25 @@ exec_prog(const char *log_file, const char *opt_log_file,
> if (written >= MAXCMDLEN)
> pg_log(PG_FATAL, "command too long\n");
>
> - if ((log = fopen_priv(log_file, "a")) == NULL)
> +#ifdef WIN32
> + {
> + /*
> + * Try to open the log file a few times in case the
> + * server takes a bit longer than we'd like to release it.
> + */
> + int iter;
> + for (iter = 0; iter < 5; iter++)
> + {
> + log = fopen_priv(log_file, "a");
> + if (log != NULL || iter == 4)
> + break;
> + sleep(1);
> + }
> + }
> +#else
> + log = fopen_priv(log_file, "a");
> +#endif
> + if (log == NULL)
> pg_log(PG_FATAL, "cannot write to log file %s\n", log_file);
> #ifdef WIN32
> fprintf(log, "\n\n");
I would like to see a more verbose comment, so we don't forget why we
did this. I think my inability to quickly discover the cause of the
previous log write problem is that I didn't document which file
descriptors are kept open on Windows. I suggest for a comment:
/* * "pg_ctl -w stop" might have reported that the server has * stopped because the postmaster.pid file has been
removed,* but "pg_ctl -w start" might still be in the process of * closing and might still be holding its stdout and -l
log* file descriptors open. Therefore, try to open the log * file a few times. */
Anyway, we can easily adjust the comment post-9.2.0.
-- Bruce Momjian <bruce@momjian.us> http://momjian.us EnterpriseDB
http://enterprisedb.com
+ It's impossible for everything to be true. +
On Wed, Sep 5, 2012 at 10:35:26PM -0400, Andrew Dunstan wrote:
> diff --git a/contrib/pg_upgrade/exec.c b/contrib/pg_upgrade/exec.c
> index 99f5006..f84d857 100644
> --- a/contrib/pg_upgrade/exec.c
> +++ b/contrib/pg_upgrade/exec.c
> @@ -63,7 +63,25 @@ exec_prog(const char *log_file, const char *opt_log_file,
> if (written >= MAXCMDLEN)
> pg_log(PG_FATAL, "command too long\n");
>
> - if ((log = fopen_priv(log_file, "a")) == NULL)
> +#ifdef WIN32
> + {
> + /*
> + * Try to open the log file a few times in case the
> + * server takes a bit longer than we'd like to release it.
> + */
> + int iter;
> + for (iter = 0; iter < 5; iter++)
> + {
> + log = fopen_priv(log_file, "a");
> + if (log != NULL || iter == 4)
> + break;
> + sleep(1);
> + }
> + }
> +#else
> + log = fopen_priv(log_file, "a");
> +#endif
> + if (log == NULL)
> pg_log(PG_FATAL, "cannot write to log file %s\n", log_file);
> #ifdef WIN32
> fprintf(log, "\n\n");
Oh, also, we normally put the ifndef WIN32 code first because that is
our most common platform. Also, is "|| iter == 4" necessary?
-- Bruce Momjian <bruce@momjian.us> http://momjian.us EnterpriseDB
http://enterprisedb.com
+ It's impossible for everything to be true. +
On 09/05/2012 10:41 PM, Bruce Momjian wrote: > > I would like to see a more verbose comment, so we don't forget why we > did this. I think my inability to quickly discover the cause of the > previous log write problem is that I didn't document which file > descriptors are kept open on Windows. I suggest for a comment: > > /* > * "pg_ctl -w stop" might have reported that the server has > * stopped because the postmaster.pid file has been removed, > * but "pg_ctl -w start" might still be in the process of > * closing and might still be holding its stdout and -l log > * file descriptors open. Therefore, try to open the log > * file a few times. > */ > > Anyway, we can easily adjust the comment post-9.2.0. Shall I apply the patch now? If so I'll include your comment. cheers andrew
On Wed, Sep 5, 2012 at 10:46:17PM -0400, Andrew Dunstan wrote: > > On 09/05/2012 10:41 PM, Bruce Momjian wrote: > > > >I would like to see a more verbose comment, so we don't forget why we > >did this. I think my inability to quickly discover the cause of the > >previous log write problem is that I didn't document which file > >descriptors are kept open on Windows. I suggest for a comment: > > > > /* > > * "pg_ctl -w stop" might have reported that the server has > > * stopped because the postmaster.pid file has been removed, > > * but "pg_ctl -w start" might still be in the process of > > * closing and might still be holding its stdout and -l log > > * file descriptors open. Therefore, try to open the log > > * file a few times. > > */ > > > >Anyway, we can easily adjust the comment post-9.2.0. > > > Shall I apply the patch now? If so I'll include your comment. Well, seems it is a crash bug. Apply so we can get some buildfarm testing overnight. -- Bruce Momjian <bruce@momjian.us> http://momjian.us EnterpriseDB http://enterprisedb.com + It's impossible for everything to be true. +