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;
}