Fix out of order log messages

This commit is contained in:
JeremyStar™ 2024-06-16 15:53:26 +02:00
parent 62b4718ef4
commit ac3e1e1224
Signed by: JeremyStarTM
GPG key ID: E366BAEF67E4704D
4 changed files with 257 additions and 53 deletions

View file

@ -19,7 +19,6 @@
package de.staropensource.sosengine.base; package de.staropensource.sosengine.base;
import de.staropensource.sosengine.base.classes.Event;
import de.staropensource.sosengine.base.classes.SubsystemMainClass; import de.staropensource.sosengine.base.classes.SubsystemMainClass;
import de.staropensource.sosengine.base.classes.helpers.EventHelper; import de.staropensource.sosengine.base.classes.helpers.EventHelper;
import de.staropensource.sosengine.base.data.info.EngineInformation; import de.staropensource.sosengine.base.data.info.EngineInformation;
@ -28,6 +27,7 @@ import de.staropensource.sosengine.base.events.EngineShutdownEvent;
import de.staropensource.sosengine.base.events.LogEvent; import de.staropensource.sosengine.base.events.LogEvent;
import de.staropensource.sosengine.base.events.internal.InternalEngineShutdownEvent; import de.staropensource.sosengine.base.events.internal.InternalEngineShutdownEvent;
import de.staropensource.sosengine.base.logging.CrashHandler; import de.staropensource.sosengine.base.logging.CrashHandler;
import de.staropensource.sosengine.base.logging.Logger;
import de.staropensource.sosengine.base.logging.LoggerInstance; import de.staropensource.sosengine.base.logging.LoggerInstance;
import de.staropensource.sosengine.base.types.CodePart; import de.staropensource.sosengine.base.types.CodePart;
import de.staropensource.sosengine.base.types.LogIssuer; import de.staropensource.sosengine.base.types.LogIssuer;
@ -110,6 +110,9 @@ public final class Engine implements SubsystemMainClass {
// Precompute event listeners // Precompute event listeners
precomputeEventListeners(); precomputeEventListeners();
// Start threads
startThreads();
// Initialize variables // Initialize variables
logger = new LoggerInstance(new LogIssuer(getClass(), CodePart.ENGINE)); logger = new LoggerInstance(new LogIssuer(getClass(), CodePart.ENGINE));
}); });
@ -199,6 +202,15 @@ public final class Engine implements SubsystemMainClass {
EventHelper.precomputeEventListeners(LogEvent.class); EventHelper.precomputeEventListeners(LogEvent.class);
} }
/**
* Starts base engine threads.
*
* @since 1-alpha1
*/
public void startThreads() {
Logger.startLoggingThread();
}
/** /**
* Shuts the engine and JVM down. * Shuts the engine and JVM down.
* *
@ -213,6 +225,7 @@ public final class Engine implements SubsystemMainClass {
logger.verb("Notifying subsystems about shutdown"); logger.verb("Notifying subsystems about shutdown");
new InternalEngineShutdownEvent().callEvent(); new InternalEngineShutdownEvent().callEvent();
logger.verb("Shutting down JVM with code " + exitCode); logger.verb("Shutting down JVM with code " + exitCode);
Logger.flushLogMessages();
Runtime.getRuntime().exit(exitCode); Runtime.getRuntime().exit(exitCode);
} }

View file

@ -185,10 +185,27 @@ public final class EngineConfiguration implements SubsystemConfiguration {
*/ */
private boolean loggerForceStandardOutput; private boolean loggerForceStandardOutput;
/**
* Determines how fast the logger will poll for messages.
* Only applies if {@code optimizeLogging} is turned on.
*
* @see EngineConfiguration#optimizeLogging
* @since 1-alpha0
*
* -- GETTER --
* Gets the value for {@code loggerForceStandardOutput}.
*
* @return variable value
* @see EngineConfiguration#loggerForceStandardOutput
* @since 1-alpha0
*/
private int loggerPollingSpeed;
/** /**
* If enabled, will makes the {@link Logger} work asynchronous. * If enabled, will makes the {@link Logger} work asynchronous.
* Don't disable unless you want your application to run <b>extremely</b> slowly. * Don't disable unless you want your application to run <b>extremely</b> slowly.
* *
* @see EngineConfiguration#loggerPollingSpeed
* @since 1-alpha0 * @since 1-alpha0
* *
* -- GETTER -- * -- GETTER --
@ -262,6 +279,7 @@ public final class EngineConfiguration implements SubsystemConfiguration {
case "loggerTemplate" -> loggerTemplate = parser.getString(group + property); case "loggerTemplate" -> loggerTemplate = parser.getString(group + property);
case "loggerImmediateShutdown" -> loggerImmediateShutdown = parser.getBoolean(group + property); case "loggerImmediateShutdown" -> loggerImmediateShutdown = parser.getBoolean(group + property);
case "loggerForceStandardOutput" -> loggerForceStandardOutput = parser.getBoolean(group + property); case "loggerForceStandardOutput" -> loggerForceStandardOutput = parser.getBoolean(group + property);
case "loggerPollingSpeed" -> loggerPollingSpeed = parser.getInteger(group + property, true);
case "optimizeLogging" -> optimizeLogging = parser.getBoolean(group + property); case "optimizeLogging" -> optimizeLogging = parser.getBoolean(group + property);
case "optimizeEvents" -> optimizeEvents = parser.getBoolean(group + property); case "optimizeEvents" -> optimizeEvents = parser.getBoolean(group + property);
@ -293,6 +311,7 @@ public final class EngineConfiguration implements SubsystemConfiguration {
loggerTemplate = "%log_color_primary%[%time_hour%:%time_minute%:%time_second%] [%log_level% %log_path%%log_info%] %log_color_secondary%%log_message%<reset>"; loggerTemplate = "%log_color_primary%[%time_hour%:%time_minute%:%time_second%] [%log_level% %log_path%%log_info%] %log_color_secondary%%log_message%<reset>";
loggerImmediateShutdown = false; loggerImmediateShutdown = false;
loggerForceStandardOutput = false; loggerForceStandardOutput = false;
loggerPollingSpeed = 25;
optimizeLogging = true; optimizeLogging = true;
optimizeEvents = true; optimizeEvents = true;
@ -328,6 +347,9 @@ public final class EngineConfiguration implements SubsystemConfiguration {
case "loggerForceStandardOutput" -> { case "loggerForceStandardOutput" -> {
return loggerForceStandardOutput; return loggerForceStandardOutput;
} }
case "loggerPollingSpeed" -> {
return loggerPollingSpeed;
}
case "optimizeLogging" -> { case "optimizeLogging" -> {
return optimizeLogging; return optimizeLogging;

View file

@ -31,8 +31,10 @@ import de.staropensource.sosengine.base.utility.PlaceholderEngine;
import lombok.Getter; import lombok.Getter;
import lombok.Setter; import lombok.Setter;
import org.jetbrains.annotations.NotNull; import org.jetbrains.annotations.NotNull;
import org.jetbrains.annotations.Nullable;
import java.util.ArrayList; import java.util.ArrayList;
import java.util.LinkedList;
import java.util.List; import java.util.List;
/** /**
@ -70,6 +72,28 @@ public final class Logger {
@Setter @Setter
private static LoggerImpl loggerImplementation = new DefaultLoggerImpl(); private static LoggerImpl loggerImplementation = new DefaultLoggerImpl();
/**
* Refers to the logging thread.
*
* @since 1-alpha1
*
* -- GETTER --
* Returns the logging thread.
*
* @return logging thread
* @since 1-alpha1
*/
@Getter
@Nullable
private static Thread loggingThread;
/**
* A list of {@link QueuedLogMessage}s.
*
* @since 1-alpha1
*/
private static final LinkedList<QueuedLogMessage> queuedMessages = new LinkedList<>();
/** /**
* Constructor. * Constructor.
* *
@ -78,19 +102,62 @@ public final class Logger {
public Logger() {} public Logger() {}
/** /**
* Handler for all log messages. * Starts the logging thread.
* *
* @param level log level * @since 1-alpha1
* @param logIssuer log issuer * @see Logger#getLoggingThread()
* @param message log message
* @since 1-alpha0
*/ */
private static void log(@NotNull LogLevel level, @NotNull LogIssuer logIssuer, @NotNull String message) { public static void startLoggingThread() {
Runnable loggingCode = () -> { if (loggingThread == null) {
// Check if engine has initialized loggingThread = Thread.ofPlatform().start(() -> {
if (Engine.getInstance() == null) return; while (true) {
if (Engine.getInstance().isShuttingDown())
return;
// Check if level is allowed flushLogMessages();
try {
//noinspection BusyWait
Thread.sleep(EngineConfiguration.getInstance().getLoggerPollingSpeed());
} catch (Exception ignored) {
}
if (Engine.getInstance().isShuttingDown())
return;
}
});
} else {
if (!loggingThread.isAlive())
loggingThread.start();
}
}
/**
* Prints all queued log messages.
*
* @since 1-alpha1
*/
public static synchronized void flushLogMessages() {
if (!queuedMessages.isEmpty()) {
//noinspection unchecked
LinkedList<QueuedLogMessage> queuedMessagesCloned = (LinkedList<QueuedLogMessage>) queuedMessages.clone();
queuedMessages.clear();
for (QueuedLogMessage queuedLogMessage : queuedMessagesCloned) {// Check if level is allowed
processLogMessage(queuedLogMessage.getIssuer(), queuedLogMessage.getLevel(), queuedLogMessage.getMessage());
}
}
}
/**
* Processes a log message.
*
* @param issuer log issuer
* @param level log level
* @param message log message
* @since 1-alpha1
*/
private static void processLogMessage(@NotNull LogIssuer issuer, @NotNull LogLevel level, @NotNull String message) {
if (level.compareTo(EngineConfiguration.getInstance().getLoggerLevel()) < 0) if (level.compareTo(EngineConfiguration.getInstance().getLoggerLevel()) < 0)
return; return;
@ -98,7 +165,7 @@ public final class Logger {
String base = EngineConfiguration.getInstance().getLoggerTemplate(); String base = EngineConfiguration.getInstance().getLoggerTemplate();
// Execute LoggerImpl#prePlaceholder // Execute LoggerImpl#prePlaceholder
base = loggerImplementation.prePlaceholder(level, logIssuer, base); base = loggerImplementation.prePlaceholder(level, issuer, base);
// Create list of temporary placeholders // Create list of temporary placeholders
List<@NotNull Placeholder> temporaryPlaceholders = new ArrayList<>(); List<@NotNull Placeholder> temporaryPlaceholders = new ArrayList<>();
@ -106,31 +173,43 @@ public final class Logger {
temporaryPlaceholders.add(new LogColorPrimary(level)); temporaryPlaceholders.add(new LogColorPrimary(level));
temporaryPlaceholders.add(new LogColorSecondary(level)); temporaryPlaceholders.add(new LogColorSecondary(level));
temporaryPlaceholders.add(new LogClass(logIssuer)); temporaryPlaceholders.add(new LogClass(issuer));
temporaryPlaceholders.add(new LogColorPrimary(level)); temporaryPlaceholders.add(new LogColorPrimary(level));
temporaryPlaceholders.add(new LogInfo(logIssuer)); temporaryPlaceholders.add(new LogInfo(issuer));
temporaryPlaceholders.add(new de.staropensource.sosengine.base.logging.placeholders.logger.LogLevel(level)); temporaryPlaceholders.add(new de.staropensource.sosengine.base.logging.placeholders.logger.LogLevel(level));
temporaryPlaceholders.add(new LogPackage(logIssuer)); temporaryPlaceholders.add(new LogPackage(issuer));
temporaryPlaceholders.add(new LogPath(logIssuer)); temporaryPlaceholders.add(new LogPath(issuer));
// Replace placeholders // Replace placeholders
base = PlaceholderEngine.getInstance().process(base, temporaryPlaceholders); base = PlaceholderEngine.getInstance().process(base, temporaryPlaceholders);
// Execute LoggerImpl#postPlaceholder // Execute LoggerImpl#postPlaceholder
base = loggerImplementation.postPlaceholder(level, logIssuer, base); base = loggerImplementation.postPlaceholder(level, issuer, base);
// Call event // Call event
if (!logIssuer.getClazz().getName().equals("de.staropensource.sosengine.slf4j_compat.CompatibilityLogger")) if (!issuer.getClazz().getName().equals("de.staropensource.sosengine.slf4j_compat.CompatibilityLogger"))
new LogEvent().callEvent(level, logIssuer, message); new LogEvent().callEvent(level, issuer, message);
// Print log message // Print log message
loggerImplementation.print(level, logIssuer, base); loggerImplementation.print(level, issuer, base);
}; }
/**
* Handler for all log messages.
*
* @param issuer log issuer
* @param level log level
* @param message log message
* @since 1-alpha0
*/
private static synchronized void log(@NotNull LogIssuer issuer, @NotNull LogLevel level, @NotNull String message) {
// Check if engine has initialized
if (Engine.getInstance() == null) return;
if (EngineConfiguration.getInstance().isOptimizeLogging()) if (EngineConfiguration.getInstance().isOptimizeLogging())
Thread.ofVirtual().start(loggingCode); queuedMessages.add(new QueuedLogMessage(issuer, level, message));
else else
loggingCode.run(); processLogMessage(issuer, level, message);
} }
/** /**
@ -141,7 +220,7 @@ public final class Logger {
* @since 1-alpha0 * @since 1-alpha0
*/ */
public static void diag(@NotNull LogIssuer logIssuer, @NotNull String message) { public static void diag(@NotNull LogIssuer logIssuer, @NotNull String message) {
log(LogLevel.DIAGNOSTIC, logIssuer, message); log(logIssuer, LogLevel.DIAGNOSTIC, message);
} }
/** /**
@ -152,7 +231,7 @@ public final class Logger {
* @since 1-alpha0 * @since 1-alpha0
*/ */
public static void verb(@NotNull LogIssuer logIssuer, @NotNull String message) { public static void verb(@NotNull LogIssuer logIssuer, @NotNull String message) {
log(LogLevel.VERBOSE, logIssuer, message); log(logIssuer, LogLevel.VERBOSE, message);
} }
/** /**
@ -163,7 +242,7 @@ public final class Logger {
* @since 1-alpha0 * @since 1-alpha0
*/ */
public static void sarn(@NotNull LogIssuer logIssuer, @NotNull String message) { public static void sarn(@NotNull LogIssuer logIssuer, @NotNull String message) {
log(LogLevel.SILENT_WARNING, logIssuer, message); log(logIssuer, LogLevel.SILENT_WARNING, message);
} }
/** /**
@ -174,7 +253,7 @@ public final class Logger {
* @since 1-alpha0 * @since 1-alpha0
*/ */
public static void info(@NotNull LogIssuer logIssuer, @NotNull String message) { public static void info(@NotNull LogIssuer logIssuer, @NotNull String message) {
log(LogLevel.INFORMATIONAL, logIssuer, message); log(logIssuer, LogLevel.INFORMATIONAL, message);
} }
/** /**
@ -185,7 +264,7 @@ public final class Logger {
* @since 1-alpha0 * @since 1-alpha0
*/ */
public static void warn(@NotNull LogIssuer logIssuer, @NotNull String message) { public static void warn(@NotNull LogIssuer logIssuer, @NotNull String message) {
log(LogLevel.WARNING, logIssuer, message); log(logIssuer, LogLevel.WARNING, message);
} }
/** /**
@ -196,7 +275,7 @@ public final class Logger {
* @since 1-alpha0 * @since 1-alpha0
*/ */
public static void error(@NotNull LogIssuer logIssuer, @NotNull String message) { public static void error(@NotNull LogIssuer logIssuer, @NotNull String message) {
log(LogLevel.ERROR, logIssuer, message); log(logIssuer, LogLevel.ERROR, message);
} }
/** /**

View file

@ -0,0 +1,90 @@
/*
* STAROPENSOURCE ENGINE SOURCE FILE
* Copyright (c) 2024 The StarOpenSource Engine Contributors
* Licensed under the GNU Affero General Public License v3
*
* This program is free software: you can redistribute it and/or modify
* it under the terms of the GNU Affero General Public License as
* published by the Free Software Foundation, either version 3 of the
* License, or (at your option) any later version.
*
* This program is distributed in the hope that it will be useful,
* but WITHOUT ANY WARRANTY; without even the implied warranty of
* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
* GNU Affero General Public License for more details.
*
* You should have received a copy of the GNU Affero General Public License
* along with this program. If not, see <https://www.gnu.org/licenses/>.
*/
package de.staropensource.sosengine.base.logging;
import de.staropensource.sosengine.base.types.LogIssuer;
import de.staropensource.sosengine.base.types.LogLevel;
import lombok.Getter;
import org.jetbrains.annotations.NotNull;
/**
* Represents a queued log message.
*
* @since 1-alpha1
*/
@SuppressWarnings({ "unused", "JavadocDeclaration", "JavadocBlankLines" })
@Getter
public class QueuedLogMessage {
/**
* The log message's issuer.
*
* @since 1-alpha1
*
* -- GETTER --
* Returns the log message's issuer.
*
* @return issuer
* @since 1-alpha1
*/
@NotNull
private final LogIssuer issuer;
/**
* The log message's level.
*
* @since 1-alpha1
*
* -- GETTER --
* Returns the log message's level.
*
* @return level
* @since 1-alpha1
*/
@NotNull
private final LogLevel level;
/**
* The log message.
*
* @since 1-alpha1
*
* -- GETTER --
* Returns the log message.
*
* @return message
* @since 1-alpha1
*/
@NotNull
private final String message;
/**
* Constructor.
*
* @param issuer log message issuer
* @param level log message level
* @param message log message
* @since 1-alpha1
*/
public QueuedLogMessage(@NotNull LogIssuer issuer, @NotNull LogLevel level, @NotNull String message) {
this.issuer = issuer;
this.level = level;
this.message = message;
}
}