Approaching a car park barrier : What it says about you!

parking-barrierWhich of these describes you?

Option 1:

  1. Drive up to the barrier.
  2. Open the car window.
  3. Rummage through your bag or glove compartment looking for your parking pass.
  4. Swipe your pass.
  5. Put your card away. Probably in a random place each time.
  6. Pull away from the barrier.

Option 2:

  1. Approach the barrier with your card in hand and the car window already open.
  2. Swipe the card immediately.
  3. Pull away, almost without stopping because you were so well prepared.

If you most closely match “Option 1″, please don’t think about a career in I.T. The fact you find it acceptable to approach any task in life in this way says to me you are not what this industry needs! Probably not what the human race needs!

Cheers

Tim… (Suffering from “barrier rage” this morning!)


Approaching a car park barrier : What it says about you! was first posted on May 19, 2015 at 8:55 am.
©2012 "The ORACLE-BASE Blog". Use of this feed is for personal non-commercial use only. If you are not reading this article in your feed reader, then the site is guilty of copyright infringement.

Change first day of week in APEX 5.0 Calendar

APEX 5.0 comes with a new calendar region, which is way nicer than the previous calendar in APEX. It has more features, looks better and is also responsive. Behind the scenes you'll see the calendar region is based on Full Calendar.


In Belgium we use Monday as first day of the week, whereas in the US they seem to use Sunday as start of the week in the calendar overview. I've been integrating Full Calendar before, so I knew that library had an option to set the first day of the week. You could either specify an option called firstDay and set that to 1, or you could change the language, and depending the language it would adjust the start day of the week.

In APEX 5.0 I looked for that option, but there's not a specific attribute to set the first day of the week, instead it's based on the language of your application. If you go to Shared Components > Globalization Attributes by default it's set to en, which has Sunday as start of the week. If you set it to en-gb it will have Monday as start of the week.


I searched some time to find how to do it, so hopefully this post will help others to find it more easily. Thanks to Patrick for sharing the way it was implemented.

Writing Tips : How often should I write?

writingThe true answer to this is to write as (in)frequently as you want, but in my motivation post I suggested writing little and often. I think this is really important when you first start. Like anything, writing takes practice. It takes a while to get into the right head-space and even longer until you are happy with the way you express yourself. I imagine that is even worse if you are trying to writing in a second language.

In addition to what I said in the motivation post, there are a couple of things to consider.

If you are in the mood, keep going. Some days it just really feels natural and you feel happy with the content you are producing. On those days, don’t put an artificial limit on yourself. Let it flow.

Even if you are writing regularly, don’t be too quick to hit that publish button. Dumping 20 blog posts on the world will probably result in many of them being overlooked by your “loyal” followers. Having a few “in reserve” is also a pretty good idea for those times when you really can’t be bothered. :) Of course, time-critical posts like, “X has just been released and it’s [amazing|rubbish]!”, have a limited shelf life. :)

As an example of these two points, this series of posts was conceived and written in a single session at the computer. Rather than banging them out, I planned to sit on them for a week and re-read them a few times, then start to release them on a daily basis.

As I said in the motivation post, the world doesn’t care how often you hit the publish button. :)

Cheers

Tim…


Writing Tips : How often should I write? was first posted on May 19, 2015 at 7:39 am.
©2012 "The ORACLE-BASE Blog". Use of this feed is for personal non-commercial use only. If you are not reading this article in your feed reader, then the site is guilty of copyright infringement.

Indexing and Transparent Data Encryption Part I (The Secret Life of Arabia)

Database security has been a really hot topic recently so I thought I might write a few posts in relation to indexing and Transparent Data Encryption (TDE) which is available as part of the Oracle Advanced Security option. To protect the database from unauthorized “backed-door” accesses, the data within the actual database files can be encrypted. […]

SQL ID Specific Performance Information

When you need to have information about one SQL_ID and don’t need everything and the kitchen sink, there are a few different ways to collect this via Oracle.  I’m surprised how rarely this is covered in performance tuning/optimization, (whatever the current “acceptable” term is for fixing a database when there are performance issues arise… J)  classes, manuals and documentation.  I’d like to cover two of my favorite here and know, there are other options that I won’t be digging into, (SQLd360, SQLTXPLAIN, tracing, etc…)

The Workload Repository SQL Report

I also refer to this as the “SQL ID Specific AWR Report”.  Now many of you may have come across this report via Cloud Control when you go into a unique SQL_ID in the console and upon looking at the details, you notice there are two options below the wait event actrivity, one for run an AWR SQL Report and one for an ASH report.  What many don’t realize, is that this report also is available from the command line on the database host.

awrsq1

Report Location:  $ORACLE_HOME/rdbms/admin/awrsqrpt.sql

Report Format:  HTML from Cloud Control and the command line, TEXT is also an option from SQL Plus.

Requirements:  Execution DBMS_Repository and privileges to run reports and store on the host or if you run via Cloud Control, then you just can save off the HTML report to your desktop.

Licensing:  Yes, you do need diagnostics pack for this feature.

What’s so great about this report?

This report, like “Search SQL”, which we’ll go over soon enough, allows you to go through all of the AWR history you possess and let you know the minimum and maximum runs, execution plans for each plan hash value that exists, along with elapsed time and other pertinent statistical information about the SQL ID in question.

