Process state dump needed to trouble shoot an ORA-600

Per Oracle Support, we need to generate a process state dump when an ORA-600 [17074] error occurs. I put together the commands in a small script called pdump.sql to do this task. This error has already crashed our production database several times.

The plan is once the ORA-600 hits, find the first trace file that causes it. At the top of the file , we should see the 'LOCK OWNERS' section, looks like:

LOCK OWNERS:
lock user session count mode flags
-------- -------- -------- ----- ---- ------------------------
5311a3900 510a1c370 510a1c370 1 N PNS/[08]
531372200 512a23348 512a23348 1 N [00]
5233801c0 513a18980 513a18980 1 N PNS/[08]
5311c3440 51b148020 51b148020 1 N PNS/[08]
531280c00 50fa23be8 50fa23be8 1 N PNS/[08]
:
53135ef00 50ea46a08 50ea46a08 1 N PNS/[08]

We note down the session address column(third one).

Then we login as sysdba, to do:

SQL> @pdump 510a1c370
SQL> @pdump 512a23348

so on and so forth for the first few.

Here is a test output for the pdump script:

sys@TESTDB> @pdump 3b4333248
sys@TESTDB> select p.pid
2 from v$session s, v$process p
3 where s.paddr = p.addr
4 and s.saddr in (upper(lpad('&1',16,'0')))
5 ;
old 4: and s.saddr in (upper(lpad('&1',16,'0')))
new 4: and s.saddr in (upper(lpad('3b4333248',16,'0')))

PID
----------
70

sys@TESTDB>
sys@TESTDB> oradebug setorapid &OPID
Unix process pid: 13818, image: oracle@testserv2(TNS V1-V3)
sys@TESTDB> oradebug unlimit
Statement processed.
sys@TESTDB> oradebug dump processstate 266
Statement processed.
sys@TESTDB> oradebug tracefile_name
/apps/opt/oracle/admin/testdb/udump/testdb_ora_13818.trc
sys@TESTDB> set echo off

DELETE statement executed even using set autotrace traceonly explain

Normally, when you issue 'set autotrace traceonly explain', then execute the SQL statement in order to get its execution plan, the SQL won't get executed actually. However, I realized that this is not true for 'DELETE' statement. Below is a test case:

SQL> select * from v$version;

BANNER
----------------------------------------------------------------
Oracle Database 10g Enterprise Edition Release 10.2.0.1.0 - 64bi
PL/SQL Release 10.2.0.1.0 - Production
CORE    10.2.0.1.0      Production
TNS for Solaris: Version 10.2.0.1.0 - Production
NLSRTL Version 10.2.0.1.0 - Production

SQL>
SQL> drop table t;

Table dropped.

SQL>
SQL> create table t
  2  as
  3  select rownum id,
  4    a.*
  5  from all_objects a where rownum <= 1000;

Table created.

SQL>
SQL> create index  t_ix on t(id);

Index created.

SQL>
SQL> execute dbms_stats.gather_table_stats(user,'t', cascade=>true);

PL/SQL procedure successfully completed.

SQL>
SQL> select count(*) from t;

  COUNT(*)
----------
      1000

SQL>
SQL>
SQL> set autotrace traceonly explain
SQL> delete from t where  id >=500;

501 rows deleted.


Execution Plan
----------------------------------------------------------
Plan hash value: 2466302700

--------------------------------------------------------------------------
 Id   Operation          Name  Rows   Bytes  Cost (%CPU) Time   
--------------------------------------------------------------------------
   0  DELETE STATEMENT           502   2008      3   (0) 00:00:01
   1   DELETE            T                                      
*  2    INDEX RANGE SCAN T_IX    502   2008      3   (0) 00:00:01
--------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - access("ID">=500)

SQL>
SQL> set autotrace off
SQL>
SQL> select count(*) from t;

  COUNT(*)
----------
       499

I also tested "explain plan for". We see the delete statement is not actually executed in this case.

SQL>
SQL> explain plan for
  2  delete from t;

Explained.


PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------
Plan hash value: 2034385699

---------------------------------------------------------------------------
 Id   Operation           Name  Rows   Bytes  Cost (%CPU) Time   
---------------------------------------------------------------------------
   0  DELETE STATEMENT           1000   4000      5   (0) 00:00:01
   1   DELETE             T                                      
   2    TABLE ACCESS FULL T      1000   4000      5   (0) 00:00:01
