Search code examples
javaoraclejdbcoracle11gwebsphere

SYSDATE in JDBC statements seems to return different times when queried against the same Oracle database


We have 3 to 4 environments with identical setup, each with multiple clustered application servers (WebSphere) and Oracle Supercluster databases.

The problem I am seeing seems to be happening in only one of the environments that too about 20% of the time.

We have

  • Two applications deployed to same application server cluster

  • Both applications use the same data source configured to use the Oracle database which is a Oracle Supercluster.

Following is the structure of the table in question

TABLE SESSION_TBL 
(
    ID NUMBER(12, 0) NOT NULL, 
    USER_ID VARCHAR2(256 BYTE) NOT NULL, 
    SESSION_ID VARCHAR2(60 BYTE) NOT NULL, 
    LOGIN_TIME TIMESTAMP(6) NOT NULL 
 ) 

Application 1 stores a record using JDBC

    String sql = "Insert into SESSION_TBL " +
                 "  (USER_ID, SESSION_ID, LOGIN_TIME ) " +
                 "  values (?,?,SYSDATE)";

    try
    {
        sessionId = getNewSessionId(userId);
        st = conn.prepareStatement(sql);
        st.setString(1, userId);
        st.setString(2, sessionId);
        int rows = st.executeUpdate();
    }

After a few seconds, Application 2 executes the following code to look up the record inserted by the first application and compares with the current time

Statement st = null;
ResultSet result = null;

String sql = " Select * " +
" from SESSION_TBL " +
" where USER_ID = '" + userId + "' " +
" and SESSION_ID = '" + sessionId + "' ";

try {
    st = conn.createStatement();
    result = st.executeQuery(sql);

    if(!result.next()) { // We have no data, need to expire the session
        logger.debug("End hasSessionExpired()");
        return true;
    }
    else {
         logger.debug("SessionInfo:ResultSet not null");
    }


    // Get the time user logged in
    // java.sql.Timestamp
    Timestamp database_date = result.getTimestamp("LOGIN_TIME"); // get date from db
    long databaseDate = database_date.getTime(); // Convert to UNIX time

    // Get the current time from the database, so we are getting the time
    // from the same sources to compare
    // See the code below for this function
    long currentTime = getCurrentTimeFromDB (conn);

    // Both time values would be in milli seconds
    long diffSecs = (currentTime - databaseDate)/1000; 
    logger.info ("db:" + databaseDate + "   now:" + currentTime + " diffSecs:" + diffSecs);

Code to get the current time from the database

public static long getCurrentTimeFromDB () {
   .
   .
    // Using SYSDATE.  We only need precision upto seconds
    String s = "SELECT SYSDATE NOW FROM DUAL";
    rs = statement.executeQuery(s);
    if (rs.next()) {
        Timestamp dbTime = rs.getTimestamp("NOW");
        currentTime = dbTime.getTime();
    }
    return currentTime;
}

In about 1 of 5 or so executions, I see the current time to be earlier than the time of the record creation (login time). When this happens I see an output of the debug statement like the following:

db:1538793249000   now:1538793023000 diffSecs:-226
db:1538793249000   now:1538793023000 diffSecs:-202
db:1538793249000   now:1538793023000 diffSecs:-225

Seems like about 200+ seconds earlier

If you notice one thing the data type of the column (LOGIN_TIME) is a Timestamp and I am using SYSDATE to populate it. However, I am also using SYSDATE to get the time from DUAL. Of the 4 environments we have, this is happening in one and not always. Is there something wrong in the code or is it possible that the database Oracle super cluster) is actually returning a date that is not correct.


Solution

  • I thought I would put an answer in case someone else runs into a similar problem. As folks have suggested (in the comments) that the cluster nodes times could be out of sync. We have 2 nodes in the cluster, one node was ahead (of the current time) by a couple of minutes. One could detect if the time is out of sync, by running a SYSDATE query against each node.