{"id":344,"date":"2016-01-21T23:35:26","date_gmt":"2016-01-21T23:35:26","guid":{"rendered":"http:\/\/nenadnoveljic.com\/blog\/?p=344"},"modified":"2017-02-14T20:39:57","modified_gmt":"2017-02-14T20:39:57","slug":"excessive-query-parsing-time-with-long-in-lists-and-extended-statistics","status":"publish","type":"post","link":"https:\/\/nenadnoveljic.com\/blog\/excessive-query-parsing-time-with-long-in-lists-and-extended-statistics\/","title":{"rendered":"Excessive query parsing time with extended statistics and long in-lists"},"content":{"rendered":"<p>Recently, I spotted several sessions in a long &#8220;cursor: pin S wait on X&#8221; wait. The waiters and the mutex holder ( the blocker) executed the same query. The blocker was burning CPU and the 10046 trace was not showing any progress. After turning on the 10053 trace it became obvious that the cursor was\u00a0still parsed.\u00a0After 20 minutes the parsing was not completed yet! Over and over again, the optimizer took more time for the same operation &#8211; calculating selectivity from the extended statistics:<\/p>\n<pre><code>ColGroup Usage:: PredCnt: 4  Matches Full: #1  Partial:<\/code><\/pre>\n<p>I sampled the Oracle dedicated process with pstack and found out that the process spent most of the time in the function kkestGetMCSelInlist. The name implies that the function has something to do with in lists. Indeed, the query &#8211; coming from a software vendor &#8211; was quite unusual in this respect: it had 11 in-lists each containing 90 elements! The search on the bug database with the keyword kkestGetMCSelInlist returned a known bug 16825679 : PARSING NEVER ENDS. The suggested workaround &#8211; setting the undocumented parameter _optimizer_extended_stats_usage_control to 224 &#8211; reduced the parsing time from 30 minutes to a couple of seconds.<\/p>\n<p>What did happen here?<\/p>\n<p>The bug note doesn&#8217;t describe what exactly got changed after the new value was set. Therefore, I compared the 10053 traces with and without the workaround and found out that the extended statistics have not been used at all after setting the parameter:<\/p>\n<pre><code>_optimizer_extended_stats_usage_control=default\r\nColGroup Usage:: PredCnt: 4  Matches Full: <span style=\"color: #ff0000;\">#1<\/span>  Partial:\r\n\r\n_optimizer_extended_stats_usage_control=224\r\nColGroup Usage:: PredCnt: 4  Matches Full:  Partial:\r\n=&gt; no matches in this case\r\n<\/code><\/pre>\n<p>But, are the extended statistics completely disabled now or just in some cases? As I couldn&#8217;t find any details on this hidden parameter on Metalink, I decided to set up a test case in order to understand the impact of the change.<\/p>\n<p>First, to set the scene, I am creating a table with two columns and the extended statistics:<\/p>\n<pre><code>CREATE TABLE t\r\n  AS\r\n  SELECT rownum n1, rownum AS n2\r\n    FROM dual\r\n    CONNECT BY level &lt;= 1000; \r\n\r\nSELECT dbms_stats.create_extended_stats(\r\n  ownname=&gt;user, tabname=&gt;'t', extension=&gt;'(n1,n2)')\r\n  FROM dual;\r\n\r\nexecute dbms_stats.gather_table_stats(user,'t') ;\r\n<\/code><\/pre>\n<p>Second, I&#8217;m running the explain plan for two queries with both columns in the where clause. The one query has the equal filter predicates, the other has an in-list.<\/p>\n<pre><code>EXPLAIN PLAN FOR\r\n  SELECT *\r\n  FROM t\r\n  WHERE n1 = 1 AND n2 = 1 ;\r\n\r\n--10053 trace: ColGroup Usage:: PredCnt: 2  Matches Full: #1  Partial:  Sel: 0.001000\r\n\r\nEXPLAIN PLAN FOR\r\n  SELECT *\r\n  FROM t\r\n  WHERE n1 = 42 AND n2 in ( 42 ,43) ;\r\n\r\n--10053 trace: ColGroup Usage:: PredCnt: 2  Matches Full: #1  Partial:  Sel: 0.002000\r\n<\/code><\/pre>\n<p>As expected, the optimizer 10053 trace provides the evidence that the extended statics were used in both queries.<\/p>\n<p>Finally, both queries will be executed again, but this time with _optimizer_extended_stats_usage_control set to 224.<\/p>\n<pre><code>alter session set \"_optimizer_extended_stats_usage_control\"=224 ;\r\n\r\nEXPLAIN PLAN FOR\r\n  SELECT *\r\n  FROM t\r\n  WHERE n1 = 42 AND n2 <span style=\"color: #ff0000;\">in<\/span> ( 42 ,43) ;\r\n\r\n<span style=\"color: #ff0000;\">--10053: no lines with ColGroup Usage found in the trace!\r\n<\/span>\r\nEXPLAIN PLAN FOR\r\n  SELECT  *\r\n  FROM t\r\n  WHERE n1 = 1 AND n2 = 1 ;\r\n\r\n--10053 trace: ColGroup Usage:: PredCnt: 2  Matches Full: #1  Partial:  Sel: 0.001000\r\n<\/code><\/pre>\n<p>In conclusion, when _optimizer_extended_stats_usage_control is set to 224 the extended events are not used just in the case of the in-list in the where clause. In the case of equal predicates, the extended statistics are used.<\/p>\n","protected":false},"excerpt":{"rendered":"<p>Excessive query parsing time with extended events and long in lists were observed on a 12c database. As a workaround set the undocumented parameter _optimizer_extended_stats_usage_control to 224. <a href=\"https:\/\/nenadnoveljic.com\/blog\/excessive-query-parsing-time-with-long-in-lists-and-extended-statistics\/\" class=\"more-link\">Continue Reading <span class=\"meta-nav\">&rarr;<\/span><\/a><\/p>\n","protected":false},"author":1,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"inline_featured_image":false,"footnotes":""},"categories":[8,11,5,20],"tags":[],"class_list":["post-344","post","type-post","status-publish","format-standard","hentry","category-12c","category-cost-based-optimizer","category-oracle","category-slow-parsing"],"yoast_head":"<!-- This site is optimized with the Yoast SEO plugin v27.4 - https:\/\/yoast.com\/product\/yoast-seo-wordpress\/ -->\n<title>Excessive query parsing time with extended statistics and long in-lists - All-round Database Topics<\/title>\n<meta name=\"description\" content=\"Excessive query parsing time with extended events and long in lists were observed on a 12c database.\u00a0As a\u00a0workaround set the undocumented parameter _optimizer_extended_stats_usage_control to 224.\" \/>\n<meta name=\"robots\" content=\"index, follow, max-snippet:-1, max-image-preview:large, max-video-preview:-1\" \/>\n<link rel=\"canonical\" href=\"https:\/\/nenadnoveljic.com\/blog\/excessive-query-parsing-time-with-long-in-lists-and-extended-statistics\/\" \/>\n<meta property=\"og:locale\" content=\"en_US\" \/>\n<meta property=\"og:type\" content=\"article\" \/>\n<meta property=\"og:title\" content=\"Excessive query parsing time with extended statistics and long in-lists - All-round Database Topics\" \/>\n<meta property=\"og:description\" content=\"Excessive query parsing time with extended events and long in lists were observed on a 12c database.\u00a0As a\u00a0workaround set the undocumented parameter _optimizer_extended_stats_usage_control to 224.\" \/>\n<meta property=\"og:url\" content=\"https:\/\/nenadnoveljic.com\/blog\/excessive-query-parsing-time-with-long-in-lists-and-extended-statistics\/\" \/>\n<meta property=\"og:site_name\" content=\"All-round Database Topics\" \/>\n<meta property=\"article:published_time\" content=\"2016-01-21T23:35:26+00:00\" \/>\n<meta property=\"article:modified_time\" content=\"2017-02-14T20:39:57+00:00\" \/>\n<meta name=\"author\" content=\"Nenad Noveljic\" \/>\n<meta name=\"twitter:card\" content=\"summary_large_image\" \/>\n<meta name=\"twitter:creator\" content=\"@NenadNoveljic\" \/>\n<meta name=\"twitter:label1\" content=\"Written by\" \/>\n\t<meta name=\"twitter:data1\" content=\"Nenad Noveljic\" \/>\n\t<meta name=\"twitter:label2\" content=\"Est. reading time\" \/>\n\t<meta name=\"twitter:data2\" content=\"3 minutes\" \/>\n<script type=\"application\/ld+json\" class=\"yoast-schema-graph\">{\"@context\":\"https:\\\/\\\/schema.org\",\"@graph\":[{\"@type\":\"Article\",\"@id\":\"https:\\\/\\\/nenadnoveljic.com\\\/blog\\\/excessive-query-parsing-time-with-long-in-lists-and-extended-statistics\\\/#article\",\"isPartOf\":{\"@id\":\"https:\\\/\\\/nenadnoveljic.com\\\/blog\\\/excessive-query-parsing-time-with-long-in-lists-and-extended-statistics\\\/\"},\"author\":{\"name\":\"Nenad Noveljic\",\"@id\":\"https:\\\/\\\/nenadnoveljic.com\\\/blog\\\/#\\\/schema\\\/person\\\/51458d9dd86dbbdd19f5add451d44efa\"},\"headline\":\"Excessive query parsing time with extended statistics and long in-lists\",\"datePublished\":\"2016-01-21T23:35:26+00:00\",\"dateModified\":\"2017-02-14T20:39:57+00:00\",\"mainEntityOfPage\":{\"@id\":\"https:\\\/\\\/nenadnoveljic.com\\\/blog\\\/excessive-query-parsing-time-with-long-in-lists-and-extended-statistics\\\/\"},\"wordCount\":404,\"commentCount\":2,\"articleSection\":[\"12c\",\"cost based optimizer\",\"Oracle\",\"slow parsing\"],\"inLanguage\":\"en-US\",\"potentialAction\":[{\"@type\":\"CommentAction\",\"name\":\"Comment\",\"target\":[\"https:\\\/\\\/nenadnoveljic.com\\\/blog\\\/excessive-query-parsing-time-with-long-in-lists-and-extended-statistics\\\/#respond\"]}]},{\"@type\":\"WebPage\",\"@id\":\"https:\\\/\\\/nenadnoveljic.com\\\/blog\\\/excessive-query-parsing-time-with-long-in-lists-and-extended-statistics\\\/\",\"url\":\"https:\\\/\\\/nenadnoveljic.com\\\/blog\\\/excessive-query-parsing-time-with-long-in-lists-and-extended-statistics\\\/\",\"name\":\"Excessive query parsing time with extended statistics and long in-lists - All-round Database Topics\",\"isPartOf\":{\"@id\":\"https:\\\/\\\/nenadnoveljic.com\\\/blog\\\/#website\"},\"datePublished\":\"2016-01-21T23:35:26+00:00\",\"dateModified\":\"2017-02-14T20:39:57+00:00\",\"author\":{\"@id\":\"https:\\\/\\\/nenadnoveljic.com\\\/blog\\\/#\\\/schema\\\/person\\\/51458d9dd86dbbdd19f5add451d44efa\"},\"description\":\"Excessive query parsing time with extended events and long in lists were observed on a 12c database.\u00a0As a\u00a0workaround set the undocumented parameter _optimizer_extended_stats_usage_control to 224.\",\"breadcrumb\":{\"@id\":\"https:\\\/\\\/nenadnoveljic.com\\\/blog\\\/excessive-query-parsing-time-with-long-in-lists-and-extended-statistics\\\/#breadcrumb\"},\"inLanguage\":\"en-US\",\"potentialAction\":[{\"@type\":\"ReadAction\",\"target\":[\"https:\\\/\\\/nenadnoveljic.com\\\/blog\\\/excessive-query-parsing-time-with-long-in-lists-and-extended-statistics\\\/\"]}]},{\"@type\":\"BreadcrumbList\",\"@id\":\"https:\\\/\\\/nenadnoveljic.com\\\/blog\\\/excessive-query-parsing-time-with-long-in-lists-and-extended-statistics\\\/#breadcrumb\",\"itemListElement\":[{\"@type\":\"ListItem\",\"position\":1,\"name\":\"Home\",\"item\":\"https:\\\/\\\/nenadnoveljic.com\\\/blog\\\/\"},{\"@type\":\"ListItem\",\"position\":2,\"name\":\"Excessive query parsing time with extended statistics and long in-lists\"}]},{\"@type\":\"WebSite\",\"@id\":\"https:\\\/\\\/nenadnoveljic.com\\\/blog\\\/#website\",\"url\":\"https:\\\/\\\/nenadnoveljic.com\\\/blog\\\/\",\"name\":\"All-round Database Topics\",\"description\":\"Nenad Noveljic\",\"potentialAction\":[{\"@type\":\"SearchAction\",\"target\":{\"@type\":\"EntryPoint\",\"urlTemplate\":\"https:\\\/\\\/nenadnoveljic.com\\\/blog\\\/?s={search_term_string}\"},\"query-input\":{\"@type\":\"PropertyValueSpecification\",\"valueRequired\":true,\"valueName\":\"search_term_string\"}}],\"inLanguage\":\"en-US\"},{\"@type\":\"Person\",\"@id\":\"https:\\\/\\\/nenadnoveljic.com\\\/blog\\\/#\\\/schema\\\/person\\\/51458d9dd86dbbdd19f5add451d44efa\",\"name\":\"Nenad Noveljic\",\"image\":{\"@type\":\"ImageObject\",\"inLanguage\":\"en-US\",\"@id\":\"https:\\\/\\\/secure.gravatar.com\\\/avatar\\\/a97b796613ea48ec8a7b79c8ffe1c685dcffc920c68121f6238d5caab5070670?s=96&d=mm&r=g\",\"url\":\"https:\\\/\\\/secure.gravatar.com\\\/avatar\\\/a97b796613ea48ec8a7b79c8ffe1c685dcffc920c68121f6238d5caab5070670?s=96&d=mm&r=g\",\"contentUrl\":\"https:\\\/\\\/secure.gravatar.com\\\/avatar\\\/a97b796613ea48ec8a7b79c8ffe1c685dcffc920c68121f6238d5caab5070670?s=96&d=mm&r=g\",\"caption\":\"Nenad Noveljic\"},\"sameAs\":[\"nenad-noveljic-9b746a6\",\"https:\\\/\\\/x.com\\\/NenadNoveljic\"],\"url\":\"https:\\\/\\\/nenadnoveljic.com\\\/blog\\\/author\\\/nenad\\\/\"}]}<\/script>\n<!-- \/ Yoast SEO plugin. -->","yoast_head_json":{"title":"Excessive query parsing time with extended statistics and long in-lists - All-round Database Topics","description":"Excessive query parsing time with extended events and long in lists were observed on a 12c database.\u00a0As a\u00a0workaround set the undocumented parameter _optimizer_extended_stats_usage_control to 224.","robots":{"index":"index","follow":"follow","max-snippet":"max-snippet:-1","max-image-preview":"max-image-preview:large","max-video-preview":"max-video-preview:-1"},"canonical":"https:\/\/nenadnoveljic.com\/blog\/excessive-query-parsing-time-with-long-in-lists-and-extended-statistics\/","og_locale":"en_US","og_type":"article","og_title":"Excessive query parsing time with extended statistics and long in-lists - All-round Database Topics","og_description":"Excessive query parsing time with extended events and long in lists were observed on a 12c database.\u00a0As a\u00a0workaround set the undocumented parameter _optimizer_extended_stats_usage_control to 224.","og_url":"https:\/\/nenadnoveljic.com\/blog\/excessive-query-parsing-time-with-long-in-lists-and-extended-statistics\/","og_site_name":"All-round Database Topics","article_published_time":"2016-01-21T23:35:26+00:00","article_modified_time":"2017-02-14T20:39:57+00:00","author":"Nenad Noveljic","twitter_card":"summary_large_image","twitter_creator":"@NenadNoveljic","twitter_misc":{"Written by":"Nenad Noveljic","Est. reading time":"3 minutes"},"schema":{"@context":"https:\/\/schema.org","@graph":[{"@type":"Article","@id":"https:\/\/nenadnoveljic.com\/blog\/excessive-query-parsing-time-with-long-in-lists-and-extended-statistics\/#article","isPartOf":{"@id":"https:\/\/nenadnoveljic.com\/blog\/excessive-query-parsing-time-with-long-in-lists-and-extended-statistics\/"},"author":{"name":"Nenad Noveljic","@id":"https:\/\/nenadnoveljic.com\/blog\/#\/schema\/person\/51458d9dd86dbbdd19f5add451d44efa"},"headline":"Excessive query parsing time with extended statistics and long in-lists","datePublished":"2016-01-21T23:35:26+00:00","dateModified":"2017-02-14T20:39:57+00:00","mainEntityOfPage":{"@id":"https:\/\/nenadnoveljic.com\/blog\/excessive-query-parsing-time-with-long-in-lists-and-extended-statistics\/"},"wordCount":404,"commentCount":2,"articleSection":["12c","cost based optimizer","Oracle","slow parsing"],"inLanguage":"en-US","potentialAction":[{"@type":"CommentAction","name":"Comment","target":["https:\/\/nenadnoveljic.com\/blog\/excessive-query-parsing-time-with-long-in-lists-and-extended-statistics\/#respond"]}]},{"@type":"WebPage","@id":"https:\/\/nenadnoveljic.com\/blog\/excessive-query-parsing-time-with-long-in-lists-and-extended-statistics\/","url":"https:\/\/nenadnoveljic.com\/blog\/excessive-query-parsing-time-with-long-in-lists-and-extended-statistics\/","name":"Excessive query parsing time with extended statistics and long in-lists - All-round Database Topics","isPartOf":{"@id":"https:\/\/nenadnoveljic.com\/blog\/#website"},"datePublished":"2016-01-21T23:35:26+00:00","dateModified":"2017-02-14T20:39:57+00:00","author":{"@id":"https:\/\/nenadnoveljic.com\/blog\/#\/schema\/person\/51458d9dd86dbbdd19f5add451d44efa"},"description":"Excessive query parsing time with extended events and long in lists were observed on a 12c database.\u00a0As a\u00a0workaround set the undocumented parameter _optimizer_extended_stats_usage_control to 224.","breadcrumb":{"@id":"https:\/\/nenadnoveljic.com\/blog\/excessive-query-parsing-time-with-long-in-lists-and-extended-statistics\/#breadcrumb"},"inLanguage":"en-US","potentialAction":[{"@type":"ReadAction","target":["https:\/\/nenadnoveljic.com\/blog\/excessive-query-parsing-time-with-long-in-lists-and-extended-statistics\/"]}]},{"@type":"BreadcrumbList","@id":"https:\/\/nenadnoveljic.com\/blog\/excessive-query-parsing-time-with-long-in-lists-and-extended-statistics\/#breadcrumb","itemListElement":[{"@type":"ListItem","position":1,"name":"Home","item":"https:\/\/nenadnoveljic.com\/blog\/"},{"@type":"ListItem","position":2,"name":"Excessive query parsing time with extended statistics and long in-lists"}]},{"@type":"WebSite","@id":"https:\/\/nenadnoveljic.com\/blog\/#website","url":"https:\/\/nenadnoveljic.com\/blog\/","name":"All-round Database Topics","description":"Nenad Noveljic","potentialAction":[{"@type":"SearchAction","target":{"@type":"EntryPoint","urlTemplate":"https:\/\/nenadnoveljic.com\/blog\/?s={search_term_string}"},"query-input":{"@type":"PropertyValueSpecification","valueRequired":true,"valueName":"search_term_string"}}],"inLanguage":"en-US"},{"@type":"Person","@id":"https:\/\/nenadnoveljic.com\/blog\/#\/schema\/person\/51458d9dd86dbbdd19f5add451d44efa","name":"Nenad Noveljic","image":{"@type":"ImageObject","inLanguage":"en-US","@id":"https:\/\/secure.gravatar.com\/avatar\/a97b796613ea48ec8a7b79c8ffe1c685dcffc920c68121f6238d5caab5070670?s=96&d=mm&r=g","url":"https:\/\/secure.gravatar.com\/avatar\/a97b796613ea48ec8a7b79c8ffe1c685dcffc920c68121f6238d5caab5070670?s=96&d=mm&r=g","contentUrl":"https:\/\/secure.gravatar.com\/avatar\/a97b796613ea48ec8a7b79c8ffe1c685dcffc920c68121f6238d5caab5070670?s=96&d=mm&r=g","caption":"Nenad Noveljic"},"sameAs":["nenad-noveljic-9b746a6","https:\/\/x.com\/NenadNoveljic"],"url":"https:\/\/nenadnoveljic.com\/blog\/author\/nenad\/"}]}},"_links":{"self":[{"href":"https:\/\/nenadnoveljic.com\/blog\/wp-json\/wp\/v2\/posts\/344","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/nenadnoveljic.com\/blog\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/nenadnoveljic.com\/blog\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/nenadnoveljic.com\/blog\/wp-json\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"https:\/\/nenadnoveljic.com\/blog\/wp-json\/wp\/v2\/comments?post=344"}],"version-history":[{"count":2,"href":"https:\/\/nenadnoveljic.com\/blog\/wp-json\/wp\/v2\/posts\/344\/revisions"}],"predecessor-version":[{"id":1412,"href":"https:\/\/nenadnoveljic.com\/blog\/wp-json\/wp\/v2\/posts\/344\/revisions\/1412"}],"wp:attachment":[{"href":"https:\/\/nenadnoveljic.com\/blog\/wp-json\/wp\/v2\/media?parent=344"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/nenadnoveljic.com\/blog\/wp-json\/wp\/v2\/categories?post=344"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/nenadnoveljic.com\/blog\/wp-json\/wp\/v2\/tags?post=344"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}