[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
Re: Deffering redisplay in COMINT
From: |
Michael Mauger |
Subject: |
Re: Deffering redisplay in COMINT |
Date: |
Sun, 13 Jan 2013 00:14:49 -0800 (PST) |
> From: Stefan Monnier <address@hidden>
> Sent: Friday, January 11, 2013 10:55 AM
>
>> but that's what I have to live with). Without the filter and
>> auto-hscroll-mode engaged, the results take nearly 30 seconds to
>> complete under Emacs. (It is nearly instantaneous outside of Emacs.)
>> With the filter you suggest, the results take about 8-10 seconds with
>> a noticeable stutter between each row. With the solution I had
>> developed (buffering the long lines in a buffer and restoring them at
>> the end of output), the results scroll by quickly in about 2-3 seconds,
>> but then it hesitates at the end (as it restores the long lines in the
>> buffer), for another 2-3 seconds. So just reducing the horizontal
>> scrolling is giving us the big payback and the more complex
>> gymnastics is probably not worth code cost.
>
> Hmm... I'm wondering why the "one line at a time" approach ends up
> slightly slower than your more complex approach. Using a single string
> occurs an O(N^2) overhead (where N is the line length: we receive O(N)
> packets per line and for each package we do a concat which costs O(N)),
> so that might be the reason (which is why I suggested using a list of
> strings, tho it makes detection of the prompt more cumbersome), but for
> 8KB lines it's not clear it would be that bad.
>
> Could you M-x profiler-start ... M-x profiler-report around your tests
> to see where the time is spent?
>
>
> Stefan
>
I ran several different configurations trying to identify important
criteria related to the display of this large block of text.
Testing ran a single database query that returns 289 rows of data
and 6000 characters per row. For a total of 1.7MB of data.
First, outside of Emacs, at the bash prompt on a GNU/Linux laptop.
$ time sqlite3 test.db <test_big.sql | wc
292 1684 1747492
real 0m0.175s
user0m0.140s
sys 0m0.004s
Basically, the database is not a constraint on performance.
I ran all tests with -Q. Each test was run in two display configurations:
* (NW) an 80x40 text terminal (GNOME Terminal 2.30.2) window, and
* (GUI) a similar sized X11 frame (GNU Emacs 24.3.50.1
(i686-pc-linux-gnu, X toolkit, Xaw3d scroll bars) of 2012-12-20)
(BZR revno:111283)
In each display environment I ran the tests with `truncate-lines' set to
`t' and then with it set to`nil'.
I then ran three different output filtering configurations:
* (BASE) Just the OOB sql.el module with it's output filters (eats
leading continuation prompts produced by multi-line commands)
* (SS) Simple filter that emits text thru the last newline and holds
the remainder for the next iteration. Avoids any horizontal scrolling.
* (HSC) My more complex minor mode that passes along the first 90
characters of each line and at the final prompt, it goes back and
inserts the remainder of each output line in the output buffer.
Below is a summary of the user experienced elapsed time of each of these
tests:
These numbers differ from what I had reported earlier but those were
based on my gut feel for the performance and based on a Cygwin/Win7
executable running on a much beefier Core i7 machine at work.
Display| GUI/X| Text/NW|
Truncate-lines| nil| t| nil| t|
---Filter---| -----| -----| -----| -----|
BASE| 3:43 | 5:51| 0:16 | 4:20 |
SS| 3:42 | 3:06 | 0:12 | 2:04 |
HSC| N/A | 0:07 | N/A | 0:04 |
* HSC is disabled when `truncate-lines' is nil; times in those cases
are the same as BASE
* HSC samples both include 1-2 seconds of hanging at the end as the
lines are updated by appending the filtered off-screen text
The two obvious takeaways from this is that GUIs are slower, and
truncate-lines set to non-nil can be painful.
I have the cpu profile saved for each of the tests and have included a
summary of some of them below. I've been staring at numbers for
the last three days so I'm getting a little cross-eyed. Let me know
if there is something more that would help you.
Here's the CPU profiler report for:
SS / NW / Trunc (2:04)
===============
- redisplay_internal (C function) 117989 97%
- jit-lock-function 1832 1%
- jit-lock-fontify-now 1832 1%
- byte-code 1820 1%
- run-hook-with-args 1820 1%
- font-lock-fontify-region 1820 1%
- font-lock-default-fontify-region 1816 1%
- font-lock-fontify-keywords-region 1812 1%
re-search-forward 1800 1%
font-lock-extend-region-wholelines 4 0%
font-lock-set-defaults 4 0%
line-beginning-position 8 0%
match-data 4 0%
- eval 28 0%
- if 20 0%
display-graphic-p 12 0%
frame-parameter 8 0%
- unless 4 0%
- if 4 0%
- display-graphic-p 4 0%
framep-on-display 4 0%
- menu-bar-update-buffers 16 0%
lookup-key 16 0%
- file-remote-p 12 0%
find-file-name-handler 12 0%
- keymap-canonicalize 7 0%
keymap-prompt 4 0%
- map-keymap 3 0%
#<compiled 0x2092fc9> 3 0%
- comint-output-filter 2511 2%
- run-hook-with-args 2150 1%
- comint-watch-for-password-prompt 1393 1%
string-match 1393 1%
- comint-postoutput-scroll-to-bottom 634 0%
recenter 611 0%
- get-buffer-window-list 8 0%
window-list-1 4 0%
vconcat 4 0%
- ansi-color-process-output 123 0%
- ansi-color-apply-on-region 123 0%
re-search-forward 123 0%
- sql-interactive-remove-continuation-prompt 273 0%
- if 270 0%
- progn 270 0%
- let 270 0%
- if 266 0%
string-match 181 0%
- while 77 0%
string-match 77 0%
- setq 4 0%
substring 4 0%
- setq 4 0%
concat 4 0%
string-match 60 0%
- jit-lock-after-change 4 0%
put-text-property 4 0%
comint-carriage-motion 4 0%
buffer-name 4 0%
SS / NW / NoTrunc (0:12)
=================
- redisplay_internal (C function) 9403 80%
- jit-lock-function 1823 15%
- jit-lock-fontify-now 1823 15%
- byte-code 1792 15%
- run-hook-with-args 1792 15%
- font-lock-fontify-region 1792 15%
- font-lock-default-fontify-region 1792 15%
- font-lock-fontify-keywords-region 1789 15%
re-search-forward 1785 15%
font-lock-extend-region-wholelines 3 0%
- run-with-timer 16 0%
- apply 12 0%
- run-at-time 12 0%
- timer-relative-time 8 0%
time-add 4 0%
mod 4 0%
current-time 4 0%
line-beginning-position 7 0%
text-property-any 4 0%
- eval 30 0%
- if 14 0%
frame-parameter 11 0%
display-graphic-p 3 0%
mode-line-frame-control 4 0%
mode-line-eol-desc 4 0%
- menu-bar-update-buffers 15 0%
lookup-key 8 0%
frame-or-buffer-changed-p 3 0%
- file-remote-p 8 0%
find-file-name-handler 8 0%
- keymap-canonicalize 8 0%
- map-keymap 8 0%
#<compiled 0x2092fc9> 4 0%
- comint-output-filter 2058 17%
- run-hook-with-args 1700 14%
- comint-watch-for-password-prompt 1373 11%
string-match 1373 11%
- comint-postoutput-scroll-to-bottom 179 1%
recenter 175 1%
get-buffer-window-list 4 0%
- ansi-color-process-output 148 1%
- ansi-color-apply-on-region 148 1%
re-search-forward 145 1%
- sql-interactive-remove-continuation-prompt 214 1%
- if 214 1%
- progn 211 1%
- let 211 1%
- if 201 1%
string-match 137 1%
- while 60 0%
string-match 60 0%
- setq 4 0%
substring 4 0%
- setq 10 0%
concat 10 0%
string-match 74 0%
comint-carriage-motion 19 0%
- jit-lock-after-change 11 0%
- run-hook-with-args 4 0%
- font-lock-extend-jit-lock-region-after-cha 4 0%
line-beginning-position 4 0%
byte-code 3 0%
move-overlay 4 0%
Automatic GC 162 1%
HSC / NW / Trunc (0:04)
================
- redisplay_internal (C function) 3501 48%
- jit-lock-function 386 5%
- jit-lock-fontify-now 386 5%
- byte-code 359 5%
- run-hook-with-args 359 5%
- font-lock-fontify-region 359 5%
- font-lock-default-fontify-region 359 5%
- font-lock-fontify-keywords-region 359 5%
re-search-forward 355 4%
make-marker 4 0%
- run-with-timer 15 0%
- apply 15 0%
- run-at-time 15 0%
- timer-relative-time 11 0%
time-add 7 0%
floor 4 0%
timer-set-function 4 0%
- eval 28 0%
- if 20 0%
frame-parameter 12 0%
- display-graphic-p 8 0%
framep-on-display 4 0%
- mode-line-eol-desc 8 0%
coding-system-eol-type-mnemonic 8 0%
keymap-canonicalize 11 0%
- menu-bar-update-buffers 8 0%
lookup-key 4 0%
frame-or-buffer-changed-p 4 0%
- file-remote-p 8 0%
find-file-name-handler 8 0%
- comint-output-filter 3185 44%
- run-hook-with-args 3084 43%
- sql-hscroll-post-output 2927 40%
- if 2927 40%
- progn 2904 40%
- let 2904 40%
- save-excursion 2904 40%
- while 2904 40%
- move-end-of-line 2852 39%
- line-move 2852 39%
- line-move-1 2852 39%
vertical-motion 2836 39%
- byte-code 12 0%
line-move-finish 12 0%
- insert 36 0%
- jit-lock-after-change 8 0%
put-text-property 4 0%
- apply 8 0%
propertize 4 0%
quote 4 0%
- save-current-buffer 16 0%
- setq 12 0%
- not 8 0%
- zerop 8 0%
forward-line 8 0%
line-end-position 4 0%
set-buffer 4 0%
- and 23 0%
- sql--hscroll-at-end-p 23 0%
- save-current-buffer 23 0%
- looking-back 23 0%
re-search-backward 19 0%
- comint-postoutput-scroll-to-bottom 133 1%
recenter 125 1%
vconcat 4 0%
select-window 4 0%
- comint-watch-for-password-prompt 12 0%
string-match 12 0%
- ansi-color-process-output 8 0%
- ansi-color-apply-on-region 8 0%
ansi-color-apply-overlay-face 4 0%
ansi-color--find-face 4 0%
- sql-hscroll-pre-output 55 0%
- if 55 0%
- let 55 0%
- save-current-buffer 55 0%
- sql--hscroll-copy-output 51 0%
- save-excursion 25 0%
insert 25 0%
- let* 19 0%
line-beginning-position 8 0%
- while 4 0%
- setq 4 0%
line-end-position 4 0%
line-end-position 3 0%
goto-char 7 0%
- looking-back 16 0%
re-search-backward 16 0%
- comint-carriage-motion 8 0%
line-beginning-position 4 0%
move-overlay 3 0%
- sql-interactive-remove-continuation-prompt 3 0%
- if 3 0%
- progn 3 0%
- let 3 0%
- setq 3 0%
concat 3 0%