FOTA flow in sleeping nodes - need two cycles?

[manutremo]

I've finally managed to get my RFM69 radios working almost 100% and am testing FOTA on my battery powered nodes.

These nodes sleep for 3h, wake up, do some processing, and then go back to sleep.

The summarized sketch is as follows:

void loop()
{
  if (!isFirmwareUpdateOngoing()) {

     < read sensors and do the processing>

    sleep(SLEEP_TIME_3h, true);
  }

When I upload a new fw to MYSController, the new fw is detected and the download appears to start for a few lines, but then the node goes to sleep and the update doesn't continue until the next wake-up cycle. This is the node log:

0 MCO:BGN:INIT NODE,CP=RPONA---,VER=2.2.0-rc.1
4 TSM:INIT
4 TSF:WUR:MS=0
8 TSM:INIT:TSP OK
10 TSF:SID:OK,ID=8
12 TSM:FPAR
12 TSM:FPAR:STATP=0
14 TSM:ID
16 TSM:ID:OK
18 TSM:UPL
24 TSF:MSG:SEND,8-8-0-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=OK:1
45 TSF:MSG:READ,0-0-8,s=255,c=3,t=25,pt=1,l=1,sg=0:1
49 TSF:MSG:PONG RECV,HP=1
53 TSM:UPL:OK
55 TSM:READY:ID=8,PAR=0,DIS=1
65 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=0,pt=6,l=10,sg=0,ft=0,st=OK:03000000400547620300
133 TSF:MSG:SEND,8-8-0-0,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=OK:0100
145 TSF:MSG:READ,0-0-8,s=255,c=3,t=15,pt=6,l=2,sg=0:0100
159 TSF:MSG:SEND,8-8-0-0,s=255,c=0,t=17,pt=0,l=10,sg=0,ft=0,st=OK:2.2.0-rc.1
225 TSF:MSG:SEND,8-8-0-0,s=255,c=3,t=6,pt=1,l=1,sg=0,ft=0,st=OK:0
258 TSF:MSG:READ,0-0-8,s=255,c=3,t=6,pt=0,l=1,sg=0:M
272 TSF:MSG:SEND,8-8-0-0,s=255,c=3,t=11,pt=0,l=17,sg=0,ft=0,st=OK:Sensor de humedad
337 TSF:MSG:SEND,8-8-0-0,s=255,c=3,t=12,pt=0,l=3,sg=0,ft=0,st=OK:3.0
446 TSF:MSG:SEND,8-8-0-0,s=1,c=0,t=35,pt=0,l=13,sg=0,ft=0,st=OK:Humedad suelo
454 MCO:REG:REQ
509 TSF:MSG:SEND,8-8-0-0,s=255,c=3,t=26,pt=1,l=1,sg=0,ft=0,st=OK:2
524 TSF:MSG:READ,0-0-8,s=255,c=3,t=27,pt=1,l=1,sg=0:1
530 MCO:PIM:NODE REG=1
534 MCO:BGN:STP
534 MCO:BGN:INIT OK,TSP=1
540 TSF:MSG:READ,0-0-8,s=255,c=3,t=6,pt=0,l=1,sg=0:M
737 TSF:MSG:SEND,8-8-0-0,s=1,c=1,t=37,pt=3,l=2,sg=0,ft=0,st=OK:0
804 TSF:MSG:SEND,8-8-0-0,s=255,c=3,t=0,pt=1,l=1,sg=0,ft=0,st=OK:25
Value1=775 96.87
Value2=185 97.10
Result = 96.99% (0.43cb)
VCC = 3.30 Volts
VCC% = 25 %
819 MCO:SLP:MS=30000,SMS=1,I1=255,M1=255,I2=255,M2=255
868 TSF:MSG:SEND,8-8-0-0,s=255,c=3,t=32,pt=5,l=4,sg=0,ft=0,st=OK:500
899 TSF:MSG:READ,0-0-8,s=0,c=4,t=1,pt=6,l=8,sg=0:0300000040054396
907 OTA:FWP:UPDATE
909 OTA:FRQ:FW REQ,T=0003,V=0000,B=053F
921 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003F05
958 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:030000003F05FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
968 OTA:FWP:RECV B=053F
976 OTA:FRQ:FW REQ,T=0003,V=0000,B=053E
989 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003E05
1026 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:030000003E05003F002100322E322E302D72632E3100
1036 OTA:FWP:RECV B=053E
1042 OTA:FRQ:FW REQ,T=0003,V=0000,B=053D
1054 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003D05
1093 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:030000003D05003C4E4F4E43453E004F4B004E41434B
1103 OTA:FWP:RECV B=053D
1110 OTA:FRQ:FW REQ,T=0003,V=0000,B=053C
1122 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003C05
1155 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:030000003C0525000D0A006E616E00696E66006F7666
1165 OTA:FWP:RECV B=053C
1171 OTA:FRQ:FW REQ,T=0003,V=0000,B=053B
1183 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003B05
1216 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:030000003B0520566F6C74730056434325203D200020
1226 OTA:FWP:RECV B=053B
1234 OTA:FRQ:FW REQ,T=0003,V=0000,B=053A
1247 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003A05
1286 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:030000003A05002520280063622900564343203D2000
1296 OTA:FWP:RECV B=053A
1302 OTA:FRQ:FW REQ,T=0003,V=0000,B=0539
1314 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003905
1349 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:030000003905616C7565323D00526573756C74203D20
1359 OTA:FWP:RECV B=0539
1366 OTA:FRQ:FW REQ,T=0003,V=0000,B=0538
1376 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003805
1384 TSF:TDI:TSL
1388 MCO:SLP:WUP=-1
1390 TSF:TRI:TSB
1398 TSF:MSG:SEND,8-8-0-0,s=255,c=3,t=33,pt=5,l=4,sg=0,ft=0,st=OK:30000
1867 OTA:FRQ:FW REQ,T=0003,V=0000,B=0538
1878 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003805
1914 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:030000003805207375656C6F0056616C7565313D0056
1925 OTA:FWP:RECV B=0538
1931 OTA:FRQ:FW REQ,T=0003,V=0000,B=0537
1943 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003705
1978 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:0300000037056564616400332E300048756D65646164
1988 OTA:FWP:RECV B=0537
1996 OTA:FRQ:FW REQ,T=0003,V=0000,B=0536
2009 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003605
2045 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:03000000360507010353656E736F722064652068756D
2056 OTA:FWP:RECV B=0536
2062 OTA:FRQ:FW REQ,T=0003,V=0000,B=0535
2074 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003505
2111 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:03000000350507070707070707070707070707070707
2121 OTA:FWP:RECV B=0535
2127 OTA:FRQ:FW REQ,T=0003,V=0000,B=0534
2140 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003405
2174 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:03000000340507000204060707070707070707070707
2185 OTA:FWP:RECV B=0534
2191 OTA:FRQ:FW REQ,T=0003,V=0000,B=0533
2203 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003305
2238 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:03000000330500AE0A7E0ADE0A520A760A620A530A05
2248 OTA:FWP:RECV B=0533
2256 OTA:FRQ:FW REQ,T=0003,V=0000,B=0532
2269 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003205
2304 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:0300000032051151117C112B12AD118B119F11000000
2314 OTA:FWP:RECV B=0532
2320 OTA:FRQ:FW REQ,T=0003,V=0000,B=0531
2332 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003105
2371 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:030000003105FF3AFF3C053D106F30FF0000000000E4
2381 OTA:FWP:RECV B=0531
2387 OTA:FRQ:FW REQ,T=0003,V=0000,B=0530
2400 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003005
2433 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:030000003005DC2C002D032E882F2D306437D4384239
2443 OTA:FWP:RECV B=0530
2449 OTA:FRQ:FW REQ,T=0003,V=0000,B=052F
2461 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000002F05
2496 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:030000002F0502044005030633188819422607281029
2506 OTA:FWP:RECV B=052F
2514 OTA:FRQ:FW REQ,T=0003,V=0000,B=052E
2527 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000002E05
2562 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:030000002E05FF1F0A1F0A01FFF709CF080104020003
2574 OTA:FWP:RECV B=052E
2580 OTA:FRQ:FW REQ,T=0003,V=0000,B=052D
2590 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000002D05
2625 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:030000002D056C084208A40856042708D407A8079507
2635 OTA:FWP:RECV B=052D
2641 OTA:FRQ:FW REQ,T=0003,V=0000,B=052C
2654 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000002C05
2689 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:030000002C055040E0F70895F894FFCFFFFF5A073207
2701 OTA:FWP:RECV B=052C
2705 OTA:FRQ:FW REQ,T=0003,V=0000,B=052B
2717 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000002B05
2797 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:030000002B0548F001900D920020C9F701C01D924150
2807 OTA:FWP:RECV B=052B
2818 OTA:FRQ:FW REQ,T=0003,V=0000,B=052A
2828 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000002A05
2928 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:030000002A0541505040D8F70895FB01DC0141505040
2938 OTA:FWP:RECV B=052A
<continues>

As can be seen, the node starts, presents itself, etc, does the first processing cycle, and arrives to the sleep instruction (line 819, sleep time reduced to 30s to speed testing). Then some CRC seems to be exchanged with the gw, and it is determined that an fota is needed (line 907). Then some blocks of code are received until the node goes to sleep after receving block 0538 (line 1384). When it returns (line 1388), the update continues with the same block and from there on to the end of the update.

As a side to this, I've capture occasions where the node determined that no fw update was necessary, went to sleep, and then did an update after waking up, like in this case:

942 MCO:SLP:MS=30000,SMS=1,I1=255,M1=255,I2=255,M2=255
993 TSF:MSG:SEND,8-8-0-0,s=255,c=3,t=32,pt=5,l=4,sg=0,ft=0,st=OK:500
1021 TSF:MSG:READ,0-0-8,s=0,c=4,t=1,pt=6,l=8,sg=0:0300000040054396
1028 OTA:FWP:UPDATE
1030 OTA:FRQ:FW REQ,T=0003,V=0000,B=053F
1042 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003F05
1071 TSF:MSG:READ,0-0-8,s=0,c=4,t=1,pt=6,l=8,sg=0:0300000040054396
1077 OTA:FWP:UPDATE SKIPPED
1089 TSF:MSG:READ,0-0-8,s=0,c=4,t=1,pt=6,l=8,sg=0:0300000040054396
1097 OTA:FWP:UPDATE SKIPPED
1501 TSF:TDI:TSL
1503 MCO:SLP:WUP=-1
1505 TSF:TRI:TSB
1513 TSF:MSG:SEND,8-8-0-0,s=255,c=3,t=33,pt=5,l=4,sg=0,ft=0,st=OK:30000
1531 OTA:FRQ:FW REQ,T=0003,V=0000,B=053F
1581 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003F05
1615 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:030000003F05FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
1626 OTA:FWP:RECV B=053F
1636 OTA:FRQ:FW REQ,T=0003,V=0000,B=053E
1646 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003E05
1681 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:030000003E05003F002100322E322E302D72632E3100
1693 OTA:FWP:RECV B=053E
1697 OTA:FRQ:FW REQ,T=0003,V=0000,B=053D
1710 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003D05
1980 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:030000003D05003C4E4F4E43453E004F4B004E41434B
1992 OTA:FWP:RECV B=053D
1996 OTA:FRQ:FW REQ,T=0003,V=0000,B=053C
2009 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003C05
2048 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:030000003C0525000D0A006E616E00696E66006F7666
2058 OTA:FWP:RECV B=053C
2064 OTA:FRQ:FW REQ,T=0003,V=0000,B=053B
2076 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003B05
2111 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:030000003B0520566F6C74730056434325203D200020
2121 OTA:FWP:RECV B=053B
2129 OTA:FRQ:FW REQ,T=0003,V=0000,B=053A
2142 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003A05
2416 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:030000003A05002520280063622900564343203D2000
2426 OTA:FWP:RECV B=053A
2433 OTA:FRQ:FW REQ,T=0003,V=0000,B=0539
2445 TSF:MSG:SEND,8-8-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:030000003905
2484 TSF:MSG:READ,0-0-8,s=255,c=4,t=3,pt=6,l=22,sg=0:030000003905616C7565323D00526573756C74203D20
2494 OTA:FWP:RECV B=0539

Lines 1077 (and 1097 again for some reason) indicate UPDATE SKIPPED; the node goes to sleep, but then an update is launched after wake-up.

Of course, no changes in the ino.hex file were done while the node was sleeping.

Would this be expected behaviour or is there some inconsistency? The fact that the firmware update needs to wait until the next wake-up cycle is very inconvenient in this scenario where the node sleeps for hours.

Alternatively is there some detailed description of the FOTA update process flow where I can try to understand?

Thanks.

[scalz]

I will try to check that if I get some time, but you still can block your sleep mode until FOTA is finished (by adding a condition in your sketch)

[manutremo]

@scalz Many thanks, let me know if I can help further with the testing.

Regarding your comment on blocking the sleep - how would that be done? I thought the conditional in my sketch (shown above) would already be blocking it.

[scalz]

@manutremo you're right. i need to take a look

[tekka]

@manutremo Can you post the entire sketch + full log when you receive a "OTA:FWP:UPDATE SKIPPED" message. In addition, it would be helpful to get infos on your setup, i.e. HW, IDE & board definition versions.

[manutremo]

@tekka Sure, here it goes:

#define MY_RADIO_RFM69
#define MY_RFM69_NEW_DRIVER  
#define MY_IS_RFM69HW
#define MY_RFM69_MAX_POWER_LEVEL_DBM 13
#define MY_RFM69_FREQUENCY RFM69_868MHZ
//#define MY_DEBUG_VERBOSE_RFM69
#define MY_PARENT_NODE_ID 0
#define MY_PARENT_NODE_IS_STATIC
#define MY_TRANSPORT_MAX_TX_FAILURES (3u)

#define MY_OTA_FIRMWARE_FEATURE
#define MY_OTA_USE_I2C_EEPROM

#define MY_DEBUG 

#include <MySensors.h>
#include <SPI.h>
#include <Vcc.h>
#include <Streaming.h>
#include <math.h>

#define SLEEP_TIME_15min  900000    // 15min x 60s = 900000 ms -13% = 783000                (my arduinos show a delay of 8s/min = 13%)
#define SLEEP_TIME_1h     3600000   // 1 h = 1*60*60000 = 3600000 ms -13% = 3132000 ms
#define SLEEP_TIME_2h     7200000   // 2 h = 2*60*60000 = 7200000 ms -13% = 6264000 ms
#define SLEEP_TIME_3h     10800000  // 3 h = 3*60*60000 = 10800000 ms -13% = 9396000 ms

#define VERSION "3.0"
#define PIN_ALIM1 4                                   // Connect to input of resistor
#define PIN_ALIM2 7                                   // Connect to input of measuring probe
#define PIN_LECTURA A0

#define AGUA_DIR            800.0
#define AGUA_INV            160.0
#define AIRE_DIR            0.0
#define AIRE_INV            1023.0
#define TIEMPO_LECTURA      10
#define MAX_REP_LECTURA     20
#define MAX_REPORTING_LOOPS 4

// Battery calibration (Li-ion)
const float VccMin   = 3.0;                         // Minimum expected Vcc level, in Volts.
const float VccMax   = 4.2;                         // Maximum expected Vcc level, in Volts.
const float VccCorrection = 3.82/3.74;              // Measured Vcc by multimeter divided by reported Vcc

#define CHILD_MOIST_ID 1
MyMessage msgmoist(CHILD_MOIST_ID, V_LEVEL);
Vcc vcc(VccCorrection);

int count=0;
signed int oldv1=0, oldv2=0;
float oldresultcb=0;

void setup() {
#ifdef MY_DEBUG
  Serial.begin(115200);
#endif
  analogReference(DEFAULT);
  pinMode(PIN_LECTURA, INPUT);
  pinMode(PIN_ALIM1, OUTPUT);
  pinMode(PIN_ALIM2, OUTPUT);
}

void presentation(){
    sendSketchInfo("Sensor de humedad", VERSION);
    present(CHILD_MOIST_ID, S_MOISTURE, "Humedad suelo");
}

void loop()
{
  if (!isFirmwareUpdateOngoing()) {
    signed int value1=0, value2=0, i=0;
    float result1, result2, resultp, resultcb;

    //Loop until readings are stable or max number of readings is reached
    do {
      oldv1=value1; oldv2=value2;
      wait(TIEMPO_LECTURA);
      digitalWrite(PIN_ALIM1, HIGH);
      digitalWrite(PIN_ALIM2, LOW);
      wait(TIEMPO_LECTURA);
      value1 = analogRead(PIN_LECTURA);

      digitalWrite(PIN_ALIM1, LOW);
      digitalWrite(PIN_ALIM2, HIGH);
      wait(TIEMPO_LECTURA);
      value2 = analogRead(PIN_LECTURA);;
      digitalWrite(PIN_ALIM1, LOW);
      digitalWrite(PIN_ALIM2, LOW);
    } while (((oldv1 != value1) && (oldv2 != value2)) || (i == MAX_REP_LECTURA));

/*
      0-10 Saturated Soil. Occurs for a day or two after irrigation 
      10-20 Soil is adequately wet (except coarse sands which are drying out at this range) 
      20-60 Usual range to irrigate or water (most soils except heavy clay soils). 
      60-100 Usual range to irrigate heavy clay soils 
      100-200 Soil is becoming dangerously dry
    */
    result1=constrain(value1/(AGUA_DIR-AIRE_DIR)*100.0, 1, 100);
    result2=constrain(100-(value2-AGUA_INV)/(AIRE_INV-AGUA_INV)*100.0,1,100);
    resultp = (result1+result2)/2.0;
    resultcb = resultcb + constrain(square((-2.96699 + 351.395/resultp)),0,200);                           //Equation fit using stat software
    count++;
  
    //Send the data - only if moisture changed to save battery (send anyways once every 4 readings). If moisture sent, send battery level.
    if ((oldresultcb!=resultcb) || (count==MAX_REPORTING_LOOPS)) {
      send(msgmoist.set((unsigned int)resultcb));
      oldresultcb=resultcb;
      //Measure battery voltage and send level
      float v = vcc.Read_Volts();  
      int p = vcc.Read_Perc(VccMin, VccMax);
      p=constrain(p,0,100);
      sendBatteryLevel(p);
      #ifdef MY_DEBUG
        Serial << "Value1=" << value1 << " " << result1 << endl << "Value2=" << value2 << " " << result2 << endl << "Result = " << resultp << "% (" << resultcb << "cb)" << endl;
        Serial << "VCC = " << v << " Volts" << endl << "VCC% = " << p << " %" << endl;
      #endif
    }
  
    if (count==MAX_REPORTING_LOOPS) count=0;
    sleep(SLEEP_TIME_3h, true);
  }
}

The node uses a Mini Pro 3.3v @ 8 MHz. I'm powering it with a Li battery through a MCP1703 LDO with the 2 caps as shown in the datasheet. The radio is a RFM69HW with a 47uF cap in the power rail and a 0.1uF soldered to the power pins of the board shield. I'm using Arduino IDE v1.8.4, with boards definition v1.6.20.

Thanks in advance.

[tekka]

@manutremo you're using a i2c eeprom? Please re-run a FOTA update with

#define MY_DEBUG_VERBOSE_OTA_UPDATE

enabled and post the full log. Could be an issue with the i2c eeprom...let's see

[manutremo]

Yes, an AT24C256. Will enable fota verbose debug but the update skipped issue doesn't happen always. Will try to reproduce it, though.

in case it matters, I'm using kisse66's bootloader here

[manutremo]

@tekka See below the log of a new occurence of the same issue with UPDATE SKIPPED. This time I enabled verbose debug for OTA . This time I was testing with another different node with a similar hw setup - I'm also adding the sketch below although I think that from an OTA standpoint it's the same. First the node says UPDATE (line 2600), then UPDATE SKIPPED (line 2654), then goes to sleep, and after wake-up the update starts. This time the firmware was a new one, so the update is correct - which makes me think that maybe it's just that the UPDATE SKIPPED appears incorrectly.

18 MCO:BGN:INIT NODE,CP=RPONA---,VER=2.2.0-rc.1
28 TSM:INIT
28 TSF:WUR:MS=0
32 TSM:INIT:TSP OK
34 TSM:INIT:STATID=22
36 TSF:SID:OK,ID=22
38 TSM:FPAR
38 TSM:FPAR:STATP=0
40 TSM:ID
43 TSM:ID:OK
45 TSM:UPL
53 TSF:MSG:SEND,22-22-0-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=OK:1
71 TSF:MSG:READ,0-0-22,s=255,c=3,t=25,pt=1,l=1,sg=0:1
77 TSF:MSG:PONG RECV,HP=1
79 TSM:UPL:OK
81 TSM:READY:ID=22,PAR=0,DIS=1
307 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=0,pt=6,l=10,sg=0,ft=0,st=OK:010001000005990D0300
370 TSF:MSG:SEND,22-22-0-0,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=OK:0100
382 TSF:MSG:READ,0-0-22,s=255,c=3,t=15,pt=6,l=2,sg=0:0100
397 TSF:MSG:SEND,22-22-0-0,s=255,c=0,t=17,pt=0,l=10,sg=0,ft=0,st=OK:2.2.0-rc.1
464 TSF:MSG:SEND,22-22-0-0,s=255,c=3,t=6,pt=1,l=1,sg=0,ft=0,st=OK:0
491 TSF:MSG:READ,0-0-22,s=255,c=3,t=6,pt=0,l=1,sg=0:M
507 TSF:MSG:SEND,22-22-0-0,s=255,c=3,t=11,pt=0,l=23,sg=0,ft=0,st=OK:Sensor de fugas de agua
575 TSF:MSG:SEND,22-22-0-0,s=255,c=3,t=12,pt=0,l=3,sg=0,ft=0,st=OK:1.1
638 TSF:MSG:SEND,22-22-0-0,s=1,c=0,t=32,pt=0,l=13,sg=0,ft=0,st=OK:Fugas de agua
647 MCO:REG:REQ
700 TSF:MSG:SEND,22-22-0-0,s=255,c=3,t=26,pt=1,l=1,sg=0,ft=0,st=OK:2
952 TSF:MSG:READ,0-0-22,s=255,c=3,t=27,pt=1,l=1,sg=0:1
958 MCO:PIM:NODE REG=1
960 MCO:BGN:STP
962 MCO:BGN:INIT OK,TSP=1
2459 !TSF:MSG:SEND,22-22-0-0,s=1,c=1,t=16,pt=1,l=1,sg=0,ft=0,st=NACK:0
2498 TSF:MSG:SEND,22-22-0-0,s=255,c=3,t=0,pt=1,l=1,sg=0,ft=1,st=OK:36
No detection
2506 MCO:SLP:MS=30000,SMS=1,I1=1,M1=1,I2=255,M2=255
2560 TSF:MSG:SEND,22-22-0-0,s=255,c=3,t=32,pt=5,l=4,sg=0,ft=0,st=OK:500
2592 TSF:MSG:READ,0-0-22,s=0,c=4,t=1,pt=6,l=8,sg=0:0100010000057CC3
2600 OTA:FWP:UPDATE
2603 OTA:FRQ:FW REQ,T=0001,V=0001,B=04FF
2615 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:01000100FF04
2648 TSF:MSG:READ,0-0-22,s=0,c=4,t=1,pt=6,l=8,sg=0:0100010000057CC3
2654 OTA:FWP:UPDATE SKIPPED
3069 TSF:TDI:TSL
3072 MCO:SLP:WUP=-1
3074 TSF:TRI:TSB
3082 TSF:MSG:SEND,22-22-0-0,s=255,c=3,t=33,pt=5,l=4,sg=0,ft=0,st=OK:30000
3104 OTA:FRQ:FW REQ,T=0001,V=0001,B=04FF
3143 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:01000100FF04
3178 TSF:MSG:READ,0-0-22,s=255,c=4,t=3,pt=6,l=22,sg=0:01000100FF04FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
3188 OTA:FWP:RECV B=04FF
3198 OTA:FRQ:FW REQ,T=0001,V=0001,B=04FE
3211 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:01000100FE04
3254 TSF:MSG:READ,0-0-22,s=255,c=4,t=3,pt=6,l=22,sg=0:01000100FE04FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
3264 OTA:FWP:RECV B=04FE
3270 OTA:FRQ:FW REQ,T=0001,V=0001,B=04FD
3282 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:01000100FD04
3315 TSF:MSG:READ,0-0-22,s=255,c=4,t=3,pt=6,l=22,sg=0:01000100FD042E310000FFFFFFFFFFFFFFFFFFFFFFFF
3328 OTA:FWP:RECV B=04FD
3334 OTA:FRQ:FW REQ,T=0001,V=0001,B=04FC
3346 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:01000100FC04
3379 TSF:MSG:READ,0-0-22,s=255,c=4,t=3,pt=6,l=22,sg=0:01000100FC0441434B003F002100322E322E302D7263
3389 OTA:FWP:RECV B=04FC
3397 OTA:FRQ:FW REQ,T=0001,V=0001,B=04FB
3407 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:01000100FB04
3446 TSF:MSG:READ,0-0-22,s=255,c=4,t=3,pt=6,l=22,sg=0:01000100FB04696F6E003C4E4F4E43453E004F4B004E
3457 OTA:FWP:RECV B=04FB
3467 OTA:FRQ:FW REQ,T=0001,V=0001,B=04FA
3477 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:01000100FA04
3514 TSF:MSG:READ,0-0-22,s=255,c=4,t=3,pt=6,l=22,sg=0:01000100FA04746564000D0A004E6F20646574656374
3524 OTA:FWP:RECV B=04FA
3530 OTA:FRQ:FW REQ,T=0001,V=0001,B=04F9
3543 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:01000100F904
3579 TSF:MSG:READ,0-0-22,s=255,c=4,t=3,pt=6,l=22,sg=0:01000100F9046167756100466C6F6F64206465746563
3592 OTA:FWP:RECV B=04F9
3598 OTA:FRQ:FW REQ,T=0001,V=0001,B=04F8
3608 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:01000100F804
3651 TSF:MSG:READ,0-0-22,s=255,c=4,t=3,pt=6,l=22,sg=0:01000100F804756100312E3100467567617320646520
3661 OTA:FWP:RECV B=04F8
3667 OTA:FRQ:FW REQ,T=0001,V=0001,B=04F7
3680 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:01000100F704
3715 TSF:MSG:READ,0-0-22,s=255,c=4,t=3,pt=6,l=22,sg=0:01000100F70472206465206675676173206465206167
3727 OTA:FWP:RECV B=04F7

#define MY_RADIO_RFM69
#define MY_RFM69_NEW_DRIVER   // ATC on RFM69 works only with the new driver (not compatible with old=default driver)
#define MY_IS_RFM69HW
#define MY_RFM69_MAX_POWER_LEVEL_DBM 13
#define MY_RFM69_FREQUENCY RFM69_868MHZ
#define MY_DEBUG_VERBOSE_OTA_UPDATE
#define MY_PARENT_NODE_ID 0
#define MY_PARENT_NODE_IS_STATIC
#define MY_TRANSPORT_MAX_TX_FAILURES (3u)

#define MY_NODE_ID 22

#define MY_OTA_FIRMWARE_FEATURE
#define MY_OTA_USE_I2C_EEPROM

#define MY_DEBUG 

#include <MySensors.h>
#include <SPI.h>
#include <Vcc.h>
#include <Streaming.h>

#define SLEEP_TIME_5min   300000
#define SLEEP_TIME_10min  600000  
#define SLEEP_TIME_15min  900000
#define SLEEP_TIME_1h     3600000
#define SLEEP_TIME_2h     7200000
#define SLEEP_TIME_3h     10800000

#define VERSION "1.1"
#define PIN_INTERRUPT 3

// Battery calibration (Li-ion)
const float VccMin   = 3.0;                         // Minimum expected Vcc level, in Volts.
const float VccMax   = 4.2;                         // Maximum expected Vcc level, in Volts.
const float VccCorrection = 3.82/3.74;              // Measured Vcc by multimeter divided by reported Vcc

#define CHILD_FLOOD_ID 1
MyMessage msgflood(CHILD_FLOOD_ID, V_TRIPPED);
Vcc vcc(VccCorrection);

bool res;
int interrupt=digitalPinToInterrupt(PIN_INTERRUPT), oldbat=101;     // Set so that it will be sent always on the first run

void setup(){
  Serial.begin(115200);
  pinMode(PIN_INTERRUPT, INPUT);
}

void presentation(){
    sendSketchInfo("Sensor de fugas de agua", VERSION);
    present(CHILD_FLOOD_ID, S_WATER_LEAK, "Fugas de agua");
}

void loop()
{
  if (!isFirmwareUpdateOngoing()) {
    // Contact status is always sent as a safety measure to allow checking if the sensor is working
    // We start with a short delay for debouncing the contact (otherwise the reading from the pin might be incorrect after exiting from the sleep()
    delay(150);
    res = (digitalRead(PIN_INTERRUPT) == LOW);
    send(msgflood.set(res));
    //Measure battery voltage and send level if it has changed
    int p = vcc.Read_Perc(VccMin, VccMax);
    p=constrain(p,0,100);
    if (p != oldbat) { oldbat = p; sendBatteryLevel(p); }
    #ifdef MY_DEBUG
    if (res) Serial.println("Flood detected"); else Serial.println("No detection");
    #endif
    sleep(interrupt, CHANGE, 20000, true);//SLEEP_TIME_3h, true);
  }
}

[manutremo]

By the way - following the above, I made a small modification to the sketch, compiled, etc. Myscontroller detected the new fw corectly and the update run fine at the next wake-up, with no SKIPPED messages.

20987 MCO:SLP:MS=20000,SMS=1,I1=1,M1=1,I2=255,M2=255
21041 TSF:MSG:SEND,22-22-0-0,s=255,c=3,t=32,pt=5,l=4,sg=0,ft=0,st=OK:500
21073 TSF:MSG:READ,0-0-22,s=0,c=4,t=1,pt=6,l=8,sg=0:010001000005990D
21082 OTA:FWP:UPDATE
21084 OTA:FRQ:FW REQ,T=0001,V=0001,B=04FF
21096 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:01000100FF04
21135 TSF:MSG:READ,0-0-22,s=255,c=4,t=3,pt=6,l=22,sg=0:01000100FF04FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
21145 OTA:FWP:RECV B=04FF
21155 OTA:FRQ:FW REQ,T=0001,V=0001,B=04FE

However I then modified the sketch again, uploaded it to Myscontroller, etc, but this time I reset the node. The log showed the UPDATE SKIPPED message again before starting the update.

18 MCO:BGN:INIT NODE,CP=RPONA---,VER=2.2.0-rc.1
28 TSM:INIT
28 TSF:WUR:MS=0
32 TSM:INIT:TSP OK
34 TSM:INIT:STATID=22
36 TSF:SID:OK,ID=22
38 TSM:FPAR
38 TSM:FPAR:STATP=0
40 TSM:ID
43 TSM:ID:OK
45 TSM:UPL
53 TSF:MSG:SEND,22-22-0-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=OK:1
71 TSF:MSG:READ,0-0-22,s=255,c=3,t=25,pt=1,l=1,sg=0:1
77 TSF:MSG:PONG RECV,HP=1
79 TSM:UPL:OK
81 TSM:READY:ID=22,PAR=0,DIS=1
94 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=0,pt=6,l=10,sg=0,ft=0,st=OK:010001000005990D0300
161 TSF:MSG:SEND,22-22-0-0,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=OK:0100
172 TSF:MSG:READ,0-0-22,s=255,c=3,t=15,pt=6,l=2,sg=0:0100
188 TSF:MSG:SEND,22-22-0-0,s=255,c=0,t=17,pt=0,l=10,sg=0,ft=0,st=OK:2.2.0-rc.1
253 TSF:MSG:SEND,22-22-0-0,s=255,c=3,t=6,pt=1,l=1,sg=0,ft=0,st=OK:0
282 TSF:MSG:READ,0-0-22,s=255,c=3,t=6,pt=0,l=1,sg=0:M
299 TSF:MSG:SEND,22-22-0-0,s=255,c=3,t=11,pt=0,l=23,sg=0,ft=0,st=OK:Sensor de fugas de agua
364 TSF:MSG:SEND,22-22-0-0,s=255,c=3,t=12,pt=0,l=3,sg=0,ft=0,st=OK:1.1
428 TSF:MSG:SEND,22-22-0-0,s=1,c=0,t=32,pt=0,l=13,sg=0,ft=0,st=OK:Fugas de agua
436 MCO:REG:REQ
489 TSF:MSG:SEND,22-22-0-0,s=255,c=3,t=26,pt=1,l=1,sg=0,ft=0,st=OK:2
505 TSF:MSG:READ,0-0-22,s=255,c=3,t=27,pt=1,l=1,sg=0:1
512 MCO:PIM:NODE REG=1
514 MCO:BGN:STP
516 MCO:BGN:INIT OK,TSP=1
675 TSF:MSG:SEND,22-22-0-0,s=1,c=1,t=16,pt=1,l=1,sg=0,ft=0,st=OK:0
739 TSF:MSG:SEND,22-22-0-0,s=255,c=3,t=0,pt=1,l=1,sg=0,ft=0,st=OK:32
No detection
745 MCO:SLP:MS=30000,SMS=1,I1=1,M1=1,I2=255,M2=255
802 TSF:MSG:SEND,22-22-0-0,s=255,c=3,t=32,pt=5,l=4,sg=0,ft=0,st=OK:500
831 TSF:MSG:READ,0-0-22,s=0,c=4,t=1,pt=6,l=8,sg=0:0100010000057CC3
839 OTA:FWP:UPDATE
841 OTA:FRQ:FW REQ,T=0001,V=0001,B=04FF
854 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:01000100FF04
882 TSF:MSG:READ,0-0-22,s=0,c=4,t=1,pt=6,l=8,sg=0:0100010000057CC3
888 OTA:FWP:UPDATE SKIPPED
1220 TSF:MSG:READ,0-0-22,s=255,c=3,t=6,pt=0,l=1,sg=0:M
1288 TSF:MSG:READ,0-0-22,s=255,c=4,t=3,pt=6,l=22,sg=0:01000100FF04FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
1298 OTA:FWP:RECV B=04FF
1308 OTA:FRQ:FW REQ,T=0001,V=0001,B=04FE
1320 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:01000100FE04
1329 TSF:TDI:TSL
1331 MCO:SLP:WUP=-1
1333 TSF:TRI:TSB
1343 TSF:MSG:SEND,22-22-0-0,s=255,c=3,t=33,pt=5,l=4,sg=0,ft=0,st=OK:30000
1810 OTA:FRQ:FW REQ,T=0001,V=0001,B=04FE
1820 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:01000100FE04
1859 TSF:MSG:READ,0-0-22,s=255,c=4,t=3,pt=6,l=22,sg=0:01000100FE04FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF
1869 OTA:FWP:RECV B=04FE
1878 OTA:FRQ:FW REQ,T=0001,V=0001,B=04FD
1888 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:01000100FD04
1925 TSF:MSG:READ,0-0-22,s=255,c=4,t=3,pt=6,l=22,sg=0:01000100FD042E310000FFFFFFFFFFFFFFFFFFFFFFFF
1935 OTA:FWP:RECV B=04FD
1943 OTA:FRQ:FW REQ,T=0001,V=0001,B=04FC
1953 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:01000100FC04
1992 TSF:MSG:READ,0-0-22,s=255,c=4,t=3,pt=6,l=22,sg=0:01000100FC0441434B003F002100322E322E302D7263
2002 OTA:FWP:RECV B=04FC
2009 OTA:FRQ:FW REQ,T=0001,V=0001,B=04FB
2021 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:01000100FB04
2056 TSF:MSG:READ,0-0-22,s=255,c=4,t=3,pt=6,l=22,sg=0:01000100FB04696F6E003C4E4F4E43453E004F4B004E
2066 OTA:FWP:RECV B=04FB
2076 OTA:FRQ:FW REQ,T=0001,V=0001,B=04FA
2086 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:01000100FA04
2123 TSF:MSG:READ,0-0-22,s=255,c=4,t=3,pt=6,l=22,sg=0:01000100FA04746564000D0A004E6F20646574656374
2134 OTA:FWP:RECV B=04FA
2140 OTA:FRQ:FW REQ,T=0001,V=0001,B=04F9
2152 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:01000100F904
2187 TSF:MSG:READ,0-0-22,s=255,c=4,t=3,pt=6,l=22,sg=0:01000100F9046167756100466C6F6F64206465746563
2197 OTA:FWP:RECV B=04F9
2203 OTA:FRQ:FW REQ,T=0001,V=0001,B=04F8

So it looks this happens only if right after a node reset. I hope this gives a hint.

As a side note - I also find interesting that the number of update blocks sent before the node goes to sleep changes between test runs.

[tekka]

@manutremo ok, I'm on something - it has to do with the smart sleep feature. I will prepare a fix for you to test.

[tekka]

@manutremo here you go: https://github.com/tekka007/MySensors/tree/FOTAUpdates

[manutremo]

Many thanks @tekka, that was really fast! I'll give it a try as soon as I can spare some minutes.

[manutremo]

@tekka Tested the new library and both issues seem to be gone now, great job !

I have one more question though

During testing I treid to put things difficult for my radios and move them until reception started to be bad. At some point the FOTA process gave up with a FW UPD FAIL message (line 41146 in attached log). So the node gave up and went to sleep. I was expecting it to try again after wake-up, but it didn't (see lines after 43589).

36734 !RFM69:SWR:NACK
36737 RFM69:PTX:NO ADJ
36771 RFM69:SWR:SEND,TO=0,RETRY=5
36966 RFM69:SWR:ACK,FROM=0,SEQ=119,RSSI=-55
36972 RFM69:ATC:ADJ TXL,cR=-55,tR=-80,TXL=12
36976 RFM69:PTX:LEVEL=12 dBm
36978 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:010001002005
36988 OTA:FRQ:FW REQ,T=0001,V=0001,B=0520
36993 RFM69:SWR:SEND,TO=0,RETRY=0
37203 !RFM69:SWR:NACK
37206 RFM69:PTX:LEVEL=13 dBm
37216 RFM69:SWR:SEND,TO=0,RETRY=1
37423 !RFM69:SWR:NACK
37425 RFM69:PTX:NO ADJ
37459 RFM69:SWR:SEND,TO=0,RETRY=2
37666 !RFM69:SWR:NACK
37668 RFM69:PTX:NO ADJ
37679 RFM69:SWR:SEND,TO=0,RETRY=3
37885 !RFM69:SWR:NACK
37888 RFM69:PTX:NO ADJ
37922 RFM69:SWR:SEND,TO=0,RETRY=4
38129 !RFM69:SWR:NACK
38131 RFM69:PTX:NO ADJ
38174 RFM69:SWR:SEND,TO=0,RETRY=5
38313 RFM69:SWR:ACK,FROM=0,SEQ=120,RSSI=-56
38318 RFM69:ATC:ADJ TXL,cR=-56,tR=-80,TXL=12
38322 RFM69:PTX:LEVEL=12 dBm
38326 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:010001002005
38334 OTA:FRQ:FW REQ,T=0001,V=0001,B=0520
38338 RFM69:SWR:SEND,TO=0,RETRY=0
38547 !RFM69:SWR:NACK
38549 RFM69:PTX:LEVEL=13 dBm
38559 RFM69:SWR:SEND,TO=0,RETRY=1
38768 !RFM69:SWR:NACK
38770 RFM69:PTX:NO ADJ
38805 RFM69:SWR:SEND,TO=0,RETRY=2
39012 !RFM69:SWR:NACK
39014 RFM69:PTX:NO ADJ
39024 RFM69:SWR:SEND,TO=0,RETRY=3
39231 !RFM69:SWR:NACK
39233 RFM69:PTX:NO ADJ
39268 RFM69:SWR:SEND,TO=0,RETRY=4
39475 !RFM69:SWR:NACK
39477 RFM69:PTX:NO ADJ
39520 RFM69:SWR:SEND,TO=0,RETRY=5
39702 RFM69:SWR:ACK,FROM=0,SEQ=121,RSSI=-54
39706 RFM69:ATC:ADJ TXL,cR=-54,tR=-80,TXL=12
39712 RFM69:PTX:LEVEL=12 dBm
39714 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:010001002005
39723 OTA:FRQ:FW REQ,T=0001,V=0001,B=0520
39729 RFM69:SWR:SEND,TO=0,RETRY=0
39938 !RFM69:SWR:NACK
39940 RFM69:PTX:LEVEL=13 dBm
39983 RFM69:SWR:SEND,TO=0,RETRY=1
40192 !RFM69:SWR:NACK
40194 RFM69:PTX:NO ADJ
40228 RFM69:SWR:SEND,TO=0,RETRY=2
40435 !RFM69:SWR:NACK
40437 RFM69:PTX:NO ADJ
40480 RFM69:SWR:SEND,TO=0,RETRY=3
40687 !RFM69:SWR:NACK
40689 RFM69:PTX:NO ADJ
40724 RFM69:SWR:SEND,TO=0,RETRY=4
40931 !RFM69:SWR:NACK
40933 RFM69:PTX:NO ADJ
40943 RFM69:SWR:SEND,TO=0,RETRY=5
41125 RFM69:SWR:ACK,FROM=0,SEQ=122,RSSI=-54
41129 RFM69:ATC:ADJ TXL,cR=-54,tR=-80,TXL=12
41134 RFM69:PTX:LEVEL=12 dBm
41138 TSF:MSG:SEND,22-22-0-0,s=255,c=4,t=2,pt=6,l=6,sg=0,ft=0,st=OK:010001002005
41146 !OTA:FRQ:FW UPD FAIL
41299 RFM69:SWR:SEND,TO=0,RETRY=0
41506 !RFM69:SWR:NACK
41508 RFM69:PTX:LEVEL=13 dBm
41519 RFM69:SWR:SEND,TO=0,RETRY=1
41725 !RFM69:SWR:NACK
41728 RFM69:PTX:NO ADJ
41762 RFM69:SWR:SEND,TO=0,RETRY=2
41969 !RFM69:SWR:NACK
41971 RFM69:PTX:NO ADJ
42014 RFM69:SWR:SEND,TO=0,RETRY=3
42221 !RFM69:SWR:NACK
42223 RFM69:PTX:NO ADJ
42258 RFM69:SWR:SEND,TO=0,RETRY=4
42465 !RFM69:SWR:NACK
42467 RFM69:PTX:NO ADJ
42477 RFM69:SWR:SEND,TO=0,RETRY=5
42684 !RFM69:SWR:NACK
42686 RFM69:PTX:NO ADJ
42721 !TSF:MSG:SEND,22-22-0-0,s=1,c=1,t=16,pt=1,l=1,sg=0,ft=0,st=NACK:0
42729 RFM69:SWR:SEND,TO=0,RETRY=0
42950 !RFM69:SWR:NACK
42952 RFM69:PTX:NO ADJ
42995 RFM69:SWR:SEND,TO=0,RETRY=1
43005 RFM69:SWR:ACK,FROM=0,SEQ=124,RSSI=-55
43010 RFM69:ATC:ADJ TXL,cR=-55,tR=-80,TXL=12
43014 RFM69:PTX:LEVEL=12 dBm
43018 TSF:MSG:SEND,22-22-0-0,s=255,c=3,t=0,pt=1,l=1,sg=0,ft=1,st=OK:20
No detection
43026 MCO:SLP:MS=30000,SMS=1,I1=1,M1=1,I2=255,M2=255
43030 RFM69:SWR:SEND,TO=0,RETRY=0
43065 RFM69:SWR:ACK,FROM=0,SEQ=125,RSSI=-56
43069 RFM69:ATC:ADJ TXL,cR=-56,tR=-80,TXL=11
43075 RFM69:PTX:LEVEL=11 dBm
43077 TSF:MSG:SEND,22-22-0-0,s=255,c=3,t=32,pt=5,l=4,sg=0,ft=0,st=OK:500
43585 TSF:TDI:TSL
43587 RFM69:RSL
43589 MCO:SLP:WUP=-1
43591 TSF:TRI:TSB
43593 RFM69:RSB
43595 RFM69:SWR:SEND,TO=0,RETRY=0
43606 RFM69:SWR:ACK,FROM=0,SEQ=126,RSSI=-56
43610 RFM69:ATC:ADJ TXL,cR=-56,tR=-80,TXL=10
43616 RFM69:PTX:LEVEL=10 dBm
43618 TSF:MSG:SEND,22-22-0-0,s=255,c=3,t=33,pt=5,l=4,sg=0,ft=0,st=OK:30000
43778 RFM69:SWR:SEND,TO=0,RETRY=0
43788 RFM69:SWR:ACK,FROM=0,SEQ=127,RSSI=-59
43792 RFM69:ATC:ADJ TXL,cR=-59,tR=-80,TXL=9
43796 RFM69:PTX:LEVEL=9 dBm

So when this occurs the only way I can think of to force another update would be update the sketch, refresh the repo in MysController and assign it to the node again. Therefore I wonder if this is intended behaviour and if so, if there is some other way to force an update after a failed one.

Thanks.