Re: PostgreSQL 9.2 beta1's pg_upgrade fails on Windows XP

Lists: pgsql-bugs
From: Edmund Horner <ejrh00(at)gmail(dot)com>
To: pgsql-bugs(at)postgresql(dot)org
Subject: PostgreSQL 9.2 beta1's pg_upgrade fails on Windows XP
Date: 2012-05-22 05:45:55
Message-ID: CAMyN-kD76ptQ8pMDGw7ci_fLPUx-Z03gAdALX8dTvTdQ7GurEA@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Lists: pgsql-bugs

(Sending this again to pgsql-bugs with no attachments; hopefully it'll
be accepted. Apologies for any duplicates! I'll provide the
attachments if you need them, though I suspect things may become clear
without them.)

Hello,

I'm forwarding this to pgsql-bugs after sending it to pgsql-testers.
I've been a bit confused about how to file it -- the release notes for
the 9.2 beta point to "More information on how to test and report
issues" here: http://www.postgresql.org/developer/beta/ which could
possibly use a bit more explanation. Between the beta not being a
normal release, and me not been an official tester, I opted to send it
there anyway since it wasn't a bug in an *existing* release. But
there is little traffic to pgsql-testers so I have sought advice on
IRC and been advised to send it here too. :-)

I'm not an official tester but I thought I would briefly experiment
with the beta. I run PostgreSQL as a normal user on Windows XP
at work, which may be an unusual (and increasingly obsolete) case not
covered as much by other
testers.

I ran into a bit of trouble running pg_upgrade to upgrade from my
9.1.3 cluster. This is the first time I have run pg_upgrade. It is
entirely possible I've done something wrong.

As a control, I was able to successfully "upgrade" the Postgresql
9.1.3 cluster into a second, new 9.1.3 cluster, using the 9.1.3
version of pg_upgrade. Similar command lines and no issues.

If this does look like a bug, I will help to resolve it (though I
might need some guidance). I have attached some basic information
below. Let me know if you need more information.

Regards,
Edmund.

Environment
Windows XP Service Pack 3
32-bit mode on Intel Core2 Duo
Data, binaries, and pg_upgrade working files are on an NTFS
partition with 4k cluster size.
User has a domain login and local admin rights.

Old cluster
Version: PostgreSQL 9.1.3
Binaries: C:\ehorner\pgsql
Data: C:\ehorner\pgdata
Locale: C
Encoding: UTF8

New cluster
Version: PostgreSQL 9.2 beta1
Binaries: C:\ehorner\pgsql92
Data: C:\ehorner\pgdata92
Locale: C
Encoding: UTF8

Sequence of steps

Unzip the PostgreSQL 9.2 demo1 binaries into c:\ehorner\pgsql92

Shut down the PostgreSQL 9.1.3 cluster (in c:\ehorner\pgsql\bin):

pg_ctl.exe stop -D c:\ehorner\pgsql

Create a new 9.2 cluster (in C:\ehorner\pgsql92\bin):

initdb.exe --no-locale -E UTF8 c:\ehorner\pgdata92

Run pg_upgrade (in C:\):

c:\ehorner\pgsql92\bin\pg_upgrade -b c:\ehorner\pgsql\bin -B
c:\ehorner\pgsql92\bin -d c:\ehorner\pgdata -D c:\ehorner\pgdata92

Expected output

A message indicating successful upgrade of the old cluster into the new one.

Actual output

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 The
process cannot access the file because it is being used by another
process.
*failure*

Consult the last few lines of "pg_upgrade_utility.log" for
the probable cause of the failure.
Failure, exiting
The process cannot access the file because it is being used by
another process.
*failure*
Consult the last few lines of "pg_upgrade_utility.log" for
the probable cause of the failure.

These files are also created (attached, except for
pg_upgrade_dump_all.sql which was 0 bytes):

pg_upgrade_dump_all.sql
pg_upgrade_internal.log
pg_upgrade_restore.log
pg_upgrade_server.log
pg_upgrade_utility.log

Running again with -v gives the output shown in output-verbose.txt.
The two lines "The process cannot access the file because it is being
used by another process." appear on stderr, which I piped along with
stdout into that file.

Finally, I have also run it using the "Filemon" program to monitor
file system calls. Filtering on pg_upgrade gets the result shown in
filemon-output.txt. There is some cruft from antivirus and other
bloatware which I have removed (since I shouldn't publicise the work
environment too much). The antivirus does
query the directory information of some of the files, but does not
appear to open them.

There are some SHARING VIOLATION errors on accessing
pg_upgrade_utility.log. My guess is that's what causes the error.
It's possible the antivirus is interfering with the file (since it
does touch it) but I do not think it explains the problem since the
9.1.3 -> 9.1.3 upgrade had no problems. I think it could be due to
the change in dump.c where this log file name is used as a pipe
destination in another exec'd program. Maybe Windows XP is more
sensitive to that than other OSs?

