RFM69Pi ACK-Problem / mysterious NodeID change / Timing-Problem

ISSchuster · 25 July 2016 14:50

Now I have a few new problems. I tried activating ACK…

I use the RFM69Pi module and a TinyTX Sensor with this codes (TinyTX/TinyTX_DS18B20.ino at master · openenergymonitor/TinyTX · GitHub & TinyTX/TinyTX_DS18B20_noACK.ino at master · openenergymonitor/TinyTX · GitHub)

ACK does not work (perhaps it’s related to problem 2).
Without ACK i receive the correct NodeID (in this case myNodeID 17 is set in the code and i receive myNodeID 17). With ACK myNodeID 1 is set and I receive myNodeID 33?!?
(Even directly with a minicom connection to RFM69Pi I get the wrong myNodeID - same with the prebuild SD Card)
After changing myNodeID to 2 I receive myNodeID 34 and so on…
The time between two transmissions is 70 Seconds?!? But in both codes it should be 60 Seconds (+/- a few ms)…

Robert.Wall · 25 July 2016 15:24

The problem with node 1 & node 33 is JeeLib. The NodeID is only 5 bits wide, and is preceded by the ACK bit and the DST (DeSTination) bit.

If you go to JeeLabs and search for “RF12 packet format and design” and “Nodes, Addresses, and Interference”, you’ll find all the details of the design and use of the data packet that JeeLib uses.

pb66 · 25 July 2016 16:04

How old is your RFM69Pi ? are you sure it’s not a RFM12Pi with a rfm69 fitted ?

There was a fix made to the rfm2pi firmware for this issue back in Dec 2014.

As Robert says the issue is caused by the “ack bit” being in the same byte as the node id and as the node id is only the 5 lowest significance bits, setting ack adds 32 to the byte value but should be masked to not effect the “nodeid” in use. That is what the firmware fix did it correctly masks that byte so only the 5bits are read.

Looking at your sketch you have
~~delay(5); and Sleepy::loseSomeTime(60000); in your main loop and also tinytx.supplyV = readVcc(); which includes a delay(2); AND rfwrite(); which includes rf12_sendWait(2); so there is 69~~ 60 seconds of sleep time which doesn’t include any actual runtime,

ISSchuster · 25 July 2016 16:14

I ordered the RFM69Pi last week at http://shop.openenergymonitor.com/

Minicom says “[RF12demo.12]” - do I need a new firmware?

Delay() should be milliseconds (delay() - Arduino Reference) - or am I wrong?
If Delay(5) are 5 Seconds then it makes sense…

Robert.Wall · 25 July 2016 16:27

Sorry Paul, but I think Stefan is right. delay(n) is n milliseconds, and the parameter in sendWait is the state/mode to power down to, not a time (it waits for the send to finish), but it can also make the timer lose ticks, see The Dark Side of rf12_sendWait(2) | Archived Forum.

pb66 · 25 July 2016 16:31

My bad yes, I’m working in Bash right now and was thinking of sleep not delay ( I constantly mix up the 2) the point being it cannot be 60s because you have a single 60s delay and then some other delays and runtime.
This has come up before for the emonTx, you will need to lower the 60000 either manually to achieve the desired interval or by adding a loop timer and deduct the looptime from the 60000 before putting it to sleep.

Also read up on the “lose some time” as this watchdog based timer is not an accurate measure of time, especially if interrupted.

As far as I was aware the latest rfm69pi’s are shipped with the bugfix included (this hexfile) perhaps @glyn.hudson can shed some more light on why that might not be the case, either way it looks like you will need to update the firmware yes.

EDIT - I have just looked through the rfm2pi repo and cannot work out why the firmware might be wrong, this was tried and tested at the time but not many users use acks so we cannot rule out something may have changed, are you able to update the firmware?

ISSchuster · 25 July 2016 17:31

Yes - I updated the firmware. Had to use the pre-built SD Card - update does not work without emoncms because of missing files in /home/pi…

The NodeID-Problem is solved now - but ACK is still not working and there is a new problem… The temperature is wrong now - but only when using ACK…

emonhub.log without ACK

33 NEW FRAME : OK 17 84 11 39 12 (-35)
2016-07-25 17:24:12,248 DEBUG    RFM2Pi     33 Timestamp : 1469467452.25
2016-07-25 17:24:12,249 DEBUG    RFM2Pi     33 From Node : 17
2016-07-25 17:24:12,250 DEBUG    RFM2Pi     33    Values : [2900, 3111]
2016-07-25 17:24:12,251 DEBUG    RFM2Pi     33      RSSI : -35
2016-07-25 17:24:12,253 INFO     RFM2Pi     Publishing: emon/17/1 2900
2016-07-25 17:24:12,256 INFO     RFM2Pi     Publishing: emon/17/2 3111
2016-07-25 17:24:12,258 INFO     RFM2Pi     Publishing: emon/17/rssi -35
2016-07-25 17:24:12,260 INFO     RFM2Pi     Publishing: emonhub/rx/17/values 2900,3111
2016-07-25 17:24:12,263 INFO     RFM2Pi     Publishing: emonhub/rx/17/rssi -35
2016-07-25 17:24:12,266 DEBUG    RFM2Pi     33 adding frame to buffer => [1469467452, 17, 2900, 3111, -35]
2016-07-25 17:24:12,267 DEBUG    RFM2Pi     33 Sent to channel' : ToEmonCMS

emonhub.log with ACK (Temperature is always 8500 and ACK is not working - but the NodeID is correct...)
2016-07-25 17:26:48,653 DEBUG    RFM2Pi     35 NEW FRAME : OK 1 52 33 39 12 (-37)
2016-07-25 17:26:48,655 DEBUG    RFM2Pi     35 Timestamp : 1469467608.65
2016-07-25 17:26:48,656 DEBUG    RFM2Pi     35 From Node : 1
2016-07-25 17:26:48,657 DEBUG    RFM2Pi     35    Values : [8500, 3111]
2016-07-25 17:26:48,658 DEBUG    RFM2Pi     35      RSSI : -37
2016-07-25 17:26:48,660 INFO     RFM2Pi     Publishing: emon/1/1 8500
2016-07-25 17:26:48,662 INFO     RFM2Pi     Publishing: emon/1/2 3111
2016-07-25 17:26:48,664 INFO     RFM2Pi     Publishing: emon/1/rssi -37
2016-07-25 17:26:48,666 INFO     RFM2Pi     Publishing: emonhub/rx/1/values 8500,3111
2016-07-25 17:26:48,668 INFO     RFM2Pi     Publishing: emonhub/rx/1/rssi -37
2016-07-25 17:26:48,670 DEBUG    RFM2Pi     35 adding frame to buffer => [1469467608, 1, 8500, 3111, -37]
2016-07-25 17:26:48,672 DEBUG    RFM2Pi     35 Sent to channel' : ToEmonCMS
2016-07-25 17:26:48,774 DEBUG    RFM2Pi     confirmed sent packet size: -> ack
2016-07-25 17:26:49,178 DEBUG    RFM2Pi     36 NEW FRAME : OK 1 52 33 39 12 (-44)
2016-07-25 17:26:49,180 DEBUG    RFM2Pi     36 Timestamp : 1469467609.18
2016-07-25 17:26:49,182 DEBUG    RFM2Pi     36 From Node : 1
2016-07-25 17:26:49,194 DEBUG    RFM2Pi     36    Values : [8500, 3111]
2016-07-25 17:26:49,195 DEBUG    RFM2Pi     36      RSSI : -44
2016-07-25 17:26:49,197 INFO     RFM2Pi     Publishing: emon/1/1 8500
2016-07-25 17:26:49,199 INFO     RFM2Pi     Publishing: emon/1/2 3111
2016-07-25 17:26:49,201 INFO     RFM2Pi     Publishing: emon/1/rssi -44
2016-07-25 17:26:49,203 INFO     RFM2Pi     Publishing: emonhub/rx/1/values 8500,3111
2016-07-25 17:26:49,205 INFO     RFM2Pi     Publishing: emonhub/rx/1/rssi -44
2016-07-25 17:26:49,208 DEBUG    RFM2Pi     36 adding frame to buffer => [1469467609, 1, 8500, 3111, -44]
2016-07-25 17:26:49,209 DEBUG    RFM2Pi     36 Sent to channel' : ToEmonCMS
2016-07-25 17:26:49,312 DEBUG    RFM2Pi     confirmed sent packet size: -> ack
2016-07-25 17:26:54,976 DEBUG    RFM2Pi     37 NEW FRAME : OK 1 52 33 39 12 (-50)
2016-07-25 17:26:54,978 DEBUG    RFM2Pi     37 Timestamp : 1469467614.98
2016-07-25 17:26:54,979 DEBUG    RFM2Pi     37 From Node : 1
2016-07-25 17:26:54,981 DEBUG    RFM2Pi     37    Values : [8500, 3111]
2016-07-25 17:26:54,982 DEBUG    RFM2Pi     37      RSSI : -50
2016-07-25 17:26:54,983 INFO     RFM2Pi     Publishing: emon/1/1 8500
2016-07-25 17:26:54,986 INFO     RFM2Pi     Publishing: emon/1/2 3111
2016-07-25 17:26:54,988 INFO     RFM2Pi     Publishing: emon/1/rssi -50
2016-07-25 17:26:54,991 INFO     RFM2Pi     Publishing: emonhub/rx/1/values 8500,3111
2016-07-25 17:26:54,993 INFO     RFM2Pi     Publishing: emonhub/rx/1/rssi -50
2016-07-25 17:26:54,996 DEBUG    RFM2Pi     37 adding frame to buffer => [1469467614, 1, 8500, 3111, -50]
2016-07-25 17:26:54,997 DEBUG    RFM2Pi     37 Sent to channel' : ToEmonCMS
2016-07-25 17:26:55,100 DEBUG    RFM2Pi     confirmed sent packet size: -> ack

ISSchuster · 25 July 2016 19:12

Update:

Temperature is working now - there is a bug in TinyTX/TinyTX_DS18B20.ino at master · openenergymonitor/TinyTX · GitHub

Change line 64:
From: Sleepy::loseSomeTime(10); // Allow 10ms for the sensor to be ready
To: delay(5);

But ACK is still not working…

pb66 · 25 July 2016 21:20

What do you see in the serial console when a packet is received? can you show us some serial output?
Is collect mode set to 0c? 1c will not respond to ack requests, it’s used when there are multiple recievers on a network.
In the “current configuration” string printed at start up and each setting change it will show “c1” if set, but “c0” is not displayed when not set as it is the default.

ISSchuster · 25 July 2016 23:01

[RF12demo.12] E i5 g210 @ 433 MHz q1
OK 8 158 10 31 12 (-51)
→ ack
OK 8 158 10 31 12 (-43)
→ ack
OK 8 158 10 31 12 (-43)
→ ack
OK 8 158 10 31 12 (-42)
→ ack

I will try debugging the node / sensor in a few days - just ordered a Genuino… At the moment I only have a programmer - so I can’t debug the sensor…

glyn.hudson · 25 July 2016 23:01

Oh dear, your RFM6Pi should have the latest firmware but since minicom says [RF12demo.12] this tells us that you are on version 1.2. Latest is 1.3 (June 15):

https://github.com/openenergymonitor/RFM2Pi/blob/master/firmware/RFM69CW_RF_Demo_ATmega328/RFM69CW_RF12_Demo_ATmega328/RFM69CW_RF12_Demo_ATmega328.ino#L7

It looks like there has been a firmware mixup in the factory. Thanks for bringing this to my attention. I will contact the factory tomorrow to try and establish what’s gone wrong.

Yes, you can update the firmware yourself. However, since this is our fault I would be happy to perform the update for you and cover shipping cost if you wanted to send the unit back.

If you want to update yourself this can be done direct from a RaspberryPi:.

$ git clone https://github.com/openenergymonitor/RFM2Pi.git
$ cd RFM2Pi/firmware/RFM69CW_RF_Demo_ATmega328/
$ sudo service emonhub stop
$ avrdude -v -c arduino -p ATMEGA328P -P /dev/ttyAMA0 -b 38400 -U flash:w:RFM2Pi/firmware/RFM69CW_RF_Demo_ATmega328/V13_RFM69CW_RF12_Demo_ATmega328.cpp.hex
$ sudo service emonhub start

Here is the V1.3 compiled .hex

ISSchuster · 25 July 2016 23:38

OK - that’s it… I think it’s working now…

[RF12demo.13]

I already updated the firmware yesterday afternoon - but I used the documentation at RFM69Pi V3 - OpenEnergyMonitor Wiki

The updated command there seems to be outdated: avrdude -v -c arduino -p ATMEGA328P -P /dev/ttyAMA0 -b 38400 -U flash:w:RFM69CW_RF12_Demo_ATmega328.cpp.hex

First I used this command - and then I used the Hex-File posted by Paul. That solved the problem with the wrong myNodeID - but it was still an old firmware (and ACK did not work)…

Think you should update the documentation - and correct the TinyTX_DS18B20/TinyTX_DS18B20.ino file

Thanks to all of you.

I will test it again later today - but it seems to work now.

2016-07-25 23:34:16,601 DEBUG    RFM2Pi     7 NEW FRAME : OK 8 133 10 31 12 (-56)
2016-07-25 23:34:16,603 DEBUG    RFM2Pi     7 Timestamp : 1469489656.6
2016-07-25 23:34:16,604 DEBUG    RFM2Pi     7 From Node : 8
2016-07-25 23:34:16,605 DEBUG    RFM2Pi     7    Values : [2693, 3103]
2016-07-25 23:34:16,606 DEBUG    RFM2Pi     7      RSSI : -56
2016-07-25 23:34:16,608 INFO     RFM2Pi     Publishing: emon/8/1 2693
2016-07-25 23:34:16,611 INFO     RFM2Pi     Publishing: emon/8/2 3103
2016-07-25 23:34:16,614 INFO     RFM2Pi     Publishing: emon/8/rssi -56
2016-07-25 23:34:16,616 INFO     RFM2Pi     Publishing: emonhub/rx/8/values 2693,3103
2016-07-25 23:34:16,619 INFO     RFM2Pi     Publishing: emonhub/rx/8/rssi -56
2016-07-25 23:34:16,622 DEBUG    RFM2Pi     7 adding frame to buffer => [1469489656, 8, 2693, 3103, -56]
2016-07-25 23:34:16,623 DEBUG    RFM2Pi     7 Sent to channel' : ToEmonCMS
2016-07-25 23:34:16,725 DEBUG    RFM2Pi     confirmed sent packet size: -> ack
2016-07-25 23:35:32,298 DEBUG    RFM2Pi     8 NEW FRAME : OK 8 127 10 31 12 (-55)
2016-07-25 23:35:32,300 DEBUG    RFM2Pi     8 Timestamp : 1469489732.3
2016-07-25 23:35:32,302 DEBUG    RFM2Pi     8 From Node : 8
2016-07-25 23:35:32,303 DEBUG    RFM2Pi     8    Values : [2687, 3103]
2016-07-25 23:35:32,304 DEBUG    RFM2Pi     8      RSSI : -55
2016-07-25 23:35:32,305 INFO     RFM2Pi     Publishing: emon/8/1 2687
2016-07-25 23:35:32,307 INFO     RFM2Pi     Publishing: emon/8/2 3103
2016-07-25 23:35:32,309 INFO     RFM2Pi     Publishing: emon/8/rssi -55
2016-07-25 23:35:32,311 INFO     RFM2Pi     Publishing: emonhub/rx/8/values 2687,3103
2016-07-25 23:35:32,313 INFO     RFM2Pi     Publishing: emonhub/rx/8/rssi -55
2016-07-25 23:35:32,315 DEBUG    RFM2Pi     8 adding frame to buffer => [1469489732, 8, 2687, 3103, -55]
2016-07-25 23:35:32,316 DEBUG    RFM2Pi     8 Sent to channel' : ToEmonCMS
2016-07-25 23:35:32,418 DEBUG    RFM2Pi     confirmed sent packet size: -> ack
2016-07-25 23:36:42,197 DEBUG    RFM2Pi     9 NEW FRAME : OK 8 133 10 31 12 (-70)
2016-07-25 23:36:42,199 DEBUG    RFM2Pi     9 Timestamp : 1469489802.2
2016-07-25 23:36:42,200 DEBUG    RFM2Pi     9 From Node : 8
2016-07-25 23:36:42,204 DEBUG    RFM2Pi     9    Values : [2693, 3103]
2016-07-25 23:36:42,210 DEBUG    RFM2Pi     9      RSSI : -70
2016-07-25 23:36:42,211 INFO     RFM2Pi     Publishing: emon/8/1 2693
2016-07-25 23:36:42,213 INFO     RFM2Pi     Publishing: emon/8/2 3103
2016-07-25 23:36:42,216 INFO     RFM2Pi     Publishing: emon/8/rssi -70
2016-07-25 23:36:42,218 INFO     RFM2Pi     Publishing: emonhub/rx/8/values 2693,3103
2016-07-25 23:36:42,219 INFO     RFM2Pi     Publishing: emonhub/rx/8/rssi -70
2016-07-25 23:36:42,222 DEBUG    RFM2Pi     9 adding frame to buffer => [1469489802, 8, 2693, 3103, -70]
2016-07-25 23:36:42,223 DEBUG    RFM2Pi     9 Sent to channel' : ToEmonCMS
2016-07-25 23:36:42,325 DEBUG    RFM2Pi     confirmed sent packet size: -> ack

glyn.hudson · 25 July 2016 23:54

Nice work

I will update the documentaion.