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