http://git.postgresql.org/gitweb/?p=postgresql.git;a=commitdiff;h=717f6d60859cc2d1d7dfd57520531a50bd78df9c

As mentioned in another message, I have also run pg_upgrade on Windows
7 64-bit. It was on a different database cluster though. On Windows
7, pg_upgrade did not appear to have a sharing violation and proceeded
to make a complete dump of the SQL. It later ran into trouble with an
oid conflict, but I think that's due to me messing around with the
cluster in question, and in any case is a separate issue.


From: Craig Ringer <ringerc(at)ringerc(dot)id(dot)au>
To: Edmund Horner <ejrh00(at)gmail(dot)com>
Cc: pgsql-bugs(at)postgresql(dot)org
Subject: Re: PostgreSQL 9.2 beta1's pg_upgrade fails on Windows XP
Date: 2012-05-22 06:49:22
Message-ID: 4FBB36F2.6060601@ringerc.id.au
Views: Raw Message | Whole Thread | Download mbox | Resend email
Lists: pgsql-bugs

First: Best. Bug. Report. Ever.

Comments inline, though I don't know enough about the Windows side to
help much.

> Checking for contrib/isn with bigint-passing mismatch ok
> Creating catalog dump The
> process cannot access the file because it is being used by another
> process.
> *failure*

Your speculation that antivirus may be involved is worth trying out,
though the fact that a different upgrade worked does indeed suggest it's
probably not that.

When you shut down the 9.1.3 cluster did you make absolutely certain
there were no postgres.exe processes lurking around when you tested?
Given the incredible thouroughness of your report I imagine you did, but
it's worth checking, as a lingering `postgres.exe' could (I imagine)
cause such an issue. Not that it should ever happen.

Do you have the option of re-trying with your AV disabled or removed?

--
Craig Ringer


From: Edmund Horner <ejrh00(at)gmail(dot)com>
To: Craig Ringer <ringerc(at)ringerc(dot)id(dot)au>, pgsql-bugs(at)postgresql(dot)org
Subject: Re: PostgreSQL 9.2 beta1's pg_upgrade fails on Windows XP
Date: 2012-05-23 03:50:47
Message-ID: CAMyN-kCd+h2GJJcF9EedUHCJxExq2HhFLu=dgGHY4a74OmfDew@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Lists: pgsql-bugs

On 22 May 2012 18:49, Craig Ringer <ringerc(at)ringerc(dot)id(dot)au> wrote:
> When you shut down the 9.1.3 cluster did you make absolutely certain there
> were no postgres.exe processes lurking around when you tested? Given the
> incredible thouroughness of your report I imagine you did, but it's worth
> checking, as a lingering `postgres.exe' could (I imagine) cause such an
> issue. Not that it should ever happen.

Yes, I ensured there were no postgres.exe processes running before
running up_upgrade. On a related note, postgres.exe processes DO
remaining running after pg_upgrade fails with this error. Not sure if
they're from the old or new binaries. I generally terminate them and
recreate the destination cluster between retries. Additionally, the
old cluster needs to be cycled: start it, and then stop it; because
the next pg_upgrade run thinks a postgres.exe could still be using it.
pg_ctl start also prints a warning about this but starts anyway.

> Do you have the option of re-trying with your AV disabled or removed?

At work I can't tamper with the AV, but I can run pg_upgrade in a
directory that is excluded from AV (the c:\ccviews directory used by
Clearcase!).

The log files are created there, and there is no AV activity on them
according to Filemon. There is still a SHARING VIOLATION on
pg_upgrade_utility.log, though:

9 3:47:42 p.m. pg_upgrade.exe:97760 OPEN C:\CCVIEWS\PG_UPGRADE_UTILITY.LOG SUCCESS Options:
Open Access: 00000081
10 3:47:42 p.m. pg_upgrade.exe:97760 QUERY
INFORMATION C:\CCVIEWS\PG_UPGRADE_UTILITY.LOG SUCCESS Length: 179
27 3:47:42 p.m. pg_upgrade.exe:97760 OPEN C:\ccviews\pg_upgrade_utility.log SUCCESS Options:
OpenIf Access: 00120196
28 3:47:42 p.m. pg_upgrade.exe:97760 QUERY
INFORMATION C:\ccviews\pg_upgrade_utility.log SUCCESS Length: 179
29 3:47:42 p.m. pg_upgrade.exe:97760 QUERY
INFORMATION C:\ccviews\pg_upgrade_utility.log SUCCESS Length: 179
30 3:47:42 p.m. pg_upgrade.exe:97760 WRITE
C:\ccviews\pg_upgrade_utility.log SUCCESS Offset: 179 Length: 179
31 3:47:42 p.m. pg_upgrade.exe:97760 CLOSE C:\ccviews\pg_upgrade_utility.log SUCCESS
101 3:47:45 p.m. cmd.exe:99028 OPEN C:\ccviews\pg_upgrade_utility.log SUCCESS Options:
Open Access: 0012019F
102 3:47:45 p.m. cmd.exe:99028 QUERY
INFORMATION C:\ccviews\pg_upgrade_utility.log SUCCESS Length: 358
103 3:47:45 p.m. cmd.exe:99028 QUERY
INFORMATION C:\ccviews\pg_upgrade_utility.log SUCCESS Length: 358
104 3:47:45 p.m. cmd.exe:99028 READ
C:\ccviews\pg_upgrade_utility.log SUCCESS Offset: 357 Length: 1
109 3:47:45 p.m. pg_ctl.exe:98832 WRITE
C:\ccviews\pg_upgrade_utility.log SUCCESS Offset: 358 Length: 30
110 3:47:45 p.m. pg_ctl.exe:98832 WRITE C:\ccviews\pg_upgrade_utility.log SUCCESS Offset:
388 Length: 1
133 3:47:45 p.m. svchost.exe:560 QUERY
INFORMATION C:\CCVIEWS\PG_UPGRADE_UTILITY.LOG SUCCESS Attributes: A
134 3:47:45 p.m. svchost.exe:560 OPEN C:\CCVIEWS\PG_UPGRADE_UTILITY.LOG SUCCESS Options:
Open Access: 00020088
135 3:47:45 p.m. svchost.exe:560 QUERY
INFORMATION C:\CCVIEWS\PG_UPGRADE_UTILITY.LOG SUCCESS FileInternalInformation
136 3:47:45 p.m. svchost.exe:560 CLOSE C:\CCVIEWS\PG_UPGRADE_UTILITY.LOG SUCCESS
141 3:47:47 p.m. pg_ctl.exe:98832 WRITE
C:\ccviews\pg_upgrade_utility.log SUCCESS Offset: 389 Length: 7
142 3:47:47 p.m. pg_ctl.exe:98832 WRITE
C:\ccviews\pg_upgrade_utility.log SUCCESS Offset: 396 Length: 16
183 3:48:01 p.m. cmd.exe:99396 OPEN C:\ccviews\pg_upgrade_utility.log SHARING
VIOLATION Options: Open Access: 0012019F
184 3:48:01 p.m. cmd.exe:99396 OPEN C:\ccviews\pg_upgrade_utility.log SHARING
VIOLATION Options: OpenIf Access: 00120196
195 3:48:02 p.m. cmd.exe:97484 OPEN C:\ccviews\pg_upgrade_utility.log SHARING
VIOLATION Options: Open Access: 0012019F
196 3:48:02 p.m. cmd.exe:97484 OPEN C:\ccviews\pg_upgrade_utility.log SHARING
VIOLATION Options: OpenIf Access: 00120196


From: Magnus Hagander <magnus(at)hagander(dot)net>
To: Edmund Horner <ejrh00(at)gmail(dot)com>
Cc: Craig Ringer <ringerc(at)ringerc(dot)id(dot)au>, pgsql-bugs(at)postgresql(dot)org, Bruce Momjian <bruce(at)momjian(dot)us>
Subject: Re: PostgreSQL 9.2 beta1's pg_upgrade fails on Windows XP
Date: 2012-05-23 13:20:30
Message-ID: CABUevEwF=3D7GxnPqh+K8qMsHNtVp9OS7Z5LQdm+JYR-Ystpaw@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Lists: pgsql-bugs

On Wed, May 23, 2012 at 5:50 AM, Edmund Horner <ejrh00(at)gmail(dot)com> wrote:
> On 22 May 2012 18:49, Craig Ringer <ringerc(at)ringerc(dot)id(dot)au> wrote:
>> When you shut down the 9.1.3 cluster did you make absolutely certain there
>> were no postgres.exe processes lurking around when you tested? Given the
>> incredible thouroughness of your report I imagine you did, but it's worth
>> checking, as a lingering `postgres.exe' could (I imagine) cause such an
>> issue. Not that it should ever happen.
>
> Yes, I ensured there were no postgres.exe processes running before
> running up_upgrade.  On a related note, postgres.exe processes DO
> remaining running after pg_upgrade fails with this error.  Not sure if
> they're from the old or new binaries.  I generally terminate them and
> recreate the destination cluster between retries.  Additionally, the
> old cluster needs to be cycled: start it, and then stop it; because
> the next pg_upgrade run thinks a postgres.exe could still be using it.
>  pg_ctl start also prints a warning about this but starts anyway.
>
>> Do you have the option of re-trying with your AV disabled or removed?
>
> At work I can't tamper with the AV, but I can run pg_upgrade in a
> directory that is excluded from AV (the c:\ccviews directory used by
> Clearcase!).
>
> The log files are created there, and there is no AV activity on them
> according to Filemon.  There is still a SHARING VIOLATION on
> pg_upgrade_utility.log, though:

This certainly looks like both pg_ctl and whatever is running under
cmd are both accessing the same logfile. This won't work. We can make
pg_ctl open it in sharing mode, but I'm pretty sure there is nothing
we can do about CMD - I assume that's coming from a shell redirect
somewhere?

> 142     3:47:47 p.m.    pg_ctl.exe:98832        WRITE
>        C:\ccviews\pg_upgrade_utility.log       SUCCESS Offset: 396 Length: 16
> 183     3:48:01 p.m.    cmd.exe:99396   OPEN    C:\ccviews\pg_upgrade_utility.log       SHARING
> VIOLATION       Options: Open  Access: 0012019F

We probably need to send these to different logfiles. Bruce?

--
 Magnus Hagander
 Me: http://www.hagander.net/
 Work: http://www.redpill-linpro.com/


From: Bruce Momjian <bruce(at)momjian(dot)us>
To: Magnus Hagander <magnus(at)hagander(dot)net>
Cc: Edmund Horner <ejrh00(at)gmail(dot)com>, Craig Ringer <ringerc(at)ringerc(dot)id(dot)au>, pgsql-bugs(at)postgresql(dot)org
Subject: Re: PostgreSQL 9.2 beta1's pg_upgrade fails on Windows XP
Date: 2012-05-24 00:33:02
Message-ID: 20120524003302.GF10306@momjian.us
Views: Raw Message | Whole Thread | Download mbox | Resend email
Lists: pgsql-bugs

