Connection failure is not handled in the case of empty http_error

[sarguez]

Describe the bug
Hello,

We encountered this during start-up for some unknown reason.

[/r2000_node 1702277410.446433]: Unable to communicate with device. Please check the IP address
[/r2000_node 1702277410.446537]: Unable to initialize device
[/r2000_node 1702277412.446467]: HTTP ERROR:

After the bringup restart, the node started spamming:

[/r2000_node INFO 1702214003.725490]: HTTP ERROR: Recv failure: Connection reset by peer

If I checked it correctly, it seems that the node is not trying to re-establish the connection when it receives an empty http_error.

  if (http_error.compare(std::string("OK")))
  {
    std::cerr << "HTTP ERROR: " << http_error << std::endl;
    if (is_connection_failure(http_error))
    {
      if (handle_connection_failure)
      {
        handle_connection_failure();
      }
    }
    return false;
  }

handle_connection_failure terminates the connection and tries to restart it.
I guess restarting the bringup without running that made it stuck in some weird state. I speculate that it may be the cause for this one:

[/r2000_node INFO 1702214003.725490]: HTTP ERROR: Recv failure: Connection reset by peer

Environment (please complete the following information):

• OS: Ubuntu 20.04.06 LTS
• ROS Version: ROS Noetic

Sensor

• Device: R2000
• FW Version:"1.62"
• HW Version:"1.72"

[hsd-dev]

Thanks for pointing out the issue. I can take a look early next week.

[sarguez]

Hello, is there any updates on this? Thanks

[hsd-dev]

Sorry for the delay. I will take a look at it today and get back.

[hsd-dev]

@sarguez the main problem here seems to be that the IP address is wrong. Have you made sure the IP address is correctly set in the YAML file?
And secondly, what do you mean by "bringup restart"? Do you restart the launch file?

Also,

If I checked it correctly, it seems that the node is not trying to re-establish the connection when it receives an empty http_error.

The driver should not try to re-establish the connection if the HTTP error is empty. It should try to re-establish only in case of these following error strings

pf_lidar_ros_driver/src/pf_driver/src/pf/pfsdp_base.cpp

Lines 51 to 52 in 16dd98c

	std::string error_1 = "Failed to connect to ";
	std::string error_2 = "No route to host";

[sarguez]

Hello,

• Yes, I've checked the yaml file and our parameters. The IP address was correctly provided.
• By "bringup restart" I meant the launch file, we have some large bringup launch file for the robot that ultimately starts the r2000 node as well.

In our case, for some reason we got an http_error that was not OK, but didn't include the strings you've mentioned as well. Instead, it was just an empty string. Would you like to handle this case in the codeblock block ?

if (http_error.compare(std::string("OK"))) { std::cerr << "HTTP ERROR: " << http_error << std::endl; if (is_connection_failure(http_error)) { if (handle_connection_failure) { handle_connection_failure(); } } return false; }
We just received an log message with an empty HTTP ERROR of the form:
[/r2000_node 1702277412.446467]: HTTP ERROR:

and then the device got stuck in this state after I restarted the node.
[/r2000_node INFO 1702214003.725490]: HTTP ERROR: Recv failure: Connection reset by peer

Do you see any possibility to handle with this case?

[hsd-dev]

I am not sure how will re-connection help in this case. Re-connection was meant for cases where the device is unplugged (device is still on) or the device is powered off. For re-connection to happen, the connection must be established in the first place. In your case, the device did not even initialized, so I don't see the point of trying to reconnect.

Maybe @ptruka has some inputs as to why the HTTP error is empty?

[ptruka]

Hello @sarguez,
To classify the issue, I have 2 basic questions:

1. Is it possible to talk to the Sensor from your robots shell? curl 'http://<Sensor_IP_here>/cmd/get_parameter'
2. Is the Sensor model name starting with OMD...?

[sarguez]

Hello,
(1) Yes, and (2) Yes.

Here is the info I got from the sensor.

