Ah, of course.  Depending on timing, I was calling xQueueReceive for a queue I hadn't created yet, regardless of the contents of said queue.  Listening just directs stuff into the queue.

Anyway, pull request created.  Let me know if this isn't what you envisioned for a fix.

Greg


Michael Balzer wrote:
Greg,

the task is messaged to, not called by the CAN framework, it runs as soon as it is created.

Regards,
Michael


Am 23.05.2018 um 22:16 schrieb Greg D.:
Ha, that's interesting.  I've pushed a fix to swap the ordering, but am not quite convinced that this is the issue.  The order of creation shouldn't matter because the OBD2ECU task doesn't register itself as a listener until after both are done.  So why would it even be called? 

Greg


Michael Balzer wrote:
Greg,

I just had a look. That crash is simply due to an initialization order mistake in your constructor, has nothing to do with the CAN bus: you create the m_rxqueue _after_ starting the OBD2ECU_task, which uses the m_rxqueue:

static void OBD2ECU_task(void *pvParameters)
  {
  obd2ecu *me = (obd2ecu*)pvParameters;

  CAN_frame_t frame;
  while(1)
    {
    if (xQueueReceive(me->m_rxqueue, &frame, (portTickType)portMAX_DELAY)==pdTRUE)
      {
      // Only handle incoming frames on our CAN bus
      if (frame.origin == me->m_can) me->IncomingFrame(&frame);
      }
    }
  }