Notice that the version of the database, that it’s a RAC instance, along with which node in the RAC environment the statement was run in, is quickly stated, so if anyone questions this, you can quickly locate this information at the top of the report.

awrsq2

The report will display the SQL_ID in question, along with identifying if there was more than one plan hash value, (which the report will number and identify by PHV, (plan hash value) and the plan hash value ID.  This will make it easy to know which execution plan and events belong to which if there is more than one.  For our example, we do only have one here.

awrsq3

Remember for the elapsed time, this is for the total time for the snapshot timeline involved and you need to look at the per execution to see how long each one actually required to complete.  These statistics are very helpful when identifying the wait event(s) that are involved in the performance challenge.

awrsq4

The plan is nicely formatted and you can step into the time used for each step in the process.  I wish it defaulted with temp usage, but alas, that is not to be in the HTML report.  This is the only area of the report where I prefer the HTML report over the text, as with this report, there is considerable size difference for storing the report and I hate giving up any data…. :)

If you’ve had an outage during your snapshot timeline, then this report, just like AWR, is dependent upon up time and will notify you of the issue, requiring you to pick snapshots that have no downtime involved.

Search SQL

Search SQL has been around since EM10g, but it’s one of the least known features.  I like it as it gives a clean, high level view of performance over a large period of time by snapshot and then you can dig down to do research from there.

Report:  None really from the command line-  it’s a compilation of report features.

Report Format:  None-  this is via the console, but some of the reports can be saved off, (such as ADDM and other reports…)  you can also copy and paste or screenshot pages.

Licensing:  Due to the way we are using it here, both the diagnostics and the tuning pack will be required.

Using Search SQL

Using our same run as we used above, we can identify a SQL_ID that is causing us concern and we want to investigate further-

awrss1

Copy the SQL_ID so you can paste it in the proper field in the Search SQL console.  You’re now going to leave the Top Activity, (or ASH Analytics, whichever you are using, both work great for this type of initial identification…)

awrss2

Each Search SQL console is database specific, so click on the Performance drop down, SQL and then Search SQL for EM12c, (EM10g and EM11g, this is directly under the Performance menu….)

awrss3

Update the following sections:

  • Add AWR Snapshots and Baselines.
  • Choose All snapshots to verify that you are seeing the entire performance data contained in your AWR.  If your database is set with the default time for retaining AWR, this is 8 days for 11.2 and above.
  • Enter in or paste the SQL ID into the SQL ID value section.
  • Click on Search, (don’t click on Show SQL, as I know this is a bit misleading, but it will just show you the SQL statement to be run by Cloud Control…)

awrss4

Four tabs will be shown, don’t be surprised if you don’t notice the completion as the cache often only returns one row:

  • Cursor Cache, (in the cache currently)
  • AWR Snapshot data, (where we’ll spend most of our time…)
  • AWR Baselines, (good data to have to back up changes in plan hash values if you have your database set to update automatically or if someone’s put in a plan from a baseline run.)
  • SQL Tuning Set if you’ve chosen to examine those, too.

You CAN examine the existing run and looking at it this way really shows you how it’s currently running vs. how it has run, but if you’re just looking for when it really ran well, then skip the curor section and jump to the AWR snapshots to see this SQL ID for ALL snapshots in the AWR-

awrss5

You’re seeing all of this from the largest elapsed time to the least descending, so although we’re able to view any patterns on how the SQL may be degrading over time, note if there are plan has value changes, (which in our example, there are and we didn’t see that for this statement in our AWR SQL Report) and click on the “Next 25” link at the bottom to get to the lesser elapsed run times.

awrss6

There are some runs with 0.00 on the run times.  You can investigate these, but we’d find that they hadn’t completed or no rows were returned.  What is more important are the runs where we see overall run times that are efficient in the elapsed time and that rows were returned.  I’ve marked them in our report.

awrss7

Upon closer inspection, you’ll also notice that they all belong to the same plan hash value except for one run.  This is a good indicator that this plan has value should be identified as the best over all for this query.

Now as we all know, it’s not just about the one query.  The database could impact the run as well.

  • What resource limitations were in play?
  • Where there any concurrency issues?
  • Where there any other factors that overall effect performance?

On the right, you’ll notice that the snapshots are links.  You can use these to inspect the over all performance of the database during the snapshot interval the execution occurred.

awrss9

Here’s all that high level statistics info at the database level.  You also have the opportunity to run an ADDM report from here and see that “all that’s important” view of your database.

awrss8

Now the second tab is going to offer you the workload repository report for this database, including the summary to tell you, is there anything up in this database at that time that you should be aware of.

You can go back to the Search SQL report and then look at the individual executions listed, too.

awrss12

This will take you to the SQL Details page for whichever one you click on-

awrss10

Just as with any SQL Details, you can see the activity, the plan, plan control, etc.  The example above is for an execution from the day before, so it’s kind of an easy way to get to it vs. going and searching historically through Top Activity.

Baselines

Now why did we choose the Baselines as part of our search?  Baselines, especially when they are automatically implemented, can impact performance at times and knowing this information can quickly let you know it wasn’t another culprit involved.

awrss11

We can see what plan hash value is attributed to what baseline, the overall elapsed time and you can click on the Baseline Name link to see when and if it was implemented to diagnose if its part of your problem.

Hopefully this gives you some more tools for your arsenal when that boss or peer is standing at your desk and demanding an answer to a challenge-  what more can we ask for but answers! :)



