SQLite

static void pthreadMutexFree(sqlite3_mutex *p){
  assert( p->nRef==0 );
  assert( p->id==SQLITE_MUTEX_FAST || p->id==SQLITE_MUTEX_RECURSIVE );
  pthread_mutex_destroy(&p->mutex);
  sqlite3_free(p);
}

#include <sys/time.h>
#ifdef SQLITE_MUTEX_NREF
# define MUTEX_ID(p)  (p->id)
#else
# define MUTEX_ID(p)  0
#endif

/*
** The sqlite3_mutex_enter() and sqlite3_mutex_try() routines attempt
** to enter a mutex.  If another thread is already within the mutex,
** sqlite3_mutex_enter() will block and sqlite3_mutex_try() will return
** SQLITE_BUSY.  The sqlite3_mutex_try() interface returns SQLITE_OK
** upon successful entry.  Mutexes created using SQLITE_MUTEX_RECURSIVE can
** be entered multiple times by the same thread.  In such cases the,
** mutex must be exited an equal number of times before another thread
** can enter.  If the same thread tries to enter any other kind of mutex
** more than once, the behavior is undefined.
*/
static void pthreadMutexEnter(sqlite3_mutex *p){

  START_DEBUG_TIMER;
  assert( p->id==SQLITE_MUTEX_RECURSIVE || pthreadMutexNotheld(p) );

#ifdef SQLITE_HOMEGROWN_RECURSIVE_MUTEX
  /* If recursive mutexes are not available, then we have to grow
  ** our own.  This implementation assumes that pthread_equal()
  ** is atomic - that it cannot be deceived into thinking self
  ** and p->owner are equal if p->owner changes between two values

  */
  pthread_mutex_lock(&p->mutex);
#if SQLITE_MUTEX_NREF
  assert( p->nRef>0 || p->owner==0 );
  p->owner = pthread_self();
  p->nRef++;
#endif
  END_DEBUG_TIMER(500) {
    sqlite3_mutex *pMaster = sqlite3_mutex_alloc(SQLITE_MUTEX_STATIC_MASTER);
    int id = -1;
    if( p>=pMaster && p<=&pMaster[SQLITE_MUTEX_STATIC_APP3-2] ){
      id = (int)(p - pMaster) + 2;
    }
    sqlite3_log(SQLITE_NOTICE, "slow mutex: %llu uS on %d/%p",iDebugTimer,id,p);
  }
#endif

#ifdef SQLITE_DEBUG
  if( p->trace ){
    printf("enter mutex %p (%d) with nRef=%d\n", p, p->trace, p->nRef);
  }
#endif

** The following routines are convenience wrappers around methods
** of the sqlite3_file object.  This is mostly just syntactic sugar. All
** of this would be completely automatic if SQLite were coded using
** C++ instead of plain old C.
*/
int sqlite3OsClose(sqlite3_file *pId){
  int rc = SQLITE_OK;
  START_DEBUG_TIMER;
  if( pId->pMethods ){
    rc = pId->pMethods->xClose(pId);
    pId->pMethods = 0;
  }
  END_DEBUG_TIMER( DEBUG_TIMER_SMALL_TIMEOUT ){
    sqlite3_log(SQLITE_NOTICE, "slow sqlite3OsClose: %llu uS", iDebugTimer);
  }
  return rc;
}
int sqlite3OsRead(sqlite3_file *id, void *pBuf, int amt, i64 offset){
  DO_OS_MALLOC_TEST(id);
  return id->pMethods->xRead(id, pBuf, amt, offset);
}
int sqlite3OsWrite(sqlite3_file *id, const void *pBuf, int amt, i64 offset){
  DO_OS_MALLOC_TEST(id);
  return id->pMethods->xWrite(id, pBuf, amt, offset);
}
int sqlite3OsTruncate(sqlite3_file *id, i64 size){
  return id->pMethods->xTruncate(id, size);
}
int sqlite3OsSync(sqlite3_file *id, int flags){
  int rc;
  START_DEBUG_TIMER;
  rc = id->pMethods->xSync(id, flags);
  END_DEBUG_TIMER( DEBUG_TIMER_SMALL_TIMEOUT ){
    sqlite3_log(SQLITE_NOTICE, 
        "slow sqlite3OsSync(ptr, %d): %llu uS", flags, iDebugTimer
    );
  }
  return rc;
}
int sqlite3OsFileSize(sqlite3_file *id, i64 *pSize){
  DO_OS_MALLOC_TEST(id);
  return id->pMethods->xFileSize(id, pSize);
}
int sqlite3OsLock(sqlite3_file *id, int lockType){
  DO_OS_MALLOC_TEST(id);

** and we need to know about the failures.  Use sqlite3OsFileControlHint()
** when simply tossing information over the wall to the VFS and we do not
** really care if the VFS receives and understands the information since it
** is only a hint and can be safely ignored.  The sqlite3OsFileControlHint()
** routine has no return value since the return value would be meaningless.
*/
int sqlite3OsFileControl(sqlite3_file *id, int op, void *pArg){
  int rc;
  START_DEBUG_TIMER;
#ifdef SQLITE_TEST
  if( op!=SQLITE_FCNTL_COMMIT_PHASETWO ){
    /* Faults are not injected into COMMIT_PHASETWO because, assuming SQLite
    ** is using a regular VFS, it is called after the corresponding 
    ** transaction has been committed. Injecting a fault at this point 
    ** confuses the test scripts - the COMMIT comand returns SQLITE_NOMEM
    ** but the transaction is committed anyway.
    **
    ** The core must call OsFileControl() though, not OsFileControlHint(),
    ** as if a custom VFS (e.g. zipvfs) returns an error here, it probably
    ** means the commit really has failed and an error should be returned
    ** to the user.  */
    DO_OS_MALLOC_TEST(id);
  }
#endif
  rc = id->pMethods->xFileControl(id, op, pArg);
  END_DEBUG_TIMER( DEBUG_TIMER_SMALL_TIMEOUT ){
    sqlite3_log(SQLITE_NOTICE, 
        "slow sqlite3OsFileControl: %llu uS", iDebugTimer);
  }
  return rc;
}
void sqlite3OsFileControlHint(sqlite3_file *id, int op, void *pArg){
  (void)id->pMethods->xFileControl(id, op, pArg);
}

int sqlite3OsSectorSize(sqlite3_file *id){
  int (*xSectorSize)(sqlite3_file*) = id->pMethods->xSectorSize;
  return (xSectorSize ? xSectorSize(id) : SQLITE_DEFAULT_SECTOR_SIZE);
}
int sqlite3OsDeviceCharacteristics(sqlite3_file *id){
  return id->pMethods->xDeviceCharacteristics(id);
}
int sqlite3OsShmLock(sqlite3_file *id, int offset, int n, int flags){
  int rc;
  START_DEBUG_TIMER;
  rc = id->pMethods->xShmLock(id, offset, n, flags);
  END_DEBUG_TIMER( DEBUG_TIMER_SMALL_TIMEOUT ){
    sqlite3_log(SQLITE_NOTICE, 
        "slow sqlite3OsShmLock(ptr, %d, %d, %d): %llu uS", 
        offset, n, flags, iDebugTimer
    );
  }
  return rc;
}
void sqlite3OsShmBarrier(sqlite3_file *id){
  START_DEBUG_TIMER;
  id->pMethods->xShmBarrier(id);
  END_DEBUG_TIMER( DEBUG_TIMER_SMALL_TIMEOUT ){
    sqlite3_log(SQLITE_NOTICE, 
        "slow sqlite3OsShmBarrier: %llu uS", iDebugTimer
    );
  }
}
int sqlite3OsShmUnmap(sqlite3_file *id, int deleteFlag){
  return id->pMethods->xShmUnmap(id, deleteFlag);
}
int sqlite3OsShmMap(
  sqlite3_file *id,               /* Database file handle */
  int iPage,

** All loads and stores begun before the barrier must complete before
** any load or store begun after the barrier.
*/
static void unixShmBarrier(
  sqlite3_file *fd                /* Database file holding the shared memory */
){
  UNUSED_PARAMETER(fd);
#if defined(__GNUC__) && GCC_VERSION>=4001000
  __sync_synchronize();
#else
  unixEnterMutex();
  unixLeaveMutex();
#endif
}

/*
** Close a connection to shared-memory.  Delete the underlying 
** storage if deleteFlag is true.
**
** If there is no shared memory associated with the connection then this

** unlock operation fails as well, then the first error code related
** to the first error encountered (the journal finalization one) is
** returned.
*/
static int pager_end_transaction(Pager *pPager, int hasMaster, int bCommit){
  int rc = SQLITE_OK;      /* Error code from journal finalization operation */
  int rc2 = SQLITE_OK;     /* Error code from db file unlock operation */
  START_DEBUG_TIMER;

  /* Do nothing if the pager does not have an open write transaction
  ** or at least a RESERVED lock. This function may be called when there
  ** is no write-transaction active but a RESERVED or greater lock is
  ** held under two circumstances:
  **
  **   1. After a successful hot-journal rollback, it is called with

      );
      sqlite3OsClose(pPager->jfd);
      if( bDelete ){
        rc = sqlite3OsDelete(pPager->pVfs, pPager->zJournal, 0);
      }
    }
  }
  END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ){
    sqlite3_log(SQLITE_NOTICE, "slow pager_end_transaction(1): %llu uS wal=%d", 
      iDebugTimer, pagerUseWal(pPager));
    iDebugTimerStart += iDebugTimer;
  }

#ifdef SQLITE_CHECK_PAGES
  sqlite3PcacheIterateDirty(pPager->pPCache, pager_set_pagehash);
  if( pPager->dbSize==0 && sqlite3PcacheRefCount(pPager->pPCache)>0 ){
    PgHdr *p = sqlite3PagerLookup(pPager, 1);
    if( p ){
      p->pageHash = 0;
      sqlite3PagerUnrefNotNull(p);
    }
  }
#endif

  sqlite3BitvecDestroy(pPager->pInJournal);
  pPager->pInJournal = 0;
  pPager->nRec = 0;
  sqlite3PcacheCleanAll(pPager->pPCache);
  END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ){
    sqlite3_log(SQLITE_NOTICE, "slow pager_end_transaction(2): %llu uS wal=%d", 
      iDebugTimer, pagerUseWal(pPager));
    iDebugTimerStart += iDebugTimer;
  }
  sqlite3PcacheTruncate(pPager->pPCache, pPager->dbSize);
  END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ){
    sqlite3_log(SQLITE_NOTICE, "slow pager_end_transaction(3): %llu uS wal=%d",
      iDebugTimer, pagerUseWal(pPager));
    iDebugTimerStart += iDebugTimer;
  }

  if( pagerUseWal(pPager) ){
    /* Drop the WAL write-lock, if any. Also, if the connection was in 
    ** locking_mode=exclusive mode but is no longer, drop the EXCLUSIVE 
    ** lock held on the database file.
    */
    rc2 = sqlite3WalEndWriteTransaction(pPager->pWal);
    assert( rc2==SQLITE_OK );
  }else if( rc==SQLITE_OK && bCommit && pPager->dbFileSize>pPager->dbSize ){
    /* This branch is taken when committing a transaction in rollback-journal
    ** mode if the database file on disk is larger than the database image.
    ** At this point the journal has been finalized and the transaction 
    ** successfully committed, but the EXCLUSIVE lock is still held on the
    ** file. So it is safe to truncate the database file to its minimum
    ** required size.  */
    assert( pPager->eLock==EXCLUSIVE_LOCK );
    rc = pager_truncate(pPager, pPager->dbSize);
  }
  END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ){
    sqlite3_log(SQLITE_NOTICE, "slow pager_end_transaction(4): %llu uS wal=%d",
      iDebugTimer, pagerUseWal(pPager));
    iDebugTimerStart += iDebugTimer;
  }

  if( rc==SQLITE_OK && bCommit && isOpen(pPager->fd) ){
    rc = sqlite3OsFileControl(pPager->fd, SQLITE_FCNTL_COMMIT_PHASETWO, 0);
    if( rc==SQLITE_NOTFOUND ) rc = SQLITE_OK;
  }

  if( !pPager->exclusiveMode 
   && (!pagerUseWal(pPager) || sqlite3WalExclusiveMode(pPager->pWal, 0))
  ){
    rc2 = pagerUnlockDb(pPager, SHARED_LOCK);
    pPager->changeCountDone = 0;
  }
  pPager->eState = PAGER_READER;
  pPager->setMaster = 0;

  END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ){
    sqlite3_log(SQLITE_NOTICE, "slow pager_end_transaction(5): %llu uS wal=%d",
      iDebugTimer, pagerUseWal(pPager));
  }
  return (rc==SQLITE_OK?rc2:rc);
}

