May 2020 - OvmsDev - Open Vehicles

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

02 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

Hacking TPMS
by Mark Webb-Johnson 24 Aug '20

24 Aug '20

I’ve been spending the last month or so hacking away at TPMS. This has been an ongoing project for the Tesla Roadster that is finally coming to fruition. About a year or so ago, we already made changes to: Modify the Tesla Roadster cable to connect the k-line pin on the diagnostic connector through to the DB9 connector on OVMS. We labelled this cable ‘OVT1’. Modify the OVMS module to connect that k-line pin to GEP7. I’m now working on an optional expansion board that will include a little TJA1027T transceiver and map it to EXP1 and EXP2 (for async comms) and EGPIO8 (for enable/disable) on the ESP32 and MAX. This board will include a jumpered option for K-line master (one diode + one resistor), as well as jumpered powered selection (5v from usb, 5v regulated from car 12v, or direct car 12v) for the K-line bus. The hand-soldered prototype, using our breakout boards, works well and the K-line async comms works. The screenshot shows OVMS sending a 19 byte request to the ECU (0x0f 0x04 .... 0xf0) and the ECU responding 19 bytes (0x0f 0x05 ... 0xf0) with the 4 tyre IDs. There is a similar command to re-program the ECU with new IDs. On the firmware side, I am implementing a new vehicle independent ’tpms’ subsystem within OVMS (enabled via configureable option). This will allow sets of tyres to be maintained in the config and read/written to the car's TPMS ECU. The following commands will be available: tpms status - show status of the system tpms list - list tyre id sets in config tpms read <set> - read IDs from tpms ecu and store in config tyre set tpms write <set> - write IDs to toms ecu from config tyre set tpms set <set> {<id>} - config a set of IDs manually tpms delete <set> - delete the specified tyre set The initial version will support Tesla Roadster, but the functionality is there for other vehicles to use if they need it (in particular for standard K-line implementations). Comments/suggestions welcome. Regards, Mark. +++Attachments+++ Bench setup, showing (from left to right): Tesla Roadster TPMS ECU opened up Breakout board (power, k, Lin, and can) OVMS for can decode Usb logic analyser Power supply (12v) K-line analysis tool (9010) Windows laptop running k-line software Mac running logic analyser and terminal to OVMS. Hand-soldered prototyping board Async comms over k-line.

4 9

File logging task
by Michael Balzer 04 Jul '20

04 Jul '20

Everyone, I've pushed the long due refactoring of the file logging into a dedicated task. This removes most of the delays involved in file logging, as the fsync() and log cycling now is done in the logging task and no longer blocks overall log message processing. I stumbled upon a bad thing (tm) though we need to resolve with logging: the esp-idf logging generally involves a semaphore wait of max 10 ms (!). I wasn't aware of this because I didn't look into the source before, there also is no warning about this in the esp-idf documentation (https://docs.espressif.com/projects/esp-idf/en/latest/api-reference/system/…) so I guess I'm not the only one being taken by surprise here. // Maximum time to wait for the mutex in a logging statement. #define *MAX_MUTEX_WAIT_MS 10* #define MAX_MUTEX_WAIT_TICKS ((MAX_MUTEX_WAIT_MS + portTICK_PERIOD_MS - 1) / portTICK_PERIOD_MS) … void IRAM_ATTR *esp_log_write*(esp_log_level_t level, const char* tag, const char* format, ...) { if (!s_log_mutex) { s_log_mutex = xSemaphoreCreateMutex(); } if (*xSemaphoreTake(s_log_mutex, MAX_MUTEX_WAIT_TICKS*) == pdFALSE) { return; } … That semaphore is needed to secure the log level tag cache against parallel access, so it also affects log messages of currently disabled tags and/or levels. This means we *must not* use the standard logging from timer callbacks, at no verbosity level. But we do, partially caused by my own code serving as a bad example I assume -- sorry. But I've not only found direct log calls in most vehicle timer callbacks, there also are some hidden ones from calling the framework, for example marking a notification as read can produce a log output from Cleanup() if tracing is enabled. We need to change this short to mid term. This may be the cause of those strange timer overflow issues we've seen occasionally. It also means every debug or verbose log output currently in the code involves potentially multiple semaphore waits, that's for example the case for all hex dumps logged by the SIMCOM module. Our primary option is to remove all log calls from all low level framework functions and timer callbacks. A simple & quick workaround could be to extend the ESP_LOGx macros to check if they are executed in the timer task context, if so suppress the message or call the ESP_EARLY log function instead. That will hide these log messages from the logging framework though, if using the _EARLY_ variant they only will be sent to the USB port. For a better solution I thought about adding a dedicated queue & task for the initial log submission as well. That will need quite some rework to the esp-idf (no changes for this in the current master) but would allow to continue logging as we do now. Cons: queue submission involves some overhead & RAM, printf format expansion needs to be done before the tag/level check, messages may need to be dropped if the task starves or RAM gets tight, log output to consoles will depend on a task as well. Opinions / better ideas? Regards, Michael -- Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal Fon 02333 / 833 5735 * Handy 0176 / 206 989 26

