Console logging of sampling broken

[jlperla]

Using [fce5fe82] Turing v0.21.6 and [366bfd00] DynamicPPL v0.19.3 or the most recent ones of those as well, I am seeing issues with console output of the logging. If I copy in the https://turing.ml/v0.21/docs/using-turing/quick-start example then I get output that looks like

julia> chain = sample(coinflip(data), HMC(ϵ, τ), iterations)
┌ LogLevel(-1): Sampling
└ @ AbstractMCMC C:\Users\jesse\.julia\packages\ProgressLogging\6KXlp\src\ProgressLogging.jl:385
Sampling   0%|██                                                                                                                                                                                                                                              |  ETA: 0:00:53Sampling   1%|███                                                                                                                                                                                                                                             |  ETA: 0:00:49Sampling   2%|████                                                                                                                                                                                                                                            |  ETA: 0:00:33Sampling   2%|█████                                                                                                                                                                                                                                           |  ETA: 0:00:24Sampling   2%|███████               
                                                                                                                                                                                                                          |  ETA: 0:00:20Sampling   3%|████████                       
                                                                                                                                                                                                                 |  ETA: 0:00:17Sampling   4%|█████████                               
                                                                                                                                                                                                        |  ETA: 0:00:14Sampling   4%|██████████                                       
                                                                                                                                                                                               |  ETA: 0:00:12Sampling   4%|███████████                                               
                                                                                                                                                                                      |  ETA: 0:00:11Sampling   5%|█████████████                                                      
                                                                                                                                                                             |  ETA: 0:00:10Sampling   6%|██████████████                                                              
                                                                                                                                                                    |  ETA: 0:00:09Sampling   6%|███████████████                                                                      
                                                                                                                                                           |  ETA: 0:00:08Sampling   6%|████████████████                                                                              
                                                                                                                                                  |  ETA: 0:00:07Sampling   7%|█████████████████                                                                                      
                                                                                                                                         |  ETA: 0:00:07Sampling   8%|███████████████████                                                                                             
                                                                                                                                |  ETA: 0:00:06Sampling   8%|████████████████████                                                                                                     
                                                                                                                       |  ETA: 0:00:06Sampling   8%|█████████████████████                                                                                                             
                                                                                                              |  ETA: 0:00:06Sampling   9%|██████████████████████                                                                                                                     
                                                                                                     |  ETA: 0:00:05Sampling  10%|███████████████████████                                                                                                                             
                                                                                            |  ETA: 0:00:05Sampling  10%|█████████████████████████                                                                                                                                    
                                                                                   |  ETA: 0:00:05Sampling  10%|██████████████████████████                                                                                                                                            
                                                                          |  ETA: 0:00:04Sampling  11%|███████████████████████████                                                                                                                                                    
                                                                 |  ETA: 0:00:04Sampling  12%|████████████████████████████                                                                                                                                                            
                                                        |  ETA: 0:00:04Sampling  12%|█████████████████████████████                                                                                                                                                                    
                                               |  ETA: 0:00:04Sampling  12%|███████████████████████████████                                                                                                                                                                           
                                      |  ETA: 0:00:04Sampling  13%|████████████████████████████████                                                                                                                                                                                   
                             |  ETA: 0:00:03Sampling  14%|█████████████████████████████████                                                                                                                                                                                           
                    |  ETA: 0:00:03Sampling  14%|██████████████████████████████████                                                                                                                                                                                                   
           |  ETA: 0:00:03Sampling  14%|███████████████████████████████████                                                                                                                                                                                                           
  |  ETA: 0:00:03Sampling  15%|█████████████████████████████████████                                                                                                                                                                                                           |  ETA: 0:00:03Sampling  16%|██████████████████████████████████████                                                                                                                                                                                                          |  ETA: 0:00:03Sampling  16%|███████████████████████████████████████                                                                                                                                                                                                         |  ETA: 0:00:03Sampling  16%|████████████████████████████████████████                                                                                                                                                                                                        |  ETA: 0:00:03Sampling  17%|█████████████████████████████████████████                                                                                                                                                                                                       |  ETA: 0:00:03Sampling  18%|███████████████████████████████████████████                                                                                                                                                                                                     |  ETA: 0:00:02Sampling  18%|████████████████████████████████████████████                                                                                                                                                                                                    |  ETA: 0:00:02Sampling  18%|████████████████████████████████

etc. It doesn't overwriting the existing display like it used to in previous versions.

[devmotion]

I can't reproduce this issue, it works fine for me with the most recent versions. As far as I know, there were no recent changes in Turing (which actually does only forward the progress keyword argument), AbstractMCMC (which is responsible for the progress logging setup), nor ProgressLogging (which is the responsible interface).

However,

┌ LogLevel(-1): Sampling

indicates that you might be missing a backend for ProgressLogging (such as e.g. TerminalLoggers, Juno, or VSCode). Maybe you (accidentally?) changed your Julia environment or REPL setup?

[jlperla]

Thanks @devmotion Interesting. Never had to do any of those manually.

Is there a something specific you need to do to support terminal logging? A "using" or something like that? The vscode one seems to work fine.

[devmotion]

AbstractMCMC should take care of loading the backends if no progress-logging capable logging backend is available (https://github.com/TuringLang/AbstractMCMC.jl/blob/a9ba4d3b1c0314393532dbd792befa55750d9a0f/src/logging.jl#L39-L48). ConsoleProgressMonitor is deprecated but a while ago it worked better on Windows (with older Julia versions at least) and IJulia, hence we use it - if nothing else is present - on these setups. Maybe before you used (automatically) TerminalLoggers and now you use (automatically) ConsoleProgressMonitor (maybe because IJulia is loaded?)? Could you try loading TerminalLoggers explicitly and check if progress logging works fine then?

[devmotion]

Or, of course, maybe it's the other way around and before you used ConsoleProgressMonitor but now AbstractMCMC selects TerminalLoggers for you.

[jlperla]

No idea. This is just using the "readme" code in https://turing.ml/v0.21/docs/using-turing/quick-start with the most recent packages I can find, so I am not sure what else I could have messed up in my setup. The terminal is on windows if that helps. Julia 1.7.3

Alas, the TerminalLoggers didn't help. I tried to add a using TerminalLoggers as well as setting the global logger following https://julialogging.github.io/TerminalLoggers.jl/dev/#Progress-bars-1 but it didn't fix the problem.

[devmotion]

And loading ConsoleProgressMonitor explicitly didn't help either? These (ConsoleProgressMonitor and TerminalLoggers) are the automatic choices if a user does not set a progress logger explicitly, and the heuristic for this choice and the implementation of the log messages in Turing/AbstractMCMC has not been changed for quite some time.

[jlperla]

OK, I am going to close the issue. Looks like this may be a general issue with logging. Maybe new julia version or something like that. I will figure it out separately. Sorry to point my finger at Turing!

[devmotion]

@jlperla I noticed that TerminalLoggers holds back some dependencies on my system: JuliaLogging/TerminalLoggers.jl#43 I assume it's not related to your problem but nevertheless you could try to see if the PR helps.