/*
** Execute a rollback if a transaction is active and unlock the 
** database file. 
**

        pp = &pPage->pNext;
        TESTONLY( nPage++; )
      }
    }
  }
  assert( pCache->nPage==nPage );
  END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ){
    sqlite3_log(SQLITE_NOTICE, "slow pcache1TruncateUnsafe() %lld nFree=%d",


                iDebugTimer, nFree);

  }
}

/******************************************************************************/
/******** sqlite3_pcache Methods **********************************************/

/*

**
** Discard all unpinned pages in the cache with a page number equal to
** or greater than parameter iLimit. Any pinned pages with a page number
** equal to or greater than iLimit are implicitly unpinned.
*/
static void pcache1Truncate(sqlite3_pcache *p, unsigned int iLimit){
  PCache1 *pCache = (PCache1 *)p;
  START_DEBUG_TIMER;
  pcache1EnterMutex(pCache->pGroup);
  if( iLimit<=pCache->iMaxKey ){
    pcache1TruncateUnsafe(pCache, iLimit);
    pCache->iMaxKey = iLimit-1;
  }
  pcache1LeaveMutex(pCache->pGroup);
  END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ){
    sqlite3_log(SQLITE_NOTICE, "slow pcache1Truncate(%d): %llu uS",
      (int)iLimit, iDebugTimer);
  }
}

