text: /*
  ** 2013-10-09
  **
  ** The author disclaims copyright to this source code.  In place of
  ** a legal notice, here is a blessing:
  **
  **    May you do good and not evil.
  **    May you find forgiveness for yourself and forgive others.
  **    May you share freely, never taking more than you give.
  **
  ******************************************************************************
  **
  ** This file contains the implementation of an SQLite vfs wrapper for
  ** unix that generates per-database log files of all disk activity.
  */
  
  /*
  ** This module contains code for a wrapper VFS that causes a log of
  ** most VFS calls to be written into a file on disk.
  **
  ** Each database connection creates a separate log file in the same
  ** directory as the original database and named after the original
  ** database.  A unique suffix is added to avoid name collisions.
  ** Separate log files are used so that concurrent processes do not
  ** try to write log operations to the same file at the same instant,
  ** resulting in overwritten or comingled log text.
  **
  ** Each individual log file records operations by a single database
  ** connection on both the original database and its associated rollback
  ** journal.
  **
  ** The log files are in the comma-separated-value (CSV) format.  The
  ** log files can be imported into an SQLite database using the ".import"
  ** command of the SQLite command-line shell for analysis.
  **
  ** One technique for using this module is to append the text of this
  ** module to the end of a standard "sqlite3.c" amalgamation file then
  ** add the following compile-time options:
  **
  **     -DSQLITE_EXTRA_INIT=sqlite3_register_vfslog
  **     -DSQLITE_USE_FCNTL_TRACE
  **
  ** The first compile-time option causes the sqlite3_register_vfslog()
  ** function, defined below, to be invoked when SQLite is initialized.
  ** That causes this custom VFS to become the default VFS for all
  ** subsequent connections.  The SQLITE_USE_FCNTL_TRACE option causes
  ** the SQLite core to issue extra sqlite3_file_control() operations
  ** with SQLITE_FCNTL_TRACE to give some indication of what is going
  ** on in the core.
  */
  
  #include "sqlite3.h"
  #include <assert.h>
  #include <stdio.h>
  #include <stdlib.h>
  #include <string.h>
  #if SQLITE_OS_UNIX
  #include <unistd.h>
  #endif
  
  #include "vfslog.h"
  #include <zlib.h>
  
  /*
  ** Log is flushed to gzip stream on 64kB boundary.
  */
  #define VFSLOG_GZIP_BLOCK_SIZE 65536
  
  static const char *const VLOG_OPNAME[] = {
      "CLOSE",
      "READ",
      "CHNGCTR_READ",
      "WRITE",
      "CHNGCTR_WRITE",
      "TRUNCATE",
      "SYNC",
      "FILESIZE",
      "LOCK",
      "UNLOCK",
      "CHECKRESERVEDLOCK",
      "FILECONTROL",
      "SECTORSIZE",
      "DEVCHAR",
      "SHMMAP",
      "SHMLOCK",
      "SHMUNMAP",
      "FETCH",
      "UNFETCH",
  
      "OPEN",
      "DELETE",
      "ACCESS",
  };
  
  volatile uint32_t vlogDefaultLogFlags =
      1 << VLOG_OP_CLOSE | 1 << VLOG_OP_READ | 1 << VLOG_OP_CHNGCTR_READ |
      1 << VLOG_OP_WRITE | 1 << VLOG_OP_CHNGCTR_WRITE | 1 << VLOG_OP_TRUNCATE |
      1 << VLOG_OP_SYNC | 1 << VLOG_OP_FILESIZE | 1 << VLOG_OP_OPEN |
      1 << VLOG_OP_DELETE;
  
  /*
  ** Forward declaration of objects used by this utility
  */
  typedef struct VLogLog VLogLog;
  typedef struct VLogVfs VLogVfs;
  typedef struct VLogFile VLogFile;
  
  /* There is a pair (an array of size 2) of the following objects for
  ** each database file being logged.  The first contains the filename
  ** and is used to log I/O with the main database.  The second has
  ** a NULL filename and is used to log I/O for the journal.  Both
  ** out pointers are the same.
  */
  struct VLogLog {
      VLogLog *pNext;   /* Next in a list of all active logs */
      VLogLog **ppPrev; /* Pointer to this in the list */
      int nRef;         /* Number of references to this object */
      int nFilename;    /* Length of zFilename in bytes */
      char *zFilename;  /* Name of database file.  NULL for journal */
      uint32_t flags;
      int64_t lastReadOfs;
      int64_t lastWriteOfs;
  
      FILE *tmpOut;
      gzFile gzOut;           /* Write gzip-ed logs here */
      sqlite3_mutex *gzMutex; /* Mutex to protect file handle above */
  };
  
  struct VLogVfs {
      sqlite3_vfs base;  /* VFS methods */
      sqlite3_vfs *pVfs; /* Parent VFS */
  };
  
  struct VLogFile {
      sqlite3_file base;   /* IO methods */
      sqlite3_file *pReal; /* Underlying file handle */
      VLogLog *pLog;       /* The log file for this file */
  };
  
  #define REALVFS(p) (((VLogVfs *) (p))->pVfs)
  
  /*
  ** Methods for VLogFile
  */
  static int vlogClose(sqlite3_file *);
  static int vlogRead(sqlite3_file *, void *, int iAmt, sqlite3_int64 iOfst);
  static int
  vlogWrite(sqlite3_file *, const void *, int iAmt, sqlite3_int64 iOfst);
  static int vlogTruncate(sqlite3_file *, sqlite3_int64 size);
  static int vlogSync(sqlite3_file *, int flags);
  static int vlogFileSize(sqlite3_file *, sqlite3_int64 *pSize);
  static int vlogLock(sqlite3_file *, int);
  static int vlogUnlock(sqlite3_file *, int);
  static int vlogCheckReservedLock(sqlite3_file *, int *pResOut);
  static int vlogFileControl(sqlite3_file *, int op, void *pArg);
  static int vlogSectorSize(sqlite3_file *);
  static int vlogDeviceCharacteristics(sqlite3_file *);
  static int vlogShmMap(sqlite3_file *, int, int, int, void volatile **);
  static int vlogShmLock(sqlite3_file *, int, int, int);
  static void vlogShmBarrier(sqlite3_file *);
  static int vlogShmUnmap(sqlite3_file *, int);
  static int vlogFetch(sqlite3_file *, sqlite3_int64, int, void **);
  static int vlogUnfetch(sqlite3_file *, sqlite3_int64, void *);
  
  /*
  ** Methods for VLogVfs
  */
  static int vlogOpen(sqlite3_vfs *, const char *, sqlite3_file *, int, int *);
  static int vlogDelete(sqlite3_vfs *, const char *zName, int syncDir);
  static int vlogAccess(sqlite3_vfs *, const char *zName, int flags, int *);
  static int vlogFullPathname(sqlite3_vfs *, const char *zName, int, char *zOut);
  static void *vlogDlOpen(sqlite3_vfs *, const char *zFilename);
  static void vlogDlError(sqlite3_vfs *, int nByte, char *zErrMsg);
  static void (*vlogDlSym(sqlite3_vfs *pVfs, void *p, const char *zSym))(void);
  static void vlogDlClose(sqlite3_vfs *, void *);
  static int vlogRandomness(sqlite3_vfs *, int nByte, char *zOut);
  static int vlogSleep(sqlite3_vfs *, int microseconds);
  static int vlogCurrentTime(sqlite3_vfs *, double *);
  static int vlogGetLastError(sqlite3_vfs *, int, char *);
  static int vlogCurrentTimeInt64(sqlite3_vfs *, sqlite3_int64 *);
  static int vlogSetSystemCall(sqlite3_vfs *, const char *, sqlite3_syscall_ptr);
  static sqlite3_syscall_ptr vlogGetSystemCall(sqlite3_vfs *, const char *);
  static const char *vlogNextSystemCall(sqlite3_vfs *, const char *);
  
  static VLogVfs vlog_vfs = {{
                                 3,        /* iVersion (set by register_vlog()) */
                                 0,        /* szOsFile (set by register_vlog()) */
                                 1024,     /* mxPathname */
                                 0,        /* pNext */
                                 "vfslog", /* zName */
                                 0,        /* pAppData */
                                 vlogOpen, /* xOpen */
                                 vlogDelete,           /* xDelete */
                                 vlogAccess,           /* xAccess */
                                 vlogFullPathname,     /* xFullPathname */
                                 vlogDlOpen,           /* xDlOpen */
                                 vlogDlError,          /* xDlError */
                                 vlogDlSym,            /* xDlSym */
                                 vlogDlClose,          /* xDlClose */
                                 vlogRandomness,       /* xRandomness */
                                 vlogSleep,            /* xSleep */
                                 vlogCurrentTime,      /* xCurrentTime */
                                 vlogGetLastError,     /* xGetLastError */
                                 vlogCurrentTimeInt64, /* xCurrentTimeInt64 */
                                 vlogSetSystemCall,    /* xSetSystemCall */
                                 vlogGetSystemCall,    /* xGetSystemCall */
                                 vlogNextSystemCall,   /* xNextSystemCall */
                             },
                             0};
  
  static sqlite3_io_methods vlog_io_methods = {
      3,                         /* iVersion */
      vlogClose,                 /* xClose */
      vlogRead,                  /* xRead */
      vlogWrite,                 /* xWrite */
      vlogTruncate,              /* xTruncate */
      vlogSync,                  /* xSync */
      vlogFileSize,              /* xFileSize */
      vlogLock,                  /* xLock */
      vlogUnlock,                /* xUnlock */
      vlogCheckReservedLock,     /* xCheckReservedLock */
      vlogFileControl,           /* xFileControl */
      vlogSectorSize,            /* xSectorSize */
      vlogDeviceCharacteristics, /* xDeviceCharacteristics */
      vlogShmMap,                /* xShmMap */
      vlogShmLock,               /* xShmLock */
      vlogShmBarrier,            /* xShmBarrier */
      vlogShmUnmap,              /* xShmUnmap */
      vlogFetch,                 /* xFetch */
      vlogUnfetch,               /* xUnfetch */
  };
  
  #if SQLITE_OS_UNIX && !defined(NO_GETTOD)
  #include <sys/time.h>
  static sqlite3_uint64 vlog_time()
  {
      struct timeval sTime;
      gettimeofday(&sTime, 0);
      return sTime.tv_usec + (sqlite3_uint64) sTime.tv_sec * 1000000;
  }
  #elif SQLITE_OS_WIN
  #include <time.h>
  #include <windows.h>
  static sqlite3_uint64 vlog_time()
  {
      FILETIME ft;
      sqlite3_uint64 u64time = 0;
  
      GetSystemTimeAsFileTime(&ft);
  
      u64time |= ft.dwHighDateTime;
      u64time <<= 32;
      u64time |= ft.dwLowDateTime;
  
      /* ft is 100-nanosecond intervals, we want microseconds */
      return u64time / (sqlite3_uint64) 10;
  }
  #else
  static sqlite3_uint64 vlog_time()
  {
      return 0;
  }
  #endif
  
  /*
  ** Write a message to the log file
  */
  static void vlogLogPrint(VLogLog *pLog,         /* The log file to write into */
                           sqlite3_int64 tStart,  /* Start time of system call */
                           sqlite3_int64 tElapse, /* Elapse time of system call */
                           VLogOp iOp,            /* Type of system call */
                           sqlite3_int64 iArg1,   /* First argument */
                           sqlite3_int64 iArg2,   /* Second argument */
                           const char *zArg3,     /* Third argument */
                           int iRes               /* Result */
                           )
  {
      if (!pLog || (pLog->flags & (1 << iOp)) == 0)
          return;
  
      char z1[40], z2[40], z3[1024];
      if (iArg1 >= 0) {
          sqlite3_snprintf(sizeof(z1), z1, "%lld", iArg1);
      } else {
          z1[0] = 0;
      }
      if (iArg2 >= 0) {
          sqlite3_snprintf(sizeof(z2), z2, "%lld", iArg2);
      } else {
          z2[0] = 0;
      }
      if (zArg3) {
          sqlite3_snprintf(sizeof(z3), z3, "\"%.*w\"", sizeof(z3) - 4, zArg3);
      } else {
          z3[0] = 0;
      }
  
      char buf[2048];
      int len = snprintf(buf, sizeof(buf), "%lld,%lld,%s,%d,%s,%s,%s,%d\n",
                         tStart, tElapse, VLOG_OPNAME[iOp], pLog->zFilename == 0,
                         z1, z2, z3, iRes);
  
      sqlite3_mutex_enter(pLog->gzMutex);
      fwrite(buf, 1, len, pLog->tmpOut);
      fflush(pLog->tmpOut);
      gzwrite(pLog->gzOut, buf, len);
      if (ftell(pLog->tmpOut) >= VFSLOG_GZIP_BLOCK_SIZE) {
          gzflush(pLog->gzOut, Z_FINISH);
          fseek(pLog->tmpOut, 0, SEEK_SET);
          ftruncate(fileno(pLog->tmpOut), 0);
      }
      sqlite3_mutex_leave(pLog->gzMutex);
  }
  
  /*
  ** List of all active log connections.  Protected by the master mutex.
  */
  static VLogLog *allLogs = 0;
  
  /*
  ** Close a VLogLog object
  */
  static void vlogLogClose(VLogLog *p)
  {
      if (p) {
          sqlite3_mutex *pMutex;
          p->nRef--;
          if (p->nRef > 0 || p->zFilename == 0)
              return;
          pMutex = sqlite3_mutex_alloc(SQLITE_MUTEX_STATIC_MASTER);
          sqlite3_mutex_enter(pMutex);
          *p->ppPrev = p->pNext;
          if (p->pNext)
              p->pNext->ppPrev = p->ppPrev;
          sqlite3_mutex_leave(pMutex);
  
          fclose(p->tmpOut);
          gzclose(p->gzOut);
          sqlite3_mutex_free(p->gzMutex);
          sqlite3_free(p);
      }
  }
  
  /*
  ** Open a VLogLog object on the given file
  */
  static VLogLog *vlogLogOpen(const char *zFilename)
  {
      int nName = (int) strlen(zFilename);
      int fileType = 0;
      sqlite3_mutex *pMutex;
      VLogLog *pLog, *pTemp;
      if (nName > 4 && strcmp(zFilename + nName - 4, "-wal") == 0) {
          nName -= 4;
          fileType = 1; /* wal */
      }
  
      if (nName > 8 && strcmp(zFilename + nName - 8, "-journal") == 0) {
          nName -= 8;
          fileType = 1; /* journal */
      } else if (nName > 12 &&
                 sqlite3_strglob("-mj??????9??", zFilename + nName - 12) == 0) {
          return 0; /* Do not log master journal files */
      }
  
      pTemp = sqlite3_malloc(sizeof(*pLog) * 2 + nName + 60);
      if (pTemp == 0)
          return 0;
      pMutex = sqlite3_mutex_alloc(SQLITE_MUTEX_STATIC_MASTER);
      sqlite3_mutex_enter(pMutex);
      for (pLog = allLogs; pLog; pLog = pLog->pNext) {
          if (pLog->nFilename == nName &&
              !memcmp(pLog->zFilename, zFilename, nName)) {
              break;
          }
      }
  
      if (pLog == 0) {
          pLog = pTemp;
          pTemp = 0;
          memset(pLog, 0, sizeof(*pLog) * 2);
          pLog->zFilename = (char *) &pLog[2];
          sqlite3_snprintf(nName + 60, pLog->zFilename, "%.*s-vfslog", nName,
                           zFilename);
  
          char *tmpName = alloca(nName + 60);
          sqlite3_snprintf(nName + 60, tmpName, "%.*s-vfslo1", nName, zFilename);
  
          pLog->tmpOut = fopen(tmpName, "ab+");
          pLog->gzOut = gzopen(pLog->zFilename, "ab");
          pLog->gzMutex = sqlite3_mutex_alloc(SQLITE_MUTEX_FAST);
          if (!pLog->tmpOut || !pLog->gzOut || !pLog->gzMutex) {
              if (pLog->tmpOut)
                  fclose(pLog->tmpOut);
              if (pLog->gzOut)
                  gzclose(pLog->gzOut);
              if (pLog->gzMutex)
                  sqlite3_mutex_free(pLog->gzMutex);
  
              sqlite3_mutex_leave(pMutex);
              sqlite3_free(pLog);
              return 0;
          }
  
          /* Flush existing content in tmpOut to gzOut */
          if (fseek(pLog->tmpOut, 0, SEEK_END) > 0) {
              fseek(pLog->tmpOut, 0, SEEK_SET);
              char buf[1024];
              int ret;
              while ((ret = fread(buf, 1, sizeof(buf), pLog->tmpOut)) >= 0) {
                  gzwrite(pLog->gzOut, buf, ret);
              }
              fseek(pLog->tmpOut, 0, SEEK_END);
          }
  
          pLog->nFilename = nName;
          pLog->flags = vlogDefaultLogFlags;
          pLog[1].tmpOut = pLog[0].tmpOut;
          pLog[1].gzOut = pLog[0].gzOut;
          pLog[1].gzMutex = pLog[0].gzMutex;
          pLog->ppPrev = &allLogs;
          if (allLogs)
              allLogs->ppPrev = &pLog->pNext;
          pLog->pNext = allLogs;
          allLogs = pLog;
      }
      sqlite3_mutex_leave(pMutex);
      if (pTemp) {
          sqlite3_free(pTemp);
      }
      if (pLog)
          pLog += fileType;
      pLog->nRef++;
  
      pLog->lastReadOfs = -1;
      pLog->lastWriteOfs = -1;
      return pLog;
  }
  
  /*
  ** Close an vlog-file.
  */
  static int vlogClose(sqlite3_file *pFile)
  {
      sqlite3_uint64 tStart, tElapse;
      int rc = SQLITE_OK;
      VLogFile *p = (VLogFile *) pFile;
  
      tStart = vlog_time();
      if (p->pReal->pMethods) {
          rc = p->pReal->pMethods->xClose(p->pReal);
      }
      tElapse = vlog_time() - tStart;
      vlogLogPrint(p->pLog, tStart, tElapse, VLOG_OP_CLOSE, -1, -1, 0, rc);
      vlogLogClose(p->pLog);
      return rc;
  }
  
  /*
  ** Compute signature for a block of content.
  **
  ** For blocks of 16 or fewer bytes, the signature is just a hex dump of
  ** the entire block.
  **
  ** For blocks of more than 16 bytes, the signature is a hex dump of the
  ** first 8 bytes followed by a 64-bit has of the entire block.
  */
  static void vlogSignature(unsigned char *p, int n, char *zCksum)
  {
      unsigned int s0 = 0, s1 = 0;
      unsigned int *pI;
      int i;
      if (n <= 16) {
          for (i = 0; i < n; i++)
              sqlite3_snprintf(3, zCksum + i * 2, "%02x", p[i]);
      } else {
          pI = (unsigned int *) p;
          for (i = 0; i < n - 7; i += 8) {
              s0 += pI[0] + s1;
              s1 += pI[1] + s0;
              pI += 2;
          }
          for (i = 0; i < 8; i++)
              sqlite3_snprintf(3, zCksum + i * 2, "%02x", p[i]);
          sqlite3_snprintf(18, zCksum + i * 2, "-%08x%08x", s0, s1);
      }
  }
  
  /*
  ** Convert a big-endian 32-bit integer into a native integer
  */
  static int bigToNative(const unsigned char *x)
  {
      return (x[0] << 24) + (x[1] << 16) + (x[2] << 8) + x[3];
  }
  
  /*
  ** Read data from an vlog-file.
  */
  static int
  vlogRead(sqlite3_file *pFile, void *zBuf, int iAmt, sqlite_int64 iOfst)
  {
      int rc;
      sqlite3_uint64 tStart, tElapse;
      VLogFile *p = (VLogFile *) pFile;
  
      tStart = vlog_time();
      rc = p->pReal->pMethods->xRead(p->pReal, zBuf, iAmt, iOfst);
      tElapse = vlog_time() - tStart;
  
      if (rc == SQLITE_OK && p->pLog && p->pLog->zFilename && iOfst <= 24 &&
          iOfst + iAmt >= 28) {
  
          unsigned char *x = ((unsigned char *) zBuf) + (24 - iOfst);
          unsigned iCtr, nFree = -1;
          char *zFree = 0;
          char zStr[12];
          iCtr = bigToNative(x);
          if (iOfst + iAmt >= 40) {
              zFree = zStr;
              sqlite3_snprintf(sizeof(zStr), zStr, "%d", bigToNative(x + 8));
              nFree = bigToNative(x + 12);
          }
  
          /* XXX: Values are meaningful only for plain-text databases */
          vlogLogPrint(p->pLog, tStart, tElapse, VLOG_OP_CHNGCTR_READ, iCtr,
                       nFree, zFree, 0);
      } else {
          char zSig[40];
          if (rc == SQLITE_OK) {
              vlogSignature(zBuf, iAmt, zSig);
          } else {
              zSig[0] = 0;
          }
  
          /* Record last read position */
          sqlite3_mutex_enter(p->pLog->gzMutex);
          p->pLog->lastReadOfs = iOfst;
          sqlite3_mutex_leave(p->pLog->gzMutex);
  
          vlogLogPrint(p->pLog, tStart, tElapse, VLOG_OP_READ, iAmt, iOfst, zSig,
                       rc);
      }
      return rc;
  }
  
  /*
  ** Write data to an vlog-file.
  */
  static int
  vlogWrite(sqlite3_file *pFile, const void *z, int iAmt, sqlite_int64 iOfst)
  {
      int rc;
      sqlite3_uint64 tStart, tElapse;
      VLogFile *p = (VLogFile *) pFile;
  
      tStart = vlog_time();
      rc = p->pReal->pMethods->xWrite(p->pReal, z, iAmt, iOfst);
      tElapse = vlog_time() - tStart;
  
      if (rc == SQLITE_OK && p->pLog && p->pLog->zFilename && iOfst <= 24 &&
          iOfst + iAmt >= 28) {
          unsigned char *x = ((unsigned char *) z) + (24 - iOfst);
          unsigned iCtr, nFree = -1;
          char *zFree = 0;
          char zStr[12];
          iCtr = bigToNative(x);
          if (iOfst + iAmt >= 40) {
              zFree = zStr;
              sqlite3_snprintf(sizeof(zStr), zStr, "%d", bigToNative(x + 8));
              nFree = bigToNative(x + 12);
          }
  
          /* XXX: Values are meaningful only for plain-text databases */
          vlogLogPrint(p->pLog, tStart, 0, VLOG_OP_CHNGCTR_WRITE, iCtr, nFree,
                       zFree, 0);
      } else {
          char zSig[40];
          vlogSignature((unsigned char *) z, iAmt, zSig);
  
          /* Record last write position */
          sqlite3_mutex_enter(p->pLog->gzMutex);
          p->pLog->lastWriteOfs = iOfst;
          sqlite3_mutex_leave(p->pLog->gzMutex);
  
          vlogLogPrint(p->pLog, tStart, tElapse, VLOG_OP_WRITE, iAmt, iOfst, zSig,
                       rc);
      }
      return rc;
  }
  
  /*
  ** Truncate an vlog-file.
  */
  static int vlogTruncate(sqlite3_file *pFile, sqlite_int64 size)
  {
      int rc;
      sqlite3_uint64 tStart, tElapse;
      VLogFile *p = (VLogFile *) pFile;
      tStart = vlog_time();
      rc = p->pReal->pMethods->xTruncate(p->pReal, size);
      tElapse = vlog_time() - tStart;
      vlogLogPrint(p->pLog, tStart, tElapse, VLOG_OP_TRUNCATE, size, -1, 0, rc);
      return rc;
  }
  
  /*
  ** Sync an vlog-file.
  */
  static int vlogSync(sqlite3_file *pFile, int flags)
  {
      int rc;
      sqlite3_uint64 tStart, tElapse;
      VLogFile *p = (VLogFile *) pFile;
      tStart = vlog_time();
      rc = p->pReal->pMethods->xSync(p->pReal, flags);
      tElapse = vlog_time() - tStart;
      vlogLogPrint(p->pLog, tStart, tElapse, VLOG_OP_SYNC, flags, -1, 0, rc);
      return rc;
  }
  
  /*
  ** Return the current file-size of an vlog-file.
  */
  static int vlogFileSize(sqlite3_file *pFile, sqlite_int64 *pSize)
  {
      int rc;
      sqlite3_uint64 tStart, tElapse;
      VLogFile *p = (VLogFile *) pFile;
      tStart = vlog_time();
      rc = p->pReal->pMethods->xFileSize(p->pReal, pSize);
      tElapse = vlog_time() - tStart;
      vlogLogPrint(p->pLog, tStart, tElapse, VLOG_OP_FILESIZE, *pSize, -1, 0, rc);
      return rc;
  }
  
  /*
  ** Lock an vlog-file.
  */
  static int vlogLock(sqlite3_file *pFile, int eLock)
  {
      int rc;
      sqlite3_uint64 tStart, tElapse;
      VLogFile *p = (VLogFile *) pFile;
      tStart = vlog_time();
      rc = p->pReal->pMethods->xLock(p->pReal, eLock);
      tElapse = vlog_time() - tStart;
      vlogLogPrint(p->pLog, tStart, tElapse, VLOG_OP_LOCK, eLock, -1, 0, rc);
      return rc;
  }
  
  /*
  ** Unlock an vlog-file.
  */
  static int vlogUnlock(sqlite3_file *pFile, int eLock)
  {
      int rc;
      sqlite3_uint64 tStart;
      VLogFile *p = (VLogFile *) pFile;
      tStart = vlog_time();
      vlogLogPrint(p->pLog, tStart, 0, VLOG_OP_UNLOCK, eLock, -1, 0, 0);
      rc = p->pReal->pMethods->xUnlock(p->pReal, eLock);
      return rc;
  }
  
  /*
  ** Check if another file-handle holds a RESERVED lock on an vlog-file.
  */
  static int vlogCheckReservedLock(sqlite3_file *pFile, int *pResOut)
  {
      int rc;
      sqlite3_uint64 tStart, tElapse;
      VLogFile *p = (VLogFile *) pFile;
      tStart = vlog_time();
      rc = p->pReal->pMethods->xCheckReservedLock(p->pReal, pResOut);
      tElapse = vlog_time() - tStart;
      vlogLogPrint(p->pLog, tStart, tElapse, VLOG_OP_CHECKRESERVEDLOCK, *pResOut,
                   -1, "", rc);
      return rc;
  }
  
  static int vlogFcntlStats(VLogFile *p, VLogStat *stats)
  {
      VLogLog *pLog = p->pLog;
  
      /* Ensure we are operating on the main DB file. */
      if (p->pLog->nFilename == 0)
          return SQLITE_ERROR;
  
      sqlite3_mutex_enter(pLog->gzMutex);
      stats->lastMainReadOffset = pLog->lastReadOfs;
      stats->lastMainWriteOffset = pLog->lastWriteOfs;
  
      /* Move to the journal file. */
      pLog++;
      stats->lastJournalReadOffset = pLog->lastReadOfs;
      stats->lastJournalWriteOffset = pLog->lastWriteOfs;
      sqlite3_mutex_leave(pLog->gzMutex);
  
      return SQLITE_OK;
  }
  
  /*
  ** File control method. For custom operations on an vlog-file.
  */
  static int vlogFileControl(sqlite3_file *pFile, int op, void *pArg)
  {
      VLogFile *p = (VLogFile *) pFile;
      if (op == SQLITE_FCNTL_VFSLOG_STAT) {
          return vlogFcntlStats(p, (VLogStat *) pArg);
      }
  
      sqlite3_uint64 tStart, tElapse;
      int rc;
      tStart = vlog_time();
      rc = p->pReal->pMethods->xFileControl(p->pReal, op, pArg);
      if (op == SQLITE_FCNTL_VFSNAME && rc == SQLITE_OK) {
          *(char **) pArg = sqlite3_mprintf("vlog/%z", *(char **) pArg);
      }
      tElapse = vlog_time() - tStart;
      if (op == SQLITE_FCNTL_TRACE) {
          vlogLogPrint(p->pLog, tStart, tElapse, VLOG_OP_FILECONTROL, op, -1,
                       pArg, rc);
      } else if (op == SQLITE_FCNTL_PRAGMA) {
          const char **azArg = (const char **) pArg;
          vlogLogPrint(p->pLog, tStart, tElapse, VLOG_OP_FILECONTROL, op, -1,
                       azArg[1], rc);
      } else if (op == SQLITE_FCNTL_SIZE_HINT) {
          sqlite3_int64 sz = *(sqlite3_int64 *) pArg;
          vlogLogPrint(p->pLog, tStart, tElapse, VLOG_OP_FILECONTROL, op, sz, 0,
                       rc);
      } else {
          vlogLogPrint(p->pLog, tStart, tElapse, VLOG_OP_FILECONTROL, op, -1, 0,
                       rc);
      }
      return rc;
  }
  
  /*
  ** Return the sector-size in bytes for an vlog-file.
  */
  static int vlogSectorSize(sqlite3_file *pFile)
  {
      int rc;
      sqlite3_uint64 tStart, tElapse;
      VLogFile *p = (VLogFile *) pFile;
      tStart = vlog_time();
      rc = p->pReal->pMethods->xSectorSize(p->pReal);
      tElapse = vlog_time() - tStart;
      vlogLogPrint(p->pLog, tStart, tElapse, VLOG_OP_SECTORSIZE, -1, -1, 0, rc);
      return rc;
  }
  
  /*
  ** Return the device characteristic flags supported by an vlog-file.
  */
  static int vlogDeviceCharacteristics(sqlite3_file *pFile)
  {
      int rc;
      sqlite3_uint64 tStart, tElapse;
      VLogFile *p = (VLogFile *) pFile;
      tStart = vlog_time();
      rc = p->pReal->pMethods->xDeviceCharacteristics(p->pReal);
      tElapse = vlog_time() - tStart;
      vlogLogPrint(p->pLog, tStart, tElapse, VLOG_OP_DEVCHAR, -1, -1, 0, rc);
      return rc;
  }
  
  static int vlogShmMap(sqlite3_file *pFile,
                        int iRegion,
                        int szRegion,
                        int bExtend,
                        void volatile **pp)
  {
      int rc;
      sqlite3_uint64 tStart, tElapse;
      VLogFile *p = (VLogFile *) pFile;
      tStart = vlog_time();
      rc = p->pReal->pMethods->xShmMap(p->pReal, iRegion, szRegion, bExtend, pp);
      tElapse = vlog_time() - tStart;
      vlogLogPrint(p->pLog, tStart, tElapse, VLOG_OP_SHMMAP, iRegion, szRegion, 0,
                   rc);
      return rc;
  }
  
  static int vlogShmLock(sqlite3_file *pFile, int offset, int n, int flags)
  {
      int rc;
      sqlite3_uint64 tStart, tElapse;
      VLogFile *p = (VLogFile *) pFile;
      tStart = vlog_time();
      rc = p->pReal->pMethods->xShmLock(p->pReal, offset, n, flags);
      tElapse = vlog_time() - tStart;
  
      const char *op = NULL;
      switch (flags) {
          case SQLITE_SHM_LOCK | SQLITE_SHM_SHARED:
              op = "LS";
              break;
          case SQLITE_SHM_LOCK | SQLITE_SHM_EXCLUSIVE:
              op = "LE";
              break;
          case SQLITE_SHM_UNLOCK | SQLITE_SHM_SHARED:
              op = "US";
              break;
          case SQLITE_SHM_UNLOCK | SQLITE_SHM_EXCLUSIVE:
              op = "UE";
              break;
      }
      vlogLogPrint(p->pLog, tStart, tElapse, VLOG_OP_SHMLOCK, offset, n, op, rc);
      return rc;
  }
  
  static void vlogShmBarrier(sqlite3_file *pFile)
  {
      // Bypass, no logging.
      VLogFile *p = (VLogFile *) pFile;
      return p->pReal->pMethods->xShmBarrier(p->pReal);
  }
  
  static int vlogShmUnmap(sqlite3_file *pFile, int deleteFlag)
  {
      int rc;
      sqlite3_uint64 tStart, tElapse;
      VLogFile *p = (VLogFile *) pFile;
      tStart = vlog_time();
      rc = p->pReal->pMethods->xShmUnmap(p->pReal, deleteFlag);
      tElapse = vlog_time() - tStart;
      vlogLogPrint(p->pLog, tStart, tElapse, VLOG_OP_SHMUNMAP, deleteFlag, -1, 0,
                   rc);
      return rc;
  }
  
  static int
  vlogFetch(sqlite3_file *pFile, sqlite3_int64 iOff, int nAmt, void **pp)
  {
      int rc;
      sqlite3_uint64 tStart, tElapse;
      VLogFile *p = (VLogFile *) pFile;
      tStart = vlog_time();
      rc = p->pReal->pMethods->xFetch(p->pReal, iOff, nAmt, pp);
      tElapse = vlog_time() - tStart;
      const char *result = pp ? "OK" : "Failed";
      vlogLogPrint(p->pLog, tStart, tElapse, VLOG_OP_FETCH, iOff, nAmt, result,
                   rc);
      return rc;
  }
  
  static int vlogUnfetch(sqlite3_file *pFile, sqlite3_int64 iOff, void *pp)
  {
      int rc;
      sqlite3_uint64 tStart, tElapse;
      VLogFile *p = (VLogFile *) pFile;
      tStart = vlog_time();
      rc = p->pReal->pMethods->xUnfetch(p->pReal, iOff, pp);
      tElapse = vlog_time() - tStart;
      vlogLogPrint(p->pLog, tStart, tElapse, VLOG_OP_UNFETCH, iOff, -1, 0, rc);
      return rc;
  }
  
  /*
  ** Open an vlog file handle.
  */
  static int vlogOpen(sqlite3_vfs *pVfs,
                      const char *zName,
                      sqlite3_file *pFile,
                      int flags,
                      int *pOutFlags)
  {
      int rc;
      sqlite3_uint64 tStart, tElapse;
      sqlite3_int64 iArg2;
      VLogFile *p = (VLogFile *) pFile;
  
      p->pReal = (sqlite3_file *) &p[1];
      if ((flags & (SQLITE_OPEN_MAIN_DB | SQLITE_OPEN_MAIN_JOURNAL |
                    SQLITE_OPEN_WAL)) != 0) {
          p->pLog = vlogLogOpen(zName);
      } else {
          p->pLog = 0;
      }
      tStart = vlog_time();
      rc = REALVFS(pVfs)->xOpen(REALVFS(pVfs), zName, p->pReal, flags, pOutFlags);
      tElapse = vlog_time() - tStart;
      iArg2 = pOutFlags ? *pOutFlags : -1;
      vlogLogPrint(p->pLog, tStart, tElapse, VLOG_OP_OPEN, flags, iArg2, 0, rc);
      if (rc == SQLITE_OK) {
          vlog_io_methods.iVersion = p->pReal->pMethods->iVersion;
          pFile->pMethods = &vlog_io_methods;
      } else {
          if (p->pLog)
              vlogLogClose(p->pLog);
          p->pLog = 0;
      }
      return rc;
  }
  
  /*
  ** 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 vlogDelete(sqlite3_vfs *pVfs, const char *zPath, int dirSync)
  {
      int rc;
      sqlite3_uint64 tStart, tElapse;
      VLogLog *pLog;
      tStart = vlog_time();
      rc = REALVFS(pVfs)->xDelete(REALVFS(pVfs), zPath, dirSync);
      tElapse = vlog_time() - tStart;
      pLog = vlogLogOpen(zPath);
      vlogLogPrint(pLog, tStart, tElapse, VLOG_OP_DELETE, dirSync, -1, 0, rc);
      vlogLogClose(pLog);
      return rc;
  }
  
  /*
  ** Test for access permissions. Return true if the requested permission
  ** is available, or false otherwise.
  */
  static int
  vlogAccess(sqlite3_vfs *pVfs, const char *zPath, int flags, int *pResOut)
  {
      int rc;
      sqlite3_uint64 tStart, tElapse;
      VLogLog *pLog;
      tStart = vlog_time();
      rc = REALVFS(pVfs)->xAccess(REALVFS(pVfs), zPath, flags, pResOut);
      tElapse = vlog_time() - tStart;
      pLog = vlogLogOpen(zPath);
      vlogLogPrint(pLog, tStart, tElapse, VLOG_OP_ACCESS, flags, *pResOut, 0, rc);
      vlogLogClose(pLog);
      return rc;
  }
  
  /*
  ** 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
  vlogFullPathname(sqlite3_vfs *pVfs, const char *zPath, int nOut, char *zOut)
  {
      return REALVFS(pVfs)->xFullPathname(REALVFS(pVfs), zPath, nOut, zOut);
  }
  
  /*
  ** Open the dynamic library located at zPath and return a handle.
  */
  static void *vlogDlOpen(sqlite3_vfs *pVfs, const char *zPath)
  {
      return REALVFS(pVfs)->xDlOpen(REALVFS(pVfs), 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 vlogDlError(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 (*vlogDlSym(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 vlogDlClose(sqlite3_vfs *pVfs, void *pHandle)
  {
      REALVFS(pVfs)->xDlClose(REALVFS(pVfs), pHandle);
  }
  
  /*
  ** Populate the buffer pointed to by zBufOut with nByte bytes of
  ** random data.
  */
  static int vlogRandomness(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 vlogSleep(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 vlogCurrentTime(sqlite3_vfs *pVfs, double *pTimeOut)
  {
      return REALVFS(pVfs)->xCurrentTime(REALVFS(pVfs), pTimeOut);
  }
  
  static int vlogGetLastError(sqlite3_vfs *pVfs, int a, char *b)
  {
      return REALVFS(pVfs)->xGetLastError(REALVFS(pVfs), a, b);
  }
  
  static int vlogCurrentTimeInt64(sqlite3_vfs *pVfs, sqlite3_int64 *p)
  {
      return REALVFS(pVfs)->xCurrentTimeInt64(REALVFS(pVfs), p);
  }
  
  static int vlogSetSystemCall(sqlite3_vfs *pVfs,
                               const char *zName,
                               sqlite3_syscall_ptr pSyscall)
  {
      return REALVFS(pVfs)->xSetSystemCall(pVfs, zName, pSyscall);
  }
  
  static sqlite3_syscall_ptr vlogGetSystemCall(sqlite3_vfs *pVfs,
                                               const char *zName)
  {
      return REALVFS(pVfs)->xGetSystemCall(pVfs, zName);
  }
  
  static const char *vlogNextSystemCall(sqlite3_vfs *pVfs, const char *zName)
  {
      return REALVFS(pVfs)->xNextSystemCall(pVfs, zName);
  }
  
  /*
  ** Register debugvfs as the default VFS for this process.
  */
  int sqlite3_register_vfslog(const char *zArg)
  {
      vlog_vfs.pVfs = sqlite3_vfs_find(0);
  
      vlog_vfs.base.iVersion = vlog_vfs.pVfs->iVersion;
      vlog_vfs.base.szOsFile = sizeof(VLogFile) + vlog_vfs.pVfs->szOsFile;
      return sqlite3_vfs_register(&vlog_vfs.base, 0);
  }
  
  int vlogGetStats(sqlite3 *db, const char *dbName, VLogStat *stats)
  {
      sqlite3_vfs *vfs;
      int rc = sqlite3_file_control(db, dbName, SQLITE_FCNTL_VFS_POINTER, &vfs);
      if (rc != SQLITE_OK)
          return rc;
      else if (!vfs->zName || strcmp(vfs->zName, "vfslog") != 0)
          return SQLITE_NOTFOUND;
  
      rc = sqlite3_file_control(db, dbName, SQLITE_FCNTL_VFSLOG_STAT, stats);
      return rc;
  }
  