Darktable: [Performance] darkroom much less performant, dt-2.7 vs. dt-2.6.2

[AxelG-DE]

Describe the bug
According to my observation, we do have a more than noticeable performance issue for darkroom in git-master vs. official 2.6.2, which makes it feel very _sticky_ on my side.

Please read this entirely, before you draw your conclusion. I think it is a bit complex and even I tried to be narrow, the report got a bit longer (also there is always a risk, I do make mistakes in English)

This bug report, from my point of view (and I might be wrong), tries to comprehend:

• High CPU load even opencl is working #2404
  and
• double preview triggered when zooming in #2064

To Reproduce
Steps to reproduce the behavior:

1. Load this picture: https://pixls-discuss.s3.dualstack.us-east-1.amazonaws.com/original/3X/3/4/34f49707aff221f5795c8a18cf8ffc14a186cb2a.DNG
   (play raw, red tulips by pphoto CC-BY-NC 4.0)
2. (pixelpipe merely has sharpen, rotation and basecurve)
3. Change WB to 2000, close dt
4. Start dt with the -d perf option
5. Change WB from 2000 to 25000 (copy the relevant lines from log)
6. repeat 1-5 with tonecurve _Gamma 0.5_ and Zoom _from 200% to fit2screen_

• All those I have done and concluded in attached .xlsx file
• In coloumn "A" I put a formular like =D11-$D$11 in order to eliminate the offset and have a relative time
• In coloumn "B" I placed a formular like =B12-B11 in order to have the used time per step
• in the WB-Chart I have marked some obvious findings, where in the other sheets, for "efficiency" reasons, merely marked the most obvious one

From there you can see, that dt-2.7 (at least here) responds way slower in total, than 2.6.2, while the single actions, they seem to be faster.

The lag I "feel" (until screen gets updated), seems actually even harder than the values I found here... (see section _Expected behavior_)

Expected behavior
Being not slower, "laggier" than 2.6.2, ideally even faster, more responsive than 2.6.2

I don't want to misapply (correct word acc. to dict. ???), that @aurelienpierre just now stated in #2064, for him, the 2.7 is way more responsive than 2.6.2
It might be, we find either something totally different (anything else might influence the UI) or a hardware related issue.

Log file analysis in attached .xlsx file created with libreoffice
dt-perf_20190429.xlsx

Platform (please complete the following information):

• OS: [Gentoo linux]
• Version [rolling distro up to date]
• nvidia-drivers 418.56
• darktable 2.7.0+1087~g7fe35d67d (found it time ago already)
• gtk+ 3.24.4-r1
• cairo 1.16.0-r3
• Core i9 9900k no OC
• 32 GB ram @3333MHz 16-18-18-32
• library on a NVMRe SSD
• photos and xmp on a 5TB Seagate HDD
• 2x GTX 1060 G1 OC

Additional context
I would like to open a new topic on pixls.us for casual talk, awareness and share experiences, while keeping this issue here for the developers and solution oriented topics.

I hope that split is appreciated and could be implemented?

_Update_1_
I did so here

[edgardoh]

@AxelG-DE , this doesn't really helps to define the problem, if I understand correctly, what you are reporting is that 2.7 "feels" slower than 2.6, but this numbers doesn't represent that. The total amount of time spent until the last call to the the pipe is finish is not relevant here, that last call does nothing.
What's important is when the image is refreshed with the last changes and when the user is able to continue working, if dt keeps working on the background that's another issue. Or even better, try to define more objectively what "feels slower" means.

[AxelG-DE]

@edgardoh
Now I am a bit lost. What I do experience is described in #2404, which I understood, was too less objective. Maybe after the long day to conclude all the information I was tooooo short in explaining what I "feel".

Actually the line above Expected Behavior and the ones below do outline, what I mean :smile:

Each and any action I perform in darkroom feels WAY more lag than 2.6.2. That latter feels more responsive and crisp in any action. Very instantaneously, which dt-2.7 does not at all. Each action seems to take 1s prior the sceen is updated in 2.7

[edgardoh]

OK, so the problem seems to be the refresh of the image. The process time of each module and the entire pipe is faster (or similar) in 2.7 than in 2.6, correct?

[AxelG-DE]

