Re: Query with Bind variables hangs but hard coded literals works fine

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_at_umn.edu> 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_at_jlcomp.demon.co.uk> 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_at_freelists.org <oracle-l-bounce_at_freelists.org> on
>> behalf of Steve Wales (AddOns) <steve.wales_at_addonsinc.com>
>> Sent: 26 November 2019 01:23
>> To: oracle-l_at_freelists.org
>> 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.
>> --
>> http://www.freelists.org/webpage/oracle-l
>>
>>
>>

--
http://www.freelists.org/webpage/oracle-l