Skip to content

fix: reset Logback once the real log folder is known + upgrade to 1.6.0 - #5343

Merged
Cervator merged 10 commits into
developfrom
fix/logging-init-phase-undefined-folder
Jul 29, 2026
Merged

fix: reset Logback once the real log folder is known + upgrade to 1.6.0#5343
Cervator merged 10 commits into
developfrom
fix/logging-init-phase-undefined-folder

Conversation

@soloturn

@soloturn soloturn commented Jul 28, 2026

Copy link
Copy Markdown
Contributor

AI-assisted change proposal. Filed by agent driven by @soloturn via GDD.

Summary

  • The actual fix (Early startup logs land in a stray logFileFolder_IS_UNDEFINED directory instead of the session log folder #5339): whichever class logs first triggers SLF4J's static binding as soon as its class loads - regardless of whether it ever logs anything. Terasology.java's own private static final Logger logger = ... field is exactly such a case: loading the Terasology class (an unavoidable prerequisite to running main()'s body at all) binds Logback before LoggingContext.initialize() ever gets a chance to set the logFileFolder system property the sifting appender's ${logFileFolder} substitution depends on. Any log statement up to that point resolved to a stray, never-cleaned logFileFolder_IS_UNDEFINED directory instead of the correct per-session folder.

  • The code already diagnosed this in a comment and had an abandoned attempt at fixing it, but that attempt created a brand new, disconnected LoggerContext rather than reconfiguring the one SLF4J's LoggerFactory actually returns - so it wouldn't have affected anything.

  • Fixed by resetting and reconfiguring the existing bound context (fetched via LoggerFactory.getILoggerFactory()) right after logFileFolder is set. Existing Logger references stay correctly bound to it, since Logger objects delegate to the context's appender configuration dynamically rather than caching resolved appenders - so this retroactively fixes logging for the rest of the run.

  • Verified empirically with a standalone repro against the real LoggingContext + facades/PC's real logback.xml: a static Logger field (mirroring Terasology.java's own) triggers premature binding before initialize() runs, then logs again after. Before this fix that creates a logFileFolder_IS_UNDEFINED directory; after this fix, no such directory is created at all, and the post-init log line lands correctly in the real per-session folder. The one line logged in the narrow pre-initialize window is lost from file output (still visible on console) rather than misplaced into a wrong folder - a much smaller residual than the original bug, which lost potentially minutes of real startup logging (module discovery, subsystem init - exactly the period most useful for diagnosing early crashes) into an ever-growing, never-cleaned stray directory.

  • Also upgraded Logback (1.4.14 → 1.6.0, current actively-developed release) and SLF4J (2.0.11 → 2.0.18, the version 1.6.0 is built/tested against), since the fix above was re-verified against 1.6.0 specifically. Along the way:

    • JaninoEventEvaluator (used by EvaluatorFilter's classic <evaluator><expression> config style) was removed back in Logback 1.5.13. Confirmed empirically that under 1.6.0 this silently degrades to a no-op stub rather than failing loudly - a filter using it stops actually filtering anything, with just a startup warning.
    • ModuleTestingEnvironment's default-logback.xml was the only place in this repo actually using EvaluatorFilter (to suppress noisy Reflections "given scan urls are empty" warnings) - migrated to a native Java EventEvaluator in a companion PR on that repo (Terasology/ModuleTestingEnvironment#81), verified to correctly deny the matching message with no warnings.
    • Two runtimeOnly Janino dependencies existed specifically to enable that: one is now unused (removed here, terasology-module.gradle.kts), and facades/PC's own copy turned out to be dead weight already (logback.xml doesn't use EvaluatorFilter at all).

Additional fixes found while testing this branch

