Application Continuity (AC) for Java – JDBC HA – part 6

Posted on , updated on by Yannick Jaquier
Oracle ,

Table of contents

Preamble

Application Continuity (AC) feature introduced Oracle Database 12c Release 1 (12.1) masks database outages to application and end users.

You must use Transaction Guard 12.2 for using this feature.
Application Continuity is a feature of the Oracle JDBC Thin driver and is not supported by JDBC OCI driver.

I am using the exact same test table as with Transaction Guard (TG). I start in this initial state:

SQL> SELECT * FROM test01;
 
        ID        VAL
---------- ----------
         1          1
         2          1
         3          1
         4          1
         5          1
         6          1
         7          1
         8          1
         9          1
        10          1
 
10 ROWS selected.

You must configure your connection string using RETRY_COUNT, RETRY_DELAY, CONNECT_TIMEOUT, and TRANSPORT_CONNECT_TIMEOUT. As you can find in Oracle documentation:

Starting from Oracle Database 12c Release 2 (12.2.0.1), you must specify the value of the TRANSPORT_CONNECT_TIMEOUT parameter in milliseconds, instead of seconds.

The definition of each parameter:

  • RETRY_COUNT: To specify the number of times an ADDRESS list is traversed before the connection attempt is terminated.
  • RETRY_DELAY: To specify the delay in seconds between subsequent retries for a connection. This parameter works in conjunction with RETRY_COUNT parameter.
  • CONNECT_TIMEOUT: To specify the timeout duration in seconds for a client to establish an Oracle Net connection to an Oracle database.
  • TRANSPORT_CONNECT_TIMEOUT: To specify the transportation timeout duration in milliseconds for a client to establish an Oracle Net connection to an Oracle database.

I have defined mine as:

(DESCRIPTION=
  (RETRY_COUNT=20)
  (RETRY_DELAY=3)
  (CONNECT_TIMEOUT=60)
  (TRANSPORT_CONNECT_TIMEOUT=3000)
  (ADDRESS=
    (PROTOCOL=TCP)
    (HOST=rac-cluster-scan.domain.com)
    (PORT=1531))
    (CONNECT_DATA=(SERVICE_NAME=pdb1srv)))

I have used the exact same service as for Transaction Guard (TG):

[oracle@server2 ~]$ srvctl config service -db orcl -service pdb1srv
Service name: pdb1srv
Server pool: server_pool01
Cardinality: UNIFORM
Service role: PRIMARY
Management policy: AUTOMATIC
DTP transaction: false
AQ HA notifications: true
Global: false
Commit Outcome: true
Failover type: TRANSACTION
Failover method:
TAF failover retries:
TAF failover delay:
Failover restore: NONE
Connection Load Balancing Goal: LONG
Runtime Load Balancing Goal: NONE
TAF policy specification: NONE
Edition:
Pluggable database name: pdb1
Maximum lag time: ANY
SQL Translation Profile:
Retention: 86400 seconds
Replay Initiation Time: 300 seconds
Drain timeout:
Stop option:
Session State Consistency: DYNAMIC
GSM Flags: 0
Service is enabled
Service is individually enabled on nodes:
Service is individually disabled on nodes:
CSS critical: no

Application Continuity (AC) testing

The idea is almost the same as for Transaction Guard (TG) I start a transaction and before the commit I kill h=the pmon of the instance where my Java program has started. And we expect to see… nothing, means that replay will re-submit the transaction and the Java program will exit successfully !

Java testing code (you need to add ojdbc8.jar, ons.jar and ucp.jar to your project):

package ac01;
 
import java.sql.Connection;
import java.sql.ResultSet;
import java.sql.SQLException;
import java.sql.Statement;
import java.time.LocalDateTime;
import java.time.format.DateTimeFormatter;
import java.util.Locale;
import oracle.jdbc.replay.ReplayStatistics;
import oracle.jdbc.replay.ReplayableConnection;
import oracle.ucp.jdbc.PoolDataSource;
import oracle.ucp.jdbc.PoolDataSourceFactory;
 
public class ac01 {
  private static void display_replay_statistics(ReplayStatistics rs) {
    System.out.println("FailedReplayCount="+rs.getFailedReplayCount());
    System.out.println("ReplayDisablingCount="+rs.getReplayDisablingCount());
    System.out.println("SuccessfulReplayCount="+rs.getSuccessfulReplayCount());
    System.out.println("TotalCalls="+rs.getTotalCalls());
    System.out.println("TotalCallsAffectedByOutages="+rs.getTotalCallsAffectedByOutages()); 
    System.out.println("TotalCallsAffectedByOutagesDuringReplay="+ rs.getTotalCallsAffectedByOutagesDuringReplay());
    System.out.println("TotalCallsTriggeringReplay="+rs.getTotalCallsTriggeringReplay());
    System.out.println("TotalCompletedRequests="+rs.getTotalCompletedRequests());
    System.out.println("TotalProtectedCalls="+rs.getTotalProtectedCalls());
    System.out.println("TotalReplayAttempts="+rs.getTotalReplayAttempts());
    System.out.println("TotalRequests="+rs.getTotalRequests());
  }
 