On Wed, May 23, 2012 at 03:20:30PM +0200, Magnus Hagander wrote:
> On Wed, May 23, 2012 at 5:50 AM, Edmund Horner <ejrh00(at)gmail(dot)com> wrote:
> > On 22 May 2012 18:49, Craig Ringer <ringerc(at)ringerc(dot)id(dot)au> wrote:
> >> When you shut down the 9.1.3 cluster did you make absolutely certain there
> >> were no postgres.exe processes lurking around when you tested? Given the
> >> incredible thouroughness of your report I imagine you did, but it's worth
> >> checking, as a lingering `postgres.exe' could (I imagine) cause such an
> >> issue. Not that it should ever happen.
> >
> > Yes, I ensured there were no postgres.exe processes running before
> > running up_upgrade.  On a related note, postgres.exe processes DO
> > remaining running after pg_upgrade fails with this error.  Not sure if
> > they're from the old or new binaries.  I generally terminate them and
> > recreate the destination cluster between retries.  Additionally, the
> > old cluster needs to be cycled: start it, and then stop it; because
> > the next pg_upgrade run thinks a postgres.exe could still be using it.
> >  pg_ctl start also prints a warning about this but starts anyway.
> >
> >> Do you have the option of re-trying with your AV disabled or removed?
> >
> > At work I can't tamper with the AV, but I can run pg_upgrade in a
> > directory that is excluded from AV (the c:\ccviews directory used by
> > Clearcase!).
> >
> > The log files are created there, and there is no AV activity on them
> > according to Filemon.  There is still a SHARING VIOLATION on
> > pg_upgrade_utility.log, though:
>
> This certainly looks like both pg_ctl and whatever is running under
> cmd are both accessing the same logfile. This won't work. We can make
> pg_ctl open it in sharing mode, but I'm pretty sure there is nothing
> we can do about CMD - I assume that's coming from a shell redirect
> somewhere?
>
> > 142     3:47:47 p.m.    pg_ctl.exe:98832        WRITE
> >        C:\ccviews\pg_upgrade_utility.log       SUCCESS Offset: 396 Length: 16
> > 183     3:48:01 p.m.    cmd.exe:99396   OPEN    C:\ccviews\pg_upgrade_utility.log       SHARING
> > VIOLATION       Options: Open  Access: 0012019F
>
> We probably need to send these to different logfiles. Bruce?

I have applied the attached patch which should fix the problem. How
can we get Edmund a copy of a new binary for testing? Does he have to
wait for beta2?

In pre-9.2, pg_ctl output was sent to /dev/null to avoid this problem,
but that was to avoid sending pg_ctl -l output and stdout output to the
same file. With 9.2, now that we have multiple output files, I sent the
pg_ctl stdout to the utility file. One would think that doing:

pg_ctl -l file1 > file2
vacuumedb > file2

would not be a problem, but Edmund is reporting he is getting a file
share error. It sounds like even though pg_ctl has finished, it still
has the file open, perhaps by the still-running postmaster. I am
unclear if the 'pg_ctl.exe' reported by the tool above is really pg_ctl
or the postmaster.

Anyway, I am pretty sure this patch fixes the problem, and I added a C
comment explaining what I think is happening, but it isn't totally clear
to me yet. It would be interesting to see the kept log files if
pg_upgrade is run with the --retain flag. (Edmund, you can email those
to me privately.) That would tell me what stage is causing the problem.
The pg_upgrade output reported seems to indicate it is pg_dumpall:

Creating catalog dump The
process cannot access the file because it is being used by another
process.
*failure*

which supports my idea that it is really the postmaster who has that
file kept open and causing the share violation.

In pre-9.2, we only output one log file, but now that we output 4,
outputting one more on Windows for pg_ctl isn't a problem. My patch
also adjusts the output file array now that is of variable size.

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

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

Attachment Content-Type Size
pg_upgrade.diff text/x-diff 5.0 KB

From: Edmund Horner <ejrh00(at)gmail(dot)com>
To: Bruce Momjian <bruce(at)momjian(dot)us>, pgsql-bugs(at)postgresql(dot)org
Subject: Re: PostgreSQL 9.2 beta1's pg_upgrade fails on Windows XP
Date: 2012-05-24 00:40:48
Message-ID: CAMyN-kAFE_BXobh_aYcCsgPPMgcKQ3UfosTqqkJWro2wvqLWJg@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Lists: pgsql-bugs

On 24 May 2012 12:33, Bruce Momjian <bruce(at)momjian(dot)us> wrote:
> I have applied the attached patch which should fix the problem.   How
> can we get Edmund a copy of a new binary for testing?  Does he have to
> wait for beta2?

My uneducated guess is that your patch will fix the problem.

But I don't think I'm up to compiling it myself. If someone reputable
can send me a new pg_upgrade.exe binary I'm happy to run it.

Edmund.


From: Magnus Hagander <magnus(at)hagander(dot)net>
To: Edmund Horner <ejrh00(at)gmail(dot)com>
Cc: Bruce Momjian <bruce(at)momjian(dot)us>, pgsql-bugs(at)postgresql(dot)org
Subject: Re: PostgreSQL 9.2 beta1's pg_upgrade fails on Windows XP
Date: 2012-05-24 13:42:25
Message-ID: CABUevEx5Y_CnktejAjLEC5B0i0xAdAKdoQH9nhrzSHECLRPeyA@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Lists: pgsql-bugs

On Thu, May 24, 2012 at 2:40 AM, Edmund Horner <ejrh00(at)gmail(dot)com> wrote:
> On 24 May 2012 12:33, Bruce Momjian <bruce(at)momjian(dot)us> wrote:
>> I have applied the attached patch which should fix the problem.   How
>> can we get Edmund a copy of a new binary for testing?  Does he have to
>> wait for beta2?
>
> My uneducated guess is that your patch will fix the problem.
>
> But I don't think I'm up to compiling it myself.  If someone reputable
> can send me a new pg_upgrade.exe binary I'm happy to run it.

I've built a new one off git master + Bruce's patch. You can get it
from http://www.hagander.net/tmp/pg_upgrade.zip - please see if that
one works for you.

--
 Magnus Hagander
 Me: http://www.hagander.net/
 Work: http://www.redpill-linpro.com/


From: Bruce Momjian <bruce(at)momjian(dot)us>
To: Magnus Hagander <magnus(at)hagander(dot)net>
Cc: Edmund Horner <ejrh00(at)gmail(dot)com>, pgsql-bugs(at)postgresql(dot)org
Subject: Re: PostgreSQL 9.2 beta1's pg_upgrade fails on Windows XP
Date: 2012-05-24 13:59:56
Message-ID: 20120524135956.GH10306@momjian.us
Views: Raw Message | Whole Thread | Download mbox | Resend email
Lists: pgsql-bugs

On Thu, May 24, 2012 at 03:42:25PM +0200, Magnus Hagander wrote:
> On Thu, May 24, 2012 at 2:40 AM, Edmund Horner <ejrh00(at)gmail(dot)com> wrote:
> > On 24 May 2012 12:33, Bruce Momjian <bruce(at)momjian(dot)us> wrote:
> >> I have applied the attached patch which should fix the problem.   How
> >> can we get Edmund a copy of a new binary for testing?  Does he have to
> >> wait for beta2?
> >
> > My uneducated guess is that your patch will fix the problem.
> >
> > But I don't think I'm up to compiling it myself.  If someone reputable
> > can send me a new pg_upgrade.exe binary I'm happy to run it.
>
> I've built a new one off git master + Bruce's patch. You can get it
> from http://www.hagander.net/tmp/pg_upgrade.zip - please see if that
> one works for you.

Thanks, but thinking more, I am more concerned. Here is what we think
is happening (ah, flashbacks to the PG Windows port):

pg_ctl start > file1
pg_dumpall > file1
pg_ctl stop > file1

generates a file share error for pg_dump. I have replaced that with:

pg_ctl start > file2
pg_dumpall > file1
pg_ctl stop > file2

I am now concerned that 'pg_ctl stop' is going to give us a share
violation. The fix will be to use 'file3' for pg_ctl stop. Can I get
an updated report to see if that is accurate? Thanks.

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

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


From: Edmund Horner <ejrh00(at)gmail(dot)com>
To: Bruce Momjian <bruce(at)momjian(dot)us>, pgsql-bugs(at)postgresql(dot)org
Subject: Re: PostgreSQL 9.2 beta1's pg_upgrade fails on Windows XP
Date: 2012-05-24 23:48:53
Message-ID: CAMyN-kBUzHrkHK77cCAU=VQvv7tT-ekXO+JJZTTBscNrzEct1g@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Lists: pgsql-bugs

On 25 May 2012 01:59, Bruce Momjian <bruce(at)momjian(dot)us> wrote:
> On Thu, May 24, 2012 at 03:42:25PM +0200, Magnus Hagander wrote:
>> I've built a new one off git master + Bruce's patch. You can get it
>> from http://www.hagander.net/tmp/pg_upgrade.zip - please see if that
>> one works for you.
>
> Thanks, but thinking more, I am more concerned.  Here is what we think
> is happening (ah, flashbacks to the PG Windows port):
>
>        pg_ctl start > file1
>        pg_dumpall > file1
>        pg_ctl stop > file1
>
> generates a file share error for pg_dump.  I have replaced that with:
>
>        pg_ctl start > file2
>        pg_dumpall > file1
>        pg_ctl stop > file2
>
> I am now concerned that 'pg_ctl stop' is going to give us a share
> violation.  The fix will be to use 'file3' for pg_ctl stop.  Can I get
> an updated report to see if that is accurate?  Thanks.

Hi Bruce and Magnus,

I've run the new EXE. It makes further progress than the previous
build, and creates the following files (with sizes):

158,142 pg_upgrade_dump_all.sql
157,127 pg_upgrade_dump_db.sql
993 pg_upgrade_dump_globals.sql
19,164 pg_upgrade_internal.log
179 pg_upgrade_restore.log
179 pg_upgrade_server.log
234 pg_upgrade_server2.log
43,476 pg_upgrade_utility.log

It still fails (when run in verbose mode):

Creating catalog dump
""c:\ehorner\pgsql\bin/pg_dumpall" --port 50432 --username "ehorner"
--schema-only --binary-upgrade --verbose > "pg_upgrade_dump_all.sql"
2>> "pg_upgrade_utility.log""
ok
""c:\ehorner\pgsql-old\bin/pg_ctl" -w -l "pg_upgrade_server2.log"
-D "c:\ehorner\pgdata-old" -o"" stop >> "pg_upgrade_server2.log"
2>&1"
The process cannot access the file because it is being used by
another process.
*failure*
There were problems executing """c:\ehorner\pgsql-old\bin/pg_ctl"
-w -l "pg_upgrade_server2.log" -D "c:\ehorner\pgdata-old" -o "" stop
>> "pg_upgrade_server2.log" 2>&1""

Consult the last few lines of "pg_upgrade_server2.log" for
the probable cause of the failure.
Failure, exiting
""c:\ehorner\pgsql-old\bin/pg_ctl" -w -l "pg_upgrade_server2.log"
-D "c:\ehorner\pgdata-old" -o"" -m fast stop >>
"pg_upgrade_server2.log" 2>&1"
The process cannot access the file because it is being used by
another process.
*failure*
There were problems executing """c:\ehorner\pgsql-old\bin/pg_ctl"
-w -l "pg_upgrade_server2.log" -D "c:\ehorner\pgdata-old" -o "" -m
fast stop >> "pg_upgrade_server2.log" 2>&1""
Consult the last few lines of "pg_upgrade_server2.log" for
the probable cause of the failure.

These messages are also in pg_upgrade_internal.log.
pg_upgrade_server2.log simply says "waiting for server to start.....
done" and "server started".

There were some SHARING VIOLATIONs on pg_upgrade_server2.log. In fact
it looks like it occurs twice to two different "cmd.exe" invocations
-- I'm not sure if that's two distinct steps in the process, or a
single step being automatically retried. It's a bit hard to correlate
the sequence of file system calls with the pg_upgrade log outputs.

17185 11:15:09 a.m. pg_ctl.exe:106380 WRITE
C:\pg_upgrade_server2.log SUCCESS Offset: 210 Length: 1
18901 11:15:11 a.m. pg_ctl.exe:106380 WRITE
C:\pg_upgrade_server2.log SUCCESS Offset: 211 Length: 7
18904 11:15:11 a.m. pg_ctl.exe:106380 WRITE
C:\pg_upgrade_server2.log SUCCESS Offset: 218 Length: 16
68104 11:15:38 a.m. cmd.exe:106096 OPEN
C:\pg_upgrade_server2.log SHARING VIOLATION Options: Open
Access: 0012019F
68105 11:15:38 a.m. cmd.exe:106096 OPEN
C:\pg_upgrade_server2.log SHARING VIOLATION Options:
OpenIf Access: 00120196
68696 11:15:38 a.m. cmd.exe:106104 OPEN
C:\pg_upgrade_server2.log SHARING VIOLATION Options: Open
Access: 0012019F
68697 11:15:38 a.m. cmd.exe:106104 OPEN
C:\pg_upgrade_server2.log SHARING VIOLATION Options:
OpenIf Access: 00120196

The offsets and lengths written by pg_ctl correpond to the last bits
of text content in the file, which is:

-----------------------------------------------------------------
pg_upgrade run on Fri May 25 11:27:02 2012
-----------------------------------------------------------------

waiting for server to start..... done
server started

I.e. I think pg_ctl wrote the last couple of lines, and then the two
cmd.exe were unable to write anything more since presumably it's still
open.

So is this the problem you predicted above with pg_ctl stop?

I'll provide the logs and filemon output privately if you need them.


From: Edmund Horner <ejrh00(at)gmail(dot)com>
To: Bruce Momjian <bruce(at)momjian(dot)us>, pgsql-bugs(at)postgresql(dot)org
Subject: Re: PostgreSQL 9.2 beta1's pg_upgrade fails on Windows XP
Date: 2012-05-24 23:52:39
Message-ID: CAMyN-kCM2DrWDf+3qUsN6w7awLc+sEXEr3d=RnhqGtcJqzsEJw@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Lists: pgsql-bugs

On 25 May 2012 11:48, Edmund Horner <ejrh00(at)gmail(dot)com> wrote:
> It still fails (when run in verbose mode):

Sorry, let me correct that to:

It still fails, regardless of verbose mode. And, in verbose mode, the
output is...


From: Bruce Momjian <bruce(at)momjian(dot)us>
To: Edmund Horner <ejrh00(at)gmail(dot)com>
Cc: pgsql-bugs(at)postgresql(dot)org
Subject: Re: PostgreSQL 9.2 beta1's pg_upgrade fails on Windows XP
Date: 2012-05-25 00:34:01
Message-ID: 20120525003401.GA25460@momjian.us
Views: Raw Message | Whole Thread | Download mbox | Resend email
Lists: pgsql-bugs

On Fri, May 25, 2012 at 11:48:53AM +1200, Edmund Horner wrote:
> It still fails (when run in verbose mode):
>
> Creating catalog dump
> ""c:\ehorner\pgsql\bin/pg_dumpall" --port 50432 --username "ehorner"
> --schema-only --binary-upgrade --verbose > "pg_upgrade_dump_all.sql"
> 2>> "pg_upgrade_utility.log""
> ok
> ""c:\ehorner\pgsql-old\bin/pg_ctl" -w -l "pg_upgrade_server2.log"
> -D "c:\ehorner\pgdata-old" -o"" stop >> "pg_upgrade_server2.log"
> 2>&1"
> The process cannot access the file because it is being used by
> another process.
> *failure*
> There were problems executing """c:\ehorner\pgsql-old\bin/pg_ctl"
> -w -l "pg_upgrade_server2.log" -D "c:\ehorner\pgdata-old" -o "" stop
> >> "pg_upgrade_server2.log" 2>&1""

Bingo, this is exactly where I expected it to fail. I am attaching a
new, applied patch that creates files pg_upgrade_server_start.log and
pg_upgrade_server_stop.log to log the pg_ctl start/stop stdout
seperately. This should fix the error. Thanks so much for testing. I
believe someone will generate a new binary for testing.

> I.e. I think pg_ctl wrote the last couple of lines, and then the two
> cmd.exe were unable to write anything more since presumably it's still
> open.
>
> So is this the problem you predicted above with pg_ctl stop?

Yep, I think we are good now. I never expected this behavior, but it
now makes sense.

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

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

Attachment Content-Type Size
pg_upgrade.diff text/x-diff 4.9 KB

From: Bruce Momjian <bruce(at)momjian(dot)us>
To: Edmund Horner <ejrh00(at)gmail(dot)com>
Cc: pgsql-bugs(at)postgresql(dot)org
Subject: Re: PostgreSQL 9.2 beta1's pg_upgrade fails on Windows XP
Date: 2012-05-25 13:10:21
Message-ID: 20120525131021.GA11374@momjian.us
Views: Raw Message | Whole Thread | Download mbox | Resend email
Lists: pgsql-bugs

On Thu, May 24, 2012 at 08:34:01PM -0400, Bruce Momjian wrote:
> On Fri, May 25, 2012 at 11:48:53AM +1200, Edmund Horner wrote:
> > It still fails (when run in verbose mode):
> >
> > Creating catalog dump
> > ""c:\ehorner\pgsql\bin/pg_dumpall" --port 50432 --username "ehorner"
> > --schema-only --binary-upgrade --verbose > "pg_upgrade_dump_all.sql"
> > 2>> "pg_upgrade_utility.log""
> > ok
> > ""c:\ehorner\pgsql-old\bin/pg_ctl" -w -l "pg_upgrade_server2.log"
> > -D "c:\ehorner\pgdata-old" -o"" stop >> "pg_upgrade_server2.log"
> > 2>&1"
> > The process cannot access the file because it is being used by
> > another process.
> > *failure*
> > There were problems executing """c:\ehorner\pgsql-old\bin/pg_ctl"
> > -w -l "pg_upgrade_server2.log" -D "c:\ehorner\pgdata-old" -o "" stop
> > >> "pg_upgrade_server2.log" 2>&1""
>
> Bingo, this is exactly where I expected it to fail. I am attaching a
> new, applied patch that creates files pg_upgrade_server_start.log and
> pg_upgrade_server_stop.log to log the pg_ctl start/stop stdout
> seperately. This should fix the error. Thanks so much for testing. I
> believe someone will generate a new binary for testing.
>
> > I.e. I think pg_ctl wrote the last couple of lines, and then the two
> > cmd.exe were unable to write anything more since presumably it's still
> > open.
> >
> > So is this the problem you predicted above with pg_ctl stop?
>
> Yep, I think we are good now. I never expected this behavior, but it
> now makes sense.

Ah, turns out I only need one extra log file on Windows, not two,
because I can reuse the utility file for pg_ctl stop. The original
beta1 code usesd the utility file for pg_ctl stop and start, which is
what caused the problem.

Applied patch attached.

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

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

Attachment Content-Type Size
pg_upgrade.diff text/x-diff 1.3 KB

From: Edmund Horner <ejrh00(at)gmail(dot)com>
To: Bruce Momjian <bruce(at)momjian(dot)us>
Cc: pgsql-bugs(at)postgresql(dot)org
Subject: Re: PostgreSQL 9.2 beta1's pg_upgrade fails on Windows XP
Date: 2012-06-12 05:10:19
Message-ID: CAMyN-kAyZvZEkXXsp5J+XRiEi+sdwuUW+y4FKk-Qn5OJymgNAA@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Lists: pgsql-bugs

On 26 May 2012 01:10, Bruce Momjian <bruce(at)momjian(dot)us> wrote:
> Ah, turns out I only need one extra log file on Windows, not two,
> because I can reuse the utility file for pg_ctl stop.  The original
> beta1 code usesd the utility file for pg_ctl stop and start, which is
> what caused the problem.
>
> Applied patch attached.

And now pg_upgrade in beta2 works fine. Thanks.


From: Bruce Momjian <bruce(at)momjian(dot)us>
To: Edmund Horner <ejrh00(at)gmail(dot)com>
Cc: pgsql-bugs(at)postgresql(dot)org
Subject: Re: PostgreSQL 9.2 beta1's pg_upgrade fails on Windows XP
Date: 2012-06-13 14:34:20
Message-ID: 20120613143420.GA4419@momjian.us
Views: Raw Message | Whole Thread | Download mbox | Resend email
Lists: pgsql-bugs

On Tue, Jun 12, 2012 at 05:10:19PM +1200, Edmund Horner wrote:
> On 26 May 2012 01:10, Bruce Momjian <bruce(at)momjian(dot)us> wrote:
> > Ah, turns out I only need one extra log file on Windows, not two,
> > because I can reuse the utility file for pg_ctl stop.  The original
> > beta1 code usesd the utility file for pg_ctl stop and start, which is
> > what caused the problem.
> >
> > Applied patch attached.
>
> And now pg_upgrade in beta2 works fine. Thanks.

Great. Thanks for the report.

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

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