Re: Ouch .. VACUUM *is* killer ...

Wow, it finally came back:

NOTICE:  Rel ndict: Pages: 65736 --> 59893; Tuple(s) moved: 993304. CPU 1924.28s/0.00u sec.

Still processing, mind you, but at least I know its not hung up :)


On Wed, 17 May 2000, The Hermit Hacker wrote:

> 
> Wow, I thought the last guy that brought this up might be just unlucky
> (slower hardware then I've been running, etc) ... but, so far, my vacuum
> has been running for ~2.5hrs and *looks* stuck as far as 'vacuum verbose'
> shows, but files keep getting updated ...
> 
> ... I don't know if this gives you any more information then we've had in
> the past, or if this has been pretty much talked out, but figured one more
> report, that is still running live, can't hurt ...
> 
>  Tom, its on the machine you have access to ... if there is anything you
> might want to look at that might help, please feel free ... its the
> udmsearch database, and from what I can tell, its PID 44718 ...
> 
> VACUUM VERBOSE has been hung at:
> 
> NOTICE:  --Relation url--
> NOTICE:  Pages 8607: Changed 0, reaped 8391, Empty 0, New 0; Tup 88821: Vac 65416, Keep/VTL 0/0, Crash 0, UnUsed
98291,MinLen 125, MaxLen 914; Re-using: Free/Avail. Space 21878184/21835520; EndEmpty/Avail. Pages 0/7059. CPU
1.92s/0.00usec.
 
> NOTICE:  Index url_crc: Pages 1385; Tuples 88821: Deleted 65416. CPU 2.23s/0.00u sec.
> NOTICE:  Index url_url: Pages 4199; Tuples 88821: Deleted 38844. CPU 2.25s/0.00u sec.
> NOTICE:  Index url_pkey: Pages 1001; Tuples 88821: Deleted 38844. CPU 1.41s/0.00u sec.
> NOTICE:  Rel url: Pages: 8607 --> 6091; Tuple(s) moved: 16669. CPU 10.10s/0.00u sec.
> NOTICE:  Index url_crc: Pages 1387; Tuples 88821: Deleted 16669. CPU 0.75s/0.00u sec.
> NOTICE:  Index url_url: Pages 4202; Tuples 88821: Deleted 16669. CPU 1.49s/0.00u sec.
> NOTICE:  Index url_pkey: Pages 1002; Tuples 88821: Deleted 16669. CPU 0.65s/0.00u sec.
> NOTICE:  --Relation ndict--
> NOTICE:  Pages 65736: Changed 5857, reaped 5913, Empty 0, New 0; Tup 10181746: Vac 993304, Keep/VTL 0/0, Crash 0,
UnUsed0, MinLen 42, MaxLen 42; Re-using: Free/Avail. Space 43847288/43847288; EndEmpty/Avail. Pages 0/5913. CPU
19.83s/0.00usec.
 
> NOTICE:  Index n_word: Pages 26102; Tuples 10181746: Deleted 993304. CPU 66.69s/0.00u sec.
> NOTICE:  Index n_url: Pages 50739; Tuples 10181746: Deleted 993304. CPU 69.34s/0.00u sec.
> 
> Uptime on the machine is normal/low:
> 
> pgsql% uptime
> 12:27PM  up 7 days,  5:55, 3 users, load averages: 3.23, 3.27, 3.33
> 
> Its a Dual-PIII 450, 512Meg of RAM, the pgsql databases are on their own
> dedicated drive, seperate from the system drive, and not even swapping:
> 
> pgsql% pstat -s
> Device          512-blocks     Used    Avail Capacity  Type
> /dev/rda0s1b       1048320        0  1048320     0%    Interleaved
> /dev/rda1s1b       1048320        0  1048320     0%    Interleaved
> Total              2096640        0  2096640     0%
> 
> lsof shows (if it matters):
> 
> pgsql% lsof -p 44718
> COMMAND    PID  USER   FD   TYPE     DEVICE  SIZE/OFF    NODE NAME
> postgres 44718 pgsql  cwd   VDIR  13,131084      2048 1253933 /pgsql/data/base/udmsearch
> postgres 44718 pgsql  rtd   VDIR  13,131072       512       2 /
> postgres 44718 pgsql  txt   VREG  13,131084   4669647  103175 /pgsql/bin/postgres
> postgres 44718 pgsql  txt   VREG  13,131076     76648  212707 /usr/libexec/ld-elf.so.1
> postgres 44718 pgsql  txt   VREG  13,131076     11128   56672 /usr/lib/libdescrypt.so.2
> postgres 44718 pgsql  txt   VREG  13,131076    118044   56673 /usr/lib/libm.so.2
> postgres 44718 pgsql  txt   VREG  13,131076     33476   56680 /usr/lib/libutil.so.3
> postgres 44718 pgsql  txt   VREG  13,131076    148316   56532 /usr/lib/libreadline.so.4
> postgres 44718 pgsql  txt   VREG  13,131076    251416   56674 /usr/lib/libncurses.so.5
> postgres 44718 pgsql  txt   VREG  13,131076    550996   56746 /usr/lib/libc.so.4
> postgres 44718 pgsql    0r  VCHR        2,2       0t0    7967 /dev/null
> postgres 44718 pgsql    1w  VREG  13,131084 233611833  761881 /pgsql/logs/postmaster.5432.93622
> postgres 44718 pgsql    2w  VREG  13,131084  19771345  761882 /pgsql/logs/5432.93622
> postgres 44718 pgsql    3r  VREG  13,131084      1752 1253891 /pgsql/data/base/udmsearch/pg_internal.init
> postgres 44718 pgsql    4u  VREG  13,131084   3547136   15922 /pgsql/data/pg_log
> postgres 44718 pgsql    5u  IPv4 0xd46352e0       0t0     TCP pgsql.tht.net:5432->hub.org:2135 (ESTABLISHED)
> postgres 44718 pgsql    6u  VREG  13,131084      8192   15874 /pgsql/data/pg_variable
> postgres 44718 pgsql    7u  VREG  13,131084     16384 1253978 /pgsql/data/base/udmsearch/pg_class
> postgres 44718 pgsql    8u  VREG  13,131084     16384 1253977 /pgsql/data/base/udmsearch/pg_class_oid_index
> postgres 44718 pgsql    9u  VREG  13,131084     57344 1253981 /pgsql/data/base/udmsearch/pg_attribute
> postgres 44718 pgsql   10u  VREG  13,131084     32768 1253979
/pgsql/data/base/udmsearch/pg_attribute_relid_attnum_index
> postgres 44718 pgsql   11u  VREG  13,131084      8192 1253989 /pgsql/data/base/udmsearch/pg_am
> postgres 44718 pgsql   12u  VREG  13,131084      8192 1253949 /pgsql/data/base/udmsearch/pg_rewrite
> postgres 44718 pgsql   13u  VREG  13,131084      8192 1253973 /pgsql/data/base/udmsearch/pg_index
> postgres 44718 pgsql   14u  VREG  13,131084      8192 1253984 /pgsql/data/base/udmsearch/pg_amproc
> postgres 44718 pgsql   15u  VREG  13,131084     16384 1253987 /pgsql/data/base/udmsearch/pg_amop
> postgres 44718 pgsql   16u  VREG  13,131084     73728 1253957 /pgsql/data/base/udmsearch/pg_operator
> postgres 44718 pgsql   17u  VREG  13,131084     16384 1253972 /pgsql/data/base/udmsearch/pg_index_indexrelid_index
> postgres 44718 pgsql   18u  VREG  13,131084     32768 1253956 /pgsql/data/base/udmsearch/pg_operator_oid_index
> postgres 44718 pgsql   19u  VREG  13,131084     16384 1253972 /pgsql/data/base/udmsearch/pg_index_indexrelid_index
> postgres 44718 pgsql   20u  VREG  13,131084     16384 1253938 /pgsql/data/base/udmsearch/pg_type
> postgres 44718 pgsql   21u  VREG  13,131084     16384 1253937 /pgsql/data/base/udmsearch/pg_type_oid_index
> postgres 44718 pgsql   22u  VREG  13,131084      8192 1253983 /pgsql/data/base/udmsearch/pg_attrdef
> postgres 44718 pgsql   23u  VREG  13,131084     16384 1253976 /pgsql/data/base/udmsearch/pg_class_relname_index
> postgres 44718 pgsql   24u  VREG  13,131084      8192 1253942 /pgsql/data/base/udmsearch/pg_trigger
> postgres 44718 pgsql   25u  VREG  13,131084     16384 1253939 /pgsql/data/base/udmsearch/pg_trigger_tgrelid_index
> postgres 44718 pgsql   26u  VREG  13,131084      8192   15921 /pgsql/data/pg_shadow
> postgres 44718 pgsql   27u  VREG  13,131084     16384 1253982 /pgsql/data/base/udmsearch/pg_attrdef_adrelid_index
> postgres 44718 pgsql   28u  VREG  13,131084 538509312 1254004 /pgsql/data/base/udmsearch/ndict
> postgres 44718 pgsql   29u  VREG  13,131084 213909504 1254006 /pgsql/data/base/udmsearch/n_word
> postgres 44718 pgsql   30u  VREG  13,131084 416432128 1254005 /pgsql/data/base/udmsearch/n_url
> 
> 
> 
> Marc G. Fournier                   ICQ#7615664               IRC Nick: Scrappy
> Systems Administrator @ hub.org 
> primary: scrappy@hub.org           secondary: scrappy@{freebsd|postgresql}.org 
> 

Marc G. Fournier                   ICQ#7615664               IRC Nick: Scrappy
Systems Administrator @ hub.org 
primary: scrappy@hub.org           secondary: scrappy@{freebsd|postgresql}.org