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