Resolution History
13-AUG-07 18:24:02 GMT
** Customer's Management 24x7 contact number: 86-10-13910601263
** Primary Customer contact name: Lori,Zhang
** Current Customer 24x7 voice phone number: 86-10-13910601263
** Current Customer Email address: kamusis@gmail.com
** Current Customer Pager/Fax number: N/A
The following files were uploaded for SR number 6470259.992:
tracefiles.zip
This SR was saved as a draft on: 13-AUG-2007 11:02:18
### This is a critical production system ###
### Your system hangs or locks up completely ###
### Introduction to the Database Performance Issues iTAR Questions ###
N/A
### Is your system completely hung or is just performing slow? ###
Slow
### Please describe any recent change in your environment? ###
This is a new installed database going to live
### When was the last time you performed a tuning process to your database? ###
N/A
### When did you start to notice slow performance? ###
2 days ago, when doing pressure test with Loadrunner
### Can you consistently reproduce the problem? ###
Yes
### Is the problem related to heavy load hours only? ###
Yes
### Are you getting any kind of error messages? ###
No error messege in alertlog file, pls find in attached zip file
### Please list all files that you plan to upload: ###
1. This is a 2 nodes RAC 10.2.0.3 system plan to going to live in no more than 1 week, so I filed a Sev
erity 1 SR.
2. When do pressure test, we shutdowned the 2nd instace, so I think this is not the issue about RAC, I don't find any alert output and trace file
in the 2nd node in the testing hour either, so all trace file uploaded is from
1st node.
3. We try to simulate 10,000 concurrent user request in Loadrunner, business transaction response time is 20s when the request is under 1000, this i
s normal,but it becomes slower and slower when user request increased over 1200
, response time increased to 120s.
4. Several patches has been applied for this database, pls find them in "inventory_node_1.txt" in uploaded zip file
5. Table SB_ZSXX which in the sql(sql_id=c4m77209p832u) is a partitioned table with o
ver 100 million records, but all the records are falling into 1 partition in thi
s test scene.
6. We query the v$sql_shared_cursor view when system going extremely slowly using statement as follows:
SELECT COUNT(*) FROM v$sql_shared_cursor
WHERE sql_id='c4m77209p832u'
AND bind_mismatch='Y';
Almost all the reason said that cursor will not share is "bind_mismatch".
Contact me via : MetaLink
13-AUG-07 18:28:15 GMT
Allocation Type: Template Parse
Product ID: 5.0 Component: UNKNOWN SubComponent:
Skill ID: 5579.0 Description: DATABASE PERFORMANCE
Analyst Chosen: TAMILLER.US
Level 5.2
TAR General Flag set to: true
13-AUG-07 18:33:15 GMT
CTC DBPERF UPDATE
===================
Manual assign to scmiller.us
13-AUG-07 18:41:30 GMT
UPDATE
======
Hi Lori,
Thank you for using MetaLink. We are currently reviewing/researching the situation and will update the Service Request (SR) or call you
as soon as we have relevant information. Thank you for your patience.
Best Regards,
Scott
Global Customer Services
STATUS
=======
@WIP -- Work In Progress
13-AUG-07 18:57:12 GMT
UPDATE
======
Hi,
From the AWR
~~~~~
Event Waits Time (s) (ms) Time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
cursor: pin S wait on X 15,432,157 157,643 10 49.9 Concurrenc
latch: library cache 289,975 45,267 156 14.3 Concurrenc
kksfbc child completion 826,819 41,592 50 13.2 Other
cursor: mutex X 216,405,052 40,706 0 12.9 Concurrenc
CPU time 8,560 2.7
~~~~~
The most common occurance of this issue is described in the following note...
Note 430555.1 Database Hung With "kksfbc child completion" and "Cursor: Pin X" Waits
Of course there's different synptoms of this issue, but this is the criteria needed to run into the bug...
One session doing DML to a partitioned object which contains a lob datatype while mu
ltiple concurrent sessions are are doing DML to that same partition.
Does this fall under any of the stress testing you were doing?
Thanks
Scott
13-AUG-07 18:57:19 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
13-AUG-07 19:13:04 GMT
New info : lori.zhang@oracle.com
Before I filed this SR I've been red Note:430555.1, I already applied the Patch 5500044 but problem not resolved,
you can find the patches I have applied in the inventory_node_1.txt.
Any other suggestion?
13-AUG-07 19:15:03 GMT
New info : lori.zhang@oracle.com
Also, this table has no lob datatype column.
13-AUG-07 19:27:18 GMT
UPDATE
======
Hi,
Thanks for the update. I'll need to see a systemstate and hang analyze while this problem is occuring to see what the blocking process is spec
ifically doing. There's multiple bugs filed against "cursor: pin S wait on X" mo
st with different causes. The other waits can be a side effect of this wait, so
we need to takle that one first.
a. hanganalyze
~~~~~~~~~~
$ sqlplus /nolog
SQL> connect / as sysdba
SQL> oradebug setmypid
SQL> oradebug unlimit
SQL> oradebug hanganalyze 3
-- wait 90 seconds
SQL> oradebug hanganalyze 3
SQL> exit;
....and then two systemstate dumps..
b. systemstate
~~~~~~~~~~
$ sqlplus /nolog
SQL> connect / as sysdba
SQL> oradebug setmypid
SQL> oradebug unlimit
SQL> oradebug dump systemstate 10
-- wait 90 seconds
SQL> oradebug dump systemstate 10
SQL> exit;
Thanks
Scott
13-AUG-07 19:27:42 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
13-AUG-07 19:31:06 GMT
New info : lori.zhang@oracle.com
OK, pls hold on, I'll upload ASAP.
13-AUG-07 19:34:52 GMT
No problem
Scott
13-AUG-07 20:11:06 GMT
The customer : lori.zhang@oracle.com : has uploaded the following file via MetaLink:
hanganalyze.zip
13-AUG-07 20:13:02 GMT
New info : lori.zhang@oracle.com
Did it.
hanganalyze.zip for hang analyze trace file.
SQL> oradebug setmypid
Statement processed.
SQL> oradebug unlimit
Statement processed.
SQL> oradebug hanganalyze 3
Hang Analysis in /oracle/admin/sdtais/udump/sdtais1_ora_8831028.trc
SQL> oradebug hanganalyze 3
Cycle 1: (0/1512)
Cycle 2: (0/1838)--(0/2278)--(0/1969)--(0/1644)--(0/1527)--(0/1874)--(0/1571)--(0/1861)--
(0/1683)--(0/1600)
Cycle 3: (0/1571)--(0/1861)--(0/1683)
Hang Analysis in /oracle/admin/sdtais/udump/sdtais1_ora_8831028.trc
SQL> exit
But, systemdump trace is over 170M even after I compressed it, do you really want that? How
should I upload it?
-rwxrwxrwa 1 lzhan None 176324188 Aug 14 04:05 sdtais1_ora_1618104.trc.Z
13-AUG-07 20:32:28 GMT
UPDATE
=======
Hi,
Please ftp the systemstate dmp to our ftp site....
Note 77483.1 External Support FTP site: Information Sheet
- in binary mode
Thanks
Scott
13-AUG-07 20:32:49 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
13-AUG-07 20:33:06 GMT
New info : lori.zhang@oracle.com
I'm uploading sdtais1_ora_1618104.trc.Z to a website, it will take about 1 hour.
You can download it from http://bbs.wisky.org/sdtais1_ora_1618104.trc.Z after it completed.
13-AUG-07 20:41:15 GMT
Ok, can you ping the SR when the file has been uploaded?
Also, would you mind generating one more hanganalyze? There looks to be some parts missing at the tai
l of the report.
Thanks
Scott
13-AUG-07 20:41:25 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
13-AUG-07 20:45:07 GMT
New info : lori.zhang@oracle.com
Sorry, what do you mean ping the SR?
I'll do a hang analyze again.
13-AUG-07 20:47:31 GMT
UPDATE
=======
Hi,
Sorry for the "support" lingo. I meant update the SR to notify that the upload has completed.
Scott
13-AUG-07 20:48:09 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
13-AUG-07 20:53:04 GMT
New info : lori.zhang@oracle.com
Sure, no problem
13-AUG-07 21:12:33 GMT
Thanks
Scott
13-AUG-07 21:13:01 GMT
The customer : lori.zhang@oracle.com : has uploaded the following file via MetaLink:
ha.new.zip
13-AUG-07 21:14:03 GMT
New info : lori.zhang@oracle.com
pls find the new hang analyze trace
13-AUG-07 21:22:03 GMT
New info : lori.zhang@oracle.com
http://bbs.wisky.org/sdtais1_ora_1618104.trc.Z is ok, pls download it
13-AUG-07 21:27:15 GMT
## GLOBAL CRITICAL ACTIVE ###
### CUSTOMER AND INTERNAL CONTACT INFORMATION###
### 1. Primary Technical Contact Details ###
### Customer Contact Name ###
### Primary Phone Number ###
### Secondary Phone Number ###
### Customer Email Address ###
### 2. Secondary Technical Contact Details ###
### Customer Contact Name ###
### Primary Phone Number ###
### Secondary Phone Number ###
### Customer Email Address ###
### 3. Customer Manager Name/Phone Number ###
### 4. Sending Engineer Full Name, AIM ID, and Phone Number ###
### 5. If the SR is escalated, provide name/ID of previous escalation owner. ###
### SR HANDOFF DETAILS###
### 6. Is a warm hand off required? ###
*** YES *** Engineer to Engineer warm hand-off by telephone is always required
### 7. List all collaboration SRs ###
### Advanced Resolution SRs ###
### Translation SRs ###
### BDE RFA ###
### Other SRs ###
###TECHNICAL SUMMARY###
### 8. Problem Definition/Verification ###
Ct is doing load testing When they try to simulate 10,000 concurrent user request in Loadrunner, business transaction response time is 20s when the request is
under 1000, this is normal,but it becomes slower and slower when user request i
ncreased over 1200, response time increased to 120s.
AWR shows the following...
Event Waits Time (s) (ms) Time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
cursor: pin S wait on X 15,432,157 157,643 10 49.9 Concurrenc
latch: library cache 289,975 45,267 156 14.3 Concurrenc
kksfbc child completion 826,819 41,592 50 13.2 Other
cursor: mutex X 216,405,052 40,706 0 12.9 Concurrenc
CPU time 8,560 2.7
Ct had applied the patch for the bug listed in this note and the problem still o
ccured..
Note 430555.1 Database Hung With "kksfbc child completion" and "Cursor: Pin X" Waits
Ct just uploaded a new hang analyze (the first one seemed to be missing some info at the tail end as well has just uploaded the systemstate to
http://bbs.wisky.org/sdtais1_ora_1618104.trc.Z
Thanks
Scott
### 9. Data Collected: Customer Files/Test Case Locations(IP, user/pass, file spec/path) ###
###ACTION PLAN FOR NEXT SHIFT###
### 10. Action Plan for this issue ###
### 11. Communications Plan: Next contact time ###
### 12. Preferred communication method ###
13-AUG-07 21:37:10 GMT
Allocation Type: A.B.C.
Product ID: 5.0 Component: RDBMS SubComponent: DBPERF
Skill ID: 5579.0 Description: DATABASE PERFORMANCE
Analyst Chosen: AMENDOZA.AU
Level 5.2
TAR General Flag set to: true
13-AUG-07 21:39:23 GMT
reviewing SR and commenced download of systemstate dump.
@wip
13-AUG-07 23:02:57 GMT
ISSUE CLARIFICATION
====================
Customer statement:
1. This is a 2 nodes RAC 10.2.0.3 system plan to going to live in no more than 1 week, so I filed
a Severity 1 SR.
2. When do pressure test, we shutdowned the 2nd instace, so I think this is not the issue about RAC, I don't find
any alert output and trace file in the 2nd node in the testing hour either, so all trace file upload
ed is from 1st node.
3. We try to simulate 10,000 concurrent user request in Loadrunner, business transaction response time is 20s when the
request is under 1000, this is normal,but it becomes slower and slower when user request incre
ased over 1200,
response time increased to 120s.
4. Several patches has been applied for this database, pls find them in "inventory_node_1.txt" in upload
ed zip file
5. Table SB_ZSXX which in the sql(sql_id=c4m77209p832u) is a partitioned table with over 100 million records, but
all the records are falling into 1 partition in this test scene.
6. We query the v$sql_shared_cursor view when system going extremely slowly using statement as follows:
SELECT COUNT(*) FROM v$sql_shared_cursor
WHERE sql_id='c4m77209p832u'
AND bind_mismatch='Y';
Almost all the reason said that cursor will not share is "bind_mismatch".
eos (end of section)
ISSUE VERIFICATION
===================
Verified issue from uploaded AWR and ASH reports.
eos (end of section)
DATA COLLECTED
===============
awrrpt_1_570_571.txt
~~~~~~~~~~~~~~~~~~~~
1. Top 5 Timed Events Avg %Total
~~~~~~~~~~~~~~~~~~ wait Call
Event Waits Time (s) (ms) Time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
cursor: pin S wait on X 15,432,157 157,643 10 49.9 Concurrenc
latch: library cache 289,975 45,267 156 14.3 Concurrenc
kksfbc child completion 826,819 41,592 50 13.2 Other
cursor: mutex X 216,405,052 40,706 0 12.9 Concurrenc
CPU time 8,560 2.7
-------------------------------------------------------------
2. Load profile shows very high parse rate while reloads in library cache doesn't appear
to be excessive.
Load Profile
~~~~~~~~~~~~ Per Second Per Transaction
--------------- ---------------
Parses: 950.59 124.46
Hard parses: 101.95 13.35
Get Pct Pin Pct Invali-
Namespace Requests Miss Requests Miss Reloads dations
--------------- ------------ ------ -------------- ------ ---------- --------
BODY 254 0.8 1,441 0.5 5 0
CLUSTER 24 0.0 55 0.0 0 0
INDEX 7 28.6 12 50.0 4 0
SQL AREA 146,823 0.1 3,586,372 3.6 362 98
TABLE/PROCEDURE 1,858 5.9 477,736 0.2 268 0
TRIGGER 453 0.0 4,536 0.2 7 0
3. It appear that same sql described by ct is responsible for most of the db elapsed time
and cpu time.
Elapsed CPU Elap per % Total
Time (s) Time (s) Executions Exec (s) DB Time SQL Id
---------- ---------- ------------ ---------- ------- -------------
268,467 6,268 N/A N/A 84.9 c4m77209p832u
SELECT ZSXH,JKPZXH,TO_CHAR(YZFSRQ_JZ,:"SYS_B_0"),JKFSRQ,SKSS_SWJG_DM FROM SB_ZSX
X WHERE YZPZXH = :"SYS_B_1" AND NSRDZDAH = :"SYS_B_2" AND YZPZZL_DM = :"SYS_B_3"
AND ((JKPZXH IS NOT NULL) OR (YZFSRQ_JZ IS NOT NULL)) AND TZLX_DM IN (:"SYS_B_4
",:"SYS_B_5") ORDER BY SKSS_SWJG_DM
4. 'DUMP HANGANALYZE_PROC 1' taken on *** 2007-08-14 03:47:23.033 dump trace for multiple processes
doing same sql but call stack differ.
Current SQL statement for this session:
SELECT ZSXH,JKPZXH,TO_CHAR(YZFSRQ_JZ,:"SYS_B_0"),JKFSRQ,SKSS_SWJG_DM FROM SB_ZSXX WHERE YZPZXH = :"SYS_B_1" AND NSR
DZDAH = :"SYS_B_2" AND YZPZZL_DM = :"SYS_B_3" AND ((JKPZXH IS NOT NULL) OR (YZFS
RQ_JZ IS NOT NULL)) AND TZLX_DM IN (:"SYS_B_4",:"SYS_B_5") ORDER BY SKSS_SWJG_DM
ANALYSIS
========
It looks like sql above is causing high 'cursor: pin S wait on X' waits on the database and is
responsible to around 85% of cpu usage and db elapsed time.
eos (end of section)
ACTION PLAN
===========
1. Please identify the part of application executing above sql and execute it with tracing enable
d.
This is to gauge where the elapsed time is spent. Please use event=10046 level 12 for tracing.
At session level:
sql> alter session set events '10046 trace name context forever, level 12';
sql> <run sql here>;
Please upload generated trace file for analysis.
eos (end of section)
Regards,
Albert
13-AUG-07 23:03:09 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
14-AUG-07 02:19:04 GMT
## GLOBAL CRITICAL PENDING ###
### CUSTOMER AND INTERNAL CONTACT INFORMATION###
### 1. Primary Technical Contact Details ###
### Customer Contact Name ###
### Primary Phone Number ###
### Secondary Phone Number ###
### Customer Email Address ###
### 2. Secondary Technical Contact Details ###
### Customer Contact Name ###
### Primary Phone Number ###
### Secondary Phone Number ###
### Customer Email Address ###
### 3. Customer Manager Name/Phone Number ###
### 4. Sending Engineer Full Name, AIM ID, and Phone Number ###
Albert Mendoza, amendozaau, +61 2 9491 1701
### 5. If the SR is escalated, provide name/ID of previous escalation owner. ###
### SR HANDOFF DETAILS###
### 6. Is a warm hand off required? ###
*** YES *** Engineer to Engineer warm hand-off by telephone is always required
### 7. List all collaboration SRs ###
### Advanced Resolution SRs ###
### Translation SRs ###
### BDE RFA ###
### Other SRs ###
###TECHNICAL SUMMARY###
### 8. Problem Definition/Verification ###
Ct is doing load testing When they try to simulate 10,000 concurrent user request in Loadrunner,
business transaction response time is 20s when the request is under 1000, this is normal,but
it becomes slower and slower when user request increased over 1200, response time
increased to 120s.
It looks like high 'cursor: pin S wait on X' waits are caused by running this sql:
SELECT ZSXH,JKPZXH,TO_CHAR(YZFSRQ_JZ,:"SYS_B_0"),JKFSRQ,SKSS_SWJG_DM FROM SB_ZSXX WHERE YZPZXH = :"SYS_B_1" AND NSRDZDAH = :"SYS_B_2" AN
D YZPZZL_DM = :"SYS_B_3" AND ((JKPZXH IS NOT NULL) OR (YZFSRQ_JZ IS NOT NULL)) A
ND TZLX_DM IN (:"SYS_B_4",:"SYS_B_5") ORDER BY SKSS_SWJG_DM
Ct had applied the patch for the bug listed in this note and the problem still occured..
Note 430555.1 Database Hung With "kksfbc child completion" and "Cursor: Pin X" Waits
### 9. Data Collected: Customer Files/Test Case Locations(IP, user/pass, file spe
c/path) ###
###ACTION PLAN FOR NEXT SHIFT###
### 10. Action Plan for this issue ###
Requested ct to execute above sql with event=10046 level 12 tracing to find out where the high elapsed time
is spent. I suspect high parse time even if sql ever completes at all.
### 11. Communications Plan: Next contact time ###
### 12. Preferred communication method ###
14-AUG-07 05:26:02 GMT
New info : lori.zhang@oracle.com
Sorry for the late response, but I maybe 10046 trace will not help, since when system going slow, I ran this SQL separately fr
om another SQL*PLUS session several times with "set autot on", seems is OK, resp
onse time and consistent gets are normal.
Anyway, I'll upload it. just hold on.
14-AUG-07 07:26:02 GMT
New info : lori.zhang@oracle.com
Pls find the 10046 trace file.
I ran that SQL 3 times with different condition value, result returned very fast, while the
whole database is facing [cursor: pin S wait on X] and CPU usage of user is
over 90%.
I don't know why I can't upload trace file from metalink, extremely slow. So pls download it from follow
URL:
http://bbs.wisky.org/sdtais1_ora_3952788_10046_level_12.zip
Thanks.
14-AUG-07 08:50:05 GMT
New info : lori.zhang@oracle.com
Execuse me, any further suggestion? Ct. is waiting....
14-AUG-07 09:45:34 GMT
(Update for record id(s): 107259833,107259847)
DATA COLLECTED
==============
Trace File
--------------
10046
sdtais1_ora_3952788_10046_level_12
SELECT ZSXH, JKPZXH, TO_CHAR(YZFSRQ_JZ, :"SYS_B_0"), JKFSRQ, SKSS_SWJG_DM
FROM SB_ZSXX
WHERE YZPZXH = :"SYS_B_1"
AND NSRDZDAH = :"SYS_B_2"
AND YZPZZL_DM = :"SYS_B_3"
AND ((JKPZXH IS NOT NULL) OR (YZFSRQ_JZ IS NOT NULL))
AND TZLX_DM IN (:"SYS_B_4",:"SYS_B_5")
ORDER BY SKSS_SWJG_DM
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 0 43 0 4
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.00 0.00 0 43 0 4
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 37
Rows Row Source Operation
------- ---------------------------------------------------
4 SORT ORDER BY (cr=43 pr=0 pw=0 time=1050 us)
4 TABLE ACCESS BY GLOBAL INDEX ROWID SB_ZSXX PARTITION: ROW LOCATION ROW LOCATION (cr=43 pr=0 pw=0 time=152 us)
58 INDEX RANGE SCAN IDX_SB_ZSXX_NSRDZDAH (cr=5 pr=0 pw=0 time=185 us)(object id 36117)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 2 0.00 0.00
SQL*Net message from client 2 0.04 0.04
********************************************************************************
UPDATE
======
If the problem is very critical you can disable this feature by setting in pfile/spfile _use_kks_mutex_pin=false
If you want the traditional library cache mechanism to be used for library cahce o
perations, you can turn this feature off by setting the parameter _use_kks_mutex
_pin to false. Other alternative is to look in the mutex_sleep view and find the
locations of the waits. This will give a clear picture on which location it is
waiting for that wait.
Regards
Muzakkir Sayed
GCS
STATUS
======
@CUS -- Waiting for customer response
14-AUG-07 09:45:36 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
14-AUG-07 09:51:33 GMT
(Update for record id(s): 107260259)
### CUSTOMER AND INTERNAL CONTACT INFORMATION ###
### 1. PRIMARY TECHNICAL CONTACT DETAILS ###
### Customer Contact Name ###
Lori Zhang
### Primary Phone Number ###
861065356579
### Customer Email Address ###
lori.zhang@oracle.com
### 4. Sending Engineer Full Name, AIM ID, and Phone Number ###
Name: mhsayed.in
IM: MuzakkirSayed
Phone: +91 80 41072496
### TECHNICAL SUMMARY ###
### 7. Problem Definition/Verification ###
Customer is seeing high 'cursor: pin S wait on X' waits.
### 8. Data Collected: Customer Files/Test Case Locations(IP, user/pass, file spec/path) ###
Any related files are on GTCR. Any related test cases are in Research if available.
### ACTION PLAN FOR NEXT SHIFT ###
### 9. Why is this SR at Pending Status and what is projected wakeup time? ###
As suggested by previous analyst SR checked for uploaded 10046 trace for given query and no 'cursor: pin S wait on X' waits found for that que
ry.
### 10. Action Plan for when this SR wakes up ###
Check for performance after setting _use_kks_mutex_pin=false.
14-AUG-07 10:10:05 GMT
The customer : lori.zhang@oracle.com : has uploaded the following file via MetaLink:
mutexsleephistory.zip
14-AUG-07 10:11:03 GMT
New info : lori.zhang@oracle.com
CT. is changing _use_kks_mutex_pin=false and plan to restart database, we will test again after database restart.
I exported all data in v$mutex_sleep_history into an xls file and uploaded it, would you p
lease take a look at it? (mutexsleephistory.zip)
If we want to use mutext, is there any workaround? any patch?
14-AUG-07 10:20:31 GMT
Hello,
We don't know of a workaround at present nor of a BUG for this issue. One thing I would ask you to do is , should the problem reproduce after setting
this parameter , that you provide level 266 systemstates as this gives me furthe
r information I need to see why we want the pin X.
Login to sqlplus as the internal user:
sqlplus -prelim "/ as sysdba"
set trace file size to unlimited:
alter session set max_dump_file_size = unlimited;
alter session set events 'immediate trace name systemstate level 266';
alter session set events 'immediate trace name systemstate level 266';
Then send me the trace files
James.
14-AUG-07 10:20:40 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
14-AUG-07 10:21:04 GMT
New info : lori.zhang@oracle.com
BTW, it should be _kks_use_mutex_pin not _use_kks_mutex_pin, right?
14-AUG-07 10:27:41 GMT
Hello,
Yes - _kks_use_mutex_pin is correct
James.
14-AUG-07 10:27:49 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
14-AUG-07 10:45:02 GMT
New info : lori.zhang@oracle.com
_kks_use_mutex_pin=false has been set but problem still there, while the No.1 wait events change to "Latch: library cache pin"
and the top activity sql still the same.
I've upload systemstate trace file into http://bbs.wisky.org/sdtais1_ora_1618104.trc.Z last night when not setting _k
ks_use_mutex_pin, I think that file is enough for you if you want to identify w
hy we wait. is it?
14-AUG-07 10:58:55 GMT
UNPUBLISHED
============
Downloading trace files...
14-AUG-07 11:20:09 GMT
New info : lori.zhang@oracle.com
Do you have any AIM account or MSN or gtalk or anyother IM? I wanna talk to you directly, since today is the last day i
have to resolve this issue.
Thanks.
14-AUG-07 11:35:13 GMT
Hello,
You can contact me on AIM: jcremoni for the moment
James.
14-AUG-07 11:35:22 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
14-AUG-07 11:48:29 GMT
RESEARCH
==========
PROCESS 123 is waiting on a PIN:
waiting for 'cursor: pin S wait on X' blocking sess=0x0 seq=63863 wait_time=0 seconds since wait star
ted=0
idn=13540c5a, value=8ea00000000, where|sleeps=500000083
While running sql: 7000002dcf56af8
KGX Atomic Operation Log 7000002e3488f80
Mutex 7000002c4fdc1f8(2282, 0) idn 13540c5a oper GET_SHRD
Cursor
Pin uid 2507 efd 0 whr 5 slp 1
opr=2 pso=7000002da20ea20 flg=0
pcs=7000002c4fdc1f8 nxt=0 flg=35 cld=685 hd=7000002c4fdbee0 par=7000002cd425680
ct=2ac hsh=0 unp=0 unn=0 hvl=c4ff2a40 nhv=2 ses=700000312b014c8
hep=7000002c4fdc278 flg=80 ld=1 ob=7000002c4fdbab8 ptr=7000002c4fdb320 fex=7000002c4
fda630
This is name=
SELECT ZSXH,JKPZXH,TO_CHAR(YZFSRQ_JZ,:"SYS_B_0"),JKFSRQ,SKSS_SWJG_DM FROM SB_ZSXX WHERE YZPZXH = :"SYS_B_1" AND NSRDZDAH = :"SYS_B_2"
AND YZPZZL_DM = :"SYS_B_3" AND ((JKPZXH IS NOT NULL) OR (YZFSRQ_JZ IS NOT NULL)
) AND TZLX_DM IN (:"SYS_B_4",:"SYS_B_5") ORDER BY SKSS_SWJG_DM
This is held by PROCESS 1076:
KGX Atomic Operation Log 7000002e0dc66d8
Mutex 7000002a63a0060(1554, 0) idn 13540c5a oper EXCL
Cursor Pin uid 1554 efd 0 whr 1 slp 0
opr=3 pso=7000002dd12d920 flg=0
pcs=7000002a63a0060 nxt=7000002a639fc08 flg=35 cld=250 hd=7000002a64452e0 par=7000002aab6b838
ct=fa hsh=0 unp=0 unn=0 hvl=a635f6c8 nhv=2 ses=700000312a15fa8
hep=7000002a63a00e0 flg=80 ld=1 ob=7000002a6363508 ptr=7000002a635ab40 fex=7000002a6359e50
sql: 7000002aab6bb48
Which is LIBRARY OBJECT HANDLE: handle=7000002aab6bb48 mtx=7000002aab6bc78(0) cdp=252
name=
SELECT ZSXH,JKPZXH,TO_CHAR(YZFSRQ_JZ,:"SYS_B_0"),JKFSRQ,SKSS_SWJG_DM FROM SB_ZSXX WHERE YZPZXH = :"SYS_B_1" AND NSRDZ
DAH = :"SYS_B_2" AND YZPZZL_DM = :"SYS_B_3" AND ((JKPZXH IS NOT NULL) OR (YZFSRQ
_JZ IS NOT NULL)) AND TZLX_DM IN (:"SYS_B_4",:"SYS_B_5") ORDER BY SKSS_SWJG_DM
hash=56302bf1a0ae2d80c24ce71013540c5a timestamp=08-14-2007 03:46:08
This SQL has an extremely high version count which may be a factor.
ACTION PLAN
===========
The systemstate I have is not a level 266 systemstate. I need this level
One 'possible' workaround is to user cursor_sharing=exact or similar
14-AUG-07 11:49:20 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
14-AUG-07 13:34:03 GMT
New info : lori.zhang@oracle.com
Pls find level 266 systemstate from http://bbs.wisky.org/xad.rar
Thanks.
14-AUG-07 14:18:27 GMT
RESEARCH
==========
The systemstate was 1.3 Gb and too big to upload so we cut it down after finding a session last waited on the library cache
In the .rar file we have a session :-
ksdxfstk+002c<-ksdxcb+04e4<-sspuser+0074<-0000441C<-skgpwwait+0094<-kslges+051c<-kslgetl+033c<-ksfglt+0198<-kglpin+0c08<-kxsGetRuntimeL
ock+0df0<-kksCheckCursor+03fc<-kksSearchChildList+071c<-kksfbc+0b8c<-opiexe+08fc
<-opiall0+0f68<-opial7+01e0<-opiodr+0adc<-ttcpip+1020<-opitsk+10b0<-opiino+0990<
-opiodr+0adc<-opidrv+0474<-sou2o+0090<-opimai_real+01bc<-main+0098<-__start+0098
last wait for 'cursor: mutex X' blocking sess=0x0 seq=48593 wait_time=2 seconds since wait started=0
idn=13540c5a, value=80200000000, where|sleeps=102bd39a0
name=
SELECT ZSXH,JKPZXH,TO_CHAR(YZFSRQ_JZ,:"SYS_B_0"),JKFSRQ,SKSS_SWJG_DM FROM SB_ZSXX WHERE YZPZXH = :"SYS_B_1" AND NSRDZDAH = :"SYS
_B_2" AND YZPZZL_DM = :"SYS_B_3" AND ((JKPZXH IS NOT NULL) OR (YZFSRQ_JZ IS NOT
NULL)) AND TZLX_DM IN (:"SYS_B_4",:"SYS_B_5") ORDER BY SKSS_SWJG_DM
hash=56302bf1a0ae2d80c24ce71013540c5a timestamp=08-14-2007 18:53:24
This SQL has 4874 versions!
This is going to be the problem, it's just the fact we are running it and continuously creating new versions . We already know it is through bind mi
smatch
They are using loadrunner to simulate load on the system and run into this problem - I am not convinced this issue is real.
ACTION PLAN
===========
The answer to this problem is to get the SQL to share - the question is how
What we need to do is set :-
alter system set events '10046 trace name context forever, level 12';
<<wait for some connections which have the problem>>
alter system set events '10046 trace name context off';
Then look in user_dump_dest for traces which contain the SQL above - we can then use those traces to investigate th
e unsharing
14-AUG-07 14:19:13 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
14-AUG-07 14:38:03 GMT
The customer : lori.zhang@oracle.com : has uploaded the following file via MetaLink:
testcase.zip
14-AUG-07 14:39:20 GMT
New info : lori.zhang@oracle.com
we did a test and here is the testing result
we did this:
sql>alter session set events '10046 trace name context forever, level 12';
sql>@most_waited_sql_sample.txt
sql>alter session set events '10046 trace name context off'
the most_waited_sql_sample.txt and 10046 trace is uploaded.
14-AUG-07 14:55:35 GMT
RESEARCH
==========
FRom the 10046:-
PARSING IN CURSOR #6 len=275 dep=0 uid=37 oct=3 lid=37 tim=939431714834 hv=324275290 ad='e29dac88'
SELECT ZSXH,JKPZXH,TO_CHAR(YZFSRQ_JZ,:"SYS_B_0"),JKFSRQ,SKSS_SWJG_DM FROM SB_ZSXX WHERE YZPZXH = :"SYS
_B_1" AND NSRDZDAH = :"SYS_B_2" AND YZPZZL_DM = :"SYS_B_3" AND ((JKPZXH IS NOT N
ULL) OR (YZFSRQ_JZ IS NOT NULL)) AND TZLX_DM IN (:"SYS_B_4",:"SYS_B_5") ORDER BY
SKSS_SWJG_DM
END OF STMT
PARSE #6:c=0,e=951,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,tim=939431714831 <- missed
BINDS #6:
kkscoacd
Bind#0
oacdty=01 mxl=32(10) mxlc=00 mal=00 scl=00 pre=00
oacflg=10 fl2=0100 frm=01 csi=852 siz=32 off=0
kxsbbbfp=110504ef0 bln=32 avl=10 flg=09
value="YYYY-MM-DD"
Bind#1
oacdty=02 mxl=22(10) mxlc=00 mal=00 scl=00 pre=00
oacflg=10 fl2=0300 frm=00 csi=00 siz=24 off=0
kxsbbbfp=110504ea0 bln=22 avl=10 flg=09
value=237007900001151105
Bind#2
oacdty=02 mxl=22(10) mxlc=00 mal=00 scl=00 pre=00
oacflg=10 fl2=0100 frm=00 csi=00 siz=24 off=0
kxsbbbfp=110504e50 bln=22 avl=10 flg=09
value=710400100204354355
Bind#3
oacdty=01 mxl=32(03) mxlc=00 mal=00 scl=00 pre=00
oacflg=10 fl2=0300 frm=01 csi=852 siz=32 off=0
kxsbbbfp=110504e08 bln=32 avl=03 flg=09
value="190"
Bind#4
oacdty=01 mxl=32(01) mxlc=00 mal=00 scl=00 pre=00
oacflg=10 fl2=0300 frm=01 csi=852 siz=32 off=0
kxsbbbfp=110504dc0 bln=32 avl=01 flg=09
value="1"
Bind#5
oacdty=01 mxl=32(01) mxlc=00 mal=00 scl=00 pre=00
oacflg=10 fl2=0300 frm=01 csi=852 siz=32 off=0
kxsbbbfp=110504d78 bln=32 avl=01 flg=09
value="4"
Then a little later :-
PARSING IN CURSOR #2 len=275 dep=0 uid=37 oct=3 lid=37 tim=939431733340 hv=324275290 ad='e2
9dac88'
SELECT ZSXH,JKPZXH,TO_CHAR(YZFSRQ_JZ,:"SYS_B_0"),JKFSRQ,SKSS_SWJG_DM FROM SB_ZSXX WHERE YZPZXH = :"SYS_B_1" AND NSRDZDAH = :"SYS_B_2" AND YZPZZL_DM = :"
SYS_B_3" AND ((JKPZXH IS NOT NULL) OR (YZFSRQ_JZ IS NOT NULL)) AND TZLX_DM IN (:
"SYS_B_4",:"SYS_B_5") ORDER BY SKSS_SWJG_DM
END OF STMT
PARSE #2:c=0,e=753,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,tim=939431733337 <- missed again
BINDS #2:
kkscoacd
Bind#0
oacdty=01 mxl=32(10) mxlc=00 mal=00 scl=00 pre=00
oacflg=10 fl2=0100 frm=01 csi=852 siz=32 off=0
kxsbbbfp=110504ef0 bln=32 avl=10 flg=09
value="YYYY-MM-DD"
Bind#1
oacdty=02 mxl=22(10) mxlc=00 mal=00 scl=00 pre=00
oacflg=10 fl2=0300 frm=00 csi=00 siz=24 off=0
kxsbbbfp=110504ea0 bln=22 avl=10 flg=09
value=237007900004077704
Bind#2
oacdty=02 mxl=22(10) mxlc=00 mal=00 scl=00 pre=00
oacflg=10 fl2=0100 frm=00 csi=00 siz=24 off=0
kxsbbbfp=110504e50 bln=22 avl=10 flg=09
value=710400100204310161
Bind#3
oacdty=01 mxl=32(03) mxlc=00 mal=00 scl=00 pre=00
oacflg=10 fl2=0300 frm=01 csi=852 siz=32 off=0
kxsbbbfp=110504e08 bln=32 avl=03 flg=09
value="190"
Bind#4
oacdty=01 mxl=32(01) mxlc=00 mal=00 scl=00 pre=00
oacflg=10 fl2=0300 frm=01 csi=852 siz=32 off=0
kxsbbbfp=110504dc0 bln=32 avl=01 flg=09
value="1"
Bind#5
oacdty=01 mxl=32(01) mxlc=00 mal=00 scl=00 pre=00
oacflg=10 fl2=0300 frm=01 csi=852 siz=32 off=0
kxsbbbfp=110504d78 bln=32 avl=01 flg=09
value="4"
So - we can see this is not sharing. Even though we don't see the waits here we
know enough to tie it as the problem
The SQL uses the following plan:-
STAT #6 id=1 cnt=0 pid=0 pos=1 obj=0 op='SORT ORDER BY (cr=4 pr=0 pw=0 time=52 us)'
STAT #6 id=2 cnt=0 pid=1 pos=1 obj=36007 op='TABLE ACCESS BY GLOBAL INDEX ROWID SB
_ZSXX PARTITION: ROW LOCATION ROW LOCATION (cr=4 pr=0 pw=0 time=36 us)'
STAT #6 id=3 cnt=0 pid=2 pos=1 obj=36104 op='INDEX RANGE SCAN IDX_SB_ZSXX_YZPZXH (cr=4 p
r=0 pw=0 time=31 us)'
14-AUG-07 15:11:42 GMT
## GLOBAL CRITICAL ACTIVE ###
### CUSTOMER AND INTERNAL CONTACT INFORMATION###
### 1. Primary Technical Contact Details ###
### Customer Contact Name ###Lori,Zhang
### Primary Phone Number ###86-10-13910601263
### Secondary Phone Number ###
### Customer Email Address ###lori.zhang@oracle.com
### 2. Secondary Technical Contact Details ###
### Customer Contact Name ###
### Primary Phone Number ###
### Secondary Phone Number ###
### Customer Email Address ###
### 3. Customer Manager Name/Phone Number ###
### 4. Sending Engineer Full Name, AIM ID, and Phone Number ###
JAmes Cremonini (jcremoni)
### 5. If the SR is escalated, provide name/ID of previous escalation owner. ###
### SR HANDOFF DETAILS###
### 6. Is a warm hand off required? ###
*** YES *** Engineer to Engineer warm hand-off by telephone is always required
### 7. List all collaboration SRs ###
### Advanced Resolution SRs ###
### Translation SRs ###
### BDE RFA ###
### Other SRs ###
###TECHNICAL SUMMARY###
### 8. Problem Definition/Verification ###
Getting an enormous number of waits on cursor pin S wait on X
### 9. Data Collected: Customer Files/Test Case Locations(IP, user/pass, file spec/path) ###
###ACTION PLAN FOR NEXT SHIFT###
### 10. Action Plan for this issue ###
I have narrowed the problem down. What is happening is that the SQL causing the issue is:-
SELECT ZSXH,JKPZXH,TO_CHAR(YZFSRQ_JZ,:"SYS_B_0"),JKFSRQ,SKSS_SWJG_DM FROM
SB_ZSXX WHERE YZPZXH = :"SYS_B_1" AND NSRDZDAH = :"SYS_B_2" AND YZPZZL_DM = :"
SYS_B_3" AND ((JKPZXH IS NOT NULL) OR (YZFSRQ_JZ IS NOT NULL)) AND TZLX_DM IN (:
"SYS_B_4",:"SYS_B_5") ORDER BY SKSS_SWJG_DM
There are 1000s of versions of this SQL which is not being shared because of bind mismatch. Everytime they run it, it is c
reating a new child which requires the X pin and causes the problem. The SQL is
run an ENORMOUS number of times though
Where I am at is I have a 10046 which captures the SQL being run a few times and it is clear it is not being shared (ign
ore the fact it does not wait in the 10046 as that is because the issue was not
fully reproduced and only this one session called it anyway)
We need to determine:-
1) Why is the SQL not sharing (unsafe binds)
2) Is this a BUG
3) Are there any w/as' ?
### 11. Communications Plan: Next contact time ###
### 12. Preferred communication method ###
14-AUG-07 15:14:26 GMT
CTC DBPERF UPDATE
====================
Manual assign to scmiller.us
14-AUG-07 15:16:30 GMT
Taking over issue. Reviewing the current state. I'll update shortly.
Scott
14-AUG-07 15:38:23 GMT
Researching known issues with sql not being shared due to bind_mismatch
I'll update shortly
Scott
14-AUG-07 16:17:49 GMT
UPDATE
=======
Hi,
Now that the problem has been narrowed down to the "unsharing" of the following sql....
SELECT ZSXH,JKPZXH,TO_CHAR(YZFSRQ_JZ,:"SYS_B_0"),JKFSRQ,SKSS_SWJG_DM FROM
SB_ZSXX WHERE YZPZXH = :"SYS_B_1" AND NSRDZDAH = :"SYS_B_2" AND YZPZZL_DM = :"
SYS_B_3" AND ((JKPZXH IS NOT NULL) OR (YZFSRQ_JZ IS NOT NULL)) AND TZLX_DM IN (:
"SYS_B_4",:"SYS_B_5") ORDER BY SKSS_SWJG_DM
...due to bind mismatch, we'll now need to see why the bind mismatch.
1) To do so, we'll first need to look at the child cursors in V$SQL_BIND_METADATA. You may need to r
un your load again. Once the problem is in place again, you'll want to run your
query against V$SQL_SHARED_CURSOR to verify that this sql is indeed populating t
he view the the enourmous amount of unshared cursors with bind_mismatch as being
the problem,
SQL> spool
SQL> select * from v$sql_bind_metadata where address in (select address from
v$sql_shared_cursor where kglhdpar in (select address from v$sqlarea where
sql_id = '<sql_id of this statement from v$sql_shared_cursor>' ); -- sql_id is a varchar
2) We'll also want to get a cursortrace. To do this, while the load process is running, find the hash value of the probl
em sql statement being run...
sql> select hash_value, sql_text from v$sqlarea where sql_text like '%SELECT ZSXH,JKPZXH,TO_CHAR(YZFSRQ_JZ,:"SYS_B_0")%';
Then once you have that, you set the trace like so...
Note 296377.1 Handling and resolving unshared cursors/large version_counts
alter system set events
'immediate trace name cursortrace level 577, address <hash_value>';
(level 578/580 can be used for high level tracing (577=level 1, 578=level 2, 580=level 3)
This will write a trace file to user_dump_dest each time we try to reuse the cursor.
To turn off tracing use:-
alter system set events
'immediate trace name cursortrace level 2147483648, address 1';
-- if this was not to stop is, then do
alter system set events
'immediate trace name cursortrace level 2147483648, address <hash_value>';
## Keep an eye on this one. During the load, once you set this, keep an eye on your user_dump_dest. We only need about 15 traces generated. Since a
new trace will get generated everytime a cursor gets reused, it could generate
a lot of files. We only need about 15. After that, disable the event.
Then please upload the traces as well as the spool from v$sl_bind_data.
Thanks
Scott
14-AUG-07 16:17:56 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
14-AUG-07 16:45:06 GMT
New info : lori.zhang@oracle.com
pls hold on
14-AUG-07 18:00:07 GMT
The customer : lori.zhang@oracle.com : has uploaded the following file via MetaLink:
testcase2.zip
14-AUG-07 18:01:05 GMT
New info : lori.zhang@oracle.com
we run another test.
we opened a sqlplus session, and ran log.sql
before ran this sql, we cleared udump directory, and collect all dump file generated after run this sql.
also, we exported the v$sql_bind_metadata into an xls file.
all files should be found in uploaded zip file.
14-AUG-07 18:02:19 GMT
New info : lori.zhang@oracle.com
Scott, can I talk to you by AIM or anyother IM?
14-AUG-07 18:17:05 GMT
yes you can talk to me via aim....scmillerus
Scott
14-AUG-07 18:17:14 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
14-AUG-07 18:22:50 GMT
RESEARCH
=========
From sdtais1_ora_8020094.trc
listed many times throughout the file...
~~~
PARSING SQLTEXT=
SELECT ZSXH,JKPZXH,TO_CHAR(YZFSRQ_JZ,:"SYS_B_0"),JKFSRQ,SKSS_SWJG_DM FROM SB_ZSXX WHERE YZPZXH = :"SYS_B_1" AND NSRDZDAH = :"SY
S_B_2" AND YZPZZL_DM = :"SYS_B_3" AND ((JKPZXH IS NOT NULL) OR (YZFSRQ_JZ IS NOT
NULL)) AND TZLX_DM IN (:"SYS_B_4",:"SYS_B_5") ORDER BY SKSS_SWJG_DM
SQLHASH=13540c5a
Checking for already pinned child.
No valid child pinned
Parent 7000002e50e43b0(7000002e5bb0f90) ready for search
kksSearchChildList outside while loop
kksCheckCursor: next child is #15
kksCheckCursor: pinning child #15 in shared mode 7000002e40e8d28 7000002e5adba30
Calling for auth
Failed sharing : Privilage <**********************
kksUnlockChild: releasing child
Failed sharing : 12000
kksSearchChildList: no suitable child found
~~~
Researching further
Scott
14-AUG-07 18:28:10 GMT
New info : lori.zhang@oracle.com
SOS
it seemed cursortrace still opened even we have run "alter system set events 'immediate trace name cursortrace level
2147483648, address 324275290';"
trace file continue to gernerate, what should I do?
14-AUG-07 18:34:00 GMT
Did you do
alter system set events 'immediate trace name cursortrace level 2147483648, address 1';
as well?
Scott
14-AUG-07 18:34:07 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
14-AUG-07 18:42:49 GMT
UPDATE
=======
Hi,
Looking at the testcase you're running (log.sql), it seems that all that would be needed to reproduce this in house is would be to set cursor
_sharing, and them import the objects and stats, then run the query.
Could you upload a rows=n export of the objects needed to run this query, along with the
associated stats? I'll file a bug if I can reproduce this in house.
1) Rows=N export of the objects involved in the query, I shouldn't need any table data.
2) The objects associated optimizer statistics
Note.242489.1 Ext/Pub Transferring Optimizer Statistics to Support
Thanks
Scott
14-AUG-07 18:42:55 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
14-AUG-07 19:15:03 GMT
New info : lori.zhang@oracle.com
yes, both SQL ran
alter system set events 'immediate trace name cursortrace level 2147483648, address 1';
alter system set events 'immediate trace name cursortrace level 2147483648, address
324275290';
but can't stop
14-AUG-07 19:18:50 GMT
please try this....
alter session set events 'immediate trace name cursortrace level 128, address <address of cursor>';
scott
14-AUG-07 19:18:58 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
14-AUG-07 19:35:03 GMT
The customer : lori.zhang@oracle.com : has uploaded the following file via MetaLink:
case3.zip
14-AUG-07 19:36:02 GMT
New info : lori.zhang@oracle.com
Pls find dmp file in upload file
14-AUG-07 19:48:55 GMT
UPDATE
=======
Thanks. I apologize for the following. I found a bug which states that cursortrace cannot be disabled w/o restarting the db....
Bug.5555371 (80) NO WAY TO TURN OFF TRACE AFTER SETTING CURSORTRACE EVENT
If I would have known about this, I would not have had you set this event.
As far as the cursor sharing problem you are facing. There look to be two bugs being worked...
Bug.6215468 (10) SQL'S ARE HAVING HIGHER VERSION COUNT DUE TO BIND MISMATCH
Bug.5545550 (16) PERFORMANCE ISSUES AFTER UPGRADE TO 10.2.0.2 FROM 9.2.0.6
Neither look to be making any significant progress. Bind_mismatch means that the bin
d metadata does not match the existing child cursor. V$SQL_BIND_METADATA doesn't
seem to show this as being the case. It's also hard to see this being the case
as you are using literals, and oracle is converting these to binds.
I did find one more piece of information. It looks like the following event was created to
allow you to specify a character bind buffer length. Depending on the length us
ed, the character binds in the child cursor can all be created using the same
bind length;
Note.336268.1 High Version count due to BIND_MISMATCH invalidation
First I'll try and reproduce and then look further into this event. I'll update shortly with an update.
Thanks
Scott
14-AUG-07 19:49:03 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
14-AUG-07 20:24:43 GMT
importing object
14-AUG-07 20:46:04 GMT
New info : lori.zhang@oracle.com
I red Note:336268.1, and
1. ALTER SESSION SET EVENTS '10503 trace name context level 4096', forever';
2. run 20 similar literal SQL
3. check v$sqlarea for version count, it expected to be 1, but still 20
14-AUG-07 20:51:02 GMT
New info : lori.zhang@oracle.com
1 more infomation
after I set 10503 event introduced in Note:336268.1, although cursor version count is 20, but
bind_mismatch column in v$sql_shared_cursor for this sql are all "N", I checked
all columns in this view, all are "N" ... so, what's the reason make this
cursor cannot be shared?
14-AUG-07 20:56:55 GMT
UPDATE
=======
Hi,
I've almost got this imported. I need to test this out in house. At this point I don't have an answer because I don't think what you're seein
g is expected behavior. Let me see if I can reproduce this on my end. I'll updat
e shortly
Scott
14-AUG-07 20:57:06 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
14-AUG-07 21:10:05 GMT
New info : lori.zhang@oracle.com
I have to have a rest now, looking forward to your good news, thank you.
14-AUG-07 21:30:31 GMT
## GLOBAL CRITICAL ACTIVE ###
### CUSTOMER AND INTERNAL CONTACT INFORMATION###
### 1. Primary Technical Contact Details ###
### Customer Contact Name ###
### Primary Phone Number ###
### Secondary Phone Number ###
### Customer Email Address ###
### 2. Secondary Technical Contact Details ###
### Customer Contact Name ###
### Primary Phone Number ###
### Secondary Phone Number ###
### Customer Email Address ###
### 3. Customer Manager Name/Phone Number ###
### 4. Sending Engineer Full Name, AIM ID, and Phone Number ###
### 5. If the SR is escalated, provide name/ID of previous escalation owner. ###
### SR HANDOFF DETAILS###
### 6. Is a warm hand off required? ###
*** YES *** Engineer to Engineer warm hand-off by telephone is always required
### 7. List all collaboration SRs ###
### Advanced Resolution SRs ###
### Translation SRs ###
### BDE RFA ###
### Other SRs ###
###TECHNICAL SUMMARY###
### 8. Problem Definition/Verification ###
Ct running into performance problem doing a dataload test.
Event Waits Time (s) (ms) Time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
cursor: pin S wait on X 15,432,157 157,643 10 49.9 Concurrenc
latch: library cache 289,975 45,267 156 14.3 Concurrenc
kksfbc child completion 826,819 41,592 50 13.2 Other
cursor: mutex X 216,405,052 40,706 0 12.9 Concurrenc
CPU time 8,560 2.7
Prior owning analyst (jcremoni) narrowed the problem down to the following select statement
not getting shared....
SELECT ZSXH,JKPZXH,TO_CHAR(YZFSRQ_JZ,:"SYS_B_0"),JKFSRQ,SKSS_SWJG_DM FROM
SB_ZSXX WHERE YZPZXH = :"SYS_B_1" AND NSRDZDAH = :"SYS_B_2" AND YZPZZL_DM = :"
SYS_B_3" AND ((JKPZXH IS NOT NULL) OR (YZFSRQ_JZ IS NOT NULL)) AND TZLX_DM IN (:
"SYS_B_4",:"SYS_B_5") ORDER BY SKSS_SWJG_DM
...due to bind_mismatch
The sql is actually being run with literals and cursor_sharing=similar...
o example from log.txt in testcase.zip
~~~~~~~
SELECT ZSXH,JKPZXH,TO_CHAR(YZFSRQ_JZ,'YYYY-MM-DD'),JKFSRQ,SKSS_SWJG_DM FROM
SB_ZSXX WHERE YZPZXH = 237007900004531099 AND NSRDZDAH = 710400100204472010
AND YZPZZL_DM = '190' AND ((JKPZXH IS NOT NULL) OR (YZFSRQ_JZ IS NOT NULL))
AND TZLX_DM IN ('1','4') ORDER BY SKSS_SWJG_DM
~~~~~~~
I have been unable to find much on bind_mismatch, especially for system generated bind
variables with CURSOR_SHARING=SIMILAR.
I did find two bugs which haven't progressed much..
Bug.6215468 (10) SQL'S ARE HAVING HIGHER VERSION COUNT DUE TO BIND MISMATCH
BUG.5545550 (16) PERFORMANCE ISSUES AFTER UPGRADE TO 10.2.0.2 FROM 9.2.0.6
I also found the following note which mentions an event that can be set to alter the buffer
length of the bind (event 10503). The ct stated that when setting that event, all the sql's
still show up in v$sql_shared_cursor, but now all show "N" for a reason the cursor is not
shared.
I also had the ct do a cursortrace. The downside to this was finding Bug.5555371 after the f
act which
states that this event cannot be shutoff. Out of the 10 or so tracefiles generated, only one seemed
to have any significant info...
o From sdtais1_ora_8020094.trc
~~~
PARSING SQLTEXT=
SELECT ZSXH,JKPZXH,TO_CHAR(YZFSRQ_JZ,:"SYS_B_0"),JKFSRQ,SKSS_SWJG_DM FROM
SB_ZSXX WHERE YZPZXH = :"SYS_B_1" AND NSRDZDAH = :"SYS_B_2" AND YZPZZL_DM = :
"SYS_B_3" AND ((JKPZXH IS NOT NULL) OR (YZFSRQ_JZ IS NOT NULL)) AND TZLX_DM IN
(:"SYS_B_4",:"SYS_B_5") ORDER BY SKSS_SWJG_DM
SQLHASH=13540c5a
Checking for already pinned child.
No valid child pinned
Parent 7000002e50e43b0(7000002e5bb0f90) ready for search
kksSearchChildList outside while loop
kksCheckCursor: next child is #15
kksCheckCursor: pinning child #15 in shared mode 7000002e40e8d28
7000002e5adba30
Calling for auth
Failed sharing : Privilage <**********************
kksUnlockChild: releasing child
Failed sharing : 12000
kksSearchChildList: no suitable child found
~~~
To attempt to reproduce, I got a rows=n export dump from the ct and imported it into the
following env. I'm not able
to reproduce the bind_mismatch problem in v$sql_shared_cursor, but all the sql's do show up in v$sql_shared_cursor
and all reasons are "N"
rmtdcsol1
-u amrdbms/only4amrdbms
-sid amr123Sa
-oracle user ctaisd/test
o testcase
$ sqlplus ctaisd/test
SQL> alter session set cursor_sharing=similar;
SQL> @testcase_script.sql
SQL> SELECT sql_text,version_count,address
FROM V$SQLAREA
WHERE sql_text like '%SELECT ZSXH%';
SQL> SELECT * FROM V$SQL_SHARED_CURSOR WHERE address = 'address';
++++++
In recap, I haven't been able to see at this point, if the bind_mismatch is related to the "Failed sharing :
Privilage"
message in the cursortrace. The ct is able to reproduce the problem rather easily, just running the same sql 20 times
in the same session (testcase_script.sql) w/ cursor_sharing=similar.
Unless a valid explanation can be provided to the ct, it'd probably be best to file a bug. That was the reason I was tr
ying
to reproduce in house.
Thanks
Scott
### 9. Data Collected: Customer Files/Test Case Locations(IP, user/pass, file spec/path) ###
###ACTION PLAN FOR NEXT SHIFT###
### 10. Action Plan for this issue ###
### 11. Communications Plan: Next contact time ###
### 12. Preferred communication method ###
14-AUG-07 21:35:31 GMT
Allocation Type: A.B.C.
Product ID: 5.0 Component: RDBMS SubComponent: DBPERF
Skill ID: 5579.0 Description: DATABASE PERFORMANCE
Analyst Chosen: AMENDOZA.AU
Level 5.2
TAR General Flag set to: true
14-AUG-07 21:42:15 GMT
reviewing SR.
@wip
15-AUG-07 00:11:06 GMT
I was able to reproduce issue on a testcase and logged bug 6342722 for this issue.
@DEV
15-AUG-07 00:17:22 GMT
Severity 1 Request Id SEV1:6342722.33811 for Defect 6342722 has been ASSIGNED.
15-AUG-07 00:20:48 GMT
Associated bug 6342722 has been updated and is still at status: 16.
15-AUG-07 00:29:39 GMT
Lori,
Bug 6342722 doesn't satisfy criteria for severity 1 bug and was logged with severity=2.
If this is not acceptable to the ct, please provide/complete justification info for
escalation below:
=========================================================
Release Status of Customer system affected: ie: PRE-PRODUCTION
Does this affect a major Milestone? Go-Live
If yes, Milestone Date
Date by which the fix must be installed on customers system
Technical Impact of this bug: bug causes high version count of the sql causing severe
'cursor: pin S wait on X' waits in the database
Business Impact:
Is a Workaround Available? cursor_sharing=force
If Yes, Why is this unacceptable?
Additional Comments
==========================================================
Thanks,
Albert
15-AUG-07 00:29:48 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
15-AUG-07 00:46:01 GMT
New info : lori.zhang@oracle.com
Pls keep this issue in Sev. 1
=========================================================
Release Status of Customer system affected: PRE-PRODUCTION
Does this affect a major Milestone? Go-Live
Milestone Date: 2007-8-20
Date by which the fix must be installed on customers system:
2007-8-16
Technical Impact of this bug:
bug causes high version count of the sql causing severe 'cursor: pin S wait on X' waits in the database
Business Impact:
Go-live plan has been broadcasted to the whole province, this is a tax system of
a whole province, very important!
Is a Workaround Available?
cursor_sharing=force
If Yes, Why is this unacceptable?
Ct. has been tested functionality with "cursor_sharing=similar" for several months, and they have no time to test again
with "cursor_sharing=force" beforethis weekend.
Additional Comments
N/A
==========================================================
15-AUG-07 00:52:01 GMT
Escalation Request for bug 6342722 has been RECEIVED.
Details for this request may be viewed in the Defect Workbench.
Escalation Request Id: ESC:6342722.399595.
15-AUG-07 00:52:55 GMT
Requested bug escalation.
@DEV
15-AUG-07 01:03:37 GMT
Severity 1 Request Id SEV1:6342722.33811 for Defect 6342722 has been UPDATED.
Please File an escalation request for this bug.
15-AUG-07 01:03:41 GMT
Severity 1 Request Id SEV1:6342722.33811 for Defect 6342722 has been CLOSED.
15-AUG-07 01:20:49 GMT
Associated bug 6342722 has been updated and is still at status: 16.
15-AUG-07 02:04:08 GMT
## GLOBAL CRITICAL ACTIVE ###
### CUSTOMER AND INTERNAL CONTACT INFORMATION###
### 1. Primary Technical Contact Details ###
** Customer's Management 24x7 contact number: 86-10-13910601263
** Primary Customer contact name: Lori,Zhang
** Current Customer 24x7 voice phone number: 86-10-13910601263
** Current Customer Email address: kamusis@gmail.com
** Current Customer Pager/Fax number: N/A
### 4. Sending Engineer Full Name, AIM ID, and Phone Number ###
Albert Mendoza, amendozaau, +61 2 9491 1701
### 5. If the SR is escalated, provide name/ID of previous escalation owner. ###
### SR HANDOFF DETAILS###
### 6. Is a warm hand off required? ###
*** YES *** Engineer to Engineer warm hand-off by telephone is always required
### 7. List all collaboration SRs ###
### Advanced Resolution SRs ###
### Translation SRs ###
### BDE RFA ###
### Other SRs ###
###TECHNICAL SUMMARY###
### 8. Problem Definition/Verification ###
This is filed as bug 6342722 with a testcase.
This sql is not being shared and has too many versions causing high waits on 'cursor: pin S wait on X'
SELECT ZSXH,JKPZXH,TO_CHAR(YZFSRQ_JZ,:"SYS_B_0"),JKFSRQ,SKSS_SWJG_DM FROM SB_ZSXX WHERE YZPZXH = :"SYS_B_1" AND NSRDZ
DAH = :"SYS_B_2" AND YZPZZL_DM = :"SYS_B_3" AND ((JKPZXH IS NOT NULL) OR (YZFSRQ
_JZ IS NOT NULL)) AND TZLX_DM IN (:"SYS_B_4",:"SYS_B_5") ORDER BY SKSS_SWJG_DM
### 9. Data Collected: Customer Files/Test Case Locations(IP, user/pass, file sp
ec/path) ###
###ACTION PLAN FOR NEXT SHIFT###
### 10. Action Plan for this issue ###
Monitor bug 6342722. Escalation request is already filed with BDE.
Please chase BDE on escalation request.
### 11. Communications Plan: Next contact time ###
### 12. Preferred communication method ###
15-AUG-07 03:51:56 GMT
BDE Engineer VOBRIEN need to be contacted through PHONE at 61 404 052 687 for SEV1:6342722.33811 .
Confirmed to call Vicki O'BRIEN at 61 404 052 687
15-AUG-07 03:56:18 GMT
Allocation Type: A.B.C.
Product ID: 5.0 Component: RDBMS SubComponent: DBPERF
Skill ID: 5579.0 Description: DATABASE PERFORMANCE
Analyst Chosen: SHANNAMA.IN
Level 3.
TAR General Flag set to: true
15-AUG-07 04:28:07 GMT
Severity 1 Request Id SEV1:6342722.33811 for Defect 6342722 has been CLOSED.
15-AUG-07 07:21:36 GMT
Associated bug 6342722 has been updated and is still at status: 16.
15-AUG-07 09:34:27 GMT
## GLOBAL CRITICAL ACTIVE ###
### CUSTOMER AND INTERNAL CONTACT INFORMATION###
### 1. Primary Technical Contact Details ###
### Customer Contact Name ###Lori,Zhang
### Primary Phone Number ###86-10-13910601263
### Secondary Phone Number ###
### Customer Email Address ###kamusis@gmail.com
### 2. Secondary Technical Contact Details ###
### Customer Contact Name ###
### Primary Phone Number ###
### Secondary Phone Number ###
### Customer Email Address ###
### 3. Customer Manager Name/Phone Number ###
### 4. Sending Engineer Full Name, AIM ID, and Phone Number ###
Shanthi Annamalai / shanthiannamalai / 080 4107 2563
### 5. If the SR is escalated, provide name/ID of previous escalation owner. ###
### SR HANDOFF DETAILS###
### 6. Is a warm hand off required? ###
*** YES *** Engineer to Engineer warm hand-off by telephone is always required
### 7. List all collaboration SRs ###
### Advanced Resolution SRs ###
### Translation SRs ###
### BDE RFA ###
### Other SRs ###
###TECHNICAL SUMMARY###
### 8. Problem Definition/Verification ###
This is filed as bug 6342722 with a testcase.
This sql is not being shared and has too many versions causing high waits on
'cursor: pin S wait on X'
SELECT ZSXH,JKPZXH,TO_CHAR(YZFSRQ_JZ,:"SYS_B_0"),JKFSRQ,SKSS_SWJG_DM FROM SB_ZSXX WHERE YZPZXH =
:"SYS_B_1" AND NSRDZDAH = :"SYS_B_2" AND YZPZZL_DM = :"SYS_B_3" AND ((JKPZXH IS NOT NULL) OR
(YZFSRQ_JZ IS NOT NULL)) AND TZLX_DM IN (:"SYS_B_4",:"SYS_B_5") ORDER BY SKSS_SWJG_DM
### 9. Data Collected: Customer Files/Test Case Locations(IP, user/pass, file spec/path) ###
###ACTION PLAN FOR NEXT SHIFT###
### 10. Action Plan for this issue ###
Monitor bug 6342722.Please chase BDE on escalation request.
### 11. Communications Plan: Next contact time ###
### 12. Preferred communication method ###
15-AUG-07 09:38:57 GMT
Allocation Type: A.B.C.
Product ID: 5.0 Component: RDBMS SubComponent: DBPERF
Skill ID: 5579.0 Description: DATABASE PERFORMANCE
Analyst Chosen: JCREMONI.UK
Level 5.2
TAR General Flag set to: true
15-AUG-07 09:46:28 GMT
Escalation Request for bug 6342722 has been APPROVED.
Escalation Request Id: ESC:6342722.399595
15-AUG-07 09:52:04 GMT
Associated bug 6342722 has been updated and is still at status: 16.
*** Unable to lock tar for update ***
15-AUG-07 09:52:47 GMT
.
UPDATE
=======
Escalation request approved
Waiting for update in active bug
15-AUG-07 10:22:01 GMT
Associated bug 6342722 has been updated and is still at status: 16.
15-AUG-07 10:52:01 GMT
Associated bug 6342722 has been updated and has changed status to 32.
15-AUG-07 12:11:03 GMT
.
RESEARCH
=========
From bug:6342722
This is not a bug.
The statistics on this table have HISTOGRAMs on columns
used in equality predicates.
eg:
Column Histogram type
YZPZZL_DM FREQUENCY
YZPZXH FREQUENCY
TZLX_DM FREQUENCY
The YZPZXH predicate has different values in each query
but as this has a histogram on it the different values
each cause a different child cursor.
This is explained in more detail in Bug.4874738 (92) HIGH VERSION COUNT DUE TO UNSAFE BINDS:
Also
Note 377847.1
-----------------------
The usual reason for a literal to be marked UNSAFE is that it
is involved in a predicate with CBO where the column involved
has HISTOGRAM statistics. As soon as a column in an equality
predicate has HISTOGRAM stats then the literal in that predicate
is UNSAFE as CBO is using it for decisions about the plan.
.
The correct thing to do for statistics in an OLTP
type environment is to only use histograms on columns that need
it where there are only a few distinct values of predicate
with heavy skew where different plans are needed for the
different predicate values. This way most SQL is shared and
absence of histograms keeps predicates safe except where
needed.
.
CURSOR_SHARING=FORCE should not have the problem with sharing
as it does not care about unsafe literals, only about non data
literals for whom different values alter the actual meaning
of the SQL. (eg; order by 1 versus order by 2).
eg: In the above example with orderid='literal' without
histograms CBO does not need to look at 'literal'
to determine the selectivity of the predicate and
so the bind does not get marked unsafe.
15-AUG-07 12:14:16 GMT
.
UPDATE
=======
Hi Lori
Please see the explanations above
It seems that in yuor case the problem column is YZPZXH
Try removing histograms for this column or using cursor_sharing=force
I think it would be better to remove the histograms
ACTION PLAN
=============
Remove histograsm for column YZPZXH
See:
Note.390249.1 How To Quickly Add/Remove Column Statistics (Histograms) For A Column:
Regards
Dena
15-AUG-07 12:14:26 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
15-AUG-07 15:19:21 GMT
### GLOBAL CRITICAL PENDING ###
### CUSTOMER AND INTERNAL CONTACT INFORMATION###
### Customer Contact Name ###Lori,Zhang
### Primary Phone Number ###86-10-13910601263
### Secondary Phone Number ###
### Customer Email Address ###kamusis@gmail.com
### 4. Sending Engineer's Full Name, AIM ID, and Phone Number ###
Dena Feinblat denafil
### 5. If SR is escalated, provide name/ID of previous escalation owner ###
### SR HANDOFF DETAILS###
### 6. List all collaboration SRs ###
### Advanced Resolution SRs ###
### Translation SRs ###
### BDE RFA ###
### Other SRs ###
###TECHNICAL SUMMARY###
### 7. Problem Definition/Verification ###
filed as bug 6342722 with a testcase.
This sql is not being shared and has too many versions causing high waits on
'cursor: pin S wait on X'
SELECT ZSXH,JKPZXH,TO_CHAR(YZFSRQ_JZ,:"SYS_B_0"),JKFSRQ,SKSS_SWJG_DM FROM SB_ZSXX WHERE YZPZXH =
:"SYS_B_1" AND NSRDZDAH = :"SYS_B_2" AND YZPZZL_DM = :"SYS_B_3" AND ((JKPZXH IS NOT NULL) OR
(YZFSRQ_JZ IS NOT NULL)) AND TZLX_DM IN (:"SYS_B_4",:"SYS_B_5") ORDER BY SKSS_SWJG_DM
Bug closed as not a bug
Customer needs to Try removing histograms for this column or using cursor_sharing=force
### 8. Data Collected: Customer Files/Test Case Locations(IP, user/pass, file spec/path) ###
###ACTION PLAN FOR NEXT SHIFT###
### 9. Why is this SR at Pending Status and what is projected wakeup time? ###
### 10. Action plan for when the SR wakes up ###
### 11. Communications Plan: Next contact time ###
### 12. Preferred communication method ###
16-AUG-07 01:43:02 GMT
New info : lori.zhang@oracle.com
Thanks for your hard work, the last explaination is clear.
so, if Ct. is using "cursor_sharing=similar", then we should recommend Ct. not to use "method_opt => FOR ALL INDEXED COLUMNS" in dbms_stats.gather
_table_stat? since histograms statistics for columns will cause CBO not to shar
ing cursor.
16-AUG-07 01:57:30 GMT
CTC ACTION:
===========
Reassigning SR - owning analyst is off shift
16-AUG-07 01:58:46 GMT
Allocation Type: A.B.C.
Product ID: 5.0 Component: RDBMS SubComponent: DBPERF
Skill ID: 5579.0 Description: DATABASE PERFORMANCE
Analyst Chosen: BARUMUGA.IN
Level 3.
TAR General Flag set to: true
16-AUG-07 02:12:39 GMT
.
Hi ,
My name is Ramkumar. I have been assinged with this Sev1 Service Request.
I am currently reviewing/researching the situation and will update the SR /
call you as soon as we have relevant information. Thank you for your patience.
Best Regards,
Ramkumar
Oracle Support Services
STATUS
=======
@WIP -- Work In Progress
16-AUG-07 02:31:32 GMT
Hi,
You are correct when using "cursor_sharing=similar", we should not collect histograms for all the indexed coloumns
( "method_opt => FOR ALL INDEXED COLUMNS" in dbms_stats.gather_table_stat) . Histograms statistics for
columns will cause CBO not to sharing cursor.
Histograms statistics should only be collected for coloumns which has realy very skewed values.
Thanks,
Ram
16-AUG-07 02:31:49 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
16-AUG-07 06:25:05 GMT
New info : lori.zhang@oracle.com
1. set cursor_sharing=force, cursor shared, but Ct. can't accept this
2. delete histogram or "collect column histogram size 1" also make cursor shared, but Ct. is afraid of if they can't collect column hist
ogram, system performance maybe decreased due to execution plan may be not corr
ect without column histogram.
Also, still some question
we do test as follows:
CREATE TABLE TEST_SB_ZSXX AS SELECT * FROM SB_ZSXX WHERE ROWNUM<100;
CREATE INDEX TEST_IDX_SB_ZSXX_YZPZXH ON TEST_SB_ZSXX(YZPZXH);
then we collect table statistics with different method, run the same SQL 11 times, query the v$sql_shared_c
ursor for versioncount. we got different result.
1. DBMS_STATS.gather_table_stats('CTAISD','TEST_SB_ZSXX',CASCADE=>TRUE);
cursor shared
2. DBMS_STATS.gather_table_stats('CTAISD','TEST_SB_ZSXX',CASCADE=>TRUE,METHOD_OPT='FOR ALL COLUMNS SIZ
E 1');
cursor shared
3. DBMS_STATS.gather_table_stats('CTAISD','TEST_SB_ZSXX',CASCADE=>TRUE,METHOD_OPT='FOR ALL COLUMNS SIZE 2');
cursor *NOT* shared, and version count is 11
4. DBMS_STATS.gather_table_stats('CTAISD','TEST_SB_ZSXX',CASCADE=>TRUE,METHOD_OPT='FOR ALL COLUMNS SIZE 3');
cursor *NOT* shared, and version count is 11
5. DBMS_STATS.gather_table_stats('CTAISD','TEST_SB_ZSXX',CASCADE=>TRUE,METHOD_OPT='FOR ALL COLUMNS SIZE AUTO');
cursor *NOT* shared, and version count is 11
my question is, is the expected behavior is "if histogram exists, whatever how much bucket is, cursor will never shared"?
16-AUG-07 06:34:10 GMT
Hi,
With CURSOR_SHARING=SIMILAR whenever the optimizer looks at a replaced bind value to make a decision then that bind is considered unsafe. This occurs in a
few scenarios but the most common is with histogram statistics on an equality p
redicate. This can cause severe problems if you have , for example, a histogram
on a main key column.
eg: select ... from orders where orderid='literal';
If you have a histogram on "orderid" then the bind will likely get marked unsafe, s
o you will get a new
child for every single value of 'literal'. We would only share the SQL if the value of 'literal' matches exactly with a value used already
.
For more details there is a very good note on this topic.
See Note 418348.1
Title: High Loaded_Versions Count for SQL In V$SQLAREA despite using bind variables
Thanks,
Ram
16-AUG-07 06:34:17 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
16-AUG-07 11:35:05 GMT
### GLOBAL CRITICAL PENDING ###
### CUSTOMER AND INTERNAL CONTACT INFORMATION###
### Customer Contact Name ###Lori,Zhang
### Primary Phone Number ###86-10-13910601263
### Secondary Phone Number ###
### Customer Email Address ###kamusis@gmail.com
### 4. Sending Engineer's Full Name, AIM ID, and Phone Number ###
Ramkumar ,bsram79 , +91-80-41072373
### 5. If SR is escalated, provide name/ID of previous escalation owner ###
### SR HANDOFF DETAILS###
### 6. List all collaboration SRs ###
### Advanced Resolution SRs ###
### Translation SRs ###
### BDE RFA ###
### Other SRs ###
###TECHNICAL SUMMARY###
### 7. Problem Definition/Verification ###
filed as bug 6342722 with a testcase.
This sql is not being shared and has too many versions causing high waits on
'cursor: pin S wait on X'
SELECT ZSXH,JKPZXH,TO_CHAR(YZFSRQ_JZ,:"SYS_B_0"),JKFSRQ,SKSS_SWJG_DM FROM SB_ZSXX WHERE YZPZXH =
:"SYS_B_1" AND NSRDZDAH = :"SYS_B_2" AND YZPZZL_DM = :"SYS_B_3" AND ((JKPZXH IS NOT NUL
L) OR
(YZFSRQ_JZ IS NOT NULL)) AND TZLX_DM IN (:"SYS_B_4",:"SYS_B_5") ORDER BY SKSS_SWJG_DM
Bug closed as not a bug
Customer needs to Try removing histograms for this column or using cursor_sharing=force
### 8. Data Collected: Customer Files/Test Case Locations(IP, user/pass, file spec/pat
h) ###
###ACTION PLAN FOR NEXT SHIFT###
### 9. Why is this SR at Pending Status and what is projected wakeup time? ###
### 10. Action plan for when the SR wakes up ###
### 11. Communications Plan: Next contact time ###
### 12. Preferred communication method ###
20-AUG-07 11:42:20 GMT
Hi,
Please update the SR with your feed back on the status of the problem.
Also please let me know if you require any further assistance with this issue?
Thanks,
Ram
20-AUG-07 11:42:27 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
22-AUG-07 12:31:16 GMT
Hi,
Please let me know if you have any further questions on this regard.
If you feel your questions were answered.
Please let me know I shall proceed to close this SR.
Thanks,
Ram
22-AUG-07 12:31:22 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
23-AUG-07 16:53:21 GMT
Hi,
Please implement the above mentioned action plan.
This should resolve the problem.
I suggest that this TAR can be put in softclose status for the next 14 days.
If the error reoccurs after implementing the above changes then you can
update the TAR within the next 14 days. Otherwise no update is required
the TAR will close automatically after 14 days.
Thanks,
Ram
23-AUG-07 16:53:52 GMT
Email Update button has been pressed: Sending email to lori.zhang@oracle.com.
02-SEP-07 22:25:08 : CHANGES MADE VIA MetaLink
NOT YET FORWARDED TO OUR INTERNAL SYSTEMS :
New info : lori.zhang@oracle.com
Thanks for all your hard working, sorry for the late response, I just come back from vacation.
Pls close this TAR.
|
