[BUG] ErrorParsingJson for valid JSON payload. Not enough free RAM?

[klein0r]

Bug report

Describe the bug

More and more people complain about ErrorParsingJson errors. Even with just a small number of custom apps. Looks like the device hasn't enough RAM to handle more than ~5 custom apps in the latest firmware version.

I have some logs of the ioBroker adapter:

This works:

2023-08-11 07:08:47.523 - debug: awtrix-light.0 (22401) sending "POST" request to "/api/custom?name=pvpower" with data: {"text":"125 W","textCase":2,"background":"#000000","color":"#faf303","icon":"44625"}
2023-08-11 07:08:47.633 - debug: awtrix-light.0 (22401) received 200 response from "/api/custom?name=pvpower" with content: "OK"

But an identical request leads to an error some minutes later:

2023-08-11 07:09:07.516 - debug: awtrix-light.0 (22401) sending "POST" request to "/api/custom?name=pvpower" with data: {"text":"128 W","textCase":2,"background":"#000000","color":"#faf303","icon":"44625"}
2023-08-11 07:09:07.583 - warn: awtrix-light.0 (22401) received 500 response from /api/custom?name=pvpower with content: "ErrorParsingJson"

• {"text":"125 W","textCase":2,"background":"#000000","color":"#faf303","icon":"44625"} - OK
• {"text":"128 W","textCase":2,"background":"#000000","color":"#faf303","icon":"44625"} - ERROR

Additional information

• Devices involved:
  • Model: Ulanzi Awtrix Smart Pixel Clock 2882 (TC001)
  • AWTRIX-LIGHT version: v0.73

Additional context

See https://github.com/klein0r/ioBroker.awtrix-light/issues/57

[Blueforcer]

Never heard of this problem. I tried to put some extra Apps into my loop (im now at 19) and still have 70kb free. Of course it depends on what you send. If you call X functions in each + effects then it will run to the limit at some point. Where 60kb (as I see in your issue) is actually still relatively much and should parse a small json easily

[Blueforcer]

firmware.zip Try this one, put {"debug_mode":true} into dev.json and have a look at the serialterminal. You will get the error message directly from the parser

[FreunderNacht]

Hi. I also seem to have a problem with too little RAM.

I also work with the IO Broker Adapter from @klein0r .

I get the following message in the IO Broker log:

awtrix-light.0
2023-08-12 13:36:43.509 warn    (custom?name=hausverbrauch) Unable to update custom app "hausverbrauch": AxiosError: Request failed with status code 500

awtrix-light.0
2023-08-12 13:36:43.509 warn    received 500 response from /api/custom?name=hausverbrauch with content: "ErrorParsingJson"

awtrix-light.0
2023-08-12 13:36:43.478 warn    (custom?name=pvproduktion) Unable to update custom app "pvproduktion": AxiosError: Request failed with status code 500

awtrix-light.0
2023-08-12 13:36:43.477 warn    received 500 response from /api/custom?name=pvproduktion with content: "ErrorParsingJson"

awtrix-light.0
2023-08-12 13:36:23.522 warn    (custom?name=pvproduktion) Unable to update custom app "pvproduktion": AxiosError: Request failed with status code 500

awtrix-light.0
2023-08-12 13:36:23.522 warn    received 500 response from /api/custom?name=pvproduktion with content: "ErrorParsingJson"

awtrix-light.0
2023-08-12 13:36:03.466 warn    (custom?name=pvproduktion) Unable to update custom app "pvproduktion": AxiosError: Request failed with status code 500

awtrix-light.0
2023-08-12 13:36:03.466 warn    received 500 response from /api/custom?name=pvproduktion with content: "ErrorParsingJson"

awtrix-light.0
2023-08-12 13:35:23.486 warn    (custom?name=hausverbrauch) Unable to update custom app "hausverbrauch": AxiosError: Request failed with status code 500

awtrix-light.0
2023-08-12 13:35:23.486 warn    received 500 response from /api/custom?name=hausverbrauch with content: "ErrorParsingJson"

awtrix-light.0
2023-08-12 13:35:23.461 warn    (custom?name=pvproduktion) Unable to update custom app "pvproduktion": AxiosError: Request failed with status code 500

awtrix-light.0
2023-08-12 13:35:23.461 warn    received 500 response from /api/custom?name=pvproduktion with content: "ErrorParsingJson"

awtrix-light.0
2023-08-12 13:35:03.426 warn    (custom?name=hausverbrauch) Unable to update custom app "hausverbrauch": AxiosError: Request failed with status code 500

