Skip to content

improve scheduler logging to only show relevant passes #5

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.

Sign up for GitHub

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

Open
SirCotare wants to merge 1 commit into
base: main
Choose a base branch
from
Open

improve scheduler logging to only show relevant passes #5

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
41 changes: 36 additions & 5 deletions ...ain/java/it/aboutbits/springboot/emailservice/lib/application/CleanupAttachmentFiles.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -3,13 +3,14 @@

import it.aboutbits.springboot.emailservice.lib.AttachmentCleanerCallback;
import it.aboutbits.springboot.emailservice.lib.exception.AttachmentException;
import lombok.AllArgsConstructor;
import lombok.RequiredArgsConstructor;
import lombok.extern.log4j.Log4j2;
import org.springframework.scheduling.annotation.Scheduled;

import java.time.Duration;
import java.util.List;

@AllArgsConstructor
@RequiredArgsConstructor
@Log4j2
public class CleanupAttachmentFiles {
private static final String JOB_DESCRIPTION = "Cleanup attachments of sent Emails.";
Expand All @@ -18,9 +19,13 @@ public class CleanupAttachmentFiles {
private final ManageEmail manageEmail;
private final List<AttachmentCleanerCallback> callbacks;

private long lastInfoLogMillis = System.currentTimeMillis();
private long silentRuns = 0;
private boolean firstRun = true;

@Scheduled(initialDelayString = "${aboutbits.emailservice.scheduling.interval:30000}", fixedDelayString = "${aboutbits.emailservice.scheduling.interval:30000}")
void cleanupAttachments() {
log.info("Start: " + JOB_DESCRIPTION);
logStartOfPass();

var emailsToCleanup = queryEmail.readyToCleanup();

Expand All @@ -35,8 +40,7 @@ void cleanupAttachments() {
}
}

log.info("Finished: " + JOB_DESCRIPTION);
log.info("Cleaned: {}, Errors: {}", countCleaned, countError);
logEndOfPass(countCleaned, countError);

for (var callback : callbacks) {
callback.report(new AttachmentCleanerCallback.Report(
Expand All @@ -47,5 +51,32 @@ void cleanupAttachments() {
}
}

private void logStartOfPass() {
if (firstRun) {
log.info(JOB_DESCRIPTION + " | Job enabled.");
firstRun = false;
}
log.debug(JOB_DESCRIPTION + " | Start");
}

private void logEndOfPass(int countCleaned, int countError) {
log.debug(JOB_DESCRIPTION + " | Finished");
if (countCleaned > 0 || countError > 0) {
lastInfoLogMillis = System.currentTimeMillis();
silentRuns = 0;
log.info(JOB_DESCRIPTION + " | Cleaned: {}, Errors: {}", countCleaned, countError);
} else {
log.debug(JOB_DESCRIPTION + " | Cleaned: {}, Errors: {}", countCleaned, countError);
silentRuns++;
}

if (lastInfoLogMillis + Duration.ofHours(1).toMillis() < System.currentTimeMillis() && !log.isDebugEnabled()) {
log.info(
JOB_DESCRIPTION + " | Ran silently {} times. Enable debug logging to see all hidden passes.",
silentRuns
);
lastInfoLogMillis = System.currentTimeMillis();
silentRuns = 0;
}
}
}
48 changes: 41 additions & 7 deletions src/main/java/it/aboutbits/springboot/emailservice/lib/application/SendScheduledEmails.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -2,13 +2,14 @@


import it.aboutbits.springboot.emailservice.lib.EmailSchedulerCallback;
import lombok.AllArgsConstructor;
import lombok.RequiredArgsConstructor;
import lombok.extern.log4j.Log4j2;
import org.springframework.scheduling.annotation.Scheduled;

import java.time.Duration;
import java.util.List;

@AllArgsConstructor
@RequiredArgsConstructor
@Log4j2
public class SendScheduledEmails {
private static final String JOB_DESCRIPTION = "Sending open and failed email notifications.";
Expand All @@ -17,9 +18,13 @@ public class SendScheduledEmails {
private final ManageEmail manageEmail;
private final List<EmailSchedulerCallback> callbacks;

private long lastInfoLogMillis = System.currentTimeMillis();
private long silentRuns = 0;
private boolean firstRun = true;

@Scheduled(initialDelayString = "${aboutbits.emailservice.scheduling.interval:30000}", fixedDelayString = "${aboutbits.emailservice.scheduling.interval:30000}")
void sendEmails() {
log.info("Start: " + JOB_DESCRIPTION);
logStartOfPass();

var emailsToSend = queryEmail.readyToSend();

Expand All @@ -31,13 +36,13 @@ void sendEmails() {
case ERROR -> countError++;
case SENT -> countSent++;
default -> log.warn(
"Email job produced an invalid notification result state: {}.",
updatedEmail.getState().name());
JOB_DESCRIPTION + " | Job produced an invalid notification result state: {}.",
updatedEmail.getState().name()
);
}
}

log.info("Finished: " + JOB_DESCRIPTION);
log.info("Sent: {}, Errors: {}", countSent, countError);
logEndOfPass(countSent, countError);

for (var callback : callbacks) {
callback.report(new EmailSchedulerCallback.Report(
Expand All @@ -47,4 +52,33 @@ void sendEmails() {
));
}
}

private void logStartOfPass() {
if (firstRun) {
log.info(JOB_DESCRIPTION + " | Job enabled.");
firstRun = false;
}
log.debug(JOB_DESCRIPTION + " | Start");
}

private void logEndOfPass(int countSent, int countError) {
log.debug(JOB_DESCRIPTION + " | Finished");
if (countSent > 0 || countError > 0) {
lastInfoLogMillis = System.currentTimeMillis();
silentRuns = 0;
log.info(JOB_DESCRIPTION + " | Sent: {}, Errors: {}", countSent, countError);
} else {
log.debug(JOB_DESCRIPTION + " | Sent: {}, Errors: {}", countSent, countError);
silentRuns++;
}

if (lastInfoLogMillis + Duration.ofHours(1).toMillis() < System.currentTimeMillis() && !log.isDebugEnabled()) {
log.info(
JOB_DESCRIPTION + " | Ran silently {} times. Enable debug logging to see all hidden passes.",
silentRuns
);
lastInfoLogMillis = System.currentTimeMillis();
silentRuns = 0;
}
}
}