Tags:  , ,

Del.icio.us
Facebook
TweetThis
Digg
StumbleUpon


Copyright © DBA Kevlar [SQL ID Specific Performance Information], All Right Reserved. 2015.

Migrated rows

I received an email recently describing a problem with a query which was running a full tablescan but: “almost all the waits are on ‘db file sequential read’ and the disk read is 10 times the table blocks”.  Some further information supplied was that the tablespace was using ASSM and 16KB block size; the table had 272 columns (ouch!) and the Oracle version was 11.2.0.4.

In his researches he had read my article on wide rows, and had picked out of one of the comments the line: “the very bad thing about chained rows and direct reads that is that finding the rest of row by ‘db file sequential read’ is never cached”, but he wasn’t sure that this was the problem he was seeing so, very sensibly, he had re-run the query with extended tracing available, and dumped (and formatted/edited) a couple of blocks from the table.

He then sent me the trace file and block dump. Generally this is a mistake – especially when the trace file is several megabytes – but he had prepared the ground well and had linked it back to one of my blog notes, and I thought there might be an opportunity for publishing a few more comments, so I took a look. Here’s a carefully edited subset of the block dump – showing all the pertinent information:


Start dump data blocks tsn: 99 file#:100 minblk 2513181 maxblk 2513181

Block header dump:  0x1926591d
 Object id on Block? Y
 seg/obj: 0x1652a7  csc: 0x53.891880b8  itc: 12  flg: E  typ: 1 - DATA
     brn: 1  bdba: 0x1965b70c ver: 0x01 opc: 0
     inc: 84  exflg: 0

 Itl           Xid                  Uba         Flag  Lck        Scn/Fsc
0x01   0x0010.01d.0000dff9  0x2b442286.3469.09  C---    0  scn 0x0053.891880b1
0x02   0x0000.000.00000000  0x00000000.0000.00  ----    0  fsc 0x0000.00000000
0x03   0x0000.000.00000000  0x00000000.0000.00  C---    0  scn 0x0000.00000000
0x04   0x0000.000.00000000  0x00000000.0000.00  C---    0  scn 0x0000.00000000
0x05   0x0000.000.00000000  0x00000000.0000.00  C---    0  scn 0x0000.00000000
0x06   0x0000.000.00000000  0x00000000.0000.00  C---    0  scn 0x0000.00000000
0x07   0x0000.000.00000000  0x00000000.0000.00  C---    0  scn 0x0000.00000000
0x08   0x0000.000.00000000  0x00000000.0000.00  C---    0  scn 0x0000.00000000
0x09   0x0000.000.00000000  0x00000000.0000.00  C---    0  scn 0x0000.00000000
0x0a   0x0000.000.00000000  0x00000000.0000.00  C---    0  scn 0x0000.00000000
0x0b   0x0000.000.00000000  0x00000000.0000.00  C---    0  scn 0x0000.00000000
0x0c   0x0000.000.00000000  0x00000000.0000.00  C---    0  scn 0x0000.00000000
bdba: 0x1926591d

data_block_dump,data header at 0x11083f154
===============
tsiz: 0x1ea8
hsiz: 0x26
pbl: 0x11083f154
     76543210
flag=--------
ntab=1
nrow=10
frre=-1
fsbo=0x26
fseo=0x4c5
avsp=0x49f
tosp=0x49f
0xe:pti[0]	nrow=10	offs=0
0x12:pri[0]	offs=0x1c15
0x14:pri[1]	offs=0x197b
0x16:pri[2]	offs=0x16e1
0x18:pri[3]	offs=0x1448
0x1a:pri[4]	offs=0x11b8
0x1c:pri[5]	offs=0xf1f
0x1e:pri[6]	offs=0xc85
0x20:pri[7]	offs=0x9ec
0x22:pri[8]	offs=0x752
0x24:pri[9]	offs=0x4c5
block_row_dump:
tab 0, row 0, @0x1c15
tl: 659 fb: -----L-- lb: 0x0  cc: 255
tab 0, row 1, @0x197b
tl: 666 fb: -----L-- lb: 0x0  cc: 255
tab 0, row 2, @0x16e1
tl: 666 fb: -----L-- lb: 0x0  cc: 255
tab 0, row 3, @0x1448
tl: 665 fb: -----L-- lb: 0x0  cc: 255
tab 0, row 4, @0x11b8
tl: 656 fb: -----L-- lb: 0x0  cc: 255
tab 0, row 5, @0xf1f
tl: 665 fb: -----L-- lb: 0x0  cc: 255
tab 0, row 7, @0x9ec
tl: 665 fb: -----L-- lb: 0x0  cc: 255
tab 0, row 8, @0x752
tl: 666 fb: -----L-- lb: 0x0  cc: 255
tab 0, row 9, @0x4c5
tl: 653 fb: -----L-- lb: 0x0  cc: 255

In the ITL you can see 10 entries with the flag set to “C—-” (committed) with no XID or SCN – that’s consistent with 10 rows migrating into the block in a single transaction. In the row directory you can see the block holds 10 rows, and in the body of the block you can see the header for each of those 10 rows with 255 columns (presumably the 2nd section of each row of 272 columns), and the flag bytes set to “—–L–” (the Last piece of a chained – as opposed to simply migrated – row).

