Remove all timers and other debugging logs except for the one timer on

pcache1TruncateUnsafe().

FossilOrigin-Name: 5980e625dbb694dc3b0535e71fd986a6d211e245

diff --git a/manifest b/manifest
index 84fa580eb2700323708a08165bc23493a3772c5a..5b8d528389cb46998d1b8cdb4f05b2bdb4dfe1fe 100644 (file)
--- 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/memjournal.c 3eb2c0b51adbd869cb6a44780323f05fa904dc85
 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/vacuum.c 59f03f92bcff57faa6a8ca256eb29ccddfb0614a
 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/vdbe_profile.tcl 67746953071a9f8f2f668b73fe899074e2c6d8c1
 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 7095413bf727100115e0aa07d502f3491f1a8481..032f7066785e10ccd1fa70a125b3911f532f5f84 100644 (file)
--- 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 9b16c0e838b926e91b805b31fcc0a96407399ece..c8663144e8c55091487fb40d94f370166857c01f 100644 (file)
--- a/src/mutex_unix.c
+++ b/src/mutex_unix.c
@@ -200,13 +200,6 @@ static void pthreadMutexFree(sqlite3_mutex *p){
   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 @@ static void pthreadMutexFree(sqlite3_mutex *p){
 ** 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 @@ static void pthreadMutexEnter(sqlite3_mutex *p){
   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 f9665e337cefccc5b0d397c60106b35d002d7075..b6c28a1dc447b43023d345f62caf6bb7b49ee8b5 100644 (file)
--- a/src/os.c
+++ b/src/os.c
@@ -61,14 +61,10 @@ int sqlite3_memdebug_vfs_oom_test = 1;
 */
 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 @@ int sqlite3OsTruncate(sqlite3_file *id, i64 size){
   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 @@ int sqlite3OsCheckReservedLock(sqlite3_file *id, int *pResOut){
 ** 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 @@ int sqlite3OsFileControl(sqlite3_file *id, int op, void *pArg){
     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 @@ int sqlite3OsDeviceCharacteristics(sqlite3_file *id){
   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 fbf14cfe38f92cc680bb54be1e440f9792b6ff23..a9344ee830988bc4b43818e17a0c5495353b508c 100644 (file)
--- a/src/os_unix.c
+++ b/src/os_unix.c
@@ -4629,12 +4629,8 @@ static void unixShmBarrier(
   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 1222cbb23146bee83c9769057554e8ec7e7b03b5..997f842d0a391603f0b5fda30f7b00d865818a94 100644 (file)
--- a/src/pager.c
+++ b/src/pager.c
@@ -1907,7 +1907,6 @@ static int pager_truncate(Pager *pPager, Pgno nPage);
 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 @@ static int pager_end_transaction(Pager *pPager, int hasMaster, int bCommit){
       }
     }
   }
-  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 @@ static int pager_end_transaction(Pager *pPager, int hasMaster, int bCommit){
   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 @@ static int pager_end_transaction(Pager *pPager, int hasMaster, int bCommit){
     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 @@ static int pager_end_transaction(Pager *pPager, int hasMaster, int bCommit){
   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 c66d06391d2c3b69dc82125836f8d6658b5542e3..5ae4ad06e39a4ae02dac5ee872f5828caefe594c 100644 (file)
--- a/src/pcache1.c
+++ b/src/pcache1.c
@@ -521,8 +521,11 @@ static void pcache1TruncateUnsafe(
   }
   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 pcache1Rekey(
 */
 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 857494ed83a632d1bb14aeeb5a403ba9abc213ae..0ab76e0784c530e3f1bfdab70b4a866f8b60d2be 100644 (file)
--- a/src/vdbeapi.c
+++ b/src/vdbeapi.c
@@ -395,7 +395,6 @@ void sqlite3_result_error_nomem(sqlite3_context *pCtx){
 */
 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 @@ static int doWalCallbacks(sqlite3 *db){
     }
   }
 #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 doWalCallbacks(sqlite3 *db){
 static int sqlite3Step(Vdbe *p){
   sqlite3 *db;
   int rc;
-  START_DEBUG_TIMER;
 
   assert(p);
   if( p->magic!=VDBE_MAGIC_RUN ){
@@ -545,11 +540,6 @@ end_of_step:
     */ 
     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 a2c969a91b44b4f514d341c09d64a828a7f97418..c0018bb71cae5d486e5e94f90963d3ce509dc16e 100644 (file)
--- a/src/vdbeaux.c
+++ b/src/vdbeaux.c
@@ -1905,7 +1905,6 @@ static int vdbeCommit(sqlite3 *db, Vdbe *p){
   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 @@ static int vdbeCommit(sqlite3 *db, Vdbe *p){
   }
 #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 cb1d36ea575cc5f43ce4336daed87f0986ce98a1..c0861d5be77552d55eb7988b650d20012da2493c 100644 (file)
--- a/src/wal.c
+++ b/src/wal.c
@@ -1718,14 +1718,6 @@ static int walCheckpoint(
     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 @@ int sqlite3WalFrames(
   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 @@ int sqlite3WalFrames(
     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 @@ int sqlite3WalFrames(
     }
   }
 
-  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 sqlite3WalCheckpoint(
   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 @@ int sqlite3WalCheckpoint(
   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);
 }