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

[Peter Beaman]

A revised version of TreeBuilder that merges data much faster than the original version. The original version persisted the sorted tree data by writing temp volumes to disk. The resulting randomly ordered pages must be read non-sequentially during the merge phase.

This new version uses StreamSaver and StreamLoader to persist and re-read the sorted records in sequential file order, significantly reducing random disk reads during the merge process.

In one large test the merge process was reduced from nearly 5 hours to about 1hr 40min.

The add-lock branch is a prerequisite due to the version bump.

Note that names and semantics of some of the protected methods in TreeBuilder changed. In particular, this version provides a deterministic way to know which value was loaded first when a duplicate key is detected.

[Peter Beaman (pbeaman)]

Fixed bug 1100038 which appears when using TreeBuilder. The bug is an redundant decrement in BufferPool#invalidate

[Nathan Williams (nwilliams)]

Persistit trunk and server dep is now at 3.2.5 so we'll probably want to bump it again.

The unique helper on Persistit isn't wrong, but seems far away from it's only usage. Constructing a TreeBuilder and then calling getName() would be mildly surprising with this appended. Maybe TreeBuilder doesn't even need an external name? Or the name written to disk could be an internal ID instead of the name?

There's quite a bit of shuffling here, but otherwise looks all plausible.

review: Needs Fixing

[Peter Beaman (pbeaman)]

Thanks.

Yes, unique() seems far away, but Persistit is our closest singleton and I prefer not to use a static. I suppose we could have multiple counters in TimestampAllocator if you prefer.

Changed setName/getName to have expected behavior.

I kind of like the external name as file name to help someone figure out what the saves files might be if the process is running for a long time or crashes. I'm not wedded to it, but that's what I had in mind.

Found and fixed a couple of other issues - especially one in which closing a temporary volume leaves all its dirty pages in the buffer pool. (isDirty -> clearDirty).

Note that this branch now has 3.2.6-upgrade as a prerequisite, but I did not know how to add that.

[Nathan Williams (nwilliams)]

The external name for the file makes sense and I'm fine with the rest.

review: Approve

[Akiban Build User (build-akiban)]

There was one failure during build/test:

* during merge: merge conflicts while merging lp:~pbeaman/akiban-persistit/tree_builder2

review: Needs Fixing

[Peter Beaman (pbeaman)]

Resolved conflicts. And A-pproving again because nothing substantive changed.

[Akiban Build User (build-akiban)]

There were 2 failures during build/test:

* job system-tests-mtr failed at build number 3175: http://172.16.20.104:8080/job/system-tests-mtr/3175/

* view must-pass failed: system-tests-mtr is red

review: Needs Fixing

[Nathan Williams (nwilliams)]

Unrelated.

=== modified file 'src/main/java/com/persistit/BufferPool.java'
--- src/main/java/com/persistit/BufferPool.java	2013-01-24 18:12:23 +0000
+++ src/main/java/com/persistit/BufferPool.java	2013-01-28 10:44:23 +0000
@@ -659,10 +659,7 @@
             }
         }
         buffer.clearValid();
-        if (buffer.isDirty()) {
-            _dirtyPageCount.decrementAndGet();
-            buffer.clearDirty();
-        }
+        buffer.clearDirty();
         buffer.setPageAddressAndVolume(0, null);
     }
 

=== modified file 'src/main/java/com/persistit/Persistit.java'
--- src/main/java/com/persistit/Persistit.java	2013-01-24 18:19:19 +0000
+++ src/main/java/com/persistit/Persistit.java	2013-01-28 10:44:23 +0000
@@ -43,6 +43,7 @@
 import java.util.TreeMap;
 import java.util.WeakHashMap;
 import java.util.concurrent.atomic.AtomicBoolean;
+import java.util.concurrent.atomic.AtomicLong;
 import java.util.concurrent.atomic.AtomicReference;
 
 import javax.management.InstanceNotFoundException;
@@ -285,6 +286,8 @@
 
     private final ThreadLocal<SoftReference<Value>> _valueThreadLocal = new ThreadLocal<SoftReference<Value>>();
 