So the block dump is consistent with the possiblity of a direct path read of a block somewhere (10 head pieces) having to read this block 10 times shortly afterwards. Can we find further corroboration in the trace file? The blockdump was for block 0x1926591d = 421943581 decimal


PARSE #4573135368:c=29,e=48,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=4116693033,tim=79008343283418
EXEC #4573135368:c=53,e=93,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=4116693033,tim=79008343283607
WAIT #4573135368: nam='SQL*Net message to client' ela= 1 driver id=1413697536 #bytes=1 p3=0 obj#=15477650 tim=79008343283636
WAIT #4573135368: nam='Disk file operations I/O' ela= 38 FileOperation=2 fileno=101 filetype=2 obj#=1462951 tim=79008343283973
WAIT #4573135368: nam='direct path read' ela= 8991 file number=100 first dba=947580 block cnt=13 obj#=1462951 tim=79008343293041

WAIT #4573135368: nam='db file sequential read' ela= 4934 file#=100 block#=2513181 blocks=1 obj#=1462951 tim=79008343298032
WAIT #4573135368: nam='db file sequential read' ela= 155 file#=100 block#=2513181 blocks=1 obj#=1462951 tim=79008343298216
WAIT #4573135368: nam='db file sequential read' ela= 127 file#=100 block#=2513181 blocks=1 obj#=1462951 tim=79008343298378
WAIT #4573135368: nam='db file sequential read' ela= 125 file#=100 block#=2513181 blocks=1 obj#=1462951 tim=79008343298526
WAIT #4573135368: nam='db file sequential read' ela= 128 file#=100 block#=2513181 blocks=1 obj#=1462951 tim=79008343298677
WAIT #4573135368: nam='db file sequential read' ela= 123 file#=100 block#=2513181 blocks=1 obj#=1462951 tim=79008343298826
WAIT #4573135368: nam='db file sequential read' ela= 134 file#=100 block#=2513181 blocks=1 obj#=1462951 tim=79008343298983
WAIT #4573135368: nam='db file sequential read' ela= 129 file#=100 block#=2513181 blocks=1 obj#=1462951 tim=79008343299135
WAIT #4573135368: nam='db file sequential read' ela= 180 file#=100 block#=2513181 blocks=1 obj#=1462951 tim=79008343299341
WAIT #4573135368: nam='db file sequential read' ela= 133 file#=100 block#=2513181 blocks=1 obj#=1462951 tim=79008343299497

WAIT #4573135368: nam='db file sequential read' ela= 11039 file#=100 block#=2513245 blocks=1 obj#=1462951 tim=79008343310565
WAIT #4573135368: nam='db file sequential read' ela= 133 file#=100 block#=2513245 blocks=1 obj#=1462951 tim=79008343310730
WAIT #4573135368: nam='db file sequential read' ela= 139 file#=100 block#=2513245 blocks=1 obj#=1462951 tim=79008343310895
WAIT #4573135368: nam='db file sequential read' ela= 124 file#=100 block#=2513245 blocks=1 obj#=1462951 tim=79008343311045
WAIT #4573135368: nam='db file sequential read' ela= 122 file#=100 block#=2513245 blocks=1 obj#=1462951 tim=79008343311190
WAIT #4573135368: nam='db file sequential read' ela= 127 file#=100 block#=2513245 blocks=1 obj#=1462951 tim=79008343311339
WAIT #4573135368: nam='db file sequential read' ela= 125 file#=100 block#=2513245 blocks=1 obj#=1462951 tim=79008343311490
WAIT #4573135368: nam='db file sequential read' ela= 134 file#=100 block#=2513245 blocks=1 obj#=1462951 tim=79008343311647
WAIT #4573135368: nam='db file sequential read' ela= 128 file#=100 block#=2513245 blocks=1 obj#=1462951 tim=79008343311797
WAIT #4573135368: nam='db file sequential read' ela= 124 file#=100 block#=2513245 blocks=1 obj#=1462951 tim=79008343311947

WAIT #4573135368: nam='db file sequential read' ela= 10592 file#=100 block#=2513309 blocks=1 obj#=1462951 tim=79008343322564
WAIT #4573135368: nam='db file sequential read' ela= 142 file#=100 block#=2513309 blocks=1 obj#=1462951 tim=79008343322740
WAIT #4573135368: nam='db file sequential read' ela= 126 file#=100 block#=2513309 blocks=1 obj#=1462951 tim=79008343322889

There are a couple of interesting details in this trace file.

First we note (as the OP said) there are very few direct path reads – but direct path reads can be asynchronous with several running concurrently, which means that we may report one direct path read while the data returned from others records no time. (You’ll have to take my word for the sparseness of direct path reads – there were 5 reading a total of 58 blocks from the object, compared to 50,000 db file sequential reads)

Then you can see that although each block that was subject to “db file sequential read” is reported 10 times, the first read is much slower than the subsequent ones – a fairly good indication that the later reads are coming from a cache somewhere. (The 50,00 reads consisted of roughly 5,300 blocks being read 10 times, 1,400 blocks being read 9 times, 460 blocks being read 8 times, and a few blocks being read 7 or fewer times.)

