libdpf/test/tests/log_test.cpp

#include <gtest/gtest.h>

#include <algorithm>
#include <array>
#include <atomic>
#include <chrono>
#include <cstdint>
#include <cstdlib>
#include <cstring>
#include <filesystem>
#include <fstream>
#include <map>
#include <mutex>
#include <sstream>
#include <string>
#include <thread>
#include <vector>

#include <unistd.h>

#include "dpf/app_flow.hpp"
#include "dpf/experiment.hpp"
#include "dpf/launch.hpp"
#include "dpf/log.hpp"
#include "dpf/prg_aes.hpp"
#include "dpf/prg_chacha.hpp"
#include "dpf/prg_count.hpp"
#include "dpf/run_config.hpp"
#include "dpf/run_log.hpp"
#include "dpf/yao.hpp"

namespace
{

std::string temp_path(const char * tag)
{
    return "/tmp/libdpf_log_test_" + std::to_string(::getpid()) + "_" + tag + ".log";
}

std::vector<std::string> read_lines(const std::string & path)
{
    std::ifstream in(path);
    std::vector<std::string> out;
    std::string line;
    while (std::getline(in, line))
        out.push_back(line);
    return out;
}

bool has(const std::string & line, const std::string & needle)
{
    return line.find(needle) != std::string::npos;
}

std::vector<std::string> with_event(const std::vector<std::string> & lines,
    const std::string & ev)
{
    std::vector<std::string> out;
    for (const auto & l : lines)
        if (has(l, " ev=" + ev + " ") || (l.size() >= ev.size() + 4
                && l.compare(l.size() - ev.size() - 4, std::string::npos, " ev=" + ev) == 0))
            out.push_back(l);
    return out;
}

/// Route the log to a fresh file for one test; silence it afterwards.
struct file_log
{
    std::string path;
    explicit file_log(const char * tag, dpf::log::level l = dpf::log::level::debug,
        dpf::log::seed_policy seeds = dpf::log::seed_policy::full)
      : path(temp_path(tag))
    {
        std::remove(path.c_str());
        dpf::log::settings s;
        s.threshold = l;
        s.sinks = "file:" + path;
        s.seeds = seeds;
        dpf::log::configure(s);
    }
    ~file_log()
    {
        dpf::log::settings s;
        s.sinks = "none";
        dpf::log::configure(s);
        std::remove(path.c_str());
    }
    std::vector<std::string> lines() const { return read_lines(path); }
};

}  // namespace

// Runs first: nothing has configured the log yet in this process.
TEST(Log, SilentUntilConfigured)
{
    EXPECT_FALSE(dpf::log::enabled(dpf::log::level::error));
    EXPECT_FALSE(dpf::log::enabled(dpf::log::level::info));
    int evaluated = 0;
    DPF_LOG(error, "never").kv("x", ++evaluated);
    EXPECT_EQ(evaluated, 0);
}

TEST(Log, LevelAndSeedPolicyNames)
{
    using dpf::log::level;
    EXPECT_EQ(dpf::log::parse_level("silent"), level::silent);
    EXPECT_EQ(dpf::log::parse_level("warn"), level::warning);
    EXPECT_EQ(dpf::log::parse_level("3"), level::info);
    EXPECT_EQ(dpf::log::parse_level("absurd"), level::trace);
    EXPECT_THROW(dpf::log::parse_level("loud"), std::invalid_argument);
    EXPECT_EQ(dpf::log::parse_seed_policy("hash"), dpf::log::seed_policy::hash);
    EXPECT_EQ(dpf::log::parse_seed_policy("off"), dpf::log::seed_policy::off);
    EXPECT_THROW(dpf::log::parse_seed_policy("maybe"), std::invalid_argument);
    dpf::log::settings bad;
    bad.sinks = "stderr,carrier-pigeon";
    EXPECT_THROW(dpf::log::configure(bad), std::invalid_argument);
    EXPECT_FALSE(dpf::log::enabled(dpf::log::level::error));
}

