RF bridge code learn problem

[xoseperez]

Originally reported by: skorc99 (Bitbucket: skorc99, GitHub: skorc99)

---

Hello,#

i tested again new version HW different way..

1.) erased flash -OK

2.) OFF rf

3.) flashed latest version

4. ) MQTT off

   DOMOTICZ off

5.) Learned CODES - all OK

rebooted

All codes stored... after reboot...

6.) MQTT ON
DOMOTICZ ON

saved...

after step 6 RF bridge stopped sending RF codes and i can not turn off MQTT ...

I think MQTT is the issue...

U

[xoseperez]

The latest version in the dev branch enqueues the RF messages and sends them using a ticker so they don't interfere with other modules (like MQTT). Can you try it to see if it solves the issue?

[xoseperez]

Original comment by skorc99 (Bitbucket: skorc99, GitHub: skorc99):

---

Hello,

now it is sending RF codes and also learn is working.

One issue still remains- after MQTT and DOMOTICZ are enabled it is not possible to save changes - i try to add IDX number but it is not saved.

I will reflash and first add all IDX, RF codes and after that is saved i will try to enable MQTT ...

U

[xoseperez]

I am not experiencing this. With MQTT connected and Domoticz enabled I can save IDX and after reboot they are still there... Serial debug is disabled for RFBridge but you can still connect to it via telnet and read the messages. Maybe you can copy here part of the debug log (saving changes from web ui, turning on/off a switch,...)

[xoseperez]

Original comment by skorc99 (Bitbucket: skorc99, GitHub: skorc99):

---

hello,

Rf bridge worked and all settigs were saved till i turned on MQTT..

ON/OFF from web also not working any more- no red light RF... after MQTT enabled...

i will try to telnet and send messeges...

U

[xoseperez]

Original comment by Iván Conde (Bitbucket: ciconde, GitHub: Unknown):

---

Similar here with a Sonoff S20 and latest firware and mosquitto broker.

Everything is working fine until I enable MQTT.
A few seconds after that, equipment reboots twice and seems to go to "unsafe os".

By the way and thus any changes not saved after enabling MQTT and getting resetted are lost.

Even more, as webpage is on explorer's cache, after reset it seems operative, because websocket fail to send config doesn't cause any visible error. I think the webpage should warn when unable to communicate with device, but that is another topic.

Debug by telnet (no serial available right now)

[MQTT] Connecting to broker at 192.168.11.216:1883
[MQTT] Will topic: S20-01/status
[MQTT] QoS: 0
[MQTT] Retain flag: 1
[MQTT] Connected!
[MQTT] Sending S20-01/app => ESPURNA (PID 1)
[MQTT] Sending S20-01/version => 1.10.1 (PID 1)
[MQTT] Sending S20-01/host => S20-01 (PID 1)
[MQTT] Sending S20-01/ip => 192.168.11.153 (PID 1)
[MQTT] Sending S20-01/mac => DC:4F:22:11:46:9C (PID 1)
[MQTT] Sending S20-01/rssi => -39 (PID 1)
[MQTT] Sending S20-01/uptime => 1007 (PID 1)
[MQTT] Sending S20-01/freeheap => 18304 (PID 1)
[MQTT] Sending S20-01/relay/0 => 0 (PID 1)
[MQTT] Sending S20-01/vcc => 3133 (PID 1)
[MQTT] Sending S20-01/status => 1 (PID 1)
[MAIN] Time: Not set
[MQTT] Unsubscribing to # (PID 1)
[MQTT] Subscribing to S20-01/relay/+/set (PID 2)
[MQTT] Subscribing to switch (PID 3)
[MQTT] Subscribing to S20-01/led/+/set (PID 4)
[MQTT] Subscribing to S20-01/action/set (PID 5)
[MQTT] Subscribing to domoticz/out (PID 6)
[HA] Sending autodiscovery MQTT message
[MQTT] Sending homeassistant/switch/S20-01/config =>  (PID 1)
[MQTT] Sending S20-01/status => 1 (PID 1)
[MQTT] Subscribe ACK for PID 2
[MQTT] Subscribe ACK for PID 3
[MQTT] Received switch => 0 - SKIPPED
[MQTT] Subscribe ACK for PID 4
[MQTT] Subscribe ACK for PID 5
[MQTT] Subscribe ACK for PID 6

Unid did a reset cycle after that, and then died until hard reset.

[xoseperez]

Original comment by skorc99 (Bitbucket: skorc99, GitHub: skorc99):

---

My debug-all ok until MQTT enabled.

After that i could not save changes and no output with telnet...

#!arduino

