Rule error 'No valid JSON'

[blacknell]

PROBLEM DESCRIPTION

I'm seeing rule error output when devices starts. It's intermittent but only happens on a reboot after deep sleep. I suspected a regression on #19412 because the json data displayed in the log for the Max17043 is clearly invalid. See qualifying note below

Sep 11 04:12:12 tasmota-CBF048-4168 ESP-RUL: No valid JSON (,"MAX17043":{"VOLTAGE":3.871,"BATTERYPERCENTAGE":62.96}}})

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 discussions
• Searched the problem in the docs
• Searched the problem in the chat
• Device used (e.g., Sonoff Basic): _____
• Tasmota binary firmware version number used: 13.1.0.2
  • Pre-compiled
  • Self-compiled
• Flashing tools used:
• Provide the output of command: Backlog Template; Module; GPIO 255:

  Configuration output here:

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

The rule action command here is not important here. Just the fact it fires the rules processor.

RULE1 ON System#Init DO Sensor90 R ENDON

• Provide the output of this command: Status 0:

  STATUS 0 output here:

• Set weblog to 4 and then, when you experience your issue, provide the output of the Console log:

  Console output here:
All output is at 4

TO REPRODUCE

Steps to reproduce the behavior:
Set up a MAX17043 using I2C
Create a simple INIT rule
Use a deep sleep time of 120 seconds

EXPECTED BEHAVIOUR

A clear and concise description of what you expected to happen.
No error logs

SCREENSHOTS

If applicable, add screenshots to help explain your problem.

ADDITIONAL CONTEXT

Add any other context about the problem here.

In the aforementioned PR, I refactors the JSON generation for the MAX sensor. The JSON output looks clean.

But strangely, and only after booting, it sometimes reports invalid json. This is causing the rules processor to barf.

I added some debug code to the MAX sensor to log the json append string I'm generating along with the original line from prior to the PR

Here you can see my debug output in first 2 lines where the old and new string are identical. And in this case the rule/json are good.

07:14:56.812 SNS: ,"MAX17043":{"Voltage":3.860,"BatteryPercentage":58.53}
07:14:56.813 SNS: ,"MAX17043":{"Voltage":3.860,"BatteryPercentage":58.53}
07:14:56.827 RUL: ProcessEvent |{"MAX17043":{"Voltage":3.860,"BatteryPercentage":58.53}}|
07:14:56.828 RUL: Event |{"MAX17043":{"VOLTAGE":3.860,"BATTERYPERCENTAGE":58.53}}|
07:14:56.839 RUL-RP1: Event = {"MAX17043":{"VOLTAGE":3.860,"BATTERYPERCENTAGE":58.53}}, Rule = ON System#Init DO Sensor90 R ENDON ON MAX17043#BatteryPercentage DO Sensor90 R ENDON
07:14:56.851 RUL-RP2: Event |{"MAX17043":{"VOLTAGE":3.860,"BATTERYPERCENTAGE":58.53}}|, Rule |SYSTEM#INIT|, Command(s) |Sensor90 R|
07:14:56.863 RUL-RM1: Teleperiod 0, Expr SYSTEM#INIT, Name SYSTEM#INIT, Param 
07:14:56.876 RUL-RP2: Event |{"MAX17043":{"VOLTAGE":3.860,"BATTERYPERCENTAGE":58.53}}|, Rule |MAX17043#BATTERYPERCENTAGE|, Command(s) |Sensor90 R|
07:14:56.888 RUL-RM1: Teleperiod 0, Expr MAX17043#BATTERYPERCENTAGE, Name MAX17043#BATTERYPERCENTAGE, Param 
07:14:56.890 RUL-RM3: Name BATTERYPERCENTAGE, Value ||, TrigCnt 1, TrigSt 0, Source {"MAX17043":{"VOLTAGE":3.860,"BATTERYPERCENTAGE":58.53}}, Json |58.53|
07:14:56.916 RUL: MAX17043#BATTERYPERCENTAGE performs "Sensor90 R"

But here you can see occasionally, this clearly invalid json string makes it through ,"MAX17043":{"VOLTAGE":3.871,"BATTERYPERCENTAGE":62.96}}} to the rules processor.

Sep 11 04:12:12 tasmota-CBF048-4168 ESP-RUL: ProcessEvent |,"MAX17043":{"Voltage":3.871,"BatteryPercentage":62.96}}}|
Sep 11 04:12:12 tasmota-CBF048-4168 ESP-RUL: Event |,"MAX17043":{"VOLTAGE":3.871,"BATTERYPERCENTAGE":62.96}}}|
Sep 11 04:12:12 tasmota-CBF048-4168 ESP-RUL-RP1: Event = ,"MAX17043":{"VOLTAGE":3.871,"BATTERYPERCENTAGE":62.96}}}, Rule = ON System#Init DO Sensor90 R ENDON
Sep 11 04:12:12 tasmota-CBF048-4168 ESP-RUL-RP2: Event |,"MAX17043":{"VOLTAGE":3.871,"BATTERYPERCENTAGE":62.96}}}|, Rule |SYSTEM#INIT|, Command(s) |Sensor90 R|
Sep 11 04:12:12 tasmota-CBF048-4168 ESP-RUL-RM1: Teleperiod 0, Expr SYSTEM#INIT, Name SYSTEM#INIT, Param 
Sep 11 04:12:12 tasmota-CBF048-4168 ESP-RUL: No valid JSON (,"MAX17043":{"VOLTAGE":3.871,"BATTERYPERCENTAGE":62.96}}})

Something is weird on boot because the string being parsed isn't complete.

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

[sfromis]

I suspect that it is related to the code added to issue the BatteryPercentage command in the FUNC_JSON_APPEND callback, and "sometimes" may be when the value was different.

[stefanbode]

This message is quite common since ages. I would not say it is new and connected to batterypercentage. Anyhow I do not see a negative impact. rules work fine.
Be careful: THIS batterypercentage is not the newly introduced batterypercentage of the device coming in th4e status message. This is coming from the driver of the MAX17043. If the JSON is misaligned I would search in the driver.

[arendst]

Well as FUNC_JSON_APPEND implies it is supposed to append to an already started json message. If this is not the case, by using the function in a not supposed way, this is the result.

Solution is not to use the function in this case or fix the issue by checking the initial length of the to append string. If it's zero then do not start with the coma. Any way, the MAX driver needs to be adjusted. I'll have a look today.

[blacknell]

I'm digging into it but it's obscure. I don't think it's just the leading comma because there's extra }} at the end too

,"MAX17043":{"Voltage":3.871,"BatteryPercentage":62.96}}}

[arendst]

No. The call ExecuteCommand is a no-go in function Max17043Show()!!!!

It corrupts the JSON string. I don't see why on earth ExecuteCommand is called as it can be easily done by updating the Settings->batery_level_percent.

I'll remove ExecuteCommand and just add the direct update of the Settings value.

NB @stefanbode is very fond of this function (See shutter code) but not knowing the impact leads to this behaviour.

[blacknell]

Ok. Thank you very much.