VACUUM ANALYZE Problem (debugging output)

Started by James Hughesabout 28 years ago3 messageshackers
Jump to latest
#1James Hughes
jamesh@interpath.com

Here is what I've been able to get so far. I don't see anything obvious.
But then, I don't really know what I'm looking for. One thing I do see
is that "pg_statistic" shows up in both situations ("\d city" and
"\dS").

If anyone can make sense of this and point me in the right direction...

-James

BTW: This is the 1-31 cvs tree

#0 0x400a9369 in __kill ()
#1 0x810a0a6 in elog (lev=-1,
fmt=0x813f1c8 "fmgr_info: function %d: cache lookup failed\n")
at elog.c:180
#2 0x810ac89 in fmgr_info (procedureId=0, finfo=0xbfffd5f4) at fmgr.c:179
#3 0x810ae0d in fmgr (procedureId=0) at fmgr.c:272
#4 0x806c080 in heapgettup (relation=0x81c6be8, tid=0x0, dir=1, b=0x827250c,
seeself=0 '\000', nkeys=3, key=0x8272550) at heapam.c:422

The code turns into a string of macros after this and I have problems
tracing it. I dumped as much information as I could from this frame...

(gdb) i arg
relation = 0x81c6be8
tid = 0x0
dir = 1
b = (Buffer *) 0x827250c
seeself = 0 '\000'
nkeys = 3
key = 0x8272550

(gdb) i loc
__isnull = 0 '\000'
__atp = 0
__test = 0
__cur_nkeys = 2
__cur_keys = 0x8272550
_tuple = 0x4017ac78
_res = 1 '\001'
tid = 0x0
seeself = 0 '\000'
lpp = 0x40178cd0
dp = 0x40178cc8 "4"
page = 0
pages = 1
lines = 1075293304
rtup = 0x0
lineoff = 0
linesleft = 10

(gdb) p *__cur_keys
$165 = {sk_flags = 0, sk_attno = 1, sk_procedure = 184, sk_func = {
fn_addr = 0, fn_plhandler = 0, fn_oid = 0, fn_nargs = 0}, sk_nargs =
0, sk_argument = 1249}

(gdb) p *_tuple
$166 = {t_len = 76, t_oid = 39712, t_cmin = 0, t_cmax = 0, t_xmin =
23647, t_xmax = 0, t_ctid = {ip_blkid = {bi_hi = 0, bi_lo = 0}, ip_posid =
1}, t_natts = 5, t_infomask = 2050, t_hoff = 40 '(', t_bits =
"\000\000\000"}

(gdb) p *lpp
$167 = {lp_off = 8112, lp_flags = 1, lp_len = 76}

(gdb) p *relation
$159 = {rd_fd = 16, rd_nblocks = 1, rd_refcnt = 44, rd_islocal = 0 '\000',
rd_isnailed = 0 '\000', rd_istemp = 0 '\000', rd_tmpunlinked = 0 '\000',
rd_am = 0x0, rd_rel = 0x81c6ae8, rd_id = 16577, lockInfo = 0x81c6d40 "\001",
rd_att = 0x81c6b40, rd_rules = 0x0, rd_istrat = 0x0, rd_support = 0x0,
trigdesc = 0x0}

(gdb) p *relation.rd_rel
$160 = {relname = {data = "pg_statistic", '\000' <repeats 19 times>},
reltype = 0, relowner = 406, relam = 0, relpages = 0, reltuples = 0,
relhasindex = 0 '\000', relisshared = 0 '\000', relkind = 114 'r',
relnatts = 5, relchecks = 0, reltriggers = 0, relhasrules = 0 '\000',
relacl = {2}}

(gdb) p *relation.rd_att
$161 = {natts = 5, attrs = 0x81c6a68, constr = 0x0}

