From: drh <drh@noemail.net>
Date: Mon, 10 Aug 2015 20:22:07 +0000 (+0000)
Subject: Add the sqlite3_experimental_log_open() interface.  This is for diagnostic
X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=46f0bd620d47298dbd8553ef32a9ba054bed092d;p=thirdparty%2Fsqlite.git

Add the sqlite3_experimental_log_open() interface.  This is for diagnostic
use only and is not intended to ever go on trunk.

FossilOrigin-Name: ac5d2e9d760bb376e828e3d39ee070b567e59d58
---

diff --git a/manifest b/manifest
index 29bb3f9b7a..153cfb7611 100644
--- a/manifest
+++ b/manifest
@@ -1,5 +1,5 @@
-C Fix\scompiler\swarnings\sand\sremove\sunreachable\scode.
-D 2015-08-08T23:30:56.001
+C Add\sthe\ssqlite3_experimental_log_open()\sinterface.\s\sThis\sis\sfor\sdiagnostic\nuse\sonly\sand\sis\snot\sintended\sto\sever\sgo\son\strunk.
+D 2015-08-10T20:22:07.840
 F Makefile.arm-wince-mingw32ce-gcc d6df77f1f48d690bd73162294bbba7f59507c72f
 F Makefile.in 2fc9ca6bf5949d415801c007ed3004a4bdb7c380
 F Makefile.linux-gcc 91d710bdc4998cb015f39edf3cb314ec4f4d7e23
@@ -276,9 +276,9 @@ F src/auth.c b56c78ebe40a2110fd361379f7e8162d23f92240
 F src/backup.c 4d9134dc988a87838c06056c89c0e8c4700a0452
 F src/bitvec.c d1f21d7d91690747881f03940584f4cc548c9d3d
 F src/btmutex.c 45a968cc85afed9b5e6cf55bf1f42f8d18107f79
-F src/btree.c f48b3ef91676c06a90a8832987ecef6b94c931ee
-F src/btree.h 969adc948e89e449220ff0ff724c94bb2a52e9f1
-F src/btreeInt.h 8177c9ab90d772d6d2c6c517e05bed774b7c92c0
+F src/btree.c 304e7b5a8f93ec7c9ed79de1620a542e4b29ab99
+F src/btree.h 4c2590d2b5649b283b653053621965c3bb8020d1
+F src/btreeInt.h d28997e3b752f2b0bbe4508229a423fd3f1cbc43
 F src/build.c 4acc35c4e0a2d94c906abd164568cd6fc989cfbb
 F src/callback.c 7b44ce59674338ad48b0e84e7b72f935ea4f68b0
 F src/complete.c addcd8160b081131005d5bc2d34adf20c1c5c92f
@@ -299,7 +299,7 @@ F src/journal.c b4124532212b6952f42eb2c12fa3c25701d8ba8d
 F src/legacy.c ba1863ea58c4c840335a84ec276fc2b25e22bc4e
 F src/lempar.c 92bafa308607dd985ca389a788cd9e0a2b608712
 F src/loadext.c dfcee8c7c032cd0fd55af3e0fc1fcfb01e426df2
-F src/main.c 0a60b7ca8252c3a6f95438fa4ce8fe5b275c69f2
+F src/main.c acfb7cf332d41a36cc6efeefb3fa571dcd30ed87
 F src/malloc.c 19461e159bccf0e2cf06a50e867963d0a7b124a8
 F src/mem0.c 6a55ebe57c46ca1a7d98da93aaa07f99f1059645
 F src/mem1.c abe6ee469b6c5a35c7f22bfeb9c9bac664a1c987
@@ -321,8 +321,8 @@ F src/os_setup.h c9d4553b5aaa6f73391448b265b89bed0b890faa
 F src/os_unix.c 388c023582b17890f10c980b30ec1922b471753b
 F src/os_win.c 40b3af7a47eb1107d0d69e592bec345a3b7b798a
 F src/os_win.h eb7a47aa17b26b77eb97e4823f20a00b8bda12ca
-F src/pager.c aa916ca28606ccf4b6877dfc2b643ccbca86589f
-F src/pager.h 6d435f563b3f7fcae4b84433b76a6ac2730036e2
+F src/pager.c 751cd2f0240be797de5d1d448a3a7d62fb244df3
+F src/pager.h ad181d413ffc47069ec2f3b0dbf5c24fec957ea7
 F src/parse.y 6d60dda8f8d418b6dc034f1fbccd816c459983a8
 F src/pcache.c cde06aa50962595e412d497e22fd2e07878ba1f0
 F src/pcache.h 9968603796240cdf83da7e7bef76edf90619cea9
