Arduino bug hunts.

my local environment is a bit of a mess. but here's some java code that is sure to blow up and give you issues talking to an arduino runing mrlcomm v.29

String port = "COM31";
Arduino ard = (Arduino)Runtime.createAndStart("ard", "Arduino");
ard.connect(port);
for (int i = 0 ; i < 10000; i++) {
  ard.sendMsg(ArduinoMsgCodec.GET_VERSION);
}
System.out.println("Done..");

Comment viewing options

Select your preferred way to display the comments and click "Save settings" to activate your changes.
GroG's picture

WHOOOHOO ! I get errors when

WHOOOHOO !

I get errors when I use your script 
currently using Windows 7 64 with Arduino IDE 1.0.5 and Mega

19:59:35.882 [COM9.portListener 1] INFO  class org.myrobotlab.service.Arduino - PUBLISH_VERSION 29
19:59:35.882 [COM9.portListener 1] INFO  c.myrobotlab.framework.Status - publishVersion 29
19:59:35.882 [COM9.portListener 1] ERROR c.myrobotlab.framework.Service - arduino error MRL->Arduino rx 248 type 1
19:59:35.882 [COM9.portListener 1] ERROR c.myrobotlab.framework.Service - arduino error MRL->Arduino rx 249 type 1
19:59:35.886 [COM9.portListener 1] INFO  class org.myrobotlab.service.Arduino - PUBLISH_VERSION 29
19:59:35.886 [COM9.portListener 1] INFO  c.myrobotlab.framework.Status - publishVersion 29
19:59:35.886 [COM9.portListener 1] ERROR c.myrobotlab.framework.Service - arduino error MRL->Arduino rx 250 type 1
19:59:35.886 [COM9.portListener 1] ERROR c.myrobotlab.framework.Service - arduino error MRL->Arduino rx 251 type 1
19:59:35.886 [COM9.portListener 1] ERROR c.myrobotlab.framework.Service - arduino error MRL->Arduino rx 252 type 1
19:59:35.886 [COM9.portListener 1] ERROR c.myrobotlab.framework.Service - arduino error MRL->Arduino rx 253 type 1
19:59:35.886 [COM9.portListener 1] ERROR c.myrobotlab.framework.Service - arduino error MRL->Arduino rx 254 type 2
19:59:35.890 [COM9.portListener 1] INFO  class org.myrobotlab.service.Arduino - PUBLISH_VERSION 29
 
Heh, with my loop I got no errors .. cuz the logging takes so long 
 
			Arduino arduino = (Arduino) Runtime.start("arduino", "Arduino");
			arduino.connect("COM9");
			for (int i = 0; i < 10000; ++i){
				arduino.sendMsg(ArduinoMsgCodec.GET_VERSION);
				log.info("{}", i);
			}
I'd have to check, but I think the  errors are messed up messages from the Arduino side recv.
Which to me makes sense...
The driver and 'uart' like hardware have some capacity for buffering, but of course there is a limit 
We could buffer more .. but there is a limit ..
There also is a limit in how much latency you want to support.
 
So at the moment I see a tight loop with a thread which is pounding the serial port, it hammer's it so hard it uses up the capacity of the buffering pretty quickly, because the hardware is only sending at 57 Kbps
 

NEWS FLASH

Uh .. now that I got the errors I can not 'un-get' them 
I've been infected !

I backed out all my changes, but now I get errors all the time, curious...
The 'change' point is when I commented out the logging - after that this was the first time I was able to get errors, and now they won't stopp even when I uncomment logging in the loop
 
