So you’re on 11.2.0.2.0 and you encountered in SQL*Plus this new feature “Unoptimized XML construct detected (enable XMLOptimizationCheck for more information)“. What can you do and how to get more info…?
I encountered this new feature in SQL*Plus a month or so ago via the executing the following:
SQL> set autotrace on
SQL> SELECT xt.nam, xt2.color
2 FROM XMLTable(XMLNamespaces(DEFAULT 'abc.com/123',
3 'xyz.net/456' AS "b"),
4 'employees/emp'
5 PASSING XMLTYPE('
6
7 Scott
8
9 red
10 orange
11
12
13
14 John
15
16 blue
17 green
18
19
20 ')
21 COLUMNS
22 nam VARCHAR2(20) PATH 'name',
23 color_t XMLTYPE PATH 'b:favorites') xt,
24 XMLTable(XMLNamespaces('xyz.net/456' AS "b"),
25 'b:favorites/b:color'
26 PASSING xt.color_t
27 COLUMNS
28 color VARCHAR2(10) PATH '.') xt2;
NAM COLOR
-------------------- ----------
Scott red
Scott orange
John blue
John green
Execution Plan
----------------------------------------------------------
Plan hash value: 1368717035
-------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
-------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 66M| 254M| 221K (1)| 00:44:21 |
| 1 | NESTED LOOPS | | 66M| 254M| 221K (1)| 00:44:21 |
| 2 | COLLECTION ITERATOR PICKLER FETCH| XMLSEQUENCEFROMXMLTYPE | 8168 | 16336 | 29 (0)| 00:00:01 |
| 3 | COLLECTION ITERATOR PICKLER FETCH| XMLSEQUENCEFROMXMLTYPE | 8168 | 16336 | 27 (0)| 00:00:01 |
-------------------------------------------------------------------------------------------------------------
Note
-----
- Unoptimized XML construct detected (enable XMLOptimizationCheck for more information)
Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
0 consistent gets
0 physical reads
0 redo size
557 bytes sent via SQL*Net to client
419 bytes received via SQL*Net from client
2 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
4 rows processed
By noticing the “COLLECTION ITERATOR PICKLER FETCH” this already dawned with me. In principle a “COLLECTION ITERATOR PICKLER FETCH” means that the XML document or (intermediate) fragment is handled in memory and should be avoided because it is “serialized” and dealt via a Pickler Fetch routine, which in most cases is done via a standard XML parser, which can not be optimized by Oracle, for example, because Oracle doesn’t have enough information (provided maybe via an XML Schema) to re-write this query in a more optimal form. See this website for more information on collection iterator pickler fetches.
XMLOptimizationCheck
The “Unoptimized XML construct detected (enable XMLOptimizationCheck for more information)” is new in SQL*Plus / database version 11.2.0.2.0 and is the equivalent of setting a 19021 level 0x1 via for example: ALTER session SET events =’19021 trace name context forever, level 0x1′.
By setting the “XMLOptimizationCheck” setting in SQL*Plus, Oracle/the database will refuse to execute this unoptimized code.
BE AWARE:
Playing with internal Oracle support database events should only be done when advised by Oracle support, or on a test system were it is not a big deal when this gets corrupted! My advice from me to you, but don’t start whining if it break your environment…You can’t say I didn’t warn you.
According to an entry in the XMLDB Developers manual this is only used in a “test” or “debug” situation.
When this mode is on, the plan of execution is automatically checked for XQuery optimization, and if the plan is suboptimal then an error is raised and diagnostic information is written to the trace file indicating which operators are not rewritten.
And in the SQL*Plus manual for the latest release, under new features, 11.2.0.2, it states:
SET XMLOPTIMIZATIONCHECK
SET XMLOPTIMIZATIONCHECK specifies that only fully optimized XML queries and DML operations are executed. It is only to assist during code development and debugging.
SQL> set XMLOptimizationCheck on
SQL> SELECT xt.nam, xt2.color
2 FROM XMLTable(XMLNamespaces(DEFAULT 'abc.com/123',
3 'xyz.net/456' AS "b"),
4 'employees/emp'
5 PASSING XMLTYPE('
6
7 Scott
8
9 red
10 orange
11
12
13
14 John
15
16 blue
17 green
18
19
20 ')
21 COLUMNS
22 nam VARCHAR2(20) PATH 'name',
23 color_t XMLTYPE PATH 'b:favorites') xt, -- path to the node that repeats
24 XMLTable(XMLNamespaces('xyz.net/456' AS "b"),
25 'b:favorites/b:color'
26 PASSING xt.color_t -- define input XMLType as output of above, aka a join
27 COLUMNS
28 color VARCHAR2(10) PATH '.') xt2;
SELECT xt.nam, xt2.color
*
ERROR at line 1:
ORA-19022: Unoptimized XML construct detected
.
In the trace directory, a trace file will be created showing the following, or alike trace file content for your statement. In the example here a trace file was created with the following content
[oracle@localhost trace]$ cat orcl_ora_3092.trc
Trace file /home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_3092.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 - Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
ORACLE_HOME = /home/oracle/app/oracle/product/11.2.0/dbhome_2
System name: Linux
Node name: localhost.localdomain
Release: 2.6.18-194.0.0.0.4.el5
Version: #1 SMP Thu Apr 8 18:20:19 EDT 2010
Machine: i686
Instance name: orcl
Redo thread mounted by this instance: 1
Oracle process number: 19
Unix process pid: 3092, image: oracle@localhost.localdomain (TNS V1-V3)
*** 2010-10-04 14:51:46.775
*** SESSION ID:(1.7) 2010-10-04 14:51:46.775
*** CLIENT ID:() 2010-10-04 14:51:46.775
*** SERVICE NAME:(SYS$USERS) 2010-10-04 14:51:46.775
*** MODULE NAME:(SQL*Plus) 2010-10-04 14:51:46.775
*** ACTION NAME:() 2010-10-04 14:51:46.775
===============================================================================
XML Performance Diagnosis:
Unparsed Query:
******* UNPARSED QUERY IS *******
SELECT CAST(SYS_XQ_UPKXML2SQL(SYS_XQEXVAL(SYS_XQEXTRACT(VALUE(KOKBF$),
'/emp/name','xmlns="abc.com/123" xmlns:b="xyz.net/456" '),0,0,20971520,0),50,1,2)
AS VARCHAR2(20) ) "NAM",CAST(SYS_XQ_UPKXML2SQL(SYS_XQEXVAL(VALUE(KOKBF$),0,0,
20971520,0),50,1,2) AS VARCHAR2(10) ) "COLOR"
FROM TABLE("SYS"."XQSEQUENCE"(EXTRACT("SYS"."XMLTYPE"(
'
Scott
red
orange
John
blue
green
'),'/oraxq_defpfx:employees/oraxq_defpfx:emp',
' xmlns:oraxq_defpfx="abc.com/123"'))) "KOKBF$",TABLE("SYS"."XQSEQUENCE"(EXTRACT
(EXTRACT(VALUE(KOKBF$),'/oraxq_defpfx:emp/b:favorites',' xmlns:oraxq_defpfx=
"abc.com/123" xmlns:b="xyz.net/456"'),'/b:favorites/b:color'
,' xmlns:b="xyz.net/456"'))) "KOKBF$"
Reason: upkxml2sql
===============================================================================
.
As shown here its depicts the “upkxml2sql” method as the guilty one. You can now try to avoid this issue by using alternative means and/or provide the database with more information, for example, while using XMLType Binary storage, XML Schema based storage (Object Relational / Binary XML) or register an XML Schema in the XDB Repository. Other alternatives could be avoiding the use of the “//” XPath operator.
The moment the query is parsed and executed / shared in cache via the cursor sharing mechanism, then there is a chance you won’t see a trace file. To avoid cursor sharing you could set the cursor sharing to “exact” and/or add white space to your query or alternate upper/lower case and/or other small tricks to force re-parsing.
Before Oracle 11.2.0.2.0 there is an alternative since, AFAIK at least, Oracle version 11.x. by setting the 19027 event, level 0x2000 to get a bit more insight in what happens under the hood, if Oracle can optimize (or not), the request via query re-write.
19027 trace name context forever, level 0x2000
If you would set the 19027 event, level 0x2000, then a trace file is produced in the trace directory of the base DIAG directory structure.
SQL> ALTER session SET events = '19027 trace name context forever, level 0x2000';
Session altered.
SQL> SELECT xt.nam, xt2.color
2 FROM XMLTable(XMLNamespaces(DEFAULT 'abc.com/123',
3 'xyz.net/456' AS "b"),
4 'employees/emp'
5 PASSING XMLTYPE('
6
7 Scott
8
9 red
10 orange
11
12
13
14 John
15
16 blue
17 green
18
19
20 ')
21 COLUMNS
22 nam VARCHAR2(20) PATH 'name',
23 color_t XMLTYPE PATH 'b:favorites') xt, -- path to the node that repeats
24 XMLTable(XMLNamespaces('xyz.net/456' AS "b"),
25 'b:favorites/b:color'
26 PASSING xt.color_t -- define input XMLType as output of above, aka a join
27 COLUMNS
28 color VARCHAR2(10) PATH '.') xt2;
NAM COLOR
-------------------- ----------
Scott red
Scott orange
John blue
John green
SQL> ALTER session SET events ='19027 trace name errorstack off';
Session altered.
The trace file can be found via following the DIAG directory structure, which can be found, for example, via entering “show parameter diag” in SQL*Plus (as user SYS or alternative highly privileged database account).
One of the latest trace files in this directory shows now similar content in that trace file as shown below.
[oracle@localhost trace]$ pwd
/home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace
[oracle@localhost trace]$ cat orcl_ora_6167.trc
Trace file /home/oracle/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_6167.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 - Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
ORACLE_HOME = /home/oracle/app/oracle/product/11.2.0/dbhome_2
System name: Linux
Node name: localhost.localdomain
Release: 2.6.18-194.0.0.0.4.el5
Version: #1 SMP Thu Apr 8 18:20:19 EDT 2010
Machine: i686
Instance name: orcl
Redo thread mounted by this instance: 1
Oracle process number: 24
Unix process pid: 6167, image: oracle@localhost.localdomain (TNS V1-V3)
*** 2010-10-04 11:06:22.030
*** SESSION ID:(1.47) 2010-10-04 11:06:22.030
*** CLIENT ID:() 2010-10-04 11:06:22.030
*** SERVICE NAME:(SYS$USERS) 2010-10-04 11:06:22.030
*** MODULE NAME:(SQL*Plus) 2010-10-04 11:06:22.030
*** ACTION NAME:() 2010-10-04 11:06:22.030
XMLTABLE RWT QUERY
select cast( sys_xq_upkxml2sql(sys_xqexval(sys_xqextract(value(QMXTABF$), '/emp/name','xmlns="abc.com/123" xmlns:b="xyz.net/456" ')), 50,1, 2) as VARCHAR2(20) ) as "NAM",xmlquery( 'declare default element namespace "abc.com/123";declare namespace b="xyz.net/456";b:favorites' PASSING BY XMLTABLE value(QMXTABF$) returning content ) as "COLOR_T" from table(xqsequence( xmlquery('declare default element namespace "abc.com/123";declare namespace b="xyz.net/456";employees/emp' passing by value QMXTABCOL$ returning sequence) )) QMXTABF$
XMLTABLE RWT QUERY END
XMLTABLE RWT QUERY
select cast( sys_xq_upkxml2sql(sys_xqexval(xmlquery( 'declare namespace b="xyz.net/456";.' PASSING BY XMLTABLE value(QMXTABF$) returning sequence )), 50,1, 2) as VARCHAR2(10) ) as "COLOR" from table(xqsequence( xmlquery('declare namespace b="xyz.net/456";b:favorites/b:color' passing by value QMXTABCOL$ returning sequence) )) QMXTABF$
XMLTABLE RWT QUERY END
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> no type info
NO REWRITE
Reason ==> xseq:not lazydef
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> non rewritable sqlx input
NO REWRITE
Reason ==> non rewritable sqlx input
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> non rewritable sqlx input
NO REWRITE
Reason ==> non rewritable sqlx input
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> non rewritable sqlx input
NO REWRITE
Reason ==> non rewritable sqlx input
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> non rewritable sqlx input
NO REWRITE
Reason ==> xseq:not lazydef
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> non rewritable sqlx input
NO REWRITE
Reason ==> non rewritable sqlx input
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> non rewritable sqlx input
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> non rewritable sqlx input
NO REWRITE
Reason ==> xseq:not lazydef
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> no type info
NO REWRITE
Reason ==> xseq:not lazydef
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> no type info
NO REWRITE
Reason ==> no type info
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> no type info
NO REWRITE
Reason ==> non rewritable sqlx input
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> no type info
NO REWRITE
Reason ==> non rewritable sqlx input
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> no type info
NO REWRITE
Reason ==> non rewritable sqlx input
NO REWRITE
Reason ==> xseq:not lazydef
NO REWRITE
Reason ==> xseq:not lazydef
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> non rewritable sqlx input
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> non rewritable sqlx input
NO REWRITE
Reason ==> xseq:not lazydef
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> no type info
NO REWRITE
Reason ==> xseq:not lazydef
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> no type info
NO REWRITE
Reason ==> no type info
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> no type info
NO REWRITE
Reason ==> non rewritable sqlx input
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> no type info
NO REWRITE
Reason ==> non rewritable sqlx input
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> no type info
NO REWRITE
Reason ==> non rewritable sqlx input
NO REWRITE
Reason ==> xseq:not lazydef
NO REWRITE
Reason ==> xseq:not lazydef
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> xseq:not lazydef
NO REWRITE
Reason ==> xseq:not lazydef
So both XMLTABLE subsections of the used query are attempted by Oracle to rewritten into internal XQuery (“xq”, XQuery, extract, evaluate, xml2sql, xq sequence routines). Looking at the original query…
SELECT xt.nam
, xt2.color
FROM XMLTable(XMLNamespaces(DEFAULT 'abc.com/123',
'xyz.net/456' AS "b"),
'employees/emp'
PASSING XMLTYPE('
Scott
red
orange
John
blue
green
')
COLUMNS
nam VARCHAR2(20) PATH 'name',
color_t XMLTYPE PATH 'b:favorites') xt
, XMLTable(XMLNamespaces('xyz.net/456' AS "b"),
'b:favorites/b:color'
PASSING xt.color_t
COLUMNS
color VARCHAR2(10) PATH '.') xt2
;
You can see the two XMLTABLE statements…
select cast( sys_xq_upkxml2sql(sys_xqexval(sys_xqextract(value(QMXTABF$), '/emp/name'
, 'xmlns="abc.com/123" xmlns:b="xyz.net/456" ')
), 50,1, 2
) as VARCHAR2(20) ) as "NAM"
, xmlquery( 'declare default element namespace "abc.com/123";
declare namespace b="xyz.net/456";
b:favorites'
PASSING BY XMLTABLE value(QMXTABF$)
returning content ) as "COLOR_T"
from table(xqsequence( xmlquery('declare default element namespace "abc.com/123";
declare namespace b="xyz.net/456";employees/emp'
passing by value QMXTABCOL$
returning sequence)
)
) QMXTABF$
and…
.
select cast( sys_xq_upkxml2sql(sys_xqexval(xmlquery( 'declare namespace b="xyz.net/456";.'
PASSING BY XMLTABLE value(QMXTABF$)
returning sequence )
), 50,1, 2
) as VARCHAR2(10) ) as "COLOR"
from table(xqsequence( xmlquery('declare namespace b="xyz.net/456";
b:favorites/b:color'
passing by value QMXTABCOL$
returning sequence)
)
) QMXTABF$
Most of this long list in the trace file can be deducted as in a more regular “10053” trace file / event…
NO REWRITE
Reason ==> not SQLX operand
NO REWRITE
Reason ==> non sqlx expression input
NO REWRITE
Reason ==> no type info
NO REWRITE
Reason ==> xseq:not lazydef
NO REWRITE
Reason ==> non rewritable sqlx input
...
...
…but I will have to dig a bit more to see how this all fits together…
For now / HTH / To be continued…
A bit of info of what is going behind the scenes regarding re-writing/optimizations can be found here:
https://www.google.com/patents/US7120645