Regular crashes by watchdog timer for smart EQ

[joshuajung]

Hi there, some other Smart EQ users and I feel like we are seeing an increased number of crashes recently (sometimes up to 7 per day), all with a 0x4008ddae 0x4008e049 0x400e9884 0x4008418a backtrace:

 ./a2l 0x4008ddae 0x4008e049 0x400ea610 0x4008418a
Using elf file: ./ovms3.elf
0x4008ddae is in invoke_abort (/home/balzer/esp/esp-idf/components/esp32/panic.c:156).
0x4008e049 is in abort (/home/balzer/esp/esp-idf/components/esp32/panic.c:171).
166     in /home/balzer/esp/esp-idf/components/esp32/panic.c
0x400ea610 is in task_wdt_isr (/home/balzer/esp/esp-idf/components/esp32/task_wdt.c:174).
0x4008418a is at /home/balzer/esp/esp-idf/components/freertos/xtensa_vectors.S:1154.

This is with current edge firmwares, and reproduction seems to be tricky (or at least we haven't yet understood how). I have been seeing crashes with this backtrace at least since firmware 423, but for me they became more prevalent after upgrading from 469 to 476. Module configuration is pretty standard otherwise (v2 only), and behavior is as expected in general.

My understanding is that the task watchdog timer monitors tasks and reboots the module/crashes in case one of them times out, right? I'm not sure if it's worth digging into this in detail, but I wanted to at least document the issue for other users with the same crash signature.

[dexterbg]

Stability is excellent with my VWUP vehicle module, so I'd assume some vehicle or plugin dependent issue.

The task watchdog triggers when high CPU activity blocks processing for too long. That may be caused by bugs as well as plugins or too high load from connected clients. The crash reports sent to the server try to provide context of the crash (running tasks), but watchdog triggers are generally hard to track down post mortem.

You're welcome to dig into the vehicle & version type crash statistics I provide on my server:

• https://dexters-web.de/f/firmware/developer/crashreport-overview.csv
• https://dexters-web.de/f/firmware/developer/crashreport.csv

These are updated every full hour.

Regards,
Michael

[joshuajung]

Thank you @dexterbg. I had a look at the files and while there are quite a few Watchdog crashes for SE/SQ, they do not seem to be limited to any recent firmware versions.

To get a clearer picture, one would probably need

1. The total number of vehicles with a specific type using a specific firmware (to check if SE/SQ or specific firmware versions have an increased crash prevalence compared to others)
2. Historical data (to check if there are actually more crashes these days, or if this is a mere case of collective confirmation bias)

I assume both aren't readily available, are they? No worries if not so, modules seem to recover fine after crashing/rebooting and at least for me this is not a huge pain point.

[zbchristian]

Recently I definetly observed more crashed due to task watchdog timeouts. By chance, I run OVMS with a Smart EQ, but I think, that the reason is independent from the actual car.

• Crashes only happen while driving and wifi is not available
• Crashes seem to be related to lost network connections and the modem tries to reconnect

In my case the problem is related to the behavior of the modem (with wifi off):

• The ppp connection is first established only with an IPV6 address
  • the event system.modem.gotip is triggered, which will start the network manager (mongoose)
• shortly afterwards the connection is restablished including IPV4 and IPV6 address
  • this triggers again system.modem.gotip and the ModemUp handler tries to start another netmanager, but gets stuck in a endless while loop in StartMongooseTask, because the first netmanager is already running
  • So the second system.modem.gotip event does not finish and the task watchdog kicks in

The actual reason is, that the timing between the two identical events is too close, and the m_mongoose_running flag is not set fast enough.

I assume, that the mobile network providers start to use more and more IPV6, hence this issue will depend on the mobile network provider, the actual modem and even its firmware version.
For a given OVMS module this might be relevant or not.

For example, I have two identical modems, with different Simcom firmware versions. The older firmware does not connect via IPV6 at all and there is no issue.

How to check, if this is a problem:

• Start the module with the console connected via USB
• Wait for wifi and the cellular modem to connect
• Issue the following commands:
  • enable + password to enter secure mode
  • log level verbose
  • wifi mode off
  • cellular setstate NetLoss
• Wait for the modem to reconnect
• Check the event status event status. If the event system.modem.gotip is collecting time, the watchdog will eventually kick in.

If a minute later the reboot occurs, the module is vulnerable to this problem and the reboot will happen each time the modem has to reconnect after a signal loss.

In the console dump below you can see the behavior. The last lines are debug messages I put into the code and which originate from the second call to StartMongooseTask.

@dexterbg here a simple fix: add a check on m_mongoose_running into the while loop in OvmsNetManager::StartMongooseTask() in ovms_netmanager.cpp
Not very elegant, but very efficient ...

void OvmsNetManager::StartMongooseTask()
  {
  if (!m_mongoose_running)
    {
    if (m_network_any)
      {
      // wait for previous task to finish shutting down:
      while (m_mongoose_task ) {
        vTaskDelay(pdMS_TO_TICKS(50));
        if (m_mongoose_running) return;
      }
      // start new task:
      xTaskCreatePinnedToCore(MongooseRawTask, "OVMS NetMan",10*1024, (void*)this,
                              CONFIG_OVMS_NETMAN_TASK_PRIORITY, &m_mongoose_task, CORE(1));
      AddTaskToMap(m_mongoose_task);
      }
    }
  }

[dexterbg]

Thanks, Christian, very helpful analysis.

Your proposed solution is most probably producing another race condition (on task shutdown), and the cause is most probably not the most common one here, but the mongoose task start/stop control is definitely broken and can fail in that way when called too quickly in series.

The crash reports currently only show a single entry with the current event being system.modem.gotip, but quite a lot with system.wifi.ap.start. These actually also show a high share of Smart vehicles, which is probably due to many Smart drivers being still new to the OVMS and not yet having disabled the AP mode. Most users disable AP mode after initial setup, as that uses a lot of power and normally isn't needed for normal operation.

So instead of the Smart adaption, possibly the Wifi AP mode mostly causes this issue, but most probably out of the same reason/flaw you detected with the task control method, as the Wifi STA & AP events also can come quickly in series.

I'll have a closer look.

[zbchristian]

Yes, this is just my quick fix.
I assume a real locking mechanism is needed to ensure, that only a single netmanager is running at any given time. and that no deadlock can occur.

[dexterbg]

Christian, please test.

[zbchristian]

Michael,
I ran once more the old version - reboot after 1min.

After the update the modem reconnects without a problem to the network and no more delay in prcessing the second system.modem.gotip event.

So, seems to work!