From 2b4f8ed55c187ed06892519a9cf878b71dd5a2ae Mon Sep 17 00:00:00 2001 From: zzz Date: Thu, 7 Jul 2011 15:19:59 +0000 Subject: [PATCH] * Blockfile: - Log error on out-of-order spans - Log error on corrupt level and discard - Fix SkipSpan non-flush bug causing null levels - Add level fixer that repairs nulls and out-of-order levels - Fix bug on backwards span construction, not hit in practice - Lots of log level changes --- core/java/src/net/metanotion/io/RAIFile.java | 10 + .../net/metanotion/io/block/BlockFile.java | 73 ++++-- .../io/block/index/BSkipLevels.java | 221 +++++++++++++++++- .../metanotion/io/block/index/BSkipList.java | 35 +-- .../metanotion/io/block/index/BSkipSpan.java | 10 +- .../metanotion/io/block/index/IBSkipSpan.java | 23 +- .../metanotion/util/skiplist/SkipLevels.java | 24 +- .../metanotion/util/skiplist/SkipList.java | 10 +- history.txt | 9 + .../src/net/i2p/router/RouterVersion.java | 2 +- 10 files changed, 357 insertions(+), 60 deletions(-) diff --git a/core/java/src/net/metanotion/io/RAIFile.java b/core/java/src/net/metanotion/io/RAIFile.java index 43ef2f2b8..9f26b01f1 100644 --- a/core/java/src/net/metanotion/io/RAIFile.java +++ b/core/java/src/net/metanotion/io/RAIFile.java @@ -68,6 +68,16 @@ public class RAIFile implements RandomAccessInterface, DataInput, DataOutput { return this.w; } + /** + * @since 0.8.8 + */ + @Override + public String toString() { + if (this.f != null) + return this.f.getAbsolutePath(); + return this.delegate.toString(); + } + public long getFilePointer() throws IOException { return delegate.getFilePointer(); } public long length() throws IOException { return delegate.length(); } public int read() throws IOException { return delegate.read(); } diff --git a/core/java/src/net/metanotion/io/block/BlockFile.java b/core/java/src/net/metanotion/io/block/BlockFile.java index eee03a0da..96a76d5bd 100644 --- a/core/java/src/net/metanotion/io/block/BlockFile.java +++ b/core/java/src/net/metanotion/io/block/BlockFile.java @@ -122,6 +122,9 @@ public class BlockFile { spanSize = file.readUnsignedShort(); } + /** + * Run an integrity check on the blockfile and all the skiplists in it + */ public static void main(String args[]) { if (args.length != 1) { System.err.println("Usage: BlockFile file"); @@ -331,12 +334,12 @@ public class BlockFile { if (flb == null) flb = new FreeListBlock(file, freeListStart); if(!flb.isEmpty()) { - if (log.shouldLog(Log.INFO)) - log.info("Alloc from " + flb); + if (log.shouldLog(Log.DEBUG)) + log.debug("Alloc from " + flb); return flb.takePage(); } else { - if (log.shouldLog(Log.INFO)) - log.info("Alloc returning empty " + flb); + if (log.shouldLog(Log.DEBUG)) + log.debug("Alloc returning empty " + flb); freeListStart = flb.getNextPage(); writeSuperBlock(); int rv = flb.page; @@ -370,8 +373,8 @@ public class BlockFile { freeListStart = page; FreeListBlock.initPage(file, page); writeSuperBlock(); - if (log.shouldLog(Log.INFO)) - log.info("Freed page " + page + " as new FLB"); + if (log.shouldLog(Log.DEBUG)) + log.debug("Freed page " + page + " as new FLB"); return; } try { @@ -379,8 +382,8 @@ public class BlockFile { flb = new FreeListBlock(file, freeListStart); if(flb.isFull()) { // Make the free page a new FLB - if (log.shouldLog(Log.INFO)) - log.info("Full: " + flb); + if (log.shouldLog(Log.DEBUG)) + log.debug("Full: " + flb); FreeListBlock.initPage(file, page); if(flb.getNextPage() == 0) { // Put it at the tail. @@ -394,13 +397,13 @@ public class BlockFile { freeListStart = page; writeSuperBlock(); } - if (log.shouldLog(Log.INFO)) - log.info("Freed page " + page + " to full " + flb); + if (log.shouldLog(Log.DEBUG)) + log.debug("Freed page " + page + " to full " + flb); return; } flb.addPage(page); - if (log.shouldLog(Log.INFO)) - log.info("Freed page " + page + " to " + flb); + if (log.shouldLog(Log.DEBUG)) + log.debug("Freed page " + page + " to " + flb); } catch (IOException ioe) { log.error("Discarding corrupt free list block page " + freeListStart, ioe); freeListStart = page; @@ -413,6 +416,10 @@ public class BlockFile { } } + /** + * If the file is writable, this runs an integrity check and repair + * on first open. + */ public BSkipList getIndex(String name, Serializer key, Serializer val) throws IOException { // added I2P BSkipList bsl = (BSkipList) openIndices.get(name); @@ -422,6 +429,13 @@ public class BlockFile { Integer page = (Integer) metaIndex.get(name); if (page == null) { return null; } bsl = new BSkipList(spanSize, this, page.intValue(), key, val, true); + if (file.canWrite()) { + log.info("Checking skiplist " + name + " in blockfile " + file); + if (bsl.bslck(true, false)) + log.logAlways(Log.WARN, "Repaired skiplist " + name + " in blockfile " + file); + else + log.info("No errors in skiplist " + name + " in blockfile " + file); + } openIndices.put(name, bsl); return bsl; } @@ -481,31 +495,44 @@ public class BlockFile { } } - public void bfck(boolean fix) { - log.warn("magic bytes " + magicBytes); - log.warn("fileLen " + fileLen); - log.warn("freeListStart " + freeListStart); - log.warn("mounted " + mounted); - log.warn("spanSize " + spanSize); - log.warn("Metaindex"); - metaIndex.bslck(true, fix); + /** + * Run an integrity check on the blockfile and all the skiplists in it + * @return true if the levels were modified. + */ + public boolean bfck(boolean fix) { + log.info("magic bytes " + magicBytes); + log.info("fileLen " + fileLen); + log.info("freeListStart " + freeListStart); + log.info("mounted " + mounted); + log.info("spanSize " + spanSize); + log.info("Metaindex"); + log.info("Checking meta index in blockfile " + file); + boolean rv = metaIndex.bslck(fix, true); + if (rv) + log.warn("Repaired meta index in blockfile " + file); + else + log.info("No errors in meta index in blockfile " + file); int items = 0; for (SkipIterator iter = metaIndex.iterator(); iter.hasNext(); ) { String slname = (String) iter.nextKey(); Integer page = (Integer) iter.next(); - log.warn("List " + slname + " page " + page); + log.info("List " + slname + " page " + page); try { + // This uses IdentityBytes, so the value class won't be right + //Serializer ser = slname.equals("%%__REVERSE__%%") ? new IntBytes() : new UTF8StringBytes(); BSkipList bsl = getIndex(slname, new UTF8StringBytes(), new IdentityBytes()); if (bsl == null) { log.error("Can't find list? " + slname); continue; } - bsl.bslck(false, fix); + // The check is now done in getIndex(), no need to do here... + // but we can't get the return value of the check here. items++; } catch (IOException ioe) { log.error("Error with list " + slname, ioe); } } - log.warn("actual size " + items); + log.info("Checked meta index and " + items + " skiplists"); + return rv; } } diff --git a/core/java/src/net/metanotion/io/block/index/BSkipLevels.java b/core/java/src/net/metanotion/io/block/index/BSkipLevels.java index b204f4d8d..744254267 100644 --- a/core/java/src/net/metanotion/io/block/index/BSkipLevels.java +++ b/core/java/src/net/metanotion/io/block/index/BSkipLevels.java @@ -29,6 +29,9 @@ SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. package net.metanotion.io.block.index; import java.io.IOException; +import java.util.Comparator; +import java.util.Set; +import java.util.TreeSet; import net.metanotion.io.RandomAccessInterface; import net.metanotion.io.block.BlockFile; @@ -77,9 +80,11 @@ public class BSkipLevels extends SkipLevels { throw new IOException("Invalid Level Skip size " + nonNull + " / " + maxLen); spanPage = bf.file.readUnsignedInt(); bottom = bsl.spanHash.get(Integer.valueOf(spanPage)); - if (bottom == null) + if (bottom == null) { // FIXME recover better? BlockFile.log.error("No span found in cache???"); + throw new IOException("No span found in cache???"); + } this.levels = new BSkipLevels[maxLen]; if (BlockFile.log.shouldLog(Log.DEBUG)) @@ -90,21 +95,55 @@ public class BSkipLevels extends SkipLevels { lps[i] = bf.file.readUnsignedInt(); } + boolean fail = false; for(int i = 0; i < nonNull; i++) { int lp = lps[i]; if(lp != 0) { levels[i] = bsl.levelHash.get(Integer.valueOf(lp)); if(levels[i] == null) { - levels[i] = new BSkipLevels(bf, lp, bsl); - bsl.levelHash.put(Integer.valueOf(lp), levels[i]); - } else { + try { + // FIXME this will explode the stack if too big + // Redo this without recursion? + // Lots of recursion in super to be fixed also... + levels[i] = new BSkipLevels(bf, lp, bsl); + bsl.levelHash.put(Integer.valueOf(lp), levels[i]); + } catch (IOException ioe) { + BlockFile.log.error("Corrupt database, bad level " + i + + " at page " + lp, ioe); + levels[i] = null; + fail = true; + continue; + } } + Comparable ourKey = key(); + Comparable nextKey = levels[i].key(); + if (ourKey != null && nextKey != null && + ourKey.compareTo(nextKey) >= 0) { + BlockFile.log.warn("Corrupt database, level out of order " + this + + ' ' + print() + + " i = " + i + ' ' + levels[i]); + // This will be fixed in blvlfix() via BlockFile.getIndex() + //levels[i] = null; + //fail = true; + } + // TODO also check that the level[] array is not out-of-order } else { if (BlockFile.log.shouldLog(Log.WARN)) BlockFile.log.warn("WTF " + this + " i = " + i + " of " + nonNull + " / " + maxLen + " valid levels but page is zero"); levels[i] = null; + fail = true; } } + if (fail && bf.file.canWrite()) { + // corruption is actually fixed in blvlfix() via BlockFile.getIndex() + // after instantiation is complete + BlockFile.log.error("Repairing corruption of " + this + + ' ' + print()); + flush(); + // if the removed levels have no other links to them, they and their data + // are lost forever, but the alternative is infinite loops / stack overflows + // in SkipSpan. + } } public static void init(BlockFile bf, int page, int spanPage, int maxHeight) throws IOException { @@ -144,8 +183,8 @@ public class BSkipLevels extends SkipLevels { BlockFile.log.error("Already killed!! " + this, new Exception()); return; } - if (BlockFile.log.shouldLog(Log.INFO)) - BlockFile.log.info("Killing " + this); + if (BlockFile.log.shouldLog(Log.DEBUG)) + BlockFile.log.debug("Killing " + this + ' ' + print(), new Exception()); isKilled = true; bsl.levelHash.remove(Integer.valueOf(levelPage)); bf.freePage(levelPage); @@ -158,27 +197,187 @@ public class BSkipLevels extends SkipLevels { BSkipList bsl = (BSkipList) sl; int page = bf.allocPage(); BSkipLevels.init(bf, page, bss.page, levels); - BlockFile.log.info("New BSkipLevels height " + levels + " page " + page); + if (BlockFile.log.shouldLog(Log.DEBUG)) + BlockFile.log.debug("New BSkipLevels height " + levels + " page " + page); return new BSkipLevels(bf, page, bsl); } catch (IOException ioe) { throw new RuntimeException("Error creating database page", ioe); } } + /** + * Run an integrity check on the skiplevels from the first, + * or just fix it if fix == true. + * Only call from the first level. + * @return true if the levels were modified. + */ @Override - public void blvlck(boolean fix, int width) { + public boolean blvlck(boolean fix) { + if (fix) + return blvlfix(); + return blvlck(fix, 0, null); + } + + /** + * Fix the levels. + * Only call from the first level. + * Primarily to fix nulls in levels caused by previous SkipLevels bug. + * This should handle dups and loops and out-of-order levels too, + * but those may cause problems before this in the constructor. + * This is fast enough to call every time the skiplist is opened. + * @return true if the levels were modified. + * @since 0.8.8 + */ + private boolean blvlfix() { + TreeSet lvls = new TreeSet(new LevelComparator()); + if (BlockFile.log.shouldLog(Log.DEBUG)) + BlockFile.log.debug("Starting level search"); + getAllLevels(this, lvls); + if (BlockFile.log.shouldLog(Log.DEBUG)) + BlockFile.log.debug("Finished level search, found " + lvls.size() + " levels"); + if (!this.equals(lvls.last())) { + BlockFile.log.error("First level is out of order! " + print()); + // TODO switch stack and other fields for the skiplist - hard to test + } + // traverse the levels, back-to-front + boolean rv = false; + SkipLevels after = null; + for (SkipLevels lv : lvls) { + boolean modified = false; + if (BlockFile.log.shouldLog(Log.DEBUG)) + BlockFile.log.debug("Checking " + lv.print()); + if (after != null) { + int min = Math.min(after.levels.length, lv.levels.length); + for (int i = 0; i < min; i++) { + SkipLevels cur = lv.levels[i]; + if (cur != after) { + if (cur != null) + BlockFile.log.warn("Level " + i + " was wrong, fixing for " + lv.print()); + else + BlockFile.log.warn("Level " + i + " was null, fixing for " + lv.print()); + lv.levels[i] = after; + modified = true; + } + } + } else { + // last one + for (int i = 0; i < lv.levels.length; i++) { + if (lv.levels[i] != null) { + lv.levels[i] = null; + BlockFile.log.warn("Last level " + i + " was non-null, fixing for " + lv.print()); + modified = true; + } + } + } + if (modified) { + lv.flush(); + rv = true; + } + after = lv; + } + if (BlockFile.log.shouldLog(Log.INFO)) + BlockFile.log.info("Checked " + lvls.size() + " levels"); + return rv; + } + + /** + * Breadth-first, sortof + * We assume everything is findable from the root level + * @param l non-null + * @param lvlSet out parameter, the result + * @since 0.8.8 + */ + private void getAllLevels(SkipLevels l, Set lvlSet) { + if (BlockFile.log.shouldLog(Log.DEBUG)) + BlockFile.log.debug("GAL " + l.print()); + // Do level 0 without recursion, on the assumption everything is findable + // from the root + SkipLevels cur = l; + while (cur != null && lvlSet.add(cur)) { + if (BlockFile.log.shouldLog(Log.DEBUG)) + BlockFile.log.debug("Adding " + cur.print()); + if (!cur.equals(this) && cur.key() == null && BlockFile.log.shouldLog(Log.WARN)) + BlockFile.log.debug("Null KEY!!! " + cur.print()); + cur = cur.levels[0]; + } + // If there were no nulls at level 0 in the middle, + // i.e. there are no problems, this won't find anything + for (int i = 1; i < l.levels.length; i++) { + SkipLevels lv = l.levels[i]; + if (lv != null && !lvlSet.contains(lv)) + getAllLevels(lv, lvlSet); + } + } + + /** + * For sorting levels in blvlfix() + * Sorts in REVERSE order. + * @since 0.8.8 + */ + private static class LevelComparator implements Comparator { + public int compare(SkipLevels l, SkipLevels r) { + Comparable lk = l.key(); + Comparable rk = r.key(); + if (lk == null && rk == null) + return 0; + if (lk == null) + return 1; + if (rk == null) + return -1; + // reverse! + return rk.compareTo(lk); + } + } + + /* + * Recursively walk through the levels at level 0 + * This needs work. + */ + @Override + public boolean blvlck(boolean fix, int width, SkipLevels[] prevLevels) { BlockFile.log.warn(" Skip level at width " + width); BlockFile.log.warn(" levels " + this.levels.length); BlockFile.log.warn(" first key " + this.key()); BlockFile.log.warn(" spanPage " + this.spanPage); BlockFile.log.warn(" levelPage " + this.levelPage); + SkipLevels higher = null; for (int i = levels.length - 1; i >= 0; i--) { if (levels[i] != null) { - BlockFile.log.warn(" level " + i + " -> " + levels[i].key() + " "); + BlockFile.log.info(" level " + i + " -> " + levels[i].key() + " "); + if (higher != null) { + if (higher.key().compareTo(key()) < 0) + BlockFile.log.warn(" Higher level has lower key " + higher.key()); + } } else { - BlockFile.log.warn(" level " + i + " empty"); + BlockFile.log.info(" level " + i + " empty"); + if (higher != null) + BlockFile.log.warn(" Higher level is not empty, key is " + higher.key()); } } + if (prevLevels != null) { + int min = Math.min(prevLevels.length, levels.length); + for (int i = 0; i < min; i++) { + if (prevLevels[i] == this) { + prevLevels[i] = levels[i]; + } else if (prevLevels[i] != null) { + // skipping over us + BlockFile.log.warn(" Previous levels is non-null " + prevLevels[i].key() + " but not pointing to us at level " + i); + // replace so we only get one error + prevLevels[i] = levels[i]; + } else { + // dead end in the middle + if (levels[i] != null) { + BlockFile.log.warn(" Previous levels is null but we are non-null " + levels[i].key() + " at level " + i); + // replace so we only get one error + prevLevels[i] = levels[i]; + } + } + } + } else { + prevLevels = new SkipLevels[levels.length]; + System.arraycopy(levels, 0, prevLevels, 0, levels.length); + } if (levels[0] != null) - levels[0].blvlck(fix, width + 1); + levels[0].blvlck(fix, width + 1, prevLevels); + return false; } @Override diff --git a/core/java/src/net/metanotion/io/block/index/BSkipList.java b/core/java/src/net/metanotion/io/block/index/BSkipList.java index 9313441f5..18753e2b7 100644 --- a/core/java/src/net/metanotion/io/block/index/BSkipList.java +++ b/core/java/src/net/metanotion/io/block/index/BSkipList.java @@ -224,33 +224,40 @@ public class BSkipList extends SkipList { return new IBSkipIterator(ss, search[0]); } - public void bslck(boolean isMeta, boolean fix) { - BlockFile.log.warn(" size " + this.size); - BlockFile.log.warn(" spans " + this.spanHash.size()); - BlockFile.log.warn(" levels " + this.levelHash.size()); - BlockFile.log.warn(" skipPage " + this.skipPage); - BlockFile.log.warn(" firstSpanPage " + this.firstSpanPage); - BlockFile.log.warn(" firstLevelPage " + this.firstLevelPage); - BlockFile.log.warn(" maxLevels " + this.maxLevels()); - printSL(); - print(); - BlockFile.log.warn("*** Lvlck() ***"); - stack.blvlck(fix, 0); + /** + * Run an integrity check on the skiplist and all the levels in it + * @return true if the levels were modified. + */ + public boolean bslck(boolean fix, boolean isMeta) { + BlockFile.log.info(" size " + this.size); + BlockFile.log.info(" spans " + this.spanHash.size()); + BlockFile.log.info(" levels " + this.levelHash.size()); + BlockFile.log.info(" skipPage " + this.skipPage); + BlockFile.log.info(" firstSpanPage " + this.firstSpanPage); + BlockFile.log.info(" firstLevelPage " + this.firstLevelPage); + BlockFile.log.info(" maxLevels " + this.maxLevels()); + //printSL(); + //print(); + //BlockFile.log.info("*** Lvlck() ***"); + boolean rv = stack.blvlck(fix); + /**** int items = 0; for (SkipIterator iter = this.iterator(); iter.hasNext(); ) { String key = (String) iter.nextKey(); if (isMeta) { int sz = ((Integer) iter.next()).intValue(); - BlockFile.log.warn(" Item " + key + " page " + sz); + BlockFile.log.info(" Item " + key.toString() + " page " + sz); } else { String cls= iter.next().getClass().getSimpleName(); - BlockFile.log.warn(" Item " + key + " class " + cls); + BlockFile.log.info(" Item " + key.toString() + " class " + cls); } items++; } BlockFile.log.warn(" actual size " + items); if (items != this.size) BlockFile.log.warn("****** size mismatch, header = " + this.size + " actual = " + items); + ****/ + return rv; } @Override diff --git a/core/java/src/net/metanotion/io/block/index/BSkipSpan.java b/core/java/src/net/metanotion/io/block/index/BSkipSpan.java index 992ed9d2e..6fabb9e73 100644 --- a/core/java/src/net/metanotion/io/block/index/BSkipSpan.java +++ b/core/java/src/net/metanotion/io/block/index/BSkipSpan.java @@ -103,7 +103,8 @@ public class BSkipSpan extends SkipSpan { BlockFile.log.error("Already killed!! " + this, new Exception()); return; } - BlockFile.log.info("Killing " + this); + if (BlockFile.log.shouldLog(Log.DEBUG)) + BlockFile.log.debug("Killing " + this); isKilled = true; try { int curPage = overflowPage; @@ -226,8 +227,8 @@ public class BSkipSpan extends SkipSpan { this.overflowPage = 0; try { int freed = freeContinuationPages(curNextPage[0]); - if (BlockFile.log.shouldLog(Log.INFO)) - BlockFile.log.info("Freed " + freed + " continuation pages"); + if (BlockFile.log.shouldLog(Log.DEBUG)) + BlockFile.log.debug("Freed " + freed + " continuation pages"); } catch (IOException ioe) { BlockFile.log.error("Error freeing " + this, ioe); } @@ -407,12 +408,13 @@ public class BSkipSpan extends SkipSpan { np = bss.nextPage; } + // Go backwards to fill in the rest. This never happens. bss = this; np = prevPage; while(np != 0) { BSkipSpan temp = bsl.spanHash.get(Integer.valueOf(np)); if(temp != null) { - bss.next = temp; + bss.prev = temp; break; } bss.prev = new BSkipSpan(bf, bsl); diff --git a/core/java/src/net/metanotion/io/block/index/IBSkipSpan.java b/core/java/src/net/metanotion/io/block/index/IBSkipSpan.java index be3a44772..ffca8306f 100644 --- a/core/java/src/net/metanotion/io/block/index/IBSkipSpan.java +++ b/core/java/src/net/metanotion/io/block/index/IBSkipSpan.java @@ -277,28 +277,49 @@ public class IBSkipSpan extends BSkipSpan { bss.next = new IBSkipSpan(bf, bsl); bss.next.next = null; bss.next.prev = bss; + Comparable previousFirstKey = bss.firstKey; bss = (IBSkipSpan) bss.next; BSkipSpan.loadInit(bss, bf, bsl, np, key, val); bss.loadFirstKey(); + Comparable nextFirstKey = bss.firstKey; + if (previousFirstKey.compareTo(nextFirstKey) >= 0) { + // TODO remove, but if we are at the bottom of a level + // we have to remove the level too, which is a mess + BlockFile.log.error("Corrupt database, span out of order " + ((BSkipSpan)bss.prev).page + + " first key " + previousFirstKey + + " next page " + bss.page + + " first key " + nextFirstKey); + } np = bss.nextPage; } + // Go backwards to fill in the rest. This never happens. bss = this; np = prevPage; while(np != 0) { temp = (IBSkipSpan) bsl.spanHash.get(Integer.valueOf(np)); if(temp != null) { - bss.next = temp; + bss.prev = temp; break; } bss.prev = new IBSkipSpan(bf, bsl); bss.prev.next = bss; bss.prev.prev = null; + Comparable nextFirstKey = bss.firstKey; bss = (IBSkipSpan) bss.prev; BSkipSpan.loadInit(bss, bf, bsl, np, key, val); bss.loadFirstKey(); + Comparable previousFirstKey = bss.firstKey; + if (previousFirstKey.compareTo(nextFirstKey) >= 0) { + // TODO remove, but if we are at the bottom of a level + // we have to remove the level too, which is a mess + BlockFile.log.error("Corrupt database, span out of order " + bss.page + + " first key " + previousFirstKey + + " next page " + ((BSkipSpan)bss.next).page + + " first key " + nextFirstKey); + } np = bss.prevPage; } } diff --git a/core/java/src/net/metanotion/util/skiplist/SkipLevels.java b/core/java/src/net/metanotion/util/skiplist/SkipLevels.java index 8e090c489..32360172e 100644 --- a/core/java/src/net/metanotion/util/skiplist/SkipLevels.java +++ b/core/java/src/net/metanotion/util/skiplist/SkipLevels.java @@ -64,7 +64,8 @@ public class SkipLevels { public String print() { StringBuilder buf = new StringBuilder(128); - buf.append("SL: ").append(key()).append(" :: "); + String k = (bottom.nKeys == 0) ? "empty" : (key() != null) ? key().toString() : "null"; + buf.append("LVLS: ").append(k).append(" :: "); for(int i=0;i