Re: [BUGS] [Win32] Problem with rename()

#1

Peter Brant wrote:

Quote:

Hi all,

In the last couple of days, we've been bitten (a couple of times, on
different servers) by an apparent glitch or bad interaction in the
Windows implementation of rename().

The relevant log message is:

[2006-04-17 16:49:22.583 ] 2252 LOG: could not rename file
"pg_xlog/000000010000010A000000BD" to
"pg_xlog/000000010000010A000000D7", continuing to try

It apparently just keeps on looping indefinitely. The "completed
rename" message from port/dirmod.c never shows up.

Shortly thereafter, Postgres becomes unresponsive. Attempts to make a
new connection just block. Autovacuums block. A "pg_ctl ... stop -m
fast" doesn't work. Only "pg_ctl ... stop -m immediate" does.

With the last occurrence, I saved off the output of "handle -a" and
"pslist -x" in case that's helpful.

Any thoughts on what might be going wrong? If it happens again, what
other clues should I be looking for?

Yes, comment I added to dirmod.c give a hint:

/*
* We need these loops because even though PostgreSQL uses flags that
* allow rename while the file is open, other applications might have
* these files open without those flags.
*/

so someone else has the file opened, but didn't use the required flags.
As to what could have it open, I don't know.

--
Bruce Momjian http://candle.pha.pa.us
EnterpriseDB http://www.enterprisedb.com

+ If your life is a hard drive, Christ can be your backup. +

---------------------------(end of broadcast)---------------------------
TIP 3: Have you checked our extensive FAQ?

http://www.postgresql.org/docs/faq

#2

""Peter Brant"" <Peter.Brant (AT) wicourts (DOT) gov>

Quote:

In the last couple of days, we've been bitten (a couple of times, on
different servers) by an apparent glitch or bad interaction in the
Windows implementation of rename().

The relevant log message is:

[2006-04-17 16:49:22.583 ] 2252 LOG: could not rename file
"pg_xlog/000000010000010A000000BD" to
"pg_xlog/000000010000010A000000D7", continuing to try

It apparently just keeps on looping indefinitely. The "completed
rename" message from port/dirmod.c never shows up.

Similar problems have been reported before -- which PG version and do you
have any anti-virus software installed?

Regards,
Qingqing

---------------------------(end of broadcast)---------------------------
TIP 5: don't forget to increase your free space map settings

#3

Quote:

Hi all,
=20
In the last couple of days, we've been bitten (a couple of=20
times, on different servers) by an apparent glitch or bad=20
interaction in the Windows implementation of rename().
=20
The relevant log message is:
=20
[2006-04-17 16:49:22.583 ] 2252 LOG: could not rename file=20
"pg_xlog/000000010000010A000000BD" to=20
"pg_xlog/000000010000010A000000D7", continuing to try
=20
It apparently just keeps on looping indefinitely. The=20
"completed rename" message from port/dirmod.c never shows up.
=20
Shortly thereafter, Postgres becomes unresponsive. Attempts=20
to make a new connection just block. Autovacuums block. A=20
"pg_ctl ... stop -m fast" doesn't work. Only "pg_ctl ...=20
stop -m immediate" does.
=20
With the last occurrence, I saved off the output of "handle=20
-a" and "pslist -x" in case that's helpful.=20=20
=20
Any thoughts on what might be going wrong? If it happens=20
again, what other clues should I be looking for?

It would be interesting to see which processes have handle(s) open to
either of these two names. "handle -a" shuold give that, I assume?

//Magnus

---------------------------(end of broadcast)---------------------------
TIP 1: if posting/reading through Usenet, please send an appropriate
subscribe-nomail command to majordomo (AT) postgresql (DOT) org so that your
message can get through to the mailing list cleanly

#4

Unfortunately, it's not that simple. It would be straightforward to
track down if it were.

In response to other questions:

It's Postgres 8.1.3 running on Windows 2003 Server. No anti-virus
software is installed. The servers are essentially bare except for the
OS and Postgres.

We have "handle -a" output from two occurrences (different servers):

For the first one:

LOG: could not rename file "pg_xlog/000000010000010A000000BD" to
"pg_xlog/000000010000010A000000D7", continuing to try

Only one process (postgres.exe) is holding a handle to
pg_xlog/000000010000010A000000BD:

F84: Event \BaseNamedObjects\pgident: postgres: bigbird
bigbird 127.0.0.1(3306) BIND
FF4: File G:\pgsql\data\pg_xlog\000000010000010A000000BD

