AryaWu/sqlite
0
1/*2** 2008 April 103**4** The author disclaims copyright to this source code. In place of5** a legal notice, here is a blessing:6**7** May you do good and not evil.8** May you find forgiveness for yourself and forgive others.9** May you share freely, never taking more than you give.10**11******************************************************************************12**13** This file contains the implementation of an SQLite vfs wrapper that14** adds instrumentation to all vfs and file methods. C and Tcl interfaces15** are provided to control the instrumentation.16*/17 18/*19** This module contains code for a wrapper VFS that causes a log of20** most VFS calls to be written into a nominated file on disk. The log 21** is stored in a compressed binary format to reduce the amount of IO 22** overhead introduced into the application by logging.23**24** All calls on sqlite3_file objects except xFileControl() are logged.25** Additionally, calls to the xAccess(), xOpen(), and xDelete()26** methods are logged. The other sqlite3_vfs object methods (xDlXXX,27** xRandomness, xSleep, xCurrentTime, xGetLastError and xCurrentTimeInt64) 28** are not logged.29**30** The binary log files are read using a virtual table implementation31** also contained in this file. 32**33** CREATING LOG FILES:34**35** int sqlite3_vfslog_new(36** const char *zVfs, // Name of new VFS37** const char *zParentVfs, // Name of parent VFS (or NULL)38** const char *zLog // Name of log file to write to39** );40**41** int sqlite3_vfslog_finalize(const char *zVfs);42**43** ANNOTATING LOG FILES:44**45** To write an arbitrary message into a log file:46**47** int sqlite3_vfslog_annotate(const char *zVfs, const char *zMsg);48**49** READING LOG FILES:50**51** Log files are read using the "vfslog" virtual table implementation52** in this file. To register the virtual table with SQLite, use:53**54** int sqlite3_vfslog_register(sqlite3 *db);55**56** Then, if the log file is named "vfs.log", the following SQL command:57**58** CREATE VIRTUAL TABLE v USING vfslog('vfs.log');59**60** creates a virtual table with 6 columns, as follows:61**62** CREATE TABLE v(63** event TEXT, // "xOpen", "xRead" etc.64** file TEXT, // Name of file this call applies to65** clicks INTEGER, // Time spent in call66** rc INTEGER, // Return value67** size INTEGER, // Bytes read or written68** offset INTEGER // File offset read or written69** );70*/71 72#include "sqlite3.h"73 74#ifdef _WIN3275#include <windows.h>76#endif77 78#include <string.h>79#include <assert.h>80 81 82/*83** Maximum pathname length supported by the vfslog backend.84*/85#define INST_MAX_PATHNAME 51286 87#define OS_ACCESS 188#define OS_CHECKRESERVEDLOCK 289#define OS_CLOSE 390#define OS_CURRENTTIME 491#define OS_DELETE 592#define OS_DEVCHAR 693#define OS_FILECONTROL 794#define OS_FILESIZE 895#define OS_FULLPATHNAME 996#define OS_LOCK 1197#define OS_OPEN 1298#define OS_RANDOMNESS 1399#define OS_READ 14 100#define OS_SECTORSIZE 15101#define OS_SLEEP 16102#define OS_SYNC 17103#define OS_TRUNCATE 18104#define OS_UNLOCK 19105#define OS_WRITE 20106#define OS_SHMUNMAP 22107#define OS_SHMMAP 23108#define OS_SHMLOCK 25109#define OS_SHMBARRIER 26110#define OS_ANNOTATE 28111 112#define OS_NUMEVENTS 29113 114#define VFSLOG_BUFFERSIZE 8192115 116typedef struct VfslogVfs VfslogVfs;117typedef struct VfslogFile VfslogFile;118 119struct VfslogVfs {120 sqlite3_vfs base; /* VFS methods */121 sqlite3_vfs *pVfs; /* Parent VFS */122 int iNextFileId; /* Next file id */123 sqlite3_file *pLog; /* Log file handle */124 sqlite3_int64 iOffset; /* Log file offset of start of write buffer */125 int nBuf; /* Number of valid bytes in aBuf[] */126 char aBuf[VFSLOG_BUFFERSIZE]; /* Write buffer */127};128 129struct VfslogFile {130 sqlite3_file base; /* IO methods */131 sqlite3_file *pReal; /* Underlying file handle */132 sqlite3_vfs *pVfslog; /* Associated VsflogVfs object */133 int iFileId; /* File id number */134};135 136#define REALVFS(p) (((VfslogVfs *)(p))->pVfs)137 138 139 140/*141** Method declarations for vfslog_file.142*/143static int vfslogClose(sqlite3_file*);144static int vfslogRead(sqlite3_file*, void*, int iAmt, sqlite3_int64 iOfst);145static int vfslogWrite(sqlite3_file*,const void*,int iAmt, sqlite3_int64 iOfst);146static int vfslogTruncate(sqlite3_file*, sqlite3_int64 size);147static int vfslogSync(sqlite3_file*, int flags);148static int vfslogFileSize(sqlite3_file*, sqlite3_int64 *pSize);149static int vfslogLock(sqlite3_file*, int);150static int vfslogUnlock(sqlite3_file*, int);151static int vfslogCheckReservedLock(sqlite3_file*, int *pResOut);152static int vfslogFileControl(sqlite3_file*, int op, void *pArg);153static int vfslogSectorSize(sqlite3_file*);154static int vfslogDeviceCharacteristics(sqlite3_file*);155 156static int vfslogShmLock(sqlite3_file *pFile, int ofst, int n, int flags);157static int vfslogShmMap(sqlite3_file *pFile,int,int,int,volatile void **);158static void vfslogShmBarrier(sqlite3_file*);159static int vfslogShmUnmap(sqlite3_file *pFile, int deleteFlag);160 161/*162** Method declarations for vfslog_vfs.163*/164static int vfslogOpen(sqlite3_vfs*, const char *, sqlite3_file*, int , int *);165static int vfslogDelete(sqlite3_vfs*, const char *zName, int syncDir);166static int vfslogAccess(sqlite3_vfs*, const char *zName, int flags, int *);167static int vfslogFullPathname(sqlite3_vfs*, const char *zName, int, char *zOut);168static void *vfslogDlOpen(sqlite3_vfs*, const char *zFilename);169static void vfslogDlError(sqlite3_vfs*, int nByte, char *zErrMsg);170static void (*vfslogDlSym(sqlite3_vfs *pVfs, void *p, const char*zSym))(void);171static void vfslogDlClose(sqlite3_vfs*, void*);172static int vfslogRandomness(sqlite3_vfs*, int nByte, char *zOut);173static int vfslogSleep(sqlite3_vfs*, int microseconds);174static int vfslogCurrentTime(sqlite3_vfs*, double*);175 176static int vfslogGetLastError(sqlite3_vfs*, int, char *);177static int vfslogCurrentTimeInt64(sqlite3_vfs*, sqlite3_int64*);178 179static sqlite3_vfs vfslog_vfs = {180 1, /* iVersion */181 sizeof(VfslogFile), /* szOsFile */182 INST_MAX_PATHNAME, /* mxPathname */183 0, /* pNext */184 0, /* zName */185 0, /* pAppData */186 vfslogOpen, /* xOpen */187 vfslogDelete, /* xDelete */188 vfslogAccess, /* xAccess */189 vfslogFullPathname, /* xFullPathname */190 vfslogDlOpen, /* xDlOpen */191 vfslogDlError, /* xDlError */192 vfslogDlSym, /* xDlSym */193 vfslogDlClose, /* xDlClose */194 vfslogRandomness, /* xRandomness */195 vfslogSleep, /* xSleep */196 vfslogCurrentTime, /* xCurrentTime */197 vfslogGetLastError, /* xGetLastError */198 vfslogCurrentTimeInt64 /* xCurrentTime */199};200 201static sqlite3_io_methods vfslog_io_methods = {202 2, /* iVersion */203 vfslogClose, /* xClose */204 vfslogRead, /* xRead */205 vfslogWrite, /* xWrite */206 vfslogTruncate, /* xTruncate */207 vfslogSync, /* xSync */208 vfslogFileSize, /* xFileSize */209 vfslogLock, /* xLock */210 vfslogUnlock, /* xUnlock */211 vfslogCheckReservedLock, /* xCheckReservedLock */212 vfslogFileControl, /* xFileControl */213 vfslogSectorSize, /* xSectorSize */214 vfslogDeviceCharacteristics, /* xDeviceCharacteristics */215 vfslogShmMap, /* xShmMap */216 vfslogShmLock, /* xShmLock */217 vfslogShmBarrier, /* xShmBarrier */218 vfslogShmUnmap /* xShmUnmap */219};220 221#ifdef _WIN32222#include <time.h>223static sqlite3_uint64 vfslog_time(){224 FILETIME ft;225 sqlite3_uint64 u64time = 0;226 227 GetSystemTimeAsFileTime(&ft);228 229 u64time |= ft.dwHighDateTime;230 u64time <<= 32;231 u64time |= ft.dwLowDateTime;232 233 /* ft is 100-nanosecond intervals, we want microseconds */234 return u64time /(sqlite3_uint64)10;235}236#elif !defined(NO_GETTOD)237#include <sys/time.h>238static sqlite3_uint64 vfslog_time(){239 struct timeval sTime;240 gettimeofday(&sTime, 0);241 return sTime.tv_usec + (sqlite3_uint64)sTime.tv_sec * 1000000;242}243#else244static sqlite3_uint64 vfslog_time(){245 return 0;246}247#endif248 249static void vfslog_call(sqlite3_vfs *, int, int, sqlite3_int64, int, int, int);250static void vfslog_string(sqlite3_vfs *, const char *);251 252/*253** Close an vfslog-file.254*/255static int vfslogClose(sqlite3_file *pFile){256 sqlite3_uint64 t;257 int rc = SQLITE_OK;258 VfslogFile *p = (VfslogFile *)pFile;259 260 t = vfslog_time();261 if( p->pReal->pMethods ){262 rc = p->pReal->pMethods->xClose(p->pReal);263 }264 t = vfslog_time() - t;265 vfslog_call(p->pVfslog, OS_CLOSE, p->iFileId, t, rc, 0, 0);266 return rc;267}268 269/*270** Read data from an vfslog-file.271*/272static int vfslogRead(273 sqlite3_file *pFile, 274 void *zBuf, 275 int iAmt, 276 sqlite_int64 iOfst277){278 int rc;279 sqlite3_uint64 t;280 VfslogFile *p = (VfslogFile *)pFile;281 t = vfslog_time();282 rc = p->pReal->pMethods->xRead(p->pReal, zBuf, iAmt, iOfst);283 t = vfslog_time() - t;284 vfslog_call(p->pVfslog, OS_READ, p->iFileId, t, rc, iAmt, (int)iOfst);285 return rc;286}287 288/*289** Write data to an vfslog-file.290*/291static int vfslogWrite(292 sqlite3_file *pFile,293 const void *z,294 int iAmt,295 sqlite_int64 iOfst296){297 int rc;298 sqlite3_uint64 t;299 VfslogFile *p = (VfslogFile *)pFile;300 t = vfslog_time();301 rc = p->pReal->pMethods->xWrite(p->pReal, z, iAmt, iOfst);302 t = vfslog_time() - t;303 vfslog_call(p->pVfslog, OS_WRITE, p->iFileId, t, rc, iAmt, (int)iOfst);304 return rc;305}306 307/*308** Truncate an vfslog-file.309*/310static int vfslogTruncate(sqlite3_file *pFile, sqlite_int64 size){311 int rc;312 sqlite3_uint64 t;313 VfslogFile *p = (VfslogFile *)pFile;314 t = vfslog_time();315 rc = p->pReal->pMethods->xTruncate(p->pReal, size);316 t = vfslog_time() - t;317 vfslog_call(p->pVfslog, OS_TRUNCATE, p->iFileId, t, rc, 0, (int)size);318 return rc;319}320 321/*322** Sync an vfslog-file.323*/324static int vfslogSync(sqlite3_file *pFile, int flags){325 int rc;326 sqlite3_uint64 t;327 VfslogFile *p = (VfslogFile *)pFile;328 t = vfslog_time();329 rc = p->pReal->pMethods->xSync(p->pReal, flags);330 t = vfslog_time() - t;331 vfslog_call(p->pVfslog, OS_SYNC, p->iFileId, t, rc, flags, 0);332 return rc;333}334 335/*336** Return the current file-size of an vfslog-file.337*/338static int vfslogFileSize(sqlite3_file *pFile, sqlite_int64 *pSize){339 int rc;340 sqlite3_uint64 t;341 VfslogFile *p = (VfslogFile *)pFile;342 t = vfslog_time();343 rc = p->pReal->pMethods->xFileSize(p->pReal, pSize);344 t = vfslog_time() - t;345 vfslog_call(p->pVfslog, OS_FILESIZE, p->iFileId, t, rc, 0, (int)*pSize);346 return rc;347}348 349/*350** Lock an vfslog-file.351*/352static int vfslogLock(sqlite3_file *pFile, int eLock){353 int rc;354 sqlite3_uint64 t;355 VfslogFile *p = (VfslogFile *)pFile;356 t = vfslog_time();357 rc = p->pReal->pMethods->xLock(p->pReal, eLock);358 t = vfslog_time() - t;359 vfslog_call(p->pVfslog, OS_LOCK, p->iFileId, t, rc, eLock, 0);360 return rc;361}362 363/*364** Unlock an vfslog-file.365*/366static int vfslogUnlock(sqlite3_file *pFile, int eLock){367 int rc;368 sqlite3_uint64 t;369 VfslogFile *p = (VfslogFile *)pFile;370 t = vfslog_time();371 rc = p->pReal->pMethods->xUnlock(p->pReal, eLock);372 t = vfslog_time() - t;373 vfslog_call(p->pVfslog, OS_UNLOCK, p->iFileId, t, rc, eLock, 0);374 return rc;375}376 377/*378** Check if another file-handle holds a RESERVED lock on an vfslog-file.379*/380static int vfslogCheckReservedLock(sqlite3_file *pFile, int *pResOut){381 int rc;382 sqlite3_uint64 t;383 VfslogFile *p = (VfslogFile *)pFile;384 t = vfslog_time();385 rc = p->pReal->pMethods->xCheckReservedLock(p->pReal, pResOut);386 t = vfslog_time() - t;387 vfslog_call(p->pVfslog, OS_CHECKRESERVEDLOCK, p->iFileId, t, rc, *pResOut, 0);388 return rc;389}390 391/*392** File control method. For custom operations on an vfslog-file.393*/394static int vfslogFileControl(sqlite3_file *pFile, int op, void *pArg){395 VfslogFile *p = (VfslogFile *)pFile;396 int rc = p->pReal->pMethods->xFileControl(p->pReal, op, pArg);397 if( op==SQLITE_FCNTL_VFSNAME && rc==SQLITE_OK ){398 *(char**)pArg = sqlite3_mprintf("vfslog/%z", *(char**)pArg);399 }400 return rc;401}402 403/*404** Return the sector-size in bytes for an vfslog-file.405*/406static int vfslogSectorSize(sqlite3_file *pFile){407 int rc;408 sqlite3_uint64 t;409 VfslogFile *p = (VfslogFile *)pFile;410 t = vfslog_time();411 rc = p->pReal->pMethods->xSectorSize(p->pReal);412 t = vfslog_time() - t;413 vfslog_call(p->pVfslog, OS_SECTORSIZE, p->iFileId, t, rc, 0, 0);414 return rc;415}416 417/*418** Return the device characteristic flags supported by an vfslog-file.419*/420static int vfslogDeviceCharacteristics(sqlite3_file *pFile){421 int rc;422 sqlite3_uint64 t;423 VfslogFile *p = (VfslogFile *)pFile;424 t = vfslog_time();425 rc = p->pReal->pMethods->xDeviceCharacteristics(p->pReal);426 t = vfslog_time() - t;427 vfslog_call(p->pVfslog, OS_DEVCHAR, p->iFileId, t, rc, 0, 0);428 return rc;429}430 431static int vfslogShmLock(sqlite3_file *pFile, int ofst, int n, int flags){432 int rc;433 sqlite3_uint64 t;434 VfslogFile *p = (VfslogFile *)pFile;435 t = vfslog_time();436 rc = p->pReal->pMethods->xShmLock(p->pReal, ofst, n, flags);437 t = vfslog_time() - t;438 vfslog_call(p->pVfslog, OS_SHMLOCK, p->iFileId, t, rc, 0, 0);439 return rc;440}441static int vfslogShmMap(442 sqlite3_file *pFile, 443 int iRegion, 444 int szRegion, 445 int isWrite, 446 volatile void **pp447){448 int rc;449 sqlite3_uint64 t;450 VfslogFile *p = (VfslogFile *)pFile;451 t = vfslog_time();452 rc = p->pReal->pMethods->xShmMap(p->pReal, iRegion, szRegion, isWrite, pp);453 t = vfslog_time() - t;454 vfslog_call(p->pVfslog, OS_SHMMAP, p->iFileId, t, rc, 0, 0);455 return rc;456}457static void vfslogShmBarrier(sqlite3_file *pFile){458 sqlite3_uint64 t;459 VfslogFile *p = (VfslogFile *)pFile;460 t = vfslog_time();461 p->pReal->pMethods->xShmBarrier(p->pReal);462 t = vfslog_time() - t;463 vfslog_call(p->pVfslog, OS_SHMBARRIER, p->iFileId, t, SQLITE_OK, 0, 0);464}465static int vfslogShmUnmap(sqlite3_file *pFile, int deleteFlag){466 int rc;467 sqlite3_uint64 t;468 VfslogFile *p = (VfslogFile *)pFile;469 t = vfslog_time();470 rc = p->pReal->pMethods->xShmUnmap(p->pReal, deleteFlag);471 t = vfslog_time() - t;472 vfslog_call(p->pVfslog, OS_SHMUNMAP, p->iFileId, t, rc, 0, 0);473 return rc;474}475 476 477/*478** Open an vfslog file handle.479*/480static int vfslogOpen(481 sqlite3_vfs *pVfs,482 const char *zName,483 sqlite3_file *pFile,484 int flags,485 int *pOutFlags486){487 int rc;488 sqlite3_uint64 t;489 VfslogFile *p = (VfslogFile *)pFile;490 VfslogVfs *pLog = (VfslogVfs *)pVfs;491 492 pFile->pMethods = &vfslog_io_methods;493 p->pReal = (sqlite3_file *)&p[1];494 p->pVfslog = pVfs;495 p->iFileId = ++pLog->iNextFileId;496 497 t = vfslog_time();498 rc = REALVFS(pVfs)->xOpen(REALVFS(pVfs), zName, p->pReal, flags, pOutFlags);499 t = vfslog_time() - t;500 501 vfslog_call(pVfs, OS_OPEN, p->iFileId, t, rc, 0, 0);502 vfslog_string(pVfs, zName);503 return rc;504}505 506/*507** Delete the file located at zPath. If the dirSync argument is true,508** ensure the file-system modifications are synced to disk before509** returning.510*/511static int vfslogDelete(sqlite3_vfs *pVfs, const char *zPath, int dirSync){512 int rc;513 sqlite3_uint64 t;514 t = vfslog_time();515 rc = REALVFS(pVfs)->xDelete(REALVFS(pVfs), zPath, dirSync);516 t = vfslog_time() - t;517 vfslog_call(pVfs, OS_DELETE, 0, t, rc, dirSync, 0);518 vfslog_string(pVfs, zPath);519 return rc;520}521 522/*523** Test for access permissions. Return true if the requested permission524** is available, or false otherwise.525*/526static int vfslogAccess(527 sqlite3_vfs *pVfs, 528 const char *zPath, 529 int flags, 530 int *pResOut531){532 int rc;533 sqlite3_uint64 t;534 t = vfslog_time();535 rc = REALVFS(pVfs)->xAccess(REALVFS(pVfs), zPath, flags, pResOut);536 t = vfslog_time() - t;537 vfslog_call(pVfs, OS_ACCESS, 0, t, rc, flags, *pResOut);538 vfslog_string(pVfs, zPath);539 return rc;540}541 542/*543** Populate buffer zOut with the full canonical pathname corresponding544** to the pathname in zPath. zOut is guaranteed to point to a buffer545** of at least (INST_MAX_PATHNAME+1) bytes.546*/547static int vfslogFullPathname(548 sqlite3_vfs *pVfs, 549 const char *zPath, 550 int nOut, 551 char *zOut552){553 return REALVFS(pVfs)->xFullPathname(REALVFS(pVfs), zPath, nOut, zOut);554}555 556/*557** Open the dynamic library located at zPath and return a handle.558*/559static void *vfslogDlOpen(sqlite3_vfs *pVfs, const char *zPath){560 return REALVFS(pVfs)->xDlOpen(REALVFS(pVfs), zPath);561}562 563/*564** Populate the buffer zErrMsg (size nByte bytes) with a human readable565** utf-8 string describing the most recent error encountered associated 566** with dynamic libraries.567*/568static void vfslogDlError(sqlite3_vfs *pVfs, int nByte, char *zErrMsg){569 REALVFS(pVfs)->xDlError(REALVFS(pVfs), nByte, zErrMsg);570}571 572/*573** Return a pointer to the symbol zSymbol in the dynamic library pHandle.574*/575static void (*vfslogDlSym(sqlite3_vfs *pVfs, void *p, const char *zSym))(void){576 return REALVFS(pVfs)->xDlSym(REALVFS(pVfs), p, zSym);577}578 579/*580** Close the dynamic library handle pHandle.581*/582static void vfslogDlClose(sqlite3_vfs *pVfs, void *pHandle){583 REALVFS(pVfs)->xDlClose(REALVFS(pVfs), pHandle);584}585 586/*587** Populate the buffer pointed to by zBufOut with nByte bytes of 588** random data.589*/590static int vfslogRandomness(sqlite3_vfs *pVfs, int nByte, char *zBufOut){591 return REALVFS(pVfs)->xRandomness(REALVFS(pVfs), nByte, zBufOut);592}593 594/*595** Sleep for nMicro microseconds. Return the number of microseconds 596** actually slept.597*/598static int vfslogSleep(sqlite3_vfs *pVfs, int nMicro){599 return REALVFS(pVfs)->xSleep(REALVFS(pVfs), nMicro);600}601 602/*603** Return the current time as a Julian Day number in *pTimeOut.604*/605static int vfslogCurrentTime(sqlite3_vfs *pVfs, double *pTimeOut){606 return REALVFS(pVfs)->xCurrentTime(REALVFS(pVfs), pTimeOut);607}608 609static int vfslogGetLastError(sqlite3_vfs *pVfs, int a, char *b){610 return REALVFS(pVfs)->xGetLastError(REALVFS(pVfs), a, b);611}612static int vfslogCurrentTimeInt64(sqlite3_vfs *pVfs, sqlite3_int64 *p){613 return REALVFS(pVfs)->xCurrentTimeInt64(REALVFS(pVfs), p);614}615 616static void vfslog_flush(VfslogVfs *p){617#ifdef SQLITE_TEST618 extern int sqlite3_io_error_pending;619 extern int sqlite3_io_error_persist;620 extern int sqlite3_diskfull_pending;621 622 int pending = sqlite3_io_error_pending;623 int persist = sqlite3_io_error_persist;624 int diskfull = sqlite3_diskfull_pending;625 626 sqlite3_io_error_pending = 0;627 sqlite3_io_error_persist = 0;628 sqlite3_diskfull_pending = 0;629#endif630 631 if( p->nBuf ){632 p->pLog->pMethods->xWrite(p->pLog, p->aBuf, p->nBuf, p->iOffset);633 p->iOffset += p->nBuf;634 p->nBuf = 0;635 }636 637#ifdef SQLITE_TEST638 sqlite3_io_error_pending = pending;639 sqlite3_io_error_persist = persist;640 sqlite3_diskfull_pending = diskfull;641#endif642}643 644static void put32bits(unsigned char *p, unsigned int v){645 p[0] = v>>24;646 p[1] = (unsigned char)(v>>16);647 p[2] = (unsigned char)(v>>8);648 p[3] = (unsigned char)v;649}650 651static void vfslog_call(652 sqlite3_vfs *pVfs,653 int eEvent,654 int iFileid,655 sqlite3_int64 nClick,656 int return_code,657 int size,658 int offset659){660 VfslogVfs *p = (VfslogVfs *)pVfs;661 unsigned char *zRec;662 if( (24+p->nBuf)>sizeof(p->aBuf) ){663 vfslog_flush(p);664 }665 zRec = (unsigned char *)&p->aBuf[p->nBuf];666 put32bits(&zRec[0], eEvent);667 put32bits(&zRec[4], iFileid);668 put32bits(&zRec[8], (unsigned int)(nClick&0xffff));669 put32bits(&zRec[12], return_code);670 put32bits(&zRec[16], size);671 put32bits(&zRec[20], offset);672 p->nBuf += 24;673}674 675static void vfslog_string(sqlite3_vfs *pVfs, const char *zStr){676 VfslogVfs *p = (VfslogVfs *)pVfs;677 unsigned char *zRec;678 int nStr = zStr ? (int)strlen(zStr) : 0;679 if( (4+nStr+p->nBuf)>sizeof(p->aBuf) ){680 vfslog_flush(p);681 }682 zRec = (unsigned char *)&p->aBuf[p->nBuf];683 put32bits(&zRec[0], nStr);684 if( zStr ){685 memcpy(&zRec[4], zStr, nStr);686 }687 p->nBuf += (4 + nStr);688}689 690static void vfslog_finalize(VfslogVfs *p){691 if( p->pLog->pMethods ){692 vfslog_flush(p);693 p->pLog->pMethods->xClose(p->pLog);694 }695 sqlite3_free(p);696}697 698int sqlite3_vfslog_finalize(const char *zVfs){699 sqlite3_vfs *pVfs;700 pVfs = sqlite3_vfs_find(zVfs);701 if( !pVfs || pVfs->xOpen!=vfslogOpen ){702 return SQLITE_ERROR;703 } 704 sqlite3_vfs_unregister(pVfs);705 vfslog_finalize((VfslogVfs *)pVfs);706 return SQLITE_OK;707}708 709int sqlite3_vfslog_new(710 const char *zVfs, /* New VFS name */711 const char *zParentVfs, /* Parent VFS name (or NULL) */712 const char *zLog /* Log file name */713){714 VfslogVfs *p;715 sqlite3_vfs *pParent;716 int nByte;717 int flags;718 int rc;719 char *zFile;720 int nVfs;721 722 pParent = sqlite3_vfs_find(zParentVfs);723 if( !pParent ){724 return SQLITE_ERROR;725 }726 727 nVfs = (int)strlen(zVfs);728 nByte = sizeof(VfslogVfs) + pParent->szOsFile + nVfs+1+pParent->mxPathname+1;729 p = (VfslogVfs *)sqlite3_malloc(nByte);730 memset(p, 0, nByte);731 732 p->pVfs = pParent;733 p->pLog = (sqlite3_file *)&p[1];734 memcpy(&p->base, &vfslog_vfs, sizeof(sqlite3_vfs));735 p->base.zName = &((char *)p->pLog)[pParent->szOsFile];736 p->base.szOsFile += pParent->szOsFile;737 memcpy((char *)p->base.zName, zVfs, nVfs);738 739 zFile = (char *)&p->base.zName[nVfs+1];740 pParent->xFullPathname(pParent, zLog, pParent->mxPathname, zFile);741 742 flags = SQLITE_OPEN_READWRITE|SQLITE_OPEN_CREATE|SQLITE_OPEN_SUPER_JOURNAL;743 pParent->xDelete(pParent, zFile, 0);744 rc = pParent->xOpen(pParent, zFile, p->pLog, flags, &flags);745 if( rc==SQLITE_OK ){746 memcpy(p->aBuf, "sqlite_ostrace1.....", 20);747 p->iOffset = 0;748 p->nBuf = 20;749 rc = sqlite3_vfs_register((sqlite3_vfs *)p, 1);750 }751 if( rc ){752 vfslog_finalize(p);753 }754 return rc;755}756 757int sqlite3_vfslog_annotate(const char *zVfs, const char *zMsg){758 sqlite3_vfs *pVfs;759 pVfs = sqlite3_vfs_find(zVfs);760 if( !pVfs || pVfs->xOpen!=vfslogOpen ){761 return SQLITE_ERROR;762 } 763 vfslog_call(pVfs, OS_ANNOTATE, 0, 0, 0, 0, 0);764 vfslog_string(pVfs, zMsg);765 return SQLITE_OK;766}767 768static const char *vfslog_eventname(int eEvent){769 const char *zEvent = 0;770 771 switch( eEvent ){772 case OS_CLOSE: zEvent = "xClose"; break;773 case OS_READ: zEvent = "xRead"; break;774 case OS_WRITE: zEvent = "xWrite"; break;775 case OS_TRUNCATE: zEvent = "xTruncate"; break;776 case OS_SYNC: zEvent = "xSync"; break;777 case OS_FILESIZE: zEvent = "xFilesize"; break;778 case OS_LOCK: zEvent = "xLock"; break;779 case OS_UNLOCK: zEvent = "xUnlock"; break;780 case OS_CHECKRESERVEDLOCK: zEvent = "xCheckResLock"; break;781 case OS_FILECONTROL: zEvent = "xFileControl"; break;782 case OS_SECTORSIZE: zEvent = "xSectorSize"; break;783 case OS_DEVCHAR: zEvent = "xDeviceChar"; break;784 case OS_OPEN: zEvent = "xOpen"; break;785 case OS_DELETE: zEvent = "xDelete"; break;786 case OS_ACCESS: zEvent = "xAccess"; break;787 case OS_FULLPATHNAME: zEvent = "xFullPathname"; break;788 case OS_RANDOMNESS: zEvent = "xRandomness"; break;789 case OS_SLEEP: zEvent = "xSleep"; break;790 case OS_CURRENTTIME: zEvent = "xCurrentTime"; break;791 792 case OS_SHMUNMAP: zEvent = "xShmUnmap"; break;793 case OS_SHMLOCK: zEvent = "xShmLock"; break;794 case OS_SHMBARRIER: zEvent = "xShmBarrier"; break;795 case OS_SHMMAP: zEvent = "xShmMap"; break;796 797 case OS_ANNOTATE: zEvent = "annotation"; break;798 }799 800 return zEvent;801}802 803typedef struct VfslogVtab VfslogVtab;804typedef struct VfslogCsr VfslogCsr;805 806/*807** Virtual table type for the vfslog reader module.808*/809struct VfslogVtab {810 sqlite3_vtab base; /* Base class */811 sqlite3_file *pFd; /* File descriptor open on vfslog file */812 sqlite3_int64 nByte; /* Size of file in bytes */813 char *zFile; /* File name for pFd */814};815 816/*817** Virtual table cursor type for the vfslog reader module.818*/819struct VfslogCsr {820 sqlite3_vtab_cursor base; /* Base class */821 sqlite3_int64 iRowid; /* Current rowid. */822 sqlite3_int64 iOffset; /* Offset of next record in file */823 char *zTransient; /* Transient 'file' string */824 int nFile; /* Size of array azFile[] */825 char **azFile; /* File strings */826 unsigned char aBuf[1024]; /* Current vfs log entry (read from file) */827};828 829static unsigned int get32bits(unsigned char *p){830 return (p[0]<<24) + (p[1]<<16) + (p[2]<<8) + p[3];831}832 833/*834** The argument must point to a buffer containing a nul-terminated string.835** If the string begins with an SQL quote character it is overwritten by836** the dequoted version. Otherwise the buffer is left unmodified.837*/838static void dequote(char *z){839 char quote; /* Quote character (if any ) */840 quote = z[0];841 if( quote=='[' || quote=='\'' || quote=='"' || quote=='`' ){842 int iIn = 1; /* Index of next byte to read from input */843 int iOut = 0; /* Index of next byte to write to output */844 if( quote=='[' ) quote = ']'; 845 while( z[iIn] ){846 if( z[iIn]==quote ){847 if( z[iIn+1]!=quote ) break;848 z[iOut++] = quote;849 iIn += 2;850 }else{851 z[iOut++] = z[iIn++];852 }853 }854 z[iOut] = '\0';855 }856}857 858#ifndef SQLITE_OMIT_VIRTUALTABLE859/*860** Connect to or create a vfslog virtual table.861*/862static int vlogConnect(863 sqlite3 *db,864 void *pAux,865 int argc, const char *const*argv,866 sqlite3_vtab **ppVtab,867 char **pzErr868){869 sqlite3_vfs *pVfs; /* VFS used to read log file */870 int flags; /* flags passed to pVfs->xOpen() */871 VfslogVtab *p;872 int rc;873 int nByte;874 char *zFile;875 876 *ppVtab = 0;877 pVfs = sqlite3_vfs_find(0);878 nByte = sizeof(VfslogVtab) + pVfs->szOsFile + pVfs->mxPathname;879 p = sqlite3_malloc(nByte);880 if( p==0 ) return SQLITE_NOMEM;881 memset(p, 0, nByte);882 883 p->pFd = (sqlite3_file *)&p[1];884 p->zFile = &((char *)p->pFd)[pVfs->szOsFile];885 886 zFile = sqlite3_mprintf("%s", argv[3]);887 if( !zFile ){888 sqlite3_free(p);889 return SQLITE_NOMEM;890 }891 dequote(zFile);892 pVfs->xFullPathname(pVfs, zFile, pVfs->mxPathname, p->zFile);893 sqlite3_free(zFile);894 895 flags = SQLITE_OPEN_READWRITE|SQLITE_OPEN_SUPER_JOURNAL;896 rc = pVfs->xOpen(pVfs, p->zFile, p->pFd, flags, &flags);897 898 if( rc==SQLITE_OK ){899 p->pFd->pMethods->xFileSize(p->pFd, &p->nByte);900 sqlite3_declare_vtab(db, 901 "CREATE TABLE xxx(event, file, click, rc, size, offset)"902 );903 *ppVtab = &p->base;904 }else{905 sqlite3_free(p);906 }907 908 return rc;909}910 911/*912** There is no "best-index". This virtual table always does a linear913** scan of the binary VFS log file.914*/915static int vlogBestIndex(sqlite3_vtab *tab, sqlite3_index_info *pIdxInfo){916 pIdxInfo->estimatedCost = 10.0;917 return SQLITE_OK;918}919 920/*921** Disconnect from or destroy a vfslog virtual table.922*/923static int vlogDisconnect(sqlite3_vtab *pVtab){924 VfslogVtab *p = (VfslogVtab *)pVtab;925 if( p->pFd->pMethods ){926 p->pFd->pMethods->xClose(p->pFd);927 p->pFd->pMethods = 0;928 }929 sqlite3_free(p);930 return SQLITE_OK;931}932 933/*934** Open a new vfslog cursor.935*/936static int vlogOpen(sqlite3_vtab *pVTab, sqlite3_vtab_cursor **ppCursor){937 VfslogCsr *pCsr; /* Newly allocated cursor object */938 939 pCsr = sqlite3_malloc(sizeof(VfslogCsr));940 if( !pCsr ) return SQLITE_NOMEM;941 memset(pCsr, 0, sizeof(VfslogCsr));942 *ppCursor = &pCsr->base;943 return SQLITE_OK;944}945 946/*947** Close a vfslog cursor.948*/949static int vlogClose(sqlite3_vtab_cursor *pCursor){950 VfslogCsr *p = (VfslogCsr *)pCursor;951 int i;952 for(i=0; i<p->nFile; i++){953 sqlite3_free(p->azFile[i]);954 }955 sqlite3_free(p->azFile);956 sqlite3_free(p->zTransient);957 sqlite3_free(p);958 return SQLITE_OK;959}960 961/*962** Move a vfslog cursor to the next entry in the file.963*/964static int vlogNext(sqlite3_vtab_cursor *pCursor){965 VfslogCsr *pCsr = (VfslogCsr *)pCursor;966 VfslogVtab *p = (VfslogVtab *)pCursor->pVtab;967 int rc = SQLITE_OK;968 int nRead;969 970 sqlite3_free(pCsr->zTransient);971 pCsr->zTransient = 0;972 973 nRead = 24;974 if( pCsr->iOffset+nRead<=p->nByte ){975 int eEvent;976 rc = p->pFd->pMethods->xRead(p->pFd, pCsr->aBuf, nRead, pCsr->iOffset);977 978 eEvent = get32bits(pCsr->aBuf);979 if( (rc==SQLITE_OK)980 && (eEvent==OS_OPEN || eEvent==OS_DELETE || eEvent==OS_ACCESS) 981 ){982 char buf[4];983 rc = p->pFd->pMethods->xRead(p->pFd, buf, 4, pCsr->iOffset+nRead);984 nRead += 4;985 if( rc==SQLITE_OK ){986 int nStr = get32bits((unsigned char *)buf);987 char *zStr = sqlite3_malloc(nStr+1);988 rc = p->pFd->pMethods->xRead(p->pFd, zStr, nStr, pCsr->iOffset+nRead);989 zStr[nStr] = '\0';990 nRead += nStr;991 992 if( eEvent==OS_OPEN ){993 int iFileid = get32bits(&pCsr->aBuf[4]);994 if( iFileid>=pCsr->nFile ){995 int nNew = sizeof(pCsr->azFile[0])*(iFileid+1);996 pCsr->azFile = (char **)sqlite3_realloc(pCsr->azFile, nNew);997 nNew -= sizeof(pCsr->azFile[0])*pCsr->nFile;998 memset(&pCsr->azFile[pCsr->nFile], 0, nNew);999 pCsr->nFile = iFileid+1;1000 }1001 sqlite3_free(pCsr->azFile[iFileid]);1002 pCsr->azFile[iFileid] = zStr;1003 }else{1004 pCsr->zTransient = zStr;1005 }1006 }1007 }1008 }1009 1010 pCsr->iRowid += 1;1011 pCsr->iOffset += nRead;1012 return rc;1013}1014 1015static int vlogEof(sqlite3_vtab_cursor *pCursor){1016 VfslogCsr *pCsr = (VfslogCsr *)pCursor;1017 VfslogVtab *p = (VfslogVtab *)pCursor->pVtab;1018 return (pCsr->iOffset>=p->nByte);1019}1020 1021static int vlogFilter(1022 sqlite3_vtab_cursor *pCursor, 1023 int idxNum, const char *idxStr,1024 int argc, sqlite3_value **argv1025){1026 VfslogCsr *pCsr = (VfslogCsr *)pCursor;1027 pCsr->iRowid = 0;1028 pCsr->iOffset = 20;1029 return vlogNext(pCursor);1030}1031 1032static int vlogColumn(1033 sqlite3_vtab_cursor *pCursor, 1034 sqlite3_context *ctx, 1035 int i1036){1037 unsigned int val;1038 VfslogCsr *pCsr = (VfslogCsr *)pCursor;1039 1040 assert( i<7 );1041 val = get32bits(&pCsr->aBuf[4*i]);1042 1043 switch( i ){1044 case 0: {1045 sqlite3_result_text(ctx, vfslog_eventname(val), -1, SQLITE_STATIC);1046 break;1047 }1048 case 1: {1049 char *zStr = pCsr->zTransient;1050 if( val!=0 && val<(unsigned)pCsr->nFile ){1051 zStr = pCsr->azFile[val];1052 }1053 sqlite3_result_text(ctx, zStr, -1, SQLITE_TRANSIENT);1054 break;1055 }1056 default:1057 sqlite3_result_int(ctx, val);1058 break;1059 }1060 1061 return SQLITE_OK;1062}1063 1064static int vlogRowid(sqlite3_vtab_cursor *pCursor, sqlite_int64 *pRowid){1065 VfslogCsr *pCsr = (VfslogCsr *)pCursor;1066 *pRowid = pCsr->iRowid;1067 return SQLITE_OK;1068}1069 1070int sqlite3_vfslog_register(sqlite3 *db){1071 static sqlite3_module vfslog_module = {1072 0, /* iVersion */1073 vlogConnect, /* xCreate */1074 vlogConnect, /* xConnect */1075 vlogBestIndex, /* xBestIndex */1076 vlogDisconnect, /* xDisconnect */1077 vlogDisconnect, /* xDestroy */1078 vlogOpen, /* xOpen - open a cursor */1079 vlogClose, /* xClose - close a cursor */1080 vlogFilter, /* xFilter - configure scan constraints */1081 vlogNext, /* xNext - advance a cursor */1082 vlogEof, /* xEof - check for end of scan */1083 vlogColumn, /* xColumn - read data */1084 vlogRowid, /* xRowid - read data */1085 0, /* xUpdate */1086 0, /* xBegin */1087 0, /* xSync */1088 0, /* xCommit */1089 0, /* xRollback */1090 0, /* xFindMethod */1091 0, /* xRename */1092 0, /* xSavepoint */1093 0, /* xRelease */1094 0, /* xRollbackTo */1095 0, /* xShadowName */1096 0 /* xIntegrity */1097 };1098 1099 sqlite3_create_module(db, "vfslog", &vfslog_module, 0);1100 return SQLITE_OK;1101}1102#endif /* SQLITE_OMIT_VIRTUALTABLE */1103 1104/**************************************************************************1105***************************************************************************1106** Tcl interface starts here.1107*/1108 1109#if defined(SQLITE_TEST) || defined(TCLSH)1110 1111#include "tclsqlite.h"1112 1113static int SQLITE_TCLAPI test_vfslog(1114 void *clientData,1115 Tcl_Interp *interp,1116 int objc,1117 Tcl_Obj *CONST objv[]1118){1119 struct SqliteDb { sqlite3 *db; };1120 sqlite3 *db;1121 Tcl_CmdInfo cmdInfo;1122 int rc = SQLITE_ERROR;1123 1124 static const char *strs[] = { "annotate", "finalize", "new", "register", 0 };1125 enum VL_enum { VL_ANNOTATE, VL_FINALIZE, VL_NEW, VL_REGISTER };1126 int iSub;1127 1128 if( objc<2 ){1129 Tcl_WrongNumArgs(interp, 1, objv, "SUB-COMMAND ...");1130 return TCL_ERROR;1131 }1132 if( Tcl_GetIndexFromObj(interp, objv[1], strs, "sub-command", 0, &iSub) ){1133 return TCL_ERROR;1134 }1135 1136 switch( (enum VL_enum)iSub ){1137 case VL_ANNOTATE: {1138 char *zVfs;1139 char *zMsg;1140 if( objc!=4 ){1141 Tcl_WrongNumArgs(interp, 3, objv, "VFS");1142 return TCL_ERROR;1143 }1144 zVfs = Tcl_GetString(objv[2]);1145 zMsg = Tcl_GetString(objv[3]);1146 rc = sqlite3_vfslog_annotate(zVfs, zMsg);1147 if( rc!=SQLITE_OK ){1148 Tcl_AppendResult(interp, "failed", (char*)0);1149 return TCL_ERROR;1150 }1151 break;1152 }1153 case VL_FINALIZE: {1154 char *zVfs;1155 if( objc!=3 ){1156 Tcl_WrongNumArgs(interp, 2, objv, "VFS");1157 return TCL_ERROR;1158 }1159 zVfs = Tcl_GetString(objv[2]);1160 rc = sqlite3_vfslog_finalize(zVfs);1161 if( rc!=SQLITE_OK ){1162 Tcl_AppendResult(interp, "failed", (char*)0);1163 return TCL_ERROR;1164 }1165 break;1166 };1167 1168 case VL_NEW: {1169 char *zVfs;1170 char *zParent;1171 char *zLog;1172 if( objc!=5 ){1173 Tcl_WrongNumArgs(interp, 2, objv, "VFS PARENT LOGFILE");1174 return TCL_ERROR;1175 }1176 zVfs = Tcl_GetString(objv[2]);1177 zParent = Tcl_GetString(objv[3]);1178 zLog = Tcl_GetString(objv[4]);1179 if( *zParent=='\0' ) zParent = 0;1180 rc = sqlite3_vfslog_new(zVfs, zParent, zLog);1181 if( rc!=SQLITE_OK ){1182 Tcl_AppendResult(interp, "failed", (char*)0);1183 return TCL_ERROR;1184 }1185 break;1186 };1187 1188 case VL_REGISTER: {1189 char *zDb;1190 if( objc!=3 ){1191 Tcl_WrongNumArgs(interp, 2, objv, "DB");1192 return TCL_ERROR;1193 }1194#ifdef SQLITE_OMIT_VIRTUALTABLE1195 Tcl_AppendResult(interp, "vfslog not available because of "1196 "SQLITE_OMIT_VIRTUALTABLE", (void*)0);1197 return TCL_ERROR;1198#else1199 zDb = Tcl_GetString(objv[2]);1200 if( Tcl_GetCommandInfo(interp, zDb, &cmdInfo) ){