Issue at runtime when running slicer, it's very slow.
Probably related to IOFactory / static initializer. Steve did some investigation about it ...

I was able to build on windows, which is good, but the result is so slow as to be unusable. Over ten minutes to load a volume as shown below.

import datetime; start = datetime.datetime.now(); loadVolume('c:/tmp/CT-chest.nrrd'); end = datetime.datetime.now(); print(end-start)
True
0:10:20.417000

If I stop in the debugger while the load is taking place, there are many stack traces like the following. It appears that every shared library module is registering each of the IO factory items so that there is a huge number to iterate through.

ntdll.dll!0000000076f12d27()    
[Frames below may be incorrect and/or missing, no symbols loaded for ntdll.dll] 
ntdll.dll!0000000076f218e2()    
ntdll.dll!0000000076f1413d()    
ntdll.dll!0000000076f89bd9()    
ntdll.dll!0000000076f2dbc0()    
ntdll.dll!0000000076f1413d()    
kernel32.dll!0000000076ab300a()     

msvcr90d.dll!_free_base(void pBlock=0x00000000356dcc50) Line 109 + 0x14 bytes C
msvcr90d.dll!_free_dbg_nolock(void pUserData=0x00000000356dcc80, int nBlockUse=1) Line 1428 C++
msvcr90d.dll!_free_dbg(void pUserData=0x00000000356dcc80, int nBlockUse=1) Line 1258 + 0xe bytes C++
msvcr90d.dll!operator delete(void pUserData=0x00000000356dcc80) Line 54 + 0x12 bytes C++
msvcp90d.dll!std::allocator<unsigned short>::deallocate(unsigned short _Ptr=0x00000000356dcc80, unsigned int64 formal=32) Line 147 C++
msvcp90d.dll!std::basic_string<char,std::char_traits<char>,std::allocator<char> >::_Tidy(bool _Built=true, unsigned __int64 _Newsize=0) Line 2168 C++
msvcp90d.dll!std::basic_string<char,std::char_traits<char>,std::allocator<char> >::~basic_string<char,std::char_traits<char>,std::allocator<char> >() Line 916 + 0xf bytes C++
ITKCommon-4.3.dll!itk::ObjectFactoryBase::CreateObject(const char itkclassname=0x0000000031fc9e50) Line 654 C++
ITKCommon-4.3.dll!itk::ObjectFactoryBase::CreateInstance(const char itkclassname=0x0000000031fc9e50) Line 136 + 0x3b bytes C++
BRAINSDemonWarpLib.dll!itk::ObjectFactory<itk::GDCMImageIO>::Create() Line 60 + 0x22 bytes C++
BRAINSDemonWarpLib.dll!itk::GDCMImageIO::New() Line 95 + 0x41 bytes C++
BRAINSDemonWarpLib.dll!itk::CreateObjectFunction<itk::GDCMImageIO>::CreateObject() Line 70 + 0x43 bytes C++
ITKCommon-4.3.dll!itk::ObjectFactoryBase::CreateAllObject(const char itkclassname=0x000007fee8f58310) Line 677 + 0x45 bytes C++
ITKCommon-4.3.dll!itk::ObjectFactoryBase::CreateAllInstance(const char itkclassname=0x000007fee8f58310) Line 158 + 0x3e bytes C++
vtkITK.dll!itk::ImageIOFactory::CreateImageIO(const char path=0x00000000356c36d0, itk::ImageIOFactory::FileModeType mode=ReadMode) Line 29 + 0x15 bytes C++
vtkITK.dll!itk::ImageFileReader<itk::Image<float,3>,itk::DefaultConvertPixelTraits<float> >::GenerateOutputInformation() Line 116 + 0x35 bytes C++
ITKCommon-4.3.dll!itk::ProcessObject::UpdateOutputInformation() Line 1330 C++
vtkITK.dll!vtkITKArchetypeImageSeriesReader::ExecuteInformation() Line 441 C++
vtkFiltering.dll!vtkSource::ProcessRequest(vtkInformation request=0x000000002fddeb60, vtkInformationVector inputVector=0x0000000000000000, vtkInformationVector outputVector=0x00000000356aeb60) Line 527 C++
vtkFiltering.dll!vtkExecutive::CallAlgorithm(vtkInformation request=0x000000002fddeb60, int direction=1, vtkInformationVector inInfo=0x0000000000000000, vtkInformationVector outInfo=0x00000000356aeb60) Line 747 + 0x39 bytes C++
vtkFiltering.dll!vtkDemandDrivenPipeline::ExecuteInformation(vtkInformation request=0x000000002fddeb60, vtkInformationVector inInfoVec=0x0000000000000000, vtkInformationVector outInfoVec=0x00000000356aeb60) Line 496 C++
vtkFiltering.dll!vtkStreamingDemandDrivenPipeline::ExecuteInformation(vtkInformation request=0x000000002fddeb60, vtkInformationVector inInfoVec=0x0000000000000000, vtkInformationVector outInfoVec=0x00000000356aeb60) Line 375 + 0x25 bytes C++
vtkFiltering.dll!vtkDemandDrivenPipeline::ProcessRequest(vtkInformation request=0x000000002fddeb60, vtkInformationVector inInfoVec=0x0000000000000000, vtkInformationVector outInfoVec=0x00000000356aeb60) Line 242 + 0x22 bytes C++
vtkFiltering.dll!vtkStreamingDemandDrivenPipeline::ProcessRequest(vtkInformation request=0x000000002fddeb60, vtkInformationVector inInfoVec=0x0000000000000000, vtkInformationVector outInfoVec=0x00000000356aeb60) Line 301 C++
vtkFiltering.dll!vtkDemandDrivenPipeline::UpdateInformation() Line 412 C++
vtkFiltering.dll!vtkStreamingDemandDrivenPipeline::Update(int port=0) Line 312 + 0x13 bytes C++
vtkFiltering.dll!vtkSource::Update() Line 137 C++
MRMLCore.dll!vtkMRMLVolumeArchetypeStorageNode::ReadDataInternal(vtkMRMLNode refNode=0x0000000032397180) Line 350 + 0x3e bytes C++
MRMLCore.dll!vtkMRMLStorageNode::ReadData(vtkMRMLNode refNode=0x0000000032397180, bool temporary=false) Line 1089 + 0x21 bytes C++
vtkSlicerVolumesModuleLogic.dll!vtkSlicerVolumesLogic::AddArchetypeVolume(const std::list<ArchetypeVolumeNodeSet (cdecl)(std::basic_string<char,std::char_traits<char>,std::allocator<char> > &,vtkMRMLScene ,int),std::allocator<ArchetypeVolumeNodeSet (cdecl)(std::basic_string<char,std::char_traits<char>,std::allocator<char> > &,vtkMRMLScene ,int)> > & volumeRegistry=[7](0x000007fed1942ec8 anonymous namespace'::MultiVolumeNodeSetFactory(class std::basic_string<char,struct std::char_traits<char>,class std::allocator<char> > & ptr64,class vtkMRMLScene * ptr64,int),0x000007fed63210aaanonymous namespace'::DiffusionWeightedVolumeNodeSetFactory(class std::basic_string<char,struct std::char_traits<char>,class std::allocator<char> > & ptr64,class vtkMRMLScene ptr,...), const char filename=0x000000000434c6f8, const char volname=0x0000000031d9ee48, int loadingOptions=0, vtkStringArray fileList=0x0000000000000000) Line 535 + 0x41 bytes C++
vtkSlicerVolumesModuleLogic.dll!vtkSlicerVolumesLogic::AddArchetypeVolume(const char filename=0x000000000434c6f8, const char volname=0x0000000031d9ee48, int loadingOptions=0, vtkStringArray fileList=0x0000000000000000) Line 473 C++
qSlicerVolumesModule.dll!qSlicerVolumesIO::load(const QMap<QString,QVariant> & properties={...}) Line 157 + 0xab bytes C++
qSlicerBaseQTCore.dll!qSlicerCoreIOManager::loadNodes(const QString & fileType={...}, const QMap<QString,QVariant> & parameters={...}, vtkCollection loadedNodes=0x0000000032350b80) Line 321 + 0x1e bytes C++
qSlicerBaseQTGUI.dll!qSlicerIOManager::loadNodes(const QString & fileType={...}, const QMap<QString,QVariant> & parameters={...}, vtkCollection loadedNodes=0x0000000032350b80) Line 320 + 0x26 bytes C++
qSlicerBaseQTGUI.dll!qSlicerIOManager::qt_static_metacall(QObject _o=0x0000000008e07b90, QMetaObject::Call _c=InvokeMetaMethod, int _id=16, void _a=0x0000000000b38340) Line 113 + 0x37 bytes C++
qSlicerBaseQTGUI.dll!qSlicerIOManager::qt_metacall(QMetaObject::Call _c=InvokeMetaMethod, int _id=16, void _a=0x0000000000b38340) Line 156 C++
PythonQt.dll!PythonQtCallSlot(PythonQtClassInfo classInfo=0x00000000045d2710, QObject objectToCall=0x0000000008e07b90, _object args=0x000000000b71c630, bool strict=true, PythonQtSlotInfo info=0x000000002c3ba140, void firstArgument=0x0000000000000000, _object pythonReturnValue=0x0000000000b38718, void directReturnValuePointer=0x0000000000000000) Line 171 + 0x3c bytes C++
PythonQt.dll!PythonQtSlotFunction_CallImpl(PythonQtClassInfo classInfo=0x00000000045d2710, QObject objectToCall=0x0000000008e07b90, PythonQtSlotInfo info=0x000000002c3ba140, _object args=0x000000000b71c630, _object formal=0x0000000000000000, void firstArg=0x0000000000000000, void directReturnValuePointer=0x0000000000000000) Line 312 + 0x51 bytes C++
PythonQt.dll!PythonQtMemberFunction_Call(PythonQtSlotInfo info=0x000000002c3ba140, _object m_self=0x000000000b6e5db0, _object args=0x000000000b71c630, _object kw=0x0000000000000000) Line 250 + 0x5a bytes C++
PythonQt.dll!PythonQtSlotFunction_Call(_object func=0x00000000072915c8, _object args=0x000000000b71c630, _object kw=0x0000000000000000) Line 239 C++
python26.dll!PyObject_Call(_object func=0x0000000000000000, _object arg=0x0000000000000003, _object kw=0x000000000b71c630) Line 2493 C
python26.dll!do_call(_object func=0x0000000000000003, _object pp_stack=0x0000000000000001, int na=120133064, int nk=11767464) Line 3968 + 0xe bytes C
python26.dll!call_function(_object pp_stack=0x0000000000000001, int oparg=131) Line 3773 + 0x11 bytes C
python26.dll!PyEval_EvalFrameEx(_frame f=0x000000000bd45a88, int throwflag=0) Line 2416 C
python26.dll!PyEval_EvalCodeEx(PyCodeObject co=0x0000000007201ea0, _object globals=0xcccccccc00000004, _object locals=0x0000000000000004, _object args=0x0000000000000004, int argcount=4, _object kws=0x000000000bd45a38, int kwcount=0, _object defs=0x0000000007201ea0, int defcount=2, _object closure=0x0000000000000000) Line 3000 + 0xf bytes C
python26.dll!fast_function(_object func=0x0000000000000004, _object pp_stack=0x0000000000000001, int n=119160616, int na=-858993460, int nk=0) Line 3850 C
python26.dll!call_function(_object pp_stack=0x0000000000000001, int oparg=131) Line 3771 + 0x16 bytes C
python26.dll!PyEval_EvalFrameEx(_frame f=0x000000000bd45878, int throwflag=0) Line 2416 C
python26.dll!PyEval_EvalCodeEx(PyCodeObject co=0x0000000007201ee0, _object globals=0x0000000000000001, _object locals=0x0000000000000005, _object args=0x0000000000000001, int argcount=1, _object kws=0x000000000bd45808, int kwcount=2, _object defs=0x0000000007201ee0, int defcount=2, _object closure=0x0000000000000000) Line 3000 + 0xf bytes C
python26.dll!fast_function(_object func=0x0000000000000001, _object pp_stack=0x0000000000000001, int n=119583464, int na=504066982, int nk=2) Line 3850 C
python26.dll!call_function(_object pp_stack=0x0000000000000001, int oparg=131) Line 3771 + 0x16 bytes C
python26.dll!PyEval_EvalFrameEx(_frame f=0x000000000bd45658, int throwflag=198465112) Line 2416 C
python26.dll!fast_function(_object func=0x0000000000000003, _object pp_stack=0x000000000b704c08, int n=198093512, int na=112, int nk=0) Line 3837 C
python26.dll!call_function(_object pp_stack=0x0000000000000001, int oparg=131) Line 3771 + 0x16 bytes C
python26.dll!PyEval_EvalFrameEx(_frame f=0x000000000bd44e18, int throwflag=0) Line 2416 C
python26.dll!PyEval_EvalCodeEx(PyCodeObject co=0x0000000000000000, _object globals=0x0000000000000001, _object locals=0x0000000000000000, _object args=0x0000000000000000, int argcount=1, _object kws=0x0000000000000000, int kwcount=0, _object defs=0x0000000000000000, int defcount=0, _object closure=0x0000000000000000) Line 3000 + 0xf bytes C
python26.dll!function_call(_object func=0x0000000000000000, _object arg=0x000000000b6f6da0, _object kw=0x0000000000000000) Line 529 + 0x3c bytes C
python26.dll!PyObject_Call(_object func=0x000000000b6f6da0, _object arg=0x000000000bcea4a8, _object kw=0x0000000000000000) Line 2493 C
python26.dll!instancemethod_call(_object func=0x000000000b6ffa68, _object arg=0x0000000002bf1048, _object kw=0x0000000000000000) Line 2580 C
python26.dll!PyObject_Call(_object func=0x0000000002bf1048, _object arg=0x0000000000b3a8a8, _object kw=0x000000000b6ffa68) Line 2493 C
python26.dll!PyEval_CallObjectWithKeywords(_object func=0x0000000004446d20, _object arg=0x0000000000000001, _object kw=0x0000000000000001) Line 3620 C
PythonQt.dll!PythonQtSignalTarget::call(_object callable=0x000000000b6ffa68, const PythonQtMethodInfo methodInfos=0x0000000004446d20, void arguments=0x0000000000b39d70, bool skipFirstArgumentOfMethodInfo=false) Line 124 + 0x13 bytes C++
PythonQt.dll!PythonQtSignalTarget::call(void arguments=0x0000000000b39d70) Line 55 + 0x2e bytes C++
PythonQt.dll!PythonQtSignalReceiver::qt_metacall(QMetaObject::Call c=InvokeMetaMethod, int id=4, void arguments=0x0000000000b39d70) Line 261 C++
QtCored4.dll!QMetaObject::metacall(QObject object=0x000000002fc293a0, QMetaObject::Call cl=InvokeMetaMethod, int idx=4, void argv=0x0000000000b39d70) Line 246 C++
QtCored4.dll!QMetaObject::activate(QObject sender=0x000000002fb007c0, const QMetaObject m=0x000000006ab6bf68, int local_signal_index=2, void argv=0x0000000000b39d70) Line 3566 + 0x49 bytes C++
QtGuid4.dll!QAbstractButton::clicked(bool _t1=false) Line 221 C++
QtGuid4.dll!QAbstractButtonPrivate::emitClicked() Line 550 C++
QtGuid4.dll!QAbstractButtonPrivate::click() Line 541 + 0xa bytes C++
QtGuid4.dll!QAbstractButton::mouseReleaseEvent(QMouseEvent e=0x0000000000b3af58) Line 1124 C++
PythonQt.dll!PythonQtShell_QPushButton::mouseReleaseEvent(QMouseEvent e=0x0000000000b3af58) Line 10330 C++
QtGuid4.dll!QWidget::event(QEvent event=0x0000000000b3af58) Line 8372 C++
QtGuid4.dll!QAbstractButton::event(QEvent e=0x0000000000b3af58) Line 1083 C++
QtGuid4.dll!QPushButton::event(QEvent e=0x0000000000b3af58) Line 684 C++
PythonQt.dll!PythonQtShell_QPushButton::event(QEvent e=0x0000000000b3af58) Line 9958 C++
QtGuid4.dll!QApplicationPrivate::notify_helper(QObject receiver=0x000000002fb007c0, QEvent e=0x0000000000b3af58) Line 4551 + 0x15 bytes C++
QtGuid4.dll!QApplication::notify(QObject receiver=0x000000002fb007c0, QEvent e=0x0000000000b3af58) Line 4094 + 0x51 bytes C++
QtCored4.dll!QCoreApplication::notifyInternal(QObject receiver=0x000000002fb007c0, QEvent event=0x0000000000b3af58) Line 915 + 0x26 bytes C++
QtCored4.dll!QCoreApplication::sendSpontaneousEvent(QObject receiver=0x000000002fb007c0, QEvent event=0x0000000000b3af58) Line 234 + 0x4c bytes C++
QtGuid4.dll!QApplicationPrivate::sendMouseEvent(QWidget receiver=0x000000002fb007c0, QMouseEvent event=0x0000000000b3af58, QWidget alienWidget=0x000000002fb007c0, QWidget nativeWidget=0x000000002dbd2670, QWidget * buttonDown=0x000000006aea7340, QPointer<QWidget> & lastMouseReceiver={...}, bool spontaneous=true) Line 3160 + 0x16 bytes C++
QtGuid4.dll!QETWidget::translateMouseEvent(const tagMSG & msg={...}) Line 3363 + 0x3f bytes C++
QtGuid4.dll!QtWndProc(HWND hwnd=0x00000000007e04e4, unsigned int message=514, unsigned int64 wParam=0, int64 lParam=9961711) Line 1696 + 0x15 bytes C++
user32.dll!0000000076dd9bd1()
user32.dll!0000000076dd98da()
QtCored4.dll!QEventDispatcherWin32::processEvents(QFlags<enum QEventLoop::ProcessEventsFlag> flags=0x0000000000b3f220) Line 810 C++
QtGuid4.dll!QGuiEventDispatcherWin32::processEvents(QFlags<enum QEventLoop::ProcessEventsFlag> flags=0x0000000000b3f26c) Line 1202 + 0x27 bytes C++
QtCored4.dll!QEventLoop::processEvents(QFlags<enum QEventLoop::ProcessEventsFlag> flags=0x0000000000b3f2e8) Line 150 C++
QtCored4.dll!QEventLoop::exec(QFlags<enum QEventLoop::ProcessEventsFlag> flags=0x0000000000b3f370) Line 204 + 0x59 bytes C++
QtCored4.dll!QCoreApplication::exec() Line 1187 + 0x23 bytes C++
QtGuid4.dll!QApplication::exec() Line 3813 C++
SlicerApp-real.exe!`anonymous namespace'::SlicerAppMain(int argc=1, char argv=0x0000000004308af0) Line 183 + 0x6 bytes C++
SlicerApp-real.exe!WinMain(HINSTANCE__ hInstance=0x000000013f7f0000, HINSTANCE hPrevInstance=0x0000000000000000, char lpCmdLine=0x0000000000d2775d, int nShowCmd=1) Line 202 + 0xe bytes C++
SlicerApp-real.exe!tmainCRTStartup() Line 574 + 0x42 bytes C
SlicerApp-real.exe!WinMainCRTStartup() Line 399 C
kernel32.dll!0000000076aa652d()
ntdll.dll!0000000076eec521()

Thanks Steve. I created issue 0002813 to specifically track the performance issue and assigned it to Hans.

The attached file itk-v4-release-windows64-vs2008.txt contains the build log of the unfixed errors when building the current slicer trunk with itk4 enabled.

The highlights of the remaining errors are:

[1] DWIConvert missing header

21>2>..........\BRAINSTools\DWIConvert\DWIConvert.cxx(32) : fatal error C1083: Cannot open include file: 'itkDCMTKSeriesFileNames.h': No such file or directory

[2] qSlicerModelsModuleWidgets pythonqt link errors (4 like this):

21>213>org_slicer_module_qSlicerModelsModuleWidgets_init.obj : error LNK2001: unresolved external symbol "public: virtual struct QMetaObject const * __cdecl PythonQtWrapper_qMRMLModelDisplayNodeWidget::metaObject(void)const " (?metaObject@PythonQtWrapper_qMRMLModelDisplayNodeWidget@@UEBAPEBUQMetaObject@@XZ)

[3] qSlicerTractographyDisplayModuleWidgets pythonqt link errors (22 like this):

21>219>org_slicer_module_qSlicerTractographyDisplayModuleWidgets_init.obj : error LNK2001: unresolved external symbol "public: virtual struct QMetaObject const * __cdecl PythonQtWrapper_qMRMLTractographyDisplayTreeView::metaObject(void)const " (?metaObject@PythonQtWrapper_qMRMLTractographyDisplayTreeView@@UEBAPEBUQMetaObject@@XZ)

[4] qSlicerVolumeRenderingModuleWidgets pythonqt link errors (25 like this):

21>224> Creating library C:\pieper\s4\s4r\Slicer-build\lib\Slicer-4.2\qt-loadable-modules\Release\qSlicerVolumeRenderingModuleWidgetsPythonQt.lib and object C:\pieper\s4\s4r\Slicer-build\lib\Slicer-4.2\qt-loadable-modules\Release\qSlicerVolumeRenderingModuleWidgetsPythonQt.exp
21>224>org_slicer_module_qSlicerVolumeRenderingModuleWidgets_init.obj : error LNK2001: unresolved external symbol "public: virtual struct QMetaObject const * __cdecl PythonQtWrapper_qSlicerCPURayCastVolumeRenderingPropertiesWidget::metaObject(void)const " (?metaObject@PythonQtWrapper_qSlicerCPURayCastVolumeRenderingPropertiesWidget@@UEBAPEBUQMetaObject@@XZ)

[5] qSlicerVolumesModuleWidgets pythonqt link errors (19 like this):

21>226> Creating library C:\pieper\s4\s4r\Slicer-build\lib\Slicer-4.2\qt-loadable-modules\Release\qSlicerVolumesModuleWidgetsPythonQt.lib and object C:\pieper\s4\s4r\Slicer-build\lib\Slicer-4.2\qt-loadable-modules\Release\qSlicerVolumesModuleWidgetsPythonQt.exp
21>226>org_slicer_module_qSlicerVolumesModuleWidgets_init.obj : error LNK2001: unresolved external symbol "public: virtual struct QMetaObject const * __cdecl PythonQtWrapper_qSlicerDiffusionTensorVolumeDisplayWidget::metaObject(void)const " (?metaObject@PythonQtWrapper_qSlicerDiffusionTensorVolumeDisplayWidget@@UEBAPEBUQMetaObject@@XZ)

[6] Two tclap errors in EMSegment

21>277>C:\pieper\s4\s4r\SlicerExecutionModel\tclap\include\tclap/StdOutput.h(240) : error C2589: '(' : illegal token on right side of '::'
21>277>C:\pieper\s4\s4r\SlicerExecutionModel\tclap\include\tclap/StdOutput.h(240) : error C2059: syntax error : '::'
21>277>Generating Code...
21>278>C:\pieper\s4\s4r\SlicerExecutionModel\tclap\include\tclap/StdOutput.h(240) : error C2589: '(' : illegal token on right side of '::'
21>278>C:\pieper\s4\s4r\SlicerExecutionModel\tclap\include\tclap/StdOutput.h(240) : error C2059: syntax error : '::'
21>278>Generating Code...
21>278>Build log was saved at "file://c:\pieper\s4\s4r\Slicer-build\Modules\Loadable\EMSegment\CommandLineApplication\EMSegmentCommandLine.dir\Release\BuildLog.htm"
21>278>EMSegmentCommandLine - 2 error(s), 0 warning(s)

21>277>EMSegmentTransformToNewFormat.cxx

[7] qSlicerEMSegmentModuleWidgets pythonqt link errors (7 like this):

21>280>org_slicer_module_qSlicerEMSegmentModuleWidgets_init.obj : error LNK2001: unresolved external symbol "public: virtual struct QMetaObject const * __cdecl PythonQtWrapper_qSlicerEMSegmentWidget::metaObject(void)const " (?metaObject@PythonQtWrapper_qSlicerEMSegmentWidget@@UEBAPEBUQMetaObject@@XZ)

In spite of the build errors, the main slicer application can be started in release mode and most things seem to work normally. I did not try the EMSegmenter, which is unlikely to work, and I did not try the python interfaces to the modules that had build failures.

Resolve during 2013 Winter Project Week.

Can you also confirm that creating a package works as expected ? That would allow us to resolve issue 0002801

As a side note, any idea why so may test are failing on windows. See http://slicer.cdash.org/viewTest.php?onlyfailed&amp;buildid=64031

Could it be related to something not working as expected with the ITKFactoryRegistration library ? Got it ... the test driver probably need to be updated to call the ITKFactoryRegsitration method before calling "RegisterTests".
See https://github.com/Slicer/Slicer/blob/master/Modules/CLI/AddScalarVolumes/Testing/AddScalarVolumesTest.cxx