Tunning an Application in 11g

While tuning in development and load test environments, I ask developers to close their sessions (reset the connection pool in weblogic environment) after the required work is traced to get the row source operation in traces to see what "really" happened.

If we experience a performance problem in production (I think every DBA must have faced this), it may not be feasible to close the connections or reset the connection pools.
Is there a way to get the row source operation in production environments without closing the sessions or resetting the connection pools?

When the sessions were not closed, sometimes I used to get row source operation and some times not.

prior to 11g you need to close the session. starting with 11g you don't.  Here is the demo of that.

run this script as such in 10g database.

set serveroutput off;
alter session set sql_trace=true;
select * from emp where deptno = 10;

host
tkprof 
exit
select * from dept where dname is not null;
host
tkprof

and Tkprof shows this.

********************************************************************************

select * from emp
where deptno = 10
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.04       0.37          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2      0.00       0.00          0          4          0           3
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.04       0.37          0          4          0           3
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 61 
Rows     Row Source Operation
-------  ---------------------------------------------------
      3  TABLE ACCESS FULL EMP (cr=4 pr=0 pw=0 time=24 us)

********************************************************************************

select * from dept
where dname is not null
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2      0.00       0.00          0          4          0           4
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.00       0.00          0          4          0           4
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 61 


********************************************************************************

you can see the " row source operation " is missing for the second sql , because the session has not closed. if you close the session you can see "row source operation" in 10g database.

but you don't need that to be done in 11g database. (here is Tkprof output from 11g instance)

********************************************************************************
select * from emp
where deptno = 10
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2      0.00       0.03          0          4          0           3
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.00       0.03          0          4          0           3
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 84 
Rows     Row Source Operation
-------  ---------------------------------------------------
      3  TABLE ACCESS FULL EMP (cr=4 pr=0 pw=0 time=0 us cost=3 size=114 card=3)

********************************************************************************

select * from dept
where dname is not null
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2      0.00       0.00          0          4          0           4
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.00       0.00          0          4          0           4
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 84 
Rows     Row Source Operation
-------  ---------------------------------------------------
      4  TABLE ACCESS FULL DEPT (cr=4 pr=0 pw=0 time=0 us cost=3 size=80 card=4)

********************************************************************************

 

Constraint validation in parallel - seems to be 11g new...

Just learnt something new in Oracle, while testing an application and it seems to be a new behavior introduced with Oracle 11g and not see in previous versions. Here is a demo of it.

I am on 11.2.0.1 and big_table has around 10M record sets.

rajesh@ORA11G> alter table big_table parallel 4;

Table altered.

rajesh@ORA11G> alter session enable parallel dml;

Session altered.

rajesh@ORA11G> exec dbms_application_info.set_client_info('VALIDATE_CONSTRAINT');

PL/SQL procedure successfully completed.

rajesh@ORA11G> alter table big_table
  2  modify id constraint id_not_null
  3  not null novalidate ;

Table altered.

So just preserved the constraint metadata in data dictionary but not validated it.

rajesh@ORA11G> alter table big_table
  2  modify constraint id_not_null
  3  validate;

while this statement runs, monitored this session from different terminal and seems validation happening in parallel.

rajesh@ORA11G> l
  1  select sid,serial#,event,sql_id,
  2    ( select distinct sql_text from v$sql t1 where t1.sql_id = t2.sql_id ) sql_text,t2.last_call_et
  3  from gv$session t2
  4* where client_info='VALIDATE_CONSTRAINT'
rajesh@ORA11G> /
       SID    SERIAL# EVENT                SQL_ID        SQL_TEXT             LAST_CALL_ET