Here is a snippet when my Arduino was worky :
You can see the main thread logging interleved with the listener thread for the Arduino
 
 
18:46:19.330 [main] INFO class org.myrobotlab.service.Arduino - 9994
18:46:19.335 [COM18.portListener 1] INFO class org.myrobotlab.service.Arduino - PUBLISH_VERSION 29
18:46:19.335 [COM18.portListener 1] INFO c.myrobotlab.framework.Status - publishVersion 29
18:46:19.337 [main] INFO class org.myrobotlab.service.Arduino - 9995
18:46:19.343 [COM18.portListener 1] INFO class org.myrobotlab.service.Arduino - PUBLISH_VERSION 29
18:46:19.343 [COM18.portListener 1] INFO c.myrobotlab.framework.Status - publishVersion 29
18:46:19.345 [main] INFO class org.myrobotlab.service.Arduino - 9996
18:46:19.352 [main] INFO class org.myrobotlab.service.Arduino - 9997
18:46:19.354 [COM18.portListener 1] INFO class org.myrobotlab.service.Arduino - PUBLISH_VERSION 29
18:46:19.354 [COM18.portListener 1] INFO c.myrobotlab.framework.Status - publishVersion 29
18:46:19.357 [COM18.portListener 1] INFO class org.myrobotlab.service.Arduino - PUBLISH_VERSION 29
18:46:19.358 [COM18.portListener 1] INFO c.myrobotlab.framework.Status - publishVersion 29
18:46:19.358 [main] INFO class org.myrobotlab.service.Arduino - 9998
18:46:19.363 [COM18.portListener 1] INFO class org.myrobotlab.service.Arduino - PUBLISH_VERSION 29
18:46:19.363 [COM18.portListener 1] INFO c.myrobotlab.framework.Status - publishVersion 29
18:46:19.366 [main] INFO class org.myrobotlab.service.Arduino - 9999
18:46:19.366 [main] INFO class org.myrobotlab.service.Arduino - here
18:46:19.366 [COM18.portListener 1] INFO class org.myrobotlab.service.Arduino - PUBLISH_VERSION 29
18:46:19.366 [COM18.portListener 1] INFO c.myrobotlab.framework.Status - publishVersion 29
 
I still kick it around some ....
 
GroG's picture

I did 4 runs at 10K

I did 4 runs at 10K getVersion messages
Here are the results
 
time 6082 ms - arduino error MRL->Arduino rx 3902 type 1
time 6432 ms - arduino error MRL->Arduino rx 3447 type 2
time 6818 ms - arduino error MRL->Arduino rx 4140 type 1
time 8164 ms - arduino error MRL->Arduino rx 1631 type 1
 
And now a little math...
 
10K Messages in 6.5 seconds
 
1 Message = 3 bytes for getVersion the 3 bytes are MAGIC_NUMBER + SIZE + METHOD_NUMBER
 
Each byte is 8 bits So...
 
10K X 3 X 8 = 240K per 6.5 seconds = 37Kbps (ish) - with lots of errors...
 
This is not "great" speed - but I've done other testing before and found the "real" line speed of Arduino is not really 57600Kbps,
but something more like 47K(ish) tops..  I always figured its like Miles Per Gallon ratings on cars, advertised as more, but usually less..
 
Now I could not stop the errors since I've begun getting them, until I do this
Thread.sleep(1); inside of sendMsg before the writes..
1 ms sleep ?!?  Yeah, its pretty silly because it will never "just" be 1 ms ..
Our CPUs and Java and all the software in-between will spend more time context switching between threads than the actual sleep
 
Anyway - the results are without error but nearly twice the time..
10K Messages in 11.5 seconds with 0 errors
 
 
Ahahaha with a Thread.sleep(10)  10 ms
Results are - 
10356 ms - 0 errors
10688 ms - 0 errors 
11105 ms - 0 errors
11105 ms - 0 error
 
 
Do you want speed or without errors ?  I'd preferr slower error free communication over very fast garbage..
 
But maybe we should look at the "loop"  .. who would do a silly loop?  How is Markus's script sending a barrage of commands which are equivalent to a tight loop ?
GroG's picture