TEST(Log, RecordFormatAndThreshold)
{
    std::string path;
    {
        file_log log("format", dpf::log::level::info);
        path = log.path;
        DPF_LOG(info, "demo").kv("plain", "abc").kv("spaced", "a b")
            .kv("quote", "say \"hi\"").kv("eq", "k=v").kv("n", std::size_t{42})
            .kv("neg", -3).kv("flag", true).kv("empty", "").hex("h", "\x01\xff", 2);
        DPF_LOG(debug, "hidden").kv("x", 1);
        DPF_LOG(warning, "shown").kv("x", 2);
        const auto lines = log.lines();
        ASSERT_EQ(lines.size(), 2u);
        const auto & l = lines[0];
        EXPECT_EQ(l.rfind("ts=", 0), 0u);
        EXPECT_TRUE(has(l, "Z lvl=info inv=" + dpf::log::invocation_id() + " pid="));
        EXPECT_EQ(dpf::log::invocation_id().size(), 16u);
        EXPECT_TRUE(has(l, " ev=demo plain=abc spaced=\"a b\" quote=\"say \\\"hi\\\"\" "
                           "eq=\"k=v\" n=42 neg=-3 flag=1 empty=\"\" h=01ff"));
        EXPECT_TRUE(has(lines[1], "lvl=warning"));
        EXPECT_TRUE(has(lines[1], "ev=shown x=2"));
    }
    EXPECT_FALSE(dpf::log::enabled(dpf::log::level::error));
}

TEST(Log, RoleScopeTagsAndRestores)
{
    file_log log("role");
    DPF_LOG(info, "outside");
    {
        const dpf::log::role_scope a("p1");
        DPF_LOG(info, "inside");
        {
            const dpf::log::role_scope b("dealer");
            DPF_LOG(info, "nested");
        }
        DPF_LOG(info, "back");
    }
    const auto lines = log.lines();
    ASSERT_EQ(lines.size(), 4u);
    EXPECT_FALSE(has(lines[0], " role="));
    EXPECT_TRUE(has(lines[1], " role=p1 ev=inside"));
    EXPECT_TRUE(has(lines[2], " role=dealer ev=nested"));
    EXPECT_TRUE(has(lines[3], " role=p1 ev=back"));
}

TEST(Log, SeedPolicies)
{
    const std::uint8_t seed[4] = {0xde, 0xad, 0xbe, 0xef};
    {
        file_log log("seed_full", dpf::log::level::info, dpf::log::seed_policy::full);
        DPF_LOG(info, "s").seed("value", seed, sizeof(seed));
        EXPECT_TRUE(has(log.lines().at(0), "value=deadbeef"));
    }
    {
        file_log log("seed_hash", dpf::log::level::info, dpf::log::seed_policy::hash);
        DPF_LOG(info, "s").seed("value", seed, sizeof(seed));
        const auto l = log.lines().at(0);
        EXPECT_TRUE(has(l, "value=sha256:"));
        EXPECT_FALSE(has(l, "deadbeef"));
        const auto pos = l.find("sha256:") + 7;
        EXPECT_EQ(l.substr(pos).size(), 16u);
    }
    {
        file_log log("seed_off", dpf::log::level::info, dpf::log::seed_policy::off);
        DPF_LOG(info, "s").seed("value", seed, sizeof(seed));
        EXPECT_TRUE(has(log.lines().at(0), "value=withheld"));
    }
    const auto abc = dpf::log::detail::sha256("",
        reinterpret_cast<const std::uint8_t *>("abc"), 3);
    std::string hex;
    dpf::log::detail::append_hex(hex, abc.data(), abc.size());
    EXPECT_EQ(hex, "ba7816bf8f01cfea414140de5dae2223b00361a396177a9cb410ff61f20015ad");
}

TEST(Log, ConcurrentRecordsStayWholeLines)
{
    file_log log("threads", dpf::log::level::info);
    constexpr int threads = 8;
    constexpr int each = 400;
    std::vector<std::thread> ts;
    for (int t = 0; t < threads; ++t)
        ts.emplace_back([t] {
            const dpf::log::role_scope role("p" + std::to_string(t));
            for (int i = 0; i < each; ++i)
                DPF_LOG(info, "tick").kv("thread", t).kv("i", i)
                    .kv("pad", std::string(64, static_cast<char>('a' + t)));
        });
    for (auto & t : ts)
        t.join();
    const auto lines = log.lines();
    ASSERT_EQ(lines.size(), static_cast<std::size_t>(threads * each));
    std::map<int, int> per;
    for (const auto & l : lines)
    {
        ASSERT_EQ(l.rfind("ts=", 0), 0u) << l;
        const auto p = l.find(" thread=");
        ASSERT_NE(p, std::string::npos) << l;
        const int t = std::stoi(l.substr(p + 8));
        EXPECT_TRUE(has(l, " role=p" + std::to_string(t) + " ")) << l;
        EXPECT_TRUE(has(l, "pad=" + std::string(64, static_cast<char>('a' + t)))) << l;
        ++per[t];
    }
    for (int t = 0; t < threads; ++t)
        EXPECT_EQ(per[t], each);
}

