Bobby Durrett's DBA Blog

Saw an interesting post related to work I am doing locking in plans and finding plans that have changed: Carlos Sierra post on queries with changing performance.

Our DBA team uses versions of my sqlstat.sql(updated) script to find queries whose elapsed time change and we use a script from Carlos Sierra’s SQLT collection to force the execution plan back to an efficient plan that the optimizer choose in the past.  Carlos Sierra’s new post includes scripts that resemble my sqlstat script but with more functionality including an interesting way of helping people figure out which queries are now running slower.  At this point we just look at the top queries that are running and run sqlstat.sql to see if they have run with less elapsed time in the past.  We eyeball it and usually it is obvious because the bad plan takes 100 times longer than the good one.  But the newly posted Carlos Sierra script seems to use some math to help figure out whether the elapsed time is really bad enough for us to consider it a problem.

I want to set up a monitoring script that pages us when a plan changes for the worse so we can decide whether to intervene and force on older plan to improve performance.  I have a simple script running on one of our databases but, as I expected, it is returning a lot of false positives.  So, I’m hoping to have some time this week to improve that script so that we get fewer false alarms and I’m going to take a close look at Carlos Sierra’s newly posted script for ideas.

– Bobby

This is pretty simple, but I thought I would share it since it is helpful to me.  I have been preparing for a large migration which involves table, index, type, function, package, and procedure changes.  When I run a big migration like this I check for invalid objects before and after the migration and attempt to recompile any that are invalid.  By checking before and after the migration I know which objects the migration invalidated.

Here’s the script:

select status,count(*)
from dba_objects
where owner='YOURSCHEMA'
group by status
order by status;

select 'alter '||object_type||' '||owner||'.'||object_name||
       ' compile;'
from dba_objects
where owner='YOURSCHEMA' and
status='INVALID' and
object_type <> 'PACKAGE BODY'
union
select 'alter package '||owner||'.'||object_name||' compile body;'
from dba_objects
where owner='YOURSCHEMA' and
status='INVALID' and
object_type = 'PACKAGE BODY';

Replace “YOURSCHEMA” with the schema that your objects are in.

Output is something like this:

STATUS    COUNT(*)
------- ----------
INVALID          7
VALID        53581

'ALTER'||OBJECT_TYPE||''||OWNER||'.'||OBJECT_NAME||'COMPILE;'
--------------------------------------------------------------
alter FUNCTION YOURSCHEMA.YOURFUNCTION compile;
alter package YOURSCHEMA.YOURPACKAGE compile body;

The counts give me a general idea of how many objects are invalid and the alters gives me sql that I can paste into a script and run to attempt to compile the objects and make them valid.

Hope this is helpful to someone else.  It’s helpful to me.

– Bobby

Yesterday was the first meeting of the newly restarted Arizona Oracle User Group, AZORA.  It was a good first meeting to kick off what I hope will turn into an active club.

We met in the Tempe Public Library in a large downstairs room with a projector screen and plenty of seating with tables so it was easy to take notes.  We also had snacks.  I got a Paradise Bakery chocolate chip cookie and bottled water so that put me in a good mood for the afternoon meeting. They also had some giveaways and so I picked up an Oracle pen and notebook to use to take notes during the talk.  They also gave away three or four Rich Niemiec books and some gift cards as prizes, but, as usual, I didn’t win anything.

The first talk was about “Big Data”.  I’m skeptical about any buzzword, including big data, but I enjoyed hearing from a technical person who was actually doing this type of work.  I would rather hear an honest perspective from someone in the midst of the battle than get a rosy picture from someone who is trying to sell me something.  Interestingly, the talk was about open source big data software and not about any Oracle product, so it gave me as an Oracle database specialist some insight into something completely outside my experience.

The second talk was about another buzzword – “The Cloud”.  The second talk was as helpful as the first because the speaker had exposure to people from a variety of companies that were actually doing cloud work.  This talk was more directly related to my Oracle database work because you can have Oracle databases and applications based on Oracle databases deployed in the cloud.

It was a good first meeting and I hope to attend and help support future meetings.  Hopefully we can spread the news about the club and get even more people involved and attending so it will be even more useful to all of us.  I appreciate those who put in the effort to kick off this first meeting.

– Bobby

Fellow Phoenicians (citizens of the Phoenix, Arizona area):

This is a reminder that tomorrow is the first meeting of the newly reborn (risen from the ashes) Arizona Oracle User Group.  Here are the meeting details: url