+    private final AtomicLong _uniqueCounter = new AtomicLong();
+
     private volatile Volume _lockVolume;
 
     /**
@@ -2513,6 +2516,10 @@
         return value;
     }
 
+    long unique() {
+        return _uniqueCounter.incrementAndGet();
+    }
+
     private final static String[] ARG_TEMPLATE = { "_flag|g|Start AdminUI",
             "_flag|i|Perform IntegrityCheck on all volumes", "_flag|w|Wait until AdminUI exists",
             "_flag|c|Perform copy-back", "properties|string|Property file name",

=== modified file 'src/main/java/com/persistit/StreamLoader.java'
--- src/main/java/com/persistit/StreamLoader.java	2012-08-24 13:57:19 +0000
+++ src/main/java/com/persistit/StreamLoader.java	2013-01-28 10:44:23 +0000
@@ -110,126 +110,126 @@
     }
 
     public void load(final ImportHandler handler) throws IOException, PersistitException {
-        String volumeName = null;
-        String treeName = null;
-        for (;;) {
-            final int b1 = _dis.read();
-            if (b1 == -1) {
-                break;
-            }
-            final int b2 = _dis.read();
-            final int recordType = ((b1 & 0xFF) << 8) + (b2 & 0xFF);
-
-            switch (recordType) {
-            case StreamSaver.RECORD_TYPE_FILL: {
-                handler.handleFillRecord();
-                _otherRecordCount++;
-                break;
-            }
-            case StreamSaver.RECORD_TYPE_DATA: {
-                final int keySize = _dis.readShort();
-                final int elisionCount = _dis.readShort();
-                final int valueSize = _dis.readInt();
-                _value.ensureFit(valueSize);
-                _dis.read(_key.getEncodedBytes(), elisionCount, keySize - elisionCount);
-                _key.setEncodedSize(keySize);
-                _dis.read(_value.getEncodedBytes(), 0, valueSize);
-                _value.setEncodedSize(valueSize);
-                handler.handleDataRecord(_key, _value);
-                _dataRecordCount++;
-                break;
-            }
-            case StreamSaver.RECORD_TYPE_KEY_FILTER: {
-                final String filterString = _dis.readUTF();
-                handler.handleKeyFilterRecord(filterString);
-                _otherRecordCount++;
-                break;
-            }
-            case StreamSaver.RECORD_TYPE_VOLUME_ID: {
-                final long id = _dis.readLong();
-                final long initialPages = _dis.readLong();
-                final long extensionPages = _dis.readLong();
-                final long maximumPages = _dis.readLong();
-                final int bufferSize = _dis.readInt();
-                final String path = _dis.readUTF();
-                volumeName = _dis.readUTF();
-                handler.handleVolumeIdRecord(id, initialPages, extensionPages, maximumPages, bufferSize, path,
-                        volumeName);
-                _otherRecordCount++;
-                break;
-            }
-            case StreamSaver.RECORD_TYPE_TREE_ID: {
-                treeName = _dis.readUTF();
-                handler.handleTreeIdRecord(treeName);
-                _otherRecordCount++;
-                postMessage("Loading Tree " + treeName, Task.LOG_VERBOSE);
-                break;
-            }
-            case StreamSaver.RECORD_TYPE_HOSTNAME: {
-                final String hostName = _dis.readUTF();
-                handler.handleHostNameRecord(hostName);
-                _otherRecordCount++;
-                break;
-            }
-            case StreamSaver.RECORD_TYPE_USER: {
-                final String hostName = _dis.readUTF();
-                handler.handleUserRecord(hostName);
-                _otherRecordCount++;
-                break;
-            }
-            case StreamSaver.RECORD_TYPE_COMMENT: {
-                final String comment = _dis.readUTF();
-                handler.handleCommentRecord(comment);
-                _otherRecordCount++;
-                break;
-            }
-            case StreamSaver.RECORD_TYPE_COUNT: {
-                final long dataRecordCount = _dis.readLong();
-                final long otherRecordCount = _dis.readLong();
-                handler.handleCountRecord(dataRecordCount, otherRecordCount);
-                _otherRecordCount++;
-                break;
-            }
-            case StreamSaver.RECORD_TYPE_START: {
-                handler.handleStartRecord();
-                _otherRecordCount++;
-                break;
-            }
-            case StreamSaver.RECORD_TYPE_END: {
-                handler.handleEndRecord();
-                _otherRecordCount++;
-                break;
-            }
-            case StreamSaver.RECORD_TYPE_TIMESTAMP: {
-                final long timeStamp = _dis.readLong();
-                handler.handleTimeStampRecord(timeStamp);
-                _otherRecordCount++;
-                break;
-            }
-            case StreamSaver.RECORD_TYPE_EXCEPTION: {
-                final String exceptionString = _dis.readUTF();
-                handler.handleExceptionRecord(exceptionString);
-                _otherRecordCount++;
-                break;
-            }
-            case StreamSaver.RECORD_TYPE_COMPLETION: {
-                handler.handleCompletionRecord();
-                _otherRecordCount++;
-                break;
-            }
-            default: {
-                throw new CorruptImportStreamException("Invalid record type " + recordType + " ("
-                        + Util.bytesToHex(new byte[] { (byte) (recordType >>> 8), (byte) recordType })
-                        + " after reading " + _dataRecordCount + " data records" + " and " + _otherRecordCount
-                        + " other records");
-            }
-            }
-
+        while (next(handler)) {
         }
         postMessage(String.format("DONE - processed %,d data records and %,d other records", _dataRecordCount,
                 _otherRecordCount), Task.LOG_NORMAL);
     }
 
+    public boolean next(final ImportHandler handler) throws IOException, PersistitException {
+        final int b1 = _dis.read();
+        if (b1 == -1) {
+            return false;
+        }
+        final int b2 = _dis.read();
+        final int recordType = ((b1 & 0xFF) << 8) + (b2 & 0xFF);
+
+        switch (recordType) {
+        case StreamSaver.RECORD_TYPE_FILL: {
+            handler.handleFillRecord();
+            _otherRecordCount++;
+            break;
+        }
+        case StreamSaver.RECORD_TYPE_DATA: {
+            final int keySize = _dis.readShort();
+            final int elisionCount = _dis.readShort();
+            final int valueSize = _dis.readInt();
+            _value.ensureFit(valueSize);
+            _dis.read(_key.getEncodedBytes(), elisionCount, keySize - elisionCount);
+            _key.setEncodedSize(keySize);
+            _dis.read(_value.getEncodedBytes(), 0, valueSize);
+            _value.setEncodedSize(valueSize);
+            handler.handleDataRecord(_key, _value);
+            _dataRecordCount++;
+            break;
+        }
+        case StreamSaver.RECORD_TYPE_KEY_FILTER: {
+            final String filterString = _dis.readUTF();
+            handler.handleKeyFilterRecord(filterString);
+            _otherRecordCount++;
+            break;
+        }
+        case StreamSaver.RECORD_TYPE_VOLUME_ID: {
+            final long id = _dis.readLong();
+            final long initialPages = _dis.readLong();
+            final long extensionPages = _dis.readLong();
+            final long maximumPages = _dis.readLong();
+            final int bufferSize = _dis.readInt();
+            final String path = _dis.readUTF();
+            handler._volumeName = _dis.readUTF();
+            handler.handleVolumeIdRecord(id, initialPages, extensionPages, maximumPages, bufferSize, path,
+                    handler._volumeName);
+            _otherRecordCount++;
+            break;
+        }
+        case StreamSaver.RECORD_TYPE_TREE_ID: {
+            handler._treeName = _dis.readUTF();
+            handler.handleTreeIdRecord(handler._treeName);
+            _otherRecordCount++;
+            postMessage("Loading Tree " + handler._treeName, Task.LOG_VERBOSE);
+            break;
+        }
+        case StreamSaver.RECORD_TYPE_HOSTNAME: {
+            final String hostName = _dis.readUTF();
+            handler.handleHostNameRecord(hostName);
+            _otherRecordCount++;
+            break;
+        }
+        case StreamSaver.RECORD_TYPE_USER: {
+            final String hostName = _dis.readUTF();
+            handler.handleUserRecord(hostName);
+            _otherRecordCount++;
+            break;
+        }
+        case StreamSaver.RECORD_TYPE_COMMENT: {
+            final String comment = _dis.readUTF();
+            handler.handleCommentRecord(comment);
+            _otherRecordCount++;
+            break;
+        }
+        case StreamSaver.RECORD_TYPE_COUNT: {
+            final long dataRecordCount = _dis.readLong();
+            final long otherRecordCount = _dis.readLong();
+            handler.handleCountRecord(dataRecordCount, otherRecordCount);
+            _otherRecordCount++;
+            break;
+        }
+        case StreamSaver.RECORD_TYPE_START: {
+            handler.handleStartRecord();
+            _otherRecordCount++;
+            break;
+        }
+        case StreamSaver.RECORD_TYPE_END: {
+            handler.handleEndRecord();
+            _otherRecordCount++;
+            break;
+        }
+        case StreamSaver.RECORD_TYPE_TIMESTAMP: {
+            final long timeStamp = _dis.readLong();
+            handler.handleTimeStampRecord(timeStamp);
+            _otherRecordCount++;
+            break;
+        }
+        case StreamSaver.RECORD_TYPE_EXCEPTION: {
+            final String exceptionString = _dis.readUTF();
+            handler.handleExceptionRecord(exceptionString);
+            _otherRecordCount++;
+            break;
+        }
+        case StreamSaver.RECORD_TYPE_COMPLETION: {
+            handler.handleCompletionRecord();
+            _otherRecordCount++;
+            break;
+        }
+        default: {
+            throw new CorruptImportStreamException("Invalid record type " + recordType + " ("
+                    + Util.bytesToHex(new byte[] { (byte) (recordType >>> 8), (byte) recordType }) + " after reading "
+                    + _dataRecordCount + " data records" + " and " + _otherRecordCount + " other records");
+        }
+        }
+        return true;
+    }
+
     /**
      * Handler for various record types in stream being loaded.
      * 
@@ -237,7 +237,7 @@
      * 
      */
 