TEST(Log, RunConfigKeysAndDescribe)
{
    dpf::app::run_config cfg;
    cfg.set("log_level", "debug");
    cfg.set("log", "file:/tmp/x.log,stderr");
    cfg.set("log_seeds", "hash");
    cfg.set("cpu2", "3");
    EXPECT_EQ(cfg.log_level, dpf::log::level::debug);
    EXPECT_EQ(cfg.log_sinks, "file:/tmp/x.log,stderr");
    EXPECT_EQ(cfg.log_seeds, dpf::log::seed_policy::hash);
    EXPECT_EQ(cfg.cpu[2], 3);
    EXPECT_THROW(cfg.set("log_level", "chatty"), std::invalid_argument);
    EXPECT_THROW(cfg.set("cpu0", "3abc"), std::invalid_argument);
    std::map<std::string, std::string> kv;
    for (const auto & p : cfg.describe())
        kv[p.first] = p.second;
    for (const char * k : {"log_level", "log", "log_seeds", "cpu2", "compact",
             "keepalive_idle", "connect_ms", "accept_ms", "join_ms", "handshake_ms"})
        EXPECT_EQ(kv.count(k), 1u) << k;
    EXPECT_EQ(kv["log_level"], "debug");
    EXPECT_EQ(kv["cpu2"], "3");

    ::setenv("DPF_LOG_LEVEL", "warning", 1);
    ::setenv("DPF_LOG_SEEDS", "off", 1);
    const auto env = dpf::app::run_config::from_env();
    ::unsetenv("DPF_LOG_LEVEL");
    ::unsetenv("DPF_LOG_SEEDS");
    EXPECT_EQ(env.log_level, dpf::log::level::warning);
    EXPECT_EQ(env.log_seeds, dpf::log::seed_policy::off);
}

TEST(Log, BannerRecordsProvenance)
{
    const std::string path = temp_path("banner");
    std::remove(path.c_str());
    ::setenv("DPF_TEST_MARKER", "banner-check", 1);
    ::setenv("DPF_TEST_SEED", "0123456789abcdef", 1);
    dpf::app::run_config cfg;
    cfg.log_sinks = "file:" + path;
    cfg.log_seeds = dpf::log::seed_policy::hash;
    dpf::app::start_logging(cfg);
    const auto lines = read_lines(path);
    ::unsetenv("DPF_TEST_MARKER");
    ::unsetenv("DPF_TEST_SEED");
    for (const char * ev : {"start", "build", "host", "argv", "env", "log", "config"})
        EXPECT_FALSE(with_event(lines, ev).empty()) << ev;
    const auto build = with_event(lines, "build").at(0);
    EXPECT_TRUE(has(build, " rev=")) << build;
    EXPECT_TRUE(has(build, " entropy=")) << build;
    EXPECT_TRUE(has(with_event(lines, "start").at(0), " utc=")) << lines[0];
    bool marker = false;
    bool seed_hidden = false;
    for (const auto & l : with_event(lines, "env"))
    {
        marker = marker || has(l, "name=DPF_TEST_MARKER value=banner-check");
        seed_hidden = seed_hidden
            || (has(l, "name=DPF_TEST_SEED value=sha256:") && !has(l, "0123456789abcdef"));
    }
    EXPECT_TRUE(marker);
    EXPECT_TRUE(seed_hidden);
    const auto config = with_event(lines, "config").at(0);
    EXPECT_TRUE(has(config, " transport=async")) << config;
    EXPECT_TRUE(has(config, " log_seeds=hash")) << config;
    dpf::log::settings off;
    off.sinks = "none";
    dpf::log::configure(off);
    std::remove(path.c_str());
}

