bugGNU nano - Bugs: bug #53562, high CPU usage with C syntax...

 
 

You are not allowed to post comments on this tracker with your current authentication level.

bug #53562: high CPU usage with C syntax highlighting when scrolling with the touchpad

Submitter:  easyaspi314 <easyaspi314>
Submitted:  Wed 04 Apr 2018 08:14:08 PM UTC
   
 
Severity:  3 - Normal Status:  Fixed
Assigned to:  bens Open/Closed:  Closed

Jump to the original submission

Sat 28 Apr 2018 09:16:39 AM UTC, comment #24: 

The improvement has been released in 2.9.6.  Thanks again for reporting.

Benno Schulenberg <bens>
Group administrator
Tue 24 Apr 2018 08:12:09 AM UTC, comment #23: 

Thanks for confirming.  The second patch has been pushed to master, commit 0d9080a2.

(And if you do a git pull && ./autogen.sh && make, you will have a slightly better gnulib too.)

Benno Schulenberg <bens>
Group administrator
Mon 23 Apr 2018 09:43:01 PM UTC, comment #22: 

Oh, sorry, I had this already typed out and I forgot to send it.

CPU usage is 2-4%. Seems to work fine, if not better than the last one.

easyaspi314 <easyaspi314>
Mon 23 Apr 2018 08:28:17 AM UTC, comment #21: 

Ping?  Info on CPU usage for second patch?

Benno Schulenberg <bens>
Group administrator
Fri 20 Apr 2018 09:57:03 AM UTC, comment #20: 

What's the CPU usage with the second patch?  Higher than with the first?  Lower?  Roughly equal?

Benno Schulenberg <bens>
Group administrator
Mon 16 Apr 2018 02:04:07 PM UTC, comment #19: 

rpl_wcwidth is how gnulib deals with overriding system functions, as C functions annoyingly need unique names.

wchar.h or wherever it is

#undef wcwidth
#define wcwidth rpl_wcwidth

wcwidth.c

#include "wchar.h"