{ "vendor":"Pepperl+Fuchs", "product":"OMD30M-R2000-B23-V1V1D-HD-1L", "part":"305986", "serial":"40000123378020", "revision_fw":"1.62", "revision_hw":"1.72", "max_connections":3, "feature_flags":[ "ethernet", "input_output_q1", "input_output_q2", "lens_contamination_monitor", "scan_data_filter" ], "radial_range_max":30.000000, "radial_range_min":0.000000, "radial_resolution":0.001000, "angular_fov":360.000000, "angular_resolution":0.000100, "ip_mode":"static", "ip_address":"192.168.22.6", "subnet_mask":"255.0.0.0", "gateway":"192.168.22.1", "scan_frequency":10, "scan_direction":"ccw", "samples_per_scan":7200, "scan_frequency_measured":10.000000, "status_flags":0, "load_indication":30, "up_time":292, "power_cycles":257, "operation_time":436065, "operation_time_scaled":497061, "temperature_current":44, "temperature_min":33, "temperature_max":56, "contamination":0, "user_tag":"OMD30M-R2000-HD", "device_family":3, "mac_address":"000d810e164d", "hmi_display_mode":"off", "hmi_language":"english", "hmi_button_lock":"on", "hmi_parameter_lock":"on", "ip_mode_current":"static", "ip_address_current":"192.168.22.6", "subnet_mask_current":"255.0.0.0", "gateway_current":"192.168.22.1", "system_time_raw":75408246954810, "user_notes":"", "locator_indication":"off", "scan_frequency_min":10.000000, "scan_frequency_max":50.000000, "sampling_rate_min":100, "sampling_rate_max":84000, "hmi_static_text_1":"Pepperl+Fuchs", "hmi_static_text_2":"R2000", "hmi_application_text_1":"", "hmi_application_text_2":"", "hmi_static_logo":"AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAP//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4IAz4IAz4IAz4IAz4IAz4IAz4IAz4P8z4P8z4P8z4PEg4PEg4PEgYPEgYPEgYPEgIPEgIPMyIPMzIPMzIPMzIPMzIPMzIPMzIPMzIPAzIPAzIPAzIPhzIPhzIPzzIP//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAP//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4IAz4IAz4IAz4IAz4IAz4IAz4IAz4P8z4P8z4P8z4PEg4PEg4PEgYPEgYPEgYPEgIPEgIPMyIPMzIPMzIPMzIPMzIPMzIPMzIPMzIPAzIPAzIPAzIPhzIPhzIPzzIP//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAP//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4IAz4IAz4IAz4IAz4IAz4IAz4IAz4P8z4P8z4P8z4PEg4PEg4PEgYPEgYPEgYPEgIPEgIPMyIPMzIPMzIPMzIPMzIPMzIPMzIPMzIPAzIPAzIPAzIPhzIPhzIPzzIP//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4P//4AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA", "hmi_application_bitmap":"AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA", "operating_mode":"measure", "emitter_type":2, "filter_type":"remission", "filter_width":2, "filter_error_handling":"tolerant", "filter_remission_threshold":"diffuse_high", "filter_maximum_margin":100, "lcm_num_sectors":12, "lcm_detection_sensitivity":"disabled", "lcm_detection_period":5000, "lcm_sector_enable":[ "on", "on", "on", "on", "on", "on", "on", "on", "on", "on", "on", "on" ], "lcm_sector_warn_flags":0, "lcm_sector_error_flags":0, "error_code":0, "error_text":"success" }

[ptruka]

Hello and thanks for the information. Everything is looking fine there.
I tried to replicate your issue on foxy with several IP settings, but I wasn't able to get an empty HTTP error.

• Is there a http_proxy set on your machine that could impact the driver?
• Have you tried to start the driver (latest, from source) with the standard r2000.launch file?

[sarguez]

Hello,

• No, there shouldn't be any http_proxies.
• Unfortutanely we don't use the latest from the source.
  We build commit "682a1fb965ee16a0b3f2646fed288c1f969ad7ba" in a build farm and install it.
  Also, we start the r2000 node from a custom launch file, passing in its configuration from another yaml file with these settings:

pf_driver_version: "1.2.1" transport: "tcp" scanner_ip: "192.168.22.6" device: "R2000" scan_topic: "/scan_top" frame_id: "laser_scanner_klt_press_link" port: 0 start_angle: -1800000

[ptruka]

Thanks for the information. I will try to replicate the issue with the driver version you mentioned.

Edit: I just finished some tests on Ubuntu 20, ROS noetic with the driver version you are using (commit 682a1fb) to see wich http error messages I can achieve.

A) IP address not available

The IP address was set to an unused address in the yaml file. Result:
HTTP ERROR: Failed to connect to 169.254.0.109 port 80: No route to host

SUMMARY
========

PARAMETERS
 * /r2000_node/R2000/device: R2000
 * /r2000_node/R2000/frame_id: scanner_link
 * /r2000_node/R2000/max_num_points_scan: 0
 * /r2000_node/R2000/packet_type: C
 * /r2000_node/R2000/scan_topic: /scan
 * /r2000_node/R2000/scanner_ip: 169.254.0.109
 * /r2000_node/R2000/start_angle: -1800000
 * /r2000_node/R2000/transport: udp
 * /r2000_node/R2000/watchdog: True
 * /r2000_node/R2000/watchdogtimeout: 60000
 * /r2000_node/device: R2000
 * /robot_description: <?xml version="1....
 * /rosdistro: noetic
 * /rosversion: 1.16.0

NODES
  /
    r2000_node (pf_driver/ros_main)
    robot_state_publisher (robot_state_publisher/robot_state_publisher)
    rviz (rviz/rviz)

auto-starting new master
process[master]: started with pid [6178]
ROS_MASTER_URI=http://localhost:11311

setting /run_id to 2831dc36-cffb-11ee-ba53-851b673072f7
process[rosout-1]: started with pid [6189]
started core service [/rosout]
process[robot_state_publisher-2]: started with pid [6196]
process[r2000_node-3]: started with pid [6197]
process[rviz-4]: started with pid [6198]
HTTP ERROR: Failed to connect to 169.254.0.109 port 80: No route to host
[ERROR] [1708438814.996074545]: Unable to communicate with device. Please check the IP address
[ERROR] [1708438814.997611703]: Unable to initialize device
[r2000_node-3] process has died [pid 6197, exit code 255, [...]

B) Wrong IP address

The IP address was set to an address of an random network device in the yaml file. (In this case my router). Result:
protocol error:
[ERROR] [1708438857.767760187]: Unable to communicate with device. Please check the IP address

SUMMARY
========

PARAMETERS
 * /r2000_node/R2000/device: R2000
 * /r2000_node/R2000/frame_id: scanner_link
 * /r2000_node/R2000/max_num_points_scan: 0
 * /r2000_node/R2000/packet_type: C
 * /r2000_node/R2000/scan_topic: /scan
 * /r2000_node/R2000/scanner_ip: 192.168.50.1
 * /r2000_node/R2000/start_angle: -1800000
 * /r2000_node/R2000/transport: udp
 * /r2000_node/R2000/watchdog: True
 * /r2000_node/R2000/watchdogtimeout: 60000
 * /r2000_node/device: R2000
 * /robot_description: <?xml version="1....
 * /rosdistro: noetic
 * /rosversion: 1.16.0

