Re: Unknown winsock error 10061

After upgrading to 8.4 on Vista I see no progress on the shared memory
problem unfortunately.

I think it's even worse now (previously it happened mainly when OS
went to sleep & then was restored, now it's all the time).

My log looks like this.
----------------------------------------------------------------------------------------------------------------------------------------------
FATAL: could not reattach to shared memory (key=288, addr=02A00000):
487
2009-07-06 11:39:45 CESTLOG: could not receive data from client:
Unknown winsock error 10061
2009-07-06 11:39:45 CESTLOG: unexpected EOF on client connection
FATAL: could not reattach to shared memory (key=288, addr=02A00000):
487
2009-07-06 11:40:20 CESTLOG: could not receive data from client:
Unknown winsock error 10061
2009-07-06 11:40:20 CESTLOG: unexpected EOF on client connection
2009-07-06 11:40:20 CESTLOG: could not receive data from client:
Unknown winsock error 10061
2009-07-06 11:40:20 CESTLOG: unexpected EOF on client connection
-----------------------------------------------------------------------------------------------------------------------------------------------

Our application runs on Linux in the production environment, but all
the developers works on Windows with local PG installations. Some of
them are getting the error - some don't.
.
It's really big problem explaining to the people that PG is really
good database.

Is there any chance to do something with it?

On Mon, Jul 6, 2009 at 11:20 AM, wstrzalka<wstrzalka(at)gmail(dot)com> wrote:
> After upgrading to 8.4 on Vista I see no progress on the shared memory
> problem unfortunately.
>
> I think it's even worse now (previously it happened mainly when OS
> went to sleep & then was restored, now it's all the time).
>
> My log looks like this.
> ----------------------------------------------------------------------------------------------------------------------------------------------
> FATAL:  could not reattach to shared memory (key=288, addr=02A00000):
> 487
> 2009-07-06 11:39:45 CESTLOG:  could not receive data from client:
> Unknown winsock error 10061
> 2009-07-06 11:39:45 CESTLOG:  unexpected EOF on client connection
> FATAL:  could not reattach to shared memory (key=288, addr=02A00000):
> 487
> 2009-07-06 11:40:20 CESTLOG:  could not receive data from client:
> Unknown winsock error 10061
> 2009-07-06 11:40:20 CESTLOG:  unexpected EOF on client connection
> 2009-07-06 11:40:20 CESTLOG:  could not receive data from client:
> Unknown winsock error 10061
> 2009-07-06 11:40:20 CESTLOG:  unexpected EOF on client connection
> -----------------------------------------------------------------------------------------------------------------------------------------------
>
> Our application runs on Linux in the production environment, but all
> the developers works on Windows with local PG installations. Some of
> them are getting the error - some don't.
> .
> It's really big problem explaining to the people that PG is really
> good database.
>
> Is there any chance to do something with it?

We'd love to, but noone with Windows development experience and
familiarity with how PostgreSQL works has yet to be able to reproduce
the problem. As you have a some people that are affected and some that
aren't, perhaps you can help figure out what triggers the bug. Can you
tell if there is any distinguishing factor between the two groups?
Maybe installation options chosen, other software that's installed
(particularly anti-virus or firewall packages), windows service pack
level, domain membership, particular hardware?

--
Dave Page
EnterpriseDB UK: http://www.enterprisedb.com

No really a pattern.
I'm sure PG is installed in standard pure version everywhere.
No domains at all.
The rest is really custom (we are working remotely - each of us with
different hardware, OS, software, etc...).
Maybe the intel dual core has smth to do about it ?

Those are affected:

My machine is:
Latitude D620, T7200, 3GB RAM, Vista Business SP2, NOD32 3.2, Windows Firewall

Guy 1:
Latitude D620, T7200, 2GB RAM, XP Prof SP3, NOD32 3.2, OutpostFirewall

Guy 2:
HP T5600 3GB RAM,XP SP2, F-Internet Security 2009

Guy 3: Acer (2 core also!!), 4GB RAM, Vista Sp2, Norton Ativirus

Which is 4 of 8 in the team.

On 8.3 it's usable - the bug is there,
but we are using pooling so it retries several times and then keeps
the connection - the problem is when you try psql ...

With 8.4 it's almost impossible to connect.

> On Mon, Jul 6, 2009 at 11:20 AM, wstrzalka<wstrzalka(at)gmail(dot)com> wrote:
>> After upgrading to 8.4 on Vista I see no progress on the shared memory
>> problem unfortunately.
>>
>> I think it's even worse now (previously it happened mainly when OS
>> went to sleep & then was restored, now it's all the time).
>>
>> My log looks like this.
>> ----------------------------------------------------------------------------------------------------------------------------------------------
>> FATAL:  could not reattach to shared memory (key=288, addr=02A00000):
>> 487
>> 2009-07-06 11:39:45 CESTLOG:  could not receive data from client:
>> Unknown winsock error 10061
>> 2009-07-06 11:39:45 CESTLOG:  unexpected EOF on client connection
>> FATAL:  could not reattach to shared memory (key=288, addr=02A00000):
>> 487
>> 2009-07-06 11:40:20 CESTLOG:  could not receive data from client:
>> Unknown winsock error 10061
>> 2009-07-06 11:40:20 CESTLOG:  unexpected EOF on client connection
>> 2009-07-06 11:40:20 CESTLOG:  could not receive data from client:
>> Unknown winsock error 10061
>> 2009-07-06 11:40:20 CESTLOG:  unexpected EOF on client connection
>> -----------------------------------------------------------------------------------------------------------------------------------------------
>>
>> Our application runs on Linux in the production environment, but all
>> the developers works on Windows with local PG installations. Some of
>> them are getting the error - some don't.
>> .
>> It's really big problem explaining to the people that PG is really
>> good database.
>>
>> Is there any chance to do something with it?

