search

InsightSoftwareConsortium / ITK

Insight Toolkit (ITK) -- Official Repository. ITK builds on a proven, spatially-oriented architecture for processing, segmentation, and registration of scientific images in two, three, or more dimensions.
https://itk.org
Apache License 2.0
1.4k stars 664 forks source link

Windows Python Module Import Failure #3425

Closed tbirdso closed 2 years ago

tbirdso commented 2 years ago

Description

Windows Python CI fails due to failure to import ITKImageIntensity module in several Python CTests.

CDash results

Expected behavior

Modules load successfully and CI passes

Actual behavior

Traceback (most recent call last):
  File "D:/a/1/s/Modules/Core/Mesh/wrapping/test/itkConnectedRegionsMeshFilterTest.py", line 28, in <module>
    threshold_filter = itk.BinaryThresholdImageFilter.IUC3IUC3.New()
  File "D:\a\1\s-build\Wrapping\Generators\Python\itk\support\lazy.py", line 138, in __getattribute__
    base.itk_load_swig_module(module, namespace)
  File "D:\a\1\s-build\Wrapping\Generators\Python\itk\support\base.py", line 96, in itk_load_swig_module
    itk_load_swig_module(dep, namespace)
  File "D:\a\1\s-build\Wrapping\Generators\Python\itk\support\base.py", line 132, in itk_load_swig_module
    l_module = loader.load(swig_module_name)
  File "D:\a\1\s-build\Wrapping\Generators\Python\itk\support\base.py", line 291, in load
    l_spec.loader.exec_module(l_module)  # pytype: disable=attribute-error
  File "<frozen importlib._bootstrap_external>", line 848, in exec_module
  File "<frozen importlib._bootstrap>", line 219, in _call_with_frames_removed
  File "D:\a\1\s-build\Wrapping\Generators\Python\itk\support\..\ITKImageIntensityPython.py", line 13, in <module>
    from . import _ITKImageIntensityPython
ImportError: cannot import name '_ITKImageIntensityPython' from 'itk' (D:\a\1\s-build\Wrapping\Generators\Python\itk\__init__.py)
itkTestDriver: Process exited with return value: 1

Reproducibility

Versions

master

Environment

Windows

Additional Information

tbirdso commented 2 years ago

@kian-weimer @hjmjohnson Could this be related to https://github.com/InsightSoftwareConsortium/ITK/pull/3200?

It looks like we are not typically running Windows CI in PRs, I believe this was due to a runner performance constraint, @dzenanz or @thewtex may have more insight. This issue is evidence in favor of adding resources to catch Windows Python issues before merge.

thewtex commented 2 years ago

It looks like we are not typically running Windows CI in PRs

Due to timeout's.

tbirdso commented 2 years ago

@thewtex Is it possible to increase the duration of the Azure Windows runners? I'm not sure what level of control we have.

thewtex commented 2 years ago

@tbirdso no, it is not.

thewtex commented 2 years ago

Note that work on C++20 modules aims to improve the build time to get us under the CI limit.

tbirdso commented 2 years ago

Having trouble recreating on my local Windows installation, tests are passing with a clean ITK Python build.

tbirdso commented 2 years ago

I am seeing the following warning when building ITK Python wrappings on Windows 2019 with Visual Studio 2022, perhaps related?

2>------ Build started: Project: itk-stub-files, Configuration: RelWithDebInfo x64 ------
2>Generating .pyi files for Python wrapper interface
2>The system cannot execute the specified program.
2>C:\Program Files\Microsoft Visual Studio\2022\Professional\MSBuild\Microsoft\VC\v170\Microsoft.CppCommon.targets(245,5): error MSB8066: Custom build for 'C:\repos\ITK-build-unstable\CMakeFiles\fa6a9a494588bf070abede55fcfc46ce\itk-stub-files.rule' exited with code 9020.
2>Done building project "itk-stub-files.vcxproj" -- FAILED.
thewtex commented 2 years ago 
2>Generating .pyi files for Python wrapper interface
2>The system cannot execute the specified program.

I get the same error.

tbirdso commented 2 years ago

Verified the error is also present in failing Windows Python build logs, unclear why not reported in dashboard

Build log

