Merge pull request #342 from szimmer1/cockroachdb-errorhandler

Refactor error format for error handling in JDBCActivity

driver-cockroachdb/src/main/resources/activities/cockroachdb-basic.yaml

@@ -4,12 +4,15 @@ description: An example of a basic cockroach insert
 
 scenarios:
   default:
-    - run driver=cockroachdb tags==phase:main threads==auto cycles===<<main-cycles:1000000>>
+    - run driver=cockroachdb tags==phase:main threads=auto cycles===<<main-cycles:1000000>>
+      serverName=localhost connectionpool=hikari
+      errors=SQLTransient.*:warn,count,retry;.*0800.*:warn,count,retry;.*40001:count,retry;stop
   rampup:
-    - run driver=cockroachdb tags==phase:rampup threads==auto cycles===<<rampup-cycles:1000000>>
+    - run driver=cockroachdb tags==phase:rampup threads=auto cycles===<<rampup-cycles:1000000>>
+      serverName=localhost connectionpool=hikari
+      errors=SQLTransient.*:warn,count,retry;.*0800.*:warn,count,retry;.*40001:count,retry;stop
   schema:
-    - run driver=cockroachdb tags==phase:schema threads==1 cycles===2
+    - run driver=cockroachdb tags==phase:schema threads===1 serverName=localhost
-    #- run driver=stdout tags==phase:schema threads==1 cycles===UNDEF
 
 bindings:
   seq_key: Mod(<<keyCount:1000000>>L); ToInt()
@@ -39,7 +42,10 @@ blocks:
       phase: rampup
     params:
     statements:
-      - rampup-insert: insert into <<database:bank>>.<<table:banktransaction>> ( code, amount ) values ( '{seq_key}', {seq_value} );
+      - rampup-insert: |
+          INSERT INTO "<<database:bank>>"."<<table:banktransaction>>"
+          (code, amount) VALUES ('{seq_key}', {seq_value})
+          ON CONFLICT (code) DO NOTHING;
         params:
         tags:
           name: rampup-insert
@@ -51,7 +57,8 @@ blocks:
       ratio: <<read_ratio:1>>
     statements:
       - main-find: |
-          SELECT code, amount FROM <<database:bank>>.<<table:banktransaction>> WHERE code = '{rw_key}' AND amount = {rw_value};
+          SELECT code, amount FROM "<<database:bank>>"."<<table:banktransaction>>"
+          WHERE code = '{rw_key}' AND amount = {rw_value};
         params:
         tags:
           name: main-find
@@ -63,7 +70,7 @@ blocks:
       ratio: <<write_ratio:1>>
     statements:
       - main-insert: |
-          UPDATE <<database:bank>>.<<table:banktransaction>> SET amount = {seq_value} WHERE code = '{seq_key}';
+          UPDATE "<<database:bank>>"."<<table:banktransaction>>" SET amount = {seq_value} WHERE code = '{seq_key}';
         params:
         tags:
           name: main-insert

driver-cockroachdb/src/main/resources/activities/postgres-basic.yaml

@@ -1,24 +1,27 @@
 # java -jar nb.jar run driver=cockroachdb workload=postgres-basic tags=phase:rampup cycles=10 \
 #   serverName=localhost databaseName=bank
-# java -jar nb.jar run driver=cockroachdb workload=postgres-basic tags=phase:main cycles=10 serverName=localhost 
+# java -jar nb.jar run driver=cockroachdb workload=postgres-basic tags=phase:main cycles=10 serverName=localhost
 description: An example of a basic postgres bank transaction workload
 
 scenarios:
   default:
-    - run driver===cockroachdb tags===phase:main threads==auto cycles=10000000
+    - run driver===cockroachdb tags===phase:main threads=auto cycles=10000000
-      serverName=localhost portNumber=5432 databaseName=<<database:bank>> user=postgres
-      password=postgres
-  rampup:
-    - run driver===cockroachdb tags===phase:rampup threads==auto cycles=<<accounts:1000000>>
-      serverName=localhost portNumber=5432 databaseName=<<database:bank>> user=postgres
-      password=postgres connectionpool=hikari filler-binding="AlphaNumericString(10)"
-  rampup-large:
-    - run driver===cockroachdb tags===phase:rampup threads==auto cycles=<<accounts:1000000>>
       serverName=localhost portNumber=5432 databaseName=<<database:bank>> user=postgres
       password=postgres connectionpool=hikari
+      errors=SQLTransient.*:warn,count,retry;.*0800.*:warn,count,retry;stop
+  rampup:
+    - run driver===cockroachdb tags===phase:rampup threads=auto cycles=<<accounts:1000000>>
+      serverName=localhost portNumber=5432 databaseName=<<database:bank>> user=postgres
+      password=postgres connectionpool=hikari filler-binding="AlphaNumericString(10)"
+      errors=SQLTransient.*:warn,count,retry;.*0800.*:warn,count,retry;stop
+  rampup-large:
+    - run driver===cockroachdb tags===phase:rampup threads=auto cycles=<<accounts:1000000>>
+      serverName=localhost portNumber=5432 databaseName=<<database:bank>> user=postgres
+      password=postgres connectionpool=hikari
+      errors=SQLTransient.*:warn,count,retry;.*0800.*:warn,count,retry;stop
   schema:
     - run driver===cockroachdb tags===phase:schema threads===1 serverName=localhost portNumber=5432
-      databaseName=bank user=postgres password=postgres connectionpool=hikari
+      databaseName=bank user=postgres password=postgres
 
 bindings:
   seq_uuid: Mod(<<accounts:1000000>>L); ToHashedUUID()
@@ -55,7 +58,7 @@ blocks:
     params:
     statements:
       - rampup-insert: |
-          INSERT INTO "<<table:account>>" (uuid, amount, amount_unit, updated_at, created_at, filler) 
+          INSERT INTO "<<table:account>>" (uuid, amount, amount_unit, updated_at, created_at, filler)
           VALUES ('{seq_uuid}', {rand_amount}, 'us_cents', '{timestamp}', '{timestamp}', '{filler}')
           ON CONFLICT DO NOTHING;
         params:

driver-cockroachdb/src/main/resources/cockroachdb.md

@@ -21,6 +21,30 @@ section for detailed parameter documentation.
     * *hikari* -
       use [HikariCP](https://github.com/brettwooldridge/HikariCP)
 * **maxtries** (optional) - number of times to retry retry-able errors; Default *3*.
-* **errors** (optional) - expression which specifies how to handle SQL state error codes.
+* **minretrydelayms** (optional) - minimum time in ms to wait before retry with exponential backoff; Default *200*.
-  Expression syntax and behavior is explained in the `error-handlers` topic. Default
+* **errors** (optional) - see `error-handlers` topic for details (`./nb help error-handlers`). Default *stop*.
-  *stop*, in other words exit on any error.
+
+#### errors parameter
+
+This parameter expects an expression which specifies how to handle exceptions by class name
+and SQL state code. Error names are formatted as `<exception-name>_<sql-state>`.
+
+For example, a *org.postgresql.util.PSQLException* with *SQLState=80001* will be formatted `PSQLException_80001`.
+To continue on such an error, use `errors=PQLException_80001:warn,count;stop`. To retry any
+*java.sql.SQLTransientException* or any *SQLState=80001* and otherwise stop, use
+`errors=SQLTransientException.*:warn,count,retry;.*80001:warn,count,retry;stop`.
+
+See scenario implementations in workloads `cockroachdb-basic` and `postgres-basic` for reasonable defaults
+of the errors parameter. This is a reasonable default error handler chain:
+
+1. `SQLTransient.*:warn,count,retry` - log, emit metric, and retry on transient errors
+([java.sql doc](https://docs.oracle.com/javase/8/docs/api/java/sql/SQLTransientException.html))
+2. `.*0800.*:warn,count,retry` - log, emit metric, and retry on "connection exception" class of postgresql driver
+SQLState codes ([postgresql java doc](https://www.postgresql.org/docs/9.4/errcodes-appendix.html))
+3. `.*40001:count,retry` - emit metric and retry on "serialization error" SQLState code of postgresql driver
+([postgresql java doc](https://www.postgresql.org/docs/9.4/errcodes-appendix.html)).
+These are common with CockroachDB
+([doc](https://www.cockroachlabs.com/docs/stable/error-handling-and-troubleshooting.html#transaction-retry-errors)).
+4. `stop` - stop the activity for any other error or if max retries are exceeded
+
+

driver-cockroachdb/src/test/java/io/nosqlbench/activitytype/cockroachdb/CockroachActivityTest.java

@@ -7,9 +7,11 @@ import org.postgresql.util.PSQLException;
 import org.postgresql.util.PSQLState;
 
 import java.net.SocketTimeoutException;
+import java.net.URI;
+import java.net.URL;
 import java.sql.SQLException;
 
-import static org.junit.jupiter.api.Assertions.assertEquals;
+import static org.junit.jupiter.api.Assertions.*;
 
 public class CockroachActivityTest {
     @Test
@@ -19,12 +21,16 @@ public class CockroachActivityTest {
 
         // When the Throwable is a SQLException, the error name should be getSQLState()
         Throwable sqlException = new SQLException("my test exception", "my-test-sql-state");
-        assertEquals("my-test-sql-state", activity.errorNameMapper(sqlException));
+        assertEquals("SQLException_my-test-sql-state", activity.errorNameMapper(sqlException));
 
         // See PSQLState to string code mapping at the Github source code website
         // https://github.com/pgjdbc/pgjdbc/blob/master/pgjdbc/src/main/java/org/postgresql/util/PSQLState.java
         Throwable psqlException = new PSQLException("retry transaction", PSQLState.CONNECTION_FAILURE);
-        assertEquals("08006", activity.errorNameMapper(psqlException));
+        assertEquals("PSQLException_08006", activity.errorNameMapper(psqlException));
+
+        // When SQLState is null or empty, suffix shouldn't be underscore
+        Throwable nullSQLState = new PSQLException("my test runtime exception", null);
+        assertEquals("PSQLException", activity.errorNameMapper(nullSQLState));
 
         // When Throwable is not a SQLException, the error name should be the class name
         Throwable runtimeException = new SocketTimeoutException("my test runtime exception");

driver-jdbc/src/main/java/io/nosqlbench/activitytype/jdbc/api/JDBCActivity.java

@@ -1,6 +1,5 @@
 package io.nosqlbench.activitytype.jdbc.api;
 
-import com.codahale.metrics.Counter;
 import com.codahale.metrics.Histogram;
 import com.codahale.metrics.Timer;
 import com.zaxxer.hikari.HikariConfig;
@@ -11,7 +10,6 @@ import io.nosqlbench.engine.api.activityimpl.ActivityDef;
 import io.nosqlbench.engine.api.activityimpl.OpDispenser;
 import io.nosqlbench.engine.api.activityimpl.SimpleActivity;
 import io.nosqlbench.engine.api.metrics.ActivityMetrics;
-import io.nosqlbench.engine.api.metrics.ExceptionCountMetrics;
 import org.apache.logging.log4j.LogManager;
 import org.apache.logging.log4j.Logger;
 
@@ -28,6 +26,7 @@ public abstract class JDBCActivity extends SimpleActivity {
     private Timer resultSuccessTimer;
     private Histogram triesHisto;
     private int maxTries;
+    private int minRetryDelayMs;
 
     protected DataSource dataSource;
     protected OpSequence<OpDispenser<String>> opSequence;
@@ -47,6 +46,7 @@ public abstract class JDBCActivity extends SimpleActivity {
         super.onActivityDefUpdate(activityDef);
 
         this.maxTries = getParams().getOptionalInteger("maxtries").orElse(3);
+        this.minRetryDelayMs = getParams().getOptionalInteger("minretrydelayms").orElse(200);
 
         LOGGER.debug("initializing data source");
         dataSource = newDataSource();
@@ -79,10 +79,15 @@ public abstract class JDBCActivity extends SimpleActivity {
     }
 
     public String errorNameMapper(Throwable e) {
+        StringBuilder sb = new StringBuilder(e.getClass().getSimpleName());
         if (e instanceof SQLException) {
-            return ((SQLException) e).getSQLState();
+            String sqlState = ((SQLException) e).getSQLState();
+            if (sqlState != null && !sqlState.isEmpty()) {
+                sb.append('_');
+                sb.append(sqlState);
+            }
         }
-        return e.getClass().getSimpleName();
+        return sb.toString();
     }
 
     @Override
@@ -94,6 +99,10 @@ public abstract class JDBCActivity extends SimpleActivity {
         return this.maxTries;
     }
 
+    public int getMinRetryDelayMs() {
+        return this.minRetryDelayMs;
+    }
+
     public DataSource getDataSource() {
         return dataSource;
     }

driver-jdbc/src/main/java/io/nosqlbench/activitytype/jdbc/impl/JDBCAction.java

@@ -40,9 +40,9 @@ public class JDBCAction implements SyncAction {
         }
 
         int maxTries = activity.getMaxTries();
+        Exception error = null;
 
         for (int tries = 1; tries <= maxTries; tries++) {
-            Exception error = null;
             long startTimeNanos = System.nanoTime();
 
             try (Connection conn = activity.getDataSource().getConnection()) {
@@ -65,12 +65,31 @@ public class JDBCAction implements SyncAction {
                 ErrorDetail detail = activity.getErrorHandler().handleError(error, cycle, executionTimeNanos);
                 if (!detail.isRetryable()) {
                     LOGGER.debug("Exit failure after non-retryable error");
-                    return 1;
+                    throw new RuntimeException("non-retryable error", error);
                 }
             }
+
+            try {
+                int retryDelay = retryDelayMs(tries, activity.getMinRetryDelayMs());
+                LOGGER.debug("tries=" + tries + " sleeping for " + retryDelay + " ms");
+                Thread.sleep(retryDelay);
+            } catch (InterruptedException e) {
+                throw new RuntimeException("thread interrupted", e);
+            }
         }
 
         LOGGER.debug("Exit failure after maxretries=" + maxTries);
-        return 1;
+        throw new RuntimeException("maxtries exceeded", error);
+    }
+
+    /**
+     * Compute retry delay based on exponential backoff with full jitter
+     * @param tries 1-indexed
+     * @param minDelayMs lower bound of retry delay
+     * @return retry delay
+     */
+    private int retryDelayMs(int tries, int minDelayMs) {
+        int exponentialDelay = minDelayMs * (int) Math.pow(2.0, tries - 1);
+        return (int) (Math.random() * exponentialDelay);
     }
 }