Index: src/printf.c ================================================================== --- src/printf.c +++ src/printf.c @@ -932,25 +932,32 @@ /* ** sqlite3_snprintf() works like snprintf() except that it ignores the ** current locale settings. This is important for SQLite because we ** are not able to use a "," as the decimal point in place of "." as ** specified by some locales. +** +** Oops: The first two arguments of sqlite3_snprintf() are backwards +** from the snprintf() standard. Unfortunately, it is too late to change +** this without breaking compatibility, so we just have to live with the +** mistake. +** +** sqlite3_vsnprintf() is the varargs version. */ +char *sqlite3_vsnprintf(int n, char *zBuf, const char *zFormat, va_list ap){ + StrAccum acc; + if( n<=0 ) return zBuf; + sqlite3StrAccumInit(&acc, zBuf, n, 0); + acc.useMalloc = 0; + sqlite3VXPrintf(&acc, 0, zFormat, ap); + return sqlite3StrAccumFinish(&acc); +} char *sqlite3_snprintf(int n, char *zBuf, const char *zFormat, ...){ char *z; va_list ap; - StrAccum acc; - - if( n<=0 ){ - return zBuf; - } - sqlite3StrAccumInit(&acc, zBuf, n, 0); - acc.useMalloc = 0; va_start(ap,zFormat); - sqlite3VXPrintf(&acc, 0, zFormat, ap); + z = sqlite3_vsnprintf(n, zBuf, zFormat, ap); va_end(ap); - z = sqlite3StrAccumFinish(&acc); return z; } /* ** This is the routine that actually formats the sqlite3_log() message. Index: src/sqlite.h.in ================================================================== --- src/sqlite.h.in +++ src/sqlite.h.in @@ -1827,10 +1827,12 @@ ** guarantees that the buffer is always zero-terminated. ^The first ** parameter "n" is the total size of the buffer, including space for ** the zero terminator. So the longest string that can be completely ** written will be n-1 characters. ** +** ^The sqlite3_vsnprintf() routine is a varargs version of sqlite3_snprintf(). +** ** These routines all implement some additional formatting ** options that are useful for constructing SQL statements. ** All of the usual printf() formatting options apply. In addition, there ** is are "%q", "%Q", and "%z" options. ** @@ -1890,10 +1892,11 @@ ** the result, [sqlite3_free()] is called on the input string.)^ */ char *sqlite3_mprintf(const char*,...); char *sqlite3_vmprintf(const char*, va_list); char *sqlite3_snprintf(int,char*,const char*, ...); +char *sqlite3_vsnprintf(int,char*,const char*, va_list); /* ** CAPI3REF: Memory Allocation Subsystem ** ** The SQLite core uses these three routines for all of its own Index: src/wal.c ================================================================== --- src/wal.c +++ src/wal.c @@ -250,10 +250,25 @@ int sqlite3WalTrace = 0; # define WALTRACE(X) if(sqlite3WalTrace) sqlite3DebugPrintf X #else # define WALTRACE(X) #endif + +/* +** WAL tracing logic added to search for an SQLITE_PROTOCOL error. +*/ +static void walTrace(const char *zFormat, ...){ + va_list ap; + char zMsg[100]; + va_start(ap, zFormat); + sqlite3_vsnprintf(sizeof(zMsg), zMsg, zFormat, ap); + va_end(ap); +#ifdef SQLITE_WAL_TRACE + fprintf(stdout, "WALTRACE: [%s]\n", zMsg); fflush(stdout); +#endif + sqlite3_log(99, "%s", zMsg); +} /* ** The maximum (and only) versions of the wal and wal-index formats ** that may be interpreted by this version of SQLite. ** @@ -502,10 +517,11 @@ int nByte = sizeof(u32*)*(iPage+1); volatile u32 **apNew; apNew = (volatile u32 **)sqlite3_realloc((void *)pWal->apWiData, nByte); if( !apNew ){ *ppPage = 0; + walTrace("realloc(%d) in walIndexPage()", nByte); return SQLITE_NOMEM; } memset((void*)&apNew[pWal->nWiData], 0, sizeof(u32*)*(iPage+1-pWal->nWiData)); pWal->apWiData = apNew; @@ -515,10 +531,11 @@ /* Request a pointer to the required page from the VFS */ if( pWal->apWiData[iPage]==0 ){ rc = sqlite3OsShmMap(pWal->pDbFd, iPage, WALINDEX_PGSZ, pWal->writeLock, (void volatile **)&pWal->apWiData[iPage] ); + if( rc ) walTrace("xShmMap():%d in walIndexPage(iPage=%d)",rc,iPage); } *ppPage = pWal->apWiData[iPage]; assert( iPage==0 || *ppPage || rc!=SQLITE_OK ); return rc; @@ -1793,24 +1810,28 @@ ** with a writer. So get a WRITE lock and try again. */ assert( badHdr==0 || pWal->writeLock==0 ); if( badHdr && SQLITE_OK==(rc = walLockExclusive(pWal, WAL_WRITE_LOCK, 1)) ){ pWal->writeLock = 1; + walTrace("trying walIndexTryHdr w/lock"); if( SQLITE_OK==(rc = walIndexPage(pWal, 0, &page0)) ){ badHdr = walIndexTryHdr(pWal, pChanged); if( badHdr ){ /* If the wal-index header is still malformed even while holding ** a WRITE lock, it can only mean that the header is corrupted and ** needs to be reconstructed. So run recovery to do exactly that. */ + walTrace("walIndexTryHdr() failed w/lock"); rc = walIndexRecover(pWal); + if( rc ) walTrace("walIndexRecover():%d", rc); *pChanged = 1; } } pWal->writeLock = 0; walUnlockExclusive(pWal, WAL_WRITE_LOCK, 1); } + else if(badHdr) walTrace("walLockExcl():%d in walIndexReadHdr()", rc); /* If the header is read successfully, check the version number to make ** sure the wal-index was not constructed with some future format that ** this version of SQLite cannot understand. */ @@ -1886,10 +1907,11 @@ assert( pWal->readLock<0 ); /* Not currently locked */ /* Take steps to avoid spinning forever if there is a protocol error. */ if( cnt>5 ){ + walTrace("cnt=%d",cnt); if( cnt>100 ) return SQLITE_PROTOCOL; sqlite3OsSleep(pWal->pVfs, 1); } if( !useWal ){ @@ -1944,16 +1966,18 @@ ** is wrapped and written for that matter) before the READ_LOCK(0) ** is obtained, that is not necessarily true. A checkpointer may ** have started to backfill the appended frames but crashed before ** it finished. Leaving a corrupt image in the database file. */ + walTrace("wal read/write race - writer won"); walUnlockShared(pWal, WAL_READ_LOCK(0)); return WAL_RETRY; } pWal->readLock = 0; return SQLITE_OK; }else if( rc!=SQLITE_BUSY ){ + walTrace("walLockShared(0):%d in walTryBeginRead", rc); return rc; } } /* If we get this far, it means that the reader will want to use @@ -1979,12 +2003,14 @@ rc = walLockExclusive(pWal, WAL_READ_LOCK(1), 1); if( rc==SQLITE_OK ){ pInfo->aReadMark[1] = pWal->hdr.mxFrame; walUnlockExclusive(pWal, WAL_READ_LOCK(1), 1); rc = WAL_RETRY; + walTrace("aReadMark[1] <- %d", pWal->hdr.mxFrame); }else if( rc==SQLITE_BUSY ){ rc = WAL_RETRY; + walTrace("aReadMark[1] is busy"); } return rc; }else{ if( mxReadMark < pWal->hdr.mxFrame ){ for(i=1; iaReadMark[i] = pWal->hdr.mxFrame; mxI = i; walUnlockExclusive(pWal, WAL_READ_LOCK(i), 1); break; }else if( rc!=SQLITE_BUSY ){ + walTrace("walLockExclusive(%d):%d", i, rc); return rc; } } } rc = walLockShared(pWal, WAL_READ_LOCK(mxI)); if( rc ){ + walTrace("walLockShared(mxI=%d):%d", mxI, rc); return rc==SQLITE_BUSY ? WAL_RETRY : rc; } /* Now that the read-lock has been obtained, check that neither the ** value in the aReadMark[] array or the contents of the wal-index ** header have changed.