Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix harvester execution logs added to previous logs #8387

Merged
merged 1 commit into from
Sep 26, 2024
Merged

Conversation

josegar74
Copy link
Member

@josegar74 josegar74 commented Sep 25, 2024

Test case:

  1. Create a harvester.
  2. Execute it and check the harvester history tab. The execution has a button to download the log file.
  3. Execute it 2 or more times and check the harvester history tab. Most probably is that the latest executions don't have the button to download the log file. Checking the previous log files, you can find out that are stored there.

The problem seems related to

ThreadContext.putIfNull("logfile", logfile);
, as Quartz probably reuses threads and putIfNull does not update the value if a thread that had a set value has been reused. The other properties added to the ThreadContext are added using put instead. It is not clear why the log file name is added using putIfNull.

Checklist

  • I have read the contribution guidelines
  • Pull request provided for main branch, backports managed with label
  • Good housekeeping of code, cleaning up comments, tests, and documentation
  • Clean commit history broken into understandable chucks, avoiding big commits with hundreds of files, cautious of reformatting and whitespace changes
  • Clean commit messages, longer verbose messages are encouraged
  • API Changes are identified in commit messages
  • Testing provided for features or enhancements using automatic tests
  • User documentation provided for new features or enhancements in manual
  • Build documentation provided for development instructions in README.md files
  • Library management using pom.xml dependency management. Update build documentation with intended library use and library tutorials or documentation

Copy link

sonarcloud bot commented Sep 25, 2024

@@ -71,7 +71,7 @@ public static String initializeHarvesterLog(String type, String name) {
}

ThreadContext.put("harvest", harvesterName);
ThreadContext.putIfNull("logfile", logfile);
ThreadContext.put("logfile", logfile);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks this makes sense if the thread is being recycled.

Q: Do we have a deinit method we could use to clear this setting?
Q: Is it worth doing some small check if this value is non-null and adding a System.out or Stacktrace to identify the conflict?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@jodygarnett

Q: Do we have a deinit method we could use to clear this setting?

Maybe can be added in the finally clause of

protected OperResult harvest() {
OperResult operResult = OperResult.OK;
Boolean releaseLock = false;
try {
if (lock.isHeldByCurrentThread() || (releaseLock = lock.tryLock(LONG_WAIT, TimeUnit.SECONDS))) {
long startTime = System.currentTimeMillis();
running = true;
cancelMonitor.set(false);
try {
String logfile = LogUtil.initializeHarvesterLog(getType(), this.getParams().getName());
this.log.info("Starting harvesting of " + this.getParams().getName());
error = null;
errors.clear();
final Logger logger = this.log;
final String nodeName = getParams().getName() + " (" + getClass().getSimpleName() + ")";
final String lastRun = OffsetDateTime.now(ZoneOffset.UTC).format(DateTimeFormatter.ISO_DATE_TIME);
try {
login();
//--- update lastRun
harvesterSettingsManager.setValue("harvesting/id:" + id + "/info/lastRun", lastRun);
//--- proper harvesting
logger.info("Started harvesting from node : " + nodeName);
HarvestWithIndexProcessor h = new HarvestWithIndexProcessor(dataMan, logger);
// todo check (was: processwithfastindexing)
h.process(settingManager.getSiteId());
logger.info("Ended harvesting from node : " + nodeName);
if (getParams().isOneRunOnly()) {
stop(Status.INACTIVE);
}
} catch (InvalidParameterValueEx e) {
logger.error("The harvester " + this.getParams().getName() + "["
+ this.getType()
+ "] didn't accept some of the parameters sent.");
errors.add(new HarvestError(context, e));
error = e;
operResult = OperResult.ERROR;
} catch (UnknownHostException e) {
logger.error("The harvester " + this.getParams().getName() + "["
+ this.getType()
+ "] host is unknown.");
// Using custom UnknownHostEx as UnknownHostException error message differs from IPv4 / IPv6,
// in IPv4 only reports the host name in the message, the harvester uses this field
// and error reported to the user is unclear
error = new UnknownHostEx(e.getMessage());
errors.add(new HarvestError(context, error));
operResult = OperResult.ERROR;
} catch (Throwable t) {
operResult = OperResult.ERROR;
logger.warning("Raised exception while harvesting from : " + nodeName);
logger.warning(" (C) Class : " + t.getClass().getSimpleName());
logger.warning(" (C) Message : " + t.getMessage());
logger.error(t);
error = t;
errors.add(new HarvestError(context, t));
} finally {
List<HarvestError> harvesterErrors = getErrors();
if (harvesterErrors != null) {
errors.addAll(harvesterErrors);
}
}
long elapsedTime = TimeUnit.MILLISECONDS.toSeconds(System.currentTimeMillis() - startTime);
logHarvest(logfile, logger, nodeName, lastRun, elapsedTime);
} finally {
cancelMonitor.set(false);
running = false;
}
} else {
log.error("Harvester '" + this.getID() + "' looks deadlocked.");
log.error("Harvester '" + this.getID() + "' hasn't initiated.");
operResult = OperResult.ERROR;
}
} catch (InterruptedException e) {
log.error(e);
} finally {
if (lock.isHeldByCurrentThread() && releaseLock) {
lock.unlock();
}
}
return operResult;
a call to ThreadContext.clearAll()?

Q: Is it worth doing some small check if this value is non-null and adding a System.out or Stacktrace to identify the conflict?

Please try to add that to the original code and check the test case provided to confirm that the problem is that the information is in the ThreadContext of a reused thread.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Okay I understand this is urgent, and address the current problem.

The feedback above can be considered for a future improvement or if the problem reoccurs.

@@ -71,7 +71,7 @@ public static String initializeHarvesterLog(String type, String name) {
}

ThreadContext.put("harvest", harvesterName);
ThreadContext.putIfNull("logfile", logfile);
ThreadContext.put("logfile", logfile);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Okay I understand this is urgent, and address the current problem.

The feedback above can be considered for a future improvement or if the problem reoccurs.

@josegar74 josegar74 merged commit c932372 into main Sep 26, 2024
11 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants