Skip to content

Commit

Permalink
Merge pull request #1892 from Expensify/flo_sqlitelogs
Browse files Browse the repository at this point in the history 
Update SQLite debug logging
  • Loading branch information
@flodnv
flodnv authored Oct 10, 2024
2 parents 208e4f0 + 4ff7615 commit 17dc709
Show file tree
Hide file tree
Showing 2 changed files with 44 additions and 23 deletions.
65 changes: 43 additions & 22 deletions libstuff/sqlite3.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -18,7 +18,7 @@
** separate file. This file contains only code for the core SQLite library.
**
** The content in this amalgamation comes from Fossil check-in
** cd6f585cadfe40778c3bf59dfbfa5f02c50c.
** 6deb4794f8e24dbb946069de1e5c34fbcd47.
*/
#define SQLITE_CORE 1
#define SQLITE_AMALGAMATION 1
Expand Down Expand Up @@ -465,7 +465,7 @@ extern "C" {
*/
#define SQLITE_VERSION "3.47.0"
#define SQLITE_VERSION_NUMBER 3047000
#define SQLITE_SOURCE_ID "2024-10-08 15:08:04 cd6f585cadfe40778c3bf59dfbfa5f02c50cf5e10af1bd553cad4dfa56ea2249"
#define SQLITE_SOURCE_ID "2024-10-10 15:28:18 6deb4794f8e24dbb946069de1e5c34fbcd4734162002f3bc7deb1a3f69adec05"

/*
** CAPI3REF: Run-Time Library Version Numbers
Expand Down Expand Up @@ -17441,17 +17441,21 @@ SQLITE_PRIVATE int sqlite3CursorRangeHintExprCheck(Walker *pWalker, Expr *pExpr)
#define COMMIT_TIME_BEFORE_VDBECOMMIT 2

#define COMMIT_TIME_BEFORE_PHASEONE 3
#define COMMIT_TIME_AFTER_FIXUNLOCKED 4
#define COMMIT_TIME_AFTER_WALFRAMES 5
#define COMMIT_TIME_START_FIXUNLOCKED 4
#define COMMIT_TIME_START_RELOCATE1 5
#define COMMIT_TIME_START_RELOCATE2 6

#define COMMIT_TIME_BEFORE_PHASETWO 6
#define COMMIT_TIME_AFTER_PHASETWO 7
#define COMMIT_TIME_AFTER_FIXUNLOCKED 7
#define COMMIT_TIME_AFTER_WALFRAMES 8

#define COMMIT_TIME_AFTER_VDBECOMMIT 8
#define COMMIT_TIME_AFTER_HALT 9
#define COMMIT_TIME_FINISH 10
#define COMMIT_TIME_BEFORE_PHASETWO 9
#define COMMIT_TIME_AFTER_PHASETWO 10

#define COMMIT_TIME_N 11
#define COMMIT_TIME_AFTER_VDBECOMMIT 11
#define COMMIT_TIME_AFTER_HALT 12
#define COMMIT_TIME_FINISH 13

#define COMMIT_TIME_N 14

/* #define COMMIT_TIME_TIMEOUT (2*1000*1000) */
#define COMMIT_TIME_TIMEOUT (10*1000) /* 10ms threshold */
Expand Down Expand Up @@ -18162,15 +18166,22 @@ struct sqlite3 {
#define PREPARE_TIME_START 0
#define PREPARE_TIME_BEGINPARSE 1
#define PREPARE_TIME_BEGINPRAGMA 2
#define PREPARE_TIME_BEGINCACHESIZE 3
#define PREPARE_TIME_BEGINSETCACHESIZE 4
#define PREPARE_TIME_ENDSETCACHESIZE 5
#define PREPARE_TIME_ENDCACHESIZE 6
#define PREPARE_TIME_ENDPRAGMA 7
#define PREPARE_TIME_ENDPARSE 8
#define PREPARE_TIME_FINISH 9

#define PREPARE_TIME_N 10
#define PREPARE_TIME_BEGINAUTHCHECK 3
#define PREPARE_TIME_ENDAUTHCHECK 4
#define PREPARE_TIME_BEGINLOADSCHEMA 5
#define PREPARE_TIME_ENDLOADSCHEMA 6


#define PREPARE_TIME_BEGINCACHESIZE 7
#define PREPARE_TIME_BEGINSETCACHESIZE 8
#define PREPARE_TIME_ENDSETCACHESIZE 9
#define PREPARE_TIME_ENDCACHESIZE 10
#define PREPARE_TIME_ENDPRAGMA 11
#define PREPARE_TIME_ENDPARSE 12
#define PREPARE_TIME_FINISH 13

#define PREPARE_TIME_N 14

#define sqlite3PrepareTimeSet(x,y) sqlite3CommitTimeSet(x,y)
SQLITE_PRIVATE void sqlite3PrepareTimeLog(const char *zSql, int nSql, u64 *aPrepareTime);
Expand Down Expand Up @@ -77355,6 +77366,8 @@ static int btreeFixUnlocked(Btree *p){
Pgno nPage = btreePagecount(pBt);
u32 nFree = get4byte(&p1[36]);

sqlite3CommitTimeSet(p->pBt->aCommitTime, COMMIT_TIME_START_FIXUNLOCKED);

assert( pBt->pMap );
rc = sqlite3PagerUpgradeSnapshot(pPager, pPage1->pDbPage);
assert( p1==pPage1->aData );
Expand Down Expand Up @@ -77401,6 +77414,7 @@ static int btreeFixUnlocked(Btree *p){

nCurrent = MAX(nPage, nHPage);
pBt->nPage = nCurrent;
sqlite3CommitTimeSet(p->pBt->aCommitTime, COMMIT_TIME_START_RELOCATE1);
rc = btreeRelocateRange(pBt, pMap->iFirst, iLast, &nCurrent);

/* There are now no collisions with the snapshot at the head of the
Expand All @@ -77417,6 +77431,9 @@ static int btreeFixUnlocked(Btree *p){
nFin--;
}
nFin = MAX(nFin, nHPage);
sqlite3CommitTimeSet(
p->pBt->aCommitTime, COMMIT_TIME_START_RELOCATE2
);
rc = btreeRelocateRange(pBt, nFin+1, nCurrent, 0);
}

Expand Down Expand Up @@ -93170,7 +93187,7 @@ SQLITE_PRIVATE void sqlite3CommitTimeLog(u64 *aCommit){
(aCommit[ii]==0 ? 0 : (int)(aCommit[ii] - i1))
);
}
sqlite3_log(SQLITE_WARNING, "slow commit (v=1): (%s)", zStr);
sqlite3_log(SQLITE_WARNING, "slow commit (v=2): (%s)", zStr);
sqlite3_free(zStr);
}
}
Expand All @@ -93180,7 +93197,7 @@ SQLITE_PRIVATE u64 sqlite3STimeNow(){
return ((u64)time.tv_sec * 1000000 + (u64)time.tv_usec);
}
SQLITE_PRIVATE void sqlite3CommitTimeSet(u64 *aCommit, int iCommit){
if( aCommit ){
if( aCommit && aCommit[iCommit]==0 ){
aCommit[iCommit] = sqlite3STimeNow();
}
}
Expand All @@ -93198,7 +93215,7 @@ SQLITE_PRIVATE void sqlite3PrepareTimeLog(const char *zSql, int nSql, u64 *aPrep
}
if( nByte<0 ){ nByte = sqlite3Strlen30(zSql); }
sqlite3_log(SQLITE_WARNING,
"slow prepare (v=1): (%s) [%.*s]", zStr, nByte, zSql
"slow prepare (v=2): (%s) [%.*s]", zStr, nByte, zSql
);
sqlite3_free(zStr);
}
Expand Down Expand Up @@ -142532,11 +142549,13 @@ SQLITE_PRIVATE void sqlite3Pragma(
zRight = sqlite3NameFromToken(db, pValue);
}

sqlite3PrepareTimeSet(db->aPrepareTime, PREPARE_TIME_BEGINAUTHCHECK);
assert( pId2 );
zDb = pId2->n>0 ? pDb->zDbSName : 0;
if( sqlite3AuthCheck(pParse, SQLITE_PRAGMA, zLeft, zRight, zDb) ){
goto pragma_out;
}
sqlite3PrepareTimeSet(db->aPrepareTime, PREPARE_TIME_ENDAUTHCHECK);

/* Send an SQLITE_FCNTL_PRAGMA file-control to the underlying VFS
** connection. If it returns SQLITE_OK, then assume that the VFS
Expand Down Expand Up @@ -142584,10 +142603,12 @@ SQLITE_PRIVATE void sqlite3Pragma(
goto pragma_out;
}

sqlite3PrepareTimeSet(db->aPrepareTime, PREPARE_TIME_BEGINLOADSCHEMA);
/* Make sure the database schema is loaded if the pragma requires that */
if( (pPragma->mPragFlg & PragFlg_NeedSchema)!=0 ){
if( sqlite3ReadSchema(pParse) ) goto pragma_out;
}
sqlite3PrepareTimeSet(db->aPrepareTime, PREPARE_TIME_ENDLOADSCHEMA);

/* Register the result column names for pragmas that return results */
if( (pPragma->mPragFlg & PragFlg_NoColumns)==0
Expand Down Expand Up @@ -257549,7 +257570,7 @@ static void fts5SourceIdFunc(
){
assert( nArg==0 );
UNUSED_PARAM2(nArg, apUnused);
sqlite3_result_text(pCtx, "fts5: 2024-10-08 15:08:04 cd6f585cadfe40778c3bf59dfbfa5f02c50cf5e10af1bd553cad4dfa56ea2249", -1, SQLITE_TRANSIENT);
sqlite3_result_text(pCtx, "fts5: 2024-10-10 15:28:18 6deb4794f8e24dbb946069de1e5c34fbcd4734162002f3bc7deb1a3f69adec05", -1, SQLITE_TRANSIENT);
}

/*
Expand Down
2 changes: 1 addition & 1 deletion libstuff/sqlite3.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -148,7 +148,7 @@ extern "C" {
*/
#define SQLITE_VERSION "3.47.0"
#define SQLITE_VERSION_NUMBER 3047000
#define SQLITE_SOURCE_ID "2024-10-08 15:08:04 cd6f585cadfe40778c3bf59dfbfa5f02c50cf5e10af1bd553cad4dfa56ea2249"
#define SQLITE_SOURCE_ID "2024-10-10 15:28:18 6deb4794f8e24dbb946069de1e5c34fbcd4734162002f3bc7deb1a3f69adec05"

/*
** CAPI3REF: Run-Time Library Version Numbers
Expand Down

0 comments on commit 17dc709

Please sign in to comment.