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