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