emacs-ess / ESS

Emacs Speaks Statistics: ESS
https://ess.r-project.org/
GNU General Public License v3.0
622 stars 162 forks source link

after turning off tracebug, in debugging, ESS continues to send <newline> to R. #973

Open mmaechler opened 4 years ago

mmaechler commented 4 years ago

Because of the source(*, echo=TRUE) breaking bug, I've turned off tracebug completely in ESS for the time being. Now, e.g.,

debug(ts)
ts(1:100, start = as.Date("2019-12-12"), frequency=12)

(which reveals a bug in current R-devel from one my own recent commits !), then in the debugger, typing 'n', occasionally inspecting variables, or typing ls.str(), I several times have ESS sending <newline> or <enter> to R "behind my back"; here's part of a transcript (using R 3.6.2 where ts() does not show any bug, of course):

debugging in: ts(1:100, start = as.Date("2019-12-12"), frequency = 12)
debug: {
    if (is.data.frame(data)) 
        data <- data.matrix(data)
    if (is.matrix(data)) {
        nseries <- ncol(data)
        ndata <- nrow(data)
        dimnames(data) <- list(NULL, names)
    }
    else {
        nseries <- 1
        ndata <- length(data)
    }
    if (ndata == 0) 
        stop("'ts' object must have one or more observations")
    if (missing(frequency)) 
        frequency <- 1/deltat
    else if (missing(deltat)) 
        deltat <- 1/frequency
    if (frequency > 1 && abs(frequency - round(frequency)) < 
        ts.eps) 
        frequency <- round(frequency)
    if (length(start) > 1L) {
        start <- start[1L] + (start[2L] - 1)/frequency
    }
    if (length(end) > 1L) {
        end <- end[1L] + (end[2L] - 1)/frequency
    }
    if (missing(end)) 
        end <- start + (ndata - 1)/frequency
    else if (missing(start)) 
        start <- end - (ndata - 1)/frequency
    if (start > end) 
        stop("'start' cannot be after 'end'")
    nobs <- floor((end - start) * frequency + 1.01)
    if (nobs != ndata) 
        data <- if (NCOL(data) == 1) {
            if (ndata < nobs) 
                rep_len(data, nobs)
            else if (ndata > nobs) 
                data[1L:nobs]
        }
        else {
            if (ndata < nobs) 
                data[rep_len(1L:ndata, nobs), ]
            else if (ndata > nobs) 
                data[1L:nobs, ]
        }
    attr(data, "tsp") <- c(start, end, frequency)
    if (!is.null(class) && class[[1]] != "none") 
        attr(data, "class") <- class
    data
}
Browse[2]> n
debug: if (is.data.frame(data)) data <- data.matrix(data)
Browse[2]> n
debug: if (is.matrix(data)) {
    nseries <- ncol(data)
    ndata <- nrow(data)
    dimnames(data) <- list(NULL, names)
} else {
    nseries <- 1
    ndata <- length(data)
}
Browse[2]> ls.str()
class : <missing>
data :  int [1:100] 1 2 3 4 5 6 7 8 9 10 ...
deltat :  num 1
end :  num(0) 
frequency :  num 12
names : <missing>
start :  Date[1:1], format: "2019-12-12"
ts.eps :  num 1e-05
Browse[2]> debug: nseries <- 1
Browse[2]> n
debug: ndata <- length(data)
Browse[2]> n
debug: if (ndata == 0) stop("'ts' object must have one or more observations")
Browse[2]> debug: if (missing(frequency)) frequency <- 1/deltat else if (missing(deltat)) deltat <- 1/frequency
Browse[2]> missing(start)
[1] FALSE
Browse[2]> debug: if (missing(deltat)) deltat <- 1/frequency
Browse[2]> 

note in the last 6-7 lines above, that two of them have debug: <.. R code ..> and these were caused by ESS entirely, without me any typing at all; so there were line advances that I did not cause by typing Enter (aka "return" aka "newline") or n at all.

mmaechler commented 4 years ago

can anybody reproduce, please? NB I have the following in my ~/.emacs initialization before loading ess :

;;MM_2019-12-13: ess-tracebug 
;;MM_2019-12-13: invalidates source(*, echo=TRUE) and confuses me more than it helps
(setq ess-use-tracebug nil); default is 't'

the behaviour super frustrating to such an extent that I sometimes need to start an R session outside of ESS (which I then do in a *shell* buffer, so I can at least use comint-style navigation) just so I can debug properly.. and yes, as an R Core member I do need to carefully debug frequently..

jabranham commented 4 years ago

Yes, I can reproduce. Haven't had time to investigate yet. If you run into this you could always temporarily enable tracebug (C-c C-t T in the inferior buffer).

