Investigating the SCN intrinsic growth rate
Back to overview

Investigating the SCN intrinsic growth rate

Published on: Category: IT development and operations

A while ago, we had a warning about the intrinsic growth of the SCN (system change number) in our Oracle 12.2 database alert file. This situation occurred several times within a few weeks.

"Warning: The SCN intrinsic growth rate has been consistently
higher than system default 16384 per sec. for last 60 mins.
Current SCN intrinsic growth rate is 25867 per sec., zas 200fffff!
The Current SCN value is  46747726691, SCN Compat value is 1"

My initial reaction was that SCNs are related to commits, so either the load on the database was very high or the application logic should be changed. Another possibility was that a commit was done after every update, instead of using batch commits.

It turned out to be a little more complicated than I expected. Where do you look when you want to find the relation between SCNs and commits? And how serious is this warning anyway? This blog is going to be about the various ways I investigated this problem and identified the potential impact.

Oracle Support notes

The first place to look for information about warnings in the alert file is the Oracle Support website. I found several related notes:

  • ORA-19706 and Related Alert Log Messages (Doc ID 1393360.1)
    This note suggests that the actual message is specific to database version 12.2, but in older versions we might have similar warnings, like “Warning: The SCN headroom for this database is only NN days!”

    If you encounter an alert log message like any of these entries, you are advised to follow the instructions in ID 1388639.1 and log a Service Request with Oracle support.

    Evidence to collect when reporting "high SCN rate" issues to Oracle Support (Doc ID 1388639.1)
  • This note gives information on what information you should deliver when logging a service request.
     
  • System Change Number (SCN), Headroom, Security and Patch Information (Doc ID 1376995.1)
    This note gives more information about the usage of the SCN. The system change number (SCN) is a logical, internal timestamp used by the Oracle Database. SCNs order events that occur within the database. The database uses SCNs to query and track changes. When a transaction commits, the database records a SCN for this commit.

    There is an upper limit to how many SCNs an Oracle Database can use. The limit is currently 281 trillion (2^48) SCN values.

    Given that there is an upper limit, it’s important that any given Oracle Database does not run out of available SCNs.
    The note also explains when the warning is raised. The Oracle Database calculates a "not to exceed" limit for the number of SCNs a database can currently use, based on the number of seconds since 1988 multiplied by 16384. Doing this ensures that Oracle Databases will ration SCNs over time.

How serious is this warning?

The warning is raised at a rate of 2^14 = 16384 SCNs per second for the last 60 minutes.
The maximum SCN is 2^48 = 281.474.976.710.656.

At a rate of 16348 SCNs per second, we will have 2^(48-14) seconds, or 544 years to reach that maximum. That should be enough in a normal situation, but the upper limit of 2^48 is only the maximum absolute value the database can store.
The limit is also related to the number of seconds since 1988. The limit of 2^48 is the maximum in the year 2532 (1988+544). But in 2018 the maximum is (2018-1988)*365*24*60*60*2^14 = 1.550.057.472.000.

The warning should not be ignored. When you reach the limit you will get ora-600 [2252] errors, but when you reach the absolute upper limit SCN the database will just stop working.

The good news is that in our situation the warning said the SCN growth rate was 25867 per second in that specific hour, so in that hour we came a little closer (25867-16384=9483) to the limit. We don’t come close to the limit every hour; the normal growth rate is lower than 16384.

Oracle Support

We called Oracle Support, and they told us Oracle Development is currently working on this issue.

Oracle Support confirmed that the SCN headroom looks good. Based on the AWR report, Oracle Support noticed a high number of commits and suggested to check with application team to commit by increasing the transaction size.

Investigation with AWR

The warning in the alert file told us that the SCN intrinsic growth rate has been consistently higher than system default: 16384 per second for last 60 mins. If we’re looking at a time frame of an hour, an AWR report might be a good place to start. We have AWR configured to make snapshots every hour.

In the AWR report, I noticed the number of user commits was 210 per second. Yes, that is a lot of commits, but it isn’t that different from the normal load of this database. And if a commit is related to a SCN, it’s also much lower than 16384 per second.

