Many bloggers have already discussed that Oracle can truncate the text of a “create table as select” statement to 20 characters depending on your version and patch level. This can be a problem in case a CTAS statement is a resource hog, yet you don’t see the SQL text that is needed for troubleshooting. A quick search on My Oracle Support reveals this can happen on 11.2.0.4, 12.1.0.1 and 12.1.0.2 systems unless patched of course. This has been bugging me for quite some time now, and merits a blog post.
Reproducing the offending behaviour
Oracle has provided a number of patches over time to fix this undesirable short-cutting of the SQL text. I wanted to reproduce the issue on 12.1 to demonstrate the effect. To my shame I have to admit that since 12.2 has come out I have somewhat neglected my 12.1 lab system. It was quite a bit out of date, which was useful for this blog post as it will turn out.
One of my 12.1 systems (a two-node RAC) was patched to July 2016:
[oracle@rac12node1 ~]$ opatch lspatches 23177536;Database PSU 12.1.0.2.160719, Oracle JavaVM Component (JUL2016) 23144544;DATABASE BUNDLE PATCH: 12.1.0.2.160719 (23144544) 23520664;OCW Interim patch for 23520664 OPatch succeeded.
This isn’t great, I prefer my lab systems to be more current. Long story short, this RAC system is about a year and a bit behind on patches. It shall be rectified at the next opportunity!
I am going to connect to a PDB to run the following steps, although it should not matter whether I’m running the test against a non-CDB or PDB.
To ensure repeated execution of my test case I have created a small script:
[oracle@rac12node1 ~]$ cat ctas_test.sql set echo on sho user alter session set events 'sql_trace level 8'; create table ctastest tablespace users as select * from dba_objects where object_id < 1000; alter session set events 'sql_trace off'; select value from v$diag_info where name like 'Def%'; [oracle@rac12node1 ~]$
In the next step I am connecting to the database to run the script:
[oracle@rac12node1 ~]$ sqlplus martin@pdb_srv SQL*Plus: Release 12.1.0.2.0 Production on Tue Oct 17 20:26:56 2017 Copyright (c) 1982, 2014, Oracle. All rights reserved. Enter password: Last Successful login time: Tue Oct 17 2017 18:52:35 +01:00 Connected to: Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production With the Partitioning, Real Application Clusters, Automatic Storage Management, OLAP, Advanced Analytics and Real Application Testing options SQL> @ctas_test SQL> SQL> sho user USER is "MARTIN" SQL> SQL> alter session set events 'sql_trace level 8'; Session altered. SQL> SQL> create table ctastest tablespace users as 2 select * from dba_objects where object_id < 1000; Table created. SQL> alter session set events 'sql_trace off'; Session altered. SQL> SQL> select value from v$diag_info where name like 'Def%'; VALUE -------------------------------------------------------------------------------- /u01/app/oracle/diag/rdbms/cdb/CDB1/trace/CDB1_ora_16279.trc
And indeed, the SQL trace shows that the statement is truncated:
===================== PARSING IN CURSOR #140207826820160 len=90 dep=0 uid=102 oct=1 lid=102 tim=28239487087 hv=3859378539 ad='afafdb58' sqlid='d7y8ssmm0kwbb' create table ctastest tab END OF STMT PARSE #140207826820160:c=282000,e=688749,p=90,cr=6300,cu=0,mis=1,r=0,dep=0,og=1, bplh=12630425,tim=28239487087 WAIT #140207826820160: nam='row cache lock' ela= 62 cache id=8 mode=0 request=3 obj#=656 tim=28239487351
My Oracle Support also mentioned a couple of other places where the command was found to be truncated. I randomly picked one that matters to me, please consider MOS for more locations where the statements were truncated. Your mileage may vary.
SQL> set long 1000000 SQL> select sql_text, sql_fulltext from v$sql where sql_id = 'd7y8ssmm0kwbb'; SQL_TEXT ------------------------------------------------------------------------------- SQL_FULLTEXT ------------------------------------------------------------------------------- create table ctastest tablespace users as select * from dba_objects where object_id < 1000 create table ctastest tablespace users as select * from dba_objects where object_id < 1000
Thankfully the SQL_TEXT and SQL_FULLTEXT show the entire statement, which is good.
Now what about 12.2?
Out of curiosity I repeated the test in 12.2 to see if the problem was fixed, and it actually appears to be the case. Using the same script to connect to the database I get a different behaviour. This time around I am patched to a more recent release:
[oracle@server2 ~]$ opatch lspatches 26609817;DATABASE RELEASE UPDATE: 12.2.0.1.170814 (26609817) OPatch succeeded.
Let’s try again:
[oracle@server2 ~]$ sqlplus martin@orcl SQL*Plus: Release 12.2.0.1.0 Production on Tue Oct 17 20:22:15 2017 Copyright (c) 1982, 2016, Oracle. All rights reserved. Enter password: Last Successful login time: Tue Oct 17 2017 20:19:24 +02:00 Connected to: Oracle Database 12c Enterprise Edition Release 12.2.0.1.0 - 64bit Production SQL> @ctas_test SQL> SQL> sho user USER is "MARTIN" SQL> SQL> alter session set events 'sql_trace level 8'; Session altered. SQL> SQL> create table ctastest tablespace users as 2 select * from dba_objects where object_id < 1000; Table created. SQL> SQL> alter session set events 'sql_trace off'; Session altered. SQL> SQL> select value from v$diag_info where name like 'Def%'; VALUE -------------------------------------------------------------------------------- /u01/app/oracle/diag/rdbms/orcl/ORCL/trace/ORCL_ora_16370.trc SQL>
Well and it seems the statement is no longer truncated. Looking at ORCL_ora_16370.ora I can find the complete statement:
===================== PARSING IN CURSOR #140577803287552 len=90 dep=0 uid=74 oct=1 lid=74 tim=39078309869 hv=3859378539 ad='64d25e58' sqlid='d7y8ssmm0kwbb' create table ctastest tablespace users as select * from dba_objects where object_id < 1000 END OF STMT PARSE #140577803287552:c=26826,e=27778,p=0,cr=140,cu=0,mis=1,r=0,dep=0,og=1, plh=3155089718,tim=39078309868 ...
Wait-what about later patch levels for 12.1?
This could easily have turned out to be “one of these posts” where the information presented is correct, yet the picture isn’t complete. Things change with the Oracle database, and newer patches address old problems. Just to be sure what I said is accurate at least at the time of writing I created a new VM with the August 2017 patch set:
[oracle@server1 ~]$ opatch lspatches 26027162;Database PSU 12.1.0.2.170718, Oracle JavaVM Component (JUL2017) 26609783;Database Patch Set Update : 12.1.0.2.170814 (26609783) 18705302; OPatch succeeded.
And interestingly, the issue with the truncated SQL statement in SQL traces disappeared:
===================== PARSING IN CURSOR #140433649086704 len=90 dep=0 uid=111 oct=1 lid=111 tim=797240178 hv=3859378539 ad='1b1add420' sqlid='d7y8ssmm0kwbb' create table ctastest tablespace users as select * from dba_objects where object_id < 1000 END OF STMT PARSE #140433649086704:c=165843,e=184715,p=197,cr=5489,cu=0,mis=1,r=0,dep=0,og=1, plh=12630425,tim=797240177 ...
Great stuff: the problem is fixed in the current version for 12.1.0.2 and 12.2.0.1. This is seriously good news for me, especially the part about 12.1.
Martins Blog 