Alert log timestamp different with system date in RAC

Received request from client as the alert log file timestamp is mismatching with server time, It is 2-node RAC with 11.2.0.3. Interestingly when we connect to the database without using the Oracle net service the timestamp is same as the server time and when we connect to the database using Oracle net service almost 4 hours of time difference noticed. Why the timestamp is different when you connect with and without Oracle net service? Strange….

node40> sqlplus '/ as sysdba'
SQL*Plus: Release 11.2.0.3.0 Production on Thu Jun 20 00:59:15 2013
Copyright (c) 1982, 2011, Oracle.  All rights reserved.
Connected to:
Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
With the Partitioning, Real Application Clusters, Automatic Storage Management, Oracle Label Security,
OLAP, Data Mining, Oracle Database Vault and Real Application Testing options
SQL> select instance_name from v$instance;
INSTANCE_NAME
----------------
amys12
SQL> alter session set nls_date_format='dd-mm-yyyy hh:mi:ss';
Session altered.
SQL> select sysdate from dual;
SYSDATE
-------------------
20-06-2013 12:59:37
SQL> !date
Thu Jun 20 12:59:56 EDT 2013

Hope you noticed above that timestamp difference from instance and the server, it is same. isn’t it? Now we will connect to the database using Oracle net service to verify the timestamp difference.

node40> sqlplus system/*******@amys
SQL*Plus: Release 11.2.0.3.0 Production on Thu Jun 20 00:59:15 2013
Copyright (c) 1982, 2011, Oracle.  All rights reserved.
Connected to:
Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
With the Partitioning, Real Application Clusters, Automatic Storage Management, Oracle Label Security,
OLAP, Data Mining, Oracle Database Vault and Real Application Testing options
SQL> select instance_name from v$instance;
INSTANCE_NAME
----------------
amys12
SQL>  select instance_name from v$instance;
INSTANCE_NAME
----------------
amys11
SQL> 
SQL> alter session set nls_date_format='dd-mm-yyyy hh:mi:ss';
Session altered.
SQL> select sysdate from dual;
SYSDATE
-------------------
20-06-2013 05:42:08
SQL> !date
Thu Jun 20 01:42:15 EDT 2013

So its clear that almost 4 hours of time difference between server and the instance. Now lets verify the settings from the instance, OS environment variables and the files related to timezone for cluster.

SQL> select
  sysdate,
  current_timestamp,
  systimestamp,
  localtimestamp
from
  dual;
SYSDATE            CURRENT_TIMESTAMP                        SYSTIMESTAMP                             LOCALTIMESTAMP
------------------ ---------------------------------------- ---------------------------------------- ---------------------------------------------------------------------------
20-JUN-13          20-JUN-13 03.57.18.080854 AM -04:00      20-JUN-13 03.57.18.080848 AM -04:00      20-JUN-13 03.57.18.080854 AM

SQL>

SQL> show parameter nls;
NAME                                 TYPE                             VALUE
------------------------------------ -------------------------------- ------------------------------
nls_calendar                         string                           GREGORIAN
nls_date_format                      string                           dd-mm-yyyy hh:mi:ss
nls_date_language                    string                           AMERICAN
nls_language                         string                           AMERICAN
nls_territory                        string                           AMERICA
nls_time_format                      string                           HH.MI.SSXFF AM
nls_time_tz_format                   string                           HH.MI.SSXFF AM TZR
nls_timestamp_format                 string                           DD-MON-RR HH.MI.SSXFF AM
nls_timestamp_tz_format              string                           DD-MON-RR HH.MI.SSXFF AM TZR
node40> env |grep NLS
NLS_LANG=AMERICAN_AMERICA.AL32UTF8
ORA_NLS10=/u00/app/oracle/product/11.2.0.3/database/nls/data
ORA_NLS33=
node40>

Haven’t seen any such timezone differences any where either from Linux and from Oracle instance and finally dont forget to verify the timzone settings for the crs configuration[environment variables] of each node. Finally if you see in below file from the CRS_HOME, the timezone for the server is EDT but the timezone from CRS configuration of the node mentioned to UTC.  Of course on startup of CRS these files also considered.

[root@node40 install]# pwd
/u00/app/11.2.0.3/grid/crs/install
[root@node40 install]# cat s_crsconfig_node40_env.txt
### This file can be used to modify the NLS_LANG environment variable, which determines the charset to be used for messages.
### For example, a new charset can be configured by setting NLS_LANG=JAPANESE_JAPAN.UTF8
### Do not modify this file except to change NLS_LANG, or under the direction of Oracle Support Services
TZ=UTC
NLS_LANG=AMERICAN_AMERICA.AL32UTF8
TNS_ADMIN=
ORACLE_BASE=
[root@node40 install]#

If we see timezone converter, Of course its exactly 4 hours of difference from UTC to EDT, To fix this issue you may need to do any of below two things.

1) Consider changing the TZ same as server timezone in crsconfig file of the node

2) Comment out the TZ variable in the crsconfig file.

After modifying you have to recycle the CRS and all the services to use of same timezone as server.

Now changed the file s_crsconfig_node40_env.txt as below from UTC to America/New_York

node40> more s_crsconfig_l120406dcss3129_env.txt
### This file can be used to modify the NLS_LANG environment variable, which determines the charset to be used for messages.
### For example, a new charset can be configured by setting NLS_LANG=JAPANESE_JAPAN.UTF8
### Do not modify this file except to change NLS_LANG, or under the direction of Oracle Support Services
TZ=America/New_York
NLS_LANG=AMERICAN_AMERICA.AL32UTF8
TNS_ADMIN=
ORACLE_BASE=
node40>

Now rebooted all the CRS services and ASM/Database services, Again tested the timestamp from instance and also from server.

node40> sqlplus system/*****@amys
SQL*Plus: Release 11.2.0.3.0 Production on Thu Jun 20 05:30:01 2013
Copyright (c) 1982, 2011, Oracle.  All rights reserved.
Connected to:
Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
With the Partitioning, Real Application Clusters, Automatic Storage Management, Oracle Label Security,OLAP, Data Mining, Oracle Database Vault and Real Application Testing options
SQL> select sysdate from dual;
SYSDATE
-------------------
20-06-2013 05:30:13
SQL> !date
Thu Jun 20 05:30:19 EDT 2013

Now after connecting to the database with the Oracle net service the timestamp is matched from the instance and also from the server.  Now it FIXED!!!!!  This might be one case and there are some other reasons for mismatch timestamp from server and alert log file. I’m listing in brief what we have to do if there is no issue with the file s_crsconfig_<node>_env.txt

Check the environment variables set for database and listener in your CRS configuration

srvctl getenv database -d <dbname>
srvctl getenv nodeapps -n <nodename>
-- If you are 11.2, then use 'getenv listener' instead of 'getenv nodeapps':
srvctl getenv listener

If required set the correct TZ value for the database via SRVCTL as follows

srvctl setenv database -d <dbname> -t 'TZ=<the TZ you want>'
srvctl setenv nodeapps -n crmnode1 -t 'TZ=<the TZ you want>'
-- If you are 11.2, then use 'setenv listener' instead of 'setenv nodeapps':
srvctl setenv listener -l <listenername> -t 'TZ=<the TZ you want>'

— Happy Reading —