Node sending req packets constantly (Packet type 2 on MQTT)

Samuel235

Firstly, you mentioned that you get a Error LED light on your gateway, i do not, instead i get a send and receive light simultaneously. I'm not sure if we're both facing seperate issues fundamentally but i think at heart, its because of the same issue (if that makes sense). You're getting a different output to the same error i think, is what i meant.

Now, my node NEVER gets what its after, its been running for 12 hours and its still sending the REQ message.

My code is the example code with a manual ID and changed LED blink value:

/**
 * The MySensors Arduino library handles the wireless radio link and protocol
 * between your home built sensors/actuators and HA controller of choice.
 * The sensors forms a self healing radio network with optional repeaters. Each
 * repeater and gateway builds a routing tables in EEPROM which keeps track of the
 * network topology allowing messages to be routed to nodes.
 *
 * Created by Henrik Ekblad <henrik.ekblad@mysensors.org>
 * Copyright (C) 2013-2015 Sensnology AB
 * Full contributor list: https://github.com/mysensors/Arduino/graphs/contributors
 *
 * Documentation: http://www.mysensors.org
 * Support Forum: http://forum.mysensors.org
 *
 * This program is free software; you can redistribute it and/or
 * modify it under the terms of the GNU General Public License
 * version 2 as published by the Free Software Foundation.
 *
 *******************************
 *
 * REVISION HISTORY
 * Version 1.0 - Henrik EKblad
 *
 * DESCRIPTION
 * This sketch provides an example how to implement a distance sensor using HC-SR04
 * Use this sensor to measure KWH and Watt of your house meeter
 * You need to set the correct pulsefactor of your meeter (blinks per KWH).
 * The sensor starts by fetching current KWH value from gateway.
 * Reports both KWH and Watt back to gateway.
 *
 * Unfortunately millis() won't increment when the Arduino is in
 * sleepmode. So we cannot make this sensor sleep if we also want
 * to calculate/report watt-number.
 * http://www.mysensors.org/build/pulse_power
 */

// Enable debug prints
#define MY_DEBUG

// Enable and select radio type attached
#define MY_RADIO_NRF24
//#define MY_RADIO_RFM69

// Assign NODE ID
#define MY_NODE_ID 16

#include <MySensors.h>

#define DIGITAL_INPUT_SENSOR 3  // The digital input you attached your light sensor.  (Only 2 and 3 generates interrupt!)
#define PULSE_FACTOR 3200       // Nummber of blinks per KWH of your meeter
#define SLEEP_MODE false        // Watt-value can only be reported when sleep mode is false.
#define MAX_WATT 10000          // Max watt value to report. This filetrs outliers.
#define CHILD_ID 1              // Id of the sensor child

unsigned long SEND_FREQUENCY =
    10000; // Minimum time between send (in milliseconds). We don't wnat to spam the gateway.
double ppwh = ((double)PULSE_FACTOR)/1000; // Pulses per watt hour
bool pcReceived = false;
volatile unsigned long pulseCount = 0;
volatile unsigned long lastBlink = 0;
volatile unsigned long watt = 0;
unsigned long oldPulseCount = 0;
unsigned long oldWatt = 0;
double oldKwh;
unsigned long lastSend;
MyMessage wattMsg(CHILD_ID,V_WATT);
MyMessage kwhMsg(CHILD_ID,V_KWH);
MyMessage pcMsg(CHILD_ID,V_VAR1);


void setup()
{
    // Fetch last known pulse count value from gw
    request(CHILD_ID, V_VAR1);

    // Use the internal pullup to be able to hook up this sketch directly to an energy meter with S0 output
    // If no pullup is used, the reported usage will be too high because of the floating pin
    pinMode(DIGITAL_INPUT_SENSOR,INPUT_PULLUP);

    attachInterrupt(digitalPinToInterrupt(DIGITAL_INPUT_SENSOR), onPulse, RISING);
    lastSend=millis();
}

void presentation()
{
    // Send the sketch version information to the gateway and Controller
    sendSketchInfo("Energy Meter", "1.0");

    // Register this device as power sensor
    present(CHILD_ID, S_POWER);
}

