Node doesn't receive data from RPI MQTT Gateway

[evb]

@cvdenzen In case of troubleshooting, try to comment out the maximum of code, only the bare minimum of code should remain active.
Go back to the original code of the dimmer : https://www.mysensors.org/build/dimmer and test first if this sketch receives the messages.

[cvdenzen]

No, the bare sketch (with only the necessary modifications, like NEW_DRIVER, NODE_ID etc.) does not receive the message.
I tried the bare sketch on two different pieces of hardware (an arduino mini pro and an easypirmultisensors2, which also is an 8 MHz avr).
The sketch:

/*
 * 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-2019 Sensnology AB
 * Full contributor list: https://github.com/mysensors/MySensors/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 - February 15, 2014 - Bruce Lacey
 * Version 1.1 - August 13, 2014 - Converted to 1.4 (hek)
 *
 * DESCRIPTION
 * This sketch provides a Dimmable LED Light using PWM and based Henrik Ekblad
 * <henrik.ekblad@gmail.com> Vera Arduino Sensor project.
 * Developed by Bruce Lacey, inspired by Hek's MySensor's example sketches.
 *
 * The circuit uses a MOSFET for Pulse-Wave-Modulation to dim the attached LED or LED strip.
 * The MOSFET Gate pin is connected to Arduino pin 3 (LED_PIN), the MOSFET Drain pin is connected
 * to the LED negative terminal and the MOSFET Source pin is connected to ground.
 *
 * This sketch is extensible to support more than one MOSFET/PWM dimmer per circuit.
 * http://www.mysensors.org/build/dimmer
 */

// Enable debug prints to serial monitor
#define MY_DEBUG
#define MY_BAUD_RATE 38400

// Enable and select radio type attached
//#define MY_RADIO_RF24
//#define MY_RADIO_NRF5_ESB
#define MY_RADIO_RFM69
//#define MY_RADIO_RFM95
// If using mysensors version<2.3.0 and want to use NEW DRIVER (OH SO BAD NAMING):
#define MY_RFM69_NEW_DRIVER
#define MY_RFM69_FREQUENCY   RFM69_868MHZ
#define MY_RFM69_NETWORKID 197// Comment it out for Auto Node ID #, original was 0x90=144
#define MY_NODE_ID 157
#include <MySensors.h>

#define SN "DimmableLED"
#define SV "1.1"

#define LED_PIN 3      // Arduino pin attached to MOSFET Gate pin
#define FADE_DELAY 10  // Delay in ms for each percentage fade up/down (10ms = 1s full-range dim)

static int16_t currentLevel = 0;  // Current dim level...
MyMessage dimmerMsg(0, V_DIMMER);
MyMessage lightMsg(0, V_LIGHT);


/***
 * Dimmable LED initialization method
 */
void setup()
{
	// Pull the gateway's current dim level - restore light level upon node power-up
	request( 0, V_DIMMER );
}

void presentation()
{
	// Register the LED Dimmable Light with the gateway
	present( 0, S_DIMMER );

	sendSketchInfo(SN, SV);
}

/***
 *  Dimmable LED main processing loop
 */
void loop()
{
}



void receive(const MyMessage &message)
{
   Serial.print( "Received a message! (node 157)" );
	if (message.getType() == V_LIGHT || message.getType() == V_DIMMER) {

		//  Retrieve the power or dim level from the incoming request message
		int requestedLevel = atoi( message.data );

		// Adjust incoming level if this is a V_LIGHT variable update [0 == off, 1 == on]
		requestedLevel *= ( message.getType() == V_LIGHT ? 100 : 1 );

		// Clip incoming level to valid range of 0 to 100
		requestedLevel = requestedLevel > 100 ? 100 : requestedLevel;
		requestedLevel = requestedLevel < 0   ? 0   : requestedLevel;

		Serial.print( "Changing level to " );
		Serial.print( requestedLevel );
		Serial.print( ", from " );
		Serial.println( currentLevel );

		fadeToLevel( requestedLevel );

		// Inform the gateway of the current DimmableLED's SwitchPower1 and LoadLevelStatus value...
		send(lightMsg.set(currentLevel > 0));

		// hek comment: Is this really nessesary?
		send( dimmerMsg.set(currentLevel) );


	}
}