vspinu commented 4 years ago

I cannot reproduce unfortunately. With or without tracebug. When I press RET repeatedly stepping happens one by one as expected.

jabranham commented 4 years ago

For me the newline is sent as soon as a type a character, not press RET

On Sun 23 Feb 2020 at 12:14, Vitalie Spinu notifications@github.com wrote:

I cannot reproduce unfortunately. With or without tracebug. When I press RET repeatedly stepping happens one by one as expected.

mmaechler commented 4 years ago

exactly! For me, it only happens once in a while (it seems), not every time... but it's a "killer": If I debug (traditionally, not with tracebug ESS support), I want to use ls.str() {I had added that to R for debugging !}, inspect variables, run some small pieces of code, etc etc.. and then the debugger advances too far, e.g., causing the error I want to debug.. and I'm out of the debugging session. It's really a very awful experience. And remember: I'm debugging sometimes very basic R functions {some of which are called by your tracebug "craft"}, so I do need to be able to run the debugger as in an R console, and not as in a tracebug-smartified-I-know-better-what-you-want-than-yourself R console...

vspinu commented 4 years ago

I am pretty sure that this is not caused by tracebug in your case. Once you disable it with M-x ess-tracebug there is no way any of the process related ess "goodies" should get in your way, simply because all of them happen in inferior-ess-tracebug-output-filter.

You can check it at any time with M-: (process-filter (ess-get-process)) RET. Without tracebug it's our plain inferior-ess-output-filter.

mmaechler commented 4 years ago

There is even more going badly wrong in R's debug() / debugonce() mode, when ess-tracebug is turned off. As we've seen there are good reasons notably for low-level developers like me to turn off tracebug. But I'm coming more and more to the conclusion that turning it off is even worse than turning it on. This is really really not tolerable: The consequence is that I have NO WAY to have R inside ESS behave like "real R". At least in Rstudio, I think I have been able to completely turn off all the hand-holding I-help-you-debugging-because-I-know-better-than-you-what-you-want.

Here's the 2nd severe problem with turned off ess-tracebug:

1) with ess-tracebug activated .. here everything is as it should be:

## ess-tracebug  activated :
> debugonce(paste); paste("a", character(), "b")
debugging in: paste("a", character(), "b")
debug: .Internal(paste(list(...), sep, collapse, zero.length))
Browse[2]> dput(list(...))
list("a", character(0), "b")
Browse[2]> c
exiting from: paste("a", character(), "b")
[1] "a  b"
> 

