Index: src/mutex.c ================================================================== --- src/mutex.c +++ src/mutex.c @@ -12,10 +12,16 @@ ** This file contains the C functions that implement mutexes. ** ** This file contains code that is common across all mutex implementations. */ #include "sqliteInt.h" +#if SQLITE_OS_UNIX +# include +# include +#elif SQLITE_OS_WIN +# include "os_win.h" +#endif #if defined(SQLITE_DEBUG) && !defined(SQLITE_MUTEX_OMIT) /* ** For debugging purposes, record when the mutex subsystem is initialized ** and uninitialized so that we can assert() if there is an attempt to @@ -80,10 +86,51 @@ GLOBAL(int, mutexIsInit) = 0; #endif return rc; } + +#if SQLITE_MUTEX_ALERT_MILLISECONDS>0 +/* Return a time value for use by the mutex subsystem. */ +i64 sqlite3MutexTimeOfDay(void){ +#ifdef SQLITE_GET_MUTEX_TIME + SQLITE_GET_MUTEX_TIME; +#else + return 0; +#endif +} + +/* +** Calculates the elapsed time, in milliseconds, that a particular mutex +** was held and issues a warning, via the sqlite3_log() interface, if it +** was held for "too long". +*/ +void sqlite3MutexTimeAlert( + sqlite3_mutex *p, + i64 entered +){ + i64 exited = sqlite3MutexTimeOfDay(); + i64 elapsed; + assert( p!=0 ); + assert( exited>=entered ); + elapsed = exited - entered; + if( elapsed>SQLITE_MUTEX_ALERT_MILLISECONDS ){ + void *tid = 0; + int mid = -1; +#ifdef SQLITE_GET_THREAD_ID + tid = SQLITE_GET_THREAD_ID(); +#endif +#ifdef SQLITE_GET_MUTEX_ID + mid = SQLITE_GET_MUTEX_ID(p); +#endif + sqlite3_log(SQLITE_NOTICE, + "thread %p delayed %lldms for mutex %p (%d)", + tid, elapsed, p, mid + ); + } +} +#endif /* ** Retrieve a pointer to a static mutex or allocate a new dynamic one. */ sqlite3_mutex *sqlite3_mutex_alloc(int id){ Index: src/mutex_noop.c ================================================================== --- src/mutex_noop.c +++ src/mutex_noop.c @@ -78,10 +78,13 @@ ** The mutex object */ typedef struct sqlite3_debug_mutex { int id; /* The mutex type */ int cnt; /* Number of entries without a matching leave */ +#if SQLITE_MUTEX_ALERT_MILLISECONDS>0 + i64 entered; /* Time that mutex was entered */ +#endif } sqlite3_debug_mutex; /* ** The sqlite3_mutex_held() and sqlite3_mutex_notheld() routine are ** intended for use inside assert() statements. @@ -162,15 +165,21 @@ */ static void debugMutexEnter(sqlite3_mutex *pX){ sqlite3_debug_mutex *p = (sqlite3_debug_mutex*)pX; assert( p->id==SQLITE_MUTEX_RECURSIVE || debugMutexNotheld(pX) ); p->cnt++; +#if SQLITE_MUTEX_ALERT_MILLISECONDS>0 + p->entered = sqlite3MutexTimeOfDay(); +#endif } static int debugMutexTry(sqlite3_mutex *pX){ sqlite3_debug_mutex *p = (sqlite3_debug_mutex*)pX; assert( p->id==SQLITE_MUTEX_RECURSIVE || debugMutexNotheld(pX) ); p->cnt++; +#if SQLITE_MUTEX_ALERT_MILLISECONDS>0 + p->entered = sqlite3MutexTimeOfDay(); +#endif return SQLITE_OK; } /* ** The sqlite3_mutex_leave() routine exits a mutex that was @@ -179,10 +188,13 @@ ** is not currently allocated. SQLite will never do either. */ static void debugMutexLeave(sqlite3_mutex *pX){ sqlite3_debug_mutex *p = (sqlite3_debug_mutex*)pX; assert( debugMutexHeld(pX) ); +#if SQLITE_MUTEX_ALERT_MILLISECONDS>0 + sqlite3MutexTimeAlert((sqlite3_mutex*)p, p->entered); +#endif p->cnt--; assert( p->id==SQLITE_MUTEX_RECURSIVE || debugMutexNotheld(pX) ); } sqlite3_mutex_methods const *sqlite3NoopMutex(void){ Index: src/mutex_unix.c ================================================================== --- src/mutex_unix.c +++ src/mutex_unix.c @@ -41,10 +41,13 @@ struct sqlite3_mutex { pthread_mutex_t mutex; /* Mutex controlling the lock */ #if SQLITE_MUTEX_NREF || defined(SQLITE_ENABLE_API_ARMOR) int id; /* Mutex type */ #endif +#if SQLITE_MUTEX_ALERT_MILLISECONDS>0 + i64 entered; /* Time that mutex was entered */ +#endif #if SQLITE_MUTEX_NREF volatile int nRef; /* Number of entrances */ volatile pthread_t owner; /* Thread that is within this mutex */ int trace; /* True to trace changes */ #endif @@ -259,19 +262,25 @@ pthread_t self = pthread_self(); if( p->nRef>0 && pthread_equal(p->owner, self) ){ p->nRef++; }else{ pthread_mutex_lock(&p->mutex); +#if SQLITE_MUTEX_ALERT_MILLISECONDS>0 + p->entered = sqlite3MutexTimeOfDay(); +#endif assert( p->nRef==0 ); p->owner = self; p->nRef = 1; } } #else /* Use the built-in recursive mutexes if they are available. */ pthread_mutex_lock(&p->mutex); +#if SQLITE_MUTEX_ALERT_MILLISECONDS>0 + p->entered = sqlite3MutexTimeOfDay(); +#endif #if SQLITE_MUTEX_NREF assert( p->nRef>0 || p->owner==0 ); p->owner = pthread_self(); p->nRef++; #endif @@ -302,10 +311,13 @@ pthread_t self = pthread_self(); if( p->nRef>0 && pthread_equal(p->owner, self) ){ p->nRef++; rc = SQLITE_OK; }else if( pthread_mutex_trylock(&p->mutex)==0 ){ +#if SQLITE_MUTEX_ALERT_MILLISECONDS>0 + p->entered = sqlite3MutexTimeOfDay(); +#endif assert( p->nRef==0 ); p->owner = self; p->nRef = 1; rc = SQLITE_OK; }else{ @@ -314,10 +326,13 @@ } #else /* Use the built-in recursive mutexes if they are available. */ if( pthread_mutex_trylock(&p->mutex)==0 ){ +#if SQLITE_MUTEX_ALERT_MILLISECONDS>0 + p->entered = sqlite3MutexTimeOfDay(); +#endif #if SQLITE_MUTEX_NREF p->owner = pthread_self(); p->nRef++; #endif rc = SQLITE_OK; @@ -348,13 +363,19 @@ #endif assert( p->nRef==0 || p->id==SQLITE_MUTEX_RECURSIVE ); #ifdef SQLITE_HOMEGROWN_RECURSIVE_MUTEX if( p->nRef==0 ){ +#if SQLITE_MUTEX_ALERT_MILLISECONDS>0 + sqlite3MutexTimeAlert(p, p->entered); +#endif pthread_mutex_unlock(&p->mutex); } #else +#if SQLITE_MUTEX_ALERT_MILLISECONDS>0 + sqlite3MutexTimeAlert(p, p->entered); +#endif pthread_mutex_unlock(&p->mutex); #endif #ifdef SQLITE_DEBUG if( p->trace ){ Index: src/mutex_w32.c ================================================================== --- src/mutex_w32.c +++ src/mutex_w32.c @@ -35,10 +35,13 @@ ** Each recursive mutex is an instance of the following structure. */ struct sqlite3_mutex { CRITICAL_SECTION mutex; /* Mutex controlling the lock */ int id; /* Mutex type */ +#if SQLITE_MUTEX_ALERT_MILLISECONDS>0 + i64 entered; /* Time that mutex was entered */ +#endif #ifdef SQLITE_DEBUG volatile int nRef; /* Number of enterances */ volatile DWORD owner; /* Thread holding this mutex */ volatile int trace; /* True to trace changes */ #endif @@ -291,10 +294,13 @@ #else assert( p ); #endif assert( winMutex_isInit==1 ); EnterCriticalSection(&p->mutex); +#if SQLITE_MUTEX_ALERT_MILLISECONDS>0 + p->entered = sqlite3MutexTimeOfDay(); +#endif #ifdef SQLITE_DEBUG assert( p->nRef>0 || p->owner==0 ); p->owner = tid; p->nRef++; if( p->trace ){ @@ -328,10 +334,13 @@ if( winMutex_isNt<0 ){ winMutex_isNt = sqlite3_win32_is_nt(); } assert( winMutex_isNt==0 || winMutex_isNt==1 ); if( winMutex_isNt && TryEnterCriticalSection(&p->mutex) ){ +#if SQLITE_MUTEX_ALERT_MILLISECONDS>0 + p->entered = sqlite3MutexTimeOfDay(); +#endif #ifdef SQLITE_DEBUG p->owner = tid; p->nRef++; #endif rc = SQLITE_OK; @@ -365,10 +374,13 @@ p->nRef--; if( p->nRef==0 ) p->owner = 0; assert( p->nRef==0 || p->id==SQLITE_MUTEX_RECURSIVE ); #endif assert( winMutex_isInit==1 ); +#if SQLITE_MUTEX_ALERT_MILLISECONDS>0 + sqlite3MutexTimeAlert(p, p->entered); +#endif LeaveCriticalSection(&p->mutex); #ifdef SQLITE_DEBUG if( p->trace ){ OSTRACE(("LEAVE-MUTEX tid=%lu, mutex=%p (%d), nRef=%d\n", tid, p, p->trace, p->nRef)); Index: src/sqliteInt.h ================================================================== --- src/sqliteInt.h +++ src/sqliteInt.h @@ -3524,10 +3524,86 @@ void sqlite3MemoryBarrier(void); #else # define sqlite3MemoryBarrier() #endif +/* +** When SQLITE_MUTEX_ALERT_MILLISECONDS is greater than zero, extra code +** will be included to issue warnings via the sqlite3_log() interface if +** a mutex is held for longer than the number of milliseconds specified +** by SQLITE_MUTEX_ALERT_MILLISECONDS. +*/ +#ifndef SQLITE_MUTEX_ALERT_MILLISECONDS +# define SQLITE_MUTEX_ALERT_MILLISECONDS (0) +#endif + +#if !defined(SQLITE_MUTEX_OMIT) && SQLITE_MUTEX_ALERT_MILLISECONDS>0 + i64 sqlite3MutexTimeOfDay(void); + void sqlite3MutexTimeAlert(sqlite3_mutex *, i64); + +/* +** This macro contains code that returns a 64-bit integer time value, +** in milliseconds, or zero if that information is not available. +*/ +# ifndef SQLITE_GET_MUTEX_TIME +# if SQLITE_OS_UNIX +# define SQLITE_GET_MUTEX_TIME { \ + struct timeval sNow; (void)gettimeofday(&sNow, 0); \ + return 1000*(i64)sNow.tv_sec + sNow.tv_usec/1000; \ + } +# elif SQLITE_OS_WIN +# define SQLITE_GET_MUTEX_TIME { \ + return (i64)GetTickCount(); \ + } +# else +# define SQLITE_GET_MUTEX_TIME { \ + return 0; \ + } +# endif +# endif + +/* +** This macro returns the integer type for the specified mutex or +** negative one if that information is not available. +*/ +# ifndef SQLITE_GET_MUTEX_ID +# if SQLITE_OS_UNIX +# if SQLITE_MUTEX_NREF || defined(SQLITE_ENABLE_API_ARMOR) +# define SQLITE_GET_MUTEX_ID(p) \ + *((int*)(((unsigned char*)(p))+sizeof(pthread_mutex_t))) +# else +# define SQLITE_GET_MUTEX_ID(p) (-1) +# endif +# elif SQLITE_OS_WIN +# define SQLITE_GET_MUTEX_ID(p) \ + *((int*)(((unsigned char*)(p))+sizeof(CRITICAL_SECTION))) +# else +# define SQLITE_GET_MUTEX_ID(p) (-1) +# endif +# endif + +/* +** This macro returns the integer identifier for the current thread +** or zero if that information is not available. +*/ +# ifndef SQLITE_GET_THREAD_ID +# if SQLITE_OS_UNIX +# define SQLITE_GET_THREAD_ID() ((void *)pthread_self()) +# elif SQLITE_OS_WIN +# define SQLITE_GET_THREAD_ID() ((void *)GetCurrentThreadId()) +# else +# define SQLITE_GET_THREAD_ID() ((void *)0) +# endif +# endif +#else +# define sqlite3MutexTimeOfDay() (0) +# define sqlite3MutexTimeAlert(X,Y) +# define SQLITE_GET_MUTEX_TIME +# define SQLITE_GET_MUTEX_ID(p) (-1) +# define SQLITE_GET_THREAD_ID() ((void *)0) +#endif + sqlite3_int64 sqlite3StatusValue(int); void sqlite3StatusUp(int, int); void sqlite3StatusDown(int, int); void sqlite3StatusHighwater(int, int);