[TELNET] Client #0 connected
[MAIN] System OK
[WEBSOCKET] Requested action: rfblea    rn
[RFBRIDGE] Sending LEARN
[RFBRIDGE] Action 0xA0
[RFBRIDGE] Action 0xA3
[RFBRIDGE]     Sending ACK
[RFBRIDGE] Learn success
[RFBRIDGE] Storing 1-ON => '2AB2015E03FC1547    00'
[WEBSOCKET] Requested action: rfbsend
[RFBRIDGE] Storing 1-ON => '2AB2015E03FC    154700'
[WEBSOCKET] Requested action: rfblearn
[RFBRIDGE] Sending LEARN
[RFBRIDGE]     Action 0xA0
[RFBRIDGE] Action 0xA3
[RFBRIDGE] Sending ACK
[RFBRIDGE] Learn success
[    RFBRIDGE] Storing 2-ON => '2AB2015E0406154700'
[WEBSOCKET] Requested action: rfbs    end
[RFBRIDGE] Storing 2-ON => '2AB2015E0406154700'
[WEBSOCKET] Requested action:     rfblearn
[RFBRIDGE] Sending LEARN
[RFBRIDGE] Action 0xA0
[RFBRIDGE] Action 0xA3
[RFB    RIDGE] Sending ACK
[RFBRIDGE] Learn success
[RFBRIDGE] Storing 0-ON => '1BB201FE03    F2374735'
[WEBSOCKET] Requested action: rfbsend
[RFBRIDGE] Storing 0-ON => '1BB201    FE03F2374735'
[WEBSOCKET] Requested action: rfblearn
[RFBRIDGE] Sending LEARN
[RFBR    IDGE] Action 0xA0
[RFBRIDGE] Action 0xA3
[RFBRIDGE] Sending ACK
[RFBRIDGE] Learn su    ccess
[RFBRIDGE] Storing 0-OFF => '1B9E01FE03F23B8E45'
[WEBSOCKET] Requested actio    n: rfbsend
[RFBRIDGE] Storing 0-OFF => '1B9E01FE03F23B8E45'
[MAIN] Uptime: 300 sec    onds
[MAIN] Free heap: 15704 bytes
[MAIN] Power: 3210 mV
[MAIN] Time: 2017-12-28 15    :37:46
[WEBSOCKET] Requested action: relay
[RELAY] #0 scheduled ON in 0 ms
[RELAY] #0 set to ON
[RFBRIDGE] Sending MESSAGE '1BB201FE03F2374735' 4 time(s)
[RFBRIDGE] Action 0xA0
[RFBRIDGE] Action 0xA0
[RELAY] Saving mask: 1
[RFBRIDGE] Action 0xA0
[RFBRIDGE] Action 0xA0
[WEBSOCKET] Requested action: relay
[RELAY] #0 scheduled OFF in 0 ms
[RELAY] #0 set to OFF
[RFBRIDGE] Sending MESSAGE '1B9E01FE03F23B8E45' 4 time(s)
[RFBRIDGE] Action 0xA0
[RFBRIDGE] Action 0xA0
[RELAY] Saving mask: 0
[RFBRIDGE] Action 0xA0
[RFBRIDGE] Action 0xA0
[WEBSOCKET] #1 disconnected
[WEBSERVER] Request: GET /index.html
[WEBSERVER] Request: GET /index.html
[WEBSOCKET] #2 connected, ip: 192.168.200.178, url: /ws
[WEBSOCKET] Parsing configuration data
[NTP] Error: NTP server not reachable
[BUTTON] Pressed #0, event: 1
[NTP] Time: 2017-12-28 15:40:59
[MAIN] Uptime: 600 seconds
[MAIN] Free heap: 16768 bytes
[MAIN] Power: 3211 mV
[MAIN] Time: 2017-12-28 15:42:46
[WEBSOCKET] Parsing configuration data
[NTP] Error: NTP server not reachable
[MQTT] Connecting to broker at 192.168.200.164:1883
[MQTT] Will topic: ESPURNA_8F3878/status
[MQTT] QoS: 0
[MQTT] Retain flag: 1
[MQTT] Connected!
[MQTT] Unsubscribing to # (PID 1)
[MQTT] Subscribing to ESPURNA_8F3878/relay/+/set (PID 2)
[MQTT] Subscribing to ESPURNA_8F3878/led/+/set (PID 3)
[MQTT] Subscribing to ESPURNA_8F3878/action/set (PID 4)
[MQTT] Subscribing to ESPURNA_8F3878/rflearn/+/set (PID 5)
[MQTT] Subscribing to ESPURNA_8F3878/rfout/set (PID 6)
[MQTT] Subscribing to domoticz/out (PID 7)
[HA] Sending autodiscovery MQTT message
[MQTT] Sending homeassistant/switch/ESPURNA_8F3878/config =>  (PID 1)
[MQTT] Sending ESPURNA_8F3878/status => 1 (PID 1)
[MQTT] Sending ESPURNA_8F3878/app => ESPURNA (PID 1)
[MQTT] Sending ESPURNA_8F3878/version => 1.10.2b (PID 1)
[MQTT] Sending ESPURNA_8F3878/host => ESPURNA_8F3878 (PID 1)
[MQTT] Sending ESPURNA_8F3878/ip => 192.168.200.160 (PID 1)
[MQTT] Sending ESPURNA_8F3878/mac => 60:01:94:8F:38:78 (PID 1)
[MQTT] Sending ESPURNA_8F3878/rssi => -45 (PID 1)
[MQTT] Sending ESPURNA_8F3878/uptime => 618 (PID 1)
[MQTT] Sending ESPURNA_8F3878/datetime => Not set (PID 1)
[MQTT] Sending ESPURNA_8F3878/freeheap => 9904 (PID 1)
[MQTT] Sending ESPURNA_8F3878/relay/0 => 0 (PID 1)
[MQTT] Sending ESPURNA_8F3878/relay/1 => 0 (PID 1)
[MQTT] Sending ESPURNA_8F3878/relay/2 => 0 (PID 1)
[MQTT] Sending ESPURNA_8F3878/relay/3 => 0 (PID 1)
[MQTT] Sending ESPURNA_8F3878/relay/4 => 0 (PID 1)
[MQTT] Sending ESPURNA_8F3878/relay/5 => 0 (PID 1)
[MQTT] Sending ESPURNA_8F3878/relay/6 => 0 (PID 1)
[MQTT] Sending ESPURNA_8F3878/relay/7 => 0 (PID 1)
[MQTT] Sending ESPURNA_8F3878/vcc => 3196 (PID 1)
[MQTT] Sending ESPURNA_8F3878/status => 1 (PID 1)
[MAIN] Time: Not set
[MQTT] Subscribe ACK for PID 2
[MQTT] Subscribe ACK for PID 3
[MQTT] Subscribe ACK for PID 4
[MQTT] Subscribe ACK for PID 5
[MQTT] Subscribe ACK for PID 6
[MQTT] Subscribe ACK for PID 7