void loop()
{
    unsigned long now = millis();
    // Only send values at a maximum frequency or woken up from sleep
    bool sendTime = now - lastSend > SEND_FREQUENCY;
    if (pcReceived && (SLEEP_MODE || sendTime)) {
        // New watt value has been calculated
        if (!SLEEP_MODE && watt != oldWatt) {
            // Check that we dont get unresonable large watt value.
            // could hapen when long wraps or false interrupt triggered
            if (watt<((unsigned long)MAX_WATT)) {
                send(wattMsg.set(watt));  // Send watt value to gw
            }
            Serial.print("Watt:");
            Serial.println(watt);
            oldWatt = watt;
        }

        // Pulse cout has changed
        if (pulseCount != oldPulseCount) {
            send(pcMsg.set(pulseCount));  // Send pulse count value to gw
            double kwh = ((double)pulseCount/((double)PULSE_FACTOR));
            oldPulseCount = pulseCount;
            if (kwh != oldKwh) {
                send(kwhMsg.set(kwh, 4));  // Send kwh value to gw
                oldKwh = kwh;
            }
        }
        lastSend = now;
    } else if (sendTime && !pcReceived) {
        // No count received. Try requesting it again
        request(CHILD_ID, V_VAR1);
        lastSend=now;
    }

    if (SLEEP_MODE) {
        sleep(SEND_FREQUENCY);
    }
}

void receive(const MyMessage &message)
{
    if (message.type==V_VAR1) {
        pulseCount = oldPulseCount = message.getLong();
        Serial.print("Received last pulse count from gw:");
        Serial.println(pulseCount);
        pcReceived = true;
    }
}

void onPulse()
{
    if (!SLEEP_MODE) {
        unsigned long newBlink = micros();
        unsigned long interval = newBlink-lastBlink;
        if (interval<10000L) { // Sometimes we get interrupt on RISING
            return;
        }
        watt = (3600000000.0 /interval) / ppwh;
        lastBlink = newBlink;
    }
    pulseCount++;
}

I can't seem to remember what controller you use, is it domonicz or openhab by any chance?

I'm still attempting to get my head around what is actually happening here.

I'm getting a 6724899 TSF:MSG:SEND,16-16-0-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK: which is showing the node is sending a request message.
I'm then getting what seems to be a blank message on the MQTT topic of Gateway1-out/16/1/2/0/24 which shows to me that it doesn't have a value stored for this request and the gateway is actually publishing that message. (So i think that the gateway is doing exactly as its being asked too.)

sundberg84

@Samuel235 - I use Domoticz on a EthernetGW.
Yes, maybe its different.

I do have a stored value, but Domoticz logs does not show me anything. In gw log I see the value is beeing sent.
Just as you, both send and recieve led is beeing lit for a second and then i get the error led after < 0.5sec maybe but not simultaneous.
We use the same code (request, if not recieved, request again).
Sometimes I have had this run for 12 hours as well, and I have moved the node and restarted it which helped.

Do you have a repeater?

We should collect some logs simulatanoius from:
-Node
-Gw
-Controller
-Repeater

Samuel235

@sundberg84 I have just found your website linked on your profile, so i realised that domoticz is what you run, may i ask how you find their dashboard? The only reason i like openhab is the dashboard feel, the setup is a little ass about backwards as i would call it and would be tempted to try domonicz (maybe this would solve my issue, very much doubt it though).

I will grab my log from the gateway and controller (if openhab shows any issues in the log for this problem that is).

I have no repeater, its just a node connecting directly to the gateway.

My node is literally setting itself up, presenting itself to the gateway and sending a request message:

0 MCO:BGN:INIT NODE,CP=RNNNA--,VER=2.1.1
3 TSM:INIT
4 TSF:WUR:MS=0
11 TSM:INIT:TSP OK
13 TSM:INIT:STATID=16
15 TSF:SID:OK,ID=16
17 TSM:FPAR
53 TSF:MSG:SEND,16-16-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
438 TSF:MSG:READ,0-0-16,s=255,c=3,t=8,pt=1,l=1,sg=0:0
443 TSF:MSG:FPAR OK,ID=0,D=1
513 TSF:MSG:READ,4-4-16,s=255,c=3,t=8,pt=1,l=1,sg=0:1
2060 TSM:FPAR:OK
2061 TSM:ID
2062 TSM:ID:OK
2064 TSM:UPL
2067 TSF:MSG:SEND,16-16-0-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=OK:1
2077 TSF:MSG:READ,0-0-16,s=255,c=3,t=25,pt=1,l=1,sg=0:1
2082 TSF:MSG:PONG RECV,HP=1
2085 TSM:UPL:OK
2086 TSM:READY:ID=16,PAR=0,DIS=1
2092 TSF:MSG:SEND,16-16-0-0,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=OK:0100
2099 TSF:MSG:READ,0-0-16,s=255,c=3,t=15,pt=6,l=2,sg=0:0100
2106 TSF:MSG:SEND,16-16-0-0,s=255,c=0,t=17,pt=0,l=5,sg=0,ft=0,st=OK:2.1.1
2115 TSF:MSG:SEND,16-16-0-0,s=255,c=3,t=6,pt=1,l=1,sg=0,ft=0,st=OK:0
4123 TSF:MSG:SEND,16-16-0-0,s=255,c=3,t=11,pt=0,l=12,sg=0,ft=0,st=OK:Energy Meter
4132 TSF:MSG:SEND,16-16-0-0,s=255,c=3,t=12,pt=0,l=3,sg=0,ft=0,st=OK:1.0
4141 TSF:MSG:SEND,16-16-0-0,s=1,c=0,t=13,pt=0,l=0,sg=0,ft=0,st=OK:
4147 MCO:REG:REQ
4151 TSF:MSG:SEND,16-16-0-0,s=255,c=3,t=26,pt=1,l=1,sg=0,ft=0,st=OK:2
4169 TSF:MSG:READ,0-0-16,s=255,c=3,t=27,pt=1,l=1,sg=0:1
4174 MCO:PIM:NODE REG=1
4177 MCO:BGN:STP
4180 TSF:MSG:SEND,16-16-0-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK:
4187 MCO:BGN:INIT OK,TSP=1
14189 TSF:MSG:SEND,16-16-0-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK:

sundberg84

@Samuel235 - My logs from the node:

Not working:

0 MCO:BGN:INIT NODE,CP=RNNNA--,VER=2.1.0
4 TSM:INIT
4 TSF:WUR:MS=0
12 TSM:INIT:TSP OK
14 TSM:INIT:STATID=8
16 TSF:SID:OK,ID=8
18 TSM:FPAR
55 TSF:MSG:SEND,8-8-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
2062 !TSM:FPAR:NO REPLY
2064 TSM:FPAR
2101 TSF:MSG:SEND,8-8-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
2738 TSF:MSG:READ,100-100-8,s=255,c=3,t=8,pt=1,l=1,sg=0:1
2744 TSF:MSG:FPAR OK,ID=100,D=2
4110 TSM:FPAR:OK
4110 TSM:ID
4112 TSM:ID:OK
4114 TSM:UPL
4122 TSF:MSG:SEND,8-8-100-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=OK:1
6131 TSM:UPL
6135 TSF:MSG:SEND,8-8-100-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=OK:1
8146 TSM:UPL
8148 TSF:MSG:SEND,8-8-100-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=OK:1
10158 TSM:UPL
10166 TSF:MSG:SEND,8-8-100-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=OK:1
12175 !TSM:UPL:FAIL
12177 TSM:FPAR
12214 TSF:MSG:SEND,8-8-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
14221 !TSM:FPAR:NO REPLY
14223 TSM:FPAR
14260 TSF:MSG:SEND,8-8-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
16269 !TSM:FPAR:NO REPLY
16271 TSM:FPAR
16308 TSF:MSG:SEND,8-8-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
18317 !TSM:FPAR:NO REPLY
18319 TSM:FPAR
18356 TSF:MSG:SEND,8-8-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
20365 !TSM:FPAR:FAIL
20367 TSM:FAIL:CNT=1
20369 TSM:FAIL:PDT
30373 TSM:FAIL:RE-INIT
30375 TSM:INIT
30384 TSM:INIT:TSP OK
30386 TSM:INIT:STATID=8
30388 TSF:SID:OK,ID=8
30390 TSM:FPAR
30427 TSF:MSG:SEND,8-8-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
31139 TSF:MSG:READ,100-100-8,s=255,c=3,t=8,pt=1,l=1,sg=0:1
31148 TSF:MSG:FPAR OK,ID=100,D=2
32436 TSM:FPAR:OK
32438 TSM:ID
32438 TSM:ID:OK
32440 TSM:UPL
32444 TSF:MSG:SEND,8-8-100-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=OK:1
34453 TSM:UPL
34457 TSF:MSG:SEND,8-8-100-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=OK:1
36466 TSM:UPL
36468 TSF:MSG:SEND,8-8-100-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=OK:1
36501 TSF:MSG:READ,0-100-8,s=255,c=3,t=25,pt=1,l=1,sg=0:2
36507 TSF:MSG:PONG RECV,HP=2
36509 TSM:UPL:OK
36511 TSM:READY:ID=8,PAR=100,DIS=2
36517 TSF:MSG:SEND,8-8-100-0,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=OK:0100
38531 TSF:MSG:SEND,8-8-100-0,s=255,c=0,t=17,pt=0,l=5,sg=0,ft=0,st=OK:2.1.0
38545 TSF:MSG:SEND,8-8-100-0,s=255,c=3,t=6,pt=1,l=1,sg=0,ft=0,st=OK:100
40597 !TSF:MSG:SEND,8-8-100-0,s=255,c=3,t=11,pt=0,l=15,sg=0,ft=0,st=NACK:Energy Meter #8
40607 TSF:MSG:SEND,8-8-100-0,s=255,c=3,t=12,pt=0,l=3,sg=0,ft=1,st=OK:1.4
40617 TSF:MSG:SEND,8-8-100-0,s=1,c=0,t=10,pt=0,l=0,sg=0,ft=0,st=OK:
40626 MCO:REG:REQ
40642 TSF:MSG:SEND,8-8-100-0,s=255,c=3,t=26,pt=1,l=1,sg=0,ft=0,st=OK:2
42655 TSF:MSG:SEND,8-8-100-0,s=255,c=3,t=26,pt=1,l=1,sg=0,ft=0,st=OK:2
44662 TSF:MSG:SEND,8-8-100-0,s=255,c=3,t=26,pt=1,l=1,sg=0,ft=0,st=OK:2
46684 TSF:MSG:SEND,8-8-100-0,s=255,c=3,t=26,pt=1,l=1,sg=0,ft=0,st=OK:2
48693 MCO:BGN:STP
49197 TSF:MSG:SEND,8-8-100-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK:
49203 MCO:BGN:INIT OK,TSP=1
54216 TSF:MSG:SEND,8-8-100-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK:
59217 TSF:MSG:SEND,8-8-100-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK:
64219 TSF:MSG:SEND,8-8-100-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK:
69208 TSF:MSG:SEND,8-8-100-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK:
74211 TSF:MSG:SEND,8-8-100-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK:
79210 TSF:MSG:SEND,8-8-100-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK:
84224 TSF:MSG:SEND,8-8-100-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK:
89214 TSF:MSG:SEND,8-8-100-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK:
94214 TSF:MSG:SEND,8-8-100-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK:
99215 TSF:MSG:SEND,8-8-100-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK:
104216 TSF:MSG:SEND,8-8-100-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK:
... Continues

Working:

0 MCO:BGN:INIT NODE,CP=RNNNA--,VER=2.1.0
4 TSM:INIT
4 TSF:WUR:MS=0
12 TSM:INIT:TSP OK
14 TSM:INIT:STATID=8
16 TSF:SID:OK,ID=8
18 TSM:FPAR
55 TSF:MSG:SEND,8-8-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
1013 TSF:MSG:READ,0-0-8,s=255,c=3,t=8,pt=1,l=1,sg=0:0
1019 TSF:MSG:FPAR OK,ID=0,D=1
1212 TSF:MSG:READ,99-99-8,s=255,c=3,t=8,pt=1,l=1,sg=0:1
1630 TSF:MSG:READ,100-100-8,s=255,c=3,t=8,pt=1,l=1,sg=0:1
2062 TSM:FPAR:OK
2062 TSM:ID
2064 TSM:ID:OK
2066 TSM:UPL
2103 !TSF:MSG:SEND,8-8-0-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=NACK:1
4112 TSM:UPL
4122 TSF:MSG:SEND,8-8-0-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=1,st=OK:1
4141 TSF:MSG:READ,0-0-8,s=255,c=3,t=25,pt=1,l=1,sg=0:1
4147 TSF:MSG:PONG RECV,HP=1
4149 TSM:UPL:OK
4151 TSM:READY:ID=8,PAR=0,DIS=1
4190 !TSF:MSG:SEND,8-8-0-0,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=NACK:0100
4198 TSF:MSG:READ,0-0-8,s=255,c=3,t=15,pt=6,l=2,sg=0:0100
4206 TSF:MSG:SEND,8-8-0-0,s=255,c=0,t=17,pt=0,l=5,sg=0,ft=1,st=OK:2.1.0
4218 TSF:MSG:SEND,8-8-0-0,s=255,c=3,t=6,pt=1,l=1,sg=0,ft=0,st=OK:0
5181 TSF:MSG:READ,0-0-8,s=255,c=3,t=6,pt=0,l=1,sg=0:M
5193 TSF:MSG:SEND,8-8-0-0,s=255,c=3,t=11,pt=0,l=15,sg=0,ft=0,st=OK:Energy Meter #8
5208 TSF:MSG:SEND,8-8-0-0,s=255,c=3,t=12,pt=0,l=3,sg=0,ft=0,st=OK:1.4
5234 TSF:MSG:SEND,8-8-0-0,s=1,c=0,t=10,pt=0,l=0,sg=0,ft=0,st=OK:
5242 MCO:REG:REQ
5249 TSF:MSG:SEND,8-8-0-0,s=255,c=3,t=26,pt=1,l=1,sg=0,ft=0,st=OK:2
5277 TSF:MSG:READ,0-0-8,s=255,c=3,t=27,pt=1,l=1,sg=0:1
5283 MCO:PIM:NODE REG=1
5285 MCO:BGN:STP
5795 TSF:MSG:SEND,8-8-0-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK:
5804 MCO:BGN:INIT OK,TSP=1
10819 TSF:MSG:SEND,8-8-0-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK:
11212 TSF:MSG:READ,0-0-8,s=1,c=2,t=24,pt=0,l=8,sg=0:21911518
Received last pulse count from gw:21911518
11220 MCO:SLP:MS=780000,SMS=0,I1=255,M1=255,I2=255,M2=255
11229 MCO:SLP:TPD

