LowPowerLab Forum

Hardware support => Moteino => Topic started by: englund on September 23, 2013, 06:19:35 AM

Title: Increasingly long time between acks when using sendWithRetry [SOLVED]
Post by: englund on September 23, 2013, 06:19:35 AM
Hi, I'm having problems with the sendWithRetry method, it seems to take longer and longer before it gets an ACK until it fails completely (although the data is received just fine). Detailed description follows.

I'm running the WirelessProgramming examples on two Moteino R3:s sitting 1m apart on the same desk.
The gateway (https://github.com/LowPowerLab/RFM69/blob/master/Examples/WirelessProgramming_gateway/WirelessProgramming_gateway.ino) is almost unmodified, I only changed TARGET_ID to 11, FREQUENCY to 868 and ACK_TIME to 500.
The node (https://github.com/LowPowerLab/RFM69/blob/master/Examples/WirelessProgramming_node/WirelessProgramming_node.ino) has the same modifications as the gateway plus the addition of sending data periodically:

////////////////////////////////////////////////////////////////////////////////////////////
  // Real sketch code here, let's blink the onboard LED every 0.5sec
  if ((int)(millis()/3000) > lastPeriod)
  {
    lastPeriod++;
    pinMode(9, OUTPUT);
    digitalWrite(9, lastPeriod%2);

    byte temperature =  radio.readTemperature(-1);
    sprintf(payload, "radio %d %lu\n", temperature, millis());
    sendSize = strlen(payload);
    Serial.print("Sending[");
    Serial.print(sendSize);
    Serial.print("]: ");
    for(byte i = 0; i < sendSize; i++){
      Serial.print((char)payload[i]);
    }
    Serial.println();

    if (radio.sendWithRetry(GATEWAYID, payload, sendSize, 5, ACK_TIME)){
    Serial.print(" ok!");
    }
    else {
    Serial.print(" nothing...");
    }
    Serial.println();
  }
  ////////////////////////////////////////////////////////////////////////////////////////////


The serial output on the node (with the debug prints in sendWithRetry enabled) is:

****Sending[16]: radio 29 117000

~ms:
4 ok!
****Sending[16]: radio 29 120000

~ms:
22 ok!
****Sending[16]: radio 29 123000

~ms:
38 ok!
****Sending[16]: radio 29 126000

~ms:
55 ok!
****Sending[16]: radio 29 129000

~ms:
72 ok!
****Sending[16]: radio 29 132000

~ms:
89 ok!
****Sending[16]: radio 29 135000

~ms:
105 ok!
****Sending[16]: radio 29 138000

~ms:
123 ok!
****Sending[16]: radio 29 141000

~ms:
140 ok!
****Sending[16]: radio 29 144000

~ms:
157 ok!
****Sending[16]: radio 29 147000

~ms:
173 ok!
****Sending[16]: radio 29 150000

~ms:
191 ok!
****Sending[16]: radio 29 153000

~ms:
206 ok!
****Sending[16]: radio 29 156000

~ms:
224 ok!
****Sending[16]: radio 29 159000

~ms:
242 ok!
****Sending[16]: radio 29 162000

RETRY#
1
RETRY#
2
RETRY#
3
RETRY#
4
RETRY#
5
RETRY#
6
nothing...
****Sending[16]: radio 29 165000

RETRY#
1
~ms:
84 ok!
****Sending[16]: radio 29 168000

RETRY#
1
~ms:
99 ok!
****Sending[16]: radio 29 171000

RETRY#
1
~ms:
117 ok!
****Sending[16]: radio 29 174000

RETRY#
1
~ms:
133 ok!
****Sending[16]: radio 29 177000

RETRY#
1
~ms:
151 ok!
****Sending[16]: radio 29 180000

RETRY#
1
~ms:
167 ok!
****Sending[16]: radio 29 183000

RETRY#
1
~ms:
184 ok!
****Sending[16]: radio 29 186000

RETRY#
1
~ms:
202 ok!
****Sending[16]: radio 29 189000

RETRY#
1
~ms:
218 ok!
****Sending[16]: radio 29 192000

RETRY#
1
~ms:
235 ok!
****Sending[16]: radio 29 195000

RETRY#
1
RETRY#
2
~ms:
3 ok!
****Sending[16]: radio 29 198000

RETRY#
1
RETRY#
2
~ms:
20 ok!
****Sending[16]: radio 29 201000

RETRY#
1
RETRY#
2
~ms:
36 ok!
****Sending[16]: radio 29 204000

RETRY#
1
RETRY#
2
~ms:
54 ok!


And the output on the gateway is:


radio 29 117000
                - ACK sent
radio 29 120000
                - ACK sent
radio 29 123000
                - ACK sent
radio 29 126000
                - ACK sent
radio 29 129000
                - ACK sent
radio 29 132000
                - ACK sent
radio 29 135000
                - ACK sent
radio 29 138000
                - ACK sent
radio 29 141000
                - ACK sent
radio 29 144000
                - ACK sent
radio 29 147000
                - ACK sent
radio 29 150000
                - ACK sent
radio 29 153000
                - ACK sent
radio 29 156000
                - ACK sent
radio 29 159000
                - ACK sent
radio 29 162000
                - ACK sent
radio 29 165000
                - ACK sent
radio 29 168000
                - ACK sent
radio 29 171000
                - ACK sent
radio 29 174000
                - ACK sent
radio 29 177000
                - ACK sent
radio 29 180000
                - ACK sent
radio 29 183000
                - ACK sent
radio 29 186000
                - ACK sent
radio 29 189000
                - ACK sent
radio 29 192000
                - ACK sent
radio 29 195000
                - ACK sent
radio 29 198000
                - ACK sent
radio 29 201000
                - ACK sent
radio 29 204000
                - ACK sent


So everything seems to be received and acked if you look at the gateway output but the node is just adding up the time it takes for the ack, in the end of the example above it's at 500 + 500 + 54 ms (2 retries).
And when it sends "radio 29 162000" it never gets an ack but the gateway receives it and sends an ack.
What is going on here??

Cheers,
Lars
Title: Re: Increasingly long time between acks when using sendWithRetry
Post by: englund on September 23, 2013, 07:13:02 AM
Also, although not important, where do the "****" that get printed before "Sending" come from in the node serial output?
Title: Re: Increasingly long time between acks when using sendWithRetry
Post by: joao_ladeira on September 23, 2013, 07:17:38 AM
Hi,

The ***** comes when you call the read temperature if im not mistaken   ;) :

RFM69.cpp
byte RFM69::readTemperature(byte calFactor) //returns centigrade
{
  setMode(RF69_MODE_STANDBY);
  writeReg(REG_TEMP1, RF_TEMP1_MEAS_START);
  while ((readReg(REG_TEMP1) & RF_TEMP1_MEAS_RUNNING)) Serial.print('*');
  return ~readReg(REG_TEMP2) + COURSE_TEMP_COEF + calFactor; //'complement'corrects the slope, rising temp = rising val
}

Best regards,
João Ladeira
Title: Re: Increasingly long time between acks when using sendWithRetry
Post by: englund on September 23, 2013, 07:25:08 AM
Ah, there it was, thanks! :)