NODES
  /
    r2000_node (pf_driver/ros_main)
    robot_state_publisher (robot_state_publisher/robot_state_publisher)
    rviz (rviz/rviz)

auto-starting new master
process[master]: started with pid [6328]
ROS_MASTER_URI=http://localhost:11311

setting /run_id to 438276a8-cffb-11ee-ba53-851b673072f7
process[rosout-1]: started with pid [6338]
started core service [/rosout]
process[robot_state_publisher-2]: started with pid [6346]
process[r2000_node-3]: started with pid [6347]
process[rviz-4]: started with pid [6348]
protocol error:  
[ERROR] [1708438857.767760187]: Unable to communicate with device. Please check the IP address
[ERROR] [1708438857.769252763]: Unable to initialize device

@sarguez If you got any advice how I could replicate your setup in some way, I would try to do so. Otherwise I'm a bit clueless how we could find the root cause here.

[sarguez]

Hello,

Unfortunately I don't know a way to reliably reproduce the issue yet, but it is encountered yet again on one of our robots. Some background again:

• We build the pf driver with commit: 682a1fb in our build farm.
• Package it as a debian package, and install to the robot.
• We don't use the r2000 launch file, and the default ymal file, but the node is launched by some other launch file with another yaml file. I can guarantee that the provided IP address is the actual IP address of the scanner, so it's not some wrong IP address problem.

This morning we realized that the top scanner was not publishing on one of our robots.
The logs showed a spam of these messages:
[/r2000_node INFO 1708906749.837431]: HTTP ERROR: [/r2000_node ERROR 1708906749.837425]: Unable to communicate with device. Please check the IP address [/r2000_node ERROR 1708906749.837454]: Unable to initialize device

I got a coredump of the r2000_node by sending SIGABRT to it.
In the attachements, you can find the coredump, as well the executable + the debug info on it.

2024-02-26-coredump.zip

This is what I see in the coredumpctl gdb.
Maybe this can give more information on what gets stuck.