(gdb) p **relation.rd_att.attrs
$163 = {attrelid = 16577, attname = {
data = "starelid", '\000' <repeats 23 times>}, atttypid = 26,
attdisbursion = 0, attlen = 4, attnum = 1, attnelems = 0, attcacheoff = 0,
atttypmod = 0, attbyval = 1 '\001', attisset = 0 '\000',
attalign = 0 '\000', attnotnull = 0 '\000', atthasdef = 0 '\000'}

(gdb) p *key
$164 = {sk_flags = 0, sk_attno = 1, sk_procedure = 184, sk_func = {
fn_addr = 0, fn_plhandler = 0, fn_oid = 0, fn_nargs = 0}, sk_nargs = 0,
sk_argument = 1249}

#5 0x806c841 in heap_getnext (scandesc=0x82724f8, backw=0, b=0x0)
at heapam.c:968
#6 0x8101285 in gethilokey (relid=1249, attnum=6, opid=520, high=0xbfffd720,
low=0xbfffd724) at selfuncs.c:353
#7 0x8100eee in intltsel (opid=520, relid=1249, attno=6, value=0, flag=3)
at selfuncs.c:113
#8 0x8101030 in intgtsel (opid=520, relid=1249, attno=6, value=0, flag=3)
at selfuncs.c:176
#9 0x810ab38 in fmgr_c (finfo=0xbfffd798, values=0xbfffd7a8,
isNull=0xbfffd797 "") at fmgr.c:115
#10 0x810ae53 in fmgr (procedureId=104) at fmgr.c:285
#11 0x80bbe38 in restriction_selectivity (functionObjectId=104,
operatorObjectId=520, relationObjectId=1249, attributeNumber=6,
constValue=0x0, constFlag=3) at plancat.c:344
#12 0x80b37e9 in compute_selec (root=0x826b980, clauses=0x8272478,
or_selectivities=0x0) at clausesel.c:319
#13 0x80b36ab in compute_clause_selec (root=0x826b980, clause=0x826fef8,
or_selectivities=0x0) at clausesel.c:199
#14 0x80b7ddc in add_clause_to_rels (root=0x826b980, clause=0x826fef8)
at initsplan.c:214
#15 0x80b7d2a in initialize_base_rels_jinfo (root=0x826b980, clauses=0x82700b0)
at initsplan.c:154
#16 0x80b82cb in subplanner (root=0x826b980, flat_tlist=0x8270190,
qual=0x82700b0) at planmain.c:249
#17 0x80b820b in query_planner (root=0x826b980, command_type=1,
tlist=0x826dd90, qual=0x826fe98) at planmain.c:168
#18 0x80b8842 in planner (parse=0x826b980) at planner.c:110
#19 0x80e5db4 in pg_parse_and_plan (
query_string=0xbfffda08 "SELECT a.attnum, a.attname, t.typname, a.attlen, a.atttypmod, a.attnotnull, a.atthasdef FROM pg_class c, pg_attribute a, pg_type t WHERE c.relname = 'city' and a.attnum > 0 and a.attrelid = c.o"...,
typev=0x0, nargs=0, queryListP=0xbfffd9a8, dest=Remote) at postgres.c:534
#20 0x80e5eb2 in pg_exec_query_dest (
query_string=0xbfffda08 "SELECT a.attnum, a.attname, t.typname, a.attlen, a.atttypmod, a.attnotnull, a.atthasdef FROM pg_class c, pg_attribute a, pg_type t WHERE c.relname = 'city' and a.attnum > 0 and a.attrelid = c.o"...,
argv=0x0, typev=0x0, nargs=0, dest=Remote) at postgres.c:615
#21 0x80e5e80 in pg_exec_query (
query_string=0xbfffda08 "SELECT a.attnum, a.attname, t.typname, a.attlen, a.atttypmod, a.attnotnull, a.atthasdef FROM pg_class c, pg_attribute a, pg_type t WHERE c.relname = 'city' and a.attnum > 0 and a.attrelid = c.o"...,
argv=0x0, typev=0x0, nargs=0) at postgres.c:597
#22 0x80e6c81 in PostgresMain (argc=9, argv=0xbffffa48) at postgres.c:1373
#23 0x80a91ed in main (argc=9, argv=0xbffffa48) at main.c:79
#24 0x806014e in _start ()