/***
 *  This method provides a graceful fade up/down effect
 */
void fadeToLevel( int toLevel )
{

	int delta = ( toLevel - currentLevel ) < 0 ? -1 : 1;

	while ( currentLevel != toLevel ) {
		currentLevel += delta;
		analogWrite( LED_PIN, (int)(currentLevel / 100. * 255) );
		delay( FADE_DELAY );
	}
}

The mqtt invocation:

mqtt pub --host rpi3.home --mqttVersion 3 --topic 'carl/mysensors/157/0/1/0/3' --message 35

The mysgw logging:

Aug  9 22:20:04 rpi3 mysgw: GWT:IMQ:TOPIC=carl/mysensors/157/0/1/0/3, MSG RECEIVED
Aug  9 22:20:04 rpi3 mysgw: GWT:TPS:TOPIC=mysensors/all/0/157/0/1/0,MSG SENT

The logging from the easypirmultisensorsbox2 (nothing shows up when an MQTT message is sent to the MQTT broker):

 
 __  __       ____
|  \/  |_   _/ ___|  ___ _ __  ___  ___  _ __ ___
| |\/| | | | \___ \ / _ \ `_ \/ __|/ _ \| `__/ __|
| |  | | |_| |___| |  __/ | | \__ \  _  | |  \__ \
|_|  |_|\__, |____/ \___|_| |_|___/\___/|_|  |___/
        |___/                      2.3.2

51 MCO:BGN:INIT NODE,CP=RPNNA---,FQ=8,REL=255,VER=2.3.2
83 TSM:INIT
86 TSF:WUR:MS=0
92 TSM:INIT:TSP OK
96 TSM:INIT:STATID=157
102 TSF:SID:OK,ID=157
108 TSM:FPAR
116 ?TSF:MSG:SEND,157-157-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
425 TSF:MSG:READ,0-0-157,s=255,c=3,t=8,pt=1,l=1,sg=0:0
440 TSF:MSG:FPAR OK,ID=0,D=1
2138 TSM:FPAR:OK
2142 TSM:ID
2146 TSM:ID:OK
2150 TSM:UPL
2187 TSF:MSG:SEND,157-157-0-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=OK:1
2392 TSF:MSG:READ,0-0-157,s=255,c=3,t=25,pt=1,l=1,sg=0:1
2406 TSF:MSG:PONG RECV,HP=1
2414 TSM:UPL:OK
2418 TSM:READY:ID=157,PAR=0,DIS=1
2449 TSF:MSG:SEND,157-157-0-0,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=OK:0100
2656 TSF:MSG:READ,0-0-157,s=255,c=3,t=15,pt=6,l=2,sg=0:0100
2689 TSF:MSG:SEND,157-157-0-0,s=255,c=0,t=17,pt=0,l=5,sg=0,ft=0,st=OK:2.3.2
2723 TSF:MSG:SEND,157-157-0-0,s=255,c=3,t=6,pt=1,l=1,sg=0,ft=0,st=OK:0
4761 TSF:MSG:SEND,157-157-0-0,s=0,c=0,t=4,pt=0,l=0,sg=0,ft=0,st=OK:
4796 TSF:MSG:SEND,157-157-0-0,s=255,c=3,t=11,pt=0,l=11,sg=0,ft=0,st=OK:DimmableLED
4835 TSF:MSG:SEND,157-157-0-0,s=255,c=3,t=12,pt=0,l=3,sg=0,ft=0,st=OK:1.1
4855 MCO:REG:REQ
4870 TSF:MSG:SEND,157-157-0-0,s=255,c=3,t=26,pt=1,l=1,sg=0,ft=0,st=OK:2
5076 TSF:MSG:READ,0-0-157,s=255,c=3,t=27,pt=1,l=1,sg=0:1
5093 MCO:PIM:NODE REG=1
5099 MCO:BGN:STP
5122 TSF:MSG:SEND,157-157-0-0,s=0,c=2,t=3,pt=0,l=0,sg=0,ft=0,st=OK:
5140 MCO:BGN:INIT OK,TSP=1

[cvdenzen]

Is the mysgw output looking good? The sent message doesn”t include the message type (3). Has anybody tested this with a topic that contains a slash?

[evb]

@cvdenzen I don't have experience with a Raspberry Pi as MQTT gateway, but your last remark about the slash is maybe a path to debug...

From the docs for a Arduino MQTT gateway:
The topic is build like this: MY_MQTT_PUBLISH_TOPIC_PREFIX/FROM-NODE-ID/SENSOR-ID/CMD-TYPE/ACK-FLAG/SUB-TYPE
Read more about the serial protocol here. An example topic for data received from your gateway could look like this:

mygateway1-out/2/1/1/0/49

If you want to send data to your sensors use MY_MQTT_SUBSCRIBE_TOPIC_PREFIX defined in your sketch. Should be looking like this (using default sketch):

mygateway1-in/2/1/1/0/49

Can you try to change your mqtt topic build?

[cvdenzen]

@evb It took some time (have also another home renovation project), but now I have set up a test gateway.
The mqtt topic with a slash in its name seems to be the problem. I changed the mqtt topic to mysensorsa and now the sketch receives the message. The mqtt gateway outputs:

Aug 15 22:50:33 DEBUG GWT:IMQ:TOPIC=mysensorsa/157/0/1/0/3, MSG RECEIVED
Aug 15 22:50:33 DEBUG TSF:MSG:SEND,0-0-157-157,s=0,c=1,t=3,pt=0,l=2,sg=0,ft=0,st=OK:35
Aug 15 22:50:34 DEBUG TSF:MSG:READ,157-157-0,s=0,c=1,t=2,pt=1,l=1,sg=0:1
Aug 15 22:50:34 DEBUG GWT:TPS:TOPIC=mysensors/all/157/0/1/0/2,MSG SENT
Aug 15 22:50:34 DEBUG TSF:MSG:READ,157-157-0,s=0,c=1,t=3,pt=2,l=2,sg=0:35
Aug 15 22:50:34 DEBUG GWT:TPS:TOPIC=mysensors/all/157/0/1/0/3,MSG SENT

I will have a look at the MySensors code and if I cannot find the problem, maybe I will change my mqtt subscription topic.

[cvdenzen]

