colcon / colcon-cmake

Extension for colcon to support CMake packages
http://colcon.readthedocs.io
Apache License 2.0
16 stars 25 forks source link

colcon-cmake with gtest_discover_tests results in a ~10X slowdown in test runs #120

Open jaron-l opened 2 years ago

jaron-l commented 2 years ago

I recently started needing to repeatedly run a specific test in a gtest framework for the ros2_control/ros2_controllers repository so I implemented gtest_discover_tests in the CMakeLists.txt file so that I could properly pass ctest-args to colcon test and filter according to that test; however, when I did so, I noticed that tests started taking a lot longer to run. For example:

When digging into the logs of the test's stdout_stderror.log, it looks like the speed difference is coming from colcon executing each test as a separate executing run when gtest_discover_tests is enabled versus running the whole executable once when discovery is not enabled. For example:

When I run the test executable directly, I get the following output:

Running main() from gmock_main.cc
[==========] Running 14 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 14 tests from ForceTorqueSensorBroadcasterTest
[ RUN      ] ForceTorqueSensorBroadcasterTest.SensorName_InterfaceNames_NotSet
[       OK ] ForceTorqueSensorBroadcasterTest.SensorName_InterfaceNames_NotSet (15 ms)
[ RUN      ] ForceTorqueSensorBroadcasterTest.SensorName_FrameId_NotSet
[       OK ] ForceTorqueSensorBroadcasterTest.SensorName_FrameId_NotSet (12 ms)
[ RUN      ] ForceTorqueSensorBroadcasterTest.InterfaceNames_FrameId_NotSet
[       OK ] ForceTorqueSensorBroadcasterTest.InterfaceNames_FrameId_NotSet (10 ms)
[ RUN      ] ForceTorqueSensorBroadcasterTest.SensorName_InterfaceNames_Set
[       OK ] ForceTorqueSensorBroadcasterTest.SensorName_InterfaceNames_Set (8 ms)

... etc for brevity...

[----------] 14 tests from ForceTorqueSensorBroadcasterTest (162 ms total)

[----------] Global test environment tear-down
[==========] 14 tests from 1 test suite ran. (172 ms total)
[  PASSED  ] 14 tests.

However when running from colcon test, I get the following output:

UpdateCTestConfiguration  from :/mnt/lund/Code/ros2_control_ws/build/force_torque_sensor_broadcaster/CTestConfiguration.ini
Parse Config file:/mnt/lund/Code/ros2_control_ws/build/force_torque_sensor_broadcaster/CTestConfiguration.ini
   Site: 1f10b170ae5d
   Build name: (empty)
 Add coverage exclude regular expressions.
Create new tag: 20220419-1251 - Experimental
UpdateCTestConfiguration  from :/mnt/lund/Code/ros2_control_ws/build/force_torque_sensor_broadcaster/CTestConfiguration.ini
Parse Config file:/mnt/lund/Code/ros2_control_ws/build/force_torque_sensor_broadcaster/CTestConfiguration.ini
Test project /mnt/lund/Code/ros2_control_ws/build/force_torque_sensor_broadcaster
Constructing a list of tests
Done constructing a list of tests
Updating test list for fixtures
Added 0 tests to meet fixture requirements
Checking test dependency graph...
Checking test dependency graph end
test 1
      Start  1: ForceTorqueSensorBroadcasterTest.SensorName_InterfaceNames_NotSet

1: Test command: /mnt/lund/Code/ros2_control_ws/build/force_torque_sensor_broadcaster/test_force_torque_sensor_broadcaster "--gtest_filter=ForceTorqueSensorBroadcasterTest.SensorName_InterfaceNames_NotSet" "--gtest_also_run_disabled_tests"
1: Test timeout computed to be: 10000000
1: Running main() from gmock_main.cc
1: Note: Google Test filter = ForceTorqueSensorBroadcasterTest.SensorName_InterfaceNames_NotSet
1: [==========] Running 1 test from 1 test suite.
1: [----------] Global test environment set-up.
1: [----------] 1 test from ForceTorqueSensorBroadcasterTest
1: [ RUN      ] ForceTorqueSensorBroadcasterTest.SensorName_InterfaceNames_NotSet
1: [ERROR] [1650372703.599663675] [test_force_torque_sensor_broadcaster]: 'sensor_name' or at least one 'interface_names.[force|torque].[x|y|z]' parameter has to be specified.
1: [       OK ] ForceTorqueSensorBroadcasterTest.SensorName_InterfaceNames_NotSet (18 ms)
1: [----------] 1 test from ForceTorqueSensorBroadcasterTest (18 ms total)
1: 
1: [----------] Global test environment tear-down
1: [==========] 1 test from 1 test suite ran. (35 ms total)
1: [  PASSED  ] 1 test.
 1/16 Test  #1: ForceTorqueSensorBroadcasterTest.SensorName_InterfaceNames_NotSet ...........   Passed    0.15 sec
test 2
      Start  2: ForceTorqueSensorBroadcasterTest.SensorName_FrameId_NotSet

2: Test command: /mnt/lund/Code/ros2_control_ws/build/force_torque_sensor_broadcaster/test_force_torque_sensor_broadcaster "--gtest_filter=ForceTorqueSensorBroadcasterTest.SensorName_FrameId_NotSet" "--gtest_also_run_disabled_tests"
2: Test timeout computed to be: 10000000
2: Running main() from gmock_main.cc
2: Note: Google Test filter = ForceTorqueSensorBroadcasterTest.SensorName_FrameId_NotSet
2: [==========] Running 1 test from 1 test suite.
2: [----------] Global test environment set-up.
2: [----------] 1 test from ForceTorqueSensorBroadcasterTest
2: [ RUN      ] ForceTorqueSensorBroadcasterTest.SensorName_FrameId_NotSet
2: [ERROR] [1650372703.744065436] [test_force_torque_sensor_broadcaster]: 'frame_id' parameter has to be provided.
2: [       OK ] ForceTorqueSensorBroadcasterTest.SensorName_FrameId_NotSet (14 ms)
2: [----------] 1 test from ForceTorqueSensorBroadcasterTest (14 ms total)
2: 
2: [----------] Global test environment tear-down
2: [==========] 1 test from 1 test suite ran. (25 ms total)
2: [  PASSED  ] 1 test.
 2/16 Test  #2: ForceTorqueSensorBroadcasterTest.SensorName_FrameId_NotSet ..................   Passed    0.14 sec
test 3
      Start  3: ForceTorqueSensorBroadcasterTest.InterfaceNames_FrameId_NotSet

etc for brevity...

which I believe from the lines reading Note: Google Test filter = Force.... on every single test that it's running each test against the executable with the given filter individually when it could run the executable once to run them all.

Does colcon-cmake support a way to batch test runs together when discovery shows that there are tests part of the same executable?