Hash Join and sequential reads

From: Debaditya Chatterjee <debaditya.chatterjee_at_gmail.com>
Date: Wed, 16 Jul 2008 20:22:10 -0400
Message-ID: <90f8af090807161722kaee539dw9049d175801d80cf@mail.gmail.com>

All,

I have a strange situation and I am unable to co-relate the sql operation and the associated wait event. We usually associate 'db file sequential reads' with index scans but in the example below, the current operation of the sql (from v$session_longops) is a HASH JOIN yet the wait event is 'db file sequential read'. There are no index scans in the execution plan and I have checked that the plan for this query hasn't changed in the last 24 hours.

The update statement is now running for more than 24 hours.

The database version is 10gR2.

Can anybody help me understand why there is a db file sequential read wait event ?

Thanks
Deba.

/* Sql_id of the session */
SQL> Select sql_id from v$session where sid=1956;

SQL_ID

---

9crcdnsy4yq0v

/* sql_plan and statement */

SQL> @/home/dechatt/sql/sql_plan
Enter value for sql_id: 9crcdnsy4yq0v
Enter value for child_number:
old 2: from table( dbms_xplan.display_cursor('&sql_id','&child_number') ) new 2: from table( dbms_xplan.display_cursor('9crcdnsy4yq0v','') )

PLAN_TABLE_OUTPUT

---

SQL_ID 9crcdnsy4yq0v, child number 0

---

update /*+ bypass_ujvc */ (select x_recency_date, case when nvl(pd.CHANGED_ON_DT,to_date('01-JAN-1900','DD-MON-YYYY')) >= nvl(rd.RESP_DATE,to_date('01-JAN-1900','DD-MON-YYYY')) then pd.CHANGED_ON_DT

    when nvl(pd.CHANGED_ON_DT,to_date('01-JAN-1900','DD-MON-YYYY')) < nvl(rd.RESP_DATE,to_date('01-JAN-1900','DD-MON-YYYY')) then rd.RESP_DATE end
derived_recency_date from w_person_d pd,(select max(d.resp_date) resp_date,

          nvl(X_PR_CON_ID, X_PRSP_CON_ID) con_prsp_id from w_response_d d
        group by nvl(X_PR_CON_ID, X_PRSP_CON_ID)) rd where pd.integration_id

=
rd.con_prsp_id(+)) v1 set v1.x_recency_date = v1.derived_recency_date

Plan hash value: 4034168942

---

| Id | Operation | Name | Rows | Bytes |TempSpc| Cost
(%CPU)| Time |

---

| 0 | UPDATE STATEMENT | | | | |

992K(100)|          |


|   1 |  UPDATE               | W_PERSON_D   |       |       |

|            |          |

|*  2 |   HASH JOIN OUTER     |              |    22M|  1497M|   822M|
992K  (1)| 03:51:29 |


|   3 |    TABLE ACCESS FULL  | W_PERSON_D   |    21M|   581M|       |

570K  (2)| 02:13:14 |


|   4 |    VIEW               |              |    22M|   877M|       |

337K  (1)| 01:18:41 |


|   5 |     SORT GROUP BY     |              |    22M|   449M|  1371M|

337K  (1)| 01:18:41 |


|   6 |      TABLE ACCESS FULL| W_RESPONSE_D |    22M|   449M|       |

246K (1)| 00:57:25 |

---

Predicate Information (identified by operation id):

---

   2 - access("PD"."INTEGRATION_ID"="RD"."CON_PRSP_ID")

/* Current Operation from v$session_longops */

SQL> SELECT opname, sofar, totalwork, start_time,

          time_remaining, elapsed_seconds, MESSAGE
     FROM v$session_longops
     WHERE SID = 1956

 ORDER BY start_time 2 3 4 5
  6 /

OPNAME SOFAR TOTALWORK START_TIME TIME_REMAINING ELAPSED_SECONDS

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

-------------- ---------------
MESSAGE

---

Table Scan         1559210    1559210 15-JUL-2008
11:35:07                    0            3801

Table Scan: ORABI.W_PERSON_D: 1559210 out of 1559210 Blocks done

Table Scan          652648     652648 15-JUL-2008
12:38:49                    0             625

Table Scan: ORABI.W_RESPONSE_D: 652648 out of 652648 Blocks done

Sort/Merge           18286      18286 15-JUL-2008
12:49:14                    0              12

Sort/Merge: : 18286 out of 18286 Blocks done

Sort Output          18249      18249 15-JUL-2008
12:49:26                    0            4888

Sort Output: : 18249 out of 18249 Blocks done

Hash Join            22635      66525 15-JUL-2008 14:11:09
185278           95552

Hash Join: : 22635 out of 66525 Blocks done

/* Wait Event information */

  1 SELECT sample_time, sql_id, event, p1, p2, p3, time_waited   2 FROM v$active_session_history
  3* WHERE sql_id = '9crcdnsy4yq0v' AND ROWNUM < 11 it_perf_at_gcwap.us.oracle.com> /

SAMPLE_TIME               SQL_ID        EVENT                     P1
P2         P3 TIME_WAITED
------------------------- ------------- ------------------------ ---

---------- ---------- -----------
16-JUL-08 04.47.05.921 PM 9crcdnsy4yq0v db file sequential read 38 217901 1 0
16-JUL-08 04.47.04.921 PM 9crcdnsy4yq0v db file sequential read 38

216711          1        4963
16-JUL-08 04.47.03.921 PM 9crcdnsy4yq0v                           38
216166          1           0
16-JUL-08 04.47.02.911 PM 9crcdnsy4yq0v db file sequential read   38
214867          1        6915
16-JUL-08 04.47.01.911 PM 9crcdnsy4yq0v db file sequential read   37
327339          1        5432
16-JUL-08 04.47.00.911 PM 9crcdnsy4yq0v db file sequential read   50
150278          1        1569
16-JUL-08 04.46.59.911 PM 9crcdnsy4yq0v                           37
324999          1           0
16-JUL-08 04.46.58.911 PM 9crcdnsy4yq0v db file sequential read   34
144055          1       10834
16-JUL-08 04.46.57.911 PM 9crcdnsy4yq0v db file sequential read   34
142434          1        7103
16-JUL-08 04.46.56.901 PM 9crcdnsy4yq0v db file sequential read   34
141082          1        4897

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

Received on Wed Jul 16 2008 - 19:22:10 CDT