1 / 42

10053 Trace Files (Mostly Harmless)

Doug Burns @ orcldoug # oug_scot. 10053 Trace Files (Mostly Harmless). Introduction. Introduction What How Why Structure Example Conclusions and References. Introduction. Who am I? Why am I talking? Setting Expectations. Who am I?. I am Doug Doug I am << Dr Seuss Edition

mahlah
Download Presentation

10053 Trace Files (Mostly Harmless)

An Image/Link below is provided (as is) to download presentation Download Policy: Content on the Website is provided to you AS IS for your information and personal use and may not be sold / licensed / shared on other websites without getting consent from its author. Content is provided to you AS IS for your information and personal use only. Download presentation by click this link. While downloading, if for some reason you are not able to download a presentation, the publisher may have deleted the file from their server. During download, if you can't get a presentation, the file might be deleted by the publisher.

E N D

Presentation Transcript

  1. Doug Burns @orcldoug #oug_scot 10053 Trace Files(Mostly Harmless)

  2. Introduction • Introduction • What • How • Why • Structure • Example • Conclusions and References

  3. Introduction • Who am I? • Why am I talking? • Setting Expectations

  4. Who am I? • 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 …

  5. A Bitter Old Man

  6. A Corporate Sell-Out

  7. A Family Man

  8. Why am I talking? • 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

  9. Setting Expectations • Although 10053 files are • Sometimes useful • Mostly Harmless • They are also • Usually unnecessary • Undocumented • Subject to change over time • Complex in places

  10. What • Introduction • What • How • Why • Structure • Example • Conclusions and References

  11. What is a 10053 Trace File? • Contains a record of the Cost Based Optimizer decision making process and the various inputs used • 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

  12. How • Introduction • What • How • Why • Structure • Example • Conclusions and References

  13. How were they generated? • 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 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';

  14. How were they generated? • 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 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';

  15. How are they generated? • Oracle 11g introduces a new tracing infrastructure • Can be accessed using • ALTER SESSION • ORADEBUG • DBMS_SQLDIAG.DUMP_TRACE • Does not require Diagnostics Pack license

  16. How are they generated? • Replacement for original method of setting event 10053 • Options are SQL_Compiler and SQL_Optimizer • There are also sub-options but I've never used them 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';

  17. How are they generated? • 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 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';

  18. How are they generated? • 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 show parameter user_dump_dest ALTER SYSTEM SET events 'trace [SQL_Compiler.*][sql:bhqn6d93r5r03]'; ALTER SYSTEM SET events 'trace [SQL_Compiler.*] off';

  19. How are they generated? • 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 BEGIN dbms_sqldiag.dump_trace( p_sql_id => '37cv4d33vbu8h', p_child_number => 0, p_component => 'Compiler', p_file_id => 'EXAMPLE1_OPTTRACE'); END; /

  20. How are they generated? 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 *******************************************

  21. Why • Introduction • What • How • Why • Structure • Example • Conclusions and References

  22. Why are they Usually Unnecessary? • Many ways of viewing the execution plan used for a statement • 10046 Trace File • DBMS_XPLAN • 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'

  23. Why are they Mostly Harmless? • 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!

  24. Why are they Sometimes Useful? • Really? You've never wondered why that optimiser won't play along? • Sometimes they are the only way of knowing why the CBO made a specific decision • They are a great way of learning about the CBO and particularly any new features • Oracle Support/Optimizer Development Group!

  25. Structure • Introduction • What • How • Why • Structure • Example • Conclusions and References

  26. SELECT * FROM DUAL; • 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

  27. Pre-amble Trace file /app/ora/local/admin/TEST1102/diag/rdbms/TEST1102_doug/TEST1102/trace/TEST1102_ora_1450_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

  28. Query Blocks, SPM, Parallel and PM 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) **************************

  29. Optimizer Information 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 - subqueryunnesting 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

  30. Parameters *************************************** 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 **************************** • Oracle 8.1.7 ≈ 50 • Oracle 11.2.0.3 > 300

  31. fix_control Environment • 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 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

  32. Query Transformations 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

  33. Query Transformations ************************* 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.

  34. Statistics 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

  35. Computations – Join Orders etc 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!

  36. SQL Statement and Plan 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 */

  37. Example • Introduction • What • How • Why • Structure • Example • Conclusions and References

  38. Conclusions and References • Introduction • What • How • Why • Structure • Example • Conclusions and References

  39. Conclusions • 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 • Some show you the real numbers • Only a optimizer trace file can truly show you why there is a discrepancy • Sometimes ;-)

  40. References • 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/brcryvaand http://tinyurl.com/cr5kz8t • Greg Rahn http://tinyurl.com/bupmehx

  41. References & Acknowledgments • My Blog Posts • http://oracledoug.com • Recent Blog Post • http://jonathanlewis.wordpress.com • Thanks • Wolfgang Breitling • Maria Colgan & Greg Rahn • Jonathan Lewis << Late addition • To Thomas Presslie and UKOUG for bringing me back home • To you, for listening

  42. Doug Burns dougburns@yahoo.com http://oracledoug.com @orcldoug #oug_scot Optimizer Trace Files(Mostly Harmless)

More Related