Add further logging intended for use in analyzing COMMIT performance.

FossilOrigin-Name: bbbd3d9be88194039bb5e2862cb14733403d37ec6c8f21fccc8447172c999343

diff --git a/manifest b/manifest
index d7bc6a6b161006b29dbed5997e5ead47b71edb93..db2885cee43f449ac81167fa99500f1d1f02dd1a 100644 (file)
--- a/manifest
+++ b/manifest
@@ -1,5 +1,5 @@
-C Add\slogging\sto\shelp\sanalyze\sCOMMIT\sperformance.
-D 2024-10-03T21:00:36.101
+C Add\sfurther\slogging\sintended\sfor\suse\sin\sanalyzing\sCOMMIT\sperformance.
+D 2024-10-04T14:11:12.210
 F .fossil-settings/empty-dirs dbb81e8fc0401ac46a1491ab34a7f2c7c0452f2f06b54ebb845d024ca8283ef1
 F .fossil-settings/ignore-glob 35175cdfcf539b2318cb04a9901442804be81cd677d8b889fcc9149c21f239ea
 F LICENSE.md df5091916dbb40e6e9686186587125e1b2ff51f022cc334e886c19a0e9982724
@@ -714,7 +714,7 @@ F src/auth.c 4c1ea890e0069ad73bead5d17a5b12c34cfa4f1a24175c8147ea439b64be271c
 F src/backup.c 5c97e8023aab1ce14a42387eb3ae00ba5a0644569e3476f38661fa6f824c3523
 F src/bitvec.c 501daeef838fa82a9fb53540d72f29e3d9172c8867f1e19f94f681e2e20b966e
 F src/btmutex.c 79a43670447eacc651519a429f6ece9fd638563cf95b469d6891185ddae2b522
-F src/btree.c 9de68aac0f5f88e553992bd46f000670d72289ce0bc41f20164c39b8d6838022
+F src/btree.c c0db29ff599f43af49b83e26754641e606bf75fd9f9f460333616d98b59badfa
 F src/btree.h bdeeb35614caa33526b603138f04c8d07a3f90a1300b5ade76848b755edf2027
 F src/btreeInt.h caa893e74d2261fb0ff1681fce998533c0552858e882bd04fc6805075f5f6e75
 F src/build.c 08697d6a4df78f8e289582eb58473445492319676f81cc4794ef4056d36ae5fd
@@ -762,8 +762,8 @@ F src/os_setup.h 6011ad7af5db4e05155f385eb3a9b4470688de6f65d6166b8956e58a3d87210
 F src/os_unix.c 74de71b4979d2a3409224869b8738d64fab55dcc855162b20d1526544ae0efa1
 F src/os_win.c 6ff43bac175bd9ed79e7c0f96840b139f2f51d01689a638fd05128becf94908a
 F src/os_win.h 7b073010f1451abe501be30d12f6bc599824944a
-F src/pager.c bfcfab4b210c602f77b601b07b6c4627e994e97218cb905ff73ab0231efd078f
-F src/pager.h dd6ade22dd303a8ca6c34f1ff0f299add7191c1bff65f0289b7fd7c3460f9551
+F src/pager.c aae9cdf124548f2867608d481acc854b9b58e769c53b574350ae4ba5dde190f8
+F src/pager.h 60eded76163c6a09d2b73cc40de117012d62f6d1222614c9261d07a73e20ac2e
 F src/parse.y 8388b36e6cd15ebc5c1796cb72dd0a67a04abc446f52838ab3a2e8591487b2f1
 F src/pcache.c 588cc3c5ccaaadde689ed35ce5c5c891a1f7b1f4d1f56f6cf0143b74d8ee6484
 F src/pcache.h 1497ce1b823cf00094bb0cf3bac37b345937e6f910890c626b16512316d3abf5
@@ -846,10 +846,10 @@ F src/utf.c 7bc550af6f3ddd5f5dc82d092c41f728acb760c92e0b47f391963b01ae52569b
 F src/util.c 5d1a0134cf4240648d1c6bb5cc8efaca0ea2b5d5c840985aec7e947271f04375
 F src/vacuum.c 25e407a6dc8b288fa4295b3d92fa9ce9318503e84df53cdf403a50fccbc1ba31
 F src/vdbe.c fea60cfe46d8839a08e4680d90a96898d542d3f6d7954e2e99cd92596f1a01f8