NO RESPONSE AFTER THIS….

[xoseperez]

Issue #287 was marked as a duplicate of this issue.

[xoseperez]

Original comment by Iván Conde (Bitbucket: ciconde, GitHub: Unknown):

---

I must confirm it is still happening on 1.11.0, for the note

[xoseperez]

Issue #314 was marked as a duplicate of this issue.

[xoseperez]

Original comment by skorc99 (Bitbucket: skorc99, GitHub: skorc99):

---

1.11.0

still the same.

After MQTT enabled RF not working.

U

[xoseperez]

Apparently it's a problem related only to MQTT, not the rfbridge.

Can you test with another board (like a normal wemos or nodemcu)? Does it connect to your MQTT broker?

[xoseperez]

Original comment by skorc99 (Bitbucket: skorc99, GitHub: skorc99):

---

Tested with sonoff basic.

Problem is the same. When MQTT is enabled it restarts and not working.

I am using mosquitto with domotizc Version: 3.8153.

Also tested with tasmota -both modules -no error and all working.

U

[xoseperez]

It's an MQTT issue then. Tasmota uses a different MQTT client so it could be the client or the implementation. Best way to debug would be to decaod the error stack trace if you know how to do it. You could also remove things from the equation, like disable Domoticz to see if the error is in the Domoticz code or in the main MQTT code.

You can test the same client Tasmota uses by setting MQTT_USE_ASYNC to 0 in the general.h file.

[xoseperez]

Original comment by skorc99 (Bitbucket: skorc99, GitHub: skorc99):

---

MQTT_USE_ASYNC to 0

now it is stable but i can only control from web.. I can also now confirm that web is working in safari.

I tested:

• water leakege sensor- i recieve alert in domoticz MQTT
  -I can not control outlet from domoticz but it works directly from browser

So it is still MQTT issue..

U

[xoseperez]

I have found an overflow bug in the mqtt code when the received payload is bigger than 255 chars, which happens with domoticz messages often. I have pushed the fix to the dev branch (fd02236). Can you please test if this is the issue you are facing?

[xoseperez]

Original comment by Iván Conde (Bitbucket: ciconde, GitHub: Unknown):

---

Definitely.

Domoticz mqtt disabled, ESPurna stable.
Domoticz mqtt enabled for a little while and ESPurna goes reset, checked twice looking at uptime.

What surprises me a lot is the fact that i have the domoticz integration disabled O_o

Anyway, I think it's confirmed that receiving domoticz mqtt messages causes the issue.
Should rename this thread :)

[xoseperez]

Yeah, that's because the firmware still subscribes to the domoticz out topic even if domoticz is not enabled but it does not process the messages. Unfortunately, another module was choking with the messages. I have changed that behavior too with the latest commit (c0d63ff). Now it only subscribes to the domoticz out topic if domoticz support is enabled (and unsubscribes if the user disables it).

[xoseperez]

Original comment by Iván Conde (Bitbucket: ciconde, GitHub: Unknown):

---

Nice commit, improves bandwidth efficiency.

That choking module... Guess we should escalate the issue. Will you open this issue?
If you want to, Xose, tell us where to open this issue on the module's forum

[xoseperez]

Original comment by skorc99 (Bitbucket: skorc99, GitHub: skorc99):

---

Hello,

tested and i can confirm that this solved the issue.

I tested:

#!arduino

-outlet - on/off- working OK controlled via WEB and domoticz

-sensor- RF input- working OK

I will do so more tests for stability..

U

[xoseperez]

Released with 1.11.2

[xoseperez]

Removing milestone: 1.11.2 (automated comment)

[xoseperez]

Original comment by Iván Conde (Bitbucket: ciconde, GitHub: Unknown):

---

Thank you very much, Xose!