calva icon indicating copy to clipboard operation
calva copied to clipboard
verified publisher icon BetterThanTomorrow

Calva is locking up with large output to output.calva-repl

Open sirmspencer opened this issue 2 years ago • 8 comments

If I accidentally output a large amount to output.calva-repl, VSCode freezes like crazy. I'm sure some of it is limitations with VSCode trying to start a formatter. The only way around this is to close vscode and open output.calva-repl in a plain text editor to clear the file.

sirmspencer avatar Jul 30 '23 23:07 sirmspencer

The output window is known to have issues around large amounts of output, the structure of which might play a role in the severity of the issue. Related issues are #942 and #804. We're planning to overhaul the output experience eventually in a way that should address / fix this issue.

bpringe avatar Aug 02 '23 02:08 bpringe

I don't think people usually experience a full on freeze, though. Do you have a reproducible case? It would be good to rule out some specific issue here that could be tripping up the formatter or some other part of Calva.

bpringe avatar Aug 02 '23 02:08 bpringe

I am on mac. Its not a system freeze, or an app freeze, it gets stuck on the calva formatter message. I can screen shot next time it happens, but its something like "trying to save, waiting on calva". It does happen without output.calva-repl being affected.

I hate mac. I'm sure at least some of it is due to the heavy paging vs ram.

sirmspencer avatar Aug 02 '23 04:08 sirmspencer

If I remember correctly, I was trying to change my worklflow in that way, that I'll simply stop viewing output.calva-repl in vscode as it tends to become very slow for large outputs. I instead tried to have that file rendered in external terminal (using something like tail with piping to some syntax highlighting/coloring apps etc)

The problems even with this approach were:

  1. the new lines coming to output.calva-repl seemed not to simply be appended to the end, but the file got fully rewritten over and over again. This effectively made using tail impossible. I guess this "full rewrite of output.calva-repl " might be related to the limitations of vscode editor API used to "append" new rows to mentioned file. (I believe the editor api that was being used was actually named append, yet the actual file behind the editor got fully rewritten).

  2. even if the file isn't being shown in vscode, calva is still writing to it behind the scenes and even this still tends to get slower and slower with increasing number of lines. So I'd say that not just the syntax highligting penalty causes the delay, but even the actual file "appending" does.

If ^^^ mentioned problems are still true today, I'm wondering if any of these ideas could improve the situation (and would make sense):

a) allow to completely turn off writing to output.calva-repl in settings. Reason: some people don't use it anyway at all (their workflow simply does not need this file). For them it's completely unnecessary to write anything to that file - it's basically wasting cpu cycles, disk writes & quickly causes significant delays in every evaluation in REPL.

b) consider splitting current "representation of output.calva-repl inside VSCode", so that there's a dedicated "mutable editor part" where user can write his/her expressions, and the "responses" part, which would be simply an append-only immutable view into output.calva-repl. Perhaps if the "user interactive" and "read & append only" part of the interactive REPL are separated, it could be possible to actually append into output.calva-repl in true append way. Of course changing the form of interactive REPL like this could be a downside for some output.calva-repl interactive REPL users who mostly evaluate forms there instead of directly in the editor. So I'm not sure it's a good idea. But trying to achieve "true append" probably is and perhaps it could be done even with current behavior somehow.

brdloush avatar Aug 02 '23 06:08 brdloush

I can confirm that the file indded does get truncated and fully rewritten:

Here's a way to log activity on a FUSE-mounted directory mounted with loggedfs:

loggedfs -f /home/my_user/projects/calvaslow/.calva/output-window

and here's the result for a single evaluation of expression in calva:

2023-08-02 09:12:21,326 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349241 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,326 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349241 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,326 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349242 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,327 INFO [default] open writeonly /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349242 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,327 INFO [default] truncate /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl to 0 bytes {SUCCESS} [ pid = 1349242 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,327 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349242 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,327 INFO [default] write 2594 bytes to /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl at offset 0 {SUCCESS} [ pid = 1349244 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,327 INFO [default] 2594 bytes written to /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl at offset 0 {SUCCESS} [ pid = 1349244 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,327 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349969 /usr/share/code/code --type=utility --utility-sub-type=node.mojom.NodeService --lang=en-US --service-sandbox-type=none --crashpad-handler-pid=1349224 --enable-crash-reporter=<redacted>,no_channel --user-data-dir=/home/my_user �E��U uid = 1000 ]
2023-08-02 09:12:21,327 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349969 /usr/share/code/code --type=utility --utility-sub-type=node.mojom.NodeService --lang=en-US --service-sandbox-type=none --crashpad-handler-pid=1349224 --enable-crash-reporter=<redacted>,no_channel --user-data-dir=/home/my_user@ uid = 1000 ]
2023-08-02 09:12:21,327 INFO [default] fsync /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349243 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,327 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349969 /usr/share/code/code --type=utility --utility-sub-type=node.mojom.NodeService --lang=en-US --service-sandbox-type=none --crashpad-handler-pid=1349224 --enable-crash-reporter=<redacted>,no_channel --user-data-dir=/home/my_user �E��U uid = 1000 ]
2023-08-02 09:12:21,327 INFO [default] release /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 0 (null) uid = 0 ]
2023-08-02 09:12:21,327 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349969 /usr/share/code/code --type=utility --utility-sub-type=node.mojom.NodeService --lang=en-US --service-sandbox-type=none --crashpad-handler-pid=1349224 --enable-crash-reporter=<redacted>,no_channel --user-data-dir=/home/my_user@
                                                                          uid = 1000 ]
