Oracle FAQ Your Portal to the Oracle Knowledge Grid
HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US
 

Home -> Community -> Usenet -> c.d.o.server -> A request for input to a personal puzzle

A request for input to a personal puzzle

From: Kevin Counts <kcounts_at_helios.acomp.usf.edu>
Date: 15 Jul 2002 18:32:02 -0700
Message-ID: <f2ac0433.0207151732.56936b7d@posting.google.com>


I am performing an upgrade of a help desk package called RightNow Web.

The upgrade of the oracle database takes several days to complete > 36 hours.
I finally moved every portion of the database into a ramdisk (tmpfs) on
a Solaris E280 (2 x 750MHz USIII w/ 4GB of RAM) and I'm running into the same slow upgrade time.

What is bugging me is I can't figure out what is going on behind the scenes.

The only active process on this test database is a pro*c program called dbaudit which logs into oracle as user 'RNW'

I turned on timed_statistics and sql_trace in the init.ora.

I verify that the process is still running (run at 21:12) :

Oracle8i Enterprise Edition Release 8.1.7.3.0 - Production With the Partitioning option
JServer Release 8.1.7.3.0 - Production

SQL> select username,sid,serial# from v$session;

USERNAME                              SID    SERIAL#
------------------------------ ---------- ----------
                                        1          1
                                        2          1
                                        3          1
                                        4          1
                                        5          1
                                        6          1
RNW                                     7         16
SYS                                     8       7981

Then I look at the tracefile which hasn't been updated since 17:58:

-rw-rw---- 1 oracle dba 75858207 Jul 15 17:58 acomp_ora_22573.trc

(its huge because they didn't use bind variables and hard parse
a reference number for each help desk incident refno)

Here are the last lines of acomp_ora_22573.trc:

 $ tail acomp_ora_22573.trc

FETCH #15:c=0,e=0,p=0,cr=21,cu=0,mis=0,r=201,dep=0,og=4,tim=3892781236
FETCH #15:c=0,e=0,p=0,cr=30,cu=0,mis=0,r=201,dep=0,og=4,tim=3892781243
FETCH #15:c=0,e=0,p=0,cr=33,cu=0,mis=0,r=169,dep=0,og=4,tim=3892781251
STAT #15 id=1 cnt=18459 pid=0 pos=0 obj=3055 op='TABLE ACCESS FULL INCIDENTS '

PARSING IN CURSOR #15 len=297 dep=0 uid=18 oct=3 lid=18 tim=3892781257 hv=3196652292 ad='9107b610'
SELECT count(*), stat_date FROM incidents inc, stats WHERE stats.interface_id = inc.interface_id AND time_created < stat_date AND
(time_closed >= stat_date OR time_closed IS NULL) AND (stat_date
BETWEEN '1999-06-24 14:52:09' AND '2002-07-15 00:00:00') AND stats.interface_id = 3 GROUP BY stat_date END OF STMT
PARSE #15:c=0,e=0,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,tim=3892781257 EXEC #15:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=3892781257
--

Let me mention that eventually this finishes -- but at this point
I'm wondering how to find out what oracle is waiting on.

The oracle process shows up in top consuming close to 50% of the cpu:

$ top
CPU states: 46.4% idle, 51.2% user,  2.4% kernel,  0.0% iowait,  0.0%
swap
Memory: 4096M real, 3130M swap in use, 2137M swap free

  PID USERNAME THR PRI NICE  SIZE   RES STATE   TIME    CPU COMMAND
22573 daemon    11  10    0  391M  371M cpu1  212:30 50.00% oracle
   71 root      11  59    0 2984K 2792K sleep  39:05  1.31% picld
 4310 oracle     1  52    0 2560K 1640K cpu0    0:00  0.33% top
 3378 root       1  58    0 3680K 2872K sleep   0:00  0.02% sshd
22572 root       4  58    0   55M   49M sleep   3:20  0.00% dbaudit
21445 oracle   258  59    0  387M  360M sleep   1:30  0.00% oracle
21447 oracle    11  59    0  384M  355M sleep   0:54  0.00% oracle
    1 root       1  58    0  808K  392K sleep   0:39  0.00% init
  379 root       1  48    0 2672K 1528K sleep   0:30  0.00% sshd
21449 oracle    11  59    0  382M  354M sleep   0:12  0.00% oracle
  519 bb         1  12    0 1040K  872K sleep   0:04  0.00% bbrun
21451 oracle     1  58    0  381M  356M sleep   0:04  0.00% oracle
23912 root       1  58    0 3680K 2872K sleep   0:04  0.00% sshd
  522 bb         1  12    0 1040K  872K sleep   0:03  0.00% bbrun
16246 root       1  58    0 3680K 2872K sleep   0:03  0.00% sshd

I truss -p dbaudit and its in a wait state:


(root_at_beetle)--(/)
# truss -p 22572 read(18, 0x01749466, 2064) (sleeping...) signotifywait() (sleeping...) door_return(0x00000000, 0, 0x00000000, 0) (sleeping...) lwp_cond_wait(0xFE7F55A0, 0xFE7F55B0, 0xFE6C3C48) (sleeping...) I truss -p oracle and its yielding to another thread: # truss -p 22573 *** SUID: ruid/euid/suid = 1 / 400 / 400 *** *** SGID: rgid/egid/sgid = 1 / 400 / 400 *** yield() = 0 yield() = 0 yield() = 0 yield() = 0 yield() = 0 Then I check v$session_wait on sid #7 to see whats going on and it looks like it sent what it needs to the client and is waiting: SQL> select event,wait_time,seconds_in_wait,state from v$session_wait where sid='7'; (edited for readability) EVENT WAIT_TIME SECONDS_IN_WAIT STATE -------------------- --------- --------------- --------------- SQL*Net message to Client -1 12334 WAITED SHORT TIME I ran this multiple times and the seq# didn't change. -- Any ideas appreciated -- I'll check out whatever else seems appropriate -- Outside input would help! Thanks Kevin Counts -- http://www.digicat.org
Received on Mon Jul 15 2002 - 20:32:02 CDT

Original text of this message

HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US