508 lines
16 KiB
C
508 lines
16 KiB
C
/*
|
|
** 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;
|
|
}
|
|
}
|
|
}
|