Merge lp:~pbeaman/akiban-persistit/fix_1017957_stress_tests_corruption into lp:akiban-persistit

[Peter Beaman]

Fix bug 1017957 - B-Tree corruption occasionally detected in stress tests.

This branch contains a new test, Bug1018526Test, that demonstrates the bug mechanism we thing is responsible for the failures.

Also included: incremental corrections in IntegrityCheck discovered when it failed to report the corrupt garbage chain correctly.

[lp:~pbeaman/akiban-persistit/fix_1017957_stress_tests_corruption]

330. By Peter Beaman on 2012-06-29

Version fixes corruption bug

331. By Peter Beaman on 2012-06-29

Cleanup

332. By Peter Beaman on 2012-06-29

Cleanup

333. By Peter Beaman on 2012-06-29

Cleanup

[Peter Beaman (pbeaman)]

Turns out there were two problems in the Exchange class that contributed to this bug, making diagnosis somewhat difficult.

This branch fixes both:

(a) There is no longer a concept of "deferred reindexing" in raw_removeKeyRangeInternal. That was a relic of the fix-length write ahead journal of the past. One of the bug mechanisms used that code path to reinsert a page pointer to a page that had changed due to releasing all locks.

(b) there was a code path that failed to bump the tree generation counter upon completing a structure delete.

To support diagnosing this bug, I added better formatting and a new, useful CLI command that walks a pointer chain and displays selected information about a page. Some of these changes are located in Buffer#toStringDetail which is now simpler and more useful.

Also, while diagnosing this bug I came across Exceptions while reporting garbage chain structure errors in IntegrityCheck. Fixed that problem and wrote a unit test to verify it.

And of course the Eclipse random line-length formatter made its usual contribution...

[Nathan Williams (nwilliams)]

The fix looks reasonable and seems to match the explanation.

I only skimmed the Buffer toString or IntegrityCheck changes but they look fine.

Please change the first sentence of the merge prop to something descriptive (it is used for the commit message) and feel free to Approve.

review: Approve

=== modified file 'src/main/java/com/persistit/Buffer.java'
--- src/main/java/com/persistit/Buffer.java	2012-06-25 15:41:14 +0000
+++ src/main/java/com/persistit/Buffer.java	2012-06-29 21:06:19 +0000
@@ -28,7 +28,6 @@
 
 import java.nio.ByteBuffer;
 import java.util.ArrayList;
-import java.util.BitSet;
 import java.util.List;
 import java.util.Set;
 
@@ -269,7 +268,7 @@
     public final static int MAX_KEY_RATIO = 16;
 
     private final static int BINARY_SEARCH_THRESHOLD = 6;
-    
+
     abstract static class VerifyVisitor {
 
         protected void visitPage(long timestamp, Volume volume, long page, int type, int bufferSize, int keyBlockStart,
@@ -330,7 +329,7 @@
      * _byteBuffer.
      */
     private byte[] _bytes;
-    
+
     /**
      * FastIndex structure used for rapid page searching
      */
@@ -2318,6 +2317,7 @@
             assertVerify();
             rightSibling.assertVerify();
         }
+
         return whereInserted;
     }
 
@@ -2594,6 +2594,7 @@
                 buffer.assertVerify();
             }
         }
+
         return result;
     }
 
