custom debugger hooks cannot run in the context of baking a REPL into a game loop

[mfiano]

With the new feature committed as per #323, it is no longer possible to install a custom debugger hook by binding *debugger-hook*. It looks like the support for this is calling the hook passed into the hook which is not correct. With this code, the code gets stuck in Sly's hook and never enter's the users, when the REPL is inside of a game loop. I think users can only install a hook for Sly's hook, which might not even work...I'm not sure.

For what it's worth, I wanted to create a debugger hook of my own in my game engine, so that I could track the timestamp the debugger was entered, in order to restore game physics correctly. This just doesn't work since this commit.

[joaotavora]

Can you show a snippet of code with a mock display loop that exemplifies this?

[mfiano]

Tried to make this brief, but it sort of exploded. Let me know if anything is unclear. The point here, is that my custom debugger hook is never used, and therefor the condition (when debugger-entry-time ...) is always nil.

(in-package #:cl-user)

(defparameter *running-p* nil)
(defparameter *init-time* 0d0)
(defparameter *running-time* 0d0)
(defparameter *pause-time* 0d0)

(defmacro with-continuable (report &body body)
  `(let* ((debugger-entry-time nil)
          (previous-hook *debugger-hook*)
          (*debugger-hook*
            (lambda (condition hook)
              (declare (ignore hook))
              (setf debugger-entry-time (get-time))
              (when previous-hook
                (funcall previous-hook condition previous-hook)))))
     (restart-case (progn ,@body)
       (continue ()
         :report ,report
         (when debugger-entry-time
           (setf *pause-time* (- (get-time) debugger-entry-time)))))))

(defun get-time ()
  (multiple-value-bind (s us) (sb-ext:get-time-of-day)
    (+ (- s *init-time*) (/ us 1d6))))

(defun main-loop ()
  (loop
    initially
       (princ "Starting our game")
       (slynk-mrepl:send-prompt)
    while *running-p*
    do (with-continuable "Custom continue"
         (princ #\.) (force-output)
         (sleep 0.4)
         (slynk:process-requests t)
         (setf *running-time* (- (get-time) *pause-time*)
               *pause-time* 0d0))))

(defun start ()
  (setf *running-p* t
        *init-time* (sb-ext:get-time-of-day))
  (slynk-mrepl:send-prompt)
  (main-loop))

(defun stop ()
  (setf *running-p* nil))

[joaotavora]

I still you're still editing, I'll leave you to it for a while...

[mfiano]

@joaotavora done now...one small correction

[mfiano]

Well debugger-entry-time would have been nil if I didn't make its initial binding 0d0...fixed

[mfiano]

And for whoever is wondering, this issue is sort of a huge deal for game development. If the engine is unable to detect how much time was spent in the debugger, then game developers might as well forget interactivity and restart their game every time it pops up. The reason why, is upon resuming with the custom continue restart, physics bodies may go through walls, etc, due to the large jump into the future.

[joaotavora]

I had to edit your recipe, since in the main loop you need to first send a REPL prompt. Otherwise the whole thing doesn't work. Also, I see your custom debugger hook being called. I'm not sure you should be doing the previous-hook trick though. That was a dirty trick that I would reserve for the SLY REPL's internals.

[joaotavora]

previous-hook trick though. That was a dirty trick that I would reserve for the SLY REPL's internals.

Maybe we do need something of the sort. I took it out and it stopped working, so I'm still working on this and will come back with the definitive recipe.

[joaotavora]

That said, your code (as fixed minimally) seems to be working, I do get a report of the "debugger pause time". Here's my version which displays that:

(defmacro with-continuable (report &body body)
  `(let* ((debugger-entry-time nil)
          (previous-hook *debugger-hook*)
          (*debugger-hook*
            (lambda (condition hook)
              (declare (ignore hook))
              (format t "~&Hey I'm being called, then maybe calling ~a~%" previous-hook)
              (force-output)
              (setf debugger-entry-time (get-time))
              (when previous-hook
                (funcall previous-hook condition previous-hook)))))
     (restart-case (progn ,@body)
       (continue ()
         :report ,report
         (when debugger-entry-time
           (setf *pause-time* (- (get-time) debugger-entry-time))
           (format t "~&Spent ~a in the pause~%" *pause-time*))))))
``

[mfiano]

I had to edit your recipe, since in the main loop you need to first send a REPL prompt.

send-prompt is called before the loop, in the start function. Now it's send-prompt, princ, send-prompt, loop.

Maybe we do need something of the sort. Here's my version which displays that:

I'll investigate later today, thanks for hacking.

[mfiano]

That said, your code (as fixed minimally) seems to be working, I do get a report of the "debugger pause time". Here's my version which displays that:

I tried your changes, and all I get is a series of dots printed out, no "Hey I'm being called" when entering or leaving the debugger, over multiple attempts.

Edit, my mistake. Something does seem to be letting it work now.

@Zulu-Inuoe who originally wrote this code for my game engine mentioned this to me about why it wasn't working:

it was my understanding the problem was not in how Sly does the debugger hook, but that it has no hook for when it's about to enter the debugger

He seems to be busy with work lately, so he might not be able to respond for some time with more insight into this.

[joaotavora]

Okay. And sorry, I didn't notice the send-prompt you already had there. I just invoked main-loop directly.

[mfiano]

If you want to ignore this issue for now, I'm fine with that. I'm also experiencing non-deterministic results as you had earlier. I just don't understand any of this.

[joaotavora]

I'm also experiencing non-deterministic results as you had earlier. I just don't understand any of this.

Okay, but I didn't experience any non-deterministic results, I think :-)

[mfiano]

In any case I appreciate looking into it. I'll put it to the side for now and move onto other tasks. Feel free to keep looking into it, or label it as "not a bug", either is fine by me. It's hard to say for me, and I spent too much time on this without getting very far :)

