Add a debug timer to pcache1Truncate(). Change the formatting of some other messages...

FossilOrigin-Name: 7d0af4b53c440f4628f0cecdc40459335630fa4e

diff --git a/manifest b/manifest
index 8f5f2ecff330137a5b72d107d5974909034d1bb8..1aeea262ebb936185c3be03e7240f45b7d5cec9a 100644 (file)
--- a/manifest
+++ b/manifest
@@ -1,5 +1,5 @@
-C Refocus\sthe\stimer\son\sthe\spager_end_transaction()\sroutine.
-D 2016-08-09T01:21:16.687
+C Add\sa\sdebug\stimer\sto\spcache1Truncate().\sChange\sthe\sformatting\sof\ssome\sother\smessages\sto\smake\sthem\seasier\sto\sread.
+D 2016-08-09T11:23:22.870
 F Makefile.arm-wince-mingw32ce-gcc d6df77f1f48d690bd73162294bbba7f59507c72f
 F Makefile.in cf57f673d77606ab0f2d9627ca52a9ba1464146a
 F Makefile.linux-gcc 91d710bdc4998cb015f39edf3cb314ec4f4d7e23
@@ -215,12 +215,12 @@ F src/os_setup.h c9d4553b5aaa6f73391448b265b89bed0b890faa
 F src/os_unix.c e7157dfa077c06aaeecdfc4dcb6b0a489ef5c57a
 F src/os_win.c a019caaae2bcbbc0cc4c39af6e7d7e43d8426053
 F src/os_win.h 09e751b20bbc107ffbd46e13555dc73576d88e21
-F src/pager.c 0d363201cc4b0f1a27f0f70f29a1e88bb5e5a31a
+F src/pager.c d69ede96f8fac2d0c9c3be64eb06edfe682b01ef
 F src/pager.h d1eee3c3f741be247ce6d82752a178515fc8578b
 F src/parse.y 5dfead8aed90cb0c7c1115898ee2266804daff45
 F src/pcache.c 4121a0571c18581ee9f82f086d5e2030051ebd6a
 F src/pcache.h 9b559127b83f84ff76d735c8262f04853be0c59a
-F src/pcache1.c e412cb585f777c840ddce0500eddc5c6043c2bb5
+F src/pcache1.c 12c155d0cd5360bfd8f79468fca573eb1e0d27b9
 F src/pragma.c 3f3e959390a10c0131676f0e307acce372777e0f
 F src/prepare.c 6ef0cf2f9274982988ed6b7cab1be23147e94196
 F src/printf.c 090fac0f779c93c8a95089a125339686648835e4
@@ -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 491f1ef36e60aa65d71444b604064e3505cabd18
-R e29c5144299bab68bda60556e6dafd92
-U drh
-Z 44d6270f2b449a107198473da9531b56
+P 9d4eb6e4750939c48aff267000bd69a73e1dc364
+R 99ef2da78b11da155f4c9630100d5493
+U dan
+Z f7da3a3db4e7fac2b6c81a30d5eadd3b

diff --git a/manifest.uuid b/manifest.uuid
index b0deb8d7c74064227c378c4150774c7c017cb45a..2e5c8f95fa08cc1d9f554d2d61159bfb05b5e68b 100644 (file)
--- a/manifest.uuid
+++ b/manifest.uuid
@@ -1 +1 @@
-9d4eb6e4750939c48aff267000bd69a73e1dc364
\ No newline at end of file
+7d0af4b53c440f4628f0cecdc40459335630fa4e
\ No newline at end of file

diff --git a/src/pager.c b/src/pager.c
index 936ed645c2918e6f8ff2eb52345479daaf7446ff..1222cbb23146bee83c9769057554e8ec7e7b03b5 100644 (file)
--- a/src/pager.c
+++ b/src/pager.c
@@ -1975,7 +1975,7 @@ 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 %d", 
+    sqlite3_log(SQLITE_NOTICE, "slow pager_end_transaction(1): %llu uS wal=%d", 
       iDebugTimer, pagerUseWal(pPager));
     iDebugTimerStart += iDebugTimer;
   }
@@ -1996,13 +1996,13 @@ static int pager_end_transaction(Pager *pPager, int hasMaster, int bCommit){
   pPager->nRec = 0;
   sqlite3PcacheCleanAll(pPager->pPCache);
   END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ){
-    sqlite3_log(SQLITE_NOTICE, "slow pager_end_transaction(2): %llu %d", 
+    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 %d",
+    sqlite3_log(SQLITE_NOTICE, "slow pager_end_transaction(3): %llu uS wal=%d",
       iDebugTimer, pagerUseWal(pPager));
     iDebugTimerStart += iDebugTimer;
   }
@@ -2025,7 +2025,7 @@ static int pager_end_transaction(Pager *pPager, int hasMaster, int bCommit){
     rc = pager_truncate(pPager, pPager->dbSize);
   }
   END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ){
-    sqlite3_log(SQLITE_NOTICE, "slow pager_end_transaction(4): %llu %d",
+    sqlite3_log(SQLITE_NOTICE, "slow pager_end_transaction(4): %llu uS wal=%d",
       iDebugTimer, pagerUseWal(pPager));
     iDebugTimerStart += iDebugTimer;
   }
@@ -2045,7 +2045,7 @@ static int pager_end_transaction(Pager *pPager, int hasMaster, int bCommit){
   pPager->setMaster = 0;
 
   END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ){
-    sqlite3_log(SQLITE_NOTICE, "slow pager_end_transaction(5): %llu %d",
+    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 a8c3217382a10b170f017a2648a8759e0dd28b5f..a43464b6bb4f71777b17b279135380435d47aa05 100644 (file)
--- a/src/pcache1.c
+++ b/src/pcache1.c
@@ -927,12 +927,17 @@ 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);
+  }
 }
 
 /*