RE: MERGE statement - where time goes ?
- From: "Milen Kulev" <makulev@xxxxxxx>
- To: "'Alberto Dell'Era'" <alberto.dellera@xxxxxxxxx>
- Date: Mon, 23 Jul 2007 20:26:59 +0200
Hello Albeto,
Thank you for your prompt reply .
OK, after selecting/filterung which rows should be inserted und which rows
should be updated (VIEW step),
The rows should be physically written to the table. This operation takes
52349971- 11221649 microseconds = 41128322 microseconds
VIEW step filtered 1378 rows. Time to update/insert a row would be:
41128322 microseconds/1378 rows = 29846 microseconds ~ 29 ms, just for writing
one row ?!
At the time of issuing the statement there were no locks (or other
serialization mechanism) on the table
T_F_MESSUNG_DLZ_2.
GlancePlus showed me at that time maximum ~ 400 I/Os per second (Max is ~ 3000
I/Os per second). So, there was no I/O
subsystem botthelneck
Furthermore, the sum of sizes of all T_F_MESSUNG_DLZ_2 columns is ~ 1k (9xx
bytes).
How is it possible to take 29 ms to update/insert 1k ?
That is what I can not explain (to me).
Best Regards. Milen
-----Original Message-----
From: Alberto Dell'Era [mailto:alberto.dellera@xxxxxxxxx]
Sent: Monday, July 23, 2007 6:03 PM
To: makulev@xxxxxxx
Subject: Re: MERGE statement - where time goes ?
Hi Milen,
that's the time requested to physically modify the table (insert or update
rows); it takes 11221649 microseconds to
calculate the differences between the "INTO" table and the "USING" table
[that's the VIEW in the plan], and 52349971-
11221649 microseconds to inject them into the "INTO" table (as specified by
"WHEN MATCHED" etc).
hth
Alberto
On 7/23/07, Milen Kulev <makulev@xxxxxxx> wrote:
> Hi lsiters,
> I have the following problem: a MERGE statement is runing and is
> taling ~ 52 seconds to run. I have traced the statement with event
> 10046 and I have found that I am "loosing" ~ 42 seconds (> 80% of
> response time) im MERGE statement step (for execution statistics &
> execution plan -> see below). The interesing lines are:
>
> Rows Row Source Operation
> ------- ---------------------------------------------------
> 2 MERGE T_F_MESSUNG_DLZ_2 (cr=27552 pr=7876 pw=0 time=52349971 us)
> 1378 VIEW (cr=4752 pr=602 pw=0 time=11221649 us)
>
>
> Does someone know what actually the MERGE is doing in the background ?
> Any Ideas, links ?
>
> OS= HPUX, Version 10.2.0.2
>
> Best Regards. Milen
>
> ------------------------------------------------------------
> merge into GPFRSYSTEM.t_f_messung_dlz_etl m
> using (select * from GPFRSYSTEM.tt_messung_dlz where ARBEITSTAGE >= 0
> or MESSSTRECKE_ID = 21) t
> on (t.order_id = m.order_id and t.messstrecke_id = m.messstrecke_id)
> WHEN MATCHED THEN UPDATE set m.status = t.status,
>
> m.arbeitstage = case when t.messstrecke_id = 21 and
t.arbeitstage < 0 then 0 else t.arbeitstage end,
>
> m.kalendertage = case when t.messstrecke_id = 21 and
t.arbeitstage < 0 then 0 else t.kalendertage end,
>
> m.produktionswochen = t.produktionswochen,
>
> m.kalenderwochen = t.kalenderwochen,
>
> m.kalendermonate = t.kalendermonate,
>
> m.messeingangsereignis = nvl(t.eingangsereignis,0) ,
>
> m.messausgangsereignis = nvl(t.ausgangsereignis,0),
>
> m.eingangsereignis = nvl(t.von,0),
>
> m.ausgangsereignis = nvl(t.bis,0),
>
> m.ereignis_zeh = t.ereignis_zeh,
>
> m.kovp_relevant = t.kovp_relevant,
>
> m.pak_geaendert = t.pak_geaendert,
> m.versandart
> = t.versandart,
>
> m.versandart_geaendert = t.versandart_geaendert,
>
> m.kundenbelegung_id = t.kundenbelegung_id,
>
> m.vab_geaendert = t.vab_geaendert,
> m.pak =
> t.pak,
>
> m.letzte_aenderung = sysdate,
>
> m.migrierte_messung = t.migrierte_messung,
> m.trend =
> t.trend
> WHEN NOT MATCHED THEN insert Values (t.messstrecke_id, t.order_id,
> t.status,
> case when t.messstrecke_id = 21 and t.arbeitstage <
> 0 then 0 else t.arbeitstage end,
> case when t.messstrecke_id = 21 and t.arbeitstage <
> 0 then 0 else t.kalendertage end,
> t.produktionswochen,t.kalenderwochen,
> t.kalendermonate, nvl(t.von,0), nvl(t.bis,0),
t.ereignis_zeh,
> nvl(t.eingangsereignis,0),
> nvl(t.ausgangsereignis,0), t.pak,t.pak_geaendert, t.versandart,
> t.versandart_geaendert, t.kundenbelegung_id,
> t.vab_geaendert, t.kovp_relevant, t.migrierte_messung, sysdate,
> t.trend)
>
> call count cpu elapsed disk query current
> rows
> ------- ------ -------- ---------- ---------- ---------- ----------
> ----------
> Parse 1 0.21 0.22 0 302 8
> 0
> Execute 1 2.43 52.35 7876 27552 22199
> 1378
> Fetch 0 0.00 0.00 0 0 0
> 0
> ------- ------ -------- ---------- ---------- ---------- ----------
> ----------
> total 2 2.64 52.57 7876 27854 22207
> 1378
>
> Misses in library cache during parse: 1
> Optimizer mode: ALL_ROWS
> Parsing user id: SYS
> call count cpu elapsed disk query current
> rows
> ------- ------ -------- ---------- ---------- ---------- ----------
> ----------
> Parse 1 0.21 0.22 0 302 8
> 0
> Execute 1 2.43 52.35 7876 27552 22199
> 1378
> Fetch 0 0.00 0.00 0 0 0
> 0
> ------- ------ -------- ---------- ---------- ---------- ----------
> ----------
> total 2 2.64 52.57 7876 27854 22207
> 1378
>
> Misses in library cache during parse: 1
> Optimizer mode: ALL_ROWS
> Parsing user id: SYS
>
> Rows Row Source Operation
> ------- ---------------------------------------------------
> 2 MERGE T_F_MESSUNG_DLZ_2 (cr=27552 pr=7876 pw=0 time=52349971 us)
> 1378 VIEW (cr=4752 pr=602 pw=0 time=11221649 us)
> 1378 NESTED LOOPS OUTER (cr=4752 pr=602 pw=0 time=11214749 us)
> 1378 TABLE ACCESS FULL TT_MESSUNG_DLZ (cr=17 pr=16 pw=0 time=65196 us)
> 49 PARTITION RANGE ITERATOR PARTITION: KEY KEY (cr=4735 pr=586 pw=0
> time=5214707 us)
> 49 PARTITION HASH ITERATOR PARTITION: KEY KEY (cr=4735 pr=586 pw=0
> time=5190425 us)
> 49 TABLE ACCESS BY LOCAL INDEX ROWID T_F_MESSUNG_DLZ_2 PARTITION:
> (cr=4735 pr=586 pw=0 time=5172029 us)
> 49 INDEX UNIQUE SCAN PK_T_F_MESSUNG_DLZ_2 PARTITION: (cr=4684
> pr=538 pw=0 time=4729204 us)(object id
89305)
>
>
> Elapsed times include waiting on following events:
> Event waited on Times Max. Wait Total Waited
> ---------------------------------------- Waited ---------- ------------
> db file sequential read 7861 0.28 50.54
> db file scattered read 1 0.04 0.04
> SQL*Net message to client 1 0.00 0.00
> SQL*Net message from client 1 0.00 0.00
> **********************************************************************
> **********
> ------------------------------------------------------------
> --
> Der GMX SmartSurfer hilft bis zu 70% Ihrer Onlinekosten zu sparen!
> Ideal für Modem und ISDN: http://www.gmx.net/de/go/smartsurfer
> --
> //www.freelists.org/webpage/oracle-l
>
>
>
--
Alberto Dell'Era
"the more you know, the faster you go"
--
//www.freelists.org/webpage/oracle-l
Other related posts:
