Bug 1720232 SQLite calls could timeout in starvation situations.

Some of our servers could cause random failures when trying to generate many key pairs from multiple threads. This is caused because some threads would starve long enough for them to give up on getting a begin transaction on sqlite. sqlite only allows one transaction at a time.

Also, there were some bugs in error handling of the broken transaction case where NSS would try to cancel a transation after the begin failed (most cases were correct, but one case in particular was problematic).

Differential Revision: https://phabricator.services.mozilla.com/D120032

9 files changed, 365 insertions, 22 deletions

diff --git a/cmd/manifest.mn b/cmd/manifest.mn
index 695177c9d..bb5319a0f 100644
--- a/cmd/manifest.mn
+++ b/cmd/manifest.mn
@@ -65,6 +65,7 @@ NSS_SRCDIRS = \
  pwdecrypt \
  rsaperf \
  rsapoptst \
+ sdbthreadtst \
  sdrtest \
  selfserv  \
  signtool \
diff --git a/cmd/sdbthreadtst/Makefile b/cmd/sdbthreadtst/Makefile
new file mode 100644
index 000000000..d7c879aec
--- /dev/null
+++ b/cmd/sdbthreadtst/Makefile
@@ -0,0 +1,48 @@
+#! gmake
+#
+# This Source Code Form is subject to the terms of the Mozilla Public
+# License, v. 2.0. If a copy of the MPL was not distributed with this
+# file, You can obtain one at http://mozilla.org/MPL/2.0/.
+
+#######################################################################
+# (1) Include initial platform-independent assignments (MANDATORY).   #
+#######################################################################
+
+include manifest.mn
+
+#######################################################################
+# (2) Include "global" configuration information. (OPTIONAL)          #
+#######################################################################
+
+include $(CORE_DEPTH)/coreconf/config.mk
+
+#######################################################################
+# (3) Include "component" configuration information. (OPTIONAL)       #
+#######################################################################
+
+#######################################################################
+# (4) Include "local" platform-dependent assignments (OPTIONAL).      #
+#######################################################################
+
+include ../platlibs.mk
+
+
+#######################################################################
+# (5) Execute "global" rules. (OPTIONAL)                              #
+#######################################################################
+
+include $(CORE_DEPTH)/coreconf/rules.mk
+
+#######################################################################
+# (6) Execute "component" rules. (OPTIONAL)                           #
+#######################################################################
+
+
+
+#######################################################################
+# (7) Execute "local" rules. (OPTIONAL).                              #
+#######################################################################
+
+
+include ../platrules.mk
+
diff --git a/cmd/sdbthreadtst/manifest.mn b/cmd/sdbthreadtst/manifest.mn
new file mode 100644
index 000000000..cf9766003
--- /dev/null
+++ b/cmd/sdbthreadtst/manifest.mn
@@ -0,0 +1,22 @@
+#
+# This Source Code Form is subject to the terms of the Mozilla Public
+# License, v. 2.0. If a copy of the MPL was not distributed with this
+# file, You can obtain one at http://mozilla.org/MPL/2.0/.
+
+CORE_DEPTH = ../..
+
+DEFINES += -DNSPR20
+
+# MODULE public and private header  directories are implicitly REQUIRED.
+MODULE = nss
+
+CSRCS = \
+	sdbthreadtst.c \
+	$(NULL)
+
+# The MODULE is always implicitly required.
+# Listing it here in REQUIRES makes it appear twice in the cc command line.
+
+PROGRAM = sdbthreadtst
+
+# USE_STATIC_LIBS = 1
diff --git a/cmd/sdbthreadtst/sdbthreadtst.c b/cmd/sdbthreadtst/sdbthreadtst.c
new file mode 100644
index 000000000..32f839c9a
--- /dev/null
+++ b/cmd/sdbthreadtst/sdbthreadtst.c
@@ -0,0 +1,213 @@
+#if defined(XP_UNIX)
+#include <unistd.h>
+#endif
+#include <stdio.h>
+#include <nss.h>
+#include <prtypes.h>
+#include <prerr.h>
+#include <prerror.h>
+#include <prthread.h>
+#include <pk11pub.h>
+#include <keyhi.h>
+
+#define MAX_THREAD_COUNT 100
+
+/* globals */
+int THREAD_COUNT = 30;
+int FAILED = 0;
+int ERROR = 0;
+int LOOP_COUNT = 100;
+int KEY_SIZE = 3072;
+int STACK_SIZE = 0;
+int VERBOSE = 0;
+char *NSSDIR = ".";
+PRBool ISTOKEN = PR_TRUE;
+CK_MECHANISM_TYPE MECHANISM = CKM_RSA_PKCS_KEY_PAIR_GEN;
+
+void
+usage(char *prog, char *error)
+{
+    if (error) {
+        fprintf(stderr, "Bad Arguments: %s", error);
+    }
+    fprintf(stderr, "usage: %s [-l loop_count] [-t thread_count] "
+                    "[-k key_size] [-s stack_size] [-d nss_dir] [-e] [-v] [-h]\n",
+            prog);
+    fprintf(stderr, "    loop_count   -- "
+                    "number of keys to generate on each thread (default=%d)\n",
+            LOOP_COUNT);
+    fprintf(stderr, "    thread_count -- "
+                    "number of of concurrent threads to run (def=%d,max=%d)\n",
+            THREAD_COUNT, MAX_THREAD_COUNT);
+    fprintf(stderr, "    key_size     -- "
+                    "rsa key size in bits (default=%d)\n",
+            KEY_SIZE);
+    fprintf(stderr, "    stack_size     -- "
+                    "thread stack size in bytes, 0=optimal (default=%d)\n",
+            STACK_SIZE);
+    fprintf(stderr, "    nss_dir     -- "
+                    "location of the nss directory (default=%s)\n",
+            NSSDIR);
+    fprintf(stderr, "    -e use session keys rather than token keys\n");
+    fprintf(stderr, "    -v verbose, print progress indicators\n");
+    fprintf(stderr, "    -h print this message\n");
+    exit(2);
+}
+
+void
+create_key_loop(void *arg)
+{
+    int i;
+    PK11SlotInfo *slot = PK11_GetInternalKeySlot();
+    PK11RSAGenParams param;
+    int threadnumber = *(int *)arg;
+    int failures = 0;
+    int progress = 5;
+    PRIntervalTime epoch = PR_IntervalNow();
+    param.keySizeInBits = KEY_SIZE;
+    param.pe = 0x10001L;
+    printf(" - thread %d starting\n", threadnumber);
+    progress = 30 / THREAD_COUNT;
+    if (progress < 2)
+        progress = 2;
+    for (i = 0; i < LOOP_COUNT; i++) {
+        SECKEYPrivateKey *privKey;
+        SECKEYPublicKey *pubKey;
+        privKey = PK11_GenerateKeyPair(slot, MECHANISM, &param, &pubKey,
+                                       ISTOKEN, PR_TRUE, NULL);
+        if (privKey == NULL) {
+            fprintf(stderr,
+                    "keypair gen in thread %d failed %s\n", threadnumber,
+                    PORT_ErrorToString(PORT_GetError()));
+            FAILED++;
+            failures++;
+        }
+        if (VERBOSE && (i % progress) == 0) {
+            PRIntervalTime current = PR_IntervalNow();
+            PRIntervalTime interval = current - epoch;
+            int seconds = (interval / PR_TicksPerSecond());
+            int mseconds = ((interval * 1000) / PR_TicksPerSecond()) - (seconds * 1000);
+            epoch = current;
+            printf(" - thread %d @ %d iterations %d.%03d sec\n", threadnumber,
+                   i, seconds, mseconds);
+        }
+        if (ISTOKEN && privKey) {
+            SECKEY_DestroyPublicKey(pubKey);
+            SECKEY_DestroyPrivateKey(privKey);
+        }
+    }
+    PK11_FreeSlot(slot);
+    printf(" * thread %d ending with %d failures\n", threadnumber, failures);
+    return;
+}
+
+int
+main(int argc, char **argv)
+{
+    PRThread *thread[MAX_THREAD_COUNT];
+    int threadnumber[MAX_THREAD_COUNT];
+    int i;
+    PRStatus status;
+    SECStatus rv;
+    char *prog = *argv++;
+    char buf[2048];
+    char *arg;
+
+    while ((arg = *argv++) != NULL) {
+        if (*arg == '-') {
+            switch (arg[1]) {
+                case 'l':
+                    if (*argv == NULL)
+                        usage(prog, "missing loop count");
+                    LOOP_COUNT = atoi(*argv++);
+                    break;
+                case 'k':
+                    if (*argv == NULL)
+                        usage(prog, "missing key size");
+                    KEY_SIZE = atoi(*argv++);
+                    break;
+                case 's':
+                    if (*argv == NULL)
+                        usage(prog, "missing stack size");
+                    STACK_SIZE = atoi(*argv++);
+                    break;
+                case 't':
+                    if (*argv == NULL)
+                        usage(prog, "missing thread count");
+                    THREAD_COUNT = atoi(*argv++);
+                    if (THREAD_COUNT > MAX_THREAD_COUNT) {
+                        usage(prog, "max thread count exceeded");
+                    }
+                    break;
+                case 'v':
+                    VERBOSE = 1;
+                    break;
+                case 'd':
+                    if (*argv == NULL)
+                        usage(prog, "missing directory");
+                    NSSDIR = *argv++;
+                    break;
+                case 'e':
+                    ISTOKEN = PR_FALSE;
+                    break;
+                case 'h':
+                    usage(prog, NULL);
+                    break;
+                default:
+                    sprintf(buf, "unknown option %c", arg[1]);
+                    usage(prog, buf);
+            }
+        } else {
+            sprintf(buf, "unknown argument %s", arg);
+            usage(prog, buf);
+        }
+    }
+    /* initialize NSS */
+    rv = NSS_InitReadWrite(NSSDIR);
+    if (rv != SECSuccess) {
+        fprintf(stderr,
+                "NSS_InitReadWrite(%s) failed(%s)\n", NSSDIR,
+                PORT_ErrorToString(PORT_GetError()));
+        exit(2);
+    }
+
+    /* need to initialize the database here if it's not already */
+
+    printf("creating %d threads\n", THREAD_COUNT);
+    for (i = 0; i < THREAD_COUNT; i++) {
+        threadnumber[i] = i;
+        thread[i] = PR_CreateThread(PR_USER_THREAD, create_key_loop,
+                                    &threadnumber[i], PR_PRIORITY_NORMAL,
+                                    PR_GLOBAL_THREAD,
+                                    PR_JOINABLE_THREAD, STACK_SIZE);
+        if (thread[i] == NULL) {
+            ERROR++;
+            fprintf(stderr,
+                    "PR_CreateThread failed iteration %d, %s\n", i,
+                    PORT_ErrorToString(PORT_GetError()));
+        }
+    }
+    printf("waiting on %d threads\n", THREAD_COUNT);
+    for (i = 0; i < THREAD_COUNT; i++) {
+        if (thread[i] == NULL) {
+            continue;
+        }
+        status = PR_JoinThread(thread[i]);
+        if (status != PR_SUCCESS) {
+            ERROR++;
+            fprintf(stderr,
+                    "PR_CreateThread filed iteration %d, %s]n", i,
+                    PORT_ErrorToString(PORT_GetError()));
+        }
+    }
+    printf("%d failures and %d errors found\n", FAILED, ERROR);
+    /* clean up */
+    NSS_Shutdown();
+    if (FAILED) {
+        exit(1);
+    }
+    if (ERROR) {
+        exit(2);
+    }
+    exit(0);
+}
diff --git a/cmd/sdbthreadtst/sdbthreadtst.gyp b/cmd/sdbthreadtst/sdbthreadtst.gyp
new file mode 100644
index 000000000..e801b16ac
--- /dev/null
+++ b/cmd/sdbthreadtst/sdbthreadtst.gyp
@@ -0,0 +1,29 @@
+# This Source Code Form is subject to the terms of the Mozilla Public
+# License, v. 2.0. If a copy of the MPL was not distributed with this
+# file, You can obtain one at http://mozilla.org/MPL/2.0/.
+{
+  'includes': [
+    '../../coreconf/config.gypi',
+    '../../cmd/platlibs.gypi'
+  ],
+  'targets': [
+    {
+      'target_name': 'sdbthreadtst',
+      'type': 'executable',
+      'sources': [
+        'sdbthreadtst.c'
+      ],
+      'dependencies': [
+        '<(DEPTH)/exports.gyp:nss_exports'
+      ]
+    }
+  ],
+  'target_defaults': {
+    'defines': [
+      'NSPR20'
+    ]
+  },
+  'variables': {
+    'module': 'nss'
+  }
+}
diff --git a/lib/softoken/sdb.c b/lib/softoken/sdb.c
index 50625ab94..4083f3244 100644
--- a/lib/softoken/sdb.c
+++ b/lib/softoken/sdb.c
@@ -82,12 +82,12 @@ typedef enum {
  * total wait time for automatic operations:
  *   1 second (SDB_SQLITE_BUSY_TIMEOUT/1000).
  * total wait time for manual operations:
- *   (1 second + 5 seconds) * 10 = 60 seconds.
+ *   (1 second + SDB_BUSY_RETRY_TIME) * 30 = 30 seconds.
  * (SDB_SQLITE_BUSY_TIMEOUT/1000 + SDB_BUSY_RETRY_TIME)*SDB_MAX_BUSY_RETRIES
  */
 #define SDB_SQLITE_BUSY_TIMEOUT 1000 /* milliseconds */
-#define SDB_BUSY_RETRY_TIME 5        /* seconds */
-#define SDB_MAX_BUSY_RETRIES 10
+#define SDB_BUSY_RETRY_TIME 5        /* 'ticks', varies by platforms */
+#define SDB_MAX_BUSY_RETRIES 30
 
 /*
  * known attributes
@@ -1001,6 +1001,7 @@ sdb_GetValidAttributeValueNoLock(SDB *sdb, CK_OBJECT_HANDLE object_id,
             found = 1;
         }
     } while (!sdb_done(sqlerr, &retry));
+
     sqlite3_reset(stmt);
     sqlite3_finalize(stmt);
     stmt = NULL;
@@ -1524,6 +1525,8 @@ sdb_Begin(SDB *sdb)
         if (sqlerr == SQLITE_BUSY) {
             PR_Sleep(SDB_BUSY_RETRY_TIME);
         }
+        /* don't retry BEGIN transaction*/
+        retry = 0;
     } while (!sdb_done(sqlerr, &retry));
 
     if (stmt) {
@@ -2261,6 +2264,7 @@ sdb_init(char *dbname, char *table, sdbDataType type, int *inUpdate,
                 }
             }
         } while (!sdb_done(sqlerr, &retry));
+
         if (sqlerr != SQLITE_DONE) {
             goto loser;
         }
diff --git a/lib/softoken/sftkdb.c b/lib/softoken/sftkdb.c
index cfa056396..7c1001be8 100644
--- a/lib/softoken/sftkdb.c
+++ b/lib/softoken/sftkdb.c
@@ -1526,7 +1526,7 @@ sftkdb_DestroyObject(SFTKDBHandle *handle, CK_OBJECT_HANDLE objectID,
 
     crv = (*db->sdb_Begin)(db);
     if (crv != CKR_OK) {
-        goto loser;
+        return crv;
     }
     crv = (*db->sdb_DestroyObject)(db, objectID);
     if (crv != CKR_OK) {
@@ -2461,7 +2461,7 @@ sftkdb_Update(SFTKDBHandle *handle, SECItem *key)
      */
     crv = (*handle->db->sdb_Begin)(handle->db);
     if (crv != CKR_OK) {
-        goto loser;
+        return crv;
     }
     inTransaction = PR_TRUE;
 
diff --git a/nss.gyp b/nss.gyp
index 5d8d63658..1fb188389 100644
--- a/nss.gyp
+++ b/nss.gyp
@@ -189,6 +189,7 @@
             'cmd/pp/pp.gyp:pp',
             'cmd/rsaperf/rsaperf.gyp:rsaperf',
             'cmd/rsapoptst/rsapoptst.gyp:rsapoptst',
+            'cmd/sdbthreadtst/sdbthreadtst.gyp:sdbthreadtst',
             'cmd/sdrtest/sdrtest.gyp:sdrtest',
             'cmd/selfserv/selfserv.gyp:selfserv',
             'cmd/shlibsign/mangle/mangle.gyp:mangle',
diff --git a/tests/dbtests/dbtests.sh b/tests/dbtests/dbtests.sh
index 9dcf738c4..61a3888c6 100755
--- a/tests/dbtests/dbtests.sh
+++ b/tests/dbtests/dbtests.sh
@@ -8,7 +8,7 @@
 #
 # mozilla/security/nss/tests/dbtest/dbtest.sh
 #
-# Certificate generating and handeling for NSS QA, can be included 
+# Certificate generating and handeling for NSS QA, can be included
 # multiple times from all.sh and the individual scripts
 #
 # needs to work on all Unix and Windows platforms
@@ -50,6 +50,7 @@ dbtest_init()
   RONLY_DIR=${HOSTDIR}/ronlydir
   EMPTY_DIR=${HOSTDIR}/emptydir
   CONFLICT_DIR=${HOSTDIR}/conflictdir
+  THREAD_DIR=${HOSTDIR}/threadir
 
   html_head "CERT and Key DB Tests"
 
@@ -61,7 +62,7 @@ dbtest_init()
 ########################################################################
 dbtest_cleanup()
 {
-  html "</TABLE><BR>" 
+  html "</TABLE><BR>"
   cd ${QADIR}
   chmod a+rw $RONLY_DIR
   . common/cleanup.sh
@@ -78,21 +79,21 @@ dbtest_main()
 {
     cd ${HOSTDIR}
 
-    
+
     Echo "test opening the database read/write in a nonexisting directory"
     ${BINDIR}/certutil -L -X -d ./non_existent_dir
     ret=$?
     if [ $ret -ne 255 ]; then
       html_failed "Certutil succeeded in a nonexisting directory $ret"
     else
-      html_passed "Certutil didn't work in a nonexisting dir $ret" 
+      html_passed "Certutil didn't work in a nonexisting dir $ret"
     fi
     ${BINDIR}/dbtest -r -d ./non_existent_dir
     ret=$?
     if [ $ret -ne 46 ]; then
       html_failed "Dbtest readonly succeeded in a nonexisting directory $ret"
     else
-      html_passed "Dbtest readonly didn't work in a nonexisting dir $ret" 
+      html_passed "Dbtest readonly didn't work in a nonexisting dir $ret"
     fi
 
     Echo "test force opening the database in a nonexisting directory"
@@ -106,7 +107,7 @@ dbtest_main()
 
     Echo "test opening the database readonly in an empty directory"
     mkdir $EMPTY_DIR
-    ${BINDIR}/tstclnt -h  ${HOST}  -d $EMPTY_DIR 
+    ${BINDIR}/tstclnt -h  ${HOST}  -d $EMPTY_DIR
     ret=$?
     if [ $ret -ne 1 ]; then
       html_failed "Tstclnt succeded in an empty directory $ret"
@@ -118,7 +119,7 @@ dbtest_main()
     if [ $ret -ne 46 ]; then
       html_failed "Dbtest readonly succeeded in an empty directory $ret"
     else
-      html_passed "Dbtest readonly didn't work in an empty dir $ret" 
+      html_passed "Dbtest readonly didn't work in an empty dir $ret"
     fi
     rm -rf $EMPTY_DIR/* 2>/dev/null
     ${BINDIR}/dbtest -i -d $EMPTY_DIR
@@ -126,7 +127,7 @@ dbtest_main()
     if [ $ret -ne 0 ]; then
       html_failed "Dbtest logout after empty DB Init loses key $ret"
     else
-      html_passed "Dbtest logout after empty DB Init has key" 
+      html_passed "Dbtest logout after empty DB Init has key"
     fi
     rm -rf $EMPTY_DIR/* 2>/dev/null
     ${BINDIR}/dbtest -i -p pass -d $EMPTY_DIR
@@ -134,12 +135,12 @@ dbtest_main()
     if [ $ret -ne 0 ]; then
       html_failed "Dbtest password DB Init loses needlogin state $ret"
     else
-      html_passed "Dbtest password DB Init maintains needlogin state" 
+      html_passed "Dbtest password DB Init maintains needlogin state"
     fi
     rm -rf $EMPTY_DIR/* 2>/dev/null
     ${BINDIR}/certutil -D -n xxxx -d $EMPTY_DIR #created DB
     ret=$?
-    if [ $ret -ne 255 ]; then 
+    if [ $ret -ne 255 ]; then
         html_failed "Certutil succeeded in deleting a cert in an empty directory $ret"
     else
         html_passed "Certutil didn't work in an empty dir $ret"
@@ -176,7 +177,7 @@ dbtest_main()
     if [ $ret -ne 46 ]; then
       html_failed "Dbtest r/w succeeded in a readonly directory $ret"
     else
-      html_passed "Dbtest r/w didn't work in an readonly dir $ret" 
+      html_passed "Dbtest r/w didn't work in an readonly dir $ret"
     fi
     else
       html_passed "Skipping Dbtest r/w in a readonly dir because user is root"
@@ -190,9 +191,9 @@ dbtest_main()
       html_passed "Certutil didn't work in an readonly dir $ret"
     fi
     else
-        html_passed "Skipping Certutil delete cert in a readonly directory test because user is root" 
+        html_passed "Skipping Certutil delete cert in a readonly directory test because user is root"
     fi
-    
+
     Echo "test opening the database ronly in a readonly directory"
 
     ${BINDIR}/dbtest -d $RONLY_DIR -r
@@ -200,7 +201,7 @@ dbtest_main()
     if [ $ret -ne 0 ]; then
       html_failed "Dbtest readonly failed in a readonly directory $ret"
     else
-      html_passed "Dbtest readonly succeeded in a readonly dir $ret" 
+      html_passed "Dbtest readonly succeeded in a readonly dir $ret"
     fi
 
     Echo "test force opening the database  r/w in a readonly directory"
@@ -223,7 +224,7 @@ dbtest_main()
     ret=$?
     if [ $ret -ne 0 ]; then
       html_failed "Nicknane conflict test failed, couldn't create database $ret"
-    else 
+    else
       ${BINDIR}/certutil -A -n alice -t ,, -i ${R_ALICEDIR}/Alice.cert -d ${CONFLICT_DIR}
       ret=$?
       if [ $ret -ne 0 ]; then
@@ -252,7 +253,7 @@ dbtest_main()
     else
       html_passed "Nicknane conflict test-setting nickname conflict was correctly rejected"
     fi
-    # import a token private key and make sure the corresponding public key is 
+    # import a token private key and make sure the corresponding public key is
     # created
     ${BINDIR}/pk11importtest -d ${CONFLICT_DIR} -f ${R_PWFILE}
     ret=$?
@@ -261,10 +262,34 @@ dbtest_main()
     else
       html_passed "Importing Token Private Key correctly creates the corrresponding Public Key"
     fi
+
+
+    if [ "${NSS_DEFAULT_DB_TYPE}" = "sql" ] ; then
+      LOOPS=${NSS_SDB_THREAD_LOOPS-7}
+      THREADS=${NSS_SDB_THREAD_THREADS-30}
+      mkdir -p ${THREAD_DIR}
+      Echo "testing for thread starvation while creating keys"
+      ${BINDIR}/certutil -N -d ${THREAD_DIR} --empty-password
+      ${BINDIR}/sdbthreadtst -l ${LOOPS} -t ${THREADS} -d ${THREAD_DIR}
+      ret=$?
+      case "$ret" in
+      "0")
+         html_passed "Successfully completed ${LOOPS} loops in ${THREADS} threads without failure."
+         ;;
+      "2")
+         html_failed "sdbthreadtst failed for some environment reason (like lack of memory)"
+         ;;
+      "1")
+         html_failed "sdbthreadtst failed do to starvation using ${LOOPS} loops and ${THREADS} threads."
+         ;;
+      *)
+         html_failed "sdbthreadtst failed with an unrecognized error code."
+      esac
+    fi
 }
 
 ################## main #################################################
 
-dbtest_init 
+dbtest_init
 dbtest_main 2>&1
 dbtest_cleanup