`
GNU gdb (Ubuntu 9.2-0ubuntu1~20.04.1) 9.2
Copyright (C) 2020 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later http://gnu.org/licenses/gpl.html
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
http://www.gnu.org/software/gdb/bugs/.
Find the GDB manual and other documentation resources online at:
http://www.gnu.org/software/gdb/documentation/.

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /opt/ros/noetic/lib/pf_driver/ros_main...
Reading symbols from /usr/lib/debug/.build-id/f5/5608d0635856e57fc7ba9e5261d74162fe3c16.debug...
[New LWP 1855320]
[New LWP 1857497]
[New LWP 1857406]
[New LWP 1857651]
[New LWP 1857653]
[New LWP 1857656]
[New LWP 1857658]
[New LWP 1857655]
[New LWP 1857410]
[New LWP 1858165]
[New LWP 1857654]
[New LWP 1857412]
[New LWP 1857652]
[New LWP 1857657]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/opt/ros/noetic/lib/pf_driver/ros_main __master:=http://soto-0011:11311 __ns:=/'.
Program terminated with signal SIGABRT, Aborted.
#0 0x00007f88329df23f in __GI___clock_nanosleep (clock_id=clock_id@entry=0, flags=flags@entry=0, req=0x7ffe6e32b490, rem=0x7ffe6e32b490) at ../sysdeps/unix/sysv/linux/clock_nanosleep.c:78
78 ../sysdeps/unix/sysv/linux/clock_nanosleep.c: No such file or directory.
[Current thread is 1 (Thread 0x7f882f183ac0 (LWP 1855320))]
(gdb) info threads
Id Target Id Frame

• 1 Thread 0x7f882f183ac0 (LWP 1855320) 0x00007f88329df23f in __GI___clock_nanosleep (clock_id=clock_id@entry=0, flags=flags@entry=0, req=0x7ffe6e32b490, rem=0x7ffe6e32b490) at ../sysdeps/unix/sysv/linux/clock_nanosleep.c:78
  2 Thread 0x7f882d56b700 (LWP 1857497) futex_abstimed_wait_cancelable (private=, abstime=0x7f882d56aa20, clockid=, expected=0, futex_word=0x5577d5db0048) at ../sysdeps/nptl/futex-internal.h:320
  3 Thread 0x7f882ed6e700 (LWP 1857406) 0x00007f8832a2168e in epoll_wait (epfd=4, events=0x7f882ed6d7f0, maxevents=6, timeout=100) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
  4 Thread 0x7f882cd6a700 (LWP 1857651) futex_abstimed_wait_cancelable (private=, abstime=0x7f882cd69a30, clockid=, expected=0, futex_word=0x5577d5daaf28) at ../sysdeps/nptl/futex-internal.h:320
  5 Thread 0x7f881f7fe700 (LWP 1857653) futex_abstimed_wait_cancelable (private=, abstime=0x7f881f7fda30, clockid=, expected=0, futex_word=0x5577d5daaf28) at ../sysdeps/nptl/futex-internal.h:320
  6 Thread 0x7f881e7fc700 (LWP 1857656) futex_abstimed_wait_cancelable (private=, abstime=0x7f881e7fba30, clockid=, expected=0, futex_word=0x5577d5daaf28) at ../sysdeps/nptl/futex-internal.h:320
  7 Thread 0x7f881d7fa700 (LWP 1857658) futex_abstimed_wait_cancelable (private=, abstime=0x7f881d7f9a30, clockid=, expected=0, futex_word=0x5577d5daaf28) at ../sysdeps/nptl/futex-internal.h:320
  8 Thread 0x7f881effd700 (LWP 1857655) futex_abstimed_wait_cancelable (private=, abstime=0x7f881effca30, clockid=, expected=0, futex_word=0x5577d5daaf28) at ../sysdeps/nptl/futex-internal.h:320
  9 Thread 0x7f882e56d700 (LWP 1857410) 0x00007f8832a14bbf in __GI___poll (fds=0x7f8820000b60, nfds=1, timeout=100) at ../sysdeps/unix/sysv/linux/poll.c:29
  10 Thread 0x7f88177fe700 (LWP 1858165) futex_abstimed_wait_cancelable (private=, abstime=0x7f88177fda60, clockid=, expected=0,
  futex_word=0x7f88331898f4 <ros::TimerManager<ros::Time, ros::Duration, ros::TimerEvent>::global()::global+148>) at ../sysdeps/nptl/futex-internal.h:320
  11 Thread 0x7f8816ffd700 (LWP 1857654) futex_abstimed_wait_cancelable (private=, abstime=0x7f8816ffca30, clockid=, expected=0, futex_word=0x5577d5daaf28) at ../sysdeps/nptl/futex-internal.h:320
  12 Thread 0x7f882dd6c700 (LWP 1857412) futex_wait_cancelable (private=, expected=0, futex_word=0x5577d5dac6fc) at ../sysdeps/nptl/futex-internal.h:183
  13 Thread 0x7f881ffff700 (LWP 1857652) futex_abstimed_wait_cancelable (private=, abstime=0x7f881fffea30, clockid=, expected=0, futex_word=0x5577d5daaf28) at ../sysdeps/nptl/futex-internal.h:320
  14 Thread 0x7f881dffb700 (LWP 1857657) futex_abstimed_wait_cancelable (private=, abstime=0x7f881dffaa30, clockid=, expected=0, futex_word=0x5577d5daaf28) at ../sysdeps/nptl/futex-internal.h:320
  (gdb) thread 1 bt
  [Switching to thread 1 (Thread 0x7f882f183ac0 (LWP 1855320))]
  #0 0x00007f88329df23f in __GI___clock_nanosleep (clock_id=clock_id@entry=0, flags=flags@entry=0, req=0x7ffe6e32b490, rem=0x7ffe6e32b490) at ../sysdeps/unix/sysv/linux/clock_nanosleep.c:78
  78 in ../sysdeps/unix/sysv/linux/clock_nanosleep.c
  (gdb) thread apply all bt
  ,
  Thread 14 (Thread 0x7f881dffb700 (LWP 1857657)):
  #0 futex_abstimed_wait_cancelable (private=, abstime=0x7f881dffaa30, clockid=, expected=0, futex_word=0x5577d5daaf28) at ../sysdeps/nptl/futex-internal.h:320
  Not getting any data from any of the scan topics #1 __pthread_cond_wait_common (abstime=0x7f881dffaa30, clockid=, mutex=0x5577d5daaed8, cond=0x5577d5daaf00) at pthread_cond_wait.c:520
  Is UDP supposed to work? #2 __pthread_cond_timedwait (cond=0x5577d5daaf00, mutex=0x5577d5daaed8, abstime=0x7f881dffaa30) at pthread_cond_wait.c:665
  Display custom text #3 0x00007f88330e035f in ros::CallbackQueue::callOne(ros::WallDuration) () from /opt/ros/noetic/lib/libroscpp.so
  Fixed hard-coded host address #4 0x00007f88331333f5 in ros::AsyncSpinnerImpl::threadFunc() () from /opt/ros/noetic/lib/libroscpp.so
  Update r2300_allscans launch file to pass args #5 0x00007f883284543b in ?? () from /lib/x86_64-linux-gnu/libboost_thread.so.1.71.0
  Dynamic reconfigure #6 0x00007f883333d609 in start_thread (arg=) at pthread_create.c:477
  Ros serialization #7 0x00007f8832a21353 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 13 (Thread 0x7f881ffff700 (LWP 1857652)):
#0 futex_abstimed_wait_cancelable (private=, abstime=0x7f881fffea30, clockid=, expected=0, futex_word=0x5577d5daaf28) at ../sysdeps/nptl/futex-internal.h:320
#1 __pthread_cond_wait_common (abstime=0x7f881fffea30, clockid=, mutex=0x5577d5daaed8, cond=0x5577d5daaf00) at pthread_cond_wait.c:520
#2 __pthread_cond_timedwait (cond=0x5577d5daaf00, mutex=0x5577d5daaed8, abstime=0x7f881fffea30) at pthread_cond_wait.c:665
#3 0x00007f88330e035f in ros::CallbackQueue::callOne(ros::WallDuration) () from /opt/ros/noetic/lib/libroscpp.so
#4 0x00007f88331333f5 in ros::AsyncSpinnerImpl::threadFunc() () from /opt/ros/noetic/lib/libroscpp.so
#5 0x00007f883284543b in ?? () from /lib/x86_64-linux-gnu/libboost_thread.so.1.71.0
#6 0x00007f883333d609 in start_thread (arg=) at pthread_create.c:477
#7 0x00007f8832a21353 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 12 (Thread 0x7f882dd6c700 (LWP 1857412)):
#0 futex_wait_cancelable (private=, expected=0, futex_word=0x5577d5dac6fc) at ../sysdeps/nptl/futex-internal.h:183
#1 __pthread_cond_wait_common (abstime=0x0, clockid=0, mutex=0x5577d5dac6a8, cond=0x5577d5dac6d0) at pthread_cond_wait.c:508
#2 __pthread_cond_wait (cond=0x5577d5dac6d0, mutex=0x5577d5dac6a8) at pthread_cond_wait.c:647
#3 0x00007f88331194d7 in ros::ROSOutAppender::logThread() () from /opt/ros/noetic/lib/libroscpp.so
#4 0x00007f883284543b in ?? () from /lib/x86_64-linux-gnu/libboost_thread.so.1.71.0
#5 0x00007f883333d609 in start_thread (arg=) at pthread_create.c:477
#6 0x00007f8832a21353 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 11 (Thread 0x7f8816ffd700 (LWP 1857654)):
#0 futex_abstimed_wait_cancelable (private=, abstime=0x7f8816ffca30, clockid=, expected=0, futex_word=0x5577d5daaf28) at ../sysdeps/nptl/futex-internal.h:320
#1 __pthread_cond_wait_common (abstime=0x7f8816ffca30, clockid=, mutex=0x5577d5daaed8, cond=0x5577d5daaf00) at pthread_cond_wait.c:520
#2 __pthread_cond_timedwait (cond=0x5577d5daaf00, mutex=0x5577d5daaed8, abstime=0x7f8816ffca30) at pthread_cond_wait.c:665
#3 0x00007f88330e035f in ros::CallbackQueue::callOne(ros::WallDuration) () from /opt/ros/noetic/lib/libroscpp.so
#4 0x00007f88331333f5 in ros::AsyncSpinnerImpl::threadFunc() () from /opt/ros/noetic/lib/libroscpp.so
#5 0x00007f883284543b in ?? () from /lib/x86_64-linux-gnu/libboost_thread.so.1.71.0
#6 0x00007f883333d609 in start_thread (arg=) at pthread_create.c:477
#7 0x00007f8832a21353 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 10 (Thread 0x7f88177fe700 (LWP 1858165)):
#0 futex_abstimed_wait_cancelable (private=, abstime=0x7f88177fda60, clockid=, expected=0, futex_word=0x7f88331898f4 <ros::TimerManager<ros::Time, ros::Duration, ros::TimerEvent>::global()::global+148>) at ../sysdeps/nptl/futex-internal.h:320
#1 __pthread_cond_wait_common (abstime=0x7f88177fda60, clockid=, mutex=0x7f88331898a0 <ros::TimerManager<ros::Time, ros::Duration, ros::TimerEvent>::global()::global+64>, cond=0x7f88331898c8 <ros::TimerManager<ros::Time, ros::Duration, ros::TimerEvent>::global()::global+104>) at pthread_cond_wait.c:520
#2 __pthread_cond_timedwait (cond=0x7f88331898c8 <ros::TimerManager<ros::Time, ros::Duration, ros::TimerEvent>::global()::global+104>, mutex=0x7f88331898a0 <ros::TimerManager<ros::Time, ros::Duration, ros::TimerEvent>::global()::global+64>, abstime=0x7f88177fda60) at pthread_cond_wait.c:665
#3 0x00007f88330b92d6 in boost::condition_variable::do_wait_until(boost::unique_lockboost::mutex&, boost::detail::mono_platform_timepoint const&) () from /opt/ros/noetic/lib/libroscpp.so
#4 0x00007f88330bae85 in ros::TimerManager<ros::Time, ros::Duration, ros::TimerEvent>::threadFunc() () from /opt/ros/noetic/lib/libroscpp.so
#5 0x00007f883284543b in ?? () from /lib/x86_64-linux-gnu/libboost_thread.so.1.71.0
#6 0x00007f883333d609 in start_thread (arg=) at pthread_create.c:477
#7 0x00007f8832a21353 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 9 (Thread 0x7f882e56d700 (LWP 1857410)):
#0 0x00007f8832a14bbf in __GI___poll (fds=0x7f8820000b60, nfds=1, timeout=100) at ../sysdeps/unix/sysv/linux/poll.c:29
#1 0x00007f8832fc44dd in XmlRpc::XmlRpcDispatch::work(double) () from /opt/ros/noetic/lib/libxmlrpcpp.so
--Type for more, q to quit, c to continue without paging--,
#2 0x00007f88330b1f1a in ros::XMLRPCManager::serverThreadFunc() () from /opt/ros/noetic/lib/libroscpp.so
#3 0x00007f883284543b in ?? () from /lib/x86_64-linux-gnu/libboost_thread.so.1.71.0
#4 0x00007f883333d609 in start_thread (arg=) at pthread_create.c:477
#5 0x00007f8832a21353 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 8 (Thread 0x7f881effd700 (LWP 1857655)):
#0 futex_abstimed_wait_cancelable (private=, abstime=0x7f881effca30, clockid=, expected=0, futex_word=0x5577d5daaf28) at ../sysdeps/nptl/futex-internal.h:320
#1 __pthread_cond_wait_common (abstime=0x7f881effca30, clockid=, mutex=0x5577d5daaed8, cond=0x5577d5daaf00) at pthread_cond_wait.c:520
#2 __pthread_cond_timedwait (cond=0x5577d5daaf00, mutex=0x5577d5daaed8, abstime=0x7f881effca30) at pthread_cond_wait.c:665
#3 0x00007f88330e035f in ros::CallbackQueue::callOne(ros::WallDuration) () from /opt/ros/noetic/lib/libroscpp.so
#4 0x00007f88331333f5 in ros::AsyncSpinnerImpl::threadFunc() () from /opt/ros/noetic/lib/libroscpp.so
#5 0x00007f883284543b in ?? () from /lib/x86_64-linux-gnu/libboost_thread.so.1.71.0
#6 0x00007f883333d609 in start_thread (arg=) at pthread_create.c:477
#7 0x00007f8832a21353 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 7 (Thread 0x7f881d7fa700 (LWP 1857658)):
#0 futex_abstimed_wait_cancelable (private=, abstime=0x7f881d7f9a30, clockid=, expected=0, futex_word=0x5577d5daaf28) at ../sysdeps/nptl/futex-internal.h:320
#1 __pthread_cond_wait_common (abstime=0x7f881d7f9a30, clockid=, mutex=0x5577d5daaed8, cond=0x5577d5daaf00) at pthread_cond_wait.c:520
#2 __pthread_cond_timedwait (cond=0x5577d5daaf00, mutex=0x5577d5daaed8, abstime=0x7f881d7f9a30) at pthread_cond_wait.c:665
#3 0x00007f88330e035f in ros::CallbackQueue::callOne(ros::WallDuration) () from /opt/ros/noetic/lib/libroscpp.so
#4 0x00007f88331333f5 in ros::AsyncSpinnerImpl::threadFunc() () from /opt/ros/noetic/lib/libroscpp.so
#5 0x00007f883284543b in ?? () from /lib/x86_64-linux-gnu/libboost_thread.so.1.71.0
#6 0x00007f883333d609 in start_thread (arg=) at pthread_create.c:477
#7 0x00007f8832a21353 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 6 (Thread 0x7f881e7fc700 (LWP 1857656)):
#0 futex_abstimed_wait_cancelable (private=, abstime=0x7f881e7fba30, clockid=, expected=0, futex_word=0x5577d5daaf28) at ../sysdeps/nptl/futex-internal.h:320
#1 __pthread_cond_wait_common (abstime=0x7f881e7fba30, clockid=, mutex=0x5577d5daaed8, cond=0x5577d5daaf00) at pthread_cond_wait.c:520
#2 __pthread_cond_timedwait (cond=0x5577d5daaf00, mutex=0x5577d5daaed8, abstime=0x7f881e7fba30) at pthread_cond_wait.c:665
#3 0x00007f88330e035f in ros::CallbackQueue::callOne(ros::WallDuration) () from /opt/ros/noetic/lib/libroscpp.so
#4 0x00007f88331333f5 in ros::AsyncSpinnerImpl::threadFunc() () from /opt/ros/noetic/lib/libroscpp.so
#5 0x00007f883284543b in ?? () from /lib/x86_64-linux-gnu/libboost_thread.so.1.71.0
#6 0x00007f883333d609 in start_thread (arg=) at pthread_create.c:477
#7 0x00007f8832a21353 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 5 (Thread 0x7f881f7fe700 (LWP 1857653)):
#0 futex_abstimed_wait_cancelable (private=, abstime=0x7f881f7fda30, clockid=, expected=0, futex_word=0x5577d5daaf28) at ../sysdeps/nptl/futex-internal.h:320
#1 __pthread_cond_wait_common (abstime=0x7f881f7fda30, clockid=, mutex=0x5577d5daaed8, cond=0x5577d5daaf00) at pthread_cond_wait.c:520
#2 __pthread_cond_timedwait (cond=0x5577d5daaf00, mutex=0x5577d5daaed8, abstime=0x7f881f7fda30) at pthread_cond_wait.c:665
#3 0x00007f88330e035f in ros::CallbackQueue::callOne(ros::WallDuration) () from /opt/ros/noetic/lib/libroscpp.so
#4 0x00007f88331333f5 in ros::AsyncSpinnerImpl::threadFunc() () from /opt/ros/noetic/lib/libroscpp.so
#5 0x00007f883284543b in ?? () from /lib/x86_64-linux-gnu/libboost_thread.so.1.71.0
#6 0x00007f883333d609 in start_thread (arg=) at pthread_create.c:477
#7 0x00007f8832a21353 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 4 (Thread 0x7f882cd6a700 (LWP 1857651)):
#0 futex_abstimed_wait_cancelable (private=, abstime=0x7f882cd69a30, clockid=, expected=0, futex_word=0x5577d5daaf28) at ../sysdeps/nptl/futex-internal.h:320
#1 __pthread_cond_wait_common (abstime=0x7f882cd69a30, clockid=, mutex=0x5577d5daaed8, cond=0x5577d5daaf00) at pthread_cond_wait.c:520
#2 __pthread_cond_timedwait (cond=0x5577d5daaf00, mutex=0x5577d5daaed8, abstime=0x7f882cd69a30) at pthread_cond_wait.c:665
#3 0x00007f88330e035f in ros::CallbackQueue::callOne(ros::WallDuration) () from /opt/ros/noetic/lib/libroscpp.so
#4 0x00007f88331333f5 in ros::AsyncSpinnerImpl::threadFunc() () from /opt/ros/noetic/lib/libroscpp.so
#5 0x00007f883284543b in ?? () from /lib/x86_64-linux-gnu/libboost_thread.so.1.71.0
#6 0x00007f883333d609 in start_thread (arg=) at pthread_create.c:477
#7 0x00007f8832a21353 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 3 (Thread 0x7f882ed6e700 (LWP 1857406)):
--Type for more, q to quit, c to continue without paging--
#0 0x00007f8832a2168e in epoll_wait (epfd=4, events=0x7f882ed6d7f0, maxevents=6, timeout=100) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
#1 0x00007f88330be648 in ros::poll_sockets(int, pollfd*, unsigned long, int) () from /opt/ros/noetic/lib/libroscpp.so
#2 0x00007f8833139eec in ros::PollSet::update(int) () from /opt/ros/noetic/lib/libroscpp.so
#3 0x00007f88330cbdcd in ros::PollManager::threadFunc() () from /opt/ros/noetic/lib/libroscpp.so
#4 0x00007f883284543b in ?? () from /lib/x86_64-linux-gnu/libboost_thread.so.1.71.0
#5 0x00007f883333d609 in start_thread (arg=) at pthread_create.c:477
#6 0x00007f8832a21353 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 2 (Thread 0x7f882d56b700 (LWP 1857497)):
#0 futex_abstimed_wait_cancelable (private=, abstime=0x7f882d56aa20, clockid=, expected=0, futex_word=0x5577d5db0048) at ../sysdeps/nptl/futex-internal.h:320
#1 __pthread_cond_wait_common (abstime=0x7f882d56aa20, clockid=, mutex=0x5577d5dafff8, cond=0x5577d5db0020) at pthread_cond_wait.c:520
#2 __pthread_cond_timedwait (cond=0x5577d5db0020, mutex=0x5577d5dafff8, abstime=0x7f882d56aa20) at pthread_cond_wait.c:665
#3 0x00007f88330e0bbf in ros::CallbackQueue::callAvailable(ros::WallDuration) () from /opt/ros/noetic/lib/libroscpp.so
#4 0x00007f883311c0bf in ros::internalCallbackQueueThreadFunc() () from /opt/ros/noetic/lib/libroscpp.so
#5 0x00007f883284543b in ?? () from /lib/x86_64-linux-gnu/libboost_thread.so.1.71.0
#6 0x00007f883333d609 in start_thread (arg=) at pthread_create.c:477
#7 0x00007f8832a21353 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 1 (Thread 0x7f882f183ac0 (LWP 1855320)):
#0 0x00007f88329df23f in __GI___clock_nanosleep (clock_id=clock_id@entry=0, flags=flags@entry=0, req=0x7ffe6e32b490, rem=0x7ffe6e32b490) at ../sysdeps/unix/sysv/linux/clock_nanosleep.c:78
#1 0x00007f88329e4ec7 in __GI___nanosleep (requested_time=, remaining=) at nanosleep.c:27
#2 0x00005577d4ac8925 in std::this_thread::sleep_for<long, std::ratio<1l, 1000l> > (__rtime=...) at /usr/include/c++/9/thread:378
#3 main (argc=, argv=) at ./src/ros/ros_main.cpp:79

`