int
wcwidth(wchar_t char) <- really rpl_wcwidth
#undef wcwidth
{

easyaspi314 <easyaspi314>
Mon 16 Apr 2018 08:41:43 AM UTC, comment #18: 

Strange... rpl_wcwidth()?  But that function does not exist anywhere in glulib.  At least, not in the modules that are included with nano.  The function was renamed to plain wcwidth() eight years ago.  Does your Mac somehow link against old gnulib modules that it has installed from the factory?

Looking at the current wcwidth() from gnulib...  Christ!  It calls locale_charset() for every invocation.  And that call involves ploughing though a list of 25 aliases, involving 50 strlen() calls!  All totally in vain, pointless, useless.  No wonder that your machine gets bogged down when trying to scroll.  :(

Anyway, the attched second version of the second patch addresses the issue with smooth-scrolling being always on.  What's the percentage of CPU usage with this patch, when using --smooth?

(file #43947)

Benno Schulenberg <bens>
Group administrator
Sun 15 Apr 2018 10:35:30 PM UTC, comment #17: 

I screwed up. That was for vanilla nano. I applied the patch and forgot to make clean.

CPU usage with that second patch is much better. However, smooth scroll is stuck on.

easyaspi314 <easyaspi314>
Sun 15 Apr 2018 06:43:01 PM UTC, comment #16: 

Yeah, I know images are hard for bots to interpret.

Ok, I'm done. :P

Here is the stack.

main
-> edit_refresh
---> update_line
-----> edit_draw
-------> actual_x
---------> parse_mbchar
-----------> rpl_wcwidth
-------------> *locale_charset*
---------------> *strlen*

locale_charset and strlen both have high self weight, which means the time spent in that function itself, not from calls in other functions.

easyaspi314 <easyaspi314>
Sun 15 Apr 2018 08:13:51 AM UTC, comment #15: 

Yes, I am supercautious -- you'll have to give me the info in words, not in a picture.  for example, from where in nano is this function in gnulib that calls strlen() called?

Benno Schulenberg <bens>
Group administrator
Sat 14 Apr 2018 08:06:54 PM UTC, comment #14: 

Too bad, the PPM is not uploading. I guess the screenshot isn't important enough for you to open it.

On the other side, I could be nicer and upload the photo to Imgur.

Fine. Here you go. https://imgur.com/a/8ceXk

easyaspi314 <easyaspi314>
Sat 14 Apr 2018 07:49:27 PM UTC, comment #13: 


>(Sorry, I won't look at binary files.)


How are you using Nano then? The only way you could run it without opening a binary is with tcc, but tcc is also a binary...unless you ported it by hand to be a shell script or something, but then again, /bin/sh is also a binary…

Even though it was a completely harmless PNG screenshot, if you insist on being paranoid, I will try and reupload it as a PPM.

If you are going to be irrational, don't be surprised when others are irrational back.

Anyway, back on topic.

The second patch doesn't help that much. And the first one was still somewhat laggy.

I think the strlen call is part of gnulib. If you looked at the screenshot, you would see the stack.

easyaspi314 <easyaspi314>
Sat 14 Apr 2018 05:53:49 PM UTC, comment #12: 

Apply to a clean 2.9.5.  (It's an alternative patch -- when combined with the other patch, it would do the wrong thing.)

Which strlen() call?  There are lots of them all over the place, but I see only one in the display routines, the one in "converted = charalloc(strlen(buf)...".  It's hard to believe that that is the biggest time waster.  (Sorry, I won't look at binary files.)

Benno Schulenberg <bens>
Group administrator
Sat 14 Apr 2018 05:06:48 PM UTC, comment #11: 

Do you want me to apply this patch to clean 2.9.5 or on top of your other patch?

Also, Instruments does profile the time in each function. And yes, actual_x is  is a bottleneck, but the most weight comes from the strlen call. Check the screenshot I attached.


easyaspi314 <easyaspi314>
Sat 14 Apr 2018 10:56:51 AM UTC, comment #10: 

Thanks for confirming that the patch reduces the CPU usage to acceptable levels -- and presumably gets rid of the perceived lag.

Could you do the same tests with the attached alternative patch?

As for profiling, I don't have a Mac.  And if I understand well, what you do on a Mac is to record the CPU-usage graph of nano.  Which is useful, but... profiling normally means: to instrument the binary so that you get a detailed report on how much time is spent in which functions, so you can identify the bottlenecks.

As for optimizing, I have long considered storing the number of columns that a line takes up -- the outcome of strlenpt().  But that probably wouldn't help much: I think nano spends most of its time in actual_x().

(file #43926)

Benno Schulenberg <bens>
Group administrator
Fri 13 Apr 2018 11:14:06 PM UTC, comment #9: 

The patch did in fact reduce CPU to about 12-20%. Good find.

As for profiling, this is Mac only.

  1. Open a document in nano.
  2. Open /Applications/Xcode.app/Contents/Applications/Instruments.app.
  3. In the second dropdown after "Choose a profiling template for" (it will probably say "All processes"), find nano (pid) under system processes. You probably have to click more at the bottom.
  4. Double click Time Profiler.
  5. Click the record button and scroll up and down. When you think you have a good sample, click pause.


So I am thinking about some potential performance improvements.

  1. Store the line length so we don't have to make expensive strlen calls
  2. Store parsed lines in UTF-16 and skip most mbtowc, but this will take RAM. Maybe only store the surrounding lines?


easyaspi314 <easyaspi314>
Fri 13 Apr 2018 11:46:41 AM UTC, comment #8: 

Oh, wow...  Indeed, just cofiguring with --disable-utf8, makes scrolling in doc/faq.html usable (nearly fully smooth).  Apparently the UTF-8 routines eat a lot of cycles.  :|

How exactly did you profile nano?  A link to a howto would be nice, because I've never done anything of the sort.

(Waiting for you to confirm that the second patch solves most of the scrolling lag for you.)

Benno Schulenberg <bens>
Group administrator
Thu 12 Apr 2018 11:20:34 AM UTC, comment #7: 

I quickly scanned the patch and it looks good.I am not at my laptop right now, but I will test it when I get a chance.

Although, I also wanted to add (I forgot to post this message a few days ago) that I profiled Nano while scrolling and a lot of the weight was not just in the regex, but in the conversion between wide characters and multibyte characters.

If I compiled with --disable-utf8 and set LANG="C", the CPU usage decreased a lot.

easyaspi314 <easyaspi314>
Thu 12 Apr 2018 09:38:02 AM UTC, comment #6: 

Attached is an improved version of the patch that also works when using --softwrap.  Especially when using --softwrap (for example on doc/faq.html), the lag (without the patch) is noticeable.

(file #43891)

Benno Schulenberg <bens>
Group administrator
Thu 12 Apr 2018 07:56:58 AM UTC, comment #5: 

I've thought about this again and... it's not that any keystroke could come in at rocket speeds, it's just the <Up> and <Down> keys.  So, maybe nano could handle those two cases in a special way.  Attached patch does that.  If you can, please test and report back whether this gets rid of the perceived lag.

(The patch should apply cleanly to 2.9.5.)

(file #43890)

Benno Schulenberg <bens>
Group administrator
Thu 05 Apr 2018 05:51:22 PM UTC, comment #4: 

2) Ah, okay, now I see what you mean.  With a 48x164 terminal, and using two-finger scrolling, I can notice a lag (especially when reaching comvert_sequence()).  But... this is to be expected: using two fingers on the touchpad to scroll is like pressing the <Up> or <Down> key very fast.  Nano can cope with normal and also quite fast typing speeds, but not with superhuman rocket streams of keystrokes.  If a user wants to "scroll" quickly through a file, they should use <PageDown>/<PageUp> -- nano is a terminal program, not a graphical one.

(That nano -- or in fact ncurses -- responds to the touchpad, I discovered by accident a few months ago: it simply never occurred to me to use the touchpad to try and scroll in a terminal.)

So... I think I'll have to mark this as: CANTFIX.

Benno Schulenberg <bens>
Group administrator
Thu 05 Apr 2018 03:31:05 PM UTC, comment #3: 

By the way, he regex application was what I meant by syntax tree. Too much time messing with Clang plugins, I guess. :-/

easyaspi314 <easyaspi314>
Thu 05 Apr 2018 03:24:14 PM UTC, comment #2: 

1. It looks like Nano hogs the CPU and makes it so the terminal can't keep up with the redrawing. Because iTerm2 never lags except for when scrolling in Nano. I believe that Terminal.app is single threaded.

2. MacBook, two finger scrolling up and down. Line by line. I took a video here: https://streamable.com/1ng1p

3. I always maximize my terminal window because my screen is too small to multitask. According to $COLUMNS and $LINES, it is 179x48.

With a 90x35 terminal in iTerm2, I am getting about 40% CPU usage and it is smoother

As for the multi core thing, it appears that when Nano and the terminal aren't fighting, iTerm2 is on one core, Nano is on the other, as the CPU graph shows both cores jumping.

Nanorc: Mac never shipped with syntax highlighting. /etc/nanorc is literally just "set nowrap". c.nanorc does have the expensive line commented out.

A side note is that with syntax off, Nano still peaks to ~25%.

easyaspi314 <easyaspi314>
Thu 05 Apr 2018 10:48:51 AM UTC, comment #1: 

Several questions.

1) What do you mean with "nano lags"?  Because if nano uses 80% CPU at maximum, it means it isn't CPU-constrained -- it isn't a lack of CPU time that makes it "lag" or "stutter".  (Or maybe that 80% is the two cores combined?  As nano is single-thread, it could very well mean that one of the cores is maxed out.)

2) What do you mean with scrolling?  Per line or per page?  To test I have used M-= in nano, and ^E in vim.

3) What is the size of your terminal?  How many lines and columns?

No, nano does not parse any syntax tree.  But when it redraws the screen (as happens when you PageUp/PageDown), it will apply the color regexes one by one, row after row.  It doesn't cache anything, apart from a tiny bit of information for the multiline regexes.

When I do the M-=/^E scrolling for src/winio.c in a 35x90 terminal, nano uses around 20% CPU and vim around 22% (with its default C syntax).  When I PageUp/PageDown, nano uses around 30% CPU, vim around 33%.  This is on a dual core Celeron N3060, speed/max: 752/2480 MHz (info from inxi).  (I monitor CPU usage with the Task Manager in Xfce -- using 'top' shows two separate CPUs, and it's too hard for me to constantly compute the average on the fly.)

One thing that might cause the slowness in nano is if you are using an old C syntax.  Move your /etc/nanorc out of the way, and make sure your ~/.nanorc includes only the c.nanorc file that was installed by your homebrew installation.  Then see if the CPU usage has normalized (after restarting nano, of course.)  The C syntax that was installed by default on your Mac still contained a costly multiline regex.  This regex was disabled/removed two years ago, in commit ae598e79.

Benno Schulenberg <bens>
Group administrator
Wed 04 Apr 2018 08:14:08 PM UTC, original submission:  

The bug


Nano has very high CPU usage when scrolling with syntax highlighting enabled, especially when smooth scroll is enabled and when compared to Vim.

Steps to reproduce


  1. Swap out <vim share>/vim/vim80/syntax/c.vim with the one I attached. That is a hacked together "port" of the Nano C syntax definitions to Vim to try and create a level playing field.
  2. Enable syntax coloring, mouse support and smooth scrolling in Nano.
  3. If you are on Mac, use Terminal.app here.
  4. Open winio.c from Nano's source code in both Nano and Vim.
  5. Start monitoring CPU usage
  6. Scroll up and down in Nano.
  7. Scroll up and down in Vim.


What happens


Vim scrolls smoothly, Nano lags.

Additionally, when scrolling, if I look at Activity Monitor, Nano goes up to 80% CPU, while Vim only goes up to 20%, with Terminal.app using more CPU to render the colors than Vim does to scroll.

As a matter of fact, with the more complex default Vim definitions, Vim still uses less CPU.

I read in Vim's docs that Vim caches the highlighting tokens. Does Nano try to parse the syntax tree each time you scroll?

System Info


Nano 2.9.5 from Homebrew
Vim 8.0.1650 from Homebrew

Mac OS X El Capitan 10.11.6
Terminal.app 2.6.2 - Amplifies performance issues because of poor color rendering
iTerm2 3.1.6beta4 - much better performance, but still noticeable lag

MacBook (13-inch, Mid-2009) MacBook5,2
2.13 GHz Intel Core 2 Duo
4 GB RAM
NVIDIA GeForce 9400M 256 MB
Yes, I know my Mac is old

easyaspi314 <easyaspi314>

 

(Note: upload size limit is set to 16384 kB, after insertion of the required escape characters.)

Attached Files
file #43928:  Screen Shot 2018-04-14 at 1.00.52 PM.png added by easyaspi314 (188KiB - image/png - Instruments profiling)
file #43891:  0001-moving-handle-consecutive-Up-s-and-Down-s-without-up.patch added by bens (2KiB - text/x-patch - second version of the patch)
file #43890:  0001-moving-handle-consecutive-Up-s-and-Down-s-without-up.patch added by bens (2KiB - text/x-patch - handles multiple, consecutive ups and downs together)
file #43800:  c.vim added by easyaspi314 (3KiB - application/octet-stream - Hacked together C Vim syntax highlighting definitions that imitates Nano's behavior)

 

Depends on the following items: None found

Items that depend on this one: None found

 

Carbon-Copy List
  • -email is unavailable- added by bens (Posted a comment)
  • -email is unavailable- added by easyaspi314 (Submitted the item)
  •  

    There are 0 votes so far. Votes easily highlight which items people would like to see resolved in priority, independently of the priority of the item set by tracker managers.

     

    Follow 16 latest changes.

    Date Changed by Updated Field Previous Value => Replaced by
    2018-04-28 bens Open/ClosedOpen Closed
    2018-04-24 bens StatusNeed Info Fixed
    2018-04-16 bens Attached File- Added 0001-scrolling-don-t-redraw-entire-edit-window-when-curso.patch, #43947
    2018-04-15 bens StatusReady For Test Need Info
    2018-04-14 easyaspi314 Attached File- Added Screen Shot 2018-04-14 at 1.00.52 PM.png, #43928
    2018-04-14 bens Attached File- Added 0001-scrolling-don-t-redraw-entire-edit-window-when-curso.patch, #43926
    2018-04-13 bens Severity2 - Minor 3 - Normal
        Assigned toNone bens
    2018-04-12 bens Attached File- Added 0001-moving-handle-consecutive-Up-s-and-Down-s-without-up.patch, #43891
    2018-04-12 bens Attached File- Added 0001-moving-handle-consecutive-Up-s-and-Down-s-without-up.patch, #43890
        StatusNeed Info Ready For Test
    2018-04-05 bens Severity3 - Normal 2 - Minor
        Summaryhigh CPU usage with C syntax highlighting when scrolling high CPU usage with C syntax highlighting when scrolling with the touchpad
    2018-04-05 bens StatusNone Need Info
        SummaryVery high CPU usage with syntax highlighting + scrolling high CPU usage with C syntax highlighting when scrolling
    2018-04-04 easyaspi314 Attached File- Added c.vim, #43800

    Back to the top

    Powered by Savane 3.13-f8d8.
    Corresponding source code