#2Bruce Momjian
bruce@momjian.us
In reply to: James Hughes (#1)
Re: [HACKERS] VACUUM ANALYZE Problem (debugging output)

I assume you have run initdb after doing the sup. Prior to the beta
release today, things could have changed in the database format.

Here is what I've been able to get so far. I don't see anything obvious.
But then, I don't really know what I'm looking for. One thing I do see
is that "pg_statistic" shows up in both situations ("\d city" and
"\dS").

If anyone can make sense of this and point me in the right direction...

-James

BTW: This is the 1-31 cvs tree

#0 0x400a9369 in __kill ()
#1 0x810a0a6 in elog (lev=-1,
fmt=0x813f1c8 "fmgr_info: function %d: cache lookup failed\n")
at elog.c:180
#2 0x810ac89 in fmgr_info (procedureId=0, finfo=0xbfffd5f4) at fmgr.c:179
#3 0x810ae0d in fmgr (procedureId=0) at fmgr.c:272
#4 0x806c080 in heapgettup (relation=0x81c6be8, tid=0x0, dir=1, b=0x827250c,
seeself=0 '\000', nkeys=3, key=0x8272550) at heapam.c:422

The code turns into a string of macros after this and I have problems
tracing it. I dumped as much information as I could from this frame...

(gdb) i arg
relation = 0x81c6be8
tid = 0x0
dir = 1
b = (Buffer *) 0x827250c
seeself = 0 '\000'
nkeys = 3
key = 0x8272550

(gdb) i loc
__isnull = 0 '\000'
__atp = 0
__test = 0
__cur_nkeys = 2
__cur_keys = 0x8272550
_tuple = 0x4017ac78
_res = 1 '\001'
tid = 0x0
seeself = 0 '\000'
lpp = 0x40178cd0
dp = 0x40178cc8 "4"
page = 0
pages = 1
lines = 1075293304
rtup = 0x0
lineoff = 0
linesleft = 10

(gdb) p *__cur_keys
$165 = {sk_flags = 0, sk_attno = 1, sk_procedure = 184, sk_func = {
fn_addr = 0, fn_plhandler = 0, fn_oid = 0, fn_nargs = 0}, sk_nargs =
0, sk_argument = 1249}

(gdb) p *_tuple
$166 = {t_len = 76, t_oid = 39712, t_cmin = 0, t_cmax = 0, t_xmin =
23647, t_xmax = 0, t_ctid = {ip_blkid = {bi_hi = 0, bi_lo = 0}, ip_posid =
1}, t_natts = 5, t_infomask = 2050, t_hoff = 40 '(', t_bits =
"\000\000\000"}

(gdb) p *lpp
$167 = {lp_off = 8112, lp_flags = 1, lp_len = 76}

(gdb) p *relation
$159 = {rd_fd = 16, rd_nblocks = 1, rd_refcnt = 44, rd_islocal = 0 '\000',
rd_isnailed = 0 '\000', rd_istemp = 0 '\000', rd_tmpunlinked = 0 '\000',
rd_am = 0x0, rd_rel = 0x81c6ae8, rd_id = 16577, lockInfo = 0x81c6d40 "\001",
rd_att = 0x81c6b40, rd_rules = 0x0, rd_istrat = 0x0, rd_support = 0x0,
trigdesc = 0x0}

(gdb) p *relation.rd_rel
$160 = {relname = {data = "pg_statistic", '\000' <repeats 19 times>},
reltype = 0, relowner = 406, relam = 0, relpages = 0, reltuples = 0,
relhasindex = 0 '\000', relisshared = 0 '\000', relkind = 114 'r',
relnatts = 5, relchecks = 0, reltriggers = 0, relhasrules = 0 '\000',
relacl = {2}}

(gdb) p *relation.rd_att
$161 = {natts = 5, attrs = 0x81c6a68, constr = 0x0}