@@ -2815,7 +2816,7 @@
     }
 
     synchronized void invalidateFastIndex() {
-            _fastIndex.invalidate();
+        _fastIndex.invalidate();
     }
 
     synchronized FastIndex getFastIndex() {
@@ -3775,7 +3776,7 @@
 
     public String toString() {
         if (_toStringDebug) {
-            return toStringDetail(-1);
+            return toStringDetail();
         }
         return String.format("Page %,d in volume %s at index %,d timestamp=%,d status=%s type=%s", _page, _vol,
                 _poolIndex, _timestamp, getStatusDisplayString(), getPageTypeName());
@@ -3785,7 +3786,7 @@
      * @return a human-readable inventory of the contents of this buffer
      */
     public String toStringDetail() {
-        return toStringDetail(-1);
+        return toStringDetail(-1, 42, 42, 0, true);
     }
 
     /**
@@ -3795,7 +3796,8 @@
      *         the one that points to findPointer. This provides a way to
      *         quickly find pointer paths in pages.
      */
-    String toStringDetail(final long findPointer) {
+    String toStringDetail(final long findPointer, final int maxKeyDisplayLength, final int maxValueDisplayLength,
+            final int contextLines, final boolean all) {
         final StringBuilder sb = new StringBuilder(String.format(
                 "Page %,d in volume %s at index @%,d status %s type %s", _page, _vol, _poolIndex,
                 getStatusDisplayString(), getPageTypeName()));
@@ -3805,52 +3807,53 @@
             sb.append(String.format("\n  type=%,d  alloc=%,d  slack=%,d  " + "keyBlockStart=%,d  keyBlockEnd=%,d "
                     + "timestamp=%,d generation=%,d right=%,d hash=%,d", _type, _alloc, _slack, KEY_BLOCK_START,
                     _keyBlockEnd, getTimestamp(), getGeneration(), getRightSibling(), _pool.hashIndex(_vol, _page)));
-
             try {
                 final Key key = new Key(_persistit);
                 final Value value = new Value(_persistit);
                 final RecordInfo[] records = getRecords();
-                BitSet bits = new BitSet();
+                int foundPointerRecord = -1;
                 if (isIndexPage() && findPointer >= 0) {
                     for (int index = 0; index < records.length; index++) {
                         if (records[index].getPointerValue() == findPointer) {
-                            bits.set(index);
+                            foundPointerRecord = index;
                         }
                     }
                 }
-                boolean elisionMarked = false;
+                boolean elision = false;
                 for (int index = 0; index < records.length; index++) {
                     RecordInfo r = records[index];
                     r.getKeyState().copyTo(key);
-                    if (isDataPage()) {
-                        r.getValueState().copyTo(value);
-                        sb.append(String.format("\n   %5d: db=%3d ebc=%3d tb=%,5d [%,d]%s=[%,d]%s", r.getKbOffset(), r
-                                .getDb(), r.getEbc(), r.getTbOffset(), r.getKLength(), key, r.getValueState()
-                                .getEncodedBytes().length, abridge(value)));
+                    String mark = " ";
+                    boolean selected = all | index < contextLines || index >= records.length - contextLines;
+                    if (foundPointerRecord >= 0) {
+                        selected |= (index >= foundPointerRecord - contextLines)
+                                && (index <= foundPointerRecord + contextLines);
+                        if (index == foundPointerRecord) {
+                            mark = "*";
+                        }
+                    }
+
+                    if (selected) {
+                        if (elision) {
+                            sb.append(String.format("\n     ..."));
+                            elision = false;
+                        }
+                        if (isDataPage()) {
+                            r.getValueState().copyTo(value);
+                            sb.append(String.format("\n%s   %5d: db=%3d ebc=%3d tb=%,5d [%,d]%s=[%,d]%s", mark, r
+                                    .getKbOffset(), r.getDb(), r.getEbc(), r.getTbOffset(), r.getKLength(), Util
+                                    .abridge(key.toString(), maxKeyDisplayLength),
+                                    r.getValueState().getEncodedBytes().length, Util.abridge(value.toString(),
+                                            maxValueDisplayLength)));
+                        } else {
+                            sb.append(String.format("\n%s  %5d: db=%3d ebc=%3d tb=%,5d [%,d]%s->%,d", mark, r
+                                    .getKbOffset(), r.getDb(), r.getEbc(), r.getTbOffset(), r.getKLength(), Util
+                                    .abridge(key.toString(), maxKeyDisplayLength), r.getPointerValue()));
+                        }
                     } else {
-                        boolean selected = true;
-                        if (findPointer >= 0) {
-                            if (index > 2 && index < records.length - 2) {
-                                boolean bit = false;
-                                for (int p = index - 2; p < index + 3; p++) {
-                                    if (bits.get(p)) {
-                                        bit = true;
-                                    }
-                                }
-                                selected &= bit;
-                            }
-                        }
-                        if (selected) {
-                            sb.append(String.format("\n  %5d: db=%3d ebc=%3d tb=%,5d [%,d]%s->%,d", r.getKbOffset(), r
-                                    .getDb(), r.getEbc(), r.getTbOffset(), r.getKLength(), key, r.getPointerValue()));
-                            elisionMarked = false;
-                        } else {
-                            if (!elisionMarked) {
-                                sb.append(String.format("\n  ..."));
-                                elisionMarked = true;
-                            }
-                        }
+                        elision = true;
                     }
+
                 }
             } catch (Exception e) {
                 sb.append(" - " + e);
@@ -3875,15 +3878,6 @@
         return sb.toString();
     }
 
-    private String abridge(final Value value) {
-        String s = value.toString();
-        if (s.length() > 120) {
-            return s.substring(0, 120) + "...";
-        } else {
-            return s;
-        }
-    }
-
     String foundAtString(int p) {
         StringBuilder sb = new StringBuilder("<");
         sb.append(p & P_MASK);
@@ -4316,4 +4310,5 @@
             ++_mvvCount;
         }
     }
+
 }
 
=== modified file 'src/main/java/com/persistit/BufferPool.java'
--- src/main/java/com/persistit/BufferPool.java	2012-06-14 17:55:08 +0000
+++ src/main/java/com/persistit/BufferPool.java	2012-06-29 21:06:19 +0000
@@ -1054,6 +1054,7 @@
     }
 
     int selectDirtyBuffers(final int[] priorities, final BufferHolder[] holders) throws PersistitException {
+        Debug.suspend();
         int count = 0;
         final int clock = _clock.get();
 
 
=== modified file 'src/main/java/com/persistit/CLI.java'
--- src/main/java/com/persistit/CLI.java	2012-06-14 20:15:48 +0000
+++ src/main/java/com/persistit/CLI.java	2012-06-29 21:06:19 +0000
@@ -1021,6 +1021,9 @@
             final @Arg("pageSize|int:16384:1024:16384|Buffer pool index") int pageSize,
             final @Arg("level|int:0:0:30|Tree level") int level, final @Arg("key|string|Key") String keyString,
             final @Arg("find|long:-1:0:99999999999999999|Optional page pointer to find") long findPointer,
+            final @Arg("maxkey|int:42:4:10000|Maximum displayed key length") int maxkey,
+            final @Arg("maxvalue|int:42:4:100000|Maximum displayed value length") int maxvalue,
+            final @Arg("context|int:3:0:100000|Context lines") int context,
             final @Arg("_flag|a|All lines") boolean allLines, final @Arg("_flag|s|Summary only") boolean summary)
             throws Exception {
 
@@ -1084,21 +1087,8 @@
                 if (summary) {
                     postMessage(buffer.toString(), LOG_NORMAL);
                     return;
-                }
-                String detail = buffer.toStringDetail(findPointer);
-                if (allLines) {
-                    postMessage(detail, LOG_NORMAL);
-                    return;
                 } else {
-                    int p = -1;
-                    for (int i = 0; i < 20; i++) {
-                        p = detail.indexOf('\n', p + 1);
-                        if (p == -1) {
-                            p = detail.length();
-                            break;
-                        }
-                    }
-                    postMessage(detail.substring(0, p), LOG_NORMAL);
+                    postMessage(buffer.toStringDetail(findPointer, maxkey, maxvalue, context, allLines), LOG_NORMAL);
                     return;
                 }
             }
@@ -1108,6 +1098,44 @@
             }
         };
     }