awtrix-light.0
2023-08-12 13:35:03.426 warn    received 500 response from /api/custom?name=hausverbrauch with content: "ErrorParsingJson"

awtrix-light.0
2023-08-12 13:35:03.395 warn    (custom?name=pvproduktion) Unable to update custom app "pvproduktion": AxiosError: Request failed with status code 500

awtrix-light.0
2023-08-12 13:35:03.395 warn    received 500 response from /api/custom?name=pvproduktion with content: "ErrorParsingJson"

[baetzmr]

Good morning, i tryed flashing firmware.bin to the device. After flashing i got 134kb free RAM after reboot instead of 78kb using 6 custon apps. I added 2 more custom apps as i had before and expected the "ErrorParsionJson" Warning... but i am still at 120kb free RAM and the device is running without any issue. Will provide a Serial Log when the Warning happens again

[baetzmr]

Hi. After flashing 0.74 it's a little bit worse. Free RAM now at 58kb and Warnings back maybe 10s after Restarting Instance of awtrix.

Serial Monitor log shows nothing...

VSCondeLog2.txt

but iobroker log:

Another issue was when i want to activate logging function on device (edit value in dev.json from false to true and save) there was many errors and the device freezes.

Serial log shows following:

VSCodeLog.txt

i go back to 0.73 (firmware.bin) you sent before. This version works fine. Using 10 custom apps without any issue

[GitHoubi]

Same here, updated to 0.74 last night and things got bad really quick again. 0.73 (firmware bin, not the official release) works absolutely perfect.

[Blueforcer]

That doesn't make any sense to me, Here are the changes from 0.73 to 0.74.... barely nothing. https://github.com/Blueforcer/awtrix-light/commit/d1567791ba1f38181e8b37604f437eed43dc64cd

Does everyone here uses the IObroker adapter?

[GitHoubi]

I was a bit suprised too I have to admit.

Yes, running ioBroker

[FreunderNacht]

Hi, I thought the problems were solved with the 0.74 update. However, when I looked at the IO Broker log this morning, I found that I have the error messages again:

` awtrix-light.0 2023-08-15 11:00:44.582 warn (custom?name=hausverbrauch) Unable to update custom app "hausverbrauch": AxiosError: Request failed with status code 500

awtrix-light.0 2023-08-15 11:00:44.582 warn received 500 response from /api/custom?name=hausverbrauch with content: "ErrorParsingJson"

awtrix-light.0 2023-08-15 11:00:44.555 warn (custom?name=pvproduktion) Unable to update custom app "pvproduktion": AxiosError: Request failed with status code 500

awtrix-light.0 2023-08-15 11:00:44.555 warn received 500 response from /api/custom?name=pvproduktion with content: "ErrorParsingJson"

awtrix-light.0 2023-08-15 11:00:24.630 warn (custom?name=hausverbrauch) Unable to update custom app "hausverbrauch": AxiosError: Request failed with status code 500

awtrix-light.0 2023-08-15 11:00:24.630 warn received 500 response from /api/custom?name=hausverbrauch with content: "ErrorParsingJson"

awtrix-light.0 2023-08-15 11:00:24.602 warn (custom?name=pvproduktion) Unable to update custom app "pvproduktion": AxiosError: Request failed with status code 500

awtrix-light.0 2023-08-15 11:00:24.602 warn received 500 response from /api/custom?name=pvproduktion with content: "ErrorParsingJson" `

There are fewer of them, but they are back. I also have the impression that the longer the adapter runs, the more there are.

Unfortunately, I'm still on the road and can't send another log at the moment.

As soon as I have the opportunity, I will try to send other logos.

[Blueforcer]

The last 3 versions I changed nothing to this related problem. So it is very unlikely that the version has anything to do with this "bug" or make it make better or worse.

Besides, IObroker logs are of no use to me here. Please only post awtix related logs. Here I need the serial output. Otherwise I don't now what's the parsing Problem

[klein0r]

Besides, IObroker logs are of no use to me here.

If @FreunderNacht would change the log level to debug, all HTTP requests will be logged.

[FreunderNacht]

Besides, IObroker logs are of no use to me here.

If @FreunderNacht would change the log level to debug, all HTTP requests will be logged.

Hello @klein0r , here is the log of the IO broker in debug log level.

IO Broker Log.txt

@Blueforcer Can you briefly explain how I can display the serial log?

Then I'll try to send you the excerpt.

In which file do I have to insert the "debug_mode":true and where do I find it?

[Blueforcer]

You need to connect awtrix to a PC, then go to the awtrix webflasher and hit console.

You need to create a dev.json in the root of the filesystem

See https://blueforcer.github.io/awtrix-light/#/dev

[GitHoubi]

firmware.zip Try this one, put {"debug_mode":true} into dev.json and have a look at the serialterminal. You will get the error message directly from the parser

This one here really runs rock solid, not a single error or disconnect since like three days? I tried .74 in between, but as official .73 and .72 all of them suffer the same problem after a while. But that custom .73 does not, it works perfectly fine.

[FreunderNacht]

You need to connect awtrix to a PC, then go to the awtrix webflasher and hit console.

You need to create a dev.json in the root of the filesystem

See https://blueforcer.github.io/awtrix-light/#/dev

@Blueforcer @klein0r I think I have found the mistake. It was one that I caused.

I had entered an icon number (the wrong number was the 54319 / the correct number was the 54619) in the adapter that did not exist (it was a number error).

However, since this icon is usually only needed at night or during heavy cloud cover, the error only occurred sporadically, which also supports my assumption that version 0.74 had supposedly solved the problem (at that time the icon was not called up).

Nevertheless, here is the log of the console:

esp-web-tools-logs.txt

I noticed another little thing here. The icons 52835 and 52840 are not .jpg but .gif. This does NOT lead to a warning message in the IO Broker log and the apps also work without problems. I only noticed that this message is present in the log.

I'll observe the whole thing for another day or two and then give feedback.

@Blueforcer Thanks for the great firmware and the help.

@klein0r Thanks for the IO Broker adapter and the help.

[Blueforcer]

if an icon exists or not, doesnt matter. Awtrix checks this. This will not generate the "ErrorParsingJson" message.

The messages in the awtrix log is a weird output of the LittleFS lib. Since you only give the name without extension, awtrix first check if the icon with .jpg exists and then if it exists as gif. the "exists" command unfortunally throws this error if the icon doesnt exists. Everything is working as expected. You can ignore those messages.

Im pretty sure, the mainproblem isnt solved yet.

[bimbolongo]

I have a question for Blueforcer. You recently posted a Firmware.bin here. What was changed about this one? This now runs error-free on my custom build. Could this change also be made with an Awtrix 2 upgrade firmware? For me, no version higher than 0.71 runs without errors.

[FreunderNacht]

if an icon exists or not, doesnt matter. Awtrix checks this. This will not generate the "ErrorParsingJson" message.

The messages in the awtrix log is a weird output of the LittleFS lib. Since you only give the name without extension, awtrix first check if the icon with .jpg exists and then if it exists as gif. the "exists" command unfortunally throws this error if the icon doesnt exists. Everything is working as expected. You can ignore those messages.

Im pretty sure, the mainproblem isnt solved yet.

Hello @Blueforcer, you were right, the problem is not solved.

I had no error messages for 2 days, or at most only very isolated ones, but since this morning I have just as many as before.

Here is the console log from the AWTRIX firmware:

2023-08-18 AWTRIX Consol-Log (Debug).txt

The console log from the AWTRIX firmware goes back even further than that of the IO Broker, as the adapter was only running in the "Info" log level. The time when the log level of the adapter was changed can be seen in the console log, as it was restarted as a result.

I also have the impression that when I restart the ESP, there are no more negative log entries in the IO Broker for a certain time.

Is there any way I can make the RAM load of the Ulanzia visible and record it?

Or is there anything else I can do to help?

Edit:

I have found the possibility to read out the free RAM via the IO Broker adapter. I will keep an eye on this value and check it the next time the message comes. After the update to firmware version 0.75, the free RAM is currently 105680 Byte.

[FreunderNacht]

Besides, IObroker logs are of no use to me here.

If @FreunderNacht would change the log level to debug, all HTTP requests will be logged.

Hello @klein0r , here is the log from the IO Broker with the AWTRIX adapter in debug mode:

2023-08-18 IO Broker Log (AWTRIX Debug).txt

It was recorded at the end at the same time as the console log of the AWTRIX firmware (see previous post).

[Blueforcer]

@FreunderNacht

"debug_mode" is not active. You need to set it in the dev.json on the awtrix filesystem.

I dont thing that the RAM is the problem 105kb (and even 60kb as mentioned above) should be more than enough.

[baetzmr]

Hi I made a short test with FW0.75 and recognized that memory usage goes down to 53 - 50kb free RAM after starting ioBroker adapter. After very short time ( < 2min) web interface is not reachable any more. Only rebooting the device by press and hold the two buttons helps. Although updating the values was not possible any more. I think we have here an issue as soon the ioBroker adapter connects to the device.

