AutonomyLab / bebop_autonomy

ROS driver for Parrot Bebop Drones 1.0 & 2.0
http://wiki.ros.org/bebop_autonomy
BSD 3-Clause "New" or "Revised" License
152 stars 121 forks source link

Crash when using bebop_node.launch (Timeout waiting for ack in buffer 11) #122

Open ghost opened 7 years ago

ghost commented 7 years ago

When running the driver using the included launch file, ie. ~$ roslaunch bebop_driver bebop_node.launch, the driver will very often crash, giving the error Timeout waiting for ack in buffer 11, among other things.

This does not occur every time the driver is run (sometimes it runs successfully) but it is very frequent (1/5 to 3/4 of attempts depending on the day).

We have also tried running as a nodelet instead, using ~$ roslaunch bebop_tools bebop_nodelet_iv.launch, for example, but have the same issue.

The system is ROS Kinetic running on Xubuntu 16.04 (no virtual machine). The same issue occurs on a different machine with the same setup.

The drone is a Bebop 2 that works perfectly with the Free Flight Pro app and/or Skycontroller. I believe it is running the latest firmware, as of 05/07/2017

bebop_autonomy, branch indigo_devel, up-to-date as of commit 8801830. We have checked out various older commits on git, all of which suffer from the same issue.

We have used the ardrone_autonomy package many times without this issue, also on branch indigo_devel.

Restarting the computer and/or terminal does not fix the problem.

stdout:

me@computer-xubuntu:~$ roslaunch bebop_driver bebop_node.launch 
... logging to ~/.ros/log/ace1d68a-6346-11e7-b558-9c5c8e7a62dc/roslaunch-computer-xubuntu-12206.log
Checking log directory for disk usage. This may take awhile.
Press Ctrl-C to interrupt
Done checking log file disk usage. Usage is <1GB.

xacro: Traditional processing is deprecated. Switch to --inorder processing!
To check for compatibility of your document, use option --check-order.
For more infos, see http://wiki.ros.org/xacro#Processing_Order
started roslaunch server http://computer-xubuntu:38319/

SUMMARY
========

PARAMETERS
 * /bebop/bebop_driver/bebop_ip: 192.168.42.1
 * /bebop/bebop_driver/camera_info_url: package://bebop_d...
 * /bebop/bebop_driver/cmd_vel_timeout: 0.2
 * /bebop/bebop_driver/odom_frame_id: odom
 * /bebop/bebop_driver/publish_odom_tf: True
 * /bebop/bebop_driver/reset_settings: True
 * /bebop/bebop_driver/states/enable_altitudechanged: True
 * /bebop/bebop_driver/states/enable_autotakeoffmodechanged: True
 * /bebop/bebop_driver/states/enable_camerastate_orientation: True
 * /bebop/bebop_driver/states/enable_commonstate_batterystatechanged: True
 * /bebop/bebop_driver/states/enable_commonstate_wifisignalchanged: True
 * /bebop/bebop_driver/states/enable_controllerstate_ispilotingchanged: True
 * /bebop/bebop_driver/states/enable_flightplanstate_availabilitystatechanged: True
 * /bebop/bebop_driver/states/enable_flightplanstate_componentstatelistchanged: True
 * /bebop/bebop_driver/states/enable_gpsstate_numberofsatellitechanged: True
 * /bebop/bebop_driver/states/enable_mavlinkstate_mavlinkfileplayingstatechanged: True
 * /bebop/bebop_driver/states/enable_mavlinkstate_mavlinkplayerrorstatechanged: True
 * /bebop/bebop_driver/states/enable_mediastreamingstate_videoenablechanged: True
 * /bebop/bebop_driver/states/enable_numberofsatellitechanged: True
 * /bebop/bebop_driver/states/enable_overheatstate_overheatchanged: True
 * /bebop/bebop_driver/states/enable_pilotingstate_altitudechanged: True
 * /bebop/bebop_driver/states/enable_pilotingstate_attitudechanged: True
 * /bebop/bebop_driver/states/enable_pilotingstate_flattrimchanged: True
 * /bebop/bebop_driver/states/enable_pilotingstate_flyingstatechanged: True
 * /bebop/bebop_driver/states/enable_pilotingstate_navigatehomestatechanged: True
 * /bebop/bebop_driver/states/enable_pilotingstate_positionchanged: True
 * /bebop/bebop_driver/states/enable_pilotingstate_speedchanged: True
 * /bebop/robot_description: <?xml version="1....
 * /rosdistro: kinetic
 * /rosversion: 1.12.7

NODES
  /bebop/
    bebop_driver (bebop_driver/bebop_driver_node)
    robot_state_publisher (robot_state_publisher/robot_state_publisher)

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

setting /run_id to ace1d68a-6346-11e7-b558-9c5c8e7a62dc
process[rosout-1]: started with pid [12233]
started core service [/rosout]
process[bebop/bebop_driver-2]: started with pid [12250]
process[bebop/robot_state_publisher-3]: started with pid [12251]
[ INFO] [1499454086.337017841]: Initializing nodelet with 4 worker threads.
[ INFO] [1499454086.376389570]: [BebopSDK] 13:01:26:376 | Bebop:225 - Bebop Cnstr()
[ INFO] [1499454086.376440060]: Nodelet Cstr
[ INFO] [1499454086.382416384]: Connecting to Bebop ...
[ INFO] [1499454086.384861273]: [CB] 13:01:26:384 | Ardrone3PilotingStateFlatTrimChanged:386 - [STATES] Enabling states/ardrone3/PilotingState/FlatTrimChanged
[ INFO] [1499454086.385787190]: [CB] 13:01:26:385 | Ardrone3PilotingStateFlyingStateChanged:430 - [STATES] Enabling states/ardrone3/PilotingState/FlyingStateChanged
[ INFO] [1499454086.387021293]: [CB] 13:01:26:387 | Ardrone3PilotingStateNavigateHomeStateChanged:532 - [STATES] Enabling states/ardrone3/PilotingState/NavigateHomeStateChanged
[ INFO] [1499454086.387961030]: [CB] 13:01:26:387 | Ardrone3PilotingStatePositionChanged:590 - [STATES] Enabling states/ardrone3/PilotingState/PositionChanged
[ INFO] [1499454086.388873440]: [CB] 13:01:26:388 | Ardrone3PilotingStateSpeedChanged:655 - [STATES] Enabling states/ardrone3/PilotingState/SpeedChanged
[ INFO] [1499454086.389725572]: [CB] 13:01:26:389 | Ardrone3PilotingStateAttitudeChanged:720 - [STATES] Enabling states/ardrone3/PilotingState/AttitudeChanged
[ INFO] [1499454086.391000108]: [CB] 13:01:26:390 | Ardrone3PilotingStateAltitudeChanged:836 - [STATES] Enabling states/ardrone3/PilotingState/AltitudeChanged
[ INFO] [1499454086.394465890]: [CB] 13:01:26:394 | Ardrone3MediaStreamingStateVideoEnableChanged:1300 - [STATES] Enabling states/ardrone3/MediaStreamingState/VideoEnableChanged
[ INFO] [1499454086.395727938]: [CB] 13:01:26:395 | Ardrone3CameraStateOrientation:1402 - [STATES] Enabling states/ardrone3/CameraState/Orientation
[ INFO] [1499454086.398700987]: [CB] 13:01:26:398 | Ardrone3GPSStateNumberOfSatelliteChanged:1794 - [STATES] Enabling states/ardrone3/GPSState/NumberOfSatelliteChanged
[ INFO] [1499454086.401210931]: [CB] 13:01:26:401 | CommonCommonStateBatteryStateChanged:148 - [STATES] Enabling states/common/CommonState/BatteryStateChanged
[ INFO] [1499454086.403775447]: [CB] 13:01:26:403 | CommonCommonStateWifiSignalChanged:510 - [STATES] Enabling states/common/CommonState/WifiSignalChanged
[ INFO] [1499454086.407013640]: [CB] 13:01:26:406 | CommonOverHeatStateOverHeatChanged:1023 - [STATES] Enabling states/common/OverHeatState/OverHeatChanged
[ INFO] [1499454086.408241386]: [CB] 13:01:26:408 | CommonMavlinkStateMavlinkFilePlayingStateChanged:1118 - [STATES] Enabling states/common/MavlinkState/MavlinkFilePlayingStateChanged
[ INFO] [1499454086.409077542]: [CB] 13:01:26:409 | CommonMavlinkStateMavlinkPlayErrorStateChanged:1183 - [STATES] Enabling states/common/MavlinkState/MavlinkPlayErrorStateChanged
[ INFO] [1499454086.412768858]: [CB] 13:01:26:412 | CommonFlightPlanStateAvailabilityStateChanged:1568 - [STATES] Enabling states/common/FlightPlanState/AvailabilityStateChanged
[ INFO] [1499454086.413706112]: [CB] 13:01:26:413 | CommonFlightPlanStateComponentStateListChanged:1619 - [STATES] Enabling states/common/FlightPlanState/ComponentStateListChanged
[ INFO] [1499454086.420073018]: [ARCONTROLLER_Network] 13:01:26:420 | ARCONTROLLER_Network_GetAvailableSocketPort:110 - d2c_port port: 54037
[ INFO] [1499454086.420190175]: [ARCONTROLLER_Stream2] 13:01:26:420 | ARCONTROLLER_Stream2_Open_Socket:124 - udp local port stream: 34815
[ INFO] [1499454086.420208025]: [ARCONTROLLER_Stream2] 13:01:26:420 | ARCONTROLLER_Stream2_Open_Socket:124 - udp local port control: 45447
[ERROR] [1499454086.952588798]: [ARNETWORK_Sender] 13:01:26:952 | ARNETWORK_Sender_ProcessBufferToSend:405 - [0x7f18082c8830] Timeout waiting for ack in buffer 11
[ERROR] [1499454086.952685800]: [ARNETWORK_Sender] 13:01:26:952 | ARNETWORK_Sender_ProcessBufferToSend:421 - [0x7f18082c8830] Will retry sending data of buffer 11
[ERROR] [1499454087.453009314]: [ARNETWORK_Sender] 13:01:27:452 | ARNETWORK_Sender_ProcessBufferToSend:405 - [0x7f18082c8830] Timeout waiting for ack in buffer 11
[ERROR] [1499454087.453101943]: [ARNETWORK_Sender] 13:01:27:453 | ARNETWORK_Sender_ProcessBufferToSend:421 - [0x7f18082c8830] Will retry sending data of buffer 11
[ERROR] [1499454087.953372899]: [ARNETWORK_Sender] 13:01:27:953 | ARNETWORK_Sender_ProcessBufferToSend:405 - [0x7f18082c8830] Timeout waiting for ack in buffer 11
[ERROR] [1499454087.953455830]: [ARNETWORK_Sender] 13:01:27:953 | ARNETWORK_Sender_ProcessBufferToSend:421 - [0x7f18082c8830] Will retry sending data of buffer 11
[ERROR] [1499454088.453769920]: [ARNETWORK_Sender] 13:01:28:453 | ARNETWORK_Sender_ProcessBufferToSend:405 - [0x7f18082c8830] Timeout waiting for ack in buffer 11
[ WARN] [1499454088.453876169]: [ARNETWORK_Sender] 13:01:28:453 | ARNETWORK_Sender_TimeOutCallback:655 - [0x7f18082c8830] Did timeout sending command : project = 0 | class = 4 | command = 1 - 0
[ERROR] [1499454088.954240048]: [ARNETWORK_Sender] 13:01:28:954 | ARNETWORK_Sender_ProcessBufferToSend:405 - [0x7f18082c8830] Timeout waiting for ack in buffer 11
[ERROR] [1499454088.954322906]: [ARNETWORK_Sender] 13:01:28:954 | ARNETWORK_Sender_ProcessBufferToSend:421 - [0x7f18082c8830] Will retry sending data of buffer 11
[ERROR] [1499454089.454610604]: [ARNETWORK_Sender] 13:01:29:454 | ARNETWORK_Sender_ProcessBufferToSend:405 - [0x7f18082c8830] Timeout waiting for ack in buffer 11
[ERROR] [1499454089.454705233]: [ARNETWORK_Sender] 13:01:29:454 | ARNETWORK_Sender_ProcessBufferToSend:421 - [0x7f18082c8830] Will retry sending data of buffer 11
[ERROR] [1499454089.954998815]: [ARNETWORK_Sender] 13:01:29:954 | ARNETWORK_Sender_ProcessBufferToSend:405 - [0x7f18082c8830] Timeout waiting for ack in buffer 11
[ERROR] [1499454089.955083068]: [ARNETWORK_Sender] 13:01:29:955 | ARNETWORK_Sender_ProcessBufferToSend:421 - [0x7f18082c8830] Will retry sending data of buffer 11
[ERROR] [1499454090.455337103]: [ARNETWORK_Sender] 13:01:30:455 | ARNETWORK_Sender_ProcessBufferToSend:405 - [0x7f18082c8830] Timeout waiting for ack in buffer 11
[ WARN] [1499454090.455429495]: [ARNETWORK_Sender] 13:01:30:455 | ARNETWORK_Sender_TimeOutCallback:655 - [0x7f18082c8830] Did timeout sending command : project = 0 | class = 4 | command = 2 - 0
[ERROR] [1499454090.955742539]: [ARNETWORK_Sender] 13:01:30:955 | ARNETWORK_Sender_ProcessBufferToSend:405 - [0x7f18082c8830] Timeout waiting for ack in buffer 11
[ERROR] [1499454090.955825303]: [ARNETWORK_Sender] 13:01:30:955 | ARNETWORK_Sender_ProcessBufferToSend:421 - [0x7f18082c8830] Will retry sending data of buffer 11
[ INFO] [1499454091.435707190]: [ARNETWORKAL_WifiNetwork] 13:01:31:435 | ARNETWORKAL_WifiNetwork_Receive:918 - [0x7f180824e380] connection lost (too long time without reception)
[ INFO] [1499454091.435944176]: [ARCONTROLLER_Device] 13:01:31:435 | ARCONTROLLER_Device_StartRun:4987 - Start failed or canceled.
[ERROR] [1499454091.456070531]: [ARNETWORK_Sender] 13:01:31:456 | ARNETWORK_Sender_ProcessBufferToSend:405 - [0x7f18082c8830] Timeout waiting for ack in buffer 11
[ERROR] [1499454091.456144213]: [ARNETWORK_Sender] 13:01:31:456 | ARNETWORK_Sender_ProcessBufferToSend:421 - [0x7f18082c8830] Will retry sending data of buffer 11
[ERROR] [1499454092.432987838]: [ARCONTROLLER_Device] 13:01:32:432 | ARCONTROLLER_Device_StartRun:4995 - Start fail error :start canceled
[ INFO] [1499454092.433334947]: [BebopSDK] 13:01:32:433 | Cleanup:326 - Bebop Cleanup()
[FATAL] [1499454092.433931782]: Init failed: Waiting for device failed: No error
[ INFO] [1499454092.434208426]: Bebop Nodelet Dstr: 0
[ INFO] [1499454092.434259030]: Killing Camera Thread ...
[ INFO] [1499454092.434307361]: Killing Aux Thread ...
[bebop/bebop_driver-2] process has died [pid 12250, exit code -11, cmd ~/bebop_ws/devel/lib/bebop_driver/bebop_driver_node __name:=bebop_driver __log:=~/.ros/log/ace1d68a-6346-11e7-b558-9c5c8e7a62dc/bebop-bebop_driver-2.log].
log file: ~/.ros/log/ace1d68a-6346-11e7-b558-9c5c8e7a62dc/bebop-bebop_driver-2*.log

Pinging the Bebop

The wifi is connected and seems to be rock solid.

me@computer-xubuntu:~$ ping 192.168.42.28
PING 192.168.42.28 (192.168.42.28) 56(84) bytes of data.
64 bytes from 192.168.42.28: icmp_seq=1 ttl=64 time=0.061 ms
64 bytes from 192.168.42.28: icmp_seq=2 ttl=64 time=0.045 ms
64 bytes from 192.168.42.28: icmp_seq=3 ttl=64 time=0.053 ms
64 bytes from 192.168.42.28: icmp_seq=4 ttl=64 time=0.055 ms
64 bytes from 192.168.42.28: icmp_seq=5 ttl=64 time=0.057 ms
64 bytes from 192.168.42.28: icmp_seq=6 ttl=64 time=0.053 ms
64 bytes from 192.168.42.28: icmp_seq=7 ttl=64 time=0.045 ms
64 bytes from 192.168.42.28: icmp_seq=8 ttl=64 time=0.047 ms
64 bytes from 192.168.42.28: icmp_seq=9 ttl=64 time=0.041 ms
64 bytes from 192.168.42.28: icmp_seq=10 ttl=64 time=0.041 ms
64 bytes from 192.168.42.28: icmp_seq=11 ttl=64 time=0.039 ms
64 bytes from 192.168.42.28: icmp_seq=12 ttl=64 time=0.042 ms
64 bytes from 192.168.42.28: icmp_seq=13 ttl=64 time=0.039 ms
64 bytes from 192.168.42.28: icmp_seq=14 ttl=64 time=0.044 ms
^C
--- 192.168.42.28 ping statistics ---
14 packets transmitted, 14 received, 0% packet loss, time 12998ms
rtt min/avg/max/mdev = 0.039/0.047/0.061/0.008 ms
adpon commented 7 years ago