Testing this branch surfaced several more bugs, unrelated to logging itself but hit along the way (CI flakiness investigation, then live gameplay testing). Each is its own commit, in case any need to be split out or reverted independently.

  • BlockFamilyLibrary resolved via the wrong context (host/client race): BlockFamilyHandler (used when parsing .block JSON files) resolved BlockFamilyLibrary via the process-wide static CoreRegistry.get(). In the integration test harness, host and client TerasologyEngine instances run in the same JVM and each overwrite that single static field with their own context on every tick - a block-family deserialization racing against that could observe the wrong engine's library, or a momentarily null one. This is what was actually failing in DelayManagerTest.delayedActionIsTriggeredTest on CI (a 30s timeout inside helper.createClient(), not a real timing flake in the test itself). Fixed by having each TerasologyEngine supply its own current-state context instead of going through the shared static.

  • Component deserialization couldn't restore final fields (e.g. LocationComponent.position): ObjectFieldMapTypeHandlerFactory.getResolvedFields() only called field.setAccessible(true) for fields carrying a specific override annotation - never for ordinary public fields. Writing to a final field via reflection always requires setAccessible(true) first regardless of visibility (a plain, JDK-version-independent Java rule). Concretely: a saved player entity's position failed to restore on load, which looked like movement had broken rather than an entity-restore failure. (An earlier attempt at this diagnosed it as a JDK-26-specific final-field-mutation restriction and added a JVM flag workaround - that diagnosis was wrong, confirmed by a standalone repro, and the flag has been removed; the actual fix is the setAccessible(true) call.)

  • Saved particle emitters couldn't resolve their Affector/Generator subtype: RuntimeDelegatingTypeHandler resolves a saved particle emitter's function by class name through ModuleTypeRegistry, which doesn't do a live classpath scan - it reads a build-time-generated index (META-INF/subtypes/<baseType>, produced by gestalt's ClassIndexProcessor annotation processor) that's only populated for hierarchies rooted at a type annotated @Index/@IndexInherited. AffectorFunction/GeneratorFunction only carried @API (a different, unrelated annotation), never @IndexInherited, so the index for either base type was never generated at all - any saved particle emitter referencing a built-in function (AccelerationAffectorFunction, TextureOffsetGeneratorFunction, etc.) fell back to the abstract base type, which has no handler, and NPE'd downstream in ParticleUpdaterImpl.configureEmitter(). Fixed by adding @IndexInherited to both base classes; verified by inspecting the regenerated index file directly (both previously-failing classes are now listed).

  • Module classloader whitelist gap for the same particle packages: while chasing the above, also whitelisted org.terasology.engine.particles.functions.affectors/.generators in ExternalApiWhitelist (same mechanism as the existing org.terasology.engine.persistence.internal entry, added previously for EntityRestorer). This didn't fix the bug on its own (the real gap was the missing index, above), but the module-scoped classloader a resolved class name loads through is whitelist-gated, so it may still be needed for the load step. Left in place rather than reverted.

  • The real cause of the remaining "Failed to register block family" NPEs (ComponentMetadata null) - non-deterministic duplicate module resolution: after the particle-index fix, similar-looking NullPointerExceptions kept recurring across different, seemingly unrelated modules from run to run of the same save. Root cause: the dependency-substitution loop in this repo's own root build.gradle.kts (meant to redirect org.terasology.modules:X to a local :modules:X project when a source checkout exists) was only ever applied to :modules's subprojects' own configurations - never to :modules itself, the parent/aggregator project whose own "classpath" configuration is what :modules:fetchModuleDependencies actually resolves to populate cachedModules/. So every module with a local checkout still got its external artifact synced into cachedModules/ right alongside the live local build. PathManager scans both cachedModules/ and modules/ at runtime; gestalt's ModulePathScanner has no idea one copy is stale, so it keeps whichever it discovers first - File.listFiles() gives no ordering guarantee across launches, so which copy "won" varied run to run. When the stale jar won, its (out of sync) component classes didn't match what current prefabs from other locally-built modules expected, producing ComponentMetadata-not-found NPEs for whichever block families a given session's world happened to touch. Fixed by extending the substitution to :modules itself; verified :modules:fetchModuleDependencies now resolves NO-SOURCE (zero external module artifacts needed) and cachedModules/ is empty after a clean re-fetch. Also hardened BlockPrefabManager.updateBlock() to skip-and-log rather than NPE on a component with no registered metadata, kept as a permanent defensive improvement rather than reverted now that the root cause is fixed.

  • SkeletonRenderer crashed the whole world-load on one skeleton's stale bone-entity references: a downstream symptom of the same module-resolution issue above (entities failing to restore consistently). SkeletalMeshComponent.boneEntities is a persisted map of per-bone sub-entity references; newSkeleton() only (re)created them as a group, gated on the whole map being null. If it was already populated from a save but even one referenced bone entity failed to restore, boneEntity.getComponent(LocationComponent.class) returned null and the next line's NPE aborted PrepareWorld outright, taking down the entire load over one skeleton's stale state. Now validates each bone entity individually and recreates just that one if missing/invalid.

Test plan

  • Standalone repro against the real LoggingContext + real logback.xml, both under Logback 1.4.14 and again under 1.6.0: no logFileFolder_IS_UNDEFINED directory created, log lines land in the correct per-session folder.
  • gradle :engine:compileJava :facades:PC:compileJava (whole multi-module build, all modules including ModuleTestingEnvironment) succeeds.
  • gradle game: confirmed live across multiple sessions/saves - player movement/position restores correctly on load, no IllegalAccessException, no particle RuntimeDelegatingTypeHandler errors, no logFileFolder_IS_UNDEFINED directory, no cachedModules/-duplicate-driven ComponentMetadata NPEs, world loads and saves cleanly.
  • ModuleTestingEnvironment-based module tests: confirm the "given scan urls are empty" noise is still suppressed.

Related

@soloturn soloturn added the Type: Bug Issues reporting and PRs fixing problems label Jul 28, 2026
@coderabbitai

coderabbitai Bot commented Jul 28, 2026

Copy link
Copy Markdown

Review Change Stack

Note

Reviews paused

It looks like this branch is under active development. To avoid overwhelming you with review comments due to an influx of new commits, CodeRabbit has automatically paused this review. You can configure this behavior by changing the reviews.auto_review.auto_pause_after_reviewed_commits setting.

Use the following commands to manage reviews:

  • @coderabbitai resume to resume automatic reviews.
  • @coderabbitai review to trigger a single review.

Use the checkboxes below for quick actions:

  • ▶️ Resume reviews
  • ✅ Review completed - (🔄 Check again to review again)
📝 Walkthrough

Walkthrough

Logging dependencies and initialization are updated, block-family parsing receives context-based library resolution, and reflective deserialization enables access to selected fields.

Changes

Logging configuration flow

Layer / File(s) Summary
Align logging runtime dependencies
settings.gradle.kts, build-logic/src/main/kotlin/..., facades/PC/build.gradle.kts
Logback and SLF4J are upgraded, Janino is removed, and PC runtime logging dependencies are updated.
Reconfigure the bound Logback context
engine/src/main/java/org/terasology/engine/core/LoggingContext.java
The active Logback context is reset and automatically reconfigured after the logging folder is established.

Block-family library resolution

Layer / File(s) Summary
Inject the active block-family library
engine/src/main/java/org/terasology/engine/world/block/loader/BlockFamilyDefinitionFormat.java, engine/src/main/java/org/terasology/engine/core/TerasologyEngine.java
Block-family deserialization accepts a library supplier, and the engine supplies the library from the active game-state context.

Runtime deserialization compatibility

Layer / File(s) Summary
Enable reflective field access
subsystems/TypeHandlerLibrary/src/main/java/.../ObjectFieldMapTypeHandlerFactory.java
Resolved fields are marked accessible before their generic types are processed.

Estimated code review effort: 3 (Moderate) | ~25 minutes

