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.

Sign up for GitHub

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

Jump to bottom

🧑‍🌾 Flaky test_action_interaction__rmw_connextdds in Windows debug and release #1162

Open
Crola1702 opened this issue Jun 26, 2024 · 6 comments · Fixed by #1172
Open

🧑‍🌾 Flaky test_action_interaction__rmw_connextdds in Windows debug and release #1162

Crola1702 opened this issue Jun 26, 2024 · 6 comments · Fixed by #1172
Assignees
@clalancette

Comments

@Crola1702
Copy link

Crola1702 commented Jun 26, 2024 •
edited
Loading

Bug report

Required Info:

  • Operating System:
    • Windows
  • Installation type:
    • Source
  • Version or commit hash:
    • Rolling
  • DDS implementation:
    • ConnextDDS

Steps to reproduce issue

  1. Run a build in nightly_win_deb
  2. See test regressions fail

Additional information

Reference build: https://ci.ros2.org/view/nightly/job/nightly_win_deb/3136/

Test regressions:

Log output: 
-- run_test.py: extra environment variables:
 - RCL_ASSERT_RMW_ID_MATCHES=rmw_connextdds
 - RMW_IMPLEMENTATION=rmw_connextdds
-- run_test.py: invoking following command in 'C:\ci\ws\build\rcl_action':
 - C:/ci/ws/build/rcl_action/Debug/test_action_interaction__rmw_connextdds.exe --gtest_output=xml:C:/ci/ws/build/rcl_action/test_results/rcl_action/test_action_interaction__rmw_connextdds.gtest.xml
Running main() from C:\ci\ws\install\src\gtest_vendor\src\gtest_main.cc
[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from TestActionClientServerInteraction__rmw_connextdds
[ RUN      ] TestActionClientServerInteraction__rmw_connextdds.test_interaction
C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(227): error: Expected equality of these values:
  ret
    Which is: 2
  0
error not set

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(238): error: Value of: this->is_goal_request_ready
  Actual: false
Expected: true
error not set

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(246): error: Expected equality of these values:
  ret
    Which is: 2201
  0
error not set

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(249): error: Expected equality of these values:
  this->outgoing_goal_request.goal.order
    Which is: 10
  this->incoming_goal_request.goal.order
    Which is: -842150451

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(253): error: Value of: (0 == memcmp(this->outgoing_goal_request.goal_id.uuid, this->incoming_goal_request.goal_id.uuid, 16))
  Actual: false
Expected: true

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(274): error: Expected equality of these values:
  ret
    Which is: 2
  0
error not set

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(287): error: Value of: this->is_goal_response_ready
  Actual: false
Expected: true

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(296): error: Expected equality of these values:
  ret
    Which is: 2103
  0
error not set

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(299): error: Expected equality of these values:
  this->outgoing_goal_response.accepted
    Which is: true
  this->incoming_goal_response.accepted
    Which is: true

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(300): error: Expected equality of these values:
  this->outgoing_goal_response.stamp.sec
    Which is: 123
  this->incoming_goal_response.stamp.sec
    Which is: -842150451

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(301): error: Expected equality of these values:
  this->outgoing_goal_response.stamp.nanosec
    Which is: 456789
  this->incoming_goal_response.stamp.nanosec
    Which is: 3452816845

[  FAILED  ] TestActionClientServerInteraction__rmw_connextdds.test_interaction (2548 ms)
[ RUN      ] TestActionClientServerInteraction__rmw_connextdds.test_interaction_with_cancel
C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(500): error: Expected equality of these values:
  ret
    Which is: 2
  0
error not set

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(511): error: Value of: this->is_goal_request_ready
  Actual: false
Expected: true
error not set

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(519): error: Expected equality of these values:
  ret
    Which is: 2201
  0
error not set

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(522): error: Expected equality of these values:
  this->outgoing_goal_request.goal.order
    Which is: 10
  this->incoming_goal_request.goal.order
    Which is: -842150451

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(526): error: Value of: (0 == memcmp(this->outgoing_goal_request.goal_id.uuid, this->incoming_goal_request.goal_id.uuid, 16))
  Actual: false
Expected: true

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(547): error: Expected equality of these values:
  ret
    Which is: 2
  0
error not set

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(560): error: Value of: this->is_goal_response_ready
  Actual: false
Expected: true

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(569): error: Expected equality of these values:
  ret
    Which is: 2103
  0
error not set

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(572): error: Expected equality of these values:
  this->outgoing_goal_response.accepted
    Which is: true
  this->incoming_goal_response.accepted
    Which is: true

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(573): error: Expected equality of these values:
  this->outgoing_goal_response.stamp.sec
    Which is: 123
  this->incoming_goal_response.stamp.sec
    Which is: -842150451

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(574): error: Expected equality of these values:
  this->outgoing_goal_response.stamp.nanosec
    Which is: 456789
  this->incoming_goal_response.stamp.nanosec
    Which is: 3452816845

[  FAILED  ] TestActionClientServerInteraction__rmw_connextdds.test_interaction_with_cancel (2414 ms)
[----------] 2 tests from TestActionClientServerInteraction__rmw_connextdds (4964 ms total)

[----------] Global test environment tear-down
[==========] 2 tests from 1 test suite ran. (4964 ms total)
[  PASSED  ] 0 tests.
[  FAILED  ] 2 tests, listed below:
[  FAILED  ] TestActionClientServerInteraction__rmw_connextdds.test_interaction
[  FAILED  ] TestActionClientServerInteraction__rmw_connextdds.test_interaction_with_cancel

 2 FAILED TESTS
-- run_test.py: return code 1
-- run_test.py: inject classname prefix into gtest result file 'C:/ci/ws/build/rcl_action/test_results/rcl_action/test_action_interaction__rmw_connextdds.gtest.xml'
-- run_test.py: verify result file 'C:/ci/ws/build/rcl_action/test_results/rcl_action/test_action_interaction__rmw_connextdds.gtest.xml'

Flaky report (last 15 days):

job_name last_fail first_fail build_count failure_count failure_percentage
nightly_win_deb 2024-06-26 2024-06-12 14 4 28.57
nightly_win_rel 2024-06-25 2024-06-25 16 1 6.25
@Crola1702 Crola1702 changed the title 🧑‍🌾 Flaky test_action_interaction__rmw_connextdds in Windows debug 🧑‍🌾 Flaky test_action_interaction__rmw_connextdds in Windows debug and release Jul 5, 2024
@Crola1702
Copy link
Author

The flaky ratio of these tests has grown up considerably:

job_name last_fail first_fail build_count failure_count failure_percentage
nightly_win_rel 2024-07-05 2024-06-25 16 8 50.0
nightly_win_deb 2024-07-05 2024-06-21 12 9 75.0

@Crola1702 Crola1702 mentioned this issue Jul 5, 2024
Closed
@clalancette clalancette mentioned this issue Jul 25, 2024
Merged
@Crola1702
Copy link
Author

This is still hapenning in Windows Debug: nightly_win_deb#3169. Test failure: https://ci.ros2.org/view/nightly/job/nightly_win_deb/3169/testReport/(root)/projectroot/test_action_interaction__rmw_connextdds/

@Crola1702 Crola1702 reopened this Jul 29, 2024
@Crola1702 Crola1702 mentioned this issue Jul 29, 2024
Closed
@Crola1702
Copy link
Author

These tests are failing consistently in Windows Debug:

Log output: 
-- run_test.py: extra environment variables:
 - RMW_IMPLEMENTATION=rmw_connextdds
-- run_test.py: invoking following command in 'C:\ci\ws\build\rcl_action':
 - C:/ci/ws/build/rcl_action/Debug/test_action_interaction.exe --gtest_output=xml:C:/ci/ws/build/rcl_action/test_results/rcl_action/test_action_interaction__rmw_connextdds.gtest.xml
Running main() from C:\ci\ws\install\src\gtest_vendor\src\gtest_main.cc
[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from TestActionClientServerInteraction
[ RUN      ] TestActionClientServerInteraction.test_interaction
C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(222): error: Expected equality of these values:
  ret
    Which is: 2
  0
error not set

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(233): error: Value of: this->is_goal_request_ready
  Actual: false
Expected: true
error not set

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(241): error: Expected equality of these values:
  ret
    Which is: 2201
  0
error not set

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(244): error: Expected equality of these values:
  this->outgoing_goal_request.goal.order
    Which is: 10
  this->incoming_goal_request.goal.order
    Which is: -842150451

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(248): error: Value of: (0 == memcmp(this->outgoing_goal_request.goal_id.uuid, this->incoming_goal_request.goal_id.uuid, 16))
  Actual: false
Expected: true

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(269): error: Expected equality of these values:
  ret
    Which is: 2
  0
error not set

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(282): error: Value of: this->is_goal_response_ready
  Actual: false
Expected: true

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(291): error: Expected equality of these values:
  ret
    Which is: 2103
  0
error not set

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(294): error: Expected equality of these values:
  this->outgoing_goal_response.accepted
    Which is: true
  this->incoming_goal_response.accepted
    Which is: true

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(295): error: Expected equality of these values:
  this->outgoing_goal_response.stamp.sec
    Which is: 123
  this->incoming_goal_response.stamp.sec
    Which is: -842150451

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(296): error: Expected equality of these values:
  this->outgoing_goal_response.stamp.nanosec
    Which is: 456789
  this->incoming_goal_response.stamp.nanosec
    Which is: 3452816845

[  FAILED  ] TestActionClientServerInteraction.test_interaction (20567 ms)
[ RUN      ] TestActionClientServerInteraction.test_interaction_with_cancel
C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(494): error: Expected equality of these values:
  ret
    Which is: 2
  0
error not set

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(505): error: Value of: this->is_goal_request_ready
  Actual: false
Expected: true
error not set

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(513): error: Expected equality of these values:
  ret
    Which is: 2201
  0
error not set

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(516): error: Expected equality of these values:
  this->outgoing_goal_request.goal.order
    Which is: 10
  this->incoming_goal_request.goal.order
    Which is: -842150451

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(520): error: Value of: (0 == memcmp(this->outgoing_goal_request.goal_id.uuid, this->incoming_goal_request.goal_id.uuid, 16))
  Actual: false
Expected: true

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(541): error: Expected equality of these values:
  ret
    Which is: 2
  0
error not set

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(554): error: Value of: this->is_goal_response_ready
  Actual: false
Expected: true

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(563): error: Expected equality of these values:
  ret
    Which is: 2103
  0
error not set

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(566): error: Expected equality of these values:
  this->outgoing_goal_response.accepted
    Which is: true
  this->incoming_goal_response.accepted
    Which is: true

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(567): error: Expected equality of these values:
  this->outgoing_goal_response.stamp.sec
    Which is: 123
  this->incoming_goal_response.stamp.sec
    Which is: -842150451

C:\ci\ws\src\ros2\rcl\rcl_action\test\rcl_action\test_action_interaction.cpp(568): error: Expected equality of these values:
  this->outgoing_goal_response.stamp.nanosec
    Which is: 456789
  this->incoming_goal_response.stamp.nanosec
    Which is: 3452816845

[  FAILED  ] TestActionClientServerInteraction.test_interaction_with_cancel (20526 ms)
[----------] 2 tests from TestActionClientServerInteraction (41094 ms total)

[----------] Global test environment tear-down
[==========] 2 tests from 1 test suite ran. (41094 ms total)
[  PASSED  ] 0 tests.
[  FAILED  ] 2 tests, listed below:
[  FAILED  ] TestActionClientServerInteraction.test_interaction

CC @clalancette

Crola1702 added a commit to osrf/buildfarm-tools that referenced this issue Aug 12, 2024
@Crola1702
Update known issues
fbc56d3 
From: gazebosim/gz-rendering#745, ros2/rcl#1162

Signed-off-by: Crola1702 <[email protected]>
@MichaelOrlov
Copy link
Contributor

@clalancette A friendly ping to follow up

@Blast545
Copy link
Contributor

🧑‍🌾 @clalancette friendly ping

@Crola1702
Copy link
Author

Friendly ping @clalancette

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@clalancette clalancette

Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Increase the test_action_interaction timeouts. ros2/rcl
4 participants
@clalancette @MichaelOrlov @Blast545 @Crola1702