November 30, 2011 (Back to the Previous Post in the Series) Today marks the second anniversary of this blog. With just 372 articles posted in the last two years, the rate at which new articles are posted has decreased rather dramatically from the 1+ article per day average that was established shortly after the launch [...]
I’ve just added Toon Koppelaars to my blog roll – and this is just a temporary note to highlight the addition.
The blog is “Triggers considered harmful, considered harmful” (and the near-quine is deliberate). It is a series of articles presenting and expanding on the presentations that Toon has given in the past at events like the Hotsos Symposium; and, eventually, will explain how we can implement all the necessary levels of constraints that allow a relational database implemented in Oracle to guarantee correct data.
Toon (along with Lex De Haan (RIP)) wrote Applied Mathematics for Database Professionals which is one of the very few books I’ve reviewed at Amazon (UK). He’s a very good writer with some very important ideas that he explains very well. If you need an explanation about the “necessary levels of constraints”, I list them all in my review.
Here’s my personal agenda for the UKOUG annual conference. I know it probably looks a bit busy – but even then there are some other sessions that I’ll be sad to miss.
I’m not sure I’ll be able to make it to all the things I’ve listed, though, however hard I try:
|Sunday||12:15 – 13:15||Redo (I’ll be presenting)|
|13:25 – 14:10||Multiblock reads (Frits Hoogland)|
|14:25 – 15:20||Optimizer Statistics (Connor McDonald)|
|15:50 – 16:15||Stats and Histograms (Wolfgang Breitling)|
|16:40 – 17:30||Performance and HA Panel Session|
|10:00 – 10:45||SQL Tuning (Kyle Hailey)|
|11:05 – 12:05||Partitioning 101 (Connor McDonald)|
|12:15 – 13:15||Real Application Testing (Mariusz Piorkowski)|
|14:30 – 15:15||Automatic Diagnostic Repository (John Hallas)|
|15:25 – 16:10||Emerging Trends in RAC (Julian Dyke)|
|16:35 – 17:35||Database I/O Performance (Alex Gorbachev)|
|17:45 – 18:30||SQL Plan Management (Doug Burns)|
|9:00 – 10:00||Security Roundtable (Pete Finnigan chairing)|
|10:10 – 10:55||Analytic Functions (Alex Nuitjen)|
|11:15 – 12:15||Trouble-shooting RAC (Julian Dyke)|
|12:25 – 13:25||Trouble-shooting (Tanel Poder)|
|14:40 – 15:25||Does RAT = performance testing (Stephen Readman)|
|15:35 – 16:20||It’s all in the Index (Michael Salt)|
|16:40 – 17:40||Beating the Optimizer (I’ll be presenting)|
|17:50 – 18:35||11g Query Optimizer (Christian Antognini)|
|9:00 – 10:00||Redo (I’ll be presenting)|
|10:10 – 11:10||All about indexes (Mark Bobak)|
|11:20 – 12:20||Latch Internals 2011 (Andrey Nikolaev)|
|12:30 – 13:30||Optimizer Roundtable (I’ll be chairing)|
|14:25 – 15:10||Index Organized Tables (Martin Widlake)|
|15:20 – 16:05||Simulating Workloads (James Morle)|
|16:15 – 17:00||What Shape is your data ? (Niall Litchfield)|
Update 1st Dec 2011: James Morle has arranged an “Oak Talks” event. This will take advantage of the “Unconference” area and will feature Oak Table members doing a 10 minute presentation (without slides, but possibly with a flipchart) during the lunch breaks. I’ve volunteered to take a Monday slot to talk about “Test Data”.
Question: What happens when 12c Cloud Control runs out of disk space?
Answer: It doesn’t work very well.
I have a 12c Cloud Control installation on an Oracle Linux 6.1 VM and I was pushing an agent to both nodes of an 184.108.40.206 RAC, also on OL6.1 VMs. The agent installation seemed to go fine and the agent upload to CC was fine, but when I tried to discover the database on the nodes it went a bit loopy. After a little messing about I noticed my disk was maxed out on the 12c CC server. Bummer!
So I turned off the VM, added another virtual disk, turned it back on and added the new disk to the existing volume. Bob’s your uncle!
Once Cloud Control was running the database discovery worked fine and it was full steam ahead.
Before I realized my mistake I was starting to think this was OL6.1 related, but as it stands I’ve still seen no ill effects of running Cloud Control or RAC on Oracle Linux 6.1.
Recently I was involved in a project where I had to trace the database calls of an application based on Oracle Portal 10.1.4. The basic requirements were the following:
Given that Oracle Portal uses a pool of connections and that for each HTTP call it can use several database sessions, statically enable SQL trace for specific sessions was not an option.
Knowing nothing about Oracle Portal I started RTFM and, gladly, I discovered that there is a simple way to inject a piece of code before and after a requested procedure is called. This is done by setting, via the administration GUI, the parameters PlsqlBeforeProcedure and PlsqlAfterProcedure.
Since Oracle Portal provides a function (WWCTX_API.GET_USER) to get the current user, I decided to create the following procedures to set/clear the client identifier before/after every call. Note that I added the call to SUBSTR and the exception handler to make sure that the procedures do not raise exceptions (hey, it’s a production system and I do not want to impact everyone!).
CREATE PROCEDURE tvd_set_client_identifier AS BEGIN dbms_session.set_identifier(substr(portal.wwctx_api.get_user,1,64)); EXCEPTION WHEN others THEN NULL; END;
CREATE PROCEDURE tvd_clear_client_identifier AS BEGIN dbms_session.clear_identifier; EXCEPTION WHEN others THEN NULL; END;
To “enable” these procedures we did the following:
With this configuration in place enabling SQL trace for a single user was easily done by calling the DBMS_MONITOR.CLIENT_ID_TRACE_ENABLE procedure by specifying the user to be traced as value for the CLIENT_ID parameter.
With only a few days to go before the UKOUG conference this year I’m preparing my presentations. I know pretty much what I want to say and, for the IOT talk at least, it is not as if I do not have enough material already prepared – some of which has been on the blog posts and some of which has not. (though it did strike me that I could just fire up the blog and walk through the thread, taking questions).
My big problem is not what to say – it is what not to say.
I’ve always had this problem when I want to impart knowledge, I have this desire to grab the audience by the throat, take what I know about the subject and somehow just cram the information into the heads of the people in front of me. All of it. I want them to know everything about it that I know, the core knowledge, the oddities, the gotchas, how it meshes with other topics. It’s ridiculous of course, if I’ve spent many hours (days, weeks, 20 years) acquiring experience, reading articles and learning, I can’t expect to pass that all on in a one hour presentation – especially as I like to provide proof and examples for what I say. But I think the desire to do so is part of what makes me a good presenter and tutor. I bounce around in front of the audience, lobbing information at them and constantly trying to judge if I need to backup and give more time to anything or if I can plough on, skipping the basics. Hint, if you are in the audience and I’m going too fast or garbling my topic, then I am always happy to be asked questions or told to reverse up a little. I’ve never been asked to speed up though
It gets even worse. If I am putting myself up there to talk about a topic then I don’t want to be found wanting. I want to be able to handle any question and have a slide or example up my sleeve to demonstrate it. It’s exhausting and, again, pointless. At somewhere like the UKOUG there is bound to be someone who knows something I don’t know about any topic.
For me the trick is to pare it down, to keep reminding myself that if the audience leaves with more knowledge than they came in with, that is a win. If they actually enjoyed the experience I’m even more happier. Maybe I should forget the topic and just take drinks and nibbles…
So, I’m currently doing what I always do, which is trying to force myself to remove stuff that is not directly relevant whilst still leaving a few little oddities and interesting items. Plus getting the 200 slides down to something more reasonable – like say 120
If I can get it down to one slide per minute (some of which I skip on the day as they are there for anyone downloading the talk) then I’m OK.
Of course, having done this, the day before the course I’ll do one last “final review” – and add a couple of dozen slides to just clarify a few points…
“Thicker Than Water” is book 4 in the Felix Castor series by Mike Carey.
I’m not even going to try and summarize this bad-boy. It’s just a crazy-paced page turner. We find out more about Felix’s life before he became a freelance exorcist. More about his brother, the Catholic Priest. More about the Anathemata, the excommunicated millitant arm of the Catholic Church. Juliet, the succubus, gets involved in the action again. It’s just bam, bam, bam. Love it.
I missed my fifth blogging anniversary by a month – my first post was dated 24th Oct 2006 on the topic of the parameter optimizer_index_cost_adj.
Since then I’ve posted about 670 articles (and deleted a few temporary ones) and drafted another 110; I’ve acquired 750 followers; and the blog has inspired a little over 6,000 comments. It’s amazing how time passes and the numbers accumulate.
To celebrate the event I’ve created a new category (see top right) of “Site History” so that I could label that first post and the various posts I’ve made about viewing figures and popular posts.
Recent Charles Hooper’s post on the topic of Recycle bin (which is, BTW, documented behavior) reminded me of an issue with that functionality I’ve seen recently. The problem was a single-row INSERT INTO table VALUES () statement was hanging for more than an hour burning CPU.
Here is how SQL Monitoring report for the statement looked like:
SQL Monitoring Report SQL Text ------------------------------ INSERT INTO TAB(X1,X2,X3,X4) VALUES (:1,:2,:3,:4) Global Information ------------------------------ Status : EXECUTING Instance ID : 1 Session : USER1 (101:34227) SQL ID : 55wauznayyk1r SQL Execution ID : 16777303 Execution Started : 11/23/2011 13:11:41 First Refresh Time : 11/23/2011 13:11:49 Last Refresh Time : 11/23/2011 14:26:50 Duration : 4511s Module/Action : JDBC Thin Client/- Service : SYS$USERS Program : JDBC Thin Client Global Stats =========================================================================================== | Elapsed | Cpu | IO | Concurrency | PL/SQL | Other | Buffer | Read | Read | | Time(s) | Time(s) | Waits(s) | Waits(s) | Time(s) | Waits(s) | Gets | Reqs | Bytes | =========================================================================================== | 4528 | 4525 | 0.71 | 0.01 | 0.01 | 2.46 | 202M | 71 | 568KB | =========================================================================================== SQL Plan Monitoring Details (Plan Hash Value=0) =============================================================================================================================== | Id | Operation | Name | Rows | Cost | Time | Start | Execs | Rows | Activity | Activity Detail | | | | | (Estim) | | Active(s) | Active | | (Actual) | (%) | (# samples) | =============================================================================================================================== | 0 | INSERT STATEMENT | | | | | | 1 | | | | | 1 | LOAD TABLE CONVENTIONAL | | | | | | 1 | | | | ===============================================================================================================================
And pstack output for Oracle process looked like this most of the time:
ffffffff7c5da730 times (64, 4a6f0, 49e2794, 10c20aba8, 10c1c04b8, 10c1ce850) + 8 000000010633d76c opiosq0 (4a, e, ffffffff7ffdc650, 20, 0, ffffffff7ffdc6c9) + 4cc 00000001035a0444 opiall0 (ffffffff7ffdc728, 1, ffffffff7ffdce10, 0, ffffffff7ffdcd28, ffffffff7ffdccd0) + 964 00000001035cf01c opikpr (65, 1c, ffffffff74167bd8, 10c000, 10c1ca000, 1648) + 21c 00000001035b86b4 opiodr (10a755, 1c, 1035cee00, 10a400, 1400, ffffffff7bc20178) + 594 0000000105143a64 rpidrus (ffffffff7ffdda78, 10c1c9ce8, 1, 0, 10a6a2, 10a400) + c4 00000001077e6260 skgmstack (ffffffff7ffddce0, 10c1c9ce8, 1051439a0, ffffffff7ffddcb8, ffffffff7ffddce0, ffffffff7ffddcb8) + 60 0000000105143fa4 rpidru (ffffffff7ffde5c8, 10a686, 10a400, 105143f00, 105000, 10a400) + a4 0000000105142cac rpiswu2 (67252c600, 0, ffffffff7ffde438, 10a6a2, 10c1ca490, 0) + 28c 000000010514b588 kprball (64, 8, 0, 2000, 105143f00, 4000) + 588 0000000105c23814 kdpurcrb (1154, 11, 0, ffffffff7ffdf308, 10a6a2, 10c1ce) + 1d4 0000000105c27a9c kdpurts (ffffffff7ffdf580, ffffffff7ffdf550, 1, ffffffff7ffdf5fc, 1a00000000, 380016) + 1a7c 0000000105c28250 kdpursp (5, 100, ffffffff7ffdf838, 1b0, 7ffffffc, 7ffffc00) + 70 00000001023c2fd4 ktsx_purge_bin (5, 80, ffffffff7ffdff7c, ffffffff7ffdff78, 5, 10c000) + 134 0000000102441ad0 ktspnr_next (ffffffff7ffe06c0, 102440e20, 10ac50558, 10ac50500, 10ac00, 10a6a2) + cb0 0000000101a0bca0 ktrsexec (ffffffff7ffe06c0, ffffffff7ffe08b0, 380000, 380025000, 380025, b) + 240 0000000102436128 ktspbmphwm (ffffffff79af7fe8, 0, 0, 4cd9980, 76, 1527801) + 468 0000000102430204 ktspmvhwm (ffffffff7ffe0ec0, 1024313cc, e, 10c1c9, ffffffff79af7fe8, 409) + 24 0000000102431448 ktsp_bump_hwm (10a400, ffffffff7ffe3fa8, 794, 10c1ca490, 1, 582) + c8 00000001024321f4 ktspgsp_main (0, 152780100000000, 380024ed8, 0, 0, 3) + 5d4 0000000103888dbc kdisnew (ffffffff7bc78860, 50c43e2, ffffffff7ffe4678, 2, ffffffff79af7fe8, 0) + 11c 000000010388bdc8 kdisnewle (ffffffff79af7fd0, 50c43e2, 2d, ffffffff7ffe4678, 0, 0) + a8 00000001038b2334 kdisle (0, 2d, 1527803, 50c43e2, 1, 2c) + 1e34 00000001037c3c54 kdiins0 (6371cfdb0, 0, 0, ffffffff7fff59a8, 0, 0) + 2bb4 000000010381a1a0 kdiinsp (6371cfdb0, ff000000000000, 0, ffffffff7fff59a8, 2, 2) + 60 0000000100c71154 kauxsin (10a400, ffffffff7bc78860, 0, 10c000, 10a6a2000, 0) + 7d4 00000001062d2764 qesltcLoadIndexList (ffffffff79ce5530, 6371cfe30, 0, 0, 0, 636f17848) + 384 00000001061d5a00 qerltcNoKdtBufferedInsRowCBK (ffffffff79ce54e8, 636f17848, 6371d0140, 10c1ca490, 500080025, 1061d5880) + 180 00000001061d10bc qerltcLoadStateMachine (1061d4, 636f17848, 10c1ca2e0, 1061d4ee0, ffffffff79ce54e8, 1) + dc 00000001061d1a38 qerltcInsertSelectRop (ffffffff7fff7f88, ffffffff7fff7ee8, ffffffff79cc0518, 10c1ca490, 104c00, 0) + d8 0000000106068284 qeruaRowProcedure (69000001, 7fff, ffffffff7fff7c18, 800000, 1061d1960, 80000) + 124 0000000106125330 qerfiFetch (642d22848, ffffffff7bc6ce58, 106068160, ffffffff7fff7c18, 7fff, 107) + 50 000000010272148c rwsfcd (642d227d0, ffffffff7bc6ce88, 106068160, ffffffff7fff7c18, 7fff, 106068160) + 6c 0000000106068620 qeruaFetch (33000002, 33008002, 106068160, ffffffff7fff7c18, 642d227d0, ffffffff79ce51b0) + 1a0 000000010272148c rwsfcd (66375c718, ffffffff79ce5458, 1061d1960, ffffffff7fff7f88, 7fff, 1061d1960) + 6c 00000001061cdfbc qerltcFetch (800000, 636f17848, 104a70c00, ffffffff79ce54e8, 10c1ca2e0, 1061d1960) + 39c 0000000104a711dc insexe (10c1df, 1061cdc20, 66, 0, 10c000, 104800) + 35c 00000001035c305c opiexe (49, 3, ffffffff7fffa26c, 0, 0, bfffffff) + 263c 0000000103e6d560 kpoal8 (5e, 1c, ffffffff7fffd728, 10c000, 10c1ca000, 1648) + 940 00000001035b86b4 opiodr (10a755, 1c, 103e6cc20, 10a400, 1400, 10c1c9000) + 594 00000001070fd3a0 ttcpip (0, 10a686d94, 10c1ca2e0, ffffffff7fffd728, ffffffff7fffc170, 10c1e0e98) + 420 000000010358c018 opitsk (10a686d94, 10c1e62e8, 10c1e0ca4, 10c1defa8, 0, 10c1c9fa0) + 5f8 000000010359d2e8 opiino (2270, 10c1e0d20, 10c000, 380000, 9b, ffffffff7ffff080) + 3e8 00000001035b86b4 opiodr (10c1e0000, 4, 10359cf00, 10c000, 1400, 10c1c9000) + 594 0000000103580c4c opidrv (3c, 4, ffffffff7ffff080, 1ea1c8, ffffffff7c742fd0, ffffffff7ffff560) + 44c 00000001046e6f3c sou2o (ffffffff7ffff058, 3c, 4, ffffffff7ffff080, 10c000, 10b800) + 5c 0000000100604430 opimai_real (0, ffffffff7ffff328, ffffffff7f73aeb8, 10b800, 1, 2) + 130 00000001046fd140 ssthrdmain (10c000, 2, 44d000, 100604300, 10c1ef000, 10c1ef) + 140 0000000100604214 main (2, ffffffff7ffff438, 0, ffffffff7ffff338, ffffffff7ffff448, ffffffff7eb00200) + 134 00000001006040bc _start (0, 0, 0, 0, 0, 0) + 17c
So looking at this process stack trace it’s possible to make a valid assumption that Oracle tried to bump High Water Mark (line 19) while executing client’s INSERT statement, then tried to free space from the recycle bin (line 14) which in turn resulted in executing a recursive statement (line 5). To find which statement is executed by the process we used errorstack at level 3 and the culprit SQL was dumped to trace in the beginning:
----- Error Stack Dump ----- ----- Current SQL Statement for this session (sql_id=b52m6vduutr8j) ----- delete from RecycleBin$ where bo=:1
This statement was executed in a recursive session by Oracle probably in a loop. Cumulative SQL runtime execution statistics showed that it has been executed ~1M times, making ~800M buffer gets. With 1024 blocks occupied by recyclebin$ and average row length of the table at 50 bytes (low estimate), it looks like 1) a bit of extra-executing 2) Oracle tries to clean up whole recycle bin, which is strange. I think SQL tracing of a such situation can give more details of how Oracle manages data that is resided in recycle bin. For me it was enough to know that issue 1) is definitely caused by the Recycle Bin functionality 2) we have an application installation code that can re-create tables many times and which most likely was catalyst to the problem.
November 28, 2011 There are a few articles that can be found on the Internet that describe the cause of indexes with names similar to BIN$ld5VAtb88PngQAB/AQF8hg==$0 and BIN$PESygWW5R0WhbOaDugxqwQ==$0 appearing in execution plans. As is likely known by readers, the Oracle Database documentation describes that these object names are associated with the recycle bin that was introduced in Oracle Database [...]