[ptruka]

Thanks for sharing the coredump. @ipa-vsp and me are trying to find some hints in there.
Would it be possible to record a rosbag as well?

2 more points:

• Is this issue appearing on multiple R2000 Lidars?
• Could you change the scanners protocol from tcp to udp?

[sarguez]

Hello,

• Yes it is happenning on multiple R2000 Lidars.
• I can discuss switching to udp with my team. It would be a bit scary if the problems magically disappear after switching. Do you have any plausible explanation on how tcp might be causing this ?

I brought more data :D
It seems there is a clear evolution to the state. The empty http error only starts to happen after it moves through several stages.
Please see the attached log of the r2000_node.

State 1: Out of nowhere, we start receiving this. This seems to be a state the lidar side. It is probably the root cause of all these. I don't know why the connection may be reset like this. Once we get into this state, this log is spammed endlessly.

[/r2000_node INFO 1708874253.097190]: HTTP ERROR: Recv failure: Connection reset by peer
[/r2000_node INFO 1708874267.091813]: HTTP ERROR: Recv failure: Connection reset by peer
[/r2000_node INFO 1708874292.008136]: HTTP ERROR: Recv failure: Connection reset by peer
[/r2000_node INFO 1708874320.184500]: HTTP ERROR: Recv failure: Connection reset by peer
[/r2000_node INFO 1708874331.841351]: HTTP ERROR: Recv failure: Connection reset by peer
[/r2000_node INFO 1708874331.842875]: HTTP ERROR: Recv failure: Connection reset by peer
[/r2000_node INFO 1708874332.212972]: HTTP ERROR: Recv failure: Connection reset by peer
[/r2000_node INFO 1708874332.262164]: HTTP ERROR: Recv failure: Connection reset by peer
[/r2000_node INFO 1708874332.420150]: HTTP ERROR: Recv failure: Connection reset by peer
[/r2000_node INFO 1708874332.421731]: HTTP ERROR: Recv failure: Connection reset by peer
[/r2000_node INFO 1708874332.788176]: HTTP ERROR: Recv failure: Connection reset by peer
[/r2000_node INFO 1708874333.315895]: HTTP ERROR: Recv failure: Connection reset by peer
[/r2000_node INFO 1708874333.317785]: HTTP ERROR: Recv failure: Connection reset by peer

