I have a feint memory of hitting same problem at some point in distant
pass. Was very hard to solve but I do believe it ended up being a change to
a parameter and maybe is was CURSOR_SHARING which we might have set in a
logon trigger for the session somehow. Sorry can't recall more details.
On Tue, Nov 26, 2019 at 9:45 AM Andy Wattenhofer <watt0012@xxxxxxx> wrote:
This was going to be my question as well, do you have
cursor_sharing=FORCE? And I would also ask you to look at what the sessions
that are running the bind variable SQL are waiting on all that time (query
v$session_wait for one of the waiting sessions). Are you seeing "cursor
mutex x"?
There's a problem in >=12.2 databases where you can get a high child
cursor count leading to library cache contention (on cursor mutex) for a
single SQL. This stems from the fact that the hidden parameter
_cursor_obsolete_threshold went up from 1024 in 12.1 to 8192 in 12.2 to
accommodate the higher number of possible pluggable databases allowed in
12.2. This can lead to high child cursor version counts in the thousands
that then cause the aforementioned contention, whereas in 12.1 it would
have been limited to 1024. Running a database with cursor_sharing=FORCE can
make the problem much worse.
Jonathan Lewis explains the basis of the problem in his 2007 post here:
https://jonathanlewis.wordpress.com/2007/01/05/bind-variables/. ;(I would
note additionally that with extended varchars enabled in the database there
are some additional bind variable allocation sizes--8192, 16386, and
32768--which can make the problem worse yet again.)
A quick way to check for this problem is to query "select * from
gv$sqlarea where version_count>1000" and look for the problem SQL in the
result set. Also look for the cursor mutex x waits I mentioned before.
Check it out.
A quick one-time fix is to exec dbms_shared_pool.purge() on the offending
SQL.
You can also use dbms_shared_pool.markhot to sort of work around the
problem if it is isolated to this one SQL. And the more permanent fix that
Oracle support might recommend is to set _corsor_obsolete_threshold=1024 to
revert back to the 12.1 setting.
On Tue, Nov 26, 2019 at 10:12 AM Jonathan Lewis <
jonathan@xxxxxxxxxxxxxxxxxx> wrote:
One other point I forgot to mention.
It's a little unusual to see "rownum < :bindvariable". Do the bind
variables take the form :SYS_B_nnnn ? This would indicate that they have
been created by Oracle in response to the cursor_sharing parameter being
set to something other than EXACT.
Regards
Jonathan Lewis
________________________________________
From: oracle-l-bounce@xxxxxxxxxxxxx <oracle-l-bounce@xxxxxxxxxxxxx> on
behalf of Steve Wales (AddOns) <steve.wales@xxxxxxxxxxxxx>
Sent: 26 November 2019 01:23
To: oracle-l@xxxxxxxxxxxxx
Subject: Query with Bind variables hangs but hard coded literals works
fine
Sorry for the length of this up front. Trying to get as much relevant
info into the initial post as people might need to point me where I’m
getting the problem
I have an Oracle 18c (18.8 if it matters) Standard Edition 2 database on
Linux 7..
There’s a query from the ERP system that’s hanging the online screen and
getting http timeouts because it’s not completing in a timely fashion.
I pulled the text of the query from v$sqltext and the bind variables from
v$sql_bind_capture.
The query is searching a parts catalog for colloquial names for parts.
If I take the query, replace the bind variables from the query with
string values and run it through SQLPLUS, it runs in about 0.7 seconds and
returns the expected values.
If I instead leave the bind variables in the query, and in SQLPLUS define
variables and then assign values via exec :v1 := ‘SOMEVALUE’, then it sits
and spins 57 MINUTES before returning the exact same result set.
The execution plans change slightly but significantly as well.
The tables:
MSF100 is a stock catalog table. Contains all stock items that the
business catalogs across all properties
MSF170 is a table that busts up the global catalog among assorted
business units
MSF120 contains the colloquial names. If I search on “ACTUATOR” it can
return me all the stock codes that have “ACTUATOR” as a colloquial name.
I assume rownum <= 20 is specified because that’s how many rows fit on a
screen at a time.
select * from( select * from MSF100 CATALOG where (CATALOG.stock_code in
(select MSF170Rec.stock_code from MSF170 MSF170Rec, MSF100 MSF100Rec
where (MSF100Rec.stock_code = MSF170Rec.stock_code))) and ( exists
(select 1 from MSF120 MSF120Rec where (MSF120Rec.colloq_code =
CATALOG.stock_code
and MSF120Rec.colloq_name like '%ACTUATOR%' and MSF120Rec.colloq_type =
'S' )) or exists (select 1 from MSF120 MSF120Rec
where (MSF120Rec.colloq_code = CATALOG.template_id and
MSF120Rec.colloq_name like '%ACTUATOR%' and MSF120Rec.colloq_type = 'I' )))
and (CATALOG.stock_status <> 'X' ) order by CATALOG.stock_code ) where
ROWNUM <= 20;
When using the static values (and I apologize in advance for what
proportional fonts do the formatting below)
(Estimated plans generated just by doing good old “explain plan for”)
---------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes
|TempSpc| Cost (%CPU)| Time |
---------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 3243 |
| 5756 (1)| 00:00:01 |
|* 1 | COUNT STOPKEY | | | |
| | |
| 2 | VIEW | | 1 | 3243 |
| 5756 (1)| 00:00:01 |
|* 3 | SORT ORDER BY STOPKEY | | 1 | 3243 |
| 5756 (1)| 00:00:01 |
| 4 | VIEW | VM_NWVW_2 | 1 | 3243 |
| 5756 (1)| 00:00:01 |
| 5 | HASH UNIQUE | | 1 | 785 |
| 5756 (1)| 00:00:01 |
|* 6 | FILTER | | | |
| | |
| 7 | NESTED LOOPS SEMI | | 1 | 785 |
| 5751 (1)| 00:00:01 |
|* 8 | HASH JOIN | | 1 | 775 |
5632K| 5751 (1)| 00:00:01 |
| 9 | INDEX FAST FULL SCAN| MSF170_PK | 262K| 2559K|
| 265 (1)| 00:00:01 |
|* 10 | TABLE ACCESS FULL | MSF100 | 74750 | 54M|
| 2466 (1)| 00:00:01 |
|* 11 | INDEX UNIQUE SCAN | MSF100_PK | 83735 | 817K|
| 0 (0)| 00:00:01 |
| 12 | INLIST ITERATOR | | | |
| | |
|* 13 | INDEX RANGE SCAN | MSF12001I1 | 1 | 49 |
| 4 (0)| 00:00:01 |
---------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter(ROWNUM<=20)
3 - filter(ROWNUM<=20)
6 - filter( EXISTS (SELECT 0 FROM "MSF120" "MSF120REC" WHERE
("MSF120REC"."COLLOQ_CODE"=:B1 AND
"MSF120REC"."COLLOQ_TYPE"='S' OR
"MSF120REC"."COLLOQ_CODE"=:B2 AND
"MSF120REC"."COLLOQ_TYPE"='I') AND
"MSF120REC"."COLLOQ_NAME" LIKE '%ACTUATOR%'))
8 - access("CATALOG"."STOCK_CODE"="MSF170REC"."STOCK_CODE")
10 - filter("CATALOG"."STOCK_STATUS"<>'X')
11 - access("MSF100REC"."STOCK_CODE"="MSF170REC"."STOCK_CODE")
13 - access(("MSF120REC"."COLLOQ_CODE"=:B1 AND
"MSF120REC"."COLLOQ_TYPE"='S' OR
"MSF120REC"."COLLOQ_CODE"=:B2 AND
"MSF120REC"."COLLOQ_TYPE"='I'))
filter("MSF120REC"."COLLOQ_NAME" LIKE '%ACTUATOR%')
When using bind variables (Yes, I know that the columns are all defined
as CHAR instead of VARCHAR2. No, I don’t know why the vendor of this
application insists on presenting their database that way):
variable v1 char(24 char)
variable v2 char(1 char)
variable v3 char(24 char)
variable v4 char(1 char)
variable v5 char(1 CHAR)
variable v6 number
exec :v1 := '%ACTUATOR% ';
exec :v2 := 'S';
exec :v3 := '%ACTUATOR% ';
exec :v4 := 'I';
exec :v5 := 'X';
exec :v6 := 20;
select * from( select * from MSF100 CATALOG where (CATALOG.stock_code in
(select MSF170Rec.stock_code from MSF170 MSF170Rec, MSF100 MSF100Rec
where (MSF100Rec.stock_code = MSF170Rec.stock_code))) and ( exists
(select 1 from MSF120 MSF120Rec where (MSF120Rec.colloq_code =
CATALOG.stock_code
and MSF120Rec.colloq_name like :v1 and MSF120Rec.colloq_type = :v2 ))
or exists (select 1 from MSF120 MSF120Rec
where (MSF120Rec.colloq_code = CATALOG.template_id and
MSF120Rec.colloq_name like :v3 and MSF120Rec.colloq_type = :v4 )))
and (CATALOG.stock_status <> :v5 ) order by CATALOG.stock_code ) where
ROWNUM <= :v6;
------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost
(%CPU)| Time |
------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 3243 |
192K (1)| 00:00:08 |
|* 1 | COUNT STOPKEY | | | |
| |
| 2 | VIEW | | 1 | 3243 |
192K (1)| 00:00:08 |
|* 3 | SORT ORDER BY STOPKEY | | 1 | 755 |
192K (1)| 00:00:08 |
|* 4 | FILTER | | | |
| |
| 5 | NESTED LOOPS SEMI | | 3 | 2265 |
192K (1)| 00:00:08 |
|* 6 | TABLE ACCESS FULL | MSF100 | 63173 | 45M| 2466
(1)| 00:00:01 |
| 7 | VIEW PUSHED PREDICATE | VW_NSO_1 | 12 | 24 | 3
(0)| 00:00:01 |
| 8 | NESTED LOOPS | | 262K| 5120K| 3
(0)| 00:00:01 |
|* 9 | INDEX UNIQUE SCAN | MSF100_PK | 1 | 10 | 1
(0)| 00:00:01 |
|* 10 | INDEX RANGE SCAN | MSF17001I1 | 262K| 2560K| 2
(0)| 00:00:01 |
|* 11 | INDEX FAST FULL SCAN | MSF120_PK | 1 | 49 | 476
(1)| 00:00:01 |
------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter(ROWNUM<=TO_NUMBER(:V6))
3 - filter(ROWNUM<=TO_NUMBER(:V6))
4 - filter( EXISTS (SELECT 0 FROM "MSF120" "MSF120REC" WHERE
"MSF120REC"."COLLOQ_TYPE"=:V2 AND "MSF120REC"."COLLOQ_NAME"
LIKE :V1 AND
"MSF120REC"."COLLOQ_CODE"=:B1 OR
"MSF120REC"."COLLOQ_TYPE"=:V4 AND
"MSF120REC"."COLLOQ_NAME" LIKE :V3 AND
"MSF120REC"."COLLOQ_CODE"=:B2))
6 - filter("CATALOG"."STOCK_STATUS"<>:V5)
9 - access("MSF100REC"."STOCK_CODE"="CATALOG"."STOCK_CODE")
10 - access("MSF170REC"."STOCK_CODE"="CATALOG"."STOCK_CODE")
filter("MSF100REC"."STOCK_CODE"="MSF170REC"."STOCK_CODE")
11 - filter("MSF120REC"."COLLOQ_TYPE"=:V2 AND "MSF120REC"."COLLOQ_NAME"
LIKE
:V1 AND "MSF120REC"."COLLOQ_CODE"=:B1 OR
"MSF120REC"."COLLOQ_TYPE"=:V4 AND
"MSF120REC"."COLLOQ_NAME" LIKE :V3 AND
"MSF120REC"."COLLOQ_CODE"=:B2)
The CPU cost on this second query is orders of magnitude greater than the
other way. I can only assume that this is why my CPU on the server goes
into overdrive as it sits and thinks forever before the http server throws
it’s hands up and gets sick of waiting.
This database was just upgraded to 18.8 from 12.1.0.2 over the weekend.
(Vendor hasn’t certified the product for 19c yet, hence the upgrade to 18c).
This was not a problem with 12.1.0.2 SE2.
One last thing, since this is an ERP package, I can’t change the code /
insert hints / build new indexes (well I suppose I could do that but the
next release upgrade would blow it away anyway). Any solution really has
to be about a config / parameter change (but if an index would work, I
suppose I’d be willing to try it as a work around for the time being).
Thanks in advance for any pointers. I’m hoping that there’s an init
parameter or something that was new in the 12.2 engine from 12.1 that might
be causing the problem.
Steve
Disclaimer
The information contained in this communication from the sender is
confidential. It is intended solely for use by the recipient and others
authorized to receive it. If you are not the recipient, you are hereby
notified that any disclosure, copying, distribution or taking action in
relation of the contents of this information is strictly prohibited and may
be unlawful.
This email has been scanned for viruses and malware, and may have been
automatically archived.
--
//www.freelists.org/webpage/oracle-l