You might also notice that the “coincidental” jump of 64 blocks between the sets of 10 reads – this appears fairly frequently, and it’s the type of pattern you might expect to see when a serial process is allocating blocks for use in a clean ASSM tablespace after the extent sizes have become fairly large (possibly the 64MB size that eventually appears with system managed extent sizes). There’s a “pseudo-random” choice of block within extent dicated by the process id, that spreads the work done by a single process steadily through the extent. Having filled 2513181, 2513245, 2513309 and so on for 16 steps the trace file comes back to 2513182, 2513246, 2513309 and so on.

It’s interesting (and time-consuming) to check the patterns but what we really need next, and don’t have, to check the theory is the set of 13 blocks dictated by the first direct path read:

WAIT #4573135368: nam='direct path read' ela= 8991 file number=100 first dba=947580 block cnt=13 obj#=1462951 tim=79008343293041

It’s likely that somewhere in the 13 blocks in the range 947580 onwards we would find the 10 row head pieces pointing to block 2513181; then the 10 row head pieces pointing to block 2513245, and so on – and I’d hope that we might see a pattern of many consecutive (or near-consecutive) rows in each originating block pointing to the same “next block”. In fact, with a few blocks in the early range, we might even get some idea of how the application was loading and updating data and be able to make some suggestions for changing the strategy to avoid row chaining.

Footnote

The OP also had a follow-up question which was: “One question for the block dump is why there is no hrid in it since the row pieces are the second row pieces and the flag bit is ‘—–L–‘?”  It would be nice to see this, of course – then we wouldn’t need to see the 947580-947592 range to see what had been happening to the data – but that’s not the way Oracle works, as I’ve pointed out above; but since the answer was in another posting of mine I simply emailed the relevant URL to the OP.


Can you restore from a full online backup ?

The question is not HOW TO DO IT but WHETHER YOU CAN DO IT !

A typical backup script would contains something like BACKUP DATABASE PLUS ARCHIVELOG:


backup database format 
  '/u99/backup/DB01/20150518/full_0_%d_s%s_p%p' 
plus archivelog format 
  '/u99/backup/DB01/20150518/arc_%d_s%s_p%p';

Starting backup at 2015-05-18_18:27:55
current log archived
input archived log thread=1 sequence=469
...
piece handle=
  /u99/backup/DB01/20150518/arc_DB01_s86_p1
Finished backup at 2015-05-18_18:27:58

Starting backup at 2015-05-18_18:27:58
input datafile file number=00002 name=
  /u02/oradata/DB01/undots01.dbf
...
including current control file in backup set
including current SPFILE in backup set
piece handle=
  /u99/backup/DB01/20150518/full_0_DB01_s88_p1
Finished backup at 2015-05-18_18:28:16

Starting backup at 2015-05-18_18:28:16
current log archived
input archived log thread=1 sequence=20 
piece handle=
  /u99/backup/DB01/20150518/arc_DB01_s89_p1 
Finished backup at 2015-05-18_18:28:17

This sounds pretty safe, but what happened if you keep this full backup for ever ? do you have all what you need in it to restore ?

It depends. Chance exists that you can restore. To annoy the paranoiacs, here is a counter example.

  1. you start your full backup at 6pm.
    backuping sequence 21,22,23,24
    backup datafiles…

  2. at 7 pm one cronjob issue backup archivelog all delete input;
    backuping and deleting sequence 21,22,23,24,25,26,27,28,29,30

  3. at 8pm your backup is about to finish
    backuping sequence 31

Well, where is my sequence 27 ?

Let’s try


rm /tmp/arch_DB01*
startup force mount;
crosscheck backup;restore database;

Starting restore at 2015-05-18_18:47:45
channel ORA_DISK_1: restore complete, elapsed time: 00:02:05
Finished restore at 2015-05-18_18:49:51

Ok, the restore was fine. Now what?


RMAN> recover database;

Starting recover at 2015-05-18_18:50:35
using channel ORA_DISK_1

starting media recovery

RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03002: failure of recover command at 05/18/2015 18:50:36
RMAN-06053: unable to perform media recovery because of missing log
RMAN-06025: no backup of archived log for thread 1 with sequence 30 
RMAN-06025: no backup of archived log for thread 1 with sequence 29 
RMAN-06025: no backup of archived log for thread 1 with sequence 27 

RMAN> alter database open;

RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03002: failure of alter db command at 05/18/2015 18:51:29
ORA-01113: file 1 needs media recovery
ORA-01110: data file 1: '/u02/oradata/TINF30/system01.dbf'

You have lost your database. Even if you did a full online backup plus archivelog, it did not contain all the archivelogs and RMAN did not tell you.

There is more than one way to reduce this annoyance :

1) don’t backup archivelogs during full backup
2) don’t delete archivelog backups done during a full backup
3) report any archivelog backups that run during a full. Either by looking in the RMAN dictionary or in your house logfiles
4) do offline backup for long term archives
5) don’t trust RMAN

And as well :
Test your backups :)

SQL Plan Baseline Manual Evolution

I’ve never really spent time on evolution because most of the time I use baselines for emergency sql plan management and not with the added value of controlled evolution with which the feature was conceived.

But some observations on sql plan baseline evolution originating from the questions:

  • What does evolution actually do?
  • What information does it use?
  • What happens with DML?

Starting point – one baselined plan

1. FTS plan in memory from SQL which should do FTS and put in a baseline

drop table t1;
drop table t2;

create table t1 
(col1  number 
,col2  varchar2(50) 
,flag  varchar2(2));
 