The problem is the refresh time, yes.

For the process, if I understood correctly, seems yes, those single items seems to be faster. That's one of the reasons, why in #2404 we didn't actually nail it down, as we compared item by item.

Actually the total processing time really seems to me to correlate to my experience. Hence your first comment partially shocked me :smile:

[edgardoh]

This won't be easy to narrow it down, but to start I'll say try it with opencl disabled, so we can be sure is not related to that.
If you can do a bisect it would be great, there's has been a lot of changes in 2.7, so even if not the exact commit (there may be not just one) at least knowing one in 2.7 where it works as 2.6 will help.

[AxelG-DE]

It is late now, here, need urgently to get some sleep :wink: (GMT+7)

I'll disable opencl tomorrow

Your last paragraph, I didn't quite get it. What is bisect and how to do it?
Indeed I'll do what I can to narrow it down

hope it didn't come with preview2 :smile:

[edgardoh]

It is late now, here, need urgently to get some sleep 😉 (GMT+7)

I'll disable opencl tomorrow

No hurry.

Your last paragraph, I didn't quite get it. What is bisect and how to do
it?

git bisec is an utility that check-out a commit, you try it, report back
and check-out another based on your feedback. It allows find a commit that
break something.
I don't use it (I do it by hand) but there's plenty of tutorials around. Or
you can pick a commit, try it, and go forward or backwards depending if it
works or not.

Indeed I'll do what I can to narrow it down

hope it didn't come with preview2 😄

au contraire, if its preview2 it will be easier for me to fix it.

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/darktable-org/darktable/issues/2484#issuecomment-487772404,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AD5LLJINHSBU2POTKEKYJPLPS54PNANCNFSM4HJG5QBQ
.

[AxelG-DE]

@edgardoh donno, in which timezone you are in, but good morning :-)

I'll disable opencl tomorrow

No hurry.

I did a quicky try without recording the -d perf but --disable-opencl actually gives me the same user experience, where dt-2.6.2 is snappier than dt 2.7 (the lag feels the same)

git bisec is an utility that check-out a commit, you try it, report back and check-out another based on your feedback.

• I expected a kind of roll-back or move forward tool.
• I will learn about bisect (unfortunately that will take time), saw a very first tutorial, so I get an idea....
• o.k., I found gitschooldude bisect tutorial and is pretty easy to understand
• I'll follow up this evening
• defining good/bad will become challenging, as I seem have to always recompile and test
• in my first quick attempt bisect ask me to remove src/external/rawspeed/[4 lines] ??? tricky as it could(!) be the culprit and I always would need to move it in and out during testing...

hope it didn't come with preview2 :smile:

au contraire, if its preview2 it will be easier for me to fix it.

I know, :-) I said so, because I was indirectly pushing for this topic with my wish of detachable side panels. BTW: I kept commenting on that closed PR... (maybe not the best idea, to comment on closed topics?)

[AxelG-DE]

What kinda test guy could I bee, if I donno my GMT? :smile:

I was too tired. GMT+2 so it was 1:00 a.m....

[edgardoh]

At this point I'm just fishing, so no idea about a commit. I think that the
bigger and oldest is the "Custom module order" PR, you can try with the
commit previous to that. Or just the last before 2.7.

With bisect you inform a "good" and "bad" commit and it will checkout one
in the middle for you, so you don't have to go through every single commit.

El mar., 30 abr. 2019 a las 2:40, AxelG-DE ([e-mail])
escribió:

@edgardoh https://github.com/edgardoh donno, in which timezone you are
in, but good morning :-)

I'll disable opencl tomorrow

No hurry.

I did a quick try without recording the -d perf but --disable-opencl
actually gives me the same user experience, where dt-2.6.2 is snappier than
dt 2.7 (the lag feels the same)

git bisec is an utility that check-out a commit, you try it, report back
and check-out another based on your feedback.

• I expected a kind of roll-back or move forward tool.
• I will learn bisec (unfortunately that will take time)
• Do I than have to go each single commit forward/backward or you have
  some suspicious ones in mind?

hope it didn't come with preview2 😄

