Re: Recursive CPU larger than total CPU used by the database
From: Ls Cheng <exriscer_at_gmail.com>
Date: Fri, 22 May 2015 00:27:48 +0200
Message-ID: <CAJ2-Qb_8HHeO_rMDE4h3NLwTzNiARBBihgydiiJDfPWuVAXTrA_at_mail.gmail.com>
Hi
WHERE sample_time >= to_date('20150521 2200', 'yyyymmdd hh24mi') AND sample_time < to_date('20150521 2230', 'yyyymmdd hh24mi') GROUP BY session_id, session_state, event ORDER BY count(*) desc;
WHERE sample_time >= to_date('20150521 2200', 'yyyymmdd hh24mi') AND sample_time < to_date('20150521 2230', 'yyyymmdd hh24mi') AND session_id = 314
GROUP BY sql_id
ORDER BY count(*) desc;
Date: Fri, 22 May 2015 00:27:48 +0200
Message-ID: <CAJ2-Qb_8HHeO_rMDE4h3NLwTzNiARBBihgydiiJDfPWuVAXTrA_at_mail.gmail.com>
Hi
This is today's 30 minutes AWR, it reported 1961 DB CPU seconds and 2519 recursive CPU seconds
Snap Id Snap Time Sessions Curs/Sess
--------- ------------------- -------- ---------
Begin Snap: 17166 21-May-15 22:00:12 206 30.9
End Snap: 17167 21-May-15 22:30:19 201 29.5
Elapsed: 30.11 (mins)
DB Time: 32.42 (mins)
Top 5 Timed Events Avg %Total
~~~~~~~~~~~~~~~~~~ wait Call
Event Waits Time (s) (ms) Time Wait
Class
------------------------------ ------------ ----------- ------ ------ ---------- CPU time 1,961 100.8 db file sequential read 204,583 356 2 18.3 User I/O Datapump dump file I/O 173,270 206 1 10.6 User I/O db file scattered read 69,775 172 2 8.8 User I/O log file parallel write 3,045 9 3 0.5System I/O
Statistic Total per Second perTrans
-------------------------------- ------------------ -------------- ------------- CPU used by this session 116,102 64.3 46.0 parse time cpu 1,362 0.8 0.5 recursive calls 2,346,502 1,299.0 929.7 recursive cpu usage 251,943 139.599.8
ASH DBTime:
SELECT session_id, session_state, event,
count(*) DBTime,
sum(count(*)) over () total_dbtime
FROM v$active_session_history
WHERE sample_time >= to_date('20150521 2200', 'yyyymmdd hh24mi') AND sample_time < to_date('20150521 2230', 'yyyymmdd hh24mi') GROUP BY session_id, session_state, event ORDER BY count(*) desc;
SESSION_ID SESSION EVENT DBTIME TOTAL_DBTIME
---------- ------- ------------------------------ ---------- ------------
314 ON CPU 683 950
--> DBMS_STATS JOB
313 ON CPU 38 950
470 ON CPU 30 950
346 ON CPU 25 950
551 WAITING log file parallel write 13 950
524 ON CPU 10 950
400 ON CPU 9 950
408 ON CPU 9 950
364 ON CPU 9 950
552 WAITING db file parallel write 8 950
439 ON CPU 7 950
494 ON CPU 4 950
.................................
ASH Top SQL:
SELECT sql_id,
count(*) DBTime,
sum(count(*)) over () total_dbtime
FROM v$active_session_history
WHERE sample_time >= to_date('20150521 2200', 'yyyymmdd hh24mi') AND sample_time < to_date('20150521 2230', 'yyyymmdd hh24mi') AND session_id = 314
GROUP BY sql_id
ORDER BY count(*) desc;
SQL_ID DBTIME TOTAL_DBTIME
------------- ---------- ------------
ayqtcdfc0j2jq 294 685 g3wqa8fkdrsh0 76 685 b1zwcs9bjfdx3 54 685 ga4ca5u6v2yzc 34 685 1a5xk5qrznhpd 30 685 696n8nucg003x 21 685 d8p6spwhn2uy3 21 685 4m18tcchz46tp 16 685 5k3uu413rnrqr 13 685 5mss4v7zkx4ny 8 685 6fp83b3yxdk8t 6 685 azsp79mtbt2ns 5 685 .................................
This from last week where it reported 866 DB CPU and 1967 recursive CPU seconds
Snap Id Snap Time Sessions Curs/Sess
--------- ------------------- -------- ---------
Begin Snap: 16734 12-May-15 22:00:38 187 31.6
End Snap: 16735 12-May-15 22:30:45 181 30.0
Elapsed: 30.11 (mins)
DB Time: 14.20 (mins)
Top 5 Timed Events Avg %Total
~~~~~~~~~~~~~~~~~~ wait Call
Event Waits Time (s) (ms) Time Wait
Class
------------------------------ ------------ ----------- ------ ------ ---------- CPU time 866 101.7 db file sequential read 203,877 365 2 42.8 User I/O Datapump dump file I/O 166,829 218 1 25.6 User I/O db file scattered read 26,079 91 3 10.7 User I/O log file parallel write 2,792 10 4 1.2System I/O
Statistic Total per Second perTrans
-------------------------------- ------------------ -------------- ------------- CPU used by this session 62,592 34.7 27.2 parse time cpu 1,396 0.8 0.6 recursive calls 1,317,943 729.5 572.0 recursive cpu usage 196,759 108.985.4
Thanks
On Thu, May 21, 2015 at 9:05 PM, Jonathan Lewis <jonathan_at_jlcomp.demon.co.uk > wrote:
> > I forgot to ask how you're reporting this. > Is this a 30 minute AWR report ? > > Just a thought - could there be a recursive statement using SQL from the > previous 30 minutes that only gets reported in the current period ? Not > sure that this could happen, but may be worth a thought. > > > > Regards > Jonathan Lewis > http://jonathanlewis.wordpress.com > _at_jloracle > ------------------------------ > *From:* oracle-l-bounce_at_freelists.org [oracle-l-bounce_at_freelists.org] on > behalf of Ls Cheng [exriscer_at_gmail.com] > *Sent:* 20 May 2015 18:31 > *To:* Oracle Mailinglist > *Subject:* Recursive CPU larger than total CPU used by the database > > Hi > > I have a 10.2.0.5 single instance database running in HP-UX. > > I have noticed that everyday at same time, between 22:00 and 22:30 the > recursive cpu shown in v$sysstat is larger than DB CPU from Time Model or > CPU used by this session from v$sysstat. > > The database claims it consumed 886 second CPU but recursive cpu usage > shows 196759 centiseconds (1967 seconds). > > This happens consistently everyday at the same time. > > Anyone observed this behaviour before? > > Thanks > > >
-- http://www.freelists.org/webpage/oracle-lReceived on Fri May 22 2015 - 00:27:48 CEST