2022-05-18T14:32:59.8756756Z [3333/3355] Generating ../../Typedefs/itkComparisonImageFilter.i, ../../Typedefs/itkPipelineMonitorImageFilter.i, ../../Typedefs/itkRandomImageSource.i, ../../Typedefs/itkComparisonImageFilterSwigInterface.h, ../../Typedefs/itkPipelineMonitorImageFilterSwigInterface.h, ../../Typedefs/itkRandomImageSourceSwigInterface.h, ../../Typedefs/itkComparisonImageFilter.idx, ../../Typedefs/itkPipelineMonitorImageFilter.idx, ../../Typedefs/itkRandomImageSource.idx, ../../Generators/Python/itk/Configuration/ITKTestKernel_snake_case.py
2022-05-18T14:32:59.9083791Z [3334/3355] Generating .pyi files for Python wrapper interface
2022-05-18T14:32:59.9089863Z FAILED: Wrapping/CMakeFiles/itk-stub-files Wrapping/Generators/Python/itk-stubs/_proxies.pyi Wrapping/Generators/Python/itk-stubs/__init__.pyi D:/a/1/s-build/Wrapping/CMakeFiles/itk-stub-files D:/a/1/s-build/Wrapping/Generators/Python/itk-stubs/_proxies.pyi D:/a/1/s-build/Wrapping/Generators/Python/itk-stubs/__init__.pyi 
2022-05-18T14:32:59.9120995Z Wrapping\CMakeFiles\itk-stub-files-b6b270a.bat af573b1e5c9b086d
2022-05-18T14:32:59.9122345Z The system cannot execute the specified program.
2022-05-18T14:32:59.9133600Z Batch file failed at line 3 with errorcode 1
2022-05-18T14:33:01.9527593Z [3335/3355] Generating itkTIFFImageIOPython.cpp, ../../Generators/Python/itk/itkTIFFImageIOPython.py
2022-05-18T14:33:02.0002944Z [3336/3355] Building CXX object Wrapping\Modules\ITKIONRRD\CMakeFiles\ITKIONRRDPython.dir\itkNrrdImageIOPython.cpp.obj
2022-05-18T14:33:02.0005323Z ninja: build stopped: subcommand failed.
2022-05-18T14:33:02.0248562Z Command exited with the value: 1
2022-05-18T14:33:02.1275457Z Error(s) when building project
2022-05-18T14:33:02.1276829Z MakeCommand:"C:\Program Files\CMake\bin\cmake.exe" --build . --config "MinSizeRel"
2022-05-18T14:33:02.1278317Z    0 Compiler errors
2022-05-18T14:33:02.1279058Z    1 Compiler warnings
2022-05-18T14:33:02.1369844Z SetCTestConfiguration:BuildDirectory:D:/a/1/s-build
2022-05-18T14:33:02.1371455Z SetCTestConfiguration:SourceDirectory:D:/a/1/s
2022-05-18T14:33:02.1435200Z Test project D:/a/1/s-build
dzenanz commented 2 years ago

why not reported in dashboard

There is no Windows Python build.

tbirdso commented 2 years ago

There is no Windows Python build.

Not for PRs, but we do have a Windows Python CI pipeline for the master branch that is currently failing, hence this issue.

Continuous Windows Python dashboard result: Windows_NT-Build3048-master-Python

tbirdso commented 2 years ago

On reviewing the logs again it looks like CMake may be trying to execute a .bat file which does not exist?

2022-05-18T14:32:59.9120995Z Wrapping\CMakeFiles\itk-stub-files-b6b270a.bat af573b1e5c9b086d
2022-05-18T14:32:59.9122345Z The system cannot execute the specified program.
tbirdso commented 2 years ago

After more testing with the itk-stub-files target it looks like we may be running into issues with Windows clipping long arguments to 8192 characters.

At https://github.com/InsightSoftwareConsortium/ITK/blob/master/Wrapping/CMakeLists.txt#L170 we define the itk-stub-files custom target which runs a Python script with several arguments. By adding a separate debugging target for debug printout and gradually removing arguments we find that the command fails only when the GLOBAL_IdxFilesList CMake variable is included as an argument.

We can define a custom debug target in the same file to interrogate how Windows receives this command argument:

  add_custom_target(itk-stub-files-debug ALL
          COMMAND echo ${GLOBAL_IdxFilesList}
          COMMENT "Printing out GLOBAL_IdxFilesList argument"
          DEPENDS ${GLOBAL_IdxFilesList}
          VERBATIM
          )

The following is printed out when this target is built:

C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkFixedArray.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkVector.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkCovariantVector.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkPoint.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkTriangleHelper.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkVariableSizeMatrix.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkVersor.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/vnl_c_vector.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/vnl_cost_function.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/vnl_diag_matrix.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/vnl_file_matrix.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/vnl_file_vector.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/vnl_fortran_copy.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/vnl_least_squares_function.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/vnl_matrix_fixed.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/vnl_matrix_fixed_ref.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/vnl_matrix_ref.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/vnl_vector_ref.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/vnl_matrix.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/vnl_vector.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/vnl_unary_function.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/ITKCommonBase.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkSize.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkOffset.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkArray.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkIndex.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkContinuousIndex.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkMatrix.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkVectorContainer.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkMapContainer.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkBoundingBox.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkRGBPixel.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkRGBAPixel.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkVariableLengthVector.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkImageRegion.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkSymmetricSecondRankTensor.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkImage.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkVectorImage.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkNeighborhood.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkImageSourceCommon.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkImageSource.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkImageToImageFilterCommon.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkImageToImageFilterA.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkImageToImageFilterB.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkInPlaceImageFilterA.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkInPlaceImageFilterB.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkDefaultDynamicMeshTraits.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkDefaultStaticMeshTraits.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkFunctionBase.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkAnnulusOperator.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkArray2D.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkBSplineInterpolationWeightFunction.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkBackwardDifferenceOperator.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkDerivativeOperator.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkDiffusionTensor3D.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkExtractImageFilter.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkFloatingPointExceptions.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkForwardDifferenceOperator.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkGaussianDerivativeOperator.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkGaussianOperator.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkImageBoundaryCondition.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkImageDuplicator.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkImageKernelOperator.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkImageSink.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkImportImageFilter.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkKernelFunctionBase.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkLaplacianOperator.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkMetaDataObject.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkMinimumMaximumImageCalculator.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkNeighborhoodOperator.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkNumericTraits.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkOptimizerParameters.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkPointSet.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkPointSetToImageFilter.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkSimpleDataObjectDecorator.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkSobelOperator.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkSpatialFunction.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkStreamingImageFilter.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkDenseFiniteDifferenceImageFilter.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkFiniteDifferenceFunction.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkFiniteDifferenceImageFilter.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkBinaryGeneratorImageFilter.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkBoxImageFilter.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkCastImageFilter.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkNeighborhoodOperatorImageFilter.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkNoiseImageFilter.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkRecursiveSeparableImageFilter.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkTernaryGeneratorImageFilter.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkUnaryGeneratorImageFilter.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkCurvatureFlowImageFilter.index.txt C:/repos/ITK-build-debug/Wrapping/Generators/Python/itk-pkl/itkMinMaxCurvatBuilding Custom Rule C:/repos/ITK/Wrapping/CMakeLists.txt

Scrolling to the end, it is clear that the list of index files is clipped in the middle of "itkMinMaxCurvature". Copying and pasting into a text editor, we see that this clip happens at column 8192, which coincides with Windows's command character limit. The same can be recreated by copying and pasting into a Command Prompt terminal on Windows.

By contract, the full value of GLOBAL_IdxFilesList can be obtained by printing the CMake list variable contents with message at configure time, which shows that the full string of index.txt files has 159,771 characters.

A few thoughts:

  1. The list of .index.txt files appears to address every wrapped object in ITK. Perhaps this could be reduced to manageable chunks by refactoring into modules?
  2. I am not a CMake expert, perhaps there is a way to overcome the Windows command length issue? However a 20x length increase seems significantly large.

cc @thewtex @kian-weimer @hjmjohnson

thewtex commented 2 years ago

@tbirdso fantastic detective work! :detective:

Perhaps we could use DEPFILE to avoid the command line length issues?

See also:

The list of .index.txt files appears to address every wrapped object in ITK. Perhaps this could be reduced to manageable chunks by refactoring into modules?

This is a good idea, and we should do it, I know Hans and Kian tried in many iterations. Due to dependency patterns, though, this is difficult. Let's get what we have out and make refactoring / improvements at a later time.

tbirdso commented 2 years ago

@thewtex add_custom_command docs show that DEPFILE is supported for respective generators in the following CMake releases:

3.7: Ninja 3.17: Ninja multi-config 3.20: Makefile Generators 3.21: Visual Studio Generators

My understanding is that at the moment we intend to support Ninja, Unix Makefiles, and Visual Studio generators for building ITK with wrappings and CMake 3.16.3 is currently the minimum required. To continue supporting these generators with DEPFILE we would need a significant CMake bump. Thoughts?

tbirdso commented 2 years ago

Assuming we do not want to bump straight to CMake to 3.21, ~I am taking a stab at refactoring into modules. As mentioned above, I certainly understand that this is a difficult change and will take time.~

@kian-weimer @hjmjohnson Any discussion that you can contribute on particular pain points from your development iterations is welcomed. I will open a draft PR to track progress. I would also appreciate any tips you have on how to test that stub files are in fact working. It sounds like these changes are motivated by improving an IDE experience, do you have tips on what IDE you used and how you checked that stub file type hints worked on Linux/macOS?

@thewtex If it is critical that Windows Python builds in the next couple of days it may be necessary to consider reverting stub changes until resolved.

EDIT: Testing a workaround with file I/O in #3444, interested in feedback on potential pitfalls.

thewtex commented 2 years ago

We build the official macOS, Windows and Linux wheels with the Ninja generator. We generally limit the CMake version to the latest LTS version of Ubuntu -- Ubuntu 22.04 has cmake 3.22. So, we could update the CMake minimum version, but 5.4 is more appropriate for this, so folks will have time to upgrade. That said, #3444 is looking great!

tbirdso commented 2 years ago

Thanks @thewtex, good to hear there is another path. #3444 is looking promising, building locally on Windows now. I am hoping we will be able to proceed without changing build requirements.