Re: Query performance issue

From: Tim Gorman <tim.evdbt_at_gmail.com>
Date: Wed, 23 Oct 2024 07:58:21 -0700
Message-ID: <0a4671c0-a65d-4ca2-80bd-2d0ec5e37fbc_at_gmail.com>





Pap,

With regards to your opening statement...

 >> /Not able to get the trace somehow with current privileges/

...I strongly recommend asking those with the proper permissions to obtain the traces and TKPROF output instead.  It is part of their job.

It is extremely painful and laborious to attempt to tune a SQL statement based on guesses, without hard information.  I strongly recommend against it.  In fact, I even recommend refusing to attempt it.

Guessing is almost always a complete waste of time.  Only occasionally is a solution found, and when it is, there is usually little understanding why the solution worked, leaving the underlying problem unresolved.

Tracing and TKPROF is a standard part of Oracle functionality, and it should always be available for (and used by) anyone attempting to optimize the performance (or troubleshoot) SQL statements.

At the same time, it can also seem like a huge waste of time for the DBA team to shepherd someone through the process of obtaining traces or TKPROF output.  Hopefully, the attached "trc_it.sh" shell script (or something similar) and method of interaction lubricates and enables the process?

So, to make the task easier, I provide them with both a SQL script which contains the SQL statement(s) I'd like to trace, as well as a shell script similar to the attached (i.e. "trc_it.sh"), which will run the provided SQL script with extended 10046 tracing enabled, then find the trace file, run TKPROF on it, then compress the trace file and finally email the compressed trace file along with the TKPROF output back to me.

I can't guarantee that the attached shell script will work in your environment "as is", but I have used scripts similar to it over the past decades consistently.  Most DBA teams welcome such a script, once they've had a chance to walk through it and realize that it isn't doing anything nefarious.  The good thing is that they can keep the shell script for repeated uses, once it has been vetted as safe.

I hope this helps?

-TIm

However, We popula