2 5

3.2.013
by Mark Webb-Johnson 10 Jun '20

10 Jun '20

Getting ready to release 3.2.013. I’ve tagged it, and built for api.openvehicles.com <http://api.openvehicles.com/> edge. The main changes here are: TPMS subsystem (including Tesla Roadster support with new optional K-line expansion board) Change to config for server.v2 For #2, I moved the server password from server.v2/password to password/server.v2, and made the server.v2 config parameter read-write. That better matches how server.v3 does it. The change is done via a config migration, so should be transparent. Absent any issues, I plan to move to EAP early in the coming week. Regards, Mark

3 10

What happened to TPMS?
by Greg D. 06 Jun '20

06 Jun '20

6 13

UserTrust/AddTrust/Comodo root CA expiration
by Mark Webb-Johnson 04 Jun '20

04 Jun '20

The AddTrust root CA certificate that our api.openvehicles.com <http://api.openvehicles.com/> is signed by has expired (last night). This will impact TLS connections to api.openvehicles.com <http://api.openvehicles.com/>. Our certificate itself is fine (and doesn’t expire until Feb 2022), but the root cert is was signed by (via intermediaries) has expired. Pretty irresponsible for AddTrust/UserTrust/Comodo to sign a certificate with a later expiration date than their own CA, imho. Also irresponsible for them not to inform the customers. Everybody can be expected to monitor their own certificate expiration date, but not that of their certificate authority. I’ve been up most of the night dealing with fallout from this (in other work and customer related systems), so not happy. Anyway, I’ve updated the trusted root certificate in edge now, and released that. AddTrust has become UserTrust. To connect via tls to api.openvehicles.com <http://api.openvehicles.com/> now, you will either need to firmware update, or manually add the trusted ca to /store/trustedca/usertrust.crt (I have attached it here, for convenience). I have also taken this opportunity to change the server v2 and v3 backoff retry times to 60 seconds (was 20 or 30). Regards, Mark.

4 3

J1850 support research
by Craig Leres 25 May '20

25 May '20

I've been doing some research on a possible J1850 expansion board; I've looked at the (nice!) work that Mark and Marko have done on TPMS and SWCAN expansion boards. It looks like the TPMS expansion adds the k-line (LIN bus) to the previously unused pin 1 of the DB9. I think I can also use pin 1 for the J1850 bus. The J1850 protocol chip I'm using (HIP7010) uses SPI as does the SWCAN board. The ESP32 docs say there are four SPI devices. Two are used for flash tasks leaving HSPI and VSPI. I believe ovms uses HSPI for SPI ram access and VSPI is used to run the can buses (and SWCAN when present). The problem I see is that the HIP7010 must be SPI master; unlike I2C I don't think you can have more than one SPI bus master. I think this means my best approach is to build a J1850 to canbus protocol bridge and just encapsulate J1850 frames in can frames? I think I could still feed the J1850 bus on pin 1 of the DB9. This way the protocol bridge would only need the HD25 connector to do everything: J1850, 5V, vehicle 12V (needed by the J1850 transceiver), and can bus lines. Am I correct in talking myself out of an expansion board? Craig

2 3

HttpApi fixed & deployed
by Sébastien Darveau 19 May '20

19 May '20

Hi all, I’ve contributed for the first time to the OVMS project by fixing a few things in the server code related to the REST Api. That was not easy since I’m not familiar with Perl but I want my soc on my Garmin watch! I’m an experienced software consultant from Montreal. I’ve been working in the mobile game and broadcast industries but I’m now into Xamarin so maybe I could give my help to the unified mobile app development. Let me know if this is still planned. I also have a Leaf 2015 with OVMS and it’s an awesome project! Best, Sebastien Darveau

2 1

Locations (actions, etc)
by Mark Webb-Johnson 05 May '20

05 May '20

Steve, What is the current status of the changes you have been making to the locations system? I have a user asking why: >location set Likini >location action enter Likini notiffy entered >****: location action enter Likini notify entered Unregconised command Usage: location action enter <location> acc <profile> Usage: location action enter <location> homelink 1|2|3 Usage: location action enter <location> notify <text> Was this ever completed? Regards, Mark

3 3

3.2.012 EAP OTA
by Mark Webb-Johnson 01 May '20

01 May '20

I think the tpms bug is serious enough to require a release. So, I’ve built a 3.2.012 and released to EAP at api.openvehicles.com <http://api.openvehicles.com/>. 2020-04-22 MWJ 3.2.012 OTA release - #357 tpms rear left temperature incorrect in v2 protocol - #354 Flush UART buffer when power cycling modem - General stability improvements to CAN logging and playback As usual, for full changelog see: https://github.com/openvehicles/Open-Vehicle-Monitoring-System-3/blob/maste… <https://github.com/openvehicles/Open-Vehicle-Monitoring-System-3/blob/maste…> This will also allow us to get more feedback on the uart reset approach, and if it makes any difference to those modules that can’t seem to recover from loss of cellular connection. Regards, Mark.

3 5