+    
+    @Cmd("pviewchain")
+    Task pviewchain(final @Arg("page|long:0:0:99999999999999999|Starting page address") long pageAddress,
+            final @Arg("find|long:-1:0:99999999999999999|Optional page pointer to find") long findPointer,
+            final @Arg("count|int:32:1:1000000|Maximum number of pages to display") long maxcount,
+            final @Arg("maxkey|int:42:4:10000|Maximum displayed key length") int maxkey,
+            final @Arg("maxvalue|int:42:4:100000|Maximum displayed value length") int maxvalue,
+            final @Arg("context|int:3:0:100000|Context lines") int context,
+            final @Arg("_flag|a|All lines") boolean allLines, final @Arg("_flag|s|Summary only") boolean summary) {
+        
+        return new Task() {
+
+            @Override
+            protected void runTask() throws Exception {
+                long currentPage = pageAddress;
+                int count = 0;
+                while (currentPage > 0 && count++ < maxcount) {
+                    if (_currentVolume == null) {
+                        postMessage("Select a volume", LOG_NORMAL);
+                        return;
+                    }
+                    final Buffer buffer = _currentVolume.getPool().getBufferCopy(_currentVolume, currentPage);
+                    if (summary) {
+                        postMessage(buffer.toString(), LOG_NORMAL);
+                    } else {
+                        postMessage(buffer.toStringDetail(findPointer, maxkey, maxvalue, context, allLines), LOG_NORMAL);
+                    }
+                    currentPage = buffer.getRightSibling();
+                }    
+            }
+
+            @Override
+            public String getStatus() {
+                return "";
+            }
+            
+        };   
+    }
 
     @Cmd("jquery")
     Task jquery(final @Arg("page|long:-1|Page address for PageNode to look up") long pageAddress,
 
=== modified file 'src/main/java/com/persistit/Exchange.java'
--- src/main/java/com/persistit/Exchange.java	2012-06-18 16:35:52 +0000
+++ src/main/java/com/persistit/Exchange.java	2012-06-29 21:06:19 +0000
@@ -38,7 +38,7 @@
 import static com.persistit.Key.LTEQ;
 import static com.persistit.Key.RIGHT_GUARD_KEY;
 import static com.persistit.Key.maxStorableKeySize;
-import static com.persistit.util.SequencerConstants.WRITE_WRITE_STORE_A;
+import static com.persistit.util.SequencerConstants.*;
 import static com.persistit.util.ThreadSequencer.sequence;
 
 import java.util.ArrayList;
@@ -526,8 +526,7 @@
         int _flags;
         long _deallocLeftPage;
         long _deallocRightPage;
-        long _deferredReindexPage;
-        long _deferredReindexChangeCount;
+
 
         private LevelCache(int level) {
             _level = level;
@@ -1330,7 +1329,8 @@
 
         final int maxSimpleValueSize = maxValueSize(key.getEncodedSize());
         final Value spareValue = _persistit.getThreadLocalValue();
-        assert !(doMVCC & value == spareValue || doFetch && value == _spareValue): "storeInternal may be use the supplied Value: " + value;
+        assert !(doMVCC & value == spareValue || doFetch && value == _spareValue) : "storeInternal may be use the supplied Value: "
+                + value;
 
         //
         // First insert the record in the data page
@@ -1356,7 +1356,7 @@
             // This method may delay significantly for I/O and must
             // be called when there are no other claimed resources.
             //
-            newLongRecordPointer = getLongRecordHelper().storeLongRecord(value,  _transaction.isActive());
+            newLongRecordPointer = getLongRecordHelper().storeLongRecord(value, _transaction.isActive());
         }
 
         if (!_ignoreTransactions && ((options & StoreOptions.DONT_JOURNAL) == 0)) {
@@ -1408,7 +1408,7 @@
                         if (!treeClaimAcquired || !_treeHolder.upgradeClaim()) {
                             treeClaimRequired = true;
                             treeWriterClaimRequired = true;
-                            throw new RetryException();
+                            throw RetryException.SINGLE;
                         }
 
                         Debug.$assert0.t(valueToStore.getPointerValue() > 0);
@@ -1460,9 +1460,8 @@
                             }
                             /*
                              * If it was a long MVV we saved it into the
-                             * variable above. Otherwise it is a
-                             * primordial value that we can't get rid
-                             * of.
+                             * variable above. Otherwise it is a primordial
+                             * value that we can't get rid of.
                              */
                             oldLongRecordPointer = 0;
 
@@ -1521,7 +1520,8 @@
                             spareValue.setEncodedSize(storedLength);
 
                             if (spareValue.getEncodedSize() > maxSimpleValueSize) {
-                                newLongRecordPointerMVV = getLongRecordHelper().storeLongRecord(spareValue, _transaction.isActive());
+                                newLongRecordPointerMVV = getLongRecordHelper().storeLongRecord(spareValue,
+                                        _transaction.isActive());
                             }
                         }
                     }
@@ -1797,13 +1797,15 @@
                 // level cache for this level will become
                 // (appropriately) invalid.
                 //
+                
+                
                 int at = buffer.split(rightSibling, key, valueWriter, foundAt, _spareKey1, sequence, _splitPolicy);
                 if (at < 0) {
                     lc.updateInsert(rightSibling, key, -at);
                 } else {
                     lc.updateInsert(buffer, key, at);
                 }
