[Ovmsdev] Need some help on CAN errors

Michael Balzer dexter at expeedo.de
Mon Sep 21 20:31:16 HKT 2020 

FYI: the errors in your log were no real errors, they were just RX
buffer 0 to buffer 1 rollover events, i.e. RX0 was full, so the message
was stored in RX1.

A real overflow (loss of frame) would have been counted in "rxovr".

An RX0 overflow indicates the MCP SPI communication isn't fast enough to
retrieve & process all frames immediately.

We had this discussion before: it seems the buffer rollover is pretty
common on the MCP buses. Maybe we really shouldn't consider it an error
condition? Users also get irritated by these:

https://www.openvehicles.com/node/2558

Regards,
Michael


Am 21.09.20 um 12:30 schrieb Chris van der Meijden:
> I'm back on track.
>
> With the fix and some changes on my code I now get all 22 messages
> through in the right order. The doors won't unlock though, but that is
> an other problem.
>
> This is my new code:
>
>         unsigned char data[8];
>         uint8_t length;
>         length = 8;
>
>         unsigned char data2[2];
>         uint8_t length2;
>         length2 = 2;
>
>         canbus *comfBus;
>         comfBus = m_can3;
>
>         // This is a very dirty workaround to get the wakup of the ring
> working.
>         // We send 0x69E some values without knowing what they do.
>
>         data2[0] = 0x14;
>         data2[1] = 0x42;
>         if (vwup_enable_write && !dev_mode)
>             comfBus->WriteStandard(0x69E, length2, data2);
>
>         vTaskDelay(10 / portTICK_PERIOD_MS);
>
>         // Send 0x291 messages
>
>         for (k=0;k<15;k++)
>         {
>            data[0] = 0x8A;
>            if (dopen) {
>               data[1] = 0xAA;
>            } else {
>               data[1] = 0x55;
>            }
>            data[2] = 0x00;
>            data[3] = 0x00;
>            data[4] = 0x00;
>            data[5] = 0x46;
>            data[6] = 0x03;
>            data[7] = 0x00;
>            if (vwup_enable_write && !dev_mode)
>             comfBus->WriteStandard(0x291, length, data);
>         }
>
>         for (k=0;k<2;k++)
>         {
>            data[0] = 0x00;
>            if (dopen) {
>               data[1] = 0xAA;
>            } else {
>               data[1] = 0x55;
>            }
>            data[2] = 0x00;
>            data[3] = 0x00;
>            data[4] = 0x00;
>            data[5] = 0x46;
>            data[6] = 0x03;
>            data[7] = 0x00;
>            if (vwup_enable_write && !dev_mode)
>             comfBus->WriteStandard(0x291, length, data);
>         }
>
>         for (k=0;k<5;k++)
>         {
>            data[0] = 0x00;
>            data[1] = 0x00;
>            data[2] = 0x00;
>            data[3] = 0x00;
>            data[4] = 0x00;
>            data[5] = 0x46;
>            data[6] = 0x03;
>            data[7] = 0x00;
>            if (vwup_enable_write && !dev_mode)
>             comfBus->WriteStandard(0x291, length, data);
>         }
>
>
> And this is the log:
>
> I (130214) v-vweup-t26: Unlock Doors
> V (130214) canlog-monitor: 1600683470.161382 3T11 69E 14 42
> V (130214) canlog-monitor: 1600683470.163658 3R11 400 00 02 01 04 00 04
> 00 00
> V (130224) canlog-monitor: 1600683470.170670 3CER TX_Queue T11 291 8a
> aa 00 00 00 46 03 00
> V (130234) canlog-monitor: 1600683470.180434 3T11 291 8a aa 00 00 00 46
> 03 00
> V (130234) canlog-monitor: 1600683470.181037 3CER TX_Queue T11 291 8a
> aa 00 00 00 46 03 00
> E (130234) can: can3: intr=4 rxpkt=1 txpkt=2 errflags=0x23400401
> rxerr=0 txerr=0 rxovr=0 txovr=0 txdelay=14 wdgreset=0 errreset=0
> V (130234) canlog-monitor: 1600683470.181088 3CER TX_Queue T11 291 8a
> aa 00 00 00 46 03 00
> V (130234) canlog-monitor: 1600683470.181136 3CER TX_Queue T11 291 8a
> aa 00 00 00 46 03 00
> V (130234) canlog-monitor: 1600683470.181183 3CER TX_Queue T11 291 8a
> aa 00 00 00 46 03 00
> V (130244) canlog-monitor: 1600683470.181231 3CER TX_Queue T11 291 8a
> aa 00 00 00 46 03 00
> V (130244) canlog-monitor: 1600683470.181278 3CER TX_Queue T11 291 8a
> aa 00 00 00 46 03 00
> V (130244) canlog-monitor: 1600683470.181325 3CER TX_Queue T11 291 8a
> aa 00 00 00 46 03 00
> V (130244) canlog-monitor: 1600683470.181373 3CER TX_Queue T11 291 8a
> aa 00 00 00 46 03 00
> V (130244) canlog-monitor: 1600683470.181420 3CER TX_Queue T11 291 8a
> aa 00 00 00 46 03 00
> V (130244) canlog-monitor: 1600683470.181468 3CER TX_Queue T11 291 8a
> aa 00 00 00 46 03 00
> V (130244) canlog-monitor: 1600683470.181515 3CER TX_Queue T11 291 8a
> aa 00 00 00 46 03 00
> V (130244) canlog-monitor: 1600683470.181562 3CER TX_Queue T11 291 8a
> aa 00 00 00 46 03 00
> V (130244) canlog-monitor: 1600683470.181610 3CER TX_Queue T11 291 8a
> aa 00 00 00 46 03 00
> E (130244) canlog-monitor: 1600683470.183376 3CER Error intr=4 rxpkt=1
> txpkt=2 errflags=0x23400401 rxerr=0 txerr=0 rxovr=0 txovr=0 txdelay=14
> wdgreset=0 errreset=0
> V (130244) canlog-monitor: 1600683470.183706 3R11 6E7 44 42 03 00 11 00
> 04 01
> V (130244) canlog-monitor: 1600683470.184082 3R11 381 02 00 00 00 00 00
> V (130244) canlog-monitor: 1600683470.184510 3R11 369 3d 00 00 d0 ff 00
> 00 00
> V (130244) canlog-monitor: 1600683470.184608 3T11 291 8a aa 00 00 00 46
> 03 00
> V (130244) canlog-monitor: 1600683470.185274 3R11 531 00 20 20 00
> V (130244) canlog-monitor: 1600683470.186426 3T11 291 8a aa 00 00 00 46
> 03 00
> V (130244) canlog-monitor: 1600683470.188290 3T11 291 8a aa 00 00 00 46
> 03 00
> V (130244) canlog-monitor: 1600683470.190066 3T11 291 8a aa 00 00 00 46
> 03 00
> V (130244) canlog-monitor: 1600683470.191871 3T11 291 8a aa 00 00 00 46
> 03 00
> V (130254) canlog-monitor: 1600683470.193276 3R11 397 00 00 00 00 00 00
> 00 00
> V (130254) canlog-monitor: 1600683470.194507 3T11 291 8a aa 00 00 00 46
> 03 00
> V (130254) canlog-monitor: 1600683470.195477 3R11 4B9 02 00 00 00 00 00
> V (130254) canlog-monitor: 1600683470.196682 3T11 291 8a aa 00 00 00 46
> 03 00
> V (130254) canlog-monitor: 1600683470.197727 3CER TX_Queue T11 291 00
> aa 00 00 00 46 03 00
> V (130254) canlog-monitor: 1600683470.200428 3T11 291 8a aa 00 00 00 46
> 03 00
> V (130254) canlog-monitor: 1600683470.200971 3CER TX_Queue T11 291 00
> aa 00 00 00 46 03 00
> V (130254) canlog-monitor: 1600683470.201671 3CER TX_Queue T11 291 00
> 00 00 00 00 46 03 00
> V (130264) canlog-monitor: 1600683470.210425 3T11 291 8a aa 00 00 00 46
> 03 00
> E (130264) can: can3: intr=16 rxpkt=7 txpkt=11 errflags=0x23400401
> rxerr=0 txerr=0 rxovr=0 txovr=0 txdelay=21 wdgreset=0 errreset=0
> I (130264) ovms-server-v2: Send MP-0 c22,0
> V (130264) canlog-monitor: 1600683470.210989 3CER TX_Queue T11 291 00
> 00 00 00 00 46 03 00
> V (130264) canlog-monitor: 1600683470.211040 3CER TX_Queue T11 291 00
> 00 00 00 00 46 03 00
> V (130264) canlog-monitor: 1600683470.211088 3CER TX_Queue T11 291 00
> 00 00 00 00 46 03 00
> V (130264) canlog-monitor: 1600683470.211135 3CER TX_Queue T11 291 00
> 00 00 00 00 46 03 00
> E (130274) canlog-monitor: 1600683470.212453 3CER Error intr=16 rxpkt=7
> txpkt=11 errflags=0x23400401 rxerr=0 txerr=0 rxovr=0 txovr=0 txdelay=21
> wdgreset=0 errreset=0
> V (130274) canlog-monitor: 1600683470.212768 3R11 4BD 02 00 00 00 00 00
> V (130274) canlog-monitor: 1600683470.213129 3R11 658 10 28 00 05 00 a4
> 1a 00
> V (130274) canlog-monitor: 1600683470.213215 3T11 291 8a aa 00 00 00 46
> 03 00
> V (130274) canlog-monitor: 1600683470.213927 3R11 3B5 02 00 00 00 00 00
> V (130274) canlog-monitor: 1600683470.215092 3T11 291 8a aa 00 00 00 46
> 03 00
> V (130274) canlog-monitor: 1600683470.216295 3R11 527 07 01 00 10 71 88
> 8f 08
> V (130274) canlog-monitor: 1600683470.217474 3T11 291 8a aa 00 00 00 46
> 03 00
> V (130274) canlog-monitor: 1600683470.218655 3R11 400 00 01 01 04 00 04
> 00 00
> V (130274) canlog-monitor: 1600683470.219894 3T11 291 8a aa 00 00 00 46
> 03 00
> V (130274) canlog-monitor: 1600683470.221120 3R11 58C 80 00 80 00 00 00
> 00 05
> V (130274) canlog-monitor: 1600683470.222263 3T11 291 8a aa 00 00 00 46
> 03 00
> V (130274) canlog-monitor: 1600683470.223433 3R11 470 40 00 00 00 00 00
> 00 13
> V (130274) canlog-monitor: 1600683470.224666 3T11 291 00 aa 00 00 00 46
> 03 00
> V (130284) canlog-monitor: 1600683470.226223 3T11 291 00 aa 00 00 00 46
> 03 00
> V (130284) canlog-monitor: 1600683470.227809 3T11 291 00 00 00 00 00 46
> 03 00
> V (130284) canlog-monitor: 1600683470.229369 3T11 291 00 00 00 00 00 46
> 03 00
> V (130284) canlog-monitor: 1600683470.231051 3T11 291 00 00 00 00 00 46
> 03 00
> V (130284) canlog-monitor: 1600683470.232657 3T11 291 00 00 00 00 00 46
> 03 00
> V (130284) canlog-monitor: 1600683470.233705 3R11 2C1 00 00 00 00 02 00
> V (130284) canlog-monitor: 1600683470.234903 3T11 291 00 00 00 00 00 46
> 03 00
>
> I will now dig on why the doors won't unlock ...
>
> Thanx!
>
> Chris
>
>
> Am Sonntag, den 20.09.2020, 13:57 +0200 schrieb Michael Balzer:
>> Chris & everyone,
>>
>> I've pushed my fix for the out of sequence transmissions and faulty
>> transmission logs on bulk transmissions. My tests showed the esp32can
>> driver had the same issue.
>>
>> The fix uses a mutex to avoid concurrent frame writes from the
>> application and CAN task context.
>>
>> In addition I fixed a bug in the mcp2515 driver that caused endless
>> log spam in case of bus errors -- the same error condition would get
>> logged over and over again.
>>
>> Chris, I've also raised the default CAN TX queue size to 30 to allow
>> your 22 frames to be queued with a standard build as well. But I hope
>> that's just a first hack and won't be necessary once you figured out
>> how the protocol works.
>>
>> Regards,
>> Michael
>>
>>
>> Am 19.09.20 um 13:13 schrieb Chris van der Meijden:
>>
>>> Perfect! Thanx.
>>>
>>> I'm back on track on monday.
>>>
>>> Regards
>>>
>>> Chris
>>>
>>> Am Samstag, den 19.09.2020, 13:12 +0200 schrieb Michael Balzer:
>>>> Chris,
>>>>
>>>> I've now set up a test environment for CAN2 & 3 and have begun
>>>> investigating the issue.
>>>>
>>>> I'll come back to you when I've fixed it.
>>>>
>>>> Regards,
>>>> Michael
>>>>
>>>>
>>>> Am 18.09.20 um 19:51 schrieb Michael Balzer:
>>>>> Chris,
>>>>>
>>>>> the fix isn't meant to eliminate bus errors, it just should
>>>>> solve the log errors.
>>>>>
>>>>> I.e. you should now see exactly those frames in the TX log,
>>>>> that you transmit.
>>>>>
>>>>> TX_Fail log entries can result from actual bus errors as well
>>>>> as from TX queue overflows.
>>>>>
>>>>> TX queue overflows are counted separately, see can can3 status.
>>>>> If you have TX overflows, you need to raise the queue size.
>>>>>
>>>>> Regards,
>>>>> Michael
>>>>>
>>>>>
>>>>> Am 18.09.20 um 19:38 schrieb Chris van der Meijden:
>>>>>> I did a first test with mixed results.
>>>>>>
>>>>>> I don't see the Asynchronous Errors anymore, but I see
>>>>>> TX_FAIL messages and neither unlocking nor climate control
>>>>>> works with the patch.
>>>>>>
>>>>>> I will continue on monday with some deeper checks and I hope
>>>>>> I can produce some
>>>>>> log output then.
>>>>>>
>>>>>> Regards
>>>>>>
>>>>>> Chris
>>>>>>
>>>>>>
>>>>>>
>>>>>> _______________________________________________
>>>>>> OvmsDev mailing list
>>>>>> OvmsDev at lists.openvehicles.com
>>>>>> http://lists.openvehicles.com/mailman/listinfo/ovmsdev
>>>>>  
>>>>>
>>>>>
>>>>> _______________________________________________
>>>>> OvmsDev mailing list
>>>>> OvmsDev at lists.openvehicles.com
>>>>> http://lists.openvehicles.com/mailman/listinfo/ovmsdev
>>>>  
>>>> _______________________________________________
>>>> OvmsDev mailing list
>>>> OvmsDev at lists.openvehicles.com
>>>> http://lists.openvehicles.com/mailman/listinfo/ovmsdev
>>>  
>>>
>>> _______________________________________________
>>> OvmsDev mailing list
>>> OvmsDev at 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 at lists.openvehicles.com
>> http://lists.openvehicles.com/mailman/listinfo/ovmsdev
> _______________________________________________
> OvmsDev mailing list
> OvmsDev at 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

More information about the OvmsDev mailing list