1. Doug Burns
[email protected] http://oracledoug.com @orcldoug #OTW #OakTable 2. Introduction What How Why Structure Example Conclusions and References 01/10/2013 3. Who am I? Why am I talking? Setting Expectations 01/10/2013 4. I am Doug Doug I am << Dr Seuss Edition Actually I am Douglas … or, if you're Scottish, Dougie or Doogie I'm not from England You will have probably noticed that already I don't know many Scottish people who do glowing introductions about their all-round genius! But, amongst other things, I am … 01/10/2013 5. 01/10/2013 6. 01/10/2013 7. 01/10/2013 8. A long time ago in a galaxy far, far away …. "A look under the hood of CBO: The 10053 Event" Wolfgang Breitling (see References) Time passes & beers are consumed & conversations follow … You almost never need to use 10053 trace files They are far too long and complex to understand … and yet … I find myself using them more often I think they're becoming easier to understand 01/10/2013 9. 01/10/2013 10. 10053 files, like most Oracle trace files are Useful in specific situations Very detailed and informative Relatively easy to generate They are also Usually unnecessary Undocumented Subject to change over time Complex in places 01/10/2013 11. Introduction What How Why Structure Example Conclusions and References 01/10/2013 12. Contains a record of the Cost Based Optimizer decision making process and the various inputs used Hard Parse Time As we'll see, it contains Server configuration items that influence the CBO Object and System Statistics used by calculations Execution Plan Steps that were considered and accepted ▪ Resulting in final overall execution plan Execution Plan Steps that were considered and rejected ▪ Including the reasons why 01/10/2013 13. Introduction What How Why Structure Example Conclusions and References 01/10/2013 14. By enabling event 10053 using any of the usual methods Run (or Explain) the SQL statement Disable event Find trace file in user_dump_dest 01/10/2013 show parameter user_dump_dest ALTER SESSION SET tracefile_identifier='EXAMPLE1_10053'; ALTER SESSION SET events '10053 trace name context forever, level 1'; SELECT * FROM dual; ALTER SESSION SET events '10053 trace name context off'; 15. The statement must be hard-parsed The statement must not have been run before Plan has been aged out of cursor cache Shared pool has been flushed New version of the statement by adding a unique comment 01/10/2013 show parameter user_dump_dest ALTER SESSION SET tracefile_identifier='EXAMPLE1_10053_1'; ALTER SESSION SET events '10053 trace name context forever, level 1'; SELECT /* EXAMPLE1_1 */ * FROM dual; ALTER SESSION SET events '10053 trace name context off'; 16. Oracle 11g introduces a new tracing infrastructure Can be accessed using ALTER SESSION ORADEBUG DBMS_SQLDIAG.DUMP_TRACE ▪ Does not require Diagnostics Pack license 01/10/2013 17. Replacement for original method of setting event 10053 Main 10053-related Options SQL_Compiler and SQL_Optimizer 01/10/2013 show parameter user_dump_dest ALTER SESSION SET tracefile_identifier='EXAMPLE1_2_OPTTRACE'; ALTER SESSION SET events 'trace [SQL_Compiler.*]'; SELECT /* EXAMPLE1_2 */ * FROM dual; ALTER SESSION SET events 'trace [SQL_Compiler.*] off'; 18. There are also sub-options 01/10/2013 SQL> oradebug doc component SQL_Compiler SQL_Compiler SQL Compiler SQL_Parser SQL Parser (qcs) SQL_Semantic SQL Semantic Analysis (kkm) SQL_Optimizer SQL Optimizer SQL_Transform SQL Transformation (kkq, vop, nso) SQL_MVRW SQL Materialized View Rewrite SQL_VMerge SQL View Merging (kkqvm) SQL_Virtual SQL Virtual Column (qksvc, kkfi) SQL_APA SQL Access Path Analysis (apa) SQL_Costing SQL Cost-based Analysis (kko, kke) SQL_Parallel_Optimization SQL Parallel Optimization (kkopq) SQL_Code_Generator SQL Code Generator (qka, qkn, qke, kkfd, qkx) SQL_Parallel_Compilation SQL Parallel Compilation (kkfd) SQL_Expression_Analysis SQL Expression Analysis (qke) SQL_Plan_Management SQL Plan Managment (kkopm) MPGE MPGE (qksctx) 19. What if you want to trace just one SQL statement that a Session executes? Perhaps inside a PL/SQL procedure or function Can also specify SQL_ID Still relies on Hard Parse 01/10/2013 show parameter user_dump_dest ALTER SESSION SET tracefile_identifier='EXAMPLE2_OPTTRACE'; ALTER SESSION SET events 'trace [SQL_Compiler.*][sql:37cv4d33vbu8h]'; SELECT /* EXAMPLE1_2 */ * FROM dual; ALTER SESSION SET events 'trace [SQL_Compiler.*] off'; 20. What if you want to trace just one SQL statement and you don't know which session will execute it? Can enable System-wide tracing using ALTER SYSTEM Still relies on Hard Parse 01/10/2013 show parameter user_dump_dest ALTER SYSTEM SET events 'trace [SQL_Compiler.*][sql:bhqn6d93r5r03]'; ALTER SYSTEM SET events 'trace [SQL_Compiler.*] off'; 21. Solves several issues Can show optimizer trace file for a statement that has already been executed and exists in the cursor cache Can force hard parse of the statement Can only use Optimizer or Compiler 01/10/2013 BEGIN dbms_sqldiag.dump_trace( p_sql_id => '37cv4d33vbu8h', p_child_number => 0, p_component => 'Compiler', p_file_id => 'EXAMPLE1_OPTTRACE'); END; / 22. 01/10/2013 Enabling tracing for cur#=10 sqlid=8rhfhbwtndmgc recursive Parsing cur#=10 sqlid=8rhfhbwtndmgc len=61 sql=/* SQL Analyze(216,0) */ SELECT /* EXAMPLE1_2 */ * FROM dual End parsing of cur#=10 sqlid=8rhfhbwtndmgc Semantic Analysis cur#=10 sqlid=8rhfhbwtndmgc OPTIMIZER INFORMATION ****************************************** ----- Current SQL Statement for this session (sql_id=8rhfhbwtndmgc) ----- /* SQL Analyze(216,0) */ SELECT /* EXAMPLE1_2 */ * FROM dual ----- PL/SQL Stack ----- ----- PL/SQL Call Stack ----- object line object handle number name 0xee579040 145 package body SYS.DBMS_SQLTUNE_INTERNAL 0xee579040 12085 package body SYS.DBMS_SQLTUNE_INTERNAL 0xee814bc0 1229 package body SYS.DBMS_SQLDIAG 0xe8c34ab0 2 anonymous block ******************************************* 23. Introduction What How Why Structure Example Conclusions and References 01/10/2013 24. Many ways of viewing the execution plan used for a statement 10046 Trace File DBMS_XPLAN - combined with /*+ gather_plan_statistics */ Real-Time SQL Monitoring Modern options allow comparison of Estimated vs. Actual row source cardinalities E-Rows vs. A-Rows Experience and data knowledge allow educated guesses about what is 'going wrong' 01/10/2013 25. No real overhead Only happens at hard parse Sounds crazy, but even if it doesn't help you, it doesn't hurt to look As long as you don't look for too long! 01/10/2013 26. You've never wondered why that optimiser won't play? Sometimes they are the only way of knowing why the CBO made a specific decision Particularly useful tools here are trace files for 'good' and 'bad' plans and a visual diff tool They are a great way of learning about the CBO and particularly any new features Oracle Support/Optimizer Development Group! 01/10/2013 27. Introduction What How Why Structure Example Conclusions and References 01/10/2013 28. Standard Trace File Pre-amble Query Block Assignment SQL Plan Management Parallel Query/Auto-DOP Predicate Move-Around Optimizer Information Query Transformations Peeked Binds Statistics Computations – Access Paths and Join Orders SQL Statement and Execution Plan dump 01/10/2013 29. 01/10/2013 Trace file /app/ora/local/admin/TEST1102/diag/rdbms/TEST1102_doug/TEST1102/trace/TEST1102_ora_1 450_DOUG_TEST2.trc Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 - 64bit Production With the Partitioning, Automatic Storage Management, OLAP, Data Mining and Real Application Testing options ORACLE_HOME = /app/ora/local/product/11.2.0.2/db_4 System name: Linux Node name: doug Release: 2.6.18-194.11.4.el5 Version: #1 SMP Fri Sep 17 04:57:05 EDT 2010 Machine: x86_64 Instance name: TEST1102 Redo thread mounted by this instance: 1 Oracle process number: 52 Unix process pid: 1450, image: oracle@doug *** 2013-03-18 10:59:58.774 *** SESSION ID:(139.79) 2013-03-18 10:59:58.774 *** CLIENT ID:() 2013-03-18 10:59:58.774 *** SERVICE NAME:(SYS$USERS) 2013-03-18 10:59:58.774 *** MODULE NAME:(TOAD 10.6.1.3) 2013-03-18 10:59:58.774 *** ACTION NAME:() 2013-03-18 10:59:58.774 30. 01/10/2013 Registered qb: SEL$1 0xad486a80 (PARSER) --------------------- QUERY BLOCK SIGNATURE --------------------- signature (): qb_name=SEL$1 nbfros=1 flg=0 fro(0): flg=4 objn=116 hint_alias="DUAL"@"SEL$1" SPM: statement not found in SMB ************************** Automatic degree of parallelism (ADOP) ************************** Automatic degree of parallelism is disabled: Parameter. PM: Considering predicate move-around in query block SEL$1 (#0) ************************** Predicate Move-Around (PM) ************************** 31. 01/10/2013 OPTIMIZER INFORMATION ****************************************** ----- Current SQL Statement for this session (sql_id=a5ks9fhw2v9s1) ----- select * from dual ******************************************* Legend The following abbreviations are used by optimizer trace. CBQT - cost-based query transformation JPPD - join predicate push-down OJPPD - old-style (non-cost-based) JPPD FPD - filter push-down PM - predicate move-around CVM - complex view merging SPJ - select-project-join SJC - set join conversion SU - subquery unnesting OBYE - order by elimination OST - old style star transformation ST - new (cbqt) star transformation CNT - count(col) to count(*) transformation JE - Join Elimination JF - join factorization SLP - select list pruning 32. Oracle 8.1.7 ≈ 50 Oracle 11.2.0.3 > 300 01/10/2013 *************************************** PARAMETERS USED BY THE OPTIMIZER ******************************** ************************************* PARAMETERS WITH ALTERED VALUES ****************************** Compilation Environment Dump _pga_max_size = 2097152 KB ************************************* PARAMETERS WITH DEFAULT VALUES ****************************** Compilation Environment Dump optimizer_mode_hinted = false optimizer_features_hinted = 0.0.0 *************************************** PARAMETERS IN OPT_PARAM HINT **************************** 33. The Optimizer Development group are Busy Bees! As they introduce fixes, they number them and store information about them in V$SYSTEM_FIX_CONTROL Can enable/disable … http://tinyurl.com/5r9zrse Coskan Blog Post 01/10/2013 Bug Fix Control Environment fix 3834770 = 1 fix 3746511 = enabled fix 4519016 = enabled fix 3118776 = enabled fix 4488689 = enabled fix 2194204 = disabled fix 2660592 = enabled 34. 01/10/2013 Considering Query Transformations on query block SEL$1 (#0) ************************** Query transformations (QT) ************************** JF: Checking validity of join factorization for query block SEL$1 (#0) JF: Bypassed: not a UNION or UNION-ALL query block. ST: not valid since star transformation parameter is FALSE TE: Checking validity of table expansion for query block SEL$1 (#0) TE: Bypassed: No partitioned table in query block. CBQT bypassed for query block SEL$1 (#0): no complex view, sub-queries or UNION (ALL) queries. CBQT: Validity checks failed for a5ks9fhw2v9s1. CSE: Considering common sub-expression elimination in query block SEL$1 (#0) Exadata/11g Upgrade project optimizer_features_enable – 10.2.0.4 Cost-based query transformation http://tinyurl.com/c6wdhxv - Jonathan Lewis Blog Post 35. 01/10/2013 ************************* Common Subexpression elimination (CSE) ************************* CSE: CSE not performed on query block SEL$1 (#0). OBYE: Considering Order-by Elimination from view SEL$1 (#0) *************************** Order-by elimination (OBYE) *************************** OBYE: OBYE bypassed: no order by to eliminate. CVM: Considering view merge in query block SEL$1 (#0) query block SEL$1 (#0) unchanged Considering Query Transformations on query block SEL$1 (#0) ************************** Query transformations (QT) ************************** JF: Checking validity of join factorization for query block SEL$1 (#0) JF: Bypassed: not a UNION or UNION-ALL query block. ST: not valid since star transformation parameter is FALSE TE: Checking validity of table expansion for query block SEL$1 (#0) TE: Bypassed: No partitioned table in query block. CBQT bypassed for query block SEL$1 (#0): no complex view, sub-queries or UNION (ALL) queries. CBQT: Validity checks failed for a5ks9fhw2v9s1. 36. 01/10/2013 SYSTEM STATISTICS INFORMATION ----------------------------- Using NOWORKLOAD Stats CPUSPEEDNW: 1416 millions instructions/sec (default is 100) IOTFRSPEED: 4096 bytes per millisecond (default is 4096) IOSEEKTIM: 10 milliseconds (default is 10) MBRC: -1 blocks (default is 32) *************************************** BASE STATISTICAL INFORMATION *********************** Table Stats:: Table: DUAL Alias: DUAL #Rows: 1 #Blks: 1 AvgRowLen: 2.00 ChainCnt: 0.00 Access path analysis for DUAL *************************************** SINGLE TABLE ACCESS PATH Single Table Cardinality Estimation for DUAL[DUAL] Table: DUAL Alias: DUAL Card: Original: 1.000000 Rounded: 1 Computed: 1.00 Non Adjusted: 1.00 Access Path: TableScan Cost: 2.00 Resp: 2.00 Degree: 0 Cost_io: 2.00 Cost_cpu: 9893 Resp_io: 2.00 Resp_cpu: 9893 Best:: AccessPath: TableScan Cost: 2.00 Degree: 1 Resp: 2.00 Card: 1.00 Bytes: 0 37. 01/10/2013 OPTIMIZER STATISTICS AND COMPUTATIONS *************************************** GENERAL PLANS *************************************** Considering cardinality-based initial join order. Permutations for Starting Table :0 Join order[1]: DUAL[DUAL]#0 *********************** Best so far: Table#: 0 cost: 2.0005 card: 1.0000 bytes: 2 *********************** (newjo-stop-1) k:0, spcnt:0, perm:1, maxperm:2000 ********************************* Number of join permutations tried: 1 ********************************* This is the section that gets very complicated very quickly! 38. 01/10/2013 Plan Table ============ -------------------------------------+-----------------------------------+ | Id | Operation | Name | Rows | Bytes | Cost | Time | -------------------------------------+-----------------------------------+ | 0 | SELECT STATEMENT | | | | 2 | | | 1 | TABLE ACCESS FULL | DUAL | 1 | 2 | 2 | 00:00:01 | -------------------------------------+-----------------------------------+ Content of other_xml column =========================== db_version : 11.2.0.2 parse_schema : RRS_CORE_DBO plan_hash : 272002086 plan_hash_2 : 4017058736 Outline Data: /*+ BEGIN_OUTLINE_DATA IGNORE_OPTIM_EMBEDDED_HINTS OPTIMIZER_FEATURES_ENABLE('11.2.0.2') DB_VERSION('11.2.0.2') ALL_ROWS OUTLINE_LEAF(@"SEL$1") FULL(@"SEL$1" "DUAL"@"SEL$1") END_OUTLINE_DATA */ 39. Introduction What How Why Structure Example Conclusions and References 01/10/2013 40. Introduction What How Why Structure Example Conclusions and References 01/10/2013 41. Many ways of viewing the execution plan used for a statement All show you the numbers that the CBO is using and the resulting plan EXPLAIN Plan etc Some show you the real numbers SQL Monitor Reports and other Plan Statistics approaches Only a optimizer trace file can truly show you why there is a discrepancy Sometimes ;-) 01/10/2013 42. Cost Based Oracle Fundamentals - Appendix Jonathan Lewis http://tinyurl.com/bxxl6 Under the hood of the CBO Wolfgang Breitling http://tinyurl.com/bxxl6 Using new 11g tracing infrastructure to generate files Optimizer Development Group (Maria Colgan) http://tinyurl.com/brcryva and http://tinyurl.com/cr5kz8t Greg Rahn http://tinyurl.com/bupmehx 01/10/2013 43. My Blog Posts http://oracledoug.com Recent Blog Post http://jonathanlewis.wordpress.com Thanks Wolfgang Breitling Maria Colgan & Greg Rahn Jonathan Lewis To you, for listening 01/10/2013 44. Doug Burns
[email protected] http://oracledoug.com @orcldoug #OTW #OakTable