I hope I can make a test tomorrow sending MQTT messages with custom apps over NodeRed and monitor the behavior of the device.

In the meantime I downgraded to firmware.bin (custom 0.73) running 12 custom apps without any issue

[Blueforcer]

My main users on my discords use Homeassistant over MQTT or raw MQTT messages and i dont have such issue reports. So I'm a little confused as to what the IOBroker adpater does so much differently. http shouldn't really be the problem now I think.

[FreunderNacht]

@FreunderNacht

"debug_mode" is not active. You need to set it in the dev.json on the awtrix filesystem.

I dont thing that the RAM is the problem 105kb (and even 60kb as mentioned above) should be more than enough.

@Blueforcer

I have created dev.json in the root directory, but there I have only entered the value for the debug mode and set it to True.

Am I in the right place in the directory tree?

Do I have to enter all values or is it enough to enter only those that differ from the default, as I have done now?

[monnypython]

I had the same problems with screen freezes, reboots, etc. while using the iobroker adapter. Since i removed the Adapter and send http requests via exec-blockly-blocks and curl commands everything works for many days without any problems. So i agree with @Blueforcer that the http requests are not the problem.

[Blueforcer]

@Blueforcer

I have created dev.json in the root directory, but there I have only entered the value for the debug mode and set it to True.

Am I in the right place in the directory tree?

Do I have to enter all values or is it enough to enter only those that differ from the default, as I have done now?

That should work. do you also restarted awtrix after adding this?

[FreunderNacht]

@Blueforcer

I have created dev.json in the root directory, but there I have only entered the value for the debug mode and set it to True.

Am I in the right place in the directory tree?

Do I have to enter all values or is it enough to enter only those that differ from the default, as I have done now?

That should work. do you also restarted awtrix after adding this?

Yes, after each change (e.g. switching from true to false) I restart the Awtrix via the button "ESP restart" in the icon menu.

Can I somehow see whether I am in debug mode?

[Blueforcer]

Hope you're meaning from false to true:)

You only see it in the serial log.you should see the JSON you sent, the buttons you press, and so on

[FreunderNacht]

Hope you're meaning from false to true:)

You only see it in the serial log.you should see the JSON you sent, the buttons you press, and so on

@Blueforcer Yes, from false to true, of course. 🙈

I think I have it now.

I had to switch the Ulanzia completely (press the 2 outer buttons on the housing length) off and on again.

Now I see much more in the log.

As soon as the messages come next time, I will record the log.

[GitHoubi]

0.75 getting instable almost immediately (using the iobroker adapter).

Back to custom 0.73 again, this runs perfectly fine for days.

@klein0r, I start to think the root cause is more likely to be found within the iobroker adapter than the awtrix fw itself.

[Blueforcer]

Today I finally got a log from another user with the same problem. I think i have fixed that. We still test it but I think I can release an update today.

[Blueforcer]

Please check this: https://github.com/Blueforcer/awtrix-light/releases/tag/0.77

[FreunderNacht]

@Blueforcer Here is a console log from the old version 0.75 in debug mode.

esp-web-tools-logs (3).txt

I have an app ("regenheute") that is only activated when it has rained.

As soon as this is the case, I seem to have exceeded a limit and the RAM is no longer sufficient.

That would make a total of 7 apps for me.

I am now updating to version 0.77.

[Blueforcer]

Wir sind schon bei 0.79 :)

komm doch mal in discord, da bin ich mit @baetzmr und anderen am infos zusammentragen. https://discord.com/channels/546407049148366859/1142893440410066994

Ich habe schon ein Test bei mir gestartet und prügel im 5 Sekundentakt 15 Customapps gleichzeitig auf die Awtrix. Nach 50 minuten und 10k Messages ist der RAM festgenagelt auf 67kb.

[FreunderNacht]

Hallo @Blueforcer, der Link funktioniert bei mir nicht.

Er zeigt an, daß die Einladung abgelaufen oder ungültig ist.

[Blueforcer]

https://discord.gg/cyBCpdx

[Blueforcer]

The problem why I couldn't recreate it is, Because the compilation my platformIO spits out locally uses less heap memory than what falls out via platformIO via github action despite the same code... for whatever reason.

[Blueforcer]

problem was this: https://github.com/espressif/arduino-esp32/issues/8482 So in the latest update its gone, and i also daved lots of RAM with the last version. Overall all helpers on discord are satisfied now. So im closing here. Thanks everybody!