SQLite

**
******************************************************************************
**
** This file contains the implementation of an SQLite vfs wrapper that
** adds instrumentation to all vfs and file methods. C and Tcl interfaces
** are provided to control the instrumentation.
**
** $Id: test_osinst.c,v 1.14 2008/06/06 11:11:26 danielk1977 Exp $
** $Id: test_osinst.c,v 1.15 2008/06/11 11:00:31 danielk1977 Exp $
*/

/*
** C interface:
**
**   sqlite3_instvfs_create()
**   sqlite3_instvfs_destroy()

#define OS_UNLOCK            19
#define OS_WRITE             20

#define OS_NUMEVENTS         21

#define BINARYLOG_STRING     30
#define BINARYLOG_MARKER     31

#define BINARYLOG_PREPARE_V2 64
#define BINARYLOG_STEP       65
#define BINARYLOG_FINALIZE   66

struct InstVfs {
  sqlite3_vfs base;
  sqlite3_vfs *pVfs;

  void *pClient;
  void (*xDel)(void *);

  return rc;                             \
}

/*
** Close an inst-file.
*/
static int instClose(sqlite3_file *pFile){
  OS_TIME_IO(OS_CLOSE, 0, 0, p->pReal->pMethods->xClose(p->pReal));
  OS_TIME_IO(OS_CLOSE, 0, 0, 
    (p->pReal->pMethods ? p->pReal->pMethods->xClose(p->pReal) : SQLITE_OK)
  );
}

/*
** Read data from an inst-file.
*/
static int instRead(
  sqlite3_file *pFile, 

    put32bits(&zRec[0], BINARYLOG_STRING);
    put32bits(&zRec[4], (int)nBlob);
    put32bits(&zRec[8], (int)isBinary);
    memcpy(&zRec[28], zBlob, nBlob);
    pLog->nBuf += nWrite;
  }
}

void sqlite3_instvfs_binarylog_call(
  sqlite3_vfs *pVfs,
  int eEvent,
  sqlite3_int64 nClick,
  int return_code,
  const char *zString
){
  InstVfs *pInstVfs = (InstVfs *)pVfs;
  InstVfsBinaryLog *pLog = (InstVfsBinaryLog *)pInstVfs->pClient;

  if( zString ){
    binarylog_blob(pVfs, zString, -1, 0);
  }
  binarylog_xcall(pLog, eEvent, 0, nClick, return_code, 0, 0, 0, 0);
}

