[ACCUMULO-667] Unexpected table not found exception

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Cannot Reproduce
• Affects Version/s: 1.4.0
• Assignee: Keith Turner
• Reporter: Keith Turner
• Created: 02/Jul/12 20:55
• Updated: 18/Dec/12 17:50
• Resolved: 18/Dec/12 17:50

Description

While running random walk test to kick the tires on a bulk import bug fix, I ran into the following error.

02 16:12:41,389 [randomwalk.Framework] ERROR: Error during random walk
java.lang.Exception: Error running node Image.xml
        at org.apache.accumulo.server.test.randomwalk.Module.visit(Module.java:259)
        at org.apache.accumulo.server.test.randomwalk.Framework.run(Framework.java:61)
        at org.apache.accumulo.server.test.randomwalk.Framework.main(Framework.java:114)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.apache.accumulo.start.Main$1.run(Main.java:89)
        at java.lang.Thread.run(Thread.java:662)
Caused by: org.apache.accumulo.core.client.TableNotFoundException: Table img_n_17502_1341245561116 does not exist
        at org.apache.accumulo.core.client.impl.Tables.getTableId(Tables.java:66)
        at org.apache.accumulo.core.client.admin.TableOperationsImpl.addSplits(TableOperationsImpl.java:319)
        at org.apache.accumulo.server.test.randomwalk.image.ImageFixture.setUp(ImageFixture.java:63)
        at org.apache.accumulo.server.test.randomwalk.Module.visit(Module.java:190)
        at org.apache.accumulo.server.test.randomwalk.Module.visit(Module.java:251)
        ... 8 more

This exception corresponds to the following test code. So addSplits() was called immediately after createTable() and did not see the table.

 try {
      conn.tableOperations().create(imageTableName);
      conn.tableOperations().addSplits(imageTableName, splits);   //line 319
      log.debug("Created table " + imageTableName + " (id:" + Tables.getNameToIdMap(instance).get(imageTableName) + ")");
    } catch (TableExistsException e) {
      log.error("Table " + imageTableName + " already exists.");
      throw e;
    }

Saw the following in the master logs. The time on the machines involved is off a few seconds. so the time discrepency does not indicate that the create table operation did not wait before returning.

02 16:12:43,063 [tableOps.Utils] INFO : table 16a (246815aaec0229bc) unlocked for write
02 16:12:43,063 [master.EventCoordinator] INFO : Created table img_n_17502_1341245561116
02 16:12:43,063 [tableOps.FinishCreateTable] DEBUG: Created table 16a img_n_17502_1341245561116

This could be a bug in ZooCache or maybe ZooCache needs to make a zookeeper sync() call before reading data.