Too slow opening a file with many columns (Performance Regression)

[eteran]

Too slow opening a file with many columns (Performance Regression)

[eteran]

I'll take a look. Certainly, a performance regression is unacceptable. I assume you are opening the .cpp file and not the .gz file directly, correctly?

[eteran]

Can you clarify "not able to open it" please? I opens on my machine, but it is noticeably slower in the display when scrolled down to the part with all of the entries for the A array which is where the bulk of the data seems to be.

I do consider this to be a performance regression, so I'll look into it regardless. But does the file not open for you at all?

[eteran]

Note to self so I don't forget when I get back from work. The long load time appears to be a regression in the performance of the parseString routine. On my machine it is taking upwards of 1 second for this file.

However, even in the "Plain" language mode, scrolling and highlighting of some portions of the file is still choppy. So this appears to be at least 2 things to address.

[mmorandi]

1. yes, the .cpp and not the the .gz. I had to compress it because github was not accepting the .cpp attachment.
2. "not able to open" was indeed imprecise on my part. It was so slow that I killed it (I've checked now: it takes about 40 s to open it on my i7-7500U CPU @ 2.70GHz).

[eteran]

40s is certainly is unacceptable! For me it's more like 2-4 seconds... I think I found this morning the routine which is causing me the initial slowness. Hopefully it'll be an easy fix.

[eteran]

So as a quick question, are you building in release mode? That may help make things at least a little bit better (though this is still an issue). Some profiling shows that the majority of the time is spent on the regex code, which I didn't intentionally change algorithmically. So maybe it's something that used to be inlined but isn't any more or something like that. I'll have to keep digging to get to the bottom of this.

[mmorandi]

I'm building with

CMAKE_BUILD_TYPE:STRING=RelWithDebInfo

Switching to

CMAKE_BUILD_TYPE:STRING=Release

changes nothing (as expected).

I cannot perform a real profiling right now. However, by repeatedly stopping nedit-ng under gdb while it is loading the file I suspect that my 40 s are eaten by QTextEngine::shapeTextWithHarfbuzzNG : it always appears near the top of the backtrace.
A few more info: I'm using opnesuse thumbleweed.
g++ 7.3.1
qt 5.10
libharfbuzz 1.7.6

[eteran]

Interesting, so for my 2s load time, QTextEngine::shapeTextWithHarfbuzzNG doesn't even show up in the profile.

However, match (from the regex engine) shows up for 50% of the profile. So we may be chasing a few performance concerns with a single case to demonstrate them.

Currently, when nedit loads a file, it parses the whole thing for syntax highlighting. I find this to be perhaps unnecessary since i think nedit can initially mark the whole file as not having highlight info yet, which will result in the portions being displayed getting highlighting data on an as needed basis.

This seems to be like it would result in faster load times in general and the cost of slightly slower first time scroll times. I'll have to keep looking into this.

[mmorandi]

Here it is spending time in TextArea::stringWidth:

#0  0x00007ffff3b0f601 in ?? () from /usr/lib64/libharfbuzz.so.0
#1  0x00007ffff3b09d18 in ?? () from /usr/lib64/libharfbuzz.so.0
#2  0x00007ffff3b31927 in ?? () from /usr/lib64/libharfbuzz.so.0
#3  0x00007ffff3aefe52 in hb_shape_plan_execute () from /usr/lib64/libharfbuzz.so.0
#4  0x00007ffff3aef5ac in hb_shape_full () from /usr/lib64/libharfbuzz.so.0
#5  0x00007ffff679b958 in QTextEngine::shapeTextWithHarfbuzzNG(QScriptItem const&, unsigned short const*, int, QFontEngine*, QVector<unsigned int> const&, bool, bool) const () from /usr/lib64/libQt5Gui.so.5
#6  0x00007ffff679e86e in QTextEngine::shapeText(int) const () from /usr/lib64/libQt5Gui.so.5
#7  0x00007ffff679f25f in QTextEngine::shape(int) const () from /usr/lib64/libQt5Gui.so.5
#8  0x00007ffff67a6861 in QTextEngine::width(int, int) const () from /usr/lib64/libQt5Gui.so.5
#9  0x00007ffff6789138 in QFontMetrics::width(QString const&, int, int) const () from /usr/lib64/libQt5Gui.so.5
#10 0x000000000054c28f in TextArea::stringWidth (this=this@entry=0xf0b0f0, string=string@entry=0x7fffffffb580 "8\265\377\377\377\177", length=length@entry=1, 
    style=<optimized out>) at /home/marco/Programmi/nedit-ng/source/TextArea.cpp:1778
#11 0x000000000054c3f4 in TextArea::measurePropChar (this=this@entry=0xf0b0f0, ch=ch@entry=56 '8', colNum=colNum@entry=38, pos=pos@entry=4385634)
    at /home/marco/Programmi/nedit-ng/source/TextArea.cpp:1766
#12 0x0000000000550eb4 in TextArea::wrappedLineCounter (this=0xf0b0f0, buf=0x1057b40, startPos=<optimized out>, maxPos=5526913, 
    maxLines=maxLines@entry=2147483647, startPosIsLineStart=<optimized out>, styleBufOffset=0, retPos=0x7fffffffb6a8, retLines=0x7fffffffb6a0, 
    retLineStart=0x7fffffffb6b0, retLineEnd=0x7fffffffb6b8) at /home/marco/Programmi/nedit-ng/source/TextArea.cpp:1674
#13 0x0000000000551441 in TextArea::TextDCountLines (this=<optimized out>, startPos=<optimized out>, endPos=<optimized out>, 
    startPosIsLineStart=<optimized out>) at /home/marco/Programmi/nedit-ng/source/TextArea.cpp:3449
....

[eteran]

Very weird. getting the stringwidth should be very cheap...

Anyway, I am also guessing that you have text wrapping enabled, does disable it (you'd have to disable it in the global preferences, not just the document ones) make any difference?

[mmorandi]

No, already checked. It still calls TextArea::stringWidth

[eteran]

Which font are you using? Perhaps it's possible that some fonts are unreasonably expensive to calculate metrics on?

[mmorandi]

Courier New
I have not saved .config/nedit-ng/config.ini nor imported nedit.rc (there is no .config/nedit-ng directory; I've checked that if I save the preferences the directory appears, but after that I've deleted it), so nedit-ng is running with all its default settings, right?

[eteran]

Yes, that will certainly cause it to use the defaults.

OK, I've made a few tweaks (and a small fix) to enable a little experimentation. Can you please pull the latest and then go into source/TextArea.cpp line 1773 and change the #if 1 to #if 0. This alternate code path is only correct for a fixed width font so I'm not going to enable it... but if you could test it and let me know if that makes things noticeably faster, that would be great.

If it does, then we know what is causing a good chunk of your slowness and can move forward from there.

For some reason QFontMetrics::width has very little cost for me, but doesn't for you, and I'd like to figure out why/what we can do about it!

[mmorandi]

I don't know why (you commits seems unrelated), but now it takes ~ 2.7 s with #if 1, and ~ 2.5 s with #if 0. Since I'm using time and ctrl-c to measure the time needed to open it it is perfectly possible that it is taking the same time.
However, if after opening the file I change the size of the font (not global preferences, only the opened file, and "Fill highlight font from primary")

1. nedit claims that the height of secondary fonts does not match primary; maybe this is technically, they are italic, bold and bold italic, but it does not make a lot of sense for the user (
2. it takes a lot (12 s?) to re-draw everything with #if 1 It takes definitely less (3 s?) with #if 0.

I've noticed that the original nedit first draws the text without any syntax highlighting, and then colors it. The effect is that one believes that the file is opened instantly, while it takes almost 2 s to finish the syntax highlighting. nedit-ng, instead, seems to wait until it is able to draw everything, already with colors. Right? The effect is that it seems a little bit slower.

[eteran]

One of the commits fixes an issue where it was forcing nedit-ng to take the "variable width font" code path all of the time, so that was probably causing a lot more of the stringWidth calls than it should have been. So, now it seems like we've gotten rid of the 40s load time, and are down to 2.5s, sweet!

Now to fix the other performance quirks, since one of my favorite things about nedit is how damn fast it was! So regarding your observations:

1. Yea, this is behavior taken from the original nedit, it just showed up less often because it used bitmap fonts. I am considering reducing the font selection to just a single font name/size and adding bold/italic to that as needed (like most editors). I already have an issue to track it (#5 )

2. Good to know. It is strange that this function is SO much more expensive on your system than on mine. I am considering some code to say "if we are dealing with a fixed width font, then use the quick path". Which may make even more sense if I remove variable width font support anyway (issue #1 )

Your note is an interesting observation that wasn't an intentional change. algorithmically, nedit-ng is doing the same work as the original nedit, but I think that Qt is coalescing the paint events. I'll look into it more.

One last thing that I've noticed is that when scrolling this file down to the part with really long lines, it gets much slower, which the original nedit doesn't suffer from nearly as much. So I plan to look into that as well!

[eteran]

I've added a "fast path" for when we've calculated that the font is entirely the same fixed width in all styles. This allows me to avoid all calls to the QFontMetrics::width function which seems to be unreasonably slow compared to the XTextWidth function that nedit was originally using.

This addresses a few performance issues when dealing with long lines of text so I'm going to close this issue.

However, there are some more "trouble spots" that I'd like to address in order to get things as snappy as I want them to be! So if you see any more aspects where it is noticeably slower than it should be and can be reliably reproduced, please open another issue for them!