/* ** 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: ** ** 1) The initial contents of all database files opened by the ** application, and ** ** 2) All SQL statements executed by the application. ** ** 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 ** somehow. ** ** 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 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 behaviour 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(). */ #include "sqlite3.h" #include "stdio.h" #include "stdlib.h" #include "string.h" #include "assert.h" #include "sys/types.h" #include "unistd.h" static int getProcessId(void){ return (int)getpid(); } #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 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 */ }; 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) ){ char *zVal1; int nVal1; char *zVal2; int nVal2; zVal1 = sqlite3_column_text(pStmt, 1); nVal1 = sqlite3_column_bytes(pStmt, 1); memcpy(zName, zVal1, nVal1+1); zVal2 = 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(). */ static void testSqllog(void *pCtx, sqlite3 *db, const char *zSql, int eType){ struct SLConn *p; 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; idb==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; } } }