diff options
Diffstat (limited to 'src/test_sqllog.c')
| -rw-r--r-- | src/test_sqllog.c | 507 |
1 files changed, 507 insertions, 0 deletions
diff --git a/src/test_sqllog.c b/src/test_sqllog.c new file mode 100644 index 0000000..4aa68b7 --- /dev/null +++ b/src/test_sqllog.c @@ -0,0 +1,507 @@ +/* +** 2012 November 26 +** +** The author disclaims copyright to this source code. In place of +** a legal notice, here is a blessing: +** +** May you do good and not evil. +** May you find forgiveness for yourself and forgive others. +** May you share freely, never taking more than you give. +** +************************************************************************* +** +** OVERVIEW +** +** This file contains experimental code used to record data from live +** SQLite applications that may be useful for offline analysis. +** Specifically, this module can be used to capture the following +** information: +** +** 1) The initial contents of all database files opened by the +** application, and +** +** 2) All SQL statements executed by the application. +** +** The captured information can then be used to run (for example) +** performance analysis looking for slow queries or to look for +** optimization opportunities in either the application or in SQLite +** itself. +** +** USAGE +** +** To use this module, SQLite must be compiled with the SQLITE_ENABLE_SQLLOG +** pre-processor symbol defined and this file linked into the application. +** One way to link this file into the application is to append the content +** of this file onto the end of the "sqlite3.c" amalgamation and then +** recompile the application as normal except with the addition of the +** -DSQLITE_ENABLE_SQLLOG option. +** +** At runtime, logging is enabled by setting environment variable +** SQLITE_SQLLOG_DIR to the name of a directory in which to store logged +** data. The logging directory must already exist. +** +** Usually, if the application opens the same database file more than once +** (either by attaching it or by using more than one database handle), only +** a single copy is made. This behavior may be overridden (so that a +** separate copy is taken each time the database file is opened or attached) +** by setting the environment variable SQLITE_SQLLOG_REUSE_FILES to 0. +** +** OUTPUT: +** +** The SQLITE_SQLLOG_DIR is populated with three types of files: +** +** sqllog_N.db - Copies of database files. N may be any integer. +** +** sqllog_N.sql - A list of SQL statements executed by a single +** connection. N may be any integer. +** +** sqllog.idx - An index mapping from integer N to a database +** file name - indicating the full path of the +** database from which sqllog_N.db was copied. +** +** ERROR HANDLING: +** +** This module attempts to make a best effort to continue logging if an +** IO or other error is encountered. For example, if a log file cannot +** be opened logs are not collected for that connection, but other +** logging proceeds as expected. Errors are logged by calling sqlite3_log(). +*/ + +#ifndef _SQLITE3_H_ +#include "sqlite3.h" +#endif +#include <stdio.h> +#include <stdlib.h> +#include <string.h> +#include <assert.h> + +#include <sys/types.h> +#include <unistd.h> +static int getProcessId(void){ +#if SQLITE_OS_WIN + return (int)_getpid(); +#else + return (int)getpid(); +#endif +} + +/* Names of environment variables to be used */ +#define ENVIRONMENT_VARIABLE1_NAME "SQLITE_SQLLOG_DIR" +#define ENVIRONMENT_VARIABLE2_NAME "SQLITE_SQLLOG_REUSE_FILES" + +/* Assume that all database and database file names are shorted than this. */ +#define SQLLOG_NAMESZ 512 + +/* Maximum number of simultaneous database connections the process may +** open (if any more are opened an error is logged using sqlite3_log() +** and processing is halted). +*/ +#define MAX_CONNECTIONS 256 + +/* There is one instance of this object for each SQLite database connection +** that is being logged. +*/ +struct SLConn { + int isErr; /* True if an error has occurred */ + sqlite3 *db; /* Connection handle */ + int iLog; /* First integer value used in file names */ + FILE *fd; /* File descriptor for log file */ +}; + +/* This object is a singleton that keeps track of all data loggers. +*/ +static struct SLGlobal { + /* Protected by MUTEX_STATIC_MASTER */ + sqlite3_mutex *mutex; /* Recursive mutex */ + int nConn; /* Size of aConn[] array */ + + /* Protected by SLGlobal.mutex */ + int bReuse; /* True to avoid extra copies of db files */ + char zPrefix[SQLLOG_NAMESZ]; /* Prefix for all created files */ + char zIdx[SQLLOG_NAMESZ]; /* Full path to *.idx file */ + int iNextLog; /* Used to allocate file names */ + int iNextDb; /* Used to allocate database file names */ + int bRec; /* True if testSqllog() is called rec. */ + int iClock; /* Clock value */ + struct SLConn aConn[MAX_CONNECTIONS]; +} sqllogglobal; + +/* +** Return true if c is an ASCII whitespace character. +*/ +static int sqllog_isspace(char c){ + return (c==' ' || c=='\t' || c=='\n' || c=='\v' || c=='\f' || c=='\r'); +} + +/* +** The first argument points to a nul-terminated string containing an SQL +** command. Before returning, this function sets *pz to point to the start +** of the first token in this command, and *pn to the number of bytes in +** the token. This is used to check if the SQL command is an "ATTACH" or +** not. +*/ +static void sqllogTokenize(const char *z, const char **pz, int *pn){ + const char *p = z; + int n; + + /* Skip past any whitespace */ + while( sqllog_isspace(*p) ){ + p++; + } + + /* Figure out how long the first token is */ + *pz = p; + n = 0; + while( (p[n]>='a' && p[n]<='z') || (p[n]>='A' && p[n]<='Z') ) n++; + *pn = n; +} + +/* +** Check if the logs directory already contains a copy of database file +** zFile. If so, return a pointer to the full path of the copy. Otherwise, +** return NULL. +** +** If a non-NULL value is returned, then the caller must arrange to +** eventually free it using sqlite3_free(). +*/ +static char *sqllogFindFile(const char *zFile){ + char *zRet = 0; + FILE *fd = 0; + + /* Open the index file for reading */ + fd = fopen(sqllogglobal.zIdx, "r"); + if( fd==0 ){ + sqlite3_log(SQLITE_IOERR, "sqllogFindFile(): error in fopen()"); + return 0; + } + + /* Loop through each entry in the index file. If zFile is not NULL and the + ** entry is a match, then set zRet to point to the filename of the existing + ** copy and break out of the loop. */ + while( feof(fd)==0 ){ + char zLine[SQLLOG_NAMESZ*2+5]; + if( fgets(zLine, sizeof(zLine), fd) ){ + int n; + char *z; + + zLine[sizeof(zLine)-1] = '\0'; + z = zLine; + while( *z>='0' && *z<='9' ) z++; + while( *z==' ' ) z++; + + n = strlen(z); + while( n>0 && sqllog_isspace(z[n-1]) ) n--; + + if( n==strlen(zFile) && 0==memcmp(zFile, z, n) ){ + char zBuf[16]; + memset(zBuf, 0, sizeof(zBuf)); + z = zLine; + while( *z>='0' && *z<='9' ){ + zBuf[z-zLine] = *z; + z++; + } + zRet = sqlite3_mprintf("%s_%s.db", sqllogglobal.zPrefix, zBuf); + break; + } + } + } + + if( ferror(fd) ){ + sqlite3_log(SQLITE_IOERR, "sqllogFindFile(): error reading index file"); + } + + fclose(fd); + return zRet; +} + +static int sqllogFindAttached( + struct SLConn *p, /* Database connection */ + const char *zSearch, /* Name to search for (or NULL) */ + char *zName, /* OUT: Name of attached database */ + char *zFile /* OUT: Name of attached file */ +){ + sqlite3_stmt *pStmt; + int rc; + + /* The "PRAGMA database_list" command returns a list of databases in the + ** order that they were attached. So a newly attached database is + ** described by the last row returned. */ + assert( sqllogglobal.bRec==0 ); + sqllogglobal.bRec = 1; + rc = sqlite3_prepare_v2(p->db, "PRAGMA database_list", -1, &pStmt, 0); + if( rc==SQLITE_OK ){ + while( SQLITE_ROW==sqlite3_step(pStmt) ){ + const char *zVal1; int nVal1; + const char *zVal2; int nVal2; + + zVal1 = (const char*)sqlite3_column_text(pStmt, 1); + nVal1 = sqlite3_column_bytes(pStmt, 1); + memcpy(zName, zVal1, nVal1+1); + + zVal2 = (const char*)sqlite3_column_text(pStmt, 2); + nVal2 = sqlite3_column_bytes(pStmt, 2); + memcpy(zFile, zVal2, nVal2+1); + + if( zSearch && strlen(zSearch)==nVal1 + && 0==sqlite3_strnicmp(zSearch, zVal1, nVal1) + ){ + break; + } + } + rc = sqlite3_finalize(pStmt); + } + sqllogglobal.bRec = 0; + + if( rc!=SQLITE_OK ){ + sqlite3_log(rc, "sqllogFindAttached(): error in \"PRAGMA database_list\""); + } + return rc; +} + + +/* +** Parameter zSearch is the name of a database attached to the database +** connection associated with the first argument. This function creates +** a backup of this database in the logs directory. +** +** The name used for the backup file is automatically generated. Call +** it zFile. +** +** If the bLog parameter is true, then a statement of the following form +** is written to the log file associated with *p: +** +** ATTACH 'zFile' AS 'zName'; +** +** Otherwise, if bLog is false, a comment is added to the log file: +** +** -- Main database file is 'zFile' +** +** The SLGlobal.mutex mutex is always held when this function is called. +*/ +static void sqllogCopydb(struct SLConn *p, const char *zSearch, int bLog){ + char zName[SQLLOG_NAMESZ]; /* Attached database name */ + char zFile[SQLLOG_NAMESZ]; /* Database file name */ + char *zFree; + char *zInit = 0; + int rc; + + rc = sqllogFindAttached(p, zSearch, zName, zFile); + if( rc!=SQLITE_OK ) return; + + if( zFile[0]=='\0' ){ + zInit = sqlite3_mprintf(""); + }else{ + if( sqllogglobal.bReuse ){ + zInit = sqllogFindFile(zFile); + }else{ + zInit = 0; + } + if( zInit==0 ){ + int rc; + sqlite3 *copy = 0; + int iDb; + + /* Generate a file-name to use for the copy of this database */ + iDb = sqllogglobal.iNextDb++; + zInit = sqlite3_mprintf("%s_%d.db", sqllogglobal.zPrefix, iDb); + + /* Create the backup */ + assert( sqllogglobal.bRec==0 ); + sqllogglobal.bRec = 1; + rc = sqlite3_open(zInit, ©); + if( rc==SQLITE_OK ){ + sqlite3_backup *pBak; + sqlite3_exec(copy, "PRAGMA synchronous = 0", 0, 0, 0); + pBak = sqlite3_backup_init(copy, "main", p->db, zName); + if( pBak ){ + sqlite3_backup_step(pBak, -1); + rc = sqlite3_backup_finish(pBak); + }else{ + rc = sqlite3_errcode(copy); + } + sqlite3_close(copy); + } + sqllogglobal.bRec = 0; + + if( rc==SQLITE_OK ){ + /* Write an entry into the database index file */ + FILE *fd = fopen(sqllogglobal.zIdx, "a"); + if( fd ){ + fprintf(fd, "%d %s\n", iDb, zFile); + fclose(fd); + } + }else{ + sqlite3_log(rc, "sqllogCopydb(): error backing up database"); + } + } + } + + if( bLog ){ + zFree = sqlite3_mprintf("ATTACH '%q' AS '%q'; -- clock=%d\n", + zInit, zName, sqllogglobal.iClock++ + ); + }else{ + zFree = sqlite3_mprintf("-- Main database is '%q'\n", zInit); + } + fprintf(p->fd, "%s", zFree); + sqlite3_free(zFree); + + sqlite3_free(zInit); +} + +/* +** If it is not already open, open the log file for connection *p. +** +** The SLGlobal.mutex mutex is always held when this function is called. +*/ +static void sqllogOpenlog(struct SLConn *p){ + /* If the log file has not yet been opened, open it now. */ + if( p->fd==0 ){ + char *zLog; + + /* If it is still NULL, have global.zPrefix point to a copy of + ** environment variable $ENVIRONMENT_VARIABLE1_NAME. */ + if( sqllogglobal.zPrefix[0]==0 ){ + FILE *fd; + char *zVar = getenv(ENVIRONMENT_VARIABLE1_NAME); + if( zVar==0 || strlen(zVar)+10>=(sizeof(sqllogglobal.zPrefix)) ) return; + sprintf(sqllogglobal.zPrefix, "%s/sqllog_%d", zVar, getProcessId()); + sprintf(sqllogglobal.zIdx, "%s.idx", sqllogglobal.zPrefix); + if( getenv(ENVIRONMENT_VARIABLE2_NAME) ){ + sqllogglobal.bReuse = atoi(getenv(ENVIRONMENT_VARIABLE2_NAME)); + } + fd = fopen(sqllogglobal.zIdx, "w"); + if( fd ) fclose(fd); + } + + /* Open the log file */ + zLog = sqlite3_mprintf("%s_%d.sql", sqllogglobal.zPrefix, p->iLog); + p->fd = fopen(zLog, "w"); + sqlite3_free(zLog); + if( p->fd==0 ){ + sqlite3_log(SQLITE_IOERR, "sqllogOpenlog(): Failed to open log file"); + } + } +} + +/* +** This function is called if the SQLLOG callback is invoked to report +** execution of an SQL statement. Parameter p is the connection the statement +** was executed by and parameter zSql is the text of the statement itself. +*/ +static void testSqllogStmt(struct SLConn *p, const char *zSql){ + const char *zFirst; /* Pointer to first token in zSql */ + int nFirst; /* Size of token zFirst in bytes */ + + sqllogTokenize(zSql, &zFirst, &nFirst); + if( nFirst!=6 || 0!=sqlite3_strnicmp("ATTACH", zFirst, 6) ){ + /* Not an ATTACH statement. Write this directly to the log. */ + fprintf(p->fd, "%s; -- clock=%d\n", zSql, sqllogglobal.iClock++); + }else{ + /* This is an ATTACH statement. Copy the database. */ + sqllogCopydb(p, 0, 1); + } +} + +/* +** The SQLITE_CONFIG_SQLLOG callback registered by sqlite3_init_sqllog(). +** +** The eType parameter has the following values: +** +** 0: Opening a new database connection. zSql is the name of the +** file being opened. db is a pointer to the newly created database +** connection. +** +** 1: An SQL statement has run to completion. zSql is the text of the +** SQL statement with all parameters expanded to their actual values. +** +** 2: Closing a database connection. zSql is NULL. The db pointer to +** the database connection being closed has already been shut down +** and cannot be used for any further SQL. +** +** The pCtx parameter is a copy of the pointer that was originally passed +** into the sqlite3_config(SQLITE_CONFIG_SQLLOG) statement. In this +** particular implementation, pCtx is always a pointer to the +** sqllogglobal global variable define above. +*/ +static void testSqllog(void *pCtx, sqlite3 *db, const char *zSql, int eType){ + struct SLConn *p = 0; + sqlite3_mutex *master = sqlite3_mutex_alloc(SQLITE_MUTEX_STATIC_MASTER); + + assert( eType==0 || eType==1 || eType==2 ); + assert( (eType==2)==(zSql==0) ); + + /* This is a database open command. */ + if( eType==0 ){ + sqlite3_mutex_enter(master); + if( sqllogglobal.mutex==0 ){ + sqllogglobal.mutex = sqlite3_mutex_alloc(SQLITE_MUTEX_RECURSIVE); + } + p = &sqllogglobal.aConn[sqllogglobal.nConn++]; + p->fd = 0; + p->db = db; + p->iLog = sqllogglobal.iNextLog++; + sqlite3_mutex_leave(master); + + /* Open the log and take a copy of the main database file */ + sqlite3_mutex_enter(sqllogglobal.mutex); + if( sqllogglobal.bRec==0 ){ + sqllogOpenlog(p); + if( p->fd ) sqllogCopydb(p, "main", 0); + } + sqlite3_mutex_leave(sqllogglobal.mutex); + } + + else{ + + int i; + for(i=0; i<sqllogglobal.nConn; i++){ + p = &sqllogglobal.aConn[i]; + if( p->db==db ) break; + } + if( i==sqllogglobal.nConn ) return; + + /* A database handle close command */ + if( eType==2 ){ + sqlite3_mutex_enter(master); + if( p->fd ) fclose(p->fd); + p->db = 0; + p->fd = 0; + + sqllogglobal.nConn--; + if( sqllogglobal.nConn==0 ){ + sqlite3_mutex_free(sqllogglobal.mutex); + sqllogglobal.mutex = 0; + }else{ + int nShift = &sqllogglobal.aConn[sqllogglobal.nConn] - p; + if( nShift>0 ){ + memmove(p, &p[1], nShift*sizeof(struct SLConn)); + } + } + sqlite3_mutex_leave(master); + + /* An ordinary SQL command. */ + }else if( p->fd ){ + sqlite3_mutex_enter(sqllogglobal.mutex); + if( sqllogglobal.bRec==0 ){ + testSqllogStmt(p, zSql); + } + sqlite3_mutex_leave(sqllogglobal.mutex); + } + } +} + +/* +** This function is called either before sqlite3_initialized() or by it. +** It checks if the SQLITE_SQLLOG_DIR variable is defined, and if so +** registers an SQLITE_CONFIG_SQLLOG callback to record the applications +** database activity. +*/ +void sqlite3_init_sqllog(void){ + if( getenv(ENVIRONMENT_VARIABLE1_NAME) ){ + if( SQLITE_OK==sqlite3_config(SQLITE_CONFIG_SQLLOG, testSqllog, 0) ){ + memset(&sqllogglobal, 0, sizeof(sqllogglobal)); + sqllogglobal.bReuse = 1; + } + } +} |