[joaotavora]

By the way

it has no hook for when it's about to enter the debugger

An easy solution to this might be to make this, sure. But I guess your previous idea should also work (and in my testing, it does).

[Zulu-Inuoe]

The trouble with trying to leverage *debugger-hook* is that by definition, it is meant to handle the debugger interactions itself.

What is desired: A way to track when the debugger is entered, so that the continue restart can calculate a time delta. What is offered by *debugger-hook*: A way to fully control the debugger, or yield (by calling the previous hook).

So I don't think the sly debugger hook is doing anything wrong. It can't call the previous hook, since then it'll get dumped into the SBCL debugger. But I -think- this could be best solved by having a slynk:*about-to-enter-debugger-hook*, if that is a feature that's worthwhile to add.

And just my two cents would be to make that a list, ala elisp hooks.

[joaotavora]

The trouble with trying to leverage debugger-hook is that by definition, it is meant to handle the debugger interactions itself.

Well said, this is absolutely true. A debuggers purpose is to either interactively help the user or automatically choose a restart, it's definitely not meant for this trickery.

But it doesn't quite mean that this trickery isn't defined to be workable and in my tests it does work. I still have to test more though.

But I -think- this could be best solved by having a slynk:about-to-enter-debugger-hook, if that is a feature that's worthwhile to add.

I agree. I'll probably add one of these hooks,

[mfiano]

While it is trickery, there isn't much else I can do if I want total interactively developed video games. Everything being live-recompilable helps a lot, but also gives rise to runtime conditions due to mistakes. :)

The alternative is to assume the physics is garbage and restart the application when the debugger is invoked. I think this trickery is well within the flexibility of the language :)

[mfiano]

Also, I did some more testing with the latest snippet above, and it seems to work 100% of the time now. I'm not sure why it wasn't working before, and pretty random when it did. I will be keeping an eye on it, but it seems like this is solved.

[joaotavora]

OK. I will try to put this into the manual's example, too. By the way I thought about this some more and I don't think it's "trickery" at all. The previous-hook technique is valid. It just means that you're delegating the handling of the error to whomever was about to do it before you.

[Zulu-Inuoe]

So if I'm understanding correctly, this works even for errors raised by the sly REPL? eg inside of (slynk:process-requests t)

Maybe I misunderstood, but I thought the problem was that inside of slynk:process-requests down the callstack there was a binding of *debugger-hook*, which would take over presenting the Sly debugger, and not calling the one established by with-continuable.

[joaotavora]

So if I'm understanding correctly, this works even for errors raised by the sly REPL? eg inside of (slynk:process-requests t)

I don't know exactly what you mean with "by the sly REPL". If you mean errors resulting from the evaluaiton of users' code in that REPL, then yes, it does.