@@ -335,11 +335,11 @@ F src/random.c ba2679f80ec82c4190062d756f22d0c358180696
 F src/resolve.c 2d47554370de8de6dd5be060cef9559eec315005
 F src/rowset.c eccf6af6d620aaa4579bd3b72c1b6395d9e9fa1e
 F src/select.c 57ef3d98c4400b93eea318813be41b2af2da2217
-F src/shell.c b1f91e60918df3a68efad1e3a11696b9a7e23d23
-F src/sqlite.h.in 447ead0a6b3293206f04a0896553955d07cfb4b9
+F src/shell.c 5e8e1115a543de8003ce9d23173e01948d831ff5
+F src/sqlite.h.in fdf8a6a1fa43e3c3f75d5a61dcd14d617f8a8c44
 F src/sqlite3.rc 992c9f5fb8285ae285d6be28240a7e8d3a7f2bad
 F src/sqlite3ext.h a0b948ebc89bac13941254641326a6aa248c2cc4
-F src/sqliteInt.h 9401d7d9124210dfd5d283af45e0addbc1455c2e
+F src/sqliteInt.h e1a5cfe6c44606429838fa9bbd1824e119e05533
 F src/sqliteLimit.h 216557999cb45f2e3578ed53ebefe228d779cb46
 F src/status.c f266ad8a2892d659b74f0f50cb6a88b6e7c12179
 F src/table.c 51b46b2a62d1b3a959633d593b89bab5e2c9155e
@@ -397,7 +397,7 @@ F src/update.c 487747b328b7216bb7f6af0695d6937d5c9e605f
 F src/utf.c fc6b889ba0779b7722634cdeaa25f1930d93820c
 F src/util.c bc9dd64b5db544218b871b66243871c202b2781f
 F src/vacuum.c 2ddd5cad2a7b9cef7f9e431b8c7771634c6b1701
-F src/vdbe.c 2ab1decd98925f8cd846993dde9dccaa69cdf0ef
+F src/vdbe.c 0f6fc42b122e61e5b98565496a524065c805837d
 F src/vdbe.h 7a75045d879118b9d3af7e8b3c108f2f27c51473
 F src/vdbeInt.h 8b54e01ad0463590e7cffabce0bc36da9ee4f816
 F src/vdbeapi.c adabbd66eb2e3a10f3998485ee0be7e326d06ee4
@@ -1372,8 +1372,10 @@ F tool/vdbe_profile.tcl 67746953071a9f8f2f668b73fe899074e2c6d8c1
 F tool/warnings-clang.sh f6aa929dc20ef1f856af04a730772f59283631d4
 F tool/warnings.sh 48bd54594752d5be3337f12c72f28d2080cb630b
 F tool/win/sqlite.vsix deb315d026cc8400325c5863eef847784a219a2f
-P 1d75a41bb2f7fcd32f9f08768517b814e452e456 962b6cd6bbc1ef82ae98cb2ddf41e7a1116e70f5
-R 9515e6f89ec29f4ddd4e24f2f6aa441a
-T +closed 962b6cd6bbc1ef82ae98cb2ddf41e7a1116e70f5
+P fd5608fb20831f1f1946c8941445b7acc463a143
+R 11798389c9e9a9f35cf98460536895f1
+T *branch * experimentalIoLog
+T *sym-experimentalIoLog *
+T -sym-trunk *
 U drh
-Z 835c78eb4169c17715bf2b1e3d1fbe33
+Z c08861a2a032f7f296a6940f57523f0b
diff --git a/manifest.uuid b/manifest.uuid
index 907ce0deb8..57ac73c1bc 100644
--- a/manifest.uuid
+++ b/manifest.uuid
@@ -1 +1 @@
-fd5608fb20831f1f1946c8941445b7acc463a143
\ No newline at end of file
+ac5d2e9d760bb376e828e3d39ee070b567e59d58
\ No newline at end of file
diff --git a/src/btree.c b/src/btree.c
index 2692ade8e4..57522f505c 100644
--- a/src/btree.c
+++ b/src/btree.c
@@ -3194,6 +3194,8 @@ int sqlite3BtreeBeginTrans(Btree *p, int wrflag){
       }
     }
   }
