Could you assist me in finding the problematic areas in the attached query?
Printable View
Could you assist me in finding the problematic areas in the attached query?
Do you have Toad? Run it through a tuning lab.
Why select from the mam_assets table twice for a.id?
Code:FROM MAM_ASSETS A
11 WHERE ((A.ACL_ID=65536) AND
12 (A.ASSET_GROUP_XID=120) AND
13 (A.IS_CURRENT_VERSION=1) AND
14 A.ID IN ( SELECT A.ID ASSET_ID FROM MAM_ASSETS A
15 WHERE (A.ID IN (SELECT SV65539.ID FROM MAM_ATTR_STRING_VALUES SV65539
1. I don't have toad. Any other way, I can find out where the time is consumed.
2. There is a UI based query wizard at the application level that generates this query. Even I spotted the same thing but I don't have any control on it.
3. I checked the health of indexes involved using 'analyze index validate structure'. They are good.
Any other comments, I would be grateful.
trace the session, see where time is being taken - stop guessing
validating the structure of an index is pointless
Hi
Whats the output of
Code:select ATTRIBUTE_XID,count(*)
from MAM_ATTR_STRING_VALUES
group by ATTRIBUTE_XID
select count(*)
from MAM_ATTR_STRING_VALUES
I executed this query in a a session and traced the session.
Attached is the formatted output after tkprof.
Mainly time is taken by CPU.
How can we reduce the execution of this query? It's teasing me a lot now.
Two pieces of code...
1- target sql statement. my_target_sql.sql in this example.
2- trace shell script. my_trace_script.sh in this example - see below.
Once you have both of them in place.
a) set your oracle_home
b) set your oracle_sid
c) nohup my_trace_script.sh > my_trace.out &
d) tkprof trace file on user_dump_destination with sys=no option
Build your my_trace_script.sh including code below...
sqlplus -s / <set linesize 180
set pagesize 0
set timing on
spool my_trace_script.out
select instance_name, host_name from v\$instance;
drop table PLAN_TABLE;
@?/rdbms/admin/utlxplan
alter session set timed_statistics = true;
alter session set sql_trace = true;
set autotrace on explain
alter session set events '10046 trace name context forever, level 12';
-- execute sql to be traced like...
@my_target_sql.sql
--
alter session set sql_trace = false;
alter session set timed_statistics = false;
spool off
EOF
Last but not least, if my_target_sql.sql is expected to return a large number of rows you may want to wrap it up on a count shell like...
select count(*) from(
--put your sql statement here
);
...after all you are looking for trace/execution plan, not for the actual output.
.out is your session log
.prf is the one where the fun begins
Hi
Check if this gets you the same result as your original query
Also see if you can or already have a index onCode:SELECT TO_CHAR(A.ID) A118,A.ASSET_GROUP_XID A2,A.ACL_ID A106,A.OWNER A4,CONVERT(A.NAME,'WE8MACROMAN8') A1,
A.FIRST_VERSION_CREATED_BY A15,LPAD(LTRIM(TO_CHAR(A.FIRST_VERSION_DATE_CREATED,'SYYYYMMDDHH24MISS')),15,'+') A16,
LPAD(LTRIM(TO_CHAR(A.DATE_CREATED,'SYYYYMMDDHH24MISS')),15,'+') A18,CONVERT(A.CHECKOUT_LOCATION,'WE8MACROMAN8') A24,
TO_CHAR(A.ASSET_SIZE) A7,A.CHECKED_OUT_BY A23,A.ARCHIVE_STATUS A27,A.STORAGE_CHANGE_REQUEST A110,A.HAS_HISTORY A74,
TO_CHAR(A.CONTAINED_IN_COUNT) A73,TO_CHAR(A.CONTAINER_OF_COUNT) A72,TO_CHAR(A.RELATED_WITH_COUNT) A71,
CONVERT(A.FILE_TYPE,'WE8MACROMAN8') A12,CONVERT(A.FILE_CREATOR_APPLICATION,'WE8MACROMAN8') A13,
CONVERT(A.FILE_EXTENSION,'WE8MACROMAN8') A9,TO_CHAR(A.REVISION) A21,A.IS_CURRENT_VERSION A109,
TO_CHAR(A.FAMILY_ID) A112,LPAD(LTRIM(TO_CHAR(A.FILE_DATE_CREATED,'SYYYYMMDDHH24MISS')),15,'+') A11,
LPAD(LTRIM(TO_CHAR(A.FILE_DATE_LAST_MODIFIED,'SYYYYMMDDHH24MISS')),15,'+') A10
FROM MAM_ASSETS A
WHERE ((A.ACL_ID=65536) AND
(A.ASSET_GROUP_XID=120) AND
(A.IS_CURRENT_VERSION=1) AND
EXISTS
(SELECT SV65539.ID FROM MAM_ATTR_STRING_VALUES SV65539
WHERE (SV65539.LOWER_CASE_STRING_VALUE LIKE
LOWER(CONVERT('%813982%','WE8MSWIN1252','WE8MACROMAN8')))
AND (SV65539.ATTRIBUTE_XID=65539)
AND A.ID=SV65539.ID)
ORDER BY A.ASSET_SIZE
MAM_ATTR_STRING_VALUES (ID,ATTRIBUTE_XID,LOWER_CASE_STRING_VALUE )
Put fingers on keyboard and type/search. Open book(s) and read.
http://www.oracle-base.com/articles/...dTkprof10g.php
Hi
Are your stats upto date on all the tables involved
How do you collect stats ?
is there a way to get back to the development team on this ?
Whats the acceptable time within which this query should finish ?
I noticed a strange thing.
"select count(*) from ....." version of the posted query executes in 2 seconds. There seems to be some problem with the select list. I tried to spot it out using the binary method but the problem seems to be with multiple columns in select list.
Description of MAM_ASSETS is attached.
I am trying to fix it up with this information. Please let me know if you have any comments regarding the same.
Hi
Did it ever run in less then 5 minutes ?
(your users are very patient to wait for 5 minutes )
Have you thought of a MV
Code:CREATE MATERIALIZED VIEW LOG ON MAM_ATTR_STRING_VALUES WITH ROWID
CREATE MATERIALIZED VIEW MAM_ATTR_STRING_VALUES_MV
CLUSTER m_lt_li (id)
REFRESH FAST ON COMMIT
ENABLE QUERY REWRITE
AS
SELECT SV65539.ID
FROM MAM_ATTR_STRING_VALUES SV65539
WHERE SV65539.LOWER_CASE_STRING_VALUE LIKE LOWER(CONVERT('%813982%','WE8MSWIN1252','WE8MACROMAN8'))
AND SV65539.ATTRIBUTE_XID=65539
There is no problem with this part. As I told earlier that the whole query executes in less than 2 seconds if I use select count(*) instead of select. I am not able to figure out why specifying the column list causes the query to take so long in fetching the results. Is it a known issue? I could understand that it has to bring column data, so more I/O is required but this more time could amount to 6 hours is not understandable.
Hi
Do you mind using a MV and showing me the results ?
Hrishy, I know you may be right. But believe me, this query on which you are asking for MV executes in less than a second. Moreover, there is a wild search '%813982%' which is not the same in every query created by the user. So, MV would help only in one particular case. Moreover, I need approval to create an MV for which I need to give the reason and I have no valid reason so far.
However, I have seen that the problem is with the select list but I don't know where. Anyways, this query has made me crazy.
It will made you crazy, because it's not picking correct index.
Do your own analysis and see why it's not picking correct index.
MY thought is if you execute this query with FULL hint it'll finish much faster.
Here since it's picking wrong index it's doing lot of buffer gets and scanning memory is CPU intensive.
Can you execute this query with FULL hint and get back to us with the autotrace details.
Did you answer when was the last time statistics gathered and how do you excatly gather statistics.
Also do provide the wait event details.
It is indeed picking the right index.
See the query below:
SELECT TO_CHAR(A.ID) A118,A.ASSET_GROUP_XID A2,A.ACL_ID A106,A.OWNER A4,CONVERT(A.NAME,'WE8MACROMAN8') A1,
A.FIRST_VERSION_CREATED_BY A15,LPAD(LTRIM(TO_CHAR(A.FIRST_VERSION_DATE_CREATED,'SYYYYMMDDHH24MISS')),15,'+') A16,
LPAD(LTRIM(TO_CHAR(A.DATE_CREATED,'SYYYYMMDDHH24MISS')),15,'+') A18,CONVERT(A.CHECKOUT_LOCATION,'WE8MACROMAN8') A24,
TO_CHAR(A.ASSET_SIZE) A7,A.CHECKED_OUT_BY A23,A.ARCHIVE_STATUS A27,A.STORAGE_CHANGE_REQUEST A110,A.HAS_HISTORY A74,
TO_CHAR(A.CONTAINED_IN_COUNT) A73,TO_CHAR(A.CONTAINER_OF_COUNT) A72,TO_CHAR(A.RELATED_WITH_COUNT) A71,
CONVERT(A.FILE_TYPE,'WE8MACROMAN8') A12,CONVERT(A.FILE_CREATOR_APPLICATION,'WE8MACROMAN8') A13,
CONVERT(A.FILE_EXTENSION,'WE8MACROMAN8') A9,TO_CHAR(A.REVISION) A21,A.IS_CURRENT_VERSION A109,TO_CHAR(A.FAMILY_ID) A112,
LPAD(LTRIM(TO_CHAR(A.FILE_DATE_CREATED,'SYYYYMMDDHH24MISS')),15,'+') A11,
LPAD(LTRIM(TO_CHAR(A.FILE_DATE_LAST_MODIFIED,'SYYYYMMDDHH24MISS')),15,'+') A10
FROM MAM_ASSETS A WHERE ((A.ACL_ID=65536) AND (A.ASSET_GROUP_XID=120) AND (A.IS_CURRENT_VERSION=1) AND
A.ID IN ( SELECT A.ID ASSET_ID FROM MAM_ASSETS A
WHERE (A.ID IN (SELECT SV65539.ID FROM MAM_ATTR_STRING_VALUES SV65539 WHERE
(SV65539.LOWER_CASE_STRING_VALUE LIKE
LOWER(CONVERT('%813982%','WE8MSWIN1252','WE8MACROMAN8'))) AND
(SV65539.ATTRIBUTE_XID=65539))) ) )
ORDER BY A.ASSET_SIZE;
The indexes on columns ACL_ID, ASSET_GROUP_XID AND IS_CURRENT_VERSION are not picked as there are more than 10 percent rows corresponding to the values of these columns.
The index on ID column is picked as the nested query returns less than 2 percent of rows. The name of index is AST_PK.
The index on ATTRIBUTE_XID column used in innermost query is also used and name of index is ATRVALSTR_ATRDEF_FK_I.
See the execution plan below:
Execution Plan
----------------------------------------------------------
0 SELECT STATEMENT Optimizer=CHOOSE (Cost=1118 Card=86 Bytes=15738)
1 0 SORT (ORDER BY) (Cost=1118 Card=86 Bytes=15738)
2 1 NESTED LOOPS (Cost=1107 Card=86 Bytes=15738)
3 2 NESTED LOOPS (Cost=1088 Card=918 Bytes=44064)
4 3 SORT (UNIQUE) (Cost=1072 Card=918 Bytes=38556)
5 4 TABLE ACCESS (BY INDEX ROWID) OF 'MAM_ATTR_STRING_VALUES' (TABLE) (Cost=1072 Card=918 Bytes=38556)
6 5 INDEX (RANGE SCAN) OF 'ATRVALSTR_ATRDEF_FK_I' (INDEX) (Cost=819 Card=367018)
7 3 INDEX (UNIQUE SCAN) OF 'AST_PK' (INDEX (UNIQUE))
8 2 TABLE ACCESS (BY INDEX ROWID) OF 'MAM_ASSETS' (TABLE) (Cost=1 Card=1 Bytes=135)
9 8 INDEX (UNIQUE SCAN) OF 'AST_PK' (INDEX (UNIQUE))
However, there is one area that I have literally found problematic after using events '10046 trace name context forever, level 12'. See the highlighted part from the excerpt of the formatted trace file below:
Rows Row Source Operation
------- ---------------------------------------------------
4 SORT ORDER BY (cr=217990536 pr=5509 pw=0 time=1737749501 us)
4 MERGE JOIN SEMI (cr=217990536 pr=5509 pw=0 time=1743457434 us)
19740 TABLE ACCESS BY INDEX ROWID MAM_ASSETS (cr=217952929 pr=5508 pw=0 time=22406421915 us)
443784 NESTED LOOPS (cr=217939831 pr=197 pw=0 time=29382428995 us)
424043 INDEX FULL SCAN AST_PK (cr=915 pr=0 pw=0 time=424066 us)(object id 2624)
19740 BITMAP CONVERSION TO ROWIDS (cr=217938916 pr=197 pw=0 time=29438106950 us)
19740 BITMAP AND (cr=217938916 pr=197 pw=0 time=29436670545 us)
424043 BITMAP CONVERSION FROM ROWIDS (cr=1273083 pr=79 pw=0 time=10021178 us)
424043 INDEX RANGE SCAN AST_PK (cr=1273083 pr=79 pw=0 time=7913561 us)(object id 2624)
424043 BITMAP CONVERSION FROM ROWIDS (cr=26333520 pr=102 pw=0 time=3238424511 us)
22005947710 INDEX RANGE SCAN AST_ASG_FK_I (cr=26333520 pr=102 pw=0 time=4114630 us)(object id 3043)
424043 BITMAP CONVERSION FROM ROWIDS (cr=190332313 pr=16 pw=0 time=26184714435 us)
1626309602 INDEX RANGE SCAN AST_CURRENT_VERSION_I (cr=190332313 pr=16 pw=0 time=3919662 us)(object id 3062)
4 SORT UNIQUE (cr=37607 pr=1 pw=0 time=1482279 us)
48 TABLE ACCESS BY INDEX ROWID MAM_ATTR_STRING_VALUES (cr=37607 pr=1 pw=0 time=3467157 us)
361416 INDEX RANGE SCAN ATRVALSTR_ATRDEF_FK_I (cr=825 pr=1 pw=0 time=2384 us)(object id 30474)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 2 0.00 0.00
db file sequential read 5509 0.55 35.60
latch: cache buffers chains 3 0.00 0.00
SQL*Net message from client 2 0.36 0.68
I am not able to find why is it wasting so much of time here. What is this BITMAP operation and why is it performed?
You can set this in session level and execute to see if bitmap conversion is happening.
_b_tree_bitmap_plans = false
However i think problem is with NL join, did you try excuting query with FULL hint?
This "LOWER(CONVERT('%813982%','WE8MSWIN1252','WE8MACROMAN8')))" is where it is doing bitmap conversion 367018 many times, so lets c after setting _b_tree_bitmap_plans = false what's happening.
BTW, how long it was taking to execute before and what changes done after which this query taking long time?
That I suppose is a hidden parameter. I will try to do it.
Yes, I tried it full hint and it took around 5 and a half hours then. No changes were made to this query. There is a wizard at application level that lets the users form any query.
Earlier, this query should have executed in less than 2 minutes if customer didn't complain before. Even if I remove all columns in select list and use count(*), then this query executes in 2 seconds. Then if I start from 1 st column of select list and start adding columns one by one (by looking into the query posted above), the query starts taking long when I reach one particular column. If I think that it is the problematic column and use only this column in select list, even then the query will again start executing in 2 seconds. So, I am not able to drill down the cause.
Just another question: Do the indexes on columns present in select list have anything to do with faster query retrieval? I think it's no but I have seen change in execution plan if I create index on column of select list and this column is not present in where clause.
Malay, I almost forgot to thank you. Thanks a ton.
The following links have more information about this hidden parameter. It's a bug kind.0
http://blogs.oracle.com/theshortensp...le_parame.html
https://support.oracle.com/CSP/main/...tFamily=Oracle
Description of this parameter:
PARM_NAME CURRENT_VAL DEFAULT_VAL DESCR
-------------------- ------------ ------------ ------------------------------------------------------------
_b_tree_bitmap_plans TRUE TRUE enable the use of bitmap plans for tables w. only B-tree ind
exes
SQL> select distinct index_type from dba_indexes;
INDEX_TYPE
---------------------------
CLUSTER
DOMAIN
FUNCTION-BASED NORMAL
IOT - TOP
LOB
NORMAL
6 rows selected.
There is no bitmap index. So, I think that I am on the right track.
That's a good news and you are welcome.
can you show use output of from sqlplus
Code:
set echo on
set line 300
set pagesize 400
set trimspool on
alter session set cursor_sharing = EXACT;
explain plan for
SELECT /* EXACT */
TO_CHAR (A.ID) A118,
A.ASSET_GROUP_XID A2,
A.ACL_ID A106,
A.OWNER A4,
CONVERT (A.NAME, 'WE8MACROMAN8') A1,
A.FIRST_VERSION_CREATED_BY A15,
LPAD (
LTRIM (
TO_CHAR (A.FIRST_VERSION_DATE_CREATED, 'SYYYYMMDDHH24MISS')
),
15,
'+'
)
A16,
LPAD (LTRIM (TO_CHAR (A.DATE_CREATED, 'SYYYYMMDDHH24MISS')),
15,
'+')
A18,
CONVERT (A.CHECKOUT_LOCATION, 'WE8MACROMAN8') A24,
TO_CHAR (A.ASSET_SIZE) A7,
A.CHECKED_OUT_BY A23,
A.ARCHIVE_STATUS A27,
A.STORAGE_CHANGE_REQUEST A110,
A.HAS_HISTORY A74,
TO_CHAR (A.CONTAINED_IN_COUNT) A73,
TO_CHAR (A.CONTAINER_OF_COUNT) A72,
TO_CHAR (A.RELATED_WITH_COUNT) A71,
CONVERT (A.FILE_TYPE, 'WE8MACROMAN8') A12,
CONVERT (A.FILE_CREATOR_APPLICATION, 'WE8MACROMAN8') A13,
CONVERT (A.FILE_EXTENSION, 'WE8MACROMAN8') A9,
TO_CHAR (A.REVISION) A21,
A.IS_CURRENT_VERSION A109,
TO_CHAR (A.FAMILY_ID) A112,
LPAD (LTRIM (TO_CHAR (A.FILE_DATE_CREATED, 'SYYYYMMDDHH24MISS')),
15,
'+')
A11,
LPAD (
LTRIM (TO_CHAR (A.FILE_DATE_LAST_MODIFIED, 'SYYYYMMDDHH24MISS')),
15,
'+'
)
A10
FROM MAM_ASSETS A
WHERE ( (A.ACL_ID = 65536)
AND (A.ASSET_GROUP_XID = 120)
AND (A.IS_CURRENT_VERSION = 1)
AND A.ID IN
(SELECT A.ID ASSET_ID
FROM MAM_ASSETS A
WHERE (A.ID IN
(SELECT SV65539.ID
FROM MAM_ATTR_STRING_VALUES SV65539
WHERE (SV65539.LOWER_CASE_STRING_VALUE LIKE
LOWER(CONVERT (
'%813982%',
'WE8MSWIN1252',
'WE8MACROMAN8'
)))
AND (SV65539.ATTRIBUTE_XID =
65539)))))
ORDER BY A.ASSET_SIZE;
select * from table(dbms_xplan.display);
alter session set cursor_sharing = FORCE;
explain plan for
SELECT /* FORCE */
TO_CHAR (A.ID) A118,
A.ASSET_GROUP_XID A2,
A.ACL_ID A106,
A.OWNER A4,
CONVERT (A.NAME, 'WE8MACROMAN8') A1,
A.FIRST_VERSION_CREATED_BY A15,
LPAD (
LTRIM (
TO_CHAR (A.FIRST_VERSION_DATE_CREATED, 'SYYYYMMDDHH24MISS')
),
15,
'+'
)
A16,
LPAD (LTRIM (TO_CHAR (A.DATE_CREATED, 'SYYYYMMDDHH24MISS')),
15,
'+')
A18,
CONVERT (A.CHECKOUT_LOCATION, 'WE8MACROMAN8') A24,
TO_CHAR (A.ASSET_SIZE) A7,
A.CHECKED_OUT_BY A23,
A.ARCHIVE_STATUS A27,
A.STORAGE_CHANGE_REQUEST A110,
A.HAS_HISTORY A74,
TO_CHAR (A.CONTAINED_IN_COUNT) A73,
TO_CHAR (A.CONTAINER_OF_COUNT) A72,
TO_CHAR (A.RELATED_WITH_COUNT) A71,
CONVERT (A.FILE_TYPE, 'WE8MACROMAN8') A12,
CONVERT (A.FILE_CREATOR_APPLICATION, 'WE8MACROMAN8') A13,
CONVERT (A.FILE_EXTENSION, 'WE8MACROMAN8') A9,
TO_CHAR (A.REVISION) A21,
A.IS_CURRENT_VERSION A109,
TO_CHAR (A.FAMILY_ID) A112,
LPAD (LTRIM (TO_CHAR (A.FILE_DATE_CREATED, 'SYYYYMMDDHH24MISS')),
15,
'+')
A11,
LPAD (
LTRIM (TO_CHAR (A.FILE_DATE_LAST_MODIFIED, 'SYYYYMMDDHH24MISS')),
15,
'+'
)
A10
FROM MAM_ASSETS A
WHERE ( (A.ACL_ID = 65536)
AND (A.ASSET_GROUP_XID = 120)
AND (A.IS_CURRENT_VERSION = 1)
AND A.ID IN
(SELECT A.ID ASSET_ID
FROM MAM_ASSETS A
WHERE (A.ID IN
(SELECT SV65539.ID
FROM MAM_ATTR_STRING_VALUES SV65539
WHERE (SV65539.LOWER_CASE_STRING_VALUE LIKE
LOWER(CONVERT (
'%813982%',
'WE8MSWIN1252',
'WE8MACROMAN8'
)))
AND (SV65539.ATTRIBUTE_XID =
65539)))))
ORDER BY A.ASSET_SIZE;
select * from table(dbms_xplan.display);
select a.index_name, b.column_name, a.distinct_keys, a.num_rows, a.last_analyzed
from user_indexes a, user_ind_columns b
where a.index_name = b.index_name
and a.index_name in ('AST_CURRENT_VERSION_I', 'AST_ASG_FK_I', 'AST_PK')
order by a.index_name, b.column_position;
Regards
FYI bitmap conversion/AND operations are not exclusively for bitmap indexes, btree indexes are perfect candidates for this type of operations, most of times is for those queries such as
select
from t1
where c1 = :a -> indexed by t1_idx1
and c2 = :b -> indexed by t1_idx2
Oracle will scan both indexes and merge the results using bitmap operations