I pushed a commit that fixes some other edge cases related to such "nested REPLs" but it doesn't change the fact that your attempt, as explained by @mfiano in his snippet, already worked. However, I have a suggestion. Instead of making that a restart, you could just use unwind-protect. So here's a general purpose macro that records the time spent in the debugger, in any situation:

(defun call-recording-debugger-time (fn)
  (let* ((debugger-entry-time nil)
         (previous-hook *debugger-hook*)
         (*debugger-hook*
           (lambda (condition hook)
             ;; Remember: this lambda may be called many times within
             ;; the same stack frame of CALL-RECORDING-DEBUGGER-TIME.
             ;; That is if the user is playing around with restarts,
             ;; for example.  We don't want to clobber the debugger
             ;; entry time because of that.
             (unless debugger-entry-time (setf debugger-entry-time (get-time)))
             (when previous-hook
               (unwind-protect
                    ;; Maybe we could bind *DEBUGGER-HOOK* to HOOK
                    ;; here, too (as suggested in the CHLS), but It
                    ;; would only make a difference if the
                    ;; PREVIOUS-HOOK where to error, which we don't
                    ;; expect it to.  And at any rate, our
                    ;; time-recording debugger wouldn't be of any
                    ;; help there, anyway.
                    (funcall previous-hook condition previous-hook)
                 (format t "~&Spent ~a in the pause~%"
                         (- (get-time) debugger-entry-time)))))))
    (funcall fn)))