-F src/vdbe.h acae49e00b2b3c04d2e093889e766635a228e2713835f97ac20d78ff9aaddde3
+F src/vdbe.h 1290838cf62f6ec7f5fa26afd9a7737c79f03bb245e0488b9ab0614977211109
 F src/vdbeInt.h 6ee567f7d9be264766f62aa331c33d702abdcaeeceea2a4e81a81c35411577ba
 F src/vdbeapi.c 53c7e26a2c0821a892b20eee2cde4656e31998212f3d515576c780dfaa45fd17
-F src/vdbeaux.c a41e2ba3f1a79e0dc396b1fb9196cfbd3c101fc0d96d9bca626fb291aef66701
+F src/vdbeaux.c 41553ba9ad84f363ed3e3af86490fcde46e9b27796814124464dde3edf60bfd7
 F src/vdbeblob.c 255be187436da38b01f276c02e6a08103489bbe2a7c6c21537b7aecbe0e1f797
 F src/vdbemem.c df568ef0187e4be2788c35174f6d9b8566ab9475f9aff2d73907ed05aa5684b2
 F src/vdbesort.c d0a3c7056c081703c8b6d91ad60f17da5e062a5c64bf568ed0fa1b5f4cae311f
@@ -857,8 +857,8 @@ F src/vdbetrace.c fe0bc29ebd4e02c8bc5c1945f1d2e6be5927ec12c06d89b03ef2a4def34bf8
 F src/vdbevtab.c fc46b9cbd759dc013f0b3724549cc0d71379183c667df3a5988f7e2f1bd485f3
 F src/vtab.c 316cd48e9320660db3047cd306cd056e4361180cebb4d0f10a39244e10c11422
 F src/vxworks.h d2988f4e5a61a4dfe82c6524dd3d6e4f2ce3cdb9
-F src/wal.c cc28bbf6c5229b6ff6e479d3db4182fffe53fb162131a1970481989800ca8d15
-F src/wal.h 8d02ab8c2a93a941f5898eb3345bf711c1d3f8f86f4be8d5428fb6c074962d8a
+F src/wal.c cbe75ede4cafe763f4efc9420c9f9a7918116f3d72f20f59fe615a15c1683cdc
+F src/wal.h 8c59ee7a835574396d7cbd04626d11fd849613e361a46e7e9519091ab03bdb29
 F src/walker.c d5006d6b005e4ea7302ad390957a8d41ed83faa177e412f89bc5600a7462a014
 F src/where.c 461d41017d900d4248a268df96d2d30506c4dcc2257f4167c4f46072003ce2cf
 F src/whereInt.h a5d079c346a658b7a6e9e47bb943d021e02fa1e6aed3b964ca112112a4892192
@@ -2250,11 +2250,8 @@ F vsixtest/vsixtest.tcl 6195aba1f12a5e10efc2b8c0009532167be5e301abe5b31385638080
 F vsixtest/vsixtest.vcxproj.data 2ed517e100c66dc455b492e1a33350c1b20fbcdc
 F vsixtest/vsixtest.vcxproj.filters 37e51ffedcdb064aad6ff33b6148725226cd608e
 F vsixtest/vsixtest_TemporaryKey.pfx e5b1b036facdb453873e7084e1cae9102ccc67a0
-P fd6ff55141be82ba36513ba6273a60c6d8b3c496ed7890ab47cccb05bec7f7c2
-R 56c53d98cfa11e21587144100d545a4b
-T *branch * bedrock-commit-instr
-T *sym-bedrock-commit-instr *
-T -sym-bedrock *
+P 72404dfc0d692bc21b3263d04c9c45dda9e61eb13dc87d2014416703bdf537de
+R cb5255d507a2478cae056fcb7fb0296b
 U dan
-Z b89e00e0a5eae92f81638e3eec35afb4
+Z 9e0f00af082fbe4c948e45d716f37584
 # Remove this line to create a well-formed Fossil manifest.