During this state, we occasionally get the 'empty reply from server' as well.

[/r2000_node INFO 1708874435.985660]: HTTP ERROR: Recv failure: Connection reset by peer
[/r2000_node INFO 1708874435.986734]: HTTP ERROR: Empty reply from server

State 2: The error changes to protocol error : 120 for no apperant reason.

[/r2000_node INFO 1708874496.916874]: protocol error: 120 Invalid handle or no handle provided
[/r2000_node INFO 1708874496.921875]: protocol error: 120 Invalid handle or no handle provided
[/r2000_node INFO 1708874496.926688]: protocol error: 120 Invalid handle or no handle provided
[/r2000_node INFO 1708874496.931299]: protocol error: 120 Invalid handle or no handle provided
[/r2000_node INFO 1708874496.936006]: protocol error: 120 Invalid handle or no handle provided
[/r2000_node INFO 1708874496.940739]: protocol error: 120 Invalid handle or no handle provided
[/r2000_node INFO 1708874496.945395]: protocol error: 120 Invalid handle or no handle provided
[/r2000_node INFO 1708874496.950443]: protocol error: 120 Invalid handle or no handle provided

State 3: R2000 node starts restarting due to network failure. This goes on for a long time as well.

[/r2000_node INFO 1708874497.148912]: Time out: No packets received in 2 seconds
[/r2000_node ERROR 1708874497.149085]: Network failure
[/r2000_node INFO 1708874497.152199]: protocol error: 120 Invalid handle or no handle provided
[/r2000_node INFO 1708874497.155190]: Device state changed to Uninitialized
[/r2000_node INFO 1708874497.172877]: Device found: R2000
[/r2000_node INFO 1708874497.177799]: protocol error: 120 Invalid handle or no handle provided
[/r2000_node INFO 1708874497.186796]: protocol error: 333 Socket couldn't be created: Invalid argument
[/r2000_node INFO 1708874497.187552]: Connection refused
[/r2000_node ERROR 1708874497.187369]: Unable to establish TCP connection
[/r2000_node ERROR 1708874497.187402]: Unable to initialize device
[/r2000_node INFO 1708874499.206057]: Device found: R2000
[/r2000_node INFO 1708874499.210743]: protocol error: 120 Invalid handle or no handle provided
[/r2000_node INFO 1708874499.219778]: protocol error: 333 Socket couldn't be created: Invalid argument
[/r2000_node INFO 1708874499.220470]: Connection refused
[/r2000_node ERROR 1708874499.220527]: Unable to establish TCP connection
[/r2000_node ERROR 1708874499.220560]: Unable to initialize device
[/r2000_node INFO 1708874501.238728]: Device found: R2000
[/r2000_node INFO 1708874501.243391]: protocol error: 120 Invalid handle or no handle provided
[/r2000_node INFO 1708874501.252735]: protocol error: 333 Socket couldn't be created: Invalid argument
[/r2000_node INFO 1708874501.253588]: Connection refused
[/r2000_node ERROR 1708874501.253610]: Unable to establish TCP connection
[/r2000_node ERROR 1708874501.253628]: Unable to initialize device
[/r2000_node INFO 1708874503.272334]: Device found: R2000
[/r2000_node INFO 1708874503.279809]: protocol error: 120 Invalid handle or no handle provided
[/r2000_node INFO 1708874503.289056]: protocol error: 333 Socket couldn't be created: Invalid argument
[/r2000_node INFO 1708874503.289672]: Connection refused
[/r2000_node ERROR 1708874503.289720]: Unable to establish TCP connection
[/r2000_node ERROR 1708874503.289756]: Unable to initialize device

