You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@accumulo.apache.org by el...@apache.org on 2014/06/16 18:52:53 UTC

git commit: ACCUMULO-2913 Add some timeouts to tests missing them, turn up logging on TSBRI to debug an otherwise silent security exception

Repository: accumulo
Updated Branches:
  refs/heads/master 6ce4d9698 -> 981bf5326


ACCUMULO-2913 Add some timeouts to tests missing them, turn up logging on TSBRI to debug an otherwise silent security exception


Project: http://git-wip-us.apache.org/repos/asf/accumulo/repo
Commit: http://git-wip-us.apache.org/repos/asf/accumulo/commit/981bf532
Tree: http://git-wip-us.apache.org/repos/asf/accumulo/tree/981bf532
Diff: http://git-wip-us.apache.org/repos/asf/accumulo/diff/981bf532

Branch: refs/heads/master
Commit: 981bf53268dd0b34d35f1bdc61ed5453b8ae3fe5
Parents: 6ce4d96
Author: Josh Elser <el...@apache.org>
Authored: Mon Jun 16 09:45:54 2014 -0700
Committer: Josh Elser <el...@apache.org>
Committed: Mon Jun 16 09:45:54 2014 -0700

----------------------------------------------------------------------
 .../test/replication/ReplicationTest.java       | 359 +++++++++----------
 test/src/test/resources/log4j.properties        |   1 -
 2 files changed, 176 insertions(+), 184 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/accumulo/blob/981bf532/test/src/test/java/org/apache/accumulo/test/replication/ReplicationTest.java
----------------------------------------------------------------------
diff --git a/test/src/test/java/org/apache/accumulo/test/replication/ReplicationTest.java b/test/src/test/java/org/apache/accumulo/test/replication/ReplicationTest.java
index cac7d94..4727a86 100644
--- a/test/src/test/java/org/apache/accumulo/test/replication/ReplicationTest.java
+++ b/test/src/test/java/org/apache/accumulo/test/replication/ReplicationTest.java
@@ -126,7 +126,7 @@ public class ReplicationTest extends ConfigurableMacIT {
     return logs;
   }
 
-  @Test
+  @Test(timeout = 1000 * 60 * 5)
   public void correctRecordsCompleteFile() throws Exception {
     Connector conn = getConnector();
     String table = "table1";
@@ -163,7 +163,8 @@ public class ReplicationTest extends ConfigurableMacIT {
       Thread.sleep(1000);
     }
 
-    Assert.assertTrue("'root' user could not read the replication table", conn.securityOperations().hasTablePermission("root", ReplicationTable.NAME, TablePermission.READ));
+    Assert.assertTrue("'root' user could not read the replication table",
+        conn.securityOperations().hasTablePermission("root", ReplicationTable.NAME, TablePermission.READ));
 
     Set<String> replRows = Sets.newHashSet();
     Scanner scanner;
@@ -206,7 +207,7 @@ public class ReplicationTest extends ConfigurableMacIT {
     Assert.assertEquals(replRows, wals);
   }
 
-  @Test
+  @Test(timeout = 1000 * 60 * 5)
   public void noRecordsWithoutReplication() throws Exception {
     Connector conn = getConnector();
     List<String> tables = new ArrayList<>();
@@ -256,13 +257,13 @@ public class ReplicationTest extends ConfigurableMacIT {
     Assert.assertFalse(conn.tableOperations().exists(ReplicationTable.NAME));
   }
 
-  @Test
+  @Test(timeout = 1000 * 60 * 5)
   public void twoEntriesForTwoTables() throws Exception {
     Connector conn = getConnector();
     String table1 = "table1", table2 = "table2";
 
     // replication shouldn't exist when we begin
-    Assert.assertFalse(conn.tableOperations().exists(ReplicationTable.NAME));
+    Assert.assertFalse("Replication table already existed at the beginning of the test", conn.tableOperations().exists(ReplicationTable.NAME));
 
     // Create two tables
     conn.tableOperations().create(table1);
@@ -296,7 +297,7 @@ public class ReplicationTest extends ConfigurableMacIT {
     int attempts = 5;
     do {
       if (!exists) {
-        UtilWaitThread.sleep(200);
+        UtilWaitThread.sleep(1000);
         exists = conn.tableOperations().exists(ReplicationTable.NAME);
         attempts--;
       }
@@ -369,8 +370,8 @@ public class ReplicationTest extends ConfigurableMacIT {
     Assert.assertEquals("Expected to find 2 records, but actually found " + records, 2, records.size());
 
     for (Entry<Key,Value> metadata : records) {
-      Assert.assertTrue("Expected record to be in metadata but wasn't " + metadata.getKey().toStringNoTruncate() + ", tableIds remaining " + tableIdsForMetadata,
-          tableIdsForMetadata.remove(metadata.getKey().getColumnQualifier().toString()));
+      Assert.assertTrue("Expected record to be in metadata but wasn't " + metadata.getKey().toStringNoTruncate() + ", tableIds remaining "
+          + tableIdsForMetadata, tableIdsForMetadata.remove(metadata.getKey().getColumnQualifier().toString()));
     }
 
     Assert.assertTrue("Expected that we had removed all metadata entries " + tableIdsForMetadata, tableIdsForMetadata.isEmpty());
@@ -760,7 +761,7 @@ public class ReplicationTest extends ConfigurableMacIT {
     Assert.fail("We had a file that was referenced but didn't get closed");
   }
 
-  @Test
+  @Test(timeout = 1000 * 60 * 5)
   public void singleTableWithSingleTarget() throws Exception {
     // We want to kill the GC so it doesn't come along and close Status records and mess up the comparisons
     // against expected Status messages.
@@ -948,7 +949,7 @@ public class ReplicationTest extends ConfigurableMacIT {
     }
   }
 
-  @Test
+  @Test(timeout = 1000 * 60 * 5)
   public void correctClusterNameInWorkEntry() throws Exception {
     Connector conn = getConnector();
     String table1 = "table1";
@@ -1256,212 +1257,204 @@ public class ReplicationTest extends ConfigurableMacIT {
     // replication shouldn't exist when we begin
     Assert.assertFalse(conn.tableOperations().exists(ReplicationTable.NAME));
 
-    // ReplicationTablesPrinterThread thread = new ReplicationTablesPrinterThread(conn, System.out);
-    // thread.start();
-
-    try {
-      // Create two tables
-      conn.tableOperations().create(table1);
+    // Create two tables
+    conn.tableOperations().create(table1);
 
-      int attempts = 5;
-      while (attempts > 0) {
-        try {
-          // Enable replication on table1
-          conn.tableOperations().setProperty(table1, Property.TABLE_REPLICATION.getKey(), "true");
-          // Replicate table1 to cluster1 in the table with id of '4'
-          conn.tableOperations().setProperty(table1, Property.TABLE_REPLICATION_TARGET.getKey() + "cluster1", "4");
-          // Use the MockReplicaSystem impl and sleep for 5seconds
-          conn.instanceOperations().setProperty(Property.REPLICATION_PEERS.getKey() + "cluster1",
-              ReplicaSystemFactory.getPeerConfigurationValue(MockReplicaSystem.class, "1000"));
-          attempts = 0;
-        } catch (Exception e) {
-          attempts--;
-          if (attempts <= 0) {
-            throw e;
-          }
-          UtilWaitThread.sleep(500);
+    int attempts = 5;
+    while (attempts > 0) {
+      try {
+        // Enable replication on table1
+        conn.tableOperations().setProperty(table1, Property.TABLE_REPLICATION.getKey(), "true");
+        // Replicate table1 to cluster1 in the table with id of '4'
+        conn.tableOperations().setProperty(table1, Property.TABLE_REPLICATION_TARGET.getKey() + "cluster1", "4");
+        // Use the MockReplicaSystem impl and sleep for 5seconds
+        conn.instanceOperations().setProperty(Property.REPLICATION_PEERS.getKey() + "cluster1",
+            ReplicaSystemFactory.getPeerConfigurationValue(MockReplicaSystem.class, "1000"));
+        attempts = 0;
+      } catch (Exception e) {
+        attempts--;
+        if (attempts <= 0) {
+          throw e;
         }
+        UtilWaitThread.sleep(500);
       }
+    }
 
-      String tableId = conn.tableOperations().tableIdMap().get(table1);
-      Assert.assertNotNull("Could not determine table id for " + table1, tableId);
+    String tableId = conn.tableOperations().tableIdMap().get(table1);
+    Assert.assertNotNull("Could not determine table id for " + table1, tableId);
 
-      // Write some data to table1
-      BatchWriter bw = conn.createBatchWriter(table1, new BatchWriterConfig());
-      for (int rows = 0; rows < 2000; rows++) {
-        Mutation m = new Mutation(Integer.toString(rows));
-        for (int cols = 0; cols < 50; cols++) {
-          String value = Integer.toString(cols);
-          m.put(value, "", value);
-        }
-        bw.addMutation(m);
+    // Write some data to table1
+    BatchWriter bw = conn.createBatchWriter(table1, new BatchWriterConfig());
+    for (int rows = 0; rows < 2000; rows++) {
+      Mutation m = new Mutation(Integer.toString(rows));
+      for (int cols = 0; cols < 50; cols++) {
+        String value = Integer.toString(cols);
+        m.put(value, "", value);
       }
+      bw.addMutation(m);
+    }
 
-      bw.close();
-
-      // Make sure the replication table exists at this point
-      boolean exists = conn.tableOperations().exists(ReplicationTable.NAME);
-      attempts = 10;
-      do {
-        if (!exists) {
-          UtilWaitThread.sleep(1000);
-          exists = conn.tableOperations().exists(ReplicationTable.NAME);
-          attempts--;
-        }
-      } while (!exists && attempts > 0);
-      Assert.assertTrue("Replication table did not exist", exists);
+    bw.close();
 
-      // Grant ourselves the write permission for later
-      conn.securityOperations().grantTablePermission("root", ReplicationTable.NAME, TablePermission.WRITE);
+    // Make sure the replication table exists at this point
+    boolean exists = conn.tableOperations().exists(ReplicationTable.NAME);
+    attempts = 10;
+    do {
+      if (!exists) {
+        UtilWaitThread.sleep(1000);
+        exists = conn.tableOperations().exists(ReplicationTable.NAME);
+        attempts--;
+      }
+    } while (!exists && attempts > 0);
+    Assert.assertTrue("Replication table did not exist", exists);
 
-      // Find the WorkSection record that will be created for that data we ingested
-      boolean notFound = true;
-      Scanner s;
-      for (int i = 0; i < 10 && notFound; i++) {
-        try {
-          s = ReplicationTable.getScanner(conn);
-          WorkSection.limit(s);
-          Entry<Key,Value> e = Iterables.getOnlyElement(s);
-          Text expectedColqual = new ReplicationTarget("cluster1", "4", tableId).toText();
-          Assert.assertEquals(expectedColqual, e.getKey().getColumnQualifier());
-          notFound = false;
-        } catch (NoSuchElementException e) {
-
-        } catch (IllegalArgumentException e) {
-          // Somehow we got more than one element. Log what they were
-          s = ReplicationTable.getScanner(conn);
-          for (Entry<Key,Value> content : s) {
-            log.info(content.getKey().toStringNoTruncate() + " => " + content.getValue());
-          }
-          Assert.fail("Found more than one work section entry");
-        } catch (RuntimeException e) {
-          // Catch a propagation issue, fail if it's not what we expect
-          Throwable cause = e.getCause();
-          if (cause instanceof AccumuloSecurityException) {
-            AccumuloSecurityException sec = (AccumuloSecurityException) cause;
-            switch (sec.getSecurityErrorCode()) {
-              case PERMISSION_DENIED:
-                // retry -- the grant didn't happen yet
-                log.warn("Sleeping because permission was denied");
-                break;
-              default:
-                throw e;
-            }
-          } else {
-            throw e;
-          }
-        }
+    // Grant ourselves the write permission for later
+    conn.securityOperations().grantTablePermission("root", ReplicationTable.NAME, TablePermission.WRITE);
 
-        Thread.sleep(2000);
-      }
+    // Find the WorkSection record that will be created for that data we ingested
+    boolean notFound = true;
+    Scanner s;
+    for (int i = 0; i < 10 && notFound; i++) {
+      try {
+        s = ReplicationTable.getScanner(conn);
+        WorkSection.limit(s);
+        Entry<Key,Value> e = Iterables.getOnlyElement(s);
+        Text expectedColqual = new ReplicationTarget("cluster1", "4", tableId).toText();
+        Assert.assertEquals(expectedColqual, e.getKey().getColumnQualifier());
+        notFound = false;
+      } catch (NoSuchElementException e) {
 
-      if (notFound) {
+      } catch (IllegalArgumentException e) {
+        // Somehow we got more than one element. Log what they were
         s = ReplicationTable.getScanner(conn);
         for (Entry<Key,Value> content : s) {
           log.info(content.getKey().toStringNoTruncate() + " => " + content.getValue());
         }
-        Assert.assertFalse("Did not find the work entry for the status entry", notFound);
+        Assert.fail("Found more than one work section entry");
+      } catch (RuntimeException e) {
+        // Catch a propagation issue, fail if it's not what we expect
+        Throwable cause = e.getCause();
+        if (cause instanceof AccumuloSecurityException) {
+          AccumuloSecurityException sec = (AccumuloSecurityException) cause;
+          switch (sec.getSecurityErrorCode()) {
+            case PERMISSION_DENIED:
+              // retry -- the grant didn't happen yet
+              log.warn("Sleeping because permission was denied");
+              break;
+            default:
+              throw e;
+          }
+        } else {
+          throw e;
+        }
       }
 
-      /**
-       * By this point, we should have data ingested into a table, with at least one WAL as a candidate for replication. Compacting the table should close all
-       * open WALs, which should ensure all records we're going to replicate have entries in the replication table, and nothing will exist in the metadata table
-       * anymore
-       */
-
-      log.info("Killing tserver");
-      // Kill the tserver(s) and restart them
-      // to ensure that the WALs we previously observed all move to closed.
-      for (ProcessReference proc : cluster.getProcesses().get(ServerType.TABLET_SERVER)) {
-        cluster.killProcess(ServerType.TABLET_SERVER, proc);
+      Thread.sleep(2000);
+    }
+
+    if (notFound) {
+      s = ReplicationTable.getScanner(conn);
+      for (Entry<Key,Value> content : s) {
+        log.info(content.getKey().toStringNoTruncate() + " => " + content.getValue());
       }
+      Assert.assertFalse("Did not find the work entry for the status entry", notFound);
+    }
+
+    /**
+     * By this point, we should have data ingested into a table, with at least one WAL as a candidate for replication. Compacting the table should close all
+     * open WALs, which should ensure all records we're going to replicate have entries in the replication table, and nothing will exist in the metadata table
+     * anymore
+     */
 
-      log.info("Starting tserver");
-      cluster.exec(TabletServer.class);
+    log.info("Killing tserver");
+    // Kill the tserver(s) and restart them
+    // to ensure that the WALs we previously observed all move to closed.
+    for (ProcessReference proc : cluster.getProcesses().get(ServerType.TABLET_SERVER)) {
+      cluster.killProcess(ServerType.TABLET_SERVER, proc);
+    }
 
-      log.info("Waiting to read tables");
+    log.info("Starting tserver");
+    cluster.exec(TabletServer.class);
 
-      // Make sure we can read all the tables (recovery complete)
-      for (String table : new String[] {MetadataTable.NAME, table1}) {
-        s = conn.createScanner(table, new Authorizations());
-        for (@SuppressWarnings("unused")
-        Entry<Key,Value> entry : s) {}
-      }
+    log.info("Waiting to read tables");
 
-      log.info("Checking for replication entries in replication");
-      // Then we need to get those records over to the replication table
-      boolean foundResults = false;
-      for (int i = 0; i < 5; i++) {
-        s = ReplicationTable.getScanner(conn);
-        int count = 0;
-        for (Entry<Key,Value> entry : s) {
-          count++;
-          log.info("{}={}", entry.getKey().toStringNoTruncate(), entry.getValue());
-        }
-        if (count > 0) {
-          foundResults = true;
-          break;
-        }
-        Thread.sleep(1000);
+    // Make sure we can read all the tables (recovery complete)
+    for (String table : new String[] {MetadataTable.NAME, table1}) {
+      s = conn.createScanner(table, new Authorizations());
+      for (@SuppressWarnings("unused")
+      Entry<Key,Value> entry : s) {}
+    }
+
+    log.info("Checking for replication entries in replication");
+    // Then we need to get those records over to the replication table
+    boolean foundResults = false;
+    for (int i = 0; i < 5; i++) {
+      s = ReplicationTable.getScanner(conn);
+      int count = 0;
+      for (Entry<Key,Value> entry : s) {
+        count++;
+        log.info("{}={}", entry.getKey().toStringNoTruncate(), entry.getValue());
+      }
+      if (count > 0) {
+        foundResults = true;
+        break;
       }
+      Thread.sleep(1000);
+    }
 
-      Assert.assertTrue("Did not find any replication entries in the replication table", foundResults);
+    Assert.assertTrue("Did not find any replication entries in the replication table", foundResults);
 
-      getCluster().exec(SimpleGarbageCollector.class);
+    getCluster().exec(SimpleGarbageCollector.class);
 
-      // Wait for a bit since the GC has to run (should be running after a one second delay)
-      Thread.sleep(5000);
+    // Wait for a bit since the GC has to run (should be running after a one second delay)
+    Thread.sleep(5000);
 
-      // We expect no records in the metadata table after compaction. We have to poll
-      // because we have to wait for the StatusMaker's next iteration which will clean
-      // up the dangling *closed* records after we create the record in the replication table.
-      // We need the GC to close the file (CloseWriteAheadLogReferences) before we can remove the record
-      log.info("Checking metadata table for replication entries");
-      foundResults = true;
-      for (int i = 0; i < 5; i++) {
-        s = conn.createScanner(MetadataTable.NAME, Authorizations.EMPTY);
-        s.setRange(ReplicationSection.getRange());
-        long size = 0;
-        for (Entry<Key,Value> e : s) {
-          size++;
-          log.info("{}={}", e.getKey().toStringNoTruncate(), ProtobufUtil.toString(Status.parseFrom(e.getValue().get())));
-        }
-        if (size == 0) {
-          foundResults = false;
-          break;
-        }
-        Thread.sleep(1000);
-        log.info("");
+    // We expect no records in the metadata table after compaction. We have to poll
+    // because we have to wait for the StatusMaker's next iteration which will clean
+    // up the dangling *closed* records after we create the record in the replication table.
+    // We need the GC to close the file (CloseWriteAheadLogReferences) before we can remove the record
+    log.info("Checking metadata table for replication entries");
+    foundResults = true;
+    for (int i = 0; i < 5; i++) {
+      s = conn.createScanner(MetadataTable.NAME, Authorizations.EMPTY);
+      s.setRange(ReplicationSection.getRange());
+      long size = 0;
+      for (Entry<Key,Value> e : s) {
+        size++;
+        log.info("{}={}", e.getKey().toStringNoTruncate(), ProtobufUtil.toString(Status.parseFrom(e.getValue().get())));
+      }
+      if (size == 0) {
+        foundResults = false;
+        break;
       }
+      Thread.sleep(1000);
+      log.info("");
+    }
 
-      Assert.assertFalse("Replication status messages were not cleaned up from metadata table", foundResults);
+    Assert.assertFalse("Replication status messages were not cleaned up from metadata table", foundResults);
 
-      /**
-       * After we close out and subsequently delete the metadata record, this will propagate to the replication table, which will cause those records to be
-       * deleted after replication occurs
-       */
+    /**
+     * After we close out and subsequently delete the metadata record, this will propagate to the replication table, which will cause those records to be
+     * deleted after replication occurs
+     */
 
-      int recordsFound = 0;
-      for (int i = 0; i < 10; i++) {
-        s = ReplicationTable.getScanner(conn);
-        recordsFound = 0;
-        for (Entry<Key,Value> entry : s) {
-          recordsFound++;
-          log.info(entry.getKey().toStringNoTruncate() + " " + ProtobufUtil.toString(Status.parseFrom(entry.getValue().get())));
-        }
-
-        if (0 == recordsFound) {
-          break;
-        } else {
-          Thread.sleep(1000);
-          log.info("");
-        }
+    int recordsFound = 0;
+    for (int i = 0; i < 10; i++) {
+      s = ReplicationTable.getScanner(conn);
+      recordsFound = 0;
+      for (Entry<Key,Value> entry : s) {
+        recordsFound++;
+        log.info(entry.getKey().toStringNoTruncate() + " " + ProtobufUtil.toString(Status.parseFrom(entry.getValue().get())));
       }
 
-      Assert.assertEquals("Found unexpected replication records in the replication table", 0, recordsFound);
-    } finally {
-      // thread.interrupt();
-      // thread.join(5000);
+      if (0 == recordsFound) {
+        break;
+      } else {
+        Thread.sleep(1000);
+        log.info("");
+      }
     }
+
+    Assert.assertEquals("Found unexpected replication records in the replication table", 0, recordsFound);
   }
 }

http://git-wip-us.apache.org/repos/asf/accumulo/blob/981bf532/test/src/test/resources/log4j.properties
----------------------------------------------------------------------
diff --git a/test/src/test/resources/log4j.properties b/test/src/test/resources/log4j.properties
index 031b685..a960c35 100644
--- a/test/src/test/resources/log4j.properties
+++ b/test/src/test/resources/log4j.properties
@@ -33,7 +33,6 @@ log4j.logger.org.apache.zookeeper.ClientCnxn=FATAL
 log4j.logger.org.apache.zookeeper.ZooKeeper=WARN
 log4j.logger.org.apache.accumulo.core.file.rfile.bcfile=INFO
 log4j.logger.org.apache.accumulo.server.util.ReplicationTableUtil=TRACE
-log4j.logger.org.apache.accumulo.core.client.impl.TabletServerBatchReaderIterator=INFO
 log4j.logger.org.apache.accumulo.core.client.impl.ThriftScanner=INFO
 log4j.logger.org.apache.accumulo.fate.zookeeper.DistributedReadWriteLock=WARN
 log4j.logger.org.mortbay.log=WARN