Home » RDBMS Server » Performance Tuning » Interpreting TKPROF for Complex Inserts/Updates
Interpreting TKPROF for Complex Inserts/Updates [message #142808] Mon, 17 October 2005 17:40 Go to next message
scottwmackey
Messages: 515
Registered: March 2005
Senior Member
I have included a few examples of some insert and update statements that I have run trace files on. I have a question about some of the numbers, mainly the huge differences between cpu and elapsed time. Given that each of these insert/update statements also contain a select component, should I assume that the cpu time is the time actually doing the update/insert and the difference between that and the elapsed is the time doing the select.
INSERT /*+APPEND*/
FIRST WHEN error IS NOT NULL THEN INTO fu_error_log
  (...)
VALUES
  (...) 
WHEN instr_master_id IS NOT NULL AND update_rnk = 1 THEN INTO tmp_fb_prs_desc
  (...)
VALUES
  (...)
WHEN cash_instr_master_id IS NOT NULL THEN INTO tmp_fb_prs_desc
  (...)
VALUES
  (...) 
WHEN instr_master_id IS NULL THEN INTO tmp_fb_prs_desc
  (...)
VALUES
  (...)
  SELECT v2.*,
         CASE
           WHEN v2.fplx_instr_type_cd IS NULL THEN
            'Instr type cd not found'
           ...
           ELSE
            NULL
         END error
  FROM   (SELECT v.*,
                 ...
                 CASE v.instr_discrim_cd
                   WHEN 'OP' THEN
                    decode(v.raw_contract_price, 0, 1, v.raw_contract_price)
                   ELSE
                    NULL
                 END contract_size,
                 (SELECT COUNT(*)
                  FROM   fd_instr_cat_map ficm
                  JOIN   fe_instn fi ON fi.code_domain_id = ficm.code_domain_id
                                 AND    fi.instn_nm = 'Generic Bank'
                  WHERE  ficm.instr_type_cd = v.instr_type_cd
                  AND    rownum < 2) instr_map_id_error
          FROM   (SELECT ...
                         fb_proc.get_price(f.expnd_bid_price, b.bid_price, :b4, fit.instr_discrim_cd) bid_price,
                         ...
                         CASE
                           WHEN fpcc.prs_cusip_code IS NOT NULL THEN
                            'CSHDOM'
                           ELSE
                            fit.instr_type_cd
                         END instr_type_cd,
                         ...
                         rank() over(PARTITION BY fim.cusip ORDER BY fim.cusip, fim.is_actv DESC, fim.expiration_dt DESC) update_rnk
                  FROM   (SELECT a_in.*,
                                 rank() over(PARTITION BY a_in.cusip ORDER BY a_in.record_seq_num DESC) rnk
                          FROM   fb_prs_desc_a a_in) a
                  ...
                  LEFT   JOIN ff_instr_type fit ON fit.instr_type_cd =
                                                   decode(a.security_type || ':' || a.security_modifier || ':' ||
                                                          a.security_calc_cd || ':' || d.abs_factor,
                                                          '7:2:R:',
                                                          'GVAGCY',
                                                          fpsc.fplx_instr_type_cd)
                  LEFT   JOIN fb_prs_int_freq fpif ON fpif.prs_int_freq = a.int_freq
                  ...
                  LEFT   JOIN (SELECT fim_in.*,
                                     fo.expiration_dt,
                                     fo.instr_master_id fo_instr_master_id
                              FROM   fi_instr_master fim_in
                              LEFT   JOIN fi_option fo ON fim_in.instr_master_id = fo.instr_master_id) fim ON fim.cusip =
                                                                                                              a.cusip
                                                                                                       AND    fim.data_prov_id IN
                                                                                                              (:b3, :b2)
                                                                                                       AND    fim.definer_id IS NULL
                                                                                                       AND    (fim.fo_instr_master_id IS NULL OR
                                                                                                             fim.instr_type_cd =
                                                                                                             'RIGHTS' OR
                                                                                                             (fim.is_actv = 1 AND
                                                                                                             fim.expiration_dt >= :b1) OR
                                                                                                             extract(YEAR FROM
                                                                                                                       fb_proc.get_date(a.mat_opt_exp_dt)) =
                                                                                                             extract(YEAR FROM
                                                                                                                       fim.expiration_dt))
                  LEFT   JOIN fb_prs_cash_cusips fpcc ON fpcc.prs_cusip_code = a.cusip
                  ..
                  LEFT   JOIN fb_prs_int_calc_cd fpicc ON fpicc.prs_int_calc_cd = a.int_calc_cd
                  WHERE  a.rnk = 1
                  AND    rownum > 0) v
          LEFT   JOIN fd_instr_cat_map ficm ON ficm.instr_type_cd = v.instr_type_cd) v2
  ORDER  BY v2.record_seq_num,
            v2.cusip


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.19       0.20          0         72          0           0
Execute      1    224.99     919.61     389270    1940599     331076      409716
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2    225.18     919.81     389270    1940671     331076      409716


********************************************************************************

UPDATE (SELECT fim.*,
               ...
        FROM   tmp_fb_prs_desc td
        JOIN   fi_instr_master fim ON fim.instr_master_id = td.instr_master_id
        WHERE  td.is_insert = 0)
SET    ...


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.05       0.16         97       1176          0           0
Execute      1     23.67     331.45      48576      39931     439455      409314
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2     23.72     331.62      48673      41107     439455      409314

********************************************************************************

INSERT /*+APPEND*/
INTO fi_instr_master fim
  (...)
  SELECT ...
  FROM   tmp_fb_prs_desc
  WHERE  is_insert = 1



call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.61       1.62        293      11545          0           0
Execute      1      0.71      11.55      14262      13315       2858         401
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      1.32      13.18      14555      24860       2858         401

[Updated on: Mon, 17 October 2005 17:41]

Report message to a moderator

Re: Interpreting TKPROF for Complex Inserts/Updates [message #142906 is a reply to message #142808] Tue, 18 October 2005 05:43 Go to previous messageGo to next message
Frank Naude
Messages: 4581
Registered: April 1998
Senior Member
Hi,

I would assume that (elapsed time - CPU time) = wait time.

Wait time includes I/O waits, locks waits, latch waits, etc.

The CPU time would be for the entire statement including the SELECT part.

Best regards.

Frank
Re: Interpreting TKPROF for Complex Inserts/Updates [message #142963 is a reply to message #142808] Tue, 18 October 2005 08:42 Go to previous messageGo to next message
smartin
Messages: 1803
Registered: March 2005
Location: Jacksonville, Florida
Senior Member
You may also want to run the select statement by itself to get the tkprof of it in isolation from the update.
Re: Interpreting TKPROF for Complex Inserts/Updates [message #142989 is a reply to message #142906] Tue, 18 October 2005 12:02 Go to previous messageGo to next message
scottwmackey
Messages: 515
Registered: March 2005
Senior Member
So if the structure of my procedure is as follows:
BEGIN
  INSERT
  INTO   tmp
  SELECT *
  FROM   t1,
         t2
  WHERE  t1.id = t2.id;
  --
  INSERT
  INTO   t8
         (a, b, c)
  SELECT a, b, c
  FROM   tmp
  WHERE  a = :x;
  --
  UPDATE (SELECT t9.*,
                 tmp.d,
                 tmp.e
          FROM   tmp,
                 t9
          WHERE  tmp.id = t9.id)
  SET    r = d,
         s = e;
  --
  COMMIT;
END;

It is my personal schema so I am absolutely sure that nobody else is touching any of my tables and I have only one active session, i.e. no latch or lock waits. But when you say I/O waits, is that the I/O time to perform my query or does that also include wait time while the discs on the box do somebody elses work, be it another Oracle process or just some general file copying or non-Oracle program execution. I do know that there are a couple hundred people on this box doing various Oracle (but not on my schema) and non-Oracle activities. Might my numbers change based on that activity? Is it something I need to take into account or does Oracle factor these out of its metrics and give me something that will be consistent?
Re: Interpreting TKPROF for Complex Inserts/Updates [message #143148 is a reply to message #142989] Wed, 19 October 2005 05:15 Go to previous message
ziggy
Messages: 27
Registered: July 2005
Location: Moscow, Russia
Junior Member

Hello, Scott!

Try extended SQL_TRACE with wait events as described in Article
http://www.orafaq.com/node/14

I think we'll see your problems in details.

Regards,
Ziggy
Previous Topic: Very Similar Queries, Very Different Elapsed Times
Next Topic: Indexes Difference
Goto Forum:
  


Current Time: Wed Nov 27 09:28:42 CST 2024