TEST(Log, LinkUpNamesEndpointsAndAuthentication)
{
    for (const char * encryption : {"off", "on"})
    {
        file_log log("links", dpf::log::level::info);
        dpf::protocol::composer c0(0);
        dpf::protocol::composer c1(1);
        auto x0 = c0.input(dpf::protocol::domain::a, 8);
        auto x1 = c1.input(dpf::protocol::domain::a, 8);
        auto o0 = c0.exchange(x0);
        (void)c1.exchange(x1);
        auto p0 = c0.schedule();
        auto p1 = c1.schedule();
        dpf::app::party_values v0(p0.nodes().size()), v1(p1.nodes().size());
        const std::uint64_t a = 11, b = 31;
        v0[x0.id].assign(8, 0);
        v1[x1.id].assign(8, 0);
        std::memcpy(v0[x0.id].data(), &a, 8);
        std::memcpy(v1[x1.id].data(), &b, 8);
        dpf::app::run_config cfg;
        cfg.kind = dpf::net::transport::mux;
        cfg.set("encryption", encryption);
        const bool tls = std::strcmp(encryption, "on") == 0;
        const auto r = dpf::run_two_party(p0, p1, v0, v1, {}, cfg);
        std::uint64_t open = 0;
        std::memcpy(&open, v0[o0.id].data(), 8);
        EXPECT_EQ(open, 42u) << encryption;
        ASSERT_EQ(r.party_wall_ns.size(), 2u);
        const auto lines = log.lines();
        const auto ups = with_event(lines, "link.up");
        ASSERT_EQ(ups.size(), 2u) << encryption;
        bool saw_accept = false, saw_connect = false;
        for (const auto & l : ups)
        {
            EXPECT_TRUE(has(l, " transport=mux")) << l;
            EXPECT_TRUE(has(l, " local=127.0.0.1:")) << l;
            EXPECT_TRUE(has(l, " remote=127.0.0.1:")) << l;
            if (tls)
            {
                EXPECT_TRUE(has(l, " encryption=TLSv1.3/")) << l;
                EXPECT_TRUE(has(l, " peer_key=")) << l;
                EXPECT_TRUE(has(l, " auth=")) << l;
            }
            else
                EXPECT_TRUE(has(l, " auth=none encryption=none")) << l;
            EXPECT_TRUE(has(l, " sndbuf=")) << l;
            EXPECT_TRUE(has(l, " rtt_us=")) << l;
            saw_accept = saw_accept || (has(l, " role=p0 ") && has(l, " how=accept peer=p1"));
            saw_connect = saw_connect || (has(l, " role=p1 ") && has(l, " how=connect peer=p0"));
        }
        EXPECT_TRUE(saw_accept) << encryption;
        EXPECT_TRUE(saw_connect) << encryption;
        EXPECT_FALSE(with_event(lines, "listen").empty());
        EXPECT_EQ(with_event(lines, "plan").size(), 2u);
        const auto done = with_event(lines, "party.done");
        ASSERT_EQ(done.size(), 2u);
        for (const auto & l : done)
        {
            EXPECT_TRUE(has(l, " wall_ns=")) << l;
            EXPECT_TRUE(has(l, " wire_out=")) << l;
        }
        EXPECT_EQ(with_event(lines, "parties.done").size(), 1u);
        EXPECT_TRUE(with_event(lines, "link.plaintext").empty());
    }
}

TEST(Log, NodeArgumentsNameTheBadField)
{
    const char * bad_party[] = {"node", "--party=zero", "--peers=a:1,b:2"};
    try
    {
        (void)dpf::app::parse_node_args(3, const_cast<char **>(bad_party),
            dpf::app::run_config{});
        FAIL() << "expected a parse error";
    }
    catch (const std::invalid_argument & e)
    {
        EXPECT_TRUE(has(e.what(), "--party needs a number")) << e.what();
    }
    const char * bad_port[] = {"node", "--party=0", "--peers=a:1,b:70000"};
    EXPECT_THROW((void)dpf::app::parse_node_args(3, const_cast<char **>(bad_port),
                     dpf::app::run_config{}),
        std::invalid_argument);
    const char * memory[] = {"node", "--party=1", "--peers=a:1,b:2", "--transport=async"};
    const auto a = dpf::app::parse_node_args(4, const_cast<char **>(memory),
        dpf::app::run_config{});
    EXPECT_EQ(a.cfg.kind, dpf::net::transport::mux);
    EXPECT_EQ(a.replaced_transport, "async");
}

TEST(SymCount, PurposeAndPrimitiveCells)
{
    using dpf::prg::primitive;
    using dpf::prg::purpose;
    dpf::prg::reset_eval_count();
    auto seed = simde_mm_set_epi64x(3, 4);
    auto blk = dpf::prg::aes128::eval(seed, 0);
    blk = dpf::prg::aes128::eval(blk, 1);
    {
        const dpf::prg::purpose_scope h(purpose::hash);
        (void)dpf::prg::aes128::eval01(blk);
        {
            const dpf::prg::purpose_scope inner(purpose::harness);
            (void)dpf::prg::aes128::eval(blk, 7);
        }
        (void)dpf::prg::aes128::eval(blk, 8);
    }
    (void)dpf::prg::chacha<20>::eval(seed, 0);
    EXPECT_EQ(dpf::prg::count(purpose::expand, primitive::aes128), 2u);
    EXPECT_EQ(dpf::prg::count(purpose::hash, primitive::aes128), 3u);
    EXPECT_EQ(dpf::prg::count(purpose::harness, primitive::aes128), 1u);
    EXPECT_EQ(dpf::prg::count(purpose::expand, primitive::chacha), 1u);
    EXPECT_EQ(dpf::prg::eval_count(), 6u);
    const auto snap = dpf::prg::snapshot();
    std::uint64_t all = 0;
    for (auto n : snap)
        all += n;
    EXPECT_EQ(all, 7u);
    dpf::prg::reset_eval_count();
    EXPECT_EQ(dpf::prg::eval_count(), 0u);
}

TEST(SymCount, GarblingHashesCountAsHash)
{
    using dpf::prg::primitive;
    using dpf::prg::purpose;
    dpf::prg::reset_eval_count();
    const auto x = simde_mm_set_epi64x(9, 10);
    (void)dpf::yao::detail::cr_hash(x, 5);
    EXPECT_EQ(dpf::prg::count(purpose::hash, primitive::aes128), 1u);
    EXPECT_EQ(dpf::prg::count(purpose::expand, primitive::aes128), 0u);
    dpf::prg::reset_eval_count();
}

TEST(SymCount, ExperimentSeedStreamIsNotProtocolWork)
{
    using dpf::prg::primitive;
    using dpf::prg::purpose;
    dpf::experiment ex("stream");
    ex.begin_timing();
    std::array<std::uint8_t, 1600> buf{};
    dpf::uniform_fill(buf);
    ex.end_timing();
    EXPECT_EQ(ex.random_bytes(), 1600u);
    EXPECT_EQ(ex.prg_evals(), 0u);
    const auto & sym = ex.sym_counts();
    EXPECT_EQ(sym[static_cast<std::size_t>(purpose::harness) * dpf::prg::primitive_count
                  + static_cast<std::size_t>(primitive::aes128)],
        100u);
}

TEST(Experiment, SeedSourceIsLoggedAndWritten)
{
    const std::string dir = "/tmp/libdpf_log_test_csv_" + std::to_string(::getpid());
    (void)::system(("rm -rf '" + dir + "'").c_str());
    file_log log("seed_source", dpf::log::level::info);
    dpf::experiment::master_seed master{};
    {
        dpf::experiment ex("fresh_one");
        master = ex.seed();
        EXPECT_FALSE(ex.seed_provided());
        ex.begin_timing();
        (void)dpf::prg::aes128::eval(simde_mm_set_epi64x(1, 2), 0);
        ex.end_timing();
        ex.write_csv(dir);
    }
    {
        auto again = dpf::experiment::replay("fresh_one", master);
        EXPECT_TRUE(again.seed_provided());
        again.set_run_id(1);
        again.write_csv(dir);
    }
    const auto seeds = with_event(log.lines(), "seed");
    ASSERT_EQ(seeds.size(), 2u);
    std::string hex;
    dpf::log::detail::append_hex(hex, master.data(), master.size());
    EXPECT_TRUE(has(seeds[0], " source=fresh")) << seeds[0];
    EXPECT_TRUE(has(seeds[0], " value=" + hex)) << seeds[0];
    EXPECT_TRUE(has(seeds[1], " source=provided")) << seeds[1];
    EXPECT_TRUE(has(seeds[1], " value=" + hex)) << seeds[1];
    const auto runs = read_lines(dir + "/runs.csv");
    ASSERT_EQ(runs.size(), 3u);
    EXPECT_EQ(runs[0], "name,party,run_id,invocation,seed_source,written_utc");
    EXPECT_TRUE(has(runs[1], "fresh_one,p0,0," + dpf::log::invocation_id() + ",fresh,"));
    EXPECT_TRUE(has(runs[2], "fresh_one,p0,1," + dpf::log::invocation_id() + ",provided,"));
    const auto sym = read_lines(dir + "/sym.csv");
    ASSERT_GE(sym.size(), 2u);
    EXPECT_EQ(sym[0], "name,party,run_id,purpose,primitive,blocks,invocation");
    EXPECT_EQ(sym[1], "fresh_one,p0,0,expand,aes128,1," + dpf::log::invocation_id());
    (void)::system(("rm -rf '" + dir + "'").c_str());
}

namespace
{

constexpr std::uint32_t k_draw = 94201;

struct chain
{
    dpf::protocol::plan plan;
    dpf::protocol::node x;
    dpf::protocol::node out;
};

chain make_chain(std::size_t party, int steps)
{
    dpf::protocol::composer c(party);
    chain ch;
    ch.x = c.input(dpf::protocol::domain::a, 8);
    auto cur = ch.x;
    for (int i = 0; i < steps; ++i)
        cur = c.compute(k_draw, {c.exchange(cur)}, dpf::protocol::domain::a, 8);
    ch.out = cur;
    ch.plan = c.schedule();
    return ch;
}

struct draw_log
{
    std::mutex mu;
    std::vector<std::uint64_t> values;
    std::size_t hooked = 0;
};

/// Adds 1 to its input, draws one word, and runs `aes` AES blocks.
dpf::protocol::kernel_fn draw_kernel(draw_log & log, int aes)
{
    return [&log, aes](std::uint32_t, const std::vector<dpf::protocol::node> &,
               const std::vector<dpf::protocol::block_span> & inputs,
               dpf::protocol::block_span output, std::size_t lanes) {
        const bool hooked = dpf::detail::uniform_bytes_hook != nullptr;
        const auto r = dpf::uniform_sample<std::uint64_t>();
        {
            std::lock_guard<std::mutex> lock(log.mu);
            log.values.push_back(r);
            log.hooked += hooked ? 1 : 0;
        }
        auto blk = simde_mm_set_epi64x(1, 2);
        for (int i = 0; i < aes; ++i)
            blk = dpf::prg::aes128::eval(blk, static_cast<psnip_uint32_t>(i));
        asm volatile("" : "+x"(blk));
        for (std::size_t l = 0; l < lanes; ++l)
        {
            std::uint64_t v = 0;
            std::memcpy(&v, inputs[0].at(l), 8);
            ++v;
            std::memcpy(output.at(l), &v, 8);
        }
    };
}

struct chain_run
{
    std::vector<dpf::protocol::plan> plans;
    std::vector<dpf::app::party_values> inputs;
};

chain_run two_party_chain(int steps)
{
    chain_run r;
    for (std::size_t p = 0; p < 2; ++p)
    {
        auto ch = make_chain(p, steps);
        dpf::app::party_values v(ch.plan.nodes().size());
        v[ch.x.id].assign(8, 0);
        const std::uint64_t in = p == 0 ? 5 : 6;
        std::memcpy(v[ch.x.id].data(), &in, 8);
        r.plans.push_back(ch.plan);
        r.inputs.push_back(v);
    }
    return r;
}

std::vector<std::uint64_t> sorted_draws(draw_log & log)
{
    std::lock_guard<std::mutex> lock(log.mu);
    auto v = log.values;
    log.values.clear();
    log.hooked = 0;
    std::sort(v.begin(), v.end());
    return v;
}

void expect_replay(dpf::net::transport kind, std::size_t pool, std::size_t trials)
{
    const auto run = two_party_chain(3);
    draw_log log;
    std::map<std::uint32_t, dpf::protocol::kernel_fn> k{{k_draw, draw_kernel(log, 0)}};
    dpf::app::run_config cfg;
    cfg.kind = kind;
    cfg.compute_threads = pool;
    cfg.trials = trials;
    dpf::experiment first("replay");
    (void)dpf::app::exercise_parties(run.plans, run.inputs, k, &first, cfg);
    const std::size_t hooked = log.hooked;
    const auto a = sorted_draws(log);
    auto again = dpf::experiment::replay("replay", first.seed());
    (void)dpf::app::exercise_parties(run.plans, run.inputs, k, &again, cfg);
    const auto b = sorted_draws(log);
    ASSERT_EQ(a.size(), 6u * trials) << dpf::net::transport_name(kind) << " pool " << pool;
    EXPECT_EQ(hooked, a.size()) << dpf::net::transport_name(kind) << " pool " << pool;
    EXPECT_EQ(a, b) << dpf::net::transport_name(kind) << " pool " << pool;
    EXPECT_TRUE(first.has_seed_named("p0/master"));
    EXPECT_TRUE(first.has_seed_named("p1/master"));
}

}  // namespace

