Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Multi-Frame DICOM load performace decreased substantially in 4.13.2+ #1542

Open
timbra339 opened this issue Jan 8, 2020 · 13 comments
Open

Multi-Frame DICOM load performace decreased substantially in 4.13.2+ #1542

timbra339 opened this issue Jan 8, 2020 · 13 comments
Assignees

Comments

@timbra339
Copy link

@timbra339 timbra339 commented Jan 8, 2020

I've updated my ITK libraries from 4.13.0 to 5.0.1 recently and noticed a quite substantial drop in DICOM data load performance.

I've looked a bit into this using the attached python test-file which loads a ~800MB multi-frame DICOM file. Here are the resulting load times using various versions of ITK (used python-wheels for that):

ITK Version: 4.13.0 (python-package itk==4.13.1.post1)
Loading took 2.3250107765197754 secs.

ITK Version: 4.13.2
Loading took 16.011502027511597 secs.

ITK Version: 5.0.0
Loading took 15.990726470947266 secs.

ITK Version: 5.0.1
Loading took 15.931232690811157 secs.

ITK Version: 5.1.0
Loading took 15.805387496948242 secs.

It looks like the performance drop cause was introduced with ITK 4.13.2, whose release notes state several changes to GDCM, so that appears to be a likely cause? The issues seems to be still in the current codebase, maybe it can be fixed for the upcoming 5.1 version? I can supply the test data if needed.

# -*- coding: utf-8 -*-

import itk
import time

print(f"ITK Version: {itk.Version.GetITKVersion()}")

reader = itk.ImageFileReader[itk.Image[itk.US, 3]].New(FileName = r"Volume_0000.dcm")
start = time.time()
reader.Update()
stop = time.time()

print(f"Loading took {stop-start} secs.")
@dzenanz

This comment has been minimized.

Copy link
Member

@dzenanz dzenanz commented Jan 8, 2020

Please give a link to the test data.

@timbra339

This comment has been minimized.

Copy link
Author

@timbra339 timbra339 commented Jan 8, 2020

Uploading the test data.
I've zeroed out the actual image content to make the file compressible, the runtimes for 4.13.0 and 5.1 are still as reported.
Volume_0000.zip

@thewtex

This comment has been minimized.

Copy link
Member

@thewtex thewtex commented Jan 8, 2020

ITK 5.1 RC 1 contains many GDCM updates.

You can install the wheels for testing with:

pip install --upgrade --pre itk

@malaterre

@timbra339

This comment has been minimized.

Copy link
Author

@timbra339 timbra339 commented Jan 8, 2020

@thewtex: This command installs the version 5.1rc1.post1 on my machine, which was the one that produced the

ITK Version: 5.1.0
Loading took 15.805387496948242 secs.

output. Should there be a more recent wheel instead?

@dzenanz

This comment has been minimized.

Copy link
Member

@dzenanz dzenanz commented Jan 8, 2020

@issakomi might also pitch in.

@issakomi

This comment has been minimized.

Copy link
Contributor

@issakomi issakomi commented Jan 8, 2020

@dzenanz thank you for CC, my app may be affected too
i confirm, tested with own C++ small prog, the issue doesn't exist in 4.13.1 and exists in 4.13.2.
itkGDCMImageIO didn't change, but GDCM was updated. The slowdown happens in
image.GetBuffer( (char*)pointer ) in GDCMImageIO::Read()

@issakomi

This comment has been minimized.

Copy link
Contributor

@issakomi issakomi commented Jan 8, 2020

Seems that this change in gdcmBitmap.h (in TryRAWCodec(char *buffer, bool &lossyflag) for particular image, the same in all codecs)

-codec.SetNeedOverlayCleanup( AreOverlaysInPixelData() );
+codec.SetNeedOverlayCleanup( AreOverlaysInPixelData() || UnusedBitsPresentInPixelData() );

makes the difference, not yet 100% sure, will check more later.

P.S. BTW, the test image Volume_0000 is strange, it has negative spacing, but it doesn't matter in particular case, tested with other images.

@thewtex

This comment has been minimized.

Copy link
Member

@thewtex thewtex commented Jan 8, 2020

Should there be a more recent wheel instead?

Yes, 5.1rc1.post1 is the current latest wheel.

@issakomi

This comment has been minimized.

Copy link
Contributor

@issakomi issakomi commented Jan 8, 2020

Rather sure now, my last post above was correct, image reader spend most time with cleaning unused bits...
(time in ms)

$ ./test Volume_0000.dcm 
    InternalReadImageInformation() dt=170
    AreOverlaysInPixelData()=false UnusedBitsPresentInPixelData()=true
    DoOverlayCleanup dt=10077
    Read() dt=10936

ITK reader dt=11581

Edit:
the change was introduced in
https://sourceforge.net/p/gdcm/gdcm/ci/f142274632546c4f1da44090f8a753a1d2cc8bbc/
and several further commits. I guess, may be, some Dicom files exist which have some issues with something in unused bits and it was a reason, don't know, but slowdown in very big, dilemma.

@malaterre

This comment has been minimized.

Copy link
Member

@malaterre malaterre commented Jan 9, 2020

-codec.SetNeedOverlayCleanup( AreOverlaysInPixelData() );
+codec.SetNeedOverlayCleanup( AreOverlaysInPixelData() || UnusedBitsPresentInPixelData() );

makes the difference, not yet 100% sure, will check more later.

The above change is actually required to be 100% conformant. There is not possible revert on my side for this piece of code. I can be more verbose here if needed.

Two solutions comes to mind:

  1. (hackish) Introduced a new option SkipCleanupUnusedBits in gdcm.ImageReader API
  2. Long term solution, check why bit masking implementation is so slow. I am pretty sure there are room for improvement here.
@timbra339

This comment has been minimized.

Copy link
Author

@timbra339 timbra339 commented Jan 9, 2020

P.S. BTW, the test image Volume_0000 is strange, it has negative spacing, but it doesn't matter in particular case, tested with other images.

Ah, thanks for pointing that out, this was a bug in the dicom exporter code.

@issakomi

This comment has been minimized.

Copy link
Contributor

@issakomi issakomi commented Jan 9, 2020

The above change is actually required to be 100% conformant.

I understand,

PS3.5 8.8.1
Receiving applications may not assume anything about the contents of unused bits, and in particular may not assume that they are zero, or that they contain sign extension bits.

I've already done an on/off UI option in my app, still in doubt about the default value.

@issakomi

This comment has been minimized.

Copy link
Contributor

@issakomi issakomi commented Jan 12, 2020

Deleted previous post, sorry, was wrong, overseen one thing.
It were probably also good to inform Slicer team about performance drop. BTW, i've preferred to set the variable to skip cleaning by default in my app (at least until it will be faster, if GDCM or myself will have time to speed up the process).

Edit:
tested the behavior of different viewers (Yes means the unused bits are cleaned or somehow skipped)

Aesculap   Yes
Inobitec   No
MicroDicom Yes
PixelMed   Yes
Radiant    Yes
TomoVision Yes
Weasis     No

couldn't find real examples with something hidden in unused bits, always zeros, here prepared test file

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
5 participants
You can’t perform that action at this time.