I hope to meet some of my fellow Phoenix area DBAs tomorrow afternoon.

– Bobby

Here’s a zip of a script I modified today: zip

Here’s an example output:

 QUERY_NUM SQL_ID        PLAN_HASH_VALUE EXECUTIONS AVG_ELAPSED OPTIMIZER_COST AVG_FETCHES  AVG_SORTS AVG_DISK_READS AVG_BUFFER_GETS   AVG_ROWS    AVG_CPU AVG_IOWAIT AVG_DIRECT_WRITES AVG_PHYS_READS AVG_PHYS_WRITES
---------- ------------- --------------- ---------- ----------- -------------- ----------- ---------- -------------- --------------- ---------- ---------- ---------- ----------------- -------------- ---------------
         1 gxk0cj3qxug85      2051250004   39504258  31630.2852             15  4.71993394 .444248288     4.07294381      440.124393 41.3960784 3447.83137 28056.5262                 0     .006406626               0
         1 gxk0cj3qxug85       548353012   24360619  31854.5456             15  4.73696596 .574941507     4.16225047      443.290799 41.5668639 3501.62695 28205.9349                 0     .009019804               0
         2 53b6j9nvd2vwa       376144290    1069593  438746.758     19.6425025  33.7741683          0     58.9193684       3864.5447  332.18592 32952.0388 406548.271                 0     19.2981312               0
         2 53b6j9nvd2vwa       655563694    1008553  414586.506     15.0111675  33.7122908          0     58.6486828      3851.28671 331.575216 32283.0233 382834.453                 0     12.4507269               0
         2 53b6j9nvd2vwa      2504177057     274652  418157.478     19.5541562  32.8918486          0     61.1868838      3726.22908 323.358235 31005.0901 388545.269                 0     23.2050923               0
         3 4usguw7d6kxy4      2543632952    1070303   151648.49     12911.7175  2.30832577 .999997197     5.49557555      6221.80141 16.7674061 130072.596 10153.4778                 0     .388805787               0
         3 4usguw7d6kxy4      3221641997     996033  151860.479      11987.696  2.22684489 .999998996     7.10842914      6073.16306  15.902446  127194.45 13655.9405                 0     .316254582               0
         3 4usguw7d6kxy4      1764817920          2    277287.5          12860           1          1              1            6956          5     260000    10575.5                 0              1               0
         4 buhvbrfw1uyrd      2225737849    2871021  37985.4363     7.37064414  32.5216263          0      5.0695129      439.697767 319.641241 3463.90361 34645.8396                 0     2.01971389               0
         5 bvttgft3kj2hg      3569562598     293543  252814.965     20.6213018  95.7064212 .999996593     12.3908524      11035.1541 951.571562 137023.945 95634.8559                 0     1.94147365               0
         6 084v1t4whvzwd       883418687      70258  940211.781     4875.03099  1.00001423          0     30.6947394      22558.3683 .954980216 880713.798 16997.2457                 0     2.93185118               0
         7 972sx2uhfswn5       632842214  229406586  279.732773             14  1.00002261 .092121309     .003579313      25.6327361 .941600155 229.417607  23.334532                 0     .000786085               0

I’m using this script to help figure out which plans to lock in with SQL profiles.  For example, sql_id gxk0cj3qxug85 executes plan 2051250004 more often than plan 548353012 and they seem similar in performance so maybe it would be safe to just lock in the first plan.

I’ve also been reviewing the plans manually to see if there were major differences or if the plans were essentially the same.

I had a few minutes so I thought I would pass this along.

– Bobby

I modified the bind variable extraction script that I normally use to make it more helpful to me.

Here was my earlier post with the old script: blog post

Here is my updated script:

set termout on 
set echo on
set linesize 32000
set pagesize 1000
set trimspool on

column NAME format a3
column VALUE_STRING format a17

spool bind2.log

select * from 
(select distinct
to_char(sb.LAST_CAPTURED,'YYYY-MM-DD HH24:MI:SS') 
  DATE_TIME,
sb.NAME,
sb.VALUE_STRING 
from 
DBA_HIST_SQLBIND sb
where 
sb.sql_id='gxk0cj3qxug85' and
sb.WAS_CAPTURED='YES')
order by 
DATE_TIME,
NAME;

spool off

Replace gxk0cj3qxug85 with the sql_id of your own query.