2) Now, with ess-tracebug mode disabled (that's the message after toggling it via M-x ess-tracebug):

## ess-tracebug disabled :
> debugonce(paste); paste("a", character(), "b")
debugging in: paste("a", character(), "b")
debug: .Internal(paste(list(...), sep, collapse, zero.length))
Browse[2]> dput(list(...))
Error in dput(list(...)) : '...' used in an incorrect context
>
mmaechler commented 4 years ago

(BTW: This bug seems to happen only for functions where body() does not start with "{" ... (that's not an excuse, but may help diagnosing)

vspinu commented 4 years ago

I cannot reproduce the second problem without tracebug. It really doesn't seem related to ESS at all.

mmaechler commented 4 years ago

This is still bugging me very regularly. And it has been reproducible by @jabranham ... I do have ess-eval-visibly set to nil (where we have nowait as default IIRC).

lionel- commented 4 years ago

@mmaechler Have you not switched to the tracebug filter, after Vitalie's fixes?

mmaechler commented 4 years ago

you mean, turned on tracebug. No, I haven't changed my non-default setting there. As I mentioned, ESS doing things on it's own (sending things to the R session) during debugging is very much a no-no for me: Often I want to debug pretty low-level stuff, and if do debug(<fn>) to a function which ESS ends up calling R with itself, the debugging is completely broken.

In other cases, debugging a function in a package of mine, e.g., I agree that ESS tracebug is nice, but indeed, I'd rather by default have full control of debugging, and not let ESS interfere with my own.

lionel- commented 4 years ago

Haven't you been using the tracebug filter for years, before switching recently? There are too many code paths in the evaluation mechanism and the default filter is not well supported and even less tested than the tracebug filter. I don't think bugs in this non-default filter should hold up the next release. It would be nice if you could try the default filter to check if the blocker issues have been fixed.

By the way, when I need a pristine environment for debugging or testing, I just use R in a terminal, perhaps with a script developed from the comfort of Emacs.

mmaechler commented 4 years ago

This (default filter) has worked nicely for decennia before the advent of tracebug; and "almost surely" for quite a bit longer: I'm almost sure I had occasionally turned off tracebug even when I had it on as per default; and only end of 2019 I had started noticing the very disruptive "sending random newline to R" behavior.

lionel- commented 4 years ago

The non-default filter is one additional code path in a very complicated mechanism, but most importantly it is not covered by unit tests. It may have worked for a long time, but until fairly recently there were zero unit tests in ESS. Because it is no longer widely used and not covered by unit tests, I worry that it might become a maintenance problem. On the other hand, it now has one ESS dev actively using it.

In any case, Vitalie has fixed the blocker issues in tracebug. Would you please try it out so we can think about a new release?

lionel- commented 4 years ago

I stand corrected! We do test the ordinary filter with with-r-running:

https://github.com/emacs-ess/ESS/blob/a7304a2788b84f93ba0c0a60e0cc7e864244e4ff/test/ess-test-r-utils.el#L194

lionel- commented 4 years ago

@mmaechler I cannot reproduce with tracebug and visibility switched off. Can you reproduce it with a vanilla Emacs? If not, could you try to pinpoint which part of your config makes it reproducible please?

lionel- commented 3 years ago

These newlines are possibly due to background tasks calling inferior-ess-available-p. This routine checks whether a process has been marked busy (i.e. there's no final prompt) and also sends a new line to double check.

lionel- commented 3 years ago

@mmaechler Can you still reproduce this? If not we can probably close this.

mmaechler commented 3 years ago

It became so extremely painful that I reverted to keep tracebug active by default and live with the drawback.. Ok, so I'll try now again to see the effect (after updating and make ing ESS ((yes, I still alway work with the *.elc ..))

lionel- commented 3 years ago

I can reproduce! I must have forgotten to turn off tracebug the last time.

The problem is that inferior-ess-available-p sends a newline to the process to double-check that it is not busy: https://github.com/emacs-ess/ESS/blob/bd87ffb1/lisp/ess-inf.el#L373-L375. This predicate is called by ess-get-next-available-process which itself is called by eldoc or completion routines. When you type n in the REPL, ESS looks for completions which triggers this newline check. Why doesn't this happen with tracebug? Because it is special-cased here: https://github.com/emacs-ess/ESS/blob/bd87ffb1/lisp/ess-inf.el#L369.

Now this newline check is normally not a problem because we have our prompts set to >. When the prompt is prefixed however, inferior-ess--set-status explicitly lets the newlines go through: https://github.com/emacs-ess/ESS/blob/bd87ffb1/lisp/ess-inf.el#L398. This means that users who have set their prompts to R> or similar must have a lot of intempestive newlines causing a mess in the output.

This check was introduced in https://github.com/emacs-ess/ESS/commit/1ff5b8c6.

Some thoughts:

I suggest trying this patch:

@@ -366,8 +366,7 @@ defined. If no project directory has been found, use
   (when-let ((proc (or proc (and ess-local-process-name
                                  (get-process ess-local-process-name)))))
     (unless (process-get proc 'busy)
-      (or (ess-debug-active-p proc) ; don't send empty lines in debugger
-          (when-let ((last-check (process-get proc 'last-availability-check)))
+      (or (when-let ((last-check (process-get proc 'last-availability-check)))
             (time-less-p (process-get proc 'last-eval) last-check))
           (progn
             ;; Send an empty string and waiting a bit to make sure we are not busy.
@@ -395,7 +394,7 @@ Return non-nil if the process is in a ready (not busy) state."
     ;; When "\n" inserted from inferior-ess-available-p, delete the prompt.
-    (when (and ready
-               (process-get proc 'availability-check)
-               (string-match-p (concat "^" inferior-ess-primary-prompt "\\'") string))
+    (when (and ready (process-get proc 'availability-check))
       (process-put proc 'suppress-next-output? t))
     (process-put proc 'availability-check nil)
     (when ready

What do you think @vspinu @mmaechler?

mmaechler commented 3 years ago

Well, I'm happy you can finally reproduce! Your patch suggestion looks very good to me (without trying it) for principal reasons (you give yourself): Less special casing i.e. more coherent behavior.... and the prompt detection business needs to become even more fail proof .. I also agree on that (says the one who's not really contributing currently apart from bug reporting... )

lionel- commented 3 years ago

Here is a reprex that we should add as unit test:

# (1) Disable the newline check
# (2) Trigger eldoc or company after evaluating this to cause a hang
{
    cat(paste0(
        "Next line looks like a prompt\n",
        getOption("prompt")
    ))
    Sys.sleep(10)
}

IIUC this is the reason that we have this newline check. It is a protection measure against what we could call "fake prompt hangs".

jkroes commented 2 years ago

I'm still seeing a lot of newlines inserted into the inferior buffer at random times when I'm not evaluating anything. Not sure whether this issue was considered resolved.