> We'd love to, but noone with Windows development experience and
> familiarity with how PostgreSQL works has yet to be able to reproduce
> the problem. As you have a some people that are affected and some that
> aren't, perhaps you can help figure out what triggers the bug. Can you
> tell if there is any distinguishing factor between the two groups?
> Maybe installation options chosen, other software that's installed
> (particularly anti-virus or firewall packages), windows service pack
> level, domain membership, particular hardware?

--
Pozdrowienia,
Wojciech Strzalka

All of the machines are laptops. Maybe some power management stuff ?

> On Mon, Jul 6, 2009 at 11:20 AM, wstrzalka<wstrzalka(at)gmail(dot)com> wrote:
>> After upgrading to 8.4 on Vista I see no progress on the shared memory
>> problem unfortunately.
>>
>> I think it's even worse now (previously it happened mainly when OS
>> went to sleep & then was restored, now it's all the time).
>>
>> My log looks like this.
>> ----------------------------------------------------------------------------------------------------------------------------------------------
>> FATAL:  could not reattach to shared memory (key=288, addr=02A00000):
>> 487
>> 2009-07-06 11:39:45 CESTLOG:  could not receive data from client:
>> Unknown winsock error 10061
>> 2009-07-06 11:39:45 CESTLOG:  unexpected EOF on client connection
>> FATAL:  could not reattach to shared memory (key=288, addr=02A00000):
>> 487
>> 2009-07-06 11:40:20 CESTLOG:  could not receive data from client:
>> Unknown winsock error 10061
>> 2009-07-06 11:40:20 CESTLOG:  unexpected EOF on client connection
>> 2009-07-06 11:40:20 CESTLOG:  could not receive data from client:
>> Unknown winsock error 10061
>> 2009-07-06 11:40:20 CESTLOG:  unexpected EOF on client connection
>> -----------------------------------------------------------------------------------------------------------------------------------------------
>>
>> Our application runs on Linux in the production environment, but all
>> the developers works on Windows with local PG installations. Some of
>> them are getting the error - some don't.
>> .
>> It's really big problem explaining to the people that PG is really
>> good database.
>>
>> Is there any chance to do something with it?

> We'd love to, but noone with Windows development experience and
> familiarity with how PostgreSQL works has yet to be able to reproduce
> the problem. As you have a some people that are affected and some that
> aren't, perhaps you can help figure out what triggers the bug. Can you
> tell if there is any distinguishing factor between the two groups?
> Maybe installation options chosen, other software that's installed
> (particularly anti-virus or firewall packages), windows service pack
> level, domain membership, particular hardware?

--
Pozdrowienia,
Wojciech Strzalka

2009/7/6 Wojciech Strzałka <wstrzalka(at)gmail(dot)com>:
>
>  No really a pattern.
>  I'm sure PG is installed in standard pure version everywhere.
>  No domains at all.
>  The rest is really custom (we are working remotely - each of us with
>  different hardware, OS, software, etc...).
>  Maybe the intel dual core has smth to do about it ?

I run a core 2 duo and have never seen any problems. I don't exactly
hammer the server though.

>  Those are affected:
>
>  My machine is:
>  Latitude D620, T7200, 3GB RAM, Vista Business SP2, NOD32 3.2, Windows Firewall
>
>  Guy 1:
>  Latitude D620, T7200, 2GB RAM, XP Prof SP3, NOD32 3.2, OutpostFirewall
>
>  Guy 2:
>  HP T5600 3GB RAM,XP SP2, F-Internet Security 2009
>
>  Guy 3: Acer (2 core also!!), 4GB RAM, Vista Sp2, Norton Ativirus
>
>
>  Which is 4 of 8 in the team.

What about those that don't see the problem? I'll grant you those 4
are pretty different though.

--
Dave Page
EnterpriseDB UK: http://www.enterprisedb.com

Wojciech Strza?ka wrote:

> All of the machines are laptops. Maybe some power management stuff ?

I experienced problems with the Standby mode (that was with pg8.2 and XPSP2).
But since this is a workstation I just stopped using the Standby mode.

I never looked into the log files but what happened was that the CPU went up
100% and the complete system was unresponsive when it was woken up (the
Taskmanager showed that a Postgres process was using the CPU). I had to reboot
the machine every time this happened. This was not reproducable (in fact it
happened maybe one in 10 times).

I never investigated this, because I thought that Postgres was not supposed to
support the Standby mode, since a database server normally runs 24 hour a day.

Rainer

In my case standby mode only increases the frequency - problem occurs
also on clean machine - right after startup.
8.4 is totally unusable on my vista. I had to downgrade back to 8.3

I've just uninstalled antivirus & disabled windows firewall - no
effect.
The strange is that subsequent requests does not behave the same -
some are succesfull, some don't.

I'll set debug level to max - maybe there will be something
interesting.

On 6 Lip, 15:47, Rainer Bauer <use(dot)(dot)(dot)(at)munnin(dot)com> wrote:
> Wojciech Strza?ka wrote:
> > All of the machines are laptops. Maybe some power management stuff ?
>
> I experienced problems with the Standby mode (that was with pg8.2 and XPSP2).
> But since this is a workstation I just stopped using the Standby mode.
>
> I never looked into the log files but what happened was that the CPU went up
> 100% and the complete system was unresponsive when it was woken up (the
> Taskmanager showed that a Postgres process was using the CPU). I had to reboot
> the machine every time this happened. This was not reproducable (in fact it
> happened maybe one in 10 times).
>
> I never investigated this, because I thought that Postgres was not supposed to
> support the Standby mode, since a database server normally runs 24 hour a day.
>
> Rainer