  public static void main(String[] args) throws Exception {
    PoolDataSource pds = PoolDataSourceFactory.getPoolDataSource();
    Connection connection1 = null;
    Statement statement1 = null;
    ResultSet resultset1 = null;
    int i = 0;
 
    //To have date format in English, my Windows desktop being in French :-)
    Locale.setDefault(new Locale("en"));
    pds.setConnectionFactoryClassName("oracle.jdbc.replay.OracleDataSourceImpl");
    pds.setUser("yjaquier");
    pds.setPassword("secure_password");
    // The RAC connection using SCAN name and HA service
    pds.setURL("jdbc:oracle:thin:@(DESCRIPTION=(RETRY_COUNT=20)(RETRY_DELAY=3)(CONNECT_TIMEOUT=60)(TRANSPORT_CONNECT_TIMEOUT=3000)" + 
        "(ADDRESS=(PROTOCOL=TCP)(HOST=rac-cluster-scan.domain.com)(PORT=1531))(CONNECT_DATA=(SERVICE_NAME=pdb1srv)))");
    pds.setConnectionPoolName("ACPool");
 
    pds.setMinPoolSize(10);
    pds.setMaxPoolSize(20);
    pds.setInitialPoolSize(10);
 
    System.out.println("Trying to obtain a new connection from pool ...");
    connection1 = pds.getConnection();
    statement1 = connection1.createStatement();
    resultset1 = statement1.executeQuery("select sys_context('USERENV','SERVER_HOST') from dual");
    while (resultset1.next()) {
      System.out.println("Working on server " + resultset1.getString(1));
    }
    // To start fresh and to avoid
    // ORA-41412: results changed during replay; failover cannot continue
    ((oracle.jdbc.replay.ReplayableConnection) connection1).endRequest(); // Explicit request end
    try {
      ((oracle.jdbc.replay.ReplayableConnection) connection1).beginRequest(); // Explicit request begin
      connection1.setAutoCommit(false);
      statement1 = connection1.createStatement();
      for (i = 1; i<=10; i++) {
        System.out.println("Update "+i+" at "+LocalDateTime.now().format(DateTimeFormatter.ofPattern("dd-MM-yyyy HH:mm:ss")));          
        resultset1 = statement1.executeQuery("update test01 set val=val+1 where id = " + i);
      }
      System.out.println("\nJust before the kill...");
      // Sleeping 30 seconds to let me kill the instance where the connection has been borrowed from the pool
      Thread.sleep(30000);
      connection1.commit();
      ((oracle.jdbc.replay.ReplayableConnection) connection1).endRequest(); // Explicit request end
    }
    catch (Exception e)
    {
      //Transaction is not recoverable ?
      System.out.println("Exception detected:");
      e.printStackTrace();
      display_replay_statistics(((oracle.jdbc.replay.ReplayableConnection) connection1).getReplayStatistics(ReplayableConnection.StatisticsReportType.FOR_CURRENT_CONNECTION));
      e = ((SQLException) e).getNextException();
      e.printStackTrace();
      resultset1.close();
      statement1.close();
      connection1.close();
      System.exit(1);
    }
    // Transaction has been recovered
    statement1 = connection1.createStatement();
    resultset1 = statement1.executeQuery("select sys_context('USERENV','SERVER_HOST') from dual");
    while (resultset1.next()) {
      System.out.println("Working on server " + resultset1.getString(1));
    }
    display_replay_statistics(((oracle.jdbc.replay.ReplayableConnection) connection1).getReplayStatistics(ReplayableConnection.StatisticsReportType.FOR_CURRENT_CONNECTION));
    connection1.close();
    System.out.println("Normal exit");
    resultset1.close();
    statement1.close();
    connection1.close();
  }
}

Output display:

ac01
ac01

So we see that the connection I have borrowed from the pool is on server2.domain.com. The kill of this instance is done just before the explicit commit, thanks to the 30 seconds delay I have added. The magic is because the catch block has NOT been executed and the update has been replayed on surviving node i.e. server3.domain.com.

This is double confirmed by a simple database query:

SQL> SELECT * FROM test01;
 
        ID        VAL
---------- ----------
         1          2
         2          2
         3          2
         4          2
         5          2
         6          2
         7          2
         8          2
         9          2
        10          2
 
10 ROWS selected.

