Originally posted by: chrysg

Dear forum,

I ran my problem twice, back-to-back (without any change in the model whatsoever) on the same machine. Yet, the outcome was not reproducible.

At a seemingly ordinary node, Dual Simplex algorithm took a few extra pivots to reach the solution. This affects variable choices for Dual Simplex in the subsequent nodes, eventually leading to different solution paths for the whole MIP.

I note that the resulting difference in overall performance (e.g., total number of nodes to reach optimality, or gap after given number of nodes) can be quite significant.

I was wondering if somebody could clarify for me why this is happening and possibly how to alleviate this behavior.

I attach below the two outputs and in particular the segments where the two runs begin to deviate. For convenience, I have omitted thousands of lines of preceding output that are identical and also most of the remaining output after the deviation has occurred.

Thank you,

Chris

P.S.1 I am using CPLEX 12.2 with THREADS = 1
P.S.2 For generation of output: MIPINTERVAL = 1, MIPDISPLAY = 5, SIMDISPLAY = 2
P.S.3 I do have callbacks, but they are 100% deterministic and, given the output, I do not think they have anything to do with this
#CPLEXOptimizers
#DecisionOptimization

Originally posted by: chrysg

File #1
#CPLEXOptimizers
#DecisionOptimization

Originally posted by: chrysg

File #2
#CPLEXOptimizers
#DecisionOptimization

Originally posted by: chrysg

I just noticed that another variation existed in my output, before the one I present in the files.

At a node long before the output I present, the number it prints "Reinitializing dual norms . . ." is different.
In file #1, it does it once, while in file #2 it repeats it two times. However, it is only after many nodes that an actual deviation occurs in the solution process.

So the question is:

1) Why does it reinitialize norms many times?
2) Why the apparent randomness in the number of times the reinitialization occurs?
3) Can this possibly be the cause of the deviation we observe later (in the files I attached)?

Thank you!

P.S. E.g., see below...LP solutions after Nodes 22399 and 22400 are exactly the same in both cases; however in between, it has printed "Reinitializing dual norms . . ." a different number of times...

File 1
======

Nodes Cuts/
Node Left Objective IInf Best Integer Best Node ItCnt Gap

22399 10505 881.5000 28 892.0000 879.3846 410375 1.41%

Iteration Dual Objective In Variable Out Variable
1 882.000000 u58 slack xvar(9.33)
2 882.000000 u359 slack u2074 slack
3 882.000000 u303 slack u1481 slack
4 882.000000 u1268 slack xvar(16.32)
5 882.000000 xvar(19.33) u2384 slack
6 883.000000 u1570 slack u1471 slack
7 883.000000 xvar(19.20) u2785 slack
8 883.000000 xvar(1.5) u383 slack
9 883.500000 xvar(5.9) u2037 slack
10 883.833333 u288 slack xvar(2.5)
11 884.166667 u2074 slack xvar(11.37)
12 884.166667 u2053 slack u2856 slack
13 884.944444 xvar(26.30) xvar(27.35)
14 885.300000 u2224 slack xvar(11.26)
15 886.000000 u266 slack xvar(9.21)
16 886.000000 xvar(21.33) xvar(11.32)
Reinitializing dual norms . . .

Nodes Cuts/
Node Left Objective IInf Best Integer Best Node ItCnt Gap

22400 10506 886.0000 28 892.0000 879.3846 410391 1.41%
Elapsed time = 312.64 sec. (tree size = 266.23 MB, solutions = 1)
Nodefile size = 139.05 MB (132.39 MB after compression)

Iteration Dual Objective In Variable Out Variable
1 886.000000 u2785 slack xvar(14.18)
2 886.000000 u2856 slack u2628 slack
3 886.000000 u1741 slack u1498 slack
4 886.000000 xvar(13.30) xvar(0.34)
5 886.000000 u2628 slack u269 slack
6 886.000000 xvar(14.19) u648 slack
7 886.000000 xvar(30.35) u372 slack
8 886.000000 xvar(17.19) xvar(21.26)
9 886.000000 u2449 slack xvar(18.21)

File 2
======

Nodes Cuts/
Node Left Objective IInf Best Integer Best Node ItCnt Gap

22399 10505 881.5000 28 892.0000 879.3846 410375 1.41%

