Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ANSI enabled terminal progress bar that implements IRascalMonitor. Thread safe-ish" #1933

Merged
merged 67 commits into from
Apr 7, 2024

Conversation

jurgenvinju
Copy link
Member

@jurgenvinju jurgenvinju commented Apr 2, 2024

This PR introduces TerminalProgressBarMonitor, an implementation of IRascalMonitor that uses ANSI codes
to position a list of active progress bar in the terminal. It leads the other output around the bars by filtering the
standard output stream.

image

This PR also contains changes to all the uses of IRascalMonitor in the interpreter and the JUnit integrations, such that we don't see too many bars on the screen at the same time, and also not too few, and the bars show meaningful progress.

If the terminal is interactive, then the TerminalProgressBarMonitor is always used. Otherwise the interpreter and the test runners default to the normal RascalConsoleMonitor. Pretty unicode characters are used if the terminal can print them, otherwise we stick with ASCII.

The time between every jobStart and jobEnd is measured and printed to the right of the progress bar. Also every bar shows the time spent since the start, after every jobStep.

…ound bar (saves space for the message string) and builtin timers, checkboxes for finished indicators, and always using the full width of terminal
…s imports and extends todos for the importing or extending module. The depending module is only finished when the necessary imported ones are fully loaded. The bar is never completed in case one of the modules fails to an parse error or serious static error. That way people can see what the state is of the system by the state of the progress bars and the printed error messages
…aks the monitor because it is not thread safe yet.
…r solution using a concurrent list implementation
@jurgenvinju
Copy link
Member Author

  • Still requires some tweaking; I think we're reporting progress for tests twice now.
  • The core monitor implementation must be thread safe. It is now, but in a very slow way. The speed-up due to parallel test running does not seem damaged though.
    • the problem is that I need to know the index of each bar in the list to be able to jump up and down with the cursor just the right amount. Deque's do not provide indexOf. CopyOnWriteArrayList does, but it is just as slow as my current solution.
    • could use a third alternative to consider..
  • a lot of the changes in this PR are about the use of the IRascalMonitor interface, rather than its implementation. This would benefit the reporting in IDEs as well.

@jurgenvinju
Copy link
Member Author

jurgenvinju commented Apr 4, 2024

So I've now run it a bit, there are some windows specific issues that we'll have to tackle. And I expect similar for VS Code (where we already had to do special things around setting the codepage of the surrounding terminal etc).

But looking at a simple import:

image

This is the same behavior as on Windows. Some of those issues have been fixed now.

6 loading bars is a bit much. Maybe 1 where all those would be combined is fine, but it's a bit heavy now. I understand during testing this helps out, but what if I have 20 modules in the import graph?

It helps the user to know which modules have been (re)loaded and how much time each module took. I've tried merging the bars into one "loading" bar, but that did not work out because I can not find a natural place in the interpreter where the loading job starts and where the job ends.

With 20 modules it is actually quite interesting to see what happens:

rascal>import lang::rascal::grammar::ParserGenerator;

