Web Console prepends 'Backlog' on RUL: output for rules that invoke events.

[dp-github]

PROBLEM DESCRIPTION

Web Console prepends 'Backlog' on RUL: output for rules that invoke events.

REQUESTED INFORMATION

Make sure your have performed every step and checked the applicable boxes before submitting your issue. Thank you!

• Read the Contributing Guide and Policy and the Code of Conduct
• Searched the problem in issues
• Searched the problem in the wiki
• Searched the problem in the forum
• Searched the problem in the chat
• Device used (e.g., Sonoff Basic): Sonoff TH16
• Tasmota binary firmware version number used: 7.1.1
  • Pre-compiled
  • Self-compiled
    • IDE / Compiler used: _____
• Flashing tools used: FTDI
• Provide the output of command: Backlog Template; Module; GPIO 255:

22:07:28 MQT: freezer/stat/RESULT = {"NAME":"Generic","GPIO":[255,255,255,255,255,255,255,255,255,255,255,255,255],"FLAG":15,"BASE":18}
22:07:28 MQT: freezer/stat/RESULT = {"Module":{"4":"Sonoff TH"}}
22:07:28 MQT: freezer/stat/RESULT = {"GPIO0":{"17":"Button1"},"GPIO1":{"0":"None"},"GPIO2":{"0":"None"},"GPIO3":{"0":"None"},"GPIO4":{"0":"None"},"GPIO5":{"0":"None"},"GPIO9":{"0":"None"},"GPIO10":{"0":"None"},"GPIO12":{"21":"Relay1"},"GPIO13":{"56":"Led1i"},"GPIO14":{"3":"SI7021"},"GPIO15":{"0":"None"},"GPIO16":{"0":"None"}}

• If using rules, provide the output of this command: Backlog Rule1; Rule2; Rule3:

22:07:46 MQT: freezer/stat/RESULT = {"Rule1":"OFF","Once":"ON","StopOnError":"OFF","Free":511,"Rules":""}
22:07:47 MQT: freezer/stat/RESULT = {"Rule2":"ON","Once":"OFF","StopOnError":"OFF","Free":435,"Rules":"ON Tele-SI7021#Temperature do backlog var2 %value%;event PublishStatus ENDON"}
22:07:47 MQT: freezer/stat/RESULT = {"Rule3":"ON","Once":"OFF","StopOnError":"OFF","Free":459,"Rules":"on Event#PublishStatus do Publish mytopic test endon"}

• Provide the output of this command: Status 0:

22:07:46 MQT: freezer/stat/RESULT = {"Rule1":"OFF","Once":"ON","StopOnError":"OFF","Free":511,"Rules":""}
22:07:47 MQT: freezer/stat/RESULT = {"Rule2":"ON","Once":"OFF","StopOnError":"OFF","Free":435,"Rules":"ON Tele-SI7021#Temperature do backlog var2 %value%;event PublishStatus ENDON"}
22:07:47 MQT: freezer/stat/RESULT = {"Rule3":"ON","Once":"OFF","StopOnError":"OFF","Free":459,"Rules":"on Event#PublishStatus do Publish mytopic test endon"}

• Provide the output of the Console log output when you experience your issue; if applicable:
  (Please use weblog 4 for more debug information)

21:45:49 CMD: rule2 ON Tele-SI7021#Temperature do backlog var2 %value%;publish mytopic test ENDON
21:45:49 MQT: freezer/stat/RESULT = {"Rule2":"ON","Once":"OFF","StopOnError":"OFF","Free":434,"Rules":"ON Tele-SI7021#Temperature do backlog var2 %value%;publish mytopic test ENDON"}
21:45:56 MQT: freezer/tele/STATE = {"Time":"2019-12-08T21:45:56","Uptime":"0T12:55:08","UptimeSec":46508,"Heap":26,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":13,"POWER":"OFF","Wifi":{"AP":1,"SSId":"Tanqueray","BSSId":"24:F5:A2:EB:BA:91","Channel":6,"RSSI":44,"LinkCount":1,"Downtime":"0T00:00:13"}}
21:45:56 MQT: freezer/tele/SENSOR = {"Time":"2019-12-08T21:45:56","SI7021":{"Temperature":45.9,"Humidity":71.3},"TempUnit":"F"}
21:45:56 RUL: TELE-SI7021#TEMPERATURE performs "backlog var2 45.9;publish mytopic test"



21:46:32 CMD: rule2 ON Tele-SI7021#Temperature do backlog var2 %value%;event PublishStatus ENDON
21:46:32 MQT: freezer/stat/RESULT = {"Rule2":"ON","Once":"OFF","StopOnError":"OFF","Free":435,"Rules":"ON Tele-SI7021#Temperature do backlog var2 %value%;event PublishStatus ENDON"}
21:46:36 MQT: freezer/tele/STATE = {"Time":"2019-12-08T21:46:36","Uptime":"0T12:55:48","UptimeSec":46548,"Heap":26,"SleepMode":"Dynamic","Sleep":50,"LoadAvg":19,"MqttCount":13,"POWER":"OFF","Wifi":{"AP":1,"SSId":"Tanqueray","BSSId":"24:F5:A2:EB:BA:91","Channel":6,"RSSI":52,"LinkCount":1,"Downtime":"0T00:00:13"}}
21:46:36 MQT: freezer/tele/SENSOR = {"Time":"2019-12-08T21:46:36","SI7021":{"Temperature":46.0,"Humidity":71.5},"TempUnit":"F"}
21:46:36 RUL: TELE-SI7021#TEMPERATURE performs "backlog backlog var2 46.0;event PublishStatus"

TO REPRODUCE

1. Create a rule that invokes an event and includes the 'backlog' command
2. When that rule fires, examine the web console output. Notice that the output now says 'backlog backlog event rulename'

EXPECTED BEHAVIOUR

Backlog should not be duplicated in the web console output

SCREENSHOTS

If applicable, add screenshots to help explain your problem.

ADDITIONAL CONTEXT

Add any other context about the problem here.

(Please, remember to close the issue when the problem has been addressed)

[dp-github]

I suspect this error is caused by xdrv_10_rules.ino line 441:

if (ucommand.indexOf("EVENT ") != -1) { commands = "backlog " + commands; }  // Always use Backlog with event to prevent rule event loop exception

I'm not familiar with the codebase at all, and I haven't looked closely enough to determine whether this affect execution of the command, or only debug reporting.

[dp-github]

Furthermore, it looks like this not only affects how the command is reported to logs and consoles, but it affects how the command is executed. ( ref: xdrv_10_rules.ino line 472)

[ascillato]

Hi,

Thanks for reporting. I will fix the second backlog.

[ascillato]

Proposed PR #7178 for review, in order to fix this. Thanks.