Skip to content

chore: improve logging#2462

Open
zepfred wants to merge 1 commit into
TimefoldAI:mainfrom
zepfred:chore/log
Open

chore: improve logging#2462
zepfred wants to merge 1 commit into
TimefoldAI:mainfrom
zepfred:chore/log

Conversation

@zepfred

@zepfred zepfred commented Jul 3, 2026

Copy link
Copy Markdown
Contributor

The PR adds additional logging information at the DEBUG level:

11:05:45.487 DEBUG [pool-5-thread-1] Custom phase (1) started.
11:05:45.488 DEBUG [pool-5-thread-1]     Custom step (0), time spent (19), score (0hard/-38007850000medium/-29758913soft),     best score (0hard/-38007850000medium/-29758913soft).
11:05:45.491  INFO [pool-5-thread-1] Custom phase (1) ended: time spent (22), best score (0hard/-38007850000medium/-29758913soft), move evaluation speed (0/sec), step total (1).

11:05:45.497 DEBUG [pool-5-thread-1] Multi-Threaded Construction Heuristic Decider started, move threads (4)
11:05:45.497 DEBUG [pool-5-thread-1] Construction Heuristic phase (2) started.
11:05:45.512 DEBUG [pool-5-thread-1]     CH step (0), time spent (43), score (0hard/-37007850000medium/-29479796soft), selected move count (2), picked move (SolverVisit{id=5f093b6c, visitGroup=null} {null -> SolverVehicleShift{id=4ba8b9dc}[0]}).
...
11:05:45.628 DEBUG [pool-5-thread-1]     CH step (158), time spent (159), score (0hard/-30000medium/-4204205soft), selected move count (18), picked move (ai.timefold.solver.core.impl.heuristic.move.SelectorBasedNoChangeMove@41d4d9d7).
11:05:45.636 DEBUG [pool-5-thread-1] Multi-Threaded Construction Heuristic Decider ended
11:05:45.636  INFO [pool-5-thread-1] Construction Heuristic phase (2) ended: time spent (167), best score (0hard/-30000medium/-4204205soft), effective move evaluation speed (15209/sec), step total (159).

11:05:45.649 DEBUG [pool-5-thread-1] Distance Matrix building ended, origin size (158), maximum destination size (40).
11:05:45.653 DEBUG [pool-5-thread-1] Distance Matrix building ended, origin size (158), maximum destination size (40).
11:05:45.657 DEBUG [pool-5-thread-1] Distance Matrix building ended, origin size (158), maximum destination size (40).
11:05:45.657 DEBUG [pool-5-thread-1] Multi-Threaded Local Search Decider started, move threads (4)
11:05:45.657 DEBUG [pool-5-thread-1] Local Search phase (3) started.
11:05:45.684 DEBUG [pool-5-thread-1]     LS step (0), time spent (215), score (0hard/-30000medium/-4203148soft), new best score (0hard/-30000medium/-4203148soft), accepted/selected move count (1/38), picked move (SolverVisit{id=797fb983, visitGroup=null} {SolverVehicleShift{id=9419b027}[0]} <-> SolverVisit{id=b20ce24e, visitGroup=null} {SolverVehicleShift{id=0ed0fa07}[0]}).
...
11:06:29.208 DEBUG [pool-5-thread-1]     LS step (130677), time spent (43739), score (0hard/0medium/-3929089soft),     best score (0hard/0medium/-3929083soft), terminated prematurely after selecting 98 moves.
11:06:29.211 DEBUG [pool-5-thread-1] Multi-Threaded Local Search Decider ended
11:06:29.211  INFO [pool-5-thread-1] Local Search phase (3) ended: time spent (43742), best score (0hard/0medium/-3929083soft), effective move evaluation speed (117863/sec), step total (130678).

@zepfred zepfred requested a review from triceo as a code owner July 3, 2026 14:15
Copilot AI review requested due to automatic review settings July 3, 2026 14:15

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

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 adds new DEBUG-level “phase started” log lines across several solver phases to make solver lifecycle logs more complete and easier to correlate with existing step/phase-end logging.

Changes:

  • Log “Custom phase started” at DEBUG when a custom phase begins.
  • Log “Construction Heuristic phase started” at DEBUG when CH begins.
  • Log “Exhaustive Search phase started” and “Local Search phase started” at DEBUG when those phases begin.

Reviewed changes

Copilot reviewed 4 out of 4 changed files in this pull request and generated 4 comments.

File Description
core/src/main/java/ai/timefold/solver/core/impl/phase/custom/DefaultCustomPhase.java Adds a DEBUG log line at custom phase start.
core/src/main/java/ai/timefold/solver/core/impl/constructionheuristic/DefaultConstructionHeuristicPhase.java Adds a DEBUG log line at construction heuristic phase start.
core/src/main/java/ai/timefold/solver/core/impl/exhaustivesearch/DefaultExhaustiveSearchPhase.java Adds a DEBUG log line at exhaustive search phase start.
core/src/main/java/ai/timefold/solver/core/impl/localsearch/DefaultLocalSearchPhase.java Adds a DEBUG log line at local search phase start.

@sonarqubecloud

sonarqubecloud Bot commented Jul 3, 2026

Copy link
Copy Markdown

@triceo triceo left a comment

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.

From the provided log, you can see that this brings zero benefit.
The delay - where there is a delay - is not wrapped by any logging statement; therefore this logging is pointless.

IMO we can just close this.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants