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