qa: parametrize logger usages (#5173)

PMD Rule Docs: https://docs.pmd-code.org/pmd-doc-6.55.0/pmd_rules_java_bestpractices.html#guardlogstatement * upgrade slf4j-2.0, permit passing suppliers to loggers (lazy evaluation) (#5174) * parametrize logs * remove superfluous toString() calls * reuse existing local variables in log * introduce new local variable to use in logic and logs Co-authored-by: soloturn <[email protected]> Co-authored-by: Tobias Nett <[email protected]>
MovingBlocks · Nov 19, 2023 · c56c4dd · c56c4dd
1 parent 317154b
commit c56c4dd
Show file tree

Hide file tree

Showing 46 changed files with 106 additions and 108 deletions.
diff --git a/build-logic/src/main/kotlin/terasology-metrics.gradle.kts b/build-logic/src/main/kotlin/terasology-metrics.gradle.kts
@@ -25,13 +25,13 @@ dependencies {
     pmd("net.sourceforge.pmd:pmd-core:7.0.0-rc4")
     pmd("net.sourceforge.pmd:pmd-java:7.0.0-rc4")
 
-    testRuntimeOnly("ch.qos.logback:logback-classic:1.2.11") {
+    testRuntimeOnly("ch.qos.logback:logback-classic:1.2.12") {
         because("runtime: to configure logging during tests with logback.xml")
     }
     testRuntimeOnly("org.codehaus.janino:janino:3.1.7") {
         because("allows use of EvaluatorFilter in logback.xml")
     }
-    testRuntimeOnly("org.slf4j:jul-to-slf4j:1.7.36") {
+    testRuntimeOnly("org.slf4j:jul-to-slf4j:2.0.9") {
         because("redirects java.util.logging (from e.g. junit) through slf4j")
     }
 

diff --git a/build-logic/src/main/kotlin/terasology-module.gradle.kts b/build-logic/src/main/kotlin/terasology-module.gradle.kts
@@ -75,7 +75,7 @@ if (project.name == "ModuleTestingEnvironment") {
     dependencies {
         // MTE is a special snowflake, it gets these things as non-test dependencies
         implementation(group = "org.terasology.engine", name = "engine-tests", version = moduleMetadata.engineVersion())
-        implementation("ch.qos.logback:logback-classic:1.2.3")
+        implementation("ch.qos.logback:logback-classic:1.2.12")
         runtimeOnly("org.codehaus.janino:janino:3.1.3") {
             because("logback filters")
         }

diff --git a/engine-tests/build.gradle b/engine-tests/build.gradle
@@ -62,11 +62,11 @@ dependencies {
 
     implementation("org.terasology.joml-ext:joml-test:0.1.0")
 
-    implementation('org.slf4j:slf4j-api:1.7.36') {
+    implementation('org.slf4j:slf4j-api:2.0.9') {
         because('a backend-independent Logger')
     }
 
-    testImplementation("ch.qos.logback:logback-classic:1.2.11") {
+    testImplementation("ch.qos.logback:logback-classic:1.4.11") {
         because("implementation: a test directly uses logback.classic classes")
     }
 

diff --git a/engine-tests/src/main/java/org/terasology/engine/integrationenvironment/Engines.java b/engine-tests/src/main/java/org/terasology/engine/integrationenvironment/Engines.java
@@ -259,7 +259,7 @@ TerasologyEngine createHost(NetworkMode hostNetworkMode) throws IOException {
         doneLoading = false;
         host.subscribeToStateChange(() -> {
             GameState newState = host.getState();
-            logger.debug("New engine state is {}", host.getState());
+            logger.debug("New engine state is {}", newState);
             if (newState instanceof StateIngame) {
                 hostContext = newState.getContext();
                 if (hostContext == null) {

diff --git a/...in/java/org/terasology/engine/integrationenvironment/IntegrationEnvironmentSubsystem.java b/...in/java/org/terasology/engine/integrationenvironment/IntegrationEnvironmentSubsystem.java
@@ -78,7 +78,7 @@ static void registerCurrentDirectoryIfModule(ModuleManager moduleManager) {
                 logger.info("Install path does not appear to be a module: {}", installPath);
             }
         } catch (IOException e) {
-            logger.warn("Could not read install path as module at " + installPath);
+            logger.warn("Could not read install path as module at {}", installPath);
         }
     }
 }
diff --git a/engine/build.gradle b/engine/build.gradle
@@ -115,10 +115,10 @@ dependencies {
     implementation group: 'de.matthiasmann.twl', name: 'PNGDecoder', version: '1111'
 
     // Logging
-    implementation('org.slf4j:slf4j-api:1.7.36') {
+    implementation('org.slf4j:slf4j-api:2.0.9') {
         because('a backend-independent Logger')
     }
-    implementation("ch.qos.logback:logback-classic:1.2.11") {
+    implementation("ch.qos.logback:logback-classic:1.2.12") {
         because("telemetry implementation uses logback to send to logstash " +
                 "and we bundle org.terasology.logback for the regex filter")
     }
@@ -133,7 +133,7 @@ dependencies {
     implementation(group: 'com.snowplowanalytics', name: 'snowplow-java-tracker', version: '0.12.1') {
         exclude group: 'org.slf4j', module: 'slf4j-simple'
     }
-    implementation group: 'net.logstash.logback', name: 'logstash-logback-encoder', version: '7.2'
+    implementation group: 'net.logstash.logback', name: 'logstash-logback-encoder', version: '7.4'
 
     // Our developed libs
     api group: 'org.terasology.gestalt', name: 'gestalt-asset-core', version: '7.2.0-SNAPSHOT'

diff --git a/engine/src/main/java/org/terasology/engine/config/RenderingDebugConfig.java b/engine/src/main/java/org/terasology/engine/config/RenderingDebugConfig.java
@@ -108,6 +108,6 @@ public void setRenderSkeletons(boolean renderSkeletons) {
 
     @Override
     public void propertyChange(PropertyChangeEvent evt) {
-        logger.info("Set {} property to {}. ", evt.getPropertyName().toUpperCase(), evt.getNewValue()); // for debugging purposes
+        logger.debug("Set {} property to {}.", evt.getPropertyName().toUpperCase(), evt.getNewValue());
     }
 }
diff --git a/engine/src/main/java/org/terasology/engine/core/TerasologyEngine.java b/engine/src/main/java/org/terasology/engine/core/TerasologyEngine.java
@@ -266,7 +266,7 @@ private void verifyInitialisation() {
      * Logs software, environment and hardware information.
      */
     private void logEnvironmentInfo() {
-        logger.info(TerasologyVersion.getInstance().toString());
+        logger.info("{}", TerasologyVersion.getInstance());
         logger.info("Home path: {}", PathManager.getInstance().getHomePath());
         logger.info("Install path: {}", PathManager.getInstance().getInstallPath());
         logger.info("Java: {} in {}", System.getProperty("java.version"), System.getProperty("java.home"));

diff --git a/engine/src/main/java/org/terasology/engine/core/modes/StateLoading.java b/engine/src/main/java/org/terasology/engine/core/modes/StateLoading.java
@@ -234,7 +234,7 @@ private void popStep() {
         current = null;
         if (!loadProcesses.isEmpty()) {
             current = loadProcesses.remove();
-            logger.debug(current.getMessage());
+            logger.debug("{}", current.getMessage());
             current.begin();
         }
     }

diff --git a/engine/src/main/java/org/terasology/engine/core/module/ModuleListDownloader.java b/engine/src/main/java/org/terasology/engine/core/module/ModuleListDownloader.java
@@ -65,7 +65,7 @@ public ModuleRegistry call() throws IOException {
             }
 
             int count = modules.size();
-            logger.info(String.format("Retrieved %d %s", count, (count == 1) ? "entry" : "entries"));
+            logger.info("Retrieved {} {}", count, (count == 1) ? "entry" : "entries");
         }
         return modules;
     }

diff --git a/engine/src/main/java/org/terasology/engine/entitySystem/event/internal/EventSystemImpl.java b/engine/src/main/java/org/terasology/engine/entitySystem/event/internal/EventSystemImpl.java
@@ -95,11 +95,11 @@ public void registerEvent(ResourceUrn uri, Class<? extends Event> eventType) {
     public void registerEventHandler(ComponentSystem handler) {
         Class handlerClass = handler.getClass();
         if (!Modifier.isPublic(handlerClass.getModifiers())) {
-            logger.error("Cannot register handler {}, must be public", handler.getClass().getName());
+            logger.error("Cannot register handler {}, must be public", handlerClass.getName());
             return;
         }
 
-        logger.debug("Registering event handler " + handlerClass.getName());
+        logger.debug("Registering event handler {}", handlerClass.getName());
         for (Method method : handlerClass.getMethods()) {
             ReceiveEvent receiveEventAnnotation = method.getAnnotation(ReceiveEvent.class);
             if (receiveEventAnnotation != null) {
@@ -127,7 +127,7 @@ public void registerEventHandler(ComponentSystem handler) {
                 method.setAccessible(true);
                 Class<?>[] types = method.getParameterTypes();
 
-                logger.debug("Found method: " + method.toString());
+                logger.debug("Found method: {}", method);
                 if (!Event.class.isAssignableFrom(types[0]) || !EntityRef.class.isAssignableFrom(types[1])) {
                     logger.error("Invalid event handler method: {}", method.getName());
                     return;

diff --git a/engine/src/main/java/org/terasology/engine/i18n/TranslationSystemImpl.java b/engine/src/main/java/org/terasology/engine/i18n/TranslationSystemImpl.java
@@ -58,7 +58,7 @@ public void refresh() {
                     TranslationProject proj = projects.computeIfAbsent(projectUrn, e -> new StandardTranslationProject());
                     proj.add(trans);
                     trans.subscribe(this::onAssetChanged);
-                    logger.info("Discovered " + trans);
+                    logger.info("Discovered {}", trans);
                 } else {
                     logger.warn("Ignoring invalid project projectUrn: {}", projectUrn);
                 }

diff --git a/engine/src/main/java/org/terasology/engine/logic/behavior/core/ActionNode.java b/engine/src/main/java/org/terasology/engine/logic/behavior/core/ActionNode.java
@@ -56,7 +56,7 @@ public void construct(Actor actor) {
             try {
                 action.construct(actor);
             } catch (Exception e) {
-                logger.debug("Exception while running construct() of action {} from entity {}: {}", action, actor.getEntity(), e.getMessage());
+                logger.debug("Exception while running construct() of action {} from entity {}: ", action, actor.getEntity(), e);
             }
         }
     }

diff --git a/engine/src/main/java/org/terasology/engine/logic/characters/CharacterSystem.java b/engine/src/main/java/org/terasology/engine/logic/characters/CharacterSystem.java
@@ -154,8 +154,8 @@ public String getDamageTypeName(Prefab damageType) {
         if (damageType.hasComponent(DisplayNameComponent.class)) {
             return damageType.getComponent(DisplayNameComponent.class).name;
         } else {
-            logger.info(String.format("%s is missing a readable DisplayName", damageType.getName()));
             String damageTypeName = damageType.getName();
+            logger.info("{} is missing a readable DisplayName", damageTypeName);
             //damageType.getName() returns a ResourceUrn String such as "engine:directDamage"
             //The following calls change the damage type to be more readable
             //For instance, "engine:directDamage" becomes "Direct Damage"
@@ -315,35 +315,35 @@ private boolean isPredictionOfEventCorrect(EntityRef character, ActivationReques
 
         Vector3f originPos = location.getWorldPosition(new Vector3f());
         if (!(event.getOrigin().equals(originPos, 0.0001f))) {
-            String msg = "Player {} seems to have cheated: It stated that it performed an action from {} but the predicted position is {}";
-            logger.info(msg, getPlayerNameFromCharacter(character), event.getOrigin(), originPos);
+            logger.info("Player {} seems to have cheated: It stated that it performed an action from {} but the predicted position is {}",
+                    getPlayerNameFromCharacter(character), event.getOrigin(), originPos);
             return false;
         }
 
         if (event.isOwnedEntityUsage()) {
             if (!event.getUsedOwnedEntity().exists()) {
-                String msg = "Denied activation attempt by {} since the used entity does not exist on the authority";
-                logger.info(msg, getPlayerNameFromCharacter(character));
+                logger.info("Denied activation attempt by {} since the used entity does not exist on the authority",
+                        getPlayerNameFromCharacter(character));
                 return false;
             }
             if (!networkSystem.getOwnerEntity(event.getUsedOwnedEntity()).equals(networkSystem.getOwnerEntity(character))) {
-                String msg = "Denied activation attempt by {} since it does not own the entity at the authority";
-                logger.info(msg, getPlayerNameFromCharacter(character));
+                logger.info("Denied activation attempt by {} since it does not own the entity at the authority",
+                        getPlayerNameFromCharacter(character));
                 return false;
             }
         } else {
             // check for cheats so that data can later be trusted:
             if (event.getUsedOwnedEntity().exists()) {
-                String msg = "Denied activation attempt by {} since it is not properly marked as owned entity usage";
-                logger.info(msg, getPlayerNameFromCharacter(character));
+                logger.info("Denied activation attempt by {} since it is not properly marked as owned entity usage",
+                        getPlayerNameFromCharacter(character));
                 return false;
             }
         }
 
         if (event.isEventWithTarget()) {
             if (!event.getTarget().exists()) {
-                String msg = "Denied activation attempt by {} since the target does not exist on the authority";
-                logger.info(msg, getPlayerNameFromCharacter(character));
+                logger.info("Denied activation attempt by {} since the target does not exist on the authority",
+                        getPlayerNameFromCharacter(character));
                 return false; // can happen if target existed on client
             }
 
@@ -360,8 +360,8 @@ private boolean isPredictionOfEventCorrect(EntityRef character, ActivationReques
             HitResult result = physics.rayTrace(originPos, direction, interactionRange, Sets.newHashSet(character),
                     DEFAULTPHYSICSFILTER);
             if (!result.isHit()) {
-                String msg = "Denied activation attempt by {} since at the authority there was nothing to activate at that place";
-                logger.info(msg, getPlayerNameFromCharacter(character));
+                logger.info("Denied activation attempt by {} since at the authority there was nothing to activate at that place",
+                        getPlayerNameFromCharacter(character));
                 return false;
             }
             EntityRef hitEntity = result.getEntity();
@@ -371,31 +371,31 @@ private boolean isPredictionOfEventCorrect(EntityRef character, ActivationReques
                  * server entity dump. When certain fields don't get replicated, then wrong entity might get hin in the
                  * hit test.
                  */
-                String msg = "Denied activation attempt by {} since at the authority another entity would have been activated";
-                logger.info(msg, getPlayerNameFromCharacter(character));
+                logger.info("Denied activation attempt by {} since at the authority another entity would have been activated",
+                        getPlayerNameFromCharacter(character));
                 return false;
             }
 
             if (!(event.getHitPosition().equals(result.getHitPoint(), 0.0001f))) {
-                String msg = "Denied activation attempt by {} since at the authority the object got hit at a differnt position";
-                logger.info(msg, getPlayerNameFromCharacter(character));
+                logger.info("Denied activation attempt by {} since at the authority the object got hit at a differnt position",
+                        getPlayerNameFromCharacter(character));
                 return false;
             }
         } else {
             // In order to trust the data later we need to verify it even if it should be correct if no one cheats:
             if (event.getTarget().exists()) {
-                String msg = "Denied activation attempt by {} since the event was not properly labeled as having a target";
-                logger.info(msg, getPlayerNameFromCharacter(character));
+                logger.info("Denied activation attempt by {} since the event was not properly labeled as having a target",
+                        getPlayerNameFromCharacter(character));
                 return false;
             }
             if (event.getHitPosition() != null) {
-                String msg = "Denied activation attempt by {} since the event was not properly labeled as having a hit position";
-                logger.info(msg, getPlayerNameFromCharacter(character));
+                logger.info("Denied activation attempt by {} since the event was not properly labeled as having a hit position",
+                        getPlayerNameFromCharacter(character));
                 return false;
             }
             if (event.getHitNormal() != null) {
-                String msg = "Denied activation attempt by {} since the event was not properly labeled as having a hit delta";
-                logger.info(msg, getPlayerNameFromCharacter(character));
+                logger.info("Denied activation attempt by {} since the event was not properly labeled as having a hit delta",
+                        getPlayerNameFromCharacter(character));
                 return false;
             }
         }

diff --git a/engine/src/main/java/org/terasology/engine/logic/config/ModuleConfigSystem.java b/engine/src/main/java/org/terasology/engine/logic/config/ModuleConfigSystem.java
@@ -32,8 +32,8 @@ public void preBegin() {
             String moduleName = moduleConfig.moduleName;
             Map<String, String> properties;
             if (propertiesPerModule.containsKey(moduleName)) {
-                logger.error("Encountered more than one Module Config for module - " + moduleName +
-                        ", this is not recommended, as the property values visible are not going to be well defined.");
+                logger.error("Encountered more than one Module Config for module - {}, this is not recommended, " +
+                        "as the property values visible are not going to be well defined.", moduleName);
                 properties = propertiesPerModule.get(moduleName);
             } else {
                 properties = new HashMap<>();

diff --git a/engine/src/main/java/org/terasology/engine/logic/inventory/ItemPickupAuthoritySystem.java b/engine/src/main/java/org/terasology/engine/logic/inventory/ItemPickupAuthoritySystem.java
@@ -82,7 +82,7 @@ public void updateExtentsOnBlockItemBoxShape(OnAddedComponent event, EntityRef i
         BlockFamily blockFamily = blockItemComponent.blockFamily;
 
         if (blockFamily == null) {
-            LOGGER.warn("Prefab " + itemEntity.getParentPrefab().getName() + " does not have a block family");
+            LOGGER.warn("Prefab {} does not have a block family", itemEntity.getParentPrefab().getName());
             return;
         }
 

diff --git a/engine/src/main/java/org/terasology/engine/network/internal/ClientConnectionHandler.java b/engine/src/main/java/org/terasology/engine/network/internal/ClientConnectionHandler.java
@@ -160,8 +160,8 @@ private void receiveModuleStart(ChannelHandlerContext channelHandlerContext,
                 joinStatus.setCurrentActivity(
                         "Downloading " + moduleDataHeader.getId() + ":" + moduleDataHeader.getVersion() + " ("
                                 + sizeString + "," + missingModules.size() + " modules remain)");
-                logger.info("Downloading " + moduleDataHeader.getId() + ":" + moduleDataHeader.getVersion() + " ("
-                        + sizeString + "," + missingModules.size() + " modules remain)");
+                logger.info("Downloading {}: {} ({}, {} modules remain)", moduleDataHeader.getId(), moduleDataHeader.getVersion(),
+                        sizeString, missingModules.size());
                 receivingModule = moduleDataHeader;
                 lengthReceived = 0;
                 try {
@@ -176,8 +176,7 @@ private void receiveModuleStart(ChannelHandlerContext channelHandlerContext,
                 }
             }
         } else {
-            logger.error("Received unwanted module {}:{} from server", moduleDataHeader.getId(),
-                    moduleDataHeader.getVersion());
+            logger.error("Received unwanted module {}:{} from server", moduleDataHeader.getId(), moduleDataHeader.getVersion());
             joinStatus.setErrorMessage("Module download error");
             channelHandlerContext.channel().close();
         }

diff --git a/engine/src/main/java/org/terasology/engine/network/internal/NetworkSystemImpl.java b/engine/src/main/java/org/terasology/engine/network/internal/NetworkSystemImpl.java
@@ -827,7 +827,7 @@ private void processRemovedClient(Client client) {
         }
         clientList.remove(client);
         clientPlayerLookup.remove(client.getEntity());
-        logger.info("Client disconnected: " + client.getName());
+        logger.info("Client disconnected: {}", client.getName());
         storageManager.deactivatePlayer(client);
         client.getEntity().send(new DisconnectedEvent());
         client.disconnect();
@@ -973,8 +973,7 @@ private <T> Map<Class<? extends T>, Integer> generateIds(ClassLibrary<T> classLi
             int fieldId = 0;
             for (FieldMetadata<?, ?> field : metadata.getFields()) {
                 if (fieldId >= 256) {
-                    logger.error("Class {} has too many fields (>255), serialization will be incomplete",
-                            metadata.getId());
+                    logger.error("Class {} has too many fields (>255), serialization will be incomplete", metadata.getId());
                     break;
                 }
                 field.setId((byte) fieldId);

diff --git a/engine/src/main/java/org/terasology/engine/network/internal/ServerInfoRequestHandler.java b/engine/src/main/java/org/terasology/engine/network/internal/ServerInfoRequestHandler.java
@@ -20,7 +20,7 @@ public class ServerInfoRequestHandler extends ChannelInboundHandlerAdapter {
 
     @Override
     public void exceptionCaught(ChannelHandlerContext ctx, Throwable cause) throws Exception {
-        logger.warn("Could not query server info: {}", cause.toString());
+        logger.warn("Could not query server info: ", cause);
     }
 
     @Override

diff --git a/engine/src/main/java/org/terasology/engine/persistence/internal/GlobalStoreLoader.java b/engine/src/main/java/org/terasology/engine/persistence/internal/GlobalStoreLoader.java
@@ -64,15 +64,16 @@ private void loadMissingPrefabs(EntityData.GlobalStore globalStore) {
         Map<String, EntityData.Prefab> pendingPrefabs = Maps.newHashMap();
         for (EntityData.Prefab prefabData : globalStore.getPrefabList()) {
             if (!prefabManager.exists(prefabData.getName())) {
+                String prefabDataName = prefabData.getName();
                 if (!prefabData.hasParentName()) {
-                    Module module = environment.get(new SimpleUri(prefabData.getName()).getModuleName());
+                    Module module = environment.get(new SimpleUri(prefabDataName).getModuleName());
                     try (ModuleContext.ContextSpan ignored = ModuleContext.setContext(module)) {
                         createPrefab(prefabData);
                     } catch (Exception e) {
-                        logger.error("Failed to load prefab {}", prefabData.getName(), e);
+                        logger.error("Failed to load prefab {}", prefabDataName, e);
                     }
                 } else {
-                    pendingPrefabs.put(prefabData.getName(), prefabData);
+                    pendingPrefabs.put(prefabDataName, prefabData);
                 }
             }
         }