Informix Lockup (Wierd)
Posted in 2003
Topics: Performance & Tuning, Server Administration, Transactions, Locking & Isolation, Logging & Checkpoints, Networking & sqlhosts Configuration, Migration, Import/Export & Data Conversion
Occasionally I am experiencing Informix
locking up. It won't accept any db
connections, or process any SQL commands on connections that are currently
open. We are running on a dual processor box and durring this lockup I am
noticing that 1 cpu is maxed out with 100% usr processes. The other
processor is doing virtually nothing.
The informix was non responding for approximately 30 minutes. When it came
back online I checked some logs. The lockup started at approximately 2pm
(14:00 hrs) Here is what the logs said:
13:27:51 Checkpoint Completed: duration was 1 seconds.
13:35:32 Logical Log 51508 Complete.
13:35:35 Logical Log 51508 - Backup Started
13:35:36 Logical Log 51508 - Backup Completed
13:43:22 Logical Log 51509 Complete.
13:43:25 Logical Log 51509 - Backup Started
13:43:26 Logical Log 51509 - Backup Completed
13:51:04 Logical Log 51510 Complete.
13:51:07 Logical Log 51510 - Backup Started
13:51:07 Logical Log 51510 - Backup Completed
13:57:53 Checkpoint Completed: duration was 1 seconds.
13:59:13 Logical Log 51511 Complete.
13:59:16 Logical Log 51511 - Backup Started
13:59:16 Logical Log 51511 - Backup Completed
14:27:24 listener-thread: err = -25573: oserr = 72: errstr = : Network
driver cannot accept a connection on the port.
System error = 72.
14:27:24 listener-thread: err = -25587: oserr = 0: errstr = : Network
receive failed.
14:27:24 listener-thread: err = -25573: oserr = 72: errstr = : Network
driver cannot accept a connection on the port.
System error = 72.
14:27:24 listener-thread: err = -25573: oserr = 72: errstr = : Network
driver cannot accept a connection on the port.
System error = 72.
This last error "Network driver cannot accept a connection on the port."
repeated approximately 50 times until
14:27:55 listener-thread: err = -25573: oserr = 72: errstr = : Network
driver cannot accept a connection on the port.
System error = 72.
Another (possibly helpful) bit of information was that a updateStatistics
script is set to run every hour on the hour. Here is the
updatestatistics.sh that runs. I'm thinking that it was possibly this
script that caused the lockup becuase both the script and the lockup started
at the same time. However the lockup occurs very infrequently.. maybe once
every other month at most. I am no informix DBA but I'm all we have so if
anyone could look over this script or has experienced a similar/same problem
could you PLEASE HELP. Thank you very much.
#!/usr/bin/ksh
# This program runs update statistics for a database in parallel
# by invoking separate connections for each table
#
# USAGE : updatestat.sh <dbname> <run_options> <no_of_processes>
#
# AUTHOR : Varadharajan Kope mkv@infogain.com
#
# NOTE :-
# * Change the value of US_DIR and test before use. US_DIR is the
directory
# where the update statistics scripts and execution outputs are kept.
# A separate file with the name <tablename>.sql is created for each
table.
# * Run 'update statistics' on the database once before using this script
# for the first time for best results.
# * Distribution level selection is based on nrows. SMALL_TAB specifies
# the no. of rows for a small table and LARGE_TAB, for a large table.
# * To know information about the arguments, type prl_us.sh at the prompt
# * Do not run update statistics very often. Once a week would be fine.
#
# DISCLAIMER :-
# The author is not responsible for any damage this script could cause
# to your system performance. But, for any performance improvement, he
is.
# USE IT AT YOUR OWN RISK.
#--LOCAL MODIFICATIONS--------
# Carl M. Barnes, Data Basics International
# modified for CEA
# set informix vars
INFORMIXDIR=/informix
ONCONFIG=onconfig.ows
INFORMIXSERVER=ol_cea_shm
INFORMIXSQLHOSTS=/informix/etc/sqlhostsTERM=vt100
TERMCAP=/informix/etc/termcap
PATH=.:/informix/bin:/informix/bin:.:/usr/ccs/bin:/usr/ccs/lib:/bin:/usr/bin:/usr/sbin:/usr/etc:/usr/ucb
export INFORMIXDIR INFORMIXSERVER ONCONFIG INFORMIXSQLHOSTS PATH TERMTERMCAP
##-cmbexport US_DIR=/dataconv/$DBNAME.stats
#-----------------------------
# ---------------------------------------------------------------------
# This function generates update statistics scripts for a table
# using the strategy suggested by Informix in the performance guide
# and the release notes which is
# 1. MEDIUM on all columns that are not part of an index as a single
statement
# with distributions only.
# 2. HIGH on all columns that are part of an index as separate statements.
# 3. For indexes that begin with the same subset of columns,
# run HIGH for the first column in each index that differs.
#
gen_us()
{
DBNAME=$1
TABNAME=$2
echo "set lock mode to wait;" > $TABNAME.sql
echo "set optimization all_rows;" >> $TABNAME.sql
# echo "set isolation to dirty read;" >> $TABNAME.sql
# for small tables run update statistics HIGH
eval dbaccess $DBNAME 2>/dev/null 1>&2 <<EOH
unload to "d.out" delimiter ';'select 'update statistics high for table ' || tabname
from systables
where tabname = "$TABNAME"
and nrows < 1000 ;
EOH
if [ `cat d.out | wc -l` -ne 0 ]
then
cat d.out >>$TABNAME.sql
rm d.out
return
fi
# Identify columns that differ where indexes start with the same columns
TABID=`get_tabid $DBNAME $TABNAME | sed '1,4d'`
echo $TABID
eval dbaccess $DBNAME 2>/dev/null 1>&2 <<EOF
set optimization all_rows;
select tabid, idxname, abs(part1) col, 1 part from sysindexes
where part1 != 0 and tabid = $TABID
union
select tabid, idxname, abs(part2) col, 2 part from sysindexes
where part2 != 0 and tabid = $TABID
union
select tabid, idxname, abs(part3) col, 3 part from sysindexes
where part3 != 0 and tabid = $TABID
union
select tabid, idxname, abs(part4) col, 4 part from sysindexes
where part4 != 0 and tabid = $TABID
union
select tabid, idxname, abs(part5) col, 5 part from sysindexes
where part5 != 0 and tabid = $TABID
union
select tabid, idxname, abs(part6) col, 6 part from sysindexes
where part6 != 0 and tabid = $TABID
union
select tabid, idxname, abs(part7) col, 7 part from sysindexes
where part7 != 0 and tabid = $TABID
union
select tabid, idxname, abs(part8) col, 8 part from sysindexes
where part8 != 0 and tabid = $TABID
union
select tabid, idxname, abs(part9) col, 9 part from sysindexes
where part9 != 0 and tabid = $TABID
union
select tabid, idxname, abs(part10) col, 10 part from sysindexes
where part10 != 0 and tabid = $TABID
union
select tabid, idxname, abs(part11) col, 11 part from sysindexes
where part11 != 0 and tabid = $TABID
union
select tabid, idxname, abs(part12) col, 12 part from sysindexes
where part12 != 0 and tabid = $TABID
union
select tabid, idxname, abs(part13) col, 13 part from sysindexes
where part13 != 0 and tabid = $TABID
union
select tabid, idxname, abs(part14) col, 14 part from sysindexes
where part14 != 0 and tabid = $TABID
union
select tabid, idxname, abs(part15) col, 15 part from sysindexes
where part15 != 0 and tabid = $TABID
Ops my
bad... the updatestats.sh isn't scheduled to run every hour... only
at 1am. This script is run every 2 hours and both recent lockups have
happened durring the execution of this script.
#!/bin/ksh
#################################
# Informix "Check It" Script
# Elisa D. Hix, Informix
# 08/23/97
#################################
INFORMIXDIR=/informix
ONCONFIG=onconfig.ows
INFORMIXSERVER=ol_cea_shm
INFORMIXSQLHOSTS=/informix/etc/sqlhostsTERM=vt100
TERMCAP=/informix/etc/termcap
PATH=.:/informix/bin:/informix/bin:.:/usr/ccs/bin:/usr/ccs/lib:/bin:/usr/bin:/usr/sbin:/usr/etc:/usr/ucb
export INFORMIXDIR INFORMIXSERVER ONCONFIG INFORMIXSQLHOSTS PATH TERMTERMCAP
## Date
echo
"------------------------------------------------------------------------"
>> /informix/logs/check_it.log
date >> /informix/logs/check_it.log
## Init
exitcode=0
## Check for "On-Line" Mode
checkit=""
checkit=`/informix/bin/onstat - | grep " On-Line "`
if [ -z "$checkit" ] ; then
echo "Informix is down (`date`)." | mail informix
echo "Informix is down (`date`)." >> /informix/logs/check_it.log
exitcode=1
fi
## Check for logs not backed up
checkit=""
checkit=`/informix/bin/onstat -l | grep "U-B" | wc -l`
if [ "$checkit" -ne 19 ] ; then
echo "Informix log backup behind (`date`)." | mail informix
echo "Informix log backup behind (`date`)." >>
/informix/logs/check_it.log
exitcode=1
fi
## Check for dynamically allocated memory segments
checkit=""
checkit=`/informix/bin/onstat -g seg | wc -l`
if [ "$checkit" -ne 12 ] ; then
echo "Informix has allocated more memory segments (`date`). Run
onmode -F to unallocate when memory is free." | mail informix echo "Informix has allocated more memory segments (`date`). Run
onmode -F to unallocate when memory is free." >> /informix/logs/check_it.log
exitcode=1fi
## Check for message log errors
checkit=""
#-cmb checkit=`tail -100 /informix/logs/online.log | grep "err = -"`
## changed to check a full days log -cmb
checkit=`grep "err = -" /informix/logs/online.log`
if [ -n "$checkit" ] ; then
echo "Informix online.log has errors (`date`)." | mail informix
echo "Informix online.log has errors (`date`)." >>
/informix/logs/check_it.log
exitcode=1
fi
## Check for tables with extents > 3 in cea database
checkit=""
#-cmb checkit=`/informix/bin/dbaccess sysmaster extent_test.sql 1>/dev/null
2>&1`
#-cmb changed the above line. it was always setting checkit to null
#-cmb
#-cmb checkit=`/informix/bin/dbaccess sysmaster extent_test.sql 1>/dev/null
2>&1`
#-cmb changed the above line. it was always setting checkit to null
#-cmb also modified the extent_test.sql file
#-cmb
#-cmb checkit=`/informix/bin/dbaccess sysmaster extent_test.sql 2>/dev/null`
#-cmb
/informix/bin/dbaccess sysmaster extent_test.sql 2>/dev/null 1> checkitF
checkit=`wc -l checkitF|awk '{print $1}'`
rm checkitF
#-cmb if [ -n "$checkit" ] ; then
if [ $checkit > 2 ] ; then
echo "Informix found tables with multiple extents (`date`). Run
extent_test.sql in /informix/scripts for table detail." | mail informix
echo "Informix found tables with multiple extents (`date`). Run
extent_test.sql in /informix/scripts for table detail." >>
/informix/logs/check_it.log
exitcode=1
fi
## Check for dbspace usage ( 4000 Kb threshold / 1000 pages )
DISKFULL=1000
TOTFREE=0
#-cmb /informix/bin/onstat -d | grep " 6" | awk '{print $2" "$3" "$6"
"$8}' |
/informix/bin/onstat -d | awk 'NR>35 && NR<67 {print $2" "$3" "$6" "$8}' |
while read CHK DBS FREE DBSPACE
do
if [ "$FREE" = "N" ] ; then
FREE=0
fi
TOTFREE=`expr ${TOTFREE} + ${FREE}`
done
if [ "$TOTFREE" -le $DISKFULL ] ; then
echo "Informix dbspace defndbs ($CHK $DBS $DBSPACE $TOTFREE
$DISKFULL) is approaching full (`date`)." | mail informix
echo "Informix dbspace defndbs ($2 $3 $6 $8 $CHK $DBS $DBSPACE
$TOTFREE $DISKFULL) is approaching full (`date`)." >>
/informix/logs/check_it.log
#-cmb exitcode=1
fi
#
## replaced the entire code to the end of the script
## with the following code.
## If any dbspace is less than 1000 pages send a email to informix and root
#-cmb
/informix/bin/onstat -d | awk 'NR>35 && NR<67 {print $2" "$3" "$5" "$6}' |
while read CHK DBS ALLOC FREE
do
case $DBS in
1) dbs1="rootdbs"
let dbs1F=$dbs1F+$FREE
let dbs1A=$dbs1A+$ALLOC
;;
2) dbs2="dbsaccount"
let dbs2F=$dbs2F+$FREE
let dbs2A=$dbs2A+$ALLOC
;;
3) dbs3="dbsbilling"
let dbs3F=$dbs3F+$FREE
let dbs3A=$dbs3A+$ALLOC
;;
4) dbs4="dbsclaim"
let dbs4F=$dbs4F+$FREE
let dbs4A=$dbs4A+$ALLOC
;;
5) dbs5="dbsindex"
let dbs5F=$dbs5F+$FREE
let dbs5A=$dbs5A+$ALLOC
;;
6) dbs6="dbslogical"
let dbs6F=$dbs6F+$FREE
let dbs6A=$dbs6A+$ALLOC
;;
7) dbs7="dbspfarch"
let dbs7F=$dbs7F+$FREE
let dbs7A=$dbs7A+$ALLOC
;;
8) dbs8="dbsphysical"
let dbs8F=$dbs8F+$FREE
let dbs8A=$dbs8A+$ALLOC
;;
9) dbs9="dbsremark"
let dbs9F=$dbs9F+$FREE
let dbs9A=$dbs9A+$ALLOC
;;
10) dbs10="dbsstatic"
let dbs10F=$dbs10F+$FREE
let dbs10A=$dbs10A+$ALLOC
;;
11) dbs11="dbstmp"
let dbs11F=$dbs11F+$FREE
let dbs11A=$dbs11A+$ALLOC
;;
12) dbs12="dbstmp1"
let dbs12F=$dbs12F+$FREE
let dbs12A=$dbs12A+$ALLOC
;;
13) dbs13="dbstmp2"
let dbs13F=$dbs13F+$FREE
let dbs13A=$dbs13A+$ALLOC
;;
14) dbs14="remark_dbs"
let dbs14F=$dbs14F+$FREE
let dbs14A=$dbs14A+$ALLOC
;;
15) dbs15="data2_dbs2"
let dbs15F=$dbs15F+$FREE
let dbs15A=$dbs15A+$ALLOC
;;
16) dbs16="data2_dbs3"
let dbs16F=$dbs16F+$FREE
let dbs16A=$dbs16A+$ALLOC
;;
17) dbs17="data2_dbs4"
let dbs17F=$dbs17F+$FREE
let dbs17A=$dbs17A+$ALLOC
;;
18) dbs18="data2_dbs5"
let dbs18F=$dbs18F+$FREE
let dbs18A=$dbs18A+$ALLOC
;;
19) dbs19="data2_dbs6"
let dbs19F=$dbs19F+$FREE
let dbs19A=$dbs19A+$ALLOC
;;
21) dbs21="data2_dbs8"
let dbs21F=$dbs21F+$FREE
let dbs21A=$dbs21A+$ALLOC
;;
22) dbs22="data2_dbs9"
let dbs22F=$dbs22F+$FREE
let dbs22A=$dbs22A+$ALLOC
;;
23) dbs23="data2_dbs10"
let dbs23F=$dbs23F+$FREE
let dbs23A=$dbs23A+$ALLOC
;;
24) dbs24="data2_dbs11"
let dbs24F=$dbs24F+$FREE
let dbs24A=$dbs24A+$ALLOC
;;
25) dbs25="data2_dbs12"
let dbs25F=$dbs25F+$FREE
let dbs25A=$dbs25A+$ALLOC
;;@@NL@
----- Original Message ----- From: "Phillips, Rob" <RPhillips@ce-a.com> To: <ids@iiug.org> Sent: Thursday, January 30, 2003 8:14 PM Subject: Informix Lockup (Wierd) [184] > Occasionally I am experiencing Informix locking up. It won't accept any db > connections, or process any SQL commands on connections that are currently > open. We are running on a dual processor box and durring this lockup I am > noticing that 1 cpu is maxed out with 100% usr processes. The other > processor is doing virtually nothing. > > The informix was non responding for approximately 30 minutes. When it came > back online I checked some logs. The lockup started at approximately 2pm > (14:00 hrs) Here is what the logs said: > > 14:27:24 listener-thread: err = -25573: oserr = 72: errstr = : Network > driver cannot accept a connection on the port. > System error = 72. in /usr/include/sys/errno.h what is error 72?
Rob:
Your script tries to run several update statistics commands in parallel. With
only one CPU VP you will practically only get two or three to actually
accomplish anything concurrently. Even so, you will be tying up the CPU VP and
I'd bet that your ONCONFIG file has a NETTYPE entry for tcp that specifies that
the CPU VP should carry the listener thread! Since the VP is VERY busy it
cannot get to any of the breakpoints at which it polls the network ports for
connections and new requests so the requests pile up in the TCP stack until it
is full. Then you get those messages until either the new requests slow down so
the listener can catch up or the update stats finally end. Change the cron
script that is running this to only request ONE update stats be run at a time.
BTW, my dostats utility does a better job and has options to reduce the daily
workload (-b, -a). Dostats is part of the package utils2_ak available from the
IIUG Software Repository.
Art S. Kagel
----- Original Message -----
From: Rob Phillips <RPhillips@ce-a.com>
At: 1/30 16:27
> Occasionally I am experiencing Informix locking up. It won't accept any db
> connections, or process any SQL commands on connections that are currently
> open. We are running on a dual processor box and durring this lockup I am
> noticing that 1 cpu is maxed out with 100% usr processes. The other
> processor is doing virtually nothing.
>
> The informix was non responding for approximately 30 minutes. When it came
> back online I checked some logs. The lockup started at approximately 2pm
> (14:00 hrs) Here is what the logs said:
>
> 13:27:51 Checkpoint Completed: duration was 1 seconds.
> 13:35:32 Logical Log 51508 Complete.
> 13:35:35 Logical Log 51508 - Backup Started
> 13:35:36 Logical Log 51508 - Backup Completed
> 13:43:22 Logical Log 51509 Complete.
> 13:43:25 Logical Log 51509 - Backup Started
> 13:43:26 Logical Log 51509 - Backup Completed
> 13:51:04 Logical Log 51510 Complete.
> 13:51:07 Logical Log 51510 - Backup Started
> 13:51:07 Logical Log 51510 - Backup Completed
> 13:57:53 Checkpoint Completed: duration was 1 seconds.
> 13:59:13 Logical Log 51511 Complete.
> 13:59:16 Logical Log 51511 - Backup Started
> 13:59:16 Logical Log 51511 - Backup Completed
> 14:27:24 listener-thread: err = -25573: oserr = 72: errstr = : Network
> driver cannot accept a connection on the port.
> System error = 72.
> 14:27:24 listener-thread: err = -25587: oserr = 0: errstr = : Network
> receive failed.
>
> 14:27:24 listener-thread: err = -25573: oserr = 72: errstr = : Network
> driver cannot accept a connection on the port.
> System error = 72.
> 14:27:24 listener-thread: err = -25573: oserr = 72: errstr = : Network
> driver cannot accept a connection on the port.
> System error = 72.
>
> This last error "Network driver cannot accept a connection on the port."
> repeated approximately 50 times until
>
> 14:27:55 listener-thread: err = -25573: oserr = 72: errstr = : Network
> driver cannot accept a connection on the port.
> System error = 72.
>
> Another (possibly helpful) bit of information was that a updateStatistics
> script is set to run every hour on the hour. Here is the
> updatestatistics.sh that runs. I'm thinking that it was possibly this
> script that caused the lockup becuase both the script and the lockup started
> at the same time. However the lockup occurs very infrequently.. maybe once
> every other month at most. I am no informix DBA but I'm all we have so if
> anyone could look over this script or has experienced a similar/same problem
> could you PLEASE HELP. Thank you very much.
>
> #!/usr/bin/ksh
> # This program runs update statistics for a database in parallel
> # by invoking separate connections for each table
> #
> # USAGE : updatestat.sh <dbname> <run_options> <no_of_processes>
> #
> # AUTHOR : Varadharajan Kope mkv@infogain.com
> #
> # NOTE :-
> # * Change the value of US_DIR and test before use. US_DIR is the
> directory
> # where the update statistics scripts and execution outputs are kept.
> # A separate file with the name <tablename>.sql is created for each
> table.
> # * Run 'update statistics' on the database once before using this script
> # for the first time for best results.
> # * Distribution level selection is based on nrows. SMALL_TAB specifies
> # the no. of rows for a small table and LARGE_TAB, for a large table.
> # * To know information about the arguments, type prl_us.sh at the prompt
> # * Do not run update statistics very often. Once a week would be fine.
> #
> # DISCLAIMER :-
> # The author is not responsible for any damage this script could cause
> # to your system performance. But, for any performance improvement, he
> is.
> # USE IT AT YOUR OWN RISK.
>
> #--LOCAL MODIFICATIONS--------
> # Carl M. Barnes, Data Basics International
> # modified for CEA
> # set informix vars
>
> INFORMIXDIR=/informix
> ONCONFIG=onconfig.ows
> INFORMIXSERVER=ol_cea_shm
> INFORMIXSQLHOSTS=/informix/etc/sqlhosts> TERM=vt100
> TERMCAP=/informix/etc/termcap
> PATH=.:/informix/bin:/informix/bin:.:/usr/ccs/bin:/usr/ccs/lib:/bin:/usr/bin> :/usr/sbin:/usr/etc:/usr/ucb
>
> export INFORMIXDIR INFORMIXSERVER ONCONFIG INFORMIXSQLHOSTS PATH TERM> TERMCAP
>
> ##-cmbexport US_DIR=/dataconv/$DBNAME.stats
>
> #-----------------------------
>
> # ---------------------------------------------------------------------
> # This function generates update statistics scripts for a table
> # using the strategy suggested by Informix in the performance guide
> # and the release notes which is
> # 1. MEDIUM on all columns that are not part of an index as a single
> statement
> # with distributions only.
> # 2. HIGH on all columns that are part of an index as separate statements.
> # 3. For indexes that begin with the same subset of columns,
> # run HIGH for the first column in each index that differs.
> #
> gen_us()
> {
> DBNAME=$1
> TABNAME=$2
>
> echo "set lock mode to wait;" > $TABNAME.sql
> echo "set optimization all_rows;" >> $TABNAME.sql
> # echo "set isolation to dirty read;" >> $TABNAME.sql>
>
> # for small tables run update statistics HIGH
>
> eval dbaccess $DBNAME 2>/dev/null 1>&2 <<EOH
>
> unload to "d.out" delimiter ';'> select 'update statistics high for table ' || tabname
> from systables
> where tabname = "$TABNAME"
> and nrows < 1000 ;
>
> EOH
>
> if [ `cat d.out | wc -l` -ne 0 ]
> then
> cat d.out >>$TABNAME.sql
> rm d.out
> return
> fi
>
> # Identify columns that differ where indexes start with the same columns
>
> TABID=`get_tabid $DBNAME $TABNAME | sed '1,4d'`
>
> echo $TABID
>
> eval dbaccess $DBNAME 2>/dev/null 1>&2 <<EOF
>
> set optimization all_rows;
>
> select tabid, idxname, abs(part1) col, 1 part from sysindexes
> where part1 != 0 and tabid = $TABID
> union
> select tabid, idxname, abs(part2) col, 2 part from sysindexes
> where part2 != 0 and tabid = $TABID
> union
> select tabid, idxname, abs(part3) col, 3 part from sysindexes
> where part3 != 0