Re: Snap IDs in Statspack skipping / missing

From: Jure Bratina <jure.bratina_at_gmail.com>
Date: Thu, 9 Mar 2023 17:45:26 +0100
Message-ID: <CAC08BHL-zubS1o-OiGZTSd7War_=9awKqWTcY15rgSCtgaR-4A_at_mail.gmail.com>



Hi Daniel,

> Does that scenario explain why the statistics being captured get weird?
(IE: DECREASE with time??)
Check whether this post is relevant to your case: https://blog.pythian.com/statspack-vs-awr-wrong-number-of-sql-executions/ . Here I describe a similar situation, where execution statistics for a particular SQL_ID captured by Statspack apparently decreased.

Hope it helps.

Regards,
Jure

On Thu, Mar 9, 2023 at 4:42 PM Daniel Hubler <DHubler_at_versiti.org> wrote:

> I can see the overload/stress situation causing the sequence being pushed
> out of the shared pool. . . .causing the gap.
>
>
>
>
>
>
>
> Does that scenario explain why the statistics being captured get weird?
> (IE: DECREASE with time??)
>
> ===
>
>
>
>
>
> SNAP_ID OLD_HASH_VALUE CPU_TIME EXECUTIONS
>
> ---------- -------------- ---------------- ----------
>
> 18929 2626584584 109,976,582,786 340901423
>
> 18933 2626584584 109,976,205,216 340900079
>
> 2 rows selected.
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
> *From:* oracle-l-bounce_at_freelists.org <oracle-l-bounce_at_freelists.org> *On
> Behalf Of *Jonathan Lewis
> *Sent:* Wednesday, March 1, 2023 5:36 PM
> *To:* oracle-l_at_freelists.org
> *Subject:* Re: Snap IDs in Statspack skipping / missing
>
>
>
> *Caution: This Email originated from outside of Versiti.*
> ------------------------------
>
>
>
> The gap is a little warning the machine was overloaded in interval between
> the two snapshots. I thought I'd written a blog note about this some years
> ago, but all I could find was a reply in a comment answering a similar
> question to the one you;ve asked:
>
> https://jonathanlewis.wordpress.com/statspack-examples/#comment-57936
> <https://urldefense.com/v3/__https:/jonathanlewis.wordpress.com/statspack-examples/*comment-57936__;Iw!!PAXy-sJw!OMyq1fpIn1OR3h_3X4bXAHvsl6AHv7Rt0vSM4KrQkiNdEZR6J4VXt7VDWaPgkVQqY0UaltcLle_b4ixEqMkKTQ$>
>
>
>
> The sequence used by statspack to generate snap ids has a cache size of 10
> - if the instance is under pressure the sequence can be forced from the
> shared pool without being written back to the seq$ table so the next call
> to nextval loses the values from the current value to the next highwater.
> To avoid gaps you could set the sequece (STATS$SNAPSHOT_ID) to NOCACHE,
>
>
>
> Regards
>
> Jonathan Lewis
>
>
>
>
>
>
>
>
>
> On Wed, 1 Mar 2023 at 22:03, Daniel Hubler <DHubler_at_versiti.org> wrote:
>
> Oracle v19.13 (SE) on Oracle linux 7
>
> ===
>
> The snap_id’s in Statspack are skipping values like this:
>
> ===
>
> Snap
>
> Instance DB Name Snap Id Snap Started Level Comment
>
> ------------ ------------ --------- ----------------- -----
> --------------------
>
> xxxxxxxx xxxxxxxx 18923 28 Feb 2023 18:00 5
>
> 18924 28 Feb 2023 19:00 5
>
> 18925 28 Feb 2023 20:00 5
>
> 18926 28 Feb 2023 21:00 5
>
> 18927 28 Feb 2023 22:00 5
>
> 18928 28 Feb 2023 23:00 5
>
> 18929 01 Mar 2023 00:00 5 <<<<<< gap
> here
>
> 18933 01 Mar 2023 01:00 5 <<<<<< gap
> here
>
> 18934 01 Mar 2023 02:00 5
>
> 18935 01 Mar 2023 03:00 5
>
> 18936 01 Mar 2023 04:00 5
>
>
>
>
>
>
>
>
>
>
>
> This would not really bother me too much, except that when you try to run
> a Statspack report
>
> that includes the gap, the results *sometimes* get wonky. Example:
>
> ===
>
> STATSPACK report for
>
>
>
> Database DB Id Instance Inst Num Startup Time Release RAC
>
> ~~~~~~~~ ----------- ------------ -------- --------------- ----------- ---
>
> 2711155550 xxxxxxxx 1 26-Jun-22 16:09 19.0.0.0.0 NO
>
>
>
> Host Name Platform CPUs Cores Sockets Memory
> (G)
>
> ~~~~ ---------------- ---------------------- ----- ----- -------
> ------------
>
> verbcdbsp91.ads. Linux x86 64-bit 10 10 5
> 31.2
>
>
>
> Snapshot Snap Id Snap Time Sessions Curs/Sess Comment
>
> ~~~~~~~~ ---------- ------------------ -------- ---------
> ------------------
>
> Begin Snap: 18929 01-Mar-23 00:00:00 387 6.1
> <<<<<<<<<<<<< including the gap!
>
> End Snap: 18933 01-Mar-23 01:00:00 380 6.2
>
> Elapsed: 60.00 (mins) Av Act Sess: 0.5
>
> DB time: 30.93 (mins) DB CPU: 22.64 (mins)
>
>
>
> .
>
> .
>
> .
>
> .
>
> LSQL ordered by CPU DB/Inst: xxxxxxxx/xxxxxxxx Snaps: 18929-18933
>
> -> Total DB CPU (s): 1,358
>
> -> Captured SQL accounts for 172.6% of Total DB CPU
>
> -> SQL reported below exceeded 1.0% of Total DB CPU
>
>
>
> CPU CPU per
> Elapsd Old
>
> Time (s) Executions Exec (s) %Total Time (s) Buffer Gets
> Hash Value
>
> ---------- ------------ ---------- ------ ---------- ---------------
> ----------
>
> ######### 340,900,079 0.00 ###### ######### 2,824,640,111
> 2626584584
>
> Module: DPQDRDTL
>
> SELECT COUNT(DI.DONOR_ID) FROM DONOR_INTERDICTIONS DI WHERE DI.D
>
> ONOR_ID = :B2 AND TRUNC(:B1 ) >= DI.EFF_DATE AND DI.TERM_DATE IS
>
> NULL AND DI.RELEASE_DATE IS NULL AND EXISTS (SELECT 'x' FROM VA
>
> LID_PROC_EXCLUSIONS VPE WHERE VPE.INTER_CODE = DI.INTER_CODE AND
>
>
>
> (((the 340 million executions is way out of line)))
>
>
>
>
>
> A little research on the single SQL statement above shows some weird data:
>
> ===
>
> SQL> l
>
> 1 select snap_id,old_hash_value,cpu_time,executions
>
> 2 from perfstat.stats$sql_summary
>
> 3 where old_hash_value = 2626584584
>
> 4 and (snap_id = 18929
>
> 5 or
>
> 6* snap_id = 18933)
>
> SQL> /
>
>
>
> SNAP_ID OLD_HASH_VALUE CPU_TIME EXECUTIONS
>
> ---------- -------------- ---------------- ----------
>
> 18929 2626584584 109,976,582,786 340901423
>
> 18933 2626584584 109,976,205,216 340900079
>
>
>
> 2 rows selected.
>
>
>
>
>
> The CPU consumption measured for that SQL went down
>
> as time went on. . .which is nuts.
>
> Same for the number of executions.
>
>
>
>
>
> Any ideas?
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>

--
http://www.freelists.org/webpage/oracle-l
Received on Thu Mar 09 2023 - 17:45:26 CET

Original text of this message