au contraire, if its preview2 it will be easier for me to fix it.
I know, :-) I said so, because I was indirectly pushing for this topic
with my wish of detachable side panels. BTW: I kept commenting on that
closed PR... (maybe not the best idea)

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/darktable-org/darktable/issues/2484#issuecomment-487826757,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AD5LLJL4OCDAT5UP3WVBDE3PS7LV3ANCNFSM4HJG5QBQ
.

[rawfiner]

On my portable computer, I get a behavior similar to the one of AxelG-DE. In particular, what I have is a lag between the moment when I change a slider value and the moment when I get the message "working.." on the screen. After the message is shown, I think the computation time is the same as before.
I did a git bisect, but could not build some commits due to library versions, so I am sorry that I don't have a single git commit. I found that this behavior appeared between commit 9327e1b3200299 and commit 1f40f2b22ebf1e64

@aurelienpierre , do you have any idea of what could cause this lag?

[AxelG-DE]

At this point I'm just fishing, so no idea about a commit. I think that the bigger and oldest is the "Custom module order" PR, you can try with the commit previous to that. Or just the last before 2.7. With bisect you inform a "good" and "bad" commit and it will checkout one in the middle for you, so you don't have to go through every single commit.

More or less I understood, how bisect will work
However, I donno how to identify the last commit prior 2.7, I thought, the first one (at the bottom with git log --graph --abbrev-commit --decorate --oneline --all is already the 2.7

Also, as I said above, I get a kind of error message, that I should delete rawspeed. That makes it quite unhandy, as I understood, after each run of bisect I need to compile and test the version bisect selects as "head". At that point of time I firstly need to bring back rawspeed manually... Anyhow, I would need some time to get used to bisect.

@rawfiner Thank you very much for confirmation. I need to study your last paragraph later again, as now I need to do other things...

[TurboGit]

What about d9b652cf10baba5f8f3df8ac32c3ee4f748efcde?

Worth trying removing the g_timeout_add() completely and call the routine directly.

[edgardoh]

@TurboGit , I just did that in #2486. Is just to try it, so no the final version.

[edgardoh]

@AxelG-DE , could you try PR #2486 against 2.6?

[AxelG-DE]

I'd like to, very much

As a total newbie to little more advanced git features like bisect (where I understood the basics but far away from mastering it), I would need a step by step introduction, how to temporarily implement a commit (and remove, if fails).

Sorry for being of little help at this point, but willing to learn.

I wonder if @rawfinder as a pro and confirm my issue somehow, could be faster?

:blush:

[edgardoh]

A pull request (PR) is not a commit, is a request to merge one or more commits, this in particular hasn't been merged yet.

To test it, on your darktable directory:

$ git fetch upstream pull/2486/head:performance_test

then:

$ git checkout performance_test

then build it as usual, when you are done:

$ git checkout master

to go back to the official, unstable branch.

Or you can clone dt on a new directory if you don't want to mess with your current installation.

[AxelG-DE]

Thank you, I'll follow

[AxelG-DE]

I needed to learn this first
https://github.com/Esri/developer-support/wiki/Setting-the-upstream-for-a-fork
:smiley:

[AxelG-DE]

@edgardoh
Did the quick tests (WB, tonecurve, zoom), it is VERY CRISP now, as I expected.
(Comparison in Excel-file yet to be done, but today fully occupied)

Cannot wait to see it merged, as I would like soon to checkout master, in order to get the latest master :-)

Is there a "risk", it might not be work for all modules? Do we need to test, whether all modules are "lag-free"?

[AxelG-DE]

I did one quick -d perf and it also confirms (in my way of seing it), it is now same fast (not faster, yet) as 2.6.2
What I see, the line [dev] took 0,000 secs (0,000 CPU) to load the image is gone. Those used up ~0.1s to 0.3s in my tests, I reported initially

[edgardoh]

@edgardoh https://github.com/edgardoh
Did the quick tests (WB, tonecurve, zoom), it is very CRISP now, as I
expected.

Great!

Cannot wait to see it merged, as I would like soon to checkout master, in
order to get the latest master :-)

I'll remove it from this PR, is better for this to have its own, so not
sure when is going to be ready.

Is there a "risk", it might not be work for all modules? Do we need to
test, whether all modules are "lag-free"?

It shouldn't affect anything else, but let's wait to see the real fix
implemented.

[AxelG-DE]

Would you mind to put the new PR# here, than I'd like to follow up :)

[AxelG-DE]

@edgardoh
A little bit OT here, sorry for that:
In case I don't do git checkout master, by means stay on git checkout performance_test and then _would do_ a

git pull
git submodule update
./build.sh

What would happen to that PR, I have recently "installed"?

[edgardoh]

No idea, but you can:

$ git status

it will tell you the active branch, if is not master, the go ahead and
checkout master.

El mié., 1 may. 2019 a las 9:26, AxelG-DE ([e-mail])
escribió:

@edgardoh https://github.com/edgardoh
A little bit OT here, sorry for that:
In case I don't do git checkout master, by means stay on git checkout
performance_test and then would do a

git pull
git submodule update
./build.sh

What would happen to that PR, I have recently "installed"?

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/darktable-org/darktable/issues/2484#issuecomment-488270132,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AD5LLJJ5EPTLTFP2OZVS53DPTGD73ANCNFSM4HJG5QBQ
.

[AxelG-DE]

My aim was a bit different :)

If Master gets an update prior a PR got merged, do I need to checkout to master first and later checkout to the PR again, or is there a shortcut?

[edgardoh]

I have no idea what your goal is...

El mié., 1 may. 2019 a las 10:45, AxelG-DE ([e-mail])
escribió:

My aim was a bit different :)

If Master gets an update prior a PR got merged, do I need to checkout to
master first and later checkout to the PR again, or is there a shortcut?

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/darktable-org/darktable/issues/2484#issuecomment-488286052,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AD5LLJLMWSR7XIZE2MVDEKLPTGNIFANCNFSM4HJG5QBQ
.

[edgardoh]

@TurboGit , do you want to rollback the timeout thing or to try something different?

[TurboGit]

I think at this stage I'll remove the timeout. Maybe will have a better way, but the purpose of this was to make dt faster and in fact for some unknown reasons it is slower.

[AxelG-DE]

@edgardoh
sorry, that I expressed my self obviously in a misunderstanding way :-) (maybe, because from time to time I type on my mobile phone)
My goal is:

1. 
   
   • I like your PR that much, I don't wanna miss it anymore until the time it is in the master
   
   
2. 
   
   • in between I still would like to appreciate the other master changes
   
   
3. 
   
   • so, what I think I have to do is: git checkout master
   
   
4. 
   
   • do the git pull (and all other necessary steps to update git-master)
   
   
5. 
   
   • afterwards "git checkout performance_test" and rebuild again
   
   

(indeed that is anyway dangerous, if Pascal adds another solution, I saw is message, right now)

Here I was just wondering, whether I could skip step 3) and just do the git pull and build and whether or not that would work and the PR is still in or I definitely need to follow steps 1-5

Maybe you think, I am inpatient, we found a way quite quickly, in this issue :smile: That would be correct. When you consider my #2404 in the same pond and the time, until I found it and struggle to nail it down, it bothered me for a while. Hence I am soooooo HAPPY about your PR :-)

[AxelG-DE]

One little thing is still strange. @aurelienpierre said, before this fix in PR2486, he already feels 2.7 was snappier than 2.6.2
How could this be? Is there something HW related? Or what else could cause something, which I consider a little risk for the wide userbase...

Am I too worried?

[TurboGit]

@edgardoh : done on master.

@AxelG-DE : can you double check that all is ok on current master? Thanks.

[aurelienpierre]

An alternative way to the timeout would be to store a timestamp at the beginning of the pipe processing, then another one when it completes. Starting a new processing would be forbidden as long as the completion timestamp is < to the beginning one.

I also tried to keep the processing trigger only on the button_release event, but then some events were lost in the sliders so it doesn't look like a good option.

[AxelG-DE]

@TurboGit
Indeed I will test, as soon I get back to my machine... (now grilling for dinner :smile: )

[Nilvus]

I think at this stage I'll remove the timeout. Maybe will have a better way, but the purpose of this was to make dt faster and in fact for some unknown reasons it is slower.

I've just tested the last revision with these timeout removed and I can confirm that lighttable views are much much better. Just on sticky preview were just before this commit, I need few seconds to see the image display correctly, now it's instantaneous, or 1 second max, even when changing images. That's really better and make dt more usable.

[AxelG-DE]

Dear @TurboGit
I can confirm, it is way more faster than before. (dt2.7+1099)
Also I'd like to say, the solution from @edgardoh was over-all ~20% faster. (Indeed nothing to talk about, if we consider, it was x7 before.)

After fiddling around in a spreadsheet, to me it looks like this PR #2486 vs 2.7+1099 (means values <100= PR is faster, values >100= master is fater) (you can see in attached .xlsx beginning wtih line 168 in the first sheet.
dt-perf_20190501.xlsx

27,15 % |   | `Weißabgleich'
93,92 % |   | `Spitzlicht-Rekonstruktion'
94,22 % |   | `Entrastern'
112,31 % |   | `Eingabefarbprofil'
118,45 % |   | `Basiskurve'
93,75 % |   | `schärfen'
92,81 % |   | `Ausgabefarbprofil'
67,95 % |   | `Gamma'
14,36 % |   | `Weißabgleich'
94,54 % |   | `Spitzlicht-Rekonstruktion'
136,28 % |   | [dev_process_preview]
72,47 % |   | `Entrastern'
78,22 % |   | `Eingabefarbprofil'
91,24 % |   | `Basiskurve'
92,19 % |   | `schärfen'
89,23 % |   | `Ausgabefarbprofil'
74,15 % |   | `Gamma'
109,52 % |   | [dev_process_image]

Cheers
Axel

[TurboGit]

Ok so let's just close this. We'll see if the solution from @edgardoh which is even faster can also be integrated at some point.

[rawfiner]

Tested today on master and that's much better :-)
Thanks to all of you for fixing this

[edgardoh]

Ok so let's just close this. We'll see if the solution from @edgardoh
https://github.com/edgardoh which is even faster can also be integrated
at some point.

My solution to what is faster than what?

—

You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/darktable-org/darktable/issues/2484#issuecomment-488573247,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AD5LLJKPAQJ3UL3JNPNDNHLPTKIAJANCNFSM4HJG5QBQ
.

[AxelG-DE]

@edgardoh
Se my comment above

But different solutions have different effects and hence a maintainer might decide against fastest solution for the sake of stability or safety, I could imagine.

[edgardoh]

@AxelG-DE , my fix is exactly the same as @TurboGit , if you've found another performance issue it has to be related to something else, this cannot impact on the performance of any given module or even the pipe, what's have been fixed is some delay on calling the pipe.

[AxelG-DE]

@edgardoh
Thank you, got it.

I donno exactly, how I could go back to that version I tested with you, maybe just by
'git checkout performance_test'

If so, I'd test more. Quite likely it may prove my idea is not correct. If it proves me to be right, I could bisect now ;)

[edgardoh]

The PR is still there unmodified, so you can check it out again.

El jue., 2 may. 2019 a las 14:49, AxelG-DE ([e-mail])
escribió:

@edgardoh https://github.com/edgardoh
Thank you, got it.

I donno exactly, how I could go back to that version I tested with you,
maybe just by
'git checkout performance_test'

If so, I'd test more. Quite likely it may prove my idea is not correct. If
it proves me to be right, I could bisect now ;)

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/darktable-org/darktable/issues/2484#issuecomment-488767726,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AD5LLJN5LCPVVAFV6RPFNSLPTMSULANCNFSM4HJG5QBQ
.

[AxelG-DE]

@edgardoh @TurboGit

I did quite some performance comparison between

• +1089 wit PR2486
• +1099
• +1112
  dt-perf_20190502.xlsx

Here and there the 1089 with PR2486 was a bit faster, but not everywhere and finally +1112 beet them up all :-) NOW I really really really think, that issue is closed :smile: :smile:

Again thank you all very much!

[AxelG-DE]

I am afraid, I was too fast with my aforementioned comment.

Believe it or not, fluently sliding the WB sliders, the response in 2.6.2 is still more instantaneously...

[AxelG-DE]

with the help of Christian K (pk5dark) I found out, it was “opencl_synch_cache=active module”

Switching that to false, what I also have for 2.6.2, the WB becomes almost the same smooth.