Lots of work on debugging diff xmit

2021-11-21 13:35:39 -05:00
parent 0881e33c6f
commit b19825aaca
23 changed files with 338 additions and 99 deletions
--- a/luprex/core/Makefile
+++ b/luprex/core/Makefile
@@ -4,6 +4,7 @@ CXX=g++ -std=c++17 -Wall -g -Iinc -Icpp
 CPP_FILES=\
 	cpp/invocation.cpp\
 	cpp/spookyv2.cpp\
+	cpp/debugcollector.cpp\
 	cpp/drivenengine.cpp\
 	cpp/driver-mingw.cpp\
 	cpp/util.cpp\
--- a/luprex/core/cpp/animqueue.cpp
+++ b/luprex/core/cpp/animqueue.cpp
@@ -463,23 +463,29 @@ void AnimQueue::deserialize(StreamBuffer *sb) {
    version_number_ = 0;
 }

-bool AnimQueue::need_patch(const AnimQueue &auth) const {
-    // Sanity check.
+bool AnimQueue::version_identical(const AnimQueue &auth) const {
+    return version_number_ == auth.version_number_;
+}
+
+bool AnimQueue::diff(const AnimQueue &auth, StreamBuffer *sb) const {
    assert(valid());
    assert(auth.valid());

-    // Fast path to detect equivalence.
-    if (version_number_ == auth.version_number_) {
+    // Fast path to equivalence detection
+    if (version_identical(auth)) {
+        assert(size_and_steps_equal(auth));
+        sb->write_uint8(255);
        return false;
    }

-    // Otherwise, do a direct comparison.
-    return !size_and_steps_equal(auth);
-}
+    // Another path to equivalence detection
+    if (size_and_steps_equal(auth)) {
+        sb->write_uint8(255);
+        return false;
+    }

-
-void AnimQueue::diff(const AnimQueue &auth, StreamBuffer *sb) const {
    // Write the first element.
+    assert(auth.steps_.size() < 255);
    sb->write_uint8(auth.steps_.size());
    sb->write_uint8(auth.size_limit_);
    const AnimStep &first = auth.steps_[0];
@@ -517,10 +523,16 @@ void AnimQueue::diff(const AnimQueue &auth, StreamBuffer *sb) const {
            }
        }
    }
+    return true;
 }

