A couple of important points:
a) v$sql_bind_capture may not hold the values that were used to optimise the
query; you should use dbms_xplan.display_cursor() to pull the plan from memory
once you've found it in one of the v$sql views. Probably best to include a
couple of extra format options:
select * from table(dbms_xplan.display_cursor('{sqlid},{child_number},'outline
peeked_binds'))
b) EXPLAIN PLAN doesn't peek at bind variables, so treats everything as worst
case unknown in its arithmetic. Including the threat that it may have to
produce a plan that is correct even when an incoming bind value is NULL.
(Notice how your "number v6" reappears as a to_number() in the predicate
section of the plan - that's because Oracle hasn't even looked at the type of
the variable you've declared.
The OUTLINE is, in effect, a set of hints that will show us some of the details
of what Oracle has done that may help us determine if there's some feature you
could switch off to get a better plan - but until we definitely have the
"right" bad plan it's not worth pursuing that path.
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