On 10/22/2024 10:43 PM, Pap wrote:
>
> Not able to get the trace somehow with current privileges. Also
> removed the UNION and made it UNION ALL but not seeing much difference.
>
> However, We populated a postgres and a mysql database with exactly the
> same data and also created the same index and in the timing wise there
> is big difference but then i tried picking up the section of the plan
> which looks similar in both but just the difference in time. Does it
> point to the difference in underlying hardware(cpu/memory/io etc) or
> is it pointing to the difference in the optimization strategy or index
> architecture between the two databases. What should be our conclusion?
> Though I was expecting, as the index is btree it should behave
> similarly in both the databases.
>
> Note:-The mysql is a serverless aws instance here vs the postgres one
> is provisioned aws instance (r7gl). but we have these tables that hold
> max some hundred thousands rows in them and <5Gb in size so does
> infrastructure make any difference here?
>
> https://gist.github.com/databasetech0073/746353a9e76d5e29b2fc6abdc80cdef8
>
> In mysql plan:-
> -> Index lookup on EX_STS using EX_STS_INDEX (AID=b3.AID,
> RC_ID=b3.RC_ID, RC_VNB=b3.RC_VNB)  (cost=0.43 rows=2) (actual
> time=0.014..0.021 rows=2 loops=70904)
> VS
> In postgres plan:-
> -> Index Scan using EX_STS_INDEX on RCE_STS EX_STS  (cost=0.42..0.82
> rows=1 width=424) (actual time=0.006..0.007 rows=2 loops=70904)
>
>
> **********
>
> In mysql plan
> -> Covering index lookup on mns using M_INF_AID_index
> (AID='XXXXXXXXXXXXXXXXXXX')  (cost=9187.54 rows=72748) (actual
> time=0.058..19.637 rows=35980 loops=1)
> -> Filter: (RNS.ASID = 'XXXXXXXXXXXXXXXXXXX')  (cost=43.50 rows=42)
> (actual time=0.042..0.218 rows=97 loops=1)
> VS
> In postgres plan
> ->  Bitmap Index Scan on M_INF_AID_index  (cost=0.00..406.98
> rows=36074 width=0) (actual time=0.790..0.790 rows=35980 loops=1)
>
> On Wed, Oct 16, 2024 at 10:25 PM yudhi s <learnerdatabase99_at_gmail.com>
> wrote:
>
> Not aware about if any "mysql" list exists. But I know there
> exists tracing in mysql which shows the details around optimizer
> decisions behind choosing certain execution path. You may try to
> see if you get any clue there.
>
> Set optimizer_trace="enabled=on"
> Select  * from information_schema.optimizer_trace;
>
> On Wed, 16 Oct, 2024, 3:52 pm Mark W. Farnham, <mwf_at_rsiz.com> wrote:
>
> The first question whenever there is a question about the
> performance of a query involving UNION is whether or not any
> members of the UNION are known to certainly be disjoint from
> each other.
>
> The deduplication part of UNIONs is expensive, so if UNION ALL
> to combine any of the component queries is valid, then that
> can make a big difference.
>
> IF the UNION (de-duplicating, not ALL) is required for
> information correctness, but a small subset of the columns can
> be used for certain de-duplication, then using that small
> subset of columns to generate a de-duplicated list of rowids
> (or a set of index matching columns) either in memory or into
> an interim filtering table then used to bring back all the
> required columns **MAY** be faster, which is dependent on the
> actual data.
>
> Regardless of whether de-duplication is required, assessing
> the sum of the run times of each component of the UNION run
> separately is a quick test to see whether (or not) this avenue
> of exploration could be faster and the likely ceiling of the
> improvement.
>
> Since de-duplication runs on the order of n log n (at best),
> it may also be possible to mutually partition some queries
> such that the sum of nx log nx for each x dependent on the
> number of rows in each partition is much less than n log n.
> Then the de-duplicated “partitions” (in the general meaning of
> the word, not Oracle partitions) can be combined with UNION
> ALL. Checking the ceiling of the possible time saving should
> be evaluated before pursuing such complications.
>
> Good luck.
>
> *From:*oracle-l-bounce_at_freelists.org
> [mailto:oracle-l-bounce_at_freelists.org] *On Behalf Of *Pap
> *Sent:* Wednesday, October 16, 2024 12:40 AM
> *To:* Oracle L
> *Subject:* Query performance issue
>
> Hello Listers,
> We have a query below which is running for ~40 seconds. As
> it's a query which is executed from UI , we were expecting it
> to finish in <~5 seconds. It has a "IN" and a "NOT IN"
> subquery , from the execution path it seems the total response
> time is mainly, to be sum of the "IN" and the "NOT IN"
> subquery section. My thought was that both "IN" and "NOT IN"
> should be executed/evaluated in parallel but not in serial
> fashion.
>
> In the execution path below , the line number marked in bold
> are the top lines for the IN and NOT IN subquery evaluation
> and they are showing "Actual time" as  Approx ~9 seconds and
> ~8 seconds and they seems to be summed up and the top lines
> showing it to be ~19 seconds. Then onwards it keeps on
> increasing with other "nested loop" joins.
>
> *Note*:- This query is running on a MYSQL 8.0 database. So I'm
> wondering if there is any mysql list similar to Oracle list ,
> in which i can share this issue?
>
> Added the query in below path:-
>
>
> https://gist.github.com/databasetech0073/95bce00c3a6bd4ae8d195401e0383185
>
> SELECT ......
> FROM R_CON_ESTS RC_STS,
>      R_CON rc,
>      D_LKP D_LKP_STS,
> D_LKP D_LKP_FRQ,
>  (select RCE.DRV_DT, RCE.AID, RCE.R_CON_ID, RCE.R_CON_VER_NB
> from R_CON_E RCE
> where RCE.MTNE_ID in (SELECT  MI1.MTNE_ID
>   FROM M_INF mi1 WHERE MI1.AID = :AID
>   UNION
>   SELECT rg.RG_MF_SK_ID
>  from RG_M_F_INF rg where rg.AS_ID =:AID
>   UNION
>   SELECT fti.FT_SRK_ID
> from M_FT fti where fti.AS_ID= :AID
> )
>  and (RCE.DRV_DT, RCE.AID, RCE.R_CON_ID, RCE.R_CON_ver_nb) NOT IN
>  (SELECT RCE_NS.DRV_DT, RCE_NS.AID, RCE_NS.R_CON_ID,
> RCE_NS.R_CON_VER_NB
>   FROM R_CON_E RCE_NS
>   WHERE RCE_NS.MTNE_ID NOT IN (select MI2.MTNE_ID
>  from M_INF MI2  where MI2.AID = :AID
>   UNION
>   SELECT    RG2.RG_MF_SK_ID
> from RG_M_F_INF RG2 where   RG2.AS_ID =:AID
>  UNION
>  SELECT    FTI1.FT_SRK_ID
>  from M_FT FTI1  where FTI1.AS_ID= :AID
> ))
> ) b
> where RC_STS.RR_FRQ_NB = D_LKP_FRQ.D_LKP_NB
>   and RC_STS.R_CON_ESTS_NB = D_LKP_STS.D_LKP_NB
>   and RC_STS.R_CON_ID = rc.R_CON_ID
>   and RC_STS.R_CON_VER_NB = rc.R_CON_VER_NB
>   and RC_STS.AID = rc.AID
>   and RC_STS.AID = b.AID
>   and RC_STS.R_CON_ID = b.R_CON_ID
>   and RC_STS.R_CON_VER_NB = b.R_CON_VER_NB
> order by 3,4,2;
>
>
>
>
> -> Sort: RC_STS.R_CON_ID, RC_STS.R_CON_VER_NB, RC_STS.R_EX_RID
>  (actual time=44392.655..44644.844 rows=745483 loops=1)
>     -> Stream results  (cost=311479029610.37
> rows=860847650219) (actual time=8957.556..42133.969
> rows=745483 loops=1)
>         -> Nested loop inner join  (cost=311479029610.37
> rows=860847650219) (actual time=8957.548..40891.903
> rows=745483 loops=1)
>             -> Nested loop inner join  (cost=225393084569.25
> rows=860847650219) (actual time=8957.541..40597.741
> rows=745483 loops=1)
>                 -> Nested loop inner join
>  (cost=139307139528.12 rows=860847650219) (actual
> time=8957.530..40092.267 rows=745483 loops=1)
>                     -> Nested loop antijoin
>  (cost=53221194487.00 rows=532199430400) (actual
> time=8957.477..29529.382 rows=671352 loops=1)
> *                        -> Nested loop inner join
>  (cost=886687.00 rows=729520) (actual time=0.123..19714.306
> rows=692583 loops=1)
>                             -> Filter:
> <in_optimizer>(RCE.MTNE_ID,<exists>(select #3))
>  (cost=84215.00 rows=729520) (actual time=0.085..9045.124
> rows=692583 loops=1)
> *                                -> Covering index scan on RCE
> using R_58  (cost=84215.00 rows=729520) (actual
> time=0.055..534.110 rows=742706 loops=1)
>                                 -> Select #3 (subquery in
> condition; dependent)
>                                     -> Limit: 1 row(s)
>  (cost=4.41..4.41 rows=1) (actual time=0.010..0.010 rows=1
> loops=742706)
>                                         -> Table scan on
> <union temporary>  (cost=4.41..5.70 rows=2) (actual
> time=0.010..0.010 rows=1 loops=742706)
> -> Union materialize with deduplication  (cost=3.18..3.18
> rows=2) (actual time=0.010..0.010 rows=1 loops=742706)
>   -> Limit table size: 1 unique row(s)
>      -> Limit: 1 row(s)  (cost=1.13 rows=1) (actual
> time=0.006..0.006 rows=1 loops=742706)
>           -> Covering index lookup on mi1 using
> M_INF_AID_index (AID='XXXXXXXXXXXXXXXXXXX',
> MTNE_ID=<cache>(RCE.MTNE_ID))  (cost=1.13 rows=1) (actual
> time=0.006..0.006 rows=1 loops=742706)
>   -> Limit table size: 1 unique row(s)
>       -> Limit: 1 row(s)  (cost=1.10 rows=1) (actual
> time=0.003..0.003 rows=1 loops=132294)
>           -> Single-row covering index lookup on rg using
> PRIMARY (RG_MF_SK_ID=<cache>(RCE.MTNE_ID),
> AS_ID='XXXXXXXXXXXXXXXXXXX')  (cost=1.10 rows=1) (actual
> time=0.003..0.003 rows=1 loops=132294)
>   -> Limit table size: 1 unique row(s)
>       -> Limit: 1 row(s)  (cost=0.74 rows=0.05) (actual
> time=0.003..0.003 rows=0 loops=50123)
>           -> Filter: (fti.AS_ID = 'XXXXXXXXXXXXXXXXXXX')
>  (cost=0.74 rows=0.05) (actual time=0.003..0.003 rows=0
> loops=50123)
>               -> Covering index lookup on fti using AK_MFTI
> (FT_SRK_ID=<cache>(RCE.MTNE_ID))  (cost=0.74 rows=2) (actual
> time=0.003..0.003 rows=0 loops=50123)
>                             -> Index lookup on rc using R_26
> (AID=RCE.AID, R_CON_ID=RCE.R_CON_ID,
> R_CON_VER_NB=RCE.R_CON_VER_NB)  (cost=1.00 rows=1) (actual
> time=0.014..0.015 rows=1 loops=692583)
>                          -> Single-row index lookup on
> <subquery7> using <auto_distinct_key> (DRV_DT=RCE.DRV_DT,
> AID=RCE.AID, R_CON_ID=RCE.R_CON_ID,
> R_CON_VER_NB=RCE.R_CON_VER_NB)  (cost=157167.31..157167.31
> rows=1) (actual time=0.014..0.014 rows=0 loops=692583)
>                             -> Materialize with deduplication
>  (cost=157167.00..157167.00 rows=729520) (actual
> time=8957.347..8957.347 rows=25843 loops=1)
> *                                -> Filter: ((RCE_NS.DRV_DT is
> not null) and (RCE_NS.AID is not null) and (RCE_NS.R_CON_ID is
> not null) and (RCE_NS.R_CON_VER_NB is not null))
>  (cost=84215.00 rows=729520) (actual time=1737.420..8871.505
> rows=50123 loops=1)
>                                     -> Filter:
> <in_optimizer>(RCE_NS.MTNE_ID,<exists>(select #8) is false)
>  (cost=84215.00 rows=729520) (actual time=1737.417..8860.489
> rows=50123 loops=1)
> * -> Covering index scan on RCE_NS using R_58  (cost=84215.00
> rows=729520) (actual time=0.039..531.571 rows=742706 loops=1)
>                                         -> Select #8 (subquery
> in condition; dependent)
> -> Limit: 1 row(s)  (cost=4.41..4.41 rows=1) (actual
> time=0.010..0.010 rows=1 loops=742706)
>   -> Table scan on <union temporary>  (cost=4.41..5.70 rows=2)
> (actual time=0.010..0.010 rows=1 loops=742706)
>       -> Union materialize with deduplication
>  (cost=3.18..3.18 rows=2) (actual time=0.010..0.010 rows=1
> loops=742706)
>           -> Limit table size: 1 unique row(s)
>            -> Limit: 1 row(s)  (cost=1.13 rows=1) (actual
> time=0.007..0.007 rows=1 loops=742706)
>                   -> Covering index lookup on MI2 using
> M_INF_AID_index (AID='XXXXXXXXXXXXXXXXXXX',
> MTNE_ID=<cache>(RCE_NS.MTNE_ID))  (cost=1.13 rows=1) (actual
> time=0.006..0.006 rows=1 loops=742706)
>           -> Limit table size: 1 unique row(s)
>               -> Limit: 1 row(s)  (cost=1.10 rows=1) (actual
> time=0.004..0.004 rows=1 loops=132294)
>                   -> Single-row covering index lookup on RG2
> using PRIMARY (RG_MF_SK_ID=<cache>(RCE_NS.MTNE_ID),
> AS_ID='XXXXXXXXXXXXXXXXXXX')  (cost=1.10 rows=1) (actual
> time=0.003..0.003 rows=1 loops=132294)
>           -> Limit table size: 1 unique row(s)
>               -> Limit: 1 row(s)  (cost=0.74 rows=0.05)
> (actual time=0.003..0.003 rows=0 loops=50123)
>                   -> Filter: (FTI1.AS_ID =
> 'XXXXXXXXXXXXXXXXXXX')  (cost=0.74 rows=0.05) (actual
> time=0.003..0.003 rows=0 loops=50123)
>                       -> Covering index lookup on FTI1 using
> AK_MFTI (FT_SRK_ID=<cache>(RCE_NS.MTNE_ID))  (cost=0.74
> rows=2) (actual time=0.003..0.003 rows=0 loops=50123)
>                     -> Index lookup on RC_STS using RCE_STS
> (AID=RCE.AID, R_CON_ID=RCE.R_CON_ID,
> R_CON_VER_NB=RCE.R_CON_VER_NB)  (cost=1.62 rows=2) (actual
> time=0.013..0.016 rows=1 loops=671352)
>                 -> Single-row index lookup on D_LKP_STS using
> PRIMARY (D_LKP_NB=RC_STS.R_CON_ESTS_NB)  (cost=1.00 rows=1)
> (actual time=0.000..0.000 rows=1 loops=745483)
>             -> Single-row index lookup on D_LKP_FRQ using
> PRIMARY (D_LKP_NB=RC_STS.RR_FRQ_NB)  (cost=1.00 rows=1)
> (actual time=0.000..0.000 rows=1 loops=745483)
>
> Regards
>
> Pap
>



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


Received on Wed Oct 23 2024 - 16:58:21 CEST

Original text of this message