Some interesting links (and

Some interesting links (and possible experiments)

http://forum.arduino.cc/index.php?topic=49560.0
 
http://arduino.stackexchange.com/questions/296/how-high-of-a-baud-rate-can-i-go-without-errors
calamity's picture

The sources of error

Hi Greg

The error are caused because the arduino is doing too much things to be able to read the serial input

setting the baudrate to 38400 have improve things for me, but lowering it to 19200 get worse

so slowering the data input to the arduino help... but arduino can support much more than 38400.

So for me it's because the arduino do not spend enough time to read the serial input, the main loop of MRLComm takes too much time to run, and by the time it came back to read more data the input buffer of the arduino overflow and lose data. More servo and pin are connected, quicker it overflow so that's why mega script have more trouble to run

I have try to modify the main loop so it updates servo and pins to run every two loops, but keep processing the messages every loop... and the error all disapear

So the solution to get rid the error is to have the arduino have more time to read serial, either by cutting time on the main loop execution or making it read more message from MRL before updating the servos/pins

 

Christian

edit: I have run my inMoov script with my modified MRLComm to update servo every two loops and got no error initializing it, but on a mega with nothing plug in it... I will try later today with my full inMoov

kwatters's picture

get yer motor running

So as it turns out.. throttling the messages into the arduino serial port can avoid these errors.  we've added a small delay after each sendMsg call to make sure the arduino has a chance to process the mrl message.  That being said, this isn't a 100% fix.  Reality is, we shouldn't be writing to the arduino if it's not able to accept new data on it's serial port.  It's a fairly small uart buffer  (I think only 64 bytes)  ...  

So... we have something that is mostly worky now..  but i suspect that there might be situations where the arduino won't be able to keep up with the data that MRL is sending...  

We have 1 courses to take to make this "better'.

1. make the arduino code "faster"  .. in that it can handle data quicker.  This is always a good option, but no matter how fast the arduino code is, it's relatively certain that a computer is going to be faster and as a result, we'll still be able to overrun the input buffer on the arduino.

2. make sure we are aware of the buffer on the arduino.  Back in the day of modems this was called "flow control"...  It required checking various signals on the serial port to know that the device hookedd up to the serial port was ready to accept new data.  I don't know how good the arduino support for this stuff is, but in theory we could monitor the "CTS"  (clear to send) and "RTS" (ready to send) line  on the serial port connected to the arduino  to ensure we're safe to write each byte...   I'm just not sure that those pins will be driven properly by the uart on the arduino.. so testing will tell..

 

anyway. minor victory for stability..  unfortunately, harry suffered some injuries in the testing of this... no worries. we have the technology, we can put him back together.  (only a broken finger.. and 2 broken parts in the neck.. yeah. he broke his neck.. but ... it....  'tis but a scratch!)   ... it's mearly a flesh wound :)

calamity's picture

in the MRLComm main loop,the

in the MRLComm main loop,the servo sweeping part seem to take forever to do, slowing down a lot the main loop, making the arduino unable to process quickly the serial buffer

I've got the idea to slow down the update of the servo position or even stop it if it have more important things to do

so at the begining of the main loop, I check the serial buffer, if it's almost empty, it run the sweep servo part every 1ms, if bytes begin to add up in the buffer, it does it every 10ms, and if the buffer is almost full, it stop sweeping the servo.

I also increase the buffer size to have a better control of the flow.

To test this I have attach up to 40 servo, ask the arduino to sweep them and spam 10k getVersion, and I don't seem to get any error report, but things are getting very slow, but seem to stay responsive

here my test script

from datetime import datetime
from time import sleep
arduino = Runtime.createAndStart("arduino","Arduino")
arduino.connect("COM15")
arduino.setLoadTimingEnabled(True)
servo=[]
 
for x in range(0,40):
  servo.append(Runtime.createAndStart("servo"+str(x),"Servo"));
  servo[-1].attach("arduino",2+x)
  servo[-1].sweep()
 
 
print(datetime.now().time())
for x in range (0,10000):
  arduino.sendMsg(2)
  #sleep(0.001)
print(datetime.now().time())
 
for ser in servo:
  ser.stop()
 
arduino.setLoadTimingEnabled(False)
 
 
http://beliweb.net:8088/test/MRLComm.ino.Mod2.txt
working with 1263
IDE 1.6.8
Window 7