diff --git a/manifest.uuid b/manifest.uuid
index fd9ef5d8c1e3f50e2ae1bae5ca817491c607fd44..dd2af01debaeb168eecc448d60d26655b9897865 100644 (file)
--- a/manifest.uuid
+++ b/manifest.uuid
@@ -1 +1 @@
-72404dfc0d692bc21b3263d04c9c45dda9e61eb13dc87d2014416703bdf537de
+bbbd3d9be88194039bb5e2862cb14733403d37ec6c8f21fccc8447172c999343

diff --git a/src/btree.c b/src/btree.c
index 7f02be7caffbf25a50738d68b78ce7b927251359..4bf87245641d76f3737a79ab8020748cdcc266b9 100644 (file)
--- a/src/btree.c
+++ b/src/btree.c
@@ -4735,7 +4735,9 @@ int sqlite3BtreeCommitPhaseOne(Btree *p, const char *zSuperJrnl){
       sqlite3CommitTimeSet(p->pBt->aCommitTime, COMMIT_TIME_AFTER_FIXUNLOCKED);
     }
     if( rc==SQLITE_OK ){
+      sqlite3PagerSetCommitTime(pBt->pPager, p->pBt->aCommitTime);
       rc = sqlite3PagerCommitPhaseOne(pBt->pPager, zSuperJrnl, 0);
+      sqlite3PagerSetCommitTime(pBt->pPager, 0);
     }
 #ifndef SQLITE_OMIT_CONCURRENT
     if( rc==SQLITE_OK ){
@@ -4840,7 +4842,9 @@ int sqlite3BtreeCommitPhaseTwo(Btree *p, int bCleanup){
     BtShared *pBt = p->pBt;
     assert( pBt->inTransaction==TRANS_WRITE );
     assert( pBt->nTransaction>0 );
+    sqlite3PagerSetCommitTime(pBt->pPager, p->pBt->aCommitTime);
     rc = sqlite3PagerCommitPhaseTwo(pBt->pPager);
+    sqlite3PagerSetCommitTime(pBt->pPager, 0);
     if( rc!=SQLITE_OK && bCleanup==0 ){
       sqlite3BtreeLeave(p);
       return rc;

diff --git a/src/pager.c b/src/pager.c
index 18418875201a873cc6d94bfbaec14322f25899da..add099f2af3323f23193440199112fd1f37bb37f 100644 (file)
--- a/src/pager.c
+++ b/src/pager.c
@@ -703,6 +703,7 @@ struct Pager {
   Wal *pWal;                  /* Write-ahead log used by "journal_mode=wal" */
   char *zWal;                 /* File name for write-ahead log */
 #endif
+  u64 *aCommitTime;
 };
 
 /*
@@ -6654,6 +6655,7 @@ int sqlite3PagerCommitPhaseOne(
       assert( rc==SQLITE_OK );
       if( ALWAYS(pList) ){
         rc = pagerWalFrames(pPager, pList, pPager->dbSize, 1);
+        sqlite3CommitTimeSet(pPager->aCommitTime, COMMIT_TIME_AFTER_WALFRAMES);
       }
       sqlite3PagerUnref(pPageOne);
       if( rc==SQLITE_OK ){
@@ -6827,6 +6829,10 @@ commit_phase_one_exit:
   return rc;
 }
 
+void sqlite3PagerSetCommitTime(Pager *pPager, u64 *aCommitTime){
+  pPager->aCommitTime = aCommitTime;
+  sqlite3WalSetCommitTime(pPager->pWal, aCommitTime);
+}
 
 /*
 ** When this function is called, the database file has been completely

diff --git a/src/pager.h b/src/pager.h
index 5828c37f86ae0d4d048277cefe93961a8745eaf9..8ce3fde0535d855b058abab4339d14e6cee8e5c4 100644 (file)
--- a/src/pager.h
+++ b/src/pager.h
@@ -280,4 +280,6 @@ int sqlite3PagerWalInfo(Pager*, u32 *pnPrior, u32 *pnFrame);
 int sqlite3PagerWalSystemErrno(Pager*);
 #endif
 
+void sqlite3PagerSetCommitTime(Pager *pPager, u64 *aCommitTime);
+
 #endif /* SQLITE_PAGER_H */

diff --git a/src/vdbe.h b/src/vdbe.h
index 2330638feb958b20c40ca656363acfa5c31829c2..60364571463a3660218710e2cc797d4595cdb4aa 100644 (file)
--- a/src/vdbe.h
+++ b/src/vdbe.h
@@ -432,17 +432,19 @@ int sqlite3CursorRangeHintExprCheck(Walker *pWalker, Expr *pExpr);
 
 #define COMMIT_TIME_BEFORE_PHASEONE 3
 #define COMMIT_TIME_AFTER_FIXUNLOCKED 4
-#define COMMIT_TIME_BEFORE_PHASETWO 5
-#define COMMIT_TIME_AFTER_PHASETWO 6
+#define COMMIT_TIME_AFTER_WALFRAMES 5
 
-#define COMMIT_TIME_AFTER_VDBECOMMIT 7
-#define COMMIT_TIME_AFTER_HALT 8
-#define COMMIT_TIME_FINISH 9
+#define COMMIT_TIME_BEFORE_PHASETWO 6
+#define COMMIT_TIME_AFTER_PHASETWO 7
 
-#define COMMIT_TIME_N 10
+#define COMMIT_TIME_AFTER_VDBECOMMIT 8
+#define COMMIT_TIME_AFTER_HALT 9
+#define COMMIT_TIME_FINISH 10
 
-#define COMMIT_TIME_TIMEOUT (2*1000*1000)
-/* #define COMMIT_TIME_TIMEOUT 0 */
+#define COMMIT_TIME_N 11
+
+/* #define COMMIT_TIME_TIMEOUT (2*1000*1000) */
+#define COMMIT_TIME_TIMEOUT 0 
 
 void sqlite3CommitTimeLog(u64*);
 u64 sqlite3STimeNow();

diff --git a/src/vdbeaux.c b/src/vdbeaux.c
index be7f783149514ead57a1c0bbe564bdf4505060f3..fe8c7b9117d614fe63fd6bd5f5075dfad40d1fc6 100644 (file)
--- a/src/vdbeaux.c
+++ b/src/vdbeaux.c
@@ -3022,7 +3022,9 @@ static int vdbeCommit(sqlite3 *db, Vdbe *p){
     for(i=0; rc==SQLITE_OK && i<db->nDb; i++){
       Btree *pBt = db->aDb[i].pBt;
       if( pBt ){
+        pBt->pBt->aCommitTime = p->aCommitTime;
         rc = sqlite3BtreeCommitPhaseTwo(pBt, 0);
+        pBt->pBt->aCommitTime = 0;
       }
     }
 

diff --git a/src/wal.c b/src/wal.c
index 7a05d7d70fef6a8a7cb14004c3866ff711df8b27..2bd64167b046909626e4b21c8c523fb78d820770 100644 (file)
--- a/src/wal.c
+++ b/src/wal.c
@@ -810,6 +810,7 @@ struct Wal {
 #ifdef SQLITE_ENABLE_SETLK_TIMEOUT
   sqlite3 *db;
 #endif
+  u64 *aCommitTime;
 };
 
 /*
@@ -5822,4 +5823,10 @@ int sqlite3WalJournalMode(Wal *pWal){
   return (isWalMode2(pWal) ? PAGER_JOURNALMODE_WAL2 : PAGER_JOURNALMODE_WAL);
 }
 
+void sqlite3WalSetCommitTime(Wal *pWal, u64 *aCommitTime){
+  if( pWal ){
+    pWal->aCommitTime = aCommitTime;
+  }
+}
+
 #endif /* #ifndef SQLITE_OMIT_WAL */

diff --git a/src/wal.h b/src/wal.h
index cfe3dc2f6966ff25c2628c22d0c567ccf3f53fd0..6202ab5a9b31d08c2e6f69847c0d1fcc0cc9f92a 100644 (file)
--- a/src/wal.h
+++ b/src/wal.h
@@ -175,5 +175,7 @@ int sqlite3WalInfo(Wal *pWal, u32 *pnPrior, u32 *pnFrame);
 /* sqlite3_wal_info() data */
 int sqlite3WalInfo(Wal *pWal, u32 *pnPrior, u32 *pnFrame);
 
+void sqlite3WalSetCommitTime(Wal *pWal, u64 *aCommitTime);
+
 #endif /* ifndef SQLITE_OMIT_WAL */
 #endif /* SQLITE_WAL_H */