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