private TimeWhenRunnable processVillages() throws InvalidConfigurationException {
   TimeWhenRunnable firstTimeWhenRunnable = null;
   try {
     List<SubnodeConfiguration> villageConfigs =
         config.configurationsAt("/village[@enabled='true']");
     for (SubnodeConfiguration villageConfig : villageConfigs) {
       // If configuration changed, abort current loop, update config and restart
       if (isConfigurationChanged()) {
         log.debug("Exiting village loop for configuration update");
         break;
       }
       String id = Village.getIdFromConfig(villageConfig);
       Village village = villages.get(id);
       if (village == null) {
         log.warn(
             "Configuration file not aligned to village map; ignoring village "
                 + villageConfig.getString("/@desc", "")
                 + " "
                 + villageConfig.getString("/url", ""));
         continue;
       }
       try {
         // getTimeWhenRunnable may update to check for triggering resources so can change page
         TimeWhenRunnable currentTimeWhenRunnable = village.getTimeWhenRunnable();
         // log.debug("currentTimeWhenRunnnable:"+currentTimeWhenRunnable);
         if (currentTimeWhenRunnable.before(new Date())) {
           EventLog.log("Processing village \"" + village.getDesc() + "\"");
           village.execute(); // Execute strategies
           currentTimeWhenRunnable = village.getTimeWhenRunnable();
           // log.debug("currentTimeWhenRunnnable after execute:"+currentTimeWhenRunnable);
         } else {
           EventLog.log(
               "Village \"" + village.getDesc() + "\" sleeping until " + currentTimeWhenRunnable);
         }
         // use current here and only reread after execute, then use new below
         if ((firstTimeWhenRunnable == null)
             || firstTimeWhenRunnable.after(currentTimeWhenRunnable)) {
           log.trace("Earlier Village " + village.getDesc() + " " + currentTimeWhenRunnable);
           firstTimeWhenRunnable = currentTimeWhenRunnable;
         }
         // check for earliest sharp strategy in village, return NEVER if none- if is store
         // earliest sharp one
         TimeWhenRunnable newTimeWhenRunnable = village.getTimeWhenSharp();
         if (newTimeWhenRunnable.isSharp()) {
           if (sharpTimeWhenRunnable == null || sharpTimeWhenRunnable.after(newTimeWhenRunnable)) {
             // log.trace("Earlier Village "+village.getDesc()+" "+newTimeWhenRunnable);
             sharpTimeWhenRunnable = newTimeWhenRunnable;
             log.trace(
                 "Earlier sharp Village is " + village.getDesc() + " " + sharpTimeWhenRunnable);
           }
         }
       } catch (SkipVillageRequested e) {
         log.debug("Village skipped");
         continue;
       } catch (SkipRequested e) {
         // Just keep going
         log.debug("Action skipped");
       } catch (ServerFatalException e) {
         throw e; // Will catch below
       } catch (Exception e) {
         String s = "Village \"" + village.getDesc() + "\" error (retrying later): ";
         log.error(s, e);
         EventLog.log(s + e.getMessage());
         util.shortestPause(false); // Just to be safe
         firstTimeWhenRunnable = null; // Retry after userPause
       }
     }
   } catch (ConcurrentModificationException e) {
     // This shouldn't happen anymore
     // Just ignore
     log.debug(
         "Village list was modified while server running (ConcurrentModificationException): skipping and repeating");
   }
   // log.debug("returning firstTimeWhenRunnable:"+firstTimeWhenRunnable);
   return firstTimeWhenRunnable;
 }
  public void run() {
    EventLog.log("Starting nanny for \"" + getServerDesc() + "\"");
    setStartedAndRunning(true);
    NDC.push(getServerDesc());
    try {
      // Nanny villages
      while (isKeepRunning()) {
        util.getConsole().checkPause();
        TimeWhenRunnable firstTimeWhenRunnable = null;
        sharpTimeWhenRunnable = null;
        if ((messageMode != null) && !messageMode.equals("false")) {
          // check messages before for commands including resume
          int msgRead = messageReader.readMessages(util, loginUrl, messageMode);
          log.info("Messages Done next " + msgRead);
        }
        // check if still enabled
        if (!suspended) {
          // Loop all enabled villages
          EventLog.log("Checking Villages");
          firstTimeWhenRunnable = processVillages();
          log.info("Villages done");
          // gac - move servers below villages
          // Loop all enabled server strategies
          TimeWhenRunnable serverStrategiesTimeWhenRunnable = processServerStrategies();
          if (serverStrategiesTimeWhenRunnable.before(firstTimeWhenRunnable)) {
            log.debug("ServerStrategy Earlier than villages");
            firstTimeWhenRunnable = serverStrategiesTimeWhenRunnable;
          }
          // gac add report processing - exists as server strategy to run periodically
          // but this will run at the end of every active period
          // count if outstanding after this read
          int moreRead = 0;
          if ((reportMode != null) && !reportMode.equals("false")) {
            // set the reporting mode and check reports
            // ReportMessageReader.getInstance().setReportsMode(reportMode);
            // EventLog.log(loginUrl+" about to read reportMode="+reportMode);
            moreRead = reportReader.readReports(util, loginUrl, reportMode);
            log.info("Server Reports done");
          }
          // read messages again
          if ((messageMode != null) && !messageMode.equals("false")) {
            // check messages
            int msgRead = messageReader.readMessages(util, loginUrl, messageMode);
            log.info("Messages at end done next " + msgRead);
            // read more if consuming all message not just scanning titles for commands
            // if (!messageMode.equalsIgnoreCase("titles")) {
            if (!messageMode.equalsIgnoreCase(messageReader.getScanMode())) {
              moreRead += msgRead;
            }
          }
          if (moreRead != 0) {
            // still more to read
            firstTimeWhenRunnable = TimeWhenRunnable.NOW; // Re-run immediately
            log.debug("Villages will be run again because more reports to read (" + moreRead + ")");
          } else {
            // no new reports left
          }
          if (isConfigurationChanged()) {
            // Update configuration
            updateConfig(getNextConfig());
            EventLog.log("evt.configReloadDone", this.getClass());
            this.nextConfig = null; // No need to synchronize here
            firstTimeWhenRunnable = TimeWhenRunnable.NOW; // Re-run immediately
            log.debug("Villages will be run again because of configuration update");
          }
        } else {
          // suspended
          log.debug("All Strategies Suspended");
          firstTimeWhenRunnable =
              new TimeWhenRunnable(
                  System.currentTimeMillis() + SUSPENDCHECK * Util.MILLI_MINUTE); // try again later
        }
        boolean sharp = false;
        long milliPause = 0;
        long milliSharp = -1L;
        if (firstTimeWhenRunnable != null) {
          log.debug("Earliest Strategy @ " + firstTimeWhenRunnable);
          sharp = firstTimeWhenRunnable.isSharp();
          milliPause = firstTimeWhenRunnable.getTime() - System.currentTimeMillis();
          if (milliPause < 0) {
            milliPause = 0;
          }
          int pauseLimit = config.getInt("/@pauseLimit", 86400) * 1000; //  Max 24h
          if (milliPause > pauseLimit) {
            log.info("Limiting pause from " + milliPause + " to " + pauseLimit);
            milliPause = pauseLimit;
          }
          if (sharpTimeWhenRunnable != null) {
            log.debug("Earliest sharp Strategy @ " + sharpTimeWhenRunnable);
            milliSharp = sharpTimeWhenRunnable.getTime() - System.currentTimeMillis();
            if (milliSharp < 0) {
              milliSharp = 0;
            }
          }
          log.debug(
              "Next available Action in "
                  + Util.milliToTimeString(milliPause)
                  + (sharp ? " sharp: " + Util.milliToTimeString(milliSharp) : ""));
        }

        if (isKeepRunning()) {
          util.userPause(milliPause, sharp, milliSharp);
          util.shortestPause(sharp); // Just to be safe
        }
      }
    } catch (Exception e) {
      EventLog.log(e.getMessage());
      log.error("", e);
      setEnabledAndStartStop(false);
    } finally {
      NDC.remove(); // not pop()
    }
  }
 private TimeWhenRunnable processServerStrategies() {
   TimeWhenRunnable firstTimeWhenRunnable = TimeWhenRunnable.NEVER;
   // Run through each strategy
   for (Strategy strategy : this.serverStrategyList) {
     if (strategy.isDeleted() || util.getConsole().isQuitting()) {
       continue;
     }
     NDC.push("(" + strategy.getDesc() + ")");
     try {
       util.getConsole().checkFlags();
       TimeWhenRunnable timeWhenRunnable = strategy.getTimeWhenRunnable();
       if (timeWhenRunnable == null
           || timeWhenRunnable.isOpportunist()
           || timeWhenRunnable.before(new Date())) {
         EventLog.log("Executing strategy \"" + strategy.getDesc() + "\"");
         TimeWhenRunnable nextTime = strategy.execute();
         if (nextTime == null) { // Just to be safe
           EventLog.log("Timewhenrunnable = null returned");
           log.warn("(Internal Error) Shouldn't return null");
           nextTime = new TimeWhenRunnable(System.currentTimeMillis());
         }
         log.debug(
             String.format(
                 "Server Strategy %s will be run after %s ",
                 strategy.getDesc(), nextTime.getTimeWhenRunnable()));
         strategy.setTimeWhenRunnable(nextTime);
         if (firstTimeWhenRunnable.after(nextTime)) {
           firstTimeWhenRunnable = nextTime;
           log.trace(
               "Earliest Server Strategy is " + strategy.getDesc() + " " + firstTimeWhenRunnable);
         }
         // check if this one is sharp - if so store earliest sharp one
         /*
         if (timeWhenRunnable!=null && timeWhenRunnable.isSharp()) {
         	if (sharpTimeWhenRunnable == null || sharpTimeWhenRunnable.after(timeWhenRunnable)) {
         	// log.trace("Earliest Village "+village.getDesc()+" "+newTimeWhenRunnable);
         	sharpTimeWhenRunnable = timeWhenRunnable;
         	log.debug("Earliest sharp Strategy is "+strategy.getDesc()+" "+timeWhenRunnable);
         	}
         }
         */
         if (nextTime.isSharp()) {
           if (sharpTimeWhenRunnable == null || sharpTimeWhenRunnable.after(nextTime)) {
             // log.trace("Earliest Village "+village.getDesc()+" "+newTimeWhenRunnable);
             sharpTimeWhenRunnable = nextTime;
             log.trace(
                 "Earliest sharp Strategy is " + strategy.getDesc() + " " + sharpTimeWhenRunnable);
           }
         }
       }
     } catch (ConversationException e) {
       String s = "Error while executing strategy \"" + strategy.getDesc() + "\" (skipping)";
       Util.log(s, e);
       EventLog.log(s);
       util.shortestPause(false); // Just to be safe
       // Just keep going to the next strategy
     } catch (TranslationException e) {
       EventLog.log(e.getMessage());
       log.error("Translation error", e);
       // Keep going
     } catch (Exception e) {
       // Any other exception skips the strategy but keeps the server going
       // so that bugs in one strategy don't prevent other strategies from executing
       String message =
           EventLog.log("msg.strategyException", this.getClass(), strategy.toString());
       log.error(message, e);
       util.shortestPause(false); // Just to be safe
       firstTimeWhenRunnable = TimeWhenRunnable.NOW; // Retry after userPause
     } finally {
       NDC.pop();
     }
   }
   return firstTimeWhenRunnable;
 }