[Ovmsdev] Early Crash (v.006)

Mark Webb-Johnson mark at webb-johnson.net
Thu May 24 08:20:16 HKT 2018


Greg, I merged your request. But it conflicted with the change I had just made (and pushed) a few hours earlier - to fix the same issue.

Anyway, I cleaned things up a bit, so the init ordering looks better now. Please try.

Regards, Mark.

> On 24 May 2018, at 4:52 AM, Greg D. <gregd2350 at gmail.com> wrote:
> 
> 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 at gmail.com <mailto:gregd2350 at 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 <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 at lists.openvehicles.com <mailto:OvmsDev at lists.openvehicles.com>
>>>>>>>>> http://lists.openvehicles.com/mailman/listinfo/ovmsdev <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 at lists.openvehicles.com <mailto:OvmsDev at lists.openvehicles.com>
>>>>>>>> http://lists.openvehicles.com/mailman/listinfo/ovmsdev <http://lists.openvehicles.com/mailman/listinfo/ovmsdev>
>>>>>>> 
>>>>>>> _______________________________________________
>>>>>>> OvmsDev mailing list
>>>>>>> OvmsDev at lists.openvehicles.com <mailto:OvmsDev at lists.openvehicles.com>
>>>>>>> http://lists.openvehicles.com/mailman/listinfo/ovmsdev <http://lists.openvehicles.com/mailman/listinfo/ovmsdev>
>>>>>> 
>>>>>> 
>>>>>> 
>>>>>> _______________________________________________
>>>>>> OvmsDev mailing list
>>>>>> OvmsDev at lists.openvehicles.com <mailto:OvmsDev at lists.openvehicles.com>
>>>>>> http://lists.openvehicles.com/mailman/listinfo/ovmsdev <http://lists.openvehicles.com/mailman/listinfo/ovmsdev>
>>>>> 
>>>>> 
>>>>> 
>>>>> _______________________________________________
>>>>> OvmsDev mailing list
>>>>> OvmsDev at lists.openvehicles.com <mailto:OvmsDev at lists.openvehicles.com>
>>>>> http://lists.openvehicles.com/mailman/listinfo/ovmsdev <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 at lists.openvehicles.com <mailto:OvmsDev at lists.openvehicles.com>
>>>> http://lists.openvehicles.com/mailman/listinfo/ovmsdev <http://lists.openvehicles.com/mailman/listinfo/ovmsdev>
>>> 
>>> 
>>> 
>>> _______________________________________________
>>> OvmsDev mailing list
>>> OvmsDev at lists.openvehicles.com <mailto:OvmsDev at lists.openvehicles.com>
>>> http://lists.openvehicles.com/mailman/listinfo/ovmsdev <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 at lists.openvehicles.com <mailto:OvmsDev at lists.openvehicles.com>
>> http://lists.openvehicles.com/mailman/listinfo/ovmsdev <http://lists.openvehicles.com/mailman/listinfo/ovmsdev>
> 
> _______________________________________________
> OvmsDev mailing list
> OvmsDev at lists.openvehicles.com
> http://lists.openvehicles.com/mailman/listinfo/ovmsdev

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.openvehicles.com/pipermail/ovmsdev/attachments/20180524/2a8623ae/attachment.htm>


More information about the OvmsDev mailing list