+  sqlite3ExperimentalLog(p->pLog, "%s TM",
+    wrflag==0 ? "begin-read" : (wrflag>2 ? "begin-exclusive" : "begin-write"));
 
 
 trans_begun:
@@ -3682,6 +3684,7 @@ int sqlite3BtreeCommitPhaseOne(Btree *p, const char *zMaster){
       sqlite3PagerTruncateImage(pBt->pPager, pBt->nPage);
     }
 #endif
+    sqlite3ExperimentalLog(p->pLog, "commit-start TM");
     rc = sqlite3PagerCommitPhaseOne(pBt->pPager, zMaster, 0);
     sqlite3BtreeLeave(p);
   }
@@ -3724,6 +3727,7 @@ static void btreeEndTransaction(Btree *p){
     p->inTrans = TRANS_NONE;
     unlockBtreeIfUnused(pBt);
   }
+  sqlite3ExperimentalLog(p->pLog, "end-transaction TM");
 
   btreeIntegrity(p);
 }
@@ -6104,6 +6108,9 @@ static int fillInCell(
       }
 #endif
       rc = allocateBtreePage(pBt, &pOvfl, &pgnoOvfl, pgnoOvfl, 0);
+      if( rc==SQLITE_OK ){
+        sqlite3ExperimentalLog(pBt->pLog, "allocate %d overflow", pgnoOvfl);
+      }
 #ifndef SQLITE_OMIT_AUTOVACUUM
       /* If the database supports auto-vacuum, and the second or subsequent
       ** overflow page is being allocated, add an entry to the pointer-map
@@ -6704,6 +6711,10 @@ static int balance_quick(MemPage *pParent, MemPage *pPage, u8 *pSpace){
   ** may be inserted. If both these operations are successful, proceed.
   */
   rc = allocateBtreePage(pBt, &pNew, &pgnoNew, 0, 0);
