September 2020 - OvmsDev

Netmanager priority issue solved
by Michael Balzer 05 Jul '23

05 Jul '23

TL;DR: you need to pull my latest esp-idf changes. I've finally found & solved the strange priority changes for our netmanager task (i.e. being raised suddenly from origin 5 to 18/22): the bug was in the esp-idf posix threads mutex implementation. I had suspected the mutex priority inheritance for a while, so added a way to retrieve the internal mutex hold count for our task list. Using this I noticed the hold count would always & only raise by 2 whenever any kind of mongoose connection was closed. That lead me to checking the thread concurrency protection for mongoose mbufs, because every mongoose connection has two mbufs associated (rx & tx), each having a posix mutex. The bug was: posix mutexes were deleted after locking (taking) them. FreeRTOS mutexes must not be deleted while being taken, that breaks the priority inheritance (more precisely the disinheritance), with the visible effect being the mutex hold count not returning to zero. As a side effect, this may also solve the strange event task starvations (hope so…). I was investigating this as I suspected some busy loop in the netmanager context. With the netman running at prio 22, that would effectively block almost all other processing including the timer service. I've found & fixed one potential busy loop trigger in the netman that would have been caused by the netman task still running while all interfaces had been lost -- not sure if that could happen, but it would explain the effects. So please watch your crash debug info & report if the issue still turns up. Regards, Michael -- Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal Fon 02333 / 833 5735 * Handy 0176 / 206 989 26

5 19

ESP32 CAN controller hardware bug / interrupt issue
by Michael Balzer 03 Apr '21

03 Apr '21

