Why wallclock time is much longer than cpu time, and why cpu time is 0 but it got an optimal solution

[WSB1997]

/opt/miniconda3/bin/cbc -log 5 -Heuristics off -ratioGap 0.01 -threads 1 -time_limit 0.08 -debug False -printingOptions all -import /var/folders/n5/c5yd589j3wj4w6ms3spr3n60mnhqsm/T/tmpgmbu__f5.pyomo.lp -stat=1 -solve -solu /var/folders/n5/c5yd589j3wj4w6ms3spr3n60mnhqsm/T/tmpgmbu__f5.pyomo.soln (default strategy 1)
logLevel was changed from 1 to 5
Option for heuristicsOnOff changed from on to off
ratioGap was changed from 0 to 0.01
threads was changed from 0 to 1
No match for time_limit - ? for list of commands
No match for 0.08 - ? for list of commands
** Current model not valid
No match for False - ? for list of commands
Option for printingOptions changed from normal to all
Presolve 9 (-7) rows, 4 (-3) columns and 22 (-9) elements
Statistics for presolved model
Original problem has 3 integers (3 of which binary)
Presolved problem has 2 integers (2 of which binary)
==== 1 zero objective 3 different
1 variables have objective of 0
2 variables have objective of 1
1 variables have objective of 10000
==== absolute objective values 3 different
1 variables have objective of 0
2 variables have objective of 1
1 variables have objective of 10000
==== for integers 0 zero objective 1 different
2 variables have objective of 1
==== for integers absolute objective values 1 different
2 variables have objective of 1
===== end objective counts
Problem has 9 rows, 4 columns (3 with objective) and 22 elements
Column breakdown:
0 of type 0.0->inf, 0 of type 0.0->up, 0 of type lo->inf,
0 of type lo->up, 2 of type free, 0 of type fixed,
0 of type -inf->0.0, 0 of type -inf->up, 2 of type 0.0->1.0
Row breakdown:
0 of type E 0.0, 0 of type E 1.0, 0 of type E -1.0,
0 of type E other, 0 of type G 0.0, 0 of type G 1.0,
0 of type G other, 2 of type L 0.0, 0 of type L 1.0,
7 of type L other, 0 of type Range 0.0->1.0, 0 of type Range other,
0 of type Free
Continuous objective value is -87698.9 - 0.00 seconds
Cgl0002I 1 variables fixed
Cgl0010I element in row 3 for column 0 changed from -109.88 to -101.00001
Cgl0009I 1 elements changed
Cgl0003I 0 fixed, 0 tightened bounds, 3 strengthened rows, 0 substitutions
Cgl0003I 0 fixed, 0 tightened bounds, 2 strengthened rows, 0 substitutions
Cgl0004I processed model has 8 rows, 4 columns (2 integer (2 of which binary)) and 20 elements
Cbc0046I Root node pass 1, 8 rows, 0 total tight cuts - objective 433431.15
Cbc0046I Root node pass 2, 9 rows, 1 total tight cuts - objective 933402
Cbc0031I 1 added rows had average density of 3
Cbc0013I At root node, 1 cuts changed objective from 433431.15 to 933402 in 2 passes
Cbc0014I Cut generator 0 (Probing) - 0 row cuts average 0.0 elements, 0 column cuts (0 active) in 0.000 seconds - new frequency is -100
Cbc0014I Cut generator 1 (Gomory) - 1 row cuts average 3.0 elements, 0 column cuts (0 active) in 0.000 seconds - new frequency is 1
Cbc0014I Cut generator 2 (Knapsack) - 0 row cuts average 0.0 elements, 0 column cuts (0 active) in 0.000 seconds - new frequency is -100
Cbc0014I Cut generator 3 (Clique) - 0 row cuts average 0.0 elements, 0 column cuts (0 active) in 0.000 seconds - new frequency is -100
Cbc0014I Cut generator 4 (MixedIntegerRounding2) - 0 row cuts average 0.0 elements, 0 column cuts (0 active) in 0.000 seconds - new frequency is -100
Cbc0014I Cut generator 5 (FlowCover) - 0 row cuts average 0.0 elements, 0 column cuts (0 active) in 0.000 seconds - new frequency is -100
Cbc0014I Cut generator 6 (TwoMirCuts) - 1 row cuts average 3.0 elements, 0 column cuts (0 active) in 0.000 seconds - new frequency is 1
Node 0 depth 0 unsatisfied 0 sum 0 obj 933402 guess 933402 branching on -1
BFeasible (0) - obj 933402 933402
Cbc0004I Integer solution of 933402 found after 1 iterations and 0 nodes (0.00 seconds)
Cbc0030I Thread 0 used 0 times, waiting to start 10.004919, 0 cpu time, 0 locks, 0 locked, 0 waiting for locks
Cbc0030I Main thread 0 waiting for threads, 1 locks, 9.5367432e-07 locked, 0 waiting for locks
Cbc0001I Search completed - best objective 933402, took 1 iterations and 0 nodes (0.00 seconds)
Cbc0035I Maximum depth 0, 0 variables fixed on reduced cost
BFeasible (0) - obj 933402 933402
Cuts at root node changed objective from 433431 to 933402
Probing was tried 4 times and created 0 cuts of which 0 were active after adding rounds of cuts (0.000 seconds)
Gomory was tried 4 times and created 2 cuts of which 0 were active after adding rounds of cuts (0.000 seconds)
Knapsack was tried 4 times and created 0 cuts of which 0 were active after adding rounds of cuts (0.000 seconds)
Clique was tried 4 times and created 0 cuts of which 0 were active after adding rounds of cuts (0.000 seconds)
MixedIntegerRounding2 was tried 4 times and created 0 cuts of which 0 were active after adding rounds of cuts (0.000 seconds)
FlowCover was tried 4 times and created 0 cuts of which 0 were active after adding rounds of cuts (0.000 seconds)
TwoMirCuts was tried 4 times and created 2 cuts of which 0 were active after adding rounds of cuts (0.000 seconds)
ZeroHalf was tried 2 times and created 0 cuts of which 0 were active after adding rounds of cuts (0.000 seconds)
Result - Optimal solution found
Objective value: 933402.00000000
Enumerated nodes: 0
Total iterations: 1
Time (CPU seconds): 0.00
Time (Wallclock seconds): 10.02
Total time (CPU seconds): 0.00 (Wallclock seconds): 10.02
solve time cost: 10.048523902893066
cost time over 10 seconds

[WSB1997]

@jjhforrest

[jjhforrest]

Where are these from?
solve time cost: 10.048523902893066
cost time over 10 seconds
The times keep on being reset in cbc executable so some inconsistencies do exist - but I don't think it is worth spending much time on them.
As times are only given to accuracy of 0.01 seconds 0 is possible for a tiny problem. The odd time is the Wallclock time of 10 seconds. Does this happen if you run it a second time?

[WSB1997]

We have a very small-scale problem. The response time need to be less than 100ms. Most cases meet the requirements, but sometimes we have the '10s' problem. I wonder if there is anyway to solve it?