---------------------------------------------------------------------------

9 rows selected.

SQL> select count(*) from t;

  COUNT(*)
----------
       499

Generate script to transfer data files with compression through SSH

Recently, I have used the following SQL to generate scripts for transferring data files in order to clone an open database. Some explanation about a similar task can be seen in this previous post

select case when mod(rn,10) = 0
then
'ssh srcserv ' || '''cat ' || file_name || 
' | gzip -c '' | gunzip -c > ' || file_name || ' &'
|| chr(10) ||
'wait ' || chr(10) ||
'echo "`date` rn: ' || rn || '" >> $LOGFILE'|| chr(10)
else
'ssh srcserv ' || '''cat ' || file_name || 
' | gzip -c '' | gunzip -c > ' || file_name || ' &'
end
from
( 
select file_name, row_number() over ( order by bytes desc ) rn 
from dba_data_files
where tablespace_name=upper('&tabspacename') 
)
/

pfile and spfile - more to learn

I thought I was quite knowlegable about spfile/pfile, especially after reading Tom Kyte's book: Expert Oracle Database Architecure Chapter 3 Files. However, weeks ago, I saw a pfile that has only one line for one of our production databases. This puzzled me for a while. Today I decided to have a test.

The line looks similiar to:
spfile=/path/to/spfile/spfileSID.ora

I was told our VCS cluster software uses pfile to start up the db. I can not confirm if this is necessary. But most likely this is why the DBA creates such a pfile. And I don't know we can do this, this is the point - one can always learn something new about Oracle.

In my test environment (10.2.0), I have a spfile under this location:

vmlinux1:/app/oracle/product/10.2.0/db_1/dbs/temp [DBT10G] $ ls
spfileDBT10G.ora

I have a pfile at stardand default location and it has only one line to tell oracle where the spfile is.

vmlinux1:/app/oracle/product/10.2.0/db_1/dbs [DBT10G] $ cat initDBT10G.ora
spfile='/app/oracle/product/10.2.0/db_1/dbs/temp/spfileDBT10G.ora'


Now I start the DB with pfile:

vmlinux1:/app/oracle/product/10.2.0/db_1/dbs [DBT10G] $ sqlplus /nolog

SQL*Plus: Release 10.2.0.1.0 - Production on Tue Jul 21 14:40:49 2009

Copyright (c) 1982, 2005, Oracle. All rights reserved.

idle> conn / as sysdba
Connected to an idle instance.
idle> startup pfile='/app/oracle/product/10.2.0/db_1/dbs/initDBT10G.ora';
ORACLE instance started.

Total System Global Area 268435456 bytes
Fixed Size 1218920 bytes
Variable Size 92276376 bytes
Database Buffers 171966464 bytes
Redo Buffers 2973696 bytes
Database mounted.
Database opened.

When checking the parameter spfile, we can see the value is the full name of the spfile. So It looks like Oracle knows that it is started up with a spfile actually.

idle> show parameter spfile

NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
spfile string /app/oracle/product/10.2.0/db_1/dbs/temp/spfileDBT10G.ora

Having troubles in creating a database link

Today, I have spent quite some time to try to get a db link from a 10g db (DBWRKEV1) to a 9i db (DBWRK920) work.

At DBWRKEV1, we can see the global_name has a funny suffix.

z9xxx94@DBWRKEV1> select * from global_name;

GLOBAL_NAME
---------------------------------------------------------
DBWRKEV1.REGRESS.RDBMS.DEV.US.ORACLE.COM


Based on this post, I tried to remove it by this way:


SQL> show user;
USER is "SYS"
SQL> update GLOBAL_NAME SET GLOBAL_NAME='DBWRKEV1';

1 row updated.

SQL> commit;

Commit complete.

z9xxx94@DBWRKEV1> select * from global_name;

GLOBAL_NAME
---------------------------------------------
DBWRKEV1

Then, I tried to create the db link again:

z9xxx94@DBWRKEV1> create database link dbwrk920 connect to z9xxx94 identified by vxxx using 'dbwrk920';

Database link created.

z9xxx94@DBWRKEV1> select * from global_name@dbwrk920;
select * from global_name@dbwrk920
*
ERROR at line 1:
ORA-02085: database link DBWRK920.REGRESS.RDBMS.DEV.US.ORACLE.COM connects to DBWRK920


Still, I have not succeeded. It should be noted that the initialization parameter global_names is TRUE in the DBWRKEV1(10g)