The AWR report also contained an ADDM finding: Waits on event "log file sync" while performing COMMIT and ROLLBACK operations were consuming significant database time. Investigate application logic for possible reduction in the number of  COMMIT operations by increasing the size of transactions.

This reduction of the commits in the ADDM finding was also suggested by Oracle Support. From my point of view, it wasn’t really that high though.

Shorter timeframe

Because the AWR wasn’t helping me find the cause, I needed to investigate a shorter timeframe. I wanted to know a more specific timeframe so I could create an ASH report. The default for ASH is 15 minutes.

So the next challenge was to find the 15 minute timeframe in which the SCN growth rate was the highest.

Doc ID 1388639.1 suggested to query v$archived_log. That view has information about all the log switches on the database, including a timestamp and the SCN. Although you could map timestamps to SCNs, it’s not really better than the AWR report. We’re still stuck to random timestamps; in this case the timestamp of the logswitch.

Using the timestamp_to_scn function

A better way is to use the function timestamp_to_scn. This function returns a SCN based on a timestamp, like the current timestamp:

  1. SQL> SELECT  timestamp_to_scn(sysdate) FROM dual ;
  2.  
  3. TIMESTAMP_TO_SCN(SYSDATE)
  4. -------------------------
  5.               91903104563
  6.  
  7. SQL>

The next step was to make a list of timestamps together with the matching SCN and the matching SCN upper limit, based on the number of seconds since 1988 multiplied by 16,384.

This shows the timestamps and SCNs for the last day:
 

  1. SELECT  sysdate - (rownum/24)                   datetimestamp
  2. ,       timestamp_to_scn(sysdate - (rownum/24)) SCN
  3. ,       ((sysdate - (rownum/24))  - to_date('01-01-1988','DD-MM-YYYY' ))
  4.             * 24 * 60 * 60 * 16384 upper_lmt
  5. FROM dual
  6. CONNECT BY rownum <= 24
  7. /
  1. DATETIMESTAMP                        SCN            UPPER_LMT
  2. ------------------- -------------------- --------------------
  3. 09-07-2018-13:23:39          95423916508       15780233527296
  4. 09-07-2018-12:23:39          95380086165       15780174544896
  5. 09-07-2018-11:23:39          95338871931       15780115562496
  6. 09-07-2018-10:23:39          95303437600       15780056580096
  7. 09-07-2018-09:23:39          95265573942       15779997597696
  8. 09-07-2018-08:23:39          95226645452       15779938615296
  9. 09-07-2018-07:23:39          95186822906       15779879632896
  10. 09-07-2018-06:23:39          95147382509       15779820650496
  11. 09-07-2018-05:23:39          95115474008       15779761668096
  12. 09-07-2018-04:23:39          95079712219       15779702685696
  13. 09-07-2018-03:23:39          95041469231       15779643703296
  14. 09-07-2018-02:23:39          95006499794       15779584720896
  15. 09-07-2018-01:23:39          94975060529       15779525738496
  16. 09-07-2018-00:23:39          94945771055       15779466756096
  17. 08-07-2018-23:23:39          94907451372       15779407773696
  18. 08-07-2018-22:23:39          94875158341       15779348791296
  19. 08-07-2018-21:23:39          94838756696       15779289808896
  20. 08-07-2018-20:23:39          94800190958       15779230826496
  21. 08-07-2018-19:23:39          94757984611       15779171844096
  22. 08-07-2018-18:23:39          94724548846       15779112861696
  23. 08-07-2018-17:23:39          94685506947       15779053879296
  24. 08-07-2018-16:23:39          94646644945       15778994896896
  25. 08-07-2018-15:23:39          94605003069       15778935914496
  26. 08-07-2018-14:23:39          94572205685       15778876932096
  27.  
  28. 24 rows selected.

The current SCN is about 0,57% of the current upper limit.

Finding the top SCN rate

Based on this idea I created a query that gives me the 15 minute timeframe with highest growth in SCNs in the last 3 days.

