optimize() can return failure, even when the underlying fit is succesful

[martinmodrak]

Describe the bug
Using $optimize() I can reliably (on my computer) get an error message even for the most trivial models, that work when called from command line. It appears there is some sort of race condition as forcing cmdstanr to reread the process output once more after the while (procs$active_procs() == 1) loop in .run_other() finishes makes the fit succeed.

To Reproduce

m_test <- cmdstan_model(write_stan_file(r"(
parameters {
  real x;
}
model {
  x ~ normal(0,1);
}
                                        )"))

fit_test <- m_test$optimize()
# Fitting finished unexpectedly! Use the $output() method for more information.

fit_test$output()
# method = optimize

Expected behavior

A succesful optimization fit.

Operating system
Windows 10.

CmdStanR version number
0.4.0.9000 (just downloaded from GitHub)

Additional context

There is no problem when runnning the model from the command line with the exact same arguments cmdstanr uses.
In fact, copying and pasting the output processing code

  output <- procs$get_proc(id)$read_output_lines()
  procs$process_output(output, id)
  error_output <- procs$get_proc(id)$read_error_lines()
  procs$process_error_output(error_output, id)

just below the loop that waits for the process to finish (at

cmdstanr/R/run.R

Line 470 in 043c8fb

successful_fit <- FALSE

) makes the problem disappear.

I verified that upon last execution at

cmdstanr/R/run.R

Line 464 in 043c8fb

procs$process_output(output, id)

the output only contains one line: method = optimize, but once the loop finishes, the output contains the whole result, including the crucial "Optimization terminated normally".

I don't think I understand the code enough to know whether this copy-paste of code is a good solution to the underlying problem, but it lets me sidestep the issue for now.

[rok-cesnovar]

Thanks Martin for the bug report and also the solution! This makes sense, this "copy-paste" fixes the issue because it makes sure to read in the rest of the output that was read since the last procs$process_output(output, id) call. If the process finishes between the last process_output call and the procs$active_procs() call in the while loop condition some of the output gets lost.

I dont see any other solution apart from reading in the rest of the stdout/stderr after the loop.

[jgabry]

I just merged Rok's PR that should fix this. @martinmodrak does the master branch now work correctly for you?

[martinmodrak]

Works on my computer. Thanks a lot!

[jgabry]

Awesome, thanks for checking!

[rok-cesnovar]

This fix also seems to have fixed our occasional false positive CI failure with optimization on Macs. Thanks again Martin for spotting this!

[jgabry]

On Wed, Jun 23, 2021 at 6:58 AM Rok Češnovar ***@***.***> wrote: This fix also seems to have fixed our occasional false positive CI failure with optimization on Macs. Thanks again Martin for spotting this!

Awesome, those mac failures were annoying!

…