[INFO] Running org.acme.callcenter.solver.CallCenterConstraintProviderTest
2024-01-18 07:42:30,217 INFO [ai.tim.sol.qua.bea.TimefoldSolverBannerBean] (main) Using Timefold Solver Community Edition v1.6.0.
2024-01-18 07:42:30,316 INFO [io.quarkus] (main) timefold-solver-quarkus-call-center-quickstart 1.0-SNAPSHOT on JVM (powered by Quarkus 3.6.4) started in 2.227s. Listening on: http://localhost:8081
2024-01-18 07:42:30,317 INFO [io.quarkus] (main) Profile test activated.
2024-01-18 07:42:30,319 INFO [io.quarkus] (main) Installed features: [cdi, resteasy, resteasy-jackson, smallrye-context-propagation, timefold-solver, timefold-solver-jackson, vertx, webjars-locator]
[INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 4.603 s -- in org.acme.callcenter.solver.CallCenterConstraintProviderTest
[INFO] Running org.acme.callcenter.solver.SolverServiceTest
2024-01-18 07:42:30,571 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-8-thread-1) Solving started: time spent (5), best score (-2init/0hard/0soft), environment mode (REPRODUCIBLE), move thread count (NONE), random (JDK with seed 0).
2024-01-18 07:42:30,578 INFO [ai.tim.sol.cor.imp.con.DefaultConstructionHeuristicPhase] (pool-8-thread-1) Construction Heuristic phase (0) ended: time spent (15), best score (-1init/-1hard/0soft), score calculation speed (166/sec), step total (1).
2024-01-18 07:42:30,580 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-8-thread-1) Real-time problem fact changes done: step total (1), new best score (-1init/-1hard/0soft).
2024-01-18 07:42:30,580 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-8-thread-1) Solving restarted: time spent (0), best score (-1init/-1hard/0soft), environment mode (REPRODUCIBLE), move thread count (NONE), random (JDK with seed 0).
2024-01-18 07:42:30,582 INFO [ai.tim.sol.cor.imp.con.DefaultConstructionHeuristicPhase] (pool-8-thread-1) Construction Heuristic phase (0) ended: time spent (2), best score (-1hard/0soft), score calculation speed (4500/sec), step total (1).
2024-01-18 07:42:30,587 INFO [ai.tim.sol.cor.imp.loc.DefaultLocalSearchPhase] (pool-8-thread-1) Local Search phase (1) ended: time spent (7), best score (0hard/0soft), score calculation speed (1500/sec), step total (5).
2024-01-18 07:42:30,588 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-8-thread-1) Real-time problem fact changes done: step total (2), new best score (0hard/0soft).
2024-01-18 07:42:30,589 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-8-thread-1) Solving restarted: time spent (0), best score (0hard/0soft), environment mode (REPRODUCIBLE), move thread count (NONE), random (JDK with seed 0).
2024-01-18 07:42:30,589 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-8-thread-1) Skipped all phases (2): out of 2 planning entities, none are movable (non-pinned).
2024-01-18 07:42:30,889 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (main) Terminating solver early.
2024-01-18 07:42:30,889 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-8-thread-1) Solving ended: time spent (0), best score (0hard/0soft), score calculation speed (1000/sec), phase total (2), environment mode (REPRODUCIBLE), move thread count (NONE).
2024-01-18 07:42:30,899 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-8-thread-2) Solving started: time spent (0), best score (0hard/0soft), environment mode (REPRODUCIBLE), move thread count (NONE), random (JDK with seed 0).
2024-01-18 07:42:30,900 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-8-thread-2) Skipped all phases (2): out of 0 planning entities, none are movable (non-pinned).
2024-01-18 07:42:30,903 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-8-thread-2) Real-time problem fact changes done: step total (2), new best score (-2init/0hard/0soft).
2024-01-18 07:42:30,904 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-8-thread-2) Solving restarted: time spent (1), best score (-2init/0hard/0soft), environment mode (REPRODUCIBLE), move thread count (NONE), random (JDK with seed 0).
2024-01-18 07:42:30,906 INFO [ai.tim.sol.cor.imp.con.DefaultConstructionHeuristicPhase] (pool-8-thread-2) Construction Heuristic phase (0) ended: time spent (3), best score (0hard/0soft), score calculation speed (8500/sec), step total (2).
2024-01-18 07:42:30,907 INFO [ai.tim.sol.cor.imp.loc.DefaultLocalSearchPhase] (pool-8-thread-2) Local Search phase (1) ended: time spent (4), best score (0hard/0soft), score calculation speed (1000/sec), step total (1).
2024-01-18 07:42:30,908 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-8-thread-2) Real-time problem fact changes done: step total (1), new best score (0hard/0soft).
2024-01-18 07:42:30,908 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-8-thread-2) Solving restarted: time spent (0), best score (0hard/0soft), environment mode (REPRODUCIBLE), move thread count (NONE), random (JDK with seed 0).
2024-01-18 07:42:30,908 INFO [ai.tim.sol.cor.imp.con.DefaultConstructionHeuristicPhase] (pool-8-thread-2) Construction Heuristic phase (0) ended: time spent (0), best score (0hard/0soft), score calculation speed (0/sec), step total (0).
2024-01-18 07:42:31,104 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (main) Terminating solver early.
2024-01-18 07:42:31,104 INFO [ai.tim.sol.cor.imp.loc.DefaultLocalSearchPhase] (pool-8-thread-2) Local Search phase (1) ended: time spent (196), best score (0hard/0soft), score calculation speed (78861/sec), step total (1).
2024-01-18 07:42:31,104 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-8-thread-2) Solving ended: time spent (196), best score (0hard/0soft), score calculation speed (78464/sec), phase total (2), environment mode (REPRODUCIBLE), move thread count (NONE).
2024-01-18 07:42:31,120 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-11-thread-1) Solving started: time spent (6), best score (-1hard/-2soft), environment mode (REPRODUCIBLE), move thread count (NONE), random (JDK with seed 0).
2024-01-18 07:42:31,123 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-11-thread-1) Real-time problem fact changes done: step total (1), new best score (-1hard/-1soft).
2024-01-18 07:42:31,123 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-11-thread-1) Solving restarted: time spent (0), best score (-1hard/-1soft), environment mode (REPRODUCIBLE), move thread count (NONE), random (JDK with seed 0).
2024-01-18 07:42:31,125 INFO [ai.tim.sol.cor.imp.loc.DefaultLocalSearchPhase] (pool-11-thread-1) Local Search phase (0) ended: time spent (2), best score (0hard/0soft), score calculation speed (9000/sec), step total (7).
2024-01-18 07:42:31,126 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-11-thread-1) Real-time problem fact changes done: step total (1), new best score (0hard/0soft).
2024-01-18 07:42:31,127 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-11-thread-1) Solving restarted: time spent (1), best score (0hard/0soft), environment mode (REPRODUCIBLE), move thread count (NONE), random (JDK with seed 0).
2024-01-18 07:42:31,127 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-11-thread-1) Skipped all phases (1): out of 1 planning entities, none are movable (non-pinned).
2024-01-18 07:42:31,127 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-11-thread-1) Solving ended: time spent (1), best score (0hard/0soft), score calculation speed (1000/sec), phase total (1), environment mode (REPRODUCIBLE), move thread count (NONE).
2024-01-18 07:42:31,247 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-8-thread-1) Solving started: time spent (0), best score (-2init/0hard/0soft), environment mode (REPRODUCIBLE), move thread count (NONE), random (JDK with seed 0).
2024-01-18 07:42:31,247 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-8-thread-1) Real-time problem fact changes done: step total (1), new best score (-1init/0hard/0soft).
2024-01-18 07:42:31,248 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-8-thread-1) Solving restarted: time spent (0), best score (-1init/0hard/0soft), environment mode (REPRODUCIBLE), move thread count (NONE), random (JDK with seed 0).
2024-01-18 07:42:31,249 INFO [ai.tim.sol.cor.imp.con.DefaultConstructionHeuristicPhase] (pool-8-thread-1) Construction Heuristic phase (0) ended: time spent (1), best score (0hard/0soft), score calculation speed (8000/sec), step total (1).
2024-01-18 07:42:31,250 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-8-thread-1) Real-time problem fact changes done: step total (1), new best score (0hard/0soft).
2024-01-18 07:42:31,250 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-8-thread-1) Solving restarted: time spent (0), best score (0hard/0soft), environment mode (REPRODUCIBLE), move thread count (NONE), random (JDK with seed 0).
2024-01-18 07:42:31,250 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-8-thread-1) Skipped all phases (2): out of 1 planning entities, none are movable (non-pinned).
2024-01-18 07:42:31,368 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (main) Terminating solver early.
2024-01-18 07:42:31,368 INFO [ai.tim.sol.cor.imp.sol.DefaultSolver] (pool-8-thread-1) Solving ended: time spent (0), best score (0hard/0soft), score calculation speed (1000/sec), phase total (2), environment mode (REPRODUCIBLE), move thread count (NONE).
Error: Tests run: 4, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 0.904 s <<< FAILURE! -- in org.acme.callcenter.solver.SolverServiceTest
Error: org.acme.callcenter.solver.SolverServiceTest.prolongCall -- Time elapsed: 0.423 s <<< FAILURE!
org.opentest4j.AssertionFailedError:
Expecting Duration:
59.709322S
to have 1L minute but had 0L
at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:77)
at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499)
at org.acme.callcenter.solver.SolverServiceTest.prolongCall(SolverServiceTest.java:87)
at java.base/java.lang.reflect.Method.invoke(Method.java:568)
at io.quarkus.test.junit.QuarkusTestExtension.runExtensionMethod(QuarkusTestExtension.java:1013)
at io.quarkus.test.junit.QuarkusTestExtension.interceptTestMethod(QuarkusTestExtension.java:827)
at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)