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 static const double SNAPSHOT_PERIOD = 1.0;
39 
40 // Max number of snapshots in a replay file
41 static const unsigned MAX_NOF_SNAPSHOTS = 10;
42 
43 // Min distance between snapshots in replay file (in seconds)
44 static const EmuDuration MIN_PARTITION_LENGTH = EmuDuration(60.0);
45 
46 // Max distance of one before last snapshot before the end time in replay file (in seconds)
47 static const EmuDuration MAX_DIST_1_BEFORE_LAST_SNAPSHOT = EmuDuration(30.0);
48 
49 static 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;
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 (auto& p : history.chunks) {
248  auto& chunk = p.second;
249  strAppend(res, p.first, ' ',
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().repaint();
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  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  } 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  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().str();
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 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 const char* const options[] = { "true", "false" };
1028  completeString(tokens, options);
1029  }
1030  }
1031 }
1032 
1033 } // namespace openmsx
MSXCommandController & getMSXCommandController()
static EmuDuration sec(unsigned x)
Definition: EmuDuration.hh:36
auto transform(Range &&range, UnaryOp op)
Definition: view.hh:312
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:170
Contains the main loop of openMSX.
Definition: Reactor.hh:64
void mute()
TODO This methods (un)mute the sound.
Definition: MSXMixer.cc:547
void swap(optional< T > &x, optional< T > &y) noexcept(noexcept(x.swap(y)))
Definition: optional.hh:816
const std::string & getMessage() const &
Definition: MSXException.hh:23
void serialize(const char *tag, T &t)
Definition: serialize.hh:539
string parseCommandFileArgument(string_view argument, string_view directory, string_view prefix, string_view extension)
Helper function for parsing filename arguments in Tcl commands.
void registerEventListener(EventType type, EventListener &listener, Priority priority=OTHER)
Registers a given object to receive certain events.
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:374
void unregisterEventListener(EventType type, EventListener &listener)
Unregisters a previously registered event listener.
Definition: span.hh:34
std::unique_ptr< MSXMotherBoard > Board
Definition: Reactor.hh:108
void distributeEvent(const EventPtr &event)
Schedule the given event for delivery.
ArgsInfo flagArg(string_view name, bool &flag)
Definition: TclArgParser.hh:72
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
ArgsInfo valueArg(string_view name, T &value)
Definition: TclArgParser.hh:85
MemBuffer< byte > releaseBuffer(size_t &size)
Definition: serialize.cc:178
void stopReplay(EmuTime::param time)
Explicitly stop replay.
void unregisterRecorder(StateChangeRecorder &recorder)
void strAppend(std::string &result, Ts &&...ts)
Definition: strCat.hh:648
auto find_if(InputRange &&range, UnaryPredicate pred)
Definition: ranges.hh:113
auto begin(const string_view &x)
Definition: string_view.hh:151
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)
void distributeReplay(const EventPtr &event)
ReverseManager::Events * events
ReverseManager(MSXMotherBoard &motherBoard)
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:165
auto count(InputRange &&range, const T &value)
Definition: ranges.hh:197
Replay(Reactor &reactor_)
EmuDuration divRoundUp(unsigned fact) const
Definition: EmuDuration.hh:72
This class implements a (close approximation) of the std::string_view class.
Definition: string_view.hh:16
Base class for all external MSX state changing events.
Definition: StateChange.hh:13
void printProgress(string_view message)
Definition: CliComm.cc:30
std::vector< Reactor::Board > motherBoards
void transferHostKeyMatrix(const Keyboard &source)
Definition: Keyboard.cc:168
CliComm & getCliComm()
Definition: Reactor.cc:280
EmuTime::param getCurrentTime()
Convenience method: This is the same as getScheduler().getCurrentTime().
Board createEmptyMotherBoard()
Definition: Reactor.cc:369
Display & getDisplay()
Definition: Reactor.hh:83
uint64_t getTime()
Get current (real) time in us.
Definition: Timer.cc:8
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
void serialize(const char *tag, const T &t)
Definition: serialize.hh:443
TclObject t
auto end(const string_view &x)
Definition: string_view.hh:152
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:285