Repeater getting NACK

flopp

7935368 TSF:MSG:SEND,7-7-0-0,s=3,c=1,t=37,pt=2,l=2,sg=0,ft=0,st=OK:1
7935375 TSF:MSG:SEND,7-7-0-0,s=251,c=1,t=55,pt=1,l=1,sg=0,ft=0,st=OK:0
7935383 TSF:MSG:SEND,7-7-0-0,s=252,c=1,t=55,pt=1,l=1,sg=0,ft=0,st=OK:1
7957760 TSF:MSG:READ,25-25-0,s=0,c=1,t=24,pt=5,l=4,sg=0:96637
7957766 TSF:MSG:REL MSG
7957806 !TSF:MSG:SEND,25-7-0-0,s=0,c=1,t=24,pt=5,l=4,sg=0,ft=0,st=NACK:96637
7987763 TSF:MSG:READ,25-25-0,s=0,c=1,t=34,pt=7,l=5,sg=0:0.01
7987768 TSF:MSG:REL MSG
7987808 TSF:MSG:SEND,25-7-0-0,s=0,c=1,t=34,pt=7,l=5,sg=0,ft=1,st=OK:0.01
7987819 TSF:MSG:READ,25-25-0,s=0,c=1,t=35,pt=7,l=5,sg=0:96.638
7987825 TSF:MSG:REL MSG
7987829 TSF:MSG:SEND,25-7-0-0,s=0,c=1,t=35,pt=7,l=5,sg=0,ft=0,st=OK:96.638
7995427 TSF:MSG:SEND,7-7-0-0,s=1,c=1,t=0,pt=7,l=5,sg=0,ft=0,st=OK:12.6
7995441 TSF:MSG:SEND,7-7-0-0,s=0,c=1,t=4,pt=7,l=5,sg=0,ft=0,st=OK:1026.2
7995449 TSF:MSG:SEND,7-7-0-0,s=2,c=1,t=1,pt=7,l=5,sg=0,ft=0,st=OK:43
7995462 TSF:MSG:SEND,7-7-0-0,s=4,c=1,t=0,pt=7,l=5,sg=0,ft=0,st=OK:0.4
7995472 TSF:MSG:SEND,7-7-0-0,s=3,c=1,t=37,pt=2,l=2,sg=0,ft=0,st=OK:1
7995481 TSF:MSG:SEND,7-7-0-0,s=251,c=1,t=55,pt=1,l=1,sg=0,ft=0,st=OK:0
7995488 TSF:MSG:SEND,7-7-0-0,s=252,c=1,t=55,pt=1,l=1,sg=0,ft=0,st=OK:1
8017766 TSF:MSG:READ,25-25-0,s=0,c=1,t=24,pt=5,l=4,sg=0:96638
8017771 TSF:MSG:REL MSG
8017811 !TSF:MSG:SEND,25-7-0-0,s=0,c=1,t=24,pt=5,l=4,sg=0,ft=0,st=NACK:96638
8047768 TSF:MSG:READ,25-25-0,s=0,c=1,t=24,pt=5,l=4,sg=0:96638
8047774 TSF:MSG:REL MSG
8047813 !TSF:MSG:SEND,25-7-0-0,s=0,c=1,t=24,pt=5,l=4,sg=0,ft=1,st=NACK:96638
8055533 TSF:MSG:SEND,7-7-0-0,s=1,c=1,t=0,pt=7,l=5,sg=0,ft=2,st=OK:12.7

above is the DEBUG from my repeater.

Node 25 is a water meter. Is looks like when the value is same as already sent, Gateway or controller is not accepting the value, but as soon as there is a new value is get OK.

Anyone that seen this or can explain why this happens?

zboblamont

@flopp Normally the Node should only send in if triggered by the meter to increment anyway, so no experience of the instance you describe.
I do know however that Domoticz will only accept a higher cumulative reading for a meter, as I had glibly configured the gas reading as an Int little realising that when it maxed out X months later, it rolled over to minus.:dizzy_face:
Presumably an identical reading would be likewise rejected...

mfalkvidd

@flopp said in Repeater getting NACK:

Is looks like when the value is same as already sent, Gateway or controller is not accepting the value

I can't see anything in the posted log that supports this conclusion. Could you elaborate?

Could you grab a log from the repeater and node25 at the same time?
Could you post the sketch for node25?

Is node25 sending more data immediately after sending the meter reading? Maybe a second send causes a collision with the the message sent by the repeater.

flopp

@mfalkvidd said in Repeater getting NACK:

@flopp said in Repeater getting NACK:

Is looks like when the value is same as already sent, Gateway or controller is not accepting the value

I can't see anything in the posted log that supports this conclusion. Could you elaborate?

Node 7 can send and gets OK, but when Node 25 send its values it gets NACK.
When the value is new from Node 25 it gets OK

Could you grab a log from the repeater and node25 at the same time?

I will try

Could you post the sketch for node25?