Second finding & commit: TL;DR: * ESP32 CAN controller is broken, delivers trashed & duplicated RX frames * we need to optimize interrupt latency Users have been reporting occasional false BMS readings on the Twizy for more than a year. The error always trashed the reading of voltage #10 and/or temperature #8, so I initially thought that must be a variant of the SPIRAM/cache bug. But the SPIRAM fix didn't help, and the bug still occured with all BMS data in internal RAM. The issue correlated with high load situations and the SIMCOM UART issue. On testing the latest changes by Marko, my car module began showing that issue regularly, so I could take a closer look. It turned out the wrong data came from the CAN bus. Checking with a CAN logger didn't show any wrong data on the bus. So I scanned our CAN driver for potential issues, found & solved some (even a serious race condition) but that didn't fix it. I then added debug dumps of all frames read, dug into the SJA1000 spec sheet and found this: The SJA1000 RX FIFO has a capacity of 64 bytes. It's supposed to work as a ring buffer, with frames wrapping around as necessary. If no space is left in the FIFO for a new frame coming in, that frame should be discarded completely, not counted, just the overflow indicator should be set & the according interrupt be generated. Reality differs. The frame causing the overflow is added to the FIFO partially. It's also counted both in the RMC register and indicated by RBS as a valid frame when retrieving the FIFO contents. The read buffer delivers the partial frame + some trashed bytes up to the nominal frame length. In the BMS frame sequence it would normally trash bytes 7 & 8 on the sixth frame of length 8 in a sequence. A standard frame needs a 3 byte header + the data bytes in the FIFO, so 6 frames would add up to 66 bytes => 64 + 2 trash. The first trash byte normally is "08", the second "84" or "2a" or sometimes "ab", possibly some internal SJA1000 data. Better yet, if you rely on the indicators of the SJA1000 when reading the FIFO, the SJA1000 will repeat the first frame within the FIFO after the invalid frame. Mostly once or twice, and sometimes 7 times or more: inv_msg: framecnt=13, invindex=6 inv_msg: 55 01 00 00 07 98 50 54 54 20 00 6e | 4..?........U.....PTT .n inv_msg: 24 04 00 00 11 40 10 22 37 55 00 37 | 4..?........$....@."7U.7 inv_msg: 25 04 00 00 0a 1b 44 ff fe 4e 01 26 | 4..?........%.....D..N.& inv_msg: 54 05 00 00 37 37 37 37 37 37 37 00 | 4..?........T...7777777. inv_msg: 56 05 00 00 31 63 14 31 53 14 31 4a | 4..?........V...1c.1S.1J inv_msg: 57 05 00 00 31 43 14 31 53 15 *08 2a* | 4..?........W...1C.1S..* ^^^^^ trashed bytes … followed by 7 repetitions of the first frame: inv_msg: 55 01 00 00 07 98 50 54 54 20 00 6e | 4..?........U.....PTT .n inv_msg: 55 01 00 00 07 98 50 54 54 20 00 6e | 4..?........U.....PTT .n inv_msg: 55 01 00 00 07 98 50 54 54 20 00 6e | 4..?........U.....PTT .n inv_msg: 55 01 00 00 07 98 50 54 54 20 00 6e | 4..?........U.....PTT .n inv_msg: 55 01 00 00 07 98 50 54 54 20 00 6e | 4..?........U.....PTT .n inv_msg: 55 01 00 00 07 98 50 54 54 20 00 6e | 4..?........U.....PTT .n inv_msg: 55 01 00 00 07 98 50 54 54 20 00 6e | 4..?........U.....PTT .n If you had occasional strange false readings leading to strange effects, this may be the explanation. Note: the SJA1000 FIFO bug may need specific circumstance to occur in addition to the overflow, maybe the overflow happening on a specific byte position in the FIFO -- I haven't tried to determine that. I've tried clearing the overflow ASAP, looping on the IR indicator and looping on the RMC, the fault is always the same. The workaround I've now done is adding up the message lengths read during a FIFO run and discard all frames exceeding the 64 byte border. Not pretty, but functional. That keeps the trashed frames from being forwarded to the OVMS application level. As with the SIMCOM UART, these overflows wouldn't happen if the interrupt handler would react fast enough. It seems we've got a general interrupt latency issue. And just as with the SIMCOM I saw a reduction of overflows when allocating the CAN IRQ on core #0, another one with raising the IRQ level to 3, so that's also part of my commit. The esp-idf CAN driver apparently has the same issue even in the latest release, I'll contact the author about this or post another issue to Espressif. So our interrupt allocation is now: Task Run# Lvl ISR# Usage Source ---------------------------------------------------------------------------------------- - 0 1 0 RTC Core ETS_RTC_CORE_INTR_SOURCE esp_timer 0 1 0 RTOS esp_timer ETS_TIMER2_INTR_SOURCE ipc0 0 1 0 RTOS Scheduler Core0 ETS_FROM_CPU_INTR0_SOURCE ipc1 1 1 1 RTOS Scheduler Core1 ETS_FROM_CPU_INTR1_SOURCE main 0 1 0 RTOS Watchdog ETS_TG0_WDT_LEVEL_INTR_SOURCE OVMS Events 1 1 1 Peripherals (GPIO ISR) ETS_GPIO_INTR_SOURCE OVMS Events 1 1 1 MAX7317 (spi_nodma) ETS_SPI3_INTR_SOURCE *esp32can init 0 3 0 ESP32 CAN ETS_CAN_INTR_SOURCE** **OVMS SIMCOM 0 2 0 SIMCOM UART ETS_UART1_INTR_SOURCE* OVMS Events 1 1 1 USB console (UART) ETS_UART0_INTR_SOURCE OVMS Events 1 1 1 SD card ETS_SDIO_HOST_INTR_SOURCE ---------------------------------------------------------------------------------------- I think we need to find the source of the interrupt latency and/or find some better scheme to distribute the tasks & interrupts over the cores. I still don't know why core #1 already got an issue with just our 6 interrupts. This may be related to the SPIRAM fix adding overhead, but I've seen the FIFO overflows before applying the fix, and the CAN issue also has been present for over a year. My working hypothesis is some task/driver disabling interrupts for too often / too long, or non-IRAM ISRs getting delayed for too often / too long. And it seems this is an issue especially on core #1. Please verify & comment. Regards, Michael PS: a little side mystery: the netmanager task starts with priority 5, then gets raised to 22 (probably a mutex priority inheritance), but never gets lowered back to 5 afterwards. A FreeRTOS bug? -- Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal Fon 02333 / 833 5735 * Handy 0176 / 206 989 26