-void AnimQueue::patch(StreamBuffer *sb) {
+void AnimQueue::patch(StreamBuffer *sb, DebugCollector *dbc) {
    int len = sb->read_uint8();
+    if (len == 255) {
+        return;
+    }
+    DebugLine(dbc) << "AnimQueue modified";
+
    size_limit_ = sb->read_uint8();
    // Decode the diff, stop at eof.
    std::deque<AnimStep> old = std::move(steps_);
@@ -557,7 +569,7 @@ const AnimStep &AnimQueue::back() const {
 static bool diff_works(const AnimQueue &master, AnimQueue &sync) {
    StreamBuffer sb;
    sync.diff(master, &sb);
-    sync.patch(&sb);
+    sync.patch(&sb, nullptr);
    return sync.size_and_steps_equal(master);
 }

@@ -658,7 +670,8 @@ LuaDefine(unittests_animqueue, "c") {
    LuaAssert(L, diff_works(aq, aqds));

    // compare again, should be no differences.
-    LuaAssert(L, !aqds.need_patch(aq));
+    LuaAssert(L, aqds.version_identical(aq));
+    LuaAssert(L, aqds.size_and_steps_equal(aq));
    LuaAssert(L, diff_works(aq, aqds));

    // Discard all but the last action.
--- a/luprex/core/cpp/animqueue.hpp
+++ b/luprex/core/cpp/animqueue.hpp
@@ -52,6 +52,7 @@
 #include <ostream>
 #include <unordered_map>
 #include "streambuffer.hpp"
+#include "debugcollector.hpp"
 #include "util.hpp"


@@ -174,6 +175,7 @@ public:
    size_t size() const { return steps_.size(); }
    int32_t size_limit() const { return size_limit_; }
    int64_t version_number() const { return version_number_; }
+    bool version_identical(const AnimQueue &aq) const;

    // Return true if the size limit and steps are identical.
    bool size_and_steps_equal(const AnimQueue &aq) const;
@@ -193,9 +195,8 @@ public:
    void deserialize(StreamBuffer *sb);

    // Difference transmission
-    bool need_patch(const AnimQueue &auth) const;
-    void diff(const AnimQueue &auth, StreamBuffer *sb) const;
-    void patch(StreamBuffer *sb);
+    bool diff(const AnimQueue &auth, StreamBuffer *sb) const;
+    void patch(StreamBuffer *sb, DebugCollector *dbc);
    void update_version(const AnimQueue &auth);
    
    // Get the final resting place after all animations are complete.
--- a/luprex/core/cpp/debugcollector.cpp
+++ b/luprex/core/cpp/debugcollector.cpp
@@ -0,0 +1,87 @@
+
+#include "debugcollector.hpp"
+#include <algorithm>
+#include <cstring>
+#include "util.hpp"
+
+void DebugCollector::flush() {
+    if (need_flush_) {
+        std::string str = oss_.str();
+        if (!str.empty()) {
+            if (is_regular_) n_regular_ += 1;
+            lines_.push_back(str);
+            oss_.str("");
+        }
+        need_flush_ = false;
+    }
+}
+
+DebugCollector::DebugCollector() : n_regular_(0), need_flush_(false), is_regular_(true), active_(false) {
+}
+
+DebugCollector::DebugCollector(const std::string &targets) 
+    : n_regular_(0), need_flush_(false), is_regular_(true), active_(false) {
+    targets_ = util::split(targets, ',');
+    std::sort(targets_.begin(), targets_.end());
+}
+
+bool DebugCollector::use(const char *target) {
+    int lo = 0;
+    int hi = targets_.size();
+    while (hi > lo) {
+        int mid = (hi + lo) >> 1;
+        int cmp = strcmp(targets_[mid].c_str(), target);
+        if (cmp == 0) return true;
+        if (cmp > 0) hi = mid;
+        else lo = mid + 1;
+    }
+    return false;
+}
+
+bool DebugCollector::do_line() {
+    if (active_) {
+        flush();
+        need_flush_ = true;
+        is_regular_ = true;
+        return true;
+    } else return false;
+}
+
+bool DebugCollector::do_header() {
+    flush();
+    need_flush_ = true;
+    is_regular_ = false;
+    return true;
+}
+
+void DebugCollector::dump(std::ostream &os) {
+    flush();
+    for (const std::string &line : lines_) {
+        os << line << std::endl;
+    }
+}
+
+DebugBlock::DebugBlock(DebugCollector *dbc, const char *target) {
+    dbc_ = dbc;
+    if (dbc) {
+        n_regular_ = dbc->n_regular_;
+        n_lines_ = dbc->lines_.size();
+        active_ = (!dbc->active_) && (dbc->use(target));
+        if (active_) dbc_->active_ = true;
+    }
+}
+
+DebugBlock::~DebugBlock() {
+    if (dbc_) {
+        dbc_->flush();
+        // If no regular lines have been added,
+        // remove all header lines that were added.
+        if (dbc_->n_regular_ == n_regular_) {
+            if (dbc_->lines_.size() != n_lines_) {
+                dbc_->lines_.resize(n_lines_);
+            }
+        }
+        if (active_) dbc_->active_ = false;
+    }
+}
+
--- a/luprex/core/cpp/debugcollector.hpp
+++ b/luprex/core/cpp/debugcollector.hpp
@@ -0,0 +1,50 @@
+#ifndef DEBUGCOLLECTOR_HPP
+#define DEBUGCOLLECTOR_HPP
+
+#include <vector>
+#include <string>
+#include <memory>
+#include <ostream>
+#include <sstream>
+
+class DebugCollector {
+private:
+    // At any given time, the stringstream may contain one
+    // extra line that hasn't yet been appended to the list of lines.
+    // The flag 'need_flush_' is true if the stringstream contains
+    // an extra line.  In that case, is_regular_ indicates whether
+    // the extra line is a header or a regular line.
+    std::vector<std::string> lines_;
+    std::vector<std::string> targets_;
+    int n_regular_;
+    bool need_flush_;
+    bool is_regular_;
+    bool active_;
+    void flush();
+    bool use(const char *target);
+public:
+    std::ostringstream oss_;
+    DebugCollector();
+    DebugCollector(const std::string &targets);
+    bool do_header();
+    bool do_line();
+    void dump(std::ostream &os);
+    friend class DebugBlock;
+};
+
+class DebugBlock {
+private:
+    DebugCollector *dbc_;
+    int n_regular_;
+    size_t n_lines_;
+    bool active_;
+public:
+    DebugBlock(DebugCollector *dbc, const char *target);
+    ~DebugBlock();
+};
+
+#define DebugHeader(dbc) if (((dbc)!=nullptr) && (dbc)->do_header()) ((dbc)->oss_)
+#define DebugLine(dbc) if (((dbc)!=nullptr) && (dbc)->do_line()) ((dbc)->oss_)
+
+#endif // DEBUGCOLLECTOR_HPP
+
--- a/luprex/core/cpp/idalloc.cpp
+++ b/luprex/core/cpp/idalloc.cpp
@@ -182,7 +182,14 @@ void IdPlayerPool::diff(const IdPlayerPool &auth, StreamBuffer *sb) const {
    assert(valid());
    assert(auth.valid());

+    // Special case: there's nothing to fix.
+    if (exactly_equal(auth)) {
+        sb->write_uint8(255);
+        return;
+    }
+
    // Write the fifo capacity and nranges
+    assert(auth.fifo_capacity_ != 255);
    sb->write_uint8(auth.fifo_capacity_);
    sb->write_uint8(auth.ranges_.size());
    
@@ -206,9 +213,14 @@ void IdPlayerPool::diff(const IdPlayerPool &auth, StreamBuffer *sb) const {
    }
 }

-void IdPlayerPool::patch(StreamBuffer *sb) {
+void IdPlayerPool::patch(StreamBuffer *sb, DebugCollector *dbc) {
    // read the header byte
    int fifo_cap = sb->read_uint8();
+    // If the fifo_cap is 255, it means there's nothing to fix.
+    if (fifo_cap == 255) {
+        return;
+    }
+    DebugLine(dbc) << "IdPlayerPool modified";
    fifo_capacity_ = fifo_cap;
    int nranges = sb->read_uint8();
    std::deque<int64_t> old = std::move(ranges_);
@@ -381,7 +393,7 @@ LuaDefine(unittests_idalloc, "c") {
    // Check case: no differences.
    sb.clear();
    ppds.diff(pp, &sb);
-    ppds.patch(&sb);
+    ppds.patch(&sb, nullptr);
    LuaAssert(L, ppds.exactly_equal(pp));

    // Add some values to master pool
@@ -391,7 +403,7 @@ LuaDefine(unittests_idalloc, "c") {
    // transmit and compare.
    sb.clear();
    ppds.diff(pp, &sb);
-    ppds.patch(&sb);
+    ppds.patch(&sb, nullptr);
    LuaAssert(L, ppds.exactly_equal(pp));

    // Pop a value from master pool
@@ -401,7 +413,7 @@ LuaDefine(unittests_idalloc, "c") {
    // transmit and compare.
    sb.clear();
    ppds.diff(pp, &sb);
-    ppds.patch(&sb);
+    ppds.patch(&sb, nullptr);
    LuaAssert(L, ppds.exactly_equal(pp));

    return 0;
--- a/luprex/core/cpp/idalloc.hpp
+++ b/luprex/core/cpp/idalloc.hpp
@@ -70,6 +70,7 @@
 #include <deque>
 #include "luastack.hpp"
 #include "streambuffer.hpp"
+#include "debugcollector.hpp"

 class IdGlobalPool {
 public:
@@ -165,7 +166,7 @@ public:
    // Difference transmission
    //
    void diff(const IdPlayerPool &auth, StreamBuffer *sb) const;
-    void patch(StreamBuffer *sb);
+    void patch(StreamBuffer *sb, DebugCollector *dbc);

    // Debug string.
    std::string debug_string() const;
--- a/luprex/core/cpp/lpxclient.cpp
+++ b/luprex/core/cpp/lpxclient.cpp
@@ -163,8 +163,10 @@ public:
    void receive_diff_from_server(StreamBuffer *sb) {
        world_to_synchronous();
        try {
-            int64_t nactor = world_->patch_everything(sb);
+            DebugCollector dbc("patch_everything");
+            int64_t nactor = world_->patch_everything(sb, &dbc);
            if (nactor != actor_id_) change_actor_id(nactor);
+            dbc.dump(stdostream());
        } catch (const StreamEof &seof) {
            abandon_server();
            return;
--- a/luprex/core/cpp/lpxserver.cpp
+++ b/luprex/core/cpp/lpxserver.cpp
@@ -29,6 +29,9 @@ public:
        // Create the master world model.
        master_.reset(new World(util::WORLD_TYPE_MASTER));

+        // Update the source code of the master model.
+        master_->update_source(get_lua_source());
+
        // Create an actor for administrative commands.
        admin_id_ = master_->create_login_actor();

--- a/luprex/core/cpp/luaconsole.cpp
+++ b/luprex/core/cpp/luaconsole.cpp
@@ -145,7 +145,7 @@ void LuaConsole::add(std::string line) {
        }
    } else {
        words_.push_back("lua");
-        words_.push_back(partial);
+        words_.push_back(util::rtrim(partial));
        clear_raw_input();
    }
    lua_settop(lua_state_, top);
--- a/luprex/core/cpp/printbuffer.cpp
+++ b/luprex/core/cpp/printbuffer.cpp
@@ -64,8 +64,6 @@ void PrintBuffer::clear() {
    }
 }

-
-
 static int first_line_len(const char *text, int len) {
    for (int i = 0; i < len; i++) {
        if (text[i] == '\n') return i;
@@ -157,11 +155,14 @@ void PrintBuffer::diff(const PrintBuffer &auth, StreamBuffer *sb) const {
    }
 }

-void PrintBuffer::patch(StreamBuffer *sb) {
+void PrintBuffer::patch(StreamBuffer *sb, DebugCollector *dbc) {
+    DebugBlock dbb(dbc, "PrintBuffer::patch");
    if (core_ == &shared_core) core_ = new PrintBufferCore;
    int auth_first = sb->read_int32();
    int auth_last = sb->read_int32();
    core_->lines_.resize(core_->first_unchecked_ - core_->first_line_);
+    int nlines = auth_last - core_->first_unchecked_;
+    if (nlines > 0) DebugLine(dbc) << "PrintBuffer received " << nlines << " lines.";
    for (int i = core_->first_unchecked_; i < auth_last; i++) {
        core_->lines_.emplace_back(sb->read_string());
    }
@@ -238,29 +239,29 @@ LuaDefine(unittests_printbuffer, "c") {
    sb.clear();
    pbm.add_string("foo\nbar\n", true);
    pbs.diff(pbm, &sb);
-    pbs.patch(&sb);
+    pbs.patch(&sb, nullptr);
    LuaAssertStrEq(L, pbs.debug_string(), "0,2:foo;bar;");
    pbm.clear();
    pbm.add_string("foo\nyow\nding\ndong\n", true);
    pbs.diff(pbm, &sb);
-    pbs.patch(&sb);
+    pbs.patch(&sb, nullptr);
    LuaAssertStrEq(L, pbs.debug_string(), "0,4:foo;bar;ding;dong;");
    pbs.discard_upto(2);
    LuaAssertStrEq(L, pbs.debug_string(), "2,4:ding;dong;");
    pbs.diff(pbm, &sb);
-    pbs.patch(&sb);
+    pbs.patch(&sb, nullptr);
    LuaAssertStrEq(L, pbs.debug_string(), "2,4:ding;dong;");
    pbs.add_string("boy\nhowdy\n", false);
    LuaAssertStrEq(L, pbs.debug_string(), "2,4:ding;dong;boy;howdy;");
    pbs.diff(pbm, &sb);
-    pbs.patch(&sb);
+    pbs.patch(&sb, nullptr);
    LuaAssertStrEq(L, pbs.debug_string(), "2,4:ding;dong;");
    pbs.add_string("boy\nhowdy\nyeah\nbaby\nget\ndown\n", false);
    LuaAssertStrEq(L, pbs.debug_string(), "2,4:ding;dong;boy;howdy;yeah;baby;get;down;");
    pbs.discard_upto(5);
    LuaAssertStrEq(L, pbs.debug_string(), "5,5:howdy;yeah;baby;get;down;");
    pbs.diff(pbm, &sb);
-    pbs.patch(&sb);
+    pbs.patch(&sb, nullptr);
    LuaAssertStrEq(L, pbs.debug_string(), "5,5:");
    

--- a/luprex/core/cpp/printbuffer.hpp
+++ b/luprex/core/cpp/printbuffer.hpp
@@ -80,6 +80,7 @@
 #include "streambuffer.hpp"
 #include "util.hpp"
 #include "invocation.hpp"
+#include "debugcollector.hpp"
 #include <deque>
 #include <string>
 #include <memory>
@@ -132,7 +133,7 @@ public:

    // Difference transmission
    void diff(const PrintBuffer &auth, StreamBuffer *sb) const;
-    void patch(StreamBuffer *sb);
+    void patch(StreamBuffer *sb, DebugCollector *dbc);
 };


--- a/luprex/core/cpp/source.cpp
+++ b/luprex/core/cpp/source.cpp
@@ -172,7 +172,7 @@ void SourceDB::diff(const SourceDB &auth, StreamBuffer *sb) {
    SLS.result();
 }

-bool SourceDB::patch(StreamBuffer *sb) {
+bool SourceDB::patch(StreamBuffer *sb, DebugCollector *dbc) {
    lua_State *L = lua_state_;
    LuaVar db, info;
    LuaStack LS(L, db, info);
@@ -182,6 +182,7 @@ bool SourceDB::patch(StreamBuffer *sb) {
        std::string fn = sb->read_string();
        int sequence = sb->read_int32();
        std::string code = sb->read_string();
+        DebugLine(dbc) << "Source file " << fn << " updated";
        if (sequence < 0) {
            LS.rawset(db, fn, LuaNil);
        } else {
@@ -494,7 +495,7 @@ LuaDefine(unittests_sourcedb, "c") {
    LuaAssertStrEq(L, sdb.get("baz"), "<nonexistent>");

    // Apply the diffs.
-    sdb.patch(&sb);
+    sdb.patch(&sb, nullptr);

    // Everything should now be copied to sdb.
    LuaAssertStrEq(L, sdb.get("foo"), "1:function foo() print('foo') end:<function>");
@@ -507,7 +508,7 @@ LuaDefine(unittests_sourcedb, "c") {

    // Diff and patch
    sdb.diff(mdb, &sb);
-    sdb.patch(&sb);
+    sdb.patch(&sb, nullptr);

    // Verify that it's been updated.
    LuaAssertStrEq(L, sdb.get("foo"), "1:function foo() print('foo') end:<function>");
@@ -531,7 +532,7 @@ LuaDefine(unittests_sourcedb, "c") {
    LuaAssert(L, sb.fill() == 14);

    // Patch.
-    sdb.patch(&sb);
+    sdb.patch(&sb, nullptr);

    // Verify that it's been updated.
    LuaAssertStrEq(L, sdb.get("foo"), "6:function foo() print('foo') end:<function>");
--- a/luprex/core/cpp/source.hpp
+++ b/luprex/core/cpp/source.hpp
@@ -122,6 +122,7 @@

 #include "luastack.hpp"
 #include "streambuffer.hpp"
+#include "debugcollector.hpp"

 class SourceDB {
 private:
@@ -155,7 +156,7 @@ public:
    // The patch routine returns true if anything was modified.
    //
    void diff(const SourceDB &auth, StreamBuffer *sb);
-    bool patch(StreamBuffer *sb);
+    bool patch(StreamBuffer *sb, DebugCollector *dbc);

    // run_unittests
    //
--- a/luprex/core/cpp/util.cpp
+++ b/luprex/core/cpp/util.cpp
@@ -388,7 +388,7 @@ LuaDefine(unittests_util, "c") {
    // Test hash_to_string
    LuaAssertStrEq(L, util::hash_to_hex(util::HashValue(0x1234,0x789a)),
        "0000000000001234000000000000789a");
-
+    
    return 0;
 }

--- a/luprex/core/cpp/util.hpp
+++ b/luprex/core/cpp/util.hpp
@@ -31,6 +31,7 @@ enum MessageType {

 using StringVec = std::vector<std::string>;
 using StringPair = std::pair<std::string, std::string>;
+using StringSet = std::set<std::string>;
 using LuaSourceVec = std::vector<StringPair>;
 using LuaSourcePtr = std::unique_ptr<LuaSourceVec>;
 using HashValue = std::pair<uint64_t, uint64_t>;
@@ -127,6 +128,12 @@ class hex32 {};
 class hex16 {};
 class hex8 {};

+class NullStreamBuffer : public std::streambuf
+{
+public:
+  int overflow(int c) { return c; }
+};
+
 } // namespace util

 std::ostream &operator<<(std::ostream &oss, const util::hex64 &v);
--- a/luprex/core/cpp/world-accessor.cpp
+++ b/luprex/core/cpp/world-accessor.cpp
@@ -182,6 +182,18 @@ LuaDefine(world_wait, "f") {
    return lua_yield(L, 1);
 }

+LuaDefine(tangible_nopredict, "c") {
+    if (lua_gettop(L) != 0) {
+        luaL_error(L, "tangible.nopredict takes no arguments");
+    }
+    World *w = World::fetch_global_pointer(L);
+    if (util::world_type_authoritative(w->world_type_)) {
+        return 0;
+    } else {
+        return lua_yield(L, 0);
+    }
+}
+
 LuaDefine(world_getregistry, "f") {
    lua_pushvalue(L, LUA_REGISTRYINDEX);
    return 1;
--- a/luprex/core/cpp/world-core.cpp
+++ b/luprex/core/cpp/world-core.cpp
@@ -586,11 +586,13 @@ void World::run_scheduled_threads(int64_t clk) {
        
        // Three possible outcomes: finished, yielded, or errored.
        if (status == LUA_YIELD) {
-            // When the wait statement yields, it yields the desired timestamp.
-            if ((lua_gettop(CO) != 1) || (!lua_isnumber(CO, 1))) {
-                std::cerr << "Thread yielded incorrectly.  Killing it." << std::endl;
+            // If there's nothing on the stack, infer that tangible.nopredict yielded.
+            if (lua_gettop(CO) == 0) {
+                std::cerr << "Thread killed self using tangible.nopredict" << std::endl;
                LS.rawset(threads, sched.thread_id(), LuaNil);
-            } else {
+            }
+            // If there's a single number on the stack, infer that 'wait' yielded.
+            else if ((lua_gettop(CO) == 1) && (lua_isnumber(CO, 1))) {
                lua_Number delay = lua_tonumber(CO, 1);
                lua_settop(CO, 0);
                LS.rawset(thinfo, "isnew", false);
@@ -599,6 +601,11 @@ void World::run_scheduled_threads(int64_t clk) {
                thread_sched_.add(sched.clock() + int64_t(delay), sched.thread_id(), sched.place_id());
                std::cerr << "Added to schedule." << std::endl;
            }
+            // In any other case, generate an error and kill the coroutine.
+            else {
+                std::cerr << "Thread yielded incorrectly.  Killing it." << std::endl;
+                LS.rawset(threads, sched.thread_id(), LuaNil);
+            }
        } else if (status == LUA_OK) {
            // Successfully ran to completion.  Remove from thread table.
            std::cerr << "Thread ran to completion." << std::endl;
--- a/luprex/core/cpp/world-difftab.cpp
+++ b/luprex/core/cpp/world-difftab.cpp
@@ -247,31 +247,42 @@ static std::string diff_tables_debug_string(StreamBuffer *sb) {
    return oss.str();
 }

-static void set_transmitted_value(LuaStack &LS, LuaSlot tangibles, LuaSlot ntmap, LuaSlot target, StreamBuffer *sb) {
+static void set_transmitted_value(LuaStack &LS, LuaSlot tangibles, LuaSlot ntmap, LuaSlot target, StreamBuffer *sb, const char *dbinfo, DebugCollector *dbc) {
    int kind = sb->read_uint8();
    switch (kind) {
    case LUA_TBOOLEAN: {
-        LS.set(target, sb->read_bool());
+        bool value = sb->read_bool();
+        DebugLine(dbc) << dbinfo << (value ? "true" : "false"); 
+        LS.set(target, value);
        return;
    }
    case LUA_TNUMBER: {
-        LS.set(target, sb->read_double());
+        double value = sb->read_double();
+        DebugLine(dbc) << dbinfo << value;
+        LS.set(target, value);
        return;
    }
    case LUA_TSTRING: {
-        LS.set(target, sb->read_string());
+        std::string value = sb->read_string();
+        DebugLine(dbc) << dbinfo << "'" << value << "'";
+        LS.set(target, value);
        return;
    }
    case LUA_TT_GENERAL: {
-        LS.rawget(target, ntmap, sb->read_int32());
+        int index = sb->read_int32();
+        DebugLine(dbc) << dbinfo << "table " << index;
+        LS.rawget(target, ntmap, index);
        return;
    }
    case LUA_TT_CLASS: {
-        LS.makeclass(target, sb->read_string());
+        std::string value = sb->read_string();
+        DebugLine(dbc) << dbinfo << "class " << value;
+        LS.makeclass(target, value);
        return;
    }
    case LUA_TT_TANGIBLE: {
        int64_t id = sb->read_int64();
+        DebugLine(dbc) << dbinfo << "tan " << id;
        LS.rawget(target, tangibles, id);
        if (LS.isnil(target)) {
            World *w = World::fetch_global_pointer(LS.state());
@@ -281,10 +292,12 @@ static void set_transmitted_value(LuaStack &LS, LuaSlot tangibles, LuaSlot ntmap
        return;
    }
    case LUA_TT_GLOBALENV: {
+        DebugLine(dbc) << dbinfo << "global env";
        LS.getglobaltable(target);
        return;
    }
    case LUA_TNIL: {
+        DebugLine(dbc) << dbinfo << "nil";
        LS.set(target, LuaNil);
        return;
    }
@@ -293,13 +306,13 @@ static void set_transmitted_value(LuaStack &LS, LuaSlot tangibles, LuaSlot ntmap
    }
 }

-static void patch_table(LuaStack &LS0, LuaSlot tangibles, LuaSlot ntmap, LuaSlot tab, StreamBuffer *sb) {
+static void patch_table(LuaStack &LS0, LuaSlot tangibles, LuaSlot ntmap, LuaSlot tab, StreamBuffer *sb, DebugCollector *dbc) {
    LuaVar key, val;
    LuaStack LS(LS0.state(), key, val);
    int ndiffs = sb->read_int32();
    for (int i = 0; i < ndiffs; i++) {
-        set_transmitted_value(LS, tangibles, ntmap, key, sb);
-        set_transmitted_value(LS, tangibles, ntmap, val, sb);
+        set_transmitted_value(LS, tangibles, ntmap, key, sb, "key=", dbc);
+        set_transmitted_value(LS, tangibles, ntmap, val, sb, "val=", dbc);
        if (LS.isnil(key)) {
            LS.setmetatable(tab, val);
        } else {
@@ -309,7 +322,7 @@ static void patch_table(LuaStack &LS0, LuaSlot tangibles, LuaSlot ntmap, LuaSlot
    LS.result();
 }

-void World::patch_numbered_tables(StreamBuffer *sb) {
+void World::patch_numbered_tables(StreamBuffer *sb, DebugCollector *dbc) {
    lua_State *L = state();
    LuaVar tangibles, ntmap, tab;
    LuaStack LS(L, tangibles, ntmap, tab);
@@ -323,7 +336,8 @@ void World::patch_numbered_tables(StreamBuffer *sb) {
        int index = sb->read_int32();
        LS.rawget(tab, ntmap, index);
        assert(LS.istable(tab));
-        patch_table(LS, tangibles, ntmap, tab, sb);
+        DebugHeader(dbc) << "Lua Table " << index << ":";
+        patch_table(LS, tangibles, ntmap, tab, sb, dbc);
    }
    LS.result();
 }
@@ -367,7 +381,7 @@ void World::diff_numbered_tables(lua_State *master, StreamBuffer *sb) {
    MLS.result();
 }

-void World::patch_tangible_databases(StreamBuffer *sb) {
+void World::patch_tangible_databases(StreamBuffer *sb, DebugCollector *dbc) {
    lua_State *L = state();
    LuaVar tangibles, ntmap, tab;
    LuaStack LS(L, tangibles, ntmap, tab);
@@ -381,7 +395,8 @@ void World::patch_tangible_databases(StreamBuffer *sb) {
        int64_t id = sb->read_int64();
        LS.rawget(tab, tangibles, id);
        assert(LS.istable(tab));
-        patch_table(LS, tangibles, ntmap, tab, sb);
+        DebugHeader(dbc) << "Tangible DB " << id << ":";
+        patch_table(LS, tangibles, ntmap, tab, sb, dbc);
    }
    LS.result();
 }
@@ -483,7 +498,7 @@ LuaDefine(table_diffapply, "c") {
    StreamBuffer sb;
    diff_tables(SLS, stnmap, stab, MLS, mtnmap, mtab, true, &sb);

-    patch_table(MLS, tangibles, mntmap, mstab, &sb);
+    patch_table(MLS, tangibles, mntmap, mstab, &sb, nullptr);

    bool eq = table_equal(MLS, mstab, mtab);
    MLS.set(eql, eq);
--- a/luprex/core/cpp/world-diffxmit.cpp
+++ b/luprex/core/cpp/world-diffxmit.cpp
@@ -7,18 +7,21 @@ util::IdVector World::get_visible_union(int64_t actor_id, World *master) {
            get_near_unsorted(actor_id, RadiusVisibility, true));
 }

-int64_t World::patch_actor(StreamBuffer *sb) {
+int64_t World::patch_actor(StreamBuffer *sb, DebugCollector *dbc) {
+    DebugBlock dbb(dbc, "patch_actor");
    int64_t actor_id = sb->read_int64();
    Tangible *s_actor = tangible_get(actor_id);
    if (s_actor == nullptr) {
+        DebugLine(dbc) << "create new actor " << actor_id;
        s_actor = tangible_make(nullptr, actor_id, "", false);
        s_actor->id_player_pool_.deserialize(sb);
        s_actor->anim_queue_.deserialize(sb);
        s_actor->print_buffer_.deserialize(sb);
    } else {
-        s_actor->id_player_pool_.patch(sb);
-        s_actor->anim_queue_.patch(sb);
-        s_actor->print_buffer_.patch(sb);
+        DebugHeader(dbc) << "patching actor " << actor_id << ":";
+        s_actor->id_player_pool_.patch(sb, dbc);
+        s_actor->anim_queue_.patch(sb, dbc);
+        s_actor->print_buffer_.patch(sb, dbc);
    }
    s_actor->update_plane_item();
    return actor_id;
@@ -46,15 +49,17 @@ void World::diff_actor(int64_t actor_id, World *master, StreamBuffer *xsb) {

    // Forward to client, and apply to server-synchronous.
    tsb.copy_into(xsb);
-    patch_actor(&tsb);
+    patch_actor(&tsb, nullptr);
    assert(tsb.empty());
 }

-void World::patch_visible(StreamBuffer *sb) {
+void World::patch_visible(StreamBuffer *sb, DebugCollector *dbc) {
+    DebugBlock dbb(dbc, "patch_visible");
    // Receive create messages.
    int count = sb->read_int32();
    for (int i = 0; i < count; i++) {
        int64_t id = sb->read_int64();
+        DebugLine(dbc) << "patch_visible create tan " << id;
        Tangible *t = tangible_make(state(), id, "", false);
        t->anim_queue_.deserialize(sb);
        t->update_plane_item();
@@ -64,6 +69,7 @@ void World::patch_visible(StreamBuffer *sb) {
    count = sb->read_int32();
    for (int i = 0; i < count; i++) {
        int64_t id = sb->read_int64();
+        DebugLine(dbc) << "patch_visible delete tan " << id;
        tangible_delete(id);
    }

@@ -71,9 +77,10 @@ void World::patch_visible(StreamBuffer *sb) {
    count = sb->read_int32();
    for (int i = 0; i < count; i++) {
        int64_t id = sb->read_int64();
+        DebugLine(dbc) << "patch_visible animqueue tan " << id;
        Tangible *t = tangible_get(id);
        assert(t != nullptr);
-        t->anim_queue_.patch(sb);
+        t->anim_queue_.patch(sb, dbc);
    }
 }

@@ -126,10 +133,12 @@ void World::diff_visible(const util::IdVector &visible, World *master, StreamBuf
        const Tangible *mt = mvis[i];
        const Tangible *st = svis[i];
        if ((mt != nullptr) && (st != nullptr)) {
-            if (st->anim_queue_.need_patch(mt->anim_queue_)) {
+            int64_t unwind = tsb.total_writes();
+            tsb.write_int64(st->id());
+            if (st->anim_queue_.diff(mt->anim_queue_, &tsb)) {
                count++;
-                tsb.write_int64(st->id());
-                st->anim_queue_.diff(mt->anim_queue_, &tsb);
+            } else {
+                tsb.unwrite_to(unwind);
            }
        }
    }
@@ -137,7 +146,7 @@ void World::diff_visible(const util::IdVector &visible, World *master, StreamBuf

    // Forward to client, and apply to server-synchronous.
    tsb.copy_into(xsb);
-    patch_visible(&tsb);
+    patch_visible(&tsb, nullptr);
    assert(tsb.empty());

    // Copy the version number from master animqueue to synch animqueue.
@@ -154,16 +163,18 @@ void World::diff_visible(const util::IdVector &visible, World *master, StreamBuf
    }
 }

-void World::patch_luatabs(StreamBuffer *sb) {
+void World::patch_luatabs(StreamBuffer *sb, DebugCollector *dbc) {
+    DebugBlock dbb(dbc, "patch_luatabs");
    int64_t actor_id = sb->read_int64();
    util::HashValue closehash = sb->read_hashvalue();
    int ncreate = sb->read_int32();
    util::IdVector closetans = get_near(actor_id, RadiusClose, true);
    assert(closehash == util::hash_id_vector(closetans));
-    number_lua_tables(closetans);
+    int nt = number_lua_tables(closetans);
    create_new_tables(ncreate);
-    patch_tangible_databases(sb);
-    patch_numbered_tables(sb);
+    DebugLine(dbc) << "lua tables: " << nt << " existing " << ncreate << " new";
+    patch_tangible_databases(sb, dbc);
+    patch_numbered_tables(sb, dbc);
    unnumber_lua_tables();
 }

@@ -193,8 +204,8 @@ void World::diff_luatabs(int64_t actor_id, World *master, StreamBuffer *xsb) {
    assert(tsb.read_int64() == actor_id);
    assert(tsb.read_hashvalue() == closehash);
    assert(tsb.read_int32() == ncreate);
-    patch_tangible_databases(&tsb);
-    patch_numbered_tables(&tsb);
+    patch_tangible_databases(&tsb, nullptr);
+    patch_numbered_tables(&tsb, nullptr);
    assert(tsb.empty());  

    // Unnumber tables in both models.
@@ -202,7 +213,8 @@ void World::diff_luatabs(int64_t actor_id, World *master, StreamBuffer *xsb) {
    master->unnumber_lua_tables();
 }

-void World::patch_tanclass(StreamBuffer *sb) {
+void World::patch_tanclass(StreamBuffer *sb, DebugCollector *dbc) {
+    DebugBlock dbb(dbc, "patch_tanclass");
    lua_State *L = state();
    LuaVar tangibles, tab, meta, sclass;
    LuaStack LS(L, tangibles, tab, meta, sclass);
@@ -262,14 +274,16 @@ void World::diff_tanclass(int64_t actor_id, World *master, StreamBuffer *xsb) {

    // Forward to client, and apply to server-synchronous.
    tsb.copy_into(xsb);
-    patch_tanclass(&tsb);
+    patch_tanclass(&tsb, nullptr);
    assert(tsb.empty());
 }

-void World::patch_source(StreamBuffer *sb) {
-    bool modified = source_db_.patch(sb);
+void World::patch_source(StreamBuffer *sb, DebugCollector *dbc) {
+    DebugBlock dbb(dbc, "patch_source");
+    bool modified = source_db_.patch(sb, dbc);
    if (modified) {
        std::string errs = source_db_.rebuild();
+        DebugLine(dbc) << "Source DB rebuilt";
        // TODO: I don't currently have any good place to send the
        // error messages.  This is a stopgap.
        std::cerr << errs;
@@ -277,15 +291,20 @@ void World::patch_source(StreamBuffer *sb) {
 }

 void World::diff_source(World *master, StreamBuffer *sb) {
-    source_db_.diff(master->source_db_, sb);
+    StreamBuffer tsb;
+    source_db_.diff(master->source_db_, &tsb);
+    tsb.copy_into(sb);
+    patch_source(&tsb, nullptr);
+    assert(tsb.empty());
 }

-int64_t World::patch_everything(StreamBuffer *sb) {
-    int64_t actor_id = patch_actor(sb);
-    patch_visible(sb);
-    patch_luatabs(sb);
-    patch_tanclass(sb);
-    patch_source(sb);
+int64_t World::patch_everything(StreamBuffer *sb, DebugCollector *dbc) {
+    DebugBlock dbb(dbc, "patch_everything");
+    int64_t actor_id = patch_actor(sb, dbc);
+    patch_visible(sb, dbc);
+    patch_luatabs(sb, dbc);
+    patch_tanclass(sb, dbc);
+    patch_source(sb, dbc);
    return actor_id;
 }

--- a/luprex/core/cpp/world-testing.cpp
+++ b/luprex/core/cpp/world-testing.cpp
@@ -233,7 +233,6 @@ static bool worlds_identical(const UniqueWorld &w1, const UniqueWorld &w2) {
    return sbw1.contents_equal(&sbw2);
 }

-
 LuaDefine(unittests_world1animdiff, "c") {
    UniqueWorld m(new World(util::WORLD_TYPE_MASTER));
    UniqueWorld ss(new World(util::WORLD_TYPE_S_SYNC));
@@ -256,7 +255,7 @@ LuaDefine(unittests_world1animdiff, "c") {

    // Now difference transmit all that to the client.
    ss->diff_visible(ids, m.get(), &sb);
-    cs->patch_visible(&sb);
+    cs->patch_visible(&sb, nullptr);
    LuaAssertStrEq(L, ss->tangible_ids_debug_string(), "123,345");
    LuaAssertStrEq(L, ss->tangible_anim_debug_string(123), 
        "id=0 action= plane=somewhere x=0 y=0 z=0 facing=0 graphic=; "
@@ -280,7 +279,7 @@ LuaDefine(unittests_world1animdiff, "c") {

    // Now difference transmit all that to the client again.
    ss->diff_visible(ids, m.get(), &sb);
-    cs->patch_visible(&sb);
+    cs->patch_visible(&sb, nullptr);
    LuaAssertStrEq(L, ss->tangible_anim_debug_string(123),
        "id=0 action= plane=somewhere x=0 y=0 z=0 facing=0 graphic=; "
        "id=770 action=walkto x=3 y=4; "
@@ -297,7 +296,7 @@ LuaDefine(unittests_world1animdiff, "c") {

    // And difference transmit
    ss->diff_visible(ids, m.get(), &sb);
-    cs->patch_visible(&sb);
+    cs->patch_visible(&sb, nullptr);
    LuaAssertStrEq(L, ss->tangible_ids_debug_string(), "123");
    LuaAssert(L, worlds_identical(ss, cs));

@@ -394,7 +393,7 @@ LuaDefine(unittests_world3diffluatab, "c") {

    // Difference transmit.
    ss->diff_luatabs(123, m.get(), &sb);
-    cs->patch_luatabs(&sb);
+    cs->patch_luatabs(&sb, nullptr);

    // Verify that the data was transmitted.
    LuaAssertStrEq(L, ss->tangible_pprint(123), expect_123);
@@ -423,7 +422,7 @@ LuaDefine(unittests_world4difftanclass, "c") {

    // Difference transmit.
    ss->diff_tanclass(123, m.get(), &sb);
-    cs->patch_tanclass(&sb);
+    cs->patch_tanclass(&sb, nullptr);

    // Verify that the data was transmitted.
    LuaAssertStrEq(L, ss->tangible_get_class(123), "chicken");
@@ -436,7 +435,7 @@ LuaDefine(unittests_world4difftanclass, "c") {

    // Difference transmit.
    ss->diff_tanclass(123, m.get(), &sb);
-    cs->patch_tanclass(&sb);
+    cs->patch_tanclass(&sb, nullptr);

    // Verify that the data was transmitted.
    LuaAssertStrEq(L, ss->tangible_get_class(123), "");
--- a/luprex/core/cpp/world.hpp
+++ b/luprex/core/cpp/world.hpp
@@ -8,6 +8,7 @@
 #include "animqueue.hpp"
 #include "invocation.hpp"
 #include "streambuffer.hpp"
+#include "debugcollector.hpp"
 #include "printbuffer.hpp"
 #include "sched.hpp"
 #include "source.hpp"
@@ -336,13 +337,13 @@ public:
    //
    ///////////////////////////////////////////////////////////

-    void patch_numbered_tables(StreamBuffer *sb);
+    void patch_numbered_tables(StreamBuffer *sb, DebugCollector *dbc);
    void diff_numbered_tables(lua_State *master, StreamBuffer *sb);

-    void patch_tangible_databases(StreamBuffer *sb);
+    void patch_tangible_databases(StreamBuffer *sb, DebugCollector *dbc);
    void diff_tangible_databases(const IdVector &basis, lua_State *master, StreamBuffer *sb);

-    void patch_tangible_classes(StreamBuffer *sb);
+    void patch_tangible_classes(StreamBuffer *sb, DebugCollector *dbc);
    void diff_tangible_classes(const IdVector &basis, lua_State *master, StreamBuffer *sb);

 public:
@@ -354,24 +355,24 @@ public:

    util::IdVector get_visible_union(int64_t actor_id, World *master);

-    int64_t patch_actor(StreamBuffer *sb);
+    int64_t patch_actor(StreamBuffer *sb, DebugCollector *dbc);
    void diff_actor(int64_t actor_id, World *master, StreamBuffer *sb); 

-    void patch_visible(StreamBuffer *sb);
+    void patch_visible(StreamBuffer *sb, DebugCollector *dbc);
    void diff_visible(const util::IdVector &ids, World *master, StreamBuffer *sb); 

-    void patch_luatabs(StreamBuffer *sb);
+    void patch_luatabs(StreamBuffer *sb, DebugCollector *dbc);
    void diff_luatabs(int64_t actor_id, World *master, StreamBuffer *sb);

-    void patch_tanclass(StreamBuffer *sb);
+    void patch_tanclass(StreamBuffer *sb, DebugCollector *dbc);
    void diff_tanclass(int64_t actor_id, World *master, StreamBuffer *sb);

-    void patch_source(StreamBuffer *sb);
+    void patch_source(StreamBuffer *sb, DebugCollector *dbc);
    void diff_source(World *master, StreamBuffer *sb);
    
    // This is the main entry point for difference transmission.
    //
-    int64_t patch_everything(StreamBuffer *sb);
+    int64_t patch_everything(StreamBuffer *sb, DebugCollector *dbc);
    void diff_everything(int64_t actor, World *master, StreamBuffer *sb);

 public:
@@ -474,6 +475,7 @@ private:
    friend int lfn_tangible_redirect(lua_State *L);
    friend int lfn_tangible_actor(lua_State *L);
    friend int lfn_tangible_place(lua_State *L);
+    friend int lfn_tangible_nopredict(lua_State *L);
 };

 using UniqueWorld = std::unique_ptr<World>;
--- a/luprex/core/lua/login.lua
+++ b/luprex/core/lua/login.lua
@@ -8,3 +8,7 @@ function login.action.becomeplayer(actor, place, dialog)
    tangible.setclass(actor, player)
 end

+function setfoo(n)
+    tangible.nopredict()
+    tangible.actor().foo = n
+end