You are viewing a plain text version of this content. The canonical link for it is here.
Posted to derby-commits@db.apache.org by mi...@apache.org on 2005/05/14 00:51:08 UTC

svn commit: r170106 - in /incubator/derby/code/trunk/java/testing/org/apache/derbyTesting/functionTests: master/TestDurabilityProperty.out suites/storemats.runall suites/storemore.runall tests/store/TestDurabilityProperty.java

Author: mikem
Date: Fri May 13 15:51:08 2005
New Revision: 170106

URL: http://svn.apache.org/viewcvs?rev=170106&view=rev
Log:
committed the following change for ksunithaghm@gmail.com

enhancements to the  TestDurabilityProperty test as a first step  to try to take care of  slow machines where inserts may take longer time than estimated bound in this test.

So if inserts in autocommit mode take more time than the estimated bound, then the test now
--checks if time taken in autocommit on and off are within a close range ( this is because syncs are not happening with derby.system.durability=test mode)
-- if not, then it checks if the time taken to do the insert with derby.system.durability=test mode and without this mode set is within close range, if so it reports a failure with a detailed message explaining the above cases and that the test times the inserts and checks if it within the approximate bounds.

Also note, it will work as expected even if all tests (derbyall)  are running with derby.system.durability=test since this(derby.system.durability) property is explicitly set as needed within the test before booting the database.

The bounds work ok with write cache enabled /disabled on my laptop..  I also tried it out on a slow machine that I have access to and it seems fine. Next, I'll look into adding some kind of acceptable bounds as a percentage of the time taken with this mode set for slower machines.   But if someone notices any issues with the timing on different configurations please post to the list. 


Modified:
    incubator/derby/code/trunk/java/testing/org/apache/derbyTesting/functionTests/master/TestDurabilityProperty.out
    incubator/derby/code/trunk/java/testing/org/apache/derbyTesting/functionTests/suites/storemats.runall
    incubator/derby/code/trunk/java/testing/org/apache/derbyTesting/functionTests/suites/storemore.runall
    incubator/derby/code/trunk/java/testing/org/apache/derbyTesting/functionTests/tests/store/TestDurabilityProperty.java

Modified: incubator/derby/code/trunk/java/testing/org/apache/derbyTesting/functionTests/master/TestDurabilityProperty.out
URL: http://svn.apache.org/viewcvs/incubator/derby/code/trunk/java/testing/org/apache/derbyTesting/functionTests/master/TestDurabilityProperty.out?rev=170106&r1=170105&r2=170106&view=diff
==============================================================================
--- incubator/derby/code/trunk/java/testing/org/apache/derbyTesting/functionTests/master/TestDurabilityProperty.out (original)
+++ incubator/derby/code/trunk/java/testing/org/apache/derbyTesting/functionTests/master/TestDurabilityProperty.out Fri May 13 15:51:08 2005
@@ -1,8 +1,6 @@
-1. create database with derby.system.durability=test mode
-num successful inserts = 500
+1. With derby.system.durability=test,Test to see if syncs are not happening 
 Is warning message about derby.system.durability=test present in derby.log =true
 log.ctrl file has durability testMode no sync marker value = true
 2. shutdown database and reboot database without derby.system.durability=test and test for marker in log.ctrl file
-expected exception for shutdown.Derby system shutdown.
 log.ctrl file has durability testMode no sync marker value = true
 Is warning message about derby.system.durability=test present in derby.log =true

Modified: incubator/derby/code/trunk/java/testing/org/apache/derbyTesting/functionTests/suites/storemats.runall
URL: http://svn.apache.org/viewcvs/incubator/derby/code/trunk/java/testing/org/apache/derbyTesting/functionTests/suites/storemats.runall?rev=170106&r1=170105&r2=170106&view=diff
==============================================================================
--- incubator/derby/code/trunk/java/testing/org/apache/derbyTesting/functionTests/suites/storemats.runall (original)
+++ incubator/derby/code/trunk/java/testing/org/apache/derbyTesting/functionTests/suites/storemats.runall Fri May 13 15:51:08 2005
@@ -4,4 +4,3 @@
 store/longColumn.sql
 store/madhare.sql
 store/streamingColumn.java
-store/TestDurabilityProperty.java

Modified: incubator/derby/code/trunk/java/testing/org/apache/derbyTesting/functionTests/suites/storemore.runall
URL: http://svn.apache.org/viewcvs/incubator/derby/code/trunk/java/testing/org/apache/derbyTesting/functionTests/suites/storemore.runall?rev=170106&r1=170105&r2=170106&view=diff
==============================================================================
--- incubator/derby/code/trunk/java/testing/org/apache/derbyTesting/functionTests/suites/storemore.runall (original)
+++ incubator/derby/code/trunk/java/testing/org/apache/derbyTesting/functionTests/suites/storemore.runall Fri May 13 15:51:08 2005
@@ -27,3 +27,4 @@
 store/Beetle6038.java
 store/holdCursorJDBC30.sql
 store/holdCursorExternalSortJDBC30.sql