TEST(Replay, RecordedMasterReplaysEveryParty)
{
    expect_replay(dpf::net::transport::async_memory, 0, 1);
    expect_replay(dpf::net::transport::memory_sink, 0, 1);
    expect_replay(dpf::net::transport::mux, 0, 3);
}

TEST(Replay, ComputePoolKernelsDrawFromTheirPartysStream)
{
    expect_replay(dpf::net::transport::async_memory, 2, 1);
}

TEST(Replay, PartyStreamsDifferAndDependOnlyOnTheMaster)
{
    const dpf::experiment::master_seed m{};
    auto a = dpf::experiment::replay("x", m);
    const auto p0 = a.derive_party(0).seed();
    const auto p1 = a.derive_party(1).seed();
    auto b = dpf::experiment::replay("other name", m);
    EXPECT_NE(p0, p1);
    EXPECT_EQ(b.derive_party(1).seed(), p1);
    EXPECT_EQ(b.derive_party(1).seed_origin(), dpf::experiment::origin::derived);
}

TEST(Counting, ComputePoolWorkIsChargedToItsParty)
{
    const auto run = two_party_chain(3);
    draw_log log;
    std::map<std::uint32_t, dpf::protocol::kernel_fn> k{{k_draw, draw_kernel(log, 20000)}};
    for (std::size_t pool : {std::size_t{0}, std::size_t{2}})
    {
        dpf::app::run_config cfg;
        cfg.kind = dpf::net::transport::async_memory;
        cfg.compute_threads = pool;
        dpf::experiment ex("pool");
        (void)dpf::app::exercise_parties(run.plans, run.inputs, k, &ex, cfg);
        EXPECT_EQ(ex.prg_evals(), 3u * 20000u) << "pool " << pool;
        EXPECT_EQ(ex.random_bytes(), 3u * 8u) << "pool " << pool;
        EXPECT_GT(ex.cpu_ns(), ex.wall_ns() / 4) << "pool " << pool;
        (void)sorted_draws(log);
    }
}

TEST(Bytes, ReceivedBytesMatchSentOnASymmetricChain)
{
    const auto run = two_party_chain(3);
    draw_log log;
    std::map<std::uint32_t, dpf::protocol::kernel_fn> k{{k_draw, draw_kernel(log, 0)}};
    dpf::app::run_config cfg;
    cfg.kind = dpf::net::transport::mux;
    dpf::experiment ex("bytes");
    (void)dpf::app::exercise_parties(run.plans, run.inputs, k, &ex, cfg);
    EXPECT_EQ(ex.bytes_out(), ex.plan_bytes_out());
    EXPECT_EQ(ex.bytes_in(), ex.bytes_out());
    EXPECT_EQ(ex.edge_bytes_in(dpf::protocol::edge_channel::peer),
        ex.edge_bytes_out(dpf::protocol::edge_channel::peer));
    ASSERT_EQ(ex.rounds().size(), 3u);
    for (const auto & r : ex.rounds())
        EXPECT_EQ(r.bytes_in, 8u) << "round " << r.round;
}

