Change the vfs instrumentation code in test_osinst.c to make it easier to deploy. Add a vtab implementation for reading the binary log file format.

FossilOrigin-Name: ee13c8849d234931bb3be36e42383d228b3cbfcb

1 files changed, 720 insertions, 705 deletions

diff --git a/src/test_osinst.c b/src/test_osinst.c
index 365da38d8..93aba75ed 100644
--- a/src/test_osinst.c
+++ b/src/test_osinst.c
@@ -15,87 +15,72 @@
 ** are provided to control the instrumentation.
 */
 
-#ifdef SQLITE_ENABLE_INSTVFS
+/* Public API: */
+int sqlite3_vfslog_new(const char *, const char *, const char *);
+int sqlite3_vfslog_finalize(const char *);
+int sqlite3_vfslog_register(sqlite3 *)
+
 /*
-** C interface:
-**
-**   sqlite3_instvfs_create()
-**   sqlite3_instvfs_destroy()
-**   sqlite3_instvfs_configure()
-**
-**   sqlite3_instvfs_reset()
-**   sqlite3_instvfs_get()
-**
-**   sqlite3_instvfs_binarylog
-**   sqlite3_instvfs_binarylog_marker
-**
-** Tcl interface (omitted if SQLITE_TEST is not set):
-** 
-**   sqlite3_instvfs create NAME ?PARENT?
+** This module contains code for a wrapper VFS that causes a log of
+** all (well, technically "most") VFS calls to be written into a nominated
+** file on disk. The log is stored in a compressed binary format to 
+** reduce the amount of IO overhead introduced into the application
+** by logging.
 **
-**       Create and register new vfs called $NAME, which is a wrapper around
-**       the existing vfs $PARENT. If the PARENT argument is omitted, the
-**       new vfs is a wrapper around the current default vfs.
+** The binary log files are read using a virtual table implementation
+** also contained in this file. 
 **
-**   sqlite3_instvfs destroy NAME
+** CREATING LOG FILES:
 **
-**       Deregister and destroy the vfs named $NAME, which must have been
-**       created by an earlier invocation of [sqlite3_instvfs create].
+**       int sqlite3_vfslog_new(
+**         const char *zVfs,          // Name of new VFS
+**         const char *zParentVfs,    // Name of parent VFS (or NULL)
+**         const char *zLog           // Name of log file to write to
+**       );
 **
-**   sqlite3_instvfs configure NAME SCRIPT
+**       int sqlite3_vfslog_finalize(const char *zVfs);
 **
-**       Configure the callback script for the vfs $NAME, which much have
-**       been created by an earlier invocation of [sqlite3_instvfs create].
-**       After a callback script has been configured, it is invoked each
-**       time a vfs or file method is called by SQLite. Before invoking
-**       the callback script, five arguments are appended to it:
+** READING LOG FILES:
 **
-**         * The name of the invoked method - i.e. "xRead".
+**   Log files are read using the "vfslog" virtual table implementation
+**   in this file. To register the virtual table with SQLite, use:
 **
-**         * The time consumed by the method call as measured by 
-**           sqlite3Hwtime() (an integer value)
+**       int sqlite3_vfslog_register(sqlite3 *db);
 **
-**         * A string value with a different meaning for different calls. 
-**           For file methods, the name of the file being operated on. For
-**           other methods it is the filename argument, if any.
+**   Then, if the log file is named "vfs.log", the following SQL command:
 **
-**         * A 32-bit integer value with a call-specific meaning.
+**       CREATE VIRTUAL TABLE v USING vfslog('vfs.log');
 **
-**         * A 64-bit integer value. For xRead() and xWrite() calls this
-**           is the file offset being written to or read from. Unused by
-**           all other calls.
+**   creates a virtual table with 6 columns, as follows:
 **
-**   sqlite3_instvfs reset NAME
+**       CREATE TABLE v(
+**         event    TEXT,             // "xOpen", "xRead" etc.
+**         file     TEXT,             // Name of file this call applies to
+**         clicks   INTEGER,          // Time spent in call
+**         rc       INTEGER,          // Return value
+**         size     INTEGER,          // Bytes read or written
+**         offset   INTEGER           // File offset read or written
+**       );
 **
-**       Zero the internal event counters associated with vfs $NAME, 
-**       which must have been created by an earlier invocation of 
-**       [sqlite3_instvfs create].
-**
-**   sqlite3_instvfs report NAME
-**
-**       Return the values of the internal event counters associated 
-**       with vfs $NAME. The report format is a list with one element
-**       for each method call (xWrite, xRead etc.). Each element is
-**       itself a list with three elements:
-**
-**         * The name of the method call - i.e. "xWrite",
-**         * The total number of calls to the method (an integer).
-**         * The aggregate time consumed by all calls to the method as
-**           measured by sqlite3Hwtime() (an integer).
 */
 
 #include "sqlite3.h"
 #include <string.h>
 #include <assert.h>
 
+/* 
+** hwtime.h contains inline assembler code for implementing 
+** high-performance timing routines.
+*/
+#include "hwtime.h"
+
+
 /*
-** Maximum pathname length supported by the inst backend.
+** Maximum pathname length supported by the vfslog backend.
 */
 #define INST_MAX_PATHNAME 512
 
 
-/* File methods */
-/* Vfs methods */
 #define OS_ACCESS            1
 #define OS_CHECKRESERVEDLOCK 2
 #define OS_CLOSE             3
@@ -125,271 +110,309 @@
 #define BINARYLOG_STEP       65
 #define BINARYLOG_FINALIZE   66
 
