config: Fix to SystemC example's event handling

This patch fixes checkpoint restore in the SystemC hosting example by handling
early PollEvent events correctly before any EventQueue events are posted.

The SystemC event queue handler (SCEventQueue) reports an error if the event
loop is entered with no Events posted.  It is possible for this to happen
after instantiate due to PollEvent events.  This patch separates out
`external' events into a different handler in sc_module.cc to prevent the
error from occurring.

This fix also improves the event handling of asynchronous events by:

    1) Making asynchronous events 'catch up' gem5 time to SystemC
        time to avoid the appearance that events have been lost
        while servicing an asynchronous event that schedules an
        event loop exit event

    2) Add an in_simulate data member to Module to allow the event
        loop to check whether events should be processed or deferred
        until the next time Module::simulate is entered

    3) Cancel pending events around the entry/exit of the event loop
        in Module::simulate

    4) Moving the state initialisation of the example entirely into
        run to correct a problem with early events in checkpoint
        restore.

It is still possible to schedule asynchronous events (and talk PollQueue
actions) while simulate is not running.  This behaviour may stil cause
some problems.

util/systemc/Makefile

@@ -66,4 +66,5 @@ gem5.$(VARIANT).sc: main.o stats.o \
 
 clean:
 	$(RM) $(ALL)
+	$(RM) *.o
 	$(RM) -r m5out

util/systemc/main.cc

@@ -120,8 +120,6 @@ class SimControl : public Gem5SystemC::Module
 
     SimControl(sc_core::sc_module_name name, int argc_, char **argv_);
 
-    void before_end_of_elaboration();
-
     void run();
 };
 
@@ -141,14 +139,26 @@ SimControl::SimControl(sc_core::sc_module_name name,
 
     cxxConfigInit();
 
+    /* Pass DPRINTF messages to SystemC */
     Trace::setDebugLogger(&logger);
 
+    /* @todo need this as an option */
     Gem5SystemC::setTickFrequency();
-    sc_core::sc_set_time_resolution(1, sc_core::SC_PS);
 
+    /* Make a SystemC-synchronising event queue and install it as the
+     *  sole top level gem5 EventQueue */
     Gem5SystemC::Module::setupEventQueues(*this);
+
+    if (sc_core::sc_get_time_resolution() !=
+        sc_core::sc_time(1, sc_core::SC_PS))
+    {
+        fatal("Time resolution must be set to 1 ps for gem5 to work");
+    }
+
+    /* Enable keyboard interrupt, async I/O etc. */
     initSignals();
 
+    /* Enable stats */
     Stats::initSimStats();
     Stats::registerHandlers(CxxConfig::statsReset, CxxConfig::statsDump);
 
@@ -168,10 +178,9 @@ SimControl::SimControl(sc_core::sc_module_name name,
 
     CxxConfigFileBase *conf = new CxxIniFile();
 
-    if (!conf->load(config_file.c_str())) {
+    if (!conf->load(config_file.c_str()))
-        std::cerr << "Can't open config file: " << config_file << '\n';
+        fatal("Can't open config file: %s", config_file);
-        std::exit(EXIT_FAILURE);
+
-    }
     arg_ptr++;
 
     config_manager = new CxxConfigManager(*conf);
@@ -231,8 +240,7 @@ SimControl::SimControl(sc_core::sc_module_name name,
             }
         }
     } catch (CxxConfigManager::Exception &e) {
-        std::cerr << e.name << ": " << e.message << "\n";
+        fatal("Config problem in sim object %s: %s", e.name, e.message);
-        std::exit(EXIT_FAILURE);
     }
 
     CxxConfig::statsEnable();
@@ -241,32 +249,52 @@ SimControl::SimControl(sc_core::sc_module_name name,
     try {
         config_manager->instantiate();
     } catch (CxxConfigManager::Exception &e) {
-        std::cerr << "Config problem in sim object " << e.name
+        fatal("Config problem in sim object %s: %s", e.name, e.message);
-            << ": " << e.message << "\n";
-
-        std::exit(EXIT_FAILURE);
-    }
-}
-
-void SimControl::before_end_of_elaboration()
-{
-    if (!checkpoint_restore) {
-        try {
-            config_manager->initState();
-            config_manager->startup();
-        } catch (CxxConfigManager::Exception &e) {
-            std::cerr << "Config problem in sim object " << e.name
-                << ": " << e.message << "\n";
-
-            std::exit(EXIT_FAILURE);
-        }
     }
 }
 
 void SimControl::run()
 {
+    EventQueue *eventq = getEventQueue(0);
     GlobalSimLoopExitEvent *exit_event = NULL;
 
+    /* There *must* be no scheduled events yet */
+    fatal_if(!eventq->empty(), "There must be no posted events"
+        " before SimControl::run");
+
+    try {
+        if (checkpoint_restore) {
+            std::cerr << "Restoring checkpoint\n";
+
+            Checkpoint *checkpoint = new Checkpoint(checkpoint_dir,
+                config_manager->getSimObjectResolver());
+
+            /* Catch SystemC up with gem5 after checkpoint restore.
+             *  Note that gem5 leading SystemC is always a violation of the
+             *  required relationship between the two, hence this careful
+             *  catchup */
+            Tick systemc_time = sc_core::sc_time_stamp().value();
+            if (curTick() > systemc_time) {
+                Tick wait_period = curTick() - systemc_time;
+
+                std::cerr << "Waiting for " << wait_period << "ps for"
+                    " SystemC to catch up to gem5\n";
+                wait(sc_core::sc_time(wait_period, sc_core::SC_PS));
+            }
+
+            config_manager->loadState(checkpoint);
+            config_manager->startup();
+            config_manager->drainResume();
+        } else {
+            config_manager->initState();
+            config_manager->startup();
+        }
+    } catch (CxxConfigManager::Exception &e) {
+        fatal("Config problem in sim object %s: %s", e.name, e.message);
+    }
+
+    fatal_if(eventq->empty(), "No events to process after system startup");
+
     if (checkpoint_save) {
         exit_event = simulate(pre_run_time);
 
@@ -299,32 +327,6 @@ void SimControl::run()
         config_manager->drainResume();
     }
 
-    if (checkpoint_restore) {
-        std::cerr << "Restoring checkpoint\n";
-
-        Checkpoint *checkpoint = new Checkpoint(checkpoint_dir,
-            config_manager->getSimObjectResolver());
-
-        Serializable::unserializeGlobals(checkpoint);
-
-        /* gem5 time can have changed, so lets wait until SystemC
-         *  catches up */
-        Tick systemc_time = sc_core::sc_time_stamp().value();
-        if (curTick() > systemc_time) {
-            Tick wait_period = curTick() - systemc_time;
-
-            std::cerr << "Waiting for " << wait_period << "ps for"
-                " SystemC to catch up to gem5\n";
-            wait(sc_core::sc_time(wait_period, sc_core::SC_PS));
-        }
-
-        config_manager->loadState(checkpoint);
-
-        config_manager->drainResume();
-
-        std::cerr << "Restored from checkpoint\n";
-    }
-
     if (switch_cpus) {
         exit_event = simulate(pre_switch_time);
 
@@ -350,6 +352,7 @@ void SimControl::run()
 
         old_cpu.switchOut();
         system.setMemoryMode(Enums::timing);
+
         new_cpu.takeOverFrom(&old_cpu);
         config_manager->drainResume();
 

util/systemc/sc_gem5_control.cc

@@ -228,8 +228,11 @@ Gem5TopLevelModule::Gem5TopLevelModule(sc_core::sc_module_name name,
      *  sole top level gem5 EventQueue */
     Gem5SystemC::Module::setupEventQueues(*this);
 
-    if (sc_core::sc_get_time_resolution() != sc_core::sc_time(1, sc_core::SC_PS))
+    if (sc_core::sc_get_time_resolution() !=
+        sc_core::sc_time(1, sc_core::SC_PS))
+    {
         fatal("Time resolution must be set to 1 ps for gem5 to work");
+    }
 
     /* Enable keyboard interrupt, async I/O etc. */
     initSignals();

util/systemc/sc_logger.cc

@@ -87,10 +87,10 @@ void CuttingStreambuf::outputLine()
 /** This is pretty much the least efficient way of doing this, but it has the
  *  advantage of having very few corners to get wrong.
  *
- *  A newly allocated streambuf will have no buffer to serve to its [oi]stream.
+ *  A newly allocated streambuf will have no buffer to serve to its
- *  It will, therefore, call overflow for every character it wants to insert
+ *  [oi]stream.  It will, therefore, call overflow for every character it
- *  into the output stream.  Those characters are captured one by one here and
+ *  wants to insert into the output stream.  Those characters are captured one
- *  added to this->line. */
+ *  by one here and added to this->line. */
 int
 CuttingStreambuf::overflow(int chr)
 {

util/systemc/sc_module.cc

@@ -76,10 +76,14 @@ setTickFrequency()
     ::setClockFrequency(1000000000000);
 }
 
-Module::Module(sc_core::sc_module_name name) : sc_core::sc_module(name)
+Module::Module(sc_core::sc_module_name name) : sc_core::sc_module(name),
+    in_simulate(false)
 {
     SC_METHOD(eventLoop);
     sensitive << eventLoopEnterEvent;
+    dont_initialize();
+
+    SC_METHOD(serviceExternalEvent);
     sensitive << externalSchedulingEvent;
     dont_initialize();
 }
@@ -95,11 +99,37 @@ Module::SCEventQueue::wakeup(Tick when)
 void
 Module::setupEventQueues(Module &module)
 {
+    fatal_if(mainEventQueue.size() != 0,
+        "Gem5SystemC::Module::setupEventQueues must be called"
+        " before any gem5 event queues are set up");
+
     numMainEventQueues = 1;
     mainEventQueue.push_back(new SCEventQueue("events", module));
     curEventQueue(getEventQueue(0));
 }
 
+void
+Module::catchup()
+{
+    EventQueue *eventq = getEventQueue(0);
+    Tick systemc_time = sc_core::sc_time_stamp().value();
+    Tick gem5_time = curTick();
+
+    /* gem5 time *must* lag SystemC as SystemC is the master */
+    fatal_if(gem5_time > systemc_time, "gem5 time must lag SystemC time"
+        " gem5: %d SystemC: %d", gem5_time, systemc_time);
+
+    eventq->setCurTick(systemc_time);
+
+    if (!eventq->empty()) {
+        Tick next_event_time M5_VAR_USED = eventq->nextTick();
+
+        fatal_if(gem5_time > next_event_time,
+            "Missed an event at time %d gem5: %d, SystemC: %d",
+            next_event_time, gem5_time, systemc_time);
+    }
+}
+
 void
 Module::notify(sc_core::sc_time time_from_now)
 {
@@ -109,8 +139,17 @@ Module::notify(sc_core::sc_time time_from_now)
 void
 Module::serviceAsyncEvent()
 {
+    EventQueue *eventq = getEventQueue(0);
+
     assert(async_event);
 
+    /* Catch up gem5 time with SystemC time so that any event here won't
+     * be in the past relative to the current time */
+    Tick systemc_time = sc_core::sc_time_stamp().value();
+
+    /* Move time on to match SystemC */
+    catchup();
+
     async_event = false;
     if (async_statdump || async_statreset) {
         Stats::schedStatEvent(async_statdump, async_statreset);
@@ -132,23 +171,38 @@ Module::serviceAsyncEvent()
         fatal("received async_exception, shouldn't be possible");
 }
 
+void
+Module::serviceExternalEvent()
+{
+    EventQueue *eventq = getEventQueue(0);
+
+    if (!in_simulate && !async_event)
+        warn("Gem5SystemC external event received while not in simulate");
+
+    if (async_event)
+        serviceAsyncEvent();
+
+    if (in_simulate && !eventq->empty())
+        eventLoop();
+}
+
 void
 Module::eventLoop()
 {
     EventQueue *eventq = getEventQueue(0);
 
+    fatal_if(!in_simulate, "Gem5SystemC event loop entered while"
+        " outside Gem5SystemC::Module::simulate");
+
     if (async_event)
         serviceAsyncEvent();
 
     while (!eventq->empty()) {
         Tick next_event_time = eventq->nextTick();
-        Tick systemc_time = sc_core::sc_time_stamp().value();
-
-        /* gem5 time *must* lag SystemC as SystemC is the master */
-        assert(curTick() <= systemc_time);
 
         /* Move time on to match SystemC */
-        eventq->setCurTick(systemc_time);
+        catchup();
+
         Tick gem5_time = curTick();
 
         /* Woken up early */
@@ -171,6 +225,8 @@ Module::eventLoop()
 
             return;
         } else if (gem5_time > next_event_time) {
+            Tick systemc_time = sc_core::sc_time_stamp().value();
+
             /* Missed event, for some reason the above test didn't work
              *  or an event was scheduled in the past */
             fatal("Missed an event at time %d gem5: %d, SystemC: %d",
@@ -180,7 +236,7 @@ Module::eventLoop()
             exitEvent = eventq->serviceOne();
 
             if (exitEvent) {
-                eventLoopExitEvent.notify();
+                eventLoopExitEvent.notify(sc_core::SC_ZERO_TIME);
                 return;
             }
         }
@@ -192,7 +248,7 @@ Module::eventLoop()
 GlobalSimLoopExitEvent *
 Module::simulate(Tick num_cycles)
 {
-    inform("Entering event queue @ %d.  Starting simulation...\n", curTick());
+    inform("Entering event queue @ %d.  Starting simulation...", curTick());
 
     if (num_cycles < MaxTick - curTick())
         num_cycles = curTick() + num_cycles;
@@ -204,6 +260,11 @@ Module::simulate(Tick num_cycles)
 
     exitEvent = NULL;
 
+    /* Cancel any outstanding events */
+    eventLoopExitEvent.cancel();
+    externalSchedulingEvent.cancel();
+
+    in_simulate = true;
     eventLoopEnterEvent.notify(sc_core::SC_ZERO_TIME);
 
     /* Wait for event queue to exit, guarded by exitEvent just incase
@@ -212,6 +273,10 @@ Module::simulate(Tick num_cycles)
     if (!exitEvent)
         wait(eventLoopExitEvent);
 
+    /* Cancel any outstanding event loop entries */
+    eventLoopEnterEvent.cancel();
+    in_simulate = false;
+
     /* Locate the global exit event */
     BaseGlobalEvent *global_event = exitEvent->globalEvent();
     assert(global_event != NULL);

util/systemc/sc_module.hh

@@ -99,6 +99,10 @@ class Module : public sc_core::sc_module
     /** Expected exit time of last eventLoop sleep */
     Tick wait_exit_time;
 
+    /** Are we in Module::simulate?  Used to mask events when not inside
+     *  the simulate loop */
+    bool in_simulate;
+
     /** Placeholder base class for a variant event queue if this becomes
      *  useful */
     class SCEventQueue : public EventQueue
@@ -131,10 +135,18 @@ class Module : public sc_core::sc_module
      *  are created */
     static void setupEventQueues(Module &module);
 
+    /** Catch gem5 time up with SystemC */
+    void catchup();
+
     /** Notify an externalSchedulingEvent at the given time from the
      *  current SystemC time */
     void notify(sc_core::sc_time time_from_now = sc_core::SC_ZERO_TIME);
 
+    /** Process an event triggered by externalSchedulingEvent and also
+     *  call eventLoop (to try and mop up any events at this time) if there
+     *  are any scheduled events */
+    void serviceExternalEvent();
+
     /** Process gem5 events up until an exit event or there are no events
      *  left. */
     void eventLoop();