insert into t1 
select rownum 
,      lpad('X',50,'X') 
,      case when rownum = 1 
            then 'Y1'
            when rownum = 2 
            then 'Y2' 
            when mod(rownum,2) = 0
            then 'N1'
            else 'N2' 
       end 
from   dual 
connect by rownum <= 100000; 

exec dbms_stats.gather_table_stats(USER,'T1',method_opt=>'FOR COLUMNS flag SIZE 5',no_invalidate=>FALSE); 
 
create index i1 on t1 (flag);

var n varchar2(2) 
exec :n := 'N1';
select /*+ domtest */ count(*), max(col2) from t1 where flag = :n;
select * from table(dbms_xplan.display_cursor);

declare
  l_op pls_integer;
begin
  l_op :=
  dbms_spm.load_plans_from_cursor_cache('45sygvgu8ccnz');
end;
/

select to_char(signature), sql_handle, sql_text, origin, last_verified, enabled, accepted from dba_sql_plan_baselines;

TO_CHAR(SIGNATURE)  SQL_HANDLE           SQL_TEXT                                                          ORIGIN       LAST_VERIFIED ENABLED ACCEPTED
------------------- -------------------- ----------------------------------------------------------------- ------------ ------------- ------- --------
8384366354684364262 SQL_745b40c6fdb2c5e6 select /*+ domtest */ count(*), max(col2) from t1 where flag = :n MANUAL-LOAD                YES     YES      

We have a full table scan baselined.

Step 2 – an alternative plan

Next, let’s execute a SQL statement which would rather do an index scan for a different set of binds.

When there is a baselined plan, then it does this automatically at hard parse time.

If a lower cost plan is generated then store it for future evaluation / evolution.

We need to flush or invalidate the existing cursor to get that hard parse though.

Then we get an AUTO_CAPTURE plan in DBA_SQL_PLAN_BASELINES, ACCEPTED = NO

comment on table t1 is 'flushme';
var n varchar2(2) 
exec :n := 'Y1';
select /*+ domtest */ count(*), max(col2) from t1 where flag = :n;
select * from table(dbms_xplan.display_cursor);

select to_char(signature), sql_handle, sql_text, origin, last_verified, enabled, accepted from dba_sql_plan_baselines;

TO_CHAR(SIGNATURE)  SQL_HANDLE           SQL_TEXT                                                          ORIGIN       LAST_VERIFIED ENABLED ACCEPTED
------------------- -------------------- ----------------------------------------------------------------- ------------ ------------- ------- --------
8384366354684364262 SQL_745b40c6fdb2c5e6 select /*+ domtest */ count(*), max(col2) from t1 where flag = :n MANUAL-LOAD                YES     YES      
8384366354684364262 SQL_745b40c6fdb2c5e6 select /*+ domtest */ count(*), max(col2) from t1 where flag = :n AUTO-CAPTURE               YES     NO   

Step 3 – Manual Evolution

Now let’s do an evolution.
And I’m going to set MODULE so we can track some sql.
(Perhaps we could/should do a sql trace but, having done it, it doesn’t really tell us much more in this case).

exec dbms_application_info.set_module('DOMTEST','SPM');

set serveroutput on
set long 10000
DECLARE
    r CLOB;
BEGIN
    r := 
    dbms_spm.evolve_sql_plan_baseline
    (sql_handle => 'SQL_745b40c6fdb2c5e6',verify=>'YES',commit=>'NO');
    dbms_output.put_line(r);
END;
/

Why would you do VERIFY => ‘NO’?

Only use case really is if you’ve already evaluated the plan yourself and want to just get it accepted.

The combination of VERIFY=> NO and COMMIT=> NO does nothing.

Our report looks like this:

------------------------------------------------------------------------------
                        Evolve SQL Plan Baseline Report
-------------------------------------------------------------------------------

Inputs:
-------
  SQL_HANDLE = SQL_745b40c6fdb2c5e6
  PLAN_NAME  = 
  TIME_LIMIT = DBMS_SPM.AUTO_LIMIT
  VERIFY     = YES
  COMMIT     = NO

Plan: SQL_PLAN_78qu0svyv5jg68576eb1f
------------------------------------
  Plan was verified: Time used .1 seconds.
  Plan passed performance criterion: 314.79 times better than baseline plan.

                            Baseline Plan      Test Plan       Stats Ratio
                            -------------      ---------       -----------
  Execution Status:              COMPLETE       COMPLETE
  Rows Processed:                       1              1
  Elapsed Time(ms):                 3.708           .047             78.89
  CPU Time(ms):                     3.777              0
  Buffer Gets:                        944              3            314.67
  Physical Read Requests:               0              0
  Physical Write Requests:              0              0
  Physical Read Bytes:                  0              0
  Physical Write Bytes:                 0              0
  Executions:                           1              1

-------------------------------------------------------------------------------
                                 Report Summary
-------------------------------------------------------------------------------
Number of plans verified: 1
Number of plans accepted: 0

I’ve also run this on 12.1.0.2 and there doesn’t seem to be a massive difference in behaviour although there are a few extra columns and stats in the output.
(including the two plans which aren’t in the output of 11g because they’re not stored although they could be derived from the analysis sql).

What? Where? How?

What has been run behind the scenes to do this?

What information has been used to do the evaluation?

select * from v$sql where module = 'DOMTEST' order by first_load_time;

Statements of interest:

/* SQL Analyze(686,0) */ select /*+ domtest */ count(*), max(col2) from t1 where flag = :n

/* SQL Analyze(686,0) */ select /*+ domtest */ count(*), max(col2) from t1 where flag = :n

SELECT obj_type, plan_id, comp_data FROM sqlobj$data WHERE signature = :1 AND category = :2;

SELECT st.sql_text, sod.comp_data, sox.optimizer_env, sox.bind_data, sox.parsing_schema_name, sox.creator
FROM   sql$text st, sqlobj$data sod, sqlobj$auxdata sox
WHERE  sod.signature = st.signature 
AND    sod.signature = :1 
AND    sod.category  = :2 
AND    sod.obj_type  = :3 
AND    sod.plan_id   = :4 
AND    sod.signature = sox.signature 
AND    sod.category  = sox.category
AND    sod.obj_type  = sox.obj_type
AND    sod.plan_id   = sox.plan_id;

What was run to evaluate the performance of the relative plans?

See the first two /* SQL Analyze */ statements.

We can look more closely at v$sql for these:

select s.sql_text, s.child_number, s.plan_hash_value phv
,      (select extractvalue(xmltype(other_xml),'other_xml/info[@type="plan_hash_2"]')
        from   v$sql_plan p
        where  p.sql_id          = s.sql_id
        and    p.plan_hash_value = s.plan_hash_value
        and    p.other_xml is not null) plan_hash_2
, s.executions, s.elapsed_time/1000/s.executions elapsed_ms, s.cpu_time/1000/s.executions cpu_ms, s.buffer_gets/s.executions, b.value_string
from   v$sql s, table(dbms_sqltune.extract_binds(s.bind_data)) b
where  s.module = 'DOMTEST' 
and    s.sql_id = '8rnh80j2b09kt';

SQL_TEXT                                                                                    CHILD_NUMBER PHV        PLAN_HASH_2 EXECUTIONS ELAPSED_MS CPU_MS S.BUFFER_GETS/S.EXECUTIONS VALUE_STRING
------------------------------------------------------------------------------------------- ------------ ---------- ----------- ---------- ---------- ------ -------------------------- ------------
/* SQL Analyze(686,0) */ select /*+ domtest */ count(*), max(col2) from t1 where flag = :n  0            1634389831 1634389831  10         4.0923     4.0994 944                        Y1
/* SQL Analyze(686,0) */ select /*+ domtest */ count(*), max(col2) from t1 where flag = :n  1            2239163167 2239163167  10         1.1728     0.1999 3                          Y1

We can see where some of the stats from the report have come from – they look to be an average over a number of executions in this example. The timings aren’t an exact match.

Note that in this case PHV = PHV2, but PHV2 is the plan_id in the underlying baselined tables as I have discussed previously elsewhere.

Where did the SQL statement come from?

Where did the bind data come from?

That’s the last statement in my “statements of interest” above.

SELECT st.sql_text, sod.comp_data, sox.optimizer_env, sox.bind_data, sox.parsing_schema_name, sox.creator
FROM   sql$text st, sqlobj$data sod, sqlobj$auxdata sox
WHERE  sod.signature = st.signature 
AND    sod.signature = :1 
AND    sod.category  = :2 
AND    sod.obj_type  = :3 
AND    sod.plan_id   = :4 
AND    sod.signature = sox.signature 
AND    sod.category  = sox.category
AND    sod.obj_type  = sox.obj_type
AND    sod.plan_id   = sox.plan_id;

The basic sql plan baseline mechanism is by signature (V$SQL.EXACT_MATCHING_SIGNATURE) but SQL$TEXT stores the actual sql text.

How else could be evaluate the baselined plans during evolution because the sql might not be in memory or in AWR!

The statement to execure bind data is from the hard parse which generated the lower cost of plan of interest and is stored in SYS.SQLOBJ$AUXDATA.BIND_DATA.

Makes sense, right?

What happens with DML?

There’s nothing I can find which spells it out in black and white but only the SELECT of the DML, be it INSERT SELECT, UPDATE or MERGE.

Even a sql trace doesn’t make this crystal clear.

But using a similar method to above:

create table t2
(cnt   number 
,col2  varchar2(50) 
,flag  varchar2(2));

var n varchar2(2) 
exec :n := 'N1';
insert into t2
select /*+ domtest */ count(*), max(col2), :n from t1 where flag = :n;
select * from table(dbms_xplan.display_cursor);

select sql_id, child_number, is_bind_aware, is_bind_sensitive, is_shareable, to_char(exact_matching_signature) sig
,      executions, plan_hash_value
from   v$sql 
where  sql_id = '08ravsws1s6bn';

declare
  l_op pls_integer;
begin
  l_op :=
  dbms_spm.load_plans_from_cursor_cache('08ravsws1s6bn');
end;
/

select to_char(signature), sql_handle, sql_text, origin, last_verified, enabled, accepted from dba_sql_plan_baselines;

comment on table t2 is 'flushme';

var n varchar2(2) 
exec :n := 'Y1';
insert into t2
select /*+ domtest */ count(*), max(col2), :n from t1 where flag = :n;
select * from table(dbms_xplan.display_cursor);

select to_char(signature), sql_handle, sql_text, origin, last_verified, enabled, accepted from dba_sql_plan_baselines;