/*
** Implementation of the sqlite3_pcache.xDestroy method. 
**
** Destroy a cache allocated using pcache1Create().
*/

/*
** This function is called after a transaction has been committed. It 
** invokes callbacks registered with sqlite3_wal_hook() as required.
*/
static int doWalCallbacks(sqlite3 *db){
  int rc = SQLITE_OK;
  START_DEBUG_TIMER;
#ifndef SQLITE_OMIT_WAL
  int i;
  for(i=0; i<db->nDb; i++){
    Btree *pBt = db->aDb[i].pBt;
    if( pBt ){
      int nEntry = sqlite3PagerWalCallback(sqlite3BtreePager(pBt));
      if( db->xWalCallback && nEntry>0 && rc==SQLITE_OK ){
        rc = db->xWalCallback(db->pWalArg, db, db->aDb[i].zName, nEntry);
      }
    }
  }
#endif
  END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ) {
    sqlite3_log(SQLITE_NOTICE, "slow doWalCallbacks: %llu uS", iDebugTimer);
  }
  return rc;
}

/*
** Execute the statement pStmt, either until a row of data is ready, the
** statement is completely executed or an error occurs.
**
** This routine implements the bulk of the logic behind the sqlite_step()
** API.  The only thing omitted is the automatic recompile if a 
** schema change has occurred.  That detail is handled by the
** outer sqlite3_step() wrapper procedure.
*/
static int sqlite3Step(Vdbe *p){
  sqlite3 *db;
  int rc;
  START_DEBUG_TIMER;

  assert(p);
  if( p->magic!=VDBE_MAGIC_RUN ){
    /* We used to require that sqlite3_reset() be called before retrying
    ** sqlite3_step() after any error or after SQLITE_DONE.  But beginning
    ** with version 3.7.0, we changed this so that sqlite3_reset() would
    ** be called automatically instead of throwing the SQLITE_MISUSE error.

  if( p->isPrepareV2 && rc!=SQLITE_ROW && rc!=SQLITE_DONE ){
    /* If this statement was prepared using sqlite3_prepare_v2(), and an
    ** error has occurred, then return the error code in p->rc to the
    ** caller. Set the error code in the database handle to the same value.
    */ 
    rc = sqlite3VdbeTransferError(p);
  }
  END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ) {
    sqlite3_log(SQLITE_NOTICE, "slow (%llu) sqlite3Step(%s)", 
        iDebugTimer, (p->zSql ? p->zSql : "")
    );
  }
  return (rc&db->errMask);
}

