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