Is node25 sending more data immediately after sending the meter reading? Maybe a second send causes a collision with the the message sent by the repeater.

/**
 * 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
 * Version 1.1 - GizMoCuz
 *
 * DESCRIPTION
 * Use this sensor to measure volume and flow of your house watermeter.
 * You need to set the correct pulsefactor of your meter (pulses per m3).
 * The sensor starts by fetching current volume reading from gateway (VAR 1).
 * Reports both volume and flow 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 flow.
 * http://www.mysensors.org/build/pulse_water
 */

// Enable debug prints to serial monitor
#define MY_DEBUG

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

#include <MySensors.h>

#define DIGITAL_INPUT_SENSOR 2                  // The digital input you attached your sensor.  (Only 2 and 3 generates interrupt!)

#define PULSE_FACTOR 1000                       // Nummber of blinks per m3 of your meter (One rotation/liter)

#define SLEEP_MODE false                        // flowvalue can only be reported when sleep mode is false.

#define MAX_FLOW 40                             // Max flow (l/min) value to report. This filters outliers.

#define CHILD_ID 0                              // Id of the sensor child

uint32_t SEND_FREQUENCY =
    30000;           // Minimum time between send (in milliseconds). We don't want to spam the gateway.

MyMessage flowMsg(CHILD_ID,V_FLOW);
MyMessage volumeMsg(CHILD_ID,V_VOLUME);
MyMessage lastCounterMsg(CHILD_ID,V_VAR1);

double ppl = ((double)PULSE_FACTOR)/1000;        // Pulses per liter

volatile uint32_t pulseCount = 0;
volatile uint32_t lastBlink = 0;
volatile double flow = 0;
bool pcReceived = false;
uint32_t oldPulseCount = 0;
uint32_t newBlink = 0;
double oldflow = 0;
double volume =0;
double oldvolume =0;
uint32_t lastSend =0;
uint32_t lastPulse =0;

void setup()
{
	// initialize our digital pins internal pullup resistor so one pulse switches from high to low (less distortion)
	pinMode(DIGITAL_INPUT_SENSOR, INPUT_PULLUP);

	pulseCount = oldPulseCount = 0;

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

	lastSend = lastPulse = millis();

	attachInterrupt(digitalPinToInterrupt(DIGITAL_INPUT_SENSOR), onPulse, FALLING);
}

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

	// Register this device as Waterflow sensor
	present(CHILD_ID, S_WATER);
}

void loop()
{
	uint32_t currentTime = millis();

	// Only send values at a maximum frequency or woken up from sleep
	if (SLEEP_MODE || (currentTime - lastSend > SEND_FREQUENCY)) {
		lastSend=currentTime;

		if (!pcReceived) {
			//Last Pulsecount not yet received from controller, request it again
			request(CHILD_ID, V_VAR1);
			return;
		}

		if (!SLEEP_MODE && flow != oldflow) {
			oldflow = flow;

			Serial.print("l/min:");
			Serial.println(flow);

			// Check that we dont get unresonable large flow value.
			// could hapen when long wraps or false interrupt triggered
			if (flow<((uint32_t)MAX_FLOW)) {
				send(flowMsg.set(flow, 2));                   // Send flow value to gw
			}
		}

		// No Pulse count received in 2min
		if(currentTime - lastPulse > 120000) {
			flow = 0;
		}

		// Pulse count has changed
		if ((pulseCount != oldPulseCount)||(!SLEEP_MODE)) {
			oldPulseCount = pulseCount;

			Serial.print("pulsecount:");
			Serial.println(pulseCount);

			send(lastCounterMsg.set(pulseCount));                  // Send  pulsecount value to gw in VAR1

			double volume = ((double)pulseCount/((double)PULSE_FACTOR));
			if ((volume != oldvolume)||(!SLEEP_MODE)) {
				oldvolume = volume;

				Serial.print("volume:");
				Serial.println(volume, 3);

				send(volumeMsg.set(volume, 3));               // Send volume value to gw
			}
		}
	}
	if (SLEEP_MODE) {
		sleep(SEND_FREQUENCY);
	}
}

void receive(const MyMessage &message)
{
	if (message.type==V_VAR1) {
		uint32_t gwPulseCount=message.getULong();
		pulseCount += gwPulseCount;
		flow=oldflow=0;
		Serial.print("Received last pulse count from gw:");
		Serial.println(pulseCount);
		pcReceived = true;
	}
}

void onPulse()
{
	if (!SLEEP_MODE) {
		uint32_t newBlink = micros();
		uint32_t interval = newBlink-lastBlink;

		if (interval!=0) {
			lastPulse = millis();
			if (interval<500000L) {
				// Sometimes we get interrupt on RISING,  500000 = 0.5sek debounce ( max 120 l/min)
				return;
			}
			flow = (60000000.0 /interval) / ppl;
		}
		lastBlink = newBlink;
	}
	pulseCount++;
}

mfalkvidd

@flopp said in Repeater getting NACK:

Node 7 can send and gets OK, but when Node 25 send its values it gets NACK.
When the value is new from Node 25 it gets OK

Thanks for clarifying. I don't understand though. What do you mean by "value is new"?

flopp

This is a water counter node.
It will send the value every 2 minutes, even if there isn’t a new value.
But when we use water it will be a increased value, then I get OK from Controller.

mfalkvidd

@flopp I can't find anything in the log you posted that supports what you are saying.

At timestamp 8017766, the repeater receives the value 96638 from node 25 for the first time 
At timestamp 8017811 (45 ms after 8017766), the repeater tries to forward the value 96638 to the gateway for the first time but doesn't get hardware ack
At timestamp 8047768 (2 ms after 8017766), the repeater receives the value 96638 from node 25 for the second time
At timestamp 8047813, the repeater tries to forward the value 96638 to the gateway for the second time but doesn't get hardware ack

So the repeater doesn't get hardware ack when the value is received for the first time, and it doesn't get ack when the value is received the second time either.

Note: A controller will never send a MySensors hardware ack. Only MySensors nodes (gateway nodes, repeater nodes and sensor nodes) send hardware ack.

FlyingDomotic

I'll try to summarize, I do apologies if I didn't understand well:

It seems that node 7 is properly discussing with gateway as soon as data is local,
It seems that node 7 is not working properly when relaying data just received,
It could also be possible that the second time node 25 sends the message, this may be due to not getting hardware ACK from node 7 to the sent message (remind that send timeout is 1500 ns, not so far from the 2 ms). Having a look to node 25 log could confirm this, showing a send ending with a NACK.

To fix the repeat of node 25, I would suggest adding a delay after receiving the message and before sending it to the gateway.

IMHO, when waiting for some time (1500 ns would be theoretically perfect giving current MySensors settings) after a write will cause issue for nodes that will write an answer to you, as you're still waiting after the original write, so you may think about waiting this delay before and after the write (the first one will ensure that the sender finished waiting for the ACK you sent to its write, the second one you received the ACK to your write).

As side effect, this could also fix the relay issue, as we're not protected against chance ;-)

flopp

Thanks for all answers.

Node 25 send its value every 30 second (before I said every 2 minutes)

So my conclusion is that GW is not sending ACK back to my repeater.

value 96637 has already been sent before so GW will not send ACK

7957760 TSF:MSG:READ,25-25-0,s=0,c=1,t=24,pt=5,l=4,sg=0:96637
7957766 TSF:MSG:REL MSG
7957806 !TSF:MSG:SEND,25-7-0-0,s=0,c=1,t=24,pt=5,l=4,sg=0,ft=0,st=NACK:96637

30 seconds later, now Node 25 sends new values(96638) that is different since last send, so this time GW will send ACK

7987763 TSF:MSG:READ,25-25-0,s=0,c=1,t=34,pt=7,l=5,sg=0:0.01
7987768 TSF:MSG:REL MSG
7987808 TSF:MSG:SEND,25-7-0-0,s=0,c=1,t=34,pt=7,l=5,sg=0,ft=1,st=OK:0.01
7987819 TSF:MSG:READ,25-25-0,s=0,c=1,t=35,pt=7,l=5,sg=0:96.638
7987825 TSF:MSG:REL MSG
7987829 TSF:MSG:SEND,25-7-0-0,s=0,c=1,t=35,pt=7,l=5,sg=0,ft=0,st=OK:96.638

30 seconds later, same values so GW will not send ACK

8017766 TSF:MSG:READ,25-25-0,s=0,c=1,t=24,pt=5,l=4,sg=0:96638
8017771 TSF:MSG:REL MSG
8017811 !TSF:MSG:SEND,25-7-0-0,s=0,c=1,t=24,pt=5,l=4,sg=0,ft=0,st=NACK:96638

30 seconds later, same values so GW will not send ACK

8047768 TSF:MSG:READ,25-25-0,s=0,c=1,t=24,pt=5,l=4,sg=0:96638
8047774 TSF:MSG:REL MSG
8047813 !TSF:MSG:SEND,25-7-0-0,s=0,c=1,t=24,pt=5,l=4,sg=0,ft=1,st=NACK:96638

or can it be that when it sends two values it will be ACK fro GW?

look at 7987763, this value is water flow
at 8017766 it is only the incremental value for my water meter, no flow is sent

FlyingDomotic

Ad=s far I understand, we're speaking about radio ACK, which just confirm the right reception on the message, what could be sent. Then, that's gateway that can understand message contents.

If senders returns NACK, it just means that no radio ACK has been received from the other end within timeout (set to 1500 ms with MySensors' setup, running @ 250 kb/s, with 15 retries). That's exactly what happens when sending message and receiver off.

In the current issue, as you're on a repeater, you're in a good position to be in a position of receiving a message, and sending immediately another one (we can also have the same thing if implementing signature), were timing issues may happen.

Repeater getting NACK

17

11.7k

11.2k

113.1k