/ Check-in [7d0af4b5]
Login

Many hyperlinks are disabled.
Use anonymous login to enable hyperlinks.

Overview
Comment:Add a debug timer to pcache1Truncate(). Change the formatting of some other messages to make them easier to read.
Downloads: Tarball | ZIP archive | SQL archive
Timelines: family | ancestors | descendants | both | debug
Files: files | file ages | folders
SHA1:7d0af4b53c440f4628f0cecdc40459335630fa4e
User & Date: dan 2016-08-09 11:23:22
Context
2016-08-09
11:44
Add another timer on pcache1TruncateUnsafe(). check-in: 42ce53f6 user: drh tags: debug
11:23
Add a debug timer to pcache1Truncate(). Change the formatting of some other messages to make them easier to read. check-in: 7d0af4b5 user: dan tags: debug
01:21
Refocus the timer on the pager_end_transaction() routine. check-in: 9d4eb6e4 user: drh tags: debug
Changes
Hide Diffs Unified Diffs Ignore Whitespace Patch

Changes to src/pager.c.

1971
1972
1973
1974
1975
1976
1977
1978
1979
1980
1981
1982
1983
1984
1985
....
1992
1993
1994
1995
1996
1997
1998
1999
2000
2001
2002
2003
2004
2005
2006
2007
2008
2009
2010
2011
2012
....
2021
2022
2023
2024
2025
2026
2027
2028
2029
2030
2031
2032
2033
2034
2035
....
2041
2042
2043
2044
2045
2046
2047
2048
2049
2050
2051
2052
2053
2054
2055
      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 %d", 
      iDebugTimer, pagerUseWal(pPager));
    iDebugTimerStart += iDebugTimer;
  }

#ifdef SQLITE_CHECK_PAGES
  sqlite3PcacheIterateDirty(pPager->pPCache, pager_set_pagehash);
  if( pPager->dbSize==0 && sqlite3PcacheRefCount(pPager->pPCache)>0 ){
................................................................................
#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 %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 %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 
................................................................................
    ** 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 %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;
................................................................................
    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 %d",
      iDebugTimer, pagerUseWal(pPager));
  }
  return (rc==SQLITE_OK?rc2:rc);
}

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







|







 







|





|







 







|







 







|







1971
1972
1973
1974
1975
1976
1977
1978
1979
1980
1981
1982
1983
1984
1985
....
1992
1993
1994
1995
1996
1997
1998
1999
2000
2001
2002
2003
2004
2005
2006
2007
2008
2009
2010
2011
2012
....
2021
2022
2023
2024
2025
2026
2027
2028
2029
2030
2031
2032
2033
2034
2035
....
2041
2042
2043
2044
2045
2046
2047
2048
2049
2050
2051
2052
2053
2054
2055
      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 ){
................................................................................
#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 
................................................................................
    ** 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;
................................................................................
    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 

Changes to src/pcache1.c.

923
924
925
926
927
928
929

930
931
932
933
934
935




936
937
938
939
940
941
942
**
** 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;

  pcache1EnterMutex(pCache->pGroup);
  if( iLimit<=pCache->iMaxKey ){
    pcache1TruncateUnsafe(pCache, iLimit);
    pCache->iMaxKey = iLimit-1;
  }
  pcache1LeaveMutex(pCache->pGroup);




}

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







>






>
>
>
>







923
924
925
926
927
928
929
930
931
932
933
934
935
936
937
938
939
940
941
942
943
944
945
946
947
**
** 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().
*/