Issues encountered

No more data to read from socket

The complete error message is the following:

java.sql.SQLRecoverableException: No more data to read from socket
at oracle.jdbc.driver.T4CMAREngineNIO.prepareForReading(T4CMAREngineNIO.java:119)
at oracle.jdbc.driver.T4CMAREngineNIO.unmarshalUB1(T4CMAREngineNIO.java:534)
at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:485)
at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:252)
at oracle.jdbc.driver.T4C7Ocommoncall.doOCOMMIT(T4C7Ocommoncall.java:72)
at oracle.jdbc.driver.T4CConnection.doCommit(T4CConnection.java:961)
at oracle.jdbc.driver.PhysicalConnection.commit(PhysicalConnection.java:1937)
at oracle.jdbc.driver.PhysicalConnection.commit(PhysicalConnection.java:1942)
at oracle.jdbc.proxy.oracle$1jdbc$1replay$1driver$1TxnReplayableConnection$2oracle$1jdbc$1internal$1OracleConnection$$$Proxy.commit(Unknown Source)
at ac01.ac01.main(ac01.java:100)

You will find plenty of Oracle notes on MOS about this issue. In my case this was the connection1.setAutoCommit(false); that was set outside of the begin/end request block.

Closed Connection

The complete trace is:

java.sql.SQLException: Closed Statement
	at oracle.jdbc.driver.OracleClosedStatement.executeQuery(OracleClosedStatement.java:2431)
	at oracle.jdbc.driver.OracleStatementWrapper.executeQuery(OracleStatementWrapper.java:366)
	at oracle.jdbc.proxy.oracle$1jdbc$1replay$1driver$1TxnReplayableStatement$2oracle$1jdbc$1internal$1OracleStatement$$$Proxy.executeQuery(Unknown Source)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
	at java.lang.reflect.Method.invoke(Unknown Source)
	at oracle.jdbc.replay.driver.TxnReplayableBase.replayOneCall(TxnReplayableBase.java:520)
	at oracle.jdbc.replay.driver.TxnFailoverManagerImpl.replayAllBeforeLastCall(TxnFailoverManagerImpl.java:1773)
	at oracle.jdbc.replay.driver.TxnFailoverManagerImpl.handleOutageInternal(TxnFailoverManagerImpl.java:1425)
	at oracle.jdbc.replay.driver.TxnFailoverManagerImpl.handleOutage(TxnFailoverManagerImpl.java:989)
	at oracle.jdbc.replay.driver.TxnReplayableBase.onErrorForAll(TxnReplayableBase.java:339)
	at oracle.jdbc.replay.driver.TxnReplayableConnection.onErrorForAll(TxnReplayableConnection.java:395)
	at oracle.jdbc.replay.driver.TxnReplayableBase.onErrorVoidForAll(TxnReplayableBase.java:262)
	at oracle.jdbc.replay.driver.TxnReplayableConnection.onErrorVoidForAll(TxnReplayableConnection.java:388)
	at oracle.jdbc.proxy.oracle$1jdbc$1replay$1driver$1TxnReplayableConnection$2oracle$1jdbc$1internal$1OracleConnection$$$Proxy.commit(Unknown Source)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
	at java.lang.reflect.Method.invoke(Unknown Source)
	at oracle.ucp.jdbc.proxy.JDBCConnectionProxyFactory.invoke(JDBCConnectionProxyFactory.java:329)
	at oracle.ucp.jdbc.proxy.ConnectionProxyFactory.invoke(ConnectionProxyFactory.java:50)
	at com.sun.proxy.$Proxy17.commit(Unknown Source)
	at ac01.ac01.main(ac01.java:112)

I had it on top of the “No more data to read from socket” one. I have the feeling that the Java block between beginRequest() and endRequest() must be re-runnable and so I have been obliged to add in this block (even if set just above):

statement1 = connection1.createStatement();

ORA-41412: results changed during replay; failover cannot continue

This one was the trickiest I had ! To see it I have even been obliged to update my Java code by adding in catch part:

e = ((SQLException) e).getNextException();
e.printStackTrace();

the full trace is:

java.sql.SQLException: ORA-41412: results changed during replay; failover cannot continue
	at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:494)
	at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:446)
	at oracle.jdbc.driver.T4C8Oall.processError(T4C8Oall.java:1054)
	at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:623)
	at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:252)
	at oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:612)
	at oracle.jdbc.driver.T4CStatement.doOall8(T4CStatement.java:213)
	at oracle.jdbc.driver.T4CStatement.doOall8(T4CStatement.java:37)
	at oracle.jdbc.driver.T4CStatement.executeForDescribe(T4CStatement.java:733)
	at oracle.jdbc.driver.OracleStatement.executeMaybeDescribe(OracleStatement.java:904)
	at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1082)
	at oracle.jdbc.driver.OracleStatement.executeQuery(OracleStatement.java:1276)
	at oracle.jdbc.driver.OracleStatementWrapper.executeQuery(OracleStatementWrapper.java:366)
	at oracle.jdbc.proxy.oracle$1jdbc$1replay$1driver$1TxnReplayableStatement$2oracle$1jdbc$1internal$1OracleStatement$$$Proxy.executeQuery(Unknown Source)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
	at java.lang.reflect.Method.invoke(Unknown Source)
	at oracle.jdbc.replay.driver.TxnReplayableBase.replayOneCall(TxnReplayableBase.java:520)
	at oracle.jdbc.replay.driver.TxnFailoverManagerImpl.replayAllBeforeLastCall(TxnFailoverManagerImpl.java:1773)
	at oracle.jdbc.replay.driver.TxnFailoverManagerImpl.handleOutageInternal(TxnFailoverManagerImpl.java:1425)
	at oracle.jdbc.replay.driver.TxnFailoverManagerImpl.handleOutage(TxnFailoverManagerImpl.java:989)
	at oracle.jdbc.replay.driver.TxnReplayableBase.onErrorForAll(TxnReplayableBase.java:339)
	at oracle.jdbc.replay.driver.TxnReplayableConnection.onErrorForAll(TxnReplayableConnection.java:395)
	at oracle.jdbc.replay.driver.TxnReplayableBase.onErrorVoidForAll(TxnReplayableBase.java:262)
	at oracle.jdbc.replay.driver.TxnReplayableConnection.onErrorVoidForAll(TxnReplayableConnection.java:388)
	at oracle.jdbc.proxy.oracle$1jdbc$1replay$1driver$1TxnReplayableConnection$2oracle$1jdbc$1internal$1OracleConnection$$$Proxy.commit(Unknown Source)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
	at java.lang.reflect.Method.invoke(Unknown Source)
	at oracle.ucp.jdbc.proxy.JDBCConnectionProxyFactory.invoke(JDBCConnectionProxyFactory.java:329)
	at oracle.ucp.jdbc.proxy.ConnectionProxyFactory.invoke(ConnectionProxyFactory.java:50)
	at com.sun.proxy.$Proxy17.commit(Unknown Source)
	at ac01.ac01.main(ac01.java:127)
Caused by: Error : 41412, Position : 49, Sql = select sys_context('USERENV','SERVER_HOST') from dual, OriginalSql = 
select sys_context('USERENV','SERVER_HOST') from dual, Error Msg = ORA-41412: results changed during replay; failover cannot continue
 
	at oracle.jdbc.driver.T4CTTIoer11.processError(T4CTTIoer11.java:498)
	... 34 more

Of course the query result returning the server name on which I am connected has changed ! I have killed the initial one ! Even the Oracle example you can found on MOS are displaying the working instance so really strange to me to hit this issue. To solve it I have added the endRequest() call just before the block I am expecting to be replayable:

((oracle.jdbc.replay.ReplayableConnection) connection1).endRequest();

Diagnostics and Tracing

I have not been able to activate tracing of replay events either on console or in a log file. The documentation says you can use:

oracle.jdbc.internal.replay.level = FINER|FINEST

And use for example, to log on console:

oracle.jdbc.internal.replay.level = FINER
handlers = java.util.logging.ConsoleHandler
java.util.logging.ConsoleHandler.level = ALL
java.util.logging.ConsoleHandler.formatter = java.util.logging.XMLFormatter

But it does not display anything for me…

References

  • Application Continuity for Java
  • “java.sql.SQLRecoverableException: No more data to read from socket” Using Application Continuity with 12c JDBC Driver (Doc ID 2140406.1)
  • How To Test Application Continuity Using A Standalone Java Program (Doc ID 1602233.1)
  • Application Continuity Throws Exception No more data to read from socket For Commits After Failover (Doc ID 2197029.1)
  • Java Client Failover With Application Continuity Fails With java.sql.SQLRecoverableException: No more data to read from socket (Doc ID 2294143.1)
  • Configuring Oracle Universal Connection Pool (UCP) for Planned Outages (Doc ID 1593786.1)
  • oracle.jdbc.replay Interface ReplayStatistics
  • Package oracle.jdbc.replay
  • Application Continuity

About Post Author

Yannick Jaquier

administrator

Find more about me on social media.

See author's posts

Leave a Reply

Your email address will not be published. Required fields are marked *

You may use these HTML tags and attributes:

<a href="" title=""> <abbr title=""> <acronym title=""> <b> <blockquote cite=""> <cite> <code> <del datetime=""> <em> <i> <q cite=""> <s> <strike> <strong>