summaryrefslogtreecommitdiffstats
path: root/src/test_sqllog.c
diff options
context:
space:
mode:
Diffstat (limited to '')
-rw-r--r--src/test_sqllog.c556
1 files changed, 556 insertions, 0 deletions
diff --git a/src/test_sqllog.c b/src/test_sqllog.c
new file mode 100644
index 0000000..9ae0e50
--- /dev/null
+++ b/src/test_sqllog.c
@@ -0,0 +1,556 @@
+/*
+** 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.
+**
+** If the environment variable SQLITE_SQLLOG_CONDITIONAL is defined, then
+** logging is only done for database connections if a file named
+** "<database>-sqllog" exists in the same directly as the main database
+** file when it is first opened ("<database>" is replaced by the actual
+** name of the main database file).
+**
+** 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"
+#define ENVIRONMENT_VARIABLE3_NAME "SQLITE_SQLLOG_CONDITIONAL"
+
+/* 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_MAIN */
+ sqlite3_mutex *mutex; /* Recursive mutex */
+ int nConn; /* Size of aConn[] array */
+
+ /* Protected by SLGlobal.mutex */
+ int bConditional; /* Only trace if *-sqllog file is present */
+ 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(
+ sqlite3 *db, /* 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(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);
+ if( zName ){
+ 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->db, 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_%02d.db", sqllogglobal.zPrefix, iDb);
+
+ /* Create the backup */
+ assert( sqllogglobal.bRec==0 );
+ sqllogglobal.bRec = 1;
+ rc = sqlite3_open(zInit, &copy);
+ 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;
+ sqlite3_snprintf(sizeof(sqllogglobal.zPrefix), sqllogglobal.zPrefix,
+ "%s/sqllog_%05d", zVar, getProcessId());
+ sqlite3_snprintf(sizeof(sqllogglobal.zIdx), 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_%05d.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 database handle passed as the only argument has just been opened.
+** Return true if this module should log initial databases and SQL
+** statements for this connection, or false otherwise.
+**
+** If an error occurs, sqlite3_log() is invoked to report it to the user
+** and zero returned.
+*/
+static int sqllogTraceDb(sqlite3 *db){
+ int bRet = 1;
+ if( sqllogglobal.bConditional ){
+ char zFile[SQLLOG_NAMESZ]; /* Attached database name */
+ int rc = sqllogFindAttached(db, "main", 0, zFile);
+ if( rc==SQLITE_OK ){
+ int nFile = strlen(zFile);
+ if( (SQLLOG_NAMESZ-nFile)<8 ){
+ sqlite3_log(SQLITE_IOERR,
+ "sqllogTraceDb(): database name too long (%d bytes)", nFile
+ );
+ bRet = 0;
+ }else{
+ memcpy(&zFile[nFile], "-sqllog", 8);
+ bRet = !access(zFile, F_OK);
+ }
+ }
+ }
+ return bRet;
+}
+
+/*
+** 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 *mainmtx = sqlite3_mutex_alloc(SQLITE_MUTEX_STATIC_MAIN);
+
+ assert( eType==0 || eType==1 || eType==2 );
+ assert( (eType==2)==(zSql==0) );
+
+ /* This is a database open command. */
+ if( eType==0 ){
+ sqlite3_mutex_enter(mainmtx);
+ if( sqllogglobal.mutex==0 ){
+ sqllogglobal.mutex = sqlite3_mutex_alloc(SQLITE_MUTEX_RECURSIVE);
+ }
+ sqlite3_mutex_leave(mainmtx);
+
+ sqlite3_mutex_enter(sqllogglobal.mutex);
+ if( sqllogglobal.bRec==0 && sqllogTraceDb(db) ){
+
+ sqlite3_mutex_enter(mainmtx);
+ p = &sqllogglobal.aConn[sqllogglobal.nConn++];
+ p->fd = 0;
+ p->db = db;
+ p->iLog = sqllogglobal.iNextLog++;
+ sqlite3_mutex_leave(mainmtx);
+
+ /* Open the log and take a copy of the main database file */
+ 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;
+ }
+
+ /* A database handle close command */
+ if( eType==2 ){
+ sqlite3_mutex_enter(mainmtx);
+ if( i<sqllogglobal.nConn ){
+ 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 if( i<sqllogglobal.nConn ){
+ int nShift = &sqllogglobal.aConn[sqllogglobal.nConn] - p;
+ if( nShift>0 ){
+ memmove(p, &p[1], nShift*sizeof(struct SLConn));
+ }
+ }
+ sqlite3_mutex_leave(mainmtx);
+
+ /* An ordinary SQL command. */
+ }else if( i<sqllogglobal.nConn && 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;
+ if( getenv(ENVIRONMENT_VARIABLE3_NAME) ){
+ sqllogglobal.bConditional = 1;
+ }
+ }
+ }
+}