Every minute a new timeframe starts, and because we have 1440 minutes in a days, we have 4320 timeframes to investigate. For each of them we have to calculate the growth of the SCN within that 15 minute timeframe.

We only want to show the top results, in this case only the timeframes with a rate of over 14000 per second.

  1. ALTER SESSION SET nls_date_format='MM/DD/YY HH24:MI' ;
  2.  
  3. WITH datelist AS
  4. ( SELECT sysdate - (rownum/1440) - (15/1440)  starttime -- 15 minute interval
  5.   ,      sysdate - (rownum/1440)                endtime
  6.   FROM dual
  7.   CONNECT BY rownum <= (3*1440)  -- 3 days history
  8. )
  9. SELECT starttime
  10. ,      endtime
  11. ,      timestamp_to_scn(endtime) - timestamp_to_scn(starttime) scngrowth
  12. ,      round((timestamp_to_scn(endtime) - timestamp_to_scn(starttime)) /
  13.           (((24*60*60)*(endtime-starttime ))))   scnrate
  14. FROM   datelist
  15. WHERE  round((timestamp_to_scn(endtime) - timestamp_to_scn(starttime)) /
  16.                   (((24*60*60)*(endtime-starttime )))) >=  14000
  17. ORDER BY 4 DESC
  18. /
  1. STARTTIME      ENDTIME                   SCNGROWTH              SCNRATE
  2. -------------- -------------- -------------------- --------------------
  3. 07/06/18 18:09 07/06/18 18:24             12761928                14180
  4. 07/07/18 05:20 07/07/18 05:35             12742537                14158
  5. 07/09/18 13:59 07/09/18 14:14             12705077                14117
  6. 07/09/18 12:57 07/09/18 13:12             12672507                14081
  7. 07/09/18 07:06 07/09/18 07:21             12654287                14060

So, now we have found the (sometimes overlapping) 15 minute time frames with the highest SCN rate (SCN growth per second) for the last 3 days. And even in those time frames the SCN rate is still under 16384. No warnings in the alert file this week….

Running the ASH report

The date format I used in the query above is the same as used by the ASH report, so you can just copy/paste the start time. For the duration we enter 15 minutes.

  1. SQL> @@$ORACLE_HOME/rdbms/admin/ashrpt.sql
  2.  
  3. ASH Samples IN this Workload Repository schema
  4. ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
  5.  
  6. Oldest ASH sample available:  01-Jul-18 00:00:01   [  12379 mins IN the past]
  7. Latest ASH sample available:  09-Jul-18 14:18:58   [      0 mins IN the past]
  8.  
  9.  
  10. Specify the timeframe TO generate the ASH report
  11. ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
  12. Enter BEGIN TIME FOR report:
  13.  
  14. --    Valid input formats:
  15. --      To specify absolute begin time:
  16. --        [MM/DD[/YY]] HH24:MI[:SS]
  17. --        Examples: 02/23/03 14:30:15
  18. --                  02/23 14:30:15
  19. --                  14:30:15
  20. --                  14:30
  21. --      To specify relative begin time: (start with '-' sign)
  22. --        -[HH24:]MI
  23. --        Examples: -1:15  (SYSDATE - 1 Hr 15 Mins)
  24. --                  -25    (SYSDATE - 25 Mins)
  25.  
  26. Defaults TO -15 mins
  27. Enter VALUE FOR begin_time: 07/06/18 18:09
  28. Report BEGIN TIME specified: 07/06/18 18:09
  29.  
  30. Enter duration IN minutes starting FROM BEGIN TIME:
  31. Defaults TO SYSDATE - begin_time
  32. Press Enter TO analyze till CURRENT TIME
  33. Enter VALUE FOR duration: 15
  34. Report duration specified:   15
  35.  
  36. USING 06-Jul-18 18:09:00 AS report BEGIN TIME
  37. USING 06-Jul-18 18:24:00 AS report END TIME
  38.  
  39. Specify the Report Name
  40. ~~~~~~~~~~~~~~~~~~~~~~~
  41. The DEFAULT report file name IS ashrpt_1_0706_1824.html.  TO USE this name,
  42. press <return> TO continue, otherwise enter an alternative.
  43. Enter VALUE FOR report_name:
  44.  
  45. USING the report name ashrpt_1_0706_1824.html
  46.  
  47. Summary OF ALL USER INPUT
  48. -------------------------
  49. Format         : HTML
  50. DB Id          : 2019395491
  51. Inst num       : 1
  52. BEGIN TIME     : 06-Jul-18 18:09:00
  53. END TIME       : 06-Jul-18 18:24:00
  54. Slot width     : DEFAULT
  55. Report targets : 0
  56. Report name    : ashrpt_1_0706_1824.html

