Thursday, December 23, 2010
Sunday, December 19, 2010
Baby Blues BBQ in Philadelphia
I visited Baby Blues BBQ in Philly this past week and had the “Mason Dixon” (1/2 RACK of MEMPHIS RIBS, 1/4 of a CHICKEN). The Mac and Cheese is great with the hot sauce by the way. If you're in Philly and want some ribs instead of a cheese stake sandwich, try them out. Great folks working the grill and super servers.
I sat where I was looking right on to the grill and watched the guys making the food. Makes ya more hungry watching the food get prepared. They were cooking up ribs and chicken and shrimp and corn on the cob all on the grill! It was great.
The place is a little of the beaten path, and worth the time to find:
3402 Sansom St
Philadelphia, PA 19104
Tuesday, November 23, 2010
Error Logging in SQLPlus
This is pretty cool. You can now log errors in to table within SQLPlus. I think when this feature first came out it was just for DML (insert, update and delete) but now it seems to work for any error that is raised within a SQLplus session.
The command to turn this on is a SQLPlus SET command, it's simplest format is:
SET ERRORLOGGING on
With this SQLPlus will start putting errors into a table called sperrorlog. What's cool about this statement is that if the table doesn't exist it will created it. In the more verbose format it would look something like this:
SET ERRORLOGGING on TABLE hsperrorlog TRUNCATE IDENTIFIER HARNESS
With this I have to create a table named hsperrorlog. The TRUNCATE option truncates the contents of the table before it starts logging anything into it. The IDENTIFIER option allows you to populate a column in the table, with the name of (you guessed it) IDENTIFIER. (Pretty cleaver eh?)
The table has these columns (all can be null):
USERNAME data type VARCHAR2(256) the user running the command.
TIMESTAMP data type TIMESTAMP(6) when the error was encountered.
SCRIPT data type VARCHAR2(1024) the name of the script being run. If this is an interactively entered command this will be null.
IDENTIFIER data type VARCHAR2(256) the optional id used when turning on error logging. You can change the identifier by just doing a set command like this:
set errorlogging ON IDENTIFIER RVD
This doesn't change the table that the errors are being logged into.
MESSAGE data type CLOB this is the error message.
STATEMENT data type CLOB this is the statement that raised the error.
I've been using it to add some needed functionality to the Hotsos Harness and it's already helped me clean up a few minor errors in the harness that have been quite hard to track down with out this.
Here is a very simple example, the output was reformatted to make this easier to read:
OP@ORCL112> SET ERRORLOGGING on TABLE hsperrorlog TRUNCATE IDENTIFIER HARNESS
OP@ORCL112> select * from XYZ;
select * from XYZ
*
ERROR at line 1:
ORA-00942: table or view does not exist
OP@ORCL112> select * from hsperrorlog;
USERNAME
-----------
OP
TIMESTAMP
----------------------------
23-NOV-10 12.59.39.000000 PM
SCRIPT
----------------------------
IDENTIFIER
----------
HARNESS
MESSAGE
---------------------------------------
ORA-00942: table or view does not exist
STATEMENT
-----------------
select * from XYZ
Check this out, it should make debugging SQL scripts a lot easier!! There are some limitations to it of course, it's not on for recursive SQL which makes a lot of sense since it could easily get into an infinite loop. Also if your scripts do reconnections, you'll have to turn it back on each time you reconnect. It is off by default.
Oh and to turn it off it looks like:
OP@ORCL112> SET ERRORLOGGING off
OP@ORCL112>
OP@ORCL112> show errorl
errorlogging is OFF
The command to turn this on is a SQLPlus SET command, it's simplest format is:
SET ERRORLOGGING on
With this SQLPlus will start putting errors into a table called sperrorlog. What's cool about this statement is that if the table doesn't exist it will created it. In the more verbose format it would look something like this:
SET ERRORLOGGING on TABLE hsperrorlog TRUNCATE IDENTIFIER HARNESS
With this I have to create a table named hsperrorlog. The TRUNCATE option truncates the contents of the table before it starts logging anything into it. The IDENTIFIER option allows you to populate a column in the table, with the name of (you guessed it) IDENTIFIER. (Pretty cleaver eh?)
The table has these columns (all can be null):
USERNAME data type VARCHAR2(256) the user running the command.
TIMESTAMP data type TIMESTAMP(6) when the error was encountered.
SCRIPT data type VARCHAR2(1024) the name of the script being run. If this is an interactively entered command this will be null.
IDENTIFIER data type VARCHAR2(256) the optional id used when turning on error logging. You can change the identifier by just doing a set command like this:
set errorlogging ON IDENTIFIER RVD
This doesn't change the table that the errors are being logged into.
MESSAGE data type CLOB this is the error message.
STATEMENT data type CLOB this is the statement that raised the error.
I've been using it to add some needed functionality to the Hotsos Harness and it's already helped me clean up a few minor errors in the harness that have been quite hard to track down with out this.
Here is a very simple example, the output was reformatted to make this easier to read:
OP@ORCL112> SET ERRORLOGGING on TABLE hsperrorlog TRUNCATE IDENTIFIER HARNESS
OP@ORCL112> select * from XYZ;
select * from XYZ
*
ERROR at line 1:
ORA-00942: table or view does not exist
OP@ORCL112> select * from hsperrorlog;
USERNAME
-----------
OP
TIMESTAMP
----------------------------
23-NOV-10 12.59.39.000000 PM
SCRIPT
----------------------------
IDENTIFIER
----------
HARNESS
MESSAGE
---------------------------------------
ORA-00942: table or view does not exist
STATEMENT
-----------------
select * from XYZ
Check this out, it should make debugging SQL scripts a lot easier!! There are some limitations to it of course, it's not on for recursive SQL which makes a lot of sense since it could easily get into an infinite loop. Also if your scripts do reconnections, you'll have to turn it back on each time you reconnect. It is off by default.
Oh and to turn it off it looks like:
OP@ORCL112> SET ERRORLOGGING off
OP@ORCL112>
OP@ORCL112> show errorl
errorlogging is OFF
Tuesday, October 12, 2010
Kerry Osborne - Keynote Speaker for Hotsos Symposium 2011!!
WOW! The 2011 Sym is lining up to be a great one!! Clear your schedule for March 6-11 2011 and be Omni Mandalay Hotel in Las Colinas (Dallas) Texas, USA!
Kerry Osborne has just been named the Keynote Speaker, and Karen Morton is doing the one day of training.
This is certainly a sym you don't want to miss. Have you signed up yet? Click here and do it now!
Kerry Osborne has just been named the Keynote Speaker, and Karen Morton is doing the one day of training.
This is certainly a sym you don't want to miss. Have you signed up yet? Click here and do it now!
Tuesday, July 13, 2010
Branded Steer
Yes I do still eat ribs. This was at a place call Branded Steer. Great fall off the bone ribs and the beans were nice and sweet, maybe a touch too sweet. The place certainly had a "Texas" feel to it, even my waitress gave a decent shot at a Taxes drawl. Not bad considering I'm in Wisconsin.
Thursday, July 8, 2010
Postings
I have been trying to make some posts recently but my HTML skills are apparently not where they need to be. When trying to post code or an explain plan they just come out unreadable. And given that my goal is to talk about Oracle SQL (oh and food too) this really hampers my ability to post things. I may just have to find a different hosting service, or I might just have to buckle down and really learn HTML so I can make readable posts here. I know it can be done, I see lots of other folks posting code and such. Some I know are using screen shots which are OK, but I'm really hoping to not have to do that. I hope every one is having a good summer here in the Northern Hemisphere, and that the winter is kind to you in the Southern.
Tuesday, May 11, 2010
What’s going on with STAT lines in 10046 trace data?
I’ve long been teaching folks about the value of using the STAT lines in 10046 Trace data to help in optimizing queries. With STAT lines it’s been quite easy to see which part of a plan takes up the most time and does the most LIOs (Logical IOs).
This is a simple plan from 10.2:
Each of the above is one line; I’ve broken it into two to make it a bit easier to read.
The ID and PID show the relationship between the steps. The ID shows the order of the steps in the plan, and the PID shows which step is the parent of a step. Hence the last two lines are children of the second line, they each have a PID of 2. And the second step is the only child of the first step. The first step has no parent since its PID is 0 (zero).
The numbers in the parenthesis are the really cool ones. These numbers tell us about how much work was done for each row source operation, including its children. So for example, the CR value (which is the LIOs) in the HASH JOIN line of 494 includes the 184 and the 310 of the next two lines. So the HASH JOIN didn’t really do any LIOs. All the LIOs were in the two other steps. 184 + 310 = 494
Of particular interest can be the TIME value. It also includes the children of a step. Here we can see which step took up the most time. The HASH JOIN shows a TIME of 595, 897, if we subtract out of that the TIME of the next two steps 24,947 + 212,985 = 237,932 so 595,897 – 237,932 = 357,965. This tells us that even though the HASH JOIN didn’t do any LIOs it did take the longest time to run.
These TIME values are in Micro Seconds (that’s what the “us” is after the time, it’s really a µs.)
This is great stuff and I use this to drill right to the problem step of a plan. However things are not looking good with 11.
Here is a simple plan in 11.1.0.6 (side note, this is the good old EMP - DEPT join, which has been a NESTED LOOP join forever, notice in 11 it’s now a SORT MERGE plan):
STAT #6 id=1 cnt=13 pid=0 pos=1 obj=0
op='MERGE JOIN (cr=6 pr=0 pw=0 time=144 us cost=5 size=767 card=13)‘
STAT #6 id=2 cnt=4 pid=1 pos=1 obj=71198
op='TABLE ACCESS BY INDEX ROWID DEPT (cr=4 pr=0 pw=0 time=44 us cost=2 size=80 card=4)'
STAT #6 id=3 cnt=4 pid=2 pos=1 obj=71199
op='INDEX FULL SCAN DEPT_DEPTNO_PK (cr=2 pr=0 pw=0 time=26 us cost=1 size=0 card=4)'
STAT #6 id=4 cnt=13 pid=1 pos=2 obj=0
op='SORT JOIN (cr=2 pr=0 pw=0 time=22 us cost=3 size=507 card=13)'
STAT #6 id=5 cnt=13 pid=4 pos=1 obj=71200
op='TABLE ACCESS BY INDEX ROWID EMP (cr=2 pr=0 pw=0 time=72 us cost=2 size=507 card=13)'
STAT #6 id=6 cnt=13 pid=5 pos=1 obj=71205
op='INDEX FULL SCAN EMP_DEPT_IDX (cr=1 pr=0 pw=0 time=24 us cost=1 size=0 card=13)'
Well it may not be clear from just looking at the stat lines but the timings are a miss. The SORT JOIN step (ID 4) shows a TIME of 22 and it has one child (ID 5). This 22 can't included the time of step 5 which is 72 (the 24 in step 6 is part of the 72.) There seems to be a pattern of any time there is a sort in the plan, the timings seem to be off.
But wait it gets worse!
In 11.1.0.7 we see this:
STAT #17 id=1 cnt=13 pid=0 pos=1 obj=0
op='MERGE JOIN (cr=6 pr=0 pw=0 time=0 us cost=5 size=767 card=13)'
STAT #17 id=2 cnt=4 pid=1 pos=1 obj=77595
op='TABLE ACCESS BY INDEX ROWID DEPT (cr=4 pr=0 pw=0 time=0 us cost=2 size=80 card=4)'
STAT #17 id=3 cnt=4 pid=2 pos=1 obj=77596
op='INDEX FULL SCAN DEPT_DEPTNO_PK (cr=2 pr=0 pw=0 time=0 us cost=1 size=0 card=4)'
STAT #17 id=4 cnt=13 pid=1 pos=2 obj=0
op='SORT JOIN (cr=2 pr=0 pw=0 time=0 us cost=3 size=507 card=13)'
STAT #17 id=5 cnt=13 pid=4 pos=1 obj=77597
op='TABLE ACCESS BY INDEX ROWID EMP (cr=2 pr=0 pw=0 time=0 us cost=2 size=507 card=13)'
STAT #17 id=6 cnt=13 pid=5 pos=1 obj=77602
op='INDEX FULL SCAN EMP_DEPT_IDX (cr=1 pr=0 pw=0 time=0 us cost=1 size=0 card=13)'
Now all the TIME values are Zero!! Well maybe this is better, at least we don’t have numbers that don’t add up! Oh and before you ask, yes STATISTICS_LEVEL was set to ALL for these tests.
I’m not sure what is going on but this is a bad sign. We at one time had a great way to see what was happening for each line in a SQL statement. Now it appears that we are getting either bad data or no data. This is quite distressing.
I don’t have an 11.2 database currently to test on. Maybe it’s fixed, but I’m doubtful. Based on the bugs I’ve seen on Metalink that address this issue, the problem still seems to be there in 11.2.
In 11.1.0.6 the data in the view V$SQL_PLAN_STATISTICS and $SQL_PLAN_STATISTICS_ALL seemed to be unaffected by this. But in 11.1.0.7 this “feature” has gotten into those views as well.
This is a simple plan from 10.2:
STAT #8 id=1 cnt=348 pid=0 pos=1 obj=0
STAT #8 id=2 cnt=2399 pid=1 pos=1 obj=0
op='HASH JOIN (cr=494 pr=19 pw=0 time=595897 us)'
STAT #8 id=3 cnt=437 pid=2 pos=1 obj=57036
op='TABLE ACCESS FULL ORD2 (cr=184 pr=11 pw=0 time=24947 us)'
STAT #8 id=4 cnt=70975 pid=2 pos=2 obj=57039
op='TABLE ACCESS FULL ORD_ITEM2 (cr=310 pr=8 pw=0 time=212985 us)'
op='SORT GROUP BY (cr=494 pr=19 pw=0 time=603190 us)'
STAT #8 id=2 cnt=2399 pid=1 pos=1 obj=0
op='HASH JOIN (cr=494 pr=19 pw=0 time=595897 us)'
STAT #8 id=3 cnt=437 pid=2 pos=1 obj=57036
op='TABLE ACCESS FULL ORD2 (cr=184 pr=11 pw=0 time=24947 us)'
STAT #8 id=4 cnt=70975 pid=2 pos=2 obj=57039
op='TABLE ACCESS FULL ORD_ITEM2 (cr=310 pr=8 pw=0 time=212985 us)'
Each of the above is one line; I’ve broken it into two to make it a bit easier to read.
The ID and PID show the relationship between the steps. The ID shows the order of the steps in the plan, and the PID shows which step is the parent of a step. Hence the last two lines are children of the second line, they each have a PID of 2. And the second step is the only child of the first step. The first step has no parent since its PID is 0 (zero).
The numbers in the parenthesis are the really cool ones. These numbers tell us about how much work was done for each row source operation, including its children. So for example, the CR value (which is the LIOs) in the HASH JOIN line of 494 includes the 184 and the 310 of the next two lines. So the HASH JOIN didn’t really do any LIOs. All the LIOs were in the two other steps. 184 + 310 = 494
Of particular interest can be the TIME value. It also includes the children of a step. Here we can see which step took up the most time. The HASH JOIN shows a TIME of 595, 897, if we subtract out of that the TIME of the next two steps 24,947 + 212,985 = 237,932 so 595,897 – 237,932 = 357,965. This tells us that even though the HASH JOIN didn’t do any LIOs it did take the longest time to run.
These TIME values are in Micro Seconds (that’s what the “us” is after the time, it’s really a µs.)
This is great stuff and I use this to drill right to the problem step of a plan. However things are not looking good with 11.
Here is a simple plan in 11.1.0.6 (side note, this is the good old EMP - DEPT join, which has been a NESTED LOOP join forever, notice in 11 it’s now a SORT MERGE plan):
STAT #6 id=1 cnt=13 pid=0 pos=1 obj=0
op='MERGE JOIN (cr=6 pr=0 pw=0 time=144 us cost=5 size=767 card=13)‘
STAT #6 id=2 cnt=4 pid=1 pos=1 obj=71198
op='TABLE ACCESS BY INDEX ROWID DEPT (cr=4 pr=0 pw=0 time=44 us cost=2 size=80 card=4)'
STAT #6 id=3 cnt=4 pid=2 pos=1 obj=71199
op='INDEX FULL SCAN DEPT_DEPTNO_PK (cr=2 pr=0 pw=0 time=26 us cost=1 size=0 card=4)'
STAT #6 id=4 cnt=13 pid=1 pos=2 obj=0
op='SORT JOIN (cr=2 pr=0 pw=0 time=22 us cost=3 size=507 card=13)'
STAT #6 id=5 cnt=13 pid=4 pos=1 obj=71200
op='TABLE ACCESS BY INDEX ROWID EMP (cr=2 pr=0 pw=0 time=72 us cost=2 size=507 card=13)'
STAT #6 id=6 cnt=13 pid=5 pos=1 obj=71205
op='INDEX FULL SCAN EMP_DEPT_IDX (cr=1 pr=0 pw=0 time=24 us cost=1 size=0 card=13)'
Well it may not be clear from just looking at the stat lines but the timings are a miss. The SORT JOIN step (ID 4) shows a TIME of 22 and it has one child (ID 5). This 22 can't included the time of step 5 which is 72 (the 24 in step 6 is part of the 72.) There seems to be a pattern of any time there is a sort in the plan, the timings seem to be off.
But wait it gets worse!
In 11.1.0.7 we see this:
STAT #17 id=1 cnt=13 pid=0 pos=1 obj=0
op='MERGE JOIN (cr=6 pr=0 pw=0 time=0 us cost=5 size=767 card=13)'
STAT #17 id=2 cnt=4 pid=1 pos=1 obj=77595
op='TABLE ACCESS BY INDEX ROWID DEPT (cr=4 pr=0 pw=0 time=0 us cost=2 size=80 card=4)'
STAT #17 id=3 cnt=4 pid=2 pos=1 obj=77596
op='INDEX FULL SCAN DEPT_DEPTNO_PK (cr=2 pr=0 pw=0 time=0 us cost=1 size=0 card=4)'
STAT #17 id=4 cnt=13 pid=1 pos=2 obj=0
op='SORT JOIN (cr=2 pr=0 pw=0 time=0 us cost=3 size=507 card=13)'
STAT #17 id=5 cnt=13 pid=4 pos=1 obj=77597
op='TABLE ACCESS BY INDEX ROWID EMP (cr=2 pr=0 pw=0 time=0 us cost=2 size=507 card=13)'
STAT #17 id=6 cnt=13 pid=5 pos=1 obj=77602
op='INDEX FULL SCAN EMP_DEPT_IDX (cr=1 pr=0 pw=0 time=0 us cost=1 size=0 card=13)'
Now all the TIME values are Zero!! Well maybe this is better, at least we don’t have numbers that don’t add up! Oh and before you ask, yes STATISTICS_LEVEL was set to ALL for these tests.
I’m not sure what is going on but this is a bad sign. We at one time had a great way to see what was happening for each line in a SQL statement. Now it appears that we are getting either bad data or no data. This is quite distressing.
I don’t have an 11.2 database currently to test on. Maybe it’s fixed, but I’m doubtful. Based on the bugs I’ve seen on Metalink that address this issue, the problem still seems to be there in 11.2.
In 11.1.0.6 the data in the view V$SQL_PLAN_STATISTICS and $SQL_PLAN_STATISTICS_ALL seemed to be unaffected by this. But in 11.1.0.7 this “feature” has gotten into those views as well.
Monday, March 22, 2010
My Oracle Book list
This is a list of books that I've pulled together over the years. I hand out this list in most of my classes and several folks have mentioned that I should post it here as well. They are not in any particular order.
These are books that every Oracle professional should have on hand. It's not intended to be the "be all end all" list, just a list of books to start with. With these and the Oracle Documentation, you will be well on your way to understanding how the Oracle Database works. Some are a little old but those still have great information in them.
No I don't get any kick back on sales of these books, maybe I should... Hummmm....
· Cost-Based Oracle Fundamentals (Apress) By: Jonathon Lewis
· Practical Oracle8i(TM): Building Efficient Databases (Addison-Wesley) By:
Jonathon Lewis
· Optimizing Oracle Performance By: Cary Milsap, Jeff Holt
· Relational Database Index Design and the Optimizers By: Tapio Lahdenmaki,
Mike Leach
· Effective Oracle by Design (Osborne ORACLE Press Series) By: Tom Kyte
· Expert Oracle, Signature Edition Programming Techniques and Solutions for
Oracle 7.3 through 8.1.7 (Expert One-On-One) By: Tom Kyte
· The Art of SQL (Art of) [Illustrated] By: Stephane Faroult, Peter Robson
· Database in Depth: Relational Theory for Practitioners By: C.J. Date
· Expert Oracle Database Architecture: 9i and 10g Programming Techniques and
Solutions By: Tom Kyte
· Oracle Database 10g High Availability with RAC, Flashback, and Data Guard
(Osborne ORACLE Press Series) By: Matthew Hart, (and others)
· Oracle Dataguard : Standby Database Failover Handbook (Oracle In-Focus series)
By: Bipul Kumar
· Mastering Oracle SQL and SQL*Plus By: Lex de Haan
· Oracle Insights: Tales of the Oak Table By: Dave Ensor, (and others)
· Oracle Wait Interface: A Practical Guide to Performance Diagnostics & Tuning
(Osborne ORACLE Press Series) By: Richmond Shee, (and others)
· For PL/SQL – anything by Steven Feuerstein
These are books that every Oracle professional should have on hand. It's not intended to be the "be all end all" list, just a list of books to start with. With these and the Oracle Documentation, you will be well on your way to understanding how the Oracle Database works. Some are a little old but those still have great information in them.
No I don't get any kick back on sales of these books, maybe I should... Hummmm....
· Cost-Based Oracle Fundamentals (Apress) By: Jonathon Lewis
· Practical Oracle8i(TM): Building Efficient Databases (Addison-Wesley) By:
Jonathon Lewis
· Optimizing Oracle Performance By: Cary Milsap, Jeff Holt
· Relational Database Index Design and the Optimizers By: Tapio Lahdenmaki,
Mike Leach
· Effective Oracle by Design (Osborne ORACLE Press Series) By: Tom Kyte
· Expert Oracle, Signature Edition Programming Techniques and Solutions for
Oracle 7.3 through 8.1.7 (Expert One-On-One) By: Tom Kyte
· The Art of SQL (Art of) [Illustrated] By: Stephane Faroult, Peter Robson
· Database in Depth: Relational Theory for Practitioners By: C.J. Date
· Expert Oracle Database Architecture: 9i and 10g Programming Techniques and
Solutions By: Tom Kyte
· Oracle Database 10g High Availability with RAC, Flashback, and Data Guard
(Osborne ORACLE Press Series) By: Matthew Hart, (and others)
· Oracle Dataguard : Standby Database Failover Handbook (Oracle In-Focus series)
By: Bipul Kumar
· Mastering Oracle SQL and SQL*Plus By: Lex de Haan
· Oracle Insights: Tales of the Oak Table By: Dave Ensor, (and others)
· Oracle Wait Interface: A Practical Guide to Performance Diagnostics & Tuning
(Osborne ORACLE Press Series) By: Richmond Shee, (and others)
· For PL/SQL – anything by Steven Feuerstein
Sunday, February 14, 2010
Oak Table Comes to Michigan!
The first Michigan Oak Table Symposium (MOTS) is happening this September! On the 16th and 17th.
Go here NOW to see more info and sign up, only 300 attendees will be allowed -> http://michigan.oaktable.net
There is a great set of speaker for this event and you wouldn't want to miss this!!
A partial list of speakers includes: Jonathan Lewis, Cary Millsap, Christian Antognini, Riyaj Shamsudeen, Randolf Geist, Charles Hooper, and many more.
(Find the Oak Tree in the above picture for a prize! Hint: There isn't one....)
Subscribe to:
Posts (Atom)