2 11

ELM327 codes to
by Soko 27 Nov '20

27 Nov '20

Heya, Another thing I can't figure out at the moment. I have to poll the VWeUp and I figured out (hopefully) how to do that. But I have no clue how to translate the "usual" ELM327 Header+PID to one entry for the OvmsVehicle::poll_pid_t The only value I've understood is the polltime. On my OBD2 interfaces I use a PID of 0x22028C for SoC. But PID is here only 16 bit! Where do I put the header 7E5? What is txmoduleid and rxmoduleid? I can't believe that I'm the first one with this issue ;) Couldn't find any doc though :( So I'm very thankful for any pointing in the correct direction/doc/example. thanks Soko

7 88

Plugin Repository
by Mark Webb-Johnson 20 Oct '20

20 Oct '20

I feel that our plugin system offers a missed opportunity. By making small extensions to available functionality, we can use this system to do so much - and with a much lower complexity and barrier to entry compared to C++ ESP IDF development. There are a couple of things I would like to now do: Implement a mechanism for plugins to directly extend the console command language (other than the current ’script exec PLUGIN.fn’). Implement a plugin repository, and command line tools for managing plugins. We simply need to have a store and directory of available plugins, a way of searching/listing those, and a uniform way to install/remove plugins. Once this is done, perhaps someone can handle the web UI side of this, and perhaps that can even be done as a plugin :-) I’m already working on #1. Just an extension to the existing script system to allow plugins to register commands, and to have the command register/deregister done automatically on plugin load/unload. However, #2 is a little more tricky and I’m looking for feedback on the design of this. My idea is: Store the plugins in a new github/openvehicles/Open-Vehicle-Monitoring-System-3/plugins folder. Eventually the /plugin folder will all be migrated to here. Each plugin has a unique name; the directory in /plugins. Within each plugin directory, there is a <name>.json file (JSON format) with defined tags to describe the plugin. If the plugin delivers a web extension, that is in the ‘web’ subdirectory. If the plugin delivered a script extension, that is in the ’script’ directory. Documentation (in rst format) is in the ‘docs' directory. The JSON file would need the following, at a minimum: Name: The plugin ID Title: One line title Group: Group for the plugin Version: The version string of the plugin Description: Longer textual description of the plugin Prerequisites: Prerequisites to be checked (Each plugin installed provides name=version, the system provides system-level ones such as the version of firmware, and then the prerequisites is simple a list of <name><operator><version> as required) We can automatically build the documentation, and list, for all plugins for our docs.openvehicles.com <http://docs.openvehicles.com/> (in a similar way to how it is done for /plugin now). On a repository server, as part of a nightly build job, we can automatically build a single directory JSON file from the <name>,json descriptors. We can publish this, as well as a git export/checkout of the plugins, on a http download site. On the module, we can store a list of repository servers (allowing the user to add/remove as they require). Contributors/authors of plugins simply GitHub clone our repository, and issue pull requests as appropriate. They can also have their own private repository servers (just need to host the directory json file and associated code files) and add it to their modules. The ‘plugin’ command tree on the module will provide commands for: List installed repositories Add a new repository Remove a repository List installed plugins List/Search available plugins Install a plugin Remove a plugin Update a plugin I would like to try to unify the web and script plugin systems a bit more closely. They are really two sides of the same coin (with some plugins providing both). Does that make sense? Any suggestions/comments? Regards, Mark.

4 7

Refactoring MODEM/SIMCOM for v3.3
by Mark Webb-Johnson 10 Oct '20

10 Oct '20