(gdb) p **relation.rd_att.attrs
$163 = {attrelid = 16577, attname = {
data = "starelid", '\000' <repeats 23 times>}, atttypid = 26,
attdisbursion = 0, attlen = 4, attnum = 1, attnelems = 0, attcacheoff = 0,
atttypmod = 0, attbyval = 1 '\001', attisset = 0 '\000',
attalign = 0 '\000', attnotnull = 0 '\000', atthasdef = 0 '\000'}

(gdb) p *key
$164 = {sk_flags = 0, sk_attno = 1, sk_procedure = 184, sk_func = {
fn_addr = 0, fn_plhandler = 0, fn_oid = 0, fn_nargs = 0}, sk_nargs = 0,
sk_argument = 1249}

#5 0x806c841 in heap_getnext (scandesc=0x82724f8, backw=0, b=0x0)
at heapam.c:968
#6 0x8101285 in gethilokey (relid=1249, attnum=6, opid=520, high=0xbfffd720,
low=0xbfffd724) at selfuncs.c:353
#7 0x8100eee in intltsel (opid=520, relid=1249, attno=6, value=0, flag=3)
at selfuncs.c:113
#8 0x8101030 in intgtsel (opid=520, relid=1249, attno=6, value=0, flag=3)
at selfuncs.c:176
#9 0x810ab38 in fmgr_c (finfo=0xbfffd798, values=0xbfffd7a8,
isNull=0xbfffd797 "") at fmgr.c:115
#10 0x810ae53 in fmgr (procedureId=104) at fmgr.c:285
#11 0x80bbe38 in restriction_selectivity (functionObjectId=104,
operatorObjectId=520, relationObjectId=1249, attributeNumber=6,
constValue=0x0, constFlag=3) at plancat.c:344
#12 0x80b37e9 in compute_selec (root=0x826b980, clauses=0x8272478,
or_selectivities=0x0) at clausesel.c:319
#13 0x80b36ab in compute_clause_selec (root=0x826b980, clause=0x826fef8,
or_selectivities=0x0) at clausesel.c:199
#14 0x80b7ddc in add_clause_to_rels (root=0x826b980, clause=0x826fef8)
at initsplan.c:214
#15 0x80b7d2a in initialize_base_rels_jinfo (root=0x826b980, clauses=0x82700b0)
at initsplan.c:154
#16 0x80b82cb in subplanner (root=0x826b980, flat_tlist=0x8270190,
qual=0x82700b0) at planmain.c:249
#17 0x80b820b in query_planner (root=0x826b980, command_type=1,
tlist=0x826dd90, qual=0x826fe98) at planmain.c:168
#18 0x80b8842 in planner (parse=0x826b980) at planner.c:110
#19 0x80e5db4 in pg_parse_and_plan (
query_string=0xbfffda08 "SELECT a.attnum, a.attname, t.typname, a.attlen, a.atttypmod, a.attnotnull, a.atthasdef FROM pg_class c, pg_attribute a, pg_type t WHERE c.relname = 'city' and a.attnum > 0 and a.attrelid = c.o"...,
typev=0x0, nargs=0, queryListP=0xbfffd9a8, dest=Remote) at postgres.c:534
#20 0x80e5eb2 in pg_exec_query_dest (
query_string=0xbfffda08 "SELECT a.attnum, a.attname, t.typname, a.attlen, a.atttypmod, a.attnotnull, a.atthasdef FROM pg_class c, pg_attribute a, pg_type t WHERE c.relname = 'city' and a.attnum > 0 and a.attrelid = c.o"...,
argv=0x0, typev=0x0, nargs=0, dest=Remote) at postgres.c:615
#21 0x80e5e80 in pg_exec_query (
query_string=0xbfffda08 "SELECT a.attnum, a.attname, t.typname, a.attlen, a.atttypmod, a.attnotnull, a.atthasdef FROM pg_class c, pg_attribute a, pg_type t WHERE c.relname = 'city' and a.attnum > 0 and a.attrelid = c.o"...,
argv=0x0, typev=0x0, nargs=0) at postgres.c:597
#22 0x80e6c81 in PostgresMain (argc=9, argv=0xbffffa48) at postgres.c:1373
#23 0x80a91ed in main (argc=9, argv=0xbffffa48) at main.c:79
#24 0x806014e in _start ()

--
Bruce Momjian
maillist@candle.pha.pa.us

#3James Hughes
jamesh@interpath.com
In reply to: Bruce Momjian (#2)
Re: [HACKERS] VACUUM ANALYZE Problem (debugging output)

On Mon, 2 Feb 1998, Bruce Momjian wrote:

: I assume you have run initdb after doing the sup. Prior to the beta
: release today, things could have changed in the database format.
:

Yes. I always do a "make distclean", cvsup the latest code, build and
install everything, delete the data directory and start from scratch.

Everything works as expected until >>AFTER<< running "vacuum analyze"...

vtest=> \d

Database    = vtest
 +------------------+----------------------------------+----------+
 |  Owner           |             Relation             |   Type   |
 +------------------+----------------------------------+----------+
 | jamesh           | city                             | table    |
 | jamesh           | county                           | table    |
 | jamesh           | i_city                           | index    |
 | jamesh           | i_county                         | index    |
 | jamesh           | i_state                          | index    |
 | jamesh           | s_city                           | sequence |
 | jamesh           | s_county                         | sequence |
 | jamesh           | s_state                          | sequence |
 | jamesh           | state                            | table    |
 +------------------+----------------------------------+----------+
vtest=> \d city
Table    = city
+----------------------+-----------------------------+-------+
|  Field               |              Type           | Length|
+----------------------+-----------------------------+-------+
| serial               | int4                        |4      |
| county               | int4                        |4      |
| state                | int4                        |4      |
| addr1                | text                        |var    |
| addr2                | text                        |var    |
| name                 | text                        |var    |
| zip                  | text                        |var    |
| title                | text                        |var    |
| lname                | text                        |var    |
| fname                | text                        |var    |
| phone                | text                        |var    |
| fax                  | text                        |var    |
| notes                | text                        |var    |
+----------------------+-----------------------------+-------+
vtest=> 
vtest=> vacuum ;
VACUUM
vtest=> \d city
Table    = city
+----------------------+-----------------------------+-------+
|      Field           |           Type              |Length |
+----------------------+-----------------------------+-------+
| serial               | int4                        |4      |
| county               | int4                        |4      |
| state                | int4                        |4      |
| addr1                | text                        |var    |
| addr2                | text                        |var    |
| name                 | text                        |var    |
| zip                  | text                        |var    |
| title                | text                        |var    |
| lname                | text                        |var    |
| fname                | text                        |var    |
| phone                | text                        |var    |
| fax                  | text                        |var    |
| notes                | text                        |var    |
+----------------------+-----------------------------+-------+
vtest=> vacuum analyze;
VACUUM
vtest=> select * from city;
serial|county|state|addr1|addr2|name|zip|title|lname|fname|phone|fax|notes
------+------+-----+-----+-----+----+---+-----+-----+-----+-----+---+-----
(0 rows)

<< Exit & Run Perl Script To Populate Database >>

vtest=> select * from city;

...
10000565|10000098|10000000| | |Yadkinville | | |
| | | |
10000566|10000099|10000000| | |Burnsville | | |
| | | |
(567 rows)

vtest=> vacuum;
VACUUM

vtest=> \d city

Table    = city
+-----------------------+---------------------------+-------+
|      Field            |          Type             |Length |
+-----------------------+---------------------------+-------+
| serial                | int4                      |4      |
| county                | int4                      |4      |
| state                 | int4                      |4      |
| addr1                 | text ...
                                      ...           |var    |
+-----------------------+---------------------------+-------+
vtest=> vacuum analyze;
VACUUM
vtest=> \d city
ERROR:  fmgr_info: function 0: cache lookup failed

vtest=> \dS
ERROR: fmgr_info: function 0: cache lookup failed

-James