Re: V$FLASHBACK_DATABASE_LOG oldest_flashback_time reporting future time

  • From: Rakesh Ra <rakeshra.tr@xxxxxxxxx>
  • To: Leng <lkaing@xxxxxxxxx>
  • Date: Sun, 26 Jan 2020 19:03:04 +0530

Hi Leng,

Thanks for the reply.

We are not using fixed_date. When we connect to the database using listener
services, the sysdate is reporting in UTC time. However when i connect to
the database using OS authentication the sysdate is reported in CST time.
So i guess the issue is with the Oracle restart timezone setting in the
$GRID_HOME/crs/install/s_crsconfig_<hostname>_env.txt. I earlier thought
the setting of US/Central is the correct one. However please see below

lrwxrwxrwx 1 root root 35 Aug 13 23:16 /etc/localtime ->
/usr/share/zoneinfo/America/Chicago

Entry from  s_crsconfig_<hostname>_env.txt:

TZ=US/Central  <<<<<<<<<<< It looks this should be "America/Chicago"
NLS_LANG=AMERICAN_AMERICA.AL32UTF8
CRS_LIMIT_STACK=2048
CRS_LIMIT_OPENFILE=65536
CRS_LIMIT_NPROC=16384
TNS_ADMIN=

v$flashback_database_log relies on fixed view x$krfblog which
essential reads the data from control file. If we check the OS environment
variables I can see it pick Universal time rather than local time. This
could be the reason that my query with sysdate is reporting CST time
whereas oldest_flashback_time is reporting in UTC time. I took the CF dump
as well and there too I see it picks Universal time for FB logs. Now I will
be focusing on correcting this at
$GRID_HOME/crs/install/s_crsconfig_<hostname>_env.txt to
TZ="America/Chicago" and then see how it behaves whether
oldest_flashback_time is working well or not.

ps -ef |grep ckpt
oracle   432016      1  0  2019 ?        02:14:50 ora_ckpt_<instance_name>

[hostname{/u01/app/12.1.0.2/grid/crs/install}: ]$ ps eww 432016
   PID TTY      STAT   TIME COMMAND
432016 ?        Ss   134:50 ora_ckpt_cdp0351a1
__CRS_ACTIVE_VERSION=12.1.0.2.0 __CLSAGFW_TYPE_NAME=ora.evm.type
ENV_FILE=/u01/app/
12.1.0.2/grid/crs/install/s_crsconfig_c617rcqfldbpf_env.txt
CRS_LIMIT_OPENFILE=65536 EDITOR=vi LANG=C
........................................
CRS_LIMIT_NPROC=16384
CLUUTIL_TRACE_FILE=/u01/app/oracle/crsdata/c617rcqfldbpf/crsconfig/cluutil4.log
*TZ=Universal* __IS_HASD_AGENT=TRUE
AGENT_HOME=/u01/app/oracle/product/OEMAgent/agent_13.2.0.0.0
SKGP_SPAWN_DIAG_PRE_EXEC_TS=1569656638
SKGP_SPAWN_DIAG_PRE_FORK_TS=1569656638
SKGP_SPAWN_DIAG_POST_FORK_TS=1569656638

BR,
Rakesh RA

On Sun, Jan 26, 2020 at 1:41 AM Leng <lkaing@xxxxxxxxx> wrote:

Are you doing a connection via Sql*Net? If not, try your query again via
Sql*net first. Also, add current_time to your query. Is your db using
fixed_date or something like that? if you do Ls on the flashback log file,
what time stamp do you get? Db time vs tz vs os time can get very
confusing.

I vaguely recall that there is a hidden parameter to change the frequency
in which flashback logs are written but that’s probably not what the
problem is.

Cheers,
Leng

On 25 Jan 2020, at 2:19 am, Rakesh Ra <rakeshra.tr@xxxxxxxxx> wrote:


Hi Listers,

I have database with version 12.1.0.2 26635845;Database PSU
12.1.0.2.171017, Oracle JavaVM Component (OCT2017). This is running on a
restart environment. The database is reporting oldest_flashback_time as a
future time and hence we are continuously getting alerted for the same. I
have checked the cluster time zone settings and this matches with the OS
server timezone which is US/Central timezone.

SELECT to_char(sysdate, 'YYYY-MM-DD HH24:MI') CURRENT_TIME
,to_char(f.oldest_flashback_time, 'YYYY-MM-DD HH24:MI')
OLDEST_FLASHBACK_TIME
,(sySQL> SQL> SQL> SQL>   2    3  sdate - f.oldest_flashback_time) * 24 *
60 HIST_MIN
FROM v$database d
,V$FLASHBACK_DATABASE_LOG f;
  4    5
CURRENT_TIME     OLDEST_FLASHBACK_TIME       HIST_MIN
------------------------------------ ------------------------------------
-------------
2020-01-24 09:13     2020-01-24 12:26 -192.72

The sysdate time is 09:13 AM CST and oldest_flashback_time is 12:26 PM
CST. Which is technically not possible as per me. I raised an SR with
Oracle and they came up with below statement which I am not in a position
to agree.

Statement from Oracle support as below:

"The oldest flashback time is determined by the oldest flashback marker
record written in the flashback logs. When the flashback log generation
reaches a new maximum we can see that
$flashback_database_log.oldest_flashback_time is more recent than sysdate
minus db_flashback_retention_target minutes and we cannot flash back the
full amount of time specified by db_flashback_retention_target.

The explanation for this is that one flashback marker record is written by
default once every 30 minutes. When flashback log generation reaches a new
maximum the logs are reused and the oldest flashback marker record is
overwritten.

Note that the DB_FLASHBACK_RETENTION_TARGET is a target and there is no
guarantee that you can flashback the database that far. In some cases if
there is space pressure in the flash recovery area where the flashback logs
are stored then the oldest flashback logs may be deleted. For a detailed
explanation of the flash recovery area deletion rules see the Database
Backup and Recovery User's Guide, Maintaining the Fast Recovery Area
section. To guarantee a flashback point-in-time you must use guaranteed
restore points (GRP). With GRP, the required flashback logs will never be
recycled or purged until GRP is dropped. You can hang the database if you
have a GRP and there’s insufficient space; so you need allocate more space
in the FRA depending on the intended duration of the GRP.

Have you reviewed below notes:

References:

Flashback logs are not kept for the full retention period even though
space is available ( Doc ID 1274075.1
<https://support.oracle.com/epmos/faces/DocumentDisplay?parent=SrDetailText&sourceId=3-22146533561&id=1274075.1>
 )
Flashback Database Best Practices & Performance ( Doc ID 565535.1
<https://support.oracle.com/epmos/faces/DocumentDisplay?parent=SrDetailText&sourceId=3-22146533561&id=565535.1>
 )"

There is no clarity on what is complex algorithm being used to retrieve 
oldest_flashback_time.
Does this make any sense or is this something normal?

BR,
Rakesh RA



Other related posts: