elasitx performance issue with itk > 4.8


#1

Hi all,

I recently upgraded my elastix registration software, and simultatneously upgrading itk from 4.8 to the 4.13. This greatly affected the registration timings (3 to 4-fold slower). After some testing, I found it this problem starts with itk 4.9. My parameterfiles contains a MultiMetric registration with Bending Energy Penalty and Advanced Mattes Mutual Information. From the elastix logs. it seems that the increased timings are mainly caused by the multi-metric registration (and they are e.g. not present in a single metric mattes mutual information).

Is there any registration expert or itk expert that may have an idea on the cause of this, and how to solve it?

I’m running Windows 10, using VS2013 (CV12), 64 bits, and compile itk and elastix with all default settings.

Best,

Theo


(Matt McCormick) #2

Hi Theo,

Did you build ITK and elastix in Release mode? Visual Studio defaults to Debug.

HTH,
Matt


(Dženan Zukić) #3

Also it is possible that different versions of Visual Studio optimize code differently. A relatively recent discussion about that can be found here.


#4

Dear Matt,

Yes, indeed I did compile both in Release mode.

Btw, I tried both with elastix 4.8 and 4.9, as well as the current version of elastix. And similar behavior was on another laptop running Windows 7.

Best regards,

Theo


#5

Dear Dzenanz,

Thanks for your response. In this case, I compiled all with the same Visual Studio (VS 2013, which is VC12), on the same system.

Best regards,

Theo


(Dženan Zukić) #6

Can you provide a minimum working example? In doing so, you might as well discover what is the source of the performance loss.


#7

Hi,

I can provide a working example (don’t think it is really minimum), let me know where I can send it.

It demonstrates the elastix call, that does a rigid registration, followed by a non-rigid one. When inspecting the elastix log-files between both runs, the major timing difference is in the non-rigid (the multi-metric registration), mainly in the last column of timings (which, as far as I understand, relates to combining the metric values, i.e. the multi-metric part).
I can confirm that running in single metric mode (i.e. leaving out the bending energy), there is not much difference between both itk-versions.

Best,

Theo


(Dženan Zukić) #8

That is the hard part of narrowing down a problem: making a small example that demonstrates the problem.

If you think combining the metric values is the problem, can you modify the code of your big example to save the metric values to a file, then write a small example which reads them and combines the metrics?

As for providing the source code, you can copy it into a post. That can affect formatting and indentation, so the best way is to put it in a public repository and provide the link to it.


#9

Yes, I understand.

However, in this case I’m using elastix (elastix.isi.uu.nl), which is a registration software that uses itk. I’m using that program, and not programming it myself. I think I could provide a stripped-down registration example (fake images and registration parameter file) but I certainly will not be able to adapt the code as you suggested.

Main reason for posting was hoping that someone in the itk-community (possibly also with elastix experience) recognizes this problem, or knows what relevant changes have happened in itk when going from 4.8.2 to 4.9.1 (something with multi-threading?) that may have caused this problem.

Best,

Theo


(Dženan Zukić) #10

@Niels_Dekker @kaspermarstal @stefanklein @mstaring @denis.p.shamonin Can you pitch in?


(Kasper Marstal) #11

Theo was so kind as to make us aware of the issue and we suggested that he posted here in case someone experienced similar issues and had an idea where the regression might come from. It is on our todo list and just wanted to gather as much information as possible.


(Bradley Lowekamp) #12

I am unaware of anything that could have caused this. It we were we would likely have considered alternatives.

I would suggest narrowing down to a small Elasitx invocation that causes this 3-4x slow down. Then use git-bisect to narrow down the offending ITK commit range. A script will have to be created to compile Elasitx against the ITK version git is bisected, then run your Elastix invocation to test the timing.


(Niels Dekker) #13

FYI, I’m still busy trying to find what caused the performance regression reported by @tvanwalsum But at least, I can reproduce the issue. It must have been introduced somewhere between 4.8.2 and 4.9 release candidate 2:

That is, between:

74155d0b7059fde841832c92a9aec78c79bc68c0
Matt McCormick, 2015-11-12
ENH: Bump CMakeLists.txt version to 4.8.2.

And:

b5ac097618781214edada6649563d2b18a19f99f
Matt McCormick, 2015-12-01
Merge topic ‘CppTest’

To be continued!


(Niels Dekker) #14

Update: after having tested the example case from Theo (@tvanwalsum), I think I may now have found the cause of the performance issue :star_struck: Theo reported here that elastix performed 3 to 4 times slower with ITK >= 4.9 than with ITK 4.8. :open_mouth:

So this is what I found: Elastix internally makes extensive use of itk::TimeProbe: it often creates a local itk::TimeProbe object. This class is derived from itk::ResourceProbe. With ITK 4.9, the ResourceProbe() constructor has an extra function call, that was not yet in ITK 4.8: GetSystemInformation(). This function call appears very time consuming (at least that’s what I observed on VS2013 + Windows 10).

ITK 4.9.0 itk::ResourceProbe() constructor calls GetSystemInformation() and Reset():
https://github.com/InsightSoftwareConsortium/ITK/blob/v4.9.0/Modules/Core/Common/include/itkResourceProbe.hxx#L51

ITK 4.8.2 itk::ResourceProbe() constructor only just calls Reset():
https://github.com/InsightSoftwareConsortium/ITK/blob/v4.8.2/Modules/Core/Common/include/itkResourceProbe.hxx#L42

So now I’m wondering how to fix this issue. Is it really necessary for the constructor of itk::TimeProbe to always call GetSystemInformation()?


(Niels Dekker) #15

Just submitted :slight_smile:

I just hope that a fix can still be included with ITK 5!


(Bradley Lowekamp) #16

Awesome job tracking that down!!

Delaying that call makes since. Does the information change? Can some of it be called once and saved into a static member?


(Niels Dekker) #17

Thanks, Brad. Honestly I don’t know much about these Probe classes. Elastix just does:

itk::TimeProbe timer;
timer.Start();
// Do some time-consuming task here...
timer.Stop();
// ...and then print timer.GetMean() as "ms".

For such a use case, I don’t think GetSystemInformation() is necessary at all.

Clearly, the system info is necessary for itk::ResourceProbe::PrintSystemInformation(). If this is the only place where the system info is used, I think it would be better to get it there, instead of in the default-constructor.

It’s probably possible, technically, to store the system info in static data members. But I have to say, I’m not a fan of static data. If this PrintSystemInformation() is in practice rarely called, I think it’s not nice to keep its data “alive” for the entire run of the process.


(Dženan Zukić) #18

… then the system information could be stored in a local static variable, which will be instantiated only if the Print method is called.


(Niels Dekker) #19

@dzenanz In the mean time I saw that PrintSystemInformation() is not the only ResourceProbe member function using system info. The other one is itk::ResourceProbe::PrintJSONSystemInformation(os).

I’m preparing a fix now, please wait :slight_smile:


(Niels Dekker) #20

Please review:

I hope it can be included with ITK 5.0 (and possibly also ITK 4.13.2…?)