@cvdenzen
I have added a GATEWAY_DEBUG line in core/MyProtocol.cpp at line 122:

	for (str = strtok_r(topic + strlen(MY_MQTT_SUBSCRIBE_TOPIC_PREFIX) + 1, "/", &p);
	        str && index < 5;
	        str = strtok_r(NULL, "/", &p), index++
	    ) {
	    GATEWAY_DEBUG(PSTR("GWT:TPS:Index=%d, mqttstr=%s\n"), str);

My conclusion is that the length of the mqtt subscription topic is the problem. The first call shows that it thinks "rs" is part of the topic beyond the PREFIX. And "rs" gets translated to "0" in the outgoing mqtt message, shifting the real items one position further and dropping the last item.
Later on I will have a look at the cause of this limitation (or maybe someone else is quicker than I am).
The output of mysgw, first try is with topic carl/mysensors, second try (that succeeds) is with mqtt topic c/mysensors:

Aug 15 23:53:19 DEBUG GWT:TPS:TOPIC=mysensors/all/157/255/3/0/21,MSG SENT
Aug 15 23:53:24 DEBUG GWT:IMQ:TOPIC=carl/mysensors/157/0/1/0/3, MSG RECEIVED
Aug 15 23:53:24 DEBUG GWT:TPS:Index=0, mqttstr=rs
Aug 15 23:53:24 DEBUG GWT:TPS:Index=1, mqttstr=157
Aug 15 23:53:24 DEBUG GWT:TPS:Index=2, mqttstr=0
Aug 15 23:53:24 DEBUG GWT:TPS:Index=3, mqttstr=1
Aug 15 23:53:24 DEBUG GWT:TPS:Index=4, mqttstr=0
Aug 15 23:53:24 DEBUG GWT:TPS:TOPIC=mysensors/all/0/157/0/1/0,MSG SENT
Aug 15 23:54:42 DEBUG GWT:IMQ:TOPIC=c/mysensors/157/0/1/0/3, MSG RECEIVED
Aug 15 23:54:42 DEBUG GWT:TPS:Index=0, mqttstr=157
Aug 15 23:54:42 DEBUG GWT:TPS:Index=1, mqttstr=0
Aug 15 23:54:42 DEBUG GWT:TPS:Index=2, mqttstr=1
Aug 15 23:54:42 DEBUG GWT:TPS:Index=3, mqttstr=0
Aug 15 23:54:42 DEBUG GWT:TPS:Index=4, mqttstr=3
Aug 15 23:54:42 DEBUG TSF:MSG:SEND,0-0-157-157,s=0,c=1,t=3,pt=0,l=2,sg=0,ft=0,st=OK:35
Aug 15 23:54:42 DEBUG TSF:MSG:READ,157-157-0,s=0,c=1,t=2,pt=1,l=1,sg=0:1
Aug 15 23:54:42 DEBUG GWT:TPS:TOPIC=mysensors/all/157/0/1/0/2,MSG SENT

[cvdenzen]

The problem is clear: the subscription topic that I use contains a wildcard: “+/mysensors”.
I send my message with prefix “carl/mysensors”.
The MySensors code assumes the length of the prefix I send is the same as the length of the subscription prefix. But it isn’t because of the wildcard character.
Is there anybody who likes to change the code to make it work? Or should I try it myself?
I see two possible solutions:

1. Parse the message from end to begin and not from begin to end.
2. Try to match the wildcard character(s) with the sent string.

[cvdenzen]

I have made some modifications to the code, tested it and it seems to work.
There is a pull request https://github.com/mysensors/MySensors/pull/1497 but I don't know how this will be handled by the MySensors developers.

Can anybody give me a link or some information about the development process? A review of my code will be necessary, I am not a C programmer.

[mfalkvidd]

Contribution guidelines are available at https://www.mysensors.org/download/contributing

[cvdenzen]

@mfalkvidd Thank you for the link. I followed the instructions, had to download/compile some packages.
It will take some time for me, I have to solve this error:

 git commit -m "Accept wildcards in mqtt subscription prefix"
cppcheck: Failed to load library configuration file 'std.cfg'. File not found
cppcheck: Failed to load library configuration file 'avr'. File not found
nofile:0:0: information: Failed to load the library avr [failedToLoadCfg]

Few minutes later, resolved, had to add CFGDIR to make cppcheck:

sudo make install FILESDIR=/usr/share/cppcheck CFGDIR=/usr/share/cppcheck

[cvdenzen]

It seems like building MySensors with my edit failed but I don’t understand the error messages.
The first error: https://ci.mysensors.org/job/MySensors/job/MySensors/job/PR-1497/2/warnings2Result/new/file.702256833/source.9006459693321295180/#1

[mfalkvidd]

@cvdenzen I don't understand the build system, but I have permission to restart builds. Sometimes that helps. I've restarted the build for your PR. Hopefully we'll get a better result this time.

[mfalkvidd]

https://ci.mysensors.org/job/MySensors/job/MySensors/job/PR-1497/3/warnings2Result/new/#1 looks better now

[cvdenzen]

@mfalkvidd Thank you!