As seen in the first logs the node is also struggling with finding its parent (No reply) so my guess so far (as always) is the radio. But what bothers me is that the first logs uses a repeater and it doesnt work (because of that?)

But we need simultanoius logs from GW and node atleast (and repeater in my case).

Samuel235

@sundberg84 - I have a fix for mine.

My issue was simply that it was asking for a value that wasn't there. If i manually put the value on the mqtt topic, then the node starts working beautifully (from what i can see).

I, however, doubt that is your case though as its working without the repeater. I now need to solve the reason why the value is not 0 if there has been no input, instead its just empty. I will take a look into how OpenHAB needs to define a 0 by default.

I will attempt to help your issue though still if you want me too, not sure how much help i can be though....

Samuel235

I will report back with my solution for the OpenHAB value fix soon as i find out.

sundberg84

@Samuel235 - it's most likely my radio with range/power issues but the node communication works 100% except for this... i will continue investigate.

Samuel235

If you turn the node off and then grab the serial output from all 3 (GW, Repeater and Node) while you power the node up and then drop them in here, i will be a second pair of eyes for you :)

sundberg84

@Samuel235 - that has been my main problem - how to grab serial output for three nodes at different locations at the same time :) but thank you! I appreciate it and will do as soon as i have it.

Samuel235

@sundberg84 - TBH, i would be tempted to do it in two phases, not as accurate but should be good enough.

If you have a laptop and a desktop, i would have the gateway connected to one and the node connected to the other and then restart the node (leaving the gateway up) and then change the device the node is connected to and put it on the repeated and then restart the node. As we don't need to restart the gateway or the repeater really, just the node.

Does that make any sense?

gohan

@sundberg84 said in Node sending req packets constantly (Packet type 2 on MQTT):

@Samuel235 - that has been my main problem - how to grab serial output for three nodes at different locations at the same time :) but thank you! I appreciate it and will do as soon as i have it.

I guess this is where esp8266 come in handy with their remote debug :)

Samuel235

I'm still getting my issue, everytime i restart the node i must manually send a "0" on Gateway1-in/16/1/1/0/24. I've even attempted to have this as an item so persistence holds the value and that isn't working either....

Samuel235

I have posted a question regarding what i think could be the fix to my issue over at: https://community.openhab.org/t/push-state-of-one-mqtt-topic-to-another/27597

Not sure if it will become of anything though. If anyone else has any experience with MQTT and openhab2 over here, then please be sure to shout a thought. It seems that not many people have got this sketch to work with openhab, google searches are bringing up posts from a year or two ago made on our forum here regarding this issue with no clear/simple solution.

Node sending req packets constantly (Packet type 2 on MQTT)

15

11.7k

11.2k

113.1k