Home » RDBMS Server » Performance Tuning » How to judge the slow query? (Windows 2003 SP2 Oracle 10.2.0.4 32-bit)
How to judge the slow query? [message #403978] Tue, 19 May 2009 23:23 Go to next message
crazypeter2005
Messages: 29
Registered: September 2008
Location: Peking China
Junior Member
The slow query:
1
SQL Stmt: <SELECT /*+ FIRST_ROWS (500) */ T.* FROM (SELECT DISTINCT GPSFolder_1.ITEMID, GPSFolder_1.COMPONENTID, GPSFolder_1.VERSIONID, 2343 AS COMPONENTTYPEID, 1533 AS ITEMTYPEID FROM ICMUT02343001 GPSFolder_1 WHERE (GPSFolder_1.ATTR0000002084 = 'GPSFolderDataD00{GPSROOT}') AND (((( ( (EXISTS (SELECT 1 FROM ICMSTCOMPILEDACL C , ICMSTITVIEWDEFS V WHERE 1533=V.ITEMTYPEID AND V.ITEMTYPEVIEWID IN (1533) AND (C.ACL = V.ACLCODE OR C.ACL = -1) AND C.UNUM=2 AND C.RPRIV='1' )) OR (EXISTS (SELECT 1 FROM ICMSTCOMPILEDACL C, ICMSTCOMPILEDPERM P , ICMSTITVIEWDEFS V WHERE 1533=V.ITEMTYPEID AND V.ITEMTYPEVIEWID IN (1533) AND (C.ACL = V.ACLCODE OR C.ACL = -1) AND C.UNUM=1 AND C.RPRIV='1' AND P.PRIVDEFCODE=121 AND P.UNUM=2 )) )))))) T , ICMSTITEMS001001 I WHERE T.ITEMID = I.ITEMID AND T.VERSIONID = I.VERSIONID>

2
SQL Stmt: <SELECT /*+ FIRST_ROWS (500) */ T.* FROM (SELECT DISTINCT ItemVersions_1.ITEMID, ItemVersions_1.COMPONENTID, ItemVersions_1.VERSIONID, ItemVersions_1.COMPONENTTYPEID, ItemVersions_1.ITEMTYPEID FROM ICMSVALLITEM001001 ItemVersions_1, ICMSTLINKS001001 Links_4, ICMSTNLSKEYWORDS NLSKeywords_6 WHERE ((ItemVersions_1.SEMANTICTYPE IN (2, 1000)) AND (((ItemVersions_1.ITEMID = Links_4.TARGETITEMID) AND ((((Links_4.LINKTYPE = NLSKeywords_6.KEYWORDCODE) AND (4 = NLSKeywords_6.KEYWORDCLASS)) AND ('ENU' = NLSKeywords_6.LANGUAGECODE)) AND (NLSKeywords_6.KEYWORDNAME = 'Contains'))) AND (Links_4.SOURCEITEMID = 'A1001001A09D21B65355H33550'))) AND ((( (ItemVersions_1.ITEMTYPEID IN (300, 301, 302, 303, 304, 400, 1000, 1001, 1002, 1003, 1004, 1005, 1006, 1007, 1008, 1009, 1010, 1011, 1012, 1013, 1014, 1015, 1016, 1017, 1018, 1019, 1020, 1021, 1022, 1023, 1024, 1025, 1026, 1027, 1028, 1030, 1031, 1532, 1533, 1534, 1535, 1537, 1538, 1539, 1540, 1541, 1542, 1543, 1544, 1545, 1546, 1547, 1548, 1549, 1550, 1551, 1552, 1553, 1556, 1557, 1558, 1559, 1560, 1561, 1562, 1563) AND ( (EXISTS (SELECT 1 FROM ICMSTCOMPILEDACL C , ICMSTITVIEWDEFS V WHERE ItemVersions_1.ITEMTYPEID=V.ITEMTYPEID AND V.ITEMTYPEVIEWID IN (300, 301, 302, 303, 304, 400, 1000, 1001, 1002, 1003, 1004, 1005, 1006, 1007, 1008, 1009, 1010, 1011, 1012, 1013, 1014, 1015, 1016, 1017, 1018, 1019, 1020, 1021, 1022, 1023, 1024, 1025, 1026, 1027, 1028, 1030, 1031, 1532, 1533, 1534, 1535, 1537, 1538, 1539, 1540, 1541, 1542, 1543, 1544, 1545, 1546, 1547, 1548, 1549, 1550, 1551, 1552, 1553, 1556, 1557, 1558, 1559, 1560, 1561, 1562, 1563) AND (C.ACL = V.ACLCODE OR C.ACL = -1) AND C.UNUM=2 AND C.RPRIV='1' )) OR (EXISTS (SELECT 1 FROM ICMSTCOMPILEDACL C, ICMSTCOMPILEDPERM P , ICMSTITVIEWDEFS V WHERE ItemVersions_1.ITEMTYPEID=V.ITEMTYPEID AND V.ITEMTYPEVIEWID IN (300, 301, 302, 303, 304, 400, 1000, 1001, 1002, 1003, 1004, 1005, 1006, 1007, 1008, 1009, 1010, 1011, 1012, 1013, 1014, 1015, 1016, 1017, 1018, 1019, 1020, 1021, 1022, 1023, 1024, 1025, 1026, 1027, 1028, 1030, 1031, 1532, 1533, 1534, 1535, 1537, 1538, 1539, 1540, 1541, 1542, 1543, 1544, 1545, 1546, 1547, 1548, 1549, 1550, 1551, 1552, 1553, 1556, 1557, 1558, 1559, 1560, 1561, 1562, 1563) AND (C.ACL = V.ACLCODE OR C.ACL = -1) AND C.UNUM=1 AND C.RPRIV='1' AND P.PRIVDEFCODE=121 AND P.UNUM=2 )) )) OR (ItemVersions_1.ITEMTYPEID IN (200, 201, 202, 600, 1536, 1554, 1555, 1564, 1565, 1566) AND ( (EXISTS (SELECT 1 FROM ICMSTCOMPILEDACL C WHERE (C.ACL = ItemVersions_1.ACLCODE OR C.ACL = -1) AND C.UNUM=2 AND C.RPRIV='1' )) OR (EXISTS (SELECT 1 FROM ICMSTCOMPILEDACL C, ICMSTCOMPILEDPERM P WHERE (C.ACL = ItemVersions_1.ACLCODE OR C.ACL = -1) AND C.UNUM=1 AND C.RPRIV='1' AND P.PRIVDEFCODE=121 AND P.UNUM=2 )) )))))) T , ICMSTITEMS001001 I WHERE T.ITEMID = I.ITEMID AND T.VERSIONID = I.VERSIONID>

Client Log:
ICMPLSLU ICMLISTUSER 00122 05/19 07:23:39.187 GMT ; AUTHOR2000 Entry
ICMPLSGU ICMLISTGRPFORUSER 00117 05/19 07:23:39.203 GMT ; AUTHOR2000 Entry
ICMPLSLP ICMLISTPRIVILEGE 00108 05/19 07:23:39.218 GMT ; AUTHOR2000 Entry
ICMPLSLP ICMLISTPRIVILEGE 00110 05/19 07:23:39.234 GMT ; AUTHOR2000 From SP
ICMPLSLU ICMLISTUSER 00122 05/19 07:23:39.250 GMT ; AUTHOR2000 Entry
ICMPLSPI ICMLISTPRIVINSET 00100 05/19 07:23:39.265 GMT ; AUTHOR2000 Entry
ICMPLSQU ICMSEARCH 00328 05/19 07:23:39.625 GMT ; AUTHOR2000 Entry
ICMPLSQU ICMSEARCH 00466 05/19 07:23:39.640 GMT ; AUTHOR2000 3 msec
ICMPLSQU ICMSEARCH 00328 05/19 07:23:46.390 GMT ; AUTHOR2000 Entry
You can see Obvious wait here.

Line 1323 : [05/19/2009 08:11:37.281] 1328 D: Creating file mutex: 'gpsfmtx_c:/progra~1/ibm/db2doc~1/dmserver/cache/libs/cm/13_views/13_dm_view.dat'
Line 1371 : [05/19/2009 08:11:37.468] 1328 D: Found the datastorepool at index 0 for the datastore name svtlsdb
Line 1408 : [05/19/2009 08:11:37.468] 1328 D: Item key: GPSFolderDataD00{GPSROOT}
Line 1410 : [05/19/2009 08:11:37.468] 1328 D: Evaluating root folder query: '/GPSFolder [@GPSObjKey = "GPSFolderDataD00{GPSROOT}"]'
Line 1411 : [05/19/2009 08:11:44.453] 1328 D: Root folder not found in 6985ms
Line 1412 : [05/19/2009 08:11:44.453] 1328 D: Number returned: 0
Line 1463 : [05/19/2009 08:11:44.515] 1328 D: Found the datastorepool at index 0 for the datastore name svtlsdb
Line 1498 : [05/19/2009 08:11:44.531] 1328 D: Get folder list command
Line 1501 : [05/19/2009 08:11:44.531] 1328 D: Item key: GPSFolderDataD00{GPSROOT}
Line 1503 : [05/19/2009 08:11:44.531] 1328 D: Evaluating root folder query: '/GPSFolder [@GPSObjKey = "GPSFolderDataD00{GPSROOT}"]'
Line 1504 : [05/19/2009 08:11:50.937] 1328 D: Root folder not found in 6406ms
You can see each Xquery takes 6 seconds

Attachement is Statpack,Please take a look at it。
It is the programe to translate the XQuery to SQL, and it is horrible.
Any suggestings?

[Updated on: Wed, 20 May 2009 01:19] by Moderator

Report message to a moderator

How to judge the slow query? [message #403981 is a reply to message #403978] Tue, 19 May 2009 23:28 Go to previous messageGo to next message
crazypeter2005
Messages: 29
Registered: September 2008
Location: Peking China
Junior Member
最近客户的机器发生了很奇怪的现象
后端是Oracle10.2.0.4的数据库,前段是某个MIS系统任何用户登陆都很慢。
取到SQL语句和Statpack结果
1
SQL Stmt: <SELECT /*+ FIRST_ROWS (500) */ T.* FROM (SELECT DISTINCT GPSFolder_1.ITEMID, GPSFolder_1.COMPONENTID, GPSFolder_1.VERSIONID, 2343 AS COMPONENTTYPEID, 1533 AS ITEMTYPEID FROM ICMUT02343001 GPSFolder_1 WHERE (GPSFolder_1.ATTR0000002084 = 'GPSFolderDataD00{GPSROOT}') AND (((( ( (EXISTS (SELECT 1 FROM ICMSTCOMPILEDACL C , ICMSTITVIEWDEFS V WHERE 1533=V.ITEMTYPEID AND V.ITEMTYPEVIEWID IN (1533) AND (C.ACL = V.ACLCODE OR C.ACL = -1) AND C.UNUM=2 AND C.RPRIV='1' )) OR (EXISTS (SELECT 1 FROM ICMSTCOMPILEDACL C, ICMSTCOMPILEDPERM P , ICMSTITVIEWDEFS V WHERE 1533=V.ITEMTYPEID AND V.ITEMTYPEVIEWID IN (1533) AND (C.ACL = V.ACLCODE OR C.ACL = -1) AND C.UNUM=1 AND C.RPRIV='1' AND P.PRIVDEFCODE=121 AND P.UNUM=2 )) )))))) T , ICMSTITEMS001001 I WHERE T.ITEMID = I.ITEMID AND T.VERSIONID = I.VERSIONID>

2
SQL Stmt: <SELECT /*+ FIRST_ROWS (500) */ T.* FROM (SELECT DISTINCT ItemVersions_1.ITEMID, ItemVersions_1.COMPONENTID, ItemVersions_1.VERSIONID, ItemVersions_1.COMPONENTTYPEID, ItemVersions_1.ITEMTYPEID FROM ICMSVALLITEM001001 ItemVersions_1, ICMSTLINKS001001 Links_4, ICMSTNLSKEYWORDS NLSKeywords_6 WHERE ((ItemVersions_1.SEMANTICTYPE IN (2, 1000)) AND (((ItemVersions_1.ITEMID = Links_4.TARGETITEMID) AND ((((Links_4.LINKTYPE = NLSKeywords_6.KEYWORDCODE) AND (4 = NLSKeywords_6.KEYWORDCLASS)) AND ('ENU' = NLSKeywords_6.LANGUAGECODE)) AND (NLSKeywords_6.KEYWORDNAME = 'Contains'))) AND (Links_4.SOURCEITEMID = 'A1001001A09D21B65355H33550'))) AND ((( (ItemVersions_1.ITEMTYPEID IN (300, 301, 302, 303, 304, 400, 1000, 1001, 1002, 1003, 1004, 1005, 1006, 1007, 1008, 1009, 1010, 1011, 1012, 1013, 1014, 1015, 1016, 1017, 1018, 1019, 1020, 1021, 1022, 1023, 1024, 1025, 1026, 1027, 1028, 1030, 1031, 1532, 1533, 1534, 1535, 1537, 1538, 1539, 1540, 1541, 1542, 1543, 1544, 1545, 1546, 1547, 1548, 1549, 1550, 1551, 1552, 1553, 1556, 1557, 1558, 1559, 1560, 1561, 1562, 1563) AND ( (EXISTS (SELECT 1 FROM ICMSTCOMPILEDACL C , ICMSTITVIEWDEFS V WHERE ItemVersions_1.ITEMTYPEID=V.ITEMTYPEID AND V.ITEMTYPEVIEWID IN (300, 301, 302, 303, 304, 400, 1000, 1001, 1002, 1003, 1004, 1005, 1006, 1007, 1008, 1009, 1010, 1011, 1012, 1013, 1014, 1015, 1016, 1017, 1018, 1019, 1020, 1021, 1022, 1023, 1024, 1025, 1026, 1027, 1028, 1030, 1031, 1532, 1533, 1534, 1535, 1537, 1538, 1539, 1540, 1541, 1542, 1543, 1544, 1545, 1546, 1547, 1548, 1549, 1550, 1551, 1552, 1553, 1556, 1557, 1558, 1559, 1560, 1561, 1562, 1563) AND (C.ACL = V.ACLCODE OR C.ACL = -1) AND C.UNUM=2 AND C.RPRIV='1' )) OR (EXISTS (SELECT 1 FROM ICMSTCOMPILEDACL C, ICMSTCOMPILEDPERM P , ICMSTITVIEWDEFS V WHERE ItemVersions_1.ITEMTYPEID=V.ITEMTYPEID AND V.ITEMTYPEVIEWID IN (300, 301, 302, 303, 304, 400, 1000, 1001, 1002, 1003, 1004, 1005, 1006, 1007, 1008, 1009, 1010, 1011, 1012, 1013, 1014, 1015, 1016, 1017, 1018, 1019, 1020, 1021, 1022, 1023, 1024, 1025, 1026, 1027, 1028, 1030, 1031, 1532, 1533, 1534, 1535, 1537, 1538, 1539, 1540, 1541, 1542, 1543, 1544, 1545, 1546, 1547, 1548, 1549, 1550, 1551, 1552, 1553, 1556, 1557, 1558, 1559, 1560, 1561, 1562, 1563) AND (C.ACL = V.ACLCODE OR C.ACL = -1) AND C.UNUM=1 AND C.RPRIV='1' AND P.PRIVDEFCODE=121 AND P.UNUM=2 )) )) OR (ItemVersions_1.ITEMTYPEID IN (200, 201, 202, 600, 1536, 1554, 1555, 1564, 1565, 1566) AND ( (EXISTS (SELECT 1 FROM ICMSTCOMPILEDACL C WHERE (C.ACL = ItemVersions_1.ACLCODE OR C.ACL = -1) AND C.UNUM=2 AND C.RPRIV='1' )) OR (EXISTS (SELECT 1 FROM ICMSTCOMPILEDACL C, ICMSTCOMPILEDPERM P WHERE (C.ACL = ItemVersions_1.ACLCODE OR C.ACL = -1) AND C.UNUM=1 AND C.RPRIV='1' AND P.PRIVDEFCODE=121 AND P.UNUM=2 )) )))))) T , ICMSTITEMS001001 I WHERE T.ITEMID = I.ITEMID AND T.VERSIONID = I.VERSIONID>

客户端的登录都发现就是这几个SQL很慢的原因
ICMPLSLU ICMLISTUSER 00122 05/19 07:23:39.187 GMT ; AUTHOR2000 Entry
ICMPLSGU ICMLISTGRPFORUSER 00117 05/19 07:23:39.203 GMT ; AUTHOR2000 Entry
ICMPLSLP ICMLISTPRIVILEGE 00108 05/19 07:23:39.218 GMT ; AUTHOR2000 Entry
ICMPLSLP ICMLISTPRIVILEGE 00110 05/19 07:23:39.234 GMT ; AUTHOR2000 From SP
ICMPLSLU ICMLISTUSER 00122 05/19 07:23:39.250 GMT ; AUTHOR2000 Entry
ICMPLSPI ICMLISTPRIVINSET 00100 05/19 07:23:39.265 GMT ; AUTHOR2000 Entry
ICMPLSQU ICMSEARCH 00328 05/19 07:23:39.625 GMT ; AUTHOR2000 Entry
ICMPLSQU ICMSEARCH 00466 05/19 07:23:39.640 GMT ; AUTHOR2000 3 msec
ICMPLSQU ICMSEARCH 00328 05/19 07:23:46.390 GMT ; AUTHOR2000 Entry
可以看到有明显的等待,都是6s.

Line 1323 : [05/19/2009 08:11:37.281] 1328 D: Creating file mutex: 'gpsfmtx_c:/progra~1/ibm/db2doc~1/dmserver/cache/libs/cm/13_views/13_dm_view.dat'
Line 1371 : [05/19/2009 08:11:37.468] 1328 D: Found the datastorepool at index 0 for the datastore name svtlsdb
Line 1408 : [05/19/2009 08:11:37.468] 1328 D: Item key: GPSFolderDataD00{GPSROOT}
Line 1410 : [05/19/2009 08:11:37.468] 1328 D: Evaluating root folder query: '/GPSFolder [@GPSObjKey = "GPSFolderDataD00{GPSROOT}"]'
Line 1411 : [05/19/2009 08:11:44.453] 1328 D: Root folder not found in 6985ms
Line 1412 : [05/19/2009 08:11:44.453] 1328 D: Number returned: 0
Line 1463 : [05/19/2009 08:11:44.515] 1328 D: Found the datastorepool at index 0 for the datastore name svtlsdb
Line 1498 : [05/19/2009 08:11:44.531] 1328 D: Get folder list command
Line 1501 : [05/19/2009 08:11:44.531] 1328 D: Item key: GPSFolderDataD00{GPSROOT}
Line 1503 : [05/19/2009 08:11:44.531] 1328 D: Evaluating root folder query: '/GPSFolder [@GPSObjKey = "GPSFolderDataD00{GPSROOT}"]'
Line 1504 : [05/19/2009 08:11:50.937] 1328 D: Root folder not found in 6406ms
可以看到每个Xquery需要6秒,解析成的SQL在最上面

附件是Statpack,大牛们给看看吧。
这是程序自动把Xquery解析成的SQL,是很恐怖的,大家看看有啥建议啊?
Re: How to judge the slow query [message #403982 is a reply to message #403978] Tue, 19 May 2009 23:28 Go to previous messageGo to next message
BlackSwan
Messages: 25050
Registered: January 2009
Location: SoCal
Senior Member
I am impressed.
NOT!

You need to help us by following the Posting Guidelines as stated below.
http://www.orafaq.com/forum/t/88153/0/
Go to the URL above click the link "Posting Guidelines"
Go to the section labeled "Practice" & do as directed.
Re: How to judge the slow query? [message #403983 is a reply to message #403981] Tue, 19 May 2009 23:29 Go to previous messageGo to next message
BlackSwan
Messages: 25050
Registered: January 2009
Location: SoCal
Senior Member
do not cross/multi-post!
Re: How to judge the slow query? [message #403985 is a reply to message #403983] Tue, 19 May 2009 23:31 Go to previous messageGo to next message
crazypeter2005
Messages: 29
Registered: September 2008
Location: Peking China
Junior Member
OK, my bad. My chrome just crash.
Re: How to judge the slow query? [message #403987 is a reply to message #403981] Tue, 19 May 2009 23:37 Go to previous messageGo to next message
crazypeter2005
Messages: 29
Registered: September 2008
Location: Peking China
Junior Member
The horrible SQL is parsed by the Client programe
Using Xquery
'/GPSFolder [@GPSObjKey = "GPSFolderDataD00{GPSROOT}"]'

The client login and query a Folder in the MIS called "Root Folder"
and then Query again to check if it contains other folder.

So the query will happen twice.

Same Xquery on DB2 backend will only take 2s but in Oracle Backend it will take 6s for each and doulbe should be 12s.

Re: How to judge the slow query? [message #403989 is a reply to message #403981] Tue, 19 May 2009 23:41 Go to previous messageGo to next message
BlackSwan
Messages: 25050
Registered: January 2009
Location: SoCal
Senior Member
>The horrible SQL is parsed by the Client programe
NO! SQL is parsed by RDBMS engine within Oracle.
Re: How to judge the slow query? [message #403991 is a reply to message #403981] Tue, 19 May 2009 23:46 Go to previous messageGo to next message
crazypeter2005
Messages: 29
Registered: September 2008
Location: Peking China
Junior Member
Yes, you are correct.
And Here is the Server Debug Log.
Re: How to judge the slow query? [message #404090 is a reply to message #403978] Wed, 20 May 2009 05:23 Go to previous messageGo to next message
cookiemonster
Messages: 12422
Registered: September 2008
Location: Rainy Manchester
Senior Member
1) Can you please read the orafaq forum guide that Blackswan has directed you to, especially the bit about code tags. Those queries are unreadable as they stand.
2) Then have a read of the performance tuning sticky at the top of this forum.
3) don't attach zip files - most people will not download them.
4) If you put up formatted queries that we can read along with explain plans we'll take a look.
5) Are both queries running slow?
Re: How to judge the slow query? [message #404261 is a reply to message #403978] Thu, 21 May 2009 02:35 Go to previous messageGo to next message
crazypeter2005
Messages: 29
Registered: September 2008
Location: Peking China
Junior Member
PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
------------------------------------------------------------
Plan hash value: 3938627814

--------------------------------------------------------------------------------
-----------------------
| Id | Operation | Name | Rows | Bytes |
Cost (%CPU)| Time |
--------------------------------------------------------------------------------
-----------------------
| 0 | SELECT STATEMENT | | 502 | 47690 |
13 (0)| 00:00:01 |
|* 1 | FILTER | | | |
| |
|* 2 | INDEX RANGE SCAN | ICMUX02343001001U | 502 | 47690 |
13 (0)| 00:00:01 |
| 3 | NESTED LOOPS | | 1 | 22 |
2 (0)| 00:00:01 |
|* 4 | TABLE ACCESS BY INDEX ROWID | ICMSTITVIEWDEFS | 1 | 12 |
1 (0)| 00:00:01 |
|* 5 | INDEX UNIQUE SCAN | SYS_C004533 | 1 | |
0 (0)| 00:00:01 |
|* 6 | INDEX RANGE SCAN | ICMSXCOMPILEDACL1X | 1 | 10 |
1 (0)| 00:00:01 |
| 7 | NESTED LOOPS | | 1 | 30 |
2 (0)| 00:00:01 |
| 8 | NESTED LOOPS | | 1 | 20 |
1 (0)| 00:00:01 |
|* 9 | TABLE ACCESS BY INDEX ROWID| ICMSTITVIEWDEFS | 1 | 12 |
1 (0)| 00:00:01 |
|* 10 | INDEX UNIQUE SCAN | SYS_C004533 | 1 | |
0 (0)| 00:00:01 |
|* 11 | INDEX UNIQUE SCAN | ICMSXCOMPILEDPRM1U | 1 | 8 |
0 (0)| 00:00:01 |
|* 12 | INDEX RANGE SCAN | ICMSXCOMPILEDACL1X | 1 | 10 |
1 (0)| 00:00:01 |
--------------------------------------------------------------------------------
-----------------------

Predicate Information (identified by operation id):
---------------------------------------------------

1 - filter( EXISTS (SELECT /*+ */ 0 FROM "ICMSTITVIEWDEFS" "V","ICMSTCOMPILED
ACL" "C" WHERE
"C"."UNUM"=2 AND "C"."RPRIV"='1' AND ("C"."ACL"="V"."ACLCODE" OR "
C"."ACL"=(-1)) AND
"V"."ITEMTYPEVIEWID"=1533 AND "V"."ITEMTYPEID"=1533) OR EXISTS (S
ELECT /*+ */ 0 FROM
"ICMSTITVIEWDEFS" "V","ICMSTCOMPILEDPERM" "P","ICMSTCOMPILEDACL" "
C" WHERE "C"."UNUM"=1 AND
"C"."RPRIV"='1' AND ("C"."ACL"="V"."ACLCODE" OR "C"."ACL"=(-1)) AN
D "P"."PRIVDEFCODE"=121 AND
"P"."UNUM"=2 AND "V"."ITEMTYPEVIEWID"=1533 AND "V"."ITEMTYPEID"=15
33))
2 - access("GPSFOLDER_1"."ATTR0000002084"='GPSFolderData♣D♠00♣{GPSROOT}')
4 - filter("V"."ITEMTYPEID"=1533)
5 - access("V"."ITEMTYPEVIEWID"=1533)
6 - access("C"."UNUM"=2 AND "C"."RPRIV"='1')
filter("C"."RPRIV"='1' AND ("C"."ACL"="V"."ACLCODE" OR "C"."ACL"=(-1)))
9 - filter("V"."ITEMTYPEID"=1533)
10 - access("V"."ITEMTYPEVIEWID"=1533)
11 - access("P"."UNUM"=2 AND "P"."PRIVDEFCODE"=121)
12 - access("C"."UNUM"=1 AND "C"."RPRIV"='1')
filter("C"."RPRIV"='1' AND ("C"."ACL"="V"."ACLCODE" OR "C"."ACL"=(-1)))

39 rows selected.

SQL>
Re: How to judge the slow query? [message #404301 is a reply to message #403978] Thu, 21 May 2009 05:07 Go to previous messageGo to next message
crazypeter2005
Messages: 29
Registered: September 2008
Location: Peking China
Junior Member
Thanks everyone. I check the SQL plan and both are not slow.
It is the client problem

[05/21/2009 09:03:14.250] 1484 T: -- DKRESULTSETCURSORICM::ISVALID()
[05/21/2009 09:03:14.250] 1484 T: - DKRESULTSETCURSORICM::ISBEGIN()=> result: 1
[05/21/2009 09:03:14.250] 1484 T: -- DKRESULTSETCURSORICM::ISBEGIN()
[05/21/2009 09:03:14.250] 1484 T: -+ DKRESULTSETCURSORICM::LOADDDOBLOCK()
[05/21/2009 09:03:14.250] 1484 T: -+ DKRESULTSETCURSORICM::FETCHNEXTMATCH()
[We can see Jump Here, This Function might has problem]

[05/21/2009 09:03:21.656] 1484 T: -- DKRESULTSETCURSORICM::FETCHNEXTMATCH()
[05/21/2009 09:03:21.656] 1484 T: - DKRESULTSETCURSORICM::LOADDDOBLOCK()=> Storing block item: 0

But on DB2 backend, the function works well.
That is to say:
The Oracle has already compute the result but the client programe has not receieve it for 6s.
Need to rewrite the connect programe...
Thanks again!
Re: How to judge the slow query? [message #405886 is a reply to message #403978] Sun, 31 May 2009 01:43 Go to previous messageGo to next message
crazypeter2005
Messages: 29
Registered: September 2008
Location: Peking China
Junior Member
1.gif is the sql that seems "slow", actually it might because of client programe caused.
2.gif is the fast sql that is normal.

2 sql has minor difference in the last sentence.

SELECT /*+ FIRST_ROWS (500) */ T.* FROM (SELECT DISTINCT GPSFolder_1.ITEMID, GPSFolder_1.COMPONENTID, GPSFolder_1.VERSIONID, 2343 AS COMPONENTTYPEID, 1533 AS ITEMTYPEID FROM ICMUT02343001 GPSFolder_1 WHERE (GPSFolder_1.ATTR0000002084 = 'GPSFolderDataD00{GPSROOT}') AND (((( ( (EXISTS (SELECT 1 FROM ICMSTCOMPILEDACL C , ICMSTITVIEWDEFS V WHERE 1533=V.ITEMTYPEID AND V.ITEMTYPEVIEWID IN (1533) AND (C.ACL = V.ACLCODE OR C.ACL = -1) AND C.UNUM=2 AND C.RPRIV='1' )) OR (EXISTS (SELECT 1 FROM ICMSTCOMPILEDACL C, ICMSTCOMPILEDPERM P , ICMSTITVIEWDEFS V WHERE 1533=V.ITEMTYPEID AND V.ITEMTYPEVIEWID IN (1533) AND (C.ACL = V.ACLCODE OR C.ACL = -1) AND C.UNUM=1 AND C.RPRIV='1' AND P.PRIVDEFCODE=121 AND P.UNUM=2 )) )))))) T , ICMSTITEMS001001 I WHERE T.ITEMID = I.ITEMID AND T.VERSIONID = I.VERSIONID

SELECT /*+ FIRST_ROWS (500) */ T.* FROM (SELECT DISTINCT GPSFolder_1.ITEMID, GPSFolder_1.COMPONENTID, GPSFolder_1.VERSIONID, 2343 AS COMPONENTTYPEID, 1533 AS ITEMTYPEID FROM ICMUT02343001 GPSFolder_1 WHERE (GPSFolder_1.ATTR0000002084 = 'GPSFolderDataD00{GPSROOT}') AND (((( ( (EXISTS (SELECT 1 FROM ICMSTCOMPILEDACL C , ICMSTITVIEWDEFS V WHERE 1533=V.ITEMTYPEID AND V.ITEMTYPEVIEWID IN (1533) AND (C.ACL = V.ACLCODE OR C.ACL = -1) AND C.UNUM=2 AND C.RPRIV='1' )) OR (EXISTS (SELECT 1 FROM ICMSTCOMPILEDACL C, ICMSTCOMPILEDPERM P , ICMSTITVIEWDEFS V WHERE 1533=V.ITEMTYPEID AND V.ITEMTYPEVIEWID IN (1533) AND (C.ACL = V.ACLCODE OR C.ACL = -1) AND C.UNUM=1 AND C.RPRIV='1' AND P.PRIVDEFCODE=121 AND P.UNUM=2 )) )))))) T
  • Attachment: 1.GIF
    (Size: 34.59KB, Downloaded 121 times)
Re: How to judge the slow query? [message #405887 is a reply to message #403978] Sun, 31 May 2009 01:43 Go to previous messageGo to next message
crazypeter2005
Messages: 29
Registered: September 2008
Location: Peking China
Junior Member
No Message Body
  • Attachment: 2.GIF
    (Size: 25.63KB, Downloaded 118 times)
Re: How to judge the slow query? [message #405888 is a reply to message #403978] Sun, 31 May 2009 01:44 Go to previous messageGo to next message
crazypeter2005
Messages: 29
Registered: September 2008
Location: Peking China
Junior Member
Any ideas about the 2 different sql and related explan?
I don`t wanna dig into code to find out why.
Re: How to judge the slow query? [message #405904 is a reply to message #403978] Sun, 31 May 2009 10:05 Go to previous messageGo to next message
BlackSwan
Messages: 25050
Registered: January 2009
Location: SoCal
Senior Member
>I don`t wanna dig into code to find out why.
Neither do we.
Re: How to judge the slow query? [message #405944 is a reply to message #403978] Mon, 01 June 2009 01:33 Go to previous messageGo to next message
crazypeter2005
Messages: 29
Registered: September 2008
Location: Peking China
Junior Member
I have a question:
I have 2 ways to get statistic info on tables
1 exec dbms_stats.gather_schema_stats(ownname=>'svtlsadm',cascade=>TRUE);

2 Use analyse tables

This slow sql can be solved by using the second method.

What is the difference?
Why the first method fails to get the correct info, and leads a big table full scan?

Any ideas?
Thanks!


Re: How to judge the slow query? [message #405948 is a reply to message #403978] Mon, 01 June 2009 01:40 Go to previous messageGo to next message
crazypeter2005
Messages: 29
Registered: September 2008
Location: Peking China
Junior Member
In this sql:
SELECT /*+ FIRST_ROWS (500) */ T.* FROM (SELECT DISTINCT GPSFolder_1.ITEMID, GPSFolder_1.COMPONENTID, GPSFolder_1.VERSIONID, 2343 AS COMPONENTTYPEID, 1533 AS ITEMTYPEID FROM ICMUT02343001 GPSFolder_1 WHERE (GPSFolder_1.ATTR0000002084 = 'GPSFolderDataD00{GPSROOT}') AND (((( ( (EXISTS (SELECT 1 FROM ICMSTCOMPILEDACL C , ICMSTITVIEWDEFS V WHERE 1533=V.ITEMTYPEID AND V.ITEMTYPEVIEWID IN (1533) AND (C.ACL = V.ACLCODE OR C.ACL = -1) AND C.UNUM=2 AND C.RPRIV='1' )) OR (EXISTS (SELECT 1 FROM ICMSTCOMPILEDACL C, ICMSTCOMPILEDPERM P , ICMSTITVIEWDEFS V WHERE 1533=V.ITEMTYPEID AND V.ITEMTYPEVIEWID IN (1533) AND (C.ACL = V.ACLCODE OR C.ACL = -1) AND C.UNUM=1 AND C.RPRIV='1' AND P.PRIVDEFCODE=121 AND P.UNUM=2 )) )))))) T , ICMSTITEMS001001 I WHERE T.ITEMID = I.ITEMID AND T.VERSIONID = I.VERSIONID

If I use dbms_stats.gather_table_stats, the sql will choose full scan large table ICMSTITEMS001001 which has 20M data.

But if I use analyze table on ICMSTITEMS001001 , the sql will use index on ICMSTITEMS001001.

Why is that?
Does oracle suggest us to use dbms_stats.gather_table_stats, it is provide by Oracle, isn`t it?
Re: How to judge the slow query? [message #405978 is a reply to message #403978] Mon, 01 June 2009 04:49 Go to previous message
crazypeter2005
Messages: 29
Registered: September 2008
Location: Peking China
Junior Member
I finally find out why.
It is the tester who execute wrong tune db script:
dbms_stats.gather_schema_stats(ownname=>'svtlsadm',cascade=>TRUE);
when dbms_stats.gather_schema_stats run without option clause,
it will NOT collect Histograms. So oracle has choose a bad plan
large table full scan.
when I execute
execute dbms_stats.gather_schema_stats(ownname =>'svtlsadm',estimate_percent =>
dbms_stats.auto_sample_size,method_opt=>'for all columns size auto', cascade=>true);


Before analyse the table:
1: query is too slow,the resp time is 32s,u can find TABLE ACCESS FULL: ICMSTITEMS001001,this is not permitted here

SQL> select count(*) from ICMUT02343001;

COUNT(*)
----------
50718

SQL> select count(*) from ICMSTITEMS001001;

COUNT(*)
----------
2723582

SQL>

SQL> SELECT /*+ FIRST_ROWS (500) */
2 T.*
3 FROM (SELECT DISTINCT GPSFolder_1.ITEMID,
4 GPSFolder_1.COMPONENTID,
5 GPSFolder_1.VERSIONID,
6 2343 AS COMPONENTTYPEID,
7 1533 AS ITEMTYPEID
8 FROM svtlsadm.ICMUT02343001 GPSFolder_1
9 WHERE (GPSFolder_1.ATTR0000002084 = 'GPSFolderData^ED^F00^E{GPSROOT}')
10 AND ((((((EXISTS (SELECT 1
11 FROM svtlsadm.ICMSTCOMPILEDACL C, svtlsadm.ICMSTITVIEWDEFS V
12 WHERE 1533 = V.ITEMTYPEID
13 AND V.ITEMTYPEVIEWID IN (1533)
14 AND (C.ACL = V.ACLCODE OR C.ACL = -1)
15 AND C.UNUM = 2
16 AND C.RPRIV = '1')) OR
17 (EXISTS (SELECT 1
18 FROM svtlsadm.ICMSTCOMPILEDACL C,
19 svtlsadm.ICMSTCOMPILEDPERM P,
20 svtlsadm.ICMSTITVIEWDEFS V
21 WHERE 1533 = V.ITEMTYPEID
22 AND V.ITEMTYPEVIEWID IN (1533)
23 AND (C.ACL = V.ACLCODE OR C.ACL = -1)
24 AND C.UNUM = 1
25 AND C.RPRIV = '1'
26 AND P.PRIVDEFCODE = 121
27 AND P.UNUM = 2)))))))) T,
28 svtlsadm.ICMSTITEMS001001 I
29 WHERE T.ITEMID = I.ITEMID
30 AND T.VERSIONID = I.VERSIONID;

Elapsed: 00:00:32.43

| 0 | SELECT STATEMENT| | 502 | 61746 |15(0)|00:00:01 |
|* 1 | FILTER | | | | |
| 2 | NESTED LOOPS | 502 | 61746 |15(0)|00:00:01 |
| 3 | TABLE ACCESS FULL | ICMSTITEMS001001| 502 | 14056 |4 (0)| 00:00:01 |
|* 4 | TABLE ACCESS BY INDEX ROWID | ICMUT02343001 | 1 | 95 |1 (0)| 00:00:01 |
|* 5 | INDEX UNIQUE SCAN | ICMUX023430011U | 1 | |0 (0)| 00:00:01 |
| 6 | NESTED LOOPS | | 1 | 22 |2 (0)| 00:00:01 |
|* 7 | TABLE ACCESS BY INDEX ROWID | ICMSTITVIEWDEFS | 1 | 12 |1 (0)| 00:00:01 |
|* 8 | INDEX UNIQUE SCAN | SYS_C004533 | 1 | | 0 (0)| 00:00:01 |
|* 9 | INDEX RANGE SCAN | ICMSXCOMPILEDACL1X | 1 | 10 |1 (0)| 00:00:01 |
| 10 | NESTED LOOPS | | 1 | 30 |2 (0)| 00:00:01 |
| 11 | NESTED LOOPS | | 1 | 20 |1 (0)| 00:00:01 |
|* 12 | TABLE ACCESS BY INDEX ROWID| ICMSTITVIEWDEFS | 1 | 12 |1 (0)| 00:00:01 |
|* 13 | INDEX UNIQUE SCAN | SYS_C004533 | 1 | |0 (0)| 00:00:01 |
|* 14 | INDEX UNIQUE SCAN | ICMSXCOMPILEDPRM1U | 1 | 8 |0 (0)| 00:00:01 |
|* 15 | INDEX RANGE SCAN | ICMSXCOMPILEDACL1X | 1 | 10 |1 (0)| 00:00:01 |

--------------------------------------------------------------------------------

After analyse the table:
SQL>analyze table ICMSTITEMS001001 compute statistics for all indexes for all indexed columns;
SQL>analyze table ICMUT02343001 compute statistics for all indexes for all indexed columns;

SQL> SELECT /*+ FIRST_ROWS (500) */ T.*
2 FROM svtlsadm.ICMSTITEMS001001 I,(SELECT DISTINCT GPSFolder_1.ITEMID,
3 GPSFolder_1.COMPONENTID,
4 GPSFolder_1.VERSIONID,
5 2343 AS COMPONENTTYPEID,
6 1533 AS ITEMTYPEID
7 FROM svtlsadm.ICMUT02343001 GPSFolder_1
8 WHERE (GPSFolder_1.ATTR0000002084 = 'GPSFolderData^ED^F00^E{GPSROO
T}')
9 AND ((((((EXISTS (SELECT 1
10 FROM svtlsadm.ICMSTCOMPILEDACL C, svtlsadm.I
CMSTITVIEWDEFS V
11 WHERE 1533 = V.ITEMTYPEID
12 AND V.ITEMTYPEVIEWID IN (1533)
13 AND (C.ACL = V.ACLCODE OR C.ACL = -1)
14 AND C.UNUM = 2
15 AND C.RPRIV = '1')) OR
16 (EXISTS (SELECT 1
17 FROM svtlsadm.ICMSTCOMPILEDACL C,
18 svtlsadm.ICMSTCOMPILEDPERM P,
19 svtlsadm.ICMSTITVIEWDEFS V
20 WHERE 1533 = V.ITEMTYPEID
21 AND V.ITEMTYPEVIEWID IN (1533)
22 AND (C.ACL = V.ACLCODE OR C.ACL = -1)
23 AND C.UNUM = 1
24 AND C.RPRIV = '1'
25 AND P.PRIVDEFCODE = 121
26 AND P.UNUM = 2)))))))) T
27 WHERE T.ITEMID = I.ITEMID
28 AND T.VERSIONID = I.VERSIONID;

ITEMID COMPONENTID VERSIONID COMPONENTTYPEID
-------------------------- ------------------ ---------- ---------------
ITEMTYPEID
----------
A1001001A09E31B53346H12088 A09E31B53346H12088 1 2343
1533

Elapsed: 00:00:00.02

Execution Plan
----------------------------------------------------------
Plan hash value: 3614278029

--------------------------------------------------------------------------------


| 0 | SELECT STATEMENT | | 54 | 6426 |
5 (0)| 00:00:01 |

|* 1 | FILTER | | | | | |
| 2 | NESTED LOOPS | | 54 | 6426 | 5 (0)| 00:00:01 |
|* 3 | INDEX RANGE SCAN | ICMUX02343001001U | 1 | 91 |3 (0)| 00:00:01 |
|* 4 | TABLE ACCESS BY INDEX ROWID | ICMSTITEMS001001 | 54 | 1512 | 2 (0)| 00:00:01 |
|* 5 | INDEX UNIQUE SCAN | SYS_C004613 | 1 | | 1 (0)| 00:00:01 |
| 6 | NESTED LOOPS | | 1 | 22 | 2 (0)| 00:00:01 |
|* 7 | TABLE ACCESS BY INDEX ROWID | ICMSTITVIEWDEFS | 1 | 12 | 1 (0)| 00:00:01 |
|* 8 | INDEX UNIQUE SCAN | SYS_C004533 | 1 | | 0 (0)| 00:00:01 |
|* 9 | INDEX RANGE SCAN | ICMSXCOMPILEDACL1X | 1 | 10 | 1 (0)| 00:00:01 |
| 10 | NESTED LOOPS | | 1 | 30 | 2 (0)| 00:00:01 |
| 11 | NESTED LOOPS | | 1 | 20 | 1 (0)| 00:00:01 |
|* 12 | TABLE ACCESS BY INDEX ROWID| ICMSTITVIEWDEFS | 1 | 12 | 1 (0)| 00:00:01 |
|* 13 | INDEX UNIQUE SCAN | SYS_C004533 | 1 | | 0 (0)| 00:00:01 |
|* 14 | INDEX UNIQUE SCAN | ICMSXCOMPILEDPRM1U | 1 | 8 | 0 (0)| 00:00:01 |
|* 15 | INDEX RANGE SCAN | ICMSXCOMPILEDACL1X | 1 | 10 | 1 (0)| 00:00:01 |

--------------------------------------------------------------------------------
Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
11 consistent gets
0 physical reads
0 redo size
708 bytes sent via SQL*Net to client
396 bytes received via SQL*Net from client
2 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
1 rows processed

SQL>

Problem solved.

It is a shame that I am the tester that use the wrong script.
But I am glad to learn this.
I am a newbie on oracle and I should learn more from your guys.
Thanks BlackSwan.
You helped me a lot!

[Updated on: Mon, 01 June 2009 10:16]

Report message to a moderator

Previous Topic: IOT - what is that?
Next Topic: stale_stats and STATTYPE_LOCKED in DBA_TAB_STATISTICS
Goto Forum:
  


Current Time: Sat Dec 10 22:39:48 CST 2016

Total time taken to generate the page: 0.09863 seconds