Re: Long Parse Time for a big Statement

From: Jonathan Lewis <jlewisoracle_at_gmail.com>
Date: Tue, 18 Jan 2022 10:18:40 +0000
Message-ID: <CAGtsp8n4n8Nvkg7Mw1MOXwYa2F1Hquvf7JFTF2f=5HcAehKJLg_at_mail.gmail.com>



  1. Yes, it works through opt_param()
  2. At what level did you set the fix_control ? In my test which produced 150 simple query blocks in the OR expansion/UNION ALL I had to set the value down to 2 before I saw any TIMER lines. (i.e reported for operation taking no more than 100 microseconds). Here's the output when I set the time down to 3 (1000 microseconds)
TIMER: Enhanced Filter Push SEL$1 cpu: 0.001349 sec elapsed: 0.001330 sec
TIMER:      bitmap access paths cpu: 0.071115 sec elapsed: 0.072790 sec
TIMER:     costing general plans cpu: 0.001136 sec elapsed: 0.000252 sec
TIMER:      bitmap access paths cpu: 0.063583 sec elapsed: 0.065344 sec
====> TIMER: CBQT OR expansion SEL$765CDFAA cpu: 6.001899 sec elapsed: 6.035463 sec
TIMER: CBQT SU and CVM SEL$765CDFAA cpu: 0.007887 sec elapsed: 0.008221 sec TIMER: Set Join Conversion SEL$765CDFAA cpu: 0.002380 sec elapsed: 0.002034 sec
====> TIMER: Complex View Merging SEL$765CDFAA cpu: 1.085488 sec elapsed: 1.143670 sec
TIMER: Filter Predicate Pull-Up SEL$765CDFAA cpu: 0.002809 sec elapsed: 0.003552 sec
TIMER: Vector Transformation SEL$765CDFAA cpu: 0.002977 sec elapsed: 0.004715 sec
TIMER: Bushy Join SEL$765CDFAA cpu: 0.005894 sec elapsed: 0.005136 sec TIMER: Group-By Placement SEL$765CDFAA cpu: 0.002926 sec elapsed: 0.003105 sec
TIMER: Table Expansion SEL$765CDFAA cpu: 0.005895 sec elapsed: 0.006072 sec TIMER: CBQT OR expansion SEL$765CDFAA cpu: 0.003969 sec elapsed: 0.003785 sec
TIMER: Star Transformation SEL$765CDFAA cpu: 0.027056 sec elapsed: 0.028752 sec
TIMER: Join Factorization SEL$765CDFAA cpu: 0.004729 sec elapsed: 0.004946 sec
TIMER: Cost-Based Join Predicate Push-Down SEL$765CDFAA cpu: 0.003886 sec elapsed: 0.003329 sec
TIMER: Statistic-based Query Transformation SEL$765CDFAA cpu: 0.001004 sec elapsed: 0.001565 sec
TIMER: Type Checking after CBQT SEL$765CDFAA cpu: 0.134407 sec elapsed: 0.135799 sec
====> TIMER: Cost-Based Transformations (Overall) SEL$765CDFAA cpu: 8.297454 sec elapsed: 8.420433 sec
TIMER: bitmap access paths cpu: 0.037322 sec elapsed: 0.039807 sec ====> TIMER: Access Path Analysis (Final) SEL$765CDFAA cpu: 4.477809 sec elapsed: 4.652031 sec
====> TIMER: SQL Optimization (Overall) SEL$765CDFAA cpu: 12.863282 sec elapsed: 13.198398 sec

I've highlighted all the lines which report more than 1 seconds (the default value for the fix is 6). Critically the first pass of OR expansion spends a huge amount of time on optimising all the branches of the UNION ALL, but none of the branches takes a significant amount of time.

In your case you've got a 55 part union all to start with, and then massive OR-expansion of each of the 55 branches - I can't imagine how many branches of sub-millisecond events you would have if you set the event to level 2.

Regards
Jonathan Lewis

On Tue, 18 Jan 2022 at 08:39, Lothar Flatz <l.flatz_at_bluewin.ch> wrote:

> HHi Jonathan,
>
> thanks. It seems I need a similar statement that does parse without
> error. I need to do furter tests, e.g. how big the influence of the case
> statement is.
> Current testing is tricky, since the result "it failed quicker" than
> without the hint is not a base I want to work with.
> Would you know by hard if opt_param works with "_no_or_expansion"?
> I used "_fix_control"='16923858 without getting an TIMER entries in the
> optimizer trace. Do you know a possible reason?
> BTW:
>
> Thanks
>
> Lothar
>
> Am 17.01.2022 um 15:06 schrieb Jonathan Lewis:
>
> If this is a common problem, and not susceptible to SQL Patch treatment,
> or the addition of /*+ no_or_expand */ hints at the start of the query
> pattern, then you could brute force it by setting "_no_or_expansion" to
> true if you can identify the sessions that need it, or just set it
> system-wide. You should get much faster optimization times - though the 55
> way union all would have to be optimized in 55 parts.
>
> Regards
> Jonathan Lewis
>
>
> On Mon, 17 Jan 2022 at 12:59, Lothar Flatz <l.flatz_at_bluewin.ch> wrote:
>
>> Hi,
>>
>> At one customer site we see generated statements, actually reports. The
>> parsetime for such a statement is over an hour, if it finishes at all.
>> It is possible we see "ORA-04031:" when we run out of memory in the
>> shared pool.
>> How big these statements are is hard to tell, since it depends on
>> formatting. With sql developer formatting i get in one typical example >
>> 130000 lines.
>> The statements are constructed relatively simple.
>> It seems to be a kind of change report where columns from different
>> tables are retrieved.
>> At the beginning is a big case statement where a meaningful name is
>> generated for a value followed by this values. I counted 7400 case
>> entries as per statement in one case.
>> I addition we have a number of big inlists.
>> All this is running against a union view of 55 Tables.
>> In other words: If i want to stress the parser I would construct a
>> statement exactly like this.
>> However, one hour seems to be a unrealistically long parse time.
>> Even though that statement needs to be rewritten, but this will take time.
>> I want to know if there is any quick fix like increasing the shared pool
>> a lot. (Which I can't test unfortunately any time soon due lack of
>> memory).
>> Any ideas how to speed up the parse time?
>>
>> Database version is 19.7. Shared Pool size is 20GB
>>
>> Thanks
>>
>> Lothar
>> --
>> http://www.freelists.org/webpage/oracle-l
>>
>>
>>
>

--
http://www.freelists.org/webpage/oracle-l
Received on Tue Jan 18 2022 - 11:18:40 CET

Original text of this message