obd2ecu::obd2ecu(const char* name, canbus* can)
  : pcp(name)
  {
  m_can = can;
  xTaskCreatePinnedToCore(OBD2ECU_task, "OVMS OBDII ECU", 6144, (void*)this, 5, &m_task, 1);

  m_rxqueue = xQueueCreate(20,sizeof(CAN_frame_t));




So the task can reach the xQueueReceive() call before the queue is actually usable.

Regards,
Michael


Am 23.05.2018 um 03:29 schrieb Greg D.:
Hi Mark,

Yeah, big shrug here too.  It occurs infrequently, during what was a reboot anyway, and the system recovered itself, so this isn't a critical issue unless it keeps happening (i.e. a crash/reboot loop).  I suppose it could also occur with a frame coming in from a HUD, though that CAN bus is on a different interface chip so if the cause is hardware dependent, it might not occur.

Perhaps we need to not launch the higher level applications (e.g. OBD2ECU) until maybe the 5 second mark, when we know the system is initialized and otherwise pretty stable, but within that "Early" timeframe?  Just a thought,

Greg


Mark Webb-Johnson wrote:
Greg,

Yes, the MyCan.RegisterListener(m_rxqueue) will register for all messages on all CAN buses.

I am trying to work out a neat way of adding filters to this (both hardware and software). Some easy standard way of filtering traffic in a standard way (like the BFP filters in Unix variants do for ethernet traffic). That will give us a performance boost for things like odb2ecu, retools, etc.

But you already have a "if (frame.origin == me->m_can)”, so not sure how this could be affecting you?

What precisely is "early" in the context of a boot crash?  That would put a bound on the size and location of the timing window.

10 seconds, I believe. You can see it with the message "I (10576) housekeeping: System considered stable (RAM: 8b=99060-99176 32b=20)” about 10 seconds into the boot.

Regards, Mark.

On 23 May 2018, at 7:55 AM, Greg D. <gregd2350@gmail.com> wrote:

Hi Michael,

Correct, not a config issue.  I had assumed it was a race condition (first time I've seen it), but didn't realize it involved my code.  Yikes!

This is the call-back into the OBD2ECU task when a CAN frame is received in the system.  Apparently everyone looking for a CAN frame gets called when a frame is received from any bus, and each process needs to filter out the ones they own.  So, somehow a CAN frame was seen to have been received before the system was fully initialized.  Perhaps something dropped into the hardware buffer after the chip was turned on, but not before the O/S had gotten everything situated for handling it.  I don't currently have anything connected to the OBDII CAN bus (CAN3) on my module, so this must have been a frame from the car itself on CAN 1.  CAN 2 is not used in my car.

What precisely is "early" in the context of a boot crash?  That would put a bound on the size and location of the timing window.

Greg


Michael Balzer wrote:
Greg,

the backtrace says the crash happened here:

0x4008f6de is in vTaskEnterCritical (/Users/mark/esp/esp-idf/components/freertos/include/freertos/portmacro.h:283).
278     * Warning: From the ISA docs: in some (unspecified) cases, the s32c1i instruction may return the
279     * *bitwise inverse* of the old mem if the mem wasn't written. This doesn't seem to happen on the
280     * ESP32 (portMUX assertions would fail).
281     */
282    static inline void uxPortCompareSet(volatile uint32_t *addr, uint32_t compare, uint32_t *set) {
283        __asm__ __volatile__ (
284            "WSR         %2,SCOMPARE1 \n"
285            "S32C1I     %0, %1, 0     \n"
286            :"=r"(*set)
287            :"r"(addr), "r"(compare), "0"(*set)
0x4008eb10 is in xQueueGenericReceive (/Users/mark/esp/esp-idf/components/freertos/./queue.c:1455).
1450        statements within the function itself.  This is done in the interest
1451        of execution time efficiency. */
1452   
1453        for( ;; )
1454        {
1455            taskENTER_CRITICAL(&pxQueue->mux);
1456            {
1457                /* Is there data in the queue now?  To be running the calling task
1458                must be    the highest priority task wanting to access the queue. */
1459                if( pxQueue->uxMessagesWaiting > ( UBaseType_t ) 0 )
0x4011f3fd is in OBD2ECU_task(void*) (/Users/mark/Documents/ovms/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3/components/obd2ecu/src/obd2ecu.cpp:155).

150      obd2ecu *me = (obd2ecu*)pvParameters;
151   
152      CAN_frame_t frame;
153      while(1)
154        {
155        if (xQueueReceive(me->m_rxqueue, &frame, (portTickType)portMAX_DELAY)==pdTRUE)
156          {
157          // Only handle incoming frames on our CAN bus
158          if (frame.origin == me->m_can) me->IncomingFrame(&frame);
159          }


So I assume that's the same bug I already reported in issue #103:

https://github.com/openvehicles/Open-Vehicle-Monitoring-System-3/issues/103

…and as it now happened to you, I assume it's not configuration related. Can you verify my assumption?

Looks like an init race condition, i.e. m_rxqueue used in undefined state.

Regards,
Michael



Am 22.05.2018 um 19:24 schrieb Greg D.:
Just noticed this on my production 3.1 module.  Was this an artifact of the 
upgrade from .005 to .006?

Last boot was 140983 second(s) ago
Time at boot: 2018-05-20 19:05:59 PDT
This is reset #17 since last power cycle
Detected boot reason: EarlyCrash (12/12)
Crash counters: 1 total, 1 early
Last crash: StoreProhibited exception on core 1
Registers:
PC : 0x4008f6de PS : 0x00060033 A0 : 0x8008eb13 A1 : 0x3ffd6150
A2 : 0xfefeff4e A3 : 0x0000abab A4 : 0xb33fffff A5 : 0x00000001
A6 : 0x00060020 A7 : 0x0000cdcd A8 : 0x0000abab A9 : 0x3ffd6150
A10 : 0x00000003 A11 : 0x00060023 A12 : 0x00060020 A13 : 0x3ffb4188
A14 : 0x000001e8 A15 : 0x00001800 SAR : 0x00000000 EXCCAUSE: 0x0000001d
EXCVADDR: 0xfefeff4e LBEG : 0x00000000 LEND : 0x00000000 LCOUNT : 0x00000000
Backtrace:
0x4008f6de 0x4008eb10 0x4011f3fd 0x40174f95 0x400e73be 0x400e4699 0x40085149 
0x40128bc2 0x40128df7 0x401287b4 0x400ea22d 0x400eac7a 0x400ead09 0x400ead19 
0x402207d6 0x400e9ece 0x400e9f79 0x400e45f5 0x400e4604 0x400f5c09 0x400f035d
Version: 3.1.006/ota_0/main (build idf v3.1-dev-455-gf4905cdf May 20 2018 20:08:31)
--------------------------------------------------------------------------------
Running partition: ota_0
Boot partition: ota_0
Firmware: 3.1.006/ota_0/main (build idf v3.1-dev-455-gf4905cdf May 20 2018 20:08:31)


_______________________________________________
OvmsDev mailing list
OvmsDev@lists.openvehicles.com
http://lists.openvehicles.com/mailman/listinfo/ovmsdev

-- 
Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal
Fon 02333 / 833 5735 * Handy 0176 / 206 989 26


_______________________________________________
OvmsDev mailing list
OvmsDev@lists.openvehicles.com
http://lists.openvehicles.com/mailman/listinfo/ovmsdev

_______________________________________________
OvmsDev mailing list
OvmsDev@lists.openvehicles.com
http://lists.openvehicles.com/mailman/listinfo/ovmsdev



_______________________________________________
OvmsDev mailing list
OvmsDev@lists.openvehicles.com
http://lists.openvehicles.com/mailman/listinfo/ovmsdev



_______________________________________________
OvmsDev mailing list
OvmsDev@lists.openvehicles.com
http://lists.openvehicles.com/mailman/listinfo/ovmsdev

-- 
Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal
Fon 02333 / 833 5735 * Handy 0176 / 206 989 26


_______________________________________________
OvmsDev mailing list
OvmsDev@lists.openvehicles.com
http://lists.openvehicles.com/mailman/listinfo/ovmsdev



_______________________________________________
OvmsDev mailing list
OvmsDev@lists.openvehicles.com
http://lists.openvehicles.com/mailman/listinfo/ovmsdev

-- 
Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal
Fon 02333 / 833 5735 * Handy 0176 / 206 989 26


_______________________________________________
OvmsDev mailing list
OvmsDev@lists.openvehicles.com
http://lists.openvehicles.com/mailman/listinfo/ovmsdev