Added some debug messages during integration test to help identify wh…

…en things happen in the test log file.

symmetric/src/test/java/org/jumpmind/symmetric/test/AbstractIntegrationTest.java

@@ -49,13 +49,21 @@ public AbstractIntegrationTest(String client, String root) {
     public AbstractIntegrationTest() throws Exception {
         if (!standalone) {
             String[] databases = TestSetupUtil.lookupDatabasePairs(DatabaseTestSuite.DEFAULT_TEST_PREFIX).iterator()
-            .next();
+                    .next();
             logger.info("Running test in standalone mode with databases " + databases[0] + " and " + databases[1]);
+            this.root = databases[1];
+            this.client = databases[0];
             standalone = true;
-            TestSetupUtil.setup(DatabaseTestSuite.DEFAULT_TEST_PREFIX, TestConstants.TEST_ROOT_DOMAIN_SETUP_SCRIPT, databases[0], databases[1]);
+            TestSetupUtil.setup(DatabaseTestSuite.DEFAULT_TEST_PREFIX, TestConstants.TEST_ROOT_DOMAIN_SETUP_SCRIPT,
+                    databases[0], databases[1]);
         }
     }
 
+    protected void logTestRunning() {
+        logger.info("Running " + new Exception().getStackTrace()[1].getMethodName() + ". "
+                + printRootAndClientDatabases());
+    }
+
     protected SymmetricEngine getRootEngine() {
         return TestSetupUtil.getRootEngine();
     }
@@ -75,12 +83,12 @@ protected IDbDialect getClientDbDialect() {
     protected String printRootAndClientDatabases() {
         return " The root database is " + root + " and the client database is " + client + ".";
     }
-    
+
     @SuppressWarnings("unchecked")
     protected <T> T findOnClient(String name) {
         return (T) AppUtils.find(name, getClientEngine());
     }
-    
+
     @SuppressWarnings("unchecked")
     protected <T> T findOnRoot(String name) {
         return (T) AppUtils.find(name, getRootEngine());

symmetric/src/test/java/org/jumpmind/symmetric/test/ParameterizedSuite.java

@@ -75,7 +75,7 @@ static class TestClassRunnerForParameters extends JUnit4ClassRunner {
             super(testClass.getJavaClass());
             fParameters = parameters;
             fConstructor = getOnlyConstructor();
-            filterParameters();
+            filterParameters();          
         }
 
         protected void filterParameters() {

symmetric/src/test/java/org/jumpmind/symmetric/test/SimpleIntegrationTest.java

@@ -113,16 +113,17 @@ public SimpleIntegrationTest() throws Exception {
     public SimpleIntegrationTest(String client, String root) throws Exception {
         super(client, root);
     }
-    
+
     protected void checkForFailedTriggers() {
         ITriggerRouterService service = AppUtils.find(Constants.TRIGGER_ROUTER_SERVICE, getClientEngine());
         Assert.assertEquals(0, service.getFailedTriggers().size());
         service = AppUtils.find(Constants.TRIGGER_ROUTER_SERVICE, getRootEngine());
         Assert.assertEquals(0, service.getFailedTriggers().size());
     }
-    
+
     @Test(timeout = 30000)
     public void registerClientWithRoot() {
+        logTestRunning();
         INodeService rootNodeService = AppUtils.find(Constants.NODE_SERVICE, getRootEngine());
         getRootEngine().openRegistration(TestConstants.TEST_CLIENT_NODE_GROUP, TestConstants.TEST_CLIENT_EXTERNAL_ID);
         Assert.assertTrue("The registration for the client should be opened now.", rootNodeService.findNodeSecurity(
@@ -135,12 +136,13 @@ public void registerClientWithRoot() {
         IStatisticManager statMgr = (IStatisticManager) getClientEngine().getApplicationContext().getBean(
                 Constants.STATISTIC_MANAGER);
         statMgr.flush();
-        
+
         checkForFailedTriggers();
     }
 
     @Test(timeout = 30000)
     public void initialLoad() {
+        logTestRunning();
         IDbDialect rootDialect = getRootDbDialect();
         rootJdbcTemplate.update(insertCustomerSql, new Object[] { 301, "Linus", "1", "42 Blanket Street",
                 "Santa Claus", "IN", 90009, new Date(), new Date(), "This is a test", BINARY_DATA });
@@ -197,6 +199,7 @@ private void insertIntoTestTriggerTable(IDbDialect dialect, Object[] values) {
 
     @Test(timeout = 30000)
     public void syncToClient() {
+        logTestRunning();
         // test pulling no data
         getClientEngine().pull();
 
@@ -236,6 +239,7 @@ public Object mapRow(ResultSet rs, int rowNum) throws SQLException {
 
     @Test(timeout = 30000)
     public void syncToRootAutoGeneratedPrimaryKey() {
+        logTestRunning();
         final String NEW_VALUE = "unique new value one value";
         IDbDialect clientDialect = getClientDbDialect();
         insertIntoTestTriggerTable(clientDialect, new Object[] { 3, "value one", "value \" two" });
@@ -249,6 +253,7 @@ public void syncToRootAutoGeneratedPrimaryKey() {
 
     @Test(timeout = 30000)
     public void reopenRegistration() {
+        logTestRunning();
         getRootEngine().reOpenRegistration(TestConstants.TEST_CLIENT_EXTERNAL_ID);
         getClientEngine().pull();
         Assert.assertEquals(1, getRootDbDialect().getJdbcTemplate().queryForInt(isRegistrationClosedSql,
@@ -272,8 +277,9 @@ private boolean turnOnNoKeysInUpdateParameter(boolean newValue) {
         return oldValue;
     }
 
-    @Test (timeout = 30000)
+    @Test(timeout = 30000)
     public void syncToRoot() throws ParseException {
+        logTestRunning();
         turnOnNoKeysInUpdateParameter(true);
         Date date = DateUtils.parseDate("2007-01-03", new String[] { "yyyy-MM-dd" });
         clientJdbcTemplate.update(insertOrderHeaderSql, new Object[] { "10", 100, null, date }, new int[] {
@@ -284,6 +290,7 @@ public void syncToRoot() throws ParseException {
 
     @Test(timeout = 30000)
     public void syncInsertCondition() throws ParseException {
+        logTestRunning();
         // Should not sync when status = null
         Date date = DateUtils.parseDate("2007-01-02", new String[] { "yyyy-MM-dd" });
         rootJdbcTemplate.update(insertOrderHeaderSql, new Object[] { "11", 100, null, date }, new int[] {
@@ -308,6 +315,7 @@ public void syncInsertCondition() throws ParseException {
 
     @Test(timeout = 30000)
     public void oneColumnTableWithPrimaryKeyUpdate() throws Exception {
+        logTestRunning();
         boolean oldValue = turnOnNoKeysInUpdateParameter(true);
         rootJdbcTemplate.update("insert into ONE_COLUMN_TABLE values(1)");
         Assert
@@ -325,14 +333,10 @@ public void oneColumnTableWithPrimaryKeyUpdate() throws Exception {
         turnOnNoKeysInUpdateParameter(oldValue);
     }
 
-    //@Test(timeout = 30000)
+    @Test(timeout = 30000)
     @SuppressWarnings("unchecked")
     public void syncUpdateCondition() {
-        rootJdbcTemplate.update(updateOrderHeaderStatusSql, new Object[] { "I", "1" });
-        getClientEngine().pull();
-        assertEquals(clientJdbcTemplate.queryForList(selectOrderHeaderSql, new Object[] { "1" }).size(), 0,
-                "The order record was sync'd when it should not have been.");
-
+        logTestRunning();
         rootJdbcTemplate.update(updateOrderHeaderStatusSql, new Object[] { "C", "1" });
         getClientEngine().pull();
         List list = clientJdbcTemplate.queryForList(selectOrderHeaderSql, new Object[] { "1" });
@@ -344,6 +348,7 @@ public void syncUpdateCondition() {
 
     @Test(timeout = 30000)
     public void ignoreNodeChannel() {
+        logTestRunning();
         INodeService nodeService = (INodeService) getRootEngine().getApplicationContext().getBean("nodeService");
         IConfigurationService configService = (IConfigurationService) getRootEngine().getApplicationContext().getBean(
                 "configurationService");
@@ -360,7 +365,7 @@ public void ignoreNodeChannel() {
         configService.reloadChannels();
     }
 
-  //  @Test(timeout = 30000)
+    // @Test(timeout = 30000)
     public void syncUpdateWithEmptyKey() {
         if (getClientDbDialect().isEmptyStringNulled()) {
             return;
@@ -377,27 +382,32 @@ public void syncUpdateWithEmptyKey() {
 
     @Test(timeout = 30000)
     public void testPurge() throws Exception {
+        logTestRunning();
         IParameterService parameterService = AppUtils.find(Constants.PARAMETER_SERVICE, getClientEngine());
         parameterService.saveParameter(ParameterConstants.PURGE_RETENTION_MINUTES, 0);
         // do an extra push & pull to make sure we have events cleared out
         getClientEngine().pull();
         getClientEngine().push();
         Thread.sleep(2000);
-             
-        int beforePurge = rootJdbcTemplate.queryForInt("select count(*) from sym_data");     
+
+        int beforePurge = rootJdbcTemplate.queryForInt("select count(*) from sym_data");
         getRootEngine().purge();
         int afterPurge = rootJdbcTemplate.queryForInt("select count(*) from sym_data");
-        Assert.assertTrue("Expected data rows to have been purged at the root.  There were " +beforePurge + " row before anf " + afterPurge + " rows after.",  (beforePurge - afterPurge) > 0);
-
-        beforePurge = clientJdbcTemplate.queryForInt("select count(*) from sym_data");  
+        Assert.assertTrue("Expected data rows to have been purged at the root.  There were " + beforePurge
+                + " row before anf " + afterPurge + " rows after.", (beforePurge - afterPurge) > 0);
+
+        beforePurge = clientJdbcTemplate.queryForInt("select count(*) from sym_data");
         getClientEngine().purge();
         afterPurge = clientJdbcTemplate.queryForInt("select count(*) from sym_data");
-        Assert.assertTrue("Expected data rows to have been purged at the client.  There were " +beforePurge + " row before anf " + afterPurge + " rows after.",  (beforePurge - afterPurge) > 0);
+        Assert.assertTrue("Expected data rows to have been purged at the client.  There were " + beforePurge
+                + " row before anf " + afterPurge + " rows after.", (beforePurge - afterPurge) > 0);
     }
 
     @Test
     public void testHeartbeat() throws Exception {
-        final String checkHeartbeatSql = "select heartbeat_time from sym_node where external_id='" + TestConstants.TEST_CLIENT_EXTERNAL_ID + "'";
+        logTestRunning();
+        final String checkHeartbeatSql = "select heartbeat_time from sym_node where external_id='"
+                + TestConstants.TEST_CLIENT_EXTERNAL_ID + "'";
         long ts = System.currentTimeMillis();
         Thread.sleep(1000);
         IParameterService parameterService = AppUtils.find(Constants.PARAMETER_SERVICE, getClientEngine());
@@ -414,6 +424,7 @@ public void testHeartbeat() throws Exception {
 
     @Test(timeout = 30000)
     public void testVirtualTransactionId() {
+        logTestRunning();
         rootJdbcTemplate.update("insert into test_very_long_table_name_1234 values('42')");
         if (getRootDbDialect().isTransactionIdOverrideSupported()) {
             assertEquals(rootJdbcTemplate.queryForObject(
@@ -428,6 +439,7 @@ public void testVirtualTransactionId() {
 
     @Test(timeout = 30000)
     public void testCaseSensitiveTableNames() {
+        logTestRunning();
         rootJdbcTemplate.update("insert into TEST_ALL_CAPS values(1, 'HELLO')");
         getClientEngine().pull();
         assertEquals(clientJdbcTemplate.queryForInt("select count(*) from TEST_ALL_CAPS where ALL_CAPS_ID = 1"), 1,
@@ -444,6 +456,7 @@ public void testCaseSensitiveTableNames() {
     @Test(timeout = 30000)
     @ParameterExcluder("mssql")
     public void testNoPrimaryKeySync() {
+        logTestRunning();
         rootJdbcTemplate.update("insert into NO_PRIMARY_KEY_TABLE values(1, 2, 'HELLO')");
         getClientEngine().pull();
         assertEquals(clientJdbcTemplate.queryForInt("select TWO_COLUMN from NO_PRIMARY_KEY_TABLE where ONE_COLUMN=1"),
@@ -461,6 +474,7 @@ public void testNoPrimaryKeySync() {
     @SuppressWarnings("unchecked")
     @Test(timeout = 30000)
     public void testReservedColumnNames() {
+        logTestRunning();
         if (getRootDbDialect() instanceof Db2DbDialect || getClientDbDialect() instanceof Db2DbDialect
                 || getRootDbDialect() instanceof FirebirdDbDialect || getClientDbDialect() instanceof FirebirdDbDialect) {
             return;
@@ -472,7 +486,7 @@ public void testReservedColumnNames() {
         rootJdbcTemplate.update(alterKeyWordSql2.replaceAll("\"", rquote));
         clientJdbcTemplate.update(alterKeyWordSql.replaceAll("\"", cquote));
         clientJdbcTemplate.update(alterKeyWordSql2.replaceAll("\"", cquote));
-        
+
         getClientDbDialect().resetCachedTableModel();
         getRootDbDialect().resetCachedTableModel();
 
@@ -497,6 +511,7 @@ public void testReservedColumnNames() {
 
     @Test(timeout = 30000)
     public void testSyncColumnLevel() throws ParseException {
+        logTestRunning();
         int id = 1;
         String[] columns = { "id", "string_value", "time_value", "date_value", "bigint_value", "decimal_value" };
         Object[] values = new Object[] { id, "moredata", getDate("2008-01-02 03:04:05"),
@@ -516,6 +531,7 @@ public void testSyncColumnLevel() throws ParseException {
 
     @Test(timeout = 30000)
     public void testSyncColumnLevelTogether() throws ParseException {
+        logTestRunning();
         int id = 1;
         String[] columns = { "id", "string_value", "time_value", "date_value", "bigint_value", "decimal_value" };
         Object[] values = new Object[] { id, "moredata", getDate("2008-01-02 03:04:05"),
@@ -533,6 +549,7 @@ public void testSyncColumnLevelTogether() throws ParseException {
 
     @Test(timeout = 30000)
     public void testSyncColumnLevelFallback() throws ParseException {
+        logTestRunning();
         int id = 1;
         String[] columns = { "id", "string_value", "time_value", "date_value", "bigint_value", "decimal_value" };
         Object[] values = new Object[] { id, "fallback on insert", getDate("2008-01-02 03:04:05"),
@@ -552,6 +569,7 @@ public void testSyncColumnLevelFallback() throws ParseException {
 
     @Test(timeout = 30000)
     public void testSyncColumnLevelNoChange() throws ParseException {
+        logTestRunning();
         int id = 1;
 
         // Change a column to the same value, which on some systems will be
@@ -563,18 +581,20 @@ public void testSyncColumnLevelNoChange() throws ParseException {
         clientJdbcTemplate.update(deleteSyncColumnLevelSql, new Object[] { id });
         getClientEngine().pull();
     }
-    
+
     @Test
     public void testTargetTableNameSync() throws Exception {
+        logTestRunning();
         Assert.assertEquals(0, clientJdbcTemplate.queryForInt("select count(*) from test_target_table_b"));
         rootJdbcTemplate.update("insert into TEST_TARGET_TABLE_A values('1','2')");
         getClientEngine().pull();
         Assert.assertEquals(1, clientJdbcTemplate.queryForInt("select count(*) from test_target_table_b"));
         Assert.assertEquals(0, clientJdbcTemplate.queryForInt("select count(*) from test_target_table_a"));
     }
-    
+
     @Test
     public void testMaxRowsBeforeCommit() throws Exception {
+        logTestRunning();
         IParameterService clientParameterService = (IParameterService) getClientEngine().getApplicationContext()
                 .getBean(Constants.PARAMETER_SERVICE);
         long oldMaxRowsBeforeCommit = clientParameterService
@@ -583,7 +603,8 @@ public void testMaxRowsBeforeCommit() throws Exception {
         int oldCount = clientJdbcTemplate.queryForInt("select count(*) from ONE_COLUMN_TABLE");
         IStatisticManager statisticManager = AppUtils.find(Constants.STATISTIC_MANAGER, getClientEngine());
         statisticManager.flush();
-        Assert.assertEquals(0, statisticManager.getStatistic(StatisticNameConstants.INCOMING_MAX_ROWS_COMMITTED).getCount());
+        Assert.assertEquals(0, statisticManager.getStatistic(StatisticNameConstants.INCOMING_MAX_ROWS_COMMITTED)
+                .getCount());
         rootJdbcTemplate.execute(new ConnectionCallback() {
             public Object doInConnection(Connection con) throws SQLException, DataAccessException {
                 con.setAutoCommit(false);
@@ -596,12 +617,18 @@ public Object doInConnection(Connection con) throws SQLException, DataAccessExce
                 return null;
             }
         });
+        int count = 0;
         do {
-           logger.warn("If you see this message more than once the root database isn't respecting the fact that auto commit is set to false!");
+            if (count > 0) {
+                logger
+                        .warn("If you see this message more than once the root database isn't respecting the fact that auto commit is set to false!");
+            }
+            count++;
         } while (getClientEngine().pull());
         int newCount = clientJdbcTemplate.queryForInt("select count(*) from ONE_COLUMN_TABLE");
-        Assert.assertEquals(50, newCount-oldCount);
-        Assert.assertEquals(8, statisticManager.getStatistic(StatisticNameConstants.INCOMING_MAX_ROWS_COMMITTED).getCount());
+        Assert.assertEquals(50, newCount - oldCount);
+        Assert.assertEquals(8, statisticManager.getStatistic(StatisticNameConstants.INCOMING_MAX_ROWS_COMMITTED)
+                .getCount());
         statisticManager.getStatistic(StatisticNameConstants.INCOMING_MAX_ROWS_COMMITTED);
         clientParameterService.saveParameter(ParameterConstants.DATA_LOADER_MAX_ROWS_BEFORE_COMMIT,
                 oldMaxRowsBeforeCommit);

symmetric/src/test/resources/symmetric-test.properties

@@ -1,5 +1,5 @@
-test.root=h2
-test.client=h2
+test.root=h2,derby
+test.client=derby,h2
 
 mysql.db.driver=com.mysql.jdbc.Driver
 mysql.db.user=root