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

klein0r · 2023-08-12T13:18:05Z

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 klein0r/ioBroker.awtrix-light#57

The text was updated successfully, but these errors were encountered:

Blueforcer · 2023-08-12T13:31:34Z

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 · 2023-08-12T13:37:07Z

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 · 2023-08-12T13:44:00Z

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 · 2023-08-13T07:13:53Z

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 · 2023-08-14T05:53:21Z

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 · 2023-08-14T07:08:57Z

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 · 2023-08-14T07:45:21Z

That doesn't make any sense to me,
Here are the changes from 0.73 to 0.74.... barely nothing.
d156779

Does everyone here uses the IObroker adapter?

GitHoubi · 2023-08-14T07:47:34Z

I was a bit suprised too I have to admit.

Yes, running ioBroker

FreunderNacht · 2023-08-15T09:31:28Z

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 · 2023-08-15T09:37:44Z

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 · 2023-08-15T09:40:51Z

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 · 2023-08-15T10:38:17Z

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 · 2023-08-15T15:24:01Z

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 · 2023-08-15T18:18:23Z

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 · 2023-08-15T21:19:07Z

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 · 2023-08-15T22:51:05Z

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 · 2023-08-16T01:07:47Z

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 · 2023-08-18T20:55:48Z

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 · 2023-08-18T21:04:57Z

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 · 2023-08-18T21:24:32Z

@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 · 2023-08-18T21:33:28Z

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 · 2023-08-18T21:43:02Z

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 · 2023-08-18T21:51:53Z

@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 · 2023-08-18T22:16:12Z

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 · 2023-08-18T23:11:33Z

@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 · 2023-08-19T09:06:12Z

@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 · 2023-08-19T09:15:03Z

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 · 2023-08-19T10:14:29Z

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 · 2023-08-19T17:35:00Z

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 · 2023-08-20T00:42:04Z

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 · 2023-08-20T08:11:31Z

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

FreunderNacht · 2023-08-21T11:16:15Z

@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 · 2023-08-21T11:27:47Z

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 · 2023-08-21T13:01:41Z

Hallo @Blueforcer,
der Link funktioniert bei mir nicht.

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

Blueforcer · 2023-08-21T13:05:41Z

https://discord.gg/cyBCpdx

Blueforcer · 2023-08-22T13:53:14Z

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 · 2023-08-22T21:31:45Z

problem was this: espressif/arduino-esp32#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!

klein0r added the bug Something isn't working label Aug 12, 2023

klein0r mentioned this issue Aug 22, 2023

Unable to update custom app - "ErrorParsingJson" klein0r/ioBroker.awtrix-light#57

Closed

2 tasks

Blueforcer closed this as completed Aug 22, 2023

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

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

Comments

klein0r commented Aug 12, 2023 • edited Loading

Bug report

Describe the bug

Additional information

Additional context

Blueforcer commented Aug 12, 2023 • edited Loading

Blueforcer commented Aug 12, 2023

FreunderNacht commented Aug 12, 2023

baetzmr commented Aug 13, 2023

baetzmr commented Aug 14, 2023

GitHoubi commented Aug 14, 2023

Blueforcer commented Aug 14, 2023 • edited Loading

GitHoubi commented Aug 14, 2023

FreunderNacht commented Aug 15, 2023

Blueforcer commented Aug 15, 2023 • edited Loading

klein0r commented Aug 15, 2023

FreunderNacht commented Aug 15, 2023

Blueforcer commented Aug 15, 2023 • edited Loading

GitHoubi commented Aug 15, 2023

FreunderNacht commented Aug 15, 2023 • edited Loading

Blueforcer commented Aug 15, 2023

bimbolongo commented Aug 16, 2023 • edited Loading

FreunderNacht commented Aug 18, 2023 • edited Loading

Edit:

FreunderNacht commented Aug 18, 2023 • edited Loading

Blueforcer commented Aug 18, 2023 • edited Loading

baetzmr commented Aug 18, 2023

Blueforcer commented Aug 18, 2023 • edited Loading

FreunderNacht commented Aug 18, 2023

monnypython commented Aug 18, 2023

Blueforcer commented Aug 18, 2023 • edited Loading

FreunderNacht commented Aug 19, 2023

Blueforcer commented Aug 19, 2023

FreunderNacht commented Aug 19, 2023

GitHoubi commented Aug 19, 2023

Blueforcer commented Aug 20, 2023

Blueforcer commented Aug 20, 2023

FreunderNacht commented Aug 21, 2023

Blueforcer commented Aug 21, 2023 • edited Loading

FreunderNacht commented Aug 21, 2023

Blueforcer commented Aug 21, 2023

Blueforcer commented Aug 22, 2023 • edited Loading

Blueforcer commented Aug 22, 2023

klein0r commented Aug 12, 2023 •

edited

Loading

Blueforcer commented Aug 12, 2023 •

edited

Loading

Blueforcer commented Aug 14, 2023 •

edited

Loading

Blueforcer commented Aug 15, 2023 •

edited

Loading

Blueforcer commented Aug 15, 2023 •

edited

Loading

FreunderNacht commented Aug 15, 2023 •

edited

Loading

bimbolongo commented Aug 16, 2023 •

edited

Loading

FreunderNacht commented Aug 18, 2023 •

edited

Loading

FreunderNacht commented Aug 18, 2023 •

edited

Loading

Blueforcer commented Aug 18, 2023 •

edited

Loading

Blueforcer commented Aug 18, 2023 •

edited

Loading

Blueforcer commented Aug 18, 2023 •

edited

Loading

Blueforcer commented Aug 21, 2023 •

edited

Loading

Blueforcer commented Aug 22, 2023 •

edited

Loading