From 92a866468ad68a1dcf86f5398b4d86bf06d4416a Mon Sep 17 00:00:00 2001 From: Richard Eckart de Castilho Date: Tue, 30 May 2023 17:06:12 +0200 Subject: [PATCH] #1066 - Recommender status info - Fix logging of start and end events for selection, training and prediction and always show the time the steps too in the recommender log --- .../service/RecommendationServiceImpl.java | 6 ----- .../recommendation/tasks/PredictionTask.java | 8 +++---- .../recommendation/tasks/SelectionTask.java | 23 ++++++++++++++----- 3 files changed, 21 insertions(+), 16 deletions(-) diff --git a/inception/inception-recommendation/src/main/java/de/tudarmstadt/ukp/inception/recommendation/service/RecommendationServiceImpl.java b/inception/inception-recommendation/src/main/java/de/tudarmstadt/ukp/inception/recommendation/service/RecommendationServiceImpl.java index 7dd0bd7b646..520adf3036d 100644 --- a/inception/inception-recommendation/src/main/java/de/tudarmstadt/ukp/inception/recommendation/service/RecommendationServiceImpl.java +++ b/inception/inception-recommendation/src/main/java/de/tudarmstadt/ukp/inception/recommendation/service/RecommendationServiceImpl.java @@ -1730,9 +1730,6 @@ public Predictions computePredictions(User aSessionOwner, Project aProject, computePredictions(predictions, casHolder.cas, document, aDataOwner, -1, -1); } - predictions.log(LogMessage.info(this, "Prediction complete")); - LOG.debug("Prediction complete"); - return predictions; } catch (ResourceInitializationException e) { @@ -1767,9 +1764,6 @@ public Predictions computePredictions(User aSessionOwner, Project aProject, // Generate new predictions or inherit at the recommender level computePredictions(predictions, predictionCas, aCurrentDocument, aDataOwner, aPredictionBegin, aPredictionEnd); - - predictions.log(LogMessage.info(this, "Prediction complete")); - LOG.debug("Prediction complete"); } catch (ResourceInitializationException e) { predictions.log( diff --git a/inception/inception-recommendation/src/main/java/de/tudarmstadt/ukp/inception/recommendation/tasks/PredictionTask.java b/inception/inception-recommendation/src/main/java/de/tudarmstadt/ukp/inception/recommendation/tasks/PredictionTask.java index 2cf70ee9548..c9641dcd31d 100644 --- a/inception/inception-recommendation/src/main/java/de/tudarmstadt/ukp/inception/recommendation/tasks/PredictionTask.java +++ b/inception/inception-recommendation/src/main/java/de/tudarmstadt/ukp/inception/recommendation/tasks/PredictionTask.java @@ -85,7 +85,7 @@ public PredictionTask(User aSessionOwner, String aTrigger, SourceDocument aCurre @Override public void execute() { - try (CasStorageSession session = CasStorageSession.openNested()) { + try (var session = CasStorageSession.openNested()) { var project = getProject(); var sessionOwner = getUser().orElseThrow(); var sessionOwnerName = sessionOwner.getUsername(); @@ -93,7 +93,7 @@ public void execute() var startTime = System.currentTimeMillis(); var predictions = generatePredictions(sessionOwner); predictions.inheritLog(getLogMessages()); - logPredictionComplete(startTime, sessionOwnerName); + logPredictionComplete(predictions, startTime, sessionOwnerName); recommendationService.putIncomingPredictions(sessionOwner, project, predictions); @@ -132,11 +132,11 @@ private Predictions generatePredictions(User sessionOwner) dataOwner, inherit, predictionBegin, predictionEnd); } - private void logPredictionComplete(long startTime, String username) + private void logPredictionComplete(Predictions aPredictions, long startTime, String username) { var duration = currentTimeMillis() - startTime; log.debug("[{}][{}]: Prediction complete ({} ms)", getId(), username, duration); - info("Prediction complete ({} ms).", duration); + aPredictions.log(LogMessage.info(this, "Prediction complete (%d ms).", duration)); } private void logPredictionStartedForOneDocument(String username, Project project, diff --git a/inception/inception-recommendation/src/main/java/de/tudarmstadt/ukp/inception/recommendation/tasks/SelectionTask.java b/inception/inception-recommendation/src/main/java/de/tudarmstadt/ukp/inception/recommendation/tasks/SelectionTask.java index b5aef1489a2..cff8720b20d 100644 --- a/inception/inception-recommendation/src/main/java/de/tudarmstadt/ukp/inception/recommendation/tasks/SelectionTask.java +++ b/inception/inception-recommendation/src/main/java/de/tudarmstadt/ukp/inception/recommendation/tasks/SelectionTask.java @@ -110,11 +110,11 @@ public SelectionTask(User aUser, Project aProject, String aTrigger, public void execute() { try (CasStorageSession session = CasStorageSession.open()) { - Project project = getProject(); - User sessionOwner = getUser().orElseThrow(); + var sessionOwner = getUser().orElseThrow(); String sessionOwnerName = sessionOwner.getUsername(); - - logEvaluationStarted(sessionOwner); + var startTime = System.currentTimeMillis(); + Project project = getProject(); + logSelectionStarted(sessionOwner); // Read the CASes only when they are accessed the first time. This allows us to skip // reading the CASes in case that no layer / recommender is available or if no @@ -192,19 +192,30 @@ protected List initialize() return; } + logSelectionComplete(startTime, sessionOwnerName); + scheduleTrainingTask(sessionOwner); } } + private void logSelectionComplete(long startTime, String username) + { + var duration = currentTimeMillis() - startTime; + log.debug("[{}][{}]: Selection complete ({} ms)", getId(), username, duration); + info("Selection complete (%d ms).", duration); + } + private void logRecommenderGone(User user, Recommender aRecommender) { log.debug("[{}][{}][{}]: Recommender no longer available... skipping", getId(), user.getUsername(), aRecommender.getName()); } - private void logEvaluationStarted(User sessionOwner) + private void logSelectionStarted(User sessionOwner) { - log.info("[{}]: Evaluation started", sessionOwner.getUsername()); + log.info("[{}]: Starting selection triggered by [{}]", sessionOwner.getUsername(), + getTrigger()); + info("Starting selection triggered by [%s]", getTrigger()); } private void scheduleTrainingTask(User sessionOwner)