Replay logging almost done. Only thing missing is stdout.

This commit is contained in:
2022-03-11 19:01:02 -05:00
parent 3c2f93759b
commit cfd299006f
4 changed files with 83 additions and 57 deletions

View File

@@ -474,10 +474,10 @@ public:
drv::ReplayPlayer player; drv::ReplayPlayer player;
player.open_logfile(fn); player.open_logfile(fn);
while (true) { while (true) {
drv::ReplayPlayer::Error err = player.step(); drv::ReplayPlayer::Status st = player.step();
if (err != drv::ReplayPlayer::ERR_NONE) { if (st != drv::ReplayPlayer::ST_REPLAYING) {
player.print_error(std::cerr); player.print_status(std::cerr);
return (err != drv::ReplayPlayer::ERR_LOGFILE_EOF) ? 1 : 0; return (st == drv::ReplayPlayer::ST_CLEAN_EXIT) ? 0 : 1;
} }
} }
} }
@@ -567,6 +567,9 @@ public:
SSL_CTX_free(ssl_ctx_with_root_certs_); SSL_CTX_free(ssl_ctx_with_root_certs_);
SSL_CTX_free(ssl_ctx_with_server_certs_); SSL_CTX_free(ssl_ctx_with_server_certs_);
DrivenEngine::set(nullptr); DrivenEngine::set(nullptr);
recorder_.clean_exit();
return 0; return 0;
} }
}; };

View File

@@ -44,6 +44,7 @@ std::vector<std::string> parse_control_lst(std::string_view ctrl) {
enum DrvAction { enum DrvAction {
CREATE_ENGINE, CREATE_ENGINE,
CLEAN_EXIT,
DRV_CLEAR_NEW_OUTGOING, DRV_CLEAR_NEW_OUTGOING,
DRV_SENT_OUTGOING, DRV_SENT_OUTGOING,
DRV_RECV_INCOMING, DRV_RECV_INCOMING,
@@ -55,9 +56,10 @@ enum DrvAction {
DRV_INVOKE_EVENT_UPDATE DRV_INVOKE_EVENT_UPDATE
}; };
static const char *action_string(DrvAction act) { inline static const char *action_string(DrvAction act) {
switch(act) { switch(act) {
case CREATE_ENGINE: return "CREATE_ENGINE"; case CREATE_ENGINE: return "CREATE_ENGINE";
case CLEAN_EXIT: return "CLEAN_EXIT";
case DRV_CLEAR_NEW_OUTGOING: return "DRV_CLEAR_NEW_OUTGOING"; case DRV_CLEAR_NEW_OUTGOING: return "DRV_CLEAR_NEW_OUTGOING";
case DRV_SENT_OUTGOING: return "DRV_SENT_OUTGOING"; case DRV_SENT_OUTGOING: return "DRV_SENT_OUTGOING";
case DRV_RECV_INCOMING: return "DRV_RECV_INCOMING"; case DRV_RECV_INCOMING: return "DRV_RECV_INCOMING";
@@ -71,7 +73,6 @@ static const char *action_string(DrvAction act) {
} }
} }
static void wlog_uint8(std::ofstream &s, uint8_t v) { static void wlog_uint8(std::ofstream &s, uint8_t v) {
s.put((char)v); s.put((char)v);
} }
@@ -104,7 +105,7 @@ static void wlog_string(std::ofstream &s, std::string_view v) {
} }
static void wlog_cmd_hash(std::ofstream &s, DrvAction act, uint32_t hash) { static void wlog_cmd_hash(std::ofstream &s, DrvAction act, uint32_t hash) {
std::cerr << "Logging " << action_string(act) << " " << hash << std::endl; // std::cerr << "Logging " << action_string(act) << " " << hash << std::endl;
wlog_uint8(s, act); wlog_uint8(s, act);
wlog_uint32(s, hash); wlog_uint32(s, hash);
} }
@@ -158,7 +159,7 @@ std::string_view rlog_string(std::ifstream &s, char *rlog_buf) {
} }
ReplayPlayer::ReplayPlayer() { ReplayPlayer::ReplayPlayer() {
error_ = ERR_NONE; status_ = ST_REPLAYING;
buf_.reset(new char[RLOG_BUFSIZE]); buf_.reset(new char[RLOG_BUFSIZE]);
} }
@@ -185,25 +186,26 @@ bool ReplayRecorder::open_logfile(const char *fn) {
} }
ReplayPlayer::Error ReplayPlayer::step() { ReplayPlayer::Status ReplayPlayer::step() {
if (error_ != ERR_NONE) return error_; if (status_ != ST_REPLAYING) return status_;
uint8_t code = rlog_uint8(f_); uint8_t code = rlog_uint8(f_);
if (f_.eof()) { if (f_.eof()) {
set_error(ERR_LOGFILE_EOF); set_status(ST_LOGFILE_ENDS_ABRUPTLY);
return error_; return status_;
} }
int hash = rlog_uint32(f_); int hash = rlog_uint32(f_);
if (!f_.good()) { if (!f_.good()) {
set_error(ERR_LOGFILE_CORRUPT); set_status(ST_LOGFILE_CORRUPT);
return error_; return status_;
} }
std::cerr << "Executing: " << action_string(DrvAction(code)) << " " << eng::memhash() << std::endl; // std::cerr << "Executing: " << action_string(DrvAction(code)) << " " << eng::memhash() << std::endl;
if (hash != eng::memhash()) { if (hash != eng::memhash()) {
set_error(ERR_NONDERMINISTIC); set_status(ST_NONDERMINISTIC);
return error_; return status_;
} }
switch (code) { switch (code) {
case CREATE_ENGINE: create_engine(); break; case CREATE_ENGINE: create_engine(); break;
case CLEAN_EXIT: clean_exit(); break;
case DRV_CLEAR_NEW_OUTGOING: drv_clear_new_outgoing(); break; case DRV_CLEAR_NEW_OUTGOING: drv_clear_new_outgoing(); break;
case DRV_SENT_OUTGOING: drv_sent_outgoing(); break; case DRV_SENT_OUTGOING: drv_sent_outgoing(); break;
case DRV_RECV_INCOMING: drv_recv_incoming(); break; case DRV_RECV_INCOMING: drv_recv_incoming(); break;
@@ -216,33 +218,36 @@ ReplayPlayer::Error ReplayPlayer::step() {
default: default:
assert(false && "Replay Log contains invalid command."); assert(false && "Replay Log contains invalid command.");
} }
return error_; return status_;
} }
void ReplayPlayer::set_error(Error e) { void ReplayPlayer::set_status(Status e) {
error_ = e; status_ = e;
f_.close(); f_.close();
f_.clear(); f_.clear();
} }
void ReplayPlayer::print_error(std::ostream &s) { void ReplayPlayer::print_status(std::ostream &s) {
switch (error_) { switch (status_) {
case ERR_NONE: case ST_REPLAYING:
s << "No errors detected: " << logfn_ << std::endl; s << "No errors detected: " << logfn_ << std::endl;
return; return;
case ERR_OPEN_LOGFILE: case ST_CLEAN_EXIT:
s << "Engine exited cleanly without errors: " << logfn_ << std::endl;
return;
case ST_ERR_OPENING_LOGFILE:
s << "Could not open logfile: " << logfn_ << std::endl; s << "Could not open logfile: " << logfn_ << std::endl;
return; return;
case ERR_LOGFILE_EOF: case ST_LOGFILE_ENDS_ABRUPTLY:
s << "Logfile reached end-of-file: " << logfn_ << std::endl; s << "Logfile reached end-of-file: " << logfn_ << std::endl;
return; return;
case ERR_LOGFILE_CORRUPT: case ST_LOGFILE_CORRUPT:
s << "Logfile corrupt: " << logfn_ << std::endl; s << "Logfile corrupt: " << logfn_ << std::endl;
return; return;
case ERR_NONDERMINISTIC: case ST_NONDERMINISTIC:
s << "Nondeterminism detected: " << logfn_ << std::endl; s << "Nondeterminism detected: " << logfn_ << std::endl;
return; return;
case ERR_CREATE_ENGINE: case ST_COULDNT_CREATE_ENGINE:
s << "Could not create engine: " << logfn_ << " " << engine_ << std::endl; s << "Could not create engine: " << logfn_ << " " << engine_ << std::endl;
return; return;
} }
@@ -253,7 +258,7 @@ bool ReplayPlayer::open_logfile(const char *fn) {
f_.clear(); f_.clear();
f_.open(fn, std::ios_base::in | std::ios_base::binary); f_.open(fn, std::ios_base::in | std::ios_base::binary);
if (!f_.good()) { if (!f_.good()) {
set_error(ERR_OPEN_LOGFILE); set_status(ST_ERR_OPENING_LOGFILE);
return false; return false;
} }
return true; return true;
@@ -273,18 +278,29 @@ bool ReplayRecorder::create_engine(const char *kind) {
void ReplayPlayer::create_engine() { void ReplayPlayer::create_engine() {
std::string_view kind = rlog_string(f_, buf_.get()); std::string_view kind = rlog_string(f_, buf_.get());
if (!f_.good()) { if (!f_.good()) {
set_error(ERR_LOGFILE_CORRUPT); set_status(ST_LOGFILE_CORRUPT);
return; return;
} }
engine_ = std::string(kind); engine_ = std::string(kind);
e_ = DrivenEngine::make(kind); e_ = DrivenEngine::make(kind);
DrivenEngine::set(e_.get()); DrivenEngine::set(e_.get());
if (e_ == nullptr) { if (e_ == nullptr) {
set_error(ERR_CREATE_ENGINE); set_status(ST_COULDNT_CREATE_ENGINE);
return; return;
} }
} }
void ReplayRecorder::clean_exit() {
if (logging_) {
wlog_cmd_hash(f_, CLEAN_EXIT, eng::memhash());
flush();
}
}
void ReplayPlayer::clean_exit() {
set_status(ST_CLEAN_EXIT);
}
void ReplayRecorder::drv_clear_new_outgoing() { void ReplayRecorder::drv_clear_new_outgoing() {
if (logging_) { if (logging_) {
wlog_cmd_hash(f_, DRV_CLEAR_NEW_OUTGOING, eng::memhash()); wlog_cmd_hash(f_, DRV_CLEAR_NEW_OUTGOING, eng::memhash());
@@ -316,16 +332,16 @@ void ReplayPlayer::drv_sent_outgoing() {
int nbytes = rlog_uint16(f_); int nbytes = rlog_uint16(f_);
uint64_t hash = rlog_uint64(f_); uint64_t hash = rlog_uint64(f_);
if (!f_.good()) { if (!f_.good()) {
set_error(ERR_LOGFILE_CORRUPT); set_status(ST_LOGFILE_CORRUPT);
return; return;
} }
std::string_view data = e_->drv_peek_outgoing(chid); std::string_view data = e_->drv_peek_outgoing(chid);
if (nbytes > int(data.size())) { if (nbytes > int(data.size())) {
set_error(ERR_NONDERMINISTIC); set_status(ST_NONDERMINISTIC);
return; return;
} }
if (hash != SpookyHash::QkHash64(data.data(), nbytes)) { if (hash != SpookyHash::QkHash64(data.data(), nbytes)) {
set_error(ERR_NONDERMINISTIC); set_status(ST_NONDERMINISTIC);
return; return;
} }
e_->drv_sent_outgoing(chid, nbytes); e_->drv_sent_outgoing(chid, nbytes);
@@ -345,7 +361,7 @@ void ReplayPlayer::drv_recv_incoming() {
int chid = rlog_uint16(f_); int chid = rlog_uint16(f_);
std::string_view data = rlog_string(f_, buf_.get()); std::string_view data = rlog_string(f_, buf_.get());
if (!f_.good()) { if (!f_.good()) {
set_error(ERR_LOGFILE_CORRUPT); set_status(ST_LOGFILE_CORRUPT);
return; return;
} }
e_->drv_recv_incoming(chid, data); e_->drv_recv_incoming(chid, data);
@@ -365,7 +381,7 @@ void ReplayPlayer::drv_notify_close() {
int chid = rlog_uint16(f_); int chid = rlog_uint16(f_);
std::string_view err = rlog_string(f_, buf_.get()); std::string_view err = rlog_string(f_, buf_.get());
if (!f_.good()) { if (!f_.good()) {
set_error(ERR_LOGFILE_CORRUPT); set_status(ST_LOGFILE_CORRUPT);
return; return;
} }
e_->drv_notify_close(chid, err); e_->drv_notify_close(chid, err);
@@ -383,7 +399,7 @@ int ReplayRecorder::drv_notify_accept(int port) {
void ReplayPlayer::drv_notify_accept() { void ReplayPlayer::drv_notify_accept() {
int port = rlog_uint16(f_); int port = rlog_uint16(f_);
if (!f_.good()) { if (!f_.good()) {
set_error(ERR_LOGFILE_CORRUPT); set_status(ST_LOGFILE_CORRUPT);
return; return;
} }
e_->drv_notify_accept(port); e_->drv_notify_accept(port);
@@ -415,7 +431,7 @@ void ReplayPlayer::drv_add_lua_source() {
std::string fn(rlog_string(f_, buf_.get())); std::string fn(rlog_string(f_, buf_.get()));
std::string_view data = rlog_string(f_, buf_.get()); std::string_view data = rlog_string(f_, buf_.get());
if (!f_.good()) { if (!f_.good()) {
set_error(ERR_LOGFILE_CORRUPT); set_status(ST_LOGFILE_CORRUPT);
return; return;
} }
e_->drv_add_lua_source(fn, data); e_->drv_add_lua_source(fn, data);
@@ -438,17 +454,17 @@ void ReplayPlayer::drv_invoke_event_init() {
std::vector<std::string> argv; std::vector<std::string> argv;
int argc = rlog_uint16(f_); int argc = rlog_uint16(f_);
if (!f_.good()) { if (!f_.good()) {
set_error(ERR_LOGFILE_CORRUPT); set_status(ST_LOGFILE_CORRUPT);
return; return;
} }
if (argc > MAX_ARGC) { if (argc > MAX_ARGC) {
set_error(ERR_LOGFILE_CORRUPT); set_status(ST_LOGFILE_CORRUPT);
return; return;
} }
for (int i = 0; i < argc; i++) { for (int i = 0; i < argc; i++) {
std::string_view arg = rlog_string(f_, buf_.get()); std::string_view arg = rlog_string(f_, buf_.get());
if (!f_.good()) { if (!f_.good()) {
set_error(ERR_LOGFILE_CORRUPT); set_status(ST_LOGFILE_CORRUPT);
return; return;
} }
argv.emplace_back(arg); argv.emplace_back(arg);
@@ -472,7 +488,7 @@ void ReplayRecorder::drv_invoke_event_update(double clock) {
void ReplayPlayer::drv_invoke_event_update() { void ReplayPlayer::drv_invoke_event_update() {
double clock = rlog_double(f_); double clock = rlog_double(f_);
if (!f_.good()) { if (!f_.good()) {
set_error(ERR_LOGFILE_CORRUPT); set_status(ST_LOGFILE_CORRUPT);
return; return;
} }
e_->drv_invoke_event_update(clock); e_->drv_invoke_event_update(clock);

View File

@@ -49,6 +49,11 @@ public:
// //
bool create_engine(const char *kind); bool create_engine(const char *kind);
// Report to the logger that the engine is about to exit cleanly,
// without any error.
//
void clean_exit();
// These don't need to be logged. // These don't need to be logged.
// //
const eng::vector<int> &drv_get_listen_ports() const { return e_->drv_get_listen_ports(); } const eng::vector<int> &drv_get_listen_ports() const { return e_->drv_get_listen_ports(); }
@@ -75,25 +80,27 @@ public:
class ReplayPlayer { class ReplayPlayer {
public: public:
enum Error { enum Status {
ERR_NONE, ST_REPLAYING,
ERR_OPEN_LOGFILE, ST_CLEAN_EXIT,
ERR_LOGFILE_EOF, ST_ERR_OPENING_LOGFILE,
ERR_LOGFILE_CORRUPT, ST_LOGFILE_ENDS_ABRUPTLY,
ERR_NONDERMINISTIC, ST_LOGFILE_CORRUPT,
ERR_CREATE_ENGINE, ST_NONDERMINISTIC,
ST_COULDNT_CREATE_ENGINE,
}; };
private: private:
std::ifstream f_; std::ifstream f_;
UniqueDrivenEngine e_; UniqueDrivenEngine e_;
std::unique_ptr<char[]> buf_; std::unique_ptr<char[]> buf_;
Error error_; Status status_;
std::string logfn_; std::string logfn_;
std::string engine_; std::string engine_;
void set_error(Error e); void set_status(Status e);
void create_engine(); void create_engine();
void clean_exit();
void drv_clear_new_outgoing(); void drv_clear_new_outgoing();
void drv_sent_outgoing(); void drv_sent_outgoing();
void drv_recv_incoming(); void drv_recv_incoming();
@@ -114,16 +121,16 @@ public:
// Execute a single step from the replay log. // Execute a single step from the replay log.
// //
// Returns an error code, which is usually ERR_NONE. // Returns a status code, which is usually ST_REPLAYING.
// If it's anything else, display an error and stop. // If it's anything else, display the status and stop.
// //
Error step(); Status step();
// Print an error message. // Print a status message.
// //
// Print a message associated with the most recent error. // Print a message associated with the most recent status report.
// //
void print_error(std::ostream &s); void print_status(std::ostream &s);
}; };
} // namespace drv } // namespace drv

BIN
luprex/core/rep.log Normal file

Binary file not shown.