Recently, I was involved in a discussion about import performance in this OTN forum in which the original poster raised the issue of whether or not import will resort to single-row inserts for tables with date columns.

For array inserts, the buffer parameter essentially specifies the size of this array. We know, however, that if a table has lob columns, the import parameter buffer is not honored, and the import utility will use single-row inserts for those tables. But tables with date columns, so the claim goes, also must suffer single-row inserts. In this blog, I will probe this further and validate that claim.

Let’s create a table and populate it with 300K rows.

 create table t1 (n1 number, v1 varchar2 (512), d1 date);

 insert into t1
 select n1, lpad(n1, 500, 'x'), sysdate
 from (select level n1 from dual connect by level <=300003);
 commit;

 REM Creating an  export file..
 host exp userid=cbqt/cbqt file=exp_t1.dmp log=exp_t1.log tables=t1

The above code fragment created a table, inserted 300,000 rows, and exported that table to an export dump file. This dump file is ready to be imported. But, we need to trace the import to measure the effect of the buffer parameter. The problem, though, is how to trace the import session alone without generating every session in the database. This can be achieved by creating a logon trigger as below. Only sessions from a test user will have trace enabled from this trigger (the username is CBQT).

REM I could use "on schema clause too, but this is part of generic code that I use.
REM Riyaj Shamsudeen - To trace a session through logon trigger
create or replace trigger
set_system_event
after logon  on database
declare
v_user dba_users.username%TYPE:=user;
sql_stmt1 varchar2(256) :='alter session set events '||chr(39)||'10046 trace name context forever, level 12'||chr(39);
begin
  if (v_user = 'CBQT') THEN
      execute immediate sql_stmt1;
  end if;
end;
/

Let’s drop the table, then import with a default buffer size of 64K. Through the logon trigger, a new SQL trace file will be generated. That trace file will be analyzed with the tkprof utility as shown in the code fragment below:

(more…)

Recently, I had an opportunity to tune latch contention for cache buffers chain (CBC) latches. The problem was high CPU-usage combined with poor application performance. A quick review of the statspack report for 15 minutes showed a latch-free wait as the top event, consuming approximately 3600 seconds in an 8-CPU server. CPU usage was quite high, which is a typical symptom of latch contention, due to the spinning involved. v$session_wait showed that hundreds of sessions were waiting for latch free event.

SQL> @waits10g

   SID PID     EVENT         P1_P2_P3_TEXT
------ ------- ------------  --------------------------------------
   294  17189  latch free    address 15873156640-number 127-tries 0
   628  17187  latch free    address 15873156640-number 127-tries 0
....
   343  17191  latch free    address 15873156640-number 127-tries 0
   599  17199  latch: cache  address 17748373096-number 122-tries 0
               buffers chains
   337  17214  latch: cache  address 17748373096-number 122-tries 0
               buffers chains
.....
   695  17228  latch: cache  address 17748373096-number 122-tries 0
               buffers chains
....
   276  15153  latch: cache  address 19878655176-number 122-tries 1
               buffers chains

I will use a two-pronged approach to find the root cause scientifically. First, I’ll find the SQL suffering from latch contention and objects associated with the access plan for that SQL. Next,I will find the buffers involved in latch contention, and map that back to objects. Finally, I will match these two techniques to pinpoint the root cause.

Before I go any further, let’s do a quick summary of the internals of latch operations.

(more…)

In this blog entry, I will discuss strategies and techniques to resolve ‘log file sync’ waits. This entry is intended to show an approach based upon scientific principles, not necessarily a step-by-step guide. Let’s understand how LGWR is inherent in implementing the commit mechanism first.

Commit Mechanism and LGWR Internals

At commit time, a process creates a redo record (containing commit opcodes) and copies that redo record into the log buffer. Then, that process signals LGWR to write the contents of log buffer. LGWR writes from the log buffer to the log file and signals user process back completing a commit. A commit is considered successful after the LGWR write is successful.

Of course, there are minor deviations from this general concept, such as latching, commits from a plsql block, or IMU-based commit generation, etc. But the general philosophy remains the same.

Signals, Semaphores and LGWR

The following section introduces the internal workings of commit and LGWR interation in Unix platforms. There are minor implementation differences between a few Unix flavours or platforms like NT/XP, for example the use of post-wait drivers instead of semaphores etc. This section will introduce, but not necessarily dive deep into, internals. I used truss to trace LGWR and user process. The command is:

truss -rall -wall -fall -vall -d -o /tmp/truss.log -p 22459

(A word of caution: don’t truss LGWR or any background process unless it is absolutely necessary. Doing so can cause performance issues, or worse, shutdown the database.)

(more…)

Recently, I had a few email exchanges — on the Oracle-l list and offline — about HW enqueue contention. A few interesting observations emerged from test cases I created during that discussion.

HW Enqueue

When a session needs access to a resource, it requests a lock on that resource in a specific mode. Internally, lock and resource structures are used to control access to a resource. Enqueues, as the name suggests, have a First In/First Out queuing mechanism. You can find more information about the internals of locks in my paper, printed in 2001, Internals of locks.