-    public static class ImportHandler {
+    protected static class ImportHandler {
         protected Persistit _persistit;
         protected TreeSelector _treeSelector;
         protected Exchange _exchange;
@@ -246,12 +246,14 @@
         protected KeyFilter _keyFilter;
         protected boolean _createMissingVolumes;
         protected boolean _createMissingTrees;
+        protected String _volumeName = null;
+        protected String _treeName = null;
 
-        public ImportHandler(final Persistit persistit) {
+        protected ImportHandler(final Persistit persistit) {
             this(persistit, new TreeSelector(), true, true);
         }
 
-        public ImportHandler(final Persistit persistit, final TreeSelector treeSelector,
+        protected ImportHandler(final Persistit persistit, final TreeSelector treeSelector,
                 final boolean createMissingVolumes, final boolean createMissingTrees) {
             _persistit = persistit;
             _treeSelector = treeSelector == null ? new TreeSelector() : treeSelector;
@@ -259,10 +261,10 @@
             _createMissingVolumes = createMissingVolumes;
         }
 
-        public void handleFillRecord() throws PersistitException {
+        protected void handleFillRecord() throws PersistitException {
         }
 
-        public void handleDataRecord(final Key key, final Value value) throws PersistitException {
+        protected void handleDataRecord(final Key key, final Value value) throws PersistitException {
             if (_keyFilter == null || _keyFilter.selected(key)) {
                 if (_volume == null || _tree == null)
                     return;
@@ -277,10 +279,10 @@
             }
         }
 
-        public void handleKeyFilterRecord(final String keyFilterString) throws PersistitException {
+        protected void handleKeyFilterRecord(final String keyFilterString) throws PersistitException {
         }
 
-        public void handleVolumeIdRecord(final long volumeId, final long initialPages, final long extensionPages,
+        protected void handleVolumeIdRecord(final long volumeId, final long initialPages, final long extensionPages,
                 final long maximumPages, final int bufferSize, final String path, final String name)
                 throws PersistitException {
             final Exchange oldExchange = _exchange;
@@ -306,7 +308,7 @@
             }
         }
 
-        public void handleTreeIdRecord(final String treeName) throws PersistitException {
+        protected void handleTreeIdRecord(final String treeName) throws PersistitException {
             final Exchange oldExchange = _exchange;
             _exchange = null;
             _tree = null;
@@ -328,31 +330,31 @@
 
         }
 
-        public void handleTimeStampRecord(final long timeStamp) throws PersistitException {
-        }
-
-        public void handleHostNameRecord(final String hostName) throws PersistitException {
-        }
-
-        public void handleUserRecord(final String userName) throws PersistitException {
-        }
-
-        public void handleCommentRecord(final String comment) throws PersistitException {
-        }
-
-        public void handleCountRecord(final long keyValueRecords, final long otherRecords) throws PersistitException {
-        }
-
-        public void handleStartRecord() throws PersistitException {
-        }
-
-        public void handleEndRecord() throws PersistitException {
-        }
-
-        public void handleExceptionRecord(final String exceptionString) throws PersistitException {
-        }
-
-        public void handleCompletionRecord() throws PersistitException {
+        protected void handleTimeStampRecord(final long timeStamp) throws PersistitException {
+        }
+
+        protected void handleHostNameRecord(final String hostName) throws PersistitException {
+        }
+
+        protected void handleUserRecord(final String userName) throws PersistitException {
+        }
+
+        protected void handleCommentRecord(final String comment) throws PersistitException {
+        }
+
+        protected void handleCountRecord(final long keyValueRecords, final long otherRecords) throws PersistitException {
+        }
+
+        protected void handleStartRecord() throws PersistitException {
+        }
+
+        protected void handleEndRecord() throws PersistitException {
+        }
+
+        protected void handleExceptionRecord(final String exceptionString) throws PersistitException {
+        }
+
+        protected void handleCompletionRecord() throws PersistitException {
         }
 
     }

=== modified file 'src/main/java/com/persistit/StreamSaver.java'
--- src/main/java/com/persistit/StreamSaver.java	2012-08-24 13:57:19 +0000
+++ src/main/java/com/persistit/StreamSaver.java	2013-01-28 10:44:23 +0000
@@ -483,7 +483,7 @@
     }
 
     /**
-     * Saves on or more trees in the specified <code>Volume</code>.
+     * Saves one or more trees in the specified <code>Volume</code>.
      * 
      * @param volume
      *            The <code>Volume</code>

=== modified file 'src/main/java/com/persistit/TreeBuilder.java'
--- src/main/java/com/persistit/TreeBuilder.java	2013-01-19 04:11:48 +0000
+++ src/main/java/com/persistit/TreeBuilder.java	2013-01-28 10:44:23 +0000
@@ -15,16 +15,22 @@
 
 package com.persistit;
 
+import java.io.BufferedInputStream;
+import java.io.BufferedOutputStream;
+import java.io.DataInputStream;
+import java.io.DataOutputStream;
 import java.io.File;
+import java.io.FileInputStream;
+import java.io.FileOutputStream;
 import java.io.IOException;
+import java.text.SimpleDateFormat;
 import java.util.ArrayList;
 import java.util.Collections;
 import java.util.Comparator;
+import java.util.Date;
 import java.util.HashMap;
-import java.util.HashSet;
 import java.util.List;
 import java.util.Map;
-import java.util.Set;
 import java.util.SortedMap;
 import java.util.TreeMap;
 import java.util.concurrent.atomic.AtomicLong;
@@ -122,11 +128,12 @@
  * of records inserted with duplicate keys</li>
  * <li>{@link #beforeMergeKey(Exchange)} - allowing filtering or custom handling
  * per record while merging</li>
- * <li>{@link #afterMergeKey(Exchange)} - behavior after merging one record</li>
- * <li>{@link #beforeSortVolumeEvicted(Volume)} - behavior before evicting a
- * sort volume when full</li>
- * <li>{@link #afterSortVolumeEvicted(Volume)} - behavior after evicting a sort
- * volume when full</li>
+ * <li>{@link #afterMergeKey(Exchange)} - customizable behavior after merging
+ * one record</li>
+ * <li>{@link #beforeSortVolumeClosed(Volume)} - customizable behavior before
+ * closing a sort volume when full</li>
+ * <li>{@link #afterSortVolumeClose(Volume)} - customizable behavior after
+ * closing a sort volume when full</li>
  * <li>{@link #getTreeComparator()} - return a custom Comparator to determine
  * sequence in which trees are populated within the {@link #merge()} method
  * </ul>
@@ -138,22 +145,26 @@
 public class TreeBuilder {
     private final static float DEFAULT_BUFFER_POOL_FRACTION = 0.5f;
     private final static long REPORT_REPORT_MULTIPLE = 1000000;
-    private final static String DEFAULT_NAME = "TreeBuilder";
+    private final static String SDF = "yyyyMMddHHmm";
+    private final static int STREAM_SIZE = 1024 * 1024;
 
     private final String _name;
+    private final long _uniqueId;
     private final Persistit _persistit;
     private final List<File> _directories = new ArrayList<File>();
-    private final List<Volume> _sortVolumes = new ArrayList<Volume>();
     private final int _pageSize;
     private final int _pageLimit;
     private final AtomicLong _sortedKeyCount = new AtomicLong();
     private final AtomicLong _mergedKeyCount = new AtomicLong();
     private volatile long _reportKeyCountMultiple = REPORT_REPORT_MULTIPLE;
-    private Volume _currentSortVolume;
-    private int _nextDirectoryIndex;
-
-    private final Set<Tree> _allTrees = new HashSet<Tree>();
-    private final List<Tree> _sortedTrees = new ArrayList<Tree>();
+    private Volume _sortVolume;
+    private File _sortFile;
+
+    private final List<Tree> _allTrees = new ArrayList<Tree>();
+    private final Map<String, Tree> _sortTreeMap = new HashMap<String, Tree>();
+
+    private int _sortFileIndex;
+    private final List<Node> _sortNodes = new ArrayList<Node>();
 
     private final ThreadLocal<Map<Tree, Exchange>> _sortExchangeMapThreadLocal = new ThreadLocal<Map<Tree, Exchange>>() {
         @Override
@@ -163,16 +174,21 @@
     };
 
     private final Comparator<Tree> _defaultTreeComparator = new Comparator<Tree>() {
+        /**
+         * Default implementation returns trees sorted in the order they were
+         * added to the _allTrees list - in other words, sorting should leave
+         * the list unchanged.
+         * 
+         * @param a
+         * @param b
+         * @return
+         */
         @Override
         public int compare(final Tree a, final Tree b) {
             if (a == b) {
                 return 0;
             }
-            if (a.getVolume() == b.getVolume()) {
-                return a.getName().compareTo(b.getName());
-            } else {
-                return a.getVolume().getName().compareTo(b.getVolume().getName());
-            }
+            return _allTrees.indexOf(a) - _allTrees.indexOf(b);
         }
 
         @Override
@@ -182,51 +198,54 @@
     };
 
     private class Node implements Comparable<Node> {
-        final Volume _volume;
-        int _treeListIndex = -1;
-        Exchange _exchange = null;
-        Tree _currentTree = null;
-        Node _duplicate;
-
-        private Node(final Volume volume) {
-            _volume = volume;
-        }
-
-        private boolean next() throws PersistitException {
-            for (;;) {
-                if (_exchange == null) {
-                    _treeListIndex++;
-                    if (_treeListIndex >= _sortedTrees.size()) {
-                        _volume.close();
-                        return false;
-                    }
-                    final String tempTreeName = "_" + _sortedTrees.get(_treeListIndex).getHandle();
-                    final Tree sortTree = _volume.getTree(tempTreeName, false);
-                    if (sortTree == null) {
-                        continue;
-                    }
-                    _exchange = new Exchange(sortTree);
-                    _currentTree = _sortedTrees.get(_treeListIndex);
-                }
-                if (_exchange.next(true)) {
-                    return true;
-                }
-                _exchange = null;
-            }
+
+        private Tree _tree;
+        private Key _key;
+        private Value _value;
+        private Node _duplicate;
+        private final int _precedence;
+
+        private final File _file;
+        private StreamLoader _loader;
+        private Handler _handler;
+        private boolean _next;
+
+        private class Handler extends StreamLoader.ImportHandler {
+
+            private Handler(final Persistit persistit) {
+                super(persistit);
+            }
+
+            @Override
+            protected void handleDataRecord(final Key key, final Value value) throws PersistitException {
+                Node.this._tree = super._tree;
+                _key = key;
+                _value = value;
+                _next = true;
+            }
+        }
+
+        private File getFile() {
+            return _file;
+        }
+
+        private Node(final File file, final int index) {
+            _file = file;
+            _precedence = index;
         }
 
         @Override
         public int compareTo(final Node node) {
-            if (_exchange == null) {
-                return node._exchange == null ? 0 : -1;
-            }
-            final int treeComparison = getTreeComparator().compare(_currentTree, node._currentTree);
-            if (treeComparison != 0) {
-                return treeComparison;
-            }
-            final Key k1 = _exchange.getKey();
-            final Key k2 = node._exchange.getKey();
-            return k1.compareTo(k2);
+            if (_tree == null) {
+                return node._tree == null ? 0 : 1;
+            }
+            if (node._tree == null) {
+                return -1;
+            }
+            if (_tree != node._tree) {
+                return _allTrees.indexOf(_tree) - _allTrees.indexOf(node._tree);
+            } else
+                return _key.compareTo(node._key);
         }
 
         @Override
@@ -237,25 +256,67 @@
                 if (sb.length() > 0) {
                     sb.append(",");
                 }
-                if (n._exchange == null) {
-                    sb.append("<null>");
+                if (n._tree == null) {
+                    sb.append("<end>");
                 } else {
-                    sb.append("<"
-                            + (n._currentTree == null ? "?" : n._currentTree.getName() + n._exchange.getKey() + "="
-                                    + n._exchange.getValue()) + ">");
+                    sb.append("<" + (n._tree.getName() + n._key + "=" + n._value) + ">");
                 }
                 n = n._duplicate;
             }
             return sb.toString();
         }
+
+        private void createStreamLoader() throws Exception {
+            _loader = new StreamLoader(_persistit, new DataInputStream(new BufferedInputStream(new FileInputStream(
+                    _file), STREAM_SIZE)));
+            _handler = new Handler(_persistit);
+        }
+
+        private boolean next() throws Exception {
+            _next = false;
+            while (_loader.next(_handler) && !_next)
+                ;
+            if (!_next) {
+                _loader.close();
+            }
+            return _next;
+        }
+
+    }
+
+    private class SortStreamSaver extends StreamSaver {
+
+        Tree _sortTree = null;
+
+        SortStreamSaver(final Persistit persistit, final DataOutputStream stream) {
+            super(persistit, stream);
+        }
+
+        @Override
+        protected void writeData(final Exchange exchange) throws IOException {
+            if (exchange.getTree() != _sortTree) {
+                final Tree source = _sortTreeMap.get(exchange.getTree().getName());
+                if (_lastVolume != source.getVolume()) {
+                    writeVolumeInfo(source.getVolume());
+                    _lastVolume = source.getVolume();
+                }
+                if (_lastTree != source) {
+                    writeTreeInfo(source);
+                    _lastTree = source;
+                }
+            }
+            writeData(exchange.getKey(), exchange.getValue());
+            _recordCount++;
+        }
     }
 
     public TreeBuilder(final Persistit persistit) {
-        this(persistit, DEFAULT_NAME, -1, DEFAULT_BUFFER_POOL_FRACTION);
+        this(persistit, new SimpleDateFormat(SDF).format(new Date()), -1, DEFAULT_BUFFER_POOL_FRACTION);
     }
 
     public TreeBuilder(final Persistit persistit, final String name, final int pageSize, final float bufferPoolFraction) {
         _name = name;
+        _uniqueId = persistit.unique();
         _persistit = persistit;
         _pageSize = pageSize == -1 ? computePageSize(persistit) : pageSize;
         final int bufferCount = _persistit.getBufferPool(_pageSize).getBufferCount();
@@ -302,10 +363,10 @@
     }
 
     /**
-     * @return Count of sort volumes that have been created while sorting keys
+     * @return Count of sort trees that have been created while sorting keys
      */
-    public final synchronized int getSortVolumeCount() {
-        return _sortVolumes.size();
+    public final synchronized int getSortFileCount() {
+        return _sortFileIndex;
     }
 
     /**
@@ -326,10 +387,8 @@
      * @return List of destination
      *         <code>Tree<code> instances. This list is built as keys are stored.
      */
-    public final List<Tree> getTrees() {
-        final List<Tree> list = new ArrayList<Tree>();
-        list.addAll(_allTrees);
-        Collections.sort(list, getTreeComparator());
+    public synchronized final List<Tree> getTrees() {
+        final List<Tree> list = new ArrayList<Tree>(_allTrees);
         return list;
     }
 
@@ -394,7 +453,7 @@
             synchronized (this) {
                 _directories.clear();
                 _directories.addAll(directories);
-                _nextDirectoryIndex = 0;
+                _sortFileIndex = 0;
             }
         }
     }
@@ -402,9 +461,9 @@
     /**
      * 
      * @return List of directories set via the
-     *         {@link #setSortTreeDirectories(List)} method.
+     *         {@link #setSortFileDirectories(List)} method.
      */
-    public final List<File> getSortTreeDirectories() {
+    public final List<File> getSortFileDirectories() {
         return Collections.unmodifiableList(_directories);
     }
 
@@ -441,7 +500,10 @@
             ex = _persistit.getExchange(newSortVolume, tempTreeName, true);
             map.put(tree, ex);
             synchronized (this) {
-                _allTrees.add(tree);
+                if (!_allTrees.contains(tree)) {
+                    _allTrees.add(tree);
+                    _sortTreeMap.put(tempTreeName, tree);
+                }
             }
         }
         key.copyTo(ex.getKey());
@@ -466,8 +528,13 @@
     private void insertNode(final Map<Node, Node> sorted, final Node node) throws Exception {
         final Node other = sorted.put(node, node);
         if (other != null) {
-            if (!duplicateKeyDetected(node._currentTree, node._exchange.getKey(), other._exchange.getValue(),
-                    node._exchange.getValue())) {
+            final boolean reverse;
+            if (node._precedence < other._precedence) {
+                reverse = duplicateKeyDetected(node._tree, node._key, node._value, other._value);
+            } else {
+                reverse = !duplicateKeyDetected(node._tree, node._key, other._value, node._value);
+            }
+            if (reverse) {
                 sorted.put(node, other);
                 final Node p = other._duplicate;
                 other._duplicate = node;
@@ -485,17 +552,16 @@
      * @throws Exception
      */
     public synchronized void merge() throws Exception {
+        finishSortVolume();
         if ((_mergedKeyCount.get() % _reportKeyCountMultiple) != 0) {
             reportSorted(_mergedKeyCount.get());
         }
-        _sortedTrees.clear();
-        _sortedTrees.addAll(_allTrees);
         Tree currentTree = null;
         Exchange ex = null;
-        Collections.sort(_sortedTrees, getTreeComparator());
         final SortedMap<Node, Node> sorted = new TreeMap<Node, Node>();
-        for (final Volume volume : _sortVolumes) {
-            final Node node = new Node(volume);
+
+        for (final Node node : _sortNodes) {
+            node.createStreamLoader();
             if (node.next()) {
                 insertNode(sorted, node);
             }
@@ -507,18 +573,18 @@
             }
             Node node = sorted.firstKey();
             node = sorted.remove(node);
-            if (node._currentTree != currentTree) {
-                ex = new Exchange(node._currentTree);
-                currentTree = node._currentTree;
+            if (node._tree != currentTree) {
+                ex = new Exchange(node._tree);
+                currentTree = node._tree;
             }
+            node._key.copyTo(ex.getKey());
+            node._value.copyTo(ex.getValue());
 
-            node._exchange.getKey().copyTo(ex.getKey());
-            node._exchange.getValue().copyTo(ex.getValue());
             if (beforeMergeKey(ex)) {
                 ex.fetchAndStore();
                 boolean stored = true;
                 if (ex.getValue().isDefined()) {
-                    if (!duplicateKeyDetected(ex.getTree(), ex.getKey(), ex.getValue(), node._exchange.getValue())) {
+                    if (!duplicateKeyDetected(ex.getTree(), ex.getKey(), ex.getValue(), node._value)) {
                         ex.store();
                         stored = false;
                     }
@@ -547,21 +613,32 @@
 
     private synchronized void reset() throws Exception {
         Exception exception = null;
-        for (final Volume volume : _sortVolumes) {
+        try {
+            if (_sortVolume != null) {
+                _sortVolume.close();
+            }
+        } catch (final PersistitException e) {
+            if (exception == null) {
+                exception = e;
+            }
+        }
+
+        for (final Node node : _sortNodes) {
             try {
-                volume.close();
-            } catch (final PersistitException e) {
+                if (node.getFile() != null) {
+                    node.getFile().delete();
+                }
+            } catch (final Exception e) {
                 if (exception == null) {
                     exception = e;
                 }
             }
         }
-        _sortVolumes.clear();
-        _currentSortVolume = null;
-        _nextDirectoryIndex = 0;
-        _sortExchangeMapThreadLocal.get().clear();
         _allTrees.clear();
-        _sortedTrees.clear();
+        _sortNodes.clear();
+        _sortVolume = null;
+        _sortFileIndex = 0;
+        _sortExchangeMapThreadLocal.get().clear();
         if (exception != null) {
             throw exception;
         }
@@ -574,91 +651,115 @@
     }
 
     private synchronized Volume getSortVolume() throws Exception {
-        final boolean full = _currentSortVolume != null && _currentSortVolume.getNextAvailablePage() > _pageLimit;
-        if (full) {
-            if (beforeSortVolumeEvicted(_currentSortVolume)) {
-                _persistit.getBufferPool(_pageSize).evict(_currentSortVolume);
-            }
-            afterSortVolumeEvicted(_currentSortVolume);
-        }
-        if (full || _currentSortVolume == null) {
-            _currentSortVolume = createSortVolume();
-            _sortVolumes.add(_currentSortVolume);
-        }
-        return _currentSortVolume;
-    }
-
-    private Volume createSortVolume() throws Exception {
-        final File directory;
-        if (_directories.isEmpty()) {
-            final String directoryName = _persistit.getConfiguration().getTmpVolDir();
-            directory = directoryName == null ? null : new File(directoryName);
-        } else {
-            directory = _directories.get(_nextDirectoryIndex % _directories.size());
-            _nextDirectoryIndex++;
-        }
-        return Volume.createTemporaryVolume(_persistit, _pageSize, directory);
-    }
-
-    /**
-     * This method may be extended to provide an application-specific ordering
-     * on <code>Tree</code>s. This ordering determines the sequence in which
-     * destination trees are built from the sort data. By default trees are
-     * build in alphabetical order by volume and tree name. However, an
-     * application may choose a different order to ensure invariants for
-     * concurrent use.
-     * 
-     * @return a <code>java.util.Comparator</code> on <code>Tree</code>
-     */
-    protected Comparator<Tree> getTreeComparator() {
-        return _defaultTreeComparator;
+        if (_sortVolume != null && _sortVolume.getNextAvailablePage() > _pageLimit) {
+            finishSortVolume();
+        }
+        if (_sortVolume == null) {
+            final File directory;
+            if (_directories.isEmpty()) {
+                String directoryName = _persistit.getConfiguration().getTmpVolDir();
+                if (directoryName == null) {
+                    directoryName = System.getProperty("java.io.tmpdir");
+                }
+                directory = new File(directoryName);
+                if (!directory.exists()) {
+                    directory.mkdirs();
+                }
+                _directories.add(directory);
+            } else {
+                directory = _directories.get(_sortFileIndex % _directories.size());
+            }
+            _sortVolume = Volume.createTemporaryVolume(_persistit, _pageSize, directory);
+            _sortFile = new File(directory, String.format("%s_%d.%06d", _name, _uniqueId, _sortFileIndex));
+            final Node node = new Node(_sortFile, _sortFileIndex);
+            _sortNodes.add(node);
+            _sortFileIndex++;
+        }
+        return _sortVolume;
+    }
+
+    private void finishSortVolume() throws Exception {
+        if (_sortVolume != null) {
+            beforeSortVolumeClosed(_sortVolume, _sortFile);
+            saveSortVolume(_sortVolume, _sortFile);
+            afterSortVolumeClose(_sortVolume, _sortFile);
+            _sortVolume.close();
+            _sortVolume = null;
+        }
+    }
+
+    private void saveSortVolume(final Volume volume, final File file) throws Exception {
+        final DataOutputStream dos = new DataOutputStream(new BufferedOutputStream(new FileOutputStream(file),
+                STREAM_SIZE));
+        final List<Tree> sorted = new ArrayList<Tree>(_allTrees);
+        Collections.sort(sorted, getTreeComparator());
+        final StreamSaver saver = new SortStreamSaver(_persistit, dos);
+        for (final Tree tree : sorted) {
+            final String sortTreeName = "_" + tree.getHandle();
+            final Tree sortTree = volume.getTree(sortTreeName, false);
+            if (sortTree != null) {
+                final Exchange exchange = new Exchange(sortTree);
+                saver.save(exchange, null);
+            }
+        }
+        file.deleteOnExit();
+        dos.close();
     }
 
     /**
      * This method may be extended to provide application-specific behavior when
-     * a sort volume has been filled to capacity. The default implementation
-     * return <code>true</code>. If this method returns <code>true</code>,
-     * <code>TreeBuilder</code> evicts the <code>Volume</code> to avoid
-     * over-running the <code>BufferPool</code> and then starts a new sort tree
-     * if a new record is subsequently stored.
+     * a sort volume has been filled to capacity. Subsequent to this call, the
+     * sort volume is streamed to a sort file and then its pages in the
+     * <code>BufferPool</code> are invalidated to allow their immediate reuse.
      * 
      * @param volume
      *            The temporary <code>Volume</code> that has been filled
-     * @return <code>true</code> to cause the current sort volume to be evicted
-     *         from the <code>BufferPool</code>
+     * @param file
+     *            the file to which the sorted key-value pairs will be written
      * @throws Exception
      */
-    protected boolean beforeSortVolumeEvicted(final Volume volume) throws Exception {
-        return true;
+    protected void beforeSortVolumeClosed(final Volume volume, final File file) throws Exception {
+
     }
 
     /**
      * This method may be extended to provide application-specific reporting
      * functionality after a sort volume has been filled to capacity and has
      * been evicted. An application may also modify the temporary directory set
-     * via {@link #setSortTreeDirectories(List)} within this method if necessary
+     * via {@link #setSortFileDirectories(List)} within this method if necessary
      * to adjust disk space utilization, for example. The default behavior of
      * this method is to do nothing.
      * 
      * @param volume
      *            The temporary <code>Volume</code> that has been filled
+     * @param file
+     *            the file to which the sorted key-value pairs have been written
      * @throws Exception
      */
-    protected void afterSortVolumeEvicted(final Volume volume) throws Exception {
+    protected void afterSortVolumeClose(final Volume volume, final File file) throws Exception {
 
     }
 
     /**
+     * <p>
      * This method may be extended to provide application-specific behavior when
-     * an attempt is made to merge records with duplicate keys. The default
-     * behavior is to throw a {@link DuplicateKeyException}.
+     * an attempt is made to merge records with duplicate keys. The two
+     * <code>Value</code>s v1 and v2 are provided in the order they were
+     * inserted into the <code>TreeBuilder</code>. behavior is to write a
+     * warning to the log and retain the first value..
+     * </p>
      * 
      * @param tree
+     *            the <code>Tree</code> to which a key is being merged
      * @param key
+     *            the <code>Key</code>
      * @param v1
+     *            the <code>Value</code> previously inserted
      * @param v2
-     * @return If <code>true</code>, the resulting value is v2. If
-     *         <code>false</code>, the resulting value is v1.
+     *            the conflicting <code>Value</code>
+     * @return <code>true</code> to replace the value previously stored,
+     *         <code>false</code> to leave the value first inserted and ignore
+     *         the new value.
      * @throws DuplicateKeyException
      *             if a key being inserted or merged matches a key already
      *             exists
@@ -728,8 +829,23 @@
 
     }
 
-    void unitTestNextSortVolume() {
+    /**
+     * This method may be extended to provide an application-specific ordering
+     * on <code>Tree</code>s. This ordering determines the sequence in which
+     * destination trees are built from the sort data. By default trees are
+     * build in alphabetical order by volume and tree name. However, an
+     * application may choose a different order to ensure invariants for
+     * concurrent use.
+     * 
+     * @return a <code>java.util.Comparator</code> on <code>Tree</code>
+     */
+    protected Comparator<Tree> getTreeComparator() {
+        return _defaultTreeComparator;
+    }
+
+    void unitTestNextSortFile() throws Exception {
+        finishSortVolume();
         _sortExchangeMapThreadLocal.get().clear();
-        _currentSortVolume = null;
+        _sortVolume = null;
     }
 }

=== modified file 'src/test/java/com/persistit/TreeBuilderTest.java'
--- src/test/java/com/persistit/TreeBuilderTest.java	2012-12-31 21:03:59 +0000
+++ src/test/java/com/persistit/TreeBuilderTest.java	2013-01-28 10:44:23 +0000
@@ -1,5 +1,5 @@
 /**
- * Copyright © 2011-2012 Akiban Technologies, Inc.  All rights reserved.
+ * Copyright © 2011-2013 Akiban Technologies, Inc.  All rights reserved.
  * 
  * This program and the accompanying materials are made available
  * under the terms of the Eclipse Public License v1.0 which
@@ -17,21 +17,25 @@
 
 import static com.persistit.unit.UnitTestProperties.VOLUME_NAME;
 import static org.junit.Assert.assertEquals;
+import static org.junit.Assert.assertTrue;
 
+import java.io.File;
 import java.util.ArrayList;
 import java.util.Collections;
 import java.util.List;
+import java.util.Random;
 import java.util.concurrent.atomic.AtomicBoolean;
 import java.util.concurrent.atomic.AtomicInteger;
 
 import org.junit.Test;
 
+import com.persistit.unit.UnitTestProperties;
+
 public class TreeBuilderTest extends PersistitUnitTestCase {
-    private final static int COUNT = 10000;
-
-    @Test
-    public void basicTest() throws Exception {
-
+    private final static int COUNT = 100000;
+    private final AtomicInteger _duplicates = new AtomicInteger();
+
+    private TreeBuilder getBasicTreeBuilder() {
         final TreeBuilder tb = new TreeBuilder(_persistit) {
             @Override
             protected void reportSorted(final long count) {
@@ -43,8 +47,21 @@
                 System.out.println("Merged " + count);
             }
 
+            @Override
+            protected boolean duplicateKeyDetected(final Tree tree, final Key key, final Value v1, final Value v2) {
+                System.out.println("Duplicate key " + key);
+                _duplicates.incrementAndGet();
+                return false;
+            }
         };
         tb.setReportKeyCountMultiple(COUNT / 2);
+        return tb;
+    }
+
+    @Test
+    public void basicTest() throws Exception {
+
+        final TreeBuilder tb = getBasicTreeBuilder();
 
         final List<Integer> shuffled = new ArrayList<Integer>(COUNT);
         for (int i = 0; i < COUNT; i++) {
@@ -68,7 +85,6 @@
             tb.store(a);
             tb.store(b);
             tb.store(c);
-
         }
 
         tb.merge();
@@ -84,7 +100,8 @@
             count++;
         }
         assertEquals("Expect every key value", COUNT, count);
-
+        _persistit.flush();
+        assertEquals(0, a.getBufferPool().getDirtyPageCount());
     }
 
     @Test
@@ -130,7 +147,7 @@
         tb.store(ex);
         assertEquals("Should have registered a dup", 2, duplicateCount.get());
 
-        tb.unitTestNextSortVolume();
+        tb.unitTestNextSortFile();
 
         ex.to(1).getValue().put("ghi");
         tb.store(ex);
@@ -157,9 +174,9 @@
     }
 
     @Test
-    public void duplicatePriority() throws Exception {
-        final TreeBuilder tb = new TreeBuilder(_persistit) {
-
+    public void duplicatePriority1() throws Exception {
+        duplicatePriorityCheck(new TreeBuilder(_persistit) {
+            // Larger value wins
             @Override
             protected boolean duplicateKeyDetected(final Tree tree, final Key key, final Value v1, final Value v2) {
                 final String s1 = v1.getString();
@@ -167,16 +184,31 @@
                 return s1.compareTo(s2) < 0;
             }
 
-        };
+        }, "xuorcxq");
+    }
+
+    @Test
+    public void duplicatePriority2() throws Exception {
+        duplicatePriorityCheck(new TreeBuilder(_persistit) {
+            // First value wins
+            @Override
+            protected boolean duplicateKeyDetected(final Tree tree, final Key key, final Value v1, final Value v2) {
+                return false;
+            }
+
+        }, "xmnraxq");
+    }
+
+    private void duplicatePriorityCheck(final TreeBuilder tb, final String expected) throws Exception {
         final Exchange ex = _persistit.getExchange(VOLUME_NAME, "a", true);
         final String nul = null;
 
         insertKeys(ex, tb, "x", "m", "n", nul, "a", nul, "q");
-        tb.unitTestNextSortVolume();
+        tb.unitTestNextSortFile();
         insertKeys(ex, tb, nul, "t", "o", "r", nul, nul, nul);
-        tb.unitTestNextSortVolume();
+        tb.unitTestNextSortFile();
         insertKeys(ex, tb, nul, "u", "m", "j", "c", "x", "l");
-        tb.unitTestNextSortVolume();
+        tb.unitTestNextSortFile();
         insertKeys(ex, tb, nul, "m", nul, nul, "a", nul, "q");
 
         tb.merge();
@@ -188,7 +220,8 @@
                 result.append(ex.getValue().getString());
             }
         }
-        assertEquals("xuorcxq", result.toString());
+        assertEquals(expected, result.toString());
+
     }
 
     private void insertKeys(final Exchange ex, final TreeBuilder tb, final String... args) throws Exception {
@@ -200,4 +233,52 @@
         }
     }
 
+    @Test
+    public void multipleDirectories() throws Exception {
+        final TreeBuilder tb = getBasicTreeBuilder();
+        final List<File> directories = new ArrayList<File>();
+        final Random random = new Random();
+        try {
+            for (int i = 0; i < 3; i++) {
+                final File file = File.createTempFile("TreeBuilderTest", "");
+                file.delete();
+                assertTrue("Expect to make directory", file.mkdir());
+                directories.add(file);
+            }
+            tb.setSortTreeDirectories(directories);
+            final Exchange ex = _persistit.getExchange(VOLUME_NAME, "TreeBuilderTest", true);
+            for (int i = 0; i < COUNT; i++) {
+                final int k = random.nextInt();
+                ex.to(k);
+                ex.getValue().put(RED_FOX + "," + k);
+                tb.store(ex);
+                if (((i + 1) % (COUNT / 10)) == 0) {
+                    tb.unitTestNextSortFile();
+                }
+            }
+            for (final File file : directories) {
+                assertTrue("Expect some files in each directory", file.list().length > 0);
+            }
+            tb.merge();
+
+            for (final File file : directories) {
+                assertTrue("Expect no remaining files", file.list().length == 0);
+            }
+
+            ex.to(Key.BEFORE);
+            int count = 0;
+            while (ex.next()) {
+                count++;
+                final int k = ex.getKey().decodeInt();
+                assertEquals(RED_FOX + "," + k, ex.getValue().getString());
+            }
+            assert count + _duplicates.get() == COUNT;
+
+        } finally {
+            for (final File file : directories) {
+                UnitTestProperties.cleanUpDirectory(file);
+            }
+        }
+    }
+
 }

=== modified file 'src/test/java/com/persistit/stress/InsertBigLoad.java'
--- src/test/java/com/persistit/stress/InsertBigLoad.java	2013-01-04 00:16:13 +0000
+++ src/test/java/com/persistit/stress/InsertBigLoad.java	2013-01-28 10:44:23 +0000
@@ -21,6 +21,7 @@
 import com.persistit.TreeBuilder;
 import com.persistit.stress.unit.BigLoad;
 import com.persistit.stress.unit.BigLoad.BigLoadTreeBuilder;
+import com.persistit.util.Util;
 
 public class InsertBigLoad extends AbstractSuite {
 
@@ -54,7 +55,10 @@
 
         try {
             execute(persistit);
+            final long start = System.nanoTime();
             tb.merge();
+            final long elapsed = System.nanoTime() - start;
+            System.out.printf("Merge took %,dms", elapsed / Util.NS_PER_MS);
 
         } finally {
             persistit.close();

=== modified file 'src/test/java/com/persistit/stress/unit/BigLoad.java'
--- src/test/java/com/persistit/stress/unit/BigLoad.java	2013-01-04 00:16:13 +0000
+++ src/test/java/com/persistit/stress/unit/BigLoad.java	2013-01-28 10:44:23 +0000
@@ -15,6 +15,7 @@
 
 package com.persistit.stress.unit;
 
+import java.io.File;
 import java.util.Random;
 
 import com.persistit.Exchange;
@@ -23,6 +24,7 @@
 import com.persistit.Tree;
 import com.persistit.TreeBuilder;
 import com.persistit.Value;
+import com.persistit.Volume;
 import com.persistit.stress.AbstractStressTest;
 import com.persistit.util.ArgParser;
 import com.persistit.util.Util;
@@ -68,7 +70,7 @@
             tb.store(resultExchange);
         }
         final long endLoadTime = System.nanoTime();
-        System.out.printf("Loaded %,d records into %,d buckets in %,dms\n", totalRecords, tb.getSortVolumeCount(),
+        System.out.printf("Loaded %,d records into %,d buckets in %,dms\n", totalRecords, tb.getSortFileCount(),
                 (endLoadTime - startLoadTime) / Util.NS_PER_MS);
         return endLoadTime - startLoadTime;
     }
@@ -157,6 +159,11 @@
         }
 
         @Override
+        protected void beforeSortVolumeClosed(final Volume volume, final File file) {
+            System.out.printf("Saving sort volume %s to file %s\n", volume, file);
+        }
+
+        @Override
         protected void reportSorted(final long count) {
             System.out.printf("Sorted %,15d records\n", count);
         }