State 4: There comes the weird empty http error state.

[/r2000_node INFO 1708876599.048967]: Device found: R2000
[/r2000_node INFO 1708876599.053862]: protocol error: 120 Invalid handle or no handle provided
[/r2000_node INFO 1708876599.063075]: protocol error: 333 Socket couldn't be created: Invalid argument
[/r2000_node INFO 1708876599.063786]: Connection refused
[/r2000_node ERROR 1708876599.063809]: Unable to establish TCP connection
[/r2000_node ERROR 1708876599.063842]: Unable to initialize device
[/r2000_node INFO 1708876601.064085]: HTTP ERROR:
[/r2000_node ERROR 1708876601.064140]: Unable to communicate with device. Please check the IP address
[/r2000_node ERROR 1708876601.064191]: Unable to initialize device
[/r2000_node INFO 1708876603.064563]: HTTP ERROR:
[/r2000_node ERROR 1708876603.064494]: Unable to communicate with device. Please check the IP address
[/r2000_node ERROR 1708876603.064523]: Unable to initialize device
[/r2000_node INFO 1708876605.064770]: HTTP ERROR:
[/r2000_node ERROR 1708876605.064830]: Unable to communicate with device. Please check the IP address
[/r2000_node ERROR 1708876605.064859]: Unable to initialize device
[/r2000_node INFO 1708876607.065201]: HTTP ERROR:

r2000_node_log_S10.txt

[ipa-vsp]

Hello @sarguez,

Could you please provide us with some additional information to help us better understand the issue you're facing? Specifically, could you share the launch file you're using and the r2000_params.yaml files for all the devices involved? Additionally, it would be helpful if you could record a rosbag while the issue occurs. Thank you!

[ptruka]

Hi @sarguez,
thanks for the additional data. The Recv failure: Connection reset by peer worries me the most. I thought this could be caused by an undefined state of the scanner during it's boot up. So I power-cycled the scanner multiple times while I started the driver. As soon as the device was pingable, the driver failed in an expected manner (Connection refused). Unfortunately the Recv failure is not caused by this scenario.

HTTP ERROR: Failed to connect to 169.254.0.103 port 80: Connection refused
[ERROR] [1710406515.579619049]: Unable to communicate with device. Please check the IP address
[ERROR] [1710406515.580615764]: Unable to initialize device 

---

Other points

• A switch to udp was a wild guess. As I took a closer look, I don't think that there is any change when we switch from tcp to udp.
• Can we assume that the network load on the machine is not causing any issue?
• Is it possible to provide the information to @ipa-vsp to enable him a deep dive?

[sarguez]

Yes, I don't think the network load is an issue.

Sure, let's do more collaboration. Ideally, we can maybe provide you with access to the robot directly for debugging.

Unfortunately I don't think I can share things like the actual launch files, bag files, logs, etc. here on GitHub.
Can you please contact me from my work mail at: arguez@magazino.eu