diff --git a/service/definition/src/main/java/ai/timefold/solver/service/definition/impl/executionprofile/VerboseLoggingExecutionProfile.java b/service/definition/src/main/java/ai/timefold/solver/service/definition/impl/executionprofile/VerboseLoggingExecutionProfile.java new file mode 100644 index 00000000000..12a00d7394b --- /dev/null +++ b/service/definition/src/main/java/ai/timefold/solver/service/definition/impl/executionprofile/VerboseLoggingExecutionProfile.java @@ -0,0 +1,81 @@ +package ai.timefold.solver.service.definition.impl.executionprofile; + +import java.util.Locale; +import java.util.Map; + +import ai.timefold.solver.service.definition.internal.executionprofile.ExecutionProfile; +import ai.timefold.solver.service.definition.internal.platform.EnvironmentVars; + +/** + * Captures verbose solver logs into a file that is collected as a run artifact. + *

+ * The profile takes no run options. It maps to a fixed set of Quarkus logging environment variables that enable a file + * appender, raise the {@code ai.timefold.solver} category to {@code DEBUG}, and write into this profile's own subdirectory of + * the execution-profile artifacts directory ({@link EnvironmentVars#DEFAULT_EXECUTION_PROFILE_DIR}). Whatever ends up there is + * bundled and uploaded when the run finishes (see {@code ExecutionProfileModelPostProcessor} in the enterprise worker). + *

+ * The extra verbosity is confined to the uploaded file: raising a category to {@code DEBUG} makes those records reach every + * handler, and Quarkus' console handler defaults to level {@code ALL}, so without intervention the {@code DEBUG} lines would + * also appear on stdout and inflate the pod's normal log stream. This profile therefore pins the console handler to + * {@code INFO}, leaving the live stdout stream unchanged while the file captures the {@code DEBUG} detail. + *

+ * The log volume is bounded by Quarkus' built-in size-based rotation: {@link #MAX_FILE_SIZE} per segment and at most + * {@link #MAX_BACKUP_INDEX} rotated segments, giving a fixed ceiling that does not grow with run duration. These limits are + * fixed constants of this specification, not tunable per run. + */ +public final class VerboseLoggingExecutionProfile implements ExecutionProfile { + + static final String ID = "verbose-logging"; + + /** File name of the log, written inside {@code //}. */ + static final String LOG_FILE_NAME = "solver-debug.log"; + + /** Solver category raised to {@code DEBUG}; never a blanket root-logger bump. */ + static final String DEBUG_CATEGORY = "ai.timefold.solver"; + + /** Maximum size of a single log segment before it is rotated. */ + static final String MAX_FILE_SIZE = "10M"; + + /** Maximum number of rotated segments kept alongside the active log. */ + static final String MAX_BACKUP_INDEX = "2"; + + static final String ENV_QUARKUS_LOG_FILE_ENABLE = "QUARKUS_LOG_FILE_ENABLE"; + static final String ENV_QUARKUS_LOG_FILE_PATH = "QUARKUS_LOG_FILE_PATH"; + static final String ENV_QUARKUS_LOG_FILE_ROTATION_MAX_FILE_SIZE = "QUARKUS_LOG_FILE_ROTATION_MAX_FILE_SIZE"; + static final String ENV_QUARKUS_LOG_FILE_ROTATION_MAX_BACKUP_INDEX = "QUARKUS_LOG_FILE_ROTATION_MAX_BACKUP_INDEX"; + // Keeps the raised DEBUG detail out of stdout; see the class Javadoc. + static final String ENV_QUARKUS_LOG_CONSOLE_LEVEL = "QUARKUS_LOG_CONSOLE_LEVEL"; + + // Environment-variable form of quarkus.log.category."".level: the category is upper-cased with its dots + // turned into single underscores, wrapped by the double-underscore quoted-segment boundaries. + static final String ENV_QUARKUS_LOG_CATEGORY_SOLVER_LEVEL = + "QUARKUS_LOG_CATEGORY__" + DEBUG_CATEGORY.toUpperCase(Locale.ROOT).replace('.', '_') + "__LEVEL"; + + static final String LOG_FILE_PATH = EnvironmentVars.DEFAULT_EXECUTION_PROFILE_DIR + "/" + ID + "/" + LOG_FILE_NAME; + + @Override + public String id() { + return ID; + } + + @Override + public String name() { + return "Verbose logging"; + } + + @Override + public String description() { + return "Captures verbose (DEBUG) solver logs into a size-bounded, rotating file that is uploaded as a run artifact."; + } + + @Override + public Map toEnvironment(Map options) { + return Map.of( + ENV_QUARKUS_LOG_FILE_ENABLE, "true", + ENV_QUARKUS_LOG_FILE_PATH, LOG_FILE_PATH, + ENV_QUARKUS_LOG_FILE_ROTATION_MAX_FILE_SIZE, MAX_FILE_SIZE, + ENV_QUARKUS_LOG_FILE_ROTATION_MAX_BACKUP_INDEX, MAX_BACKUP_INDEX, + ENV_QUARKUS_LOG_CATEGORY_SOLVER_LEVEL, "DEBUG", + ENV_QUARKUS_LOG_CONSOLE_LEVEL, "INFO"); + } +} diff --git a/service/definition/src/main/resources/META-INF/services/ai.timefold.solver.service.definition.internal.executionprofile.ExecutionProfile b/service/definition/src/main/resources/META-INF/services/ai.timefold.solver.service.definition.internal.executionprofile.ExecutionProfile index 51bcdb4831d..9c5d8109ac5 100644 --- a/service/definition/src/main/resources/META-INF/services/ai.timefold.solver.service.definition.internal.executionprofile.ExecutionProfile +++ b/service/definition/src/main/resources/META-INF/services/ai.timefold.solver.service.definition.internal.executionprofile.ExecutionProfile @@ -1 +1,2 @@ ai.timefold.solver.service.definition.impl.executionprofile.SeedExecutionProfile +ai.timefold.solver.service.definition.impl.executionprofile.VerboseLoggingExecutionProfile diff --git a/service/definition/src/test/java/ai/timefold/solver/service/definition/impl/executionprofile/VerboseLoggingExecutionProfileTest.java b/service/definition/src/test/java/ai/timefold/solver/service/definition/impl/executionprofile/VerboseLoggingExecutionProfileTest.java new file mode 100644 index 00000000000..a53ac925148 --- /dev/null +++ b/service/definition/src/test/java/ai/timefold/solver/service/definition/impl/executionprofile/VerboseLoggingExecutionProfileTest.java @@ -0,0 +1,69 @@ +package ai.timefold.solver.service.definition.impl.executionprofile; + +import static org.assertj.core.api.Assertions.assertThat; + +import java.util.Map; + +import ai.timefold.solver.service.definition.internal.platform.EnvironmentVars; + +import org.junit.jupiter.api.Test; + +class VerboseLoggingExecutionProfileTest { + + private final VerboseLoggingExecutionProfile profile = new VerboseLoggingExecutionProfile(); + + @Test + void enablesRotatingFileLoggingAtDebug() { + assertThat(profile.toEnvironment(Map.of())) + .containsOnly( + Map.entry(VerboseLoggingExecutionProfile.ENV_QUARKUS_LOG_FILE_ENABLE, "true"), + Map.entry(VerboseLoggingExecutionProfile.ENV_QUARKUS_LOG_FILE_PATH, + VerboseLoggingExecutionProfile.LOG_FILE_PATH), + Map.entry(VerboseLoggingExecutionProfile.ENV_QUARKUS_LOG_FILE_ROTATION_MAX_FILE_SIZE, + VerboseLoggingExecutionProfile.MAX_FILE_SIZE), + Map.entry(VerboseLoggingExecutionProfile.ENV_QUARKUS_LOG_FILE_ROTATION_MAX_BACKUP_INDEX, + VerboseLoggingExecutionProfile.MAX_BACKUP_INDEX), + Map.entry(VerboseLoggingExecutionProfile.ENV_QUARKUS_LOG_CATEGORY_SOLVER_LEVEL, "DEBUG"), + Map.entry(VerboseLoggingExecutionProfile.ENV_QUARKUS_LOG_CONSOLE_LEVEL, "INFO")); + } + + @Test + void encodesTheSolverCategoryEnvVarName() { + // The category env-var name is derived from the dotted category, not hardcoded, so the two can never drift apart. + assertThat(VerboseLoggingExecutionProfile.ENV_QUARKUS_LOG_CATEGORY_SOLVER_LEVEL) + .isEqualTo("QUARKUS_LOG_CATEGORY__AI_TIMEFOLD_SOLVER__LEVEL"); + } + + @Test + void keepsTheDebugDetailOutOfStdout() { + // Raising the category to DEBUG alone would also surface on the console (default level ALL); pinning the console + // handler to INFO confines the extra verbosity to the uploaded file. + assertThat(profile.toEnvironment(Map.of())) + .containsEntry(VerboseLoggingExecutionProfile.ENV_QUARKUS_LOG_CONSOLE_LEVEL, "INFO"); + } + + @Test + void writesIntoItsOwnSubdirectoryOfTheArtifactsDirectory() { + // The log must land under // so the post-processor bundles it, and so multiple active profiles + // never collide on the same file. + assertThat(profile.toEnvironment(Map.of())) + .containsEntry(VerboseLoggingExecutionProfile.ENV_QUARKUS_LOG_FILE_PATH, + EnvironmentVars.DEFAULT_EXECUTION_PROFILE_DIR + "/" + profile.id() + "/" + + VerboseLoggingExecutionProfile.LOG_FILE_NAME); + } + + @Test + void ignoresRunOptions() { + // The profile is fully static: it recognizes no options and never varies its environment. + assertThat(profile.toEnvironment(Map.of("seed", "42", "solver", "fast"))) + .isEqualTo(profile.toEnvironment(Map.of())); + } + + @Test + void raisesOnlyTheSolverCategoryNotTheRootLogger() { + Map environment = profile.toEnvironment(Map.of()); + assertThat(environment).containsEntry(VerboseLoggingExecutionProfile.ENV_QUARKUS_LOG_CATEGORY_SOLVER_LEVEL, "DEBUG"); + // No blanket root-logger level bump. + assertThat(environment).doesNotContainKey("QUARKUS_LOG_LEVEL"); + } +} diff --git a/service/quarkus/deployment/src/main/java/ai/timefold/solver/service/quarkus/deployment/TimefoldLoggingConfigProcessor.java b/service/quarkus/deployment/src/main/java/ai/timefold/solver/service/quarkus/deployment/TimefoldLoggingConfigProcessor.java index 9dc363e0bf2..6309bc41ba8 100644 --- a/service/quarkus/deployment/src/main/java/ai/timefold/solver/service/quarkus/deployment/TimefoldLoggingConfigProcessor.java +++ b/service/quarkus/deployment/src/main/java/ai/timefold/solver/service/quarkus/deployment/TimefoldLoggingConfigProcessor.java @@ -22,6 +22,8 @@ void confiugreSolverLogging(CombinedIndexBuildItem combinedIndex, "%d{HH:mm:ss.SSS} %5p %m%n")); runtimeConfigBuildProducer.produce( new RunTimeConfigurationDefaultBuildItem("quarkus.log.handler.file.solver.filter", "solver-log-filter")); + runtimeConfigBuildProducer.produce( + new RunTimeConfigurationDefaultBuildItem("quarkus.log.handler.file.solver.level", "INFO")); runtimeConfigBuildProducer.produce( new RunTimeConfigurationDefaultBuildItem("quarkus.log.category.\"ai.timefold.solver\".handlers", "solver")); }