[Ovmsdev] Need some help on CAN errors

Chris van der Meijden chris at arachnon.de
Fri Sep 18 23:09:29 HKT 2020


That did the trick :-)
It compiled. Now I just have to wait till the car is back from shoppig
...
As soon as I have results, I'll be back.
Chris

Am Freitag, den 18.09.2020, 16:54 +0200 schrieb Michael Balzer:
> Chris,
> 
> see git help apply, you can try
> 
> git apply --whitespace=fix
> or
> git apply --whitespace=nowarn
> 
> Regards,
> Michael
> 
> 
> Am 18.09.20 um 16:45 schrieb Chris van der Meijden:
> > Hey Michael
> > 
> > I get this error message on the patch:
> > 
> > git apply ../mcp2515.patch
> > 
> > ../mcp2515.patch:9: trailing whitespace.
> >   OvmsRecMutexLock lock(&m_mutex);
> > ../mcp2515.patch:17: trailing whitespace.
> >   // if there are frames waiting in the TX queue, add the new one
> > there
> > as well:
> > ../mcp2515.patch:18: trailing whitespace.
> >   if (uxQueueMessagesWaiting(m_txqueue))
> > ../mcp2515.patch:19: trailing whitespace.
> >     {
> > ../mcp2515.patch:20: trailing whitespace.
> >     return QueueWrite(p_frame, maxqueuewait);
> > error: Anwendung des Patches fehlgeschlagen:
> > vehicle/OVMS.V3/components/mcp2515/src/mcp2515.cpp:308
> > error: vehicle/OVMS.V3/components/mcp2515/src/mcp2515.cpp: Patch
> > konnte
> > nicht angewendet werden
> > error: Anwendung des Patches fehlgeschlagen:
> > vehicle/OVMS.V3/components/mcp2515/src/mcp2515.h:35
> > error: vehicle/OVMS.V3/components/mcp2515/src/mcp2515.h: Patch
> > konnte
> > nicht angewendet werden
> > 
> > I'm even with the master ...
> > 
> > Greetinx
> > 
> > Chris
> > 
> > Am Freitag, den 18.09.2020, 15:59 +0200 schrieb Michael Balzer:
> > > Chris,
> > > 
> > > I've got no simple way to test changes to the MCP2515 driver, can
> > > you
> > > please try the attached patch?
> > > 
> > > In case you're not familiar with patching:
> > > 
> > > git apply …/mcp2515.patch
> > > 
> > > That's simply adding a mutex to Write() &
> > > AsynchronousInterruptHandler() plus a minor optimization to
> > > directly
> > > queue a frame if the queue isn't empty.
> > > 
> > > Thanks,
> > > Michael
> > > 
> > > 
> > > Am 18.09.20 um 15:39 schrieb Chris van der Meijden:
> > > 
> > > > Correction:
> > > > 
> > > > The crashes occur when I use
> > > > 
> > > >   CAN_frame_t txframe;
> > > >   txframe = {};
> > > >   txframe.MsgID = 0x219;
> > > >   txframe.FIR.B.DLC = 8;
> > > >   txframe.data = { 0x…, 0x…, … };
> > > >   txframe.Write(m_can3);
> > > > 
> > > > to write to the bus.
> > > > 
> > > > When I use the 
> > > > 
> > > > comfBus->WriteStandard(0x219, length, data);
> > > > 
> > > > method I have no crashes.
> > > > 
> > > > Continuing the quest ...
> > > > 
> > > > Chris
> > > > 
> > > > 
> > > > Am Donnerstag, den 17.09.2020, 21:35 +0200 schrieb Michael
> > > > Balzer:
> > > > > That looks like a bug in the MCP2515 driver.
> > > > > 
> > > > > > The TX that come to the bus (3T11) we see 15 times the
> > > > > > first
> > > > > > messages
> > > > > > (that is right), one time the second messages (wrong,
> > > > > > should be
> > > > > > two)
> > > > > > and 6 times the third messages (wrong, should be 5).
> > > > > 
> > > > >  
> > > > > I haven't fully analyzed the code path yet, but my impression
> > > > > so
> > > > > far is we have a race condition between mcp2515::Write() and
> > > > > mcp2515::AsynchronousInterruptHandler(). If I'm right, that
> > > > > could
> > > > > lead to wrong TX log entries and even to lost or out of
> > > > > sequence
> > > > > frame transmissions in a situation like yours, when many
> > > > > frames
> > > > > get sent in series without any delay.
> > > > > 
> > > > > The race scheme is:
> > > > > 
> > > > > - The application task (low prio) calls Write() concurrently
> > > > > to
> > > > > the "TX done" interrupt of the last frame sent being raised.
> > > > > - The interrupt is sent to the CAN task (high prio), which
> > > > > calls
> > > > > AsynchronousInterruptHandler() concurrently now to the
> > > > > Write().
> > > > > - Both Write() and AsynchronousInterruptHandler() may now get
> > > > > "TX
> > > > > buffer is free" from the MCP2515
> > > > > - …Write() will then immediately fill the TX buffer with the
> > > > > new
> > > > > frame
> > > > > - …and AsynchronousInterruptHandler() will concurrently fill
> > > > > the
> > > > > TX buffer with the next frame of the TX queue if any
> > > > > 
> > > > > As the SPI bus has a lock, both writes may succeed, but
> > > > > m_tx_frame will contain only the last of the two frames, so
> > > > > the
> > > > > next log entry will be wrong. The m_tx_frame container
> > > > > (originating from PR 259) has been designed under the
> > > > > assumption
> > > > > of stricly sequential frame transmissions.
> > > > > 
> > > > > You could have had that very effect on the second time of the
> > > > > second message vs. the first time of the third message:
> > > > > 
> > > > > 1600352233.392765 3CER TX_Queue T11 291 8a aa 00 00 00 46 03
> > > > > 00
> > > > > 1600352233.394239 3T11 291 8a aa 00 00 00 46 03 00
> > > > > 1600352233.394816 3CER TX_Queue T11 291 00 aa 00 00 00 46 03
> > > > > 00
> > > > > 1600352233.395680 3T11 291 8a aa 00 00 00 46 03 00
> > > > > 1600352233.396153 3CER TX_Queue T11 291 00 aa 00 00 00 46 03
> > > > > 00
> > > > > 1600352233.404239 3T11 291 00 aa 00 00 00 46 03 00
> > > > > 1600352233.404538 3CER TX_Queue T11 291 00 00 00 00 00 46 03
> > > > > 00
> > > > > 1600352233.404753 3CER TX_Queue T11 291 00 00 00 00 00 46 03
> > > > > 00
> > > > > … TX "00 aa" done IRQ coming in here, queue has "00 00" frame
> > > > > ready which gets sent concurrently
> > > > >   → wrong frame "00 00" is now in m_tx_frame and gets logged
> > > > > instead of "00 aa":
> > > > > 1600352233.405126 3T11 291 00 00 00 00 00 46 03 00
> > > > > 
> > > > > 
> > > > > A second opinion on this would be good, possibly by someone
> > > > > else
> > > > > who has worked on the MCP2515 code last?
> > > > > 
> > > > > Chris, while we're thinking about this, you could try
> > > > > serialising
> > > > > the frames by sending them one by one using the TX callback.
> > > > > The
> > > > > TX queue is meant to handle bulk transmissions, but you may
> > > > > need
> > > > > to raise the queue size (sdkconfig:
> > > > > CONFIG_OVMS_HW_CAN_TX_QUEUE_SIZE=20) in that case.
> > > > > 
> > > > > > On the RX side (3R11) we only see 3 times the first
> > > > > > messages,
> > > > > > none of
> > > > > > the second and one of the third.
> > > > > 
> > > > >  
> > > > > The RX log entries are the frames received from the vehicle.
> > > > > 
> > > > > Regards,
> > > > > Michael
> > > > > 
> > > > > 
> > > > > 
> > > > > Am 17.09.20 um 17:06 schrieb Chris van der Meijden:
> > > > > > Hi all
> > > > > > 
> > > > > > I'm trying to make the Lock/Unlock function work for the VW
> > > > > > e-
> > > > > > UP on
> > > > > > T26A.
> > > > > > 
> > > > > > I found the right messages and got it working once, not
> > > > > > knowing
> > > > > > why.
> > > > > > 
> > > > > > What I need to do is sending 22 messages in a row. My code
> > > > > > for
> > > > > > that is:
> > > > > > 
> > > > > >         // Send 0x291 messages
> > > > > > 
> > > > > >         for (k=0;k<15;k++)
> > > > > >         {
> > > > > >            data[0] = 0x8A;
> > > > > >            data[1] = 0xAA;
> > > > > >            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;
> > > > > >            data[1] = 0xAA;
> > > > > >            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);
> > > > > > 
> > > > > >         }
> > > > > > 
> > > > > > This is what I get in the logging:
> > > > > > 
> > > > > > V (96275) canlog-monitor: 1600352233.355713 3T11 291 8a aa
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > V (96275) canlog-monitor: 1600352233.357066 3CER TX_Queue
> > > > > > T11
> > > > > > 291 8a aa
> > > > > > 00 00 00 46 03 00
> > > > > > V (96275) canlog-monitor: 1600352233.357673 3T11 291 8a aa
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > V (96275) canlog-monitor: 1600352233.358156 3CER TX_Queue
> > > > > > T11
> > > > > > 291 8a aa
> > > > > > 00 00 00 46 03 00
> > > > > > E (96285) mcp2515: AsynchronousInterruptHandler: error
> > > > > > while
> > > > > > sending
> > > > > > frame. msgId 0x291
> > > > > > V (96285) canlog-monitor: 1600352233.364241 3T11 291 8a aa
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > E (96285) can: can3: intr=8 rxpkt=0 txpkt=4
> > > > > > errflags=0x85050101
> > > > > > rxerr=0
> > > > > > txerr=107 rxovr=0 txovr=0 txdelay=6 wdgreset=0 errreset=0
> > > > > > V (96285) canlog-monitor: 1600352233.364745 3CER TX_Queue
> > > > > > T11
> > > > > > 291 8a aa
> > > > > > 00 00 00 46 03 00
> > > > > > W (96285) mcp2515: can3 EFLG: TX_Err_Warn EWARN 
> > > > > > V (96285) canlog-monitor: 1600352233.364965 3CER TX_Queue
> > > > > > T11
> > > > > > 291 8a aa
> > > > > > 00 00 00 46 03 00
> > > > > > E (96285) can: can3: intr=8 rxpkt=1 txpkt=5
> > > > > > errflags=0x4050104
> > > > > > rxerr=0
> > > > > > txerr=107 rxovr=0 txovr=0 txdelay=6 wdgreset=0 errreset=0
> > > > > > E (96285) canlog-monitor: 1600352233.366305 3CER Error
> > > > > > intr=8
> > > > > > rxpkt=0
> > > > > > txpkt=4 errflags=0x85050101 rxerr=0 txerr=107 rxovr=0
> > > > > > txovr=0
> > > > > > txdelay=6
> > > > > > wdgreset=0 errreset=0
> > > > > > V (96285) canlog-monitor: 1600352233.367035 3R11 291 8a aa
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > V (96285) canlog-monitor: 1600352233.367620 3T11 291 8a aa
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > V (96295) canlog-monitor: 1600352233.367647 3CER TX_Fail
> > > > > > T11
> > > > > > 291 8a aa
> > > > > > 00 00 00 46 03 00
> > > > > > E (96295) canlog-monitor: 1600352233.368350 3CER Error
> > > > > > intr=8
> > > > > > rxpkt=1
> > > > > > txpkt=5 errflags=0x4050104 rxerr=0 txerr=107 rxovr=0
> > > > > > txovr=0
> > > > > > txdelay=6
> > > > > > wdgreset=0 errreset=0
> > > > > > V (96295) canlog-monitor: 1600352233.368403 3T11 291 8a aa
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > V (96295) canlog-monitor: 1600352233.369064 3T11 291 8a aa
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > V (96295) canlog-monitor: 1600352233.370243 3R11 470 40 00
> > > > > > 00
> > > > > > 00 00 00
> > > > > > 00 14
> > > > > > V (96295) canlog-monitor: 1600352233.371859 3CER TX_Queue
> > > > > > T11
> > > > > > 291 8a aa
> > > > > > 00 00 00 46 03 00
> > > > > > V (96295) canlog-monitor: 1600352233.374239 3T11 291 8a aa
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > V (96295) canlog-monitor: 1600352233.374827 3CER TX_Queue
> > > > > > T11
> > > > > > 291 8a aa
> > > > > > 00 00 00 46 03 00
> > > > > > V (96295) canlog-monitor: 1600352233.375507 3T11 291 8a aa
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > V (96295) canlog-monitor: 1600352233.375976 3CER TX_Queue
> > > > > > T11
> > > > > > 291 8a aa
> > > > > > 00 00 00 46 03 00
> > > > > > V (96305) canlog-monitor: 1600352233.384241 3T11 291 8a aa
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > V (96305) canlog-monitor: 1600352233.384985 3CER TX_Queue
> > > > > > T11
> > > > > > 291 8a aa
> > > > > > 00 00 00 46 03 00
> > > > > > V (96305) canlog-monitor: 1600352233.385602 3CER TX_Queue
> > > > > > T11
> > > > > > 291 8a aa
> > > > > > 00 00 00 46 03 00
> > > > > > E (96305) can: can3: intr=14 rxpkt=2 txpkt=10
> > > > > > errflags=0x27450501
> > > > > > rxerr=0 txerr=100 rxovr=0 txovr=0 txdelay=12 wdgreset=0
> > > > > > errreset=0
> > > > > > V (96305) canlog-monitor: 1600352233.386140 3CER TX_Queue
> > > > > > T11
> > > > > > 291 8a aa
> > > > > > 00 00 00 46 03 00
> > > > > > W (96305) mcp2515: can3 EFLG: TX_Err_Warn EWARN 
> > > > > > E (96305) canlog-monitor: 1600352233.387010 3CER Error
> > > > > > intr=14
> > > > > > rxpkt=2
> > > > > > txpkt=10 errflags=0x27450501 rxerr=0 txerr=100 rxovr=0
> > > > > > txovr=0
> > > > > > txdelay=12 wdgreset=0 errreset=0
> > > > > > V (96305) canlog-monitor: 1600352233.387820 3R11 291 8a aa
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > V (96315) canlog-monitor: 1600352233.388508 3R11 291 8a aa
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > V (96315) canlog-monitor: 1600352233.388548 3T11 291 8a aa
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > V (96315) canlog-monitor: 1600352233.388586 3T11 291 8a aa
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > V (96315) canlog-monitor: 1600352233.390509 3T11 291 8a aa
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > V (96315) canlog-monitor: 1600352233.391040 3R11 359 ff 89
> > > > > > ff
> > > > > > 00 10 6b
> > > > > > 80 00
> > > > > > V (96315) canlog-monitor: 1600352233.392246 3T11 291 8a aa
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > V (96315) canlog-monitor: 1600352233.392765 3CER TX_Queue
> > > > > > T11
> > > > > > 291 8a aa
> > > > > > 00 00 00 46 03 00
> > > > > > V (96315) canlog-monitor: 1600352233.394239 3T11 291 8a aa
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > V (96315) canlog-monitor: 1600352233.394816 3CER TX_Queue
> > > > > > T11
> > > > > > 291 00 aa
> > > > > > 00 00 00 46 03 00
> > > > > > V (96315) canlog-monitor: 1600352233.395680 3T11 291 8a aa
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > V (96315) canlog-monitor: 1600352233.396153 3CER TX_Queue
> > > > > > T11
> > > > > > 291 00 aa
> > > > > > 00 00 00 46 03 00
> > > > > > V (96325) canlog-monitor: 1600352233.404239 3T11 291 00 aa
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > V (96325) canlog-monitor: 1600352233.404538 3CER TX_Queue
> > > > > > T11
> > > > > > 291 00 00
> > > > > > 00 00 00 46 03 00
> > > > > > V (96325) canlog-monitor: 1600352233.404753 3CER TX_Queue
> > > > > > T11
> > > > > > 291 00 00
> > > > > > 00 00 00 46 03 00
> > > > > > V (96325) canlog-monitor: 1600352233.404791 3R11 291 00 00
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > V (96325) canlog-monitor: 1600352233.405089 3R11 457 00 47
> > > > > > 00
> > > > > > V (96325) canlog-monitor: 1600352233.405126 3T11 291 00 00
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > V (96325) canlog-monitor: 1600352233.406203 3T11 291 00 00
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > V (96325) canlog-monitor: 1600352233.407538 3T11 291 00 00
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > V (96325) canlog-monitor: 1600352233.408701 3CER TX_Queue
> > > > > > T11
> > > > > > 291 00 00
> > > > > > 00 00 00 46 03 00
> > > > > > V (96335) canlog-monitor: 1600352233.414259 3T11 291 00 00
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > E (96335) can: can3: intr=25 rxpkt=7 txpkt=21
> > > > > > errflags=0x27400501
> > > > > > rxerr=0 txerr=90 rxovr=0 txovr=0 txdelay=18 wdgreset=0
> > > > > > errreset=0
> > > > > > E (96335) canlog-monitor: 1600352233.416398 3CER Error
> > > > > > intr=25
> > > > > > rxpkt=7
> > > > > > txpkt=21 errflags=0x27400501 rxerr=0 txerr=90 rxovr=0
> > > > > > txovr=0
> > > > > > txdelay=18 wdgreset=0 errreset=0
> > > > > > V (96335) canlog-monitor: 1600352233.416729 3R11 320 01 00
> > > > > > 00
> > > > > > 01 00 02
> > > > > > 00 80
> > > > > > V (96335) canlog-monitor: 1600352233.417216 3R11 575 00 00
> > > > > > 00
> > > > > > 00
> > > > > > V (96335) canlog-monitor: 1600352233.417255 3T11 291 00 00
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > V (96335) canlog-monitor: 1600352233.417283 3T11 291 00 00
> > > > > > 00
> > > > > > 00 00 46
> > > > > > 03 00
> > > > > > I (96335) ovms-server-v2: Send MP-0 c22,0
> > > > > > 
> > > > > > I see some weird stuff here ...
> > > > > > 
> > > > > > The TX that come to the bus (3T11) we see 15 times the
> > > > > > first
> > > > > > messages
> > > > > > (that is right), one time the second messages (wrong,
> > > > > > should be
> > > > > > two)
> > > > > > and 6 times the third messages (wrong, should be 5).
> > > > > > 
> > > > > > On the RX side (3R11) we only see 3 times the first
> > > > > > messages,
> > > > > > none of
> > > > > > the second and one of the third.
> > > > > > 
> > > > > > To unlock the doors we need on 3R11 (???) 15 times first, 5
> > > > > > times
> > > > > > second and two times third.
> > > > > > 
> > > > > > I don't understand enough from the can communication within
> > > > > > OVMS to
> > > > > > solve this on my own. Could someone help me out here?
> > > > > > 
> > > > > > Thanx!
> > > > > > 
> > > > > > 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
> > 
> > _______________________________________________
> > 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/20200918/d0a3c417/attachment-0002.htm>


More information about the OvmsDev mailing list