[jboss-jira] [JBoss JIRA] (DROOLS-1262) Logging level DEBUG should be less verbose: "Fire Loop" & "State was" should be trace

[Geoffrey De Smet (JIRA)]

Geoffrey De Smet created DROOLS-1262:
----------------------------------------

             Summary: Logging level DEBUG should be less verbose: "Fire Loop" & "State was" should be trace
                 Key: DROOLS-1262
                 URL: https://issues.jboss.org/browse/DROOLS-1262
             Project: Drools
          Issue Type: Bug
          Components: core engine
    Affects Versions: 7.0.0.Beta1, 6.5.0.CR1, 6.4.0.Final
            Reporter: Geoffrey De Smet
            Assignee: Mario Fusco
            Priority: Critical


In the latest 6.4 product patches, I am seeing customers that are up to 10 times slower due to drools in their optaplanner cases. It turns out that they have no logging configuration and many systems - such as WildFly use DEBUG logging by default (often to a file so no one notices it).

Meanwhile the log  fills up with this:
{code}
2016-08-29 15:20:57,338 [SwingWorker-pool-2-thread-1] DEBUG State was INACTIVE is now FIRING_ALL_RULES
2016-08-29 15:20:57,338 [SwingWorker-pool-2-thread-1] DEBUG Fire Loop
2016-08-29 15:20:57,338 [SwingWorker-pool-2-thread-1] DEBUG Fire Loop
2016-08-29 15:20:57,338 [SwingWorker-pool-2-thread-1] DEBUG Fire Loop
2016-08-29 15:20:57,338 [SwingWorker-pool-2-thread-1] DEBUG Fire Loop
2016-08-29 15:20:57,338 [SwingWorker-pool-2-thread-1] DEBUG Fire Loop
2016-08-29 15:20:57,338 [SwingWorker-pool-2-thread-1] DEBUG State was FIRING_ALL_RULES is now HALTING
2016-08-29 15:20:57,338 [SwingWorker-pool-2-thread-1] DEBUG State was HALTING is now INACTIVE
2016-08-29 15:20:57,338 [SwingWorker-pool-2-thread-1] TRACE         Move index (0), score (-10hard/-128070soft), accepted (false), move (CloudProcess-67 {CloudComputer-45} <-> CloudProcess-147 {CloudComputer-18}).
2016-08-29 15:20:57,338 [SwingWorker-pool-2-thread-1] DEBUG State was INACTIVE is now FIRING_ALL_RULES
2016-08-29 15:20:57,338 [SwingWorker-pool-2-thread-1] DEBUG Fire Loop
2016-08-29 15:20:57,338 [SwingWorker-pool-2-thread-1] DEBUG Fire Loop
2016-08-29 15:20:57,338 [SwingWorker-pool-2-thread-1] DEBUG Fire Loop
2016-08-29 15:20:57,338 [SwingWorker-pool-2-thread-1] DEBUG Fire Loop
2016-08-29 15:20:57,338 [SwingWorker-pool-2-thread-1] DEBUG Fire Loop
2016-08-29 15:20:57,338 [SwingWorker-pool-2-thread-1] DEBUG State was FIRING_ALL_RULES is now HALTING
2016-08-29 15:20:57,338 [SwingWorker-pool-2-thread-1] DEBUG State was HALTING is now INACTIVE
2016-08-29 15:20:57,338 [SwingWorker-pool-2-thread-1] TRACE         Move index (1), score (0hard/-128070soft), accepted (true), move (CloudProcess-104 {CloudComputer-89} <-> CloudProcess-295 {CloudComputer-26}).
2016-08-29 15:20:57,338 [SwingWorker-pool-2-thread-1] DEBUG     LS step (6730), time spent (3432), score (0hard/-128070soft),     best score (0hard/-126690soft), accepted/selected move count (1/2), picked move (CloudProcess-104 {CloudComputer-89} <-> CloudProcess-295 {CloudComputer-26}).
{code}

but without the optaplanner TRACE lines.

Solution proposal A): remove the line "Fire Loop" and put "State was" on trace logging.

Solution proposal B): collapse the 5 lines "Fire Loop" into "5 fire loops" and put "State was" on trace logging.

Solution proposal C): put the line "Fire Loop" and "State was" on trace logging.
I personally dislike this one - even trace logging should still be useful and not more verbose that it needs to be (although it should log in high detail).

This should be fixed for 7.0, 6.5.x and I 'll ask QA to consider adding it for 6.4.x.



--
This message was sent by Atlassian JIRA
(v6.4.11#64026)