-struct InstVfs {
-  sqlite3_vfs base;
-  sqlite3_vfs *pVfs;
 
-  void *pClient;
-  void (*xDel)(void *);
-  void (*xCall)(void *, int, int, sqlite3_int64, int, const char *, int, int, sqlite3_int64);
+#define VFSLOG_BUFFERSIZE 8192
 
-  /* Counters */
-  sqlite3_int64 aTime[OS_NUMEVENTS];
-  int aCount[OS_NUMEVENTS];
+typedef struct VfslogVfs VfslogVfs;
+typedef struct VfslogFile VfslogFile;
 
-  int iNextFileId;
+struct VfslogVfs {
+  sqlite3_vfs base;               /* VFS methods */
+  sqlite3_vfs *pVfs;              /* Parent VFS */
+  int iNextFileId;                /* Next file id */
+  sqlite3_file *pLog;             /* Log file handle */
+  sqlite3_int64 iOffset;          /* Log file offset of start of write buffer */
+  int nBuf;                       /* Number of valid bytes in aBuf[] */
+  char aBuf[VFSLOG_BUFFERSIZE];   /* Write buffer */
 };
-typedef struct InstVfs InstVfs;
 
-#define REALVFS(p) (((InstVfs *)(p))->pVfs)
-
-typedef struct inst_file inst_file;
-struct inst_file {
-  sqlite3_file base;
-  sqlite3_file *pReal;
-  InstVfs *pInstVfs;
-  const char *zName;
-  int iFileId;               /* File id number */
-  int flags;
+struct VfslogFile {
+  sqlite3_file base;              /* IO methods */
+  sqlite3_file *pReal;            /* Underlying file handle */
+  sqlite3_vfs *pVfslog;           /* Associated VsflogVfs object */
+  int iFileId;                    /* File id number */
 };
 
+#define REALVFS(p) (((VfslogVfs *)(p))->pVfs)
+
+
+
 /*
-** Method declarations for inst_file.
+** Method declarations for vfslog_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*, int *pResOut);
-static int instFileControl(sqlite3_file*, int op, void *pArg);
-static int instSectorSize(sqlite3_file*);
-static int instDeviceCharacteristics(sqlite3_file*);
+static int vfslogClose(sqlite3_file*);
+static int vfslogRead(sqlite3_file*, void*, int iAmt, sqlite3_int64 iOfst);
+static int vfslogWrite(sqlite3_file*,const void*,int iAmt, sqlite3_int64 iOfst);
+static int vfslogTruncate(sqlite3_file*, sqlite3_int64 size);
+static int vfslogSync(sqlite3_file*, int flags);
+static int vfslogFileSize(sqlite3_file*, sqlite3_int64 *pSize);
+static int vfslogLock(sqlite3_file*, int);
+static int vfslogUnlock(sqlite3_file*, int);
+static int vfslogCheckReservedLock(sqlite3_file*, int *pResOut);
+static int vfslogFileControl(sqlite3_file*, int op, void *pArg);
+static int vfslogSectorSize(sqlite3_file*);
+static int vfslogDeviceCharacteristics(sqlite3_file*);
 
 /*
-** Method declarations for inst_vfs.
+** Method declarations for vfslog_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, int *);
-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 *pVfs, void *p, const char*zSym))(void);
-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 void binarylog_blob(sqlite3_vfs *, const char *, int, int); 
-
-static sqlite3_vfs inst_vfs = {
+static int vfslogOpen(sqlite3_vfs*, const char *, sqlite3_file*, int , int *);
+static int vfslogDelete(sqlite3_vfs*, const char *zName, int syncDir);
+static int vfslogAccess(sqlite3_vfs*, const char *zName, int flags, int *);
+static int vfslogFullPathname(sqlite3_vfs*, const char *zName, int, char *zOut);
+static void *vfslogDlOpen(sqlite3_vfs*, const char *zFilename);
+static void vfslogDlError(sqlite3_vfs*, int nByte, char *zErrMsg);
+static void (*vfslogDlSym(sqlite3_vfs *pVfs, void *p, const char*zSym))(void);
+static void vfslogDlClose(sqlite3_vfs*, void*);
+static int vfslogRandomness(sqlite3_vfs*, int nByte, char *zOut);
+static int vfslogSleep(sqlite3_vfs*, int microseconds);
+static int vfslogCurrentTime(sqlite3_vfs*, double*);
+
+static sqlite3_vfs vfslog_vfs = {
   1,                      /* iVersion */
-  sizeof(inst_file),      /* szOsFile */
+  sizeof(VfslogFile),     /* szOsFile */
   INST_MAX_PATHNAME,      /* mxPathname */
   0,                      /* pNext */
   0,                      /* zName */
   0,                      /* pAppData */
-  instOpen,               /* xOpen */
-  instDelete,             /* xDelete */
-  instAccess,             /* xAccess */
-  instFullPathname,       /* xFullPathname */
-  instDlOpen,             /* xDlOpen */
-  instDlError,            /* xDlError */
-  instDlSym,              /* xDlSym */
-  instDlClose,            /* xDlClose */
-  instRandomness,         /* xRandomness */
-  instSleep,              /* xSleep */
-  instCurrentTime,        /* xCurrentTime */
+  vfslogOpen,               /* xOpen */
+  vfslogDelete,             /* xDelete */
+  vfslogAccess,             /* xAccess */
+  vfslogFullPathname,       /* xFullPathname */
+  vfslogDlOpen,             /* xDlOpen */
+  vfslogDlError,            /* xDlError */
+  vfslogDlSym,              /* xDlSym */
+  vfslogDlClose,            /* xDlClose */
+  vfslogRandomness,         /* xRandomness */
+  vfslogSleep,              /* xSleep */
+  vfslogCurrentTime,        /* xCurrentTime */
 };
 
-static sqlite3_io_methods inst_io_methods = {
+static sqlite3_io_methods vfslog_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 */
+  vfslogClose,                      /* xClose */
+  vfslogRead,                       /* xRead */
+  vfslogWrite,                      /* xWrite */
+  vfslogTruncate,                   /* xTruncate */
+  vfslogSync,                       /* xSync */
+  vfslogFileSize,                   /* xFileSize */
+  vfslogLock,                       /* xLock */
+  vfslogUnlock,                     /* xUnlock */
+  vfslogCheckReservedLock,          /* xCheckReservedLock */
+  vfslogFileControl,                /* xFileControl */
+  vfslogSectorSize,                 /* xSectorSize */
+  vfslogDeviceCharacteristics       /* xDeviceCharacteristics */
 };
 
-/* 
-** hwtime.h contains inline assembler code for implementing 
-** high-performance timing routines.
-*/
-#include "hwtime.h"
-
-#define OS_TIME_IO(eEvent, A, B, Call) {     \
-  inst_file *p = (inst_file *)pFile;         \
-  InstVfs *pInstVfs = p->pInstVfs;           \
-  int rc;                                    \
-  sqlite_uint64 t = sqlite3Hwtime();         \
-  rc = Call;                                 \
-  t = sqlite3Hwtime() - t;                   \
-  pInstVfs->aTime[eEvent] += t;              \
-  pInstVfs->aCount[eEvent] += 1;             \
-  if( pInstVfs->xCall ){                     \
-    pInstVfs->xCall(                         \
-      pInstVfs->pClient,eEvent,p->iFileId,t,rc,p->zName,p->flags,A,B  \
-    );                                       \
-  }                                          \
-  return rc;                                 \
+static sqlite3_uint64 vfslog_time(){
+  return sqlite3Hwtime();
 }
 
-#define OS_TIME_VFS(eEvent, Z, flags, A, B, Call) {      \
-  InstVfs *pInstVfs = (InstVfs *)pVfs;   \
-  int rc;                                \
-  sqlite_uint64 t = sqlite3Hwtime();     \
-  rc = Call;                             \
-  t = sqlite3Hwtime() - t;               \
-  pInstVfs->aTime[eEvent] += t;          \
-  pInstVfs->aCount[eEvent] += 1;         \
-  if( pInstVfs->xCall ){                 \
-    pInstVfs->xCall(pInstVfs->pClient,eEvent,0, t, rc, Z, flags, A, B); \
-  }                                      \
-  return rc;                             \
-}
+static void vfslog_call(sqlite3_vfs *, int, int, int, int, int, int);
+static void vfslog_string(sqlite3_vfs *, const char *);
 
 /*
-** Close an inst-file.
+** Close an vfslog-file.
 */
