Many hyperlinks are disabled.
Use anonymous login
to enable hyperlinks.
Overview
Comment: | Refocus the timer on the pager_end_transaction() routine. |
---|---|
Downloads: | Tarball | ZIP archive |
Timelines: | family | ancestors | descendants | both | debug |
Files: | files | file ages | folders |
SHA1: |
9d4eb6e4750939c48aff267000bd69a7 |
User & Date: | drh 2016-08-09 01:21:16.687 |
Context
2016-08-09
| ||
11:23 | Add a debug timer to pcache1Truncate(). Change the formatting of some other messages to make them easier to read. (check-in: 7d0af4b53c user: dan tags: debug) | |
01:21 | Refocus the timer on the pager_end_transaction() routine. (check-in: 9d4eb6e475 user: drh tags: debug) | |
2016-08-04
| ||
14:08 | Add extra logging calls to this branch. (check-in: 491f1ef36e user: dan tags: debug) | |
Changes
Changes to src/malloc.c.
︙ | ︙ | |||
292 293 294 295 296 297 298 | /* ** Allocate memory. This routine is like sqlite3_malloc() except that it ** assumes the memory subsystem has already been initialized. */ void *sqlite3Malloc(u64 n){ void *p; | < < < < < | 292 293 294 295 296 297 298 299 300 301 302 303 304 305 306 307 308 309 310 311 312 313 314 315 316 317 318 319 320 | /* ** Allocate memory. This routine is like sqlite3_malloc() except that it ** assumes the memory subsystem has already been initialized. */ void *sqlite3Malloc(u64 n){ void *p; if( n==0 || n>=0x7fffff00 ){ /* A memory allocation of a number of bytes which is near the maximum ** signed integer value might cause an integer overflow inside of the ** xMalloc(). Hence we limit the maximum size to 0x7fffff00, giving ** 255 bytes of overhead. SQLite itself will never use anything near ** this amount. The only way to reach the limit is with sqlite3_malloc() */ p = 0; }else if( sqlite3GlobalConfig.bMemstat ){ sqlite3_mutex_enter(mem0.mutex); mallocWithAlarm((int)n, &p); sqlite3_mutex_leave(mem0.mutex); }else{ p = sqlite3GlobalConfig.m.xMalloc((int)n); } assert( EIGHT_BYTE_ALIGNMENT(p) ); /* IMP: R-11148-40995 */ return p; } /* ** This version of the memory allocation is for use by the application. ** First make sure the memory subsystem is initialized, then do the ** allocation. |
︙ | ︙ | |||
476 477 478 479 480 481 482 | return (sqlite3_uint64)sqlite3GlobalConfig.m.xSize(p); } /* ** Free memory previously obtained from sqlite3Malloc(). */ void sqlite3_free(void *p){ | < < < < | 471 472 473 474 475 476 477 478 479 480 481 482 483 484 485 486 487 488 489 490 491 492 493 494 495 496 | return (sqlite3_uint64)sqlite3GlobalConfig.m.xSize(p); } /* ** Free memory previously obtained from sqlite3Malloc(). */ void sqlite3_free(void *p){ if( p==0 ) return; /* IMP: R-49053-54554 */ assert( sqlite3MemdebugHasType(p, MEMTYPE_HEAP) ); assert( sqlite3MemdebugNoType(p, ~MEMTYPE_HEAP) ); if( sqlite3GlobalConfig.bMemstat ){ sqlite3_mutex_enter(mem0.mutex); sqlite3StatusAdd(SQLITE_STATUS_MEMORY_USED, -sqlite3MallocSize(p)); sqlite3StatusAdd(SQLITE_STATUS_MALLOC_COUNT, -1); sqlite3GlobalConfig.m.xFree(p); sqlite3_mutex_leave(mem0.mutex); }else{ sqlite3GlobalConfig.m.xFree(p); } } /* ** Add the size of memory allocation "p" to the count in ** *db->pnBytesFreed. */ static SQLITE_NOINLINE void measureAllocationSize(sqlite3 *db, void *p){ |
︙ | ︙ |
Changes to src/pager.c.
︙ | ︙ | |||
1903 1904 1905 1906 1907 1908 1909 1910 1911 1912 1913 1914 1915 1916 | ** 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 */ /* 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 | > | 1903 1904 1905 1906 1907 1908 1909 1910 1911 1912 1913 1914 1915 1916 1917 | ** 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 |
︙ | ︙ | |||
1969 1970 1971 1972 1973 1974 1975 1976 1977 1978 1979 1980 1981 1982 1983 1984 1985 1986 1987 1988 1989 1990 1991 1992 1993 1994 1995 1996 1997 1998 1999 2000 2001 2002 2003 2004 2005 2006 2007 2008 2009 2010 2011 2012 2013 2014 2015 2016 2017 2018 2019 2020 2021 2022 2023 2024 2025 2026 2027 2028 2029 2030 2031 2032 | ); sqlite3OsClose(pPager->jfd); if( bDelete ){ rc = sqlite3OsDelete(pPager->pVfs, pPager->zJournal, 0); } } } #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); sqlite3PcacheTruncate(pPager->pPCache, pPager->dbSize); 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); } 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; return (rc==SQLITE_OK?rc2:rc); } /* ** Execute a rollback if a transaction is active and unlock the ** database file. ** | > > > > > > > > > > > > > > > > > > > > > > > > | 1970 1971 1972 1973 1974 1975 1976 1977 1978 1979 1980 1981 1982 1983 1984 1985 1986 1987 1988 1989 1990 1991 1992 1993 1994 1995 1996 1997 1998 1999 2000 2001 2002 2003 2004 2005 2006 2007 2008 2009 2010 2011 2012 2013 2014 2015 2016 2017 2018 2019 2020 2021 2022 2023 2024 2025 2026 2027 2028 2029 2030 2031 2032 2033 2034 2035 2036 2037 2038 2039 2040 2041 2042 2043 2044 2045 2046 2047 2048 2049 2050 2051 2052 2053 2054 2055 2056 2057 | ); 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 ){ 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 %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 ** 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 %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 %d", iDebugTimer, pagerUseWal(pPager)); } return (rc==SQLITE_OK?rc2:rc); } /* ** Execute a rollback if a transaction is active and unlock the ** database file. ** |
︙ | ︙ | |||
6102 6103 6104 6105 6106 6107 6108 | int sqlite3PagerCommitPhaseOne( Pager *pPager, /* Pager object */ const char *zMaster, /* If not NULL, the master journal name */ int noSync /* True to omit the xSync on the db file */ ){ int rc = SQLITE_OK; /* Return code */ | < < | 6127 6128 6129 6130 6131 6132 6133 6134 6135 6136 6137 6138 6139 6140 | int sqlite3PagerCommitPhaseOne( Pager *pPager, /* Pager object */ const char *zMaster, /* If not NULL, the master journal name */ int noSync /* True to omit the xSync on the db file */ ){ int rc = SQLITE_OK; /* Return code */ assert( pPager->eState==PAGER_WRITER_LOCKED || pPager->eState==PAGER_WRITER_CACHEMOD || pPager->eState==PAGER_WRITER_DBMOD || pPager->eState==PAGER_ERROR ); assert( assert_pager_state(pPager) ); |
︙ | ︙ | |||
6251 6252 6253 6254 6255 6256 6257 | } } commit_phase_one_exit: if( rc==SQLITE_OK && !pagerUseWal(pPager) ){ pPager->eState = PAGER_WRITER_FINISHED; } | < < < < | 6274 6275 6276 6277 6278 6279 6280 6281 6282 6283 6284 6285 6286 6287 | } } commit_phase_one_exit: if( rc==SQLITE_OK && !pagerUseWal(pPager) ){ pPager->eState = PAGER_WRITER_FINISHED; } return rc; } /* ** When this function is called, the database file has been completely ** updated to reflect the changes made by the current transaction and |
︙ | ︙ | |||
6276 6277 6278 6279 6280 6281 6282 | ** irrevocably committed. ** ** If an error occurs, an IO error code is returned and the pager ** moves into the error state. Otherwise, SQLITE_OK is returned. */ int sqlite3PagerCommitPhaseTwo(Pager *pPager){ int rc = SQLITE_OK; /* Return code */ | < | 6295 6296 6297 6298 6299 6300 6301 6302 6303 6304 6305 6306 6307 6308 | ** irrevocably committed. ** ** If an error occurs, an IO error code is returned and the pager ** moves into the error state. Otherwise, SQLITE_OK is returned. */ int sqlite3PagerCommitPhaseTwo(Pager *pPager){ int rc = SQLITE_OK; /* Return code */ /* This routine should not be called if a prior error has occurred. ** But if (due to a coding error elsewhere in the system) it does get ** called, just return the same error code without doing anything. */ if( NEVER(pPager->errCode) ) return pPager->errCode; assert( pPager->eState==PAGER_WRITER_LOCKED |
︙ | ︙ | |||
6311 6312 6313 6314 6315 6316 6317 | assert( pPager->journalOff==JOURNAL_HDR_SZ(pPager) || !pPager->journalOff ); pPager->eState = PAGER_READER; return SQLITE_OK; } PAGERTRACE(("COMMIT %d\n", PAGERID(pPager))); rc = pager_end_transaction(pPager, pPager->setMaster, 1); | < < < < | 6329 6330 6331 6332 6333 6334 6335 6336 6337 6338 6339 6340 6341 6342 | assert( pPager->journalOff==JOURNAL_HDR_SZ(pPager) || !pPager->journalOff ); pPager->eState = PAGER_READER; return SQLITE_OK; } PAGERTRACE(("COMMIT %d\n", PAGERID(pPager))); rc = pager_end_transaction(pPager, pPager->setMaster, 1); return pager_error(pPager, rc); } /* ** If a write transaction is open, then all changes made within the ** transaction are reverted and the current write-transaction is closed. ** The pager falls back to PAGER_READER state if successful, or PAGER_ERROR |
︙ | ︙ |
Changes to src/sqliteInt.h.
︙ | ︙ | |||
3811 3812 3813 3814 3815 3816 3817 3818 3819 3820 3821 3822 3823 3824 | ** Threading interface */ #if SQLITE_MAX_WORKER_THREADS>0 int sqlite3ThreadCreate(SQLiteThread**,void*(*)(void*),void*); int sqlite3ThreadJoin(SQLiteThread*, void**); #endif #define START_DEBUG_TIMER \ sqlite3_uint64 iDebugTimerStart, iDebugTimer; \ struct timeval debug_timer_var; \ gettimeofday(&debug_timer_var, 0); \ iDebugTimerStart = 1000000*(sqlite3_uint64)debug_timer_var.tv_sec \ + debug_timer_var.tv_usec; | > | 3811 3812 3813 3814 3815 3816 3817 3818 3819 3820 3821 3822 3823 3824 3825 | ** Threading interface */ #if SQLITE_MAX_WORKER_THREADS>0 int sqlite3ThreadCreate(SQLiteThread**,void*(*)(void*),void*); int sqlite3ThreadJoin(SQLiteThread*, void**); #endif #include <sys/time.h> #define START_DEBUG_TIMER \ sqlite3_uint64 iDebugTimerStart, iDebugTimer; \ struct timeval debug_timer_var; \ gettimeofday(&debug_timer_var, 0); \ iDebugTimerStart = 1000000*(sqlite3_uint64)debug_timer_var.tv_sec \ + debug_timer_var.tv_usec; |
︙ | ︙ |
Changes to src/vdbeapi.c.
︙ | ︙ | |||
542 543 544 545 546 547 548 | /* 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 ) { | | | | 542 543 544 545 546 547 548 549 550 551 552 553 554 555 556 557 | /* 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 |
︙ | ︙ |