Iteration Dual Objective In Variable Out Variable
1 882.000000 u58 slack xvar(9.33)
2 882.000000 u359 slack u2074 slack
3 882.000000 u303 slack u1481 slack
4 882.000000 u1268 slack xvar(16.32)
5 882.000000 xvar(19.33) u2384 slack
6 883.000000 u1570 slack u1471 slack
7 883.000000 xvar(19.20) u2785 slack
8 883.000000 xvar(1.5) u383 slack
9 883.500000 xvar(5.9) u2037 slack
10 883.833333 u288 slack xvar(2.5)
11 884.166667 u2074 slack xvar(11.37)
12 884.166667 u2053 slack u2856 slack
13 884.944444 xvar(26.30) xvar(27.35)
14 885.300000 u2224 slack xvar(11.26)
15 886.000000 u266 slack xvar(9.21)
16 886.000000 xvar(21.33) xvar(11.32)
Reinitializing dual norms . . .
Reinitializing dual norms . . .

Nodes Cuts/
Node Left Objective IInf Best Integer Best Node ItCnt Gap

22400 10506 886.0000 28 892.0000 879.3846 410391 1.41%
Elapsed time = 325.25 sec. (tree size = 266.23 MB, solutions = 1)
Nodefile size = 139.05 MB (132.39 MB after compression)

Iteration Dual Objective In Variable Out Variable
1 886.000000 u2785 slack xvar(14.18)
2 886.000000 u2856 slack u2628 slack
3 886.000000 u1741 slack u1498 slack
4 886.000000 xvar(13.30) xvar(0.34)
5 886.000000 u2628 slack u269 slack
6 886.000000 xvar(14.19) u648 slack
7 886.000000 xvar(30.35) u372 slack
8 886.000000 xvar(17.19) xvar(21.26)
9 886.000000 u2449 slack xvar(18.21)
#CPLEXOptimizers
#DecisionOptimization

Originally posted by: SystemAdmin

If your code is deterministic, then this is a bug in CPLEX 12.2. Could you please upgrade to 12.4 and try again? Of course, if it does not reproduce it would not mean that the bug is fixed, though...

We just recently found a very subtle determinism issue that is related to node file compression. Maybe this one is hurting you as well. Namely, our deterministic clock (which is used in statistics, for example, to dynamically select the simplex pricing rule) is updated during compression and decompression based on the size of the compressed data. And because the compression of the node data also involves two (or three, if you are attaching user data to the nodes) pointers, the size of the compressed data can be influenced by the actual values of the pointers. And since those are results of the OS memory allocator, they are not deterministic.

Getting a different compressed size for different values of pointers should be pretty rare, and if it happens, the difference in size should be very small. Moreover, such a small difference affecting the search procedure should really be an exceptional case, but it may be that you are hitting exactly this.

If this is really the case for you, then a work-around would be to disable the compression (setting the CPX_PARAM_NODEFILEIND to 0 or 2). Another option would be to wait for our next release, where this issue will be fixed.
Tobias
#CPLEXOptimizers
#DecisionOptimization

Originally posted by: chrysg

Tobias,

Thanks once more for your prompt responses.

I ran with NODEFILEIND = 0 and the problem persists. I doubt it is the subtle issue you described.

Again, I re-point the attention to my previous post. The first output difference is always a "Reinitializing dual norms . . ." entry in only one of the two outputs.
Sometimes it is entered when in the other run it is not entered at all, sometimes it is entered in both outputs yet a different number of times.

Thanks,

Chrys

P.S. There are some practical difficulties with migrating to 12.4 right now, but once I do I will report my findings.
#CPLEXOptimizers
#DecisionOptimization

Originally posted by: SystemAdmin

The "Reinitializing dual norms..." could have been the consequence of a different deterministic clock count and the resulting change in the simplex pricing strategy. This is why I was thinking of this subtle issue with the node file compression. But since you are disabling this, this is out of the picture.

So, unfortunately I do not have any additional ideas apart from upgrading to the newest version. It could be that we fixed some determinism issues between 12.2 and 12.4; I just do not remember.

Can you reproduce this without callbacks? And can you then also reproduce it by dumping the model to a .sav file and running it in the interactive? In this case, I could take a look at what is going on...
Tobias
#CPLEXOptimizers
#DecisionOptimization