[postgis-users] Re: Help: Performance of spatial query
Jeremy Palmer
jpalmer at paradise.net.nz
Sun Mar 28 01:55:57 PST 2004
David Blasby <dblasby at refractions.net> wrote:
>It could be, but its unlikely.
>The easiest way to find out would be to:
>1. compile PostGIS with the -g option (to get debug information in it)
>2. make sure valgrind is installed on your system
>3. run the postmaster with valgrind (ie. "valgrind postmaster -D ...")
>4. run your query
>5. see where valgrind says it died.
Thanks David,
I followed the steps you outlined and this is what valgrind gave from the
time I started the server:
bash-2.05b$ valgrind --leak-check=yes postmaster -D /mnt/lib/pgsql/data -d 5
==2965== Memcheck, a.k.a. Valgrind, a memory error detector for x86-linux.
==2965== Copyright (C) 2002, and GNU GPL'd, by Julian Seward.
==2965== Using valgrind-1.9.6, a program instrumentation system for
x86-linux.
==2965== Copyright (C) 2000-2002, and GNU GPL'd, by Julian Seward.
==2965== Estimated CPU clock rate is 852 MHz
==2965== For more details, rerun with: -v
==2965==
DEBUG: postmaster: PostmasterMain: initial environ dump:
DEBUG: -----------------------------------------
DEBUG: HOSTNAME=Death
DEBUG: TERM=xterm
DEBUG: SHELL=/bin/bash
DEBUG: HISTSIZE=1000
DEBUG: SSH_CLIENT=192.168.0.10 2239 22
DEBUG:
LD_PRELOAD=/usr/lib/valgrind/vgskin_memcheck.so:/usr/lib/valgrind/valgrind.s
o:
DEBUG: QTDIR=/usr/lib/qt-3.1
DEBUG: SSH_TTY=/dev/pts/3
DEBUG: VG_ARGS= --suppressions=/usr/lib/valgrind/default.supp
--leak-check=yes
DEBUG: USER=postgres
DEBUG: LD_LIBRARY_PATH=/usr/lib/valgrind:
DEBUG:
LS_COLORS=no=00:fi=00:di=00;34:ln=00;36:pi=40;33:so=00;35:bd=40;33;01:cd=40;
33;01:or=01;05;37;41:mi=01;05;37;41:ex=00;32:*.cmd=00;32:*.exe=00;32:*.com=0
0;32:*.btm=00;32:*.bat=00;32:*.sh=00;32:*.csh=00;32:*.tar=00;31:*.tgz=00;31:
*.arj=00;31:*.taz=00;31:*.lzh=00;31:*.zip=00;31:*.z=00;31:*.Z=00;31:*.gz=00;
31:*.bz2=00;31:*.bz=00;31:*.tz=00;31:*.rpm=00;31:*.cpio=00;31:*.jpg=00;35:*.
gif=00;35:*.bmp=00;35:*.xbm=00;35:*.xpm=00;35:*.png=00;35:*.tif=00;35:
DEBUG: USERNAME=root
DEBUG: MAIL=/var/spool/mail/root
DEBUG:
PATH=/usr/local/sbin:/usr/local/bin:/sbin:/bin:/usr/sbin:/usr/bin:/usr/X11R6
/bin:/root/bin
DEBUG: INPUTRC=/etc/inputrc
DEBUG: PWD=/root
DEBUG: LANG=en_NZ.UTF-8
DEBUG: SSH_ASKPASS=/usr/libexec/openssh/gnome-ssh-askpass
DEBUG: SHLVL=2
DEBUG: HOME=/var/lib/pgsql
DEBUG: LD_ASSUME_KERNEL=2.2.5
DEBUG: BASH_ENV=/root/.bashrc
DEBUG: LOGNAME=postgres
DEBUG: SSH_CONNECTION=192.168.0.10 2239 192.168.0.2 22
DEBUG: LESSOPEN=|/usr/bin/lesspipe.sh %s
DEBUG: G_BROKEN_FILENAMES=1
DEBUG: -----------------------------------------
DEBUG: searching PATH for executable
DEBUG: could not stat "/usr/local/sbin/postgres": No such file or directory
DEBUG: could not stat "/usr/local/bin/postgres": No such file or directory
DEBUG: could not stat "/sbin/postgres": No such file or directory
DEBUG: could not stat "/bin/postgres": No such file or directory
DEBUG: could not stat "/usr/sbin/postgres": No such file or directory
DEBUG: found "/usr/bin/postgres" using PATH
LOG: could not create IPv6 socket: Address family not supported by protocol
DEBUG: invoking IpcMemoryCreate(size=10436608)
DEBUG: max_safe_fds = 985, usable_fds = 1019, already_open = 5
DEBUG: searching PATH for executable
DEBUG: could not stat "/usr/local/sbin/postmaster": No such file or
directory
DEBUG: could not stat "/usr/local/bin/postmaster": No such file or
directory
DEBUG: could not stat "/sbin/postmaster": No such file or directory
DEBUG: could not stat "/bin/postmaster": No such file or directory
DEBUG: could not stat "/usr/sbin/postmaster": No such file or directory
DEBUG: found "/usr/bin/postmaster" using PATH
LOG: database system was shut down at 2004-03-29 09:37:31 NZST
LOG: checkpoint record is at 5/64A34EC4
LOG: redo record is at 5/64A34EC4; undo record is at 0/0; shutdown TRUE
LOG: next transaction ID: 54815; next OID: 76331865
LOG: database system is ready
DEBUG: proc_exit(0)
DEBUG: shmem_exit(0)
DEBUG: exit(0)
==2969== discard syms in /lib/libnss_files-2.3.2.so due to munmap()
==2969==
==2969== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 2 from 1)
==2969== malloc/free: in use at exit: 72643 bytes in 85 blocks.
==2969== malloc/free: 437 allocs, 352 frees, 207956 bytes allocated.
==2969== For counts of detected errors, rerun with: -v
==2969== searching for pointers to 85 not-freed blocks.
==2969== checked 17271268 bytes.
==2969==
==2969== 35 bytes in 1 blocks are definitely lost in loss record 5 of 21
==2969== at 0x40163791: malloc (in /usr/lib/valgrind/valgrind.so)
==2969== by 0x4036139F: __GI___strdup (in /lib/libc-2.3.2.so)
==2969== by 0x81E78B3: (within /usr/bin/postgres)
==2969== by 0x81E7952: CreateDataDirLockFile (in /usr/bin/postgres)
==2969==
==2969== 112 bytes in 1 blocks are possibly lost in loss record 10 of 21
==2969== at 0x40163791: malloc (in /usr/lib/valgrind/valgrind.so)
==2969== by 0x81EE134: save_ps_display_args (in /usr/bin/postgres)
==2969== by 0x811E18F: main (in /usr/bin/postgres)
==2969== by 0x402FCAB6: __libc_start_main (in /lib/libc-2.3.2.so)
==2969==
==2969== LEAK SUMMARY:
==2969== definitely lost: 35 bytes in 1 blocks.
==2969== possibly lost: 112 bytes in 1 blocks.
==2969== still reachable: 72496 bytes in 83 blocks.
==2969== suppressed: 0 bytes in 0 blocks.
==2969== Reachable blocks (those to which a pointer was found) are not
shown.
==2969== To see them, rerun with: --show-reachable=yes
==2969==
DEBUG: reaping dead processes
DEBUG: forked new backend, pid=2972 socket=8
DEBUG: postmaster child[2972]: starting with (
DEBUG: postgres
DEBUG: -d5
DEBUG: -v196608
DEBUG: -p
DEBUG: auditdb
DEBUG: )
DEBUG: InitPostgres
DEBUG: StartTransactionCommand
LOG: statement: SELECT NOD1.id as nod_id1,
NOD2.id as nod_id2
FROM node NOD1,
node NOD2
WHERE NOD1.shape && expand(BOX3D(NOD2.shape),0.000002)
AND distance(NOD1.shape, NOD2.shape) <= 0.000002
AND NOD1.id < NOD2.id
==2970== Syscall param write(buf) contains uninitialised or unaddressable
byte(s)
==2970== at 0x403BD198: __GI___libc_write (in /lib/libc-2.3.2.so)
==2970== by 0x4035410D: new_do_write (in /lib/libc-2.3.2.so)
==2970== by 0x403540A5: _IO_do_write@@GLIBC_2.1 (in /lib/libc-2.3.2.so)
==2970== by 0x403539E7: _IO_file_close_it@@GLIBC_2.1 (in
/lib/libc-2.3.2.so)
==2970== Address 0x40225009 is not stack'd, malloc'd or free'd
DEBUG: parse tree:
DETAIL: {QUERY :commandType 1 :querySource 0 :canSetTag true :utilityStmt
<>
:resultRelation 0 :into <> :hasAggs false :hasSubLinks false :rtable
({RTE
:alias {ALIAS :aliasname nod1 :colnames <>} :eref {ALIAS :aliasname
nod1
:colnames ("id" "shape")} :rtekind 0 :relid 76215473 :inh true
:inFromCl true
:checkForRead true :checkForWrite false :checkAsUser 0} {RTE :alias
{ALIAS
:aliasname nod2 :colnames <>} :eref {ALIAS :aliasname nod2 :colnames
("id"
"shape")} :rtekind 0 :relid 76215473 :inh true :inFromCl true
:checkForRead
true :checkForWrite false :checkAsUser 0}) :jointree {FROMEXPR
:fromlist
({RANGETBLREF :rtindex 1} {RANGETBLREF :rtindex 2}) :quals {BOOLEXPR
:boolop
and :args ({BOOLEXPR :boolop and :args ({OPEXPR :opno 17341
:opfuncid 0
:opresulttype 16 :opretset false :args ({VAR :varno 1 :varattno 2
:vartype
17165 :vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 2}
{FUNCEXPR :funcid
17201 :funcresulttype 17165 :funcretset false :funcformat 2 :args
({FUNCEXPR
:funcid 17203 :funcresulttype 17149 :funcretset false :funcformat 0
:args
({FUNCEXPR :funcid 17199 :funcresulttype 17149 :funcretset false
:funcformat 0
:args ({VAR :varno 2 :varattno 2 :vartype 17165 :vartypmod -1
:varlevelsup 0
:varnoold 2 :varoattno 2})} {FUNCEXPR :funcid 1746 :funcresulttype
701
:funcretset false :funcformat 2 :args ({CONST :consttype 1700
:constlen -1
:constbyval false :constisnull false :constvalue 10 [ 10 0 0 0 -2 -1
6 0 -56 0
]})})})})} {OPEXPR :opno 673 :opfuncid 0 :opresulttype 16 :opretset
false
:args ({FUNCEXPR :funcid 17255 :funcresulttype 701 :funcretset false
:funcformat 0 :args ({VAR :varno 1 :varattno 2 :vartype 17165
:vartypmod -1
:varlevelsup 0 :varnoold 1 :varoattno 2} {VAR :varno 2 :varattno 2
:vartype
17165 :vartypmod -1 :varlevelsup 0 :varnoold 2 :varoattno 2})}
{FUNCEXPR
:funcid 1746 :funcresulttype 701 :funcretset false :funcformat 2
:args ({CONST
:consttype 1700 :constlen -1 :constbyval false :constisnull false
:constvalue
10 [ 10 0 0 0 -2 -1 6 0 -56 0 ]})})})} {OPEXPR :opno 97 :opfuncid 0
:opresulttype 16 :opretset false :args ({VAR :varno 1 :varattno 1
:vartype 23
:vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 1} {VAR :varno 2
:varattno
1 :vartype 23 :vartypmod -1 :varlevelsup 0 :varnoold 2 :varoattno
1})})}}
:rowMarks () :targetList ({TARGETENTRY :resdom {RESDOM :resno 1
:restype 23
:restypmod -1 :resname nod_id1 :ressortgroupref 0 :resorigtbl
76215473
:resorigcol 1 :resjunk false} :expr {VAR :varno 1 :varattno 1
:vartype 23
:vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 1}} {TARGETENTRY
:resdom
{RESDOM :resno 2 :restype 23 :restypmod -1 :resname nod_id2
:ressortgroupref 0
:resorigtbl 76215473 :resorigcol 1 :resjunk false} :expr {VAR :varno
2
:varattno 1 :vartype 23 :vartypmod -1 :varlevelsup 0 :varnoold 2
:varoattno
1}}) :groupClause <> :havingQual <> :distinctClause <> :sortClause
<>
:limitOffset <> :limitCount <> :setOperations <> :resultRelations
()}
DEBUG: rewritten parse tree:
DETAIL: ({QUERY :commandType 1 :querySource 0 :canSetTag true :utilityStmt
<>
:resultRelation 0 :into <> :hasAggs false :hasSubLinks false :rtable
({RTE
:alias {ALIAS :aliasname nod1 :colnames <>} :eref {ALIAS :aliasname
nod1
:colnames ("id" "shape")} :rtekind 0 :relid 76215473 :inh true
:inFromCl true
:checkForRead true :checkForWrite false :checkAsUser 0} {RTE :alias
{ALIAS
:aliasname nod2 :colnames <>} :eref {ALIAS :aliasname nod2 :colnames
("id"
"shape")} :rtekind 0 :relid 76215473 :inh true :inFromCl true
:checkForRead
true :checkForWrite false :checkAsUser 0}) :jointree {FROMEXPR
:fromlist
({RANGETBLREF :rtindex 1} {RANGETBLREF :rtindex 2}) :quals {BOOLEXPR
:boolop
and :args ({BOOLEXPR :boolop and :args ({OPEXPR :opno 17341
:opfuncid 0
:opresulttype 16 :opretset false :args ({VAR :varno 1 :varattno 2
:vartype
17165 :vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 2}
{FUNCEXPR :funcid
17201 :funcresulttype 17165 :funcretset false :funcformat 2 :args
({FUNCEXPR
:funcid 17203 :funcresulttype 17149 :funcretset false :funcformat 0
:args
({FUNCEXPR :funcid 17199 :funcresulttype 17149 :funcretset false
:funcformat 0
:args ({VAR :varno 2 :varattno 2 :vartype 17165 :vartypmod -1
:varlevelsup 0
:varnoold 2 :varoattno 2})} {FUNCEXPR :funcid 1746 :funcresulttype
701
:funcretset false :funcformat 2 :args ({CONST :consttype 1700
:constlen -1
:constbyval false :constisnull false :constvalue 10 [ 10 0 0 0 -2 -1
6 0 -56 0
]})})})})} {OPEXPR :opno 673 :opfuncid 0 :opresulttype 16 :opretset
false
:args ({FUNCEXPR :funcid 17255 :funcresulttype 701 :funcretset false
:funcformat 0 :args ({VAR :varno 1 :varattno 2 :vartype 17165
:vartypmod -1
:varlevelsup 0 :varnoold 1 :varoattno 2} {VAR :varno 2 :varattno 2
:vartype
17165 :vartypmod -1 :varlevelsup 0 :varnoold 2 :varoattno 2})}
{FUNCEXPR
:funcid 1746 :funcresulttype 701 :funcretset false :funcformat 2
:args ({CONST
:consttype 1700 :constlen -1 :constbyval false :constisnull false
:constvalue
10 [ 10 0 0 0 -2 -1 6 0 -56 0 ]})})})} {OPEXPR :opno 97 :opfuncid 0
:opresulttype 16 :opretset false :args ({VAR :varno 1 :varattno 1
:vartype 23
:vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 1} {VAR :varno 2
:varattno
1 :vartype 23 :vartypmod -1 :varlevelsup 0 :varnoold 2 :varoattno
1})})}}
:rowMarks () :targetList ({TARGETENTRY :resdom {RESDOM :resno 1
:restype 23
:restypmod -1 :resname nod_id1 :ressortgroupref 0 :resorigtbl
76215473
:resorigcol 1 :resjunk false} :expr {VAR :varno 1 :varattno 1
:vartype 23
:vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 1}} {TARGETENTRY
:resdom
{RESDOM :resno 2 :restype 23 :restypmod -1 :resname nod_id2
:ressortgroupref 0
:resorigtbl 76215473 :resorigcol 1 :resjunk false} :expr {VAR :varno
2
:varattno 1 :vartype 23 :vartypmod -1 :varlevelsup 0 :varnoold 2
:varoattno
1}}) :groupClause <> :havingQual <> :distinctClause <> :sortClause
<>
:limitOffset <> :limitCount <> :setOperations <> :resultRelations
()})
DEBUG: plan:
DETAIL: {NESTLOOP :startup_cost 0.00 :total_cost 91110.33 :plan_rows
2500000
:plan_width 8 :targetlist ({TARGETENTRY :resdom {RESDOM :resno 1
:restype 23
:restypmod -1 :resname nod_id1 :ressortgroupref 0 :resorigtbl
76215473
:resorigcol 1 :resjunk false} :expr {VAR :varno 65000 :varattno 1
:vartype 23
:vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 1}} {TARGETENTRY
:resdom
{RESDOM :resno 2 :restype 23 :restypmod -1 :resname nod_id2
:ressortgroupref 0
:resorigtbl 76215473 :resorigcol 1 :resjunk false} :expr {VAR :varno
65001
:varattno 1 :vartype 23 :vartypmod -1 :varlevelsup 0 :varnoold 2
:varoattno
1}}) :qual <> :lefttree {SEQSCAN :startup_cost 0.00 :total_cost
475.00
:plan_rows 15000 :plan_width 36 :targetlist ({TARGETENTRY :resdom
{RESDOM
:resno 1 :restype 23 :restypmod -1 :resname <> :ressortgroupref 0
:resorigtbl
0 :resorigcol 0 :resjunk false} :expr {VAR :varno 2 :varattno 1
:vartype 23
:vartypmod -1 :varlevelsup 0 :varnoold 2 :varoattno 1}} {TARGETENTRY
:resdom
{RESDOM :resno 2 :restype 17165 :restypmod -1 :resname <>
:ressortgroupref 0
:resorigtbl 0 :resorigcol 0 :resjunk false} :expr {VAR :varno 2
:varattno 2
:vartype 17165 :vartypmod -1 :varlevelsup 0 :varnoold 2 :varoattno
2}}) :qual
<> :lefttree <> :righttree <> :initPlan <> :extParam () :allParam ()
:nParamExec 0 :scanrelid 2} :righttree {INDEXSCAN :startup_cost 0.00
:total_cost 6.01 :plan_rows 1 :plan_width 36 :targetlist
({TARGETENTRY :resdom
{RESDOM :resno 1 :restype 23 :restypmod -1 :resname <>
:ressortgroupref 0
:resorigtbl 0 :resorigcol 0 :resjunk false} :expr {VAR :varno 1
:varattno 1
:vartype 23 :vartypmod -1 :varlevelsup 0 :varnoold 1 :varoattno 1}}
{TARGETENTRY :resdom {RESDOM :resno 2 :restype 17165 :restypmod -1
:resname <>
:ressortgroupref 0 :resorigtbl 0 :resorigcol 0 :resjunk false} :expr
{VAR
:varno 1 :varattno 2 :vartype 17165 :vartypmod -1 :varlevelsup 0
:varnoold 1
:varoattno 2}}) :qual <> :lefttree <> :righttree <> :initPlan <>
:extParam ()
:allParam () :nParamExec 0 :scanrelid 1 :indxid ( 76230478)
:indxqual
(({OPEXPR :opno 17341 :opfuncid 17326 :opresulttype 16 :opretset
false :args
({VAR :varno 1 :varattno 1 :vartype 17165 :vartypmod -1 :varlevelsup
0
:varnoold 1 :varoattno 2} {FUNCEXPR :funcid 17201 :funcresulttype
17165
:funcretset false :funcformat 2 :args ({FUNCEXPR :funcid 17203
:funcresulttype
17149 :funcretset false :funcformat 0 :args ({FUNCEXPR :funcid 17199
:funcresulttype 17149 :funcretset false :funcformat 0 :args ({VAR
:varno 65001
:varattno 2 :vartype 17165 :vartypmod -1 :varlevelsup 0 :varnoold 2
:varoattno
2})} {CONST :consttype 701 :constlen 8 :constbyval false
:constisnull false
:constvalue 8 [ -115 -19 -75 -96 -9 -58 -64 62 ]})})})}))
:indxqualorig
(({OPEXPR :opno 17341 :opfuncid 17326 :opresulttype 16 :opretset
false :args
({VAR :varno 1 :varattno 2 :vartype 17165 :vartypmod -1 :varlevelsup
0
:varnoold 1 :varoattno 2} {FUNCEXPR :funcid 17201 :funcresulttype
17165
:funcretset false :funcformat 2 :args ({FUNCEXPR :funcid 17203
:funcresulttype
17149 :funcretset false :funcformat 0 :args ({FUNCEXPR :funcid 17199
:funcresulttype 17149 :funcretset false :funcformat 0 :args ({VAR
:varno 65001
:varattno 2 :vartype 17165 :vartypmod -1 :varlevelsup 0 :varnoold 2
:varoattno
2})} {CONST :consttype 701 :constlen 8 :constbyval false
:constisnull false
:constvalue 8 [ -115 -19 -75 -96 -9 -58 -64 62 ]})})})}))
:indxorderdir 0}
:initPlan <> :extParam () :allParam () :nParamExec 0 :jointype 0
:joinqual
({OPEXPR :opno 673 :opfuncid 296 :opresulttype 16 :opretset false
:args
({FUNCEXPR :funcid 17255 :funcresulttype 701 :funcretset false
:funcformat 0
:args ({VAR :varno 65000 :varattno 2 :vartype 17165 :vartypmod -1
:varlevelsup
0 :varnoold 1 :varoattno 2} {VAR :varno 65001 :varattno 2 :vartype
17165
:vartypmod -1 :varlevelsup 0 :varnoold 2 :varoattno 2})} {CONST
:consttype 701
:constlen 8 :constbyval false :constisnull false :constvalue 8 [
-115 -19 -75
-96 -9 -58 -64 62 ]})} {OPEXPR :opno 97 :opfuncid 66 :opresulttype
16
:opretset false :args ({VAR :varno 65000 :varattno 1 :vartype 23
:vartypmod -1
:varlevelsup 0 :varnoold 1 :varoattno 1} {VAR :varno 65001 :varattno
1
:vartype 23 :vartypmod -1 :varlevelsup 0 :varnoold 2 :varoattno
1})})}
DEBUG: PortalRun
DEBUG: proc_exit(0)
DEBUG: shmem_exit(0)
DEBUG: exit(0)
==2799== discard syms in /lib/libnss_files-2.3.2.so due to munmap()
==2799==
==2799== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 2 from 1)
==2799== malloc/free: in use at exit: 97243 bytes in 90 blocks.
==2799== malloc/free: 432 allocs, 342 frees, 133753 bytes allocated.
==2799== For counts of detected errors, rerun with: -v
==2799== searching for pointers to 90 not-freed blocks.
==2799== checked 17286104 bytes.
==2799==
==2799== 35 bytes in 1 blocks are definitely lost in loss record 7 of 23
==2799== at 0x40163791: malloc (in /usr/lib/valgrind/valgrind.so)
==2799== by 0x4036139F: __GI___strdup (in /lib/libc-2.3.2.so)
==2799== by 0x81E78B3: (within /usr/bin/postgres)
==2799== by 0x81E7952: CreateDataDirLockFile (in /usr/bin/postgres)
==2799==
==2799== 112 bytes in 1 blocks are possibly lost in loss record 12 of 23
==2799== at 0x40163791: malloc (in /usr/lib/valgrind/valgrind.so)
==2799== by 0x81EE134: save_ps_display_args (in /usr/bin/postgres)
==2799== by 0x811E18F: main (in /usr/bin/postgres)
==2799== by 0x402FCAB6: __libc_start_main (in /lib/libc-2.3.2.so)
==2799==
==2799== LEAK SUMMARY:
==2799== definitely lost: 35 bytes in 1 blocks.
==2799== possibly lost: 112 bytes in 1 blocks.
==2799== still reachable: 97096 bytes in 88 blocks.
==2799== suppressed: 0 bytes in 0 blocks.
==2799== Reachable blocks (those to which a pointer was found) are not
shown.
==2799== To see them, rerun with: --show-reachable=yes
==2799==
DEBUG: reaping dead processes
DEBUG: child process (PID 2799) exited with exit code 0
DEBUG: proc_exit(0)
DEBUG: shmem_exit(0)
DEBUG: exit(0)
DEBUG: reaping dead processes
DEBUG: child process (PID 2796) was terminated by signal 9
LOG: server process (PID 2796) was terminated by signal 9
LOG: terminating any other active server processes
DEBUG: sending SIGQUIT to process 2800
WARNING: terminating connection because of crash of another server process
DETAIL: The postmaster has commanded this server process to roll back the
current transaction and exit, because another server process exited
abnormally and possibly corrupted shared memory.
HINT: In a moment you should be able to reconnect to the database and
repeat your command.
==2800==
==2800== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 2 from 1)
==2800== malloc/free: in use at exit: 105190 bytes in 179 blocks.
==2800== malloc/free: 439 allocs, 260 frees, 134047 bytes allocated.
==2800== For counts of detected errors, rerun with: -v
==2800== searching for pointers to 179 not-freed blocks.
==2800== checked 17340524 bytes.
==2800==
==2800== 35 bytes in 1 blocks are definitely lost in loss record 14 of 42
==2800== at 0x40163791: malloc (in /usr/lib/valgrind/valgrind.so)
==2800== by 0x4036139F: __GI___strdup (in /lib/libc-2.3.2.so)
==2800== by 0x81E78B3: (within /usr/bin/postgres)
==2800== by 0x81E7952: CreateDataDirLockFile (in /usr/bin/postgres)
==2800==
==2800== LEAK SUMMARY:
==2800== definitely lost: 35 bytes in 1 blocks.
==2800== possibly lost: 0 bytes in 0 blocks.
==2800== still reachable: 105155 bytes in 178 blocks.
==2800== suppressed: 0 bytes in 0 blocks.
==2800== Reachable blocks (those to which a pointer was found) are not
shown.
==2800== To see them, rerun with: --show-reachable=yes
==2800==
DEBUG: reaping dead processes
DEBUG: child process (PID 2800) exited with exit code 1
LOG: all server processes terminated; reinitializing
DEBUG: shmem_exit(0)
DEBUG: invoking IpcMemoryCreate(size=10436608)
LOG: database system was interrupted at 2004-03-29 08:56:04 NZST
LOG: checkpoint record is at 5/632E2B8C
LOG: redo record is at 5/632E2B8C; undo record is at 0/0; shutdown TRUE
LOG: next transaction ID: 54810; next OID: 76231860
LOG: database system was not properly shut down; automatic recovery in
progress
LOG: record with zero length at 5/632E2BCC
LOG: redo is not required
LOG: database system is ready
DEBUG: proc_exit(0)
DEBUG: shmem_exit(0)
DEBUG: exit(0)
==2801== discard syms in /lib/libnss_files-2.3.2.so due to munmap()
==2801==
==2801== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 2 from 1)
==2801== malloc/free: in use at exit: 72679 bytes in 86 blocks.
==2801== malloc/free: 493 allocs, 407 frees, 372312 bytes allocated.
==2801== For counts of detected errors, rerun with: -v
==2801== searching for pointers to 86 not-freed blocks.
==2801== checked 17281228 bytes.
==2801==
==2801== 35 bytes in 1 blocks are definitely lost in loss record 5 of 22
==2801== at 0x40163791: malloc (in /usr/lib/valgrind/valgrind.so)
==2801== by 0x4036139F: __GI___strdup (in /lib/libc-2.3.2.so)
==2801== by 0x81E78B3: (within /usr/bin/postgres)
==2801== by 0x81E7952: CreateDataDirLockFile (in /usr/bin/postgres)
==2801==
==2801== 36 bytes in 1 blocks are definitely lost in loss record 7 of 22
==2801== at 0x40163791: malloc (in /usr/lib/valgrind/valgrind.so)
==2801== by 0x80999B1: SimpleLruInit (in /usr/bin/postgres)
==2801== by 0x8090BD2: CLOGShmemInit (in /usr/bin/postgres)
==2801== by 0x816A4AA: CreateSharedMemoryAndSemaphores (in
/usr/bin/postgres)
==2801==
==2801== 112 bytes in 1 blocks are possibly lost in loss record 11 of 22
==2801== at 0x40163791: malloc (in /usr/lib/valgrind/valgrind.so)
==2801== by 0x81EE134: save_ps_display_args (in /usr/bin/postgres)
==2801== by 0x811E18F: main (in /usr/bin/postgres)
==2801== by 0x402FCAB6: __libc_start_main (in /lib/libc-2.3.2.so)
==2801==
==2801== LEAK SUMMARY:
==2801== definitely lost: 71 bytes in 2 blocks.
==2801== possibly lost: 112 bytes in 1 blocks.
==2801== still reachable: 72496 bytes in 83 blocks.
==2801== suppressed: 0 bytes in 0 blocks.
==2801== Reachable blocks (those to which a pointer was found) are not
shown.
==2801== To see them, rerun with: --show-reachable=yes
==2801==
DEBUG: reaping dead processes
DEBUG: proc_exit(0)
DEBUG: shmem_exit(0)
DEBUG: exit(0)
==2804== discard syms in /lib/libnss_files-2.3.2.so due to munmap()
==2804==
==2804== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 2 from 1)
==2804== malloc/free: in use at exit: 97255 bytes in 89 blocks.
==2804== malloc/free: 470 allocs, 381 frees, 135509 bytes allocated.
==2804== For counts of detected errors, rerun with: -v
==2804== searching for pointers to 89 not-freed blocks.
==2804== checked 17286956 bytes.
==2804==
==2804== 35 bytes in 1 blocks are definitely lost in loss record 5 of 22
==2804== at 0x40163791: malloc (in /usr/lib/valgrind/valgrind.so)
==2804== by 0x4036139F: __GI___strdup (in /lib/libc-2.3.2.so)
==2804== by 0x81E78B3: (within /usr/bin/postgres)
==2804== by 0x81E7952: CreateDataDirLockFile (in /usr/bin/postgres)
==2804==
==2804== 36 bytes in 1 blocks are definitely lost in loss record 7 of 22
==2804== at 0x40163791: malloc (in /usr/lib/valgrind/valgrind.so)
==2804== by 0x80999B1: SimpleLruInit (in /usr/bin/postgres)
==2804== by 0x8090BD2: CLOGShmemInit (in /usr/bin/postgres)
==2804== by 0x816A4AA: CreateSharedMemoryAndSemaphores (in
/usr/bin/postgres)
==2804==
==2804== 112 bytes in 1 blocks are possibly lost in loss record 11 of 22
==2804== at 0x40163791: malloc (in /usr/lib/valgrind/valgrind.so)
==2804== by 0x81EE134: save_ps_display_args (in /usr/bin/postgres)
==2804== by 0x811E18F: main (in /usr/bin/postgres)
==2804== by 0x402FCAB6: __libc_start_main (in /lib/libc-2.3.2.so)
==2804==
==2804== LEAK SUMMARY:
==2804== definitely lost: 71 bytes in 2 blocks.
==2804== possibly lost: 112 bytes in 1 blocks.
==2804== still reachable: 97072 bytes in 86 blocks.
==2804== suppressed: 0 bytes in 0 blocks.
==2804== Reachable blocks (those to which a pointer was found) are not
shown.
==2804== To see them, rerun with: --show-reachable=yes
==2804==
DEBUG: reaping dead processes
DEBUG: child process (PID 2804) exited with exit code 0
DEBUG: proc_exit(0)
DEBUG: shmem_exit(0)
DEBUG: exit(0)
==2806== discard syms in /lib/libnss_files-2.3.2.so due to munmap()
==2806==
==2806== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 2 from 1)
==2806== malloc/free: in use at exit: 97255 bytes in 89 blocks.
==2806== malloc/free: 477 allocs, 388 frees, 135803 bytes allocated.
==2806== For counts of detected errors, rerun with: -v
==2806== searching for pointers to 89 not-freed blocks.
==2806== checked 17286956 bytes.
==2806==
==2806== 35 bytes in 1 blocks are definitely lost in loss record 5 of 22
==2806== at 0x40163791: malloc (in /usr/lib/valgrind/valgrind.so)
==2806== by 0x4036139F: __GI___strdup (in /lib/libc-2.3.2.so)
==2806== by 0x81E78B3: (within /usr/bin/postgres)
==2806== by 0x81E7952: CreateDataDirLockFile (in /usr/bin/postgres)
==2806==
==2806== 36 bytes in 1 blocks are definitely lost in loss record 7 of 22
==2806== at 0x40163791: malloc (in /usr/lib/valgrind/valgrind.so)
==2806== by 0x80999B1: SimpleLruInit (in /usr/bin/postgres)
==2806== by 0x8090BD2: CLOGShmemInit (in /usr/bin/postgres)
==2806== by 0x816A4AA: CreateSharedMemoryAndSemaphores (in
/usr/bin/postgres)
==2806==
==2806== 112 bytes in 1 blocks are possibly lost in loss record 11 of 22
==2806== at 0x40163791: malloc (in /usr/lib/valgrind/valgrind.so)
==2806== by 0x81EE134: save_ps_display_args (in /usr/bin/postgres)
==2806== by 0x811E18F: main (in /usr/bin/postgres)
==2806== by 0x402FCAB6: __libc_start_main (in /lib/libc-2.3.2.so)
==2806==
==2806== LEAK SUMMARY:
==2806== definitely lost: 71 bytes in 2 blocks.
==2806== possibly lost: 112 bytes in 1 blocks.
==2806== still reachable: 97072 bytes in 86 blocks.
==2806== suppressed: 0 bytes in 0 blocks.
==2806== Reachable blocks (those to which a pointer was found) are not
shown.
==2806== To see them, rerun with: --show-reachable=yes
==2806==
DEBUG: reaping dead processes
DEBUG: child process (PID 2806) exited with exit code 0
I'm not sure if this helps as I can't see any useful debug information when
the server crashes...
It maybe worth noting that I watched the postmaster process with TOP until
the crash. What I noticed was that the memory usage gradually increased
until it reached 95%, at which time postmaster then crashed.
Thanks Jeremy
More information about the postgis-users
mailing list