|
| Time in Oracle | 6 July 1999 |
| What resolution are timed statistics reported in by Oracle? | ||
 | Almost all Oracle times are in centiseconds, but some are in seconds. The SQL*Plus SET TIMING ON is an exception. It is port specific, and gives milliseconds on some platforms, but not all. |
|
| Recursive calls | 12 October 1999 |
| A utlestat report I have run on a particular instance shows 245 recursive calls per second. Is there any way I can work how much of the recursive activity is due to dynamic space management, and how much is due to the heavy PL/SQL usage? In your experience, how much recursive SQL activity is it reasonable to expect from PL/SQL intensive applications? One of the tuning documents on MetaLink says that ratio of the recursive calls to user calls should be less than 10%. | ||
| The contribution of system tasks (such as populating the dictionary cache, dynamic extension, and so) is almost always insignificant by comparison with the number of recursive calls from stored program units. The target of 10% for recursive calls is an old version 6 tuning rule that no longer applies. |
|
| Timing in Oracle | 27 October 1999 |
| I have noticed that Oracle measures some statistics in seconds, some in 100ths of a second, and some in milliseconds. I have been told by Oracle Support that these units may be documented incorrectly. For example, today I had question about WRITETIM in V$FILESTAT, and they said that this parameter is in milliseconds, whereas the documentation says 100ths of a second. Anyway, how can the true units for a statistic be determined? | ||
| All statistics in the V$ views are either in seconds or centiseconds, and I am not aware of any documentation bugs regarding this. Support are definitely wrong about V$FILESTAT showing milliseconds. There was a paper circulating about 2 years ago that made that claim, and that may be where the information is coming from, but it is clearly wrong. The only use of milliseconds in Oracle is that the SET TIMING ON command returns milliseconds on some platforms. If you suspect a documentation bug, the only way to check is to measure whatever it is against a known timer such as V$TIMER or DBMS_UTILITY.GET_TIME. |
|
| Slow inserting | 28 October 1999 |
Here is a listing from V$SYSTEM_EVENT.
What's causes all the pmon timer and smon timer waits?
Increasing the number of block buffers, the shared pool and sort area size only has marginal impact on these waits.
There are 50 rollback segments and I have resized them with large extents with only marginal impact.
I am using Oracle 8.0.5.1 on HP K-class with 6 processors and raw partition.
This database is used to benchmark a heavily inserting application.
Could these waits be caused by the CPU being so much faster than I/O?
EVENT TOTAL_WAITS TOTAL_TIMEOUTS TIME_WAITED AVERAGE_WAIT --------------------------- ----------- -------------- ----------- ------------ rdbms ipc message 105790 14558 5503890 52.0265621 SQL*Net message from client 2818486 0 4438999 1.57495868 log file sync 2771634 210 2842901 1.02571299 pmon timer 4041 4035 1215290 300.739916 smon timer 43 39 1193952 27766.3256 enqueue 157396 2 918233 5.83390302 latch free 623534 451472 914831 1.467171 buffer busy waits 636528 1557 549700 .863591232 log file parallel write 558785 0 187438 .335438496 db file parallel write 17350 4 108726 6.26662824 buffer deadlock 48272 46659 93475 1.93642277 rdbms ipc reply 8000 0 82468 10.3085 write complete waits 1193 0 14799 12.4048617 control file parallel write 4056 0 8055 1.98594675 SQL*Net message to client 2818487 0 4344 .001541252 db file sequential read 6823 0 1463 .214421809 log file switch completion 66 0 1126 17.0606061 free buffer waits 1601 0 622 .388507183 db file scattered read 341 0 242 .709677419 sort segment request 1 1 101 101 | ||
|
This database has several problems, but they are not the ones you think.
The pmon timer and smon timer events are idle waits.
These background processes wait on these event when they have no work to do.
Your first problem is that you don't have sufficient freelists on the table to which you are inserting, or possibly have a primary key index on a sequence generated primary key that is not a reverse key index. This is probably what is causing your buffer busy waits and buffer deadlock waits. You also have enqueue waits that are probably a side effect of the lack of process freelists. Also, if your latch free waits are largely on the cache buffers chains latches, then that is probably another side effect. The ratio of you log file sync to log file parallel write waits indicates that your log_buffer is much too big. Drop it back to 160K. Your write complete waits and rdbms ipc reply waits indicate the either DBWn's write batch is too big, or you are checkpointing too intensively. Make sure that db_files is not much higher than the number of datafiles that you actually have. If you are using incremental checkpoints ( db_block_max_dirty_target) don't be too ambitious. |
|
|
Here is the V$WAITSTAT output.
We are benchmarking around 150 transactions per second (several inserts and one update).
The table is using 10 freelists.
We use an internally generated id instead of an Oracle sequence.
The log buffer is 1.6M.
The log files are 1G and do not switch during the benchmark period.
The database block is 2K.
Is this the cause of all my problems?
CLASS COUNT TIME ------------------ ---------- ---------- data block 1961113 1870278 segment header 34535 159082 undo header 233632 86239 undo block 1886 1706 |
|
Yes, that db_block_size is a problem,
because it will prevent you having more than 24 process freelists, and you need more than that.
I recommend an 8K block size for this level of concurrency.
However, if you have time, you may also want to benchmark 16K.
Also, put 50 process freelists on the key tables, and 2 freelist groups, and drop your log_buffer to 160K.
However, your real problem is probably your failure to use a proper Oracle sequence to generate the id numbers! |
|
| Event 10046 | 3 November 1999 |
| I don't understand what "event 10046, level 8" is? | ||
|
Event 10046 is a widely used superset of sql_trace. The syntax for the parameter file setting is
event = "10046 trace name context forever, level 8" The syntax for a single session is alter session set events '10046 trace name context forever, level 8'; Have a play with it and get familiar with the output. It is a very valuable tuning/diagnostic tool. See the excellent Oracle Note 39817.1 for a detailed explanation of the information in the trace file. |
|
| pipe get waits | 5 November 1999 |
| While watching my wait events for the last few weeks, pipe get is the event that makes up the largest percentage of time waited. What does this mean? | ||
| This is an "idle wait". The session is waiting to receive a message on a pipe. To learn more about pipes, see the package specification for DBMS_PIPE in $ORACLE_HOME/rdbms/admin/dbmspipe.sql. |
|
| Timeouts | 23 December 1999 |
| What does TOTAL_TIMEOUTS mean in V$SESSION_EVENT, and why are they only non-zero for latch free waits? | ||
| Timeouts are waits that were never posted. It is normal for latch waits, idle waits and long-term enqueue waits to timeout. Otherwise it is rare. This is reasonably well explained in chapters 2 and 3 of my book. |
|
| Right-hand indexes | 27 December 1999 |
| Our database seems to be having lot of buffer busy waits in the data block class. We do have right-hand indexes, because we use sequence numbers for many things. We have 1300 connections and 200 active users at any point in time. Given this scenario, I am wondering whether the buffer busy waits are for indexes? | ||
| Assuming your indexes are in separate tablespaces, you can check whether your buffer busy waits correspond to the index tablespaces by looking in X$KCBFWAIT. You can do that using the APT script called buffer_busy_waits.sql. Failing that, you will need to trace the wait parameter values and work out which blocks are hot by looking up the p1(file#) and p2(block#) values in DBA_EXTENTS. See our trace_waits.sql for that. |
|
| V$SESSION_WAIT.SECONDS_IN_WAIT | 27 December 1999 |
V$SESSION_WAIT.SECONDS_IN_WAIT and V$SESSION_EVENT.MAX_WAIT don't seem to agree.
Here is an example where I've had a db file sequential read wait clock 106 seconds,
but V$SESSION_EVENT shows a MAX_WAIT of 21.
SID SEQ# EVENT P1TEXT P1 P2TEXT P2 P3TEXT P3 WAIT_TIME SECONDS_IN_WAIT
----- ------ ----------------------- --------- --- ------- ---- ------- --- ---------- ---------------
23 59950 db file sequential read file# 40 block# 1877 blocks 1 -1 106
SID EVENT TOTAL_WAITS TOTAL_TIMEOUTS TIME_WAITED AVERAGE_WAIT MAX_WAIT
----- ----------------------- ----------- -------------- ----------- ------------ ----------
23 db file sequential read 53487 0 12021 .2247462 21
I'm obviously misreading something here?
| ||
| The problem here is that the SECONDS_IN_WAIT field is not defined for "short" waits. If you have a look at the underlying X$KSUSECST.KSUSEWTM column directly, you will see that it is only reset for "known" waits. Otherwise it continues to increase. |
|
| Delete performance | 31 January 2000 |
|
I have a large table with two indexes from which I have to delete sets of about 4 million rows repeatedly.
The process opens a cursor on the rows to be deleted, fetches 1000, deletes 1000 using the rowids, and repeats, committing every 5000 rows.
The basic problem is that I'm only able to delete about 20 to 50 rows a second, and at this rate, each set takes days to delete.
Why is it taking so long?
We're running Oracle 7.3.3 on Solaris 2.6. The data is spread over 30+ disks, and there is no disk contention. The system has enough memory and is not CPU starved. This is what V$SESSION_EVENT shows. SQL> select * from v$session_event where sid = 103 order by time_waited desc; SID EVENT TOTAL_WAITS TOTAL_TIMEOUTS TIME_WAITED AVERAGE_WAIT --- -------------------------- ----------- -------------- ----------- ------------ 103 db file sequential read 4774208 0 10975798 2.29897776 103 log buffer space 35484 572 1061939 29.927263 103 latch free 525321 525319 569661 1.08440553 103 free buffer waits 5062 1035 228744 45.1884631 103 buffer busy waits 18142 75 67459 3.71838827 103 log file switch completion 713 208 40266 56.4740533 103 log file sync 617 118 29308 47.5008104 103 write complete waits 192 21 8825 45.9635417 | ||
| Such operations do a lot less work if you can drive them off a full table scan. If not, at least close and re-open the outer cursor after each commit, to prevent having to do extra work for read-consistency. Also, your log files are too small, and you need more db_writers. |
|
| calls to kcmgas | 4 February 2000 |
| I'd like to develop a stored procedure that can be invoked every 5 minutes, to look to see if the current SCN has changed, and execute ALTER SYSTEM ARCHIVE LOG CURRENT if it has. This will push out a new archive log to my standby database, thereby keeping the standby a maximum of 5 minutes stale. However, I can't seem to find the current SCN in any V$ views. What about using userenv('COMMITSCN')? | ||
|
Using COMMITSCN is not a good idea.
You can only use it once in a transaction, and you have to commit to fix the value.
That would raise the SCN and result in a log switch every five minutes anyway.
Not to mention that it is an undocumented feature, and has a memory leak bug.
Maybe a better way is to query the value of the calls to kcmgas system statistic. This statistic is incremented by 1 for each SCN allocation. If you check it just after each manual log switch, and then check it again every 5 minutes, you will know whether the SCN has changed. By the way, this will have to be a shell script or pre-compiled executable rather than a stored procedure, because ALTER SYSTEM does not work from PL/SQL. |
|
| buffer busy waits and V$WAITSTAT | 5 February 2000 |
| What is the difference between buffer busy waits as reported in V$SYSTEM_EVENT and the information that is reported in V$WAITSTAT? Does the total count of waits from V$WAITSTAT define the buffer busy waits in more detail? | ||
| That's right, V$WAITSTAT is just a breakdown by buffer class of the buffer busy waits shown in V$SYSTEM_EVENT. |
|
| Getting to 0 | 26 February 2000 |
| Is it possible to actually have 0 waits for the data block class in V$WAITSTAT? I am seeing very few waits, but still they exist. Should I expect that, or should I strive to attain 0 waits? | ||
| I would not bother to try to eliminate the last few data block waits. It is often possible to do so, but you will spend many hours on the effort and only stand to gain a few centiseconds. |
|
| Unit of time for waits | 2 March 2000 |
| What is the unit of time for the Oracle wait events? | ||
|
The wait events are always timed in centiseconds, although SET TIMING ON returns milliseconds on some platforms.
Here's an example ...
SQL> select time_waited from v$system_event where event = 'PL/SQL lock timer'; no rows selected SQL> set timing on SQL> execute sys.dbms_lock.sleep(10); PL/SQL procedure successfully completed. real: 10245 SQL> select time_waited from v$system_event where event = 'PL/SQL lock timer'; EVENT TIME_WAITED ---------------------------------------------------------------- ----------- PL/SQL lock timer 1024 |
|
| Background waits for log file sync | 3 March 2000 |
| When I check the events that background processes have been waiting for, it seems that DBW0 does not wait for log file sync events, but PMON does. Why? | ||
| DBWn does not necessarily wait for log file syncs. It only waits if it needs to write a block for which the redo has not yet been flushed. The risk of this is highest in an interval checkpoint. PMON on the other hand has to commit lots of transactions, and so waits for LGWR in a log file sync wait, just like a foreground process. |
|
| control file parallel write | 3 March 2000 |
| I've had 227,750 waits for control file parallel write. V$SESSION_EVENT shows 15 waits by ARCH, 3 by DBW0 and 277,702 by LGWR. What is LGWR doing, or is there an I/O bottleneck? Also, where did the other 30 waits go? | ||
| I suspect that it is in fact the CKPT process, rather than the LGWR process that is waiting here. In 8.0.5 a heartbeat mechanism was included in CKPT's timeout action (every 3 seconds) to update the checkpoint progress record for the thread in the controlfile. Join V$SESSION_EVENT.SID to V$SESSION.SID and V$SESSION.PADDR to V$BGPROCESS.PADDR to confirm. The other 30 waits would be from controlfile transactions by foreground sessions that have since disconnected. |
|
| log file sync and slave waits | 24 March 2000 |
| I noticed high waits on log file sync, so I set dbwr_io_slaves in order to get some LGWR I/O slaves indirectly. Now I've got high slave waits as well. Why is this? | ||
| slave waits are an idle wait. You can ignore them. However, the presence of LGWR I/O slaves has little to do with the log file sync statistics. Your high commit rate is the cause. |
|
| lock manager wait for remote message | 24 March 2000 |
| I am trying to find some information on the lock manager wait for remote message event, and haven't come across anything yet. | ||
| It is an idle wait - one of the ones to ignore. |
| Copyright © Ixora Pty Ltd |
|