RE: Snap IDs in Statspack skipping / missing

From: Daniel Hubler <DHubler_at_Versiti.org>
Date: Thu, 9 Mar 2023 15:41:53 +0000
Message-ID: <MW5PR17MB596673ABFDD1C37504DCFDEFA8B59_at_MW5PR17MB5966.namprd17.prod.outlook.com>

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<mailto: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 - 16:41:53 CET