I don't suppose this explains anything but - why not to try (this is
DEBUG and has more details, but looks like some information are less detailed than in
INFO log level ?? (ie. socket error code is missing):

2009-07-06 23:31:12 CEST DEBUG: 00000: shmem_exit(0)
2009-07-06 23:31:12 CEST LOCATION: shmem_exit, .\src\backend\storage\ipc\ipc.c:164
2009-07-06 23:31:12 CEST DEBUG: 00000: exit(0)
2009-07-06 23:31:12 CEST LOCATION: proc_exit, .\src\backend\storage\ipc\ipc.c:116
2009-07-06 23:31:12 CEST DEBUG: 00000: forked new backend, pid=1468 socket=944
2009-07-06 23:31:12 CEST LOCATION: BackendStartup, .\src\backend\postmaster\postmaster.c:2850
2009-07-06 23:31:12 CEST DEBUG: 00000: reaping dead processes
2009-07-06 23:31:12 CEST LOCATION: reaper, .\src\backend\postmaster\postmaster.c:2082
2009-07-06 23:31:12 CEST DEBUG: 00000: server process (PID 3096) exited with exit code 0
2009-07-06 23:31:12 CEST LOCATION: LogChildExit, .\src\backend\postmaster\postmaster.c:2509
2009-07-06 23:31:12 CEST DEBUG: 00000: forked new backend, pid=7868 socket=908
2009-07-06 23:31:12 CEST LOCATION: BackendStartup, .\src\backend\postmaster\postmaster.c:2850
FATAL: could not reattach to shared memory (key=248, addr=02100000): 487
2009-07-06 23:31:12 CEST LOG: 00000: loaded library "$libdir/plugins/plugin_debugger.dll"
2009-07-06 23:31:12 CEST LOCATION: load_libraries, .\src\backend\utils\init\miscinit.c:1187
2009-07-06 23:31:12 CEST DEBUG: 00000: postgres child[7868]: starting with (
2009-07-06 23:31:12 CEST LOCATION: BackendRun, .\src\backend\postmaster\postmaster.c:3198
2009-07-06 23:31:12 CEST DEBUG: 00000: postgres
2009-07-06 23:31:12 CEST LOCATION: BackendRun, .\src\backend\postmaster\postmaster.c:3201
2009-07-06 23:31:12 CEST DEBUG: 00000: -v196608
2009-07-06 23:31:12 CEST LOCATION: BackendRun, .\src\backend\postmaster\postmaster.c:3201
2009-07-06 23:31:12 CEST DEBUG: 00000: -y
2009-07-06 23:31:12 CEST LOCATION: BackendRun, .\src\backend\postmaster\postmaster.c:3201
2009-07-06 23:31:12 CEST DEBUG: 00000: onebigdb
2009-07-06 23:31:12 CEST LOCATION: BackendRun, .\src\backend\postmaster\postmaster.c:3201
2009-07-06 23:31:12 CEST DEBUG: 00000: )
2009-07-06 23:31:12 CEST LOCATION: BackendRun, .\src\backend\postmaster\postmaster.c:3203
2009-07-06 23:31:12 CEST DEBUG: 00000: InitPostgres
2009-07-06 23:31:12 CEST LOCATION: PostgresMain, .\src\backend\tcop\postgres.c:3347
2009-07-06 23:31:12 CEST DEBUG: 00000: reaping dead processes
2009-07-06 23:31:12 CEST LOCATION: reaper, .\src\backend\postmaster\postmaster.c:2082
2009-07-06 23:31:12 CEST DEBUG: 00000: server process (PID 1468) exited with exit code 1
2009-07-06 23:31:12 CEST LOCATION: LogChildExit, .\src\backend\postmaster\postmaster.c:2509
2009-07-06 23:31:12 CEST DEBUG: 00000: StartTransaction

Is there any way I could help with problem investigation?

Maybe some prepared version with extra debug.

Setting up build env. looks quite crazy but I could try
with some help (this will take quite long time assuming my free time,
but if there is no other way ...).

> 2009/7/6 Wojciech Strzałka <wstrzalka(at)gmail(dot)com>:
>>
>>  No really a pattern.
>>  I'm sure PG is installed in standard pure version everywhere.
>>  No domains at all.
>>  The rest is really custom (we are working remotely - each of us with
>>  different hardware, OS, software, etc...).
>>  Maybe the intel dual core has smth to do about it ?

> I run a core 2 duo and have never seen any problems. I don't exactly
> hammer the server though.

>>  Those are affected:
>>
>>  My machine is:
>>  Latitude D620, T7200, 3GB RAM, Vista Business SP2, NOD32 3.2, Windows Firewall
>>
>>  Guy 1:
>>  Latitude D620, T7200, 2GB RAM, XP Prof SP3, NOD32 3.2, OutpostFirewall
>>
>>  Guy 2:
>>  HP T5600 3GB RAM,XP SP2, F-Internet Security 2009
>>
>>  Guy 3: Acer (2 core also!!), 4GB RAM, Vista Sp2, Norton Ativirus
>>
>>
>>  Which is 4 of 8 in the team.

> What about those that don't see the problem? I'll grant you those 4
> are pretty different though.

--
Pozdrowienia,
Wojciech Strzałka

Wojciech Strzałka escribió:
>
> I don't suppose this explains anything but - why not to try (this is
> DEBUG and has more details, but looks like some information are less detailed than in
> INFO log level ?? (ie. socket error code is missing):

I suggest you add %p to log_line_prefix to differentiate log lines for
various processes. Also perhaps you want to set log_error_verbosity to
VERBOSE to see more details about each message.