Segments have a High Water Mark (HWM) indicating that blocks below that HWM have been formatted. New tables or truncated tables (that is, truncated without a reuse storage clause), have the HWM value set to the segment header block — meaning, there are zero blocks below the HWM. As new rows are inserted or existing rows updated (increasing row length), more blocks are added to the free lists, and the HWM is bumped up to reflect these new blocks. HW enqueues are acquired in Exclusive mode before updating the HWM, and essentially, HW enqueues operate as a serializing mechanism for HWM updates.

In non-ASSM tablespaces, the HWM is bumped up by five blocks at a time. (Actually, the undocumented parameter _bump_highwater_mark_count controls this behavior, and it defaults to five.) Heavy inserts into a table can result in increased HWM activity leading to HW enqueue contention. This issue is prevalent if the table has LOB columns or if the row length is large.

Measuring HW Enqueue Contention

We will use a few test cases to see how the underlying extent size and table structures are affecting HW enqueue contention. But first we need to find a way to measure the total number of gets on HW enqueue. If the total number of gets on the HW enqueue is reduced, enqueue contention can be relieved.

The fixed table x$ksqst stores statistics about the total number of enqueue gets, and the successes and failures of those gets at the instance level. For example, to see total number of gets on HW enqueue, the following query can be used. (The ksqstreq column indicates total number of gets; ksqstwat shows the total number of waits.) (more…)

A few days ago, a developer and I had an interesting conversation. The developer was trying to tune an expensive SQL statement, using following trial-and-error method:

loop until acceptable performance
    explain plan -> execute SQL with sql trace -> tkprof -> rewrite
end loop;

After looking at his method in amusement, I showed him how to identify and tune SQL statements scientifically, and decided to blog about it.

Let’s look at a simple case and then proceed to slightly more complex versions. The following code fragment creates test tables, indices, and collects statistics on those tables.

 create table t1_vc as
 select trunc(n/10000) n1, mod(n, 1000) n2 ,
          lpad( n,255) c_filler
 from (select level n from dual connect by level <= 100001);
 create index t1_vc_i1 on t1_vc (n1);
 create table t2_vc as
 select trunc(n/ 100) n1, mod(n, 10000) n2 ,
          lpad( n,255) c_filler
 from (select level n from dual connect by level   null, cascade => true);
 exec dbms_stats.gather_table_stats(user, 't2_vc',estimate_percent => null, cascade => true);
 null, cascade => true);
  exec dbms_stats.gather_table_stats(user, 't2_vc',estimate_percent => null, cascade => true);

Simple SQL, but I had to use hints to illustrate the point I’m driving at. Let’s do an explain plan on this SQL.

explain plan for
select /*+ use_nl (t1_vc, t2_vc ) */
t1_vc.n1 , t2_vc.n2
from  t1_vc, t2_vc where
t1_vc.n1 = t2_vc.n1 and t1_vc.n2 between 101 and 105 and t1_vc.n1=1
/
select * from table(dbms_xplan.display)
/

Plan hash value: 3808913109

------------------------------------------------------------------------------------------
| Id  | Operation                     | Name     | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT              |          |  5453 | 81795 |   643   (0)| 00:00:08 |
|   1 |  NESTED LOOPS                 |          |       |       |            |          |
|   2 |   NESTED LOOPS                |          |  5453 | 81795 |   643   (0)| 00:00:08 |
|*  3 |    TABLE ACCESS BY INDEX ROWID| T1_VC    |    55 |   385 |   368   (0)| 00:00:05 |
|*  4 |     INDEX RANGE SCAN          | T1_VC_I1 |  9091 |       |    18   (0)| 00:00:01 |
|*  5 |    INDEX RANGE SCAN           | T2_VC_I1 |   100 |       |     1   (0)| 00:00:01 |
|   6 |   TABLE ACCESS BY INDEX ROWID | T2_VC    |   100 |   800 |     5   (0)| 00:00:01 |
------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   3 - filter(”T1_VC”.”N2″=101)
   4 - access(”T1_VC”.”N1″=1)
   5 - access(”T2_VC”.”N1″=1)

20 rows selected.

The execution plan looks okay, but this statement is executed millions of times, so we need to reduce time as much as possible. Can this SQL be tuned further?

(more…)

We all have encountered this situation many times before: the cost-based optimizer assumes no correlation between two columns (until 11g), and this has the effect of erroneously reducing the cardinality of a row source. Incorrect cardinality estimates are one of many root causes for SQL performance issues. Consider the following example.

This code creates a table and populates data with four columns:

create table t_vc as
select mod(n, 100) n1, mod(n, 100) n2 ,
mod(n, 50) n3 , mod(n, 20) n4
from (select level n from dual connect by level <= 10001);

The first two columns, n1 and n2, have a strong correlation: n1 is always equals to n2.

Let’s collect statistics with histograms on all columns.

begin
dbms_stats.gather_Table_stats( user, 'T_VC', estimate_percent => null, method_opt => 'for all columns size 254');
end;
/

Let’s explain the plan for the query, specifying one predicate, exactly 100 rows with a value of 10.

(more…)