2023-08-02 09:12:21,328 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349242 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,328 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349242 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,329 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349243 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,329 INFO [default] open /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349243 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,329 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349243 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,330 INFO [default] read 4096 bytes from /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl at offset 0 {SUCCESS} [ pid = 1349243 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,330 INFO [default] 2594 bytes read from /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl at offset 0 {SUCCESS} [ pid = 1349243 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,330 INFO [default] release /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 0 (null) uid = 0 ]
2023-08-02 09:12:21,335 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349242 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,335 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349242 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,336 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349244 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,336 INFO [default] open writeonly /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349244 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,337 INFO [default] truncate /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl to 0 bytes {SUCCESS} [ pid = 1349244 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,337 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349244 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,337 INFO [default] write 2626 bytes to /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl at offset 0 {SUCCESS} [ pid = 1349241 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,337 INFO [default] 2626 bytes written to /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl at offset 0 {SUCCESS} [ pid = 1349241 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,337 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349969 /usr/share/code/code --type=utility --utility-sub-type=node.mojom.NodeService --lang=en-US --service-sandbox-type=none --crashpad-handler-pid=1349224 --enable-crash-reporter=<redacted>,no_channel --user-data-dir=/home/my_user �E��U uid = 1000 ]
2023-08-02 09:12:21,337 INFO [default] fsync /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349243 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,337 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349969 /usr/share/code/code --type=utility --utility-sub-type=node.mojom.NodeService --lang=en-US --service-sandbox-type=none --crashpad-handler-pid=1349224 --enable-crash-reporter=<redacted>,no_channel --user-data-dir=/home/my_user@
                                                                          uid = 1000 ]
2023-08-02 09:12:21,337 INFO [default] release /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 0 (null) uid = 0 ]
2023-08-02 09:12:21,337 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349969 /usr/share/code/code --type=utility --utility-sub-type=node.mojom.NodeService --lang=en-US --service-sandbox-type=none --crashpad-handler-pid=1349224 --enable-crash-reporter=<redacted>,no_channel --user-data-dir=/home/my_user �E��U uid = 1000 ]
2023-08-02 09:12:21,337 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349969 /usr/share/code/code --type=utility --utility-sub-type=node.mojom.NodeService --lang=en-US --service-sandbox-type=none --crashpad-handler-pid=1349224 --enable-crash-reporter=<redacted>,no_channel --user-data-dir=/home/my_user@
                                                                          uid = 1000 ]
2023-08-02 09:12:21,343 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349244 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,343 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349244 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,345 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349243 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,345 INFO [default] open /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349243 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,345 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349243 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,345 INFO [default] read 4096 bytes from /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl at offset 0 {SUCCESS} [ pid = 1349243 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,345 INFO [default] 2626 bytes read from /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl at offset 0 {SUCCESS} [ pid = 1349243 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,345 INFO [default] release /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 0 (null) uid = 0 ]
2023-08-02 09:12:21,405 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349244 /usr/share/code/code . uid = 1000 ]
2023-08-02 09:12:21,405 INFO [default] getattr /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl {SUCCESS} [ pid = 1349244 /usr/share/code/code . uid = 1000 ]

The problematic part seems to be this:

2023-08-02 09:12:21,327 INFO [default] truncate /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl to 0 bytes {SUCCESS} [ pid = 1349242 /usr/share/code/code . uid = 1000 ]
...
2023-08-02 09:12:21,327 INFO [default] write 2594 bytes to /home/my_user/projects/calvaslow/.calva/output-window/output.calva-repl at offset 0 {SUCCESS} [ pid = 1349244 /usr/share/code/code . uid = 1000 ]

brdloush avatar Aug 02 '23 07:08 brdloush

Yes, probably not a file you can use tail -f on. It's Calva that uses the append semantics, btw. The VS Code API for these things uses words like insert, replace, and delete.

The real fix here is probably to offer a way to output stdout to some other place than the REPL window. Or rewrite the REPL window to not be a regular VS Code editor/file. Or both.

PEZ avatar Aug 02 '23 11:08 PEZ

b) consider splitting current "representation of output.calva-repl inside VSCode", so that there's a dedicated "mutable editor part" where user can write his/her expressions, and the "responses" part, which would be simply an append-only immutable view into output.calva-repl. Perhaps if the "user interactive" and "read & append only" part of the interactive REPL are separated, it could be possible to actually append into output.calva-repl in true append way. Of course changing the form of interactive REPL like this could be a downside for some output.calva-repl interactive REPL users who mostly evaluate forms there instead of directly in the editor. So I'm not sure it's a good idea. But trying to achieve "true append" probably is and perhaps it could be done even with current behavior somehow.

This is basically the idea for how it can/should work 😃 , except maybe not with an editor/file, as Peter mentioned.

The real fix here is probably to offer a way to output stdout to some other place than the REPL window.

I think the issue is pretty common without involving stdout output, and instead just with evaluation results, though that still could be a useful feature if someone wants to have high volume streaming stdout output.

bpringe avatar Aug 03 '23 00:08 bpringe

I can screen shot next time it happens, but its something like "trying to save, waiting on calva".

I've not seen this before. I'm also on MacOS. A screenshot would be nice.

bpringe avatar Aug 03 '23 00:08 bpringe