void sqlite3_instvfs_binarylog_marker(
  sqlite3_vfs *pVfs,
  const char *zMarker
){
  InstVfs *pInstVfs = (InstVfs *)pVfs;
  InstVfsBinaryLog *pLog = (InstVfsBinaryLog *)pInstVfs->pClient;

#include <string.h>
#include <stdlib.h>
#include <ctype.h>
#include <unistd.h>
#include <stdarg.h>
#include "sqlite3.h"

/* 
** hwtime.h contains inline assembler code for implementing 
** high-performance timing routines.
*/
#include "hwtime.h"
#include "test_osinst.c"

/*
** Send a message to the log file.
*/
static void logMessage(const char *zFormat, ...){
  va_list ap;
  va_start(ap, zFormat);
  vprintf(zFormat, ap);
  va_end(ap);
}

/*
** Timers
*/
static sqlite3_uint64 prepTime = 0;
static sqlite3_uint64 runTime = 0;
static sqlite3_uint64 finalizeTime = 0;
static sqlite3_uint64 instTime = 0;

typedef struct inst_file inst_file;
struct inst_file {
  sqlite3_file base;
  sqlite3_file *pReal;
};

/*
** Method declarations for inst_file.
*/
static int instClose(sqlite3_file*);
static int instRead(sqlite3_file*, void*, int iAmt, sqlite3_int64 iOfst);
static int instWrite(sqlite3_file*,const void*,int iAmt, sqlite3_int64 iOfst);
static int instTruncate(sqlite3_file*, sqlite3_int64 size);
static int instSync(sqlite3_file*, int flags);
static int instFileSize(sqlite3_file*, sqlite3_int64 *pSize);
static int instLock(sqlite3_file*, int);
static int instUnlock(sqlite3_file*, int);
static int instCheckReservedLock(sqlite3_file*);
static int instFileControl(sqlite3_file*, int op, void *pArg);
static int instSectorSize(sqlite3_file*);
static int instDeviceCharacteristics(sqlite3_file*);

/*
** Method declarations for inst_vfs.
*/
static int instOpen(sqlite3_vfs*, const char *, sqlite3_file*, int , int *);
static int instDelete(sqlite3_vfs*, const char *zName, int syncDir);
static int instAccess(sqlite3_vfs*, const char *zName, int flags);
static int instGetTempName(sqlite3_vfs*, int nOut, char *zOut);
static int instFullPathname(sqlite3_vfs*, const char *zName, int, char *zOut);
static void *instDlOpen(sqlite3_vfs*, const char *zFilename);
static void instDlError(sqlite3_vfs*, int nByte, char *zErrMsg);
static void *instDlSym(sqlite3_vfs*,void*, const char *zSymbol);
static void instDlClose(sqlite3_vfs*, void*);
static int instRandomness(sqlite3_vfs*, int nByte, char *zOut);
static int instSleep(sqlite3_vfs*, int microseconds);
static int instCurrentTime(sqlite3_vfs*, double*);

static sqlite3_vfs inst_vfs = {
  1,                      /* iVersion */
  0,                      /* szOsFile */
  0,                      /* mxPathname */
  0,                      /* pNext */
  "instVfs",              /* zName */
  0,                      /* pAppData */
  instOpen,               /* xOpen */
  instDelete,             /* xDelete */
  instAccess,             /* xAccess */
  instGetTempName,        /* xGetTempName */
  instFullPathname,       /* xFullPathname */
  instDlOpen,             /* xDlOpen */
  instDlError,            /* xDlError */
  instDlSym,              /* xDlSym */
  instDlClose,            /* xDlClose */
  instRandomness,         /* xRandomness */
  instSleep,              /* xSleep */
  instCurrentTime         /* xCurrentTime */
};

static sqlite3_io_methods inst_io_methods = {
  1,                            /* iVersion */
  instClose,                      /* xClose */
  instRead,                       /* xRead */
  instWrite,                      /* xWrite */
  instTruncate,                   /* xTruncate */
  instSync,                       /* xSync */
  instFileSize,                   /* xFileSize */
  instLock,                       /* xLock */
  instUnlock,                     /* xUnlock */
  instCheckReservedLock,          /* xCheckReservedLock */
  instFileControl,                /* xFileControl */
  instSectorSize,                 /* xSectorSize */
  instDeviceCharacteristics       /* xDeviceCharacteristics */
};

#define OS_TIME_IO(MESSAGE, A, B, CALL)      \
  int rc;                                    \
  sqlite_uint64 t1, t2;                      \
  inst_file *p = (inst_file*)pFile;          \
  t1 = sqlite3Hwtime();                      \
  rc = CALL;                                 \
  t2 = sqlite3Hwtime();                      \
  logMessage(MESSAGE, A, B, t2-t1);          \
  instTime += sqlite3Hwtime() - t2;          \
  return rc;

#define OS_TIME_VFS(MESSAGE, A, B, CALL)                 \
  int rc;                                                \
  sqlite_uint64 t1, t2;                                  \
  sqlite3_vfs *pRealVfs = (sqlite3_vfs*)pVfs->pAppData;  \
  t1 = sqlite3Hwtime();                                  \
  rc = CALL;                                             \
  t2 = sqlite3Hwtime();                                  \
  logMessage(MESSAGE, A, B, t2-t1);                      \
  instTime += sqlite3Hwtime() - t2;                      \
  return rc;


/*
** Close an inst-file.
*/
static int instClose(sqlite3_file *pFile){
  OS_TIME_IO("xClose: %s%s%lld cycles\n", "", "",
    p->pReal->pMethods->xClose(p->pReal)
  );
}

/*
** Read data from an inst-file.
*/
static int instRead(
  sqlite3_file *pFile, 
  void *zBuf, 
  int iAmt, 
  sqlite_int64 iOfst
){
  OS_TIME_IO("xRead: %d bytes at offset %lld - %lld cycles\n", iAmt, iOfst, 
    p->pReal->pMethods->xRead(p->pReal, zBuf, iAmt,iOfst)
  );
}

/*
** Write data to an inst-file.
*/
static int instWrite(
  sqlite3_file *pFile,
  const void *z,
  int iAmt,
  sqlite_int64 iOfst
){
  OS_TIME_IO("xWrite: %d bytes at offset %lld - %lld cycles\n", iAmt, iOfst,
    p->pReal->pMethods->xWrite(p->pReal, z, iAmt, iOfst)
  );
}

/*
** Truncate an inst-file.
*/
static int instTruncate(sqlite3_file *pFile, sqlite_int64 size){
  OS_TIME_IO("xTruncate: to %lld bytes - %s%lld cycles\n", size, "",
    p->pReal->pMethods->xTruncate(p->pReal, size)
  );
}

/*
** Sync an inst-file.
*/
static int instSync(sqlite3_file *pFile, int flags){
  OS_TIME_IO("xSync: %s%s%lld cycles\n", "", "", 
    p->pReal->pMethods->xSync(p->pReal, flags)
  );
}

/*
** Return the current file-size of an inst-file.
*/
static int instFileSize(sqlite3_file *pFile, sqlite_int64 *pSize){
  OS_TIME_IO("xFileSize: %s%s%lld cycles\n", "", "", 
    p->pReal->pMethods->xFileSize(p->pReal, pSize)
  );
}

/*
** Lock an inst-file.
*/
static int instLock(sqlite3_file *pFile, int eLock){
  OS_TIME_IO("xLock: %d %s%lld cycles\n", eLock, "",
    p->pReal->pMethods->xLock(p->pReal, eLock)
  );
}

/*
** Unlock an inst-file.
*/
static int instUnlock(sqlite3_file *pFile, int eLock){
  OS_TIME_IO("xUnlock: %d %s%lld\n", eLock, "",
    p->pReal->pMethods->xUnlock(p->pReal, eLock)
  );
}

/*
** Check if another file-handle holds a RESERVED lock on an inst-file.
*/
static int instCheckReservedLock(sqlite3_file *pFile){
  OS_TIME_IO("xCheckReservedLock: %s%s%lld cycles\n", "", "",
    p->pReal->pMethods->xCheckReservedLock(p->pReal)
  );
}

/*
** File control method. For custom operations on an inst-file.
*/
static int instFileControl(sqlite3_file *pFile, int op, void *pArg){
  OS_TIME_IO("xFileControl:  op=%d - %s%lld cycles\n", op, "",
    p->pReal->pMethods->xFileControl(p->pReal, op, pArg)
  );
}

/*
** Return the sector-size in bytes for an inst-file.
*/
static int instSectorSize(sqlite3_file *pFile){
  OS_TIME_IO("xSectorSize: %s%s%lld cycles\n", "", "",
    p->pReal->pMethods->xSectorSize(p->pReal)
  );
}

/*
** Return the device characteristic flags supported by an inst-file.
*/
static int instDeviceCharacteristics(sqlite3_file *pFile){
  OS_TIME_IO("xDeviceCharacteristics: %s%s%lld cycles\n", "", "",
    p->pReal->pMethods->xDeviceCharacteristics(p->pReal)
  );
}

/*
** Open an inst file handle.
*/
static int instOpen(
  sqlite3_vfs *pVfs,
  const char *zName,
  sqlite3_file *pFile,
  int flags,
  int *pOutFlags
){
  inst_file *p = (inst_file *)pFile;
  pFile->pMethods = &inst_io_methods;
  p->pReal = (sqlite3_file *)&p[1];

  OS_TIME_VFS("xOpen: \"%s\" flags=0x04%x - %lld cycles\n", zName, flags,
    pRealVfs->xOpen(pRealVfs, zName, p->pReal, flags, pOutFlags)
  );
}

/*
** Delete the file located at zPath. If the dirSync argument is true,
** ensure the file-system modifications are synced to disk before
** returning.
*/
static int instDelete(sqlite3_vfs *pVfs, const char *zPath, int dirSync){
  OS_TIME_VFS("xDelete:  \"%s\", dirSync=%d - %lld cycles\n",
    zPath, dirSync,
    pRealVfs->xDelete(pRealVfs, zPath, dirSync) 
  );
}

/*
** Test for access permissions. Return true if the requested permission
** is available, or false otherwise.
*/
static int instAccess(sqlite3_vfs *pVfs, const char *zPath, int flags){
  OS_TIME_VFS("xAccess of \"%s\", flags=0x%04x - %lld cycles\n",
    zPath, flags,
    pRealVfs->xAccess(pRealVfs, zPath, flags) 
  );
}

/*
** Populate buffer zBufOut with a pathname suitable for use as a 
** temporary file. zBufOut is guaranteed to point to a buffer of 
** at least (INST_MAX_PATHNAME+1) bytes.
*/
static int instGetTempName(sqlite3_vfs *pVfs, int nOut, char *zBufOut){
  OS_TIME_VFS("xGetTempName: %s%s%lld cycles\n", "", "",
    pRealVfs->xGetTempname(pRealVfs, nOut, zBufOut)
  );
}

/*
** Populate buffer zOut with the full canonical pathname corresponding
** to the pathname in zPath. zOut is guaranteed to point to a buffer
** of at least (INST_MAX_PATHNAME+1) bytes.
*/
static int instFullPathname(
  sqlite3_vfs *pVfs, 
  const char *zPath, 
  int nOut, 
  char *zOut
){
  OS_TIME_VFS("xFullPathname: \"%s\" - %s%lld cycles\n",
    zPath, "",
    pRealVfs->xFullPathname(pRealVfs, zPath, nOut, zOut)
  );
}

/*
** Open the dynamic library located at zPath and return a handle.
*/
static void *instDlOpen(sqlite3_vfs *pVfs, const char *zPath){
  sqlite3_vfs *pRealVfs = (sqlite3_vfs*)pVfs->pAppData;
  return pRealVfs->xDlOpen(pRealVfs, zPath);
}

/*
** Populate the buffer zErrMsg (size nByte bytes) with a human readable
** utf-8 string describing the most recent error encountered associated 
** with dynamic libraries.
*/
static void instDlError(sqlite3_vfs *pVfs, int nByte, char *zErrMsg){
  sqlite3_vfs *pRealVfs = (sqlite3_vfs*)pVfs->pAppData;
  pRealVfs->xDlError(pRealVfs, nByte, zErrMsg);
}

/*
** Return a pointer to the symbol zSymbol in the dynamic library pHandle.
*/
static void *instDlSym(sqlite3_vfs *pVfs, void *pHandle, const char *zSymbol){
  sqlite3_vfs *pRealVfs = (sqlite3_vfs*)pVfs->pAppData;
  return pRealVfs->xDlSym(pRealVfs, pHandle, zSymbol);
}

/*
** Close the dynamic library handle pHandle.
*/
static void instDlClose(sqlite3_vfs *pVfs, void *pHandle){
  sqlite3_vfs *pRealVfs = (sqlite3_vfs*)pVfs->pAppData;
  pRealVfs->xDlClose(pRealVfs, pHandle);
}

/*
** Populate the buffer pointed to by zBufOut with nByte bytes of 
** random data.
*/
static int instRandomness(sqlite3_vfs *pVfs, int nByte, char *zBufOut){
  OS_TIME_VFS("xRandomness:  nByte=%d - %s%lld cycles\n", nByte, "",
    pRealVfs->xRandomness(pRealVfs, nByte, zBufOut)
  );
}

/*
** Sleep for nMicro microseconds. Return the number of microseconds 
** actually slept.
*/
static int instSleep(sqlite3_vfs *pVfs, int nMicro){
  OS_TIME_VFS("xSleep:  usec=%d - %s%lld cycles\n", nMicro, "",
    pRealVfs->xSleep(pRealVfs, nMicro) 
  );
}

/*
** Return the current time as a Julian Day number in *pTimeOut.
*/
static int instCurrentTime(sqlite3_vfs *pVfs, double *pTimeOut){
  OS_TIME_VFS("xCurrentTime:  %s%s%lld cycles\n", "", "",
    pRealVfs->xCurrentTime(pRealVfs, pTimeOut) 
  );
}

/*
** Insert the instructed VFS as the default VFS.
*/
static void setupInstrumentedVfs(void){
  sqlite3_vfs *p;
  sqlite3_vfs *pParent;

  pParent = sqlite3_vfs_find(0);
  if( !pParent ){
    return;
  }

  p = sqlite3_malloc(sizeof(inst_vfs));
  if( p ){
    *p = inst_vfs;
    p->szOsFile = pParent->szOsFile + sizeof(inst_file);
    p->mxPathname = pParent->mxPathname;
    p->pAppData = pParent;
    sqlite3_vfs_register(p, 1);
  }
}


/*
** Prepare and run a single statement of SQL.
*/
static void prepareAndRun(sqlite3 *db, const char *zSql){
static void prepareAndRun(sqlite3_vfs *pInstVfs, sqlite3 *db, const char *zSql){
  sqlite3_stmt *pStmt;
  const char *stmtTail;
  sqlite_uint64 iStart, iElapse;
  int rc;
  char zMessage[1024];
  zMessage[1023] = '\0';
  
  printf("****************************************************************\n");
  printf("SQL statement: [%s]\n", zSql);
  instTime = 0;
  iStart = sqlite3Hwtime();

  sqlite3_uint64 iTime;

  sqlite3_snprintf(1023, zMessage, "sqlite3_prepare_v2: %s", zSql);
  sqlite3_instvfs_binarylog_marker(pInstVfs, zMessage);

  iTime = sqlite3Hwtime();
  rc = sqlite3_prepare_v2(db, zSql, -1, &pStmt, &stmtTail);
  iElapse = sqlite3Hwtime();
  iElapse -= iStart + instTime;
  iTime = sqlite3Hwtime() - iTime;
  sqlite3_instvfs_binarylog_call(pInstVfs,BINARYLOG_PREPARE_V2,iTime,rc,zSql);

  prepTime += iElapse;
  printf("sqlite3_prepare_v2() returns %d in %llu cycles\n", rc, iElapse);
  if( rc==SQLITE_OK ){
    int nRow = 0;
    instTime = 0;
    iStart = sqlite3Hwtime();

    sqlite3_snprintf(1023, zMessage, "sqlite3_step loop: %s", zSql);
    sqlite3_instvfs_binarylog_marker(pInstVfs, zMessage);
    iTime = sqlite3Hwtime();
    while( (rc=sqlite3_step(pStmt))==SQLITE_ROW ){ nRow++; }
    iElapse = sqlite3Hwtime();
    iElapse -= iStart + instTime;
    iTime = sqlite3Hwtime() - iTime;
    sqlite3_instvfs_binarylog_call(pInstVfs, BINARYLOG_STEP, iTime, rc, zSql);

    runTime += iElapse;
    printf("sqlite3_step() returns %d after %d rows in %llu cycles\n",
    sqlite3_snprintf(1023, zMessage, "sqlite3_finalize: %s", zSql);
           rc, nRow, iElapse);
    instTime = 0;
    iStart = sqlite3Hwtime();
    sqlite3_instvfs_binarylog_marker(pInstVfs, zMessage);
    iTime = sqlite3Hwtime();
    rc = sqlite3_finalize(pStmt);
    iElapse = sqlite3Hwtime();
    iElapse -= iStart + instTime;
    finalizeTime += iElapse;
    printf("sqlite3_finalize() returns %d in %llu cycles\n", rc, iElapse);
    iTime = sqlite3Hwtime() - iTime;
    sqlite3_instvfs_binarylog_call(pInstVfs, BINARYLOG_FINALIZE, iTime, rc, zSql);
  }
}

static int stringcompare(const char *zLeft, const char *zRight){
  int ii;
  for(ii=0; zLeft[ii] && zRight[ii]; ii++){
    if( zLeft[ii]!=zRight[ii] ) return 0;
  }
  return( zLeft[ii]==zRight[ii] );
}

int main(int argc, char **argv){
  sqlite3 *db;
static char *readScriptFile(const char *zFile, int *pnScript){
  sqlite3_vfs *pVfs = sqlite3_vfs_find(0);
  sqlite3_file *p;
  int rc;
  int nSql;
  char *zSql;
  sqlite3_int64 nByte;
  char *zData = 0;
  int flags = SQLITE_OPEN_READONLY|SQLITE_OPEN_MAIN_DB;

  p = (sqlite3_file *)malloc(pVfs->szOsFile);
  rc = pVfs->xOpen(pVfs, zFile, p, flags, &flags);
  if( rc!=SQLITE_OK ){
    goto error_out;
  }

  rc = p->pMethods->xFileSize(p, &nByte);
  if( rc!=SQLITE_OK ){
    goto close_out;
  }

  zData = (char *)malloc(nByte+1);
  rc = p->pMethods->xRead(p, zData, nByte, 0);
  if( rc!=SQLITE_OK ){
    goto close_out;
  }
  zData[nByte] = '\0';

  p->pMethods->xClose(p);
  free(p);
  *pnScript = nByte;
  return zData;

close_out:
  p->pMethods->xClose(p);

error_out:
  free(p);
  free(zData);
  return 0;
}

int main(int argc, char **argv){

  const char zUsageMsg[] = 
    "Usage: %s options...\n"
    "  where available options are:\n"
    "\n"
    "    -db      DATABASE-FILE  (database file to operate on)\n"
    "    -script  SCRIPT-FILE    (script file to read sql from)\n"
    "    -log     LOG-FILE       (log file to create)\n"
    "    -logdata                (log all data to log file)\n"
    "\n"
    "  Options -db, -script and -log are compulsory\n"
    "\n"
  ;

  const char *zDb = 0;
  const char *zScript = 0;
  const char *zLog = 0;
  int logdata = 0;

  int ii;
  int i, j;
  FILE *in;
  sqlite_uint64 iStart, iElapse;
  sqlite_uint64 iSetup = 0;
  int nStmt = 0;
  int nByte = 0;
  int rc;

  sqlite3_vfs *pInstVfs;                 /* Instrumentation VFS */

  char *zSql = 0;
  int nSql;

  sqlite3 *db;

  for(ii=1; ii<argc; ii++){
    if( stringcompare("-db", argv[ii]) && (ii+1)<argc ){
  if( argc!=3 ){
    fprintf(stderr, "Usage: %s FILENAME SQL-SCRIPT\n"
                    "Runs SQL-SCRIPT against a UTF8 database\n",
                    argv[0]);
    exit(1);
  }
  in = fopen(argv[2], "r");
  fseek(in, 0L, SEEK_END);
  nSql = ftell(in);
  zSql = malloc( nSql+1 );
      zDb = argv[++ii];
    }

    else if( stringcompare("-script", argv[ii]) && (ii+1)<argc ){
      zScript = argv[++ii];
    }

    else if( stringcompare("-log", argv[ii]) && (ii+1)<argc ){
      zLog = argv[++ii];
    }

    else if( stringcompare("-logdata", argv[ii]) ){
      logdata = 1;
    }

    else {
      goto usage;
    }
  }
  if( !zDb || !zScript || !zLog ) goto usage;

  fseek(in, 0L, SEEK_SET);
  nSql = fread(zSql, 1, nSql, in);
  zSql[nSql] = 0;

  printf("SQLite version: %d\n", sqlite3_libversion_number());
  zSql = readScriptFile(zScript, &nSql);
  if( !zSql ){
    fprintf(stderr, "Failed to read script file\n");
    return -1;
  }

  unlink(argv[1]);
  setupInstrumentedVfs();
  instTime = 0;
  pInstVfs = sqlite3_instvfs_binarylog("logging", 0, zLog, logdata);

  iStart = sqlite3Hwtime();
  rc = sqlite3_open(argv[1], &db);
  iElapse = sqlite3Hwtime();
  rc = sqlite3_open_v2(
     zDb, &db, SQLITE_OPEN_READWRITE | SQLITE_OPEN_CREATE, "logging"
  );
  if( rc!=SQLITE_OK ){
    fprintf(stderr, "Failed to open db: %s\n", sqlite3_errmsg(db));
  iElapse -= iStart + instTime;
  iSetup = iElapse;
  printf("sqlite3_open() returns %d in %llu cycles\n", rc, iElapse);
    return -2;
  }

  for(i=j=0; j<nSql; j++){
    if( zSql[j]==';' ){
      int isComplete;
      char c = zSql[j+1];
      zSql[j+1] = 0;
      isComplete = sqlite3_complete(&zSql[i]);
      zSql[j+1] = c;
      if( isComplete ){
        zSql[j] = 0;
        while( i<j && isspace(zSql[i]) ){ i++; }
        if( i<j ){
          nStmt++;
          nByte += j-i;
          prepareAndRun(db, &zSql[i]);
          prepareAndRun(pInstVfs, db, &zSql[i]);
        }
        zSql[j] = ';';
        i = j+1;
      }
    }
  }
  instTime = 0;
  
  iStart = sqlite3Hwtime();
  sqlite3_close(db);
  sqlite3_instvfs_destroy(pInstVfs);
  iElapse = sqlite3Hwtime();
  iElapse -= iStart + instTime;
  iSetup += iElapse;
  printf("sqlite3_close() returns in %llu cycles\n", iElapse);
  printf("\n");
  return 0;
  
usage:
  fprintf(stderr, zUsageMsg, argv[0]);
  printf("Statements run:       %15d\n", nStmt);
  printf("Bytes of SQL text:    %15d\n", nByte);
  printf("Total prepare time:   %15llu cycles\n", prepTime);
  printf("Total run time:       %15llu cycles\n", runTime);
  printf("Total finalize time:  %15llu cycles\n", finalizeTime);
  printf("Open/Close time:      %15llu cycles\n", iSetup);
  printf("Total Time:           %15llu cycles\n",
      prepTime + runTime + finalizeTime + iSetup);
  return 0;
  return -3;
}