TEST(Trials, EveryPartyIsTimedAndMediansReachSummary)
{
    const auto run = two_party_chain(2);
    draw_log log;
    std::map<std::uint32_t, dpf::protocol::kernel_fn> k{{k_draw, draw_kernel(log, 0)}};
    dpf::app::run_config cfg;
    cfg.kind = dpf::net::transport::async_memory;
    cfg.warmup = 1;
    cfg.trials = 3;
    dpf::experiment ex("trials");
    (void)dpf::app::exercise_parties(run.plans, run.inputs, k, &ex, cfg);
    EXPECT_EQ(ex.trials().size(), 3u);
    EXPECT_GE(ex.slowest_median_ns(), ex.median_trial_ns());
    const std::string dir = "/tmp/libdpf_log_test_trials_" + std::to_string(::getpid());
    (void)::system(("rm -rf '" + dir + "'").c_str());
    ex.write_csv(dir);
    const auto trials = read_lines(dir + "/trials.csv");
    ASSERT_EQ(trials.size(), 1u + 3u * 2u);
    EXPECT_EQ(trials[0], "name,party,run_id,trial,wall_ns,invocation");
    EXPECT_EQ(trials[1].rfind("trials,p0,0,0,", 0), 0u) << trials[1];
    EXPECT_EQ(trials[2].rfind("trials,p1,0,0,", 0), 0u) << trials[2];
    const auto summary = read_lines(dir + "/summary.csv");
    ASSERT_EQ(summary.size(), 2u);
    EXPECT_TRUE(has(summary[0], ",median_ns,slowest_median_ns,trials,invocation"));
    EXPECT_TRUE(has(summary[1], "," + std::to_string(ex.median_trial_ns()) + ","
        + std::to_string(ex.slowest_median_ns()) + ",3," + dpf::log::invocation_id()));
    (void)::system(("rm -rf '" + dir + "'").c_str());
}

TEST(Csv, ChangedHeaderMovesTheOldFileAside)
{
    const std::string dir = "/tmp/libdpf_log_test_rotate_" + std::to_string(::getpid());
    (void)::system(("rm -rf '" + dir + "' && mkdir -p '" + dir + "'").c_str());
    {
        std::ofstream old(dir + "/summary.csv");
        old << "name,party,run_id,wall_ns\nold,p0,0,1\n";
    }
    file_log log("rotate", dpf::log::level::warning);
    dpf::experiment ex("rotate");
    ex.write_csv(dir);
    const auto now = read_lines(dir + "/summary.csv");
    ASSERT_EQ(now.size(), 2u);
    EXPECT_TRUE(has(now[0], ",invocation"));
    std::size_t moved = 0;
    for (const auto & e : std::filesystem::directory_iterator(dir))
        if (e.path().filename().string().rfind("summary.before-", 0) == 0)
        {
            ++moved;
            EXPECT_EQ(read_lines(e.path().string()).at(1), "old,p0,0,1");
        }
    EXPECT_EQ(moved, 1u);
    EXPECT_EQ(with_event(log.lines(), "csv.moved").size(), 1u);
    (void)::system(("rm -rf '" + dir + "'").c_str());
}

TEST(Gate, AllPartiesStartTogetherAndAFailureReleasesTheRest)
{
    {
        dpf::app::detail::start_gate gate(3);
        std::atomic<int> through{0};
        std::vector<std::thread> ts;
        for (int i = 0; i < 3; ++i)
            ts.emplace_back([&] { through += gate.arrive_and_wait() ? 1 : 0; });
        for (auto & t : ts)
            t.join();
        EXPECT_EQ(through.load(), 3);
    }
    {
        dpf::app::detail::start_gate gate(3);
        std::atomic<int> through{0};
        std::vector<std::thread> ts;
        for (int i = 0; i < 2; ++i)
            ts.emplace_back([&] { through += gate.arrive_and_wait() ? 1 : 0; });
        std::this_thread::sleep_for(std::chrono::milliseconds(20));
        gate.fail();
        for (auto & t : ts)
            t.join();
        EXPECT_EQ(through.load(), 0);
    }
}