---------- ---------- -------------------- ------------- -------------------- ------------
        18        335 direct path read     dt1u018kpcbpy  select /*+ all_rows           10
        21        890 PX Deq: Execute Repl dt1u018kpcbpy  select /*+ all_rows           10
        22        923 direct path read     dt1u018kpcbpy  select /*+ all_rows           10
       143        814 direct path read     dt1u018kpcbpy  select /*+ all_rows           10

4 rows selected.

but when the same test case repeated on 10.2.0.5 on Linux I don't see any parallel validations.

rajesh@ORA10G> alter table big_table modify id null;

Table altered.

rajesh@ORA10G> alter table big_table noparallel;

Table altered.

rajesh@ORA10G> alter table big_table parallel 4;

Table altered.

rajesh@ORA10G> alter session enable parallel dml;

Session altered.

rajesh@ORA10G> exec dbms_application_info.set_client_info('VALIDATE_CONSTRAINT');

PL/SQL procedure successfully completed.

rajesh@ORA10G> alter table big_table
  2  modify id constraint id_not_null
  3  not null novalidate ;

Table altered.

rajesh@ORA10G> alter table big_table
  2  modify constraint id_not_null
  3  validate;

now, this running gv$session show's me this. (no parallel validation happening)

rajesh@ORA10G> select sid,serial#,event,sql_id,
  2    ( select distinct sql_text from v$sql t1 where t1.sql_id = t2.sql_id ) sql_text,t2.last_call_et
  3  from gv$session t2
  4  where client_info='VALIDATE_CONSTRAINT' ;
       SID    SERIAL# EVENT                SQL_ID        SQL_TEXT             LAST_CALL_ET
---------- ---------- -------------------- ------------- -------------------- ------------
       294      57526 i/o slave wait       dxyabb2qfv82y                                30

1 row selected.

 

Executing DDL - When session is hung...

Here is one situation I encountered when trying to load data into database using parallel dml.

the load was hung and it was WAITING !!

Identify the process at the session level and see what it is waiting on..


uhg_801142427@IRDST01> select sid,serial#,status,event,wait_class,sql_id
  2  from gv$session
  3  where (inst_id,sid,serial#) in
  4    ( select inst_id,sid,serial#
  5      from gv$px_session
  6      where qcsid = 373 )
  7  order by sid ;
       SID    SERIAL# STATUS   EVENT                                              WAIT_CLASS           SQL_ID
---------- ---------- -------- -------------------------------------------------- -------------------- --------------------
       298      32948 INACTIVE PX Deq: Execution Msg                              Idle                 9593s3p3ftvk1
       304      38750 ACTIVE   statement suspended, wait error to be cleared      Configuration        9593s3p3ftvk1
       318      20599 INACTIVE PX Deq: Execution Msg                              Idle                 9593s3p3ftvk1
       327      35082 ACTIVE   statement suspended, wait error to be cleared      Configuration        9593s3p3ftvk1
       336      22952 INACTIVE PX Deq: Execution Msg                              Idle                 9593s3p3ftvk1
       356      47430 INACTIVE PX Deq: Execution Msg                              Idle                 9593s3p3ftvk1
       359      46791 ACTIVE   statement suspended, wait error to be cleared      Configuration        9593s3p3ftvk1
       364      26433 ACTIVE   statement suspended, wait error to be cleared      Configuration        9593s3p3ftvk1
       373      53151 ACTIVE   PX Deq: Execute Reply                              Idle                 9593s3p3ftvk1
9 rows selected.

looking at the wait event I don't have any clue what's wrong in the database. why the "statement suspended" what "wait error" should be cleared?

peeking down to the session wait statistics I still see the same.

uhg_801142427@IRDST01> select inst_id,sid,event,state,p1text,p1,p2text,p2
  2  from gv$session_wait
  3  where (inst_id,sid) in
  4  ( select inst_id,sid
  5      from gv$px_session
  6      where qcsid = 373 ) ;
   INST_ID        SID EVENT                                              STATE               P1TEXT       P1 P2TEXT               P2
---------- ---------- -------------------------------------------------- ------------------- ---------- ------------ ---------- ------------
         1        298 PX Deq: Execution Msg                              WAITING             sleeptime/    268566527 passes              388
                                                                                             senderid
         1        304 statement suspended, wait error to be cleared      WAITING                               0                           0
         1        318 PX Deq: Execution Msg                              WAITING             sleeptime/    268566527 passes              573
                                                                                             senderid
         1        327 statement suspended, wait error to be cleared      WAITING                               0                           0
         1        336 PX Deq: Execution Msg                              WAITING             sleeptime/    268566527 passes              569
                                                                                             senderid
         1        356 PX Deq: Execution Msg                              WAITING             sleeptime/    268566527 passes              574
                                                                                             senderid
         1        359 statement suspended, wait error to be cleared      WAITING                               0                           0
         1        364 statement suspended, wait error to be cleared      WAITING                               0                           0
         1        373 PX Deq: Execute Reply                              WAITING             sleeptime/      200 passes          478
                                                                                             senderid

9 rows selected.

But the real answer to the problem lies in the DBA_RESUMABLE a very handy view to display information's about resumable statements.

uhg_801142427@IRDST01> select instance_id,session_id,status,suspend_time,
  2    error_msg
  3  from dba_resumable
  4  /
INSTANCE_ID SESSION_ID STATUS    SUSPEND_TIME         ERROR_MSG
----------- ---------- --------- -------------------- --------------------------------------------------
          1        364 SUSPENDED 07/04/13 11:17:43    ORA-01652: unable to extend temp segment by 128 in
                                                       tablespace TS_IRADS_DEFAULT
          1        327 SUSPENDED 07/04/13 11:17:43    ORA-01652: unable to extend temp segment by 128 in
                                                       tablespace TS_IRADS_DEFAULT
          1        304 SUSPENDED 07/04/13 11:17:43    ORA-01652: unable to extend temp segment by 128 in
                                                       tablespace TS_IRADS_DEFAULT
          1        359 SUSPENDED 07/04/13 11:17:43    ORA-01652: unable to extend temp segment by 128 in
                                                       tablespace TS_IRADS_DEFAULT

Now looking at this information in dba_resumable, I am very clear that I was running out of the space in Tablespace and added more space to succeed the data loads.