Incompatible with ESPAsyncWebServer?

Hi,

I have a crash problem and I can't figure out why.

I've written a program for a Sonoff SV switch (ESP8266 with relay) so that I can change the state of the relay in three ways: by pressing the physical button on the device, by sending a MQTT message and by clicking on a button on a webpage. All three methods result in a call to the same Publish() function that publishes the new state to MQTT. I'm using PubSubClient for MQTT handling and ESPAsyncWebServer as webserver.

Now I'm trying to add some logging to a MySQL server. Now Publish() additionally calls a new mysqlLog() right after publishing a MQTT message. mysqlLog() inserts one simple row in a MySQL table. I keep the MySQL connection alive in the main loop() and everything works fine.

If I press the button on the device, Publish() is called which in turn calls mysqlLog() which inserts a record in the MySQL table.

If the device receives a MQTT message, the same Publish() is called which in turn calls the same mysqlLog() and again a record is inserted in the table.

Works like a charm, over and over again. But yeah, however:

If I click on the button on the webpage, the same Publish() is called again which in turn calls the same mysqlLog() again with the same parameters but now the device crashes. I've narrowed it down to execute(). The SQL is valid every time. Code snippet from mysqlLog():

// Initiate the query class instance
MySQL_Cursor *cur_mem = new MySQL_Cursor(&mysqlConn);

// Execute the query
Serial.printf("==> %s ", sql);          // This SQL string is valid
bool ok = cur_mem->execute(sql);        // Seems to crash when called from ESPAsyncWebServer
Serial.printf("%s\n", ok ? "OK" : "FAILED");

// Note: since there are no results, we do not need to read any data
// Deleting the cursor also frees up memory used
delete cur_mem;

It looks like there is some kind of incompatibility between MySQL Connect Arduino and ESP Async Webserver. Or maybe I should configure something differently, but I just can't figure out what. I've checked the rest of my code but I can't see or think of any other problem.

Any ideas?

Hi. I need more information. What version of MySQL are you using? What version of the connector? What do you mean by crash? Are there error messages? Are you keeping the connection open or are you closing and opening it when you run a query? Can you share what mysqllog() is?

Hi Chuck,

I'm using MySQL version 8.0.23 and version 1.2.0 of the connector. By crash I mean that the device does a soft reset when it is inside execute(). Normally (following the code above) the query is displayed in the terminal window, the query is executed, "OK" is displayed and the record is inserted in the database. But sometimes I only see the query displayed and then the device resets, which means it happens somewhere in execute(). One time I saw a text like "user panic mode" or something like that flashing by just before the CUT HERE line, but I haven't seen that anymore. An example output during a crash:

==> INSERT INTO `ha`.`thermo` (ntp_time, device, action, message, msgvalue, json) VALUES ('2021-03-21 21:51:07','thermoswitch','Publish','thermoswitch/living_room','','{"state":"off","name":"Living Room","physicalbutton":"enabled","isheater":"true","iscooler":"true","log":"true"}')
--------------- CUT HERE FOR EXCEPTION DECODER ---------------

Soft WDT reset

>>>stack>>>

ctx: sys
sp: 3fffe8f0 end: 3fffffb0 offset: 01a0
[ snip ]
3fffffa0:  feefeffe 00000000 3fff0810 40213c69
<<<stack<<<

--------------- CUT HERE FOR EXCEPTION DECODER ---------------

 ets Jan  8 2013,rst cause:1, boot mode:(1,7)

 ets Jan  8 2013,rst cause:4, boot mode:(1,7)

wdt reset
Exception in thread rx:
Traceback (most recent call last):
  File "C:\Users\...\.platformio\python3\lib\threading.py", line 926, in _bootstrap_inner
    self.run()
  File "C:\Users\...\.platformio\python3\lib\threading.py", line 870, in run
    self._target(*self._args, **self._kwargs)
  File "c:\users\...\.platformio\penv\lib\site-packages\serial\tools\miniterm.py", line 499, in reader
    data = self.serial.read(self.serial.in_waiting or 1)
  File "c:\users\...\.platformio\penv\lib\site-packages\serial\serialwin32.py", line 259, in in_waiting
    raise SerialException("ClearCommError failed ({!r})".format(ctypes.WinError()))
serial.serialutil.SerialException: ClearCommError failed (PermissionError(13, 'Access is denied.', None, 5))

In the main loop() I am checking every 5 seconds if the client is connected. If not, loop() calls connect() again. I don't see the program reconnecting, so I assume the connection is open and stays open the whole time the program is running. The cursor itself is opened and closed with every query.

The mysqlLog() function in itself isn't really that exciting. It just constructs the query from some variables, then opens a cursor, executes the query and closes the cursor. I have checked every query on which the device crashes with MySQL Workbench and every query is correct.

What popped my question was the fact that I only see the device crashing when I do something on the website the device is serving with ESP Async Webserver, not on any other occassion. It looks like the problem only occurs when a query is executed while the webserver is handling a client request.

Piece of code from the webserver:

async_server.on("/update", HTTP_GET, [] (AsyncWebServerRequest *request)
{
  bool dataChanged = false;
  // do stuff with request->hasParam() here
    ...
  request->send(200, "text/plain", "OK");
  if (dataChanged)
    Publish();          // mysqlLog() is called from here
}

Of course it could be some other problem in my code. I'm a very experienced C++ programmer and MySQL user, but I also have my bad moments. Just haven't found this one yet :). Or perhaps I'm overestimating these ESP8266's by running a MQTT client, a MySQL client and serving multiple web clients all at the same time.

Anyway, because the crashes only seem to occur when called during a web request, I thought there might be a link of some sort.

I am not certain there is a correlation either. However, when a soft reset happens, it is usually and out of memory situation. When you compile your sketch, check to see how much space is available for user data. If it is < 20% then you may be running into a memory problem.

Aside from that, make sure you properly free any memory your allocating and reduce the number of variables, strings, structures, etc, to reduce the memory footprint. All of those things will help.

What may also help is to connect at the top of the loop() then disconnect at the end, then wait for about 500 ms. See the Wiki for how best to do that.

If you agree it could be memory, you can print out the memory available through one or more ways (google for it).

Finally, if you are making multiple connections to MySQL, use a different user for the sketch - that’s a long shot, but could help.

Dr. Bell

On Mar 22, 2021, at 8:24 AM, jov58 @.***> wrote:

Hi Chuck,

I'm using MySQL version 8.0.23 and version 1.2.0 of the connector. By crash I mean that the device does a soft reset when it is inside execute(). Normally (following the code above) the query is displayed in the terminal window, the query is executed, "OK" is displayed and the record is inserted in the database. But sometimes I only the query displays and then the device resets, which means it happens somewhere in execute(). One time I saw a text like "user panic mode" or something like that flashing by just before the CUT HERE line, but I haven't seen that anymore. An example output during a crash:

==> INSERT INTO ha.thermo (ntp_time, device, action, message, msgvalue, json) VALUES ('2021-03-21 21:51:07','thermoswitch','Publish','thermoswitch/living_room','','{"state":"off","name":"Living Room","physicalbutton":"enabled","isheater":"true","iscooler":"true","log":"true"}') --------------- CUT HERE FOR EXCEPTION DECODER ---------------

Soft WDT reset

stack>>>

ctx: sys sp: 3fffe8f0 end: 3fffffb0 offset: 01a0 [ snip ] 3fffffa0: feefeffe 00000000 3fff0810 40213c69 <<<stack<<<

--------------- CUT HERE FOR EXCEPTION DECODER ---------------

ets Jan 8 2013,rst cause:1, boot mode:(1,7)

ets Jan 8 2013,rst cause:4, boot mode:(1,7)

wdt reset Exception in thread rx: Traceback (most recent call last): File "C:\Users....platformio\python3\lib\threading.py", line 926, in _bootstrap_inner self.run() File "C:\Users....platformio\python3\lib\threading.py", line 870, in run self._target(*self._args, **self._kwargs) File "c:\users....platformio\penv\lib\site-packages\serial\tools\miniterm.py", line 499, in reader data = self.serial.read(self.serial.in_waiting or 1) File "c:\users....platformio\penv\lib\site-packages\serial\serialwin32.py", line 259, in in_waiting raise SerialException("ClearCommError failed ({!r})".format(ctypes.WinError())) serial.serialutil.SerialException: ClearCommError failed (PermissionError(13, 'Access is denied.', None, 5))

In the main loop() I am checking every 5 seconds if the client is connected. If not, loop() calls connect() again. I don't see the program reconnecting, so I assume the connection is open and stays open the whole time the program is running. The cursor itself is opened and closed with every query.

The mysqlLog() function in itself isn't really that exciting. It just constructs the query from some variables, then opens a cursor, executes the query and closes the cursor. I have checked every query on which the device crashes with MySQL Workbench and every query is correct.

What popped my question was the fact that I only see the device crashing when I do something on the website the device is serving with ESP Async Webserver, not on any other occassion. It looks like the problem only occurs when a query is executed while the webserver is handling a client request.

Piece of code from the webserver:

async_server.on("/update", HTTP_GET, [] (AsyncWebServerRequest *request) { bool dataChanged = false; // do stuff with request->hasParam() here ... request->send(200, "text/plain", "OK"); if (dataChanged) Publish(); // mysqlLog() is called from here } Of course it could be some other problem in my code. I'm a very experienced C++ programmer and MySQL user, but I also have my bad moments. Just haven't found this one yet :). Or perhaps I'm overestimating these ESP8266's by running a MQTT client, a MySQL client and serving multiple web clients all at the same time.

Anyway, because the crashes only seem to occur when called during a web request, I thought there might be a link of some sort.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/ChuckBell/MySQL_Connector_Arduino/issues/165#issuecomment-804022425, or unsubscribe https://github.com/notifications/unsubscribe-auth/AB6SHYHQ5U6TOBAUDJT5TTLTE4ZI3ANCNFSM4ZNDJCSA.

This is the memory usage:

RAM:   [=====     ]  49.4% (used 40428 bytes from 81920 bytes)
Flash: [======    ]  61.9% (used 471516 bytes from 761840 bytes)

While running, ESP.getFreeHeap() reports a steady ~32K free heap. So it doesn't look like a memory problem. Also, when I comment out the execute() call and leave the rest of the log function intact, there are no problems.

I'm already using a dedicated MySQL user for this device only.

I got this from ESPExceptionDecoder when analyzing the stack output:

Decoding stack results
0x40240024: mem_free at core/mem.c line 237
0x402397c0: tcp_input at core/tcp_in.c line 501
0x4023f29e: ip4_input at core/ipv4/ip4.c line 1467
0x4023624d: ethernet_input_LWIP2 at netif/ethernet.c line 188
0x4023606c: esp2glue_ethernet_input at glue-lwip/lwip-git.c line 469
0x4025ba2e: ethernet_input at glue-esp/lwip-esp.c line 365
0x4025ba3f: ethernet_input at glue-esp/lwip-esp.c line 373
0x4022138e: __ssputs_r at /home/earle/src/esp-quick-toolchain/repo/newlib/newlib/libc/stdio/nano-vfprintf.c line 233
0x4021b10d: _printf_i at /home/earle/src/esp-quick-toolchain/repo/newlib/newlib/libc/stdio/nano-vfprintf_i.c line 194
0x4022138e: __ssputs_r at /home/earle/src/esp-quick-toolchain/repo/newlib/newlib/libc/stdio/nano-vfprintf.c line 233
0x402212c4: __ssputs_r at /home/earle/src/esp-quick-toolchain/repo/newlib/newlib/libc/stdio/nano-vfprintf.c line 180
0x4022138e: __ssputs_r at /home/earle/src/esp-quick-toolchain/repo/newlib/newlib/libc/stdio/nano-vfprintf.c line 233
0x4022138e: __ssputs_r at /home/earle/src/esp-quick-toolchain/repo/newlib/newlib/libc/stdio/nano-vfprintf.c line 233
0x402212c4: __ssputs_r at /home/earle/src/esp-quick-toolchain/repo/newlib/newlib/libc/stdio/nano-vfprintf.c line 180
0x4021b238: _printf_i at /home/earle/src/esp-quick-toolchain/repo/newlib/newlib/libc/stdio/nano-vfprintf_i.c line 246
0x4022138e: __ssputs_r at /home/earle/src/esp-quick-toolchain/repo/newlib/newlib/libc/stdio/nano-vfprintf.c line 233
0x40221578: _svfprintf_r at /home/earle/src/esp-quick-toolchain/repo/newlib/newlib/libc/stdio/nano-vfprintf.c line 531
0x4022138e: __ssputs_r at /home/earle/src/esp-quick-toolchain/repo/newlib/newlib/libc/stdio/nano-vfprintf.c line 233
0x4022138e: __ssputs_r at /home/earle/src/esp-quick-toolchain/repo/newlib/newlib/libc/stdio/nano-vfprintf.c line 233
0x402212c4: __ssputs_r at /home/earle/src/esp-quick-toolchain/repo/newlib/newlib/libc/stdio/nano-vfprintf.c line 180
0x4021b238: _printf_i at /home/earle/src/esp-quick-toolchain/repo/newlib/newlib/libc/stdio/nano-vfprintf_i.c line 246
0x40235c2d: glue2esp_linkoutput at glue-esp/lwip-esp.c line 301
0x40235eba: new_linkoutput at glue-lwip/lwip-git.c line 260
0x402362dc: ethernet_output at netif/ethernet.c line 312
0x4023dab4: etharp_output_to_arp_index at core/ipv4/etharp.c line 770
0x4023f56e: ip4_output_if at core/ipv4/ip4.c line 1550
0x4023dd08: etharp_output_LWIP2 at core/ipv4/etharp.c line 885
0x4023f500: ip4_output_if_opt_src at core/ipv4/ip4.c line 1764

Don't know if you can make anything of it and if it's really related to the problem.

Opening and closing the connection in loop() doesn't work because the webserver works asynchronously. But I've found a workaround, yeey!

Instead of calling mysqlLog() directly from inside a webserver handler function, I set a flag. The flag is picked up by loop() and mysqlLog() is called from there. Since then I have seen no problems.

Excellent! When you’re satisfied it is working, kindly close the thread. Dr. Bell

On Mar 22, 2021, at 19:20, jov58 @.***> wrote:

Opening and closing the connection in loop() doesn't work because the webserver works asynchronously. But I've found a workaround, yeey!

Instead of calling mysqlLog() directly from inside a webserver handler function, I set a flag. The flag is picked up by loop() and mysqlLog() is called from there. Since then I have seen no problems.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub, or unsubscribe.

ChuckBell / MySQL_Connector_Arduino

Incompatible with ESPAsyncWebServer? #165