+store/TestDurabilityProperty.java

Modified: incubator/derby/code/trunk/java/testing/org/apache/derbyTesting/functionTests/tests/store/TestDurabilityProperty.java
URL: http://svn.apache.org/viewcvs/incubator/derby/code/trunk/java/testing/org/apache/derbyTesting/functionTests/tests/store/TestDurabilityProperty.java?rev=170106&r1=170105&r2=170106&view=diff
==============================================================================
--- incubator/derby/code/trunk/java/testing/org/apache/derbyTesting/functionTests/tests/store/TestDurabilityProperty.java (original)
+++ incubator/derby/code/trunk/java/testing/org/apache/derbyTesting/functionTests/tests/store/TestDurabilityProperty.java Fri May 13 15:51:08 2005
@@ -24,6 +24,7 @@
 import java.sql.Statement;
 import java.sql.PreparedStatement;
 import java.sql.DriverManager;
+import java.sql.SQLException;
 import java.io.*;
 
 /**
@@ -63,34 +64,11 @@
  */
 public class TestDurabilityProperty {
     public static void main(String[] args) {
-        Connection conn = null;
-        Statement s = null;
-        PreparedStatement ps = null;
         try {
-            report("1. create database with derby.system.durability=test mode");
-            // use the ij utility to read the property file and
-            // make the initial connection.
-            org.apache.derby.tools.ij.getPropertyArg(args);
-            System.setProperty("derby.system.durability","test");
-            conn = org.apache.derby.tools.ij.startJBMS();
-
-            s = conn.createStatement();
-            s.execute("create table t1 (c1 int, c2 int)");
-            s.close();
-
-            // Test 1
-            // this is a quick check incase someone breaks the
-            // derby.system.durability=test
-            long timeTaken = doInsertsInAutoCommit(conn);
-            conn.close();
-
-            int approxUpperBound = 3000; // approximate upper bound in
-                                         // millisecond
-            if (timeTaken > approxUpperBound) {
-                report("FAIL -- derby.system.durability=test mode seems to be broken.");
-                report(" Time to insert rows in test exceeded the usual limit.");
-            }
-
+            // Test 1: check if derby.system.durability=test
+            // mode is not doing syncs 
+            testNoSyncs(args);
+            
             String derbyHome = System.getProperty("derby.system.home");
             // Test 2
             // Check if derby.log has the warning message
@@ -118,17 +96,57 @@
     }
 
     /**
+     * time inserts 
+     * 
+     * @param mode
+     *            value for derby.system.durability property
+     * @param create
+     *            should table be created or not
+     * @param autoCommit
+     *            whether inserts should happen in autocommit mode or not
+     * @return time taken to do inserts
+     * @throws Exception
+     */
+    public static long timeTakenToInsert(String mode, boolean create,
+            boolean autoCommit) throws Exception {
+        System.setProperty("derby.system.durability", mode);
+        Connection conn = org.apache.derby.tools.ij.startJBMS();
+
+        if (create) {
+            Statement s = conn.createStatement();
+            s.execute("create table t1 (c1 int, c2 int)");
+            s.close();
+        }
+
+        long timeTaken = doInserts(conn, autoCommit);
+
+        try {
+            conn.close();
+            DriverManager.getConnection("jdbc:derby:;shutdown=true");
+        } catch (SQLException sqle) {
+            if ("XJ015".equals(sqle.getSQLState())) {
+            }// ok database shutdown
+            else {
+                report(sqle.getSQLState());
+                report("ERROR! during shutdown");
+                sqle.printStackTrace();
+            }
+        }
+
+        return timeTaken;
+    }
+
+
+    /**
      * Note doing inserts in autocommit mode is probably the worst case scenario
      * in terms of performance as each commit will involve a flush/sync to disk
      * but in case of the derby.system.durability=test mode, the syncs dont 
      * happen.
-     * This test case times the inserts and assumes that the inserts on any
-     * system will be less than three second for 500 inserts. Note this upper
-     * bound on time is just an approximate estimation
      */
-    public static long doInsertsInAutoCommit(Connection conn) throws Exception {
+    public static long doInserts(Connection conn,boolean autoCommit) throws Exception {
         PreparedStatement ps = conn
                 .prepareStatement("insert into t1 values(?,?)");
+        conn.setAutoCommit(autoCommit);
         long count = 0;
 
         long start = System.currentTimeMillis();
@@ -139,9 +157,12 @@
             count += ps.executeUpdate();
         }
 
+        if (!autoCommit)
+            conn.commit();
         long end = System.currentTimeMillis();
-        report("num successful inserts = " + count);
-
+        if (count < 500)
+            report(" FAIL!! all rows didnt get inserted ?");
+        
         return (end - start);
     }
 
@@ -210,14 +231,6 @@
     {
         // shutdown database
         Connection conn = null;
-        try
-        {
-            conn = DriverManager.getConnection("jdbc:derby:;shutdown=true");
-        }
-        catch(Exception e)
-        {
-            report("expected exception for shutdown." + e.getMessage());
-        }
         // unset property
         System.setProperty("derby.system.durability","");
         conn = org.apache.derby.tools.ij.startJBMS();
@@ -235,4 +248,96 @@
         System.out.println(msg);
     }
 
+    /**
+     * Test if derby.system.durability=test property is broken or not. We time
+     * inserts for 500 repeated inserts and make some approximate estimations on
+     * how fast it should be. Since it is a timing based test, there might be
+     * cases of a really really slow machine in some weird cases where this test
+     * may have diffs in this part of the test.
+     * 
+     * So basically to determine if something is wrong, the following is done
+     * to try best to eliminate issues with slow machines
+     * 1)if inserts with autocommit on is fast enough (an estimated
+     * bound)
+     * 2)if not, then since no syncs happen , check if time taken to do
+     * inserts for autocommit on and off are in proximity range 
+     * 3)if 1 and 2 is not satisfied, then check time taken without this mode set
+     * and with this mode set.
+     * If they are in proximity range something could be wrong. It
+     * might be good to check the machine configuration and environment when
+     * test was running <BR>
+     * Also note, although it would seem like a solution would be to bump the
+     * estimated bound to a high limit, this might not help since on a really
+     * good disk the inserts doing syncs might well be done within the bound and
+     * thus would not be possible to know if this mode was possibly broken.
+     *  
+     */
+    public static void testNoSyncs(String[] args) throws Exception {
+        boolean debug = false;  // if set, prints out useful info when debugging test
+        
+        report("1. With derby.system.durability=test,"
+                + "Test to see if syncs are not happening ");
+        // use the ij utility to read the property file and
+        // make the initial connection.
+        org.apache.derby.tools.ij.getPropertyArg(args);
+
+        boolean create = true;
+
+        // Note we time inserts in normal all syncs case first even
+        // though we may not require it if the inserts finish fast enough
+        // But timing them here because once database is booted with
+        // derby.system.durability=test there are no guarantees on consistency
+        // of database so dont want to mess up numbers for the all syncs case
+
+        // derby.system.durability is not test so it will default to
+        // normal mode and autocommit=true
+        long timeCommitOn = timeTakenToInsert("", create, true);
+        String derbyHome = System.getProperty("derby.system.home");
+        if (isMessageInDerbyLog(derbyHome))
+            report("ERROR! System should not have been booted with"
+                    + "derby.system.durability=test mode here");
+        create = false;
+        // derby.system.durability=test and autocommit=true
+        long timeWithTestModeCommitOn = timeTakenToInsert("test", create, true);
+        // derby.system.durability=test and autocommit=false
+        long timeWithTestModeCommitOff = timeTakenToInsert("test", create, false);
+      
+        if (debug) {
+            report("timeCommitOn = " + timeCommitOn);
+            report("timeWithTestModeCommitOn = " + timeWithTestModeCommitOn);
+            report("timeWithTestModeCommitOff = " + timeWithTestModeCommitOff);
+        }
+
+        // an approximation on the upper bound for time taken to do
+        // inserts in autocommit mode with derby.system.durability=test mode
+        long upperBound = 3000;
+
+        // if it takes a lot of time to do the inserts then do extra checks
+        // to determine if derby.system.durability=test mode is broken or not
+        // because we cant be sure if inserts just took a long time
+        // because of a really slow machine
+        if (timeWithTestModeCommitOn > upperBound) {
+
+            long proximityRange = 1000;
+
+            // in derby.system.durability=test autocommit on or off should
+            // be in same range since syncs are not happening
+            if (Math.abs(timeWithTestModeCommitOn - timeWithTestModeCommitOff) > proximityRange) {
+                // another approximation here (1.5 times of with testmode set)
+                if (timeWithTestModeCommitOn > timeCommitOn
+                        || (timeCommitOn < (1.5 * timeWithTestModeCommitOn))) {
+                    report("FAIL -- derby.system.durability=test mode seems to be broken.");
+                    report("-- In this mode one would expect that inserts with autocommit off and on "
+                            + "would be in the same range as syncs are not happening but the difference "
+                            + "here seems to be more than the approximate estimated range.");
+                    report("-- Also comparing the time taken to do the inserts without this" +
+                            " property set seems to be in the same"
+                            + " range as with this property set.");
+                    report("-- Please note this test times inserts and approximate estimates were " +
+                            "considered to report this observation.");
+                }
+            }
+        }
+
+    }
 }