Oracle FAQ | Your Portal to the Oracle Knowledge Grid |
Home -> Community -> Usenet -> c.d.o.server -> A request for input to a personal puzzle
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=3892781251STAT #15 id=1 cnt=18459 pid=0 pos=0 obj=3055 op='TABLE ACCESS FULL INCIDENTS '
-- 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:Received on Mon Jul 15 2002 - 20:32:02 CDT
(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