/ Check-in [92618492]
Login

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

Overview
Comment:Enhance the log messages emitted when a page conflict is detected.
Downloads: Tarball | ZIP archive | SQL archive
Timelines: family | ancestors | descendants | both | begin-concurrent
Files: files | file ages | folders
SHA3-256: 92618492b048867af38922825f3d094eaaa2dd919b1ed2f7372483cc53f892bf
User & Date: dan 2017-05-29 14:27:37
Wiki:begin-concurrent
Context
2017-05-29
19:23
Instead of a root page number, log the object (table or index) name if a page level locking conflict is detected. check-in: 9ad846e5 user: dan tags: begin-concurrent
14:27
Enhance the log messages emitted when a page conflict is detected. check-in: 92618492 user: dan tags: begin-concurrent
2017-05-26
18:18
Adjust the bitvec related sqlite3_log messages added by [9527089b]. check-in: a7e0e7a4 user: dan tags: begin-concurrent
Changes
Hide Diffs Side-by-Side Diffs Show Whitespace Changes Patch

Changes to src/btree.c.

  2285   2285   getAndInitPage_error:
  2286   2286     if( pCur ) pCur->iPage--;
  2287   2287     testcase( pgno==0 );
  2288   2288     assert( pgno!=0 || rc==SQLITE_CORRUPT );
  2289   2289     return rc;
  2290   2290   }
  2291   2291   
         2292  +#ifndef SQLITE_OMIT_CONCURRENT
         2293  +/* 
         2294  +** Set the value of the MemPage.pgnoRoot variable, if it exists.
         2295  +*/
         2296  +static void setMempageRoot(MemPage *pPg, u32 pgnoRoot){
         2297  +  pPg->pgnoRoot = pgnoRoot;
         2298  +}
         2299  +#else
         2300  +# define setMempageRoot(x,y)
         2301  +#endif
         2302  +
  2292   2303   /*
  2293   2304   ** Release a MemPage.  This should be called once for each prior
  2294   2305   ** call to btreeGetPage.
  2295   2306   */
  2296   2307   static void releasePageNotNull(MemPage *pPage){
  2297   2308     assert( pPage->aData );
  2298   2309     assert( pPage->pBt );
................................................................................
  5218   5229   ** This function returns SQLITE_CORRUPT if the page-header flags field of
  5219   5230   ** the new child page does not match the flags field of the parent (i.e.
  5220   5231   ** if an intkey page appears to be the parent of a non-intkey page, or
  5221   5232   ** vice-versa).
  5222   5233   */
  5223   5234   static int moveToChild(BtCursor *pCur, u32 newPgno){
  5224   5235     BtShared *pBt = pCur->pBt;
         5236  +  int rc;
  5225   5237   
  5226   5238     assert( cursorOwnsBtShared(pCur) );
  5227   5239     assert( pCur->eState==CURSOR_VALID );
  5228   5240     assert( pCur->iPage<BTCURSOR_MAX_DEPTH );
  5229   5241     assert( pCur->iPage>=0 );
  5230   5242     if( pCur->iPage>=(BTCURSOR_MAX_DEPTH-1) ){
  5231   5243       return SQLITE_CORRUPT_BKPT;
  5232   5244     }
  5233   5245     pCur->info.nSize = 0;
  5234   5246     pCur->curFlags &= ~(BTCF_ValidNKey|BTCF_ValidOvfl);
  5235   5247     pCur->aiIdx[pCur->iPage++] = pCur->ix;
  5236   5248     pCur->ix = 0;
  5237         -  return getAndInitPage(pBt, newPgno, &pCur->apPage[pCur->iPage],
         5249  +  rc = getAndInitPage(pBt, newPgno, &pCur->apPage[pCur->iPage],
  5238   5250                           pCur, pCur->curPagerFlags);
         5251  +  if( rc==SQLITE_OK ){
         5252  +    setMempageRoot(pCur->apPage[pCur->iPage], pCur->pgnoRoot);
         5253  +  }
         5254  +  return rc;
  5239   5255   }
  5240   5256   
  5241   5257   #ifdef SQLITE_DEBUG
  5242   5258   /*
  5243   5259   ** Page pParent is an internal (non-leaf) tree page. This function 
  5244   5260   ** asserts that page number iChild is the left-child if the iIdx'th
  5245   5261   ** cell in page pParent. Or, if iIdx is equal to the total number of
................................................................................
  5337   5353       assert( pCur->iPage==(-1) );
  5338   5354       rc = getAndInitPage(pCur->pBtree->pBt, pCur->pgnoRoot, &pCur->apPage[0],
  5339   5355                           0, pCur->curPagerFlags);
  5340   5356       if( rc!=SQLITE_OK ){
  5341   5357         pCur->eState = CURSOR_INVALID;
  5342   5358          return rc;
  5343   5359       }
         5360  +    setMempageRoot(pCur->apPage[0], pCur->pgnoRoot);
  5344   5361       pCur->iPage = 0;
  5345   5362       pCur->curIntKey = pCur->apPage[0]->intKey;
  5346   5363     }
  5347   5364     pRoot = pCur->apPage[0];
  5348   5365     assert( pRoot->pgno==pCur->pgnoRoot );
  5349   5366   
  5350   5367     /* If pCur->pKeyInfo is not NULL, then the caller that opened this cursor
................................................................................
  7496   7513   ** SQLITE_NOMEM.
  7497   7514   */
  7498   7515   static int balance_nonroot(
  7499   7516     MemPage *pParent,               /* Parent page of siblings being balanced */
  7500   7517     int iParentIdx,                 /* Index of "the page" in pParent */
  7501   7518     u8 *aOvflSpace,                 /* page-size bytes of space for parent ovfl */
  7502   7519     int isRoot,                     /* True if pParent is a root-page */
  7503         -  int bBulk                       /* True if this call is part of a bulk load */
         7520  +  int bBulk,                      /* True if this call is part of a bulk load */
         7521  +  Pgno pgnoRoot                   /* Root page of b-tree being balanced */
  7504   7522   ){
  7505   7523     BtShared *pBt;               /* The whole database */
  7506   7524     int nMaxCells = 0;           /* Allocated size of apCell, szCell, aFrom. */
  7507   7525     int nNew = 0;                /* Number of pages in apNew[] */
  7508   7526     int nOld;                    /* Number of pages in apOld[] */
  7509   7527     int i, j, k;                 /* Loop counters */
  7510   7528     int nxDiv;                   /* Next divider slot in pParent->aCell[] */
................................................................................
  7588   7606     pgno = get4byte(pRight);
  7589   7607     while( 1 ){
  7590   7608       rc = getAndInitPage(pBt, pgno, &apOld[i], 0, 0);
  7591   7609       if( rc ){
  7592   7610         memset(apOld, 0, (i+1)*sizeof(MemPage*));
  7593   7611         goto balance_cleanup;
  7594   7612       }
         7613  +    setMempageRoot(apOld[i], pgnoRoot);
         7614  +
  7595   7615       nMaxCells += 1+apOld[i]->nCell+apOld[i]->nOverflow;
  7596   7616       if( (i--)==0 ) break;
  7597   7617   
  7598   7618       if( pParent->nOverflow && i+nxDiv==pParent->aiOvfl[0] ){
  7599   7619         apDiv[i] = pParent->apOvfl[0];
  7600   7620         pgno = get4byte(apDiv[i]);
  7601   7621         szNew[i] = pParent->xCellSize(pParent, apDiv[i]);
................................................................................
  8396   8416             ** has completed, it is safe to release the pSpace buffer used by
  8397   8417             ** the previous call, as the overflow cell data will have been 
  8398   8418             ** copied either into the body of a database page or into the new
  8399   8419             ** pSpace buffer passed to the latter call to balance_nonroot().
  8400   8420             */
  8401   8421             u8 *pSpace = sqlite3PageMalloc(pCur->pBt->pageSize);
  8402   8422             rc = balance_nonroot(pParent, iIdx, pSpace, iPage==1,
  8403         -                               pCur->hints&BTREE_BULKLOAD);
         8423  +                               pCur->hints&BTREE_BULKLOAD, pCur->pgnoRoot);
  8404   8424             if( pFree ){
  8405   8425               /* If pFree is not NULL, it points to the pSpace buffer used 
  8406   8426               ** by a previous call to balance_nonroot(). Its contents are
  8407   8427               ** now stored either on real database pages or within the 
  8408   8428               ** new pSpace buffer, so it may be safely freed here. */
  8409   8429               sqlite3PageFree(pFree);
  8410   8430             }
................................................................................
  8994   9014   ** Erase the given database page and all its children.  Return
  8995   9015   ** the page to the freelist.
  8996   9016   */
  8997   9017   static int clearDatabasePage(
  8998   9018     BtShared *pBt,           /* The BTree that contains the table */
  8999   9019     Pgno pgno,               /* Page number to clear */
  9000   9020     int freePageFlag,        /* Deallocate page if true */
  9001         -  int *pnChange            /* Add number of Cells freed to this counter */
         9021  +  int *pnChange,           /* Add number of Cells freed to this counter */
         9022  +  Pgno pgnoRoot
  9002   9023   ){
  9003   9024     MemPage *pPage;
  9004   9025     int rc;
  9005   9026     unsigned char *pCell;
  9006   9027     int i;
  9007   9028     int hdr;
  9008   9029     CellInfo info;
................................................................................
  9009   9030   
  9010   9031     assert( sqlite3_mutex_held(pBt->mutex) );
  9011   9032     if( pgno>btreePagecount(pBt) ){
  9012   9033       return SQLITE_CORRUPT_BKPT;
  9013   9034     }
  9014   9035     rc = getAndInitPage(pBt, pgno, &pPage, 0, 0);
  9015   9036     if( rc ) return rc;
         9037  +  setMempageRoot(pPage, pgnoRoot);
  9016   9038     if( pPage->bBusy ){
  9017   9039       rc = SQLITE_CORRUPT_BKPT;
  9018   9040       goto cleardatabasepage_out;
  9019   9041     }
  9020   9042     pPage->bBusy = 1;
  9021   9043     hdr = pPage->hdrOffset;
  9022   9044     for(i=0; i<pPage->nCell; i++){
  9023   9045       pCell = findCell(pPage, i);
  9024   9046       if( !pPage->leaf ){
  9025         -      rc = clearDatabasePage(pBt, get4byte(pCell), 1, pnChange);
         9047  +      rc = clearDatabasePage(pBt, get4byte(pCell), 1, pnChange, pgnoRoot);
  9026   9048         if( rc ) goto cleardatabasepage_out;
  9027   9049       }
  9028   9050       rc = clearCell(pPage, pCell, &info);
  9029   9051       if( rc ) goto cleardatabasepage_out;
  9030   9052     }
  9031   9053     if( !pPage->leaf ){
  9032         -    rc = clearDatabasePage(pBt, get4byte(&pPage->aData[hdr+8]), 1, pnChange);
         9054  +    rc = clearDatabasePage(
         9055  +        pBt, get4byte(&pPage->aData[hdr+8]), 1, pnChange, pgnoRoot
         9056  +    );
  9033   9057       if( rc ) goto cleardatabasepage_out;
  9034   9058     }else if( pnChange ){
  9035   9059       assert( pPage->intKey || CORRUPT_DB );
  9036   9060       testcase( !pPage->intKey );
  9037   9061       *pnChange += pPage->nCell;
  9038   9062     }
  9039   9063     if( freePageFlag ){
................................................................................
  9070   9094     rc = saveAllCursors(pBt, (Pgno)iTable, 0);
  9071   9095   
  9072   9096     if( SQLITE_OK==rc ){
  9073   9097       /* Invalidate all incrblob cursors open on table iTable (assuming iTable
  9074   9098       ** is the root of a table b-tree - if it is not, the following call is
  9075   9099       ** a no-op).  */
  9076   9100       invalidateIncrblobCursors(p, (Pgno)iTable, 0, 1);
  9077         -    rc = clearDatabasePage(pBt, (Pgno)iTable, 0, pnChange);
         9101  +    rc = clearDatabasePage(pBt, (Pgno)iTable, 0, pnChange, (Pgno)iTable);
  9078   9102     }
  9079   9103     sqlite3BtreeLeave(p);
  9080   9104     return rc;
  9081   9105   }
  9082   9106   
  9083   9107   /*
  9084   9108   ** Delete all information from the single table that pCur is open on.

Changes to src/btreeInt.h.

   297    297     u8 *aData;           /* Pointer to disk image of the page data */
   298    298     u8 *aDataEnd;        /* One byte past the end of usable data */
   299    299     u8 *aCellIdx;        /* The cell index area */
   300    300     u8 *aDataOfst;       /* Same as aData for leaves.  aData+4 for interior */
   301    301     DbPage *pDbPage;     /* Pager page handle */
   302    302     u16 (*xCellSize)(MemPage*,u8*);             /* cellSizePtr method */
   303    303     void (*xParseCell)(MemPage*,u8*,CellInfo*); /* btreeParseCell method */
          304  +#ifndef SQLITE_OMIT_CONCURRENT
          305  +  u32 pgnoRoot;        /* Root page of b-tree that this page belongs to */
          306  +#endif
   304    307   };
   305    308   
   306    309   /*
   307    310   ** A linked list of the following structures is stored at BtShared.pLock.
   308    311   ** Locks are added (or upgraded from READ_LOCK to WRITE_LOCK) when a cursor 
   309    312   ** is opened on the table with root page BtShared.iTable. Locks are removed
   310    313   ** from this list when a transaction is committed or rolled back, or when

Changes to src/wal.c.

   239    239   ** When a rollback occurs, the value of K is decreased. Hash table entries
   240    240   ** that correspond to frames greater than the new K value are removed
   241    241   ** from the hash table at this point.
   242    242   */
   243    243   #ifndef SQLITE_OMIT_WAL
   244    244   
   245    245   #include "wal.h"
          246  +#include "btreeInt.h"
   246    247   
   247    248   /*
   248    249   ** Trace output macros
   249    250   */
   250    251   #if defined(SQLITE_TEST) && defined(SQLITE_DEBUG)
   251    252   int sqlite3WalTrace = 0;
   252    253   # define WALTRACE(X)  if(sqlite3WalTrace) sqlite3DebugPrintf X
................................................................................
  2912   2913                 sz = (sz&0xfe00) + ((sz&0x0001)<<16);
  2913   2914                 iOffset = walFrameOffset(i+iZero, sz) + WAL_FRAME_HDRSIZE + 40;
  2914   2915                 rc = sqlite3OsRead(pWal->pWalFd, aNew, sizeof(aNew), iOffset);
  2915   2916                 if( rc==SQLITE_OK && memcmp(aOld, aNew, sizeof(aNew)) ){
  2916   2917                   rc = SQLITE_BUSY_SNAPSHOT;
  2917   2918                 }
  2918   2919               }else if( sqlite3BitvecTestNotNull(pAllRead, aPgno[i]) ){
         2920  +              PgHdr *pPg = 0;
         2921  +              rc = sqlite3PagerGet(pPage1->pPager, aPgno[i], &pPg, 0);
         2922  +              if( rc==SQLITE_OK ){
         2923  +                Pgno pgnoRoot = 0;
         2924  +                int bWrite = -1;
         2925  +                if( pPg ){
         2926  +                  pgnoRoot = ((MemPage*)sqlite3PagerGetExtra(pPg))->pgnoRoot;
         2927  +                  bWrite = sqlite3PagerIswriteable(pPg);
         2928  +                  sqlite3PagerUnref(pPg);
         2929  +                }
  2919   2930                 sqlite3_log(SQLITE_OK,
  2920         -                  "cannot commit CONCURRENT transaction (conflict at page %d)",
  2921         -                  (int)aPgno[i]
         2931  +                  "cannot commit CONCURRENT transaction "
         2932  +                  "- conflict at page %d "
         2933  +                  "(%s page; part of b-tree with root page %d)",
         2934  +                  (int)aPgno[i], 
         2935  +                  (bWrite==0?"read-only":(bWrite>0?"read/write":"unknown")),
         2936  +                  (int)pgnoRoot
  2922   2937                 );
  2923   2938                 rc = SQLITE_BUSY_SNAPSHOT;
         2939  +              }
  2924   2940               }else if( (pPg = sqlite3PagerLookup(pPager, aPgno[i])) ){
  2925   2941                 /* Page aPgno[i], which is present in the pager cache, has been
  2926   2942                 ** modified since the current CONCURRENT transaction was started.
  2927   2943                 ** However it was not read by the current transaction, so is not
  2928   2944                 ** a conflict. There are two possibilities: (a) the page was
  2929   2945                 ** allocated at the of the file by the current transaction or 
  2930   2946                 ** (b) was present in the cache at the start of the transaction.

Added test/concurrent5.test.

            1  +# 2017 May 26
            2  +#
            3  +# The author disclaims copyright to this source code.  In place of
            4  +# a legal notice, here is a blessing:
            5  +#
            6  +#    May you do good and not evil.
            7  +#    May you find forgiveness for yourself and forgive others.
            8  +#    May you share freely, never taking more than you give.
            9  +#
           10  +#***********************************************************************
           11  +#
           12  +#
           13  +
           14  +set testdir [file dirname $argv0]
           15  +source $testdir/tester.tcl
           16  +source $testdir/lock_common.tcl
           17  +source $testdir/wal_common.tcl
           18  +set ::testprefix concurrent5
           19  +
           20  +ifcapable !concurrent {
           21  +  finish_test
           22  +  return
           23  +}
           24  +
           25  +db close
           26  +sqlite3_shutdown
           27  +test_sqlite3_log [list lappend ::log]
           28  +set ::log [list]
           29  +
           30  +sqlite3 db test.db
           31  +
           32  +proc do_test_conflict_msg {tn msg} {
           33  +  set msg "cannot commit CONCURRENT transaction - [string trim $msg]"
           34  +  uplevel [list do_test $tn {lindex $::log end} $msg]
           35  +}
           36  +
           37  +do_execsql_test 1.0 {
           38  +  PRAGMA journal_mode = wal;
           39  +  CREATE TABLE t1(x, y);
           40  +  CREATE TABLE t2(c);
           41  +  WITH s(i) AS (SELECT 1 UNION ALL SELECT i+1 FROM s WHERE i<100)
           42  +  INSERT INTO t1 SELECT randomblob(400), randomblob(400) FROM s;
           43  +} {wal}
           44  +
           45  +sqlite3 db2 test.db
           46  +
           47  +do_test 1.1.1 {
           48  +  set ::log [list]
           49  +  db2 eval {
           50  +    BEGIN CONCURRENT;
           51  +      SELECT count(*) FROM t1;
           52  +      INSERT INTO t2 VALUES(10);
           53  +  }
           54  +
           55  +  db eval {
           56  +    INSERT INTO t1 VALUES(randomblob(200), randomblob(200));
           57  +  }
           58  +
           59  +  catchsql COMMIT db2
           60  +} {1 {database is locked}}
           61  +do_test_conflict_msg 1.1.2 {
           62  +  conflict at page 2 (read-only page; part of b-tree with root page 2)
           63  +}
           64  +
           65  +do_test 1.2.1 {
           66  +  set ::log [list]
           67  +  db2 eval {
           68  +    ROLLBACK;
           69  +    BEGIN CONCURRENT;
           70  +      INSERT INTO t1 VALUES(11, 12);
           71  +  }
           72  +
           73  +  db eval {
           74  +    INSERT INTO t1 VALUES(12, 11);
           75  +  }
           76  +
           77  +  catchsql COMMIT db2
           78  +} {1 {database is locked}}
           79  +
           80  +do_test_conflict_msg 1.2.2 {
           81  +  conflict at page 105 (read/write page; part of b-tree with root page 2)
           82  +}
           83  +
           84  +do_test 1.3.1 {
           85  +  set ::log [list]
           86  +  db2 eval {
           87  +    ROLLBACK;
           88  +    BEGIN CONCURRENT;
           89  +      INSERT INTO t2 VALUES('x');
           90  +  }
           91  +
           92  +  db eval {
           93  +    INSERT INTO t2 VALUES('y');
           94  +  }
           95  +
           96  +  catchsql COMMIT db2
           97  +} {1 {database is locked}}
           98  +
           99  +do_test_conflict_msg 1.3.2 {
          100  +  conflict at page 3 (read/write page; part of b-tree with root page 3)
          101  +}
          102  +
          103  +db close
          104  +db2 close
          105  +sqlite3_shutdown
          106  +test_sqlite3_log 
          107  +sqlite3_initialize
          108  +finish_test
          109  +