Finally, I was able to use the db link through following approach:


At DBWRK920


z9xxx94@DBWRK920> select * from global_name;

GLOBAL_NAME
---------------------------------------------------------------------------
DBWRK920

z9xxx94@DBWRK920> alter database rename global_name to dbwrk920.world;

Database altered.

z9xxx94@DBWRK920> select * from global_name;

GLOBAL_NAME
---------------------------------------------------------------------------
DBWRK920.WORLD


At DBWRKEV1


z9xxx94@DBWRKEV1> create database link dbwrk920.world connect to z9xxx94 identified by vxxx using 'dbwrk920';

Database link created.


z9xxx94@DBWRKEV1>
z9xxx94@DBWRKEV1> select * from global_name@dbwrk920.world;

GLOBAL_NAME
--------------------------------------------------------------
DBWRK920.WORLD

Explore SQL Profiles - Part II

Explore SQL Profiles - Part I can be found here.

More than often, it turns out my task is to explore what other people have already explored. Thanks google, more than often, I can find the right experts who are willing to share their knowledge. Below are the two posts about SQL Profiles that makes this happen.

Plan stability in 10g - using existing cursors to create Stored Outlines and SQL profiles by Randolf Geist

SQL Profiles by Kerry Osborne

What I am going to describe is my personal experience about exploring SQL Profiles in order to deal with a problem SQL in the production environment.

The following query in one of our production 10g database has sub-optimal execution plan:

SELECT COUNT(SESSION_KEY) FROM RMS WHERE cust_btn='8136777776' AND
SESSION_KEY like 'BillingSummary%' AND LAST_ACCESS_DATE >= (SYSDATE-1)There are hundreds of such kind of queries that are only different in the literals are runing at any time during the day. Yeah, they do not use bind variables. This is not my concern in my position now. I rememberred once they said for some reason, they can not adopt bind variables. The table is truncated every night, and it then grows from 0 to about 200K rows prior to being truncated. There are an index on SESSION_KEY column and another index on cust_btn column. The bad plan uses the index on SESSION_KEY, while the good plan uses the index on cust_btn.

I have tried to use DBMS_SQLTUNE package to generate a SQL Profile to accept automatically, however, Oracle have not given any recommenations (first time due to stale stats, after gathering stats, no lucky either). This left me the choice to create it manually. My steps are as follows:

(1) Execute the sql with hint on good index and display the outline

SQL> SELECT /*+ index (RMS,IX_CUST_BTN_RMAS ) */
  2          COUNT(SESSION_KEY) FROM RMS WHERE cust_btn='8136777776' AND
  3      SESSION_KEY like 'BillingSummary%' AND LAST_ACCESS_DATE >= (SYSDATE-1);

COUNT(SESSION_KEY)
------------------
                 1

Elapsed: 00:00:00.00
SQL>
SQL> select * from table(dbms_xplan.display_cursor(null,null,'OUTLINE'));

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------
SQL_ID  b5mp8fdcxdxav, child number 0
-------------------------------------
SELECT /*+ index (RMS,IX_CUST_BTN_RMAS ) */         COUNT(SESSION_KEY) FROM
RMS WHERE cust_btn='8136777776' AND     SESSION_KEY like 'BillingSummary%'
AND LAST_ACCESS_DATE >= (SYSDATE-1)

Plan hash value: 2513418175

----------------------------------------------------------------------------------------
 Id   Operation                     Name               Rows   Bytes  Cost (%CPU) Time
----------------------------------------------------------------------------------------
   0  SELECT STATEMENT                                                   7 (100)     
   1   SORT AGGREGATE                                      1     69                  
*  2    TABLE ACCESS BY INDEX ROWID RMS      1     69      7   (0) 00:00:01
*  3     INDEX RANGE SCAN           IX_CUST_BTN_RMAS       7             1   (0) 00:00:01
-----------------------------------------------------------------------------------------

Outline Data
-------------

  /*+
      BEGIN_OUTLINE_DATA
      IGNORE_OPTIM_EMBEDDED_HINTS
      OPTIMIZER_FEATURES_ENABLE('10.2.0.4')
      ALL_ROWS
      OUTLINE_LEAF(@"SEL$1")
      INDEX_RS_ASC(@"SEL$1" "RMS"@"SEL$1" ("RMS"."CUST_BTN"))
      END_OUTLINE_DATA
  */

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - filter(("SESSION_KEY" LIKE 'BillingSummary%' AND "LAST_ACCESS_DATE">=SYSDATE@!-1))
   3 - access("CUST_BTN"='8136777776')