/*
** This is the top-level implementation of sqlite3_step().  Call
** sqlite3Step() to do most of the work.  If a schema error occurs,
** call sqlite3Reprepare() and try again.

** takes care of the master journal trickery.
*/
static int vdbeCommit(sqlite3 *db, Vdbe *p){
  int i;
  int nTrans = 0;  /* Number of databases with an active write-transaction */
  int rc = SQLITE_OK;
  int needXcommit = 0;
  START_DEBUG_TIMER;

#ifdef SQLITE_OMIT_VIRTUALTABLE
  /* With this option, sqlite3VtabSync() is defined to be simply 
  ** SQLITE_OK so p is not used. 
  */
  UNUSED_PARAMETER(p);
#endif

    sqlite3EndBenignMalloc();
    enable_simulated_io_errors();

    sqlite3VtabCommit(db);
  }
#endif

  END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ) {
    sqlite3_log(SQLITE_NOTICE, "slow vdbeCommit: %llu uS", iDebugTimer);
  }
  return rc;
}

/* 
** This routine checks that the sqlite3.nVdbeActive count variable
** matches the number of vdbe's in the list sqlite3.pVdbe that are
** currently active. An assertion fails if the two counts do not match.

  if( pInfo->nBackfill<mxSafeFrame
   && (rc = walBusyLock(pWal, xBusy, pBusyArg, WAL_READ_LOCK(0), 1))==SQLITE_OK
  ){
    i64 nSize;                    /* Current size of database file */
    u32 nBackfill = pInfo->nBackfill;

    /* ELATDPP: Extra logging added to debug performance problem */
    sqlite3_log(SQLITE_NOTICE, 
        "wal: checkpoint salt1=%08x salt2=%08x "
        "nBackfill=%d mxSafeFrame=%d mxFrame=%d",
        pWal->hdr.aSalt[0], pWal->hdr.aSalt[1],
        (int)nBackfill, (int)mxSafeFrame, (int)pWal->hdr.mxFrame
    );

    /* Sync the WAL to disk */
    if( sync_flags ){
      rc = sqlite3OsSync(pWal->pWalFd, sync_flags);
    }

    /* If the database may grow as a result of this checkpoint, hint
    ** about the eventual size of the db file to the VFS layer.

  PgHdr *p;                       /* Iterator to run through pList with. */
  PgHdr *pLast = 0;               /* Last frame in list */
  int nExtra = 0;                 /* Number of extra copies of last page */
  int szFrame;                    /* The size of a single frame */
  i64 iOffset;                    /* Next byte to write in WAL file */
  WalWriter w;                    /* The writer */

  START_DEBUG_TIMER;

  assert( pList );
  assert( pWal->writeLock );

  /* If this frame set completes a transaction, then nTruncate>0.  If
  ** nTruncate==0 then this frame set does not complete the transaction. */
  assert( (isCommit!=0)==(nTruncate!=0) );

    nDbSize = (isCommit && p->pDirty==0) ? nTruncate : 0;
    rc = walWriteOneFrame(&w, p, nDbSize, iOffset);
    if( rc ) return rc;
    pLast = p;
    iOffset += szFrame;
  }

  /* ELATDPP: Extra logging added to debug performance problem */
  sqlite3_log(SQLITE_NOTICE, "wal: write nFrame=%d iFrame=%d", 
      iFrame - pWal->hdr.mxFrame, 
      pWal->hdr.mxFrame+1
  );

  /* If this is the end of a transaction, then we might need to pad
  ** the transaction and/or sync the WAL file.
  **
  ** Padding and syncing only occur if this set of frames complete a
  ** transaction and if PRAGMA synchronous=FULL.  If synchronous==NORMAL
  ** or synchronous==OFF, then no padding or syncing are needed.
  **

    /* If this is a commit, update the wal-index header too. */
    if( isCommit ){
      walIndexWriteHdr(pWal);
      pWal->iCallback = iFrame;
    }
  }

  END_DEBUG_TIMER( DEBUG_TIMER_BIG_TIMEOUT ) {
    sqlite3_log(SQLITE_NOTICE, "slow sqlite3WalFrames: %llu uS", iDebugTimer);
  }

  WALTRACE(("WAL%p: frame write %s\n", pWal, rc ? "failed" : "ok"));
  return rc;
}