+  if( rc==SQLITE_OK ){
+    sqlite3ExperimentalLog(pPage->pBt->pLog,
+                           "allocate %d quickbalance", pgnoNew);
+  }
 
   if( rc==SQLITE_OK ){
 
@@ -7327,6 +7338,7 @@ static int balance_nonroot(
       assert( i>0 );
       rc = allocateBtreePage(pBt, &pNew, &pgno, (bBulk ? 1 : pgno), 0);
       if( rc ) goto balance_cleanup;
+      sqlite3ExperimentalLog(pBt->pLog, "allocate %d balance", pgno);
       zeroPage(pNew, pageFlags);
       apNew[i] = pNew;
       nNew++;
@@ -7697,6 +7709,9 @@ static int balance_deeper(MemPage *pRoot, MemPage **ppChild){
   rc = sqlite3PagerWrite(pRoot->pDbPage);
   if( rc==SQLITE_OK ){
     rc = allocateBtreePage(pBt,&pChild,&pgnoChild,pRoot->pgno,0);
+    if( rc==SQLITE_OK ){
+      sqlite3ExperimentalLog(pBt->pLog, "allocate %d balancedeeper", pgnoChild);
+    }
     copyNodeContent(pRoot, pChild, &rc);
     if( ISAUTOVACUUM ){
       ptrmapPut(pBt, pgnoChild, PTRMAP_BTREE, pRoot->pgno, &rc);
@@ -8166,6 +8181,8 @@ static int btreeCreateTable(Btree *p, int *piTable, int createTabFlags){
   rc = allocateBtreePage(pBt, &pRoot, &pgnoRoot, 1, 0);
   if( rc ){
     return rc;
+  }else{
+    sqlite3ExperimentalLog(p->pLog, "allocate %d createtable", pgnoRoot);
   }
 #else
   if( pBt->autoVacuum ){
@@ -8203,6 +8220,8 @@ static int btreeCreateTable(Btree *p, int *piTable, int createTabFlags){
     rc = allocateBtreePage(pBt, &pPageMove, &pgnoMove, pgnoRoot, BTALLOC_EXACT);
     if( rc!=SQLITE_OK ){
       return rc;
+    }else{
+      sqlite3ExperimentalLog(p->pLog, "allocate %d createtable", pgnoMove);
     }
 
     if( pgnoMove!=pgnoRoot ){
@@ -8280,6 +8299,7 @@ static int btreeCreateTable(Btree *p, int *piTable, int createTabFlags){
   }else{
     rc = allocateBtreePage(pBt, &pRoot, &pgnoRoot, 1, 0);
     if( rc ) return rc;
+    sqlite3ExperimentalLog(p->pLog, "allocate %d createtable", pgnoRoot);
   }
 #endif
   assert( sqlite3PagerIswriteable(pRoot->pDbPage) );
@@ -9578,3 +9598,14 @@ int sqlite3BtreeIsReadonly(Btree *p){
 ** Return the size of the header added to each page by this module.
 */
 int sqlite3HeaderSizeBtree(void){ return ROUND8(sizeof(MemPage)); }
+
+
+/*
+** Set the Btree ExperimentalLog
+*/
+ExperimentalLog *sqlite3BtreeExperimentalLog(Btree *p, ExperimentalLog *pLog){
+  ExperimentalLog *pOld = p->pLog;
+  p->pLog = pLog;
+  p->pBt->pLog = pLog;
+  return pOld;
+}
diff --git a/src/btree.h b/src/btree.h
index 3edc2b3b57..22c984d40a 100644
--- a/src/btree.h
+++ b/src/btree.h
@@ -270,5 +270,6 @@ void sqlite3BtreeCursorList(Btree*);
 # define sqlite3SchemaMutexHeld(X,Y,Z) 1
 #endif
 
+ExperimentalLog *sqlite3BtreeExperimentalLog(Btree*,ExperimentalLog*);
 
 #endif /* _BTREE_H_ */
diff --git a/src/btreeInt.h b/src/btreeInt.h
index e52130cc39..140e18b15f 100644
--- a/src/btreeInt.h
+++ b/src/btreeInt.h
@@ -363,6 +363,7 @@ struct Btree {
 #ifndef SQLITE_OMIT_SHARED_CACHE
   BtLock lock;       /* Object used to lock page 1 */
 #endif
+  ExperimentalLog *pLog; /* Write various actions to this experimental log */
 };
 
 /*
@@ -414,6 +415,7 @@ struct Btree {
 struct BtShared {
   Pager *pPager;        /* The page cache */
   sqlite3 *db;          /* Database connection currently using this Btree */
+  ExperimentalLog *pLog; /* Log activities here */
   BtCursor *pCursor;    /* A list of all open cursors */
   MemPage *pPage1;      /* First page of the database */
   u8 openFlags;         /* Flags to sqlite3BtreeOpen() */
diff --git a/src/main.c b/src/main.c
index 36206eec8c..289f3f612b 100644
--- a/src/main.c
+++ b/src/main.c
@@ -978,6 +978,7 @@ static int sqlite3Close(sqlite3 *db, int forceZombie){
     return SQLITE_MISUSE_BKPT;
   }
   sqlite3_mutex_enter(db->mutex);
+  sqlite3_experimental_log_open(db, 0);
 
   /* Force xDisconnect calls on all virtual tables */
   disconnectAllVtab(db);
@@ -3786,3 +3787,66 @@ int sqlite3_db_readonly(sqlite3 *db, const char *zDbName){
   pBt = sqlite3DbNameToBtree(db, zDbName);
   return pBt ? sqlite3BtreeIsReadonly(pBt) : -1;
 }
+
+/*
+** Turn on logging for the main database of database connection db.
+** Disable logging if zFilename is NULL.
+*/
+void sqlite3_experimental_log_open(sqlite3 *db, const char *zFilename){
+  Btree *pBtree;
+  Pager *pPager;
+  ExperimentalLog *pLog;
+
+  sqlite3_mutex_enter(db->mutex);
+  pBtree = db->aDb[0].pBt;
+  if( pBtree ){
+    pPager = sqlite3BtreePager(pBtree);
+    pLog = sqlite3BtreeExperimentalLog(pBtree, 0);
+    if( pLog ){
+      sqlite3ExperimentalLog(pLog, "close TM");
+      fclose(pLog->out);
+      sqlite3_free(pLog);
+      pLog = 0;
+    }
+    if( zFilename ){
+      pLog = sqlite3_malloc( sizeof(*pLog) );
+      if( pLog ){ 
+        pLog->out = fopen(zFilename, "a+");
+        pLog->pVfs = db->pVfs;
+        if( pLog->out==0 ){
+          sqlite3_free(pLog);
+          pLog = 0;
+        }else{
+          sqlite3ExperimentalLog(pLog, "open %s TM", zFilename);
+        }
+      }
+    }
+    db->pLog = pLog;
+    sqlite3BtreeExperimentalLog(pBtree, pLog);
+    sqlite3PagerExperimentalLog(pPager, pLog);
+  }
+  sqlite3_mutex_leave(db->mutex);
+}
+
+/*
+** Write a message on the given ExperimentalLog if it is open
+*/
+void sqlite3ExperimentalLog(ExperimentalLog *pLog, const char *zFormat, ...){
+  if( pLog ){
+    va_list ap;
+    StrAccum acc;
+    sqlite3_int64 iTime = 0;
+    char zMsg[200];
+    va_start(ap, zFormat);
+    sqlite3StrAccumInit(&acc, 0, zMsg, sizeof(zMsg), 0);
+    sqlite3VXPrintf(&acc, 0, zFormat, ap);
+    if( acc.nChar>2 && strncmp(zMsg+acc.nChar-2, "TM", 2)==0 ){
+      acc.nChar -= 2;
+      sqlite3OsCurrentTimeInt64(pLog->pVfs, &iTime);
+      sqlite3XPrintf(&acc, 0, "%lld", iTime);
+    }
+    sqlite3StrAccumAppend(&acc, "\n", 1);
+    sqlite3StrAccumFinish(&acc);
+    fwrite(zMsg, 1, sqlite3Strlen30(zMsg), pLog->out);
+  }
+}
diff --git a/src/pager.c b/src/pager.c
index 060edb8d1d..1173390912 100644
--- 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
+  ExperimentalLog *pLog;      /* Output logging */
 };
 
 /*
@@ -4427,6 +4428,9 @@ static int pagerStress(void *p, PgHdr *pPg){
     return SQLITE_OK;
   }
 
+  if( pPager->pLog ){
+    sqlite3ExperimentalLog(pPager->pLog, "spill %d", pPg->pgno);
+  }
   pPg->pDirty = 0;
   if( pagerUseWal(pPager) ){
     /* Write a single frame for this page to the log. */
@@ -5268,6 +5272,9 @@ int sqlite3PagerAcquire(
     return SQLITE_CORRUPT_BKPT;
   }
   pPager->hasBeenUsed = 1;
+  if( pPager->pLog ){
+    sqlite3ExperimentalLog(pPager->pLog, "read %d", pgno);
+  }
 
   /* If the pager is in the error state, return an error immediately. 
   ** Otherwise, request the page from the PCache layer. */
@@ -5703,6 +5710,9 @@ static int pager_write(PgHdr *pPg){
   assert( pPager->errCode==0 );
   assert( pPager->readOnly==0 );
   CHECK_PAGE(pPg);
+  if( pPager->pLog ){
+    sqlite3ExperimentalLog(pPager->pLog, "write %d", pPg->pgno);
+  }
 
   /* The journal file needs to be opened. Higher level routines have already
   ** obtained the necessary locks to begin the write-transaction, but the
@@ -5889,6 +5899,12 @@ int sqlite3PagerWrite(PgHdr *pPg){
   }
 }
 
+/* Set experimental logging for this pager
+*/
+void sqlite3PagerExperimentalLog(Pager *p, ExperimentalLog *pLog){
+  p->pLog = pLog;
+}
+
 /*
 ** Return TRUE if the page given in the argument was previously passed
 ** to sqlite3PagerWrite().  In other words, return TRUE if it is ok
@@ -7088,6 +7104,11 @@ int sqlite3PagerCheckpoint(Pager *pPager, int eMode, int *pnLog, int *pnCkpt){
         pPager->ckptSyncFlags, pPager->pageSize, (u8 *)pPager->pTmpSpace,
         pnLog, pnCkpt
     );
+    if( pPager->pLog ){
+      const char *azType[] = { "passive", "full", "restart", "truncate" };
+      sqlite3ExperimentalLog(pPager->pLog, "checkpoint %s %d %d",
+                             azType[eMode], *pnLog, *pnCkpt);
+    }
   }
   return rc;
 }
@@ -7266,5 +7287,4 @@ int sqlite3PagerWalFramesize(Pager *pPager){
 }
 #endif
 
-
 #endif /* SQLITE_OMIT_DISKIO */
diff --git a/src/pager.h b/src/pager.h
index e3b57f435e..e7696ca148 100644
--- a/src/pager.h
+++ b/src/pager.h
@@ -193,6 +193,8 @@ void sqlite3PagerTruncateImage(Pager*,Pgno);
 
 void sqlite3PagerRekey(DbPage*, Pgno, u16);
 
+void sqlite3PagerExperimentalLog(Pager*, ExperimentalLog*);
+
 #if defined(SQLITE_HAS_CODEC) && !defined(SQLITE_OMIT_WAL)
 void *sqlite3PagerCodec(DbPage *);
 #endif
diff --git a/src/shell.c b/src/shell.c
index c289998a7b..79b1f76157 100644
--- a/src/shell.c
+++ b/src/shell.c
@@ -2849,6 +2849,18 @@ static int do_meta_command(char *zLine, ShellState *p){
     rc = 2;
   }else
 
+  if( c=='e' && strncmp(azArg[0], "explog", n)==0 ){
+    open_db(p, 0);
+    if( nArg!=2 ){
+      fprintf(stderr, "Usage: .explog FILENAME|off\n");
+      rc = 1;
+    }else if( strcmp(azArg[1],"off")==0 ){
+      sqlite3_experimental_log_open(p->db, 0);
+    }else{
+      sqlite3_experimental_log_open(p->db, azArg[1]);
+    }
+  }else
+
   if( c=='e' && strncmp(azArg[0], "explain", n)==0 ){
     int val = nArg>=2 ? booleanValue(azArg[1]) : 1;
     if(val == 1) {
diff --git a/src/sqlite.h.in b/src/sqlite.h.in
index 99fb4eb588..cae9ebe48b 100644
--- a/src/sqlite.h.in
+++ b/src/sqlite.h.in
@@ -7728,6 +7728,8 @@ int sqlite3_stmt_scanstatus(
 */
 void sqlite3_stmt_scanstatus_reset(sqlite3_stmt*);
 
+/* Experimental logging APIs.  Not for release. */
+void sqlite3_experimental_log_open(sqlite3*, const char *zFilename);
 
 /*
 ** Undo the hack that converts floating point types to integer for
diff --git a/src/sqliteInt.h b/src/sqliteInt.h
index 9c79c91dfa..7842bea265 100644
--- a/src/sqliteInt.h
+++ b/src/sqliteInt.h
@@ -923,6 +923,7 @@ typedef struct Schema Schema;
 typedef struct Expr Expr;
 typedef struct ExprList ExprList;
 typedef struct ExprSpan ExprSpan;
+typedef struct ExperimentalLog ExperimentalLog;
 typedef struct FKey FKey;
 typedef struct FuncDestructor FuncDestructor;
 typedef struct FuncDef FuncDef;
@@ -1247,8 +1248,18 @@ struct sqlite3 {
 #ifdef SQLITE_USER_AUTHENTICATION
   sqlite3_userauth auth;        /* User authentication information */
 #endif
+  ExperimentalLog *pLog;        /* Write experimental log messages here */
 };
 
+/*
+** Information needed by the experimental log
+*/
+struct ExperimentalLog {
+  FILE *out;                    /* Write on this file descriptor */
+  sqlite3_vfs *pVfs;            /* Used to get current time of day */
+};
+void sqlite3ExperimentalLog(ExperimentalLog*, const char *zFormat, ...);
+
 /*
 ** A macro to discover the encoding of a database.
 */
diff --git a/src/vdbe.c b/src/vdbe.c
index f9c988cdf7..e2b9c0212a 100644
--- a/src/vdbe.c
+++ b/src/vdbe.c
@@ -6521,6 +6521,15 @@ case OP_Init: {          /* jump */
   char *zTrace;
   char *z;
 
+  if( db->pLog && p->zSql ){
+    char *z = sqlite3DbStrDup(db, p->zSql);
+    int ii;
+    for(ii=0; z[ii]; ii++){
+      if( sqlite3Isspace(z[ii]) ) z[ii] = ' ';
+    }
+    sqlite3ExperimentalLog(db->pLog, "sql {%s}", z);
+    sqlite3DbFree(db, z);
+  }
 #ifndef SQLITE_OMIT_TRACE
   if( db->xTrace
    && !p->doingRerun