GNOME Bugzilla – Bug 657763
Meld is too slow
Last modified: 2014-07-20 02:04:47 UTC
In meld I open the file with 13k lines having 134 differences compared to svn base. It takes about 10 seconds for meld to completely open it and stop painting the diffs. By that time it consumes ~2.7sec of user CPU time. I am comparing with the older tk-based utility tkdiff performing exactly the same function. At 5 seconds after start it already finished showing the file and it took only 0.34sec of user time. So meld is much slower. Even on such small file (13k lines) it's quite painful to wait. Meld should be debloated and streamlined. Otherwise it's usability suffers.
I suggest optimization based on valgrind (cachegrind) profile.
I'm sorry, but Meld and tkdiff aren't even vaguely comparable. They're written in different languages, use different toolkits, have different capabilities, and have different comparison backends. Furthermore, Meld is written in Python, and as such a cachegrind (or callgrind) profile isn't helpful. If you have specific cases that are particularly slow, you can attach them, or profile them (using a Python profiler) to figure out what's taking the time. However, 'is too slow' isn't a useful comment. I suspect that if you profile the differences, you'll find that our inline highlighting algorithm is what's making Meld slower. That could certainly be improved, but at the moment it also produces (I would say) far better results than the tkdiff one.
Meld and tkdiff are comparable functionally. They perform roughly the same function in different ways. Underlying technology is just a choice developers made that shouldn't cause major differences in timing.
Created attachment 199392 [details] shell script generating the testcase Please consider this example. Using the attached shell script 'gen-lines', generate two files and compare them. They are 15k lines each with 15 one line differences. ./gen-lines 0 > 0 ./gen-lines 1 > 1 time meld 0 1 After meld is done drawing the differences, I close its window and I typically get such timing: real 0m14.000s user 0m7.143s sys 0m0.217s Note that user time is 7.1 sec, and real time is about twice as long. This means that meld also significantly loads the X server during this to the degree that it takes as much time to repaint as meld uses to read and compare files. Now compare to tkdiff (I also close its window after it's done drawing): time tkdiff 0 1 real 0m1.941s user 0m0.166s sys 0m0.060s It only took 0.166 sec user time to read files and to draw the differences. diff command called by tkdiff takes close to 0 user time. X server probably took ~1.820 sec. Striking difference with meld on this very simple and basic example. Conclusion: Two problems are exposed by this testcase. First problem is that meld is unreasonably slow. Second problem is that it significantly loads X server for it's time to be noticeable.
I've looked at your testcase. I have no idea why you're getting such discrepancies between your real and user/sys times - I don't see this - but either way I don't think you have any reason for believing that X is involved. If you profiled your test case (and I have), then you'd see that 90% of the time is spent inside Gtk. If you looked harder, you'd probably find that it was spent doing text layout, something which Gtk does very differently to Tk. As I said, comparing Meld and tkdiff is not useful. I regularly go over the Meld code base looking for speed improvements, and will continue to do so. This bug, however, is not helping.
But pointing fingers to gtk doesn't really help the case. The truth is that when I try running meld in production environment on the real cases, every time I see meld to be much slower. I like the way it shows the results much better, but speed is a killer. It may be that gtk isn't used right, maybe it's called in inefficient way. I am not a meld developer so I don't know. That's why I filed this PR. Comparing meld and tkdiff makes perfect sense to me since they do pretty much exactly the same thing, just in different ways. Meld results are much nicer, but the question is should this really cost 45X user time difference is a question.
Created attachment 217650 [details] kcachegrind profile (valgrind with callgrind plugin) How was the testcase profiled? How did you determine that this is gtk fault? Looking at callgrind profile (attached) I see that almost all top records which account for ~70% are python related. Nothing from gtk there. Only some minor libpango contribution. Currently, this testcase takes ~14.16 sec in meld and ~0.367 sec in tkdiff. This difference (~40X) is outrageous, that's why I am reopening this PR. Speaking from the standpoint of the user in this case, I see this problem every time I run meld. It takes very very long to compare moderately sized files (1k lines). Technology differences shouldn't be used to explain the slow runtime since technology doesn't matter for the user, running time and quality of results do.
The test case was profiled using Python's profiling tools, specifically cProfile. Callgrind isn't generally used for Python profiling, and unless care is taken, I wouldn't trust the results. Running your test case on a 4-year-old machine, this completes in 5.5 seconds. I have no idea why it's taking three times as long for you. Your test case is 15k lines, not 1k. With the two-line patch below, the time to run your test case drops from 5.5 seconds to 3.5 seconds. I'm not going to apply this patch because I consider the trade-offs involved to be very dubious. If you'd like to try and figure out what's going on, be my guest. As far as I can tell, setting the textviews to editable appears to trigger re-validation and re-layout in GTK+. I may be wrong. It's entirely possible that there is a problem with PyGtk here, or that we're hooked up to too many signals or whatever. I don't know. diff --git a/meld/filediff.py b/meld/filediff.py index 5158cf0..6673852 100644 @@ -283,7 +283,7 @@ class FileDiff(melddoc.MeldDoc, gnomeglade.Component): def _disconnect_buffer_handlers(self): for textview in self.textview: - textview.set_editable(0) + textview.set_sensitive(False) for buf in self.textbuffer: assert hasattr(buf,"handlers") for h in buf.handlers: @@ -291,7 +291,7 @@ class FileDiff(melddoc.MeldDoc, gnomeglade.Component): def _connect_buffer_handlers(self): for textview in self.textview: - textview.set_editable(1) + textview.set_sensitive(True) for buf in self.textbuffer: id0 = buf.connect("insert-text", self.on_text_insert_text) id1 = buf.connect("delete-range", self.on_text_delete_range)
Created attachment 217684 [details] cProfile file So there is an issue that meld runs 3+ times slower on FreeBSD than on Ubuntu on the same HW. I let maintainers know about this. I also ran the cProfile on my BSD system. Attaching the result. The top lines by tottime there are these: 6589090 33.147 0.000 59.565 0.000 filediff.py:706(killit) 6595034/6594984 5.748 0.000 5.748 0.000 {len} 6584556 8.216 0.000 8.216 0.000 {method 'count' of 'unicode' objects} 94 10.658 0.113 70.224 0.747 {method 'sub' of '_sre.SRE_Pattern' objects} 6589090 6.096 0.000 6.096 0.000 {method 'group' of '_sre.SRE_Match' objects} 6589102 6.360 0.000 6.360 0.000 {method 'groups' of '_sre.SRE_Match' objects} I don't see where are these expensive gtk+ calls? Am I running cProfile wrong? I just replaces profile.run with cProfile.run in meld.
That's a very odd trace, and looks nothing like what I get. Your trace shows that you're spending almost all your time doing text filtering; that's the 'killit' call at the top. Do you have a large number of complex text filters defined and active? Do 'killit' and the calls on '_sre.SRE_Pattern' show up on Ubuntu as well? I just went and enabled three of the default text filters, and I can only just see regex calls starting to come up in the profile. The easiest way to get a profile is to run "python -m cProfile -s time bin/meld" from the top level Meld directory.
Created attachment 217689 [details] cProfile log from Ubuntu i386 VM My Ubuntu VM also shows totally different profile, see attachment. I am not sure how do can I see what text filters are defined. I just installed meld from ports, didn't do anything special. Pretty much all port options are defaults for everything, including python.
Ubuntu VM profile is similar to what I see here. You can check which text filters you have enabled by going to Edit -> Preferences and selecting the "Text Filters" tab. Any filters that are enabled will have a tick in the active column. The only way the BSD profile makes any sense to me is if *many* filters are active; we don't use regexes for anything much else.
The only text filter that was defined for me was this one: All whitespace [ \t\r\f\v]* Removing it makes user time to drop to 3.45 sec. So this filter is extremely expensive. I probably added it myself not realizing the consequences. Without the filter profile becomes more like on Ubuntu: ncalls tottime percall cumtime percall filename:lineno(function) 1 6.627 6.627 8.069 8.069 {gtk._gtk.main} 16 0.185 0.012 0.446 0.028 matchers.py:77(preprocess) 32017 0.140 0.000 0.140 0.000 {method 'append' of 'list' objects} 668 0.138 0.000 0.138 0.000 {method 'insert' of 'gtk.TextBuffer' objects} ... So number one performance issue is text filters. And number two is gtk._gtk.main.
I have no idea why this is still open, so closing. Current 3.11.x doesn't have the text validation wait that I mentioned in comment 8 anyway - apparently the revalidation in GtkTextView was fixed - and the regex 'problem' was always a red herring.