openMSX
ReverseManager.cc
Go to the documentation of this file.
1 #include "ReverseManager.hh"
2 #include "MSXMotherBoard.hh"
3 #include "EventDistributor.hh"
5 #include "Keyboard.hh"
6 #include "Debugger.hh"
7 #include "EventDelay.hh"
8 #include "MSXMixer.hh"
10 #include "XMLException.hh"
11 #include "TclArgParser.hh"
12 #include "TclObject.hh"
13 #include "FileOperations.hh"
14 #include "FileContext.hh"
15 #include "StateChange.hh"
16 #include "Timer.hh"
17 #include "CliComm.hh"
18 #include "Display.hh"
19 #include "Reactor.hh"
20 #include "CommandException.hh"
21 #include "MemBuffer.hh"
22 #include "one_of.hh"
23 #include "ranges.hh"
24 #include "serialize.hh"
25 #include "serialize_meta.hh"
26 #include "view.hh"
27 #include <cassert>
28 #include <cmath>
29 #include <iomanip>
30 
31 using std::string;
32 using std::vector;
33 using std::shared_ptr;
34 using std::move;
35 
36 namespace openmsx {
37 
38 // Time between two snapshots (in seconds)
39 constexpr double SNAPSHOT_PERIOD = 1.0;
40 
41 // Max number of snapshots in a replay file
42 constexpr unsigned MAX_NOF_SNAPSHOTS = 10;
43 
44 // Min distance between snapshots in replay file (in seconds)
45 constexpr auto MIN_PARTITION_LENGTH = EmuDuration(60.0);
46 
47 // Max distance of one before last snapshot before the end time in replay file (in seconds)
49 
50 constexpr const char* const REPLAY_DIR = "replays";
51 
52 // A replay is a struct that contains a vector of motherboards and an MSX event
53 // log. Those combined are a replay, because you can replay the events from an
54 // existing motherboard state: the vector has to have at least one motherboard
55 // (the initial state), but can have optionally more motherboards, which are
56 // merely in-between snapshots, so it is quicker to jump to a later time in the
57 // event log.
58 
59 struct Replay
60 {
61  explicit Replay(Reactor& reactor_)
62  : reactor(reactor_), currentTime(EmuTime::dummy()) {}
63 
65 
66  ReverseManager::Events* events;
67  std::vector<Reactor::Board> motherBoards;
68  EmuTime currentTime;
69  // this is the amount of times the reverse goto command was used, which
70  // is interesting for the TAS community (see tasvideos.org). It's an
71  // indication of the effort it took to create the replay. Note that
72  // there is no way to verify this number.
73  unsigned reRecordCount;
74 
75  template<typename Archive>
76  void serialize(Archive& ar, unsigned version)
77  {
78  if (ar.versionAtLeast(version, 2)) {
79  ar.serializeWithID("snapshots", motherBoards, std::ref(reactor));
80  } else {
82  ar.serialize("snapshot", *newBoard);
83  motherBoards.push_back(move(newBoard));
84  }
85 
86  ar.serialize("events", *events);
87 
88  if (ar.versionAtLeast(version, 3)) {
89  ar.serialize("currentTime", currentTime);
90  } else {
91  assert(ar.isLoader());
92  assert(!events->empty());
93  currentTime = events->back()->getTime();
94  }
95 
96  if (ar.versionAtLeast(version, 4)) {
97  ar.serialize("reRecordCount", reRecordCount);
98  }
99  }
100 };
101 SERIALIZE_CLASS_VERSION(Replay, 4);
102 
103 
104 // struct ReverseHistory
105 
106 void ReverseManager::ReverseHistory::swap(ReverseHistory& other)
107 {
108  std::swap(chunks, other.chunks);
109  std::swap(events, other.events);
110 }
111 
112 void ReverseManager::ReverseHistory::clear()
113 {
114  // clear() and free storage capacity
115  Chunks().swap(chunks);
116  Events().swap(events);
117 }
118 
119 
120 class EndLogEvent final : public StateChange
121 {
122 public:
123  EndLogEvent() = default; // for serialize
124  explicit EndLogEvent(EmuTime::param time_)
125  : StateChange(time_)
126  {
127  }
128 
129  template<typename Archive> void serialize(Archive& ar, unsigned /*version*/)
130  {
131  ar.template serializeBase<StateChange>(*this);
132  }
133 };
134 REGISTER_POLYMORPHIC_CLASS(StateChange, EndLogEvent, "EndLog");
135 
136 // class ReverseManager
137 
139  : syncNewSnapshot(motherBoard_.getScheduler())
140  , syncInputEvent (motherBoard_.getScheduler())
141  , motherBoard(motherBoard_)
142  , eventDistributor(motherBoard.getReactor().getEventDistributor())
143  , reverseCmd(motherBoard.getCommandController())
144  , keyboard(nullptr)
145  , eventDelay(nullptr)
146  , replayIndex(0)
147  , collecting(false)
148  , pendingTakeSnapshot(false)
149  , reRecordCount(0)
150 {
151  eventDistributor.registerEventListener(OPENMSX_TAKE_REVERSE_SNAPSHOT, *this);
152 
153  assert(!isCollecting());
154  assert(!isReplaying());
155 }
156 
158 {
159  stop();
161 }
162 
163 bool ReverseManager::isReplaying() const
164 {
165  return replayIndex != history.events.size();
166 }
167 
168 void ReverseManager::start()
169 {
170  if (!isCollecting()) {
171  // create first snapshot
172  collecting = true;
173  takeSnapshot(getCurrentTime());
174  // schedule creation of next snapshot
175  schedule(getCurrentTime());
176  // start recording events
177  motherBoard.getStateChangeDistributor().registerRecorder(*this);
178  }
179  assert(isCollecting());
180 }
181 
182 void ReverseManager::stop()
183 {
184  if (isCollecting()) {
185  motherBoard.getStateChangeDistributor().unregisterRecorder(*this);
186  syncNewSnapshot.removeSyncPoint(); // don't schedule new snapshot takings
187  syncInputEvent .removeSyncPoint(); // stop any pending replay actions
188  history.clear();
189  replayIndex = 0;
190  collecting = false;
191  pendingTakeSnapshot = false;
192  }
193  assert(!pendingTakeSnapshot);
194  assert(!isCollecting());
195  assert(!isReplaying());
196 }
197 
198 EmuTime::param ReverseManager::getEndTime(const ReverseHistory& hist) const
199 {
200  if (!hist.events.empty()) {
201  if (auto* ev = dynamic_cast<const EndLogEvent*>(
202  hist.events.back().get())) {
203  // last log element is EndLogEvent, use that
204  return ev->getTime();
205  }
206  }
207  // otherwise use current time
208  assert(!isReplaying());
209  return getCurrentTime();
210 }
211 
212 void ReverseManager::status(TclObject& result) const
213 {
214  result.addDictKeyValue("status", !isCollecting() ? "disabled"
215  : isReplaying() ? "replaying"
216  : "enabled");
217 
218  EmuTime b(isCollecting() ? begin(history.chunks)->second.time
219  : EmuTime::zero());
220  result.addDictKeyValue("begin", (b - EmuTime::zero()).toDouble());
221 
222  EmuTime end(isCollecting() ? getEndTime(history) : EmuTime::zero());
223  result.addDictKeyValue("end", (end - EmuTime::zero()).toDouble());
224 
225  EmuTime current(isCollecting() ? getCurrentTime() : EmuTime::zero());
226  result.addDictKeyValue("current", (current - EmuTime::zero()).toDouble());
227 
228  TclObject snapshots;
229  snapshots.addListElements(view::transform(history.chunks, [](auto& p) {
230  return (p.second.time - EmuTime::zero()).toDouble();
231  }));
232  result.addDictKeyValue("snapshots", snapshots);
233 
234  auto lastEvent = rbegin(history.events);
235  if (lastEvent != rend(history.events) && dynamic_cast<const EndLogEvent*>(lastEvent->get())) {
236  ++lastEvent;
237  }
238  EmuTime le(isCollecting() && (lastEvent != rend(history.events)) ? (*lastEvent)->getTime() : EmuTime::zero());
239  result.addDictKeyValue("last_event", (le - EmuTime::zero()).toDouble());
240 }
241 
242 void ReverseManager::debugInfo(TclObject& result) const
243 {
244  // TODO this is useful during development, but for the end user this
245  // information means nothing. We should remove this later.
246  string res;
247  size_t totalSize = 0;
248  for (const auto& [idx, chunk] : history.chunks) {
249  strAppend(res, idx, ' ',
250  (chunk.time - EmuTime::zero()).toDouble(), ' ',
251  ((chunk.time - EmuTime::zero()).toDouble() / (getCurrentTime() - EmuTime::zero()).toDouble()) * 100, "%"
252  " (", chunk.size, ")"
253  " (next event index: ", chunk.eventCount, ")\n");
254  totalSize += chunk.size;
255  }
256  strAppend(res, "total size: ", totalSize, '\n');
257  result = res;
258 }
259 
260 static void parseGoTo(Interpreter& interp, span<const TclObject> tokens,
261  bool& novideo, double& time)
262 {
263  novideo = false;
264  ArgsInfo info[] = { flagArg("-novideo", novideo) };
265  auto args = parseTclArgs(interp, tokens.subspan(2), info);
266  if (args.size() != 1) throw SyntaxError();
267  time = args[0].getDouble(interp);
268 }
269 
270 void ReverseManager::goBack(span<const TclObject> tokens)
271 {
272  bool novideo;
273  double t;
274  auto& interp = motherBoard.getReactor().getInterpreter();
275  parseGoTo(interp, tokens, novideo, t);
276 
277  EmuTime now = getCurrentTime();
278  EmuTime target(EmuTime::dummy());
279  if (t >= 0) {
280  EmuDuration d(t);
281  if (d < (now - EmuTime::zero())) {
282  target = now - d;
283  } else {
284  target = EmuTime::zero();
285  }
286  } else {
287  target = now + EmuDuration(-t);
288  }
289  goTo(target, novideo);
290 }
291 
292 void ReverseManager::goTo(span<const TclObject> tokens)
293 {
294  bool novideo;
295  double t;
296  auto& interp = motherBoard.getReactor().getInterpreter();
297  parseGoTo(interp, tokens, novideo, t);
298 
299  EmuTime target = EmuTime::zero() + EmuDuration(t);
300  goTo(target, novideo);
301 }
302 
303 void ReverseManager::goTo(EmuTime::param target, bool novideo)
304 {
305  if (!isCollecting()) {
306  throw CommandException(
307  "Reverse was not enabled. First execute the 'reverse "
308  "start' command to start collecting data.");
309  }
310  goTo(target, novideo, history, true); // move in current time-line
311 }
312 
313 // this function is used below, but factored out, because it's already way too long
314 static void reportProgress(Reactor& reactor, const EmuTime& targetTime, int percentage)
315 {
316  double targetTimeDisp = (targetTime - EmuTime::zero()).toDouble();
317  std::ostringstream sstr;
318  sstr << "Time warping to " <<
319  int(targetTimeDisp / 60) << ':' << std::setfill('0') <<
320  std::setw(5) << std::setprecision(2) << std::fixed <<
321  std::fmod(targetTimeDisp, 60.0) <<
322  "... " << percentage << '%';
323  reactor.getCliComm().printProgress(sstr.str());
324  reactor.getDisplay().repaintDelayed(0);
325 }
326 
327 void ReverseManager::goTo(
328  EmuTime::param target, bool novideo, ReverseHistory& hist,
329  bool sameTimeLine)
330 {
331  auto& mixer = motherBoard.getMSXMixer();
332  try {
333  // The call to MSXMotherBoard::fastForward() below may take
334  // some time to execute. The DirectX sound driver has a problem
335  // (not easily fixable) that it keeps on looping the sound
336  // buffer on buffer underruns (the SDL driver plays silence on
337  // underrun). At the end of this function we will switch to a
338  // different active MSXMotherBoard. So we can as well now
339  // already mute the current MSXMotherBoard.
340  mixer.mute();
341 
342  // -- Locate destination snapshot --
343  // We can't go back further in the past than the first snapshot.
344  assert(!hist.chunks.empty());
345  auto it = begin(hist.chunks);
346  EmuTime firstTime = it->second.time;
347  EmuTime targetTime = std::max(target, firstTime);
348  // Also don't go further into the future than 'end time'.
349  targetTime = std::min(targetTime, getEndTime(hist));
350 
351  // Duration of 2 PAL frames. Possible improvement is to use the
352  // actual refresh rate (PAL/NTSC). But it should be the refresh
353  // rate of the active video chip (v99x8/v9990) at the target
354  // time. This is quite complex to get and the difference between
355  // 2 PAL and 2 NTSC frames isn't that big.
356  double dur2frames = 2.0 * (313.0 * 1368.0) / (3579545.0 * 6.0);
357  EmuDuration preDelta(novideo ? 0.0 : dur2frames);
358  EmuTime preTarget = ((targetTime - firstTime) > preDelta)
359  ? targetTime - preDelta
360  : firstTime;
361 
362  // find oldest snapshot that is not newer than requested time
363  // TODO ATM we do a linear search, could be improved to do a binary search.
364  assert(it->second.time <= preTarget); // first one is not newer
365  assert(it != end(hist.chunks)); // there are snapshots
366  do {
367  ++it;
368  } while (it != end(hist.chunks) &&
369  it->second.time <= preTarget);
370  // We found the first one that's newer, previous one is last
371  // one that's not newer (thus older or equal).
372  assert(it != begin(hist.chunks));
373  --it;
374  ReverseChunk& chunk = it->second;
375  EmuTime snapshotTime = chunk.time;
376  assert(snapshotTime <= preTarget);
377 
378  // IF current time is before the wanted time AND either
379  // - current time is closer than the closest (earlier) snapshot
380  // - OR current time is close enough (I arbitrarily choose 1s)
381  // THEN it's cheaper to start from the current position (and
382  // emulated forward) than to start from a snapshot
383  // THOUGH only when we're currently in the same time-line
384  // e.g. OK for a 'reverse goto' command, but not for a
385  // 'reverse loadreplay' command.
386  auto& reactor = motherBoard.getReactor();
387  EmuTime currentTime = getCurrentTime();
388  MSXMotherBoard* newBoard;
389  Reactor::Board newBoard_; // either nullptr or the same as newBoard
390  if (sameTimeLine &&
391  (currentTime <= preTarget) &&
392  ((snapshotTime <= currentTime) ||
393  ((preTarget - currentTime) < EmuDuration(1.0)))) {
394  newBoard = &motherBoard; // use current board
395  } else {
396  // Note: we don't (anymore) erase future snapshots
397  // -- restore old snapshot --
398  newBoard_ = reactor.createEmptyMotherBoard();
399  newBoard = newBoard_.get();
400  MemInputArchive in(chunk.savestate.data(),
401  chunk.size,
402  chunk.deltaBlocks);
403  in.serialize("machine", *newBoard);
404 
405  if (eventDelay) {
406  // Handle all events that are scheduled, but not yet
407  // distributed. This makes sure no events get lost
408  // (important to keep host/msx keyboard in sync).
409  eventDelay->flush();
410  }
411 
412  // terminate replay log with EndLogEvent (if not there already)
413  if (hist.events.empty() ||
414  !dynamic_cast<const EndLogEvent*>(hist.events.back().get())) {
415  hist.events.push_back(
416  std::make_shared<EndLogEvent>(currentTime));
417  }
418 
419  // Transfer history to the new ReverseManager.
420  // Also we should stop collecting in this ReverseManager,
421  // and start collecting in the new one.
422  auto& newManager = newBoard->getReverseManager();
423  newManager.transferHistory(hist, chunk.eventCount);
424 
425  // transfer (or copy) state from old to new machine
426  transferState(*newBoard);
427 
428  // In case of load-replay it's possible we are not collecting,
429  // but calling stop() anyway is ok.
430  stop();
431  }
432 
433  // -- goto correct time within snapshot --
434  // Fast forward 2 frames before target time.
435  // If we're short on snapshots, create them at intervals that are
436  // at least the usual interval, but the later, the more: each
437  // time divide the remaining time in half and make a snapshot
438  // there.
439  auto lastProgress = Timer::getTime();
440  auto startMSXTime = newBoard->getCurrentTime();
441  auto lastSnapshotTarget = startMSXTime;
442  bool everShowedProgress = false;
443  syncNewSnapshot.removeSyncPoint(); // don't schedule new snapshot takings during fast forward
444  while (true) {
445  auto currentTimeNewBoard = newBoard->getCurrentTime();
446  auto nextSnapshotTarget = std::min(
447  preTarget,
448  lastSnapshotTarget + std::max(
449  EmuDuration(SNAPSHOT_PERIOD),
450  (preTarget - lastSnapshotTarget) / 2
451  ));
452  auto nextTarget = std::min(nextSnapshotTarget, currentTimeNewBoard + EmuDuration::sec(1));
453  newBoard->fastForward(nextTarget, true);
454  auto now = Timer::getTime();
455  if (((now - lastProgress) > 1000000) || ((currentTimeNewBoard >= preTarget) && everShowedProgress)) {
456  everShowedProgress = true;
457  lastProgress = now;
458  int percentage = ((currentTimeNewBoard - startMSXTime) * 100u) / (preTarget - startMSXTime);
459  reportProgress(newBoard->getReactor(), targetTime, percentage);
460  }
461  // note: fastForward does not always stop at
462  // _exactly_ the requested time
463  if (currentTimeNewBoard >= preTarget) break;
464  if (currentTimeNewBoard >= nextSnapshotTarget) {
465  // NOTE: there used to be
466  //newBoard->getReactor().getEventDistributor().deliverEvents();
467  // here, but that has all kinds of nasty side effects: it enables
468  // processing of hotkeys, which can cause things like the machine
469  // being deleted, causing a crash. TODO: find a better way to support
470  // live updates of the UI whilst being in a reverse action...
471  newBoard->getReverseManager().takeSnapshot(currentTimeNewBoard);
472  lastSnapshotTarget = nextSnapshotTarget;
473  }
474  }
475  // re-enable automatic snapshots
476  schedule(getCurrentTime());
477 
478  // switch to the new MSXMotherBoard
479  // Note: this deletes the current MSXMotherBoard and
480  // ReverseManager. So we can't access those objects anymore.
481  bool unmute = true;
482  if (newBoard_) {
483  unmute = false;
484  reactor.replaceBoard(motherBoard, move(newBoard_));
485  }
486 
487  // Fast forward to actual target time with board activated.
488  // This makes sure the video output gets rendered.
489  newBoard->fastForward(targetTime, false);
490 
491  // In case we didn't actually create a new board, don't leave
492  // the (old) board muted.
493  if (unmute) {
494  mixer.unmute();
495  }
496 
497  //assert(!isCollecting()); // can't access 'this->' members anymore!
498  assert(newBoard->getReverseManager().isCollecting());
499  } catch (MSXException&) {
500  // Make sure mixer doesn't stay muted in case of error.
501  mixer.unmute();
502  throw;
503  }
504 }
505 
506 void ReverseManager::transferState(MSXMotherBoard& newBoard)
507 {
508  // Transfer viewonly mode
509  const auto& oldDistributor = motherBoard.getStateChangeDistributor();
510  auto& newDistributor = newBoard .getStateChangeDistributor();
511  newDistributor.setViewOnlyMode(oldDistributor.isViewOnlyMode());
512 
513  // transfer keyboard state
514  auto& newManager = newBoard.getReverseManager();
515  if (newManager.keyboard && keyboard) {
516  newManager.keyboard->transferHostKeyMatrix(*keyboard);
517  }
518 
519  // transfer watchpoints
520  newBoard.getDebugger().transfer(motherBoard.getDebugger());
521 
522  // copy rerecord count
523  newManager.reRecordCount = reRecordCount;
524 
525  // transfer settings
526  const auto& oldController = motherBoard.getMSXCommandController();
527  newBoard.getMSXCommandController().transferSettings(oldController);
528 }
529 
530 void ReverseManager::saveReplay(
531  Interpreter& interp, span<const TclObject> tokens, TclObject& result)
532 {
533  const auto& chunks = history.chunks;
534  if (chunks.empty()) {
535  throw CommandException("No recording...");
536  }
537 
538  std::string_view filenameArg;
539  int maxNofExtraSnapshots = MAX_NOF_SNAPSHOTS;
540  ArgsInfo info[] = { valueArg("-maxnofextrasnapshots", maxNofExtraSnapshots) };
541  auto args = parseTclArgs(interp, tokens.subspan(2), info);
542  switch (args.size()) {
543  case 0: break; // nothing
544  case 1: filenameArg = args[0].getString(); break;
545  default: throw SyntaxError();
546  }
547  if (maxNofExtraSnapshots < 0) {
548  throw CommandException("Maximum number of snapshots should be at least 0");
549  }
550 
552  filenameArg, REPLAY_DIR, "openmsx", ".omr");
553 
554  auto& reactor = motherBoard.getReactor();
555  Replay replay(reactor);
556  replay.reRecordCount = reRecordCount;
557 
558  // store current time (possibly somewhere in the middle of the timeline)
559  // so that on load we can go back there
560  replay.currentTime = getCurrentTime();
561 
562  // restore first snapshot to be able to serialize it to a file
563  auto initialBoard = reactor.createEmptyMotherBoard();
564  MemInputArchive in(begin(chunks)->second.savestate.data(),
565  begin(chunks)->second.size,
566  begin(chunks)->second.deltaBlocks);
567  in.serialize("machine", *initialBoard);
568  replay.motherBoards.push_back(move(initialBoard));
569 
570  if (maxNofExtraSnapshots > 0) {
571  // determine which extra snapshots to put in the replay
572  const auto& startTime = begin(chunks)->second.time;
573  // for the end time, try to take MAX_DIST_1_BEFORE_LAST_SNAPSHOT
574  // seconds before the normal end time so that we get an extra snapshot
575  // at that point, which is comfortable if you want to reverse from the
576  // last snapshot after loading the replay.
577  const auto& lastChunkTime = rbegin(chunks)->second.time;
578  const auto& endTime = ((startTime + MAX_DIST_1_BEFORE_LAST_SNAPSHOT) < lastChunkTime) ? lastChunkTime - MAX_DIST_1_BEFORE_LAST_SNAPSHOT : lastChunkTime;
579  EmuDuration totalLength = endTime - startTime;
580  EmuDuration partitionLength = totalLength.divRoundUp(maxNofExtraSnapshots);
581  partitionLength = std::max(MIN_PARTITION_LENGTH, partitionLength);
582  EmuTime nextPartitionEnd = startTime + partitionLength;
583  auto it = begin(chunks);
584  auto lastAddedIt = begin(chunks); // already added
585  while (it != end(chunks)) {
586  ++it;
587  if (it == end(chunks) || (it->second.time > nextPartitionEnd)) {
588  --it;
589  assert(it->second.time <= nextPartitionEnd);
590  if (it != lastAddedIt) {
591  // this is a new one, add it to the list of snapshots
592  Reactor::Board board = reactor.createEmptyMotherBoard();
593  MemInputArchive in2(it->second.savestate.data(),
594  it->second.size,
595  it->second.deltaBlocks);
596  in2.serialize("machine", *board);
597  replay.motherBoards.push_back(move(board));
598  lastAddedIt = it;
599  }
600  ++it;
601  while (it != end(chunks) && it->second.time > nextPartitionEnd) {
602  nextPartitionEnd += partitionLength;
603  }
604  }
605  }
606  assert(lastAddedIt == std::prev(end(chunks))); // last snapshot must be included
607  }
608 
609  // add sentinel when there isn't one yet
610  bool addSentinel = history.events.empty() ||
611  !dynamic_cast<EndLogEvent*>(history.events.back().get());
612  if (addSentinel) {
614  history.events.push_back(std::make_shared<EndLogEvent>(
615  getCurrentTime()));
616  }
617  try {
618  XmlOutputArchive out(filename);
619  replay.events = &history.events;
620  out.serialize("replay", replay);
621  out.close();
622  } catch (MSXException&) {
623  if (addSentinel) {
624  history.events.pop_back();
625  }
626  throw;
627  }
628 
629  if (addSentinel) {
630  // Is there a cleaner way to only add the sentinel in the log?
631  // I mean avoid changing/restoring the current log. We could
632  // make a copy and work on that, but that seems much less
633  // efficient.
634  history.events.pop_back();
635  }
636 
637  result = "Saved replay to " + filename;
638 }
639 
640 void ReverseManager::loadReplay(
641  Interpreter& interp, span<const TclObject> tokens, TclObject& result)
642 {
643  bool enableViewOnly = false;
644  std::optional<TclObject> where;
645  ArgsInfo info[] = {
646  flagArg("-viewonly", enableViewOnly),
647  valueArg("-goto", where),
648  };
649  auto arguments = parseTclArgs(interp, tokens.subspan(2), info);
650  if (arguments.size() != 1) throw SyntaxError();
651 
652  // resolve the filename
654  string fileNameArg(arguments[0].getString());
655  string filename;
656  try {
657  // Try filename as typed by user.
658  filename = context.resolve(fileNameArg);
659  } catch (MSXException& /*e1*/) { try {
660  // Not found, try adding '.omr'.
661  filename = context.resolve(fileNameArg + ".omr");
662  } catch (MSXException& e2) { try {
663  // Again not found, try adding '.gz'.
664  // (this is for backwards compatibility).
665  filename = context.resolve(fileNameArg + ".gz");
666  } catch (MSXException& /*e3*/) {
667  // Show error message that includes the default extension.
668  throw e2;
669  }}}
670 
671  // restore replay
672  auto& reactor = motherBoard.getReactor();
673  Replay replay(reactor);
674  Events events;
675  replay.events = &events;
676  try {
677  XmlInputArchive in(filename);
678  in.serialize("replay", replay);
679  } catch (XMLException& e) {
680  throw CommandException("Cannot load replay, bad file format: ",
681  e.getMessage());
682  } catch (MSXException& e) {
683  throw CommandException("Cannot load replay: ", e.getMessage());
684  }
685 
686  // get destination time index
687  auto destination = EmuTime::zero();
688  if (!where || (*where == "begin")) {
689  destination = EmuTime::zero();
690  } else if (*where == "end") {
691  destination = EmuTime::infinity();
692  } else if (*where == "savetime") {
693  destination = replay.currentTime;
694  } else {
695  destination += EmuDuration(where->getDouble(interp));
696  }
697 
698  // OK, we are going to be actually changing states now
699 
700  // now we can change the view only mode
701  motherBoard.getStateChangeDistributor().setViewOnlyMode(enableViewOnly);
702 
703  assert(!replay.motherBoards.empty());
704  auto& newReverseManager = replay.motherBoards[0]->getReverseManager();
705  auto& newHistory = newReverseManager.history;
706 
707  if (newReverseManager.reRecordCount == 0) {
708  // serialize Replay version >= 4
709  newReverseManager.reRecordCount = replay.reRecordCount;
710  } else {
711  // newReverseManager.reRecordCount is initialized via
712  // call from MSXMotherBoard to setReRecordCount()
713  }
714 
715  // Restore event log
716  swap(newHistory.events, events);
717  auto& newEvents = newHistory.events;
718 
719  // Restore snapshots
720  unsigned replayIdx = 0;
721  for (auto& m : replay.motherBoards) {
722  ReverseChunk newChunk;
723  newChunk.time = m->getCurrentTime();
724 
725  MemOutputArchive out(newHistory.lastDeltaBlocks,
726  newChunk.deltaBlocks, false);
727  out.serialize("machine", *m);
728  newChunk.savestate = out.releaseBuffer(newChunk.size);
729 
730  // update replayIdx
731  // TODO: should we use <= instead??
732  while (replayIdx < newEvents.size() &&
733  (newEvents[replayIdx]->getTime() < newChunk.time)) {
734  replayIdx++;
735  }
736  newChunk.eventCount = replayIdx;
737 
738  newHistory.chunks[newHistory.getNextSeqNum(newChunk.time)] =
739  move(newChunk);
740  }
741 
742  // Note: untill this point we didn't make any changes to the current
743  // ReverseManager/MSXMotherBoard yet
744  reRecordCount = newReverseManager.reRecordCount;
745  bool novideo = false;
746  goTo(destination, novideo, newHistory, false); // move to different time-line
747 
748  result = "Loaded replay from " + filename;
749 }
750 
751 void ReverseManager::transferHistory(ReverseHistory& oldHistory,
752  unsigned oldEventCount)
753 {
754  assert(!isCollecting());
755  assert(history.chunks.empty());
756 
757  // 'ids' for old and new serialize blobs don't match, so cleanup old cache
758  oldHistory.lastDeltaBlocks.clear();
759 
760  // actual history transfer
761  history.swap(oldHistory);
762 
763  // resume collecting (and event recording)
764  collecting = true;
765  schedule(getCurrentTime());
766  motherBoard.getStateChangeDistributor().registerRecorder(*this);
767 
768  // start replaying events
769  replayIndex = oldEventCount;
770  // replay log contains at least the EndLogEvent
771  assert(replayIndex < history.events.size());
772  replayNextEvent();
773 }
774 
775 void ReverseManager::execNewSnapshot()
776 {
777  // During record we should take regular snapshots, and 'now'
778  // it's been a while since the last snapshot. But 'now' can be
779  // in the middle of a CPU instruction (1). However the CPU
780  // emulation code cannot handle taking snapshots at arbitrary
781  // moments in EmuTime (2)(3)(4). So instead we send out an
782  // event that indicates we want to take a snapshot (5).
783  // (1) Schedulables are executed at the exact requested
784  // EmuTime, even in the middle of a Z80 instruction.
785  // (2) The CPU code serializes all registers, current time and
786  // various other status info, but not enough info to be
787  // able to resume in the middle of an instruction.
788  // (3) Only the CPU has this limitation of not being able to
789  // take a snapshot at any EmuTime, all other devices can.
790  // This is because in our emulation model the CPU 'drives
791  // time forward'. It's the only device code that can be
792  // interrupted by other emulation code (via Schedulables).
793  // (4) In the past we had a CPU core that could execute/resume
794  // partial instructions (search SVN history). Though it was
795  // much more complex and it also ran slower than the
796  // current code.
797  // (5) Events are delivered from the Reactor code. That code
798  // only runs when the CPU code has exited (meaning no
799  // longer active in any stackframe). So it's executed right
800  // after the CPU has finished the current instruction. And
801  // that's OK, we only require regular snapshots here, they
802  // should not be *exactly* equally far apart in time.
803  pendingTakeSnapshot = true;
804  eventDistributor.distributeEvent(
805  std::make_shared<SimpleEvent>(OPENMSX_TAKE_REVERSE_SNAPSHOT));
806 }
807 
808 void ReverseManager::execInputEvent()
809 {
810  auto event = history.events[replayIndex];
811  try {
812  // deliver current event at current time
813  motherBoard.getStateChangeDistributor().distributeReplay(event);
814  } catch (MSXException&) {
815  // can throw in case we replay a command that fails
816  // ignore
817  }
818  if (!dynamic_cast<const EndLogEvent*>(event.get())) {
819  ++replayIndex;
820  replayNextEvent();
821  } else {
822  assert(!isReplaying()); // stopped by replay of EndLogEvent
823  }
824 }
825 
826 int ReverseManager::signalEvent(const shared_ptr<const Event>& event)
827 {
828  (void)event;
829  assert(event->getType() == OPENMSX_TAKE_REVERSE_SNAPSHOT);
830 
831  // This event is send to all MSX machines, make sure it's actually this
832  // machine that requested the snapshot.
833  if (pendingTakeSnapshot) {
834  pendingTakeSnapshot = false;
835  takeSnapshot(getCurrentTime());
836  // schedule creation of next snapshot
837  schedule(getCurrentTime());
838  }
839  return 0;
840 }
841 
842 unsigned ReverseManager::ReverseHistory::getNextSeqNum(EmuTime::param time) const
843 {
844  if (chunks.empty()) {
845  return 0;
846  }
847  const auto& startTime = begin(chunks)->second.time;
848  double duration = (time - startTime).toDouble();
849  return lrint(duration / SNAPSHOT_PERIOD);
850 }
851 
852 void ReverseManager::takeSnapshot(EmuTime::param time)
853 {
854  // (possibly) drop old snapshots
855  // TODO does snapshot pruning still happen correctly (often enough)
856  // when going back/forward in time?
857  unsigned seqNum = history.getNextSeqNum(time);
858  dropOldSnapshots<25>(seqNum);
859 
860  // During replay we might already have a snapshot with the current
861  // sequence number, though this snapshot does not necessarily have the
862  // exact same EmuTime (because we don't (re)start taking snapshots at
863  // the same moment in time).
864 
865  // actually create new snapshot
866  ReverseChunk& newChunk = history.chunks[seqNum];
867  newChunk.deltaBlocks.clear();
868  MemOutputArchive out(history.lastDeltaBlocks, newChunk.deltaBlocks, true);
869  out.serialize("machine", motherBoard);
870  newChunk.time = time;
871  newChunk.savestate = out.releaseBuffer(newChunk.size);
872  newChunk.eventCount = replayIndex;
873 }
874 
875 void ReverseManager::replayNextEvent()
876 {
877  // schedule next event at its own time
878  assert(replayIndex < history.events.size());
879  syncInputEvent.setSyncPoint(history.events[replayIndex]->getTime());
880 }
881 
882 void ReverseManager::signalStateChange(const shared_ptr<StateChange>& event)
883 {
884  if (isReplaying()) {
885  // this is an event we just replayed
886  assert(event == history.events[replayIndex]);
887  if (dynamic_cast<EndLogEvent*>(event.get())) {
888  signalStopReplay(event->getTime());
889  } else {
890  // ignore all other events
891  }
892  } else {
893  // record event
894  history.events.push_back(event);
895  ++replayIndex;
896  assert(!isReplaying());
897  }
898 }
899 
900 void ReverseManager::signalStopReplay(EmuTime::param time)
901 {
902  motherBoard.getStateChangeDistributor().stopReplay(time);
903  // this is needed to prevent a reRecordCount increase
904  // due to this action ending the replay
905  reRecordCount--;
906 }
907 
908 void ReverseManager::stopReplay(EmuTime::param time)
909 {
910  if (isReplaying()) {
911  // if we're replaying, stop it and erase remainder of event log
912  syncInputEvent.removeSyncPoint();
913  Events& events = history.events;
914  events.erase(begin(events) + replayIndex, end(events));
915  // search snapshots that are newer than 'time' and erase them
916  auto it = ranges::find_if(history.chunks, [&](auto& p) {
917  return p.second.time > time;
918  });
919  history.chunks.erase(it, end(history.chunks));
920  // this also means someone is changing history, record that
921  reRecordCount++;
922  }
923  assert(!isReplaying());
924 }
925 
926 /* Should be called each time a new snapshot is added.
927  * This function will erase zero or more earlier snapshots so that there are
928  * more snapshots of recent history and less of distant history. It has the
929  * following properties:
930  * - the very oldest snapshot is never deleted
931  * - it keeps the N or N+1 most recent snapshots (snapshot distance = 1)
932  * - then it keeps N or N+1 with snapshot distance 2
933  * - then N or N+1 with snapshot distance 4
934  * - ... and so on
935  * @param count The index of the just added (or about to be added) element.
936  * First element should have index 1.
937  */
938 template<unsigned N>
939 void ReverseManager::dropOldSnapshots(unsigned count)
940 {
941  unsigned y = (count + N) ^ (count + N + 1);
942  unsigned d = N;
943  unsigned d2 = 2 * N + 1;
944  while (true) {
945  y >>= 1;
946  if ((y == 0) || (count < d)) return;
947  history.chunks.erase(count - d);
948  d += d2;
949  d2 *= 2;
950  }
951 }
952 
953 void ReverseManager::schedule(EmuTime::param time)
954 {
955  syncNewSnapshot.setSyncPoint(time + EmuDuration(SNAPSHOT_PERIOD));
956 }
957 
958 
959 // class ReverseCmd
960 
961 ReverseManager::ReverseCmd::ReverseCmd(CommandController& controller)
962  : Command(controller, "reverse")
963 {
964 }
965 
966 void ReverseManager::ReverseCmd::execute(span<const TclObject> tokens, TclObject& result)
967 {
968  checkNumArgs(tokens, AtLeast{2}, "subcommand ?arg ...?");
969  auto& manager = OUTER(ReverseManager, reverseCmd);
970  auto& interp = getInterpreter();
971  executeSubCommand(tokens[1].getString(),
972  "start", [&]{ manager.start(); },
973  "stop", [&]{ manager.stop(); },
974  "status", [&]{ manager.status(result); },
975  "debug", [&]{ manager.debugInfo(result); },
976  "goback", [&]{ manager.goBack(tokens); },
977  "goto", [&]{ manager.goTo(tokens); },
978  "savereplay", [&]{ manager.saveReplay(interp, tokens, result); },
979  "loadreplay", [&]{ manager.loadReplay(interp, tokens, result); },
980  "viewonlymode", [&]{
981  auto& distributor = manager.motherBoard.getStateChangeDistributor();
982  switch (tokens.size()) {
983  case 2:
984  result = distributor.isViewOnlyMode();
985  break;
986  case 3:
987  distributor.setViewOnlyMode(tokens[2].getBoolean(interp));
988  break;
989  default:
990  throw SyntaxError();
991  }},
992  "truncatereplay", [&] {
993  if (manager.isReplaying()) {
994  manager.signalStopReplay(manager.getCurrentTime());
995  }});
996 }
997 
998 string ReverseManager::ReverseCmd::help(const vector<string>& /*tokens*/) const
999 {
1000  return "start start collecting reverse data\n"
1001  "stop stop collecting\n"
1002  "status show various status info on reverse\n"
1003  "goback <n> go back <n> seconds in time\n"
1004  "goto <time> go to an absolute moment in time\n"
1005  "viewonlymode <bool> switch viewonly mode on or off\n"
1006  "truncatereplay stop replaying and remove all 'future' data\n"
1007  "savereplay [<name>] save the first snapshot and all replay data as a 'replay' (with optional name)\n"
1008  "loadreplay [-goto <begin|end|savetime|<n>>] [-viewonly] <name> load a replay (snapshot and replay data) with given name and start replaying\n";
1009 }
1010 
1011 void ReverseManager::ReverseCmd::tabCompletion(vector<string>& tokens) const
1012 {
1013  if (tokens.size() == 2) {
1014  static constexpr const char* const subCommands[] = {
1015  "start", "stop", "status", "goback", "goto",
1016  "savereplay", "loadreplay", "viewonlymode",
1017  "truncatereplay",
1018  };
1019  completeString(tokens, subCommands);
1020  } else if ((tokens.size() == 3) || (tokens[1] == "loadreplay")) {
1021  if (tokens[1] == one_of("loadreplay", "savereplay")) {
1022  std::vector<const char*> cmds;
1023  if (tokens[1] == "loadreplay") {
1024  cmds = { "-goto", "-viewonly" };
1025  }
1026  completeFileName(tokens, userDataFileContext(REPLAY_DIR), cmds);
1027  } else if (tokens[1] == "viewonlymode") {
1028  static constexpr const char* const options[] = { "true", "false" };
1029  completeString(tokens, options);
1030  }
1031  }
1032 }
1033 
1034 } // namespace openmsx
openmsx::MSXMotherBoard::getReactor
Reactor & getReactor()
Definition: MSXMotherBoard.hh:135
one_of.hh
openmsx::StateChangeDistributor::unregisterRecorder
void unregisterRecorder(StateChangeRecorder &recorder)
Definition: StateChangeDistributor.cc:36
openmsx::StateChangeDistributor::distributeReplay
void distributeReplay(const EventPtr &event)
Definition: StateChangeDistributor.cc:53
openmsx::userDataFileContext
FileContext userDataFileContext(string_view subDir)
Definition: FileContext.cc:171
gl::min
vecN< N, T > min(const vecN< N, T > &x, const vecN< N, T > &y)
Definition: gl_vec.hh:274
openmsx::StateChangeDistributor::registerRecorder
void registerRecorder(StateChangeRecorder &recorder)
(Un)registers the given object to receive state change events.
Definition: StateChangeDistributor.cc:30
Timer.hh
Display.hh
serialize.hh
openmsx::MAX_DIST_1_BEFORE_LAST_SNAPSHOT
constexpr auto MAX_DIST_1_BEFORE_LAST_SNAPSHOT
Definition: ReverseManager.cc:48
openmsx::EndLogEvent::EndLogEvent
EndLogEvent()=default
openmsx::Replay::motherBoards
std::vector< Reactor::Board > motherBoards
Definition: ReverseManager.cc:67
openmsx::flagArg
ArgsInfo flagArg(std::string_view name, bool &flag)
Definition: TclArgParser.hh:72
openmsx::ReverseManager::Replay
friend struct Replay
Definition: ReverseManager.hh:155
openmsx::Replay::reRecordCount
unsigned reRecordCount
Definition: ReverseManager.cc:73
openmsx::EmuDuration
Definition: EmuDuration.hh:18
openmsx::StateChange
Base class for all external MSX state changing events.
Definition: StateChange.hh:13
TclObject.hh
XMLException.hh
serialize_meta.hh
openmsx::REPLAY_DIR
constexpr const char *const REPLAY_DIR
Definition: ReverseManager.cc:50
LZ4::count
ALWAYS_INLINE unsigned count(const uint8_t *pIn, const uint8_t *pMatch, const uint8_t *pInLimit)
Definition: lz4.cc:207
openmsx::Replay::events
ReverseManager::Events * events
Definition: ReverseManager.cc:66
t
TclObject t
Definition: TclObject_test.cc:264
ranges.hh
openmsx::MSXMotherBoard::getStateChangeDistributor
StateChangeDistributor & getStateChangeDistributor()
Definition: MSXMotherBoard.hh:120
openmsx::Timer::getTime
uint64_t getTime()
Get current (real) time in us.
Definition: Timer.cc:7
openmsx::Replay::currentTime
EmuTime currentTime
Definition: ReverseManager.cc:68
openmsx::Reactor::Board
std::unique_ptr< MSXMotherBoard > Board
Definition: Reactor.hh:110
strAppend
void strAppend(std::string &result, Ts &&...ts)
Definition: strCat.hh:644
StateChangeDistributor.hh
span::subspan
constexpr subspan_return_t< Offset, Count > subspan() const
Definition: span.hh:266
openmsx::Reactor::createEmptyMotherBoard
Board createEmptyMotherBoard()
Definition: Reactor.cc:395
EventDelay.hh
span
Definition: span.hh:34
openmsx::Reactor
Contains the main loop of openMSX.
Definition: Reactor.hh:66
openmsx::SERIALIZE_CLASS_VERSION
SERIALIZE_CLASS_VERSION(CassettePlayer, 2)
openmsx::StateChangeDistributor::stopReplay
void stopReplay(EmuTime::param time)
Explicitly stop replay.
Definition: StateChangeDistributor.cc:77
Reactor.hh
openmsx::ReverseManager::ReverseManager
ReverseManager(MSXMotherBoard &motherBoard)
Definition: ReverseManager.cc:138
TclArgParser.hh
OUTER
#define OUTER(type, member)
Definition: outer.hh:41
openmsx::OPENMSX_TAKE_REVERSE_SNAPSHOT
@ OPENMSX_TAKE_REVERSE_SNAPSHOT
Used to schedule 'taking reverse snapshots' between Z80 instructions.
Definition: Event.hh:51
view::transform
auto transform(Range &&range, UnaryOp op)
Definition: view.hh:306
openmsx::SNAPSHOT_PERIOD
constexpr double SNAPSHOT_PERIOD
Definition: ReverseManager.cc:39
ReverseManager.hh
openmsx::ReverseManager::~ReverseManager
~ReverseManager()
Definition: ReverseManager.cc:157
openmsx::Reactor::getInterpreter
Interpreter & getInterpreter()
Definition: Reactor.cc:311
openmsx::Replay::Replay
Replay(Reactor &reactor_)
Definition: ReverseManager.cc:61
openmsx::MSXMotherBoard
Definition: MSXMotherBoard.hh:59
one_of
Definition: one_of.hh:7
openmsx::StateChangeDistributor::setViewOnlyMode
void setViewOnlyMode(bool value)
Set viewOnlyMode.
Definition: StateChangeDistributor.hh:65
openmsx::MSXMotherBoard::getMSXCommandController
MSXCommandController & getMSXCommandController()
Definition: MSXMotherBoard.hh:117
EventDistributor.hh
openmsx::filename
constexpr const char *const filename
Definition: FirmwareSwitch.cc:10
openmsx::EndLogEvent::serialize
void serialize(Archive &ar, unsigned)
Definition: ReverseManager.cc:129
openmsx::MSXMotherBoard::getMSXMixer
MSXMixer & getMSXMixer()
Definition: MSXMotherBoard.hh:124
StateChange.hh
openmsx::FileOperations::parseCommandFileArgument
string parseCommandFileArgument(string_view argument, string_view directory, string_view prefix, string_view extension)
Helper function for parsing filename arguments in Tcl commands.
Definition: FileOperations.cc:732
openmsx::N
constexpr unsigned N
Definition: ResampleHQ.cc:224
view.hh
openmsx::EndLogEvent::EndLogEvent
EndLogEvent(EmuTime::param time_)
Definition: ReverseManager.cc:124
MemBuffer.hh
FileContext.hh
FileOperations.hh
span::size
constexpr index_type size() const noexcept
Definition: span.hh:296
gl::context
std::unique_ptr< Context > context
Definition: GLContext.cc:9
openmsx::EmuDuration::sec
static constexpr EmuDuration sec(unsigned x)
Definition: EmuDuration.hh:39
std::swap
void swap(openmsx::MemBuffer< T > &l, openmsx::MemBuffer< T > &r) noexcept
Definition: MemBuffer.hh:211
Keyboard.hh
openmsx::MSXCommandController::transferSettings
void transferSettings(const MSXCommandController &from)
Transfer setting values from one machine to another, used for during 'reverse'.
Definition: MSXCommandController.cc:172
openmsx::parseTclArgs
std::vector< TclObject > parseTclArgs(Interpreter &interp, span< const TclObject > inArgs, span< const ArgsInfo > table)
Definition: commands/TclArgParser.cc:11
openmsx::MSXMixer::mute
void mute()
TODO This methods (un)mute the sound.
Definition: MSXMixer.cc:548
gl::max
vecN< N, T > max(const vecN< N, T > &x, const vecN< N, T > &y)
Definition: gl_vec.hh:292
MSXCommandController.hh
openmsx::REGISTER_POLYMORPHIC_CLASS
REGISTER_POLYMORPHIC_CLASS(DiskContainer, NowindRomDisk, "NowindRomDisk")
openmsx::MIN_PARTITION_LENGTH
constexpr auto MIN_PARTITION_LENGTH
Definition: ReverseManager.cc:45
ranges::find_if
auto find_if(InputRange &&range, UnaryPredicate pred)
Definition: ranges.hh:113
openmsx::EventDistributor::registerEventListener
void registerEventListener(EventType type, EventListener &listener, Priority priority=OTHER)
Registers a given object to receive certain events.
Definition: EventDistributor.cc:23
openmsx::valueArg
ArgsInfo valueArg(std::string_view name, T &value)
Definition: TclArgParser.hh:85
CliComm.hh
openmsx::MSXMotherBoard::getDebugger
Debugger & getDebugger()
Definition: MSXMotherBoard.hh:123
openmsx::EventDistributor::unregisterEventListener
void unregisterEventListener(EventType type, EventListener &listener)
Unregisters a previously registered event listener.
Definition: EventDistributor.cc:35
openmsx::Replay::serialize
void serialize(Archive &ar, unsigned version)
Definition: ReverseManager.cc:76
MSXMixer.hh
openmsx::Replay
Definition: ReverseManager.cc:59
openmsx::EndLogEvent
Definition: ReverseManager.cc:120
CommandException.hh
openmsx
Thanks to enen for testing this on a real cartridge:
Definition: Autofire.cc:5
openmsx::MAX_NOF_SNAPSHOTS
constexpr unsigned MAX_NOF_SNAPSHOTS
Definition: ReverseManager.cc:42
MSXMotherBoard.hh
Debugger.hh
openmsx::EventDistributor::distributeEvent
void distributeEvent(const EventPtr &event)
Schedule the given event for delivery.
Definition: EventDistributor.cc:44
openmsx::EventDelay::flush
void flush()
Definition: EventDelay.cc:185
openmsx::Replay::reactor
Reactor & reactor
Definition: ReverseManager.cc:64