I have started the work on refactoring the modem driver to support virtual driver implementations (SIMCOM 5360 being just one of them). This is a major refactoring that will take some time to complete. It is likely that the following components/files will be affected: Component simcom (major changes) New component ovms_modem introduced ovms_webserver/dev/commands.htm ovms_webserver/src/web_cfg_init.cpp ovms_webserver/src/web_cfg.cpp Component powermgmt And several other components mentioning Simcom, but only very minor changes I would appreciate it if no major changes were made to those components in the next week or two, as that may make merging difficult. Once I’ve got the modem code refactored, and a compatible SIMCOM 5360 driver working, I’ll publish to the for-v3.3 branch for wider testing. I can then add the other modem drivers I have been working on. Regards, Mark. P.S. Pretty obvious that this work is to abstract out the modem type specific code, to make it easier to add support for other modem types in OVMS. This is a long-term project, and not something happening anytime soon, but I am working on it.

4 17

Modem won't start
by Chris van der Meijden 10 Oct '20

10 Oct '20

Hi all I'm suddenly having problems with the modem. It is stuck in PoweringOn and shows a signal of 0 dBm. Here the status: Network Registration: NotRegistered Provider: Signal: 0 dBm State: PoweringOn PPP: Not connected GPS: Not connected And here the debug log: I (201194) simcom: State timeout, transition to 2 I (201194) simcom: State: Enter PoweringOn state I (201194) simcom: Power Cycle D (201194) max7317: egpio.output.0.high D (202194) max7317: egpio.output.0.low D (202204) events: Signal(system.modem.poweringon) D (202204) events: Signal(egpio.output.0.high) D (202204) simcom: tx scmd ch=0 len=4 : AT D (202214) events: Signal(egpio.output.0.low) D (203194) simcom: tx scmd ch=0 len=4 : AT D (204194) simcom: tx scmd ch=0 len=4 : AT D (205194) simcom: tx scmd ch=0 len=4 : AT D (206194) simcom: tx scmd ch=0 len=4 : AT D (207194) simcom: tx scmd ch=0 len=4 : AT D (208194) simcom: tx scmd ch=0 len=4 : AT D (209194) simcom: tx scmd ch=0 len=4 : AT D (210194) simcom: tx scmd ch=0 len=4 : AT D (211194) simcom: tx scmd ch=0 len=4 : AT D (212194) simcom: tx scmd ch=0 len=4 : AT D (213194) simcom: tx scmd ch=0 len=4 : AT D (214194) simcom: tx scmd ch=0 len=4 : AT D (215194) simcom: tx scmd ch=0 len=4 : AT D (216194) simcom: tx scmd ch=0 len=4 : AT D (217194) simcom: tx scmd ch=0 len=4 : AT D (218194) simcom: tx scmd ch=0 len=4 : AT D (219194) simcom: tx scmd ch=0 len=4 : AT D (220194) simcom: tx scmd ch=0 len=4 : AT D (221194) simcom: tx scmd ch=0 len=4 : AT Hard reset did not help ... I found this discussion https://www.openvehicles.com/node/2381 with recent postings. Could there be a general problem with the modem, or is it my hardware (again ...)? Thanx Chris

4 10

USB port fragility
by Michael Balzer 10 Oct '20

10 Oct '20

Mark, I've had multiple cases now of damaged and broken off USB ports. I've added a fragility warning to the user guide: https://docs.openvehicles.com/en/latest/userguide/components.html#the-ovms-… Maybe we should add that to the multilingual quick start info sheet coming with the module as well? Regards, Michael -- Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal Fon 02333 / 833 5735 * Handy 0176 / 206 989 26

8 12

Re: [Ovmsdev] can log vfs crashes
by Derek Caudwell 01 Oct '20

01 Oct '20