I have this exact problem as well. I'm using Ubuntu 16.04, no virtual machine as well. Bebop 2 software version 4.0.6

thomas-bamford commented 7 years ago

Hello, Does this problem persist when the IP address is set to the default value 192.168.42.1? Looking at the terminal output you are pinging a different IP than you have set in the parameters of the launch file (/bebop/bebop_driver/bebop_ip: 192.168.42.1).

ghost commented 7 years ago

Thank you for helping me out here.

My bad, i3status gives the Bebop WIFI connection as 192.168.42.28.

Pinging the default 192.168.42.1 gives:

me@computer-xubuntu:~$ ping 192.168.42.1
PING 192.168.42.1 (192.168.42.1) 56(84) bytes of data.
64 bytes from 192.168.42.1: icmp_seq=1 ttl=64 time=1.80 ms
64 bytes from 192.168.42.1: icmp_seq=2 ttl=64 time=3.68 ms
64 bytes from 192.168.42.1: icmp_seq=3 ttl=64 time=1.94 ms
64 bytes from 192.168.42.1: icmp_seq=4 ttl=64 time=2.17 ms
64 bytes from 192.168.42.1: icmp_seq=5 ttl=64 time=1.75 ms
64 bytes from 192.168.42.1: icmp_seq=6 ttl=64 time=1.77 ms
64 bytes from 192.168.42.1: icmp_seq=7 ttl=64 time=4.61 ms
64 bytes from 192.168.42.1: icmp_seq=8 ttl=64 time=1.97 ms
64 bytes from 192.168.42.1: icmp_seq=9 ttl=64 time=13.0 ms
64 bytes from 192.168.42.1: icmp_seq=10 ttl=64 time=2.17 ms
^C
--- 192.168.42.1 ping statistics ---
10 packets transmitted, 10 received, 0% packet loss, time 9013ms
rtt min/avg/max/mdev = 1.757/3.497/13.077/3.319 ms

