/ Check-in [429c5b20]
Login
SQLite training in Houston TX on 2019-11-05 (details)
Part of the 2019 Tcl Conference

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

Overview
Comment:Fix problems in test_sqllog.c. Clarify the experimental SQLITE_CONFIG_SQLLOG interface. Handle at least the more likely error conditions in test_sqllog.c.
Downloads: Tarball | ZIP archive | SQL archive
Timelines: family | ancestors | descendants | both | sqllog
Files: files | file ages | folders
SHA1: 429c5b2056d7b7c644ca53bc97b8e0b9cb89ab04
User & Date: dan 2012-11-27 10:56:39
Context
2012-11-27
16:39
Get SQLLOG working on windows. Fix a couple of compiler warnings. Closed-Leaf check-in: b3809c93 user: drh tags: sqllog
10:56
Fix problems in test_sqllog.c. Clarify the experimental SQLITE_CONFIG_SQLLOG interface. Handle at least the more likely error conditions in test_sqllog.c. check-in: 429c5b20 user: dan tags: sqllog
2012-11-26
19:50
Add an option to register global hooks used for logging all SQL executed by an application. check-in: cd501bbc user: dan tags: sqllog
Changes
Hide Diffs Side-by-Side Diffs Ignore Whitespace Patch

Changes to src/main.c.

   130    130     ** must be complete.  So isInit must not be set until the very end
   131    131     ** of this routine.
   132    132     */
   133    133     if( sqlite3GlobalConfig.isInit ) return SQLITE_OK;
   134    134   
   135    135   #ifdef SQLITE_ENABLE_SQLLOG
   136    136     {
   137         -    extern sqlite3_init_sqllog(void);
          137  +    extern void sqlite3_init_sqllog(void);
   138    138       sqlite3_init_sqllog();
   139    139     }
   140    140   #endif
   141    141   
   142    142     /* Make sure the mutex subsystem is initialized.  If unable to 
   143    143     ** initialize the mutex subsystem, return early with the error.
   144    144     ** If the system is so sick that we are unable to allocate a mutex,
................................................................................
   833    833          "statements or unfinished backups");
   834    834       sqlite3_mutex_leave(db->mutex);
   835    835       return SQLITE_BUSY;
   836    836     }
   837    837   
   838    838   #ifdef SQLITE_ENABLE_SQLLOG
   839    839     if( sqlite3GlobalConfig.xSqllog ){
   840         -    sqlite3GlobalConfig.xSqllog(sqlite3GlobalConfig.pSqllogArg, db, 0, 0);
          840  +    /* Closing the handle. Fourth parameter is passed the value 2. */
          841  +    sqlite3GlobalConfig.xSqllog(sqlite3GlobalConfig.pSqllogArg, db, 0, 2);
   841    842     }
   842    843   #endif
   843    844   
   844    845     /* Convert the connection into a zombie and then close it.
   845    846     */
   846    847     db->magic = SQLITE_MAGIC_ZOMBIE;
   847    848     sqlite3LeaveMutexAndCloseZombie(db);
................................................................................
  2471   2472       db = 0;
  2472   2473     }else if( rc!=SQLITE_OK ){
  2473   2474       db->magic = SQLITE_MAGIC_SICK;
  2474   2475     }
  2475   2476     *ppDb = db;
  2476   2477   #ifdef SQLITE_ENABLE_SQLLOG
  2477   2478     if( sqlite3GlobalConfig.xSqllog ){
  2478         -    sqlite3GlobalConfig.xSqllog(
  2479         -        sqlite3GlobalConfig.pSqllogArg, db, zFilename, -1
  2480         -    );
         2479  +    /* Opening a db handle. Fourth parameter is passed 0. */
         2480  +    void *pArg = sqlite3GlobalConfig.pSqllogArg;
         2481  +    sqlite3GlobalConfig.xSqllog(pArg, db, zFilename, 0);
  2481   2482     }
  2482   2483   #endif
  2483   2484     return sqlite3ApiExit(0, rc);
  2484   2485   }
  2485   2486   
  2486   2487   /*
  2487   2488   ** Open a new database handle.

Changes to src/sqlite.h.in.

  1595   1595   ** </dl>
  1596   1596   **
  1597   1597   ** [[SQLITE_CONFIG_SQLLOG]]
  1598   1598   ** <dt>SQLITE_CONFIG_SQLLOG
  1599   1599   ** <dd>This option is only available if sqlite is compiled with the
  1600   1600   ** SQLITE_ENABLE_SQLLOG pre-processor macro defined. The first argument should
  1601   1601   ** be a pointer to a function of type void(*)(void*,sqlite3*,const char*, int).
  1602         -** The second should be of type (void*).
         1602  +** The second should be of type (void*). The callback is invoked by the library
         1603  +** in three separate circumstances, identified by the value passed as the
         1604  +** fourth parameter. If the fourth parameter is 0, then the database connection
         1605  +** passed as the second argument has just been opened. The third argument
         1606  +** points to a buffer containing the name of the main database file. If the
         1607  +** fourth parameter is 1, then the SQL statement that the third parameter
         1608  +** points to has just been executed. Or, if the fourth parameter is 2, then
         1609  +** the connection being passed as the second parameter is being closed. The
         1610  +** third parameter is passed NULL In this case.
  1603   1611   ** </dl>
  1604   1612   */
  1605   1613   #define SQLITE_CONFIG_SINGLETHREAD  1  /* nil */
  1606   1614   #define SQLITE_CONFIG_MULTITHREAD   2  /* nil */
  1607   1615   #define SQLITE_CONFIG_SERIALIZED    3  /* nil */
  1608   1616   #define SQLITE_CONFIG_MALLOC        4  /* sqlite3_mem_methods* */
  1609   1617   #define SQLITE_CONFIG_GETMALLOC     5  /* sqlite3_mem_methods* */

Changes to src/test_sqllog.c.

    44     44   **
    45     45   **      sqllog_N.sql  - A list of SQL statements executed by a single
    46     46   **                      connection. N may be any integer.
    47     47   **
    48     48   **      sqllog.idx    - An index mapping from integer N to a database
    49     49   **                      file name - indicating the full path of the
    50     50   **                      database from which sqllog_N.db was copied.
           51  +**
           52  +** ERROR HANDLING:
           53  +**
           54  +**   This module attempts to make a best effort to continue logging if an
           55  +**   IO or other error is encountered. For example, if a log file cannot 
           56  +**   be opened logs are not collected for that connection, but other
           57  +**   logging proceeds as expected. Errors are logged by calling sqlite3_log().
    51     58   */
    52     59   
    53     60   #include "sqlite3.h"
    54     61   #include "stdio.h"
    55     62   #include "stdlib.h"
    56     63   #include "string.h"
    57     64   #include "assert.h"
           65  +
           66  +#include "sys/types.h"
           67  +#include "unistd.h"
           68  +static int getProcessId(void){
           69  +  return (int)getpid();
           70  +}
           71  +
    58     72   
    59     73   #define ENVIRONMENT_VARIABLE1_NAME "SQLITE_SQLLOG_DIR"
    60     74   #define ENVIRONMENT_VARIABLE2_NAME "SQLITE_SQLLOG_REUSE_FILES"
    61     75   
    62     76   /* Assume that all database and database file names are shorted than this. */
    63     77   #define SQLLOG_NAMESZ 512
    64     78   
................................................................................
    78     92   struct SLGlobal {
    79     93     /* Protected by MUTEX_STATIC_MASTER */
    80     94     sqlite3_mutex *mutex;           /* Recursive mutex */
    81     95     int nConn;                      /* Size of aConn[] array */
    82     96   
    83     97     /* Protected by SLGlobal.mutex */
    84     98     int bReuse;                     /* True to avoid extra copies of db files */
    85         -  char zDir[SQLLOG_NAMESZ];       /* Directory to create files in */
           99  +  char zPrefix[SQLLOG_NAMESZ];    /* Prefix for all created files */
    86    100     char zIdx[SQLLOG_NAMESZ];       /* Full path to *.idx file */
    87    101     int iNextLog;                   /* Used to allocate file names */
    88    102     int iNextDb;                    /* Used to allocate database file names */
    89    103     int bRec;                       /* True if testSqllog() is called rec. */
    90    104     int iClock;                     /* Clock value */
    91    105     struct SLConn aConn[MAX_CONNECTIONS];
    92    106   } sqllogglobal;
................................................................................
   131    145   */
   132    146   static char *sqllogFindFile(const char *zFile){
   133    147     char *zRet = 0;
   134    148     FILE *fd = 0;
   135    149   
   136    150     /* Open the index file for reading */
   137    151     fd = fopen(sqllogglobal.zIdx, "r");
          152  +  if( fd==0 ){
          153  +    sqlite3_log(SQLITE_IOERR, "sqllogFindFile(): error in fopen()");
          154  +    return 0;
          155  +  }
   138    156   
          157  +  /* Loop through each entry in the index file. If zFile is not NULL and the
          158  +  ** entry is a match, then set zRet to point to the filename of the existing
          159  +  ** copy and break out of the loop.  */
   139    160     while( feof(fd)==0 ){
   140         -    char *z;
   141         -    int n;
   142    161       char zLine[SQLLOG_NAMESZ*2+5];
          162  +    if( fgets(zLine, sizeof(zLine), fd) ){
          163  +      int n;
          164  +      char *z;
   143    165   
   144         -    fgets(zLine, sizeof(zLine), fd);
   145         -    z = zLine;
   146         -    while( *z>='0' && *z<='9' ) z++;
   147         -    while( *z==' ' ) z++;
   148         -
   149         -    n = strlen(z);
   150         -    while( n>0 && sqllog_isspace(z[n-1]) ) n--;
   151         -    if( n==strlen(zFile) && 0==memcmp(zFile, z, n) ){
   152         -      char zBuf[16];
          166  +      zLine[sizeof(zLine)-1] = '\0';
   153    167         z = zLine;
   154         -      while( *z>='0' && *z<='9' ){
   155         -        zBuf[z-zLine] = *z;
   156         -        z++;
          168  +      while( *z>='0' && *z<='9' ) z++;
          169  +      while( *z==' ' ) z++;
          170  +
          171  +      n = strlen(z);
          172  +      while( n>0 && sqllog_isspace(z[n-1]) ) n--;
          173  +
          174  +      if( n==strlen(zFile) && 0==memcmp(zFile, z, n) ){
          175  +        char zBuf[16];
          176  +        memset(zBuf, 0, sizeof(zBuf));
          177  +        z = zLine;
          178  +        while( *z>='0' && *z<='9' ){
          179  +          zBuf[z-zLine] = *z;
          180  +          z++;
          181  +        }
          182  +        zRet = sqlite3_mprintf("%s_%s.db", sqllogglobal.zPrefix, zBuf);
          183  +        break;
   157    184         }
   158         -      zRet = sqlite3_mprintf("%s/sqllog_%s.db", sqllogglobal.zDir, zBuf);
   159         -      break;
   160    185       }
   161    186     }
          187  +
          188  +  if( ferror(fd) ){
          189  +    sqlite3_log(SQLITE_IOERR, "sqllogFindFile(): error reading index file");
          190  +  }
   162    191   
   163    192     fclose(fd);
   164    193     return zRet;
   165    194   }
   166    195   
   167         -static void sqllogFindAttached(
          196  +static int sqllogFindAttached(
   168    197     struct SLConn *p,               /* Database connection */
   169    198     const char *zSearch,            /* Name to search for (or NULL) */
   170    199     char *zName,                    /* OUT: Name of attached database */
   171    200     char *zFile                     /* OUT: Name of attached file */
   172    201   ){
   173    202     sqlite3_stmt *pStmt;
   174    203     int rc;
................................................................................
   197    226         ){
   198    227           break;
   199    228         }
   200    229       }
   201    230       rc = sqlite3_finalize(pStmt);
   202    231     }
   203    232     sqllogglobal.bRec = 0;
          233  +
          234  +  if( rc!=SQLITE_OK ){
          235  +    sqlite3_log(rc, "sqllogFindAttached(): error in \"PRAGMA database_list\"");
          236  +  }
          237  +  return rc;
   204    238   }
   205    239   
   206    240   
   207    241   /*
   208    242   ** Parameter zSearch is the name of a database attached to the database 
   209    243   ** connection associated with the first argument. This function creates
   210    244   ** a backup of this database in the logs directory.
................................................................................
   224    258   ** The SLGlobal.mutex mutex is always held when this function is called.
   225    259   */
   226    260   static void sqllogCopydb(struct SLConn *p, const char *zSearch, int bLog){
   227    261     char zName[SQLLOG_NAMESZ];      /* Attached database name */
   228    262     char zFile[SQLLOG_NAMESZ];      /* Database file name */
   229    263     char *zFree;
   230    264     char *zInit = 0;
          265  +  int rc;
   231    266   
   232         -  sqllogFindAttached(p, zSearch, zName, zFile);
          267  +  rc = sqllogFindAttached(p, zSearch, zName, zFile);
          268  +  if( rc!=SQLITE_OK ) return;
          269  +
   233    270     if( zFile[0]=='\0' ){
   234    271       zInit = sqlite3_mprintf("");
   235    272     }else{
   236    273       if( sqllogglobal.bReuse ){
   237    274         zInit = sqllogFindFile(zFile);
   238    275       }else{
   239    276         zInit = 0;
   240    277       }
   241    278       if( zInit==0 ){
   242    279         int rc;
   243    280         sqlite3 *copy = 0;
   244         -      FILE *fd;
   245    281         int iDb;
   246    282   
   247    283         /* Generate a file-name to use for the copy of this database */
   248    284         iDb = sqllogglobal.iNextDb++;
   249         -      zInit = sqlite3_mprintf("%s/sqllog_%d.db", sqllogglobal.zDir, iDb);
          285  +      zInit = sqlite3_mprintf("%s_%d.db", sqllogglobal.zPrefix, iDb);
   250    286   
   251    287         /* Create the backup */
   252    288         assert( sqllogglobal.bRec==0 );
   253    289         sqllogglobal.bRec = 1;
   254    290         rc = sqlite3_open(zInit, &copy);
   255    291         if( rc==SQLITE_OK ){
   256    292           sqlite3_backup *pBak;
   257    293           sqlite3_exec(copy, "PRAGMA synchronous = 0", 0, 0, 0);
   258    294           pBak = sqlite3_backup_init(copy, "main", p->db, zName);
   259    295           if( pBak ){
   260    296             sqlite3_backup_step(pBak, -1);
   261         -          sqlite3_backup_finish(pBak);
          297  +          rc = sqlite3_backup_finish(pBak);
          298  +        }else{
          299  +          rc = sqlite3_errcode(copy);
   262    300           }
   263    301           sqlite3_close(copy);
   264    302         }
   265    303         sqllogglobal.bRec = 0;
   266    304   
   267         -      /* Write an entry into the database index file */
   268         -      fd = fopen(sqllogglobal.zIdx, "a");
   269         -      fprintf(fd, "%d %s\n", iDb, zFile);
   270         -      fclose(fd);
          305  +      if( rc==SQLITE_OK ){
          306  +        /* Write an entry into the database index file */
          307  +        FILE *fd = fopen(sqllogglobal.zIdx, "a");
          308  +        if( fd ){
          309  +          fprintf(fd, "%d %s\n", iDb, zFile);
          310  +          fclose(fd);
          311  +        }
          312  +      }else{
          313  +        sqlite3_log(rc, "sqllogCopydb(): error backing up database");
          314  +      }
   271    315       }
   272    316     }
   273    317   
   274    318     if( bLog ){
   275         -    zFree = sqlite3_mprintf("ATTACH '%q' AS '%q'; -- clock=%d steps=1\n", 
          319  +    zFree = sqlite3_mprintf("ATTACH '%q' AS '%q'; -- clock=%d\n", 
   276    320           zInit, zName, sqllogglobal.iClock++
   277    321       );
   278    322     }else{
   279    323       zFree = sqlite3_mprintf("-- Main database is '%q'\n", zInit);
   280    324     }
   281    325     fprintf(p->fd, "%s", zFree);
   282    326     sqlite3_free(zFree);
................................................................................
   290    334   ** The SLGlobal.mutex mutex is always held when this function is called.
   291    335   */
   292    336   static void sqllogOpenlog(struct SLConn *p){
   293    337     /* If the log file has not yet been opened, open it now. */
   294    338     if( p->fd==0 ){
   295    339       char *zLog;
   296    340   
   297         -    /* If it is still NULL, have global.zDir point to a copy of environment
   298         -    ** variable $ENVIRONMENT_VARIABLE1_NAME.  */
   299         -    if( sqllogglobal.zDir[0]==0 ){
          341  +    /* If it is still NULL, have global.zPrefix point to a copy of 
          342  +    ** environment variable $ENVIRONMENT_VARIABLE1_NAME.  */
          343  +    if( sqllogglobal.zPrefix[0]==0 ){
   300    344         FILE *fd;
   301    345         char *zVar = getenv(ENVIRONMENT_VARIABLE1_NAME);
   302         -      if( zVar==0 || strlen(zVar)>=(sizeof(sqllogglobal.zDir)) ) return;
   303         -      memcpy(sqllogglobal.zDir, zVar, strlen(zVar)+1);
   304         -      sprintf(sqllogglobal.zIdx, "%s/sqllog.idx", sqllogglobal.zDir);
          346  +      if( zVar==0 || strlen(zVar)+10>=(sizeof(sqllogglobal.zPrefix)) ) return;
          347  +      sprintf(sqllogglobal.zPrefix, "%s/sqllog_%d", zVar, getProcessId());
          348  +      sprintf(sqllogglobal.zIdx, "%s.idx", sqllogglobal.zPrefix);
   305    349         if( getenv(ENVIRONMENT_VARIABLE2_NAME) ){
   306    350           sqllogglobal.bReuse = atoi(getenv(ENVIRONMENT_VARIABLE2_NAME));
   307    351         }
   308    352         fd = fopen(sqllogglobal.zIdx, "w");
   309         -      close(fd);
          353  +      if( fd ) fclose(fd);
   310    354       }
   311    355   
   312    356       /* Open the log file */
   313         -    zLog = sqlite3_mprintf("%s/sqllog_%d.sql", sqllogglobal.zDir, p->iLog);
          357  +    zLog = sqlite3_mprintf("%s_%d.sql", sqllogglobal.zPrefix, p->iLog);
   314    358       p->fd = fopen(zLog, "w");
   315         -    assert( p->fd );
   316    359       sqlite3_free(zLog);
          360  +    if( p->fd==0 ){
          361  +      sqlite3_log(SQLITE_IOERR, "sqllogOpenlog(): Failed to open log file");
          362  +    }
   317    363     }
   318    364   }
   319    365   
   320    366   /*
   321    367   ** This function is called if the SQLLOG callback is invoked to report
   322    368   ** execution of an SQL statement. Parameter p is the connection the statement
   323         -** was executed by, parameter zSql is the text of the statement itself and
   324         -** parameter nStep is the number of times sqlite3_step() was called.
          369  +** was executed by and parameter zSql is the text of the statement itself.
   325    370   */
   326         -static void testSqllogStmt(struct SLConn *p, const char *zSql, int nStep){
          371  +static void testSqllogStmt(struct SLConn *p, const char *zSql){
   327    372     const char *zFirst;             /* Pointer to first token in zSql */
   328    373     int nFirst;                     /* Size of token zFirst in bytes */
   329    374   
   330         -  assert( nStep>0 );
   331         -
   332    375     sqllogTokenize(zSql, &zFirst, &nFirst);
   333    376     if( nFirst!=6 || 0!=sqlite3_strnicmp("ATTACH", zFirst, 6) ){
   334    377       /* Not an ATTACH statement. Write this directly to the log. */
   335         -    fprintf(p->fd, "%s; -- clock=%d steps=%d\n", 
   336         -        zSql, sqllogglobal.iClock++, nStep
   337         -    );
          378  +    fprintf(p->fd, "%s; -- clock=%d\n", zSql, sqllogglobal.iClock++);
   338    379     }else{
   339    380       /* This is an ATTACH statement. Copy the database. */
   340    381       sqllogCopydb(p, 0, 1);
   341    382     }
   342    383   }
   343    384   
   344    385   /*
   345    386   ** The SQLITE_CONFIG_SQLLOG callback registered by sqlite3_init_sqllog().
   346    387   */
   347         -static void testSqllog(void *pCtx, sqlite3 *db, const char *zSql, int nStep){
          388  +static void testSqllog(void *pCtx, sqlite3 *db, const char *zSql, int eType){
   348    389     struct SLConn *p;
   349    390     sqlite3_mutex *master = sqlite3_mutex_alloc(SQLITE_MUTEX_STATIC_MASTER);
   350    391   
   351         -#if 0
   352         -  if( sqllogglobal.isErr && zSql ){
   353         -    /* If an error has already occurred, ignore all callbacks except
   354         -    ** those reporting calls to sqlite3_close().  */
   355         -    return;
   356         -  }
   357         -#endif
          392  +  assert( eType==0 || eType==1 || eType==2 );
          393  +  assert( (eType==2)==(zSql==0) );
   358    394   
   359    395     /* This is a database open command. */
   360         -  if( zSql && nStep<0 ){
          396  +  if( eType==0 ){
   361    397       sqlite3_mutex_enter(master);
   362    398       if( sqllogglobal.mutex==0 ){
   363    399         sqllogglobal.mutex = sqlite3_mutex_alloc(SQLITE_MUTEX_RECURSIVE);
   364    400       }
   365    401       p = &sqllogglobal.aConn[sqllogglobal.nConn++];
   366    402       p->fd = 0;
   367    403       p->db = db;
................................................................................
   368    404       p->iLog = sqllogglobal.iNextLog++;
   369    405       sqlite3_mutex_leave(master);
   370    406   
   371    407       /* Open the log and take a copy of the main database file */
   372    408       sqlite3_mutex_enter(sqllogglobal.mutex);
   373    409       if( sqllogglobal.bRec==0 ){
   374    410         sqllogOpenlog(p);
   375         -      sqllogCopydb(p, "main", 0);
          411  +      if( p->fd ) sqllogCopydb(p, "main", 0);
   376    412       }
   377    413       sqlite3_mutex_leave(sqllogglobal.mutex);
   378    414     }
   379    415   
   380    416     else{
   381    417   
   382    418       int i;
................................................................................
   383    419       for(i=0; i<sqllogglobal.nConn; i++){
   384    420         p = &sqllogglobal.aConn[i];
   385    421         if( p->db==db ) break;
   386    422       }
   387    423       if( i==sqllogglobal.nConn ) return;
   388    424   
   389    425       /* A database handle close command */
   390         -    if( zSql==0 ){
          426  +    if( eType==2 ){
   391    427         sqlite3_mutex_enter(master);
   392    428         if( p->fd ) fclose(p->fd);
   393    429         p->db = 0;
   394    430         p->fd = 0;
   395    431   
   396    432         sqllogglobal.nConn--;
   397    433         if( sqllogglobal.nConn==0 ){
................................................................................
   402    438           if( nShift>0 ){
   403    439             memmove(p, &p[1], nShift*sizeof(struct SLConn));
   404    440           }
   405    441         }
   406    442         sqlite3_mutex_leave(master);
   407    443   
   408    444       /* An ordinary SQL command. */
   409         -    }else{
          445  +    }else if( p->fd ){
   410    446         sqlite3_mutex_enter(sqllogglobal.mutex);
   411    447         if( sqllogglobal.bRec==0 ){
   412         -        testSqllogStmt(p, zSql, nStep);
          448  +        testSqllogStmt(p, zSql);
   413    449         }
   414    450         sqlite3_mutex_leave(sqllogglobal.mutex);
   415    451       }
   416    452     }
   417    453   }
   418    454   
   419    455   /*