Now I'm hoping Felix will work his usual magic and solve the ACK-problem!
Title: Re: Increasingly long time between acks when using sendWithRetry
Post by: joao_ladeira on September 23, 2013, 07:38:21 AM
Np :).

Im at work now, but if for some reason i get into that problem i will let you know, but since i got mine to work (since last friday :) ) i dint encounter that problem you are reporting.
If you try the node and gateway examples (not the wireless programing ones) do you get that effect as well?

Best regards,
JL.
Title: Re: Increasingly long time between acks when using sendWithRetry
Post by: Felix on September 23, 2013, 09:41:28 AM
I'd have to try the code myself to see for sure what's going on, can't do it right now, but hopefully later today.
However at first glance, it seems you might be using an older version of the library, which was printing the "~ms ..." in the sendWithRetry() function. That was only there for early lib development debugging and was left in as an artifact. Or maybe you went in and uncommented that yourself .. ?
Title: Re: Increasingly long time between acks when using sendWithRetry
Post by: englund on September 23, 2013, 01:37:27 PM
I went in and uncommented that myself to try and figure out what was going on but to no awail :(
I hope you find something.. I'll try the regular node and gateway in an hour as JL suggested.
Title: Re: Increasingly long time between acks when using sendWithRetry
Post by: englund on September 23, 2013, 04:34:32 PM
So the regular gateway and node example works just fine.. super weird. I can't see any functional difference in the code.
Title: Re: Increasingly long time between acks when using sendWithRetry
Post by: englund on September 23, 2013, 05:09:11 PM
Ok, I think I found the problem. This line:


byte inputLen = readSerialLine(input);


in WirelessProgramming_gateway blocks for 1000ms every time and thus makes the client wait for an ACK until it's done. Since I was sending every 3000ms I got a slowly increasing ACK-delay due to other things in the code on the node and gateway taking slightly different time.

It says in the feature list that the RFM69 library is interrupt driven but I can't find any information on how to use the interrupt driven approach instead of the radio.receiveDone polling. Is it possible to call an interrupt function when a packet has been received to immediately send the ACK?
Title: Re: Increasingly long time between acks when using sendWithRetry
Post by: john k2ox on September 23, 2013, 05:49:05 PM
the radio sets an output when it receives a packet. Felix's lib sets the AtMega to interupt when that pin changes. He grabs the data and gives it to you. Part of his receive routine.
Title: Re: Increasingly long time between acks when using sendWithRetry
Post by: Felix on September 23, 2013, 07:23:48 PM
It's interrupt driven, but the lib makes it easy for you since it grabs the data as soon as it's available and then allows you to collect it whenever you ask for it. Hence the receiveDone() call which abstracts all those details. I think that's more preferable than you dealing with interrupt routines.

The gateway example blocks for 1000ms, which can be reduced to 100ms or even less. So yes that can easily explain the behavior you're seeing. It's because the gateway example is not focused on receiving data, but rather listening for a wireless-programming command from the host.
I do realize all the code I provide does not fit all the scenarios and has shortcomings ... but it's there to give a decent head start :)
Title: Re: Increasingly long time between acks when using sendWithRetry
Post by: englund on September 24, 2013, 03:19:32 PM
I made a fork & topic branch (https://github.com/larsenglund/RFM69/compare/radiocallback (https://github.com/larsenglund/RFM69/compare/radiocallback)) that adds callback functionality to the RFM69 library. It seems to be working fine here. If you want to merge it into the master I can create a pull request?
Title: Re: Increasingly long time between acks when using sendWithRetry
Post by: Felix on September 24, 2013, 07:43:33 PM
Thanks for the effort. However I'm trying to think who will use a callback call from an interrupt routine. It's so easy to screw it up it's going to create more problems than solve. People won't know how to properly use it. People barely know how to use the library as easy as it is to use now. Let alone using interrupts and function pointers properly...

Also you cannot use timing functions in an interrupt, they rely on interrupts.
And starting other transmissions from the interrupt is another problem. You will generate interrupts from within the interrupt. Big no no there.
Interrupts have to be as short as possible and not generate other interrupts, especially the same interrupt.
Hope this makes sense...
Title: Re: Increasingly long time between acks when using sendWithRetry
Post by: englund on September 25, 2013, 04:35:06 AM
Ah, I see, I did think it was too easy :)
But when using the polled approach, what happens if we during the 100ms delay in the gateway receive 2 transmissions? Or even worse, if we during each 100ms delay receive 2 transmissions. Either the gateway or nodes packet queues (if there are any queues) will fill up since we only read one packet between every 100ms delay. I guess we will start losing packets?

Was I just lucky that my callback approach works for me? Will it break down if I spend to much time in the callback or if I send anything other than the ACK and ping? Is there a safe (and not overly complex) way to implement a callback approach?
Title: Re: Increasingly long time between acks when using sendWithRetry
Post by: Felix on September 25, 2013, 08:12:44 AM
You have to let the interrupt finish as soon as possible if you want to avoid losing packets, and perhaps implement a queue if you want to avoid loosing packets. But even so you still have to poll at some point.
That's why I never implemented a queue in the library because it didn't make sense. It's up to the user to make sure they are picking up all the packets that are received.