Sequence Diagram(s)

sequenceDiagram
  participant LoggingContext
  participant LoggerFactory
  participant LoggerContext
  participant ContextInitializer
  LoggingContext->>LoggerFactory: getILoggerFactory()
  LoggerFactory-->>LoggingContext: return active factory
  LoggingContext->>LoggerContext: reset()
  LoggingContext->>ContextInitializer: autoConfig()
  ContextInitializer-->>LoggingContext: reload logback.xml
Loading
sequenceDiagram
  participant TerasologyEngine
  participant BlockFamilyDefinitionFormat
  participant BlockFamilyHandler
  participant GameState
  TerasologyEngine->>BlockFamilyDefinitionFormat: provide BlockFamilyLibrary supplier
  BlockFamilyDefinitionFormat->>BlockFamilyHandler: register handler with supplier
  BlockFamilyHandler->>GameState: resolve active context
  GameState-->>BlockFamilyHandler: return BlockFamilyLibrary
Loading

Possibly related PRs

Suggested reviewers: cervator, benjaminamos

Poem

I twitch my nose as logs align,
No stray folders left behind.
A library hops through context bright,
Fields open up for save-load flight.
Hop, hop—clean paths and code take wing!

🚥 Pre-merge checks | ✅ 3 | ❌ 2

❌ Failed checks (2 warnings)

Check name Status Explanation Resolution
Linked Issues check ⚠️ Warning The fix still leaves a pre-init log line out of the file output, so the earliest logs are not fully routed as #5339 requires. Ensure LoggingContext initializes before any static logger binds, or otherwise capture the first init log in the active session folder.
Out of Scope Changes check ⚠️ Warning The PR also changes block-family loading and reflection access, which are unrelated to #5339's logging fix. Split the unrelated engine/reflection changes into a separate PR and keep this one focused on logging and dependency updates.
✅ Passed checks (3 passed)
Check name Status Explanation
Docstring Coverage ✅ Passed No functions found in the changed files to evaluate docstring coverage. Skipping docstring coverage check.
Title check ✅ Passed The title clearly summarizes the main logging-context reset and Logback upgrade.
Description check ✅ Passed The description is detailed and directly matches the logging fix, dependency bumps, and related follow-up changes.
✨ Finishing Touches
📝 Generate docstrings
  • Create stacked PR
  • Commit on current branch
🧪 Generate unit tests (beta)
  • Create PR with unit tests
  • Commit unit tests in branch fix/logging-init-phase-undefined-folder

Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out.

❤️ Share

Comment @coderabbitai help to get the list of available commands.

@coderabbitai coderabbitai Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

🧹 Nitpick comments (1)
engine/src/main/java/org/terasology/engine/core/TerasologyEngine.java (1)

425-426: 🗄️ Data Integrity & Integration | 🔵 Trivial | 🏗️ Heavy lift

Add regression coverage for engine-local resolution.

Add a test using two engine/state contexts with distinct BlockFamilyLibrary registrations, including parsing before and after state initialization. This is the core behavior change, while game and module-test verification remain pending.

🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

In `@engine/src/main/java/org/terasology/engine/core/TerasologyEngine.java` around
lines 425 - 426, Add regression coverage around the BlockFamilyDefinitionFormat
construction in TerasologyEngine, using two engine/state contexts with distinct
BlockFamilyLibrary registrations. Verify parsing resolves against the correct
engine-local library both before and after state initialization, preserving
separate context behavior.
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

Nitpick comments:
In `@engine/src/main/java/org/terasology/engine/core/TerasologyEngine.java`:
- Around line 425-426: Add regression coverage around the
BlockFamilyDefinitionFormat construction in TerasologyEngine, using two
engine/state contexts with distinct BlockFamilyLibrary registrations. Verify
parsing resolves against the correct engine-local library both before and after
state initialization, preserving separate context behavior.

ℹ️ Review info
⚙️ Run configuration

Configuration used: Organization UI

Review profile: CHILL

Plan: Pro Plus

Run ID: ddae7d22-1549-427a-9858-a96ff0dbc267

📥 Commits

Reviewing files that changed from the base of the PR and between 7b3fe51 and 06bb6fa.

📒 Files selected for processing (2)
  • engine/src/main/java/org/terasology/engine/core/TerasologyEngine.java
  • engine/src/main/java/org/terasology/engine/world/block/loader/BlockFamilyDefinitionFormat.java

@coderabbitai coderabbitai Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

Actionable comments posted: 1

🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

Inline comments:
In `@build-logic/src/main/kotlin/org/terasology/gradology/exec.kt`:
- Around line 91-95: Condition the jvmArgs call in the RunTerasology
configuration on JavaVersion.current() being at least JavaVersion.VERSION_26, so
the --enable-final-field-mutation flag is only passed to JDK 26+ runtimes while
preserving existing behavior on supported older JDKs.
🪄 Autofix (Beta)

Fix all unresolved CodeRabbit comments on this PR:

  • Push a commit to this branch (recommended)
  • Create a new PR with the fixes

ℹ️ Review info
⚙️ Run configuration

Configuration used: Organization UI

Review profile: CHILL

Plan: Pro Plus

Run ID: 2c740db3-fe7c-4144-9736-29cfff05f90a

📥 Commits

Reviewing files that changed from the base of the PR and between 06bb6fa and b40c285.

📒 Files selected for processing (1)
  • build-logic/src/main/kotlin/org/terasology/gradology/exec.kt

Comment on lines +91 to +95
// Component deserialization reflectively sets final fields on Components (e.g.
// LocationComponent.position) - newer JDKs are progressively locking that down. Without
// this, saved entities can silently fail to restore their state on load (seen as a hard
// IllegalAccessException on JDK 26, where a JDK 17-21 caller only got a warning).
jvmArgs("--enable-final-field-mutation=ALL-UNNAMED")

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