This also seems like a reasonable connection.

After pressing the Bebop's power button four times, I can telnet into 192.168.42.1 but not 192.168.42.28, so I believe the drone is on the former.

thomas-bamford commented 7 years ago

You're welcome. Does i3status provide you with the IP of your computer on the Bebop's network? I am not familiar with this software. The default network of the Bebop is 192.168.42.1.

Some ideas for the disconnecting issue:

Please let me know how this goes, I will try to help as best I can.

ghost commented 7 years ago

i3status is a Linux statusbar that displays some useful information, including internet connection. I wouldn't trust it too much though.

We also tried resetting the drone to get back to the older firmware. The issue happens less often now, but still regularly (>1/2 of attempts).

More detailed connection information:

General

Interface:    802.11 WiFi (wlp3s0)
Driver:       wl
Speed:        65 Mb/s
Security:     WPA/WPA2

IPv4

IP Address:              192.168.42.28
Broadcast Address:       192.168.42.255
Subnet Mask:             255.255.255.0
Default Route:           192.168.42.1

IPv6
IP Address:    fe80::b78d:eb37:be29:bccd/64

Note that the computer does not have IPv6

This and this forum posts refer to the same error message, but using only the Parrot SDK, and not the bebop_autonomy driver. Is it possible that this is an upstream issue?

Thank you again for all the help, it is very much appreciated.

thomas-bamford commented 7 years ago

Hi @Adam-JW-Casey, sorry for the delayed reply, thank you for your patience. Thanks for trying out my suggestions, its unfortunate that they haven't resulted in a solution. It is possible this is an upstream issue since the ARNETWORK_Sender errors are raised by the SDK.

geforcexfx commented 5 years ago

Hi. is this problem fixed? I am having the same error when trying to connect to bebop 2. If yes, can you please show me how? Thanks