positron icon indicating copy to clipboard operation
positron copied to clipboard

Some R commands are skipped when executing multiple commands after each other

Open LanderDC opened this issue 1 year ago • 5 comments

Positron Version:

Positron Version: 2024.07.0 (Universal) build 67 Code - OSS Version: 1.91.0 Commit: 58e22e191273c6fcb403c458ddb3088b0b80dcd0 Date: 2024-07-18T04:44:17.582Z Electron: 29.4.0 Chromium: 122.0.6261.156 Node.js: 20.9.0 V8: 12.2.281.27-electron.0 OS: Darwin x64 23.5.0

Steps to reproduce the issue:

Running multiple commands after each other with Cmd + Enter from an Rscript (without waiting for them to finish), skips the execution of some commands, giving errors downstream. It sometimes even seems that multiple commands are running at the same time.

In the screenshot below you can see the order in which I executed the commands (script) and the output of the console showing which commands ran (white) and which didn't (grey). afbeelding

What did you expect to happen?

I expected a similar behaviour as Rstudio where you can execute commands from an Rscript, while another command is still running, that are put into a "queue" and executed in order.

Were there any error messages in the Output panel or Developer Tools console?

No

LanderDC avatar Jul 18 '24 13:07 LanderDC

Can you please paste the code that you ran in as text so it is easy for us to try?

DavisVaughan avatar Jul 18 '24 13:07 DavisVaughan

The screenshot was from a script with my own data, but here is the same code with an example dataset, which also behaves funky:

library(tidyverse)
library(phyloseq)
library(decontam)
data(GlobalPatterns)

sample_data(GlobalPatterns)

#' ### Remove contamination
#' #### Visualize library sizes of samples and negative controls
decontam <- as.data.frame(sample_data(GlobalPatterns))
decontam
decontam$LibrarySize <- sample_sums(GlobalPatterns)
decontam <- decontam[order(decontam$LibrarySize),]
decontam$Index <- seq(nrow(decontam))
ggplot(data=decontam, aes(x=Index, y=LibrarySize, color=SampleType)) + 
  geom_point()+
  ggtitle("Library sizes")

ggplot(data=decontam, aes(y="libraries", x=LibrarySize, color=SampleType)) + 
  geom_jitter(height = .01)+
  scale_x_log10()+
  ggtitle("Library sizes")

#' #### Detect contaminants
sample_data(GlobalPatterns)$is.neg <- sample_data(GlobalPatterns)$SampleType == "Mock"
sample_data(GlobalPatterns)$is.neg
contamdf.prev <- decontam::isContaminant(GlobalPatterns, method="prevalence", neg="is.neg")


#' **Number of contaminating contigs:**
table(contamdf.prev$contaminant)

contaminants <- rownames(contamdf.prev[contamdf.prev$contaminant==T,])

FYI, first selecting all code that needs to be run and then Cmd+Enter does not give any issues.

LanderDC avatar Jul 18 '24 14:07 LanderDC

Okay I was able to reproduce. It does look like if you hit CMD + Enter really really fast and there is some longer running code involved (like loading these large packages) then it is possible for a line to get dropped. That's not great!

library(tidyverse)
library(phyloseq)
library(decontam)

x <- 1
y <- x
z <- y
a <- z

Note that I am mashing CMD + Enter as fast as I can to get this to occur

https://github.com/user-attachments/assets/b9150adb-79fb-43a8-bb4b-dda476951283

DavisVaughan avatar Jul 18 '24 14:07 DavisVaughan

That's exactly what I'm seeing. I would say that if there is code that runs longer than a few seconds, a "normal" speed of Cmd + Enter is enough to trigger this behaviour.

LanderDC avatar Jul 18 '24 14:07 LanderDC

I believe this is also coming up for folks when they do something like "Run Above" in a Quarto doc: https://github.com/posit-dev/positron/discussions/4104

juliasilge avatar Jul 22 '24 17:07 juliasilge

Another example with "Run above" in a Quarto document: #4231

juliasilge avatar Aug 05 '24 19:08 juliasilge

I've got a pretty good idea of what the problem is here, but I could use some advice on the best way to solve this kind of thing.

I think the crux of the issue is this await right here, which allows execution to jump out of this function and can allow for out of order execution:

https://github.com/posit-dev/positron/blob/5c0e59335c9e5de714d387f1e87f0a3d8eeafcc8/src/vs/workbench/services/positronConsole/browser/positronConsoleService.ts#L1950

Imagine that we have a this._runtimeItemPendingInput containing this code, and lets call it chunk A

library(tidyverse)
library(phyloseq)
library(decontam)

x <- 1
  • In processPendingInput() for chunk A, we set this._runtimeItemPendingInput = undefined to declare we are handling it
  • In processPendingInput() for chunk A, we call await this.session.isCodeFragmentComplete(codeFragment); to determine if a fragment of chunk A is complete
  • This await allows execution to switch out of this function, in particular addPendingInput() is allowed to run and:
  • In addPendingInput(), it sees this._runtimeItemPendingInput is undefined and creates a new pending input item, with, say, chunk B, and sets this._runtimeItemPendingInput
y <- x
z <- y
  • In processPendingInput() for chunk B, we do the same dance as above but with chunk B. Set this._runtimeItemPendingInput = undefined and call await this.session.isCodeFragmentComplete(codeFragment); but with chunk B fragments. This switches us back to chunk A control flow.
  • In processPendingInput() for chunk A, we find that library(tidyverse) is a complete statement and plan to execute it, but first we set this._runtimeItemPendingInput to the remaining lines in that chunk. Then we execute library(tidyverse).
  • Then we switch back to processPendingInput() for chunk B, where it finds y <- x as a complete statement and tries to evaluate that, but BOOM that is an out of order code execution.

https://github.com/posit-dev/positron/blob/5c0e59335c9e5de714d387f1e87f0a3d8eeafcc8/src/vs/workbench/services/positronConsole/browser/positronConsoleService.ts#L1856-L1880

https://github.com/posit-dev/positron/blob/5c0e59335c9e5de714d387f1e87f0a3d8eeafcc8/src/vs/workbench/services/positronConsole/browser/positronConsoleService.ts#L1973-L1982

This theory is supported by some console logs, which added logs right before and after that await, where you can see execution switch away. Look at Checking if fragment is complete from processPendingInput(): library(decontam) and then look how Finished checking if fragment is complete from processPendingInput(): library(decontam) is many lines down the page because of the await.

Screenshot 2024-08-05 at 5 05 31 PM

DavisVaughan avatar Aug 05 '24 21:08 DavisVaughan

Verified Fixed

Positron Version(s) : 2024.08.0-24
OS Version          : OSX

Test scenario(s)

Unable to repro manually after many tries. Was able to repro manually with previous release:

library(tidyverse) library(arrow) library(RSQLite)

x <- 1 y <- x z <- y a <- z b <- a c <- b

Link(s) to TestRail test cases run or created: Automated test in progress

testlabauto avatar Aug 09 '24 15:08 testlabauto