The output looks like this (I’ve scrambled the values to obscure production data):

DATE_TIME           NAM VALUE_STRING
------------------- --- -----------------
2014-08-29 11:22:13 :B1 ABC
2014-08-29 11:22:13 :B2 DDDDDD
2014-08-29 11:22:13 :B3 2323
2014-08-29 11:22:13 :B4 555
2014-08-29 11:22:13 :B5 13412341
2014-08-29 11:22:13 :B6 44444
2014-08-29 11:26:47 :B1 gtgadsf
2014-08-29 11:26:47 :B2 adfaf
2014-08-29 11:26:47 :B3 4444
2014-08-29 11:26:47 :B4 5435665
2014-08-29 11:26:47 :B5 4444
2014-08-29 11:26:47 :B6 787

This is better than the original script because it keeps related bind variable values together.

– Bobby

4/27/21

Current version bind2.sql

I was testing SQL plan baselines on a base 11.2.0.3 release of Oracle on a 64 bit Linux virtual machine.  I ran DBMS_SPM.LOAD_PLANS_FROM_CURSOR_CACHE to create a SQL plan baseline for a test query after running that query once to get its plan in the cursor cache.  When I ran the test query after creating the SQL plan baseline and called dbms_xplan.display_cursor to see its new plan I got an ORA-01403 error:

ORCL:SYSTEM>select * from table(dbms_xplan.display_cursor(null,null,'ALL'));

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------
SQL_ID  4mu5a860ardpz, child number 1

An uncaught error happened in prepare_sql_statement : ORA-01403: no data found

NOTE: cannot fetch plan for SQL_ID: 4mu5a860ardpz, CHILD_NUMBER: 1
      Please verify value of SQL_ID and CHILD_NUMBER;
      It could also be that the plan is no longer in cursor cache (check v$sql_plan)

I applied patch 19183482 to my test system and the ORA-01403 error went away:

ORCL:SYSTEM>select * from table(dbms_xplan.display_cursor(null,null,'ALL'));

PLAN_TABLE_OUTPUT
-------------------------------------------------------------------------------------
SQL_ID  4mu5a860ardpz, child number 1
-------------------------------------
select sum(blocks) from test

Plan hash value: 1950795681

---------------------------------------------------------------------------
| Id  | Operation          | Name | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |      |       |       |    29 (100)|          |
|   1 |  SORT AGGREGATE    |      |     1 |     3 |            |          |
|   2 |   TABLE ACCESS FULL| TEST |  2844 |  8532 |    29   (0)| 00:00:01 |
---------------------------------------------------------------------------

Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------

   1 - SEL$1
   2 - SEL$1 / TEST@SEL$1

