Inconsistent (sometimes garbled) solver output

[4er4er4er]

The ASL version of Gurobi 11 produces the same output in many different environments. For example,

ampl: model multmip3.mod;
ampl: data multmip3.dat;

ampl: option solver gurobiasl;
ampl: option gurobi_options 'presolve=0 numericfocus=3';

ampl: solve;
Gurobi 11.0.0: presolve=0
numericfocus=3
Gurobi 11.0.0: optimal solution; objective 235625
364 simplex iterations
60 branch-and-cut nodes
plus 34 simplex iterations for intbasis
ampl: 

The MP version is much more variable, however. In the following examples, the option numericfocus=3 is sometimes not echoed, and there are various formatting glitches:

sw.exe:

Gurobi 11.0.0:   pre:solve = 0
  alg:nuGurobi 11.0.0: optimal solution; objective 235625
325 simplex iteration(s)
53 branching node(s)

IDE:

Gurobi 11.0.0:   pre:solve = 0
  alg:numericfocus = 3
               Gurobi 11.0.0: optimal solution; objective 235625
325 simplex iteration(s)
53 branching node(s)

cmd.exe:

Gurobi 11.0.0:   pre:solve = 0
  alg:numericfocus = 3
Gurobi 11.0.0: optimal solution; objective 235625
325 simplex iteration(s)
53 branching node(s)

Jupyter notebook (nonprinting char before second "Gurobi"):

Gurobi 11.0.0:   pre:solve = 0
  alg:numericfocus = 3
 Gurobi 11.0.0: optimal solution; objective 235625
325 simplex iteration(s)
53 branching node(s)

Google Colab:

Gurobi 11.0.0:   pre:solve = 0
  alg:nuGurobi 11.0.0: optimal solution; objective 235625
411 simplex iteration(s)
60 branching node(s)

There are similar issues with other solvers, so I just picked Gurobi as a good example to start with. These issues do not affect the performance of MP or the solver, but they can confuse users, and they have caused a lot of difficulty in preparing good-looking examples.

[glebbelov]

The above commit should fix the described case, namely when options are present (sorry for not checking it myself but my Windows VM is weary...).

Should fix, because of the following. The examples show that GurobiMP prints 15 backspaces before the final message, despite intermittent output after the initial banner Gurobi 11.0.0:. This is now fixed.

However, when no options are given, both ASL and MP drivers would print the 15 bs. This is the expected behaviour when running with -AMPL from command line, as probably many modeling systems do. However, for IDE and Jupyter which don't delete anything, this would still result in this:

Gurobi 11.0.0:    Gurobi 11.0.0: optimal solution...

or similar. AMPL has a mechanism to avoid using backspaces at all: just pass them in the beginning of the message in the .sol file, then AMPL skips so many symbols when printing the message. But when running from command line with the -AMPL flag, we don't have the calling AMPL doing it, which results in the banner left astray:

bg22@bg69-Dell:~/Documents/prj/AMPL/solvers-private/mp/test/end2end/cases/categorized/fast/suf_common$ gurobi /tmp/mipl2.nl -AMPL
Gurobi 11.0.1: bg22@bg69-Dell:~/Documents/prj/AMPL/solvers-private/mp/test/end2end/cases/categorized/fast/suf_common$

Dilemma...

[glebbelov]

... We can avoid printing bs's completely if we delay printing the banner until some intermittent output is printed. This solves all the cases above, except for the case when no solver options are used and the computation runs long - currently ASL and MP print the banner, solve, delete it, and AMPL overwrites it with the solver message. With the proposed change, nothing will be printed until AMPL's output. But who needs the banner when the computation runs and outlev=1 not provided?

[4er4er4er]

We have always shown a short message (like Gurobi 11.0.0:) to indicate when AMPL's processing has ended and the solver driver's processing has begun. It's a problem for support if that message no longer appears. So I would wait on eliminating it, at least until we can give it some more thought. I'll try to write a more detailed comment about it soon.

[4er4er4er]

With the latest Gurobi build (20240320), both the initial banner Gurobi 11.0.1: and the final solve_message lines appear to be working as intended in the Windows sw.exe window, in the Windows Command Prompt window, and in the try.ampl.com notebook. Only the IDE has trouble, if there is no solver output:

ampl: solve;
Gurobi 11.0.1:                Gurobi 11.0.1: optimal solution; objective 235625
186 simplex iterations
12 branching nodes
ampl:

Have you observed other environments where that give trouble with the output in some situations?

I still think it's a good idea to have the Gurobi 11.0.1: banner at the beginning in all cases. The AMPL FAQ advises looking for this banner to tell that the solver executable has started -- see How can I tell whether messages on my screen are coming from AMPL or from the solver?. Even when the solver does produce some output, the banner can useful for support purposes; it confirms which solver is running, which is especially helpful in situations where the user does not give us the entire log (or has aborted the run).