/* 
** This routine is called to implement sqlite3_wal_checkpoint() and
** related interfaces.

  int *pnLog,                     /* OUT: Number of frames in WAL */
  int *pnCkpt                     /* OUT: Number of backfilled frames in WAL */
){
  int rc;                         /* Return code */
  int isChanged = 0;              /* True if a new wal-index header is loaded */
  int eMode2 = eMode;             /* Mode to pass to walCheckpoint() */

  /* ELATDPP: Extra logging added to debug performance problem */
  sqlite3_int64 t1, t2;
  sqlite3OsCurrentTimeInt64(pWal->pVfs, &t1);

  assert( pWal->ckptLock==0 );
  assert( pWal->writeLock==0 );

  if( pWal->readOnly ) return SQLITE_READONLY;
  WALTRACE(("WAL%p: checkpoint begins\n", pWal));
  rc = walLockExclusive(pWal, WAL_CKPT_LOCK, 1);
  if( rc ){

    memset(&pWal->hdr, 0, sizeof(WalIndexHdr));
  }

  /* Release the locks. */
  sqlite3WalEndWriteTransaction(pWal);
  walUnlockExclusive(pWal, WAL_CKPT_LOCK, 1);
  pWal->ckptLock = 0;

  /* ELATDPP: Extra logging added to debug performance problem */
  sqlite3OsCurrentTimeInt64(pWal->pVfs, &t2);
  sqlite3_log(SQLITE_NOTICE, "wal: checkpoint rc=%d ms=%lld", rc, t2-t1);

  WALTRACE(("WAL%p: checkpoint %s\n", pWal, rc ? "failed" : "ok"));
  return (rc==SQLITE_OK && eMode!=eMode2 ? SQLITE_BUSY : rc);
}

/* Return the value to pass to a sqlite3_wal_hook callback, the
** number of frames in the WAL at the point of the last commit since
** sqlite3WalCallback() was called.  If no commits have occurred since