X Loading Map                                                                                                  / 0:00:00.122 
X Loading Exception                                                                                            / 0:00:00.025 
X Loading List                                                                                                 | 0:00:00.352 
X Loading String                                                                                               / 0:00:00.484 
X Loading Message                                                                                              / 0:00:00.006 
X Loading Type                                                                                                 \ 0:00:00.279 
X Loading ParseTree                                                                                            - 0:00:00.430 
X Loading lang::rascal::syntax::Rascal                                                                         / 0:00:00.648 
X Loading ValueIO                                                                                              \ 0:00:00.011 
X Loading Grammar                                                                                              | 0:00:00.053 
X Loading lang::rascal::grammar::definition::Literals                                                          - 0:00:00.080 
X Loading util::Maybe                                                                                          / 0:00:00.004 
X Loading lang::rascal::grammar::definition::Attributes                                                        \ 0:00:00.121 
X Loading IO                                                                                                   \ 0:00:00.100 
X Loading lang::rascal::grammar::definition::Names                                                             \ 0:00:00.017 
X Loading lang::rascal::grammar::definition::Characters                                                        \ 0:00:00.080 
X Loading lang::rascal::grammar::definition::Symbols                                                           \ 0:00:00.131 
X Loading lang::rascal::grammar::definition::Productions                                                       \ 0:00:00.462 
X Loading lang::rascal::grammar::definition::Layout                                                            / 0:00:00.036 
X Loading util::Math                                                                                           \ 0:00:00.047 
X Loading Set                                                                                                  / 0:00:00.099 
X Loading lang::rascal::grammar::definition::Modules                                                           / 0:00:00.157 
X Loading lang::rascal::grammar::definition::Regular                                                           - 0:00:00.184 
X Loading lang::rascal::grammar::ConcreteSyntax                                                                - 0:00:00.028 
X Loading Node                                                                                                 / 0:00:00.017 
X Loading lang::rascal::grammar::definition::Keywords                                                          - 0:00:00.028 
X Loading Relation                                                                                             / 0:00:00.059 
X Loading analysis::graphs::Graph                                                                              - 0:00:00.101 
X Loading lang::rascal::format::Escape                                                                         \ 0:00:00.038 
X Loading analysis::grammars::Dependency                                                                       / 0:00:00.009 
X Loading lang::rascal::format::Grammar                                                                        \ 0:00:00.250 
X Loading lang::rascal::grammar::definition::References                                                        - 0:00:00.055 
X Loading lang::rascal::grammar::definition::Priorities                                                        / 0:00:00.407 
X Loading lang::rascal::grammar::Lookahead                                                                     / 0:00:00.092 
X Loading lang::rascal::grammar::definition::Parameters                                                        - 0:00:00.023 
X Loading util::Monitor                                                                                        \ 0:00:00.070 
X Loading lang::rascal::grammar::ParserGenerator                                                               | 0:00:02.911 
ok
rascal>

We get the same information as before, when we did not have the bars: a list of loaded modules. However, while they are loading we see them being resolved one by one, and you can also seep dependencies via imports and extends explicitly. Note that extended modules are loaded every time they are being extended, so that bar will keep moving a while, or sometimes come back if it was finished in the meantime. Imported modules make the progress bar of the depending module wait. Every module that finished advances the bar for the dependent module.

In principle the top module should always be the last to finish, and therefore it is always the last bar to be printed and it ends up at the bottom with the longest running time.

@jurgenvinju
Copy link
Member Author

I think we should maybe do a call and talk about the TerminalProgressBarMonitor and how we could split up the
responsibilities?

See above; printing the bars and printing the normal output are not separate responsibilities; or at least they can not be since we have to synchronize on what is shown in the terminal. Unless this is not true, it would not help to talk about it more.

If you really really want to separate this, then we could print the bars to the output with some escaped quotes around them. Then let another wrapper around stdout detect those quotes and move the output to the right place. I tried this, but it generates a lot of flickering and other artefacts due to moving large part of the screen all the time. Also such a solution would mean a deep semantic interaction between the producer and the consumer of the bars, which also needs to be timed correctly, which I'd like even less than the current design where everything that semantically depends is close by.

The core essence of why the current design works is the ProgressBar.update function which jumps up to the right line, only prints it again if something has changed, and then jumps back tot the current cursor position. If we'd, for example, clear all bars and print them again for every interaction, you would get an annoying strobe effect.

@jurgenvinju
Copy link
Member Author

jurgenvinju commented Apr 4, 2024

TODO: pressing CTRL+C, or any other interrupt for that matter, messes up the progress bars and also the console after the prompt returns. Back to the drawing board; I'm putting this in draft modus again because that's not mergable.

@jurgenvinju jurgenvinju marked this pull request as draft April 4, 2024 14:28
@jurgenvinju jurgenvinju self-assigned this Apr 4, 2024
@jurgenvinju jurgenvinju marked this pull request as ready for review April 4, 2024 17:27
@jurgenvinju
Copy link
Member Author

  • CTRL+C problem = solved
  • Resizing = implemented

I think this might be the right time to merge. @DavyLandman thanks for the feedback; I've fixed all issues identified. The general design issue with the two interfaces for one class is something beyond me, or at least this PR.

@DavyLandman
Copy link
Member

It helps the user to know which modules have been (re)loaded and how much time each module took. I've tried merging the bars into one "loading" bar, but that did not work out because I can not find a natural place in the interpreter where the loading job starts and where the job ends.

