rosbag2_py test errors in Windows Debug nightlies

[nuclearsandwich]

Description

The rosbag2_py package doesn't seem to be building correctly in Windows debug and this is causing failures in test.
See https://ci.ros2.org/view/nightly/job/nightly_win_deb/1714/testReport/ which has two blank test failures attributed to rosbag2_py. Looking at the full log reveals excerpts like this one:

1: =================================== ERRORS ====================================
1: ________________________ ERROR collecting test session ________________________
1: C:\Python38\lib\site-packages\pluggy\hooks.py:286: in __call__
1:     return self._hookexec(self, self.get_hookimpls(), kwargs)
1: C:\Python38\lib\site-packages\pluggy\manager.py:93: in _hookexec
1:     return self._inner_hookexec(hook, methods, kwargs)
1: C:\Python38\lib\site-packages\pluggy\manager.py:84: in <lambda>
1:     self._inner_hookexec = lambda hook, methods, kwargs: hook.multicall(
1: C:\Python38\lib\site-packages\_pytest\python.py:195: in pytest_collect_file
1:     module = ihook.pytest_pycollect_makemodule(
1: C:\Python38\lib\site-packages\pluggy\hooks.py:286: in __call__
1:     return self._hookexec(self, self.get_hookimpls(), kwargs)
1: C:\Python38\lib\site-packages\pluggy\manager.py:93: in _hookexec
1:     return self._inner_hookexec(hook, methods, kwargs)
1: C:\Python38\lib\site-packages\pluggy\manager.py:84: in <lambda>
1:     self._inner_hookexec = lambda hook, methods, kwargs: hook.multicall(
1: C:\ci\ws\install\Lib\site-packages\launch_testing\pytest\hooks.py:161: in pytest_pycollect_makemodule
1:     entrypoint = find_launch_test_entrypoint(path)
1: C:\ci\ws\install\Lib\site-packages\launch_testing\pytest\hooks.py:155: in find_launch_test_entrypoint
1:     return getattr(path.pyimport(), 'generate_test_description', None)
1: C:\Python38\lib\site-packages\py\_path\local.py:704: in pyimport
1:     __import__(modname)
1: C:\Python38\lib\site-packages\_pytest\assertion\rewrite.py:170: in exec_module
1:     exec(co, module.__dict__)
1: ..\test\test_sequential_reader.py:19: in <module>
1:     from rclpy.serialization import deserialize_message
1: C:\ci\ws\install\Lib\site-packages\rclpy\serialization.py:15: in <module>
1:     from rclpy.impl.implementation_singleton import rclpy_implementation as _rclpy
1: C:\ci\ws\install\Lib\site-packages\rclpy\impl\implementation_singleton.py:32: in <module>
1:     rclpy_implementation = import_c_library('._rclpy', package)
1: C:\ci\ws\install\Lib\site-packages\rpyutils\import_c_library.py:39: in import_c_library
1:     return importlib.import_module(name, package=package)
1: C:\Python38\lib\importlib\__init__.py:127: in import_module
1:     return _bootstrap._gcd_import(name[level:], package, level)
1: E   ModuleNotFoundError: No module named 'rclpy._rclpy'
1: E   The C extension 'C:\ci\ws\install\Lib\site-packages\_rclpy.pyd' isn't present on the system. Please refer to 'https://index.ros.org/doc/ros2/Troubleshooting/Installation-Troubleshooting/#import-failing-without-library-present-on-the-system' for possible solutions
1: - generated xml file: C:\ci\ws\build\rosbag2_py\test_results\rosbag2_py\test_sequential_reader_py.xunit.xml -
1: =========================== short test summary info ===========================
1: ERROR .. - ModuleNotFoundError: No module named 'rclpy._rclpy'
1: !!!!!!!!!!!!!!!!!!! Interrupted: 1 error during collection !!!!!!!!!!!!!!!!!!!!
1: ============================== 1 error in 0.43s ===============================

To Reproduce

Behavior should be reproducible on any Windows machine with a Debug build. See the CI build https://ci.ros2.org/view/nightly/job/nightly_win_deb/1714 for an example.

System (please complete the following information)

• OS: Windows; Debug configuration
• ROS 2 Distro: Rolling / mainline
• Version: 038bae2 (rosbag2_py reader and writer #308)

[mabelzhang]

I just realized I haven't been updating this ticket with the latest progress, if you could call it that. I've run CI about 20 times with different tweaks over the past few weeks but haven't been able to fix this. I've solicited some internal help, but the attempts haven't been successful.

I did advance to a different error though, so, progress?

The latest build https://ci.ros2.org/job/ci_windows/12257/

..\..\src\ros2\rosbag2\rosbag2_py\test\test_sequential_reader.py:19: in <module>
    from common import get_rosbag_options
..\..\src\ros2\rosbag2\rosbag2_py\test\common.py:17: in <module>
    import rosbag2_py
..\..\install\Lib\site-packages\rosbag2_py\__init__.py:23: in <module>
    from rosbag2_py._reader import \
E   ModuleNotFoundError: No module named 'rosbag2_py._reader'
- generated xml file: C:\ci\ws\build\rosbag2_py\test_results\rosbag2_py\test_sequential_reader_py.xunit.xml -

Here's what I've done so far to reach the error above.

The original error in this ticket was that rclpy could not be found in Windows Debug mode. We figured out that Python needs some specific configuration in the CMakeLists.txt for Debug mode (PythonExtra, PYTHON_EXECUTABLE_DEBUG, etc). I compared with and copy the setup in tf2_py and message_filters.

But PythonExtra did not work directly for this package for some reason - it could not find PythonLibs:
https://ci.ros2.org/job/ci_windows/12112/

So I added PythonLibs before PythonExtra, and now it finds PythonExtra. (Though I don't think PythonLibs should be needed in the first place, since tf2_py did not need it, and PythonExtra is supposed to be the one looking for it, not downstream. I also read here that after CMake 3.12, PythonInterp (can be found) and PythonLibs (cannot be found) have been changed to simply Python. Python did not work for me. Anyway that is besides the point. Currently with PythonLibs, PythonExtra works.)

Then we get to the latest ModuleNotFoundError above about rosbag2_py._reader. We thought it could be related to this ticket pybind/pybind11#2018 . To fix it, maybe we need to move PYTHON_EXECUTABLE_DEBUG outside the BUILD_TESTING block, above the calls to pybind11_add_module(), so that pybind can see the Python executable in Debug mode.

So I did that, but then I'm back to the beginning with rclpy not found again...
I played the same game with PythonExtra and PythonLibs, but with the PYTHON_EXECUTABLE_DEBUG higher in the file, I got a different error - it was not able to open python38.lib:
https://ci.ros2.org/job/ci_windows/12232/

17:01:11   Checking Build System
17:01:11   Building Custom Rule C:/ci/ws/src/ros2/rosbag2/rosbag2_py/CMakeLists.txt
17:01:11   _reader.cpp
17:01:11 LINK : fatal error LNK1104: cannot open file 'python38.lib' [C:\ci\ws\build\rosbag2_py\_reader.vcxproj]
17:01:11   Building Custom Rule C:/ci/ws/src/ros2/rosbag2/rosbag2_py/CMakeLists.txt
17:01:11   _storage.cpp
17:01:11 LINK : fatal error LNK1104: cannot open file 'python38.lib' [C:\ci\ws\build\rosbag2_py\_storage.vcxproj]
17:01:11   Building Custom Rule C:/ci/ws/src/ros2/rosbag2/rosbag2_py/CMakeLists.txt
17:01:11   _writer.cpp
17:01:11 LINK : fatal error LNK1104: cannot open file 'python38.lib' [C:\ci\ws\build\rosbag2_py\_writer.vcxproj]

That is the farthest I've gotten making tweaks and rerunning CI. My next guess is copying more of the setup from message_filters, specifically, these lines https://github.com/ros2/message_filters/blob/master/CMakeLists.txt#L48-L54 .

In parallel, I also installed ROS 2 on my Windows locally to try to speed up the process (as opposed to waiting 40 minutes for each CI run), but I got stuck even sooner. colcon had trouble finding pytest on my setup, even though python and python_d (Python debug mode) were able to import pytest just fine. That's a completely different alley so I will not describe that here.

The changes above are in branch fix_issue_504_windows.

[nuclearsandwich]

My next guess is copying more of the setup from message_filters, specifically, these lines https://github.com/ros2/message_filters/blob/master/CMakeLists.txt#L48-L54 .

These lines deal with registering a hook to make sure that this package's install location is put on the PYTHONPATH and installing the package's python modules.
I don't think anything there will affect not being able to successfully run CMake configuration for this package.

Looking at your latest build:

00:29:29.270 -- Found PythonLibs: C:/Python38/libs/python38_d.lib (found suitable version "3.8.3", minimum required is "3.5") 
00:29:29.270 -- Found PythonInterp: C:/Python38/python.exe (found suitable version "3.8.3", minimum required is "3.5") 

It looks like your PythonLibs is picking up debug but the debug interpreter isn't being used. I'm not exactly sure what would cause that. If pybind11 is looking for Python via CMake or has its own CMake module handling it's possible that there's a precedence issue with pybind11(_vendor) and python_cmake_module. I haven't pursued that further though.