(defmacro recording-debugger-time ((&rest options) &body body)
  "A time-recording pseudo debugger hook.
Pseudo in the sense that it records some useful information which is
the time spent choosing a restart, but it does not by itself choose
one of those restarts."
  (declare (ignore options))
  `(call-recording-debugger-time (lambda () ,@body)))

[Zulu-Inuoe]

If you mean errors resulting from the evaluaiton of users' code in that REPL, then yes, it does.

Yes, that's what I meant

Ah okay, I looked at the commits and didn't see anything so I was confused. Not to mention, it doesn't help that I had an older version of Slynk when looking at the code the other day, so I was extra confused.

Thanks!

[joaotavora]

you could just use unwind-protect

Unless you're interested in a restart that does some corrections based on the time spent in the debugger. But in that case it's better to compose (a variation of) my macro with that time-correcting restart.

[mfiano]

I have a question. In my game engine, I have two callsites for with-continuable: one around the iteration of the main game loop, and another one around the call to handle-requests. It looks like livesupport does the same thing: https://github.com/cbaggers/livesupport/blob/master/livesupport.lisp#L48

This doesn't seem to be needed, but I haven't tested, since handle-requests is called during the main loop.

[joaotavora]

I haven't analysed extensively, but I'd say none of that livesupport.lisp is needed. At any rate, continuable is better written as (with-simple-restart (continue "Continue skipping the rest of XYZ") <xyz>) IMO. I do agree that to make a game's debugging compatible with both SLIME and SLY a compatibility package may be neded. But in SLY, the rules are rather simple:

1. Send a prompt the first time
2. Serve any pending requests with (process-requests t) at every step in the game loop

Everything else, restarts for skipping parts of the game loop or for skipping over an errored manual request, are pure CL. Here' s the example I put in the documentation a while back:

(defun my-repl-aware-game-loop ()
  (loop initially
          (princ "Starting our game")
          (slynk-mrepl:send-prompt)
        for i from 0
        do (with-simple-restart (continue "Skip rest of this game loop iteration")
             (when (zerop (mod i 10))
               (fresh-line)
               (princ "Doing high-priority 3D game loop stuff"))
             (sleep 0.1)
             ;; When you're ready to serve a potential waiting 
             ;; REPL request, just do this non-blocking thing:
             (with-simple-restart (abort "Abort this game-REPL evaluation")
               (slynk:process-requests t))
             ;; If the user selected the above abort, code continues here
             (when (zerop (mod i 10))
               (fresh-line)
               (princ "More incredibly complex game stuff")))))

As you can see, you're given two separate restarts. The names are just conventions (though they do play together with keybindings in the debugger).

[mfiano]

I see. In my case, I don't think I want such a thing. I want a single restart that can be used to skip the rest of the game loop iteration, and one that tracks any time spent in the debugger. Using another restart inside of the repl-tracking restart would not accomplish this after cursory testing.

The single restart would be invoked due to game loop logic errors, or the user evaluating something in the REPL, since the repl is also running in the game loop.

[mfiano]

As a side note, does Sly have any way to have my custom restart be selected with Sly's debugger keybindings? c for my custom continue restart, rather than the default?

[joaotavora]

I see. In my case, I don't think I want such a thing. I want a single restart that can be used to skip the rest of the game loop iteration, and one that tracks any time spent in the debugger. Using another restart inside of the repl-tracking restart would not accomplish this after cursory testing.

More restarts don't hurt, generally. They just give you more control options.

As a side note, does Sly have any way to have my custom restart be selected with Sly's debugger keybindings? c for my custom continue restart, rather than the default?

yes, c should select the innermost restart named CL:CONTINUE and a should select the innermost restart named CL:ABORT. q has recently been changed from sly-db-quit to sly-db-abort, i.e. it does the very same thing as a. This is because q was often mistyped by some people and led to tearing down the thread by mistake.

[joaotavora]

If you need to track time spent in the debugger inside any arbitrary span of code, use the macro (or a variation thereof) that I gave you. Does livesupport.lisp do that for you automatically?

[mfiano]

This is because q was often mistyped by some people and led to tearing down the thread by mistake.

Oh that is awesome. I have steered away from using that in other codes because of that.

[joaotavora]

Anyway, a point here is that restarts and time-tracking debuggers aren't necessarily linked, unless you want to do a restart that does something with the time information just before transferring control non-locally to some other point. But that should be done by composition, I think, not by interlinking the two concepts in the same macro.

[mfiano]

If you need to track time spent in the debugger inside any arbitrary span of code, use the macro (or a variation thereof) that I gave you. Does livesupport.lisp do that for you automatically?

Will do. I do not personally use livesupport, but a similar portability wrapper with different domain-specific code, such as the use of Sly's recent send-to-repl support, with a graceful fallback on SLIME or no backend.

By the way, can you merge that branch? It is highly useful and have tested it for a month or more without issues.

[joaotavora]

What branch?

[mfiano]

scratch/345-copy-to-repl-in-emacs

[joaotavora]

OK, done. I'd forgotten about it

[mfiano]

Thanks. I had a few people wanting to try it when it lands in master. I'll let them know now.

I appreciate all the information in this thread. It was incredibly helpful. Thank you both for your time on this matter.

[mfiano]

yes, c should select the innermost restart named CL:CONTINUE

This does not seem to be the case. I issue c with the latest snippet above, and it attempts to call the [CONTINUE] Retry using ... restart and not the continue restart established with restart-case.

So it never leaves the debugger, and just attempts to re-evaluate the form.

[joaotavora]

Well, is your restart the innermost one (topmost in the stack of restarts) and named CL:CONTINUE? SBCL makes some restarts for "trying again" with undefined variable names, which might clobber that (but that's not's SLY's fault). Other more realistic errors won't have these kinds of "continue" restart, like say, trying to add a numer and a string with CL:+.

Play around with this:

(restart-case
             (restart-case
                 (+ 42 "42")
               (continue ()
                 :report "never mind this was stupid"
                 (format t "~&Yes, it was~%")))
           (continue ()
             :report "stop this charade altogether"
             (format t "~&OK man, just an example~%")))

If this doesn't suit you, you can name your restart ABORT, for "aborting" the game loop iteration, and again, if it's the topmost it'll call that. You can also invoke restarts by number.

[mfiano]

Great, thank you. Using abort works and makes more sense, and can have a description denoting it's aborting the currently executing game frame. Thanks again

[joaotavora]

Common Lisp's quite the language, hey? ;-)

[mfiano]

Ain't that the truth. Sly makes it so much better than with even SLIME at that. :)

[joaotavora]

I'd love to play one of these games by the way, very very curious

[mfiano]

Well, after 10 years of writing a game engine, I have recently only just began writing a game. It may be a while, but I'll be sure to let you know when it's ready to be played.

[joaotavora]

:+1: let me know. Maybe I'll try to join the the next game jam. I know very little. Are there teams? I want to be on yours! :-)

[mfiano]

Haha, I haven't actually ever participated, despite organizing the jam. Mostly because I have been so focused on a game engine, and I only have a few game ideas that aren't really scoped small enough for a jam :)

Teams are optional. The last jam just finished the other day. The next one will be in April.

[mfiano]

Anyway, I am still on Freenode if you want to talk about it. Our engine dev channel is #bufferswap. Feel free to join if you are interested in the stuff we are working on.