Continuing improvements to error reporting and the sqlite3_log() routine.

FossilOrigin-Name: edea3bb740ddd096a46e00678b59d465bb1e2903

13 files changed, 130 insertions, 73 deletions

diff --git a/src/legacy.c b/src/legacy.c
index 871e15863..ebab2de37 100644
--- a/src/legacy.c
+++ b/src/legacy.c
@@ -41,7 +41,7 @@ int sqlite3_exec(
   int nRetry = 0;             /* Number of retry attempts */
   int callbackIsInit;         /* True if callback data is initialized */
 
-  if( !sqlite3SafetyCheckOk(db) ) return SQLITE_MISUSE;
+  if( !sqlite3SafetyCheckOk(db) ) return SQLITE_MISUSE_BKPT;
   if( zSql==0 ) zSql = "";
 
   sqlite3_mutex_enter(db->mutex);
diff --git a/src/main.c b/src/main.c
index 348ddb565..f31c83267 100644
--- a/src/main.c
+++ b/src/main.c
@@ -257,7 +257,7 @@ int sqlite3_config(int op, ...){
 
   /* sqlite3_config() shall return SQLITE_MISUSE if it is invoked while
   ** the SQLite library is in use. */
-  if( sqlite3GlobalConfig.isInit ) return SQLITE_MISUSE;
+  if( sqlite3GlobalConfig.isInit ) return SQLITE_MISUSE_BKPT;
 
   va_start(ap, op);
   switch( op ){
@@ -601,7 +601,7 @@ int sqlite3_close(sqlite3 *db){
     return SQLITE_OK;
   }
   if( !sqlite3SafetyCheckSickOrOk(db) ){
-    return SQLITE_MISUSE;
+    return SQLITE_MISUSE_BKPT;
   }
   sqlite3_mutex_enter(db->mutex);
 
@@ -948,7 +948,7 @@ int sqlite3CreateFunc(
       (!xFunc && (!xFinal && xStep)) ||
       (nArg<-1 || nArg>SQLITE_MAX_FUNCTION_ARG) ||
       (255<(nName = sqlite3Strlen30( zFunctionName))) ){
-    return SQLITE_MISUSE;
+    return SQLITE_MISUSE_BKPT;
   }
   
 #ifndef SQLITE_OMIT_UTF16
@@ -1279,7 +1279,7 @@ const char *sqlite3_errmsg(sqlite3 *db){
     return sqlite3ErrStr(SQLITE_NOMEM);
   }
   if( !sqlite3SafetyCheckSickOrOk(db) ){
-    return sqlite3ErrStr(SQLITE_MISUSE);
+    return sqlite3ErrStr(SQLITE_MISUSE_BKPT);
   }
   sqlite3_mutex_enter(db->mutex);
   if( db->mallocFailed ){
@@ -1348,7 +1348,7 @@ const void *sqlite3_errmsg16(sqlite3 *db){
 */
 int sqlite3_errcode(sqlite3 *db){
   if( db && !sqlite3SafetyCheckSickOrOk(db) ){
-    return SQLITE_MISUSE;
+    return SQLITE_MISUSE_BKPT;
   }
   if( !db || db->mallocFailed ){
     return SQLITE_NOMEM;
@@ -1357,7 +1357,7 @@ int sqlite3_errcode(sqlite3 *db){
 }
 int sqlite3_extended_errcode(sqlite3 *db){
   if( db && !sqlite3SafetyCheckSickOrOk(db) ){
-    return SQLITE_MISUSE;
+    return SQLITE_MISUSE_BKPT;
   }
   if( !db || db->mallocFailed ){
     return SQLITE_NOMEM;
@@ -1395,7 +1395,7 @@ static int createCollation(
     enc2 = SQLITE_UTF16NATIVE;
   }
   if( enc2<SQLITE_UTF8 || enc2>SQLITE_UTF16BE ){
-    return SQLITE_MISUSE;
+    return SQLITE_MISUSE_BKPT;
   }
 
   /* Check if this call is removing or replacing an existing collation 
diff --git a/src/mem1.c b/src/mem1.c
index 67dd47453..558eed847 100644
--- a/src/mem1.c
+++ b/src/mem1.c
@@ -42,6 +42,8 @@ static void *sqlite3MemMalloc(int nByte){
   if( p ){
     p[0] = nByte;
     p++;
+  }else{
+    sqlite3_log(SQLITE_NOMEM, "failed to allocate %u bytes of memory", nByte);
   }
   return (void *)p;
 }
@@ -62,6 +64,18 @@ static void sqlite3MemFree(void *pPrior){
 }
 
 /*
+** Report the allocated size of a prior return from xMalloc()
+** or xRealloc().
+*/
+static int sqlite3MemSize(void *pPrior){
+  sqlite3_int64 *p;
+  if( pPrior==0 ) return 0;
+  p = (sqlite3_int64*)pPrior;
+  p--;
+  return (int)p[0];
+}
+
+/*
 ** Like realloc().  Resize an allocation previously obtained from
 ** sqlite3MemMalloc().
 **
@@ -80,23 +94,15 @@ static void *sqlite3MemRealloc(void *pPrior, int nByte){
   if( p ){
     p[0] = nByte;
     p++;
+  }else{
+    sqlite3_log(SQLITE_NOMEM,
+      "failed memory resize %u to %u bytes",
+      sqlite3MemSize(pPrior), nByte);
   }
   return (void*)p;
 }
 
 /*
-** Report the allocated size of a prior return from xMalloc()
-** or xRealloc().
-*/
-static int sqlite3MemSize(void *pPrior){
-  sqlite3_int64 *p;
-  if( pPrior==0 ) return 0;
-  p = (sqlite3_int64*)pPrior;
-  p--;
-  return (int)p[0];
-}
-
-/*
 ** Round up a request size to the next valid allocation size.
 */
 static int sqlite3MemRoundup(int n){
diff --git a/src/mem5.c b/src/mem5.c
index 3fe04e245..feb1cb7e9 100644
--- a/src/mem5.c
+++ b/src/mem5.c
@@ -268,7 +268,10 @@ static void *memsys5MallocUnsafe(int nByte){
   ** two in order to create a new free block of size iLogsize.
   */
   for(iBin=iLogsize; mem5.aiFreelist[iBin]<0 && iBin<=LOGMAX; iBin++){}
-  if( iBin>LOGMAX ) return 0;
+  if( iBin>LOGMAX ){
+    sqlite3_log(SQLITE_NOMEM, "failed to allocate %u bytes", nByte);
+    return 0;
+  }
   i = memsys5UnlinkFirst(iBin);
   while( iBin>iLogsize ){
     int newSize;
diff --git a/src/os_unix.c b/src/os_unix.c
index 80c966b56..1cce7dac1 100644
--- a/src/os_unix.c
+++ b/src/os_unix.c
@@ -1111,7 +1111,7 @@ static int transferOwnership(unixFile *pFile){
   }
   if( pFile->locktype!=NO_LOCK ){
     /* We cannot change ownership while we are holding a lock! */
-    return SQLITE_MISUSE;
+    return SQLITE_MISUSE_BKPT;
   }
   OSTRACE4("Transfer ownership of %d from %d to %d\n",
             pFile->h, pFile->tid, hSelf);
@@ -1512,7 +1512,7 @@ static int _posixUnlock(sqlite3_file *id, int locktype, int handleNFSUnlock){
     return SQLITE_OK;
   }
   if( CHECK_THREADID(pFile) ){
-    return SQLITE_MISUSE;
+    return SQLITE_MISUSE_BKPT;
   }
   unixEnterMutex();
   h = pFile->h;
@@ -2735,7 +2735,7 @@ static int afpUnlock(sqlite3_file *id, int locktype) {
     return SQLITE_OK;
   }
   if( CHECK_THREADID(pFile) ){
-    return SQLITE_MISUSE;
+    return SQLITE_MISUSE_BKPT;
   }
   unixEnterMutex();
   pLock = pFile->pLock;
diff --git a/src/prepare.c b/src/prepare.c
index 2bb1ff690..c8cd6f6f6 100644
--- a/src/prepare.c
+++ b/src/prepare.c
@@ -689,7 +689,7 @@ static int sqlite3LockAndPrepare(
   assert( ppStmt!=0 );
   *ppStmt = 0;
   if( !sqlite3SafetyCheckOk(db) ){
-    return SQLITE_MISUSE;
+    return SQLITE_MISUSE_BKPT;
   }
   sqlite3_mutex_enter(db->mutex);
   sqlite3BtreeEnterAll(db);
@@ -797,7 +797,7 @@ static int sqlite3Prepare16(
   assert( ppStmt );
   *ppStmt = 0;
   if( !sqlite3SafetyCheckOk(db) ){
-    return SQLITE_MISUSE;
+    return SQLITE_MISUSE_BKPT;
   }
   sqlite3_mutex_enter(db->mutex);
   zSql8 = sqlite3Utf16to8(db, zSql, nBytes);
diff --git a/src/status.c b/src/status.c
index 58a7e68c1..f4c77a910 100644
--- a/src/status.c
+++ b/src/status.c
@@ -83,7 +83,7 @@ void sqlite3StatusSet(int op, int X){
 int sqlite3_status(int op, int *pCurrent, int *pHighwater, int resetFlag){
   wsdStatInit;
   if( op<0 || op>=ArraySize(wsdStat.nowValue) ){
-    return SQLITE_MISUSE;
+    return SQLITE_MISUSE_BKPT;
   }
   *pCurrent = wsdStat.nowValue[op];
   *pHighwater = wsdStat.mxValue[op];
diff --git a/src/tokenize.c b/src/tokenize.c
index a93eeaa78..4b40770d5 100644
--- a/src/tokenize.c
+++ b/src/tokenize.c
@@ -480,6 +480,7 @@ abort_parse:
   assert( pzErrMsg!=0 );
   if( pParse->zErrMsg ){
     *pzErrMsg = pParse->zErrMsg;
+    sqlite3_log(pParse->rc, "%s", *pzErrMsg);
     pParse->zErrMsg = 0;
     nErr++;
   }
diff --git a/src/util.c b/src/util.c
index 813ef6e62..159da1eea 100644
--- a/src/util.c
+++ b/src/util.c
@@ -161,7 +161,6 @@ void sqlite3ErrorMsg(Parse *pParse, const char *zFormat, ...){
     sqlite3DbFree(db, pParse->zErrMsg);
     pParse->zErrMsg = zMsg;
     pParse->rc = SQLITE_ERROR;
-    sqlite3_log(SQLITE_ERROR, pParse->zErrMsg);
   }
 }
 
@@ -1010,6 +1009,17 @@ void *sqlite3HexToBlob(sqlite3 *db, const char *z, int n){
 }
 #endif /* !SQLITE_OMIT_BLOB_LITERAL || SQLITE_HAS_CODEC */
 
+/*
+** Log an error that is an API call on a connection pointer that should
+** not have been used.  The "type" of connection pointer is given as the
+** argument.  The zType is a word like "NULL" or "closed" or "invalid".
+*/
+static void logBadConnection(const char *zType){
+  sqlite3_log(SQLITE_MISUSE, 
+     "API call with %s database connection pointer",
+     zType
+  );
+}
 
 /*
 ** Check to make sure we have a valid db pointer.  This test is not
@@ -1027,9 +1037,15 @@ void *sqlite3HexToBlob(sqlite3 *db, const char *z, int n){
 */
 int sqlite3SafetyCheckOk(sqlite3 *db){
   u32 magic;
-  if( db==0 ) return 0;
+  if( db==0 ){
+    logBadConnection("NULL");
+    return 0;
+  }
   magic = db->magic;
   if( magic!=SQLITE_MAGIC_OPEN ){
+    if( !sqlite3SafetyCheckSickOrOk(db) ){
+      logBadConnection("unopened");
+    }
     return 0;
   }else{
     return 1;
@@ -1040,6 +1056,10 @@ int sqlite3SafetyCheckSickOrOk(sqlite3 *db){
   magic = db->magic;
   if( magic!=SQLITE_MAGIC_SICK &&
       magic!=SQLITE_MAGIC_OPEN &&
-      magic!=SQLITE_MAGIC_BUSY ) return 0;
-  return 1;
+      magic!=SQLITE_MAGIC_BUSY ){
+    logBadConnection( magic==SQLITE_MAGIC_CLOSED ? "closed" : "invalid" );
+    return 0;
+  }else{
+    return 1;
+  }
 }
diff --git a/src/vdbe.c b/src/vdbe.c
index 74bd91986..71fa635d0 100644
--- a/src/vdbe.c
+++ b/src/vdbe.c
@@ -847,7 +847,9 @@ case OP_Halt: {
   p->errorAction = (u8)pOp->p2;
   p->pc = pc;
   if( pOp->p4.z ){
+    assert( p->rc!=SQLITE_OK );
     sqlite3SetString(&p->zErrMsg, db, "%s", pOp->p4.z);
+    sqlite3_log(pOp->p1, "abort at %d in [%s]: %s", pc, p->zSql, pOp->p4.z);
   }
   rc = sqlite3VdbeHalt(p);
   assert( rc==SQLITE_BUSY || rc==SQLITE_OK || rc==SQLITE_ERROR );
@@ -5697,6 +5699,7 @@ default: {          /* This is really OP_Noop and OP_Explain */
 vdbe_error_halt:
   assert( rc );
   p->rc = rc;
+  sqlite3_log(rc, "prepared statement aborts at %d: [%s]", pc, p->zSql);
   sqlite3VdbeHalt(p);
   if( rc==SQLITE_IOERR_NOMEM ) db->mallocFailed = 1;
   rc = SQLITE_ERROR;
@@ -5725,12 +5728,6 @@ no_mem:
   rc = SQLITE_NOMEM;
   goto vdbe_error_halt;
 
-  /* Jump to here for an SQLITE_MISUSE error.
-  */
-abort_due_to_misuse:
-  rc = SQLITE_MISUSE;
-  /* Fall thru into abort_due_to_error */
-
   /* Jump to here for any other kind of fatal error.  The "rc" variable
   ** should hold the error number.
   */
diff --git a/src/vdbeapi.c b/src/vdbeapi.c
index 242d428e0..060f27224 100644
--- a/src/vdbeapi.c
+++ b/src/vdbeapi.c
@@ -32,6 +32,28 @@ int sqlite3_expired(sqlite3_stmt *pStmt){
 #endif
 
 /*
+** Check on a Vdbe to make sure it has not been finalized.  Log
+** an error and return true if it has been finalized (or is otherwise
+** invalid).  Return false if it is ok.
+*/
+static int vdbeSafety(Vdbe *p){
+  if( p->db==0 ){
+    sqlite3_log(SQLITE_MISUSE, "API called with finalized prepared statement");
+    return 1;
+  }else{
+    return 0;
+  }
+}
+static int vdbeSafetyNotNull(Vdbe *p){
+  if( p==0 ){
+    sqlite3_log(SQLITE_MISUSE, "API called with NULL prepared statement");
+    return 1;
+  }else{
+    return vdbeSafety(p);
+  }
+}
+
+/*
 ** The following routine destroys a virtual machine that is created by
 ** the sqlite3_compile() routine. The integer returned is an SQLITE_
 ** success/failure code that describes the result of executing the virtual
@@ -50,7 +72,7 @@ int sqlite3_finalize(sqlite3_stmt *pStmt){
 #if SQLITE_THREADSAFE
     sqlite3_mutex *mutex;
 #endif
-    if( db==0 ) return SQLITE_MISUSE;
+    if( vdbeSafety(v) ) return SQLITE_MISUSE_BKPT;
 #if SQLITE_THREADSAFE
     mutex = v->db->mutex;
 #endif
@@ -299,7 +321,9 @@ static int sqlite3Step(Vdbe *p){
 
   assert(p);
   if( p->magic!=VDBE_MAGIC_RUN ){
-    return SQLITE_MISUSE;
+    sqlite3_log(SQLITE_MISUSE, 
+          "attempt to step a halted statement: [%s]", p->zSql);
+    return SQLITE_MISUSE_BKPT;
   }
 
   /* Check that malloc() has not failed. If it has, return early. */
@@ -394,39 +418,41 @@ end_of_step:
 ** call sqlite3Reprepare() and try again.
 */
 int sqlite3_step(sqlite3_stmt *pStmt){
-  int rc = SQLITE_MISUSE;
+  int rc = SQLITE_OK;
   Vdbe *v = (Vdbe*)pStmt;
-  if( v && (v->db)!=0 ){
-    int cnt = 0;
-    sqlite3 *db = v->db;
-    sqlite3_mutex_enter(db->mutex);
-    while( (rc = sqlite3Step(v))==SQLITE_SCHEMA
-           && cnt++ < 5
-           && (rc = sqlite3Reprepare(v))==SQLITE_OK ){
-      sqlite3_reset(pStmt);
-      v->expired = 0;
-    }
-    if( rc==SQLITE_SCHEMA && ALWAYS(v->isPrepareV2) && ALWAYS(db->pErr) ){
-      /* This case occurs after failing to recompile an sql statement. 
-      ** The error message from the SQL compiler has already been loaded 
-      ** into the database handle. This block copies the error message 
-      ** from the database handle into the statement and sets the statement
-      ** program counter to 0 to ensure that when the statement is 
-      ** finalized or reset the parser error message is available via
-      ** sqlite3_errmsg() and sqlite3_errcode().
-      */
-      const char *zErr = (const char *)sqlite3_value_text(db->pErr); 
-      sqlite3DbFree(db, v->zErrMsg);
-      if( !db->mallocFailed ){
-        v->zErrMsg = sqlite3DbStrDup(db, zErr);
-      } else {
-        v->zErrMsg = 0;
-        v->rc = SQLITE_NOMEM;
-      }
+  int cnt = 0;
+  sqlite3 *db;
+  if( vdbeSafetyNotNull(v) ){
+    return SQLITE_MISUSE_BKPT;
+  }
+  db = v->db;
+  sqlite3_mutex_enter(db->mutex);
+  while( (rc = sqlite3Step(v))==SQLITE_SCHEMA
+         && cnt++ < 5
+         && (rc = sqlite3Reprepare(v))==SQLITE_OK ){
+    sqlite3_reset(pStmt);
+    v->expired = 0;
+  }
+  if( rc==SQLITE_SCHEMA && ALWAYS(v->isPrepareV2) && ALWAYS(db->pErr) ){
+    /* This case occurs after failing to recompile an sql statement. 
+    ** The error message from the SQL compiler has already been loaded 
+    ** into the database handle. This block copies the error message 
+    ** from the database handle into the statement and sets the statement
+    ** program counter to 0 to ensure that when the statement is 
+    ** finalized or reset the parser error message is available via
+    ** sqlite3_errmsg() and sqlite3_errcode().
+    */
+    const char *zErr = (const char *)sqlite3_value_text(db->pErr); 
+    sqlite3DbFree(db, v->zErrMsg);
+    if( !db->mallocFailed ){
+      v->zErrMsg = sqlite3DbStrDup(db, zErr);
+    } else {
+      v->zErrMsg = 0;
+      v->rc = SQLITE_NOMEM;
     }
-    rc = sqlite3ApiExit(db, rc);
-    sqlite3_mutex_leave(db->mutex);
   }
+  rc = sqlite3ApiExit(db, rc);
+  sqlite3_mutex_leave(db->mutex);
   return rc;
 }
 
@@ -896,12 +922,16 @@ const void *sqlite3_column_origin_name16(sqlite3_stmt *pStmt, int N){
 */
 static int vdbeUnbind(Vdbe *p, int i){
   Mem *pVar;
-  if( p==0 ) return SQLITE_MISUSE;
+  if( vdbeSafetyNotNull(p) ){
+    return SQLITE_MISUSE_BKPT;
+  }
   sqlite3_mutex_enter(p->db->mutex);
   if( p->magic!=VDBE_MAGIC_RUN || p->pc>=0 ){
     sqlite3Error(p->db, SQLITE_MISUSE, 0);
     sqlite3_mutex_leave(p->db->mutex);
-    return SQLITE_MISUSE;
+    sqlite3_log(SQLITE_MISUSE, 
+        "bind on a busy prepared statement: [%s]", p->zSql);
+    return SQLITE_MISUSE_BKPT;
   }
   if( i<1 || i>p->nVar ){
     sqlite3Error(p->db, SQLITE_RANGE, 0);
diff --git a/src/vdbeblob.c b/src/vdbeblob.c
index 2871f1ad1..829b6de6d 100644
--- a/src/vdbeblob.c
+++ b/src/vdbeblob.c
@@ -318,7 +318,7 @@ static int blobReadWrite(
   Vdbe *v;
   sqlite3 *db;
 
-  if( p==0 ) return SQLITE_MISUSE;
+  if( p==0 ) return SQLITE_MISUSE_BKPT;
   db = p->db;
   sqlite3_mutex_enter(db->mutex);
   v = (Vdbe*)p->pStmt;
diff --git a/src/vtab.c b/src/vtab.c
index bd1c16a98..cbb752354 100644
--- a/src/vtab.c
+++ b/src/vtab.c
@@ -647,7 +647,7 @@ int sqlite3_declare_vtab(sqlite3 *db, const char *zCreateTable){
   if( !pTab ){
     sqlite3Error(db, SQLITE_MISUSE, 0);
     sqlite3_mutex_leave(db->mutex);
-    return SQLITE_MISUSE;
+    return SQLITE_MISUSE_BKPT;
   }
   assert( (pTab->tabFlags & TF_Virtual)!=0 );