[Ovmsdev] OVMS Poller module/singleton

Sun Feb 2 20:58:20 HKT 2025

Hi everyone,

On 2025-01-28 19:12, Michael Balzer wrote:

> Reading the Leaf code, I don't see any regular status ping polling,

Actually there is some defined polling of BMS:

static const OvmsPoller::poll_pid_t obdii_polls[] =
   {
     // BUS 2
     { CHARGER_TXID, CHARGER_RXID, VEHICLE_POLL_TYPE_OBDIIGROUP, VIN_PID, 
{  0, 900, 0, 0 }, 2, ISOTP_STD },           // VIN [19]
     { CHARGER_TXID, CHARGER_RXID, VEHICLE_POLL_TYPE_OBDIIEXTENDED, 
QC_COUNT_PID, {  0, 900, 0, 0 }, 2, ISOTP_STD },   // QC [2]
     { CHARGER_TXID, CHARGER_RXID, VEHICLE_POLL_TYPE_OBDIIEXTENDED, 
L1L2_COUNT_PID, {  0, 900, 0, 0 }, 2, ISOTP_STD }, // L0/L1/L2 [2]
     // BUS 1
     { BMS_TXID, BMS_RXID, VEHICLE_POLL_TYPE_OBDIIGROUP, 0x01, {  0, 60, 
0, 60 }, 1, ISOTP_STD },   // bat [39/41]
     { BMS_TXID, BMS_RXID, VEHICLE_POLL_TYPE_OBDIIGROUP, 0x02, {  0, 60, 
0, 60 }, 1, ISOTP_STD },   // battery voltages [196]
     { BMS_TXID, BMS_RXID, VEHICLE_POLL_TYPE_OBDIIGROUP, 0x06, {  0, 60, 
0, 60 }, 1, ISOTP_STD },   // battery shunts [96]
     { BMS_TXID, BMS_RXID, VEHICLE_POLL_TYPE_OBDIIGROUP, 0x04, {  0, 300, 
0, 300 }, 1, ISOTP_STD }, // battery temperatures [14]
     POLL_LIST_END
   };

BMS_TXID is 0x79B, and this is mostly what I see appearing in CRTD 
overnight:

1738275829.012407 CXX OVMS CRTD
1738275829.012407 CVR 3.1
1738275829.020355 1CXX Info Type:vfs Format:crtd(discard) Vehicle:NL 
Path:/sd/can4.crtd
1738275879.419663 1CER TX_Fail T11 79B 02 21 01 55 55 55 55 55
1738275880.419598 1CER TX_Fail T11 79B 02 21 02 55 55 55 55 55
1738275881.419606 1CER TX_Fail T11 79B 02 21 06 55 55 55 55 55
1738275942.419724 1CER TX_Fail T11 79B 02 21 01 55 55 55 55 55
1738275943.419618 1CER TX_Fail T11 79B 02 21 02 55 55 55 55 55
1738275944.419611 1CER TX_Fail T11 79B 02 21 06 55 55 55 55 55
1738276005.419663 1CER TX_Fail T11 79B 02 21 01 55 55 55 55 55
1738276006.419606 1CER TX_Fail T11 79B 02 21 02 55 55 55 55 55

The first night, that was everything I saw until a charge pilot event 
woke the car up at 05:50.

The second night, at 03:46 there were two records of apparently 
successful transmits, which coincides with errors being logged.

1738381606.559723 1CER TX_Fail T11 79B 02 21 01 55 55 55 55 55
1738381607.560118 1CER TX_Fail T11 79B 02 21 02 55 55 55 55 55

1738381607.561672 1CER Error intr=32898937 rxpkt=32886195 txpkt=4872 
errflags=0x204c00 rxerr=0 txerr=127 rxinval=0 rxovr=3 txovr=0 
txdelay=213 txfail=5411 wdgreset=0 errreset=5 txqueue=0
1738381607.561766 1T11 79B 02 21 02 55 55 55 55 55
1738381607.561816 1CST Status intr=32898937 rxpkt=32886195 txpkt=4873 
errflags=0x204c00 rxerr=0 txerr=127 rxinval=0 rxovr=3 txovr=0 
txdelay=213 txfail=5411 wdgreset=0 errreset=5 txqueue=0

1738381608.559656 1CER TX_Fail T11 79B 02 21 06 55 55 55 55 55
1738381608.559819 1CST Status intr=32898940 rxpkt=32886195 txpkt=4873 
errflags=0x8048d9 rxerr=0 txerr=135 rxinval=0 rxovr=3 txovr=0 
txdelay=213 txfail=5412 wdgreset=0 errreset=5 txqueue=0
1738381608.561065 1CER Error intr=32898943 rxpkt=32886195 txpkt=4873 
errflags=0x8048d9 rxerr=0 txerr=134 rxinval=0 rxovr=3 txovr=0 
txdelay=213 txfail=5412 wdgreset=0 errreset=5 txqueue=0
1738381608.561163 1T11 79B 02 21 06 55 55 55 55 55

1738381669.559719 1CER TX_Fail T11 79B 02 21 01 55 55 55 55 55
1738381670.559655 1CER TX_Fail T11 79B 02 21 02 55 55 55 55 55

The above activity is what creates records in the otherwise-quiet system 
log:
2025-02-01 03:46:48.272 GMT E (189607402) can: can1: intr=32898936 
rxpkt=32886195 txpkt=4872 errflags=0x8048d9 rxerr=0 txerr=128 rxinval=0 
rxovr=3 txovr=0 txdelay=213 txfail=5411 wdgreset=0 er
rreset=5 txqueue=0
2025-02-01 03:46:49.272 GMT E (189608402) can: can1: intr=32898940 
rxpkt=32886195 txpkt=4873 errflags=0x8048d9 rxerr=0 txerr=135 rxinval=0 
rxovr=3 txovr=0 txdelay=213 txfail=5412 wdgreset=0 er
rreset=5 txqueue=0

