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.

Sign up for GitHub

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

Jump to bottom

Handle recursive-edit (fixes debugger, and other things) #47

Closed
lastquestion opened this issue Jul 1, 2020 · 4 comments · Fixed by #42
Closed

Handle recursive-edit (fixes debugger, and other things) #47

lastquestion opened this issue Jul 1, 2020 · 4 comments · Fixed by #42
Projects
Explain-pause-mode

Comments

@lastquestion
Copy link
Owner

in #42 we started recording time via call-interactively and making a call stack, versus attempting to measure via pre-/post-command hooks. This is way more accurate, but recursive-edit breaks it. This is used by debug which can confuse the call stack tracking.

Fix and add a test by advising recursive-edit in some way, if possible.
@lastquestion
Copy link
Owner Author

Notes:

C layer

  • minibuf.c calls recursive_edit_1
  • keyboard.c has lots of recursive_edit stuff and defines recursive-edit and recursive_edit_1
  • emacs.c calls Frecursive_edit e.g via LISP

recursive_edit_1

  • Just calls command_loop like normal which ultimately calls call-interactive so that's OK from native C.
    This means that we already do the right thing subtracting out any further commands that are run, but sitting there with no actions just adds executing time to the debugged command.
  • Call from minibuf.c is from read_minibuf which is how minibuffers are entered. We've already advised all entries into minibuffer so that's OK from native C.

recursive_edit

  • Just calls recursive_edit_1
  • Is called from main in emacs.c as Frecursive_edit, but that's too early to ever catch. Anyway that just starts a commandloop which we already model via root-emacs.

elisp layer

20 calls to recursive-edit in some major packages and modes

finish via:

  • throw 'exit
    • throw t to get to top-level, e.g.
  • abort-recursive-edit C code "abort the command that caused this recursive edit OR ** minibuffer edit **"
  • exit-recursive-edit C code "exit"

abort-recursive-edit

  • never called via C
  • Just throws 'exit 't

exit-recursive-edit

  • never called via C
  • Just throws 'exit nil

@lastquestion
Copy link
Owner Author

lastquestion commented Jul 1, 2020 •
edited

To investigate:

  • Advise unwind-protect code needs special case to handle the exit conditions and record what's going on. If we throw out to top level, we need to unwind our own stack all the way out to root-emacs.
  • How does this interact with timers?? When timers fire and filters fire, what happens when you abort and exit??
  • If I exit-recursive-edit from another function inside call-interactively, the code should catch the error, unwind-protect out the first call, let elisp jump to the actual handler, and then unwind-protect our way if it's not to top level. Test.

@lastquestion
Copy link
Owner Author

Everything works normally. throw 'exit t ends up unwinding as expected to the function call site, and then quit is thrown, and the stack unwinds with the unwind protects we already have to get back to top-level. I think a regular native-wrap is sufficient.

@lastquestion
Copy link
Owner Author

When you're in recursive edit, we refuse to install explain-pause-mode, which makes sense. Adjust the messaging.

