[HACKERS] postmaster in a tight loop

2008-02-12 Thread Dan Langille

Folks,

I encountered a situation on Sunday night where the postmaster was in  
a tight
loop.  That's the conclusion we reached, but have no real proof.  I  
also have no
idea how to reproduce this situation.  This post is just an FYI in  
case it helps.


The laptop was running hot so I looked around and found pgsql to be  
the cause.

I decided to shutdown the postmaster, but it would not shutdown:

# /usr/local/etc/rc.d/postgresql stop
pg_ctl: server does not shut down

After that, I started looking closer.

For starters, here is what the system looked like:

$ date
Sun Feb 10 19:38:10 EST 2008


$ ps auwx | grep pgsql
pgsql   1172 90.0  0.4 44636  3088  ??  Rs   10:45AM  21:55.16 / 
usr/local/bin/postgres -D /usr/local/pgsql/data
pgsql   1183  0.0  0.4 44652  3392  ??  Ss   10:45AM   0:06.77  
postgres: writer process(postgres)
pgsql   1184  0.0  0.4 44652  3176  ??  Ss   10:45AM   0:04.42  
postgres: wal writer process(postgres)
pgsql   1185  0.0  0.4 44884  3336  ??  Ss   10:45AM   0:03.35  
postgres: autovacuum launcher process(postgres)
pgsql   1186  0.0  0.4  8588  3060  ??  Ss   10:45AM   0:03.77  
postgres: stats collector process(postgres)


A little bit from top:

last pid: 89359;  load averages:  3.10,  2.84,   
2.30   
up 0+08:53:20  19:37:54

84 processes:  5 running, 79 sleeping
CPU states: 48.3% user,  0.8% nice, 50.8% system,  0.0% interrupt,   
0.0% idle

Mem: 306M Active, 235M Inact, 104M Wired, 27M Cache, 85M Buf, 68M Free
Swap: 512M Total, 512M Free

  PID USERNAMETHR PRI NICE   SIZERES STATETIME   WCPU  
COMMAND
 1172 pgsql 1 1300 44636K  3088K RUN 22:18 77.34%  
postgres

 1387 root  1 1000 85936K 62032K RUN 10:48  4.49% Xorg
89357 dan   1   80  1860K  1424K wait 0:00  1.00% sh
46507 dan   1  960 15636K  9900K select   1:52  0.05%  
npviewer.bin
88563 dan   1  960 28856K 21128K RUN  0:01  0.05%  
kdeinit


$ uname -a
FreeBSD laptop.unixathome.org 6.3-PRERELEASE FreeBSD 6.3-PRERELEASE  
#2: Wed Nov  7 10:54:48 EST 2007 [EMAIL PROTECTED]:/usr/obj/usr/src/sys/ 
PCBSD  i386


Running PostgreSQL 8.3.0

Looking at ktrace output, I saw a lot of this:

1172 postgres CALL  kse_release(0xbfbfd500)
1172 postgres RET   kse_release -1 errno 22 Invalid argument

The ldd output for postgres is:

[EMAIL PROTECTED]:/usr/home/dan] $ ldd /usr/local/bin/postgres
/usr/local/bin/postgres:
libintl.so.8 = /usr/local/lib/libintl.so.8 (0x2835a000)
libxml2.so.5 = /usr/local/lib/libxml2.so.5 (0x28363000)
libssl.so.4 = /usr/lib/libssl.so.4 (0x2846f000)
libcrypto.so.4 = /lib/libcrypto.so.4 (0x2849d000)
libcrypt.so.3 = /lib/libcrypt.so.3 (0x2859)
libm.so.4 = /lib/libm.so.4 (0x285a8000)
libpthread.so.2 = /lib/libpthread.so.2 (0x285be000)
libc.so.6 = /lib/libc.so.6 (0x285e3000)
libiconv.so.3 = /usr/local/lib/libiconv.so.3 (0x286c9000)
libz.so.3 = /lib/libz.so.3 (0x287b6000)
[EMAIL PROTECTED]:/usr/home/dan] $

The server was compiled with these options:

[EMAIL PROTECTED]:~] $ less /var/db/ports/postgresql83/options
# This file is auto-generated by 'make config'.
# No user-servicable parts inside!
# Options for postgresql-client-8.3.0
_OPTIONS_READ=postgresql-client-8.3.0
WITH_NLS=true
WITHOUT_PAM=true
WITHOUT_LDAP=true
WITHOUT_MIT_KRB5=true
WITHOUT_HEIMDAL_KRB5=true
WITHOUT_OPTIMIZED_CFLAGS=true
WITH_XML=true
WITH_TZDATA=true
WITHOUT_DEBUG=true
WITHOUT_INTDATE=true
[EMAIL PROTECTED]:~] $



--
Dan Langille -- http://www.langille.org/
[EMAIL PROTECTED]





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


Re: [HACKERS] postmaster in a tight loop

2008-02-12 Thread Tom Lane
Alvaro Herrera [EMAIL PROTECTED] writes:
 I find it a bit worrying that the postmaster is calling that syscall at
 all.

Yeah.  Misguided thread-aware library perhaps?

Next time please try to get a stack trace.

regards, tom lane

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

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


Re: [HACKERS] postmaster in a tight loop

2008-02-12 Thread Alvaro Herrera
Dan Langille wrote:

 Looking at ktrace output, I saw a lot of this:

 1172 postgres CALL  kse_release(0xbfbfd500)
 1172 postgres RET   kse_release -1 errno 22 Invalid argument

Humm, kse_release seems related to multithreading.  Or so says
http://nixdoc.net/man-pages/FreeBSD/kse_release.2.html

I find it a bit worrying that the postmaster is calling that syscall at
all.

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

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