Hi Michael, When the vehicle is not set to poll and only receiving can1 messages I managed to obtain a 10Mb file - logging a variety of signals some with 10ms timing without any issues. However, when polling and can1/can2 are operating and I try to log the same signals I get the following crash trace. I would suspect the underlying cause of the crashing relates to both buses being active as opposed to the polling but that may not be the case. Last crash: abort() was called on core 0 Backtrace: 0x4008e627 0x4008e8c1 0x400e7060 0x40083f6a Event: ticker.1@esp32wifi 0 secs WDT tasks: IDLE1|OVMS DukTape 0x4008e627 is in invoke_abort (/mnt/c/linux/ovms/esp-idf/components/esp32/panic.c:156). 151 #endif 152 while (1) { 153 if (esp_cpu_in_ocd_debug_mode()) { 154 __asm__ ("break 0,0"); 155 } 156 *((int *) 0) = 0; 157 } 158 } 159 160 void abort() 0x4008e8c1 is in abort (/mnt/c/linux/ovms/esp-idf/components/esp32/panic.c:171). 166 * don't overwrite that. 167 */ 168 if (esp_reset_reason_get_hint() == ESP_RST_UNKNOWN) { 169 esp_reset_reason_set_hint(ESP_RST_PANIC); 170 } 171 invoke_abort(); 172 } 173 174 175 static const char *edesc[] = { 0x400e7060 is in task_wdt_isr (/mnt/c/linux/ovms/esp-idf/components/esp32/task_wdt.c:174). 169 esp_task_wdt_isr_user_handler(); 170 if (twdt_config->panic){ //Trigger Panic if configured to do so 171 ESP_EARLY_LOGE(TAG, "Aborting."); 172 portEXIT_CRITICAL_ISR(&twdt_spinlock); 173 esp_reset_reason_set_hint(ESP_RST_TASK_WDT); 174 abort(); 175 } 176 177 portEXIT_CRITICAL_ISR(&twdt_spinlock); 178 } 0x40083f6a is at /mnt/c/linux/ovms/esp-idf/components/freertos/xtensa_vectors.S:1154. 1149 wsr a0, PS 1150 rsync 1151 1152 /* OK to call C code at this point, dispatch user ISRs */ 1153 1154 dispatch_c_isr 1 XCHAL_INTLEVEL1_MASK 1155 1156 /* Done handling interrupts, transfer control to OS */ 1157 call0 XT_RTOS_INT_EXIT /* does not return directly here */ 1158

2 1

Duktape Persistent Function References
by Mark Webb-Johnson 28 Sep '20

28 Sep '20

@Michael this is probably for you. I am trying to implement javascript command registration. The idea is that a javascript module can call something like: OvmsCommand.Register(basecommand, name, title, callbackfn, usage, min, max) Then we reflect that into MyCommandApp.RegisterCommand, and keep a track of which command is for which javascript callbackfn. When the command is executed, we pass it into duktape. I also have tracking for javascript module loading and unloading, so I can DeregisterCommand() if duktape is reloaded (and also protected against commands being registered in short-lived scripts run from the command line). To implement this, I need to store the callbackfn as a persistent reference to a duktape javascript function. The issue with callback function references in duktape is summarised here: https://wiki.duktape.org/howtonativepersistentreferences <https://wiki.duktape.org/howtonativepersistentreferences> When a Duktape/C function is called, Duktape places the call arguments on the value stack. While the arguments are on the value stack, they're guaranteed to be reachable and the Duktape/C function can safely work with the arguments. However, when the Duktape/C function returns, the value stack is unwound and references in the function's value stack frame are lost. If the last reference to a particular value was in the function's value stack frame, the value will be garbage collected when the function return is processed. The standard approach is to store the reference back in the duktape duk_push_global_stash so it won’t get garbage-collected. But, that seems messy. I see that Michael has already implemented something that seems similar in ovms_script.{h, cpp}, for the async http callbacks. Presumably to avoid this issue. But, the approach seems very different, and I am not sure if it is stopping _all_ garbage collection for the duration of the async query, or just that particular object being garbage collected. The work seems extensive (quite a few objects involved). So @Michael, any suggestions for this? I don’t want to reinvent the wheel... Regards, Mark.

3 18

Fwd: Your app Open Vehicles (490098531) has been approved for beta testing.
by Mark Webb-Johnson 28 Sep '20

28 Sep '20

This contains the image updates. Regards, Mark > > > > > Build 1.8.3 (20200928) of your app has been approved for TestFlight beta testing. > > App Name: Open Vehicles > App Apple ID: 490098531 > Bundle Version Short String: 1.8.3 > Build Number: 20200928 > Platform: iOS > SKU: OVMS-IOS

1 0