Open chrisspen opened 6 years ago
I am also facing the same issue on Ubuntu 16.04 w86 computers. It was working with 14.04 I think and curiously on ARM processors (Raspberry Pi, Orange Pi...), it is working even with Xenial.
But I have never tried to dig further.
Note that the TCP version of rosserial_server
works like a charm, so the issue seems to be on the serial part of Boost.asio...
Ah, yes, I should have mentioned I too am running this on an ARM platform (Raspberry Pi 3). This is package only supported on x86?
@chrisspen Ah, it's curious because for me, it works on ARM and not x86. But I don't think it is related to the architecture but more the OS configuration (like ModemManager using the serial port or bad timeouts...)
I am running x86 w/ arduino. I uncommented out a few debug lines of a typical run. I'm a bit unsure how the buffering works but seems to possibly copy too much from the hardware buffer... The following is a stack overflow response to the same error. The issue came down to the read call reading too much from the buffer and getting an eof error.
[ INFO] [1516111293.010958410]: Buffer read of 1 bytes, wi: 152, ri: 111
[ INFO] [1516111293.010994638]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.011039362]: Received body of length 1 for message on topic 0.
[ WARN] [1516111293.011075941]: Rejecting message on topicId=0, length=1 with bad checksum. chsum 32
[ INFO] [1516111293.011112510]: Buffer read of 1 bytes, wi: 152, ri: 112
[ INFO] [1516111293.011148731]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.011192363]: Buffer read of 1 bytes, wi: 152, ri: 113
[ INFO] [1516111293.011229265]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.011272711]: Buffer read of 1 bytes, wi: 152, ri: 114
[ INFO] [1516111293.011308953]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.011351627]: Buffer read of 1 bytes, wi: 152, ri: 115
[ INFO] [1516111293.011389740]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.011431944]: Buffer read of 1 bytes, wi: 152, ri: 116
[ INFO] [1516111293.011469334]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.011512205]: Buffer read of 1 bytes, wi: 152, ri: 117
[ INFO] [1516111293.011548490]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.011592675]: Buffer read of 1 bytes, wi: 152, ri: 118
[ INFO] [1516111293.011629049]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.011673835]: Buffer read of 1 bytes, wi: 152, ri: 119
[ INFO] [1516111293.011711536]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.011753832]: Buffer read of 1 bytes, wi: 152, ri: 120
[ INFO] [1516111293.011790295]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.011832560]: Buffer read of 1 bytes, wi: 152, ri: 121
[ INFO] [1516111293.011870064]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.011913258]: Buffer read of 1 bytes, wi: 152, ri: 122
[ INFO] [1516111293.011949154]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.011992171]: Buffer read of 1 bytes, wi: 152, ri: 123
[ INFO] [1516111293.012028955]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.012074729]: Buffer read of 1 bytes, wi: 152, ri: 124
[ INFO] [1516111293.012110962]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.012153556]: Buffer read of 1 bytes, wi: 152, ri: 125
[ INFO] [1516111293.012189814]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.012231846]: Buffer read of 1 bytes, wi: 152, ri: 126
[ INFO] [1516111293.012271607]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.012314265]: Buffer read of 1 bytes, wi: 152, ri: 127
[ INFO] [1516111293.012356388]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.012419548]: Buffer read of 1 bytes, wi: 152, ri: 128
[ INFO] [1516111293.012458686]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.012542219]: Buffer read of 1 bytes, wi: 152, ri: 129
[ INFO] [1516111293.012583491]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.012629047]: Buffer read of 1 bytes, wi: 152, ri: 130
[ INFO] [1516111293.012665459]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.012707975]: Buffer read of 1 bytes, wi: 152, ri: 131
[ INFO] [1516111293.012744122]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.012785498]: Buffer read of 1 bytes, wi: 152, ri: 132
[ INFO] [1516111293.012822697]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.012864450]: Buffer read of 1 bytes, wi: 152, ri: 133
[ INFO] [1516111293.012900537]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.012943790]: Buffer read of 1 bytes, wi: 152, ri: 134
[ INFO] [1516111293.012980186]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.013021727]: Buffer read of 1 bytes, wi: 152, ri: 135
[ INFO] [1516111293.013057837]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.013069235]: Buffer read of 1 bytes, wi: 152, ri: 136
[ INFO] [1516111293.013078747]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.013089962]: Buffer read of 1 bytes, wi: 152, ri: 137
[ INFO] [1516111293.013099474]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.013110992]: Buffer read of 1 bytes, wi: 152, ri: 138
[ INFO] [1516111293.013120449]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.013132020]: Buffer read of 1 bytes, wi: 152, ri: 139
[ INFO] [1516111293.013141462]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.013152682]: Buffer read of 1 bytes, wi: 152, ri: 140
[ INFO] [1516111293.013162236]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.013173153]: Buffer read of 1 bytes, wi: 152, ri: 141
[ INFO] [1516111293.013182886]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.013194007]: Buffer read of 1 bytes, wi: 152, ri: 142
[ INFO] [1516111293.013203472]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.013214849]: Buffer read of 1 bytes, wi: 152, ri: 143
[ INFO] [1516111293.013224333]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.013235824]: Buffer read of 1 bytes, wi: 152, ri: 144
[ INFO] [1516111293.013245157]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.013258128]: Buffer read of 1 bytes, wi: 152, ri: 145
[ INFO] [1516111293.013267360]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.013278840]: Buffer read of 1 bytes, wi: 152, ri: 146
[ INFO] [1516111293.013288694]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.013300718]: Buffer read of 1 bytes, wi: 152, ri: 147
[ INFO] [1516111293.013310154]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.013321505]: Buffer read of 1 bytes, wi: 152, ri: 148
[ INFO] [1516111293.013331019]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.013342408]: Buffer read of 1 bytes, wi: 152, ri: 149
[ INFO] [1516111293.013351946]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.013362936]: Buffer read of 1 bytes, wi: 152, ri: 150
[ INFO] [1516111293.013372963]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.013384187]: Buffer read of 1 bytes, wi: 152, ri: 151
[ INFO] [1516111293.013393673]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111293.013405088]: Buffer read of 1 bytes, wi: 0, ri: 0
[ INFO] [1516111293.013415056]: Requesting transfer of at least 1 byte(s).
[ INFO] [1516111293.013429196]: Read operation failed with: asio.misc:2
[ WARN] [1516111293.013441269]: Socket asio error, closing socket: asio.misc:2
[ INFO] [1516111295.008675475]: Opened /dev/ttyACM0
[ INFO] [1516111295.008912046]: Buffer read of 1 bytes, wi: 0, ri: 0
[ INFO] [1516111295.008985822]: Requesting transfer of at least 1 byte(s).
[ INFO] [1516111295.009093437]: Successfully read 16 byte(s), now 16 available.
[ INFO] [1516111295.009156423]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111295.009220699]: Read Sync First
[ INFO] [1516111295.009276074]: Buffer read of 1 bytes, wi: 16, ri: 1
[ INFO] [1516111295.009332206]: Invoking success callback with buffer of requested size 1 byte(s).
[ INFO] [1516111295.009391129]: REad sync second
[ INFO] [1516111295.009443603]: Buffer read of 5 bytes, wi: 16, ri: 2
[ INFO] [1516111295.009499398]: Invoking success callback with buffer of requested size 5 byte(s).
[ INFO] [1516111295.009565900]: Received message header with length 8 and topic_id=10
[ INFO] [1516111295.009623169]: REading length+1
[ INFO] [1516111295.009686636]: Buffer read of 9 bytes, wi: 16, ri: 7
[ INFO] [1516111295.009745759]: Invoking success callback with buffer of requested size 9 byte(s).
[ INFO] [1516111295.009816883]: Received body of length 9 for message on topic 10.
[ INFO] [1516111295.009936103]: Buffer read of 1 bytes, wi: 0, ri: 0
[ INFO] [1516111295.010002827]: Requesting transfer of at least 1 byte(s).
[ INFO] [1516111295.010096986]: Read operation failed with: asio.misc:2
[ WARN] [1516111295.010161089]: Socket asio error, closing socket: asio.misc:2
Is this error just that in the Async buffer, the buffer is empty, and socket is asked to do an async_read to get at least 1 byte of data from the port as at
where transfer_bytes is 1 (this code isn't executed unless it is at least 1. However nothing has been sent from the serial device and the port is empty? Would this cause an error asio.misc.2
?.
To test I tried spamming the port from the device with log messages as well as putting a delay in the reading of sync bytes. This got rid of the error misc.2, but instead I had a buffer overflow :-)
So I think this is the issue (ie no data on the hardware) but unsure how to handle this gracefully.
From my side; It is not working on x64.
This problem is therefore occurring on all platforms.
Note that it sometimes works.
Also, it always works if I listen to the port via:
sudo interceptty -s 'ispeed 57600 ospeed 57600' -l /dev/ttyACM0 /dev/ttyDUMMY | interceptty-nicedump
And that I start the node on /dev/ttyDUMMY.
Might be...
Confirmed behaviour of working on 14.04/Indigo and failing on 16.04/Kinetic on ARMHF platform.
Reconnecting the MEGA and trying rosserial_server first gives this behaviour:
odroid@devbot_01:/$ roslaunch rosserial_server serial.launch --wait --screen -v
.
.
.
process[rosserial_server-1]: started with pid [32227]
process[rosserial_message_info-2]: started with pid [32228]
[ INFO] [1516320933.261930460]: rosserial_server session configured for /dev/ttyACM0 at 115200bps.
[ INFO] [1516320933.262822506]: Opened /dev/ttyACM0
[INFO] [1516320934.224919]: rosserial message_info_service node
[ INFO] [1516320935.264040260]: Opened /dev/ttyACM0
[ INFO] [1516320937.264956012]: Opened /dev/ttyACM0
[ INFO] [1516320939.265818722]: Opened /dev/ttyACM0
[ INFO] [1516320941.266647805]: Opened /dev/ttyACM0
[ INFO] [1516320943.267631514]: Opened /dev/ttyACM0
[ INFO] [1516320945.268525263]: Opened /dev/ttyACM0
^C[rosserial_message_info-2] killing on exit
[rosserial_server-1] killing on exit
[rosserial_server-1] escalating to SIGTERM
shutting down processing monitor...
... shutting down processing monitor complete
done
Rosserial_python works regardless of when the MEGA was connected and what has previously been tried.
odroid@devbot_01:/$ rosrun rosserial_python serial_node.py /dev/ttyACM0 _baud:=115200
[INFO] [1516321190.292869]: ROS Serial Python Node
[INFO] [1516321190.305997]: Connecting to /dev/ttyACM0 at 115200 baud
[INFO] [1516321192.432421]: Note: subscribe buffer size is 512 bytes
[INFO] [1516321192.433272]: Setup subscriber on toggle_led [std_msgs/Empty]
Rosserial_server produces different behaviour if it is executed after rosserial_python?
odroid@devbot_01:/$ roslaunch rosserial_server serial.launch --wait --screen -v
.
.
.
process[rosserial_server-1]: started with pid [32628]
process[rosserial_message_info-2]: started with pid [32629]
[ INFO] [1516321368.340855278]: rosserial_server session configured for /dev/ttyACM0 at 115200bps.
[ INFO] [1516321368.341705157]: Opened /dev/ttyACM0
[ WARN] [1516321368.341995825]: Socket asio error, closing socket: asio.misc:2
[INFO] [1516321369.305647]: rosserial message_info_service node
[ INFO] [1516321370.342624629]: Opened /dev/ttyACM0
[ WARN] [1516321370.342902297]: Socket asio error, closing socket: asio.misc:2
[ INFO] [1516321372.343443599]: Opened /dev/ttyACM0
[ WARN] [1516321372.343750767]: Socket asio error, closing socket: asio.misc:2
^C[rosserial_message_info-2] killing on exit
[rosserial_server-1] killing on exit
shutting down processing monitor...
... shutting down processing monitor complete
done
Hopefully there is a solution looming as we updated our fleet from rosserial_python to rosserial_server in 14.04 to fix stability issues.
I personally have it working on the ARMhf platform (Odroid XU4) under kinetics and failing often on x64
We possibly have a mixture of working and not-working XU3/XU4 systems running the 16.04/Kinetic combination. The outputs that I have shown previously were from a fresh install of 16.04/Kinetic performed yesterday. I will need to wait until Monday my time (Friday night here) to check if the research payloads are back from their field-trials to look at the working system(s).
*EDIT: I forgot to mention that the MEGA is running one of the bare-bone 'ros_lib' example programs; I will try with our full Arduino program when I get a chance.
Same ROS version, same rosserial version, same boost library version, different behaviours.
Mostly working on the odroid XU4 Kinetic Ubuntu 16.04; Version 0.7.7 of rosserial and sometimes failing.
odroid@odroid100:~$ rosversion rosserial_server
0.7.7
odroid@odroid100:~$ cat /usr/include/boost/version.hpp | grep "BOOST_LIB_VERSION"
// BOOST_LIB_VERSION must be defined to be the same as BOOST_VERSION
#define BOOST_LIB_VERSION "1_58
Mostly failing on the computer x64 Kinetic Ubuntu 16.04; Version 0.7.7 of rosserial and sometimes succeeding.
alexis@TheMagician:~$ rosversion rosserial_server
0.7.7
alexis@TheMagician:~$ cat /usr/include/boost/version.hpp | grep "BOOST_LIB_VERSION"
// BOOST_LIB_VERSION must be defined to be the same as BOOST_VERSION
#define BOOST_LIB_VERSION "1_58
@philboske Can you try with interceptty?
I installed this version: https://github.com/rjrpaz/interceptty
Using:
sudo interceptty -s 'ispeed 57600 ospeed 57600' -l /dev/ttyACM0 /dev/ttyDUMMY | interceptty-nicedump
And opening the port /dev/ttyDUMMY with the rosserial_server worked almost every time
If found this from a long time ago, but has the same error, and due to the read function returning with zero bytes which was due to a buffer size not being initalise. Not exactly the issue in our case. I reimplemented the socket read with the boost::asio::serial_port::read_some(). I get the same error in the same way,
ROS_INFO("mem length, %ld writeIndex %ld HeadRoom %ld", mem_.size(), write_index_, bytesHeadroom());
size_t bytes_read =0;
boost::system::error_code ec;
while (bytes_read<transfer_bytes){
int b = stream_.read_some(boost::asio::buffer(&mem_[write_index_], bytesHeadroom()), ec);
if (b == 0)
{
ROS_ERROR("Error");
break;
}
else{
bytes_read+=b;
write_index_+=b;
}
}
this->callback(ec, bytes_read);
/*boost::asio::async_read(stream_,
boost::asio::buffer(&mem_[write_index_], bytesHeadroom()),
boost::asio::transfer_at_least(transfer_bytes),
boost::bind(&AsyncReadBuffer::callback, this,
boost::asio::placeholders::error,
boost::asio::placeholders::bytes_transferred));*/
producing:
[ INFO] [1516362418.129118265]: Starting session. [ INFO] [1516362418.129210798]: mem length, 1023 writeIndex 0 HeadRoom 1023 [ INFO] [1516362418.129249626]: Successfully read 16 byte(s), now 31 available. [ INFO] [1516362418.129306963]: Buffer is empty, resetting indexes to the beginning. [ INFO] [1516362418.129336763]: mem length, 1023 writeIndex 0 HeadRoom 1023
[ WARN] [1516362418.129362581]: Socket asio error, closing socket: asio.misc:2
I did a reimplementation of the async_read, with no effect. This seems to be a boost::asio::error, quite deep in where they interact with hardware. I was using kernel 4.13 on an x86 machine (which needs at least 4.8 for all peripherals to work) I downgraded my kernel to 4.4.107 and this specific error goes away, and the message flow is much more consistent and no asio.misc2 errors. It seems boost 1.58 was build to interface with earlier kernels and theres been a change which has broken that. I suggest downgrading the kernel or upgrading boost
Edit actually, I just ran it back up under 4.13 and it is working fine too? I have no idea why but I can speculate that at the kernel/hardware level somthing has changed (probably from changing the kernel) which is allowing it to work.
Edit Now its not working fine after changing the baud rate.
@PeterQFR: Going by the output that you provided, the error seems to occur between:
And:
The callback that is bound to the async_read() call is stating that there are still bytes available, yet the callSuccessfulCallback() call is reporting that there are no bytes available.
According to the Boost documentation:
An error code of boost::asio::error::eof indicates that the connection was closed by the peer.
And this fits in with the behaviour that I posted earlier where it was failing to maintain a connection, even without raising a asio::misc::2 error (which is EOF). Note that I only received aiso::misc::2 errors after I had successfully connected previously with rosserial_python. The first attempt at connecting using rosserial_server would hang when issued with a SIGINT (i.e. Ctrl+C), finally being escallated to a SIGTERM unless I disconnected the MEGA.
Thats different to what I've found. Line 151 wouldn't get executed on error as that callback would return an error code. I also added:
else if (error == boost::asio::error::eof)
{
ROS_ERROR("EOF Error");
}
in that same callback, and I could confirm that it is returning the error from the boost::asio::async_read(). That why I think it is a hardware configuration error from somewhere in the io_service or at the kernel, as that is where that error code comes from.
Hmmm, okay, my apologies.
@AlexisTM: Works fine with 'interceptty' redirecting to /dev/ttyDUMMY.
@philboske I could be completely wrong though.. I've used boost asio with no problems modifying from the mavros implementation, but have not been able to get serial_server to work. The main difference I can see is that in the mavros implementation is that the io_service is being run in a separate thread. I'll try that here and see if it improves things.
Thinking back though I've not really used the arduino USB TTYACM0 port but direct serial connection either through ttyS0 or a direct serial port on an ARM chip. The arduino USB to Serial chip is not a full hardware implementation like the FTDI chip but a firmware flashed micro which has caused issues in the past.
Another thing I notices is that the asio.misc2 error occurs if you use @AlexisTM interceptTTY and shut it down mid session which points to an interface issue. Another alternate method would be to use the terminos command which is what we use at work fairly successfully.
I've run into this issue now, too. Are there any updates regarding this, for instance someone fixing things in a fork and just forgetting to post here? ;)
I upgraded all ROS packages and the kernel. It never happened again.
If I remember well, this is due to a Boost version compatibility issue with a certain kernel.
It is the same for me. I have recently tried again and I did not have this issue anymore.
That's interesting. I'm on 16.04 with latest kinetic packages from .debs and kernel 4.13.0-41-generic
and the problem persists.
Any solutions to this yet? I am also having the same problems...
I doubt that it received any attention after the numerous people reporting that a fresh install and update (colloquially 'the solution') seemingly fixed their problems.
I am fairly sure (this is testing my memory) that we implemented rosserial_python on our deployed fleet of teaching robots, and once they become stable, I don't touch them again. Our research fleet is another topic altogether, but we haven't had problems either way.
ok...apparently I just did a fresh install of rosserial server, and now it works fine.
Just had the same error message on multiple machines in multiple configurations (Ubuntu 16/18.04, kinetic vs melodic, different kernels, x86 and arm). Restarting the roscore fixed it for me.
[ 62%] Building CXX object rosserial/rosserial_server/CMakeFiles/rosserial_server_serial_node.dir/src/serial_node.cpp.o In file included from /usr/include/c++/5/cstdint:35:0, from /home/ubuntu/catkin_ws/src/rosserial/rosserial_server/include/rosserial_server/async_read_buffer.h:44, from /home/ubuntu/catkin_ws/src/rosserial/rosserial_server/include/rosserial_server/session.h:50, from /home/ubuntu/catkin_ws/src/rosserial/rosserial_server/include/rosserial_server/serial_session.h:43, from /home/ubuntu/catkin_ws/src/rosserial/rosserial_server/src/serial_node.cpp:40: /usr/include/c++/5/bits/c++0x_warning.h:32:2: error: #error This file requires compiler and library support for the ISO C++ 2011 standard. This support must be enabled with the -std=c++11 or -std=gnu++11 compiler options.
^
In file included from /home/ubuntu/catkin_ws/src/rosserial/rosserial_server/include/rosserial_server/session.h:50:0,
from /home/ubuntu/catkin_ws/src/rosserial/rosserial_server/include/rosserial_server/serial_session.h:43,
from /home/ubuntu/catkin_ws/src/rosserial/rosserial_server/src/serial_node.cpp:40:
/home/ubuntu/catkin_ws/src/rosserial/rosserial_server/include/rosserial_server/async_read_buffer.h:46:14: error: 'make_signed' in namespace 'std' does not name a template type
typedef std::make_signed
I sourced the rosserial driver _ws and do catkin_make it shows this error im using ubuntu16.04, ros kinetic this error caused due to rosserial_server lilbrary codes how to solve this but the rosserial works fine im able to communicate with arduino
From the looks of it, you need to enable C++11 for your project.
I'm trying to test the rosserial_server
serial_node
with an Arduino Mega by running:and it's immediately returning the error output:
To confirm the problem wasn't with the Arduino, I also tested it with the legacy rosserial_python
serial_node.py
:it works fine and shows the expected output:
I read that rosserial_server is experimental, but is there any reason why it shouldn't be able to connect to a basic Arduino Mega?