Column Projection Information (identified by operation id):
-----------------------------------------------------------

   1 - (#keys=0) SUM("BLOCKS")[22]
   2 - "BLOCKS"[NUMBER,22]

Note
-----
   - SQL plan baseline SQL_PLAN_dscatqjvyk4qy6b581ab9 used for this statement

Here is a zip of the script that I ran to create the ORA-01403 error and the output that it generated with and without the patch applied on my test database: zip

Here is a list of the bugs that patch 19183482’s readme says it will fix:

14512308: SPM BASELINE PLAN CANNOT BE REPRODUCED
15858022: ‘LIBRARY CACHE: MUTEX X’ AND LIBRARY CACHE LOCKS  PURGED_CURSOR
16400122: SPIKES IN LIBRARY CACHE
16625010: SPM BASELINE NOT WORKING FOR SQL CALLED FROM PL/SQL

I haven’t gotten very far into my investigation of SQL plan baselines but it looks like it would be a good idea to apply 19183482 before using SQL plan baselines on 11.2.0.3.  I barely got started using SQL plan baselines and I immediately hit this bug.

– Bobby

I have a number 0f SQL Profiles on a database I’m working on and I wanted to know the sql_id of the SQL statements that they relate to.  Here is what I came up with:

select distinct 
p.name sql_profile_name,
s.sql_id
from 
dba_sql_profiles p,
DBA_HIST_SQLSTAT s
where
p.name=s.sql_profile;

Here is the output on my system:

SQL_PROFILE_NAME               SQL_ID
------------------------------ -------------
coe_5up1944u1zb7r_1979920644   5up1944u1zb7r
coe_b9ad7h2rvtxwf_3569562598   b9ad7h2rvtxwf
coe_9f21udzrfcygh_2815756405   9f21udzrfcygh
coe_366brswtxxuct_10194574     366brswtxxuct
coe_2261y37rp45py_2815756405   2261y37rp45py

These are all profiles I created manually with the SQLT scripts so the profile name includes the sql_id but not all sql profiles are like this.  I have more entries in dba_sql_profiles than these five but these are the only rows that matched a row in dba_hist_sqlstat so I guess this won’t work for queries that are not used very often or are so fast that they don’t get pulled into the tables that are behind dba_hist_sqlstat.

– Bobby

4/27/21

Current version profiles.sql

Today I was trying to see if upgrading from 11.2.0.2 to 11.2.0.4 would change the SYS.WRH$_SQL_PLAN table.  This table is large on our production system so I wanted to find out if some time-consuming update to this table would occur that would slow down our production upgrade but not be detected on our test systems.  We recently performed this upgrade on our development database and I was looking at the logs to see whether SYS.WRH$_SQL_PLAN was modified.  I found this curious entry (edited for brevity):

create table WRH$_SQL_PLAN
2  (snap_id           number        /* last snap id, used for purging */
3  ,dbid           number       not null
4  ,sql_id           varchar2(13)    not null
...
42   using index tablespace SYSAUX
43  ) tablespace SYSAUX
44  /

Table created.

The “Table created.” message sounds like the database created a new table without any errors.  But, looking at DBA_OBJECTS the table was not new.  So, I guessed that when you are running the catproc.sql script which includes the create table statement for SYS.WRH$_SQL_PLAN it must contain something that suppresses the error that you should get when you try to create a table and the table already exists:

ORA-00955: name is already used by an existing object

So, I opened my 11.2.0.3 test database using STARTUP RESTRICT  and ran @catproc.sql as SYSDBA and to my surprise I got the error just as you normally would:

 42   using index tablespace SYSAUX
 43  ) tablespace SYSAUX
 44  /
create table WRH$_SQL_PLAN
             *
ERROR at line 1:
ORA-00955: name is already used by an existing object

So, I decided to restart this database with STARTUP UPGRADE and rerun catproc.sql and as a result the error disappeared:

 40  ,constraint WRH$_SQL_PLAN_PK primary key
 41      (dbid, sql_id, plan_hash_value, id)
 42   using index tablespace SYSAUX
 43  ) tablespace SYSAUX
 44  /

Table created.

Cue the mysterious Twilight Zone music…

I guess this is a “feature” of the startup upgrade command but the “Table created.” message is kind of confusing.  The table isn’t really created if it exists.  But, I guess the good thing is that it doesn’t report an error.

– Bobby

The Unix utilities ps and top report memory differently with HugePages than without.

Without HugePages ps -eF seems to include the SGA memory under the SZ column:

UID        PID  PPID  C    SZ   RSS PSR STIME TTY          TIME CMD
... 
oracle    1822     1  0 846155 16232  0 07:19 ?        00:00:00 ora_d000_orcl
oracle    1824     1  0 846155 16228  0 07:19 ?        00:00:00 ora_d001_orcl
oracle    1826     1  0 846155 16236  0 07:19 ?        00:00:00 ora_d002_orcl
oracle    1828     1  0 846155 16232  0 07:19 ?        00:00:00 ora_d003_orcl
oracle    1830     1  0 846155 16224  0 07:19 ?        00:00:00 ora_d004_orcl
oracle    1832     1  0 846155 16232  0 07:19 ?        00:00:00 ora_d005_orcl
oracle    1834     1  0 846155 16236  0 07:19 ?        00:00:00 ora_d006_orcl
oracle    1836     1  0 846155 16228  0 07:19 ?        00:00:00 ora_d007_orcl
oracle    1838     1  0 846155 16224  0 07:19 ?        00:00:00 ora_d008_orcl
oracle    1840     1  0 846155 16232  0 07:19 ?        00:00:00 ora_d009_orcl
oracle    1842     1  0 846155 16240  0 07:19 ?        00:00:00 ora_d010_orcl
oracle    1844     1  0 846155 16228  0 07:19 ?        00:00:00 ora_d011_orcl
...

Here SZ = 846155 kilobytes = 826 megabytes.  If you add up all the SZ values it comes to 81 gigabytes which wont fit in my 4 gig memory and 4 gig swap.  It seems to include the amount of the SGA actually used, not the full 3 gigabyte max sga size, otherwise the total would have been hundreds of gigabytes.

