Question: Why do we need this bunch of information?

[Vamillion]

Hi everyone,

I'm a bit confused. Why do I need, as a developer not maintaining this library, so much information for every single rule execution? Using logging level debug is a well known default I know. But this information is realy not necessary for me at all. I'm spending more than 25 % in logging information.

DEBUG DefaultRulesEngine:386 - Engine parameters { skipOnFirstAppliedRule = false, skipOnFirstNonTriggeredRule = false, skipOnFirstFailedRule = false, priorityThreshold = 2147483647 }
dev-server       | |#]
dev-server       |
dev-server       | [#|2021-02-09T14:09:11.333+0000|INFO|Payara 4.1||_ThreadID=165;_ThreadName=concurrent/__defaultManagedScheduledExecutorService-managedThreadFactory-Thread-4;_TimeMillis=1612879751333;_LevelValue=800;|
dev-server       |   02092021 14:09 DEBUG DefaultRulesEngine:382 - Registered rules:
dev-server       | |#]
dev-server       |
dev-server       | [#|2021-02-09T14:09:11.333+0000|INFO|Payara 4.1||_ThreadID=165;_ThreadName=concurrent/__defaultManagedScheduledExecutorService-managedThreadFactory-Thread-4;_TimeMillis=1612879751333;_LevelValue=800;|
dev-server       |   02092021 14:09 DEBUG DefaultRulesEngine:403 - Rule { name = 'HistoryLinkingRule', description = 'Rule which merges the provided histories from all reports together.', priority = '2147483646'}
dev-server       | |#]
dev-server       |
dev-server       | [#|2021-02-09T14:09:11.334+0000|INFO|Payara 4.1||_ThreadID=165;_ThreadName=concurrent/__defaultManagedScheduledExecutorService-managedThreadFactory-Thread-4;_TimeMillis=1612879751334;_LevelValue=800;|
dev-server       |   02092021 14:09 DEBUG DefaultRulesEngine:382 - Known facts:
dev-server       | |#]
dev-server       |
dev-server       | [#|2021-02-09T14:09:11.334+0000|INFO|Payara 4.1||_ThreadID=165;_ThreadName=concurrent/__defaultManagedScheduledExecutorService-managedThreadFactory-Thread-4;_TimeMillis=1612879751334;_LevelValue=800;|
dev-server       |   02092021 14:09 DEBUG DefaultRulesEngine:382 - Rules evaluation started
dev-server       | |#]
dev-server       |
dev-server       | [#|2021-02-09T14:09:11.334+0000|INFO|Payara 4.1||_ThreadID=165;_ThreadName=concurrent/__defaultManagedScheduledExecutorService-managedThreadFactory-Thread-4;_TimeMillis=1612879751334;_LevelValue=800;|
dev-server       |   02092021 14:09 DEBUG DefaultRulesEngine:386 - Rule 'HistoryLinkingRule' has been evaluated to false, it has not been executed

For clarity, I like this framework very much, but what's the purpose of logging these information explictly every execution run using multiple Logging statements on different code positions?

Why not using Log-Level Trace if it need to be logged somewhere by time? Why not concatenating this information into one single Log-Entry? Why responding the evaluation result every time instead of making this optional?

[fmbenhassine]

The default log level used to be INFO and was changed to DEBUG (see #192 and #166).

Are you saying that the default should be TRACE and not DEBUG? TRACE is actually discouraged by SLF4J.

If you are not interested in this debug output, why don't you configure the log level to be INFO for the org.jeasy.rules package?

[Vamillion]

Hi thanks for the comment to my questions. Setting the log level explicitly for the package is a quite good idea. I need to say that I forgotten this feature in SLF4J.

---

But may you want to think about an code optimization, changing these four separate log entries above to a single entry. This would reduce the execution time a bit more.

May you find this change interesting. You could add this into the DefaultRulesEngine if you want.

void logAll(Rules rules, Facts facts) {
        String logMessage  = String.format("%nEngine parameters: %n%s%n", parameters);
        StringBuilder rulesMessage = new StringBuilder("Registered rules:");
        StringBuilder factsMessage = new StringBuilder("Known facts:");

        for (Rule rule : rules) {
            rulesMessage.append(String.format("%nRule { name = '%s', description = '%s', priority = '%s'}%n",
                    rule.getName(), rule.getDescription(), rule.getPriority()));
        }

        for (Fact<?> fact : facts) {
            factsMessage.append(String.format("%n%s", fact));
        }

        factsMessage.append(String.format("%nRules evaluation started"));
        LOGGER.debug("{}{}{}", logMessage, rulesMessage, factsMessage);
    }

---

Feel free to close the issue after giving a quick answer.