It fits well with your description below, although in these nights I 
didn't see any queuing. Just a small probability of thinking it can send 
a frame on a bus that's off.

> On my UpMiiGo (which switches off the bus), the ESP32CAN most of the 
> time recognizes an immediate failure for a TX with the vehicle being 
> off. That means the TX buffer (in the controller) gets cleared 
> immediately, with an immediate "TX_Fail" result for the frame. Ideally 
> that would be the case always while the bus is off.
> 
> But the ESP32CAN controller sometimes tries to send the frame, waiting 
> for an ack, repeating the transmission and then ending up in the frame 
> being stuck in the TX buffer. Then the TX queue (software) gets filled 
> with the status ping request frame from there, up to the 30 frames 
> capacity of the TX queue, then counting TX overflows.
> 
> This continues until the ESP32CAN, due to unknown reasons, thinks it 
> could send the frame. The TX queue then gets flushed immediately, with 
> the frames appearing as being sent successfully (although there is no 
> ECU active, the bus is still off).
> 
> After the queue has been cleared, this loop starts over.
> 
> So it may happen, that the TX queue gets filled, and the ESP32CAN 
> thinks it can send frames, even while the bus is shut off.

On the third night the crtd log says it tried to send BMS polls at 
23:37, 23:39, 00:00 and 00:02.

1738452975.674976 1CER TX_Fail T11 79B 02 21 06 55 55 55 55 55
1738453036.675613 1CER TX_Fail T11 79B 02 21 01 55 55 55 55 55
1738453036.677195 1CER Error intr=41628672 rxpkt=41612603 txpkt=6073 
errflags=0x8048d9 rxerr=0 txerr=128 rxinval=0 rxovr=3 txovr=0 
txdelay=259 txfail=6847 wdgreset=0 errreset=7 txqueue=0
1738453036.686582 1T11 79B 02 21 01 55 55 55 55 55
1738453036.686690 1CST Status intr=41628708 rxpkt=41612603 txpkt=6074 
errflags=0x204c00 rxerr=0 txerr=127 rxinval=0 rxovr=3 txovr=0 
txdelay=259 txfail=6847 wdgreset=0 errreset=7 txqueue=0
1738453037.674988 1CER TX_Fail T11 79B 02 21 02 55 55 55 55 55
1738453037.675148 1CST Status intr=41628711 rxpkt=41612603 txpkt=6074 
errflags=0x8048d9 rxerr=0 txerr=135 rxinval=0 rxovr=3 txovr=0 
txdelay=259 txfail=6848 wdgreset=0 errreset=7 txqueue=0
1738453037.676306 1CER Error intr=41628714 rxpkt=41612603 txpkt=6074 
errflags=0x8048d9 rxerr=0 txerr=134 rxinval=0 rxovr=3 txovr=0 
txdelay=259 txfail=6848 wdgreset=0 errreset=7 txqueue=0
1738453037.676389 1T11 79B 02 21 02 55 55 55 55 55
1738453038.674985 1CER TX_Fail T11 79B 02 21 06 55 55 55 55 55

1738453164.675494 1CER TX_Fail T11 79B 02 21 02 55 55 55 55 55
1738453164.676968 1CER Error intr=41628729 rxpkt=41612603 txpkt=6075 
errflags=0x8048d9 rxerr=0 txerr=133 rxinval=0 rxovr=3 txovr=0 
txdelay=259 txfail=6855 wdgreset=0 errreset=7 txqueue=0
1738453164.677076 1T11 79B 02 21 02 55 55 55 55 55
1738453165.675001 1CER TX_Fail T11 79B 02 21 06 55 55 55 55 55

1738454366.674962 1CER TX_Fail T11 79B 02 21 04 55 55 55 55 55
1738454427.675572 1CER TX_Fail T11 79B 02 21 01 55 55 55 55 55
1738454427.677047 1CER Error intr=41628861 rxpkt=41612603 txpkt=6076 
errflags=0x8048d9 rxerr=0 txerr=133 rxinval=0 rxovr=3 txovr=0 
txdelay=259 txfail=6918 wdgreset=0 errreset=7 txqueue=0
1738454427.686539 1T11 79B 02 21 01 55 55 55 55 55
1738454428.674962 1CER TX_Fail T11 79B 02 21 02 55 55 55 55 55

1738454555.679243 1CER TX_Fail T11 79B 02 21 06 55 55 55 55 55
1738454555.680668 1CER Error intr=41628916 rxpkt=41612603 txpkt=6077 
errflags=0x8048d9 rxerr=0 txerr=131 rxinval=0 rxovr=3 txovr=0 
txdelay=259 txfail=6926 wdgreset=0 errreset=7 txqueue=0
1738454555.680756 1T11 79B 02 21 06 55 55 55 55 55
1738454616.678795 1CER TX_Fail T11 79B 02 21 01 55 55 55 55 55

So far I haven't seen any errors with a non-zero txqueue value, but I'll 
continue to keep a lookout for any issues. Until then, this seems to be 
its normal behaviour. I haven't explored the Leaf modules' BMS polling 
code, but I'm wondering if some changes there would help, e.g. not 
polling when the car is off.

Chris
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.openvehicles.com/pipermail/ovmsdev/attachments/20250202/023ffb00/attachment.htm>