Doing the same exercise with 3 gigabytes of huge pages ps looks like this:

UID        PID  PPID  C    SZ   RSS PSR STIME TTY          TIME CMD
...
oracle    1809     1  0 59211 15552   0 07:52 ?        00:00:00 ora_d000_orcl
oracle    1811     1  0 59211 15544   0 07:52 ?        00:00:00 ora_d001_orcl
oracle    1813     1  0 59211 15548   0 07:52 ?        00:00:00 ora_d002_orcl
oracle    1815     1  0 59211 15544   0 07:52 ?        00:00:00 ora_d003_orcl
oracle    1817     1  0 59211 15544   0 07:52 ?        00:00:00 ora_d004_orcl
oracle    1819     1  0 59211 15548   0 07:52 ?        00:00:00 ora_d005_orcl
oracle    1821     1  0 59211 15544   0 07:52 ?        00:00:00 ora_d006_orcl
oracle    1823     1  0 59211 15544   0 07:52 ?        00:00:00 ora_d007_orcl
oracle    1825     1  0 59211 15544   0 07:52 ?        00:00:00 ora_d008_orcl
oracle    1827     1  0 59211 15544   0 07:52 ?        00:00:00 ora_d009_orcl
oracle    1829     1  0 59211 15544   0 07:52 ?        00:00:00 ora_d010_orcl
oracle    1831     1  0 59211 15544   0 07:52 ?        00:00:00 ora_d011_orcl
...

SZ = 59211 k= 57 meg.  Total SZ = 5.89 gigabytes.  Still this is bigger than total memory but closer to the 4 gig memory available.  It’s just a guess, but I’m pretty sure that with HugePages this total doesn’t include the amount of memory in use in the SGA in the SZ for each process as it did without HugePages.

The other weird thing is how different top looks with HugePages.  Here is top with the database having just come up without HugePages:

top - 07:20:16 up 3 min,  2 users,  load average: 1.06, 0.33, 0.13
Tasks: 187 total,   1 running, 186 sleeping,   0 stopped,   0 zombie
Cpu(s):  1.6%us,  6.3%sy,  0.0%ni, 77.8%id, 14.2%wa,  0.0%hi,  0.1%si,  0.0%st
Mem:   4050836k total,   984444k used,  3066392k free,    14460k buffers
Swap:  4095996k total,        0k used,  4095996k free,   450128k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND            
 2010 oracle    20   0 3310m  51m  44m D  7.6  1.3   0:00.21 oracle             
 1988 oracle    20   0 3307m  50m  45m D  3.8  1.3   0:00.21 oracle             
 1794 oracle    -2   0 3303m  15m  13m S  1.9  0.4   0:01.07 oracle

Notice that we have about 3 gigabytes free – 3066392k and nothing in swap.

Here is the same system  with 3 gig of HugePages:

top - 07:53:21 up 2 min,  2 users,  load average: 0.81, 0.29, 0.11
Tasks: 179 total,   1 running, 178 sleeping,   0 stopped,   0 zombie
Cpu(s):  2.0%us,  8.6%sy,  0.0%ni, 69.2%id, 20.1%wa,  0.0%hi,  0.1%si,  0.0%st
Mem:   4050836k total,  3860100k used,   190736k free,    14332k buffers
Swap:  4095996k total,        0k used,  4095996k free,   239104k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND            
 1781 oracle    -2   0 3303m  15m  13m S  3.5  0.4   0:01.02 oracle             
    1 root      20   0 19400 1520 1220 S  0.0  0.0   0:01.43 init               
    2 root      20   0     0    0    0 S  0.0  0.0   0:00.00 kthreadd

Now only 190736k is free.  But, note that in both cases top lists the oracle processes with 3300 meg of virtual memory, which is consistent with the 3 gig max sga.

I’ve still got a lot to learn about HugePages but I thought I would pass along these observations.  This article on Oracle’s support site helped me learn about HugePages:

HugePages on Oracle Linux 64-bit (Doc ID 361468.1)

I ended up sizing the HugePages down to 2 gig on my 4 gig test system and reducing sga max size to 2 gig as well.  My system was sluggish with so little free memory when I was using a 3 gig SGA and HugePages.  It was much snappier with only 2 gig tied up in HugePages and dedicated to the SGA, leaving 2 gig for everything else.

This was all done with Oracle’s 64 bit version of Linux and 11.2.0.3 database.

– Bobby