👨‍🌾 Test failure on WIndows test_subscription_not_initialized_with_content_filtering

[Blast545]

Bug report

Required Info:

• Operating System:
  • Windows
• Installation type:
  • Source, buildfarm
• Version or commit hash:
  • main
• DDS implementation:
  • RTI Connext
• Client library (if applicable):
  • N/A

Steps to reproduce issue

Run a buildfarm nightly_win_rel job.

Expected behavior

Test passes.

Actual behavior

Test fails.

Additional information

Error log:

C:\ci\ws\src\ros2\rcl\rcl\test\rcl\test_subscription.cpp:1300
Value of: wait_for_subscription_to_be_ready(&subscription, context_ptr, 10, 1000)
  Actual: false
Expected: true

https://ci.ros2.org/view/nightly/job/nightly_win_rel/2261/testReport/junit/rcl/TestSubscriptionFixture__rmw_connextdds/test_subscription_not_initialized_with_content_filtering/

PR introducing this regression:
#894

[clalancette]

@fujitatomoya @iuhilnehc-ynos Can you take a look?

[iuhilnehc-ynos]

I can reproduce this issue in my local windows10 env.

After calling rcl_subscription_set_content_filter with (int32_value = %0, {4} ) and waiting for content filter propagation, the first rcl_publish publishing a data that can't be filtered worked as we expected, but the message sent by the second rcl_publish should be received by the subscription, but the data can't be evaluated by the DDS_SqlFilter_evaluateOnSerialized inside RTI_CustomSqlFilter_evaluate.

log

c:\dev\ros2_rolling\build\rcl\test\Release>test_subscription__rmw_connextdds.exe --gtest_filter="*test_subscription_not_initialized_with_content_filtering"
Running main() from C:\dev\ros2_rolling\install\src\gtest_vendor\src\gtest_main.cc
Note: Google Test filter = *test_subscription_not_initialized_with_content_filtering
[==========] Running 1 test from 1 test suite.
[----------] Global test environment set-up.
[----------] 1 test from TestSubscriptionFixture__rmw_connextdds
[ RUN      ] TestSubscriptionFixture__rmw_connextdds.test_subscription_not_initialized_with_content_filtering
RTI Connext DDS EVAL License issued to Huayang [email protected] For non-production use only.
Expires on 07-May-2022 See www.rti.com for more information.
set_memory_management_property
RTI_CustomSqlFilter_compile
create cft_topic:00000268AE49E1E0 ros_discovery_info rmw_dds_common::msg::dds_::ParticipantEntitiesInfo_
dds_topic_cft:00000268AE49E1E0
RTI_CustomSqlFilter_compile
RTI_CustomSqlFilter_evaluate with expression:
RTI_CustomSqlFilter_compile
create cft_topic:00000268AE49E390 rt/rcl_test_subscription_not_begin_content_filtered_chatter test_msgs::msg::dds_::BasicTypes_
dds_topic_cft:00000268AE49E390
RTI_CustomSqlFilter_evaluate with expression:
RTI_CustomSqlFilter_compile
[ERROR] [1649226843.125977600] [rmw_connextdds]: no content-filter associated with subscription
RTI_CustomSqlFilter_evaluate with expression:
RTI_CustomSqlFilter_evaluate with expression:
RTI_CustomSqlFilter_compile
DDS_SqlFilter_compile ret:0
DDS_ContentFilteredTopic_set_expression, ret:0
RTI_CustomSqlFilter_compile
DDS_SqlFilter_compile ret:0
RTI_CustomSqlFilter_evaluate with expression:
RTI_CustomSqlFilter_evaluate with expression:
RTI_CustomSqlFilter_evaluate with expression: int32_value = %0 param: 4
RTI_CustomSqlFilter_evaluate with expression: int32_value = %0 param: 4
after DDS_SqlFilter_evaluateOnSerialized , ret:false
RTI_CustomSqlFilter_evaluate with expression: int32_value = %0 param: 4
after rcl_publish with int32_value(4) in the test
RTI_CustomSqlFilter_evaluate with expression: int32_value = %0 param: 4
after DDS_SqlFilter_evaluateOnSerialized , ret:false
                                             ///////\  `DDS_SqlFilter_evaluateOnSerialized`  return false, so there is no available event in the subscription.
C:\dev\ros2_rolling\src\ros2\rcl\rcl\test\rcl\test_subscription.cpp(1301): error: Value of: wait_for_subscription_to_be_ready(&subscription, context_ptr, 10, 1000)
  Actual: false
Expected: true
RTI_CustomSqlFilter_evaluate with expression:
RTI_CustomSqlFilter_evaluate with expression:
RTI_CustomSqlFilter_evaluate with expression:
RTI_CustomSqlFilter_evaluate with expression:
RTI_CustomSqlFilter_evaluate with expression:
RTI_CustomSqlFilter_evaluate with expression:
[  FAILED  ] TestSubscriptionFixture__rmw_connextdds.test_subscription_not_initialized_with_content_filtering (30637 ms)
[----------] 1 test from TestSubscriptionFixture__rmw_connextdds (30639 ms total)

[----------] Global test environment tear-down
[==========] 1 test from 1 test suite ran. (30646 ms total)
[  PASSED  ] 0 tests.
[  FAILED  ] 1 test, listed below:
[  FAILED  ] TestSubscriptionFixture__rmw_connextdds.test_subscription_not_initialized_with_content_filtering

 1 FAILED TEST

Notice that the test case can be passed in ubuntu platform.

After changing the message type from test_msgs/msg/BasicTypes to test_msgs/msg/Strings(patch), this test case can be passed in windows10.

log

c:\dev\ros2_rolling\build\rcl\test\Release>test_subscription__rmw_connextdds.exe --gtest_filter="*test_subscription_not_initialized_with_content_filtering"
Running main() from C:\dev\ros2_rolling\install\src\gtest_vendor\src\gtest_main.cc
Note: Google Test filter = *test_subscription_not_initialized_with_content_filtering
[==========] Running 1 test from 1 test suite.
[----------] Global test environment set-up.
[----------] 1 test from TestSubscriptionFixture__rmw_connextdds
[ RUN      ] TestSubscriptionFixture__rmw_connextdds.test_subscription_not_initialized_with_content_filtering
RTI Connext DDS EVAL License issued to (omitted data) For non-production use only.
Expires on 07-May-2022 See www.rti.com for more information.
set_memory_management_property
RTI_CustomSqlFilter_compile
create cft_topic:0000024D5BB70EC0 ros_discovery_info rmw_dds_common::msg::dds_::ParticipantEntitiesInfo_
dds_topic_cft:0000024D5BB70EC0
RTI_CustomSqlFilter_compile
RTI_CustomSqlFilter_evaluate with expression:
RTI_CustomSqlFilter_compile
create cft_topic:0000024D5BB71070 rt/rcl_test_subscription_not_begin_content_filtered_chatter test_msgs::msg::dds_::Strings_
dds_topic_cft:0000024D5BB71070
RTI_CustomSqlFilter_evaluate with expression:
RTI_CustomSqlFilter_compile[ERROR] [1649224303.438887500] [rmw_connextdds]: no content-filter associated with subscription

RTI_CustomSqlFilter_evaluate with expression:
RTI_CustomSqlFilter_evaluate with expression:
RTI_CustomSqlFilter_compile
DDS_SqlFilter_compile ret:0
DDS_ContentFilteredTopic_set_expression, ret:RTI_CustomSqlFilter_compile
0
DDS_SqlFilter_compile ret:0
RTI_CustomSqlFilter_evaluate with expression:
RTI_CustomSqlFilter_evaluate with expression:
RTI_CustomSqlFilter_evaluate with expression: string_value = %0 param: '4'
RTI_CustomSqlFilter_evaluate with expression: string_value = %0 param: '4'
after DDS_SqlFilter_evaluateOnSerialized , ret:false
RTI_CustomSqlFilter_evaluate with expression: string_value = %0 param: '4'
after rcl_publish with string_value("4") in the test
RTI_CustomSqlFilter_evaluate with expression: string_value = %0 param: '4'
after DDS_SqlFilter_evaluateOnSerialized , ret:true
                                             ///////\  `DDS_SqlFilter_evaluateOnSerialized` return true
RTI_CustomSqlFilter_evaluate with expression:
RTI_CustomSqlFilter_evaluate with expression:
RTI_CustomSqlFilter_evaluate with expression:
RTI_CustomSqlFilter_evaluate with expression:
RTI_CustomSqlFilter_evaluate with expression:
RTI_CustomSqlFilter_evaluate with expression:
[       OK ] TestSubscriptionFixture__rmw_connextdds.test_subscription_not_initialized_with_content_filtering (20477 ms)
[----------] 1 test from TestSubscriptionFixture__rmw_connextdds (20479 ms total)

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

@asorbini
Could you give me any suggestions?

[asorbini]

@iuhilnehc-ynos I found a small issue in the custom SQL filter code. After resolving it, the test passes consistently. I will open a PR on rmw_connextdds to fix it.

[asorbini]

Fixed by ros2/rmw_connextdds#81

[clalancette]

Closing this out, as it was fixed by the referenced PR. Feel free to reopen if it pops up again.