(2) Create a SQL Profile manually.

Note: using the outline info otained in (1) to specify the profile attribute.

begin
dbms_sqltune.import_sql_profile(
   name => 'profile_myacc_2',
   description => 'SQL profile created manually',
   category => 'TEST',
   sql_text => q'[SELECT COUNT(SESSION_KEY) FROM RMS WHERE cust_btn='8136777776' AND SESSION_KEY like 'BillingSummary%' AND LAST_ACCESS_DATE >= (SYSDATE-1)]',
   profile => sqlprof_attr(
        'IGNORE_OPTIM_EMBEDDED_HINTS',
        'ALL_ROWS',
        'OUTLINE_LEAF(@"SEL$1")',
        'INDEX_RS_ASC(@"SEL$1" "RMS"@"SEL$1" ("RMS"."CUST_BTN"))'
   ),
   replace => FALSE,
   force_match => TRUE
);
end;
/

(3) Verify the SQL profile can be used

a. Without using the profile, consistent gets= 17999

SQL> set autotrace on
SQL> SELECT COUNT(SESSION_KEY) FROM RMS WHERE cust_btn='6095884091' AND
 SESSION_KEY like 'LinkSummary%' AND LAST_ACCESS_DATE >= (SYSDATE-1)  2
  3  ;

COUNT(SESSION_KEY)
------------------
                 1


Execution Plan
----------------------------------------------------------
Plan hash value: 769759756

---------------------------------------------------------------------------------
 Id   Operation                     Name               Rows   Bytes  Cost (%CPU) Time 
----------------------------------------------------------------------------------------
   0  SELECT STATEMENT                                     1     69      4   (0) 00:00:01
   1   SORT AGGREGATE                                      1     69                   
*  2    TABLE ACCESS BY INDEX ROWID RMS                    1     69      4   (0) 00:00:01
*  3     INDEX RANGE SCAN           IX_MYACC_SUM_KEY       1             3   (0) 00:00:01
------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - filter("CUST_BTN"='6095884091' AND "LAST_ACCESS_DATE">=SYSDATE@!-1)
   3 - access("SESSION_KEY" LIKE 'LinkSummary%')
       filter("SESSION_KEY" LIKE 'LinkSummary%')


Statistics
----------------------------------------------------------
          1  recursive calls
          0  db block gets
      17990  consistent gets
          0  physical reads
          0  redo size
        525  bytes sent via SQL*Net to client
        488  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

b. With the profile, consistent gets= 7

SQL> alter session set sqltune_category=test;

Session altered.

SQL> SELECT COUNT(SESSION_KEY) FROM RMS WHERE cust_btn='6095884091' AND
 SESSION_KEY like 'LinkSummary%' AND LAST_ACCESS_DATE >= (SYSDATE-1)  2  ;

COUNT(SESSION_KEY)
------------------
                 1


Execution Plan
----------------------------------------------------------
Plan hash value: 2513418175

--------------------------------------------------------------------------------
 Id   Operation                     Name               Rows   Bytes  Cost (%CPU) Time
--------------------------------------------------------------------------------------
   0  SELECT STATEMENT                                     1     69      7   (0) 00:00:01
   1   SORT AGGREGATE                                      1     69                  
*  2    TABLE ACCESS BY INDEX ROWID RMS                    1     69      7   (0) 00:00:01
*  3     INDEX RANGE SCAN           IX_CUST_BTN_RMAS       7             1   (0) 00:00:01
----------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - filter("SESSION_KEY" LIKE 'LinkSummary%' AND "LAST_ACCESS_DATE">=SYSDATE@!-1)
   3 - access("CUST_BTN"='6095884091')

Note
-----
   - SQL profile "profile_myacc_2" used for this statement

Statistics
----------------------------------------------------------
          0  recursive calls
          0  db block gets
          7  consistent gets
          0  physical reads
          0  redo size
        525  bytes sent via SQL*Net to client
        488  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

Sep 16, 2013 update:

A tool called SQLT provides a script called coe_xfr_sql_profile.sql that can be used to create a sql profile in a very convenient way.

see: SQLT (SQLTXPLAIN) - Tool that helps to diagnose a SQL statement performing poorly or one that produces wrong results (Doc ID 215187.1)