Home » RDBMS Server » Performance Tuning » performance problem
performance problem [message #276320] Wed, 24 October 2007 16:19 Go to next message
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 Go to previous messageGo to next message
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 Go to previous messageGo to next message
rleishman
Messages: 3724
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 #276339 is a reply to message #276320] Wed, 24 October 2007 22:31 Go to previous messageGo to next message
BlackSwan
Messages: 25039
Registered: January 2009
Location: SoCal
Senior Member
>Fetch 2919
>SQL*Net message from client 2920
1 round trip per row fetched & spent 10+ seconds going across the cable.
Re: performance problem [message #276340 is a reply to message #276339] Wed, 24 October 2007 22:38 Go to previous messageGo to next message
rleishman
Messages: 3724
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 Go to previous messageGo to next message
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 Go to previous messageGo to next message
rleishman
Messages: 3724
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 Go to previous messageGo to next message
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 Go to previous messageGo to next message
rleishman
Messages: 3724
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 Go to previous messageGo to next message
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 Go to previous messageGo to next message
rleishman
Messages: 3724
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 Go to previous messageGo to next message
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 Go to previous messageGo to next message
rleishman
Messages: 3724
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
Re: performance problem [message #277834 is a reply to message #277673] Wed, 31 October 2007 17:23 Go to previous message
Nokia
Messages: 15
Registered: July 2007
Junior Member
Thanks.

I found this link regarding that parameters .

http://oracledoug.com/px8.html
Previous Topic: Parallel Query yields High Consistent Gets vs Serial
Next Topic: find out query is taking full table scan or index scan
Goto Forum:
  


Current Time: Tue Dec 06 04:16:48 CST 2016

Total time taken to generate the page: 0.05244 seconds