Can't we detect the import command in the REPL?

With 20 modules it is actually quite interesting to see what happens:

rascal>import lang::rascal::grammar::ParserGenerator;

X Loading Map                                                                                                  / 0:00:00.122 
X Loading Exception                                                                                            / 0:00:00.025 
X Loading List                                                                                                 | 0:00:00.352 
X Loading String                                                                                               / 0:00:00.484 
X Loading Message                                                                                              / 0:00:00.006 
X Loading Type                                                                                                 \ 0:00:00.279 
X Loading ParseTree                                                                                            - 0:00:00.430 
X Loading lang::rascal::syntax::Rascal                                                                         / 0:00:00.648 
X Loading ValueIO                                                                                              \ 0:00:00.011 
X Loading Grammar                                                                                              | 0:00:00.053 
X Loading lang::rascal::grammar::definition::Literals                                                          - 0:00:00.080 
X Loading util::Maybe                                                                                          / 0:00:00.004 
X Loading lang::rascal::grammar::definition::Attributes                                                        \ 0:00:00.121 
X Loading IO                                                                                                   \ 0:00:00.100 
X Loading lang::rascal::grammar::definition::Names                                                             \ 0:00:00.017 
X Loading lang::rascal::grammar::definition::Characters                                                        \ 0:00:00.080 
X Loading lang::rascal::grammar::definition::Symbols                                                           \ 0:00:00.131 
X Loading lang::rascal::grammar::definition::Productions                                                       \ 0:00:00.462 
X Loading lang::rascal::grammar::definition::Layout                                                            / 0:00:00.036 
X Loading util::Math                                                                                           \ 0:00:00.047 
X Loading Set                                                                                                  / 0:00:00.099 
X Loading lang::rascal::grammar::definition::Modules                                                           / 0:00:00.157 
X Loading lang::rascal::grammar::definition::Regular                                                           - 0:00:00.184 
X Loading lang::rascal::grammar::ConcreteSyntax                                                                - 0:00:00.028 
X Loading Node                                                                                                 / 0:00:00.017 
X Loading lang::rascal::grammar::definition::Keywords                                                          - 0:00:00.028 
X Loading Relation                                                                                             / 0:00:00.059 
X Loading analysis::graphs::Graph                                                                              - 0:00:00.101 
X Loading lang::rascal::format::Escape                                                                         \ 0:00:00.038 
X Loading analysis::grammars::Dependency                                                                       / 0:00:00.009 
X Loading lang::rascal::format::Grammar                                                                        \ 0:00:00.250 
X Loading lang::rascal::grammar::definition::References                                                        - 0:00:00.055 
X Loading lang::rascal::grammar::definition::Priorities                                                        / 0:00:00.407 
X Loading lang::rascal::grammar::Lookahead                                                                     / 0:00:00.092 
X Loading lang::rascal::grammar::definition::Parameters                                                        - 0:00:00.023 
X Loading util::Monitor                                                                                        \ 0:00:00.070 
X Loading lang::rascal::grammar::ParserGenerator                                                               | 0:00:02.911 
ok
rascal>

We get the same information as before, when we did not have the bars: a list of loaded modules. However, while they are loading we see them being resolved one by one, and you can also seep dependencies via imports and extends explicitly. Note that extended modules are loaded every time they are being extended, so that bar will keep moving a while, or sometimes come back if it was finished in the meantime. Imported modules make the progress bar of the depending module wait. Every module that finished advances the bar for the dependent module.

In VS Code you would see this:

image

So that's quite a big difference for most users. I know that if you run rascal in some less typical setups, you could see all those prints, but they weren't visible for most users. I do not think people will appreciate that much internal "information".

In principle the top module should always be the last to finish, and therefore it is always the last bar to be printed and it ends up at the bottom with the longest running time.

…alues from IRascalMonitor.job to get this working. Minor change since it used to return a boolean, now it can return anything. Should be backward compatible (source, not binary)
@jurgenvinju
Copy link
Member Author

Thanks for the sugestions Davy. The importer now prints only one bar for the entire loading processes. It's still the same steps. This means it has a bit of a "Zeno" feeling as more work is discovered while more imports are being discovered per module, recursively. But it works and it uses less real estate. There is no more insight into module loading time now, except for the entire process.