Nothing has the target file open.

The second is similar, except that two postgres.exe processes (and
nothing else) have the file open:

LOG: could not rename file "pg_xlog/000000010000010A0000006E" to
"pg_xlog/000000010000010A00000087", continuing to try

#1:
F84: Event \BaseNamedObjects\pgident: postgres: bigbird
bigbird 127.0.0.1(2367) SELECT
EFC: File G:\pgsql\data\pg_xlog\000000010000010A0000006E

#2:
F84: Event \BaseNamedObjects\pgident: postgres: bigbird
bigbird 127.0.0.1(2420) SELECT
FF4: File G:\pgsql\data\pg_xlog\000000010000010A0000006E

Nothing has the target file open.

Pete

Quote:

Bruce Momjian <pgman (AT) candle (DOT) pha.pa.us> 04/18/06 2:58 am
Yes, comment I added to dirmod.c give a hint:

/*
* We need these loops because even though PostgreSQL uses flags
that
* allow rename while the file is open, other applications might
have
* these files open without those flags.
*/

so someone else has the file opened, but didn't use the required flags.

As to what could have it open, I don't know.

---------------------------(end of broadcast)---------------------------
TIP 1: if posting/reading through Usenet, please send an appropriate
subscribe-nomail command to majordomo (AT) postgresql (DOT) org so that your
message can get through to the mailing list cleanly

#5

------=_Part_19640_7250357.1145370919835
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: base64
Content-Disposition: inline

UGV0ZXIsCgo+IEc6XHBnc3FsXGRhdGFccGdfeGxvZ1wwMDAwMD AwMTAwMDAwMTBBMDAwMDAwQkQK
CnByb3BhYmx5IGEgdmVyeSBzdHVwaWQgcXVlc3Rpb246ICJHIi AtIGlzIHRoYXQgcmVhbGx5IGEg
TE9LQUwgZHJpdmUgYXQgdGhhdApzZXJ2ZXIsIG9yIHJhdGhlci Bzb21lIE5BUyBvciBzaW1pbGlh
cj8KCkkgaGFkIHRoZSBzYW1lIGVycm9yIGluIG9uZSBsb2dmaW xlIG9uZSB0aW1lLCBidXQgdGhl
cmUgd2hlcmUgYSBsYXJnZSBhbW91bnQKb2YgcG9zc2libGUgY3 VscHJpdHMgKHZpcmFsIHNjYW5u
ZXIsIGxvZ2luIHNjcmlwdCBjaGFuZ2luZyBwZXJtaXNzaW9ucy wKYmFja3VwcywgYWNjZXNzIGNv
bnRyb2wgc29mdHdhcmUuLi4pIGFuZCB3ZSBjb3VsZCBub3Qgcm Vwcm9kdWNlIHRoZSBlcnJvci4K
CkhhcmFsZAotLQpHSFVNIEhhcmFsZCBNYXNzYQpwZXJzdWFkZX JlIGV0IHByb2dyYW1tYXJlCkhh
cmFsZCBBcm1pbiBNYXNzYQpSZWluc2J1cmdzdHJhw59lIDIwMm IKNzAxOTcgU3R1dHRnYXJ0CjAx
NzMvOTQwOTYwNwotClBvc3RncmVTUUwgLSBzdXBwb3J0ZWQgYn kgYSBjb21tdW5pdHkgdGhhdCBk
b2VzIG5vdCBwdXQgeW91IG9uIGhvbGQK
------=_Part_19640_7250357.1145370919835
Content-Type: text/html; charset=UTF-8
Content-Transfer-Encoding: base64
Content-Disposition: inline

UGV0ZXIsPGJyPjxicj4mZ3Q7IEc6XHBnc3FsXGRhdGFccGdfeG xvZ1wwMDAwMDAwMTAwMDAwMTBB
MDAwMDAwQkQ8YnI+PGJyPnByb3BhYmx5IGEgdmVyeSBzdHVwaW QgcXVlc3Rpb246ICZxdW90O0cm
cXVvdDsgLSBpcyB0aGF0IHJlYWxseSBhIExPS0FMIGRyaXZlIG F0IHRoYXQgc2VydmVyLCBvciBy
YXRoZXIgc29tZSBOQVMgb3Igc2ltaWxpYXI/IDxicj48YnI+SSBoYWQgdGhlIHNhbWUgZXJyb3Ig
aW4gb25lIGxvZ2ZpbGUgb25lIHRpbWUsIGJ1dCB0aGVyZSB3aG VyZSBhIGxhcmdlIGFtb3VudCBv
ZiBwb3NzaWJsZSBjdWxwcml0cyAodmlyYWwgc2Nhbm5lciwgbG 9naW4gc2NyaXB0IGNoYW5naW5n
IHBlcm1pc3Npb25zLCBiYWNrdXBzLCBhY2Nlc3MgY29udHJvbC Bzb2Z0d2FyZS4uLikgYW5kIHdl
IGNvdWxkIG5vdCByZXByb2R1Y2UgdGhlIGVycm9yLgo8YnI+PG JyPkhhcmFsZDxicj4tLSA8YnI+
R0hVTSBIYXJhbGQgTWFzc2E8YnI+cGVyc3VhZGVyZSBldCBwcm 9ncmFtbWFyZTxicj5IYXJhbGQg
QXJtaW4gTWFzc2E8YnI+UmVpbnNidXJnc3RyYcOfZSAyMDJiPG JyPjcwMTk3IFN0dXR0Z2FydDxi
cj4wMTczLzk0MDk2MDc8YnI+LTxicj5Qb3N0Z3JlU1FMIC0gc3 VwcG9ydGVkIGJ5IGEgY29tbXVu
aXR5IHRoYXQgZG9lcyBub3QgcHV0IHlvdSBvbiBob2xkCg==
------=_Part_19640_7250357.1145370919835--

#6

Ok. So we're obviously blocking ourselves out.

Which process was the stalled one? Was it the same one that held the
file open, or a different one?

Looking at our code, we have the comment:
/* These flags allow concurrent rename/unlink */
(FILE_SHARE_READ |
FILE_SHARE_WRITE | FILE_SHARE_DELETE),

But I'm not sure that those flags actually guarantee that. They do allow
concurrent unlink, but not necessarily rename. I read elsewhere that it
should work, but can't find backing docs on MSDN. Seems it works in most
cases, but perhaps there are some where it doesn't?

Is there any way we can force our own other backends to close a file?
That would be an easy fix - have the postmaster tell all other backends
to close all files and reopen...

/Magnus

Quote:

-----Original Message-----
From: Peter Brant [mailto:Peter.Brant (AT) wicourts (DOT) gov]=20
Sent: Tuesday, April 18, 2006 4:15 PM
To: Bruce Momjian; Qingqing Zhou <zhouqq (AT) cs (DOT) toronto.edu;=20
Magnus Hagander <mha (AT) sollentuna (DOT) net
Cc: pgsql-bugs (AT) postgresql (DOT) org
Subject: Re: [BUGS] [Win32] Problem with rename()
=20
Unfortunately, it's not that simple. It would be=20
straightforward to track down if it were.
=20
In response to other questions:
=20
It's Postgres 8.1.3 running on Windows 2003 Server. No=20
anti-virus software is installed. The servers are=20
essentially bare except for the OS and Postgres.
=20
We have "handle -a" output from two occurrences (different servers):
=20
For the first one:
=20
LOG: could not rename file=20
"pg_xlog/000000010000010A000000BD" to=20
"pg_xlog/000000010000010A000000D7", continuing to try
=20
Only one process (postgres.exe) is holding a handle to
pg_xlog/000000010000010A000000BD:
=20
F84: Event \BaseNamedObjects\pgident: postgres: bigbird
bigbird 127.0.0.1(3306) BIND
FF4: File G:\pgsql\data\pg_xlog\000000010000010A000000BD
=20
Nothing has the target file open.
=20
The second is similar, except that two postgres.exe processes=20
(and nothing else) have the file open:
=20
LOG: could not rename file=20
"pg_xlog/000000010000010A0000006E" to=20
"pg_xlog/000000010000010A00000087", continuing to try
=20
#1:
F84: Event \BaseNamedObjects\pgident: postgres: bigbird
bigbird 127.0.0.1(2367) SELECT
EFC: File G:\pgsql\data\pg_xlog\000000010000010A0000006E
=20
#2:
F84: Event \BaseNamedObjects\pgident: postgres: bigbird
bigbird 127.0.0.1(2420) SELECT
FF4: File G:\pgsql\data\pg_xlog\000000010000010A0000006E
=20
Nothing has the target file open.
=20
Pete
=20
Bruce Momjian <pgman (AT) candle (DOT) pha.pa.us> 04/18/06 2:58 am
Yes, comment I added to dirmod.c give a hint:
=20
/*
* We need these loops because even though PostgreSQL=20
uses flags that
* allow rename while the file is open, other=20
applications might have
* these files open without those flags.
*/
=20
so someone else has the file opened, but didn't use the=20
required flags.
=20
As to what could have it open, I don't know.
=20
=20

---------------------------(end of broadcast)---------------------------
TIP 6: explain analyze is your friend

#7

"Peter Brant" <Peter.Brant (AT) wicourts (DOT) gov> writes:

Quote:

LOG: could not rename file "pg_xlog/000000010000010A000000BD" to
"pg_xlog/000000010000010A000000D7", continuing to try
...
Only one process (postgres.exe) is holding a handle to
pg_xlog/000000010000010A000000BD:
...
The second is similar, except that two postgres.exe processes (and
nothing else) have the file open:

Hmm, could these be backends that have been sitting idle for some time?
I'd expect a backend to be holding open a handle for whichever WAL
segment it last wrote to. If the backend sits idle for a couple of
checkpoints while others are advancing the end of WAL, then that segment
could become a target for renaming.

The only workable fix I can think of is to allow the checkpointer to
simply fail to rename this segment and go on about its business,
figuring that we'll be able to rename/delete the WAL segment in some
future checkpoint cycle. Not sure how messy that would be to implement.

regards, tom lane

---------------------------(end of broadcast)---------------------------
TIP 1: if posting/reading through Usenet, please send an appropriate
subscribe-nomail command to majordomo (AT) postgresql (DOT) org so that your
message can get through to the mailing list cleanly

#8

"Magnus Hagander" <mha (AT) sollentuna (DOT) net> writes:

Quote:

Looking at our code, we have the comment:
/* These flags allow concurrent rename/unlink */
(FILE_SHARE_READ |
FILE_SHARE_WRITE | FILE_SHARE_DELETE),

But I'm not sure that those flags actually guarantee that. They do allow
concurrent unlink, but not necessarily rename. I read elsewhere that it
should work, but can't find backing docs on MSDN. Seems it works in most
cases, but perhaps there are some where it doesn't?

I think there are two different cases involved in rename:

1. Someone has a handle for the file-to-be-renamed;
2. Someone has a handle for the file that is to be deleted (ie currently
has the name being renamed to).

If #2 doesn't work then we've got serious problems. I think though that
#1 can only occur in the context of WAL segment recycling, so we can
probably work around it if that doesn't work.

regards, tom lane

---------------------------(end of broadcast)---------------------------
TIP 1: if posting/reading through Usenet, please send an appropriate
subscribe-nomail command to majordomo (AT) postgresql (DOT) org so that your
message can get through to the mailing list cleanly

#9

Quote:

Looking at our code, we have the comment:
/* These flags allow concurrent rename/unlink */
(FILE_SHARE_READ |
FILE_SHARE_WRITE | FILE_SHARE_DELETE),
=20
But I'm not sure that those flags actually guarantee that.=20
They do allow
concurrent unlink, but not necessarily rename. I read=20
elsewhere that it
should work, but can't find backing docs on MSDN. Seems it=20
works in most
cases, but perhaps there are some where it doesn't?
=20
I think there are two different cases involved in rename:
=20
1. Someone has a handle for the file-to-be-renamed;
2. Someone has a handle for the file that is to be deleted=20
(ie currently
has the name being renamed to).
=20
If #2 doesn't work then we've got serious problems. I think=20
though that
#1 can only occur in the context of WAL segment recycling, so we can
probably work around it if that doesn't work.

The problem reported here was 1. Nobody had handles to the new filename.
I don't think I've seen any reports of issue 2, but most were never
researched to this depth (because most were just a case of
uninstalling-the-antivirus-to-make-it-work).

//Magnus

---------------------------(end of broadcast)---------------------------
TIP 4: Have you searched our list archives?

http://archives.postgresql.org

#10

They are local.

Pete

Quote:

"Harald Armin Massa" <haraldarminmassa (AT) gmail (DOT) com> 04/18/06 4:35 pm

"G" - is that really a LOKAL drive at that server, or rather some NAS

or similiar?

---------------------------(end of broadcast)---------------------------
TIP 9: In versions below 8.0, the planner will ignore your desire to
choose an index scan if your joining column's datatypes do not
match