exec dbms_application_info.set_module('DOMTEST2','SPM');
select * from v$sql where module = 'DOMTEST2' order by first_load_time;

set serveroutput on
set long 10000
DECLARE
    r CLOB;
BEGIN
    r := 
    dbms_spm.evolve_sql_plan_baseline
    (sql_handle => 'SQL_4ed45b79c88f3392',verify=>'YES',commit=>'NO');
    dbms_output.put_line(r);
END;
/

We get a similar report and similar evaluation sql.
We can see from ROWS_PROCESSED that no rows were actually inserted.

select s.sql_text, s.child_number, s.plan_hash_value phv
,      (select extractvalue(xmltype(other_xml),'other_xml/info[@type="plan_hash_2"]')
        from   v$sql_plan p
        where  p.sql_id          = s.sql_id
        and    p.plan_hash_value = s.plan_hash_value
        and    p.other_xml is not null) plan_hash_2
, s.rows_processed,s.executions, s.elapsed_time/1000/s.executions elapsed_ms, s.cpu_time/1000/s.executions cpu_ms, s.buffer_gets/s.executions
from   v$sql s
where  s.module = 'DOMTEST2' 
and    s.sql_id = 'b04dpwja6smx7';

SQL_TEXT                                                                                                       CHILD_NUMBER PHV        PLAN_HASH_2 ROWS_PROCESSED EXECUTIONS ELAPSED_MS CPU_MS S.BUFFER_GETS/S.EXECUTIONS
-------------------------------------------------------------------------------------------                    ------------ ---------- ----------- -------------- ---------- ---------- ------ --------------------------
/* SQL Analyze(771,0) */ insert into t2 select /*+ domtest */ count(*), max(col2), :n from t1 where flag = :n  0            1634389831 1634389831  0              10         4.1668     4.1993 944                       
/* SQL Analyze(771,0) */ insert into t2 select /*+ domtest */ count(*), max(col2), :n from t1 where flag = :n  1            2239163167 2239163167  0              10         0.1512     0.1  3                         

I also tried with the addition of a PK just to double check that it couldn’t be inserted. Nothing to see.

Finally…

One note about evolution behaviour and the adjustment of the threshold for plan verification, i.e. the bit which results in this:

Plan was verified: Time used .1 seconds.
Plan passed performance criterion: 314.79 times better than baseline plan.

You can use parameter _plan_verify_improvement_margin, e.g.

ALTER SYSTEM SET “_plan_verify_improvement_margin”=120;

Unfortunately valid range for parameter is between 100 and 10000 so not high enough for me to show it’s influence on the results above (> 300x improvment).


Roll up! Roll up! This week’s events!

Here’s a quick reminder of a couple of events happening this week.

On Tuesday evening it’s Oracle Midlands Event #9 in Birmingham. First up is Joel Goodman, who is practically a walking Oracle Encyclopaedia, speaking about “Oracle Distributed Transactions”. Next up is Richard Harrison, a regular Oracle Midlands attendee and returning speaker, this time presenting about “Data Pump Tips & Tricks”. It’s going to be a good evening, so please come out and show your support! It’s sponsored by Red Stack Technology, so it’s free!

On Wednesday it is the UKOUG Systems Event. I’m in the first slot, so it’s going to be an extremely early train ride for me. There is packed agenda, so I’m sure there is something for everyone involved in the systems side of things!

Hopefully I’ll get to see some of you folks at these events!

Cheers

Tim…


Roll up! Roll up! This week’s events! was first posted on May 18, 2015 at 8:39 am.
©2012 "The ORACLE-BASE Blog". Use of this feed is for personal non-commercial use only. If you are not reading this article in your feed reader, then the site is guilty of copyright infringement.

Writing Tips : Should I go back and rewrite/revise/remove old posts?

writingThe answer to this is very much dependent on the content and context of the material. If you have said something really bad in a legal sense, then you should definitely consider deleting it, or deal with the consequences. Assuming we are not talking about those naked pictures of you at a stag/hen party, what do I think?

I do rewrite old articles if I’m sufficiently motivated by a drastic change in my understanding of the subject. The articles on my website are more fact-based, so if there is incorrect information, it should be revised. I tend to write version-specific articles, so I don’t usually add features to old articles, but write a new features article, then link the articles in a chain. That prevents an article becoming massive over time, while still clearly showing the progression of the feature set for those that care about more than the basics.

My blog posts are more opinion than fact, so I am less inclined to revise them. If my opinion alters, I prefer to write a new post discussing my current opinion and why I changed my mind, with forward and back links between the posts. I think this is much more informative for readers, as they can see how you’ve developed over time. There is little value in trying to rewrite history. :)

I remember having a conversation with Chris Muir about this a long time ago and he was very much of the opinion that a blog post is a point in time snapshot of your opinion and thoughts, so it shouldn’t be retrospectively changed. His words have obviously influenced my opinion in this matter. :)

Ultimately, the Way Back Machine will reveal that terrible secret (you thought Buffer Cache Hit Ratios were a great way to tune a database) and you will be exposed. :)

Cheers

Tim…


Writing Tips : Should I go back and rewrite/revise/remove old posts? was first posted on May 18, 2015 at 6:42 am.
©2012 "The ORACLE-BASE Blog". Use of this feed is for personal non-commercial use only. If you are not reading this article in your feed reader, then the site is guilty of copyright infringement.