From: dan Date: Tue, 19 Nov 2024 17:32:03 +0000 (+0000) Subject: Extra logging for the freelist and hash table components of COMMITs of BEGIN CONCURRE... X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=74880dccd02200a4e84cbeb50c439a759e25ac99;p=thirdparty%2Fsqlite.git Extra logging for the freelist and hash table components of COMMITs of BEGIN CONCURRENT transactions. FossilOrigin-Name: 2ba41da8c437e466c71f65d67a615293efb5a2d9da9b6e9cbb7b296221d4104a --- diff --git a/manifest b/manifest index 9e211aeef6..a26b8c62a8 100644 --- a/manifest +++ b/manifest @@ -1,5 +1,5 @@ -C Increase\smaximum\slength\sof\ssqlite3_log()\smessages\sto\s700\sbytes.\sMark\slog\smessages\sas\sv=10. -D 2024-11-13T14:42:32.861 +C Extra\slogging\sfor\sthe\sfreelist\sand\shash\stable\scomponents\sof\sCOMMITs\sof\sBEGIN\sCONCURRENT\stransactions. +D 2024-11-19T17:32:03.892 F .fossil-settings/empty-dirs dbb81e8fc0401ac46a1491ab34a7f2c7c0452f2f06b54ebb845d024ca8283ef1 F .fossil-settings/ignore-glob 35175cdfcf539b2318cb04a9901442804be81cd677d8b889fcc9149c21f239ea F LICENSE.md df5091916dbb40e6e9686186587125e1b2ff51f022cc334e886c19a0e9982724 @@ -713,7 +713,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 68f32f71c33ab571b8d706940108c448e165d0c3d7317a1b5883d2b9dfcf2512 +F src/btree.c 2664c81f217a42afadc7c010bb4a175057d5e53b99e9512234eb74817f2ad59c F src/btree.h bdeeb35614caa33526b603138f04c8d07a3f90a1300b5ade76848b755edf2027 F src/btreeInt.h caa893e74d2261fb0ff1681fce998533c0552858e882bd04fc6805075f5f6e75 F src/build.c 08697d6a4df78f8e289582eb58473445492319676f81cc4794ef4056d36ae5fd @@ -846,10 +846,10 @@ F src/utf.c f23165685a67b4caf8ec08fb274cb3f319103decfb2a980b7cfd55d18dfa855e F src/util.c 5d1a0134cf4240648d1c6bb5cc8efaca0ea2b5d5c840985aec7e947271f04375 F src/vacuum.c 25e407a6dc8b288fa4295b3d92fa9ce9318503e84df53cdf403a50fccbc1ba31 F src/vdbe.c fea60cfe46d8839a08e4680d90a96898d542d3f6d7954e2e99cd92596f1a01f8 -F src/vdbe.h e439c7b44191828413f461eac23360ffbf0513fe57d129853f690c4ea4d46746 +F src/vdbe.h b7efae210f5aea8d4e7b6412f70b0b1c744dc397527339f68a186bf24c04198d F src/vdbeInt.h 92b7eabbaadbe8127741cd96e7e39c4834c2bb0b75987d5f6251975f47233690 F src/vdbeapi.c 80235ac380e9467fec1cb0883354d841f2a771976e766995f7e0c77f845406df -F src/vdbeaux.c 4f7e3fc42eea9612ae59ff5f123280507935be53d0d2e9ea474957b30f9e1f29 +F src/vdbeaux.c 6bc54bfbfa1b03d776e2efa76828128a964efd012d86b60ec892c659523d2548 F src/vdbeblob.c 255be187436da38b01f276c02e6a08103489bbe2a7c6c21537b7aecbe0e1f797 F src/vdbemem.c 831a244831eaa45335f9ae276b50a7a82ee10d8c46c2c72492d4eb8c98d94d89 F src/vdbesort.c d0a3c7056c081703c8b6d91ad60f17da5e062a5c64bf568ed0fa1b5f4cae311f @@ -857,7 +857,7 @@ F src/vdbetrace.c fe0bc29ebd4e02c8bc5c1945f1d2e6be5927ec12c06d89b03ef2a4def34bf8 F src/vdbevtab.c fc46b9cbd759dc013f0b3724549cc0d71379183c667df3a5988f7e2f1bd485f3 F src/vtab.c 5fb499d20494b7eecaadb7584634af9afcb374cb0524912b475fcb1712458a1b F src/vxworks.h d2988f4e5a61a4dfe82c6524dd3d6e4f2ce3cdb9 -F src/wal.c c5c772a50621548398bff23df38cc338c8b874188d1fa7bf975f3381f6071126 +F src/wal.c b15990d5cc1fbc418170a5d14bc32c84b955c29ab189056ad60db31f87ea72b2 F src/wal.h 8c59ee7a835574396d7cbd04626d11fd849613e361a46e7e9519091ab03bdb29 F src/walker.c d5006d6b005e4ea7302ad390957a8d41ed83faa177e412f89bc5600a7462a014 F src/where.c c046dd58c3410f7b7528e1e6317cb876398557bad346d568ed8562321a7d002d @@ -2249,8 +2249,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 e0c0176793d41bef30e093975a87170981277dac20cde08e0fd3e0b6f40dca2f -R 40d5d8e3822854d0b02030b6b7d7027f +P 35aa893d4537d0b3605084a1f2f5529794e82af59b8893053815d3fcb4719a27 +R 1424c980ed8c56bd0af68164564ef6ef U dan -Z 1f420b344bc232a0c739cabd514cf0b5 +Z cb872ff1639c1f0cfce91c12fa6be434 # Remove this line to create a well-formed Fossil manifest. diff --git a/manifest.uuid b/manifest.uuid index 7e973bcf72..ca3694bfd7 100644 --- a/manifest.uuid +++ b/manifest.uuid @@ -1 +1 @@ -35aa893d4537d0b3605084a1f2f5529794e82af59b8893053815d3fcb4719a27 +2ba41da8c437e466c71f65d67a615293efb5a2d9da9b6e9cbb7b296221d4104a diff --git a/src/btree.c b/src/btree.c index 941f27910f..cb8aa11950 100644 --- a/src/btree.c +++ b/src/btree.c @@ -4561,7 +4561,7 @@ static int btreeRelocateRange( if( pBt->aCommitTime ) t1 = sqlite3STimeNow(); rc = allocateBtreePage(pBt, &pFree, &dummy, iPg, BTALLOC_EXACT); if( pBt->aCommitTime ){ - pBt->aCommitTime[COMMIT_TIME_RELOCATE2_ALLOCATEUS] += (sqlite3STimeNow() - t1); + pBt->aCommitTime[COMMIT_TIME_RELOCATE2_EXACTUS] += (sqlite3STimeNow() - t1); } if( pFree ){ assert( sqlite3PagerPageRefcount(pFree->pDbPage)==1 ); diff --git a/src/vdbe.h b/src/vdbe.h index 6725bb5f3b..b3df6f165a 100644 --- a/src/vdbe.h +++ b/src/vdbe.h @@ -441,39 +441,42 @@ int sqlite3CursorRangeHintExprCheck(Walker *pWalker, Expr *pExpr); #define COMMIT_TIME_RELOCATE2_READUS 10 #define COMMIT_TIME_RELOCATE2_READCOUNT 11 -#define COMMIT_TIME_RELOCATE2_ALLOCATEUS 12 -#define COMMIT_TIME_RELOCATE2_RELOCATEUS 13 +#define COMMIT_TIME_RELOCATE2_EXACTUS 12 +#define COMMIT_TIME_RELOCATE2_ALLOCATEUS 13 +#define COMMIT_TIME_RELOCATE2_RELOCATEUS 14 -#define COMMIT_TIME_AFTER_FIXUNLOCKED 14 +#define COMMIT_TIME_AFTER_FIXUNLOCKED 15 -#define COMMIT_TIME_BEFORE_WALFRAMES 15 -#define COMMIT_TIME_AFTER_CHANGECOUNTER 16 -#define COMMIT_TIME_AFTER_RESTARTLOG 17 -#define COMMIT_TIME_AFTER_WRITEHDR 18 +#define COMMIT_TIME_BEFORE_WALFRAMES 16 +#define COMMIT_TIME_AFTER_CHANGECOUNTER 17 +#define COMMIT_TIME_AFTER_RESTARTLOG 18 +#define COMMIT_TIME_AFTER_WRITEHDR 19 -#define COMMIT_TIME_OSWRITE 19 +#define COMMIT_TIME_OSWRITE 20 -#define COMMIT_TIME_AFTER_WRITEFRAMES 20 +#define COMMIT_TIME_AFTER_WRITEFRAMES 21 -#define COMMIT_TIME_NFRAME 21 -#define COMMIT_TIME_HASHMAPUS 22 +#define COMMIT_TIME_NFRAME 22 +#define COMMIT_TIME_HASHMAPUS 23 -#define COMMIT_TIME_BEFORE_WALINDEX 23 -#define COMMIT_TIME_AFTER_WALINDEX 24 -#define COMMIT_TIME_AFTER_WALINDEXHDR 25 +#define COMMIT_TIME_BEFORE_WALINDEX 24 -#define COMMIT_TIME_WALFRAMESFLAGS 26 +#define COMMIT_TIME_WALINDEX_HASHGETUS 25 +#define COMMIT_TIME_WALINDEX_CLEANUPUS 26 +#define COMMIT_TIME_WALINDEX_ENTRYUS 27 -#define COMMIT_TIME_AFTER_WALFRAMES 27 +#define COMMIT_TIME_AFTER_WALINDEX 28 +#define COMMIT_TIME_AFTER_WALINDEXHDR 29 +#define COMMIT_TIME_WALFRAMESFLAGS 30 +#define COMMIT_TIME_AFTER_WALFRAMES 31 +#define COMMIT_TIME_BEFORE_PHASETWO 32 +#define COMMIT_TIME_AFTER_PHASETWO 33 -#define COMMIT_TIME_BEFORE_PHASETWO 28 -#define COMMIT_TIME_AFTER_PHASETWO 29 +#define COMMIT_TIME_AFTER_VDBECOMMIT 34 +#define COMMIT_TIME_AFTER_HALT 35 +#define COMMIT_TIME_FINISH 36 -#define COMMIT_TIME_AFTER_VDBECOMMIT 30 -#define COMMIT_TIME_AFTER_HALT 31 -#define COMMIT_TIME_FINISH 32 - -#define COMMIT_TIME_N 33 +#define COMMIT_TIME_N 37 /* #define COMMIT_TIME_TIMEOUT (2*1000*1000) */ #define COMMIT_TIME_TIMEOUT (10*1000) /* 10ms threshold */ diff --git a/src/vdbeaux.c b/src/vdbeaux.c index 390446c585..6d77ca2ef4 100644 --- a/src/vdbeaux.c +++ b/src/vdbeaux.c @@ -5483,6 +5483,10 @@ void sqlite3CommitTimeLog(u64 *aCommit){ || ii==COMMIT_TIME_RELOCATE2_ALLOCATEUS || ii==COMMIT_TIME_RELOCATE2_RELOCATEUS || ii==COMMIT_TIME_HASHMAPUS + || ii==COMMIT_TIME_RELOCATE2_EXACTUS + || ii==COMMIT_TIME_WALINDEX_HASHGETUS + || ii==COMMIT_TIME_WALINDEX_CLEANUPUS + || ii==COMMIT_TIME_WALINDEX_ENTRYUS ){ iVal = (int)aCommit[ii]; zU = "us"; diff --git a/src/wal.c b/src/wal.c index 6c6219e813..117781aed0 100644 --- a/src/wal.c +++ b/src/wal.c @@ -1621,6 +1621,7 @@ static int walIndexAppend(Wal *pWal, int iWal, u32 iFrame, u32 iPage){ int rc; /* Return code */ WalHashLoc sLoc; /* Wal-index hash table location */ u32 iExternal; + u64 t; if( isWalMode2(pWal) ){ iExternal = walExternalEncode(iWal, iFrame); @@ -1629,7 +1630,11 @@ static int walIndexAppend(Wal *pWal, int iWal, u32 iFrame, u32 iPage){ iExternal = iFrame; } + if( pWal->aCommitTime ) t = sqlite3STimeNow(); rc = walHashGet(pWal, walFramePage(iExternal), &sLoc); + if( pWal->aCommitTime ){ + pWal->aCommitTime[COMMIT_TIME_WALINDEX_HASHGETUS] += sqlite3STimeNow()-t; + } /* Assuming the wal-index file was successfully mapped, populate the ** page number array and hash table entry. @@ -1658,17 +1663,25 @@ static int walIndexAppend(Wal *pWal, int iWal, u32 iFrame, u32 iPage){ ** the hash-table before writing any new entries. */ if( sLoc.aPgno[idx-1] ){ + if( pWal->aCommitTime ) t = sqlite3STimeNow(); walCleanupHash(pWal); assert( !sLoc.aPgno[idx-1] ); + if( pWal->aCommitTime ){ + pWal->aCommitTime[COMMIT_TIME_WALINDEX_CLEANUPUS]+=sqlite3STimeNow()-t; + } } /* Write the aPgno[] array entry and the hash-table slot. */ + if( pWal->aCommitTime ) t = sqlite3STimeNow(); nCollide = idx; for(iKey=walHash(iPage); sLoc.aHash[iKey]; iKey=walNextHash(iKey)){ if( (nCollide--)==0 ) return SQLITE_CORRUPT_BKPT; } sLoc.aPgno[idx-1] = iPage; AtomicStore(&sLoc.aHash[iKey], (ht_slot)idx); + if( pWal->aCommitTime ){ + pWal->aCommitTime[COMMIT_TIME_WALINDEX_ENTRYUS]+=sqlite3STimeNow()-t; + } #ifdef SQLITE_ENABLE_EXPENSIVE_ASSERT /* Verify that the number of entries in the hash table exactly equals