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