OptaPlanner, Score calculation speed will be too low

Viewed 135

Run my optaplanner project and got following output. Seems there are two issues. What do these output mean? The first is

Score calculation speed will be too low because move thread ({})'s destroy wasn't processed soon enough.

and the other one is

ERROR 603112 --- [pool-1-thread-3] o.o.core.impl.solver.thread.ThreadUtils  : Multithreaded Local Search's ExecutorService didn't terminate within timeout (1 seconds).

the output that contains the errors is here.

the application.properties is copied from somewhere, don't understand it much. the file is like this:

spring.datasource.url=jdbc:h2:mem:fedb;DB_CLOSE_DELAY=-1
spring.datasource.driverClassName=org.h2.Driver
spring.datasource.username=sa
spring.jpa.database-platform=org.hibernate.dialect.H2Dialect
logging.level.root=INFO
logging.level.org.springframework=INFO
logging.level.org.drools=INFO
logging.level.org.optaplanner.core=INFO
optaplanner.solver.termination.spent-limit=2s
optaplanner.solver.move-thread-count=10
optaplanner.solver.environment-mode=NON_REPRODUCIBLE
spring.servlet.multipart.max-file-size=500MB
spring.servlet.multipart.max-request-size=500MB
server.port=8090

To answer Geoffrey's questions: Using Java 1.8.0_241, OptaPlanner optaplanner-bom 7.59.0.Final. The terminate time is set to 2 seconds, the app exits on time with a working solution. The error output can be reproduced all the time yesterday, but no error at all today, no code change. Really strange. Today's output is here. I think I should delete the post.

2 Answers

On top of Geoffrey's answer, I want to point out one more thing from the log you provided:

 The resolvedMoveThreadCount (10) is higher than the availableProcessorCount (8), which is counter-efficient.

You seem to be over-extending your machine. All that context switching may be grinding your solvers to a halt.

Furthermore, I believe the current best practice is to not go above 4 move threads, as the solver likely won't scale past that anyway.

This is interesting. It smells like an exotic bug.

The CH didn't have enough time finish, even though it got more than 10+ minutes:

  INFO Solving started: time spent (12), ...
 ERROR Multithreaded Local Search's ExecutorService didn't terminate within timeout (1 seconds).
  INFO Score calculation speed will be too low because move thread ({})'s destroy wasn't processed soon enough.
  ...
  INFO Construction Heuristic ... ended: time spent (682760), ..., step total (1).
  INFO Solving ended: time spent (682760), ...

More worryingly, the CH did even finish the first step in 10+ minutes!

  1. Does this reproduce in every run? I see NON_REPRODUCIBLE is configured.
  2. Does this reproduce with moveThreadCount=NONE ?
  3. Any clue in TRACE logging?
  4. Which OptaPlanner version?
Related