Blog Archives
Job hang with Wait Event: log file switch (private strand flush incomplete)
If only someone will give us a buck for each bug that we “(re)discoverer” in 10g (precisely 10.2.0.x). I wonder if 10g (R1 & R2) is (was) really a production level product at all. Sometimes, I feel working with 10g is very much like working with a Beta product – just an expensive one :-(.
I can only hope that Oracle will keep patching 10g R2 to at least patchset 10.2.0.8 – yeah, I know, a zero chance for that to happen. I guess we’ll have to live with tons of bugs for several years.
Today, I had to kill hanged job that was spending hours waiting for the event: log file switch (private strand flush incomplete).
Perhaps you noticed occasional “Private Strand Flush Not Complete” message in alert.log, that can be safely ignored, as described in Metalink note 372557.1 Alert Log Messages: Private Strand Flush Not Complete, this notice can for example follow after you manually switch log file.
Our scenario is different:
- application developer started job via dbms_job
- inside job execution time frame, daily RMAN incremental backup started and finished (in approx. 10 minutes). Part of the backup job is also a log switch – nothing more than a detail that I think is worth mentioning
- RMAN job completed successfully, but the other job that was running simply hanged waiting on above event for several more hours – I could not confirm that the deadlock happened at exact time when log switch that is part of RMAN daily backup job kicked in
- just for the record, everything was ok with archiver and I/O subsystem
I’m not applying that log switch that was part of RMAN job “locked” other process running the job. It’s just the fact that at the time of the hang only job submitted with dbms_job and RMAN backup were active, perhaps it’s just a coincidence and those two events are not related at all!?
Anyway, a quick search on Metalink revealed the recently filled bug that resembles our case very well:
6806770 LGWR SPINS WHEN OTHER PROCESSES ARE WAITING FOR ‘LOG FILE SWITCH’
What worries me is that bug is somehow connected with a bag of 10g so called “new features behind the scene” – one such feature is In Memory Undo (IMU) and that only workaround proposed is to disable IMU by setting _in_memory_undo = FALSE.
How unfortunate is that? I was just recently reading an excellent white paper written by Craig Shallahamer about IMU.
For now, I decided not to turn IMU off – but if the problem persist then I’m afraid we’ll have to turn In Memory Undo off. (It’s becoming some kind of a folklore – get to know the cool new features, then turn them off and wait until they’re debugged:-).
Performance degradation of INSERT … SELECT with UNION ALL
Recently we migrated one of our production database from x86 (Oracle 10.2.0.2) to x64 (Oracle 10.2.0.3 + Patch 12) following scenario described in this thread. Only after a couple of days developer reported performance degradation in execution of the batch report that previously run smoothly. Report spent enormous amount of time executing INSERT …. SELECT statement with several UNION ALL statements inside (btw. SELECT statement(s) block itself is not trivial, it has close to 1000 lines of code, several inline views, but at the end, it returns just 70 rows). When we removed INSERT and executed just the SELECT, everything run fine (under 20s). The moment we placed INSERT in front of the SELECT statement the response time rocket to the sky.
In SELECT_PLAN.TXT you can see execution plan with standalone SELECT (select count(*) from (select …))and cost 41.713, and in INSERT_PLAN.TXT execution plan of insert statement with the same select statement and cost 14.000.000.
Object statistics were up to date.
To make long story short, when executing INSERT version of the statement, Oracle CBO pushed predicates to inline views. When we hinted the select statement with /*+ NO_PUSH_PRED(v) */ cost dropped from 14M to around 50K.
We found several interesting Metalink notes:
Note: 418383.1 "Wrong Results Using _OPTIMIZER_PUSH_PRED_COST_BASED=TRUE" Note: 400768.1 "Join Between Dba_segments And Dba_tables Is Extremely Slow After 10g Upgrade" Bug 5199213 - "RESULT OF A QUERY IS NOT RETURNED WHEN ACCESSING VIEW WITH UNION ALL" Bug 6155146 - Wrong results from query rewrite with pushed predicate Bug 6041535 - Wrong results when predicate pushed into union-all branches
Our case is perhaps best described in this Metalink note:
Bug 5620485 - Non code based push predicate into UNION view can get poor plan
We disabled CBO option due to the fact that we run several reports of the same “style” and don’t want to hint every one of them:
alter system set "_optimizer_push_pred_cost_based"=FALSE scope=both;
After this tweak report run under 20s.
You can check the value with SQL*Plus show parameter or the query:
select a.ksppinm name, b.ksppstvl value, a.ksppdesc description
from sys.x$ksppi a, sys.x$ksppcv b
where a.indx = b.indx
and a.ksppinm='_optimizer_push_pred_cost_based';
We’ll wait for the patchset 10.2.0.4 and see if the bug is fixed, before turning on this optimization.
INSERT_PLAN.TXT
#################################
EXPLAIN PLAN FOR INSERT...SELECT
#################################
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
Plan hash value: 1778844142
----------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes |TempSpc| Cost (%CPU)| Time | Pstart| Pstop |
----------------------------------------------------------------------------------------------------
| 0 | INSERT STATEMENT | | 2104K| 202M| | 14M (76)| 17:12:59 | | |
| 1 | UNION-ALL | | | | | | | | |
| 2 | HASH GROUP BY | | 526K| 39M| 93M| 3718K (1)| 04:18:06 | | |
| 3 | NESTED LOOPS OUTER | | 526K| 39M| | 3710K (1)| 04:17:32 | | |
|* 4 | HASH JOIN | | 526K| 35M| | 2564 (8)| 00:00:11 | | |
| 5 | TABLE ACCESS FULL | D_SKD | 1758 | 12306 | | 30 (4)| 00:00:01 | | |
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
|* 6 | HASH JOIN | | 528K| 31M| | 2524 (7)| 00:00:11 | | |
| 7 | MERGE JOIN CARTESIAN | | 50 | 600 | | 14 (0)| 00:00:01 | | |
|* 8 | TABLE ACCESS FULL | D_OZNAKE_OBD | 5 | 30 | | 4 (0)| 00:00:01 | |
| 9 | BUFFER SORT | | 10 | 60 | | 10 (0)| 00:00:01 | | |
| 10 | INLIST ITERATOR | | | | | | | | |
| 11 | TABLE ACCESS BY INDEX ROWID| D_STAT_KONTINGENTI | 10 | 60 | | 2 (0)| 00:00:01
|* 12 | INDEX RANGE SCAN | DSG_SPODK_IDX | 10 | | | 1 (0)| 00:00:01 | | |
| 13 | PARTITION RANGE SINGLE | | 528K| 25M| | 2500 (7)| 00:00:11 | 89 |
|* 14 | TABLE ACCESS FULL | F_POSTAVKE | 528K| 25M| | 2500 (7)| 00:00:11 | 8
| 15 | VIEW PUSHED PREDICATE | | 1 | 8 | | 7 (0)| 00:00:01 | | |
| 16 | NESTED LOOPS | | 1 | 40 | | 7 (0)| 00:00:01 | | |
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
| 17 | NESTED LOOPS | | 1 | 28 | | 3 (0)| 00:00:01 | | |
| 18 | TABLE ACCESS BY INDEX ROWID | D_TARIFA | 1 | 18 | | 2 (0)| 00:00:01
|* 19 | INDEX UNIQUE SCAN | DTA_PK | 1 | | | 1 (0)| 00:00:01 | | |
| 20 | TABLE ACCESS BY INDEX ROWID | D_STAT_KONTINGENTI | 1 | 10 | | 1 (0)| 0
|* 21 | INDEX UNIQUE SCAN | DSG_PK | 1 | | | 0 (0)| 00:00:01 | | |
|* 22 | TABLE ACCESS FULL | ZAK_ZAKRIVANJE | 1 | 12 | | 4 (0)| 00:00:01 |
| 23 | HASH GROUP BY | | 526K| 53M| 134M| 3721K (1)| 04:18:17 | | |
| 24 | NESTED LOOPS OUTER | | 526K| 53M| | 3710K (1)| 04:17:32 | | |
|* 25 | HASH JOIN | | 526K| 35M| | 2551 (8)| 00:00:11 | | |
| 26 | VIEW | index$_join$_012 | 1758 | 10548 | | 16 (7)| 00:00:01 | | |
|* 27 | HASH JOIN | | | | | | | | |
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
| 28 | INDEX FAST FULL SCAN | DSKD_ID1_IDX | 1758 | 10548 | | 6 (0)| 00:00:01 |
| 29 | INDEX FAST FULL SCAN | DSD_PK | 1758 | 10548 | | 9 (0)| 00:00:01 | |
|* 30 | HASH JOIN | | 528K| 32M| | 2524 (7)| 00:00:11 | | |
| 31 | MERGE JOIN CARTESIAN | | 50 | 700 | | 14 (0)| 00:00:01 | | |
|* 32 | TABLE ACCESS FULL | D_OZNAKE_OBD | 5 | 30 | | 4 (0)| 00:00:01 | |
| 33 | BUFFER SORT | | 10 | 80 | | 10 (0)| 00:00:01 | | |
| 34 | INLIST ITERATOR | | | | | | | | |
| 35 | TABLE ACCESS BY INDEX ROWID| D_STAT_KONTINGENTI | 10 | 80 | | 2 (0)| 00:00:01
|* 36 | INDEX RANGE SCAN | DSG_SPODK_IDX | 10 | | | 1 (0)| 00:00:01 | | |
| 37 | PARTITION RANGE SINGLE | | 528K| 25M| | 2500 (7)| 00:00:11 | 89 |
|* 38 | TABLE ACCESS FULL | F_POSTAVKE | 528K| 25M| | 2500 (7)| 00:00:11 | 8
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
| 39 | VIEW PUSHED PREDICATE | | 1 | 35 | | 7 (0)| 00:00:01 | | |
| 40 | NESTED LOOPS | | 1 | 53 | | 7 (0)| 00:00:01 | | |
| 41 | NESTED LOOPS | | 1 | 28 | | 3 (0)| 00:00:01 | | |
| 42 | TABLE ACCESS BY INDEX ROWID | D_TARIFA | 1 | 18 | | 2 (0)| 00:00:01
|* 43 | INDEX UNIQUE SCAN | DTA_PK | 1 | | | 1 (0)| 00:00:01 | | |
| 44 | TABLE ACCESS BY INDEX ROWID | D_STAT_KONTINGENTI | 1 | 10 | | 1 (0)| 0
|* 45 | INDEX UNIQUE SCAN | DSG_PK | 1 | | | 0 (0)| 00:00:01 | | |
|* 46 | TABLE ACCESS FULL | ZAK_ZAKRIVANJE | 1 | 25 | | 4 (0)| 00:00:01 |
| 47 | HASH GROUP BY | | 526K| 53M| 134M| 3721K (1)| 04:18:18 | | |
| 48 | NESTED LOOPS OUTER | | 526K| 53M| | 3710K (1)| 04:17:32 | | |
|* 49 | HASH JOIN | | 526K| 36M| | 2564 (8)| 00:00:11 | | |
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
| 50 | TABLE ACCESS FULL | D_SKD | 1758 | 12306 | | 29 (0)| 00:00:01 | | |
|* 51 | HASH JOIN | | 528K| 32M| | 2524 (7)| 00:00:11 | | |
| 52 | MERGE JOIN CARTESIAN | | 50 | 700 | | 14 (0)| 00:00:01 | | |
|* 53 | TABLE ACCESS FULL | D_OZNAKE_OBD | 5 | 30 | | 4 (0)| 00:00:01 | |
| 54 | BUFFER SORT | | 10 | 80 | | 10 (0)| 00:00:01 | | |
| 55 | INLIST ITERATOR | | | | | | | | |
| 56 | TABLE ACCESS BY INDEX ROWID| D_STAT_KONTINGENTI | 10 | 80 | | 2 (0)| 00:00:01
|* 57 | INDEX RANGE SCAN | DSG_SPODK_IDX | 10 | | | 1 (0)| 00:00:01 | | |
| 58 | PARTITION RANGE SINGLE | | 528K| 25M| | 2500 (7)| 00:00:11 | 89 |
|* 59 | TABLE ACCESS FULL | F_POSTAVKE | 528K| 25M| | 2500 (7)| 00:00:11 | 8
| 60 | VIEW PUSHED PREDICATE | | 1 | 35 | | 7 (0)| 00:00:01 | | |
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
| 61 | NESTED LOOPS | | 1 | 53 | | 7 (0)| 00:00:01 | | |
| 62 | NESTED LOOPS | | 1 | 28 | | 3 (0)| 00:00:01 | | |
| 63 | TABLE ACCESS BY INDEX ROWID | D_TARIFA | 1 | 18 | | 2 (0)| 00:00:01
|* 64 | INDEX UNIQUE SCAN | DTA_PK | 1 | | | 1 (0)| 00:00:01 | | |
| 65 | TABLE ACCESS BY INDEX ROWID | D_STAT_KONTINGENTI | 1 | 10 | | 1 (0)| 0
|* 66 | INDEX UNIQUE SCAN | DSG_PK | 1 | | | 0 (0)| 00:00:01 | | |
|* 67 | TABLE ACCESS FULL | ZAK_ZAKRIVANJE | 1 | 25 | | 4 (0)| 00:00:01 |
| 68 | HASH GROUP BY | | 526K| 56M| 141M| 3721K (1)| 04:18:20 | | |
| 69 | NESTED LOOPS OUTER | | 526K| 56M| | 3710K (1)| 04:17:32 | | |
|* 70 | HASH JOIN | | 526K| 36M| | 2564 (8)| 00:00:11 | | |
| 71 | TABLE ACCESS FULL | D_SKD | 1758 | 12306 | | 29 (0)| 00:00:01 | | |
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
|* 72 | HASH JOIN | | 528K| 32M| | 2524 (7)| 00:00:11 | | |
| 73 | MERGE JOIN CARTESIAN | | 50 | 700 | | 14 (0)| 00:00:01 | | |
|* 74 | TABLE ACCESS FULL | D_OZNAKE_OBD | 5 | 30 | | 4 (0)| 00:00:01 | |
| 75 | BUFFER SORT | | 10 | 80 | | 10 (0)| 00:00:01 | | |
| 76 | INLIST ITERATOR | | | | | | | | |
| 77 | TABLE ACCESS BY INDEX ROWID| D_STAT_KONTINGENTI | 10 | 80 | | 2 (0)| 00:00:01
|* 78 | INDEX RANGE SCAN | DSG_SPODK_IDX | 10 | | | 1 (0)| 00:00:01 | | |
| 79 | PARTITION RANGE SINGLE | | 528K| 25M| | 2500 (7)| 00:00:11 | 89 |
|* 80 | TABLE ACCESS FULL | F_POSTAVKE | 528K| 25M| | 2500 (7)| 00:00:11 | 8
| 81 | VIEW PUSHED PREDICATE | | 1 | 40 | | 7 (0)| 00:00:01 | | |
| 82 | NESTED LOOPS | | 1 | 59 | | 7 (0)| 00:00:01 | | |
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
| 83 | NESTED LOOPS | | 1 | 28 | | 3 (0)| 00:00:01 | | |
| 84 | TABLE ACCESS BY INDEX ROWID | D_TARIFA | 1 | 18 | | 2 (0)| 00:00:01
|* 85 | INDEX UNIQUE SCAN | DTA_PK | 1 | | | 1 (0)| 00:00:01 | | |
| 86 | TABLE ACCESS BY INDEX ROWID | D_STAT_KONTINGENTI | 1 | 10 | | 1 (0)| 0
|* 87 | INDEX UNIQUE SCAN | DSG_PK | 1 | | | 0 (0)| 00:00:01 | | |
|* 88 | TABLE ACCESS FULL | ZAK_ZAKRIVANJE | 1 | 31 | | 4 (0)| 00:00:01 |
----------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
4 - access("P"."K_TARSKD"="T"."K_TARSKD")
6 - access("P"."K_STATKONT"="SK"."K_STATKONT" AND "P"."K_OZNOBD"="OO"."K_OZNOBD")
8 - filter("OO"."OZNOBD"='1')
12 - access("SK"."SPODKONT"='1' OR "SK"."SPODKONT"='3' OR "SK"."SPODKONT"='5' OR "SK"."SPODKONT"='
"SK"."SPODKONT"='7')
14 - filter("P"."LETO"=2007 AND "P"."MESEC"=5)
19 - access("TP"."K_TARIFA"="P"."K_TARIFA")
21 - access("SK"."K_STATKONT"="P"."K_STATKONT")
22 - filter("ZZ"."VELJA_DO" IS NULL AND "TP"."TARIFA_ID"="ZZ"."TARIFA_ID" AND "SK"."SKONT"="ZZ"."S
25 - access("P"."K_TARSKD"="T"."K_TARSKD")
27 - access(ROWID=ROWID)
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
30 - access("P"."K_STATKONT"="SK"."K_STATKONT" AND "P"."K_OZNOBD"="OO"."K_OZNOBD")
32 - filter("OO"."OZNOBD"='1')
36 - access("SK"."SPODKONT"='1' OR "SK"."SPODKONT"='3' OR "SK"."SPODKONT"='5' OR "SK"."SPODKONT"='
"SK"."SPODKONT"='7')
38 - filter("P"."LETO"=2007 AND "P"."MESEC"=5)
43 - access("TP"."K_TARIFA"="P"."K_TARIFA")
45 - access("SK"."K_STATKONT"="P"."K_STATKONT")
46 - filter("ZZ"."VELJA_DO" IS NULL AND "TP"."TARIFA_ID"="ZZ"."TARIFA_ID" AND "SK"."SKONT"="ZZ"."S
49 - access("P"."K_TARSKD"="T"."K_TARSKD")
51 - access("P"."K_STATKONT"="SK"."K_STATKONT" AND "P"."K_OZNOBD"="OO"."K_OZNOBD")
53 - filter("OO"."OZNOBD"='1')
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
57 - access("SK"."SPODKONT"='1' OR "SK"."SPODKONT"='3' OR "SK"."SPODKONT"='5' OR "SK"."SPODKONT"='
"SK"."SPODKONT"='7')
59 - filter("P"."LETO"=2007 AND "P"."MESEC"=5)
64 - access("TP"."K_TARIFA"="P"."K_TARIFA")
66 - access("SK"."K_STATKONT"="P"."K_STATKONT")
67 - filter("ZZ"."VELJA_DO" IS NULL AND "TP"."TARIFA_ID"="ZZ"."TARIFA_ID" AND "SK"."SKONT"="ZZ"."S
70 - access("P"."K_TARSKD"="T"."K_TARSKD")
72 - access("P"."K_STATKONT"="SK"."K_STATKONT" AND "P"."K_OZNOBD"="OO"."K_OZNOBD")
74 - filter("OO"."OZNOBD"='1')
78 - access("SK"."SPODKONT"='1' OR "SK"."SPODKONT"='3' OR "SK"."SPODKONT"='5' OR "SK"."SPODKONT"='
"SK"."SPODKONT"='7')
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
80 - filter("P"."LETO"=2007 AND "P"."MESEC"=5)
85 - access("TP"."K_TARIFA"="P"."K_TARIFA")
87 - access("SK"."K_STATKONT"="P"."K_STATKONT")
88 - filter("ZZ"."VELJA_DO" IS NULL AND "TP"."TARIFA_ID"="ZZ"."TARIFA_ID" AND "SK"."SKONT"="ZZ"."S
136 rows selected.
SELECT_PLAN.TXT
###############################
EXPLAIN PLAN FOR SELECT
###############################
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
Plan hash value: 2682894902
----------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes |TempSpc| Cost (%CPU)| Time | Pstart| Pstop |
----------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | | 41713 (4)| 00:02:54 | | |
| 1 | SORT AGGREGATE | | 1 | | | | | | |
| 2 | VIEW | | 2104K| | | 41713 (4)| 00:02:54 | | |
| 3 | UNION-ALL | | | | | | | | |
| 4 | HASH GROUP BY | | 526K| 35M| 80M| 9149 (4)| 00:00:39 | | |
|* 5 | HASH JOIN RIGHT OUTER | | 526K| 35M| | 1470 (14)| 00:00:07 | | |
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
| 6 | VIEW | | 775 | 6975 | | 140 (5)| 00:00:01 | | |
|* 7 | HASH JOIN | | 775 | 24025 | | 140 (5)| 00:00:01 | | |
|* 8 | HASH JOIN | | 94 | 2350 | | 136 (4)| 00:00:01 | | |
|* 9 | TABLE ACCESS FULL | ZAK_ZAKRIVANJE | 77 | 924 | | 3 (0)| 00:00:01 | |
| 10 | TABLE ACCESS FULL | D_TARIFA | 24439 | 310K| | 132 (4)| 00:00:01 | |
| 11 | VIEW | index$_join$_007 | 18 | 108 | | 3 (0)| 00:00:01 | | |
|* 12 | HASH JOIN | | | | | | | | |
| 13 | INDEX FAST FULL SCAN| DSG_PK | 18 | 108 | | 1 (0)| 00:00:01 | | |
| 14 | INDEX FAST FULL SCAN| DSG_SKONT_IDX | 18 | 108 | | 1 (0)| 00:00:01 | | |
|* 15 | HASH JOIN | | 526K| 31M| | 1319 (14)| 00:00:06 | | |
| 16 | TABLE ACCESS FULL | D_SKD | 1758 | 12306 | | 16 (7)| 00:00:01 | |
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
|* 17 | HASH JOIN | | 528K| 27M| | 1293 (14)| 00:00:06 | | |
| 18 | MERGE JOIN CARTESIAN | | 50 | 600 | | 11 (0)| 00:00:01 | | |
|* 19 | TABLE ACCESS FULL | D_OZNAKE_OBD | 5 | 30 | | 3 (0)| 00:00:01 | | |
| 20 | BUFFER SORT | | 10 | 60 | | 8 (0)| 00:00:01 | | |
|* 21 | TABLE ACCESS FULL | D_STAT_KONTINGENTI | 10 | 60 | | 2 (0)| 00:00:01 | | |
| 22 | PARTITION RANGE SINGLE| | 528K| 21M| | 1272 (13)| 00:00:06 | 89 | 89 |
|* 23 | TABLE ACCESS FULL | F_POSTAVKE | 528K| 21M| | 1272 (13)| 00:00:06 | 89 | 89 |
| 24 | HASH GROUP BY | | 526K| 43M| 109M| 10599 (3)| 00:00:45 | | |
|* 25 | HASH JOIN RIGHT OUTER | | 526K| 43M| | 1470 (14)| 00:00:07 | | |
| 26 | VIEW | | 775 | 18600 | | 140 (5)| 00:00:01 | | |
|* 27 | HASH JOIN | | 775 | 34100 | | 140 (5)| 00:00:01 | | |
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
|* 28 | HASH JOIN | | 94 | 3572 | | 136 (4)| 00:00:01 | | |
|* 29 | TABLE ACCESS FULL | ZAK_ZAKRIVANJE | 77 | 1925 | | 3 (0)| 00:00:01 | |
| 30 | TABLE ACCESS FULL | D_TARIFA | 24439 | 310K| | 132 (4)| 00:00:01 | |
| 31 | VIEW | index$_join$_016 | 18 | 108 | | 3 (0)| 00:00:01 | | |
|* 32 | HASH JOIN | | | | | | | | |
| 33 | INDEX FAST FULL SCAN| DSG_PK | 18 | 108 | | 1 (0)| 00:00:01 | | |
| 34 | INDEX FAST FULL SCAN| DSG_SKONT_IDX | 18 | 108 | | 1 (0)| 00:00:01 | | |
|* 35 | HASH JOIN | | 526K| 31M| | 1319 (14)| 00:00:06 | | |
| 36 | TABLE ACCESS FULL | D_SKD | 1758 | 10548 | | 15 (0)| 00:00:01 | |
|* 37 | HASH JOIN | | 528K| 28M| | 1293 (14)| 00:00:06 | | |
| 38 | MERGE JOIN CARTESIAN | | 50 | 700 | | 11 (0)| 00:00:01 | | |
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
|* 39 | TABLE ACCESS FULL | D_OZNAKE_OBD | 5 | 30 | | 3 (0)| 00:00:01 | | |
| 40 | BUFFER SORT | | 10 | 80 | | 8 (0)| 00:00:01 | | |
|* 41 | TABLE ACCESS FULL | D_STAT_KONTINGENTI | 10 | 80 | | 2 (0)| 00:00:01 | | |
| 42 | PARTITION RANGE SINGLE| | 528K| 21M| | 1272 (13)| 00:00:06 | 89 | 89 |
|* 43 | TABLE ACCESS FULL | F_POSTAVKE | 528K| 21M| | 1272 (13)| 00:00:06 | 89 | 89 |
| 44 | HASH GROUP BY | | 526K| 44M| 109M| 10684 (3)| 00:00:45 | | |
|* 45 | HASH JOIN RIGHT OUTER | | 526K| 44M| | 1470 (14)| 00:00:07 | | |
| 46 | VIEW | | 775 | 18600 | | 140 (5)| 00:00:01 | | |
|* 47 | HASH JOIN | | 775 | 34100 | | 140 (5)| 00:00:01 | | |
|* 48 | HASH JOIN | | 94 | 3572 | | 136 (4)| 00:00:01 | | |
|* 49 | TABLE ACCESS FULL | ZAK_ZAKRIVANJE | 77 | 1925 | | 3 (0)| 00:00:01 | |
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
| 50 | TABLE ACCESS FULL | D_TARIFA | 24439 | 310K| | 132 (4)| 00:00:01 | |
| 51 | VIEW | index$_join$_025 | 18 | 108 | | 3 (0)| 00:00:01 | | |
|* 52 | HASH JOIN | | | | | | | | |
| 53 | INDEX FAST FULL SCAN| DSG_PK | 18 | 108 | | 1 (0)| 00:00:01 | | |
| 54 | INDEX FAST FULL SCAN| DSG_SKONT_IDX | 18 | 108 | | 1 (0)| 00:00:01 | | |
|* 55 | HASH JOIN | | 526K| 32M| | 1319 (14)| 00:00:06 | | |
| 56 | TABLE ACCESS FULL | D_SKD | 1758 | 12306 | | 15 (0)| 00:00:01 | |
|* 57 | HASH JOIN | | 528K| 28M| | 1293 (14)| 00:00:06 | | |
| 58 | MERGE JOIN CARTESIAN | | 50 | 700 | | 11 (0)| 00:00:01 | | |
|* 59 | TABLE ACCESS FULL | D_OZNAKE_OBD | 5 | 30 | | 3 (0)| 00:00:01 | | |
| 60 | BUFFER SORT | | 10 | 80 | | 8 (0)| 00:00:01 | | |
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
|* 61 | TABLE ACCESS FULL | D_STAT_KONTINGENTI | 10 | 80 | | 2 (0)| 00:00:01 | | |
| 62 | PARTITION RANGE SINGLE| | 528K| 21M| | 1272 (13)| 00:00:06 | 89 | 89 |
|* 63 | TABLE ACCESS FULL | F_POSTAVKE | 528K| 21M| | 1272 (13)| 00:00:06 | 89 | 89 |
| 64 | HASH GROUP BY | | 526K| 47M| 117M| 11281 (3)| 00:00:47 | | |
|* 65 | HASH JOIN RIGHT OUTER | | 526K| 47M| | 1470 (14)| 00:00:07 | | |
| 66 | VIEW | | 775 | 23250 | | 140 (5)| 00:00:01 | | |
|* 67 | HASH JOIN | | 775 | 38750 | | 140 (5)| 00:00:01 | | |
|* 68 | HASH JOIN | | 94 | 4136 | | 136 (4)| 00:00:01 | | |
|* 69 | TABLE ACCESS FULL | ZAK_ZAKRIVANJE | 77 | 2387 | | 3 (0)| 00:00:01 | |
| 70 | TABLE ACCESS FULL | D_TARIFA | 24439 | 310K| | 132 (4)| 00:00:01 | |
| 71 | VIEW | index$_join$_034 | 18 | 108 | | 3 (0)| 00:00:01 | | |
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
|* 72 | HASH JOIN | | | | | | | | |
| 73 | INDEX FAST FULL SCAN| DSG_PK | 18 | 108 | | 1 (0)| 00:00:01 | | |
| 74 | INDEX FAST FULL SCAN| DSG_SKONT_IDX | 18 | 108 | | 1 (0)| 00:00:01 | | |
|* 75 | HASH JOIN | | 526K| 32M| | 1319 (14)| 00:00:06 | | |
| 76 | TABLE ACCESS FULL | D_SKD | 1758 | 12306 | | 15 (0)| 00:00:01 | |
|* 77 | HASH JOIN | | 528K| 28M| | 1293 (14)| 00:00:06 | | |
| 78 | MERGE JOIN CARTESIAN | | 50 | 700 | | 11 (0)| 00:00:01 | | |
|* 79 | TABLE ACCESS FULL | D_OZNAKE_OBD | 5 | 30 | | 3 (0)| 00:00:01 | | |
| 80 | BUFFER SORT | | 10 | 80 | | 8 (0)| 00:00:01 | | |
|* 81 | TABLE ACCESS FULL | D_STAT_KONTINGENTI | 10 | 80 | | 2 (0)| 00:00:01 | | |
| 82 | PARTITION RANGE SINGLE| | 528K| 21M| | 1272 (13)| 00:00:06 | 89 | 89 |
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
|* 83 | TABLE ACCESS FULL | F_POSTAVKE | 528K| 21M| | 1272 (13)| 00:00:06 | 89 | 89 |
----------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
5 - access("P"."K_TARIFA"="Z"."K_TARIFA"(+) AND "P"."K_STATKONT"="Z"."K_STATKONT"(+))
7 - access("SK"."SKONT"="ZZ"."SKONT")
8 - access("TP"."TARIFA_ID"="ZZ"."TARIFA_ID")
9 - filter("ZZ"."VELJA_DO" IS NULL)
12 - access(ROWID=ROWID)
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
15 - access("P"."K_TARSKD"="T"."K_TARSKD")
17 - access("P"."K_STATKONT"="SK"."K_STATKONT" AND "P"."K_OZNOBD"="OO"."K_OZNOBD")
19 - filter("OO"."OZNOBD"='1')
21 - filter("SK"."SPODKONT"='1' OR "SK"."SPODKONT"='3' OR "SK"."SPODKONT"='5' OR "SK"."SPODKONT"='
"SK"."SPODKONT"='7')
23 - filter("P"."LETO"=2007 AND "P"."MESEC"=5)
25 - access("P"."K_TARIFA"="Z"."K_TARIFA"(+) AND "P"."K_STATKONT"="Z"."K_STATKONT"(+))
27 - access("SK"."SKONT"="ZZ"."SKONT")
28 - access("TP"."TARIFA_ID"="ZZ"."TARIFA_ID")
29 - filter("ZZ"."VELJA_DO" IS NULL)
32 - access(ROWID=ROWID)
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
35 - access("P"."K_TARSKD"="T"."K_TARSKD")
37 - access("P"."K_STATKONT"="SK"."K_STATKONT" AND "P"."K_OZNOBD"="OO"."K_OZNOBD")
39 - filter("OO"."OZNOBD"='1')
41 - filter("SK"."SPODKONT"='1' OR "SK"."SPODKONT"='3' OR "SK"."SPODKONT"='5' OR "SK"."SPODKONT"='
"SK"."SPODKONT"='7')
43 - filter("P"."LETO"=2007 AND "P"."MESEC"=5)
45 - access("P"."K_TARIFA"="Z"."K_TARIFA"(+) AND "P"."K_STATKONT"="Z"."K_STATKONT"(+))
47 - access("SK"."SKONT"="ZZ"."SKONT")
48 - access("TP"."TARIFA_ID"="ZZ"."TARIFA_ID")
49 - filter("ZZ"."VELJA_DO" IS NULL)
52 - access(ROWID=ROWID)
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
55 - access("P"."K_TARSKD"="T"."K_TARSKD")
57 - access("P"."K_STATKONT"="SK"."K_STATKONT" AND "P"."K_OZNOBD"="OO"."K_OZNOBD")
59 - filter("OO"."OZNOBD"='1')
61 - filter("SK"."SPODKONT"='1' OR "SK"."SPODKONT"='3' OR "SK"."SPODKONT"='5' OR "SK"."SPODKONT"='
"SK"."SPODKONT"='7')
63 - filter("P"."LETO"=2007 AND "P"."MESEC"=5)
65 - access("P"."K_TARIFA"="Z"."K_TARIFA"(+) AND "P"."K_STATKONT"="Z"."K_STATKONT"(+))
67 - access("SK"."SKONT"="ZZ"."SKONT")
68 - access("TP"."TARIFA_ID"="ZZ"."TARIFA_ID")
69 - filter("ZZ"."VELJA_DO" IS NULL)
72 - access(ROWID=ROWID)
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
75 - access("P"."K_TARSKD"="T"."K_TARSKD")
77 - access("P"."K_STATKONT"="SK"."K_STATKONT" AND "P"."K_OZNOBD"="OO"."K_OZNOBD")
79 - filter("OO"."OZNOBD"='1')
81 - filter("SK"."SPODKONT"='1' OR "SK"."SPODKONT"='3' OR "SK"."SPODKONT"='5' OR "SK"."SPODKONT"='
"SK"."SPODKONT"='7')
83 - filter("P"."LETO"=2007 AND "P"."MESEC"=5)
138 rows selected.
SQL>
ORA-00600 [LibraryCacheNotEmptyOnClose]
An example of the error reported after SHUTDOWN IMMEDIATE:
SQL*Plus: Release 10.2.0.3.0 - Production on Sob Jan 26 14:23:59 2008 Copyright (c) 1982, 2006, Oracle. All Rights Reserved. Connected. Database closed. Database dismounted. ORA-00600: internal error code, arguments: [LibraryCacheNotEmptyOnClose], [], [], [], [], [], [], [] Disconnected from Oracle Database 10g Enterprise Edition Release 10.2.0.3.0 - 64bit Production With the Partitioning, OLAP and Data Mining options
According to Metalink note 4483084.8 “Bug 4483084 – OERI[LibraryCacheNotEmptyOnClose] on shutdown” this error message could be ignored. Bug is fixed in 11.1.0.6.
We’re getting this error sporadically after we migrated to 64-bit 10g R2, never received the error before (on 32-bit OS/RDBMS).
How to change Oracle wordsize from 32-bit to 64-bit
Another test case scenario (in addition to one described here) for Oracle Word size change, from 32-bit to 64-bit.
We want source database (32-bit Oracle 10.2.0.2, Windows 2003 SP1, 32-bit) to convert to target database
(64-bit Oracle 10.2.0.3 + Patch 12, Windows 2003 SP2, x64). Basically we’re changing the word size of the database and patching the database at the same time. This scenario was tested in test environment and will be used shortly on one of our production database.
We already installed 64-bit Oracle Software (10.2.0.3 + Patch 12) on our new machine and made necessary configuration of the storage, directories, spfile, password file etc. We also copied all database/ctl files from production server to the new, x64 machine (after shutdown normal).
You must be aware of the following:
- it’s important that target (64-bit) Oracle10g is of the proper release (minimum 10.2.0.3 + Patch 5, in our case is Patch 12, otherwise known as CPUOCT2007) or you might hit ORA-600 error that I wrote about.
- make sure SQLNET.ORA is present on target database and that contains NAMES.DIRECTORY_PATH= (TNSNAMES), or you might hit another bug.
- don’t even think of using Oracle on Windows 2003 with SP1 and large amount of memory! Read this before you decide what to do.
- make sure you read Metalink Note:62290.1 “Changing between 32-bit and 64-bit Word Sizes”
- read and understand patchset readme (10.2.0.3) as well as readme that comes with Patch 12.
- this test scenario is for single, non-RAC, Oracle instance
From here on the steps are:
1) create service on x64:
set ORACLE_SID=ORCL D:\oracle\ORA10\bin\oradim.exe -new -sid ORCL -startmode manual -spfile D:\oracle\ORA10\bin\oradim.exe -edit -sid ORCL -startmode auto -srvcstart system
2) start the instance in upgrade mode
I’m intentionally using pfile for the sake of simplicity of editing; after migration spfile is used)
startup upgrade pfile=D:\ORACLE\ORA10\database\initorcl.ora
3) invalidate PL/SQL packages
spool CATOUT_32_64.log @D:\ORACLE\ORA10\RDBMS\ADMIN\UTLIRP.SQL spool off
Check CATOUT_32_64.log.
Do not shutdown and restart the database!
4) Upgrade
SPOOL CATUPGRD.LOG @D:\ORACLE\ORA10\RDBMS\ADMIN\CATUPGRD.SQL SPOOL OFF
Check CATUPGRD.LOG for errors – some errors can be ignored, refer to readme that comes with Patchset 10.2.0.3.
5) Check status for the package DBMS_STANDARD
select status from dba_objects where object_name='DBMS_STANDARD' and object_type='PACKAGE' and owner='SYS'; Recompile if package is invalid: alter package dbms_standard compile;
6) Check the number of invalid objects for SYS and recompile if needed
select count(*) from dba_objects where owner='SYS' and status='INVALID'; @D:\ORACLE\ORA10\RDBMS\ADMIN\UTLRP.SQL
7) Check status of database components
column comp_name format a40 column version format a10 select comp_name, version, status from dba_registry; COMP_NAME VERSION STATUS ---------------------------------------- ---------- ----------- Oracle interMedia 10.2.0.3.0 VALID Oracle Enterprise Manager 10.2.0.3.0 VALID Oracle XML Database 10.2.0.3.0 VALID Oracle Text 10.2.0.3.0 VALID Oracle Expression Filter 10.2.0.3.0 VALID Oracle Rule Manager 10.2.0.3.0 VALID Oracle Workspace Manager 10.2.0.1.0 VALID Oracle Data Mining 10.2.0.3.0 VALID Oracle Database Catalog Views 10.2.0.3.0 VALID Oracle Database Packages and Types 10.2.0.3.0 VALID JServer JAVA Virtual Machine 10.2.0.3.0 VALID Oracle XDK 10.2.0.3.0 VALID Oracle Database Java Packages 10.2.0.3.0 VALID SQL>
8) Apply CPUOCT2007
In addition of running CATUPGRD.SQL we have to run CATCPU script as well, in our case for CPUOct2007.
cd %ORACLE_HOME%\CPU\CPUOct2007 sqlplus /nolog CONNECT / AS SYSDBA @catcpu.sql QUIT The script will end with report similar as: TIMESTAMP -------------------------------------------------------------------------------- COMP_TIMESTAMP CPU_END 2008-01-18 20:22:54 No. of Invalid Objects is :575 Please refer to README.html to for instructions on validating these objects PL/SQL procedure successfully completed. Logfile for the current catcpu.sql session is : APPLY_ORAX_18Jan2008_20_18_52.log Check log file mentioned in catcpu.sql report - some errors can be ignored (refer to CPU readme)! At this stage you can check dba_registry again: SQL> column comp_name format a40 SQL> column version format a10 SQL> select comp_name, version, status from dba_registry; COMP_NAME VERSION STATUS ---------------------------------------- ---------- ----------- Oracle interMedia 10.2.0.3.0 VALID Oracle Enterprise Manager 10.2.0.3.0 VALID Oracle XML Database 10.2.0.3.0 VALID Oracle Text 10.2.0.3.0 VALID Oracle Expression Filter 10.2.0.3.0 VALID Oracle Rule Manager 10.2.0.3.0 VALID Oracle Workspace Manager 10.2.0.1.0 VALID Oracle Data Mining 10.2.0.3.0 VALID Oracle Database Catalog Views 10.2.0.3.0 VALID Oracle Database Packages and Types 10.2.0.3.0 UPGRADED JServer JAVA Virtual Machine 10.2.0.3.0 VALID COMP_NAME VERSION STATUS ---------------------------------------- ---------- ----------- Oracle XDK 10.2.0.3.0 VALID Oracle Database Java Packages 10.2.0.3.0 VALID 13 rows selected.
9) Run UTLRP.SQL once again…
@D:\ORACLE\ORA10\RDBMS\ADMIN\UTLRP.SQL
## WELCOME TO 64-bit World – END OF TEST CASE ##
Do you run Oracle on MS Windows 2003-SP1? Check this out…
If you’re using Oracle on Windows 2003 SP1 on a machine with lots of memory, you should install SP2 as soon as possible.
Check Metalink note: 464683.1 “Unexplained Database Slowdown Seen on Windows 2003 Service Pack 1”
and Microsoft Knowledge base articles:
- A program that uses structured exception handling may stop responding for several seconds in Microsoft Windows Server 2003 with SP1
- SQL Server 2000 or SQL Server 2005 may temporarily stop responding on a Windows Server 2003 Service Pack 1-based computer
I can barely remember how many times we noticed exact symptoms, without having a clue what is going on…part of the problem is certainly slow adoption of Windows 2003 in the first year or two after release, otherwise this sorts of bugs would crop out earlier. The MS decision to wait so long with SP1/SP2 release was also a bummer for MS customers.
dbaportal.eu 