-static int instClose(sqlite3_file *pFile){
-  OS_TIME_IO(OS_CLOSE, 0, 0, 
-    (p->pReal->pMethods ? p->pReal->pMethods->xClose(p->pReal) : SQLITE_OK)
-  );
+static int vfslogClose(sqlite3_file *pFile){
+  sqlite3_uint64 t;
+  int rc = SQLITE_OK;
+  VfslogFile *p = (VfslogFile *)pFile;
+
+  t = vfslog_time();
+  if( p->pReal->pMethods ){
+    rc = p->pReal->pMethods->xClose(p->pReal);
+  }
+  t = vfslog_time() - t;
+  vfslog_call(p->pVfslog, OS_CLOSE, p->iFileId, t, rc, 0, 0);
+  return rc;
 }
 
 /*
-** Read data from an inst-file.
+** Read data from an vfslog-file.
 */
-static int instRead(
+static int vfslogRead(
   sqlite3_file *pFile, 
   void *zBuf, 
   int iAmt, 
   sqlite_int64 iOfst
 ){
-  sqlite3_vfs *pVfs = (sqlite3_vfs *)(((inst_file *)pFile)->pInstVfs);
-  OS_TIME_IO(OS_READ, iAmt, (binarylog_blob(pVfs, zBuf, iAmt, 1), iOfst), 
-      p->pReal->pMethods->xRead(p->pReal, zBuf, iAmt, iOfst)
-  );
+  int rc;
+  sqlite3_uint64 t;
+  VfslogFile *p = (VfslogFile *)pFile;
+  t = vfslog_time();
+  rc = p->pReal->pMethods->xRead(p->pReal, zBuf, iAmt, iOfst);
+  t = vfslog_time() - t;
+  vfslog_call(p->pVfslog, OS_READ, p->iFileId, t, rc, iAmt, (int)iOfst);
+  return rc;
 }
 
 /*
-** Write data to an inst-file.
+** Write data to an vfslog-file.
 */
-static int instWrite(
+static int vfslogWrite(
   sqlite3_file *pFile,
   const void *z,
   int iAmt,
   sqlite_int64 iOfst
 ){
-  sqlite3_vfs *pVfs = (sqlite3_vfs *)(((inst_file *)pFile)->pInstVfs);
-  binarylog_blob(pVfs, z, iAmt, 1);
-  OS_TIME_IO(OS_WRITE, iAmt, iOfst, 
-      p->pReal->pMethods->xWrite(p->pReal, z, iAmt, iOfst)
-  );
+  int rc;
+  sqlite3_uint64 t;
+  VfslogFile *p = (VfslogFile *)pFile;
+  t = vfslog_time();
+  rc = p->pReal->pMethods->xWrite(p->pReal, z, iAmt, iOfst);
+  t = vfslog_time() - t;
+  vfslog_call(p->pVfslog, OS_WRITE, p->iFileId, t, rc, iAmt, (int)iOfst);
+  return rc;
 }
 
 /*
-** Truncate an inst-file.
+** Truncate an vfslog-file.
 */
-static int instTruncate(sqlite3_file *pFile, sqlite_int64 size){
-  OS_TIME_IO(OS_TRUNCATE, 0, (int)size, 
-    p->pReal->pMethods->xTruncate(p->pReal, size)
-  );
+static int vfslogTruncate(sqlite3_file *pFile, sqlite_int64 size){
+  int rc;
+  sqlite3_uint64 t;
+  VfslogFile *p = (VfslogFile *)pFile;
+  t = vfslog_time();
+  rc = p->pReal->pMethods->xTruncate(p->pReal, size);
+  t = vfslog_time() - t;
+  vfslog_call(p->pVfslog, OS_TRUNCATE, p->iFileId, t, rc, 0, (int)size);
+  return rc;
 }
 
 /*
-** Sync an inst-file.
+** Sync an vfslog-file.
 */
-static int instSync(sqlite3_file *pFile, int flags){
-  OS_TIME_IO(OS_SYNC, flags, 0, p->pReal->pMethods->xSync(p->pReal, flags));
+static int vfslogSync(sqlite3_file *pFile, int flags){
+  int rc;
+  sqlite3_uint64 t;
+  VfslogFile *p = (VfslogFile *)pFile;
+  t = vfslog_time();
+  rc = p->pReal->pMethods->xSync(p->pReal, flags);
+  t = vfslog_time() - t;
+  vfslog_call(p->pVfslog, OS_SYNC, p->iFileId, t, rc, flags, 0);
+  return rc;
 }
 
 /*
-** Return the current file-size of an inst-file.
+** Return the current file-size of an vfslog-file.
 */
-static int instFileSize(sqlite3_file *pFile, sqlite_int64 *pSize){
-  OS_TIME_IO(OS_FILESIZE, (int)(*pSize), 0, 
-    p->pReal->pMethods->xFileSize(p->pReal, pSize)
-  );
+static int vfslogFileSize(sqlite3_file *pFile, sqlite_int64 *pSize){
+  int rc;
+  sqlite3_uint64 t;
+  VfslogFile *p = (VfslogFile *)pFile;
+  t = vfslog_time();
+  rc = p->pReal->pMethods->xFileSize(p->pReal, pSize);
+  t = vfslog_time() - t;
+  vfslog_call(p->pVfslog, OS_FILESIZE, p->iFileId, t, rc, 0, (int)*pSize);
+  return rc;
 }
 
 /*
-** Lock an inst-file.
+** Lock an vfslog-file.
 */
-static int instLock(sqlite3_file *pFile, int eLock){
-  OS_TIME_IO(OS_LOCK, eLock, 0, p->pReal->pMethods->xLock(p->pReal, eLock));
+static int vfslogLock(sqlite3_file *pFile, int eLock){
+  int rc;
+  sqlite3_uint64 t;
+  VfslogFile *p = (VfslogFile *)pFile;
+  t = vfslog_time();
+  rc = p->pReal->pMethods->xLock(p->pReal, eLock);
+  t = vfslog_time() - t;
+  vfslog_call(p->pVfslog, OS_LOCK, p->iFileId, t, rc, eLock, 0);
+  return rc;
 }
 
 /*
-** Unlock an inst-file.
+** Unlock an vfslog-file.
 */
-static int instUnlock(sqlite3_file *pFile, int eLock){
-  OS_TIME_IO(OS_UNLOCK, eLock, 0, p->pReal->pMethods->xUnlock(p->pReal, eLock));
+static int vfslogUnlock(sqlite3_file *pFile, int eLock){
+  int rc;
+  sqlite3_uint64 t;
+  VfslogFile *p = (VfslogFile *)pFile;
+  t = vfslog_time();
+  rc = p->pReal->pMethods->xUnlock(p->pReal, eLock);
+  t = vfslog_time() - t;
+  vfslog_call(p->pVfslog, OS_UNLOCK, p->iFileId, t, rc, eLock, 0);
+  return rc;
 }
 
 /*
-** Check if another file-handle holds a RESERVED lock on an inst-file.
+** Check if another file-handle holds a RESERVED lock on an vfslog-file.
 */
-static int instCheckReservedLock(sqlite3_file *pFile, int *pResOut){
-  OS_TIME_IO(OS_CHECKRESERVEDLOCK, 0, 0, 
-      p->pReal->pMethods->xCheckReservedLock(p->pReal, pResOut)
-  );
+static int vfslogCheckReservedLock(sqlite3_file *pFile, int *pResOut){
+  int rc;
+  sqlite3_uint64 t;
+  VfslogFile *p = (VfslogFile *)pFile;
+  t = vfslog_time();
+  rc = p->pReal->pMethods->xCheckReservedLock(p->pReal, pResOut);
+  t = vfslog_time() - t;
+  vfslog_call(p->pVfslog, OS_CHECKRESERVEDLOCK, p->iFileId, t, rc, *pResOut, 0);
+  return rc;
 }
 
 /*
-** File control method. For custom operations on an inst-file.
+** File control method. For custom operations on an vfslog-file.
 */
-static int instFileControl(sqlite3_file *pFile, int op, void *pArg){
-  OS_TIME_IO(OS_FILECONTROL, 0, 0, p->pReal->pMethods->xFileControl(p->pReal, op, pArg));
+static int vfslogFileControl(sqlite3_file *pFile, int op, void *pArg){
+  VfslogFile *p = (VfslogFile *)pFile;
+  return p->pReal->pMethods->xFileControl(p->pReal, op, pArg);
 }
 
 /*
-** Return the sector-size in bytes for an inst-file.
+** Return the sector-size in bytes for an vfslog-file.
 */
-static int instSectorSize(sqlite3_file *pFile){
-  OS_TIME_IO(OS_SECTORSIZE, 0, 0, p->pReal->pMethods->xSectorSize(p->pReal));
+static int vfslogSectorSize(sqlite3_file *pFile){
+  int rc;
+  sqlite3_uint64 t;
+  VfslogFile *p = (VfslogFile *)pFile;
+  t = vfslog_time();
+  rc = p->pReal->pMethods->xSectorSize(p->pReal);
+  t = vfslog_time() - t;
+  vfslog_call(p->pVfslog, OS_SECTORSIZE, p->iFileId, t, rc, 0, 0);
+  return rc;
 }
 
 /*
-** Return the device characteristic flags supported by an inst-file.
+** Return the device characteristic flags supported by an vfslog-file.
 */
-static int instDeviceCharacteristics(sqlite3_file *pFile){
-  OS_TIME_IO(OS_DEVCHAR, 0, 0, p->pReal->pMethods->xDeviceCharacteristics(p->pReal));
+static int vfslogDeviceCharacteristics(sqlite3_file *pFile){
+  int rc;
+  sqlite3_uint64 t;
+  VfslogFile *p = (VfslogFile *)pFile;
+  t = vfslog_time();
+  rc = p->pReal->pMethods->xDeviceCharacteristics(p->pReal);
+  t = vfslog_time() - t;
+  vfslog_call(p->pVfslog, OS_DEVCHAR, p->iFileId, t, rc, 0, 0);
+  return rc;
 }
 
 /*
-** Open an inst file handle.
+** Open an vfslog file handle.
 */
-static int instOpen(
+static int vfslogOpen(
   sqlite3_vfs *pVfs,
   const char *zName,
   sqlite3_file *pFile,
   int flags,
   int *pOutFlags
 ){
-  inst_file *p = (inst_file *)pFile;
-  pFile->pMethods = &inst_io_methods;
+  int rc;
+  sqlite3_uint64 t;
+  VfslogFile *p = (VfslogFile *)pFile;
+  VfslogVfs *pLog = (VfslogVfs *)pVfs;
+
+  pFile->pMethods = &vfslog_io_methods;
   p->pReal = (sqlite3_file *)&p[1];
-  p->pInstVfs = (InstVfs *)pVfs;
-  p->zName = zName;
-  p->flags = flags;
-  p->iFileId = ++p->pInstVfs->iNextFileId;
-
-  binarylog_blob(pVfs, zName, -1, 0);
-  OS_TIME_VFS(OS_OPEN, zName, flags, p->iFileId, 0,
-    REALVFS(pVfs)->xOpen(REALVFS(pVfs), zName, p->pReal, flags, pOutFlags)
-  );
+  p->pVfslog = pVfs;
+  p->iFileId = ++pLog->iNextFileId;
+
+  t = vfslog_time();
+  rc = REALVFS(pVfs)->xOpen(REALVFS(pVfs), zName, p->pReal, flags, pOutFlags);
+  t = vfslog_time() - t;
+
+  vfslog_call(pVfs, OS_OPEN, p->iFileId, t, rc, 0, 0);
+  vfslog_string(pVfs, zName);
+  return rc;
 }
 
 /*
@@ -397,27 +420,35 @@ static int instOpen(
 ** ensure the file-system modifications are synced to disk before
 ** returning.
 */
-static int instDelete(sqlite3_vfs *pVfs, const char *zPath, int dirSync){
-  binarylog_blob(pVfs, zPath, -1, 0);
-  OS_TIME_VFS(OS_DELETE, zPath, 0, dirSync, 0,
-    REALVFS(pVfs)->xDelete(REALVFS(pVfs), zPath, dirSync) 
-  );
+static int vfslogDelete(sqlite3_vfs *pVfs, const char *zPath, int dirSync){
+  int rc;
+  sqlite3_uint64 t;
+  t = vfslog_time();
+  rc = REALVFS(pVfs)->xDelete(REALVFS(pVfs), zPath, dirSync);
+  t = vfslog_time() - t;
+  vfslog_call(pVfs, OS_DELETE, 0, t, rc, dirSync, 0);
+  vfslog_string(pVfs, zPath);
+  return rc;
 }
 
 /*
 ** Test for access permissions. Return true if the requested permission
 ** is available, or false otherwise.
 */
-static int instAccess(
+static int vfslogAccess(
   sqlite3_vfs *pVfs, 
   const char *zPath, 
   int flags, 
   int *pResOut
 ){
-  binarylog_blob(pVfs, zPath, -1, 0);
-  OS_TIME_VFS(OS_ACCESS, zPath, 0, flags, *pResOut, 
-    REALVFS(pVfs)->xAccess(REALVFS(pVfs), zPath, flags, pResOut) 
-  );
+  int rc;
+  sqlite3_uint64 t;
+  t = vfslog_time();
+  rc = REALVFS(pVfs)->xAccess(REALVFS(pVfs), zPath, flags, pResOut);
+  t = vfslog_time() - t;
+  vfslog_call(pVfs, OS_ACCESS, 0, t, rc, flags, *pResOut);
+  vfslog_string(pVfs, zPath);
+  return rc;
 }
 
 /*
@@ -425,21 +456,19 @@ static int instAccess(
 ** to the pathname in zPath. zOut is guaranteed to point to a buffer
 ** of at least (INST_MAX_PATHNAME+1) bytes.
 */
-static int instFullPathname(
+static int vfslogFullPathname(
   sqlite3_vfs *pVfs, 
   const char *zPath, 
   int nOut, 
   char *zOut
 ){
-  OS_TIME_VFS( OS_FULLPATHNAME, zPath, 0, 0, 0,
-    REALVFS(pVfs)->xFullPathname(REALVFS(pVfs), zPath, nOut, zOut);
-  );
+  return REALVFS(pVfs)->xFullPathname(REALVFS(pVfs), zPath, nOut, zOut);
 }
 
 /*
 ** Open the dynamic library located at zPath and return a handle.
 */
-static void *instDlOpen(sqlite3_vfs *pVfs, const char *zPath){
+static void *vfslogDlOpen(sqlite3_vfs *pVfs, const char *zPath){
   return REALVFS(pVfs)->xDlOpen(REALVFS(pVfs), zPath);
 }
 
@@ -448,21 +477,21 @@ static void *instDlOpen(sqlite3_vfs *pVfs, const char *zPath){
 ** utf-8 string describing the most recent error encountered associated 
 ** with dynamic libraries.
 */
-static void instDlError(sqlite3_vfs *pVfs, int nByte, char *zErrMsg){
+static void vfslogDlError(sqlite3_vfs *pVfs, int nByte, char *zErrMsg){
   REALVFS(pVfs)->xDlError(REALVFS(pVfs), nByte, zErrMsg);
 }
 
 /*
 ** Return a pointer to the symbol zSymbol in the dynamic library pHandle.
 */
-static void (*instDlSym(sqlite3_vfs *pVfs, void *p, const char *zSym))(void){
+static void (*vfslogDlSym(sqlite3_vfs *pVfs, void *p, const char *zSym))(void){
   return REALVFS(pVfs)->xDlSym(REALVFS(pVfs), p, zSym);
 }
 
 /*
 ** Close the dynamic library handle pHandle.
 */
-static void instDlClose(sqlite3_vfs *pVfs, void *pHandle){
+static void vfslogDlClose(sqlite3_vfs *pVfs, void *pHandle){
   REALVFS(pVfs)->xDlClose(REALVFS(pVfs), pHandle);
 }
 
@@ -470,99 +499,166 @@ static void instDlClose(sqlite3_vfs *pVfs, void *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( OS_RANDOMNESS, 0, 0, nByte, 0,
-    REALVFS(pVfs)->xRandomness(REALVFS(pVfs), nByte, zBufOut);
-  );
+static int vfslogRandomness(sqlite3_vfs *pVfs, int nByte, char *zBufOut){
+  return REALVFS(pVfs)->xRandomness(REALVFS(pVfs), nByte, zBufOut);
 }
 
 /*
 ** Sleep for nMicro microseconds. Return the number of microseconds 
 ** actually slept.
 */
-static int instSleep(sqlite3_vfs *pVfs, int nMicro){
-  OS_TIME_VFS( OS_SLEEP, 0, 0, nMicro, 0, 
-    REALVFS(pVfs)->xSleep(REALVFS(pVfs), nMicro) 
-  );
+static int vfslogSleep(sqlite3_vfs *pVfs, int nMicro){
+  return REALVFS(pVfs)->xSleep(REALVFS(pVfs), nMicro);
 }
 
 /*
 ** Return the current time as a Julian Day number in *pTimeOut.
 */
-static int instCurrentTime(sqlite3_vfs *pVfs, double *pTimeOut){
-  OS_TIME_VFS( OS_CURRENTTIME, 0, 0, 0, 0,
-    REALVFS(pVfs)->xCurrentTime(REALVFS(pVfs), pTimeOut) 
-  );
+static int vfslogCurrentTime(sqlite3_vfs *pVfs, double *pTimeOut){
+  return REALVFS(pVfs)->xCurrentTime(REALVFS(pVfs), pTimeOut);
 }
 
-sqlite3_vfs *sqlite3_instvfs_create(const char *zName, const char *zParent){
-  int nByte;
-  InstVfs *p;
-  sqlite3_vfs *pParent;
+static void vfslog_flush(VfslogVfs *p){
+#ifdef SQLITE_TEST
+  extern int sqlite3_io_error_pending;
+  extern int sqlite3_io_error_persist;
+  extern int sqlite3_diskfull_pending;
 
-  pParent = sqlite3_vfs_find(zParent);
-  if( !pParent ){
-    return 0;
-  }
+  int pending = sqlite3_io_error_pending;
+  int persist = sqlite3_io_error_persist;
+  int diskfull = sqlite3_diskfull_pending;
 
-  nByte = strlen(zName) + 1 + sizeof(InstVfs);
-  p = (InstVfs *)sqlite3_malloc(nByte);
-  if( p ){
-    char *zCopy = (char *)&p[1];
-    memset(p, 0, nByte);
-    memcpy(p, &inst_vfs, sizeof(sqlite3_vfs));
-    p->pVfs = pParent;
-    memcpy(zCopy, zName, strlen(zName));
-    p->base.zName = (const char *)zCopy;
-    p->base.szOsFile += pParent->szOsFile;
-    sqlite3_vfs_register((sqlite3_vfs *)p, 0);
+  sqlite3_io_error_pending = 0;
+  sqlite3_io_error_persist = 0;
+  sqlite3_diskfull_pending = 0;
+#endif
+
+  if( p->nBuf ){
+    p->pLog->pMethods->xWrite(p->pLog, p->aBuf, p->nBuf, p->iOffset);
+    p->iOffset += p->nBuf;
+    p->nBuf = 0;
   }
 
-  return (sqlite3_vfs *)p;
+#ifdef SQLITE_TEST
+  sqlite3_io_error_pending = pending;
+  sqlite3_io_error_persist = persist;
+  sqlite3_diskfull_pending = diskfull;
+#endif
 }
 
-void sqlite3_instvfs_configure(
+static void put32bits(unsigned char *p, unsigned int v){
+  p[0] = v>>24;
+  p[1] = v>>16;
+  p[2] = v>>8;
+  p[3] = v;
+}
+
+static void vfslog_call(
   sqlite3_vfs *pVfs,
-  void (*xCall)(
-      void*, 
-      int,                           /* File id */
-      int,                           /* Event code */
-      sqlite3_int64, 
-      int,                           /* Return code */
-      const char*,                   /* File name */
-      int, 
-      int, 
-      sqlite3_int64
-  ),
-  void *pClient,
-  void (*xDel)(void *)
+  int eEvent,
+  int iFileid,
+  int nClick,
+  int return_code,
+  int size,
+  int offset
 ){
-  InstVfs *p = (InstVfs *)pVfs;
-  assert( pVfs->xOpen==instOpen );
-  if( p->xDel ){
-    p->xDel(p->pClient);
+  VfslogVfs *p = (VfslogVfs *)pVfs;
+  unsigned char *zRec;
+  if( (24+p->nBuf)>sizeof(p->aBuf) ){
+    vfslog_flush(p);
+  }
+  zRec = (unsigned char *)&p->aBuf[p->nBuf];
+  put32bits(&zRec[0], eEvent);
+  put32bits(&zRec[4], iFileid);
+  put32bits(&zRec[8], nClick);
+  put32bits(&zRec[12], return_code);
+  put32bits(&zRec[16], size);
+  put32bits(&zRec[20], offset);
+  p->nBuf += 24;
+}
+
+static void vfslog_string(sqlite3_vfs *pVfs, const char *zStr){
+  VfslogVfs *p = (VfslogVfs *)pVfs;
+  unsigned char *zRec;
+  int nStr = zStr ? strlen(zStr) : 0;
+  if( (4+nStr+p->nBuf)>sizeof(p->aBuf) ){
+    vfslog_flush(p);
+  }
+  zRec = (unsigned char *)&p->aBuf[p->nBuf];
+  put32bits(&zRec[0], nStr);
+  if( zStr ){
+    memcpy(&zRec[4], zStr, nStr);
   }
-  p->xCall = xCall;
-  p->xDel = xDel;
-  p->pClient = pClient;
+  p->nBuf += (4 + nStr);
 }
 
-void sqlite3_instvfs_destroy(sqlite3_vfs *pVfs){
-  if( pVfs ){
-    sqlite3_vfs_unregister(pVfs);
-    sqlite3_instvfs_configure(pVfs, 0, 0, 0);
-    sqlite3_free(pVfs);
+static void vfslog_finalize(VfslogVfs *p){
+  if( p->pLog->pMethods ){
+    vfslog_flush(p);
+    p->pLog->pMethods->xClose(p->pLog);
   }
+  sqlite3_free(p);
+}
+
+int sqlite3_vfslog_finalize(const char *zVfs){
+  sqlite3_vfs *pVfs;
+  pVfs = sqlite3_vfs_find(zVfs);
+  if( !pVfs || pVfs->xOpen!=vfslogOpen ){
+    return SQLITE_ERROR;
+  } 
+  vfslog_finalize((VfslogVfs *)pVfs);
+  return SQLITE_OK;
 }
 
-void sqlite3_instvfs_reset(sqlite3_vfs *pVfs){
-  InstVfs *p = (InstVfs *)pVfs;
-  assert( pVfs->xOpen==instOpen );
-  memset(p->aTime, 0, sizeof(sqlite3_int64)*OS_NUMEVENTS);
-  memset(p->aCount, 0, sizeof(int)*OS_NUMEVENTS);
+int sqlite3_vfslog_new(
+  const char *zVfs,               /* New VFS name */
+  const char *zParentVfs,         /* Parent VFS name (or NULL) */
+  const char *zLog                /* Log file name */
+){
+  VfslogVfs *p;
+  sqlite3_vfs *pParent;
+  int nByte;
+  int flags;
+  int rc;
+  char *zFile;
+  int nVfs;
+
+  pParent = sqlite3_vfs_find(zParentVfs);
+  if( !pParent ){
+    return SQLITE_ERROR;
+  }
+
+  nVfs = strlen(zVfs);
+  nByte = sizeof(VfslogVfs) + pParent->szOsFile + nVfs+1+pParent->mxPathname+1;
+  p = (VfslogVfs *)sqlite3_malloc(nByte);
+  memset(p, 0, nByte);
+
+  p->pVfs = pParent;
+  p->pLog = (sqlite3_file *)&p[1];
+  memcpy(&p->base, &vfslog_vfs, sizeof(sqlite3_vfs));
+  p->base.zName = &((char *)p->pLog)[pParent->szOsFile];
+  p->base.szOsFile += pParent->szOsFile;
+  memcpy((char *)p->base.zName, zVfs, nVfs);
+
+  zFile = (char *)&p->base.zName[nVfs+1];
+  pParent->xFullPathname(pParent, zLog, pParent->mxPathname, zFile);
+
+  flags = SQLITE_OPEN_READWRITE|SQLITE_OPEN_CREATE|SQLITE_OPEN_MASTER_JOURNAL;
+  pParent->xDelete(pParent, zFile, 0);
+  rc = pParent->xOpen(pParent, zFile, p->pLog, flags, &flags);
+  if( rc==SQLITE_OK ){
+    memcpy(p->aBuf, "sqlite_ostrace1.....", 20);
+    p->iOffset = 0;
+    p->nBuf = 20;
+    rc = sqlite3_vfs_register((sqlite3_vfs *)p, 1);
+  }
+  if( rc ){
+    vfslog_finalize(p);
+  }
+  return rc;
 }
 
-const char *sqlite3_instvfs_name(int eEvent){
+static const char *vfslog_eventname(int eEvent){
   const char *zEvent = 0;
 
   switch( eEvent ){
@@ -574,10 +670,10 @@ const char *sqlite3_instvfs_name(int eEvent){
     case OS_FILESIZE:          zEvent = "xFilesize"; break;
     case OS_LOCK:              zEvent = "xLock"; break;
     case OS_UNLOCK:            zEvent = "xUnlock"; break;
-    case OS_CHECKRESERVEDLOCK: zEvent = "xCheckReservedLock"; break;
+    case OS_CHECKRESERVEDLOCK: zEvent = "xCheckResLock"; break;
     case OS_FILECONTROL:       zEvent = "xFileControl"; break;
     case OS_SECTORSIZE:        zEvent = "xSectorSize"; break;
-    case OS_DEVCHAR:           zEvent = "xDeviceCharacteristics"; break;
+    case OS_DEVCHAR:           zEvent = "xDeviceChar"; break;
     case OS_OPEN:              zEvent = "xOpen"; break;
     case OS_DELETE:            zEvent = "xDelete"; break;
     case OS_ACCESS:            zEvent = "xAccess"; break;
@@ -590,478 +686,397 @@ const char *sqlite3_instvfs_name(int eEvent){
   return zEvent;
 }
 
-void sqlite3_instvfs_get(
-  sqlite3_vfs *pVfs, 
-  int eEvent, 
-  const char **pzEvent, 
-  sqlite3_int64 *pnClick, 
-  int *pnCall
-){
-  InstVfs *p = (InstVfs *)pVfs;
-  assert( pVfs->xOpen==instOpen );
-  if( eEvent<1 || eEvent>=OS_NUMEVENTS ){
-    *pzEvent = 0;
-    *pnClick = 0;
-    *pnCall = 0;
-    return;
-  }
+typedef struct VfslogVtab VfslogVtab;
+typedef struct VfslogCsr VfslogCsr;
 
-  *pzEvent = sqlite3_instvfs_name(eEvent);
-  *pnClick = p->aTime[eEvent];
-  *pnCall = p->aCount[eEvent];
-}
-
-#define BINARYLOG_BUFFERSIZE 8192
+/*
+** Virtual table type for the vfslog reader module.
+*/
+struct VfslogVtab {
+  sqlite3_vtab base;              /* Base class */
+  sqlite3_file *pFd;              /* File descriptor open on vfslog file */
+  sqlite3_int64 nByte;            /* Size of file in bytes */
+  char *zFile;                    /* File name for pFd */
+};
 
-struct InstVfsBinaryLog {
-  int nBuf;
-  char *zBuf;
-  sqlite3_int64 iOffset;
-  int log_data;
-  sqlite3_file *pOut;
-  char *zOut;                       /* Log file name */
+/*
+** Virtual table cursor type for the vfslog reader module.
+*/
+struct VfslogCsr {
+  sqlite3_vtab_cursor base;       /* Base class */
+  sqlite3_int64 iRowid;           /* Current rowid. */
+  sqlite3_int64 iOffset;          /* Offset of next record in file */
+  char *zTransient;               /* Transient 'file' string */
+  int nFile;                      /* Size of array azFile[] */
+  char **azFile;                  /* File strings */
+  unsigned char aBuf[1024];       /* Current vfs log entry (read from file) */
 };
-typedef struct InstVfsBinaryLog InstVfsBinaryLog;
 
-static void put32bits(unsigned char *p, unsigned int v){
-  p[0] = v>>24;
-  p[1] = v>>16;
-  p[2] = v>>8;
-  p[3] = v;
+static unsigned int get32bits(unsigned char *p){
+  return (p[0]<<24) + (p[1]<<16) + (p[2]<<8) + p[3];
 }
 
-static void binarylog_flush(InstVfsBinaryLog *pLog){
-  sqlite3_file *pFile = pLog->pOut;
+/*
+** The argument must point to a buffer containing a nul-terminated string.
+** If the string begins with an SQL quote character it is overwritten by
+** the dequoted version. Otherwise the buffer is left unmodified.
+*/
+static void dequote(char *z){
+  char quote;                     /* Quote character (if any ) */
+  quote = z[0];
+  if( quote=='[' || quote=='\'' || quote=='"' || quote=='`' ){
+    int iIn = 1;                  /* Index of next byte to read from input */
+    int iOut = 0;                 /* Index of next byte to write to output */
+    if( quote=='[' ) quote = ']';  
+    while( z[iIn] ){
+      if( z[iIn]==quote ){
+        if( z[iIn+1]!=quote ) break;
+        z[iOut++] = quote;
+        iIn += 2;
+      }else{
+        z[iOut++] = z[iIn++];
+      }
+    }
+    z[iOut] = '\0';
+  }
+}
 
-#ifdef SQLITE_TEST
-  extern int sqlite3_io_error_pending;
-  extern int sqlite3_io_error_persist;
-  extern int sqlite3_diskfull_pending;
+/*
+** Connect to or create a vfslog virtual table.
+*/
+static int vlogConnect(
+  sqlite3 *db,
+  void *pAux,
+  int argc, const char *const*argv,
+  sqlite3_vtab **ppVtab,
+  char **pzErr
+){
+  sqlite3_vfs *pVfs;              /* VFS used to read log file */
+  int flags;                      /* flags passed to pVfs->xOpen() */
+  VfslogVtab *p;
+  int rc;
+  int nByte;
+  char *zFile;
 
-  int pending = sqlite3_io_error_pending;
-  int persist = sqlite3_io_error_persist;
-  int diskfull = sqlite3_diskfull_pending;
+  *ppVtab = 0;
+  pVfs = sqlite3_vfs_find(0);
+  nByte = sizeof(VfslogVtab) + pVfs->szOsFile + pVfs->mxPathname;
+  p = sqlite3_malloc(nByte);
+  if( p==0 ) return SQLITE_NOMEM;
+  memset(p, 0, nByte);
 
-  sqlite3_io_error_pending = 0;
-  sqlite3_io_error_persist = 0;
-  sqlite3_diskfull_pending = 0;
-#endif
+  p->pFd = (sqlite3_file *)&p[1];
+  p->zFile = &((char *)p->pFd)[pVfs->szOsFile];
 
-  pFile->pMethods->xWrite(pFile, pLog->zBuf, pLog->nBuf, pLog->iOffset);
-  pLog->iOffset += pLog->nBuf;
-  pLog->nBuf = 0;
+  zFile = sqlite3_mprintf("%s", argv[3]);
+  if( !zFile ){
+    sqlite3_free(p);
+    return SQLITE_NOMEM;
+  }
+  dequote(zFile);
+  pVfs->xFullPathname(pVfs, zFile, pVfs->mxPathname, p->zFile);
+  sqlite3_free(zFile);
 
-#ifdef SQLITE_TEST
-  sqlite3_io_error_pending = pending;
-  sqlite3_io_error_persist = persist;
-  sqlite3_diskfull_pending = diskfull;
-#endif
-}
+  flags = SQLITE_OPEN_READWRITE|SQLITE_OPEN_MASTER_JOURNAL;
+  rc = pVfs->xOpen(pVfs, p->zFile, p->pFd, flags, &flags);
 
-static void binarylog_xcall(
-  void *p,
-  int eEvent,
-  int iFileId,
-  sqlite3_int64 nClick,
-  int return_code,
-  const char *zName,
-  int flags,
-  int nByte,
-  sqlite3_int64 iOffset
-){
-  InstVfsBinaryLog *pLog = (InstVfsBinaryLog *)p;
-  unsigned char *zRec;
-  if( (28+pLog->nBuf)>BINARYLOG_BUFFERSIZE ){
-    binarylog_flush(pLog);
+  if( rc==SQLITE_OK ){
+    p->pFd->pMethods->xFileSize(p->pFd, &p->nByte);
+    sqlite3_declare_vtab(db, 
+        "CREATE TABLE xxx(event, file, click, rc, size, offset)"
+    );
+    *ppVtab = &p->base;
+  }else{
+    sqlite3_free(p);
   }
-  zRec = (unsigned char *)&pLog->zBuf[pLog->nBuf];
-  put32bits(&zRec[0], eEvent);
-  put32bits(&zRec[4], (int)iFileId);
-  put32bits(&zRec[8], (int)nClick);
-  put32bits(&zRec[12], return_code);
-  put32bits(&zRec[16], flags);
-  put32bits(&zRec[20], nByte);
-  put32bits(&zRec[24], (int)iOffset);
-  pLog->nBuf += 28;
+
+  return rc;
 }
 
-static void binarylog_xdel(void *p){
-  /* Close the log file and free the memory allocated for the 
-  ** InstVfsBinaryLog structure.
-  */
-  InstVfsBinaryLog *pLog = (InstVfsBinaryLog *)p;
-  sqlite3_file *pFile = pLog->pOut;
-  if( pLog->nBuf ){
-    binarylog_flush(pLog);
+/*
+** There is no "best-index". This virtual table always does a linear
+** scan of the binary VFS log file.
+*/
+static int vlogBestIndex(sqlite3_vtab *tab, sqlite3_index_info *pIdxInfo){
+  pIdxInfo->estimatedCost = 10.0;
+  return SQLITE_OK;
+}
+
+/*
+** Disconnect from or destroy a vfslog virtual table.
+*/
+static int vlogDisconnect(sqlite3_vtab *pVtab){
+  VfslogVtab *p = (VfslogVtab *)pVtab;
+  if( p->pFd->pMethods ){
+    p->pFd->pMethods->xClose(p->pFd);
+    p->pFd->pMethods = 0;
   }
-  pFile->pMethods->xClose(pFile);
-  sqlite3_free(pLog->pOut);
-  sqlite3_free(pLog->zBuf);
-  sqlite3_free(pLog);
+  sqlite3_free(p);
+  return SQLITE_OK;
 }
 
-static void binarylog_blob(
-  sqlite3_vfs *pVfs,
-  const char *zBlob,
-  int nBlob,
-  int isBinary
-){
-  InstVfsBinaryLog *pLog;
-  InstVfs *pInstVfs = (InstVfs *)pVfs;
+/*
+** Open a new vfslog cursor.
+*/
+static int vlogOpen(sqlite3_vtab *pVTab, sqlite3_vtab_cursor **ppCursor){
+  VfslogCsr *pCsr;                /* Newly allocated cursor object */
+
+  pCsr = sqlite3_malloc(sizeof(VfslogCsr));
+  if( !pCsr ) return SQLITE_NOMEM;
+  memset(pCsr, 0, sizeof(VfslogCsr));
+  *ppCursor = &pCsr->base;
+  return SQLITE_OK;
+}
 
-  if( pVfs->xOpen!=instOpen || pInstVfs->xCall!=binarylog_xcall ){
-    return;
+/*
+** Close a vfslog cursor.
+*/
+static int vlogClose(sqlite3_vtab_cursor *pCursor){
+  VfslogCsr *p = (VfslogCsr *)pCursor;
+  int i;
+  for(i=0; i<p->nFile; i++){
+    sqlite3_free(p->azFile[i]);
   }
-  pLog = (InstVfsBinaryLog *)pInstVfs->pClient;
-  if( zBlob && (!isBinary || pLog->log_data) ){
-    unsigned char *zRec;
-    int nWrite;
+  sqlite3_free(p->azFile);
+  sqlite3_free(p->zTransient);
+  sqlite3_free(p);
+  return SQLITE_OK;
+}
 
-    if( nBlob<0 ){
-      nBlob = strlen(zBlob);
-    }
-    nWrite = nBlob + 28;
-  
-    if( (nWrite+pLog->nBuf)>BINARYLOG_BUFFERSIZE ){
-      binarylog_flush(pLog);
+/*
+** Move a vfslog cursor to the next entry in the file.
+*/
+static int vlogNext(sqlite3_vtab_cursor *pCursor){
+  VfslogCsr *pCsr = (VfslogCsr *)pCursor;
+  VfslogVtab *p = (VfslogVtab *)pCursor->pVtab;
+  int rc = SQLITE_OK;
+  int nRead;
+
+  sqlite3_free(pCsr->zTransient);
+  pCsr->zTransient = 0;
+
+  nRead = 24;
+  if( pCsr->iOffset+nRead<=p->nByte ){
+    int eEvent;
+    rc = p->pFd->pMethods->xRead(p->pFd, pCsr->aBuf, nRead, pCsr->iOffset);
+
+    eEvent = get32bits(pCsr->aBuf);
+    if( (rc==SQLITE_OK)
+     && (eEvent==OS_OPEN || eEvent==OS_DELETE || eEvent==OS_ACCESS) 
+    ){
+      char buf[4];
+      rc = p->pFd->pMethods->xRead(p->pFd, buf, 4, pCsr->iOffset+nRead);
+      nRead += 4;
+      if( rc==SQLITE_OK ){
+        int nStr = get32bits((unsigned char *)buf);
+        char *zStr = sqlite3_malloc(nStr+1);
+        rc = p->pFd->pMethods->xRead(p->pFd, zStr, nStr, pCsr->iOffset+nRead);
+        zStr[nStr] = '\0';
+        nRead += nStr;
+
+        if( eEvent==OS_OPEN ){
+          int iFileid = get32bits(&pCsr->aBuf[4]);
+          if( iFileid>=pCsr->nFile ){
+            int nNew = sizeof(pCsr->azFile[0])*(iFileid+1);
+            pCsr->azFile = (char **)sqlite3_realloc(pCsr->azFile, nNew);
+            nNew -= sizeof(pCsr->azFile[0])*pCsr->nFile;
+            memset(&pCsr->azFile[pCsr->nFile], 0, nNew);
+            pCsr->nFile = iFileid+1;
+          }
+          sqlite3_free(pCsr->azFile[iFileid]);
+          pCsr->azFile[iFileid] = zStr;
+        }else{
+          pCsr->zTransient = zStr;
+        }
+      }
     }
-  
-    zRec = (unsigned char *)&pLog->zBuf[pLog->nBuf];
-    memset(zRec, 0, nWrite);
-    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;
+  pCsr->iRowid += 1;
+  pCsr->iOffset += nRead;
+  return rc;
+}
 
-  if( zString ){
-    binarylog_blob(pVfs, zString, -1, 0);
-  }
-  binarylog_xcall(pLog, eEvent, 0, nClick, return_code, 0, 0, 0, 0);
+static int vlogEof(sqlite3_vtab_cursor *pCursor){
+  VfslogCsr *pCsr = (VfslogCsr *)pCursor;
+  VfslogVtab *p = (VfslogVtab *)pCursor->pVtab;
+  return (pCsr->iOffset>=p->nByte);
 }
 
-void sqlite3_instvfs_binarylog_marker(
-  sqlite3_vfs *pVfs,
-  const char *zMarker
+static int vlogFilter(
+  sqlite3_vtab_cursor *pCursor, 
+  int idxNum, const char *idxStr,
+  int argc, sqlite3_value **argv
 ){
-  InstVfs *pInstVfs = (InstVfs *)pVfs;
-  InstVfsBinaryLog *pLog = (InstVfsBinaryLog *)pInstVfs->pClient;
-  binarylog_blob(pVfs, zMarker, -1, 0);
-  binarylog_xcall(pLog, BINARYLOG_MARKER, 0, 0, 0, 0, 0, 0, 0);
+  VfslogCsr *pCsr = (VfslogCsr *)pCursor;
+  pCsr->iRowid = 0;
+  pCsr->iOffset = 20;
+  return vlogNext(pCursor);
 }
 
-sqlite3_vfs *sqlite3_instvfs_binarylog(
-  const char *zVfs,
-  const char *zParentVfs, 
-  const char *zLog,
-  int log_data
+static int vlogColumn(
+  sqlite3_vtab_cursor *pCursor, 
+  sqlite3_context *ctx, 
+  int i
 ){
-  InstVfsBinaryLog *p;
-  sqlite3_vfs *pVfs;
-  sqlite3_vfs *pParent;
-  int nByte;
-  int flags;
-  int rc;
+  unsigned int val;
+  VfslogCsr *pCsr = (VfslogCsr *)pCursor;
 
-  pParent = sqlite3_vfs_find(zParentVfs);
-  if( !pParent ){
-    return 0;
-  }
+  assert( i<7 );
+  val = get32bits(&pCsr->aBuf[4*i]);
 
-  nByte = sizeof(InstVfsBinaryLog) + pParent->mxPathname+1;
-  p = (InstVfsBinaryLog *)sqlite3_malloc(nByte);
-  memset(p, 0, nByte);
-  p->zBuf = sqlite3_malloc(BINARYLOG_BUFFERSIZE);
-  p->zOut = (char *)&p[1];
-  p->pOut = (sqlite3_file *)sqlite3_malloc(pParent->szOsFile);
-  p->log_data = log_data;
-  pParent->xFullPathname(pParent, zLog, pParent->mxPathname, p->zOut);
-  flags = SQLITE_OPEN_READWRITE|SQLITE_OPEN_CREATE|SQLITE_OPEN_MASTER_JOURNAL;
-  pParent->xDelete(pParent, p->zOut, 0);
-  rc = pParent->xOpen(pParent, p->zOut, p->pOut, flags, &flags);
-  if( rc==SQLITE_OK ){
-    memcpy(p->zBuf, "sqlite_ostrace1.....", 20);
-    p->iOffset = 0;
-    p->nBuf = 20;
-  }
-  if( rc ){
-    binarylog_xdel(p);
-    return 0;
+  switch( i ){
+    case 0: {
+      sqlite3_result_text(ctx, vfslog_eventname(val), -1, SQLITE_STATIC);
+      break;
+    }
+    case 1: {
+      char *zStr = pCsr->zTransient;
+      if( val!=0 && val<pCsr->nFile ){
+        zStr = pCsr->azFile[val];
+      }
+      sqlite3_result_text(ctx, zStr, -1, SQLITE_TRANSIENT);
+      break;
+    }
+    default:
+      sqlite3_result_int(ctx, val);
+      break;
   }
 
-  pVfs = sqlite3_instvfs_create(zVfs, zParentVfs);
-  if( pVfs ){
-    sqlite3_instvfs_configure(pVfs, binarylog_xcall, p, binarylog_xdel);
-  }
+  return SQLITE_OK;
+}
+
+static int vlogRowid(sqlite3_vtab_cursor *pCursor, sqlite_int64 *pRowid){
+  VfslogCsr *pCsr = (VfslogCsr *)pCursor;
+  *pRowid = pCsr->iRowid;
+  return SQLITE_OK;
+}
 
-  return pVfs;
+int sqlite3_vfslog_register(sqlite3 *db){
+  static sqlite3_module vfslog_module = {
+    0,                            /* iVersion */
+    vlogConnect,                /* xCreate */
+    vlogConnect,                /* xConnect */
+    vlogBestIndex,              /* xBestIndex */
+    vlogDisconnect,             /* xDisconnect */
+    vlogDisconnect,             /* xDestroy */
+    vlogOpen,                   /* xOpen - open a cursor */
+    vlogClose,                  /* xClose - close a cursor */
+    vlogFilter,                 /* xFilter - configure scan constraints */
+    vlogNext,                   /* xNext - advance a cursor */
+    vlogEof,                    /* xEof - check for end of scan */
+    vlogColumn,                 /* xColumn - read data */
+    vlogRowid,                  /* xRowid - read data */
+    0,                            /* xUpdate */
+    0,                            /* xBegin */
+    0,                            /* xSync */
+    0,                            /* xCommit */
+    0,                            /* xRollback */
+    0,                            /* xFindMethod */
+    0,                            /* xRename */
+  };
+
+  sqlite3_create_module(db, "vfslog", &vfslog_module, 0);
+  return SQLITE_OK;
 }
-#endif /* SQLITE_ENABLE_INSTVFS */
+
 
 /**************************************************************************
 ***************************************************************************
 ** Tcl interface starts here.
 */
-#if SQLITE_TEST
 
-#include <tcl.h>
-
-#ifdef SQLITE_ENABLE_INSTVFS
-struct InstVfsCall {
-  Tcl_Interp *interp;
-  Tcl_Obj *pScript;
-};
-typedef struct InstVfsCall InstVfsCall;
-
-static void test_instvfs_xcall(
-  void *p,
-  int eEvent,
-  int iFileId,
-  sqlite3_int64 nClick,
-  int return_code,
-  const char *zName,
-  int flags,
-  int nByte,
-  sqlite3_int64 iOffset
-){
-  int rc;
-  InstVfsCall *pCall = (InstVfsCall *)p;
-  Tcl_Obj *pObj = Tcl_DuplicateObj( pCall->pScript);
-  const char *zEvent = sqlite3_instvfs_name(eEvent);
-
-  Tcl_IncrRefCount(pObj);
-  Tcl_ListObjAppendElement(0, pObj, Tcl_NewStringObj(zEvent, -1));
-  Tcl_ListObjAppendElement(0, pObj, Tcl_NewWideIntObj(nClick));
-  Tcl_ListObjAppendElement(0, pObj, Tcl_NewStringObj(zName, -1));
-  Tcl_ListObjAppendElement(0, pObj, Tcl_NewIntObj(nByte));
-  Tcl_ListObjAppendElement(0, pObj, Tcl_NewWideIntObj(iOffset));
-
-  rc = Tcl_EvalObjEx(pCall->interp, pObj, TCL_EVAL_GLOBAL|TCL_EVAL_DIRECT);
-  if( rc ){
-    Tcl_BackgroundError(pCall->interp);
-  }
-  Tcl_DecrRefCount(pObj);
-}
+#ifdef SQLITE_TEST
 
-static void test_instvfs_xdel(void *p){
-  InstVfsCall *pCall = (InstVfsCall *)p;
-  Tcl_DecrRefCount(pCall->pScript);
-  sqlite3_free(pCall);
-}
+#include <tcl.h>
 
-static int test_sqlite3_instvfs(
-  void * clientData,
+static int test_vfslog(
+  void *clientData,
   Tcl_Interp *interp,
   int objc,
   Tcl_Obj *CONST objv[]
 ){
-  static const char *IV_strs[] = 
-               { "create",  "destroy",  "reset",  "report", "configure", "binarylog", "marker", 0 };
-  enum IV_enum { IV_CREATE, IV_DESTROY, IV_RESET, IV_REPORT, IV_CONFIGURE, IV_BINARYLOG, IV_MARKER };
+  struct SqliteDb { sqlite3 *db; };
+  sqlite3 *db;
+  Tcl_CmdInfo cmdInfo;
+  int rc = SQLITE_ERROR;
+
+  static const char *strs[] = { "finalize", "new",  "register",  0 };
+  enum VL_enum { VL_FINALIZE, VL_NEW, VL_REGISTER };
   int iSub;
 
   if( objc<2 ){
     Tcl_WrongNumArgs(interp, 1, objv, "SUB-COMMAND ...");
+    return TCL_ERROR;
   }
-  if( Tcl_GetIndexFromObj(interp, objv[1], IV_strs, "sub-command", 0, &iSub) ){
+  if( Tcl_GetIndexFromObj(interp, objv[1], strs, "sub-command", 0, &iSub) ){
     return TCL_ERROR;
   }
 
-  switch( (enum IV_enum)iSub ){
-    case IV_CREATE: {
-      char *zParent = 0;
-      sqlite3_vfs *p;
-      int isDefault = 0;
-      if( objc>2 && 0==strcmp("-default", Tcl_GetString(objv[2])) ){
-        isDefault = 1;
-      }
-      if( (objc-isDefault)!=4 && (objc-isDefault)!=3 ){
-        Tcl_WrongNumArgs(interp, 2, objv, "?-default? NAME ?PARENT-VFS?");
-        return TCL_ERROR;
-      }
-      if( objc==(4+isDefault) ){
-        zParent = Tcl_GetString(objv[3+isDefault]);
-      }
-      p = sqlite3_instvfs_create(Tcl_GetString(objv[2+isDefault]), zParent);
-      if( !p ){
-        Tcl_AppendResult(interp, "error creating vfs ", 0);
-        return TCL_ERROR;
-      }
-      if( isDefault ){
-        sqlite3_vfs_register(p, 1);
-      }
-      Tcl_SetObjResult(interp, objv[2]);
-      break;
-    }
-    case IV_BINARYLOG: {
-      char *zName = 0;
-      char *zLog = 0;
-      char *zParent = 0;
-      sqlite3_vfs *p;
-      int isDefault = 0;
-      int isLogdata = 0;
-      int argbase = 2;
-
-      for(argbase=2; argbase<(objc-2); argbase++){
-        if( 0==strcmp("-default", Tcl_GetString(objv[argbase])) ){
-          isDefault = 1;
-        }
-        else if( 0==strcmp("-parent", Tcl_GetString(objv[argbase])) ){
-          argbase++;
-          zParent = Tcl_GetString(objv[argbase]);
-        }
-        else if( 0==strcmp("-logdata", Tcl_GetString(objv[argbase])) ){
-          isLogdata = 1;
-        }else{
-          break;
-        }
-      }
-
-      if( (objc-argbase)!=2 ){
-        Tcl_WrongNumArgs(
-            interp, 2, objv, "?-default? ?-parent VFS? ?-logdata? NAME LOGFILE"
-        );
-        return TCL_ERROR;
-      }
-      zName = Tcl_GetString(objv[argbase]);
-      zLog = Tcl_GetString(objv[argbase+1]);
-      p = sqlite3_instvfs_binarylog(zName, zParent, zLog, isLogdata);
-      if( !p ){
-        Tcl_AppendResult(interp, "error creating vfs ", 0);
-        return TCL_ERROR;
-      }
-      if( isDefault ){
-        sqlite3_vfs_register(p, 1);
-      }
-      Tcl_SetObjResult(interp, objv[2]);
-      break;
-    }
-
-    case IV_MARKER: {
-      sqlite3_vfs *p;
-      if( objc!=4 ){
-        Tcl_WrongNumArgs(interp, 2, objv, "VFS MARKER");
+  switch( (enum VL_enum)iSub ){
+    case VL_FINALIZE: {
+      int rc;
+      char *zVfs;
+      if( objc!=3 ){
+        Tcl_WrongNumArgs(interp, 2, objv, "VFS");
         return TCL_ERROR;
       }
-      p = sqlite3_vfs_find(Tcl_GetString(objv[2]));
-      if( !p || p->xOpen!=instOpen ){
-        Tcl_AppendResult(interp, "no such vfs: ", Tcl_GetString(objv[2]), 0);
+      zVfs = Tcl_GetString(objv[2]);
+      rc = sqlite3_vfslog_finalize(zVfs);
+      if( rc!=SQLITE_OK ){
+        Tcl_AppendResult(interp, "failed", 0);
         return TCL_ERROR;
       }
-      sqlite3_instvfs_binarylog_marker(p, Tcl_GetString(objv[3]));
-      Tcl_ResetResult(interp);
       break;
-    }
-
-    case IV_CONFIGURE: {
-      InstVfsCall *pCall;
-
-      sqlite3_vfs *p;
-      if( objc!=4 ){
-        Tcl_WrongNumArgs(interp, 2, objv, "NAME SCRIPT");
+    };
+
+    case VL_NEW: {
+      int rc;
+      char *zVfs;
+      char *zParent;
+      char *zLog;
+      if( objc!=5 ){
+        Tcl_WrongNumArgs(interp, 2, objv, "VFS PARENT LOGFILE");
         return TCL_ERROR;
       }
-      p = sqlite3_vfs_find(Tcl_GetString(objv[2]));
-      if( !p || p->xOpen!=instOpen ){
-        Tcl_AppendResult(interp, "no such vfs: ", Tcl_GetString(objv[2]), 0);
+      zVfs = Tcl_GetString(objv[2]);
+      zParent = Tcl_GetString(objv[3]);
+      zLog = Tcl_GetString(objv[4]);
+      if( *zParent=='\0' ) zParent = 0;
+      rc = sqlite3_vfslog_new(zVfs, zParent, zLog);
+      if( rc!=SQLITE_OK ){
+        Tcl_AppendResult(interp, "failed", 0);
         return TCL_ERROR;
       }
-
-      if( strlen(Tcl_GetString(objv[3])) ){
-        pCall = (InstVfsCall *)sqlite3_malloc(sizeof(InstVfsCall));
-        pCall->interp = interp;
-        pCall->pScript = Tcl_DuplicateObj(objv[3]);
-        Tcl_IncrRefCount(pCall->pScript);
-        sqlite3_instvfs_configure(p, 
-            test_instvfs_xcall, (void *)pCall, test_instvfs_xdel
-        );
-      }else{
-        sqlite3_instvfs_configure(p, 0, 0, 0);
-      }
       break;
-    }
+    };
 
-    case IV_REPORT:
-    case IV_DESTROY:
-    case IV_RESET: {
-      sqlite3_vfs *p;
+    case VL_REGISTER: {
+      char *zDb;
       if( objc!=3 ){
-        Tcl_WrongNumArgs(interp, 2, objv, "NAME");
+        Tcl_WrongNumArgs(interp, 2, objv, "DB");
         return TCL_ERROR;
       }
-      p = sqlite3_vfs_find(Tcl_GetString(objv[2]));
-      if( !p || p->xOpen!=instOpen ){
-        Tcl_AppendResult(interp, "no such vfs: ", Tcl_GetString(objv[2]), 0);
-        return TCL_ERROR;
+      zDb = Tcl_GetString(objv[2]);
+      if( Tcl_GetCommandInfo(interp, zDb, &cmdInfo) ){
+        db = ((struct SqliteDb*)cmdInfo.objClientData)->db;
+        rc = sqlite3_vfslog_register(db);
       }
-
-      if( ((enum IV_enum)iSub)==IV_DESTROY ){
-        sqlite3_instvfs_destroy(p);
-      }
-      if( ((enum IV_enum)iSub)==IV_RESET ){
-        sqlite3_instvfs_reset(p);
-      }
-      if( ((enum IV_enum)iSub)==IV_REPORT ){
-        int ii;
-        Tcl_Obj *pRet = Tcl_NewObj();
-
-        const char *zName = (char *)1;
-        sqlite3_int64 nClick;
-        int nCall;
-        for(ii=1; zName; ii++){
-          sqlite3_instvfs_get(p, ii, &zName, &nClick, &nCall);
-          if( zName ){
-            Tcl_Obj *pElem = Tcl_NewObj();
-            Tcl_ListObjAppendElement(0, pElem, Tcl_NewStringObj(zName, -1));
-            Tcl_ListObjAppendElement(0, pElem, Tcl_NewIntObj(nCall));
-            Tcl_ListObjAppendElement(0, pElem, Tcl_NewWideIntObj(nClick));
-            Tcl_ListObjAppendElement(0, pRet, pElem);
-          }
-        }
-
-        Tcl_SetObjResult(interp, pRet);
+      if( rc!=SQLITE_OK ){
+        Tcl_AppendResult(interp, "Bad sqlite3 handle: ", zDb, 0);
+        return TCL_ERROR;
       }
-
       break;
-    }
+    };
   }
 
   return TCL_OK;
 }
-#endif /* SQLITE_ENABLE_INSTVFS */
-
-/* Alternative implementation of sqlite3_instvfs when the real
-** implementation is unavailable. 
-*/
-#ifndef SQLITE_ENABLE_INSTVFS
-static int test_sqlite3_instvfs(
-  void * clientData,
-  Tcl_Interp *interp,
-  int objc,
-  Tcl_Obj *CONST objv[]
-){
-  Tcl_AppendResult(interp, 
-     "not compiled with -DSQLITE_ENABLE_INSTVFS; sqlite3_instvfs is "
-     "unavailable", (char*)0);
-  return TCL_ERROR;
-}
-#endif /* !defined(SQLITE_ENABLE_INSTVFS) */
 
 int SqlitetestOsinst_Init(Tcl_Interp *interp){
-  Tcl_CreateObjCommand(interp, "sqlite3_instvfs", test_sqlite3_instvfs, 0, 0);
+  Tcl_CreateObjCommand(interp, "vfslog", test_vfslog, 0, 0);
   return TCL_OK;
 }
 
 #endif /* SQLITE_TEST */
+