Remove all timers and other debugging logs except for the one timer on
pcache1TruncateUnsafe().
FossilOrigin-Name: 5980e625dbb694dc3b0535e71fd986a6d211e245
diff --git a/manifest b/manifest
index 84fa580..5b8d528 100644
--- a/manifest
+++ b/manifest
@@ -1,5 +1,5 @@
-C Add\sanother\stimer\son\spcache1TruncateUnsafe().
-D 2016-08-09T11:44:06.664
+C Remove\sall\stimers\sand\sother\sdebugging\slogs\sexcept\sfor\sthe\sone\stimer\son\npcache1TruncateUnsafe().
+D 2016-08-10T02:54:15.340
F Makefile.arm-wince-mingw32ce-gcc d6df77f1f48d690bd73162294bbba7f59507c72f
F Makefile.in cf57f673d77606ab0f2d9627ca52a9ba1464146a
F Makefile.linux-gcc 91d710bdc4998cb015f39edf3cb314ec4f4d7e23
@@ -205,22 +205,22 @@
F src/mutex.c 84a073c9a23a8d7bdd2ea832522d1730df18812c
F src/mutex.h 779d588e3b7756ec3ecf7d78cde1d84aba414f85
F src/mutex_noop.c f3f09fd7a2eb4287cfc799753ffc30380e7b71a1
-F src/mutex_unix.c 543aab0a578f09ad15e2b743789e4cfe8ab04cf5
+F src/mutex_unix.c 1b10d5413dfc794364a8adf3eb3a192926b43fa3
F src/mutex_w32.c 06bfff9a3a83b53389a51a967643db3967032e1e
F src/notify.c 9711a7575036f0d3040ba61bc6e217f13a9888e7
-F src/os.c a93752993c14b6496ec50212e093a3825e10ce8f
+F src/os.c 1b147e4cf7cc39e618115c14a086aed44bc91ace
F src/os.h 3e57a24e2794a94d3cf2342c6d9a884888cd96bf
F src/os_common.h 92815ed65f805560b66166e3583470ff94478f04
F src/os_setup.h c9d4553b5aaa6f73391448b265b89bed0b890faa
-F src/os_unix.c e7157dfa077c06aaeecdfc4dcb6b0a489ef5c57a
+F src/os_unix.c fb587121840f690101336879adfa6d0b2cd0e8c7
F src/os_win.c a019caaae2bcbbc0cc4c39af6e7d7e43d8426053
F src/os_win.h 09e751b20bbc107ffbd46e13555dc73576d88e21
-F src/pager.c d69ede96f8fac2d0c9c3be64eb06edfe682b01ef
+F src/pager.c 8d97b3633f098fef817656dcbf167ca904511d78
F src/pager.h d1eee3c3f741be247ce6d82752a178515fc8578b
F src/parse.y 5dfead8aed90cb0c7c1115898ee2266804daff45
F src/pcache.c 4121a0571c18581ee9f82f086d5e2030051ebd6a
F src/pcache.h 9b559127b83f84ff76d735c8262f04853be0c59a
-F src/pcache1.c eeb485caa40fda583d21977a7b5fbd3852904d7f
+F src/pcache1.c 938bc830177ccd5198ab07a7522338c8598a00f7
F src/pragma.c 3f3e959390a10c0131676f0e307acce372777e0f
F src/prepare.c 6ef0cf2f9274982988ed6b7cab1be23147e94196
F src/printf.c 090fac0f779c93c8a95089a125339686648835e4
@@ -292,14 +292,14 @@
F src/vdbe.c 5ee15a66ce07e0482b92aa29e4dd0c5827a22d79
F src/vdbe.h 09f5b4e3719fa454f252322b1cdab5cf1f361327
F src/vdbeInt.h e2a060a55ee18a6ab973353a5e2ec7ee569bf787
-F src/vdbeapi.c 4fc644896359dc095481b80336888eb3aad7c4aa
-F src/vdbeaux.c e755d2a3d873a8211689219b385e7c86243ad24d
+F src/vdbeapi.c 37a6c6ae284a97bcace365f2f0a225680c0499d9
+F src/vdbeaux.c edbb7a9c8b2a8f7a68ac75c2475edd4040266b76
F src/vdbeblob.c 848238dc73e93e48432991bb5651bf87d865eca4
F src/vdbemem.c 31d8eabb0cd78bfeab4e5124c7363c3e9e54db9f
F src/vdbesort.c 975aeffa99acb0991b2f288d30294756bff41438
F src/vdbetrace.c 7e4222955e07dd707a2f360c0eb73452be1cb010
F src/vtab.c cb0c194303fea276b48d7d4b6d970b5a96bde8de
-F src/wal.c 430abe09fd057a8789a9589a3db366c40f1427dc
+F src/wal.c 10e7de7ce90865a68153f001a61f1d985cd17983
F src/wal.h df01efe09c5cb8c8e391ff1715cca294f89668a4
F src/walker.c c253b95b4ee44b21c406e2a1052636c31ea27804
F src/where.c 4ce8c4826b7f86d080f0ed4e7a9045bb5014be77
@@ -1207,7 +1207,7 @@
F tool/warnings-clang.sh f6aa929dc20ef1f856af04a730772f59283631d4
F tool/warnings.sh 0abfd78ceb09b7f7c27c688c8e3fe93268a13b32
F tool/win/sqlite.vsix deb315d026cc8400325c5863eef847784a219a2f
-P 7d0af4b53c440f4628f0cecdc40459335630fa4e
-R 67c20c387fa50de70cf8667debaaa82a
+P 42ce53f648a506d0a5d9c1231eb28c11b4e6b124
+R e064622bb758d47c8c7ad1ed3f41c26c
U drh
-Z 63fcef9cf7b93ddf816f7412e9d532bf
+Z 49509f85b3a161b812f3ddad4852a442
diff --git a/manifest.uuid b/manifest.uuid
index 7095413..032f706 100644
--- a/manifest.uuid
+++ b/manifest.uuid
@@ -1 +1 @@
-42ce53f648a506d0a5d9c1231eb28c11b4e6b124
\ No newline at end of file
+5980e625dbb694dc3b0535e71fd986a6d211e245
\ No newline at end of file
diff --git a/src/mutex_unix.c b/src/mutex_unix.c
index 9b16c0e..c866314 100644
--- a/src/mutex_unix.c
+++ b/src/mutex_unix.c
@@ -200,13 +200,6 @@
sqlite3_free(p);
}
-#include <sys/time.h>
-#ifdef SQLITE_MUTEX_NREF
-# define MUTEX_ID(p) (p->id)
-#else
-# define MUTEX_ID(p) 0
-#endif
-
/*
** The sqlite3_mutex_enter() and sqlite3_mutex_try() routines attempt
** to enter a mutex. If another thread is already within the mutex,
@@ -219,8 +212,6 @@
** more than once, the behavior is undefined.
*/
static void pthreadMutexEnter(sqlite3_mutex *p){
-
- START_DEBUG_TIMER;
assert( p->id==SQLITE_MUTEX_RECURSIVE || pthreadMutexNotheld(p) );
#ifdef SQLITE_HOMEGROWN_RECURSIVE_MUTEX
@@ -254,14 +245,6 @@
p->owner = pthread_self();
p->nRef++;
#endif
- END_DEBUG_TIMER(500) {
- sqlite3_mutex *pMaster = sqlite3_mutex_alloc(SQLITE_MUTEX_STATIC_MASTER);
- int id = -1;
- if( p>=pMaster && p<=&pMaster[SQLITE_MUTEX_STATIC_APP3-2] ){
- id = (int)(p - pMaster) + 2;
- }
- sqlite3_log(SQLITE_NOTICE, "slow mutex: %llu uS on %d/%p",iDebugTimer,id,p);
- }
#endif
#ifdef SQLITE_DEBUG
diff --git a/src/os.c b/src/os.c
index f9665e3..b6c28a1 100644
--- a/src/os.c
+++ b/src/os.c
@@ -61,14 +61,10 @@
*/
int sqlite3OsClose(sqlite3_file *pId){
int rc = SQLITE_OK;
- START_DEBUG_TIMER;
if( pId->pMethods ){
rc = pId->pMethods->xClose(pId);
pId->pMethods = 0;
}
- END_DEBUG_TIMER( DEBUG_TIMER_SMALL_TIMEOUT ){
- sqlite3_log(SQLITE_NOTICE, "slow sqlite3OsClose: %llu uS", iDebugTimer);
- }
return rc;
}
int sqlite3OsRead(sqlite3_file *id, void *pBuf, int amt, i64 offset){
@@ -83,15 +79,8 @@
return id->pMethods->xTruncate(id, size);
}
int sqlite3OsSync(sqlite3_file *id, int flags){
- int rc;
- START_DEBUG_TIMER;
- rc = id->pMethods->xSync(id, flags);
- END_DEBUG_TIMER( DEBUG_TIMER_SMALL_TIMEOUT ){
- sqlite3_log(SQLITE_NOTICE,
- "slow sqlite3OsSync(ptr, %d): %llu uS", flags, iDebugTimer
- );
- }
- return rc;
+ DO_OS_MALLOC_TEST(id);
+ return id->pMethods->xSync(id, flags);
}
int sqlite3OsFileSize(sqlite3_file *id, i64 *pSize){
DO_OS_MALLOC_TEST(id);
@@ -118,8 +107,6 @@
** routine has no return value since the return value would be meaningless.
*/
int sqlite3OsFileControl(sqlite3_file *id, int op, void *pArg){
- int rc;
- START_DEBUG_TIMER;
#ifdef SQLITE_TEST
if( op!=SQLITE_FCNTL_COMMIT_PHASETWO ){
/* Faults are not injected into COMMIT_PHASETWO because, assuming SQLite
@@ -135,12 +122,7 @@
DO_OS_MALLOC_TEST(id);
}
#endif
- rc = id->pMethods->xFileControl(id, op, pArg);
- END_DEBUG_TIMER( DEBUG_TIMER_SMALL_TIMEOUT ){
- sqlite3_log(SQLITE_NOTICE,
- "slow sqlite3OsFileControl: %llu uS", iDebugTimer);
- }
- return rc;
+ return id->pMethods->xFileControl(id, op, pArg);
}
void sqlite3OsFileControlHint(sqlite3_file *id, int op, void *pArg){
(void)id->pMethods->xFileControl(id, op, pArg);
@@ -154,25 +136,10 @@
return id->pMethods->xDeviceCharacteristics(id);
}
int sqlite3OsShmLock(sqlite3_file *id, int offset, int n, int flags){
- int rc;
- START_DEBUG_TIMER;
- rc = id->pMethods->xShmLock(id, offset, n, flags);
- END_DEBUG_TIMER( DEBUG_TIMER_SMALL_TIMEOUT ){
- sqlite3_log(SQLITE_NOTICE,
- "slow sqlite3OsShmLock(ptr, %d, %d, %d): %llu uS",
- offset, n, flags, iDebugTimer
- );
- }
- return rc;
+ return id->pMethods->xShmLock(id, offset, n, flags);
}
void sqlite3OsShmBarrier(sqlite3_file *id){
- START_DEBUG_TIMER;
id->pMethods->xShmBarrier(id);
- END_DEBUG_TIMER( DEBUG_TIMER_SMALL_TIMEOUT ){
- sqlite3_log(SQLITE_NOTICE,
- "slow sqlite3OsShmBarrier: %llu uS", iDebugTimer
- );
- }
}
int sqlite3OsShmUnmap(sqlite3_file *id, int deleteFlag){
return id->pMethods->xShmUnmap(id, deleteFlag);
diff --git a/src/os_unix.c b/src/os_unix.c
index fbf14cf..a9344ee 100644
--- a/src/os_unix.c
+++ b/src/os_unix.c
@@ -4629,12 +4629,8 @@
sqlite3_file *fd /* Database file holding the shared memory */
){
UNUSED_PARAMETER(fd);
-#if defined(__GNUC__) && GCC_VERSION>=4001000
- __sync_synchronize();
-#else
unixEnterMutex();
unixLeaveMutex();
-#endif
}
/*
diff --git a/src/pager.c b/src/pager.c
index 1222cbb..997f842 100644
--- a/src/pager.c
+++ b/src/pager.c
@@ -1907,7 +1907,6 @@
static int pager_end_transaction(Pager *pPager, int hasMaster, int bCommit){
int rc = SQLITE_OK; /* Error code from journal finalization operation */
int rc2 = SQLITE_OK; /* Error code from db file unlock operation */
- START_DEBUG_TIMER;
/* Do nothing if the pager does not have an open write transaction
** or at least a RESERVED lock. This function may be called when there
@@ -1974,11 +1973,6 @@
}
}
}
- END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ){
- sqlite3_log(SQLITE_NOTICE, "slow pager_end_transaction(1): %llu uS wal=%d",
- iDebugTimer, pagerUseWal(pPager));
- iDebugTimerStart += iDebugTimer;
- }
#ifdef SQLITE_CHECK_PAGES
sqlite3PcacheIterateDirty(pPager->pPCache, pager_set_pagehash);
@@ -1995,17 +1989,7 @@
pPager->pInJournal = 0;
pPager->nRec = 0;
sqlite3PcacheCleanAll(pPager->pPCache);
- END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ){
- sqlite3_log(SQLITE_NOTICE, "slow pager_end_transaction(2): %llu uS wal=%d",
- iDebugTimer, pagerUseWal(pPager));
- iDebugTimerStart += iDebugTimer;
- }
sqlite3PcacheTruncate(pPager->pPCache, pPager->dbSize);
- END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ){
- sqlite3_log(SQLITE_NOTICE, "slow pager_end_transaction(3): %llu uS wal=%d",
- iDebugTimer, pagerUseWal(pPager));
- iDebugTimerStart += iDebugTimer;
- }
if( pagerUseWal(pPager) ){
/* Drop the WAL write-lock, if any. Also, if the connection was in
@@ -2024,11 +2008,6 @@
assert( pPager->eLock==EXCLUSIVE_LOCK );
rc = pager_truncate(pPager, pPager->dbSize);
}
- END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ){
- sqlite3_log(SQLITE_NOTICE, "slow pager_end_transaction(4): %llu uS wal=%d",
- iDebugTimer, pagerUseWal(pPager));
- iDebugTimerStart += iDebugTimer;
- }
if( rc==SQLITE_OK && bCommit && isOpen(pPager->fd) ){
rc = sqlite3OsFileControl(pPager->fd, SQLITE_FCNTL_COMMIT_PHASETWO, 0);
@@ -2044,10 +2023,6 @@
pPager->eState = PAGER_READER;
pPager->setMaster = 0;
- END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ){
- sqlite3_log(SQLITE_NOTICE, "slow pager_end_transaction(5): %llu uS wal=%d",
- iDebugTimer, pagerUseWal(pPager));
- }
return (rc==SQLITE_OK?rc2:rc);
}
diff --git a/src/pcache1.c b/src/pcache1.c
index c66d063..5ae4ad0 100644
--- a/src/pcache1.c
+++ b/src/pcache1.c
@@ -521,8 +521,11 @@
}
assert( pCache->nPage==nPage );
END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ){
- sqlite3_log(SQLITE_NOTICE, "slow pcache1TruncateUnsafe() %lld nFree=%d",
- iDebugTimer, nFree);
+ sqlite3_log(SQLITE_NOTICE,
+ "slow pcache1TruncateUnsafe() %lld "
+ " nFree=%d nHash=%d nPage=%d iLimit=%d iMaxKey=%d",
+ iDebugTimer,
+ nFree, pCache->nHash, pCache->nPage, iLimit, pCache->iMaxKey);
}
}
@@ -934,17 +937,12 @@
*/
static void pcache1Truncate(sqlite3_pcache *p, unsigned int iLimit){
PCache1 *pCache = (PCache1 *)p;
- START_DEBUG_TIMER;
pcache1EnterMutex(pCache->pGroup);
if( iLimit<=pCache->iMaxKey ){
pcache1TruncateUnsafe(pCache, iLimit);
pCache->iMaxKey = iLimit-1;
}
pcache1LeaveMutex(pCache->pGroup);
- END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ){
- sqlite3_log(SQLITE_NOTICE, "slow pcache1Truncate(%d): %llu uS",
- (int)iLimit, iDebugTimer);
- }
}
/*
diff --git a/src/vdbeapi.c b/src/vdbeapi.c
index 857494e..0ab76e0 100644
--- a/src/vdbeapi.c
+++ b/src/vdbeapi.c
@@ -395,7 +395,6 @@
*/
static int doWalCallbacks(sqlite3 *db){
int rc = SQLITE_OK;
- START_DEBUG_TIMER;
#ifndef SQLITE_OMIT_WAL
int i;
for(i=0; i<db->nDb; i++){
@@ -408,9 +407,6 @@
}
}
#endif
- END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ) {
- sqlite3_log(SQLITE_NOTICE, "slow doWalCallbacks: %llu uS", iDebugTimer);
- }
return rc;
}
@@ -426,7 +422,6 @@
static int sqlite3Step(Vdbe *p){
sqlite3 *db;
int rc;
- START_DEBUG_TIMER;
assert(p);
if( p->magic!=VDBE_MAGIC_RUN ){
@@ -545,11 +540,6 @@
*/
rc = sqlite3VdbeTransferError(p);
}
- END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ) {
- sqlite3_log(SQLITE_NOTICE, "slow (%llu) sqlite3Step(%s)",
- iDebugTimer, (p->zSql ? p->zSql : "")
- );
- }
return (rc&db->errMask);
}
diff --git a/src/vdbeaux.c b/src/vdbeaux.c
index a2c969a..c0018bb 100644
--- a/src/vdbeaux.c
+++ b/src/vdbeaux.c
@@ -1905,7 +1905,6 @@
int nTrans = 0; /* Number of databases with an active write-transaction */
int rc = SQLITE_OK;
int needXcommit = 0;
- START_DEBUG_TIMER;
#ifdef SQLITE_OMIT_VIRTUALTABLE
/* With this option, sqlite3VtabSync() is defined to be simply
@@ -2135,9 +2134,6 @@
}
#endif
- END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ) {
- sqlite3_log(SQLITE_NOTICE, "slow vdbeCommit: %llu uS", iDebugTimer);
- }
return rc;
}
diff --git a/src/wal.c b/src/wal.c
index cb1d36e..c0861d5 100644
--- a/src/wal.c
+++ b/src/wal.c
@@ -1718,14 +1718,6 @@
i64 nSize; /* Current size of database file */
u32 nBackfill = pInfo->nBackfill;
- /* ELATDPP: Extra logging added to debug performance problem */
- sqlite3_log(SQLITE_NOTICE,
- "wal: checkpoint salt1=%08x salt2=%08x "
- "nBackfill=%d mxSafeFrame=%d mxFrame=%d",
- pWal->hdr.aSalt[0], pWal->hdr.aSalt[1],
- (int)nBackfill, (int)mxSafeFrame, (int)pWal->hdr.mxFrame
- );
-
/* Sync the WAL to disk */
if( sync_flags ){
rc = sqlite3OsSync(pWal->pWalFd, sync_flags);
@@ -2738,8 +2730,6 @@
i64 iOffset; /* Next byte to write in WAL file */
WalWriter w; /* The writer */
- START_DEBUG_TIMER;
-
assert( pList );
assert( pWal->writeLock );
@@ -2827,12 +2817,6 @@
iOffset += szFrame;
}
- /* ELATDPP: Extra logging added to debug performance problem */
- sqlite3_log(SQLITE_NOTICE, "wal: write nFrame=%d iFrame=%d",
- iFrame - pWal->hdr.mxFrame,
- pWal->hdr.mxFrame+1
- );
-
/* If this is the end of a transaction, then we might need to pad
** the transaction and/or sync the WAL file.
**
@@ -2908,10 +2892,6 @@
}
}
- END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ) {
- sqlite3_log(SQLITE_NOTICE, "slow sqlite3WalFrames: %llu uS", iDebugTimer);
- }
-
WALTRACE(("WAL%p: frame write %s\n", pWal, rc ? "failed" : "ok"));
return rc;
}
@@ -2941,10 +2921,6 @@
int isChanged = 0; /* True if a new wal-index header is loaded */
int eMode2 = eMode; /* Mode to pass to walCheckpoint() */
- /* ELATDPP: Extra logging added to debug performance problem */
- sqlite3_int64 t1, t2;
- sqlite3OsCurrentTimeInt64(pWal->pVfs, &t1);
-
assert( pWal->ckptLock==0 );
assert( pWal->writeLock==0 );
@@ -3015,11 +2991,6 @@
sqlite3WalEndWriteTransaction(pWal);
walUnlockExclusive(pWal, WAL_CKPT_LOCK, 1);
pWal->ckptLock = 0;
-
- /* ELATDPP: Extra logging added to debug performance problem */
- sqlite3OsCurrentTimeInt64(pWal->pVfs, &t2);
- sqlite3_log(SQLITE_NOTICE, "wal: checkpoint rc=%d ms=%lld", rc, t2-t1);
-
WALTRACE(("WAL%p: checkpoint %s\n", pWal, rc ? "failed" : "ok"));
return (rc==SQLITE_OK && eMode!=eMode2 ? SQLITE_BUSY : rc);
}
