/ Check-in [007ca283]
Login

Many hyperlinks are disabled.
Use anonymous login to enable hyperlinks.

Overview
Comment:Add the undocumented and experimental I/O tracing interface. This interface is likely to change and may be completely abandoned in the near future. (CVS 3665)
Downloads: Tarball | ZIP archive | SQL archive
Timelines: family | ancestors | descendants | both | trunk
Files: files | file ages | folders
SHA1: 007ca283892a66dd8b9e0dfece4f75d0d08a4300
User & Date: drh 2007-02-28 04:47:27
Context
2007-02-28
06:14
Work around incompatibilities in the windows printf() routine within the new I/O tracing logic. (CVS 3666) check-in: ceb3a07f user: drh tags: trunk
04:47
Add the undocumented and experimental I/O tracing interface. This interface is likely to change and may be completely abandoned in the near future. (CVS 3665) check-in: 007ca283 user: drh tags: trunk
2007-02-27
02:01
Improvements to OS layer tracing on the unix backend. (CVS 3664) check-in: 3ad96dbe user: drh tags: trunk
Changes
Hide Diffs Side-by-Side Diffs Ignore Whitespace Patch

Changes to src/main.c.

    10     10   **
    11     11   *************************************************************************
    12     12   ** Main file for the SQLite library.  The routines in this file
    13     13   ** implement the programmer interface to the library.  Routines in
    14     14   ** other files are for internal use by SQLite and should not be
    15     15   ** accessed by users of the library.
    16     16   **
    17         -** $Id: main.c,v 1.360 2006/12/19 18:57:11 drh Exp $
           17  +** $Id: main.c,v 1.361 2007/02/28 04:47:27 drh Exp $
    18     18   */
    19     19   #include "sqliteInt.h"
    20     20   #include "os.h"
    21     21   #include <ctype.h>
    22     22   
    23     23   /*
    24     24   ** The following constant value is used by the SQLITE_BIGENDIAN and
................................................................................
    29     29   /*
    30     30   ** The version of the library
    31     31   */
    32     32   const char sqlite3_version[] = SQLITE_VERSION;
    33     33   const char *sqlite3_libversion(void){ return sqlite3_version; }
    34     34   int sqlite3_libversion_number(void){ return SQLITE_VERSION_NUMBER; }
    35     35   
           36  +/*
           37  +** If the following function pointer is not NULL and if
           38  +** SQLITE_ENABLE_IOTRACE is enabled, then messages describing
           39  +** I/O active are written using this function.  These messages
           40  +** are intended for debugging activity only.
           41  +*/
           42  +void (*sqlite3_io_trace)(const char*, ...) = 0;
           43  +
    36     44   /*
    37     45   ** This is the default collating function named "BINARY" which is always
    38     46   ** available.
    39     47   */
    40     48   static int binCollFunc(
    41     49     void *NotUsed,
    42     50     int nKey1, const void *pKey1,

Changes to src/pager.c.

    14     14   ** The pager is used to access a database disk file.  It implements
    15     15   ** atomic commit and rollback through the use of a journal file that
    16     16   ** is separate from the database file.  The pager also implements file
    17     17   ** locking to prevent two processes from writing the same database
    18     18   ** file simultaneously, or one process from reading the database while
    19     19   ** another is writing.
    20     20   **
    21         -** @(#) $Id: pager.c,v 1.282 2007/01/05 02:00:47 drh Exp $
           21  +** @(#) $Id: pager.c,v 1.283 2007/02/28 04:47:27 drh Exp $
    22     22   */
    23     23   #ifndef SQLITE_OMIT_DISKIO
    24     24   #include "sqliteInt.h"
    25     25   #include "os.h"
    26     26   #include "pager.h"
    27     27   #include <assert.h>
    28     28   #include <string.h>
................................................................................
   658    658     /* The random check-hash initialiser */ 
   659    659     sqlite3Randomness(sizeof(pPager->cksumInit), &pPager->cksumInit);
   660    660     put32bits(&zHeader[sizeof(aJournalMagic)+4], pPager->cksumInit);
   661    661     /* The initial database size */
   662    662     put32bits(&zHeader[sizeof(aJournalMagic)+8], pPager->dbSize);
   663    663     /* The assumed sector size for this process */
   664    664     put32bits(&zHeader[sizeof(aJournalMagic)+12], pPager->sectorSize);
          665  +  IOTRACE(("JHDR %p %lld %d\n", pPager, pPager->journalHdr, sizeof(zHeader)))
   665    666     rc = sqlite3OsWrite(pPager->jfd, zHeader, sizeof(zHeader));
   666    667   
   667    668     /* The journal header has been written successfully. Seek the journal
   668    669     ** file descriptor to the end of the journal header sector.
   669    670     */
   670    671     if( rc==SQLITE_OK ){
          672  +    IOTRACE(("JTAIL %p %lld\n", pPager, pPager->journalOff-1))
   671    673       rc = sqlite3OsSeek(pPager->jfd, pPager->journalOff-1);
   672    674       if( rc==SQLITE_OK ){
   673    675         rc = sqlite3OsWrite(pPager->jfd, "\000", 1);
   674    676       }
   675    677     }
   676    678     return rc;
   677    679   }
................................................................................
   857    859   ** processes or threads might change the file.  So make sure all of
   858    860   ** our internal cache is invalidated.
   859    861   */
   860    862   static void pager_unlock(Pager *pPager){
   861    863     if( !MEMDB ){
   862    864       sqlite3OsUnlock(pPager->fd, NO_LOCK);
   863    865       pPager->dbSize = -1;
          866  +    IOTRACE(("UNLOCK %p\n", pPager))
   864    867     }
   865    868     pPager->state = PAGER_UNLOCK;
   866    869     assert( pPager->pAll==0 );
   867    870   }
   868    871   
   869    872   
   870    873   /*
................................................................................
  1684   1687       sqlite3OsClose(&fd);
  1685   1688       sqliteFree(zFullPathname);
  1686   1689       sqliteFree(pPager);
  1687   1690       return ((rc==SQLITE_OK)?SQLITE_NOMEM:rc);
  1688   1691     }
  1689   1692   
  1690   1693     TRACE3("OPEN %d %s\n", FILEHANDLEID(fd), zFullPathname);
         1694  +  IOTRACE(("OPEN %p %s\n", pPager, zFullPathname))
  1691   1695     pPager->zFilename = (char*)&pPager[1];
  1692   1696     pPager->zDirectory = &pPager->zFilename[nameLen+1];
  1693   1697     pPager->zJournal = &pPager->zDirectory[nameLen+1];
  1694   1698     strcpy(pPager->zFilename, zFullPathname);
  1695   1699     strcpy(pPager->zDirectory, zFullPathname);
  1696   1700   
  1697   1701     for(i=nameLen; i>0 && pPager->zDirectory[i-1]!='/'; i--){}
................................................................................
  1821   1825   int sqlite3pager_read_fileheader(Pager *pPager, int N, unsigned char *pDest){
  1822   1826     int rc = SQLITE_OK;
  1823   1827     memset(pDest, 0, N);
  1824   1828     if( MEMDB==0 ){
  1825   1829       disable_simulated_io_errors();
  1826   1830       sqlite3OsSeek(pPager->fd, 0);
  1827   1831       enable_simulated_io_errors();
         1832  +    IOTRACE(("DBHDR %p 0 %d\n", pPager, N))
  1828   1833       rc = sqlite3OsRead(pPager->fd, pDest, N);
  1829   1834       if( rc==SQLITE_IOERR_SHORT_READ ){
  1830   1835         rc = SQLITE_OK;
  1831   1836       }
  1832   1837     }
  1833   1838     return rc;
  1834   1839   }
................................................................................
  2003   2008       rc = SQLITE_OK;
  2004   2009     }else{
  2005   2010       do {
  2006   2011         rc = sqlite3OsLock(pPager->fd, locktype);
  2007   2012       }while( rc==SQLITE_BUSY && sqlite3InvokeBusyHandler(pPager->pBusyHandler) );
  2008   2013       if( rc==SQLITE_OK ){
  2009   2014         pPager->state = locktype;
         2015  +      IOTRACE(("LOCK %p %d\n", pPager, locktype))
  2010   2016       }
  2011   2017     }
  2012   2018     return rc;
  2013   2019   }
  2014   2020   
  2015   2021   /*
  2016   2022   ** Truncate the file to the number of pages specified.
................................................................................
  2076   2082   #endif
  2077   2083   
  2078   2084     disable_simulated_io_errors();
  2079   2085     pPager->errCode = 0;
  2080   2086     pager_reset(pPager);
  2081   2087     enable_simulated_io_errors();
  2082   2088     TRACE2("CLOSE %d\n", PAGERID(pPager));
         2089  +  IOTRACE(("CLOSE %p\n", pPager))
  2083   2090     assert( pPager->errCode || (pPager->journalOpen==0 && pPager->stmtOpen==0) );
  2084   2091     if( pPager->journalOpen ){
  2085   2092       sqlite3OsClose(&pPager->jfd);
  2086   2093     }
  2087   2094     sqliteFree(pPager->aInJournal);
  2088   2095     if( pPager->stmtOpen ){
  2089   2096       sqlite3OsClose(&pPager->stfd);
................................................................................
  2222   2229           /* Write the nRec value into the journal file header. If in
  2223   2230           ** full-synchronous mode, sync the journal first. This ensures that
  2224   2231           ** all data has really hit the disk before nRec is updated to mark
  2225   2232           ** it as a candidate for rollback. 
  2226   2233           */
  2227   2234           if( pPager->fullSync ){
  2228   2235             TRACE2("SYNC journal of %d\n", PAGERID(pPager));
         2236  +          IOTRACE(("JSYNC %p\n", pPager))
  2229   2237             rc = sqlite3OsSync(pPager->jfd, 0);
  2230   2238             if( rc!=0 ) return rc;
  2231   2239           }
  2232   2240           rc = sqlite3OsSeek(pPager->jfd,
  2233   2241                              pPager->journalHdr + sizeof(aJournalMagic));
  2234   2242           if( rc ) return rc;
         2243  +        IOTRACE(("JHDR %p %lld %d\n", pPager,
         2244  +                  pPager->journalHdr + sizeof(aJournalMagic), 4))
  2235   2245           rc = write32bits(pPager->jfd, pPager->nRec);
  2236   2246           if( rc ) return rc;
  2237   2247   
  2238   2248           rc = sqlite3OsSeek(pPager->jfd, pPager->journalOff);
  2239   2249           if( rc ) return rc;
  2240   2250         }
  2241   2251         TRACE2("SYNC journal of %d\n", PAGERID(pPager));
         2252  +      IOTRACE(("JSYNC %d\n", pPager))
  2242   2253         rc = sqlite3OsSync(pPager->jfd, pPager->full_fsync);
  2243   2254         if( rc!=0 ) return rc;
  2244   2255         pPager->journalStarted = 1;
  2245   2256       }
  2246   2257       pPager->needSync = 0;
  2247   2258   
  2248   2259       /* Erase the needSync flag from every page.
................................................................................
  2373   2384       ** than Pager.dbSize, this means sqlite3pager_truncate() was called to
  2374   2385       ** make the file smaller (presumably by auto-vacuum code). Do not write
  2375   2386       ** any such pages to the file.
  2376   2387       */
  2377   2388       if( pList->pgno<=pPager->dbSize ){
  2378   2389         char *pData = CODEC2(pPager, PGHDR_TO_DATA(pList), pList->pgno, 6);
  2379   2390         TRACE3("STORE %d page %d\n", PAGERID(pPager), pList->pgno);
         2391  +      IOTRACE(("PGOUT %p %d\n", pPager, pList->pgno))
  2380   2392         rc = sqlite3OsWrite(pPager->fd, pData, pPager->pageSize);
  2381   2393         TEST_INCR(pPager->nWrite);
  2382   2394       }
  2383   2395   #ifndef NDEBUG
  2384   2396       else{
  2385   2397         TRACE3("NOSTORE %d page %d\n", PAGERID(pPager), pList->pgno);
  2386   2398       }
................................................................................
  2776   2788       }else{
  2777   2789         assert( MEMDB==0 );
  2778   2790         rc = sqlite3OsSeek(pPager->fd, (pgno-1)*(i64)pPager->pageSize);
  2779   2791         if( rc==SQLITE_OK ){
  2780   2792           rc = sqlite3OsRead(pPager->fd, PGHDR_TO_DATA(pPg),
  2781   2793                                 pPager->pageSize);
  2782   2794         }
         2795  +      IOTRACE(("PGIN %p %d\n", pPager, pgno))
  2783   2796         TRACE3("FETCH %d page %d\n", PAGERID(pPager), pPg->pgno);
  2784   2797         CODEC1(pPager, PGHDR_TO_DATA(pPg), pPg->pgno, 3);
  2785   2798         if( rc!=SQLITE_OK && rc!=SQLITE_IOERR_SHORT_READ ){
  2786   2799           pPg->pgno = 0;
  2787   2800           sqlite3pager_unref(PGHDR_TO_DATA(pPg));
  2788   2801           return rc;
  2789   2802         }else{
................................................................................
  3147   3160             pEnd = pData2 + pPager->pageSize;
  3148   3161             pData2 -= 4;
  3149   3162             saved = *(u32*)pEnd;
  3150   3163             put32bits(pEnd, cksum);
  3151   3164             szPg = pPager->pageSize+8;
  3152   3165             put32bits(pData2, pPg->pgno);
  3153   3166             rc = sqlite3OsWrite(pPager->jfd, pData2, szPg);
         3167  +          IOTRACE(("JOUT %p %d %lld %d\n", pPager, pPg->pgno,
         3168  +                   pPager->journalOff, szPg))
  3154   3169             pPager->journalOff += szPg;
  3155   3170             TRACE4("JOURNAL %d page %d needSync=%d\n",
  3156   3171                     PAGERID(pPager), pPg->pgno, pPg->needSync);
  3157   3172             *(u32*)pEnd = saved;
  3158   3173   
  3159   3174   	  /* An error has occured writing to the journal file. The 
  3160   3175             ** transaction will be rolled back by the layer above.
................................................................................
  3300   3315         ** gets written at least once so that the disk file will be the correct
  3301   3316         ** size. If you do not write this page and the size of the file
  3302   3317         ** on the disk ends up being too small, that can lead to database
  3303   3318         ** corruption during the next transaction.
  3304   3319         */
  3305   3320       }else{
  3306   3321         TRACE3("DONT_WRITE page %d of %d\n", pgno, PAGERID(pPager));
         3322  +      IOTRACE(("CLEAN %p %d\n", pPager, pgno))
  3307   3323         makeClean(pPg);
  3308   3324   #ifdef SQLITE_CHECK_PAGES
  3309   3325         pPg->pageHash = pager_pagehash(pPg);
  3310   3326   #endif
  3311   3327       }
  3312   3328     }
  3313   3329   }
................................................................................
  3330   3346       pPager->aInJournal[pPg->pgno/8] |= 1<<(pPg->pgno&7);
  3331   3347       pPg->inJournal = 1;
  3332   3348       if( pPager->stmtInUse ){
  3333   3349         pPager->aInStmt[pPg->pgno/8] |= 1<<(pPg->pgno&7);
  3334   3350         page_add_to_stmt_list(pPg);
  3335   3351       }
  3336   3352       TRACE3("DONT_ROLLBACK page %d of %d\n", pPg->pgno, PAGERID(pPager));
         3353  +    IOTRACE(("GARBAGE %p %d\n", pPager, pPg->pgno))
  3337   3354     }
  3338   3355     if( pPager->stmtInUse && !pPg->inStmt && (int)pPg->pgno<=pPager->stmtSize ){
  3339   3356       assert( pPg->inJournal || (int)pPg->pgno>pPager->origDbSize );
  3340   3357       assert( pPager->aInStmt!=0 );
  3341   3358       pPager->aInStmt[pPg->pgno/8] |= 1<<(pPg->pgno&7);
  3342   3359       page_add_to_stmt_list(pPg);
  3343   3360     }
................................................................................
  3783   3800       rc = pager_write_pagelist(pPg);
  3784   3801       if( rc!=SQLITE_OK ) goto sync_exit;
  3785   3802   
  3786   3803       /* Sync the database file. */
  3787   3804       if( !pPager->noSync ){
  3788   3805         rc = sqlite3OsSync(pPager->fd, 0);
  3789   3806       }
         3807  +    IOTRACE(("DBSYNC %p\n", pPager))
  3790   3808   
  3791   3809       pPager->state = PAGER_SYNCED;
  3792   3810     }else if( MEMDB && nTrunc!=0 ){
  3793   3811       rc = sqlite3pager_truncate(pPager, nTrunc);
  3794   3812     }
  3795   3813   
  3796   3814   sync_exit:
................................................................................
  3821   3839     int h;
  3822   3840     Pgno needSyncPgno = 0;
  3823   3841   
  3824   3842     assert( pPg->nRef>0 );
  3825   3843   
  3826   3844     TRACE5("MOVE %d page %d (needSync=%d) moves to %d\n", 
  3827   3845         PAGERID(pPager), pPg->pgno, pPg->needSync, pgno);
         3846  +  IOTRACE(("MOVE %p %d %d\n", pPager, pPg->pgno, pgno))
  3828   3847   
  3829   3848     if( pPg->needSync ){
  3830   3849       needSyncPgno = pPg->pgno;
  3831   3850       assert( pPg->inJournal );
  3832   3851       assert( pPg->dirty );
  3833   3852       assert( pPager->needSync );
  3834   3853     }

Changes to src/shell.c.

     8      8   **    May you find forgiveness for yourself and forgive others.
     9      9   **    May you share freely, never taking more than you give.
    10     10   **
    11     11   *************************************************************************
    12     12   ** This file contains code to implement the "sqlite" command line
    13     13   ** utility for accessing SQLite databases.
    14     14   **
    15         -** $Id: shell.c,v 1.158 2007/01/08 14:31:36 drh Exp $
           15  +** $Id: shell.c,v 1.159 2007/02/28 04:47:27 drh Exp $
    16     16   */
    17     17   #include <stdlib.h>
    18     18   #include <string.h>
    19     19   #include <stdio.h>
    20     20   #include <assert.h>
    21     21   #include "sqlite3.h"
    22     22   #include <ctype.h>
           23  +#include <stdarg.h>
    23     24   
    24     25   #if !defined(_WIN32) && !defined(WIN32) && !defined(__MACOS__) && !defined(__OS2__)
    25     26   # include <signal.h>
    26     27   # include <pwd.h>
    27     28   # include <unistd.h>
    28     29   # include <sys/types.h>
    29     30   #endif
................................................................................
    92     93   
    93     94   /*
    94     95   ** Prompt strings. Initialized in main. Settable with
    95     96   **   .prompt main continue
    96     97   */
    97     98   static char mainPrompt[20];     /* First line prompt. default: "sqlite> "*/
    98     99   static char continuePrompt[20]; /* Continuation prompt. default: "   ...> " */
          100  +
          101  +/*
          102  +** Write I/O traces to the following stream.
          103  +*/
          104  +static FILE *iotrace = 0;
          105  +
          106  +/*
          107  +** This routine works like printf in that its first argument is a
          108  +** format string and subsequent arguments are values to be substituted
          109  +** in place of % fields.  The result of formatting this string
          110  +** is written to iotrace.
          111  +*/
          112  +static void iotracePrintf(const char *zFormat, ...){
          113  +  va_list ap;
          114  +  if( iotrace==0 ) return;
          115  +  va_start(ap, zFormat);
          116  +  vfprintf(iotrace, zFormat, ap);
          117  +  va_end(ap);
          118  +}
    99    119   
   100    120   
   101    121   /*
   102    122   ** Determines if a string is a number of not.
   103    123   */
   104    124   static int isNumber(const char *z, int *realnum){
   105    125     if( *z=='-' || *z=='+' ) z++;
................................................................................
  1212   1232         "ORDER BY 1",
  1213   1233         callback, &data, &zErrMsg
  1214   1234       );
  1215   1235       zShellStatic = 0;
  1216   1236       if( zErrMsg ){
  1217   1237         fprintf(stderr,"Error: %s\n", zErrMsg);
  1218   1238         sqlite3_free(zErrMsg);
         1239  +    }
         1240  +  }else
         1241  +
         1242  +  if( c=='i' && strncmp(azArg[0], "iotrace", n)==0 ){
         1243  +    extern void (*sqlite3_io_trace)(const char*, ...);
         1244  +    if( iotrace && iotrace!=stdout ) fclose(iotrace);
         1245  +    iotrace = 0;
         1246  +    if( nArg<2 ){
         1247  +      sqlite3_io_trace = 0;
         1248  +    }else if( strcmp(azArg[1], "-")==0 ){
         1249  +      sqlite3_io_trace = iotracePrintf;
         1250  +      iotrace = stdout;
         1251  +    }else{
         1252  +      iotrace = fopen(azArg[1], "w");
         1253  +      if( iotrace==0 ){
         1254  +        fprintf(stderr, "cannot open \"%s\"\n", azArg[1]);
         1255  +        sqlite3_io_trace = 0;
         1256  +      }else{
         1257  +        sqlite3_io_trace = iotracePrintf;
         1258  +      }
  1219   1259       }
  1220   1260     }else
  1221   1261   
  1222   1262   #ifndef SQLITE_OMIT_LOAD_EXTENSION
  1223   1263     if( c=='l' && strncmp(azArg[0], "load", n)==0 && nArg>=2 ){
  1224   1264       const char *zFile, *zProc;
  1225   1265       char *zErrMsg = 0;

Changes to src/sqliteInt.h.

     7      7   **    May you do good and not evil.
     8      8   **    May you find forgiveness for yourself and forgive others.
     9      9   **    May you share freely, never taking more than you give.
    10     10   **
    11     11   *************************************************************************
    12     12   ** Internal interface definitions for SQLite.
    13     13   **
    14         -** @(#) $Id: sqliteInt.h,v 1.538 2007/02/24 11:52:55 drh Exp $
           14  +** @(#) $Id: sqliteInt.h,v 1.539 2007/02/28 04:47:27 drh Exp $
    15     15   */
    16     16   #ifndef _SQLITEINT_H_
    17     17   #define _SQLITEINT_H_
    18     18   
    19     19   /*
    20     20   ** Extra interface definitions for those who need them
    21     21   */
................................................................................
  1893   1893   void sqlite3InvalidFunction(sqlite3_context*,int,sqlite3_value**);
  1894   1894   int sqlite3Reprepare(Vdbe*);
  1895   1895   
  1896   1896   #ifdef SQLITE_SSE
  1897   1897   #include "sseInt.h"
  1898   1898   #endif
  1899   1899   
         1900  +/*
         1901  +** If the SQLITE_ENABLE IOTRACE exists then the global variable
         1902  +** sqlite3_io_trace is a pointer to a printf-like routine used to
         1903  +** print I/O tracing messages. 
         1904  +*/
         1905  +#ifdef SQLITE_ENABLE_IOTRACE
         1906  +# define IOTRACE(A)  if( sqlite3_io_trace ){ sqlite3_io_trace A; }
         1907  +#else
         1908  +# define IOTRACE(A)
         1909  +#endif
         1910  +extern void (*sqlite3_io_trace)(const char*,...);
         1911  +
  1900   1912   #endif