🎯 Functional Correctness | 🟠 Major | ⚡ Quick win

🧩 Analysis chain

🏁 Script executed:

#!/bin/bash
rg -n --hidden -S \
  'JavaLanguageVersion|toolchain|sourceCompatibility|targetCompatibility|java-version|setup-java|JAVA_VERSION|JDK' .

Repository: MovingBlocks/Terasology

Length of output: 4150


🏁 Script executed:

#!/bin/bash
set -euo pipefail

printf '--- build-logic exec.kt relevant section ---\n'
cat -n build-logic/src/main/kotlin/org/terasology/gradology/exec.kt | sed -n '1,150p'

printf '\n--- README Java requirements ---\n'
cat -n README.md | sed -n '105,135p'

printf '\n--- build.gradle.kts Java/toolchain references ---\n'
cat -n build.gradle.kts | sed -n '1,140p'

printf '\n--- GitHub workflow Java versions ---\n'
if [ -d .github/workflows ]; then
  rg -n -S 'java-version|setup-java|jdk|java' .github/workflows || true
else
  echo 'no .github/workflows'
fi

Repository: MovingBlocks/Terasology

Length of output: 252


🏁 Script executed:

#!/bin/bash
set -euo pipefail

echo '--- build-logic exec.kt relevant section ---'
cat -n build-logic/src/main/kotlin/org/terasology/gradology/exec.kt | sed -n '1,150p'

echo
echo '--- README Java requirements ---'
cat -n README.md | sed -n '105,135p'

echo
echo '--- build.gradle.kts Java/toolchain references ---'
cat -n build.gradle.kts | sed -n '1,140p'

echo
echo '--- GitHub workflow Java versions ---'
if [ -d .github/workflows ]; then
  rg -n -S 'java-version|setup-java|jdk|java' .github/workflows || true
else
  echo 'no .github/workflows'
fi

Repository: MovingBlocks/Terasology

Length of output: 14228


🌐 Web query:

JEP 468 Java 26 --enable-final-field-mutation JDK 26 option Java 17 21 final field mutation

💡 Result:

The query conflates two distinct topics: JEP 468 (which is unrelated to final field mutation) and the new restrictions on final field mutation introduced in JDK 26 via JEP 500 [1][2]. JEP 468 (Derived Record Creation) JEP 468 is a preview language feature focused on enhancing the Java language with "derived record creation" (also referred to as "withers" or "reconstruction") [2][3]. This feature allows developers to create a new record instance based on an existing one by modifying only specific components, simplifying the process of handling immutable data [2][3][4]. It is entirely unrelated to the mutation of final fields. Final Field Mutation in JDK 26 (JEP 500) Starting in JDK 26, the JDK restricts the mutation of final fields through deep reflection (e.g., via java.lang.reflect.Field::set) to improve application integrity and security [5][6][7]. By default, such attempts now trigger a runtime warning [5][8][9]. Two new command-line options have been introduced to manage this transition [7][9]: 1. --enable-final-field-mutation: This permanent option enables specific modules (or ALL-UNNAMED for the class path) to mutate final fields through deep reflection, suppressing the associated warnings [5][7][9]. Example usage: java --enable-final-field-mutation=ALL-UNNAMED Application [5][1] 2. --illegal-final-field-mutation: This temporary option manages how illegal mutation attempts are handled [7][9]. It supports the following values: - warn: The default in JDK 26; issues a warning at runtime [8][7][9]. - allow: Permits the mutation. - debug: Provides additional debugging information. - deny: Blocks the mutation (expected to become the future default) [8][7][9]. Oracle recommends that developers identify libraries performing deep reflection on final fields and update, replace, or remove them rather than relying on these flags, as these mechanisms are intended to be a last resort [5][7]. These changes do not retroactively apply to older Java versions like Java 17 or 21, as they are specific to the runtime behavior of JDK 26 and later [5][1][9].

Citations:


Condition the final-field mutation flag on JDK 26+.

The project’s documented baseline is JDK 17, so applying --enable-final-field-mutation=ALL-UNNAMED to every RunTerasology task will make Gradle launch the application with an unrecognized flag on supported JDKs. Gate this JVM arg by JavaVersion.current() >= JavaVersion.VERSION_26, or raise the enforced runtime baseline before requiring JDK 26+.

🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

In `@build-logic/src/main/kotlin/org/terasology/gradology/exec.kt` around lines 91
- 95, Condition the jvmArgs call in the RunTerasology configuration on
JavaVersion.current() being at least JavaVersion.VERSION_26, so the
--enable-final-field-mutation flag is only passed to JDK 26+ runtimes while
preserving existing behavior on supported older JDKs.

soloturn and others added 6 commits July 28, 2026 19:57
Whichever class logs first triggers SLF4J's static binding as soon as its
class loads - regardless of whether it ever actually logs anything.
Terasology.java's own `private static final Logger logger = ...` field is
exactly such a case: loading the Terasology class (an unavoidable
prerequisite to running main()'s body at all) binds Logback before
LoggingContext.initialize() ever gets a chance to set the logFileFolder
system property the sifting appender's ${logFileFolder} substitution
depends on. Any log statement up to that point resolves to a stray,
never-cleaned logFileFolder_IS_UNDEFINED directory instead of the correct
per-session folder.

The code already diagnosed this in a comment and had an abandoned attempt
at fixing it, but that attempt created a brand new, disconnected
LoggerContext rather than reconfiguring the one SLF4J's LoggerFactory
actually returns - so it wouldn't have affected anything.

Fixed by resetting and reconfiguring the *existing* bound context (fetched
via LoggerFactory.getILoggerFactory()) right after logFileFolder is set.
Existing Logger references (including any already obtained before this
point) stay correctly bound to it, since Logger objects delegate to the
context's appender configuration dynamically rather than caching resolved
appenders - so this retroactively fixes logging for the rest of the run.

Verified empirically with a standalone repro against the real
LoggingContext + facades/PC's real logback.xml: a static Logger field
(mirroring Terasology.java's own) triggers premature binding before
initialize() runs, then logs again after. Before this fix that would
create a `logFileFolder_IS_UNDEFINED` directory; after this fix, no such
directory is created at all, and the post-init log line lands correctly in
the real per-session folder. The one line logged in the narrow
pre-initialize window is lost from file output (still visible on console)
rather than misplaced into a wrong folder - a much smaller residual than
the original bug, which lost potentially minutes of real startup logging
(module discovery, subsystem init - exactly the period most useful for
diagnosing early crashes) into an ever-growing, never-cleaned stray
directory.

Closes #5339.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
The previous pin (Logback 1.4.14) was in the now-EOL 1.4.x line; 1.6.0 is
the current actively-developed release (confirmed via logback.qos.ch),
requiring JDK 11+ and SLF4J 2.0.1+ - both already satisfied here. Bumped
SLF4J alongside it to 2.0.18, the version Logback 1.6.0 is itself built
and tested against.

JaninoEventEvaluator (used by EvaluatorFilter's <evaluator><expression>
config style) was removed back in Logback 1.5.13, well before this jump.
Verified empirically that under both 1.5.13+ and 1.6.0 this silently
degrades to a no-op stub rather than failing loudly - the filter still
"works" (no exceptions, just a startup warning) but stops actually
filtering anything.

Two runtimeOnly Janino dependencies were declared specifically to enable
EvaluatorFilter in a logback.xml: ModuleTestingEnvironment's
default-logback.xml (migrated to a native evaluator in a companion commit
on that repo) and facades/PC's own logback.xml (checked - it doesn't
actually use EvaluatorFilter at all, so that dependency was already dead
weight). Removed both along with the version bump, since nothing in this
repo depends on Janino-based evaluation anymore.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
…oreRegistry

BlockFamilyHandler (used when parsing .block JSON files) resolved
BlockFamilyLibrary via the process-wide static CoreRegistry.get(). In the
integration test harness, host and client TerasologyEngine instances run in
the same JVM and each overwrite that single static field with their own
context on every tick (TerasologyEngine.tick() -> CoreRegistry.setContext()).
A block-family deserialization racing against that can observe the wrong
engine's library, or a momentarily null one during a state transition -
exactly the NPE seen in CI on DelayManagerTest: the client engine timed out
30s into helper.createClient() because CoreRegistry.get(BlockFamilyLibrary)
returned null partway through world/chunk loading.

BlockFamilyDefinitionFormat now takes an optional Supplier<BlockFamilyLibrary>;
TerasologyEngine supplies its own current-state context
(() -> getState().getContext().get(BlockFamilyLibrary.class)) instead of
going through the shared static, so each engine instance resolves its own
library regardless of what any other engine in the same JVM is doing. The
single-arg constructor keeps the CoreRegistry-based fallback for
UniverseSetupScreen's world-preview use, which deliberately borrows whatever
game engine is currently running rather than owning its own library.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
…erridden ones

ObjectFieldMapTypeHandlerFactory.getResolvedFields() only called
field.setAccessible(true) for fields carrying a PRIVATE_OVERRIDE_ANNOTATIONS
annotation. Every other collected field - including ordinary public ones -
never got it called. Writing to a `final` field via reflection always
requires setAccessible(true) first, regardless of the field's own visibility;
this is a plain, JDK-version-independent Java reflection rule.
ObjectFieldMapTypeHandler.deserialize() writes every non-private field
directly via field.set(...), so any `public final` field - e.g.
LocationComponent.position - threw IllegalAccessException the moment it
needed to deserialize to a non-default value, on any JDK: concretely, a
saved player entity's position failed to restore on load, which looked like
movement had broken rather than an entity-restore failure.

Confirmed with a standalone repro (final mutable-reference field, Field.set()
with vs. without a prior setAccessible(true) call) that reproduces the exact
stack trace shape one-for-one absent the call, and disappears once it's
added.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
…le classloading

Loading a saved particle emitter deserializes its Affector/Generator function
by class name (RuntimeDelegatingTypeHandler.findSubtypeWithName() ->
ModuleEnvironmentSandbox.findSubTypeOf() -> ModuleTypeRegistry.load()), which
resolves the name through the module-scoped classloader chain -
ExternalApiWhitelist-gated, same mechanism gestalt-module uses to sandbox
what module code can reference (ModuleManager.java:260-261 feeds
ExternalApiWhitelist.PACKAGES/CLASSES into the permission set that classloader
checks against).

org.terasology.engine.particles.functions.affectors and .generators - engine-
internal packages, not something modules are expected to subclass, so never
added to the whitelist - aren't listed. So AccelerationAffectorFunction,
TextureOffsetGeneratorFunction etc. fail to load via that path even though
they're ordinary loadable engine classes: "Cannot find subtype ... to
deserialize as, deserializing as base type" falls back to the abstract base
type, which has no handler, NPEs downstream in
ParticleUpdaterImpl.configureEmitter() when the emitter's now-null function
map is used.

Same bug shape as the existing org.terasology.engine.persistence.internal
whitelist entry a few lines up ("Allow persistence internals needed during
client join (EntityRestorer, etc.)") - this is that same fix applied to the
particle system's built-in function types.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
The previous commit's ExternalApiWhitelist entries had no effect - wrong
mechanism. Traced further: RuntimeDelegatingTypeHandler resolving a saved
particle emitter's Affector/Generator subtype by name goes through
ModuleTypeRegistry.getSubtypesOf(), which doesn't do a live classpath scan -
it reads a build-time-generated index at META-INF/subtypes/<baseTypeName>,
produced by gestalt's ClassIndexProcessor annotation processor. That index is
only populated for a class hierarchy whose root is annotated @Index or
@IndexInherited (ClassIndexProcessor.processSubtypeIndexInReverseWay()/
processSubtypeIndexByDirectMarked()).

AffectorFunction and GeneratorFunction only carried @API (a different,
unrelated annotation - permission/module-visibility, not indexing) - never
@IndexInherited. So the index files for these two base types were never
generated at all engine/build/classes/META-INF/subtypes/ had no entry for
either name. TypeHandler, by contrast, does have @IndexInherited, which is
why RuntimeDelegatingTypeHandler's own delegate resolution works fine while
its runtime-subtype resolution for particle functions didn't.

Verified by inspecting the generated index after rebuilding: both
AccelerationAffectorFunction and TextureOffsetGeneratorFunction (the two
classes failing to resolve in the original log) are now listed under their
respective base type's index file.

The ExternalApiWhitelist additions from the previous commit are left in place
- once the index gap is fixed, the subsequent class-loading step for a
resolved subtype name may still need to pass through the module-scoped,
whitelist-gated classloader, so they may still be load-bearing even though
their effect couldn't be observed until this fix (the class was never
proposed as a load candidate in the first place).

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
@soloturn
soloturn force-pushed the fix/logging-init-phase-undefined-folder branch from ca939c1 to 12d23f5 Compare July 28, 2026 17:57
soloturn and others added 2 commits July 28, 2026 20:18
…o restore

SkeletalMeshComponent.boneEntities is a persisted map of per-bone sub-entity
references. newSkeleton() only (re)created bone entities as a group, gated
on the whole map being null - if it was already populated (loaded from a
save) but even one referenced bone entity failed to restore (a dangling id,
matching the "Entity NNNNN doesn't exist" PojoEntityManager errors seen
throughout a JoshariasSurvival load), boneEntity.getComponent(LocationComponent.class)
returned null and the NPE on the next line crashed PrepareWorld outright,
aborting the entire world load over one skeleton's stale bone state.

Now validates each bone entity individually (exists() and has a
LocationComponent) and recreates just that one if not, instead of trusting
the whole cached map or nothing. Root cause of why those bone entities went
missing in the first place (this specific save's entity restoration, chunk
load ordering, or something else) is not addressed here - this only stops a
single skeleton's corrupted state from taking down the whole load.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
…ust its subprojects

Root-caused the intermittent "Failed to register block family" NPEs (and
before that, the SkeletonRenderer/entity-restore failures): different game
sessions were non-deterministically loading two different copies of the same
module - a locally-built source checkout under modules/<X>, and a stale
pre-built jar shadowing it in cachedModules/<X>.jar - because the dependency
substitution loop in this file only configured the rule on :modules's
*subprojects'* own configurations, never on :modules itself, the aggregator
project whose own "classpath" configuration is what
:modules:fetchModuleDependencies actually resolves to populate
cachedModules/. Every module with a local checkout was still resolved
externally for that one configuration and synced into cachedModules/ right
next to the live build.

PathManager's runtime module scan includes both cachedModules/ and modules/;
gestalt's ModulePathScanner has no idea one copy is stale, so it just keeps
whichever it discovers first (File.listFiles() gives no ordering guarantee
across launches) and silently discards the other as a "duplicate module".
When the stale jar won, its (older, out of sync with the live source)
Component classes didn't match what current prefabs from other locally-built
modules expected, producing scattered ComponentMetadata-not-found NPEs -
different modules affected depending on which specific block families a
given session's world happened to touch.

Fixed by applying the substitution to :modules itself in addition to its
subprojects. Verified: :modules:fetchModuleDependencies now resolves
NO-SOURCE (zero external module artifacts needed - confirmed every module
this workspace uses has a local checkout), and cachedModules/ is empty after
a clean re-fetch.

Also hardens BlockPrefabManager.updateBlock() to skip (log + continue)
rather than NPE on a component with no registered metadata, kept as a
permanent defensive improvement rather than reverted now that the root
cause is fixed - a component going unregistered for any other reason
in the future shouldn't be able to take down block registration for an
entire family again.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
PermissionSet.isPermitted matches the exact class or its own package with no
hierarchy walk, so @API on the abstract base does not cover concrete subtypes —
the whitelist entries are required, not precautionary. Module-Security.md gains
that rule plus the @API (permission) vs @IndexInherited (discovery) distinction,
since needing both is what made this bug hard to place.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@agent-refr

Copy link
Copy Markdown
Collaborator

Reviewed and tested this locally against an Omega workspace on JDK 17. Pushed one commit (050e2a0) with the reasoning behind the whitelist entries plus a Module-Security.md section.

The ExternalApiWhitelist additions are load-bearing — they can lose the "may still be needed" hedge. PermissionSet.isPermitted is apiClasses.contains(type) || apiPackages.contains(packageOf(type)): an exact match on the class or its own package, with no walk up the hierarchy. So the @API on the abstract AffectorFunction/GeneratorFunction permits only those two classes. AccelerationAffectorFunction carries no @API and its package has no package-info.java, so the package entries are the only thing making it loadable once the index gap is fixed. Both halves are needed: @IndexInherited to resolve the name, the whitelist to load it.

Added that rule to docs/Module-Security.md, which documented the whitelist and the classloader wiring but never the matching semantics — along with the @API (permission) vs @IndexInherited (discovery) distinction, since the two are easy to conflate and each failing alone gives a different confusing symptom.

Tested:

  • :modules:ModuleTestingEnvironment:test — 15 test classes pass, including DelayManagerTest, which corroborates the BlockFamilyLibrary context fix.
  • :engine:checkstyleMain clean.

Two notes:

  • The description is a commit behind again — the "Additional fixes" section lists four, but 520699b5 (local-source module substitution / cachedModules shadowing) makes five. That one's a good find and deserves the writeup.
  • Unrelated to this PR, but for the record since it came up while testing: module-side MTE tests still fail for modules with a code-bearing dependency (:modules:SimpleFarming:integrationTest, 7/7, Environment has no module for <X>). Unchanged by this branch — flagging only so it isn't mistaken for a regression from it.

Copilot AI left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

Pull request overview

This PR addresses early-startup Logback initialization ordering so log output consistently lands in the correct per-session log folder, and upgrades the logging stack (Logback/SLF4J). It also includes several robustness fixes discovered during testing (serialization/deserialization, block family resolution, particle subtype indexing, module sandboxing, Gradle module substitution, and world-load hardening).

Changes:

  • Reset and reconfigure the SLF4J-bound Logback LoggerContext after logFileFolder is set to avoid logFileFolder_IS_UNDEFINED outputs; upgrade Logback to 1.6.0 and SLF4J to 2.0.18 (and remove now-unused Janino deps).
  • Fix multiple persistence/runtime issues: reflective deserialization of final fields, particle function subtype discovery via @IndexInherited, and sandbox whitelist coverage for particle packages.
  • Reduce nondeterministic module duplication by applying Gradle dependency substitution rules to :modules itself; harden block prefab and skeleton world-load paths against inconsistent/missing persisted entities/components.

Reviewed changes

Copilot reviewed 14 out of 15 changed files in this pull request and generated 3 comments.

Show a summary per file
File Description
subsystems/TypeHandlerLibrary/src/main/java/org/terasology/persistence/typeHandling/coreTypes/factories/ObjectFieldMapTypeHandlerFactory.java Makes fields reflectively accessible to support deserializing final fields.
settings.gradle.kts Bumps Logback and SLF4J versions in the version catalog.
facades/PC/build.gradle.kts Removes Janino runtime dependency previously used for Logback evaluator filters.
engine/src/main/java/org/terasology/engine/world/block/loader/BlockFamilyDefinitionFormat.java Allows block family parsing to use an engine-specific BlockFamilyLibrary supplier instead of global CoreRegistry.
engine/src/main/java/org/terasology/engine/world/block/internal/BlockPrefabManager.java Avoids NPE during block prefab processing when component metadata is missing; logs and skips.
engine/src/main/java/org/terasology/engine/rendering/logic/SkeletonRenderer.java Recreates invalid/missing persisted bone entities instead of crashing world load.
engine/src/main/java/org/terasology/engine/particles/functions/generators/GeneratorFunction.java Adds @IndexInherited to generate subtype indexes for persistence.
engine/src/main/java/org/terasology/engine/particles/functions/affectors/AffectorFunction.java Adds @IndexInherited to generate subtype indexes for persistence.
engine/src/main/java/org/terasology/engine/core/TerasologyEngine.java Wires block family parsing to the engine’s current context to avoid host/client cross-talk.
engine/src/main/java/org/terasology/engine/core/module/ExternalApiWhitelist.java Whitelists particle function packages for module sandboxed class loading during deserialization.
engine/src/main/java/org/terasology/engine/core/LoggingContext.java Resets/reconfigures the already-bound Logback context after logFileFolder is known.
docs/Module-Security.md Documents sandbox permission semantics and clarifies @API vs subtype indexing (@IndexInherited).
build.gradle.kts Extends module dependency substitution to :modules itself to avoid duplicate module artifacts.
build-logic/src/main/kotlin/terasology-module.gradle.kts Updates ModuleTestingEnvironment logging dependency to Logback 1.6.0 and removes Janino.
build-logic/src/main/kotlin/terasology-metrics.gradle.kts Updates test runtime logging dependencies to Logback 1.6.0 / SLF4J 2.0.18 and removes Janino.

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

Comment on lines +99 to +105
ILoggerFactory loggerFactory = LoggerFactory.getILoggerFactory();
if (loggerFactory instanceof LoggerContext) {
LoggerContext context = (LoggerContext) loggerFactory;
context.reset();
try {
new ContextInitializer(context).autoConfig();
} catch (JoranException e) {
Comment on lines 336 to 342
@Override
public Class<? extends BlockFamily> deserialize(JsonElement json, Type typeOfT, JsonDeserializationContext context)
throws JsonParseException {

BlockFamilyLibrary library = CoreRegistry.get(BlockFamilyLibrary.class);
BlockFamilyLibrary library = blockFamilyLibrarySupplier.get();
return library.getBlockFamily(json.getAsString());
}
Comment on lines +98 to +106
// ObjectFieldMapTypeHandler.deserialize() writes non-private fields directly via
// field.set(...) - writing a `final` field via reflection always requires
// setAccessible(true) first, regardless of the field's own visibility (this is a
// plain Java reflection rule, unrelated to any JDK version's deprecation warnings
// about *already-accessible* final-field mutation). Without this, any `public final`
// field - e.g. LocationComponent.position - throws IllegalAccessException the moment
// it needs to be deserialized to a non-default value.
field.setAccessible(true);

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

Tested this branch locally on JDK 17 with an Omega workspace; not planning to act on this one, reasoning below in case it is worth a second look.

Suggestion (a) — restrict to non-private fields actually accessed via Field#get/set — describes the set already being handled here. And the bug this commit fixes is precisely that writing a final field reflectively needs setAccessible(true) regardless of its visibility, so narrowing by visibility would reintroduce it.

Suggestion (b) — skip the field when access cannot be enabled — would turn a loud failure into silent data loss, which is the exact symptom being fixed: LocationComponent.position quietly failing to restore looked like movement was broken rather than an entity-restore failure.

On the InaccessibleObjectException risk: that applies to types in modules that do not open their packages. What is deserialized here is Terasology's own Components from the unnamed module, and getResolvedFields already runs inside AccessController.doPrivileged. If a genuinely closed JDK type ever reaches this path, failing loudly at handler construction seems preferable to dropping fields at deserialization time.

@coderabbitai coderabbitai Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

Actionable comments posted: 2

🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

Inline comments:
In `@docs/Module-Security.md`:
- Line 49: Update the “What counts as permitted” heading under “Security
Mechanisms” from an H3 to an H2, preserving the following H3 headings as
correctly nested subsections.

In
`@engine/src/main/java/org/terasology/engine/rendering/logic/SkeletonRenderer.java`:
- Around line 101-106: Update the invalid-entity recovery branch in
SkeletonRenderer to destroy an existing boneEntity that is missing
LocationComponent before creating and storing its replacement. Use the engine’s
entity-destruction API, while preserving the current behavior for null or
non-existent entities and the subsequent skeleton.boneEntities update.
🪄 Autofix (Beta)

Fix all unresolved CodeRabbit comments on this PR:

  • Push a commit to this branch (recommended)
  • Create a new PR with the fixes

ℹ️ Review info
⚙️ Run configuration

Configuration used: Organization UI

Review profile: CHILL

Plan: Pro Plus

Run ID: c8aa4c35-eb30-4416-b453-04f88e3426a2

📥 Commits

Reviewing files that changed from the base of the PR and between b40c285 and 050e2a0.

📒 Files selected for processing (15)
  • build-logic/src/main/kotlin/terasology-metrics.gradle.kts
  • build-logic/src/main/kotlin/terasology-module.gradle.kts
  • build.gradle.kts
  • docs/Module-Security.md
  • engine/src/main/java/org/terasology/engine/core/LoggingContext.java
  • engine/src/main/java/org/terasology/engine/core/TerasologyEngine.java
  • engine/src/main/java/org/terasology/engine/core/module/ExternalApiWhitelist.java
  • engine/src/main/java/org/terasology/engine/particles/functions/affectors/AffectorFunction.java
  • engine/src/main/java/org/terasology/engine/particles/functions/generators/GeneratorFunction.java
  • engine/src/main/java/org/terasology/engine/rendering/logic/SkeletonRenderer.java
  • engine/src/main/java/org/terasology/engine/world/block/internal/BlockPrefabManager.java
  • engine/src/main/java/org/terasology/engine/world/block/loader/BlockFamilyDefinitionFormat.java
  • facades/PC/build.gradle.kts
  • settings.gradle.kts
  • subsystems/TypeHandlerLibrary/src/main/java/org/terasology/persistence/typeHandling/coreTypes/factories/ObjectFieldMapTypeHandlerFactory.java
💤 Files with no reviewable changes (1)
  • facades/PC/build.gradle.kts
🚧 Files skipped from review as they are similar to previous changes (6)
  • settings.gradle.kts
  • engine/src/main/java/org/terasology/engine/core/LoggingContext.java
  • build-logic/src/main/kotlin/terasology-module.gradle.kts
  • engine/src/main/java/org/terasology/engine/core/TerasologyEngine.java
  • engine/src/main/java/org/terasology/engine/world/block/loader/BlockFamilyDefinitionFormat.java
  • build-logic/src/main/kotlin/terasology-metrics.gradle.kts

Comment thread docs/Module-Security.md Outdated
Comment on lines +101 to 106
if (boneEntity == null || !boneEntity.exists() || !boneEntity.hasComponent(LocationComponent.class)) {
if (boneEntity != null && boneEntity.exists()) {
logger.warn("Bone entity for \"{}\" exists but has no LocationComponent, recreating", bone.getName());
}
boneEntity = entityManager.create(new LocationComponent());
skeleton.boneEntities.put(bone.getName(), boneEntity);

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

🩺 Stability & Availability | 🟠 Major | ⚡ Quick win

Destroy replaced invalid bone entities.

When an existing entity lacks LocationComponent, this branch replaces the map entry without destroying the old entity. That leaves an orphaned entity in the world; repeated recovery can accumulate stale bone entities. Clean up the existing invalid entity through the engine’s entity-destruction API before creating its replacement.

🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

In
`@engine/src/main/java/org/terasology/engine/rendering/logic/SkeletonRenderer.java`
around lines 101 - 106, Update the invalid-entity recovery branch in
SkeletonRenderer to destroy an existing boneEntity that is missing
LocationComponent before creating and storing its replacement. Use the engine’s
entity-destruction API, while preserving the current behavior for null or
non-existent entities and the subsequent skeleton.boneEntities update.

The CoreRegistry-backed fallback supplier can be empty mid state-transition —
the javadoc says so — and the NPE surfaced as an opaque Gson failure. Also fixes
the heading levels flagged by markdownlint in the previous commit.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

@Cervator Cervator left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

Loads of tweaks and testing on this all day. Got one maybe follow-up from a review comment and one minor thing actively testing, but with it being 2 am I'm going to merge this now - then sometime tomorrow the module PR that goes with it, after the engine build is done :-)

I had my agent post some of the additional details in a separate comment.

@Cervator
Cervator merged commit 78f0198 into develop Jul 29, 2026
3 of 4 checks passed
@Cervator
Cervator deleted the fix/logging-init-phase-undefined-folder branch July 29, 2026 06:12
BenjaminAmos pushed a commit that referenced this pull request Jul 29, 2026
…gure failure

Two review points from #5343 that were raised but not picked up before merge.

SkeletonRenderer replaced an invalid bone entity without destroying the old
one, leaking an entity per affected bone on every load of such a save.

LoggingContext calls reset() before autoConfig(), so a JoranException left the
context with no appenders and logging dead for the rest of the run.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Type: Bug Issues reporting and PRs fixing problems

Projects

Status: ✅ Done
Status: No status

Development

Successfully merging this pull request may close these issues.

Early startup logs land in a stray logFileFolder_IS_UNDEFINED directory instead of the session log folder

4 participants