The bug with the first few bars repeating themselves is back; and there is sometimes this stacktrace:

unexpected error: Index 1 out of bounds for length 1
java.lang.ArrayIndexOutOfBoundsException: Index 1 out of bounds for length 1
        at org.rascalmpl.repl.TerminalProgressBarMonitor$ANSI.getCursorPosition(TerminalProgressBarMonitor.java:319)
        at org.rascalmpl.repl.TerminalProgressBarMonitor.testUnicodeEnabled(TerminalProgressBarMonitor.java:82)
        at org.rascalmpl.repl.TerminalProgressBarMonitor.<init>(TerminalProgressBarMonitor.java:69)
        at org.rascalmpl.debug.IRascalMonitor.buildConsoleMonitor(IRascalMonitor.java:126)
        at org.rascalmpl.shell.ShellEvaluatorFactory.getDefaultEvaluator(ShellEvaluatorFactory.java:34)
        at org.rascalmpl.shell.REPLRunner$1.constructEvaluator(REPLRunner.java:51)
        at org.rascalmpl.repl.RascalInterpreterREPL.initialize(RascalInterpreterREPL.java:75)
        at org.rascalmpl.repl.BaseREPL.initialize(BaseREPL.java:158)
        at org.rascalmpl.repl.BaseREPL.<init>(BaseREPL.java:112)
        at org.rascalmpl.shell.REPLRunner.<init>(REPLRunner.java:37)
        at org.rascalmpl.shell.RascalShell.main(RascalShell.java:71)
23:45:10 rascal (progress-bar *=)$ 

depending on the initial size or cursor position of the terminal that the REPL starts in. strange.

@jurgenvinju
Copy link
Member Author

image

@DavyLandman
Copy link
Member

Thanks for the sugestions Davy. The importer now prints only one bar for the entire loading processes. It's still the same steps. This means it has a bit of a "Zeno" feeling as more work is discovered while more imports are being discovered per module, recursively. But it works and it uses less real estate. There is no more insight into module loading time now, except for the entire process.

Thanks, that sounds better indeed 👍🏽

The bug with the first few bars repeating themselves is back; and there is sometimes this stacktrace:

unexpected error: Index 1 out of bounds for length 1
java.lang.ArrayIndexOutOfBoundsException: Index 1 out of bounds for length 1
        at org.rascalmpl.repl.TerminalProgressBarMonitor$ANSI.getCursorPosition(TerminalProgressBarMonitor.java:319)
        at org.rascalmpl.repl.TerminalProgressBarMonitor.testUnicodeEnabled(TerminalProgressBarMonitor.java:82)
        at org.rascalmpl.repl.TerminalProgressBarMonitor.<init>(TerminalProgressBarMonitor.java:69)
        at org.rascalmpl.debug.IRascalMonitor.buildConsoleMonitor(IRascalMonitor.java:126)
        at org.rascalmpl.shell.ShellEvaluatorFactory.getDefaultEvaluator(ShellEvaluatorFactory.java:34)
        at org.rascalmpl.shell.REPLRunner$1.constructEvaluator(REPLRunner.java:51)
        at org.rascalmpl.repl.RascalInterpreterREPL.initialize(RascalInterpreterREPL.java:75)
        at org.rascalmpl.repl.BaseREPL.initialize(BaseREPL.java:158)
        at org.rascalmpl.repl.BaseREPL.<init>(BaseREPL.java:112)
        at org.rascalmpl.shell.REPLRunner.<init>(REPLRunner.java:37)
        at org.rascalmpl.shell.RascalShell.main(RascalShell.java:71)
23:45:10 rascal (progress-bar *=)$ 

Maybe there is a race, where the terminal is still getting initialized?

Also, for comparison, this is what we have to do in VS Code to detect the encoding & fix a windows issue:

https://github.com/usethesource/rascal-language-servers/blob/f3c5155a58a01957481aefa854a61ca33e04781e/rascal-lsp/src/main/java/org/rascalmpl/vscode/lsp/terminal/LSPTerminalREPL.java#L102-L132

@jurgenvinju jurgenvinju merged commit 0687e40 into main Apr 7, 2024
1 check passed
@jurgenvinju jurgenvinju deleted the progress-bar branch April 7, 2024 15:57
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants