Home » RDBMS Server » Performance Tuning » performance problem
| performance problem [message #276320] |
Wed, 24 October 2007 16:19  |
Nokia
Messages: 15
Registered: July 2007
|
Junior Member |
|
|
SELECT DV.DVC_TID_NEID AS DEVICEID, MP.MP_SLOT AS SLOT, MP.MP_SUBSLOT AS SUBSLOT, MP.MP_PORT AS PORT,
MP.MP_INTERFACE AS INTERFACE,
MP.MP_SUBINTERFACE AS SUBINTERFACE, L3.L3_PE_IP_ADDRESS AS IP, CC.CCIRC_COMMITTED_INFO_RATE AS SPEED,
MP.MP_USAGE AS USAGE, MP.MP_DEPLOYMENT_STATUS AS STATUS, MP.MP_SLOT_TYPE AS PORTTYPE,
(CASE WHEN CC.CCIRC_NAME LIKE '%FAR_END%' THEN SUBSTR ( CC.CCIRC_NAME, 10, 90) ELSE CC.CCIRC_NAME END)
AS SITE, CC.CCIRC_COMMITTED_INFO_RATE
AS CIRCUITTYPE, CC.CCIRC_COMMENT AS COMMENTS,
MP.MP_CARD_TYPE AS INTERFACETYPE FROM DEVICE DV
INNER JOIN NETWORK_CLASS NT ON
NT.NETWORK_HASH = DV.NETWORK_HASH AND NT.SRC = DV.SRC
INNER JOIN MONITORING_POINT MP ON
MP.DVC_HASH = DV.DVC_HASH AND MP.SRC = DV.SRC LEFT JOIN LAYER3_DESCRIPTOR L3 ON L3.MP_HASH=MP.MP_HASH AND
L3.SRC = MP.SRC LEFT JOIN CUSTOMER_CIRCUIT CC
ON CC.MP_HASH_1 = MP.MP_HASH AND CC.SRC = MP.SRC WHERE NT.NETWORK_TYPE = 'PUBLIC IP INTERFACES' AND
MP.MP_USAGE <>'UPLINK' AND DV.SRC = 'LGL' ORDER BY DV.DVC_TID_NEID;
Tkprof Report
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.03 0.03 0 0 0 0
Execute 1 0.01 0.03 0 30 0 0
Fetch 2919 10.10 22.00 55963 82785 0 43771
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2921 10.14 22.06 55963 82815 0 43771
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
PX Deq: Join ACK 5 0.00 0.00
PX Deq Credit: send blkd 83 1.95 7.83
PX Deq: Parse Reply 6 0.00 0.01
SQL*Net message to client 2920 0.00 0.01
PX Deq: Execute Reply 78 0.41 0.94
db file sequential read 2478 0.00 0.07
db file scattered read 4698 0.00 0.98
PX Deq Credit: need buffer 43 0.00 0.02
db file parallel read 1 0.00 0.00
PX qref latch 2 0.00 0.00
SQL*Net message from client 2920 10.85 904.01
PX Deq: Table Q qref 2 0.00 0.00
SQL*Net break/reset to client 1 0.00 0.00
PX Deq: Signal ACK 4 0.00 0.01
latch: session allocation 1 0.00 0.00
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.03 0.03 0 0 0 0
Execute 1 0.01 0.03 0 30 0 0
Fetch 2919 10.10 22.00 55963 82785 0 43771
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2921 10.14 22.06 55963 82815 0 43771
Explain plan
| Id | Operation | Name | Rows | Bytes |TempSpc| Cost (%CPU)| Time | Pstart| Pstop | TQ |IN-OUT| PQ Distrib |
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 9117 | 1727K| | 20661 (3)| 00:04:08 | | | | | |
| 1 | PX COORDINATOR | | | | | | | | | | | |
| 2 | PX SEND QC (ORDER) | :TQ10008 | 9117 | 1727K| | 20661 (3)| 00:04:08 | | | Q1,08 | P->S | QC (ORDER) |
| 3 | SORT ORDER BY | | 9117 | 1727K| 3656K| 20661 (3)| 00:04:08 | | | Q1,08 | PCWP | |
| 4 | PX RECEIVE | | 9117 | 1727K| | 20270 (3)| 00:04:04 | | | Q1,08 | PCWP | |
| 5 | PX SEND RANGE | :TQ10007 | 9117 | 1727K| | 20270 (3)| 00:04:04 | | | Q1,07 | P->P | RANGE |
PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
|* 6 | HASH JOIN OUTER | | 9117 | 1727K| 1224K| 20270 (3)| 00:04:04 | | | Q1,07 | PCWP | |
| 7 | PX RECEIVE | | 6971 | 1136K| | 15867 (3)| 00:03:11 | | | Q1,07 | PCWP | |
| 8 | PX SEND HASH | :TQ10006 | 6971 | 1136K| | 15867 (3)| 00:03:11 | | | Q1,06 | P->P | HASH |
|* 9 | HASH JOIN OUTER | | 6971 | 1136K| | 15867 (3)| 00:03:11 | | | Q1,06 | PCWP | |
| 10 | PX RECEIVE | | 6096 | 767K| | 8236 (3)| 00:01:39 | | | Q1,06 | PCWP | |
| 11 | PX SEND HASH | :TQ10005 | 6096 | 767K| | 8236 (3)| 00:01:39 | | | Q1,05 | P->P | HASH |
|* 12 | HASH JOIN | | 6096 | 767K| | 8236 (3)| 00:01:39 | | | Q1,05 | PCWP | |
| 13 | PX RECEIVE | | 521 | 35428 | | 87 (0)| 00:00:02 | | | Q1,05 | PCWP | |
| 14 | PX SEND HASH | :TQ10004 | 521 | 35428 | | 87 (0)| 00:00:02 | | | Q1,04 | P->P | HASH |
| 15 | NESTED LOOPS | | 521 | 35428 | | 87 (0)| 00:00:02 | | | Q1,04 | PCWP | |
| 16 | BUFFER SORT | | | | | | | | | Q1,04 | PCWC | |
PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
| 17 | PX RECEIVE | | | | | | | | | Q1,04 | PCWP | |
| 18 | PX SEND BROADCAST | :TQ10000 | | | | | | | | | S->P | BROADCAST |
| 19 | TABLE ACCESS BY INDEX ROWID | NETWORK_CLASS | 1 | 25 | | 1 (0)| 00:00:01 | | | | | |
|* 20 | INDEX UNIQUE SCAN | NETWORK_CLASS_IDX2 | 1 | | | 0 (0)| 00:00:01 | | | | | |
| 21 | PX PARTITION HASH ALL | | 521 | 22403 | | 86 (0)| 00:00:02 | 1 | 10 | Q1,04 | PCWC | |
| 22 | TABLE ACCESS BY LOCAL INDEX ROWID| DEVICE | 521 | 22403 | | 86 (0)| 00:00:02 | 1 | 10 | Q1,04 | PCWP | |
|* 23 | INDEX RANGE SCAN | DEVICE_NETWORK_IDX5 | 521 | | | 10 (0)| 00:00:01 | 1 | 10 | Q1,04 | PCWP | |
| 24 | BUFFER SORT | | | | | | | | | Q1,05 | PCWC | |
| 25 | PX RECEIVE | | 291K| 16M| | 8146 (3)| 00:01:38 | | | Q1,05 | PCWP | |
| 26 | PX SEND HASH | :TQ10001 | 291K| 16M| | 8146 (3)| 00:01:38 | | | | S->P | HASH |
| 27 | PARTITION HASH ALL | | 291K| 16M| | 8146 (3)| 00:01:38 | 1 | 10 | | | |
PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
|* 28 | TABLE ACCESS FULL | MONITORING_POINT | 291K| 16M| | 8146 (3)| 00:01:38 | 1 | 10 | | | |
| 29 | BUFFER SORT | | | | | | | | | Q1,06 | PCWC | |
| 30 | PX RECEIVE | | 679K| 24M| | 7623 (2)| 00:01:32 | | | Q1,06 | PCWP | |
| 31 | PX SEND HASH | :TQ10002 | 679K| 24M| | 7623 (2)| 00:01:32 | | | | S->P | HASH |
| 32 | PARTITION HASH ALL | | 679K| 24M| | 7623 (2)| 00:01:32 | 1 | 10 | | | |
|* 33 | TABLE ACCESS FULL | CUSTOMER_CIRCUIT | 679K| 24M| | 7623 (2)| 00:01:32 | 1 | 10 | | | |
| 34 | BUFFER SORT | | | | | | | | | Q1,07 | PCWC | |
| 35 | PX RECEIVE | | 496K| 12M| | 3415 (3)| 00:00:41 | | | Q1,07 | PCWP | |
| 36 | PX SEND HASH | :TQ10003 | 496K| 12M| | 3415 (3)| 00:00:41 | | | | S->P | HASH |
|* 37 | TABLE ACCESS FULL | LAYER3_DESCRIPTOR | 496K| 12M| | 3415 (3)| 00:00:41 | | | | | |
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Statistics are updated.
[Updated on: Wed, 24 October 2007 16:21] Report message to a moderator |
|
|
|
| Re: performance problem [message #276321 is a reply to message #276320] |
Wed, 24 October 2007 16:28  |
Nokia
Messages: 15
Registered: July 2007
|
Junior Member |
|
|
Indexes
INDEX_NAME COLUMN_NAME TABLE_NAME
------------------------------ ------------------------------ ------------------------------
CCIRC_MP_FK_IDX_MP_FK1 MP_HASH_1 CUSTOMER_CIRCUIT
CCIRC_MP_FK_IDX_MP_FK1 SRC CUSTOMER_CIRCUIT
CCIRC_MP_FK_IDX_MP_FK2 MP_HASH_2 CUSTOMER_CIRCUIT
CCIRC_MP_FK_IDX_MP_FK2 SRC CUSTOMER_CIRCUIT
CCIRC_PK_IDX CCIRC_HASH CUSTOMER_CIRCUIT
CCIRC_PK_IDX SRC CUSTOMER_CIRCUIT
CCIRC_IDX1 CUST_HASH CUSTOMER_CIRCUIT
CCIRC_IDX1 CCIRC_ID CUSTOMER_CIRCUIT
CCIRC_IDX1 SRC CUSTOMER_CIRCUIT
DEVICE_PK_IDX DVC_HASH DEVICE
DEVICE_PK_IDX SRC DEVICE
INDEX_NAME COLUMN_NAME TABLE_NAME
------------------------------ ------------------------------ ------------------------------
DEVICE_IDX1 DVC_TID_NEID DEVICE
DEVICE_IDX1 NETWORK_HASH DEVICE
DEVICE_IDX1 SRC DEVICE
DEVICE_STATION_IDX2 SITE_HASH DEVICE
DEVICE_STATION_IDX2 SRC DEVICE
DEVICE_DM_MODEL_NAME_IDX3 DM_HASH DEVICE
DEVICE_DM_MODEL_NAME_IDX3 SRC DEVICE
DEVICE_CONC_NAME_IDX4 CONC_HASH_1 DEVICE
DEVICE_CONC_NAME_IDX4 NETWORK_HASH DEVICE
DEVICE_CONC_NAME_IDX4 CONC_HASH_2 DEVICE
DEVICE_CONC_NAME_IDX4 SRC DEVICE
INDEX_NAME COLUMN_NAME TABLE_NAME
------------------------------ ------------------------------ ------------------------------
DEVICE_NETWORK_IDX5 NETWORK_HASH DEVICE
DEVICE_NETWORK_IDX5 SRC DEVICE
LAYER3_DESCRIPTOR_PK_IDX MP_HASH LAYER3_DESCRIPTOR
LAYER3_DESCRIPTOR_PK_IDX SRC LAYER3_DESCRIPTOR
MP_PK_IDX MP_HASH MONITORING_POINT
MP_PK_IDX SRC MONITORING_POINT
MP_IDX1 DVC_HASH MONITORING_POINT
MP_IDX1 MP_AID MONITORING_POINT
MP_IDX2 SRC MONITORING_POINT
NETWORK_CLASS_PK_IDX NETWORK_HASH NETWORK_CLASS
NETWORK_CLASS_PK_IDX SRC NETWORK_CLASS
INDEX_NAME COLUMN_NAME TABLE_NAME
------------------------------ ------------------------------ ------------------------------
NETWORK_CLASS_IDX2 NETWORK_TYPE NETWORK_CLASS
NETWORK_CLASS_IDX2 SRC NETWORK_CLASS
|
|
|
|
| Re: performance problem [message #276338 is a reply to message #276321] |
Wed, 24 October 2007 22:24 |
rleishman
Messages: 3728
Registered: October 2005
Location: Melbourne, Australia
|
Senior Member |
|
|
That's a very long time for doing not much work.
- There are no enormous full table scans
- The only index range scan is bounded with no filtering and executed once only.
- The volumes processed - mostly full scans - are quite small.
I wonder if the overheads of all that parallelism is causing a problem?
Try it with NOPARALLEL hints on all tables and post the Tk*Prof of that.
Also, is there any recursive SQL? Post the recursive SQL results from the bottom of the TK Prof report.
Ross Leishman
|
|
|
|
|
|
| Re: performance problem [message #276340 is a reply to message #276339] |
Wed, 24 October 2007 22:38 |
rleishman
Messages: 3728
Registered: October 2005
Location: Melbourne, Australia
|
Senior Member |
|
|
Good point - use array fetches instead. What language is the client program written in?
Having said that, I've seen what I judge to be spurious Message From Client waits before, but I doubt yours are spurious since they match exactly with the rows fetched.
Ross Leishman
|
|
|
|
| Re: performance problem [message #276616 is a reply to message #276340] |
Thu, 25 October 2007 11:13 |
Nokia
Messages: 15
Registered: July 2007
|
Junior Member |
|
|
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 2 0.00 0.00 0 0 0 0
Execute 2 0.00 0.00 0 0 0 0
Fetch 2 0.02 0.00 0 0 2 2
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 6 0.02 0.00 0 0 2 2
Misses in library cache during parse: 0
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------
1 SEQUENCE ORA_TQ_BASE$ (cr=1 pr=0 pw=0 time=2296 us)
1 FAST DUAL (cr=0 pr=0 pw=0 time=7 us)
********************************************************************************
update seq$ set increment$=:2,minvalue=:3,maxvalue=:4,cycle#=:5,order$=:6,
cache=:7,highwater=:8,audit$=:9,flags=:10
where
obj#=:1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 2 0.00 0.00 0 0 0 0
Execute 2 0.00 0.00 0 2 4 2
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.00 0.00 0 2 4 2
Misses in library cache during parse: 0
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 2)
Rows Row Source Operation
------- ---------------------------------------------------
1 UPDATE SEQ$ (cr=1 pr=0 pw=0 time=456 us)
1 INDEX UNIQUE SCAN I_SEQ1 (cr=1 pr=0 pw=0 time=42 us)(object id 102)
********************************************************************************
SELECT
DV.DVC_TID_NEID AS DEVICEID, MP.MP_SLOT AS SLOT, MP.MP_SUBSLOT AS SUBSLOT, MP.MP_PORT AS PORT, MP.MP_INTERFACE AS INTERFACE, MP.MP_SUBINTERFACE AS SUBINTERFA
CE, L3.L3_PE_IP_ADDRESS AS IP, CC.CCIRC_COMMITTED_INFO_RATE AS SPEED, MP.MP_USAGE AS USAGE, MP.MP_DEPLOYMENT_STATUS AS STATUS, MP.MP_SLOT_TYPE AS PORTTYPE, (
CASE WHEN CC.CCIRC_NAME LIKE '%FAR_END%' THEN SUBSTR ( CC.CCIRC_NAME, 10, 90) ELSE CC.CCIRC_NAME END) AS SITE, CC.CCIRC_COMMITTED_INFO_RATE AS CIRCUITTYPE, C
C.CCIRC_COMMENT AS COMMENTS, MP.MP_CARD_TYPE AS INTERFACETYPE FROM DEVICE DV INNER JOIN NETWORK_CLASS NT ON NT.NETWORK_HASH = DV.NETWORK_HASH AND NT.SRC = DV
.SRC INNER JOIN MONITORING_POINT MP ON MP.DVC_HASH = DV.DVC_HASH AND MP.SRC = DV.SRC LEFT JOIN LAYER3_DESCRIPTOR L3 ON L3.MP_HASH=MP.MP_HASH AND L3.SRC = MP.
SRC LEFT JOIN CUSTOMER_CIRCUIT CC ON CC.MP_HASH_1 = MP.MP_HASH AND CC.SRC = MP.SRC WHERE NT.NETWORK_TYPE = 'PUBLIC IP INTERFACES' AND MP.MP_USAGE <>'UPLINK'
AND DV.SRC = 'LGL' ORDER BY DV.DVC_TID_NEID
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.03 0.03 0 0 0 0
Execute 1 0.00 0.34 0 30 0 0
Fetch 1 7.32 13.42 41511 71088 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 7.35 13.80 41511 71118 0 0
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 53
Rows Row Source Operation
------- ---------------------------------------------------
0 PX COORDINATOR (cr=30 pr=0 pw=0 time=345258 us)
0 PX SEND QC (ORDER) :TQ10008 (cr=0 pr=0 pw=0 time=0 us)
0 SORT ORDER BY (cr=0 pr=0 pw=0 time=0 us)
0 PX RECEIVE (cr=0 pr=0 pw=0 time=0 us)
0 PX SEND RANGE :TQ10007 (cr=0 pr=0 pw=0 time=0 us)
0 HASH JOIN OUTER (cr=0 pr=0 pw=0 time=0 us)
0 PX RECEIVE (cr=0 pr=0 pw=0 time=0 us)
0 PX SEND HASH :TQ10006 (cr=0 pr=0 pw=0 time=0 us)
0 HASH JOIN OUTER (cr=0 pr=0 pw=0 time=0 us)
0 PX RECEIVE (cr=0 pr=0 pw=0 time=0 us)
0 PX SEND HASH :TQ10005 (cr=0 pr=0 pw=0 time=0 us)
0 HASH JOIN (cr=0 pr=0 pw=0 time=0 us)
0 PX RECEIVE (cr=0 pr=0 pw=0 time=0 us)
0 PX SEND HASH :TQ10004 (cr=0 pr=0 pw=0 time=0 us)
0 NESTED LOOPS (cr=0 pr=0 pw=0 time=0 us)
0 BUFFER SORT (cr=0 pr=0 pw=0 time=0 us)
0 PX RECEIVE (cr=0 pr=0 pw=0 time=0 us)
0 PX SEND BROADCAST :TQ10000 (cr=0 pr=0 pw=0 time=0 us)
1 TABLE ACCESS BY INDEX ROWID NETWORK_CLASS (cr=2 pr=0 pw=0 time=65 us)
1 INDEX UNIQUE SCAN NETWORK_CLASS_IDX2 (cr=1 pr=0 pw=0 time=40 us)(object id 16854)
0 PX PARTITION HASH ALL PARTITION: 1 10 (cr=0 pr=0 pw=0 time=0 us)
0 TABLE ACCESS BY LOCAL INDEX ROWID DEVICE PARTITION: 1 10 (cr=0 pr=0 pw=0 time=0 us)
0 INDEX RANGE SCAN DEVICE_NETWORK_IDX5 PARTITION: 1 10 (cr=0 pr=0 pw=0 time=0 us)(object id 16964)
0 BUFFER SORT (cr=0 pr=0 pw=0 time=0 us)
0 PX RECEIVE (cr=0 pr=0 pw=0 time=0 us)
0 PX SEND HASH :TQ10001 (cr=0 pr=0 pw=0 time=0 us)
376834 PARTITION HASH ALL PARTITION: 1 10 (cr=36039 pr=24712 pw=0 time=1527276 us)
376834 TABLE ACCESS FULL MONITORING_POINT PARTITION: 1 10 (cr=36039 pr=24712 pw=0 time=8153060 us)
0 BUFFER SORT (cr=0 pr=0 pw=0 time=0 us)
0 PX RECEIVE (cr=0 pr=0 pw=0 time=0 us)
0 PX SEND HASH :TQ10002 (cr=0 pr=0 pw=0 time=0 us)
684627 PARTITION HASH ALL PARTITION: 1 10 (cr=35047 pr=16799 pw=0 time=1383304 us)
684627 TABLE ACCESS FULL CUSTOMER_CIRCUIT PARTITION: 1 10 (cr=35047 pr=16799 pw=0 time=2260635 us)
0 BUFFER SORT (cr=0 pr=0 pw=0 time=0 us)
0 PX RECEIVE (cr=0 pr=0 pw=0 time=0 us)
0 PX SEND HASH :TQ10003 (cr=0 pr=0 pw=0 time=0 us)
0 TABLE ACCESS FULL LAYER3_DESCRIPTOR (cr=0 pr=0 pw=0 time=0 us)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
PX Deq: Join ACK 11 0.00 0.00
os thread startup 5 0.08 0.31
PX Deq Credit: send blkd 15 1.93 3.86
PX Deq: Parse Reply 20 0.00 0.01
SQL*Net message to client 2 0.00 0.00
PX Deq: Execute Reply 53 0.38 0.94
db file sequential read 3880 0.00 0.11
db file scattered read 3978 0.04 0.77
PX Deq Credit: need buffer 11 0.01 0.01
enq: PS - contention 6 0.01 0.03
SQL*Net break/reset to client 2 0.00 0.00
SQL*Net message from client 1 0.00 0.00
********************************************************************************
SELECT /*+ NOPARALLEL(NETWORK_CLASS) NOPARALLEL(DEVICE) NOPARALLEL(MONITORING_POINT) NOPARALLEL(CUSTOMER_CIRCUIT)
NOPARALLEL(LAYER3_DESCRIPTOR) */
DV.DVC_TID_NEID AS DEVICEID, MP.MP_SLOT AS SLOT, MP.MP_SUBSLOT AS SUBSLOT, MP.MP_PORT AS PORT, MP.MP_INTERFACE AS INTERFACE, MP.MP_SUBINTERFACE AS SUBINTERFA
CE, L3.L3_PE_IP_ADDRESS AS IP, CC.CCIRC_COMMITTED_INFO_RATE AS SPEED, MP.MP_USAGE AS USAGE, MP.MP_DEPLOYMENT_STATUS AS STATUS, MP.MP_SLOT_TYPE AS PORTTYPE, (
CASE WHEN CC.CCIRC_NAME LIKE '%FAR_END%' THEN SUBSTR ( CC.CCIRC_NAME, 10, 90) ELSE CC.CCIRC_NAME END) AS SITE, CC.CCIRC_COMMITTED_INFO_RATE AS CIRCUITTYPE, C
C.CCIRC_COMMENT AS COMMENTS, MP.MP_CARD_TYPE AS INTERFACETYPE FROM DEVICE DV INNER JOIN NETWORK_CLASS NT ON NT.NETWORK_HASH = DV.NETWORK_HASH AND NT.SRC = DV
.SRC INNER JOIN MONITORING_POINT MP ON MP.DVC_HASH = DV.DVC_HASH AND MP.SRC = DV.SRC LEFT JOIN LAYER3_DESCRIPTOR L3 ON L3.MP_HASH=MP.MP_HASH AND L3.SRC = MP.
SRC LEFT JOIN CUSTOMER_CIRCUIT CC ON CC.MP_HASH_1 = MP.MP_HASH AND CC.SRC = MP.SRC WHERE NT.NETWORK_TYPE = 'PUBLIC IP INTERFACES' AND MP.MP_USAGE <>'UPLINK'
AND DV.SRC = 'LGL' ORDER BY DV.DVC_TID_NEID
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.03 0.03 0 0 0 0
Execute 1 0.02 0.05 5 30 0 0
Fetch 10788 10.88 20.07 55200 83793 0 161806
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 10790 10.93 20.15 55205 83823 0 161806
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 53
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 10790 0.00 0.02
SQL*Net message from client 10789 20.91 698.92
db file sequential read 4053 0.00 0.11
PX Deq: Join ACK 7 0.00 0.01
PX Deq Credit: send blkd 37 1.93 5.93
PX Deq: Parse Reply 7 0.00 0.00
PX Deq: Execute Reply 69 0.59 1.96
db file scattered read 4678 0.00 0.88
PX Deq Credit: need buffer 25 0.00 0.00
db file parallel read 1 0.00 0.00
PX qref latch 2 0.00 0.00
PX Deq: Table Q qref 14 0.00 0.00
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 2 0.06 0.07 0 0 0 0
Execute 2 0.02 0.39 5 60 0 0
Fetch 10789 18.20 33.49 96711 154881 0 161806
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 10793 18.28 33.96 96716 154941 0 161806
Misses in library cache during parse: 2
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 10792 0.00 0.02
SQL*Net message from client 10790 20.91 698.92
PX Deq: Join ACK 18 0.00 0.01
os thread startup 5 0.08 0.31
PX Deq Credit: send blkd 52 1.93 9.79
PX Deq: Parse Reply 27 0.00 0.01
PX Deq: Execute Reply 122 0.59 2.90
db file sequential read 7933 0.00 0.22
db file scattered read 8656 0.04 1.65
PX Deq Credit: need buffer 36 0.01 0.01
enq: PS - contention 6 0.01 0.03
SQL*Net break/reset to client 2 0.00 0.00
db file parallel read 1 0.00 0.00
PX qref latch 2 0.00 0.00
PX Deq: Table Q qref 14 0.00 0.00
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 4 0.00 0.00 0 0 0 0
Execute 4 0.00 0.00 0 2 4 2
Fetch 2 0.02 0.00 0 0 2 2
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 10 0.02 0.00 0 2 6 4
Misses in library cache during parse: 0
I guess its written in JAVA but im not sure.
|
|
|
|
| Re: performance problem [message #276667 is a reply to message #276616] |
Thu, 25 October 2007 22:39 |
rleishman
Messages: 3728
Registered: October 2005
Location: Melbourne, Australia
|
Senior Member |
|
|
I would have liked to have seen the plan for the noparallel execution. It took longer, but I have no certainty that the join orders and sequences are the same as the parallel solution.
I notice that your rerun of the parallel solution returned no rows. Obviously something has changed. But it does give us some new information. It still took 10 seconds, but this time it did not have to interface with the client thousands of times. This tells us that the 10 seconds was spent at the server.
Furthermore, one of the driving tables (DEVICE) returned no rows - this caused the primary inner-join to return no rows, and the outer joins to return no rows. This should make the join operations pretty cheap.
The Recursive totals at the bottom show that the time was not spent on recursive SQL either.
So the only real activity here is the full table scan of MONITORING_POINT and CUSTOMER_CIRCUIT - a bit more than 1M rows in total.
So why so slow to scan these two tables? The Disk and Query columns of tkprof give relatively low disk volumes - so it's not spending time reading white-space.
I'm beginning to think that there is a hardware problem. The two possible issues that come to mind are:
- Contention on the Oracle disks where this data resides. Other processes could be blocking you.
- Insufficient memory on the server, causing your process to be continually swapped to disk whilst it is running.
You should be able to see both of these by monitoring the disks. What operating system are you on? On Linux and at least one other Unix flavour I've seen (Sequent I think), the SAR command can give you disk activity. For example:
$ sar -d 5 2
Linux 2.6.16.46-0.14-bigsmp (odmsp01) 10/26/2007
01:20:21 PM DEV tps rd_sec/s wr_sec/s avgrq-sz avgqu-sz await svctm %util
01:20:26 PM dev8-0 6.20 0.00 139.20 22.45 0.01 2.32 2.32 1.44
01:20:26 PM DEV tps rd_sec/s wr_sec/s avgrq-sz avgqu-sz await svctm %util
01:20:31 PM dev8-0 2.00 0.00 54.40 27.20 0.02 9.20 8.40 1.68
Average: DEV tps rd_sec/s wr_sec/s avgrq-sz avgqu-sz await svctm %util
Average: dev8-0 4.10 0.00 96.80 23.61 0.02 4.00 3.80 1.56
This is not a very good example because it's from a PC with a single disk. What's more, I don't really know how to read it properly. But if you have a large server with many disks, you should see much higher numbers on one or more of the database disks if there is contention from other processes. If swapping is occurring, you should see high activity on the local disks (assuming the database is stored on external media).
I don't know if that is much help; I don't work in the hardware-space. If it were me, I'd be dragging in the sysadmin to help.
One other thing you could do is benchmark full table scans of those tables. Try tracing this:
SELECT *
FROM MONITORING_POINT
WHERE ROWNUM > 1
Also do the other table.
If it is fast, and your join remains slow, then I am wrong about the hardware issue and we're back to square one.
Ross Leishman
|
|
|
|
| Re: performance problem [message #276884 is a reply to message #276667] |
Fri, 26 October 2007 10:50 |
Nokia
Messages: 15
Registered: July 2007
|
Junior Member |
|
|
thank you so much rleishman for your help.
Here i did what you told me.
SELECT *
FROM MONITORING_POINT
WHERE ROWNUM > 1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 4.24 4.15 15042 36039 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 4.24 4.16 15042 36039 0 0
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 53
Rows Row Source Operation
------- ---------------------------------------------------
0 COUNT (cr=36039 pr=15042 pw=0 time=4155327 us)
0 FILTER (cr=36039 pr=15042 pw=0 time=4155321 us)
1697479 PARTITION HASH ALL PARTITION: 1 10 (cr=36039 pr=15042 pw=0 time=3395464 us)
1697479 TABLE ACCESS FULL MONITORING_POINT PARTITION: 1 10 (cr=36039 pr=15042 pw=0 time=3397863 us)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 1 0.00 0.00
SQL*Net more data to client 1 0.00 0.00
db file scattered read 1379 0.00 0.18
db file sequential read 1759 0.00 0.03
SQL*Net message from client 1 32.58 32.58
********************************************************************************
SELECT ORA_TQ_BASE$.NEXTVAL
FROM
DUAL
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 0 1 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.00 0 0 1 1
Misses in library cache during parse: 0
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------
1 SEQUENCE ORA_TQ_BASE$ (cr=1 pr=0 pw=0 time=879 us)
1 FAST DUAL (cr=0 pr=0 pw=0 time=4 us)
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
SQL*Net message from client 2 23.55 35.13
********************************************************************************
update seq$ set increment$=:2,minvalue=:3,maxvalue=:4,cycle#=:5,order$=:6,
cache=:7,highwater=:8,audit$=:9,flags=:10
where
obj#=:1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 1 2 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 1 2 1
SELECT *
FROM device where rownum>1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.29 0.27 2180 2210 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.29 0.28 2180 2210 0 0
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 53
Rows Row Source Operation
------- ---------------------------------------------------
0 COUNT (cr=2210 pr=2180 pw=0 time=279509 us)
0 FILTER (cr=2210 pr=2180 pw=0 time=279503 us)
75260 PARTITION HASH ALL PARTITION: 1 10 (cr=2210 pr=2180 pw=0 time=301892 us)
75260 TABLE ACCESS FULL DEVICE PARTITION: 1 10 (cr=2210 pr=2180 pw=0 time=156216 us)
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 10 0.00 0.00
db file scattered read 213 0.00 0.03
SQL*Net message from client 2 4.79 8.55
********************************************************************************
SELECT *
FROM CUSTOMER_CIRCUIT where rownum>1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 4.52 4.42 30535 35152 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 4.52 4.42 30535 35152 0 0
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 53
Rows Row Source Operation
------- ---------------------------------------------------
0 COUNT (cr=35152 pr=30535 pw=0 time=4425188 us)
0 FILTER (cr=35152 pr=30535 pw=0 time=4425183 us)
1644792 PARTITION HASH ALL PARTITION: 1 10 (cr=35152 pr=30535 pw=0 time=4934489 us)
1644792 TABLE ACCESS FULL CUSTOMER_CIRCUIT PARTITION: 1 10 (cr=35152 pr=30535 pw=0 time=3293240 us)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 1 0.00 0.00
db file scattered read 2026 0.00 0.41
db file sequential read 15 0.00 0.00
SQL*Net message from client 1 3.22 3.22
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 10 0.01 0.02 0 0 0 0
Execute 10 0.02 0.04 6 30 0 0
Fetch 7 13.89 13.72 49624 109440 1 2
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 27 13.92 13.79 49630 109470 1 2
Misses in library cache during parse: 5
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 8 0.00 0.00
SQL*Net message from client 8 61.06 126.18
SQL*Net more data to client 2 0.00 0.00
db file scattered read 3927 0.00 0.65
db file sequential read 2037 0.00 0.04
PX Deq: Join ACK 5 0.00 0.00
PX Deq: Parse Reply 14 0.00 0.02
PX Deq: Execute Reply 99 0.00 0.11
PX Deq: Signal ACK 1 0.00 0.00
latch: session allocation 2 0.00 0.00
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 1 2 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 1 2 1
Misses in library cache during parse: 0
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
SQL*Net message from client 2 23.55 37.43
Thanks again for your help.
|
|
|
|
| Re: performance problem [message #277100 is a reply to message #276884] |
Sun, 28 October 2007 22:35 |
rleishman
Messages: 3728
Registered: October 2005
Location: Melbourne, Australia
|
Senior Member |
|
|
My mistake. I was using my eyes to determine what was a reasonable read-rate, not my calculator.
I've got a really cruddy database where I am, and I ran a benchmark on a 10M row table resulting in disk/elapsed < 1000 blocks/sec.
Figuring that database is cruddy, yours should definitely be better. You are getting 3000-6000 blocks/sec.
I don't think there is any problem with this. Sorry for misleading you.
Is there any reason you think it should be much faster?
Ross Leishman
|
|
|
|
| Re: performance problem [message #277344 is a reply to message #277100] |
Mon, 29 October 2007 12:27 |
Nokia
Messages: 15
Registered: July 2007
|
Junior Member |
|
|
Thanks Ross.
Ross how you examined that mine 3000-6000 blocks are executing /sec.
I need some clarification on COST column.
--------------------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | Pstart| Pstop | TQ |IN-OUT| PQ Distrib |
--------------------------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 423K| 38M| 473 (2)| 00:00:06 | | | | | |
| 1 | PX COORDINATOR | | | | | | | | | | |
| 2 | PX SEND QC (RANDOM)| :TQ10000 | 423K| 38M| 473 (2)| 00:00:06 | | | Q1,00 | P->S | QC (RAND) |
| 3 | PX BLOCK ITERATOR | | 423K| 38M| 473 (2)| 00:00:06 | 1 | 10 | Q1,00 | PCWC | |
|* 4 | TABLE ACCESS FULL| ALARM_CUSTOMER_CIRCUIT | 423K| 38M| 473 (2)| 00:00:06 | 1 | 10 | Q1,00 | PCWP | |
--------------------------------------------------------------------------------------------------------------------------------------------
Or this one
PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Plan hash value: 1851588011
-----------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | Pstart| Pstop |
-----------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 423K| 38M| 18469 (1)| 00:03:42 | | |
| 1 | TABLE ACCESS BY GLOBAL INDEX ROWID| ALARM_CUSTOMER_CIRCUIT | 423K| 38M| 18469 (1)| 00:03:42 | ROWID | ROWID |
|* 2 | INDEX RANGE SCAN | MY_IND | 423K| | 1137 (1)| 00:00:14 | | |
-----------------------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
Just making sure the COST in 2nd explain plan is higher can some one clear mine doubts about this column.
One more thing whats the total time taken by this query?
00:03:44
+
00:03:44
+
00:03:44=.... Or only once 00:03:44 ?
I already noticed TIME is good in PLAN 1.
Thanks.
[Updated on: Mon, 29 October 2007 14:33] Report message to a moderator |
|
|
|
| Re: performance problem [message #277388 is a reply to message #277344] |
Mon, 29 October 2007 20:58 |
rleishman
Messages: 3728
Registered: October 2005
Location: Melbourne, Australia
|
Senior Member |
|
|
The values in Explain Plan are ESTIMATES. Personally I take no notice of the time/rows/bytes/etc.
COST is a relative (not absolute) measure that is Oracle's estimate of which plan will perform better. The only way to tell for sure which plan is truly better is to run the SQL with both under a variety of circumstances.
The measure I was using was taken from the TK*Prof. The DISK column shows the number of blocks read, which is usually the most time-consuming part. QUERY I ignored - this is the number of buffers retrieved from cache (a relatively fast operation). I also used the ELAPSED time.
Looking at your TK*Prof, it read 41511 blocks, (plus it read some buffers and performed some joins) in 13 seconds. 41511 / 13 = 3193 blocks/sec MINIMUM (it would be faster if we could quantify the cost of query buffers and joins).
Ross Leishman
|
|
|
|
| Re: performance problem [message #277625 is a reply to message #277388] |
Tue, 30 October 2007 22:35 |
Nokia
Messages: 15
Registered: July 2007
|
Junior Member |
|
|
Thank you so much for your help.
I have one more question regarding these two things
PX Deq: Signal ACK
PX Deq Credit: send blkd
I'm not sure these are related to some thing parallel or what?
I saw these 2 many times in execution plan but didn't get the meaning of these two.
Thanks Again
Ross
|
|
|
|
| Re: performance problem [message #277673 is a reply to message #277625] |
Wed, 31 October 2007 02:20 |
rleishman
Messages: 3728
Registered: October 2005
Location: Melbourne, Australia
|
Senior Member |
|
|
I don't know precisely what they are, but I believe they are related to parallel query repartitioning the data for each join.
Ross Leishman
|
|
|
|
|
|
Goto Forum:
Current Time: Tue Jun 25 02:13:17 CDT 2024
|
] 
Blog
Search
Help
Members
Register
Login
Home
