ros2 / ros2/system_tests

test_communication puts stack trace and its failure in different test cases

Open
#418 1 comment 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

Dominant language
C++
Stars
45
Forks
57
Avg merge
9h 19m
Merged PRs (30d)
2

Description

Bug report

System info:
https://ci.ros2.org/view/nightly/job/nightly_win_deb/1589/

Steps to reproduce issue

run CI https://ci.ros2.org/view/nightly/job/nightly_win_deb/1589/testReport/(root)/projectroot/test_publisher_subscriber__rclpy__rmw_cyclonedds_cpp/

Expected behavior

The crash fails the test case associated with it.

Actual behavior

The useful stack trace appears in the passing test case "test_subscriber_terminates_in_a_finite_amount_of_time[WStrings]"

139: test_subscriber_terminates_in_a_finite_amount_of_time[WStrings] (test_communication.TestPublisherSubscriber)
139: Test that the subscriber terminates after a finite amount of time. ... [INFO] [test_publisher-23]: process started with pid [5128]
139: [INFO] [test_subscriber-24]: process started with pid [1732]
139: [test_subscriber-24] exception in subscriber:
139: [test_subscriber-24] Traceback (most recent call last):
139: [test_subscriber-24]   File "C:/ci/ws/src/ros2/system_tests/test_communication/test/subscriber_py.py", line 81, in <module>
139: [test_subscriber-24]     listener(message_name=args.message_name, namespace=args.namespace)
139: [test_subscriber-24]   File "C:/ci/ws/src/ros2/system_tests/test_communication/test/subscriber_py.py", line 65, in listener
139: [test_subscriber-24]     rclpy.spin_once(node)
139: [test_subscriber-24]   File "C:\ci\ws\install\Lib\site-packages\rclpy\__init__.py", line 171, in spin_once
139: [test_subscriber-24]     executor.spin_once(timeout_sec=timeout_sec)
139: [test_subscriber-24]   File "C:\ci\ws\install\Lib\site-packages\rclpy\executors.py", line 685, in spin_once
139: [test_subscriber-24]     raise handler.exception()
139: [test_subscriber-24]   File "C:\ci\ws\install\Lib\site-packages\rclpy\task.py", line 239, in __call__
139: [test_subscriber-24]     self._handler.send(None)
139: [test_subscriber-24]   File "C:\ci\ws\install\Lib\site-packages\rclpy\executors.py", line 397, in handler
139: [test_subscriber-24]     arg = take_from_wait_list(entity)
139: [test_subscriber-24]   File "C:\ci\ws\install\Lib\site-packages\rclpy\executors.py", line 325, in _take_subscription
139: [test_subscriber-24]     msg = _rclpy.rclpy_take(capsule, sub.msg_type, sub.raw)
139: [test_subscriber-24] UnicodeDecodeError: 'utf-16-le' codec can't decode bytes in position 0-1: illegal encoding
139: [ERROR] [test_subscriber-24]: process has died [pid 1732, exit code 1, cmd 'C:\Python37\python_d.exe C:/ci/ws/src/ros2/system_tests/test_communication/test/subscriber_py.py WStrings /test_time_11_49_47'].
139: [WARNING] [test_publisher-23]: 'SIGINT' sent to process[test_publisher-23] not supported on Windows, escalating to 'SIGTERM'
139: [INFO] [test_publisher-23]: sending signal 'SIGTERM' to process[test_publisher-23]
139: [ERROR] [test_publisher-23]: process has died [pid 5128, exit code 1, cmd 'C:\Python37\python_d.exe C:/ci/ws/src/ros2/system_tests/test_communication/test/publisher_py.py WStrings /test_time_11_49_47'].
139: ok

A useless stack trace appears in the failed test case:

139: test_processes_finished_gracefully[WStrings] (test_communication.TestPublisherSubscriberAfterShutdown)
139: Test that both executables finished gracefully. ... FAIL
139: 
139: ======================================================================
139: FAIL: test_processes_finished_gracefully[WStrings] (test_communication.TestPublisherSubscriberAfterShutdown)
139: Test that both executables finished gracefully.
139: ----------------------------------------------------------------------
139: Traceback (most recent call last):
139:   File "C:\ci\ws\build\test_communication\test_publisher_subscriber__rclpy__rmw_fastrtps_cpp_Debug.py", line 77, in test_processes_finished_gracefully
139:     'test_subscriber'
139:   File "C:\ci\ws\install\Lib\site-packages\launch_testing\asserts\assert_exit_codes.py", line 64, in assertExitCodes
139:     info.returncode
139: AssertionError: Proc test_subscriber-24 exited with code 1
Additional information

Unfortunately, searching these logs for the string "[ERROR]" is made somewhat less useful since even a passing test cases send a SIGTERM to the subprocess, causing it to log an error.

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start by reproducing the referenced Windows CI failure and read the test_communication cases, especially test_processes_finished_gracefully, plus subscriber_py.py and publisher_py.py. Trace how launch_testing records subprocess failures and assigns output to test cases. Done means the originating crash is reported with its associated test rather than a separate passing or shutdown test.

Written by the indexing model from the issue text.

Assessment

Tech stack
python
Domain
testing-qa
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
30/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.