Advise call-interactively; add streaming logging; move profiles to explain-pause-top; add integration & regression tests
#42
Conversation
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
3 tasks
|
Also fixes #19, partially. I think with some small fix it should fix it for both TTY menu bar kinds. Did not test on windowed yet. |
This was
linked to
issues
Jun 13, 2020
|
lastquestion
force-pushed
the
execution-loop
branch
from
2f911d4 to
603669f
Compare
|
Rebased to get the fix in #43 in master. Also, squashed the changes so far. |
|
File notify events are sent as special key map entries in So the mismeasurement is somewhere else :-( |
2 tasks
2 tasks
|
Above PR fixes #41. Also, I discovered that repeat timers often repeat a bunch of times on mac when AppNap is enabled (which it is by default on Mac). I made a comment about this in Bug#41865 https://lists.gnu.org/archive/html/bug-gnu-emacs/2020-06/msg00651.html in GNU emacs bug list. |
…`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.
lastquestion
force-pushed
the
execution-loop
branch
from
9087a0e to
28291ed
Compare
|
Rebase to get fix for #44 and squash the history. I have been working on reducing memory allocations for the refresh handler and cleaning up the top display code. Going to add one more feature to show the times for the "slow executions" in a new line similar to profiles, clean up some more TODOs, fix some more bugs, and add the integration tests. This might be 2 more weeks at this rate... |
1. Update the profiling code to always store slow times and counts. 2. 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. 3. Update the top UI to show slow times as a similar line as profiles. 4. Generally improve memory performance by hoisting lets out of tight loops if possible, and use closure globals for anything in the measurement hooks. Still more possible work here.
Closed
3 tasks
Full integration tests that 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.
lastquestion
changed the title
call-interactively; add streaming logging; move profiles to explain-pause-topcall-interactively; add streaming logging; move profiles to explain-pause-top; add integration & regression tests
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`.
lastquestion
force-pushed
the
execution-loop
branch
from
1905bcf to
58785b8
Compare
|
The above commit fixes #46 in this branch and adds yet more tests. I'm probably not going to backport that fix. |
Also pass bytecode warnings.
Closed
Closed
|
|
lastquestion
force-pushed
the
execution-loop
branch
from
04eaf62 to
54dbc20
Compare
|
🎉 let's merge. There's a few tests I'd like to add around displaying things but I will do that in followup PRs. This will be |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
Feature complete, integration tests work, manually tested on 26 and 28, test ran on 26, 27, 28.
debuggerLarge PR to fix the measurement problem and at the same time separate the display abstractions. This thing needs:
call-interactively
In #26, it turns out that hooking
pre-command-hookis 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 advisecall-interactivelyinstead. This gives much more accurate data for minibuffer, so we don't need the minibuffer hooks either. This work also fixes #18, because nowcall-inteactivelytime 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, a new feature is added. Logs of the command records entry/exit/profile/measurement can be streamed to arbitrary 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-topand removeexplain-pause-logandexplain-pause-profilesThe 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-logandexplain-pause-profiles' as well. Instead, profiles are displayed directly inexplain-pause-top. Now the limit of profiles applies per command. Whenexplain-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--tableis extended even more to be even more generic and handle multiple extra lines of full width text after the column header line.However, this drops the "parent" stack of each command, and combines them all together at the leaf. The previous UX allowed you to see separate parents if they came from timers. I removed this because I think I want to build a tree view for this that roots commands within the buffer that they were taken.
This removes the now unused logging
defcustoms.Testing
Add an integration test runner that runs emacs under tmux. Drive that emacs via another emacs that runs the test code. Drive all of that via Make. Add regression tests for all existing bugs that had repros that would not be covered by unit tests. There is still some areas that need testing, especially regarding the display layer which ought to be tested via batch emacs and reading a buffer, probably driven via buttercup.
The test suite can run against all the versions of Emacs supported, but it doesn't work for windowed emacs yet. Not sure I need to double the matrix there. If more bugs come at that layer I will consider adding it.
Random things
Also, rearrange deffaces into the right group.