-
+                
                 long oldRightSibling = buffer.getRightSibling();
                 long newRightSibling = rightSibling.getPageAddress();
 
@@ -2148,7 +2150,8 @@
                         if (matches) {
                             index = _key.nextElementIndex(parentIndex);
                             if (index > 0) {
-                                boolean isVisibleMatch = fetchFromBufferInternal(buffer, outValue, foundAt, minimumBytes);
+                                boolean isVisibleMatch = fetchFromBufferInternal(buffer, outValue, foundAt,
+                                        minimumBytes);
                                 //
                                 // In any case (matching sibling, child or
                                 // niece/nephew) we need to ignore this
@@ -2736,7 +2739,8 @@
      *             As thrown from any internal method.
      * @return <code>true</code> if the value was visible.
      */
-    private boolean fetchFromBufferInternal(Buffer buffer, Value value, int foundAt, int minimumBytes) throws PersistitException {
+    private boolean fetchFromBufferInternal(Buffer buffer, Value value, int foundAt, int minimumBytes)
+            throws PersistitException {
         buffer.fetch(foundAt, value);
         return fetchFromValueInternal(value, minimumBytes, buffer);
     }
@@ -2744,20 +2748,21 @@
     /**
      * Helper for finalizing the value to return from a, potentially, MVV
      * contained in the given Value.
-     *
+     * 
      * @param value
      *            Value to finalize.
      * @param minimumBytes
      *            Minimum amount of LONG_RECORD to fetch. If &lt;0, the
      *            <code>value</code> will contain just the descriptor portion.
      * @param bufferForPruning
-     *            If not <code>null</code> and <code>Value</code> did contain
-     *            an MVV, call {@link Buffer#enqueuePruningAction(int)}.
+     *            If not <code>null</code> and <code>Value</code> did contain an
+     *            MVV, call {@link Buffer#enqueuePruningAction(int)}.
      * @throws PersistitException
      *             As thrown from any internal method.
      * @return <code>true</code> if the value was visible.
      */
-    private boolean fetchFromValueInternal(Value value, int minimumBytes, Buffer bufferForPruning) throws PersistitException {
+    private boolean fetchFromValueInternal(Value value, int minimumBytes, Buffer bufferForPruning)
+            throws PersistitException {
         boolean visible = true;
         /*
          * We must fetch the full LONG_RECORD, if needed, while buffer is
@@ -3042,7 +3047,7 @@
 
     /**
      * Removes all records with keys falling between <code>key1</code> and
-     * </code>key2</code>, lefty-inclusive. Validity checks and Key value
+     * </code>key2</code>, left-inclusive. Validity checks and Key value
      * adjustments have been done by caller - this method does the work.
      * 
      * @param key1
@@ -3145,7 +3150,6 @@
         boolean result = false;
 
         boolean deallocationRequired = true; // assume until proven false
-        boolean deferredReindexRequired = false;
         boolean tryQuickDelete = true;
 
         if (!_ignoreTransactions) {
@@ -3227,9 +3231,6 @@
                                     + " failed to get writer claim on " + _tree);
                         }
                         treeClaimAcquired = true;
-                        _tree.bumpGeneration();
-                        // Because we actually haven't changed anything yet.
-                        _cachedTreeGeneration++;
                     }
                     //
                     // Need to redo this check now that we have a
@@ -3265,12 +3266,6 @@
                                 lc._rightBuffer = buffer;
                                 lc._rightFoundAt = foundAt2;
                             } else {
-                                //
-                                // Since we are spanning pages we need an
-                                // exclusive claim on the tree to prevent
-                                // an insertion from propagating upward through
-                                // the deletion range.
-                                //
                                 pageAddr2 = buffer.getRightSibling();
                                 samePage = false;
                             }
@@ -3358,11 +3353,13 @@
                             _volume.getStructure().harvestLongRecords(buffer1, foundAt1, Integer.MAX_VALUE);
                             _volume.getStructure().harvestLongRecords(buffer2, 0, foundAt2);
 
+                            Debug.$assert0.t(_tree.isMine() && buffer1.isMine() && buffer2.isMine());
                             boolean rebalanced = buffer1.join(buffer2, foundAt1, foundAt2, _spareKey1, _spareKey2,
                                     _joinPolicy);
                             if (buffer1.isDataPage()) {
                                 _tree.bumpChangeCount();
                             }
+                            
                             buffer1.setDirtyAtTimestamp(timestamp);
                             buffer2.setDirtyAtTimestamp(timestamp);
 
@@ -3419,9 +3416,11 @@
                                     }
                                 }
                                 if (needsReindex) {
-                                    lc._deferredReindexPage = buffer2.getPageAddress();
-                                    lc._deferredReindexChangeCount = buffer2.getGeneration();
-                                    deferredReindexRequired = true;
+                                    _spareKey1.copyTo(_spareKey2);
+                                    _value.setPointerValue(buffer2.getPageAddress());
+                                    _value.setPointerPageType(buffer2.getPageType());
+
+                                    storeInternal(_spareKey2, _value, level + 1, StoreOptions.NONE);
                                     needsReindex = false;
                                 }
                             }
@@ -3449,7 +3448,7 @@
                     }
                     break;
                 } catch (RetryException re) {
-                    // handled below
+                    // handled below by releasing claims and retrying
                 } finally {
                     //
                     // Release all buffers.
@@ -3459,10 +3458,17 @@
                     }
 
                     if (treeClaimAcquired) {
+                        if (treeWriterClaimRequired) {
+                            _tree.bumpGeneration();
+                        }
                         _treeHolder.release();
                         treeClaimAcquired = false;
                     }
                 }
+                /*
+                 * Having released all prior claims, now acquire an exclusive
+                 * claim on the Tree.
+                 */
                 if (treeWriterClaimRequired) {
                     if (!_treeHolder.claim(true)) {
                         Debug.$assert0.t(false);
@@ -3490,51 +3496,11 @@
                 deallocationRequired = false;
                 break;
             }
-            while (deferredReindexRequired) {
-                Buffer buffer = null;
-                try {
-                    for (int level = _cacheDepth; --level >= 0;) {
-                        LevelCache lc = _levelCache[level];
-                        if (lc._deferredReindexPage != 0) {
-                            if (!treeClaimAcquired) {
-                                if (!_treeHolder.claim(treeWriterClaimRequired)) {
-                                    Debug.$assert0.t(false);
-                                    throw new InUseException("Thread " + Thread.currentThread().getName()
-                                            + " failed to get writer claim on " + _tree);
-                                }
-                                treeClaimAcquired = true;
-                            }
-
-                            long deferredPage = lc._deferredReindexPage;
-                            buffer = _pool.get(_volume, deferredPage, false, true);
-                            if (buffer.getGeneration() == lc._deferredReindexChangeCount) {
-                                checkPageType(buffer, level + PAGE_TYPE_DATA, false);
-                                buffer.nextKey(_spareKey2, buffer.toKeyBlock(0));
-                                _value.setPointerValue(buffer.getPageAddress());
-                                _value.setPointerPageType(buffer.getPageType());
-                                storeInternal(_spareKey2, _value, level + 1, StoreOptions.NONE);
-                            } else {
-                                _persistit.getLogBase().unindexedPage.log(deferredPage, _volume, _tree.getName());
-                            }
-                            lc._deferredReindexPage = 0;
-                            buffer.releaseTouched();
-                            buffer = null;
-                        }
-                    }
-                    deferredReindexRequired = false;
-                } catch (RetryException re) {
-                    // can this even be thrown here?
-                } finally {
-                    if (buffer != null) {
-                        buffer.releaseTouched();
-                        buffer = null;
-                    }
-                }
-            }
-
         } finally {
             if (treeClaimAcquired) {
-                _tree.bumpGeneration();
+                if (treeWriterClaimRequired) {
+                    _tree.bumpGeneration();
+                }
                 _treeHolder.release();
                 treeClaimAcquired = false;
             }
 
=== modified file 'src/main/java/com/persistit/IntegrityCheck.java'
--- src/main/java/com/persistit/IntegrityCheck.java	2012-06-26 19:36:26 +0000
+++ src/main/java/com/persistit/IntegrityCheck.java	2012-06-29 21:06:19 +0000
@@ -339,7 +339,14 @@
     }
 
     private void addFault(String description, long page, int level, int position) {
-        Fault fault = new Fault(resourceName(), this, description, page, level, position);
+        Fault fault = new Fault(resourceName(), this, description, page, _treeDepth, level, position);
+        if (_faults.size() < MAX_FAULTS)
+            _faults.add(fault);
+        postMessage(fault.toString(), LOG_VERBOSE);
+    }
+
+    private void addGarbageFault(String description, long page, int level, int position) {
+        Fault fault = new Fault(resourceName(), this, description, page, 3, level, position);
         if (_faults.size() < MAX_FAULTS)
             _faults.add(fault);
         postMessage(fault.toString(), LOG_VERBOSE);
@@ -645,10 +652,10 @@
         int _depth;
         int _position;
 
-        Fault(String treeName, IntegrityCheck work, String description, long page, int level, int position) {
+        Fault(String treeName, IntegrityCheck work, String description, long page, int depth, int level, int position) {
             _treeName = treeName;
             _description = description;
-            _depth = work._treeDepth;
+            _depth = depth;
             _path = new long[_depth - level];
             for (int index = _depth; --index > level;) {
                 if (index >= work._edgeBuffers.length) {
@@ -657,7 +664,7 @@
                     _path[index - level] = work._edgePages[index];
                 }
             }
-            _path[level] = page;
+            _path[0] = page;
             _level = level;
             _depth = work._treeDepth;
             _position = position;
@@ -994,11 +1001,11 @@
     private void checkGarbagePage(Buffer garbageBuffer) throws PersistitException {
         long page = garbageBuffer.getPageAddress();
         if (!garbageBuffer.isGarbagePage()) {
-            addFault("Unexpected page type " + garbageBuffer.getPageType() + " expected a garbage page", page, 1, 0);
+            addGarbageFault("Unexpected page type " + garbageBuffer.getPageType() + " expected a garbage page", page, 1, 0);
             return;
         }
         if (_usedPageBits.get(page)) {
-            addFault("Garbage page is referenced by multiple parents", page, 1, 0);
+            addGarbageFault("Garbage page is referenced by multiple parents", page, 1, 0);
             return;
         }
 
@@ -1007,7 +1014,7 @@
         int size = garbageBuffer.getBufferSize();
         int count = (size - next) / Buffer.GARBAGE_BLOCK_SIZE;
         if (count * Buffer.GARBAGE_BLOCK_SIZE != (size - next)) {
-            addFault("Garbage page is malformed: _alloc=" + next + " is not at a multiple of "
+            addGarbageFault("Garbage page is malformed: _alloc=" + next + " is not at a multiple of "
                     + Buffer.GARBAGE_BLOCK_SIZE + " bytes", page, 1, 0);
         }
         _usedPageBits.set(page, true);
@@ -1026,12 +1033,12 @@
         _edgePages[2] = page;
         while (page != 0 && page != right) {
             if (_usedPageBits.get(page)) {
-                addFault("Page on garbage chain is referenced by multiple parents", page, 3, 0);
+                addGarbageFault("Page on garbage chain is referenced by multiple parents", page, 0, 0);
                 return;
             }
             Buffer buffer = getPage(page);
             if (!buffer.isDataPage() && !buffer.isIndexPage() && !buffer.isLongRecordPage()) {
-                addFault("Page of type " + buffer.getPageTypeName() + " found on garbage page", page, 3, 0);
+                addGarbageFault("Page of type " + buffer.getPageTypeName() + " found on garbage page", page, 0, 0);
             }
             _counters._garbagePageCount++;
             _pagesVisited++;
 
=== modified file 'src/main/java/com/persistit/VolumeStorageV2.java'
--- src/main/java/com/persistit/VolumeStorageV2.java	2012-06-22 19:07:13 +0000
+++ src/main/java/com/persistit/VolumeStorageV2.java	2012-06-29 21:06:19 +0000
@@ -363,6 +363,7 @@
         _headBuffer = _volume.getStructure().getPool().get(_volume, 0, true, false);
         boolean truncated = false;
         try {
+            _headBuffer.init(Buffer.PAGE_TYPE_HEAD);
             _headBuffer.setFixed();
 
             initMetaData(_headBuffer.getBytes());
 
=== modified file 'src/main/java/com/persistit/exception/RetryException.java'
--- src/main/java/com/persistit/exception/RetryException.java	2012-05-25 18:50:59 +0000
+++ src/main/java/com/persistit/exception/RetryException.java	2012-06-29 21:06:19 +0000
@@ -30,7 +30,4 @@
 
     public final static RetryException SINGLE = new RetryException();
 
-    public RetryException() {
-
-    }
 }
 
=== modified file 'src/main/java/com/persistit/util/Debug.java'
--- src/main/java/com/persistit/util/Debug.java	2012-06-04 18:58:23 +0000
+++ src/main/java/com/persistit/util/Debug.java	2012-06-29 21:06:19 +0000
@@ -106,6 +106,32 @@
         }
         System.err.println("Debug " + sb.toString());
     }
+    
+    public static String trace(int from, int to) {
+        return " " + Thread.currentThread().getName() + " {" + Debug.callStack(from + 2, to + 2) + "}";
+    }
+    
+    public static String callStack(final int from, final int to) {
+        RuntimeException exception = new RuntimeException();
+        exception.fillInStackTrace();
+        StackTraceElement[] elements = exception.getStackTrace();
+        int a = Math.max(0, from);
+        int b = Math.min(to, elements.length);
+        StringBuilder sb = new StringBuilder();
+        for (int index = b; index >= a; index--) {
+            StackTraceElement t = exception.getStackTrace()[index];
+            if (index != b) {
+                sb.append("->");
+            }
+            sb.append(t.getClassName());
+            sb.append('#');
+            sb.append(t.getMethodName());
+            sb.append('[');
+            sb.append(t.getLineNumber());
+            sb.append("]");
+        }
+        return sb.toString();
+    }
 
     /**
      * Set the suspend flag so that callers to the suspend method either do or
 
=== modified file 'src/main/java/com/persistit/util/SequencerConstants.java'
--- src/main/java/com/persistit/util/SequencerConstants.java	2012-05-25 18:50:59 +0000
+++ src/main/java/com/persistit/util/SequencerConstants.java	2012-06-29 21:06:19 +0000
@@ -97,4 +97,5 @@
     int LONG_RECORD_ALLOCATE_A = allocate("LONG_RECORD_ALLOCATE_A");
     int LONG_RECORD_ALLOCATE_B = allocate("LONG_RECORD_ALLOCATE_B");
     int[][] LONG_RECORD_ALLOCATE_SCHEDULED = new int[][]{array(LONG_RECORD_ALLOCATE_B), array(LONG_RECORD_ALLOCATE_A, LONG_RECORD_ALLOCATE_B)};
+
 }
 
=== modified file 'src/main/java/com/persistit/util/Util.java'
--- src/main/java/com/persistit/util/Util.java	2012-05-25 18:50:59 +0000
+++ src/main/java/com/persistit/util/Util.java	2012-06-29 21:06:19 +0000
@@ -234,6 +234,14 @@
         return format(Long.toString(i), width, true);
     }
 
+    public static String abridge(final String s, final int maxLength) {
+        if (s.length() > maxLength) {
+            return s.substring(0, maxLength - 3) + "...";
+        } else {
+            return s;
+        }
+    }
+
     public static boolean equalsByteSubarray(byte[] source, int next, byte[] target) {
         return equalsByteSubarray(source, next, target, 0, target.length);
     }
 
=== added file 'src/test/java/com/persistit/Bug1017957Test.java'
--- src/test/java/com/persistit/Bug1017957Test.java	1970-01-01 00:00:00 +0000
+++ src/test/java/com/persistit/Bug1017957Test.java	2012-06-29 21:06:19 +0000
@@ -0,0 +1,235 @@
+/**
+ * Copyright © 2012 Akiban Technologies, Inc.  All rights reserved.
+ *
+ * This program is free software: you can redistribute it and/or modify
+ * it under the terms of the GNU Affero General Public License as
+ * published by the Free Software Foundation, version 3 (only) of the
+ * License.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU Affero General Public License for more details.
+ *
+ * You should have received a copy of the GNU Affero General Public License
+ * along with this program.  If not, see <http://www.gnu.org/licenses/>.
+ * 
+ * This program may also be available under different license terms. For more
+ * information, see www.akiban.com or contact [e-mail].
+ */
+
+package com.persistit;
+
+import static org.junit.Assert.assertEquals;
+
+import java.io.PrintWriter;
+import java.util.Properties;
+import java.util.concurrent.atomic.AtomicInteger;
+
+import org.junit.Test;
+
+import com.persistit.mxbeans.ManagementMXBean;
+import com.persistit.unit.PersistitUnitTestCase;
+import com.persistit.unit.UnitTestProperties;
+
+/**
+ * https://bugs.launchpad.net/akiban-persistit/+bug/1017957
+ * 
+ * During the past week the 8-hour stress test suite has generated several
+ * CorruptVolumeExceptions and other related phenomena. Examples:
+ * 
+ * Stress6 [main] FAILED: com.persistit.exception.CorruptVolumeException: Volume
+ * persistit(/tmp/persistit_tests/persistit) level=0 page=15684
+ * initialPage=57164
+ * key=<{"stress6",98,5,"xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx"}> walked
+ * right more than 50 pages last page visited=81324 at
+ * com.persistit.Exchange.corrupt(Exchange.java:3884) at
+ * com.persistit.Exchange.searchLevel(Exchange.java:1250) at
+ * com.persistit.Exchange.searchTree(Exchange.java:1125) at
+ * com.persistit.Exchange.storeInternal(Exchange.java:1443) at
+ * com.persistit.Exchange.store(Exchange.java:1294) at
+ * com.persistit.Exchange.store(Exchange.java:2534) at
+ * com.persistit.stress.unit.Stress6.executeTest(Stress6.java:98) at
+ * com.persistit.stress.AbstractStressTest.run(AbstractStressTest.java:93) at
+ * java.lang.Thread.run(Thread.java:662)
+ * 
+ * Stress2txn [main] FAILED: com.persistit.exception.RebalanceException at
+ * com.persistit.Buffer.join(Buffer.java:2523) at
+ * com.persistit.Exchange.raw_removeKeyRangeInternal(Exchange.java:3367) at
+ * com.persistit.Exchange.removeKeyRangeInternal(Exchange.java:3070) at
+ * com.persistit.Exchange.removeInternal(Exchange.java:2999) at
+ * com.persistit.Exchange.remove(Exchange.java:2927) at
+ * com.persistit.stress.unit.Stress2txn.executeTest(Stress2txn.java:231) at
+ * com.persistit.stress.AbstractStressTest.run(AbstractStressTest.java:93) at
+ * java.lang.Thread.run(Thread.java:662)
+ * 
+ * Stress2txn [main] FAILED: com.persistit.exception.CorruptVolumeException:
+ * LONG_RECORD chain is invalid at page 111919 - invalid page type: Page 111,919
+ * in volume persistit(/tmp/persistit_tests/persistit) at index 1,559
+ * timestamp=909,787,072 status=vr1 type=Data at
+ * com.persistit.LongRecordHelper.corrupt(LongRecordHelper.java:243) at
+ * com.persistit.LongRecordHelper.fetchLongRecord(LongRecordHelper.java:103) at
+ * com.persistit.Exchange.fetchFixupForLongRecords(Exchange.java:2841) at
+ * com.persistit.Exchange.fetchFromValueInternal(Exchange.java:2778) at
+ * com.persistit.Exchange.fetchFromBufferInternal(Exchange.java:2747) at
+ * com.persistit.Exchange.traverse(Exchange.java:2157) at
+ * com.persistit.Exchange.traverse(Exchange.java:1960) at
+ * com.persistit.Exchange.traverse(Exchange.java:1897) at
+ * com.persistit.Exchange.next(Exchange.java:2330) at
+ * com.persistit.stress.unit.Stress2txn.executeTest(Stress2txn.java:188) at
+ * com.persistit.stress.AbstractStressTest.run(AbstractStressTest.java:93) at
+ * java.lang.Thread.run(Thread.java:662)
+ * 
+ * Bug mechanism #1:
+ * 
+ * An obscure path through Exchange#raw_removeKeyRangeInternal inserts a
+ * key-pointer pair into an index page. It does so after removing all claims on
+ * pages and the tree itself. After removing claims, before inserting the
+ * key-pointer pair we believe the page itself gets put unto a garbage chain. So
+ * after the re-insertion, the index page now has a pointer to a page that will
+ * be reused and will contain unrelated data.
+ * 
+ * 
+ * Bug mechanism #2: An obscure path through Exchange#raw_removeKeyRangeInternal
+ * performs a structure delete (i.e., joins one more pairs of pages) but fails
+ * to bump the Tree generation. The allows use of a stale LevelCache array.
+ * 
+ * This test procedure exhibited both bug mechanisms reliably within 10 seconds
+ * prior to fixing the code. We also implemented a test method based on the
+ * ThreadSequencer to precisely elaborate the sequence of interactions between
+ * two threads that cause the failure. However, the bug fix eliminates the code
+ * path that allows the sequencer to work, so the test was removed.
+ * 
+ * @author peter
+ * 
+ */
+public class Bug1017957Test extends PersistitUnitTestCase {
+
+    @Override
+    protected Properties getProperties(boolean cleanup) {
+        return UnitTestProperties.getBiggerProperties(cleanup);
+    }
+
+    private final long STRESS_NANOS = 10L * 1000000000L;
+
+    /**
+     * 
+     * @throws Exception
+     */
+    @Test
+    public void induceCorruptionByStress() throws Exception {
+        final long expiresAt = System.nanoTime() + STRESS_NANOS;
+        final AtomicInteger totalErrors = new AtomicInteger();
+        Thread t1 = new Thread(new Runnable() {
+            public void run() {
+                int count = 0;
+                int errors = 0;
+                try {
+                    Exchange ex = _persistit.getExchange("persistit", "Bug1017957Test", true);
+                    while (System.nanoTime() < expiresAt) {
+                        try {
+                            Key key = createUnsafeStructure(ex);
+                            removeInterestingKey(ex, key);
+                            if (++count % 5000 == 0) {
+                                System.out.printf("T1 iterations %,d\n", count);
+                            }
+                        } catch (Exception e) {
+                            if (++errors < 10) {
+                                e.printStackTrace();
+                            }
+                            totalErrors.incrementAndGet();
+                        }
+                    }
+                } catch (Exception e) {
+                    throw new RuntimeException(e);
+                }
+            }
+        });
+
+        Thread t2 = new Thread(new Runnable() {
+            public void run() {
+                int count = 0;
+                int errors = 0;
+                try {
+                    Exchange ex = _persistit.getExchange("persistit", "Bug1017957Test", true);
+                    while (System.nanoTime() < expiresAt) {
+                        try {
+                            removeCoveringRange(ex);
+                            insertOtherStuff(ex);
+                            if (++count % 5000 == 0) {
+                                System.out.printf("T2 iterations %,d\n", count);
+                            }
+                        } catch (Exception e) {
+                            if (++errors < 10) {
+                                e.printStackTrace();
+                            }
+                            totalErrors.incrementAndGet();
+                        }
+                    }
+                } catch (Exception e) {
+                    if (++errors < 10) {
+                        e.printStackTrace();
+                    }
+                }
+            }
+        });
+
+        t1.start();
+        t2.start();
+        t1.join();
+        t2.join();
+
+        IntegrityCheck icheck = new IntegrityCheck(_persistit);
+        icheck.setMessageLogVerbosity(Task.LOG_VERBOSE);
+        icheck.setMessageWriter(new PrintWriter(System.out));
+        icheck.checkVolume(_persistit.getVolume("persistit"));
+        System.out.printf("\nTotal errors %d", totalErrors.get());
+        assertEquals("Corrupt volume", 0, icheck.getFaults().length);
+        assertEquals("Exception occurred", 0, totalErrors.get());
+    }
+
+    /**
+     * Create a B-Tree with a structure that will induce a deferred index
+     * insertion on removal of key. We need an index page that's pretty full
+     * such that removing a key and inserting a different one will result in
+     * splitting the index page.
+     * 
+     * @throws Exception
+     */
+    private Key createUnsafeStructure(final Exchange ex) throws Exception {
+        Key result = null;
+        final String v = createString(5500); // less than long record
+        final String k = createString(1040);
+        for (int i = 1000; i < 1019; i++) {
+            if (i == 1009) {
+                ex.clear().append(i).append(k.substring(0, 20));
+                ex.getValue().put("interesting");
+                ex.store();
+                result = new Key(ex.getKey());
+            }
+            ex.clear().append(i).append(k);
+            ex.getValue().put(v);
+            ex.store();
+        }
+        return result;
+    }
+
+    private void removeInterestingKey(final Exchange ex, final Key interestingKey) throws Exception {
+        interestingKey.copyTo(ex.getKey());
+        ex.remove();
+    }
+
+    private void removeCoveringRange(final Exchange ex) throws Exception {
+        final Key key1 = new Key(_persistit).append(1005);
+        final Key key2 = new Key(_persistit).append(1015);
+        ex.removeKeyRange(key1, key2);
+    }
+
+    private void insertOtherStuff(final Exchange ex) throws Exception {
+        for (int k = 0; k < 100; k++) {
+            ex.clear().append(1009).append(k).append(RED_FOX);
+            ex.getValue().put(RED_FOX);
+            ex.store();
+        }
+    }
+}
 
=== modified file 'src/test/java/com/persistit/IntegrityCheckTest.java'
--- src/test/java/com/persistit/IntegrityCheckTest.java	2012-05-25 18:50:59 +0000
+++ src/test/java/com/persistit/IntegrityCheckTest.java	2012-06-29 21:06:19 +0000
@@ -211,6 +211,16 @@
         _persistit.getTransactionIndex().cleanup();
         assertEquals(0, _persistit.getTransactionIndex().getAbortedCount());
     }
+    
+    @Test
+    public void testCorruptGarbageChain() throws PersistitException {
+        final Exchange ex = _persistit.getExchange(_volumeName, "mvv", true);
+        nonTransactionalStore(ex);
+        corrupt4(ex);
+        IntegrityCheck icheck = icheck();
+        icheck.checkVolume(ex.getVolume());
+        assertTrue(icheck.getFaults().length > 0);
+    }
 
     private String key(final int i) {
         return String.format("%05d%s", i, RED_FOX);
@@ -314,6 +324,19 @@
         buffer.setDirtyAtTimestamp(_persistit.getTimestampAllocator().updateTimestamp());
         buffer.release();
     }
+    
+    /**
+     * Corrupts garbage chain by adding a live data chain to it
+     * @throw PersistitException
+     */
+    private void corrupt4(final Exchange ex) throws PersistitException {
+        Key key = ex.getKey();
+        ex.clear().to(key(500));
+        Buffer copy = ex.fetchBufferCopy(0);
+        Buffer buffer = ex.getBufferPool().get(ex.getVolume(), copy.getPageAddress(), true, true);
+        ex.getVolume().getStructure().deallocateGarbageChain(buffer.getPageAddress(), buffer.getRightSibling());
+        buffer.release();
+    }
 
     private IntegrityCheck icheck() {
         IntegrityCheck icheck = new IntegrityCheck(_persistit);