KDevelop: abstractfilemanagerimport benchmark
ClosedPublic

Authored by rjvbb on Sep 29 2017, 2:58 PM.

Details

Summary

This is the benchmark that I wrote for D7995. It can be called with a list of source directories to measure the time it takes to import these in parallel as projects. It aims to do this as KDevelop does it, but without any additional overhead that could come from a full-blown project controller, code parsing etc.

The main goal of this benchmark is to compare the overhead from creating and populating a project dirwatcher (see D7995). Therefore it also measures the time it takes to delete the project dirwatcher (= an aspect of closing projects). This is done sequentially.

Diff Detail

Lint
Lint Skipped
Unit
Unit Tests Skipped
There are a very large number of changes, so older changes are hidden. Show Older Changes
Restricted Application added a subscriber: kdevelop-devel. · View Herald TranscriptSep 29 2017, 2:58 PM
rjvbb added inline comments.Sep 29 2017, 3:01 PM
kdevplatform/project/abstractfilemanagerplugin.h
107–120

The request was for a standalone benchmark. I have thus added these 2 additions to AFMP. I don't mind simply removing them and their application in the benchmark if they're seen as a problem.

rjvbb updated this revision to Diff 20096.Sep 29 2017, 3:05 PM

benchmark .cpp was missing

rjvbb set the repository for this revision to R32 KDevelop.Sep 29 2017, 3:05 PM
rjvbb updated this revision to Diff 20098.Sep 29 2017, 3:26 PM

splice out the dirwatcher creation timing; in the current KDevelop code this includes the addDir() call...

rjvbb set the repository for this revision to R32 KDevelop.Sep 29 2017, 3:27 PM
rjvbb added a comment.Sep 29 2017, 3:49 PM

Example output on Mac (2.7Ghz i7 with 12Gb RAM and a fast HDD)

time tests/abstractfilemanagerpluginimportbenchmark kdevelop-git-5/ ~/cworks/new/gcc/gcc7-mp9-work/gcc-7.2.0/ /opt/local/linux-ports/
kdevplatform.serialization: "The data-repository at /Users/bertin/.cache/kdevduchain/abstractfilemanagerpluginimportbenchmark-{1a0f5b28-f6ee-4c7f-ae47-ab53181b36bd} has to be cleared."
KDirWatch backend: QFSWatch
Starting import of project # 0 at "/Users/bertin/work/src/new/KDE/KF5/kdevelop-git-5"
        creating dirwatcher took 0.796 seconds
Starting import of project # 1 at "/Users/bertin/cworks/new/gcc/gcc7-mp9-work/gcc-7.2.0"
        creating dirwatcher took 111.693 seconds
Starting import of project # 2 at "/opt/local/linux-ports"
        creating dirwatcher took 9.406 seconds
imported project 0 with 3677 files (watched: 3677 ): 121.344 seconds
imported project 2 with 904 files (watched: 904 ): 0.343 seconds
imported project 1 with 75038 files (watched: 75038 ): 13.047 seconds
Done.
        closing project 0 : 14.588 seconds
        closing project 1 : 202.722 seconds
        closing project 2 : 1.192 seconds
310.140 user_cpu 23.914 kernel_cpu 5:44.62 total_time 96.9%CPU
rjvbb added a comment.Sep 29 2017, 7:27 PM

Some final timing results, from my Linux rig (1.6Ghz N3150, 8Gb RAM, ZFS on an SSHD)

> time abstractfilemanagerpluginimportbenchmark kdevelop-git-5 ~/cworks/Scratch/gcc/gcc-7.2.0 /opt/local/linux-ports 
KDirWatch backend: Inotify
Starting import of project # 0 at "/home/bertin/work/src/Scratch/KDE/KF5/kdevelop-git-5"
        creating dirwatcher took 0.173 seconds
Starting import of project # 1 at "/home/bertin/cworks/Scratch/gcc/gcc-7.2.0"
        creating dirwatcher took 1.019 seconds
Starting import of project # 2 at "/opt/local/linux-ports"
        creating dirwatcher took 0.044 seconds
imported project 2 with 5051 files (watched: 5051 ): 0.724 seconds
imported project 0 with 6568 files (watched: 6568 ): 1.949 seconds
imported project 1 with 75038 files (watched: 75038 ): 2.822 seconds
Done.
        closing project 0 : 0.01 seconds
        closing project 1 : 0.033 seconds
        closing project 2 : 0.001 seconds
4.724 user_cpu 1.735 kernel_cpu 0:04.98 total_time 129.5%CPU

Using QFileSystemWatcher:

> time env KDIRWATCH_METHOD=QFSWatch abstractfilemanagerpluginimportbenchmark kdevelop-git-5 ~/cworks/Scratch/gcc/gcc-7.2.0 /opt/local/linux-ports/
KDirWatch backend: QFSWatch
Starting import of project # 0 at "/home/bertin/work/src/Scratch/KDE/KF5/kdevelop-git-5"
        creating dirwatcher took 1.398 seconds
Starting import of project # 1 at "/home/bertin/cworks/Scratch/gcc/gcc-7.2.0"
        creating dirwatcher took 202.161 seconds
Starting import of project # 2 at "/opt/local/linux-ports"
        creating dirwatcher took 2.576 seconds
imported project 2 with 5051 files (watched: 5051 ): 0.749 seconds
imported project 0 with 6568 files (watched: 6568 ): 205.659 seconds
imported project 1 with 75038 files (watched: 75038 ): 5.374 seconds
Done.
        closing project 0 : 39.803 seconds
        closing project 1 : 257.608 seconds
        closing project 2 : 0.01 seconds
515.422 user_cpu 19.418 kernel_cpu 8:27.21 total_time 105.4%CPU

The 2nd timings show how the actual import of the smaller project 0 (KDevelop) is held up by the dirwatcher creation for the big project 1 (GCC 7.2) which is imported a lot faster.

rjvbb updated this revision to Diff 20161.Sep 30 2017, 3:40 PM

the dirwatcher deletion timing should probably be part of this patch.

rjvbb set the repository for this revision to R32 KDevelop.Sep 30 2017, 3:41 PM
mwolff requested changes to this revision.Oct 1 2017, 12:03 PM
mwolff added a subscriber: mwolff.
mwolff added inline comments.
kdevplatform/project/abstractfilemanagerplugin.cpp
124

If you find this overly useful (I don't personally, but OK), please commit this part right away with the following code:

#ifdef TIME_IMPORT_JOB
QElapsedTimer timer;
timer.start();
#endif

delete m_watchers.take(project);

#ifdef TIME_IMPORT_JOB
qCDebug(FILEMANAGER) << "Deleting dir watcher took" << timer.elapsed() / 1000.0 << "seconds for project" << project->name();
#endif
kdevplatform/project/abstractfilemanagerplugin.h
107

remove this, it's imo not useful to know from the benchmark number and its an approximation anyways

119

remove. if necessary connect to IProjectController::projectClosing internally, but don't let others call this directly

kdevplatform/project/tests/abstractfilemanagerpluginimportbenchmark.cpp
42

remove, once the two new functions are gone

55

{ on its own line

61

should be handled outside the creation of this object (i.e. don't create an instance when this invariant isn't upheld)

72

remove once above is fixed

76

don't output a project number, us the project name/path only

101

s_numBenchmarksRunning, but I'd actually remove this as a static here and instead push it to a stack variable in main below

112

imo it's more useful to know the number of files and dirs rather than the number of watched items (that should be an implementation detail, cf. comment above)

116

move down, see "MOVE_TO_HERE" marker below

135

you could try to init with AutoTestShell::init({"no plugins"}) to ensure no other plugin gets loaded

148

indent align the &app with the benchmark above, increment indent level below (such that }); is again on the same level)

152

MOVE_TO_HERE

159
if (benchmarks.isEmpty()) {
    qWarning() << "no projects to import";
    return 1;
}
return app.exec();
This revision now requires changes to proceed.Oct 1 2017, 12:03 PM
rjvbb added inline comments.Oct 1 2017, 1:25 PM
kdevplatform/project/abstractfilemanagerplugin.cpp
124

Not exactly like that: the timer should only be started when the project is still being watched. Without that conditional the debug statement can print multiple additional times with a 0s timing.

I'll push to 5.2 and hold off updating this rev. until the commit has been merged by someone.

kdevplatform/project/abstractfilemanagerplugin.h
107

The benchmark timings do depend on this number, so they really only means something when printed with the number of watched items. At least when the number is correct, so if I remove it here I'll have to find another way to obtain the info in the follow-up patch.

IMHO this is all the more true if the improved algorithm refrains from watching folders that are filtered out because that means you cannot even do a simple find foo -type d | wc -l to determine the number of directories under foo.

Actually, I could already introduce the ProjectWatcher class (it no longer needs a mutex), with or without the bit that applies the project filter. That should make the number of watched items available in the benchmark via dynamic_cast<ProjectWatcher*>(m_manager->projectWatcher(m_project)). Not watching likely filter suspects like .git and build should reduce import times a bit already so I like the idea, let me know if that's acceptable?

119

Can you please explain how that would work without creating a ProjectController instance in the benchmark?
I do get a non-null result from projectController() in the benchmark app but when I get a crash when I do emit projectController()->projectClosing(m_project). I don't understand why, the only explanation that makes sense to me is that the method returns an uninitialised IProjectController pointer.
The signal could also be sent from the Project instance itself rather than from the ProjectController.

Is there no other way to call this hidden code without patching code that's otherwise completely unrelated to dirwatching issues?

PLEASE don't just look at the patch, *try* it locally, look at the numbers you get with the most relevant KDirWatch methods and decide whether or not the time spent deleting dirwatchers is really irrelevant to you.

I honestly don't really understand why AFMP couldn't have a (protected) method that basically does the opposite of what the import method does.

kdevplatform/project/tests/abstractfilemanagerpluginimportbenchmark.cpp
76

OK here, but not in the other output (knowing the completion order is useful IMHO).

112

What comment are you referring to?

fileSet().size() gives the number of files and dirs. In the follow-up patch only dirs will be watched, so the 2 values being printed will give provide the number of files and the number of dirs in a way that I consider most useful to assess the impact of dirwatcher initialisation. (The benchmark will print the actual time of that step in the current code.)

rjvbb marked 12 inline comments as done.Oct 1 2017, 4:33 PM
rjvbb added inline comments.
kdevplatform/project/tests/abstractfilemanagerpluginimportbenchmark.cpp
116

not entirely certain what to move - probably just the "Done" output?

rjvbb marked an inline comment as done.Oct 1 2017, 4:40 PM

revision update pending 5.2->master merge and more info. Changes marked done already uploaded to D7995.

rjvbb updated this revision to Diff 20252.Oct 2 2017, 2:50 PM

Updated as instructed except for the projectClosing issue (waiting for more info there).

I've also gone ahead with my idea to introduce the ProjectWatcher class here already. It won't be possible yet to obtain the number of watched items (ProjectWatcher::size() will return 1 in the benchmark with the current approach so the information is not printed in this version.

rjvbb set the repository for this revision to R32 KDevelop.Oct 2 2017, 2:50 PM
rjvbb updated this revision to Diff 20585.Oct 11 2017, 10:40 AM

This revision removes direct timing of dirwatcher destruction and thus the now unnecessary AFMP::projectClosing method..

The output text is reworded slightly, and a total run timer allows to assess at a glance how well import of multiple project can be done in parallel (as well as other overhead, like dirwatcher destruction, when combined with an external process timer).

I hope this unblocks the hold-up.

rjvbb set the repository for this revision to R32 KDevelop.Oct 11 2017, 10:41 AM
rjvbb marked 3 inline comments as done.
mwolff requested changes to this revision.Oct 19 2017, 12:22 PM

the commit message should include some output numbers and document how to run this test with different backends. I.e. something like the following should be the desired commit message _and_ also shows the desired output from the benchmark itself:

On my (linux) machine, running the benchmark on the kdevelop master repo, I measure the following:

KDIRWATCH_METHOD=inotify ./kdevplatform/project/tests/abstractfilemanagerpluginimportbenchmark ~/projects/kf5/src/extragear/kdevelop/kdevelop/
KDirWatch backend: Inotify
Benchmark set-up took 0.152 seconds
Starting import of project "/home/milian/projects/kf5/src/extragear/kdevelop/kdevelop"
creating dirwatcher took 0.021 seconds
imported project 0 with 5611 elements (XXX files & YYY folders) took 0.062 seconds
Done in 0.236 seconds total (excluding dirwatcher destruction)
Closing project
Done in XYZ seconds total

KDIRWATCH_METHOD=QFSWatch ./kdevplatform/project/tests/abstractfilemanagerpluginimportbenchmark ~/projects/kf5/src/extragear/kdevelop/kdevelop/
KDirWatch backend: QFSWatch
Benchmark set-up took 0.181 seconds
Starting import of project "/home/milian/projects/kf5/src/extragear/kdevelop/kdevelop"
creating dirwatcher took 0.14 seconds
imported project 0 with 5611 elements (XXX files & YYY folders) took 0.066 seconds
Done in 0.388 seconds total (excluding dirwatcher destruction)
Closing project
Done in XYZ seconds total

Note that the number of calls to addDir is completely useless output (it's an implementation detail). What is interesting, is the total time only.

Note also how for me, the QSFWatch dirwatcher creation only takes 0.14s for the kdevelop project, which is still pretty fast. Using FAM takes ages though. Please do add the numbers for your mac machine, too.

kdevplatform/project/projectwatcher.cpp
39

this filter check here is conceptually different functionality compared to before. I'm not saying it's a bad change, but it makes this patch do more than just adding a benchmark. Please split your patches up to make it easier to review _and_ to keep the history sane.

Splitting up this patch that way will also allow us to assess the impact of this change.

kdevplatform/project/tests/abstractfilemanagerpluginimportbenchmark.cpp
44

Name the class after the file: AbstractFileManagerPluginImportBenchmark

58

here and below: don't use qInfo, it's usually not enabled. Instead, use qDebug or better yet use a QTextStream m_out member and initialize it with m_out(stdout).

This revision now requires changes to proceed.Oct 19 2017, 12:22 PM
Note that the number of calls to `addDir` is completely useless output (it's an implementation detail). What is interesting, is the total time only.

I agree that this is true for the current implementation. However, it's the only thing we can measure at the moment without burdening the benchmark or the importer itself with code to count the number of directories in a project. That number of calls should be seen in the light of before and after comparison. I'm fine with meto output this only in a benchmark mod included with the actual dirwatcher modification (in which case it can be printed as "number of dirs watched" since addDir() will be adding a single dir only).

Note also how for me, the QSFWatch dirwatcher creation only takes 0.14s for the kdevelop project, which is still pretty fast.

Maybe you have a fast SSD and had been doing enough things in that project directory that the entire tree structure was cached? I systematically get much longer durations, though they do stabilise on lower numbers than what I can get when the tree structure isn't cached at all.

FWIW, I'm currently seeing 13115 elements under my working copy of the master branch (and still 12896 when I move the .git directory out of the way). Of those, 9202 are entries from the in-source build directory, which contains *only* the results of running cmake, *not* of building.

Maybe you could also try with the gcc 7.2.0 source tree?

Splitting up this patch that way will also allow us to assess the impact of this change.

So I should defer this review to get that basic change in, for instance the introduction of a ProjectWatcher class? Is that going to be taking as long as this review? I'm not against doing it, but it shouldn't make management of my local patches completely unworkable either so please do provide any feedback that could speed up getting that change in (preferably still into the 5.2 branch). Feel free to email them to keep them out of this ticket.

here and below: don't use qInfo, it's usually not enabled. Instead, use qDebug or better yet use a QTextStream m_out member and initialize it with m_out(stdout).

I thought that too, but got corrected on another ticket (I think by dfaure): qInfo *is* enabled by default, or was it qCInfo? I'll use QTextStream and just hope it'll print everything as qInfo c.s. do.

rjvbb added a comment.Oct 20 2017, 2:14 PM

Anyone interested: here's an observation related to benchmarking dirwatching:

I have a session with a project for audacity (2.2.0-rc1, git working copy). I notice that KDevelop becomes noticeably busy on the UI thread when I run configure on that project (in a regular in-tree set-up). I'd be curious to know if others see this as well (with stock KDevelop) - be it with audacity or any comparably large project that contains sources for more than a few 3rd-party dependencies that all use autoconf.

In D8059#157312, @rjvbb wrote:
Note that the number of calls to `addDir` is completely useless output (it's an implementation detail). What is interesting, is the total time only.

I agree that this is true for the current implementation. However, it's the only thing we can measure at the moment without burdening the benchmark or the importer itself with code to count the number of directories in a project. That number of calls should be seen in the light of before and after comparison. I'm fine with meto output this only in a benchmark mod included with the actual dirwatcher modification (in which case it can be printed as "number of dirs watched" since addDir() will be adding a single dir only).

Again - no! The important number is the time spent. Anything else is not interesting at all. The idea to output the dirs and files of a project (which can be done quite easily using the ProjectModel API) would give some secondary information. But it's not crucial at all.

The number of calls to addDir is totally uninteresting. Even more so as before it was/is recursive internally while you are about to change it. So what value is there when the benchmark shows "1 call to addDir" now, and then eventually "1000 calls to addDir"?!

Again: We only care about the time it takes to import the project.

Note also how for me, the QSFWatch dirwatcher creation only takes 0.14s for the kdevelop project, which is still pretty fast.

Maybe you have a fast SSD and had been doing enough things in that project directory that the entire tree structure was cached? I systematically get much longer durations, though they do stabilise on lower numbers than what I can get when the tree structure isn't cached at all.

On Linux or on Mac? One way or another, this clearly shows (again, I keep repeating myself) that we need data from a proper profiler. Please do run it through perf as I have requested multiple times. As a first step, at least run the benchmark through perf stat as that would show us already whether you are suffering from IO or CPU load.

FWIW, I'm currently seeing 13115 elements under my working copy of the master branch (and still 12896 when I move the .git directory out of the way). Of those, 9202 are entries from the in-source build directory, which contains *only* the results of running cmake, *not* of building.

So the issue for you is maybe that you are tracking the build folder as part of the project? What happens when you move that build dir to a sibling folder?

Maybe you could also try with the gcc 7.2.0 source tree?

Splitting up this patch that way will also allow us to assess the impact of this change.

So I should defer this review to get that basic change in, for instance the introduction of a ProjectWatcher class?

No, you should first submit this benchmark without changing any other code. As I said above the ProjectWatcher class is not required for this benchmark.

Is that going to be taking as long as this review? I'm not against doing it, but it shouldn't make management of my local patches completely unworkable either so please do provide any feedback that could speed up getting that change in (preferably still into the 5.2 branch). Feel free to email them to keep them out of this ticket.

Reviewing takes as long as it takes. You cannot magically make it faster.

here and below: don't use qInfo, it's usually not enabled. Instead, use qDebug or better yet use a QTextStream m_out member and initialize it with m_out(stdout).

I thought that too, but got corrected on another ticket (I think by dfaure): qInfo *is* enabled by default, or was it qCInfo? I'll use QTextStream and just hope it'll print everything as qInfo c.s. do.

Do use QTextStream please.

In D8059#157415, @rjvbb wrote:

Anyone interested: here's an observation related to benchmarking dirwatching:

I have a session with a project for audacity (2.2.0-rc1, git working copy). I notice that KDevelop becomes noticeably busy on the UI thread when I run configure on that project (in a regular in-tree set-up). I'd be curious to know if others see this as well (with stock KDevelop) - be it with audacity or any comparably large project that contains sources for more than a few 3rd-party dependencies that all use autoconf.

Again, use a profiler and see where the load comes from. But sure, if you are running in-tree, a lot of dirty directory change signals will come in and need to be handled. This also means the filter will run on them. Depending on how many events are fired, this can take some time of course. But this is not part of this patch here at hand! Please concentrate on getting this one in first...

rjvbb added a comment.Oct 23 2017, 7:01 PM
The number of calls to addDir is totally uninteresting. Even more so as before it was/is recursive internally while you are about to change it. So what value is there when the benchmark shows "1 call to addDir" now, and then eventually "1000 calls to addDir"?!

Again: We only care about the time it takes to import the project.

Please read me carefully. I DO care about more than time alone. If it takes 10 hours to add a quadrizillion directories I might be happy, but not if it takes 10 minutes to add only 5 directories (directory content shouldn't matter since we're watching only directories).

Printing the number of directories loaded is only appropriate if we know that it corresponds to the exact number of directories watched. We don't know that here, there are 2 different models at play.

Please don't try to teach me how to set up experiments (and I won't try to explain what the PS in FLOPS stand for).

On Linux or on Mac?

On both. I should have kept this information to my self, I've only been posting and comparing the stabilised scores anyway.

So the issue for you is maybe that you are tracking the build folder as part of the project?

The benchmark cannot exclude anything under the target directory, and the current dirwatcher implementation cannot either (it lets KDirWatch::addDir() do its recursive thing). Neither have filters set up.

What happens when you move that build dir to a sibling folder?

Load times decrease, evidently.

I rarely use in-tree build dirs, so the build directory is NOT what is slowing things down under normal use.

rjvbb added a comment.Oct 23 2017, 7:11 PM

But sure, if you are running in-tree

Off-topic, but out-of-tree autoconf projects have never worked properly for me in KDevelop. They only give me the content of the build directory in the Project toolview. Not very useful...

In D8059#159018, @rjvbb wrote:
The number of calls to addDir is totally uninteresting. Even more so as before it was/is recursive internally while you are about to change it. So what value is there when the benchmark shows "1 call to addDir" now, and then eventually "1000 calls to addDir"?!

Again: We only care about the time it takes to import the project.

Please read me carefully. I DO care about more than time alone. If it takes 10 hours to add a quadrizillion directories I might be happy, but not if it takes 10 minutes to add only 5 directories (directory content shouldn't matter since we're watching only directories).

Printing the number of directories loaded is only appropriate if we know that it corresponds to the exact number of directories watched. We don't know that here, there are 2 different models at play.

Please don't try to teach me how to set up experiments (and I won't try to explain what the PS in FLOPS stand for).

Your experiment is pointless, so of course I'll teach you. I won't accept the patch as-is, so would you rather I just say no without giving an explanation?

One more try in teaching you how this is supposed to be used:

  1. run benchmark with perf stat -r 5 on a predefined folder structure, let's say GCC source dir, remember the output, this is your baseline
  2. apply a patch that supposedly optimizes something (e.g. apply the filter before watching a dir)
  3. rerun the benchmark on the same folder, again with perf stat -r 5
  4. compare the output of the two perf stat runs.

Since the benchmark input (e.g. GCC source dir) does not change in between, the number of dirs is not interesting at all. We only care about whether the import after applying the patch is faster or not. All of this information would then be put into the commit message of the patch and then pushed up for review, along with all information that is required for someone else to reproduce the test.

On Linux or on Mac?

On both. I should have kept this information to my self, I've only been posting and comparing the stabilised scores anyway.

What is a stabilised score?

So the issue for you is maybe that you are tracking the build folder as part of the project?

The benchmark cannot exclude anything under the target directory, and the current dirwatcher implementation cannot either (it lets KDirWatch::addDir() do its recursive thing). Neither have filters set up.

The point is: I don't have the build dir as part of the project, so maybe that's why it's so much faster for me?

What happens when you move that build dir to a sibling folder?

Load times decrease, evidently.

By how much?

I rarely use in-tree build dirs, so the build directory is NOT what is slowing things down under normal use.

rjvbb updated this revision to Diff 21195.Oct 23 2017, 8:05 PM
rjvbb marked 2 inline comments as done.

patch updated through KDevelop's patchreview plugin

rjvbb set the repository for this revision to R32 KDevelop.Oct 23 2017, 8:05 PM
rjvbb added a comment.Oct 23 2017, 8:35 PM

I see further discussion is pointless, we'll never agree. You want an incomplete benchmark, fine, you got one (I can strip out more data that's not import time).

Timing results will be posted once the patch is ready to go in.

rjvbb updated this revision to Diff 21200.Oct 23 2017, 10:41 PM

output cleanup: print only import timings.

rjvbb set the repository for this revision to R32 KDevelop.Oct 23 2017, 10:42 PM
mwolff requested changes to this revision.Oct 24 2017, 8:36 AM
mwolff added inline comments.
kdevplatform/project/abstractfilemanagerplugin.cpp
495

this part of the patch (i.e. introducing the temporary and referencing it instead of looking it up repeatedly in m_watchers) is fine, but unrelated to this patch. Please commit it separately.

kdevplatform/project/tests/abstractfilemanagerpluginimportbenchmark.cpp
49

break long line, add newline after path,

60

instead of using "\n"; m_out.flush(), use << endl; which achieves the same

69

remove QObject:: prefix, break long line by adding a newline before this,

160

excess newline

This revision now requires changes to proceed.Oct 24 2017, 8:36 AM
rjvbb marked 3 inline comments as done.Oct 25 2017, 11:08 AM
rjvbb updated this revision to Diff 21300.Oct 25 2017, 11:48 AM

Updated as requested.

Results on Linux ("stock" dirwatching):

INotify backend

> perf stat -r 3 abstractfilemanagerpluginimportbenchmark gcc-7.2.0
KDirWatch backend: Inotify
Starting import of project gcc-7.2.0
        creating dirwatcher took 1.265 seconds
importing project 0 took 3.162 seconds
Done in 4.428 seconds total
KDirWatch backend: Inotify
Starting import of project gcc-7.2.0
        creating dirwatcher took 1.232 seconds
importing project 0 took 3.098 seconds
Done in 4.331 seconds total
KDirWatch backend: Inotify
Starting import of project gcc-7.2.0
        creating dirwatcher took 1.307 seconds
importing project 0 took 3.14 seconds
Done in 4.448 seconds total

 Performance counter stats for 'abstractfilemanagerpluginimportbenchmark gcc-7.2.0' (3 runs):

       5115.785502      task-clock:u (msec)       #    0.976 CPUs utilized            ( +-  0.84% )
                 0      context-switches:u        #    0.000 K/sec                  
                 0      cpu-migrations:u          #    0.000 K/sec                  
            23,868      page-faults:u             #    0.005 M/sec                    ( +-  0.86% )
     4,749,860,940      cycles:u                  #    0.928 GHz                      ( +-  0.14% )
     3,097,364,964      instructions:u            #    0.65  insn per cycle           ( +-  0.01% )
       741,470,473      branches:u                #  144.938 M/sec                    ( +-  0.02% )
        23,852,653      branch-misses:u           #    3.22% of all branches          ( +-  0.23% )

       5.241247911 seconds time elapsed                                          ( +-  0.76% )

QFileSystemWatcher backend

> env KDIRWATCH_METHOD=QFSWatch time perf stat -r 3 abstractfilemanagerpluginimportbenchmark gcc-7.2.0
KDirWatch backend: QFSWatch
Starting import of project gcc-7.2.0
        creating dirwatcher took 183.192 seconds
importing project 0 took 3.54 seconds
Done in 186.734 seconds total
KDirWatch backend: QFSWatch
Starting import of project gcc-7.2.0
        creating dirwatcher took 176.655 seconds
importing project 0 took 4.017 seconds
Done in 180.672 seconds total
KDirWatch backend: QFSWatch
Starting import of project gcc-7.2.0
        creating dirwatcher took 175.662 seconds
importing project 0 took 3.14 seconds
Done in 178.803 seconds total

 Performance counter stats for 'abstractfilemanagerpluginimportbenchmark gcc-7.2.0' (3 runs):

     175971.327864      task-clock:u (msec)       #    0.959 CPUs utilized            ( +-  1.38% )
                 0      context-switches:u        #    0.000 K/sec                  
                 0      cpu-migrations:u          #    0.000 K/sec                  
            34,114      page-faults:u             #    0.194 K/sec                    ( +-  0.48% )
   310,070,244,556      cycles:u                  #    1.762 GHz                      ( +-  0.20% )
    54,088,827,245      instructions:u            #    0.17  insn per cycle           ( +-  0.00% )
     8,733,088,527      branches:u                #   49.628 M/sec                    ( +-  0.00% )
       206,976,905      branch-misses:u           #    2.37% of all branches          ( +-  0.35% )

     183.439620257 seconds time elapsed                                          ( +-  1.32% )
rjvbb set the repository for this revision to R32 KDevelop.Oct 25 2017, 11:49 AM
mwolff accepted this revision.Oct 26 2017, 9:15 AM

please fix the nit, then feel free to commit to master branch. Note again that the commit message should include your measurements you posted above.

Otherwise, it's interesting to see that QFSWatcher takes so much more CPU time, this should really be profiled and fixed upstream.

kdevplatform/project/tests/abstractfilemanagerpluginimportbenchmark.cpp
50

align with the ( in the line above

This revision is now accepted and ready to land.Oct 26 2017, 9:15 AM
This revision was automatically updated to reflect the committed changes.
rjvbb added a comment.Oct 27 2017, 4:44 PM
Otherwise, it's interesting to see that QFSWatcher takes so much more CPU time, this should really be profiled and fixed upstream.

That's assuming the KDirWatch wrapper doesn't introduce a lot of additional overhead when using the QFSW backend. But even so, this would make sense if QFSW doesn't use highly optimised kernel features for watching files.

Also, when I compare the results of a recursive KDirWatch::addDir that adds dirs and files with my optimised implementation that watches only directories, the difference is negligible with the iNotify backend. I don't know that SDK, but one explanation would be that it handles individual file monitoring via a shared monitor on the enclosing directory.

I did introduce a small inaccuracy in the commit message: the test gcc source tree is not on a HDD but on an SSD (mounted over USB3 and Thunderbolt). The results loading the project from the internal HDD are worse:

> time abstractfilemanagerpluginimportbenchmark gcc-7.2.0
KDirWatch backend: QFSWatch
Starting import of project gcc-7.2.0
        creating dirwatcher took 115.008 seconds
importing project 0 took 3.793 seconds
Done in 118.802 seconds total
105.242 user_cpu 12.118 kernel_cpu 2:01.32 total_time 96.7%CPU
rjvbb added a comment.Oct 27 2017, 5:26 PM

So, where do we go from here?

I started preparing the introduction of the ProjectWatcher class (which was rejected from the benchmark introduction patch) but then realised that it isn't justified as a standalone commit. That class only makes sense if you're going to use it other than by handing the project top dir to ProjectWatcher::addDir, telling it to add everything under that directory.

The class makes sense as part of my patch that lets FileManagerListJob determine which directories (dirs only!) get watched, and it's with that use pattern that it makes sense to check if the directory trips a filter.

IOW, I'm not in favour of going through a review just to introduce a ProjectWatcher class knowing it does things (like locking a mutex) that are superfluous in the current context.

As to checking the project filter in ProjectWatcher::addDir() : it seems obvious that this *must* have a significant benefit under the right conditions (in-tree build dir and/or the .git directory for projects with a matching exclusion filter). Is it really necessary to go through an additional review just to add the filter check?

mwolff added a comment.Nov 2 2017, 9:47 PM
In D8059#160968, @rjvbb wrote:

So, where do we go from here?

I started preparing the introduction of the ProjectWatcher class (which was rejected from the benchmark introduction patch) but then realised that it isn't justified as a standalone commit. That class only makes sense if you're going to use it other than by handing the project top dir to ProjectWatcher::addDir, telling it to add everything under that directory.

The class makes sense as part of my patch that lets FileManagerListJob determine which directories (dirs only!) get watched, and it's with that use pattern that it makes sense to check if the directory trips a filter.

IOW, I'm not in favour of going through a review just to introduce a ProjectWatcher class knowing it does things (like locking a mutex) that are superfluous in the current context.

As to checking the project filter in ProjectWatcher::addDir() : it seems obvious that this *must* have a significant benefit under the right conditions (in-tree build dir and/or the .git directory for projects with a matching exclusion filter). Is it really necessary to go through an additional review just to add the filter check?

Fair enough, I see the point you are making. Feel free to update the existing patch that changes the watcher, then we can continue from there

rjvbb added a comment.Nov 3 2017, 12:43 PM

OK, will do - but then what about D8579? Should I just include the changes to the benchmark tool in this patch set?

FWIW, I wrote my previous message on this ticket before I realised that calling the project filter from the ProjectWatcher class is redundant in the current implementation, since ProjectWatcher::addDir() is apparently called only with valid directories. That just means the whole point I was making in the previous message is moot and the ProjectWatcher class can simply be introduced as a means to improve the dirwatching algorithm just like it was intended originally.