Since it has been suggested that the problem may be caused by DLLs
loaded or not by the processes, I suggest you try to find out which ones
are attached to each process, when it works and when it doesn't. Is
there a difference?

--
Alvaro Herrera http://www.CommandPrompt.com/
PostgreSQL Replication, Consulting, Custom Development, 24x7 support

2009/7/6 Alvaro Herrera <alvherre(at)commandprompt(dot)com>:
> Wojciech Strzałka escribió:
>>
>> I don't suppose this explains anything but - why not to try (this is
>> DEBUG and has more details, but looks like some information are less detailed than in
>> INFO log level ?? (ie. socket error code is missing):
>
> I suggest you add %p to log_line_prefix to differentiate log lines for
> various processes.  Also perhaps you want to set log_error_verbosity to
> VERBOSE to see more details about each message.
>
> Since it has been suggested that the problem may be caused by DLLs
> loaded or not by the processes, I suggest you try to find out which ones
> are attached to each process, when it works and when it doesn't.  Is
> there a difference?

Also, try removing the plugin_debugger.dll from
shared_preload_libraries in postgresql.conf to eliminate that from the
equation.

--
Dave Page
EnterpriseDB UK: http://www.enterprisedb.com

Here ( http://www.codelabs.pl/_varia/pg.zip ) is detailed info from
my machine (PostgreSQL 8.3.6, compiled by Visual C++ build 1400):

- detailed log file with several memory attach problems
- process activity log file (created by Process Monitor from SysInternals)
- dll's loaded by postgres.exe (snapshot only)

Maybe by comparing log entries you will be able to tell smth.

Still there is not much info in the pg log file (my config file in
package).

Removing plugin_debugger.dll didn't helped.


> 2009/7/6 Alvaro Herrera <alvherre(at)commandprompt(dot)com>:
>> Wojciech Strzałka escribió:
>>>
>>> I don't suppose this explains anything but - why not to try (this is
>>> DEBUG and has more details, but looks like some information are less detailed than in
>>> INFO log level ?? (ie. socket error code is missing):
>>
>> I suggest you add %p to log_line_prefix to differentiate log lines for
>> various processes.  Also perhaps you want to set log_error_verbosity to
>> VERBOSE to see more details about each message.
>>
>> Since it has been suggested that the problem may be caused by DLLs
>> loaded or not by the processes, I suggest you try to find out which ones
>> are attached to each process, when it works and when it doesn't.  Is
>> there a difference?

> Also, try removing the plugin_debugger.dll from
> shared_preload_libraries in postgresql.conf to eliminate that from the
> equation.

--
Pozdrowienia,
Wojciech Strzałka

2009/7/7 Wojciech Strzałka <wstrzalka(at)gmail(dot)com>:
>
>  Here ( http://www.codelabs.pl/_varia/pg.zip ) is detailed info from
>  my machine (PostgreSQL 8.3.6, compiled by Visual C++ build 1400):
>
>  - detailed log file with several memory attach problems
>  - process activity log file (created by Process Monitor from SysInternals)
>  - dll's loaded by postgres.exe (snapshot only)
>
>  Maybe by comparing log entries you will be able to tell smth.

I can't spot anything obviously wrong (other than the original error
of course). My only suggestion right now is that we try putting a
retry loop in PGSharedMemoryReAttach() and see if the error is a
transient thing.

Any other ideas?

--
Dave Page
EnterpriseDB UK: http://www.enterprisedb.com

Sorry if what i'm talking is completely silly, but
the error code (ERROR_INVALID_ADDRESS - 487 (0x1E7)) returned from
MapViewOfFileEx suggest the ShMem address is wrong. The Windows
error codes are usually not really helpfull but
can we log the UsedShmemSegAddr and UsedShmemSegID in
PGSharedMemoryCreate and maybe also on successful PGSharedMemoryReAttach
in DEBUG log level?

> 2009/7/7 Wojciech Strzałka <wstrzalka(at)gmail(dot)com>:
>>
>>  Here ( http://www.codelabs.pl/_varia/pg.zip ) is detailed info from
>>  my machine (PostgreSQL 8.3.6, compiled by Visual C++ build 1400):
>>
>>  - detailed log file with several memory attach problems
>>  - process activity log file (created by Process Monitor from SysInternals)
>>  - dll's loaded by postgres.exe (snapshot only)
>>
>>  Maybe by comparing log entries you will be able to tell smth.

> I can't spot anything obviously wrong (other than the original error
> of course). My only suggestion right now is that we try putting a
> retry loop in PGSharedMemoryReAttach() and see if the error is a
> transient thing.

> Any other ideas?

--
Pozdrowienia,
Wojciech Strzałka

2009/7/7 Wojciech Strzałka <wstrzalka(at)gmail(dot)com>:
>
>   Sorry if what i'm talking is completely silly, but
>   the error code (ERROR_INVALID_ADDRESS - 487 (0x1E7)) returned from
>   MapViewOfFileEx suggest the ShMem address is wrong. The Windows
>   error codes are usually not really helpfull but
>   can we log the UsedShmemSegAddr and UsedShmemSegID in
>   PGSharedMemoryCreate and maybe also on successful PGSharedMemoryReAttach
>   in DEBUG log level?

We could, but I don't see how it could be wrong, as it's only set in
PGSharedMemoryCreate and when we pass it down from postmaster to
backend. If something we're being stomped on there, I'd expect it to
be a more random problem.

<reads code some more>

Although, the reattach does get called almost immediately following
the backend variables being read, so maybe they are getting clobbered,
and it's pretty much always shows up in the re-mapping of the shared
memory.

What distribution are you running? I'll see if I can hack up a build
with the extra debugging, but I need to get the integer_datetimes
option right for your database.

--
Dave Page
EnterpriseDB UK: http://www.enterprisedb.com

I think both 8.3 & 8.4 are from EnterpriseDB (the integer_datetime
is 'off' at least in 8.3 which is active at the time).

Don't hesitate too much - reinstalling binaries with dump & restore of
data is not a problem whatever version you'll send to me.

> 2009/7/7 Wojciech Strzałka <wstrzalka(at)gmail(dot)com>:
>>
>>   Sorry if what i'm talking is completely silly, but
>>   the error code (ERROR_INVALID_ADDRESS - 487 (0x1E7)) returned from
>>   MapViewOfFileEx suggest the ShMem address is wrong. The Windows
>>   error codes are usually not really helpfull but
>>   can we log the UsedShmemSegAddr and UsedShmemSegID in
>>   PGSharedMemoryCreate and maybe also on successful PGSharedMemoryReAttach
>>   in DEBUG log level?

> We could, but I don't see how it could be wrong, as it's only set in
> PGSharedMemoryCreate and when we pass it down from postmaster to
> backend. If something we're being stomped on there, I'd expect it to
> be a more random problem.

> <reads code some more>

> Although, the reattach does get called almost immediately following
> the backend variables being read, so maybe they are getting clobbered,
> and it's pretty much always shows up in the re-mapping of the shared
> memory.

> What distribution are you running? I'll see if I can hack up a build
> with the extra debugging, but I need to get the integer_datetimes
> option right for your database.

--
Pozdrowienia,
Wojciech Strzałka

2009/7/7 Wojciech Strzałka <wstrzalka(at)gmail(dot)com>:
>
>  I think both 8.3 & 8.4 are from EnterpriseDB (the integer_datetime
>  is 'off' at least in 8.3 which is active at the time).

OK, I put a zip of a server build at
http://uploads.enterprisedb.com/download.php?file=fc168613430d6c1bf756036466963a5f

It's PG84, and includes some DEBUG2's in PGSharedMemoryCreate,
PGSharedMemoryReAttach and restore_backend_variables, all prefixed
with ***

It should work with the dependencies that come with the 8.4 installer
- it'll probably be easiest to just drop in postgres.exe to an
existing installation.

--
Dave Page
EnterpriseDB UK: http://www.enterprisedb.com

Witam!

W liście datowanym 7 lipca 2009 (18:02:30) napisano:

> 2009/7/7 Wojciech Strzałka <wstrzalka(at)gmail(dot)com>:
>>
>>  I think both 8.3 & 8.4 are from EnterpriseDB (the integer_datetime
>>  is 'off' at least in 8.3 which is active at the time).

> OK, I put a zip of a server build at
> http://uploads.enterprisedb.com/download.php?file=fc168613430d6c1bf756036466963a5f

I was wondering why I can not see the DEBUG2 info you were talking
about (tripple star), and probably that's another bug.
Whichever debug1 - debug5 level I set in config file the pg_settings
tells me that it's set to 'debug' (without a number) - and there is
no info you mentioned in config file.

I can set log level to 'debug5' (as well as back to 'debug' using SET but it's only to current session.

The more strange is that 'debug' is not officialy supported value by
this param. Probably it's some legacy setting hanging there and log parser applies it
before whole word is read (if it makes sense)?


What do you say about it? Please change the triple star to eg. INFO
level or take a look at logging level to be able to go forward with
the original problem.

----------------------------------------------
postgres=# set log_min_error_statement = 'debug'; <--- this is strange
SET
postgres=# set log_min_error_statement = 'debug1';
SET
postgres=# set log_min_error_statement = 'debug6';
ERROR: invalid value for parameter "log_min_error_statement": "debug6"
-------------------------------------------------

> It's PG84, and includes some DEBUG2's in PGSharedMemoryCreate,
> PGSharedMemoryReAttach and restore_backend_variables, all prefixed
> with ***

> It should work with the dependencies that come with the 8.4 installer
> - it'll probably be easiest to just drop in postgres.exe to an
> existing installation.

--
Pozdrowienia,
Wojciech Strzałka

2009/7/8 Wojciech Strzałka <wstrzalka(at)gmail(dot)com>:

>  I was wondering why I can not see the DEBUG2 info you were talking
>  about (tripple star), and probably that's another bug.
>  Whichever debug1 - debug5 level I set in config file the pg_settings
>  tells me that it's set to 'debug' (without a number) - and there is
>  no info you mentioned in config file.

Yeah, I'm not sure what blackhole that's going down.

>  What do you say about it? Please change the triple star to eg. INFO
>  level or take a look at logging level to be able to go forward with
>  the original problem.

The stars are just text in the message. I tried using elog(INFO...)
but that didn't work either. Not sure why, and I don't really have
time to figure that out. fprintf(stderr...) does work for me however,
please try this:
http://uploads.enterprisedb.com/download.php?file=e91d1a36ea6e32bc7a867fd27d70e597

--
Dave Page
EnterpriseDB UK: http://www.enterprisedb.com

Witam!

W liście datowanym 8 lipca 2009 (13:55:00) napisano:

> 2009/7/8 Wojciech Strzałka <wstrzalka(at)gmail(dot)com>:

>>  I was wondering why I can not see the DEBUG2 info you were talking
>>  about (tripple star), and probably that's another bug.
>>  Whichever debug1 - debug5 level I set in config file the pg_settings
>>  tells me that it's set to 'debug' (without a number) - and there is
>>  no info you mentioned in config file.

> Yeah, I'm not sure what blackhole that's going down.

Looks like not only MySQL has blackhole storage engine ;)

And the result is:

2009-07-08 14:26:00 CEST PID:9612 DEBUG: 00000: forked new backend, pid=8120 socket=948
2009-07-08 14:26:00 CEST PID:9612 LOCATION: BackendStartup, .\src\backend\postmaster\postmaster.c:3029
*** Finished restoring shared memory vars in restore_backend_variables (key=256, addr=02400000)
FATAL: could not reattach to shared memory (key=256, addr=02400000): 487
2009-07-08 14:26:00 CEST PID:9612 DEBUG: 00000: reaping dead processes
2009-07-08 14:26:00 CEST PID:9612 LOCATION: reaper, .\src\backend\postmaster\postmaster.c:2184
2009-07-08 14:26:00 CEST PID:9612 DEBUG: 00000: server process (PID 8120) exited with exit code 1
2009-07-08 14:26:00 CEST PID:9612 LOCATION: LogChildExit, .\src\backend\postmaster\postmaster.c:2653
2009-07-08 14:26:01 CEST PID:9612 DEBUG: 00000: forked new backend, pid=9952 socket=948
2009-07-08 14:26:01 CEST PID:9612 LOCATION: BackendStartup, .\src\backend\postmaster\postmaster.c:3029
*** Finished restoring shared memory vars in restore_backend_variables (key=256, addr=02400000)
*** Finished reattaching shared memory segment in PGSharedMemoryReAttach (key=256, addr=02400000)
2009-07-08 14:26:01 CEST PID:9952 DEBUG: 00000: postgres child[9952]: starting with (
2009-07-08 14:26:01 CEST PID:9952 LOCATION: BackendRun, .\src\backend\postmaster\postmaster.c:3384
2009-07-08 14:26:01 CEST PID:9952 DEBUG: 00000: postgres
2009-07-08 14:26:01 CEST PID:9952 LOCATION: BackendRun, .\src\backend\postmaster\postmaster.c:3387
2009-07-08 14:26:01 CEST PID:9952 DEBUG: 00000: -v196608
2009-07-08 14:26:01 CEST PID:9952 LOCATION: BackendRun, .\src\backend\postmaster\postmaster.c:3387
2009-07-08 14:26:01 CEST PID:9952 DEBUG: 00000: -y
2009-07-08 14:26:01 CEST PID:9952 LOCATION: BackendRun, .\src\backend\postmaster\postmaster.c:3387
2009-07-08 14:26:01 CEST PID:9952 DEBUG: 00000: masterdb
2009-07-08 14:26:01 CEST PID:9952 LOCATION: BackendRun, .\src\backend\postmaster\postmaster.c:3387
2009-07-08 14:26:01 CEST PID:9952 DEBUG: 00000: )
2009-07-08 14:26:01 CEST PID:9952 LOCATION: BackendRun, .\src\backend\postmaster\postmaster.c:3389
2009-07-08 14:26:01 CEST PID:9952 DEBUG: 00000: InitPostgres
2009-07-08 14:26:01 CEST PID:9952 LOCATION: PostgresMain, .\src\backend\tcop\postgres.c:3333
2009-07-08 14:26:01 CEST PID:9952 DEBUG: 00000: my backend id is 5
2009-07-08 14:26:01 CEST PID:9952 LOCATION: SharedInvalBackendInit, .\src\backend\storage\ipc\sinvaladt.c:316
2009-07-08 14:26:01 CEST PID:9952 DEBUG: 00000: StartTransaction
2009-07-08 14:26:01 CEST PID:9952 LOCATION: ShowTransactionState, .\src\backend\access\transam\xact.c:4073
2009-07-08 14:26:01 CEST PID:9952 DEBUG: 00000: name: unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2009-07-08 14:26:01 CEST PID:9952 LOCATION: ShowTransactionStateRec, .\src\backend\access\transam\xact.c:4111
2009-07-08 14:26:01 CEST PID:9952 DEBUG: 00000: CommitTransaction
2009-07-08 14:26:01 CEST PID:9952 LOCATION: ShowTransactionState, .\src\backend\access\transam\xact.c:4073
2009-07-08 14:26:01 CEST PID:9952 DEBUG: 00000: name: unnamed; blockState: STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2009-07-08 14:26:01 CEST PID:9952 LOCATION: ShowTransactionStateRec, .\src\backend\access\transam\xact.c:4111
2009-07-08 14:26:01 CEST PID:9952 DEBUG: 00000: parse <unnamed>: SHOW TRANSACTION ISOLATION LEVEL
2009-07-08 14:26:01 CEST PID:9952 LOCATION: exec_parse_message, .\src\backend\tcop\postgres.c:1117
2009-07-08 14:26:01 CEST PID:9952 STATEMENT: SHOW TRANSACTION ISOLATION LEVEL

--
Pozdrowienia,
Wojciech Strzałka

Dave Page <dpage(at)pgadmin(dot)org> wrote:
> 2009/7/7 Wojciech Strzałka <wstrzalka(at)gmail(dot)com>:
> >
> >  Here ( http://www.codelabs.pl/_varia/pg.zip ) is detailed info from
> >  my machine (PostgreSQL 8.3.6, compiled by Visual C++ build 1400):
> >
> >  - detailed log file with several memory attach problems
> >  - process activity log file (created by Process Monitor from SysInternals)
> >  - dll's loaded by postgres.exe (snapshot only)
> >
> >  Maybe by comparing log entries you will be able to tell smth.
>
> I can't spot anything obviously wrong (other than the original error
> of course). My only suggestion right now is that we try putting a
> retry loop in PGSharedMemoryReAttach() and see if the error is a
> transient thing.
>
> Any other ideas?

Hello,

When failed to reattach, how about the memory regions ?

For instance, do Sleep() when reattach failed, and check the memory by VMMap.
(from SysInternals)
# Of course, it becomes only for debugging.

I think the region to be used as Shared Memory might be used as Heap.
compare with the parent process.

I don't know why the Heap region moves.
- the order of which DLL is loaded ?
- Heap size is changed ?

I think this error often occurs when postmater receives a lot of requests.
In our environment, we can reproduce error by following tests.
# AMD Opteron 850 (4 processor) + Windows Server 2008

(Windows server)
postgresql.conf
max_connections = 300

(*nix client)
export PGHOST=WINDOWS
export PGUSER=postgres
while :; do
pgbench -n -c 250 || break
done
# maybe fail in 3 to 5 loops

Though the topic changes a little, we are testing about this problem.

In the past, there was the thread about this problem,
and it suggested using VirtualAllocEx().
(But no patch was posted, right?)
http://archives.postgresql.org/pgsql-general/2007-08/msg01592.php

So I tries using VirtualAllocEx().
By this fix, the problem doesn't occur in testing by pgbench.

However, I cannot explain why the memory region was changed,
and cannot guarantee that all problems are solved.

FYI, my patch is put up.
Sorry for large patch, it has too many debug codes.

* postmaster.c
In internal_forkexec(), reserve shared memory region before ResumeThread().

* win32_shmem.c
new function to do VirtualAllocEx()
PGSharedMemoryReAttach() free reserved region before MapViewOfFileEx()

* DEBUG code
if define DEBUG_VQ, outputs info about memory regions to stderr.
(Sorry, it is not so useful...)

if define DEBUG_VQ_DONT_RESERV,
don't call VirtualAllocEx()/VirtualFree(), so it works as original
with debug-outs.
This do Sleep() when reattach fail.

regards,

--
Tsutomu Yamada
SRA OSS, Inc. Japan

When the server starts, it should also spew out the initial shmem
segment ID and address - did you get them? They may go to stderr
rather than the log, because they're output so early in the startup. I
assume they're the same because one of the attaches seems to work
fine.

2009/7/8 Wojciech Strzałka <wstrzalka(at)gmail(dot)com>:
> And the result is:
>
> 2009-07-08 14:26:00 CEST PID:9612 DEBUG:  00000: forked new backend, pid=8120 socket=948
> 2009-07-08 14:26:00 CEST PID:9612 LOCATION:  BackendStartup, .\src\backend\postmaster\postmaster.c:3029
> *** Finished restoring shared memory vars in restore_backend_variables (key=256, addr=02400000)
> FATAL:  could not reattach to shared memory (key=256, addr=02400000): 487
> 2009-07-08 14:26:00 CEST PID:9612 DEBUG:  00000: reaping dead processes
> 2009-07-08 14:26:00 CEST PID:9612 LOCATION:  reaper, .\src\backend\postmaster\postmaster.c:2184
> 2009-07-08 14:26:00 CEST PID:9612 DEBUG:  00000: server process (PID 8120) exited with exit code 1
> 2009-07-08 14:26:00 CEST PID:9612 LOCATION:  LogChildExit, .\src\backend\postmaster\postmaster.c:2653
> 2009-07-08 14:26:01 CEST PID:9612 DEBUG:  00000: forked new backend, pid=9952 socket=948
> 2009-07-08 14:26:01 CEST PID:9612 LOCATION:  BackendStartup, .\src\backend\postmaster\postmaster.c:3029
> *** Finished restoring shared memory vars in restore_backend_variables (key=256, addr=02400000)
> *** Finished reattaching shared memory segment in PGSharedMemoryReAttach (key=256, addr=02400000)
> 2009-07-08 14:26:01 CEST PID:9952 DEBUG:  00000: postgres child[9952]: starting with (
> 2009-07-08 14:26:01 CEST PID:9952 LOCATION:  BackendRun, .\src\backend\postmaster\postmaster.c:3384
> 2009-07-08 14:26:01 CEST PID:9952 DEBUG:  00000:        postgres
> 2009-07-08 14:26:01 CEST PID:9952 LOCATION:  BackendRun, .\src\backend\postmaster\postmaster.c:3387
> 2009-07-08 14:26:01 CEST PID:9952 DEBUG:  00000:        -v196608
> 2009-07-08 14:26:01 CEST PID:9952 LOCATION:  BackendRun, .\src\backend\postmaster\postmaster.c:3387
> 2009-07-08 14:26:01 CEST PID:9952 DEBUG:  00000:        -y
> 2009-07-08 14:26:01 CEST PID:9952 LOCATION:  BackendRun, .\src\backend\postmaster\postmaster.c:3387
> 2009-07-08 14:26:01 CEST PID:9952 DEBUG:  00000:        masterdb
> 2009-07-08 14:26:01 CEST PID:9952 LOCATION:  BackendRun, .\src\backend\postmaster\postmaster.c:3387
> 2009-07-08 14:26:01 CEST PID:9952 DEBUG:  00000: )
> 2009-07-08 14:26:01 CEST PID:9952 LOCATION:  BackendRun, .\src\backend\postmaster\postmaster.c:3389
> 2009-07-08 14:26:01 CEST PID:9952 DEBUG:  00000: InitPostgres
> 2009-07-08 14:26:01 CEST PID:9952 LOCATION:  PostgresMain, .\src\backend\tcop\postgres.c:3333
> 2009-07-08 14:26:01 CEST PID:9952 DEBUG:  00000: my backend id is 5
> 2009-07-08 14:26:01 CEST PID:9952 LOCATION:  SharedInvalBackendInit, .\src\backend\storage\ipc\sinvaladt.c:316
> 2009-07-08 14:26:01 CEST PID:9952 DEBUG:  00000: StartTransaction
> 2009-07-08 14:26:01 CEST PID:9952 LOCATION:  ShowTransactionState, .\src\backend\access\transam\xact.c:4073
> 2009-07-08 14:26:01 CEST PID:9952 DEBUG:  00000: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 2009-07-08 14:26:01 CEST PID:9952 LOCATION:  ShowTransactionStateRec, .\src\backend\access\transam\xact.c:4111
> 2009-07-08 14:26:01 CEST PID:9952 DEBUG:  00000: CommitTransaction
> 2009-07-08 14:26:01 CEST PID:9952 LOCATION:  ShowTransactionState, .\src\backend\access\transam\xact.c:4073
> 2009-07-08 14:26:01 CEST PID:9952 DEBUG:  00000: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
> 2009-07-08 14:26:01 CEST PID:9952 LOCATION:  ShowTransactionStateRec, .\src\backend\access\transam\xact.c:4111
> 2009-07-08 14:26:01 CEST PID:9952 DEBUG:  00000: parse <unnamed>: SHOW TRANSACTION ISOLATION LEVEL
> 2009-07-08 14:26:01 CEST PID:9952 LOCATION:  exec_parse_message, .\src\backend\tcop\postgres.c:1117
> 2009-07-08 14:26:01 CEST PID:9952 STATEMENT:  SHOW TRANSACTION ISOLATION LEVEL
>
>
>
> --
> Pozdrowienia,
>  Wojciech Strzałka
>
>

--
Dave Page
EnterpriseDB UK: http://www.enterprisedb.com

On Wed, Jul 8, 2009 at 2:03 PM, Tsutomu Yamada<tsutomu(at)sraoss(dot)co(dot)jp> wrote:

> In the past, there was the thread about this problem,
> and it suggested using VirtualAllocEx().
> (But no patch was posted, right?)
> http://archives.postgresql.org/pgsql-general/2007-08/msg01592.php
>
> So I tries using VirtualAllocEx().
> By this fix, the problem doesn't occur in testing by pgbench.
>
> However, I cannot explain why the memory region was changed,
> and cannot guarantee that all problems are solved.

Ooh, interesting. I put a patched build at
http://uploads.enterprisedb.com/download.php?file=abb85b99acc1cf1668e3ff35bdb665ee

It has DEBUG_VQ defined. Wojciech - can you give it a try please?

Thanks Yamada-san.

--
Dave Page
EnterpriseDB UK: http://www.enterprisedb.com

Looks very good by now.

I'll test the version for a few days in my regular work and will
post more feedback here.

On 8 Lip, 17:37, dp(dot)(dot)(dot)(at)pgadmin(dot)org (Dave Page) wrote:
> On Wed, Jul 8, 2009 at 2:03 PM, Tsutomu Yamada<tsut(dot)(dot)(dot)(at)sraoss(dot)co(dot)jp> wrote:
> > In the past, there was the thread about this problem,
> > and it suggested using VirtualAllocEx().
> > (But no patch was posted, right?)
> >http://archives.postgresql.org/pgsql-general/2007-08/msg01592.php
>
> > So I tries using VirtualAllocEx().
> > By this fix, the problem doesn't occur in testing by pgbench.
>
> > However, I cannot explain why the memory region was changed,
> > and cannot guarantee that all problems are solved.
>
> Ooh, interesting. I put a patched build athttp://uploads.enterprisedb.com/download.php?file=abb85b99acc1cf1668e...
>
> It has DEBUG_VQ defined. Wojciech - can you give it a try please?
>
> Thanks Yamada-san.
>
> --
> Dave Page
> EnterpriseDB UK:  http://www.enterprisedb.com
>
> --
> Sent via pgsql-bugs mailing list (pgsql-b(dot)(dot)(dot)(at)postgresql(dot)org)
> To make changes to your subscription:http://www.postgresql.org/mailpref/pgsql-bugs

So as promised - the patch is very stable. No more memory problems,
neither any other issues.

Great job Yamada-san!!!!

Dave - can I assume you'll manage this fix to be pushed to official
release?

On 9 Lip, 17:08, wstrzalka <wstrza(dot)(dot)(dot)(at)gmail(dot)com> wrote:
>   Looks very good by now.
>
>   I'll test the version for a few days in my regular work and will
> post more feedback here.
>
> On 8 Lip, 17:37, dp(dot)(dot)(dot)(at)pgadmin(dot)org (Dave Page) wrote:
>
> > On Wed, Jul 8, 2009 at 2:03 PM, Tsutomu Yamada<tsut(dot)(dot)(dot)(at)sraoss(dot)co(dot)jp> wrote:
> > > In the past, there was the thread about this problem,
> > > and it suggested using VirtualAllocEx().
> > > (But no patch was posted, right?)
> > >http://archives.postgresql.org/pgsql-general/2007-08/msg01592.php
>
> > > So I tries using VirtualAllocEx().
> > > By this fix, the problem doesn't occur in testing by pgbench.
>
> > > However, I cannot explain why the memory region was changed,
> > > and cannot guarantee that all problems are solved.
>
> > Ooh, interesting. I put a patched build athttp://uploads.enterprisedb.com/download.php?file=abb85b99acc1cf1668e...
>
> > It has DEBUG_VQ defined. Wojciech - can you give it a try please?
>
> > Thanks Yamada-san.
>
> > --
> > Dave Page
> > EnterpriseDB UK:  http://www.enterprisedb.com
>
> > --
> > Sent via pgsql-bugs mailing list (pgsql-b(dot)(dot)(dot)(at)postgresql(dot)org)
> > To make changes to your subscription:http://www.postgresql.org/mailpref/pgsql-bugs