Finding SCN in AWR

The AWR report didn’t show us much information about the current SCN, but it has some information about the growth rate, if you know where to find it.

Under “Instance Activity Stats” you can find the number of “calls to kcmgas”. In the Oracle documentation this is described as the “Number of calls to routine kcmgas to get a new SCN”.

The value of these calls per second in the AWR report is very close to the SCN rate as calculated with the timestamp_to_scn function.

V$SESSTAT view

The number of “calls to kcmgas” used to create a new SCN can also be found in the views V$SESSTAT and V$SYSSTAT.

We can use V$SESSTAT to find the sessions that cause a high SCN rate. We can also test the impact on the SCN number of specific actions.

For example, when I do a select on a big table that’s also in use by other sessions, my session will do another 7 calls to kcmgas. So, my query will cause a higher SCN. This is caused by the read consistency of the database, that also uses a SCN.

  1. SQL> CONNECT <user>/<pass>@<service>
  2. Connected.
  3. SQL> SELECT ses.value
  4. FROM v$sesstat ses
  5. ,    v$statname stat
  6. WHERE stat.statistic#=ses.statistic#
  7. AND ses.sid IN (SELECT sid FROM v$mystat)
  8. AND stat.name = 'calls to kcmgas'
  9. /
  10.  
  11.                VALUE
  12. --------------------
  13.                    2
  14.  
  15. SQL> SELECT COUNT(*) FROM mybigtable ;
  16.  
  17.             COUNT(*)
  18. --------------------
  19.             12198814
  20.  
  21. SQL>  SELECT ses.value
  22. FROM v$sesstat ses
  23. ,    v$statname stat
  24. WHERE stat.statistic#=ses.statistic#
  25. AND ses.sid IN (SELECT sid FROM v$mystat)
  26. AND stat.name = 'calls to kcmgas'
  27. /
  28.  
  29.                VALUE
  30. --------------------
  31.                    9
  32.  
  33. SQL>

Comparing the SCN and commit rate

With V$SESSTAT we can query the statistics for all sessions currently connected to the database. In this way we can find sessions that are responsible for a high SCN rate. We can compare this to the commit rate for that session.

The results of the query below showed us that on our database the high SCN rate was mainly caused by background processes. For most user sessions there is a relation between a high SCN rate and a high commit rate, for background sessions the commit rate is always empty.

  1. SELECT ses.sid
  2. ,      decode(ses.username ,NULL,'background','user' ) session_type
  3. ,      (sysdate - logon_time) * 24 * 60 * 60 connect_seconds
  4. ,      sstat1.value SCN#
  5. ,      sstat2.value COMMIT#
  6. ,      round(sstat1.value / ((sysdate - logon_time ) * 24 * 60 * 60),2) scn_rate
  7. ,      round(sstat2.value / ((sysdate - logon_time ) * 24 * 60 * 60),2) commit_rate
  8. FROM   v$sesstat  sstat1
  9. ,      v$sesstat  sstat2
  10. ,      v$statname sn1
  11. ,      v$statname sn2
  12. ,      v$session  ses
  13. WHERE sstat1.statistic# = sn1.statistic#
  14. AND   sstat2.statistic# = sn2.statistic#
  15. AND   sn1.name          = 'calls to kcmgas'
  16. AND   sn2.name          = 'user commits'
  17. AND   ses.sid           = sstat1.sid
  18. AND   ses.sid           = sstat2.sid
  19. ORDER BY 6 DESC
  20. /
  21.  
  22.        SID SESSION_TY CONNECT_SECONDS       SCN#    COMMIT#   SCN_RATE COMMIT_RATE
  23. ---------- ---------- --------------- ---------- ---------- ---------- -----------
  24.       8478 background          459572  214506344          0     466.75           0
  25.       7551 background          452395  209729934          0      463.6           0
  26.       3776 background          290389  133863489          0     460.98           0
  27.       8496 background          121201   55685740          0     459.45           0
  28.       8729 background          286773  128180386          0     446.98           0
  29.      12009 background          290392  128867329          0     443.77           0
  30.      13173 background          196775   87268032          0     443.49           0
  31.      12004 background          103166   45681480          0      442.8           0
  32.       8735 background          275980  121563094          0     440.48           0
  33.       3096 background          430810  185436599          0     430.44           0
  34.       8027 background           95990   40912187          0     426.21           0
  35.       7529 background          193218   81367643          0     421.12           0
  36.       2370 background          527978  219521415          0     415.78           0
  37.      14604 background          283216  117052382          0      413.3           0
  38.      14132 background          113965   46586388          0     408.78           0
  39.       7552 background          294009  119775077          0     407.39           0
  40.      13172 background          182423   73865595          0     404.91           0
  41.      14592 background           74414   29767705          0     400.03           0
  42.       3802 background          268804  107486102          0     399.87           0
  43.       9910 background          117582   46596720          0     396.29           0
  44.      12021 background           49182   19321676          0     392.86           0
  45.        974 background          160816   59996495          0     373.08           0
  46.      12723 background           74450   25455559          0     341.91           0
  47.       3310 background          193215   65915175          0     341.15           0
  48.      12963 background           49179   15687084          0     318.98           0
  49.       6111 background         3584090 1031139557          0      287.7           0
  50.       6829 USER                   303       1267       1123       4.18        3.71
  51.       9665 USER                   904       1845       1691       2.04        1.87
  52.       8022 USER                   898       1677       1520       1.87        1.69
  53.       3323 USER                   898       1406       1260       1.57         1.4
  54.       2839 USER                  7503      10822       9813       1.44        1.31
  55.      11060 USER                  3892       5334       4781       1.37        1.23
  56.      13184 USER                  1765       2359       2038       1.34        1.15
  57.       9199 USER                   898       1135        935       1.26        1.04
  58.       2130 USER                  8105       9548       8518       1.18        1.05
  59.      11525 USER                   898       1054        944       1.17        1.05
  60.       6130 USER                  3895       4453       4199       1.14        1.08
  61.       8012 USER                  7503       8576       7774       1.14        1.04
  62.       4497 USER                   898        962        882       1.07         .98
  63.       5201 USER                  7220       7551       6226       1.05         .86
  64.      11317 USER                 12906      13371      11997       1.04         .93
  65.  
  66. [...]
  67. 1979 ROWS selected.

Conclusion

Be aware that there are limits to the SCN, so when you find warnings in the alert file, you need to investigate the problem. If you find an issue you should work with Oracle Support. By uploading information they can check if there is enough room between the current and maximum SCN.

Problems can be caused by a bug, like 12371955: Hot Backup can cause increased SCN growth rate leading to ORA-600 [2252] errors (Doc ID 12371955.8).

If you want to find the exact moment there is a high growth of SCNs you need to convert timestamps to SCNs. You get the best results using the functions SCN_TO_TIMESTAMP and TIMESTAMP_TO_SCN.

A high commit rate is always related to user processes, but SCNs are also related to background processes. Even sessions that don’t commit can have an impact on the SCN.

Bastiaan Bak
About the author Bastiaan Bak

DBA with over 15 years of experience. Experience in various branches, with several modules. Including: Oracle database, Oracle RAC, Oracle EBS and PL/SQL.

More posts by Bastiaan Bak
Comments
Reply