lastquestion added a commit that referenced this issue Jul 3, 2020
@lastquestion
Advise call-interactively; add streaming logging; move profiles to …
36b9b71 
…`explain-pause-top`; add integration & regression tests (#42)

* Advise `call-interactively`; add streaming logging; move profiles to `explain-pause-top';
performance improvements; handle recursive timers

> call-interactively
In #26, it turns out that hooking `pre-command-hook` is rife with troubles, because
elisp can call it and we cannot be sure that the calls are matched. After a lot of
thought, instead redesign the measurement engine to advise `call-interactively` instead.
This gives much more accurate data for minibuffer, so we don't need the minibuffer
hooks either. This work also fixes #18, because now `call-inteactively` time spent
in native waits for keyboard input (from interactive specs) are excluded.

To do this, this PR introduces proper frame records and stack. I have some concern
about the memory usage of this and how well the GC collects the unused branches of
the tree.

Native frames are inserted whenever elisp is going to call into anything that might
wait for keyboard or user input. They are also inserted in between timers and
their callbacks, so that in all cases, native wait code has a parent frame to
subtract time from. This resolves #31 as well.

> streaming logging
This change is very large and rebuilds the measurement engine completely. In order
not to regress existing bug fixes and also newly fixed bugs, a integration test
suite that runs emacs in interactive mode is going to be needed. To enable this,
streaming logging of the command records entry/exit/profile/measurement is added
to a UNIX socket. The major intent of this is to enable diffing of measurement
engine behavior in tests, but it will also allow for out of process visualization
of emacs, which will be really useful when GC or blocking stuff happens; you can't
see what's actually running right now because we're inside the same process, of
course.

> Move profiles to `explain-pause-top` and remove `explain-pause-log` and
`explain-pause-profiles`
The log isn't actually super useful and the UX is not great for it anyway. Since
the measurement engine rebuilds the command hook API, I took this chance to fix
the display engines as well. Remove `explain-pause-log` and `explain-pause-profiles'
as well. Instead, profiles are displayed directly in `explain-pause-top`. Now the
limit of profiles applies per command. When `explain-pause-top` is first open,
it backfills from the profiling statistics so even if you didn't have it open, it
still knows about slow commands. Currrently, I don't have a good UX for native
frames yet, so they are hidden from the top view. Fixes #39.

Also, while doing this, I had to move the click handlers, so add a new defcustom
to allow customization of what actually happens when the profile button is clicked.
Fixes #16.

`explain-pause-top--table` is extended even more to be even more generic and handle
multiple extra lines of full width text after the column header line.

This removes the now unused logging `defcustoms`.

> Performance improvements to `explain-pause-top`
Generally, opt to preallocate vectors of strings and try moderately hard not to
allocate memory during refreshes. Also, move to a more consistent double buffering
algorithm, which is where we were going anyway. Now we flip between two sets of
cached data, which allows re-use of strings even if the entries have moved in
order. This also simplifies the code. In tight loops, move let bindings outside
the loop, to save on frame allocations.

Also, use a recursive timer instead of a interval timer because interval timers
will reschedule repeatedly after a delay, and this is not configurable via a
binding like I thought before. See emacs bug #41865.

> Handle recursive timers
If a timer reschedules itself by calling `run-with-timer` within itself, the command
stack grows indefinitely and will run out of memory eventually. Fix this by reusing
the native command frame if possible; if not, after a certain depth - 64,
`explain-pause--timer-frame-max-depth`, not configurable - just reparent the entire
stack to root-emacs.

> Profiling edge cases
If a command is marked for  profiling, but fails to actually save the profile, e.g. it isn't 
slow, for `explain-pause-profile-slow-threshold` times, reset the profiling request 
and start over.

> Full integration tests 
These run emacs in tmux so we can press keys and fully simulate a user. Use the 
event logging stream to connect to the driver, which is also written in elisp. Drive 
the driver via Make. Add test cases for most existing (fixed) bugs that are not 
covered at unit test layer.

> Bug fix for #46: Return the original wrapped sentinel/filter function when 
requested.

When we wrap a process filter or sentinel, we end up putting in a lambda into the
actual process. If later, `process-filter` is called to get the filter out, eq 
comparisons that used to work will fail.

Store the original callbacks into the process object so we can hijack 
`process-filter` to return the original. Fixes #46. Originally found from `magit`, in 
`with-editor`, in `with-editor-set-process-filter`.

> Advise x-popup-menu; add a test for it.
> Advise recursive-edit; add a test for it. Fixes debugging and #47 
> Add a bytecode compile target to make and fix all warnings.
@lastquestion lastquestion linked a pull request Jul 3, 2020 that will close this issue
Advise call-interactively; add streaming logging; move profiles to explain-pause-top; add integration & regression tests #42
Merged
5 tasks
@lastquestion lastquestion added this to To do in Explain-pause-mode via automation Jul 3, 2020
@lastquestion lastquestion moved this from To do to Done in Explain-pause-mode Jul 3, 2020
@lastquestion lastquestion mentioned this issue Jul 5, 2020
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
Explain-pause-mode
  
Done
Milestone
No milestone
1 participant
@lastquestion