ros_gz icon indicating copy to clipboard operation
ros_gz copied to clipboard

Published 20 hours ago • verified publisher icon gazebosim

ros_ign_bridge test_launch_test_ros_subscriber.launch.py fails intermittently

Open andermi opened this issue 1 year ago • 3 comments

Environment

  • OS Version: Ubuntu 20.04
  • Source: galactic, 94abe668a8e5ef8cfad9059f9e8ce125f12415c6

Description

ros_ign_bridge test_launch_test_ros_subscriber.launch.py fails intermittently

Steps to reproduce

  1. clone, checkout, build
  2. colcon test

Output

test 3
[0.171s]       Start  3: test_launch_test_ros_subscriber.launch.py
[0.171s] 
[0.171s] 3: Test command: /usr/bin/python3 "-u" "/opt/ros/galactic/share/ament_cmake_test/cmake/run_test.py" "/home/anderson/wec/igngzb/openrobotics/workspace/build/ros_ign_bridge/test_results/ros_ign_bridge/test_launch_test_ros_subscriber.launch.py.xunit.xml" "--package-name" "ros_ign_bridge" "--output-file" "/home/anderson/wec/igngzb/openrobotics/workspace/build/ros_ign_bridge/launch_test/test_launch_test_ros_subscriber.launch.py.txt" "--command" "/usr/bin/python3" "-m" "launch_testing.launch_test" "/home/anderson/wec/igngzb/openrobotics/workspace/src/ros_ign/ros_ign_bridge/test/launch/test_ros_subscriber.launch.py" "gz_msgs_ver:=8.6.0" "--junit-xml=/home/anderson/wec/igngzb/openrobotics/workspace/build/ros_ign_bridge/test_results/ros_ign_bridge/test_launch_test_ros_subscriber.launch.py.xunit.xml" "--package-name=ros_ign_bridge"
[0.171s] 3: Test timeout computed to be: 200
[0.210s] 3: -- run_test.py: invoking following command in '/home/anderson/wec/igngzb/openrobotics/workspace/build/ros_ign_bridge':
[0.210s] 3:  - /usr/bin/python3 -m launch_testing.launch_test /home/anderson/wec/igngzb/openrobotics/workspace/src/ros_ign/ros_ign_bridge/test/launch/test_ros_subscriber.launch.py gz_msgs_ver:=8.6.0 --junit-xml=/home/anderson/wec/igngzb/openrobotics/workspace/build/ros_ign_bridge/test_results/ros_ign_bridge/test_launch_test_ros_subscriber.launch.py.xunit.xml --package-name=ros_ign_bridge
[0.425s] 3: [INFO] [launch]: All log files can be found below /home/anderson/.ros/log/2022-08-18-16-50-57-737194-Gladosu-3464716
[0.426s] 3: [INFO] [launch]: Default logging verbosity is set to INFO
[0.465s] 3: test_termination (ros_ign_bridge.ROSSubscriberTest) ... [INFO] [test_ign_publisher-1]: process started with pid [3464719]
[0.465s] 3: [INFO] [test_ros_subscriber-2]: process started with pid [3464721]
[0.465s] 3: [INFO] [parameter_bridge-3]: process started with pid [3464723]
[0.465s] 3: [INFO] [python3-4]: process started with pid [3464725]
[0.482s] 3: [test_ros_subscriber-2] [==========] Running 45 tests from 1 test suite.
[0.482s] 3: [test_ros_subscriber-2] [----------] Global test environment set-up.
[0.482s] 3: [test_ros_subscriber-2] [----------] 45 tests from ROSSubscriberTest
[0.482s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.vector3d_point
[0.517s] 3: [parameter_bridge-3] [INFO] [1660866657.901788223] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/vector3d_point (ignition.msgs.Vector3d) -> /vector3d_point (geometry_msgs/msg/Point)] (Lazy 0)
[0.518s] 3: [parameter_bridge-3] [INFO] [1660866657.902900337] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/pose_pose (ignition.msgs.Pose) -> /pose_pose (geometry_msgs/msg/Pose)] (Lazy 0)
[0.518s] 3: [parameter_bridge-3] [INFO] [1660866657.903379264] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/pose_posestamped (ignition.msgs.Pose) -> /pose_posestamped (geometry_msgs/msg/PoseStamped)] (Lazy 0)
[0.519s] 3: [parameter_bridge-3] [INFO] [1660866657.903830133] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/quaternion_quaternion (ignition.msgs.Quaternion) -> /quaternion_quaternion (geometry_msgs/msg/Quaternion)] (Lazy 0)
[0.519s] 3: [parameter_bridge-3] [INFO] [1660866657.904277476] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/pose_transform (ignition.msgs.Pose) -> /pose_transform (geometry_msgs/msg/Transform)] (Lazy 0)
[0.520s] 3: [parameter_bridge-3] [INFO] [1660866657.904733060] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/pose_transformstamped (ignition.msgs.Pose) -> /pose_transformstamped (geometry_msgs/msg/TransformStamped)] (Lazy 0)
[0.520s] 3: [parameter_bridge-3] [INFO] [1660866657.905200116] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/twist_twist (ignition.msgs.Twist) -> /twist_twist (geometry_msgs/msg/Twist)] (Lazy 0)
[0.521s] 3: [parameter_bridge-3] [INFO] [1660866657.905663295] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/vector3d_vector3 (ignition.msgs.Vector3d) -> /vector3d_vector3 (geometry_msgs/msg/Vector3)] (Lazy 0)
[0.521s] 3: [parameter_bridge-3] [INFO] [1660866657.906187911] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/wrench_wrench (ignition.msgs.Wrench) -> /wrench_wrench (geometry_msgs/msg/Wrench)] (Lazy 0)
[0.522s] 3: [parameter_bridge-3] [INFO] [1660866657.906668835] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/odometry_odometry (ignition.msgs.Odometry) -> /odometry_odometry (nav_msgs/msg/Odometry)] (Lazy 0)
[0.522s] 3: [parameter_bridge-3] [INFO] [1660866657.907486700] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/any_parametervalue (ignition.msgs.Any) -> /any_parametervalue (rcl_interfaces/msg/ParameterValue)] (Lazy 0)
[0.523s] 3: [parameter_bridge-3] [INFO] [1660866657.908092042] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/contact_contact (ignition.msgs.Contact) -> /contact_contact (ros_ign_interfaces/msg/Contact)] (Lazy 0)
[0.524s] 3: [parameter_bridge-3] [INFO] [1660866657.908955691] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/contacts_contacts (ignition.msgs.Contacts) -> /contacts_contacts (ros_ign_interfaces/msg/Contacts)] (Lazy 0)
[0.524s] 3: [parameter_bridge-3] [INFO] [1660866657.909584047] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/dataframe_dataframe (ignition.msgs.Dataframe) -> /dataframe_dataframe (ros_ign_interfaces/msg/Dataframe)] (Lazy 0)
[0.525s] 3: [parameter_bridge-3] [INFO] [1660866657.910147208] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/entity_entity (ignition.msgs.Entity) -> /entity_entity (ros_ign_interfaces/msg/Entity)] (Lazy 0)
[0.525s] 3: [parameter_bridge-3] [INFO] [1660866657.910673342] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/guicamera_guicamera (ignition.msgs.GUICamera) -> /guicamera_guicamera (ros_ign_interfaces/msg/GuiCamera)] (Lazy 0)
[0.526s] 3: [parameter_bridge-3] [INFO] [1660866657.911251488] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/jointwrench_jointwrench (ignition.msgs.JointWrench) -> /jointwrench_jointwrench (ros_ign_interfaces/msg/JointWrench)] (Lazy 0)
[0.527s] 3: [parameter_bridge-3] [INFO] [1660866657.911812095] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/light_light (ignition.msgs.Light) -> /light_light (ros_ign_interfaces/msg/Light)] (Lazy 0)
[0.527s] 3: [parameter_bridge-3] [INFO] [1660866657.912384571] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/param_paramvec (ignition.msgs.Param) -> /param_paramvec (ros_ign_interfaces/msg/ParamVec)] (Lazy 0)
[0.528s] 3: [parameter_bridge-3] [INFO] [1660866657.912920157] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/param_v_paramvec (ignition.msgs.Param_V) -> /param_v_paramvec (ros_ign_interfaces/msg/ParamVec)] (Lazy 0)
[0.528s] 3: [parameter_bridge-3] [INFO] [1660866657.913340861] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/stringmsg_v_stringvec (ignition.msgs.StringMsg_V) -> /stringmsg_v_stringvec (ros_ign_interfaces/msg/StringVec)] (Lazy 0)
[0.529s] 3: [parameter_bridge-3] [INFO] [1660866657.913857362] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/trackvisual_trackvisual (ignition.msgs.TrackVisual) -> /trackvisual_trackvisual (ros_ign_interfaces/msg/TrackVisual)] (Lazy 0)
[0.529s] 3: [parameter_bridge-3] [INFO] [1660866657.914387571] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/videorecord_videorecord (ignition.msgs.VideoRecord) -> /videorecord_videorecord (ros_ign_interfaces/msg/VideoRecord)] (Lazy 0)
[0.530s] 3: [parameter_bridge-3] [INFO] [1660866657.914914029] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/clock_clock (ignition.msgs.Clock) -> /clock_clock (rosgraph_msgs/msg/Clock)] (Lazy 0)
[0.530s] 3: [parameter_bridge-3] [INFO] [1660866657.915497495] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/batterystate_batterystate (ignition.msgs.BatteryState) -> /batterystate_batterystate (sensor_msgs/msg/BatteryState)] (Lazy 0)
[0.531s] 3: [parameter_bridge-3] [INFO] [1660866657.916391115] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/camerainfo_camerainfo (ignition.msgs.CameraInfo) -> /camerainfo_camerainfo (sensor_msgs/msg/CameraInfo)] (Lazy 0)
[0.532s] 3: [parameter_bridge-3] [INFO] [1660866657.916928916] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/fluidpressure_fluidpressure (ignition.msgs.FluidPressure) -> /fluidpressure_fluidpressure (sensor_msgs/msg/FluidPressure)] (Lazy 0)
[0.532s] 3: [parameter_bridge-3] [INFO] [1660866657.917470147] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/image_image (ignition.msgs.Image) -> /image_image (sensor_msgs/msg/Image)] (Lazy 0)
[0.533s] 3: [parameter_bridge-3] [INFO] [1660866657.917992912] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/imu_imu (ignition.msgs.IMU) -> /imu_imu (sensor_msgs/msg/Imu)] (Lazy 0)
[0.533s] 3: [parameter_bridge-3] [INFO] [1660866657.918530507] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/model_jointstate (ignition.msgs.Model) -> /model_jointstate (sensor_msgs/msg/JointState)] (Lazy 0)
[0.534s] 3: [parameter_bridge-3] [INFO] [1660866657.919061261] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/laserscan_laserscan (ignition.msgs.LaserScan) -> /laserscan_laserscan (sensor_msgs/msg/LaserScan)] (Lazy 0)
[0.534s] 3: [parameter_bridge-3] [INFO] [1660866657.919575572] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/magnetometer_magneticfield (ignition.msgs.Magnetometer) -> /magnetometer_magneticfield (sensor_msgs/msg/MagneticField)] (Lazy 0)
[0.535s] 3: [parameter_bridge-3] [INFO] [1660866657.920086480] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/navsat_navsatfix (ignition.msgs.NavSat) -> /navsat_navsatfix (sensor_msgs/msg/NavSatFix)] (Lazy 0)
[0.535s] 3: [parameter_bridge-3] [INFO] [1660866657.920612117] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/pointcloudpacked_pointcloud2 (ignition.msgs.PointCloudPacked) -> /pointcloudpacked_pointcloud2 (sensor_msgs/msg/PointCloud2)] (Lazy 0)
[0.536s] 3: [parameter_bridge-3] [INFO] [1660866657.921137005] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/boolean_bool (ignition.msgs.Boolean) -> /boolean_bool (std_msgs/msg/Bool)] (Lazy 0)
[0.537s] 3: [parameter_bridge-3] [INFO] [1660866657.921715578] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/color_colorrgba (ignition.msgs.Color) -> /color_colorrgba (std_msgs/msg/ColorRGBA)] (Lazy 0)
[0.537s] 3: [parameter_bridge-3] [INFO] [1660866657.922218038] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/empty_empty (ignition.msgs.Empty) -> /empty_empty (std_msgs/msg/Empty)] (Lazy 0)
[0.538s] 3: [parameter_bridge-3] [INFO] [1660866657.922713223] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/float_float32 (ignition.msgs.Float) -> /float_float32 (std_msgs/msg/Float32)] (Lazy 0)
[0.538s] 3: [parameter_bridge-3] [INFO] [1660866657.923210338] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/double_float64 (ignition.msgs.Double) -> /double_float64 (std_msgs/msg/Float64)] (Lazy 0)
[0.539s] 3: [parameter_bridge-3] [INFO] [1660866657.923704545] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/header_header (ignition.msgs.Header) -> /header_header (std_msgs/msg/Header)] (Lazy 0)
[0.539s] 3: [parameter_bridge-3] [INFO] [1660866657.924203742] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/int32_int32 (ignition.msgs.Int32) -> /int32_int32 (std_msgs/msg/Int32)] (Lazy 0)
[0.539s] 3: [parameter_bridge-3] [INFO] [1660866657.924692200] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/stringmsg_string (ignition.msgs.StringMsg) -> /stringmsg_string (std_msgs/msg/String)] (Lazy 0)
[0.540s] 3: [parameter_bridge-3] [INFO] [1660866657.925184106] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/uint32_uint32 (ignition.msgs.UInt32) -> /uint32_uint32 (std_msgs/msg/UInt32)] (Lazy 0)
[0.540s] 3: [parameter_bridge-3] [INFO] [1660866657.925676520] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/pose_v_tfmessage (ignition.msgs.Pose_V) -> /pose_v_tfmessage (tf2_msgs/msg/TFMessage)] (Lazy 0)
[0.541s] 3: [parameter_bridge-3] [INFO] [1660866657.926419443] [ros_ign_bridge]: Creating IGN->ROS Bridge: [/jointtrajectory_jointtrajectory (ignition.msgs.JointTrajectory) -> /jointtrajectory_jointtrajectory (trajectory_msgs/msg/JointTrajectory)] (Lazy 0)
[0.617s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.vector3d_point (135 ms)
[0.617s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.pose_pose
[0.627s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.pose_pose (11 ms)
[0.627s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.pose_posestamped
[0.637s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.pose_posestamped (10 ms)
[0.638s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.quaternion_quaternion
[0.648s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.quaternion_quaternion (10 ms)
[0.648s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.pose_transform
[0.658s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.pose_transform (11 ms)
[0.658s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.pose_transformstamped
[0.669s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.pose_transformstamped (10 ms)
[0.669s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.twist_twist
[0.679s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.twist_twist (11 ms)
[0.679s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.vector3d_vector3
[0.690s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.vector3d_vector3 (10 ms)
[0.690s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.wrench_wrench
[0.700s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.wrench_wrench (10 ms)
[0.700s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.odometry_odometry
[0.710s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.odometry_odometry (11 ms)
[0.711s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.any_parametervalue
[0.721s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.any_parametervalue (10 ms)
[0.721s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.contact_contact
[0.732s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.contact_contact (11 ms)
[0.732s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.contacts_contacts
[0.743s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.contacts_contacts (11 ms)
[0.743s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.dataframe_dataframe
[2.772s] 3: [test_ros_subscriber-2] /home/anderson/wec/igngzb/openrobotics/workspace/build/ros_ign_bridge/generated/test/ros_ign_interfaces_subscriber.cpp:57: Failure
[2.772s] 3: [test_ros_subscriber-2] Value of: client.callbackExecuted
[2.772s] 3: [test_ros_subscriber-2]   Actual: false
[2.772s] 3: [test_ros_subscriber-2] Expected: true
[2.772s] 3: [test_ros_subscriber-2] [  FAILED  ] ROSSubscriberTest.dataframe_dataframe (2030 ms)
[2.773s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.entity_entity
[4.807s] 3: [test_ros_subscriber-2] /home/anderson/wec/igngzb/openrobotics/workspace/build/ros_ign_bridge/generated/test/ros_ign_interfaces_subscriber.cpp:69: Failure
[4.808s] 3: [test_ros_subscriber-2] Value of: client.callbackExecuted
[4.808s] 3: [test_ros_subscriber-2]   Actual: false
[4.808s] 3: [test_ros_subscriber-2] Expected: true
[4.808s] 3: [test_ros_subscriber-2] [  FAILED  ] ROSSubscriberTest.entity_entity (2035 ms)
[4.808s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.guicamera_guicamera
[6.842s] 3: [test_ros_subscriber-2] /home/anderson/wec/igngzb/openrobotics/workspace/build/ros_ign_bridge/generated/test/ros_ign_interfaces_subscriber.cpp:81: Failure
[6.842s] 3: [test_ros_subscriber-2] Value of: client.callbackExecuted
[6.842s] 3: [test_ros_subscriber-2]   Actual: false
[6.842s] 3: [test_ros_subscriber-2] Expected: true
[6.842s] 3: [test_ros_subscriber-2] [  FAILED  ] ROSSubscriberTest.guicamera_guicamera (2035 ms)
[6.842s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.jointwrench_jointwrench
[8.878s] 3: [test_ros_subscriber-2] /home/anderson/wec/igngzb/openrobotics/workspace/build/ros_ign_bridge/generated/test/ros_ign_interfaces_subscriber.cpp:93: Failure
[8.878s] 3: [test_ros_subscriber-2] Value of: client.callbackExecuted
[8.878s] 3: [test_ros_subscriber-2]   Actual: false
[8.878s] 3: [test_ros_subscriber-2] Expected: true
[8.878s] 3: [test_ros_subscriber-2] [  FAILED  ] ROSSubscriberTest.jointwrench_jointwrench (2035 ms)
[8.878s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.light_light
[8.888s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.light_light (11 ms)
[8.888s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.param_paramvec
[8.899s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.param_paramvec (10 ms)
[8.899s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.param_v_paramvec
[8.909s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.param_v_paramvec (10 ms)
[8.909s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.stringmsg_v_stringvec
[8.919s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.stringmsg_v_stringvec (11 ms)
[8.919s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.trackvisual_trackvisual
[10.948s] 3: [test_ros_subscriber-2] /home/anderson/wec/igngzb/openrobotics/workspace/build/ros_ign_bridge/generated/test/ros_ign_interfaces_subscriber.cpp:153: Failure
[10.948s] 3: [test_ros_subscriber-2] Value of: client.callbackExecuted
[10.948s] 3: [test_ros_subscriber-2]   Actual: false
[10.948s] 3: [test_ros_subscriber-2] Expected: true
[10.948s] 3: [test_ros_subscriber-2] [  FAILED  ] ROSSubscriberTest.trackvisual_trackvisual (2029 ms)
[10.948s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.videorecord_videorecord
[12.980s] 3: [test_ros_subscriber-2] /home/anderson/wec/igngzb/openrobotics/workspace/build/ros_ign_bridge/generated/test/ros_ign_interfaces_subscriber.cpp:165: Failure
[12.981s] 3: [test_ros_subscriber-2] Value of: client.callbackExecuted
[12.981s] 3: [test_ros_subscriber-2]   Actual: false
[12.981s] 3: [test_ros_subscriber-2] Expected: true
[12.981s] 3: [test_ros_subscriber-2] [  FAILED  ] ROSSubscriberTest.videorecord_videorecord (2032 ms)
[12.981s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.clock_clock
[15.019s] 3: [test_ros_subscriber-2] /home/anderson/wec/igngzb/openrobotics/workspace/build/ros_ign_bridge/generated/test/rosgraph_msgs_subscriber.cpp:33: Failure
[15.019s] 3: [test_ros_subscriber-2] Value of: client.callbackExecuted
[15.019s] 3: [test_ros_subscriber-2]   Actual: false
[15.019s] 3: [test_ros_subscriber-2] Expected: true
[15.019s] 3: [test_ros_subscriber-2] [  FAILED  ] ROSSubscriberTest.clock_clock (2038 ms)
[15.019s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.batterystate_batterystate
[15.030s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.batterystate_batterystate (11 ms)
[15.030s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.camerainfo_camerainfo
[15.040s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.camerainfo_camerainfo (11 ms)
[15.040s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.fluidpressure_fluidpressure
[15.051s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.fluidpressure_fluidpressure (10 ms)
[15.051s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.image_image
[15.072s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.image_image (21 ms)
[15.072s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.imu_imu
[15.082s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.imu_imu (10 ms)
[15.082s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.model_jointstate
[15.093s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.model_jointstate (11 ms)
[15.093s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.laserscan_laserscan
[15.103s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.laserscan_laserscan (10 ms)
[15.103s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.magnetometer_magneticfield
[15.114s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.magnetometer_magneticfield (11 ms)
[15.114s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.navsat_navsatfix
[15.124s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.navsat_navsatfix (10 ms)
[15.124s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.pointcloudpacked_pointcloud2
[15.135s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.pointcloudpacked_pointcloud2 (11 ms)
[15.135s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.boolean_bool
[15.145s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.boolean_bool (10 ms)
[15.145s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.color_colorrgba
[15.156s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.color_colorrgba (11 ms)
[15.156s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.empty_empty
[15.166s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.empty_empty (10 ms)
[15.166s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.float_float32
[15.177s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.float_float32 (11 ms)
[15.177s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.double_float64
[15.187s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.double_float64 (10 ms)
[15.187s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.header_header
[15.198s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.header_header (11 ms)
[15.198s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.int32_int32
[15.208s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.int32_int32 (10 ms)
[15.208s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.stringmsg_string
[15.219s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.stringmsg_string (11 ms)
[15.219s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.uint32_uint32
[15.229s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.uint32_uint32 (10 ms)
[15.229s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.pose_v_tfmessage
[15.240s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.pose_v_tfmessage (11 ms)
[15.240s] 3: [test_ros_subscriber-2] [ RUN      ] ROSSubscriberTest.jointtrajectory_jointtrajectory
[15.251s] 3: [test_ros_subscriber-2] [       OK ] ROSSubscriberTest.jointtrajectory_jointtrajectory (11 ms)
[15.251s] 3: [test_ros_subscriber-2] [----------] 45 tests from ROSSubscriberTest (14769 ms total)
[15.251s] 3: [test_ros_subscriber-2] 
[15.251s] 3: [test_ros_subscriber-2] [----------] Global test environment tear-down
[15.251s] 3: [test_ros_subscriber-2] [==========] 45 tests from 1 test suite ran. (14769 ms total)
[15.251s] 3: [test_ros_subscriber-2] [  PASSED  ] 38 tests.
[15.251s] 3: [test_ros_subscriber-2] [  FAILED  ] 7 tests, listed below:
[15.251s] 3: [test_ros_subscriber-2] [  FAILED  ] ROSSubscriberTest.dataframe_dataframe
[15.251s] 3: [test_ros_subscriber-2] [  FAILED  ] ROSSubscriberTest.entity_entity
[15.251s] 3: [test_ros_subscriber-2] [  FAILED  ] ROSSubscriberTest.guicamera_guicamera
[15.251s] 3: [test_ros_subscriber-2] [  FAILED  ] ROSSubscriberTest.jointwrench_jointwrench
[15.251s] 3: [test_ros_subscriber-2] [  FAILED  ] ROSSubscriberTest.trackvisual_trackvisual
[15.251s] 3: [test_ros_subscriber-2] [  FAILED  ] ROSSubscriberTest.videorecord_videorecord
[15.251s] 3: [test_ros_subscriber-2] [  FAILED  ] ROSSubscriberTest.clock_clock
[15.251s] 3: [test_ros_subscriber-2] 
[15.251s] 3: [test_ros_subscriber-2]  7 FAILED TESTS
[15.423s] 3: [ERROR] [test_ros_subscriber-2]: process has died [pid 3464721, exit code 1, cmd '/home/anderson/wec/igngzb/openrobotics/workspace/install/ros_ign_bridge/lib/ros_ign_bridge/test_ros_subscriber --ros-args'].
[15.425s] 3: [INFO] [python3-4]: sending signal 'SIGINT' to process[python3-4]
[15.425s] 3: [INFO] [parameter_bridge-3]: sending signal 'SIGINT' to process[parameter_bridge-3]
[15.425s] 3: [INFO] [test_ign_publisher-1]: sending signal 'SIGINT' to process[test_ign_publisher-1]
[15.426s] 3: [parameter_bridge-3] [INFO] [1660866672.810187600] [rclcpp]: signal_handler(signal_value=2)
[15.427s] 3: [INFO] [python3-4]: process has finished cleanly [pid 3464725]
[15.431s] 3: [INFO] [test_ign_publisher-1]: process has finished cleanly [pid 3464719]
[20.430s] 3: [ERROR] [parameter_bridge-3]: process[parameter_bridge-3] failed to terminate '5' seconds after receiving 'SIGINT', escalating to 'SIGTERM'
[20.430s] 3: [INFO] [parameter_bridge-3]: sending signal 'SIGTERM' to process[parameter_bridge-3]
[20.434s] 3: [INFO] [parameter_bridge-3]: process has finished cleanly [pid 3464723]
[20.435s] 3: ok
[20.435s] 3: 
[20.435s] 3: ----------------------------------------------------------------------
[20.435s] 3: Ran 1 test in 14.960s
[20.435s] 3: 
[20.435s] 3: OK
[20.435s] 3: test_exit_code (ros_ign_bridge.ROSSubscriberTestAfterShutdown) ... FAIL
[20.435s] 3: 
[20.435s] 3: ======================================================================
[20.435s] 3: FAIL: test_exit_code (ros_ign_bridge.ROSSubscriberTestAfterShutdown)
[20.435s] 3: ----------------------------------------------------------------------
[20.436s] 3: Traceback (most recent call last):
[20.436s] 3:   File "/home/anderson/wec/igngzb/openrobotics/workspace/src/ros_ign/ros_ign_bridge/test/launch/test_ros_subscriber.launch.py", line 88, in test_exit_code
[20.436s] 3:     launch_testing.asserts.assertExitCodes(
[20.436s] 3:   File "/opt/ros/galactic/lib/python3.8/site-packages/launch_testing/asserts/assert_exit_codes.py", line 62, in assertExitCodes
[20.436s] 3:     assert info.returncode in allowable_exit_codes, 'Proc {} exited with code {}'.format(
[20.436s] 3: AssertionError: Proc test_ros_subscriber-2 exited with code 1
[20.436s] 3: 
[20.436s] 3: ----------------------------------------------------------------------
[20.436s] 3: Ran 1 test in 0.000s
[20.436s] 3: 
[20.436s] 3: FAILED (failures=1)
[20.452s] 3: -- run_test.py: return code 1
[20.452s] 3: -- run_test.py: verify result file '/home/anderson/wec/igngzb/openrobotics/workspace/build/ros_ign_bridge/test_results/ros_ign_bridge/test_launch_test_ros_subscriber.launch.py.xunit.xml'
[20.458s]  3/13 Test  #3: test_launch_test_ros_subscriber.launch.py ...***Failed   20.29 sec

andermi avatar Aug 19 '22 00:08 andermi

I was not able to reproduce this, is the same test failing every time?

quarkytale avatar Aug 25 '22 01:08 quarkytale

same test failing every time

It's the same tests within test_launch_test_ros_subscriber.launch.py that fail, but they don't fail every time.

andermi avatar Aug 25 '22 19:08 andermi

A suggestion was to check if its a flaky test or not by trying --retest-until-pass N.

quarkytale avatar Aug 26 '22 05:08 quarkytale

@andermi out of curiosity, is there another bridge/publisher/subscriber instance that maybe a zombie? I have had this happen rarely, but it seems to always be related to a test that didn't bring itself down cleanly.

mjcarroll avatar Sep 23 '22 13:09 mjcarroll

Possible, although I haven't had this issue pop up again for a long time.

andermi avatar Sep 23 '22 14:09 andermi

Alright, I'm trying to prune down issues, so if you haven't seen this for a while, I'm going to close it. If it comes up again, feel free to re-open.

mjcarroll avatar Sep 23 '22 14:09 mjcarroll