** invariants are (1) you must have -DSQLITE_ENABLE_VFSTRACE so that
** the shell.c source file will know to include the -vfstrace command-line
** option and (2) you must compile and link the three source files
-** shell,c, test_vfstrace.c, and sqlite3.c.
+** shell,c, test_vfstrace.c, and sqlite3.c.
+**
+** RUNTIME CONTROL OF VFSTRACE OUTPUT
+**
+** The application can use the "vfstrace" pragma to control which VFS
+** APIs are traced. To disable all output:
+**
+** PRAGMA vfstrace('-all');
+**
+** To enable all output (which is the default setting):
+**
+** PRAGMA vfstrace('+all');
+**
+** Individual APIs can be enabled or disabled by name, with or without
+** the initial "x" character. For example, to set up for tracing lock
+** primatives only:
+**
+** PRAGMA vfstrace('-all, +Lock,Unlock,ShmLock');
+**
+** The argument to the vfstrace pragma ignores capitalization and any
+** characters other than alphabetics, '+', and '-'.
*/
#include <stdlib.h>
#include <string.h>
struct vfstrace_info {
sqlite3_vfs *pRootVfs; /* The underlying real VFS */
int (*xOut)(const char*, void*); /* Send output here */
+ unsigned int mTrace; /* Mask of interfaces to trace */
+ u8 bOn; /* Tracing on/off */
void *pOutArg; /* First argument to xOut */
const char *zVfsName; /* Name of this trace-VFS */
sqlite3_vfs *pTraceVfs; /* Pointer back to the trace VFS */
sqlite3_file *pReal; /* The real underlying file */
};
+/*
+** Bit values for vfstrace_info.mTrace.
+*/
+#define VTR_CLOSE 0x00000001
+#define VTR_READ 0x00000002
+#define VTR_WRITE 0x00000004
+#define VTR_TRUNC 0x00000008
+#define VTR_SYNC 0x00000010
+#define VTR_FSIZE 0x00000020
+#define VTR_LOCK 0x00000040
+#define VTR_UNLOCK 0x00000080
+#define VTR_CRL 0x00000100
+#define VTR_FCTRL 0x00000200
+#define VTR_SECSZ 0x00000400
+#define VTR_DEVCHAR 0x00000800
+#define VTR_SHMLOCK 0x00001000
+#define VTR_SHMMAP 0x00002000
+#define VTR_SHMBAR 0x00004000
+#define VTR_SHMUNMAP 0x00008000
+#define VTR_OPEN 0x00010000
+#define VTR_DELETE 0x00020000
+#define VTR_ACCESS 0x00040000
+#define VTR_FULLPATH 0x00080000
+#define VTR_DLOPEN 0x00100000
+#define VTR_DLERR 0x00200000
+#define VTR_DLSYM 0x00400000
+#define VTR_DLCLOSE 0x00800000
+#define VTR_RAND 0x01000000
+#define VTR_SLEEP 0x02000000
+#define VTR_CURTIME 0x04000000
+#define VTR_LASTERR 0x08000000
+
/*
** Method declarations for vfstrace_file.
*/
){
va_list ap;
char *zMsg;
- va_start(ap, zFormat);
- zMsg = sqlite3_vmprintf(zFormat, ap);
- va_end(ap);
- pInfo->xOut(zMsg, pInfo->pOutArg);
- sqlite3_free(zMsg);
+ if( pInfo->bOn ){
+ va_start(ap, zFormat);
+ zMsg = sqlite3_vmprintf(zFormat, ap);
+ va_end(ap);
+ pInfo->xOut(zMsg, pInfo->pOutArg);
+ sqlite3_free(zMsg);
+ }
}
/*
*pI = i;
}
+/*
+** Turn tracing output on or off according to mMask.
+*/
+static void vfstraceOnOff(vfstrace_info *pInfo, unsigned int mMask){
+ pInfo->bOn = (pInfo->mTrace & mMask)!=0;
+}
+
/*
** Close an vfstrace-file.
*/
vfstrace_file *p = (vfstrace_file *)pFile;
vfstrace_info *pInfo = p->pInfo;
int rc;
+ vfstraceOnOff(pInfo, VTR_CLOSE);
vfstrace_printf(pInfo, "%s.xClose(%s)", pInfo->zVfsName, p->zFName);
rc = p->pReal->pMethods->xClose(p->pReal);
vfstrace_print_errcode(pInfo, " -> %s\n", rc);
vfstrace_file *p = (vfstrace_file *)pFile;
vfstrace_info *pInfo = p->pInfo;
int rc;
+ vfstraceOnOff(pInfo, VTR_READ);
vfstrace_printf(pInfo, "%s.xRead(%s,n=%d,ofst=%lld)",
pInfo->zVfsName, p->zFName, iAmt, iOfst);
rc = p->pReal->pMethods->xRead(p->pReal, zBuf, iAmt, iOfst);
vfstrace_file *p = (vfstrace_file *)pFile;
vfstrace_info *pInfo = p->pInfo;
int rc;
+ vfstraceOnOff(pInfo, VTR_WRITE);
vfstrace_printf(pInfo, "%s.xWrite(%s,n=%d,ofst=%lld)",
pInfo->zVfsName, p->zFName, iAmt, iOfst);
rc = p->pReal->pMethods->xWrite(p->pReal, zBuf, iAmt, iOfst);
vfstrace_file *p = (vfstrace_file *)pFile;
vfstrace_info *pInfo = p->pInfo;
int rc;
+ vfstraceOnOff(pInfo, VTR_TRUNC);
vfstrace_printf(pInfo, "%s.xTruncate(%s,%lld)", pInfo->zVfsName, p->zFName,
size);
rc = p->pReal->pMethods->xTruncate(p->pReal, size);
if( flags & ~(SQLITE_SYNC_FULL|SQLITE_SYNC_DATAONLY) ){
sqlite3_snprintf(sizeof(zBuf)-i, &zBuf[i], "|0x%x", flags);
}
+ vfstraceOnOff(pInfo, VTR_SYNC);
vfstrace_printf(pInfo, "%s.xSync(%s,%s)", pInfo->zVfsName, p->zFName,
&zBuf[1]);
rc = p->pReal->pMethods->xSync(p->pReal, flags);
vfstrace_file *p = (vfstrace_file *)pFile;
vfstrace_info *pInfo = p->pInfo;
int rc;
+ vfstraceOnOff(pInfo, VTR_FSIZE);
vfstrace_printf(pInfo, "%s.xFileSize(%s)", pInfo->zVfsName, p->zFName);
rc = p->pReal->pMethods->xFileSize(p->pReal, pSize);
vfstrace_print_errcode(pInfo, " -> %s,", rc);
vfstrace_file *p = (vfstrace_file *)pFile;
vfstrace_info *pInfo = p->pInfo;
int rc;
+ vfstraceOnOff(pInfo, VTR_LOCK);
vfstrace_printf(pInfo, "%s.xLock(%s,%s)", pInfo->zVfsName, p->zFName,
lockName(eLock));
rc = p->pReal->pMethods->xLock(p->pReal, eLock);
vfstrace_file *p = (vfstrace_file *)pFile;
vfstrace_info *pInfo = p->pInfo;
int rc;
+ vfstraceOnOff(pInfo, VTR_UNLOCK);
vfstrace_printf(pInfo, "%s.xUnlock(%s,%s)", pInfo->zVfsName, p->zFName,
lockName(eLock));
rc = p->pReal->pMethods->xUnlock(p->pReal, eLock);
vfstrace_file *p = (vfstrace_file *)pFile;
vfstrace_info *pInfo = p->pInfo;
int rc;
+ vfstraceOnOff(pInfo, VTR_CRL);
vfstrace_printf(pInfo, "%s.xCheckReservedLock(%s,%d)",
pInfo->zVfsName, p->zFName);
rc = p->pReal->pMethods->xCheckReservedLock(p->pReal, pResOut);
char zBuf2[100];
char *zOp;
char *zRVal = 0;
+ vfstraceOnOff(pInfo, VTR_FCTRL);
switch( op ){
case SQLITE_FCNTL_LOCKSTATE: zOp = "LOCKSTATE"; break;
case SQLITE_GET_LOCKPROXYFILE: zOp = "GET_LOCKPROXYFILE"; break;
case SQLITE_FCNTL_POWERSAFE_OVERWRITE: zOp = "POWERSAFE_OVERWRITE"; break;
case SQLITE_FCNTL_PRAGMA: {
const char *const* a = (const char*const*)pArg;
+ if( a[1] && strcmp(a[1],"vfstrace")==0 && a[2] ){
+ const u8 *zArg = (const u8*)a[2];
+ if( zArg[0]>='0' && zArg[0]<=9 ){
+ pInfo->mTrace = (sqlite3_uint64)strtoll(a[2], 0, 0);
+ }else{
+ static const struct {
+ const char *z;
+ unsigned int m;
+ } aKw[] = {
+ { "all", 0xffffffff },
+ { "close", VTR_CLOSE },
+ { "read", VTR_READ },
+ { "write", VTR_WRITE },
+ { "truncate", VTR_TRUNC },
+ { "sync", VTR_SYNC },
+ { "filesize", VTR_FSIZE },
+ { "lock", VTR_LOCK },
+ { "unlock", VTR_UNLOCK },
+ { "checkreservedlock", VTR_CRL },
+ { "filecontrol", VTR_FCTRL },
+ { "sectorsize", VTR_SECSZ },
+ { "devicecharacteristics", VTR_DEVCHAR },
+ { "shmlock", VTR_SHMLOCK },
+ { "shmmap", VTR_SHMMAP },
+ { "shmummap", VTR_SHMUNMAP },
+ { "shmbarrier", VTR_SHMBAR },
+ { "open", VTR_OPEN },
+ { "delete", VTR_DELETE },
+ { "access", VTR_ACCESS },
+ { "fullpathname", VTR_FULLPATH },
+ { "dlopen", VTR_DLOPEN },
+ { "dlerror", VTR_DLERR },
+ { "dlsym", VTR_DLSYM },
+ { "dlclose", VTR_DLCLOSE },
+ { "randomness", VTR_RAND },
+ { "sleep", VTR_SLEEP },
+ { "currenttime", VTR_CURTIME },
+ { "currenttimeint64", VTR_CURTIME },
+ { "getlasterror", VTR_LASTERR },
+ };
+ int onOff = 1;
+ while( zArg[0] ){
+ int jj, n;
+ while( zArg[0]!=0 && zArg[0]!='-' && zArg[0]!='+'
+ && !isalpha(zArg[0]) ) zArg++;
+ if( zArg[0]==0 ) break;
+ if( zArg[0]=='-' ){
+ onOff = 0;
+ zArg++;
+ }else if( zArg[0]=='+' ){
+ onOff = 1;
+ zArg++;
+ }
+ while( !isalpha(zArg[0]) ){
+ if( zArg[0]==0 ) break;
+ zArg++;
+ }
+ if( zArg[0]=='x' && isalpha(zArg[1]) ) zArg++;
+ for(n=0; isalpha(zArg[n]); n++){}
+ for(jj=0; jj<sizeof(aKw)/sizeof(aKw[0]); jj++){
+ if( sqlite3_strnicmp(aKw[jj].z,(const char*)zArg,n)==0 ){
+ if( onOff ){
+ pInfo->mTrace |= aKw[jj].m;
+ }else{
+ pInfo->mTrace &= ~aKw[jj].m;
+ }
+ break;
+ }
+ }
+ zArg += n;
+ }
+ }
+ }
sqlite3_snprintf(sizeof(zBuf), zBuf, "PRAGMA,[%s,%s]",a[1],a[2]);
zOp = zBuf;
break;
vfstrace_file *p = (vfstrace_file *)pFile;
vfstrace_info *pInfo = p->pInfo;
int rc;
+ vfstraceOnOff(pInfo, VTR_SECSZ);
vfstrace_printf(pInfo, "%s.xSectorSize(%s)", pInfo->zVfsName, p->zFName);
rc = p->pReal->pMethods->xSectorSize(p->pReal);
vfstrace_printf(pInfo, " -> %d\n", rc);
vfstrace_file *p = (vfstrace_file *)pFile;
vfstrace_info *pInfo = p->pInfo;
int rc;
+ vfstraceOnOff(pInfo, VTR_DEVCHAR);
vfstrace_printf(pInfo, "%s.xDeviceCharacteristics(%s)",
pInfo->zVfsName, p->zFName);
rc = p->pReal->pMethods->xDeviceCharacteristics(p->pReal);
int rc;
char zLck[100];
int i = 0;
+ vfstraceOnOff(pInfo, VTR_SHMLOCK);
memcpy(zLck, "|0", 3);
if( flags & SQLITE_SHM_UNLOCK ) strappend(zLck, &i, "|UNLOCK");
if( flags & SQLITE_SHM_LOCK ) strappend(zLck, &i, "|LOCK");
vfstrace_file *p = (vfstrace_file *)pFile;
vfstrace_info *pInfo = p->pInfo;
int rc;
+ vfstraceOnOff(pInfo, VTR_SHMMAP);
vfstrace_printf(pInfo, "%s.xShmMap(%s,iRegion=%d,szRegion=%d,isWrite=%d,*)",
pInfo->zVfsName, p->zFName, iRegion, szRegion, isWrite);
rc = p->pReal->pMethods->xShmMap(p->pReal, iRegion, szRegion, isWrite, pp);
static void vfstraceShmBarrier(sqlite3_file *pFile){
vfstrace_file *p = (vfstrace_file *)pFile;
vfstrace_info *pInfo = p->pInfo;
+ vfstraceOnOff(pInfo, VTR_SHMBAR);
vfstrace_printf(pInfo, "%s.xShmBarrier(%s)\n", pInfo->zVfsName, p->zFName);
p->pReal->pMethods->xShmBarrier(p->pReal);
}
vfstrace_file *p = (vfstrace_file *)pFile;
vfstrace_info *pInfo = p->pInfo;
int rc;
+ vfstraceOnOff(pInfo, VTR_SHMUNMAP);
vfstrace_printf(pInfo, "%s.xShmUnmap(%s,delFlag=%d)",
pInfo->zVfsName, p->zFName, delFlag);
rc = p->pReal->pMethods->xShmUnmap(p->pReal, delFlag);
p->zFName = zName ? fileTail(zName) : "<temp>";
p->pReal = (sqlite3_file *)&p[1];
rc = pRoot->xOpen(pRoot, zName, p->pReal, flags, pOutFlags);
+ vfstraceOnOff(pInfo, VTR_OPEN);
vfstrace_printf(pInfo, "%s.xOpen(%s,flags=0x%x)",
pInfo->zVfsName, p->zFName, flags);
if( p->pReal->pMethods ){
vfstrace_info *pInfo = (vfstrace_info*)pVfs->pAppData;
sqlite3_vfs *pRoot = pInfo->pRootVfs;
int rc;
+ vfstraceOnOff(pInfo, VTR_DELETE);
vfstrace_printf(pInfo, "%s.xDelete(\"%s\",%d)",
pInfo->zVfsName, zPath, dirSync);
rc = pRoot->xDelete(pRoot, zPath, dirSync);
vfstrace_info *pInfo = (vfstrace_info*)pVfs->pAppData;
sqlite3_vfs *pRoot = pInfo->pRootVfs;
int rc;
+ vfstraceOnOff(pInfo, VTR_ACCESS);
vfstrace_printf(pInfo, "%s.xAccess(\"%s\",%d)",
pInfo->zVfsName, zPath, flags);
rc = pRoot->xAccess(pRoot, zPath, flags, pResOut);
vfstrace_info *pInfo = (vfstrace_info*)pVfs->pAppData;
sqlite3_vfs *pRoot = pInfo->pRootVfs;
int rc;
+ vfstraceOnOff(pInfo, VTR_FULLPATH);
vfstrace_printf(pInfo, "%s.xFullPathname(\"%s\")",
pInfo->zVfsName, zPath);
rc = pRoot->xFullPathname(pRoot, zPath, nOut, zOut);
static void *vfstraceDlOpen(sqlite3_vfs *pVfs, const char *zPath){
vfstrace_info *pInfo = (vfstrace_info*)pVfs->pAppData;
sqlite3_vfs *pRoot = pInfo->pRootVfs;
+ vfstraceOnOff(pInfo, VTR_DLOPEN);
vfstrace_printf(pInfo, "%s.xDlOpen(\"%s\")\n", pInfo->zVfsName, zPath);
return pRoot->xDlOpen(pRoot, zPath);
}
static void vfstraceDlError(sqlite3_vfs *pVfs, int nByte, char *zErrMsg){
vfstrace_info *pInfo = (vfstrace_info*)pVfs->pAppData;
sqlite3_vfs *pRoot = pInfo->pRootVfs;
+ vfstraceOnOff(pInfo, VTR_DLERR);
vfstrace_printf(pInfo, "%s.xDlError(%d)", pInfo->zVfsName, nByte);
pRoot->xDlError(pRoot, nByte, zErrMsg);
vfstrace_printf(pInfo, " -> \"%s\"", zErrMsg);
static void vfstraceDlClose(sqlite3_vfs *pVfs, void *pHandle){
vfstrace_info *pInfo = (vfstrace_info*)pVfs->pAppData;
sqlite3_vfs *pRoot = pInfo->pRootVfs;
+ vfstraceOnOff(pInfo, VTR_DLCLOSE);
vfstrace_printf(pInfo, "%s.xDlOpen()\n", pInfo->zVfsName);
pRoot->xDlClose(pRoot, pHandle);
}
static int vfstraceRandomness(sqlite3_vfs *pVfs, int nByte, char *zBufOut){
vfstrace_info *pInfo = (vfstrace_info*)pVfs->pAppData;
sqlite3_vfs *pRoot = pInfo->pRootVfs;
+ vfstraceOnOff(pInfo, VTR_RAND);
vfstrace_printf(pInfo, "%s.xRandomness(%d)\n", pInfo->zVfsName, nByte);
return pRoot->xRandomness(pRoot, nByte, zBufOut);
}
static int vfstraceSleep(sqlite3_vfs *pVfs, int nMicro){
vfstrace_info *pInfo = (vfstrace_info*)pVfs->pAppData;
sqlite3_vfs *pRoot = pInfo->pRootVfs;
+ vfstraceOnOff(pInfo, VTR_SLEEP);
+ vfstrace_printf(pInfo, "%s.xSleep(%d)\n", pInfo->zVfsName, nMicro);
return pRoot->xSleep(pRoot, nMicro);
}
static int vfstraceCurrentTime(sqlite3_vfs *pVfs, double *pTimeOut){
vfstrace_info *pInfo = (vfstrace_info*)pVfs->pAppData;
sqlite3_vfs *pRoot = pInfo->pRootVfs;
- return pRoot->xCurrentTime(pRoot, pTimeOut);
+ int rc;
+ vfstraceOnOff(pInfo, VTR_CURTIME);
+ vfstrace_printf(pInfo, "%s.xCurrentTime()", pInfo->zVfsName);
+ rc = pRoot->xCurrentTime(pRoot, pTimeOut);
+ vfstrace_printf(pInfo, " -> %.17g\n", *pTimeOut);
+ return rc;
}
static int vfstraceCurrentTimeInt64(sqlite3_vfs *pVfs, sqlite3_int64 *pTimeOut){
vfstrace_info *pInfo = (vfstrace_info*)pVfs->pAppData;
sqlite3_vfs *pRoot = pInfo->pRootVfs;
- return pRoot->xCurrentTimeInt64(pRoot, pTimeOut);
+ int rc;
+ vfstraceOnOff(pInfo, VTR_CURTIME);
+ vfstrace_printf(pInfo, "%s.xCurrentTimeInt64()", pInfo->zVfsName);
+ rc = pRoot->xCurrentTimeInt64(pRoot, pTimeOut);
+ vfstrace_printf(pInfo, " -> %lld\n", *pTimeOut);
+ return rc;
}
/*
-** Return th3 most recent error code and message
+** Return the most recent error code and message
*/
-static int vfstraceGetLastError(sqlite3_vfs *pVfs, int iErr, char *zErr){
+static int vfstraceGetLastError(sqlite3_vfs *pVfs, int nErr, char *zErr){
vfstrace_info *pInfo = (vfstrace_info*)pVfs->pAppData;
sqlite3_vfs *pRoot = pInfo->pRootVfs;
- return pRoot->xGetLastError(pRoot, iErr, zErr);
+ int rc;
+ vfstraceOnOff(pInfo, VTR_LASTERR);
+ vfstrace_printf(pInfo, "%s.xGetLastError(%d,zBuf)", pInfo->zVfsName, nErr);
+ if( nErr ) zErr[0] = 0;
+ rc = pRoot->xGetLastError(pRoot, nErr, zErr);
+ vfstrace_printf(pInfo, " -> zBuf[] = \"%s\", rc = %d\n", nErr?zErr:"", rc);
+ return rc;
}
/*
pInfo->pOutArg = pOutArg;
pInfo->zVfsName = pNew->zName;
pInfo->pTraceVfs = pNew;
+ pInfo->mTrace = 0xffffffff;
+ pInfo->bOn = 1;
vfstrace_printf(pInfo, "%s.enabled_for(\"%s\")\n",
pInfo->zVfsName, pRoot->zName);
return sqlite3_vfs_register(pNew, makeDefault);