Not processing canbus frames anymore
I have a v3.3 module in my Corvette and recently got it back on the road but I find that following the sim7600 modem testing I did a few weeks ago, it doesn't seem to be processing canbus frames. When the car is running, the module does not appear to update soc or vin although this used to work. Comparing "module sum" between it and my Cadillac turned up something extra in the [vehicle] section: [vehicle] 12v.alert: 12v.ref: - id: RF059 + id: 768V name: timezone: PST8PDT,M3.2.0,M11.1.0 timezone_region: America/Los_Angeles - type: CHEVROLET_C6_CORVETTE units.distance: M While the [auto] section only has expected differences: [auto] @@ -38,9 +44,9 @@ scripting: yes server.v2: yes server.v3: yes - vehicle.type: C6CORVETTE + vehicle.type: C2CTS wifi.mode: client - wifi.ssid.ap: RF059 + wifi.ssid.ap: 768V wifi.ssid.client: Team America I don't really remember/know how to quickly monitor the canbus but with the car running it *seems* to be seeing canbus frames: OVMS# can log start monitor crtd CAN logging to MONITOR active: Type:monitor Format:crtd(discard) Vehicle:C6CORVETTE Note: info logging is at debug log level, frame logging is at verbose, and errors as usual OVMS# can log status #1: open Type:monitor Format:crtd(discard) Vehicle:C6CORVETTE Messages:7240 Dropped:0 Filtered:0 Rate:0.0% MONITOR: running Messages:7240 Discarded:0 Dropped:0 Filtered:0 Rate:0.0% OVMS# can log status #1: open Type:monitor Format:crtd(discard) Vehicle:C6CORVETTE Messages:11447 Dropped:0 Filtered:0 Rate:0.0% MONITOR: running Messages:11447 Discarded:0 Dropped:0 Filtered:0 Rate:0.0% OVMS# can list can1: Active/500000 dbc none can2: Off/1000000 dbc none can3: Off/1000000 dbc none Any suggestions on how to figure out what I'm doing wrong? Craig
On 3/16/22 10:54, Craig Leres wrote:
I have a v3.3 module in my Corvette and recently got it back on the road but I find that following the sim7600 modem testing I did a few weeks ago, it doesn't seem to be processing canbus frames. When the car is running, the module does not appear to update soc or vin although this used to work.
Nevermind; I changed the vehicle type, change it back, and rebooted the module and it seems to be working again. I'm still interested in the mod sum -> [vehicle] -> type difference though. Craig
I also appear to be having this issue. My module will pick up all the data that I expect when it first boots, but shortly after, metrics are stale and the web interfaces show a bunch of question marks. I used to have stability problems and the module would keep rebooting, but I think I fixed that by bringing the xtensa up to date in my build environment. I assumed all the issues I was having were due to my programming, but I'm having doubts that it's actually picking up and processing all the frames. CAN logging to SD card and streaming to SavvyCAN through WiFi seem to work well. Another issue I'm having is that my GPS is no longer working. I never got my T-mobile SIM properly activated but the GPS used to work. Now the module is just in this loop: I (20386793) cellular: State: Enter Identify state I (20387153) cellular: Identified cellular modem: SIM5360/SIMCOM SIM5360 (include US and EU variants) I (20387153) cellular: Set modem driver to 'SIM5360' I (20387153) cellular: State: Enter PoweredOn state I (20403153) housekeeping: 2022-03-16 19:25:08 PDT (RAM: 8b=78740-82120 32b=12344 SPI=3384268-3417604) I (20407153) cellular: State: Enter MuxStart state I (20485693) ovms-server-v2: Incoming Msg: MP-0 AFA I (20485693) ovms-server-v2: Send MP-0 a I (20527143) cellular: State: Enter PoweringOn state I (20527143) cellular: Set modem driver to 'auto' I (20527143) cellular-modem-auto: Power Cycle 2000ms I (20557143) cellular: State: Enter PoweringOn state I (20557143) cellular-modem-auto: Power Cycle 4000ms I (20563803) cellular: State: Enter Identify state I (20564153) cellular: Identified cellular modem: SIM5360/SIMCOM SIM5360 (include US and EU variants) I (20564153) cellular: Set modem driver to 'SIM5360' I (20564153) cellular: State: Enter PoweredOn state I (20584153) cellular: State: Enter MuxStart state I (20703153) housekeeping: 2022-03-16 19:30:08 PDT (RAM: 8b=78740-82120 32b=12344 SPI=3384268-3417632) I (20704143) cellular: State: Enter PoweringOn state I (20704143) cellular: Set modem driver to 'auto' I (20704143) cellular-modem-auto: Power Cycle 2000ms I (20734143) cellular: State: Enter PoweringOn state I (20734143) cellular-modem-auto: Power Cycle 4000ms I (20740793) cellular: State: Enter Identify state I (20741153) cellular: Identified cellular modem: SIM5360/SIMCOM SIM5360 (include US and EU variants) I (20741153) cellular: Set modem driver to 'SIM5360' I (20741153) cellular: State: Enter PoweredOn state I (20761153) cellular: State: Enter MuxStart state and the status page shows: MODEM Status Model: SIM5360 Network Registration: Unknown Provider: Signal: 0 dBm Mode: State: MuxStart Mux: Status down PPP: Not running GPS: Not running All troubleshooting suggestions welcomed. - Mike On Wed, Mar 16, 2022 at 12:25 PM Craig Leres <leres@xse.com> wrote:
On 3/16/22 10:54, Craig Leres wrote:
I have a v3.3 module in my Corvette and recently got it back on the road but I find that following the sim7600 modem testing I did a few weeks ago, it doesn't seem to be processing canbus frames. When the car is running, the module does not appear to update soc or vin although this used to work.
Nevermind; I changed the vehicle type, change it back, and rebooted the module and it seems to be working again.
I'm still interested in the mod sum -> [vehicle] -> type difference though.
Craig _______________________________________________ OvmsDev mailing list OvmsDev@lists.openvehicles.com http://lists.openvehicles.com/mailman/listinfo/ovmsdev
On 3/16/22 10:54, Craig Leres wrote:
I have a v3.3 module in my Corvette and recently got it back on the road but I find that following the sim7600 modem testing I did a few weeks ago, it doesn't seem to be processing canbus frames. When the car is running, the module does not appear to update soc or vin although this used to work.
Actually there still seems to be a problem. Today I relearned how to run savvycan remotely. What I find is I receive a burst of packets when I first connect and then I lose the connection. I tried swapping in my dev module but get the same symptoms. For all three of my modules currently powered up, the gvret session consistently dies ~7 seconds after connecting. Thursday I went for a quick drive and got a flatbed alert and I see now that with the engine running v.e.on is "no". No idea why the module in my CTS-V doesn't have the same problem. (But it is also unable to keep a gvret session up.) Craig
On 3/20/22 00:40, Craig Leres wrote: Thursday I went for a quick drive and got a flatbed alert and I see now that with the engine running v.e.on is "no". No idea why the module in my CTS-V doesn't have the same problem. (But it is also unable to keep a gvret session up.) I observe the same behavior that I get a supposed theft alarm reported and then when I look in the metrics I see that v.e.on is set to 'no'. When I look at the status of the CAN bus, I see that no more messages are coming in. I only observe the problem on CAN2 (125kbps) and CAN3 (500kbps). As soon as I set the CAN bus to stop and directly restart it, new messages immediately start flowing in again. Kind regards, Simon
On 4/3/22 12:58, Simon Ehlen wrote:
On 3/20/22 00:40, Craig Leres wrote: Thursday I went for a quick drive and got a flatbed alert and I see now that with the engine running v.e.on is "no". No idea why the module in my CTS-V doesn't have the same problem. (But it is also unable to keep a gvret session up.)
I observe the same behavior that I get a supposed theft alarm reported and then when I look in the metrics I see that v.e.on is set to 'no'. When I look at the status of the CAN bus, I see that no more messages are coming in. I only observe the problem on CAN2 (125kbps) and CAN3 (500kbps). As soon as I set the CAN bus to stop and directly restart it, new messages immediately start flowing in again.
Which vehicle type are you using? My problems are specific to the C6 Corvette and I'm been having a difficult time getting any traction on what I'm doing wrong. What I see is that any version I boot works for a little while. But after some length of time, the canbus stops working and I get flatbed alerts because the module does not detect that the car is running. The last build I did under FreeBSD that works with the Corvette is 3.3.001-285-g601f2a70. But everything works with my Cadillac... Initially I was thinking I had a toolchain problem of some kind. But I tried running the edge version recently (3.3.002-18 or similar) and it failed (points away from toolchain/FreeBSD environment). I also tried building 3.3.001-285 with my current FreeBSD tools and it fails (points back to toolchain/FreeBSD environment). Over the weekend I restored the system I do ovms builds on, from February 22nd, to a spare SSD and tried rebuilding 3.3.001-285; that version seems to work. I built 3.3.002-25 and have booted that; I'll be driving the Corvette a couple more run cycles today and will be able to tell if it works. I don't believe my xtensa-esp32-elf package has changed in a really long time. But I did switch from python 3.8 to 3.9 around the time things stopped working and I'm pretty sure python is used in at least the linking process, so maybe that's my problem. Craig
On 4/4/22 23:05, Craig Leres wrote:
Which vehicle type are you using?
My vehicle type is a Ford Focus electric, the module is still in the early stages of development.
What I see is that any version I boot works for a little while.
But after some length of time, the canbus stops working and
I get flatbed alerts because the module does not detect that the car is running.
That's how it is for me, too. I have read-only access to the CAN buses without additional polling. After some time I notice that the values are no longer updated, if I then look at the bus with 'can can2 status', I see that neither interrupts nor packets come in, although the bus is definitely still active. Either a module reset or a restart of the bus let the messages flow again. On which bus do you have the problem? So far I could only observe this on CAN2 and CAN3. CAN1 was not stalled as far as I can tell. Kind regards, Simon
On 5/4/22 20:23 Greg D. wrote:
I wonder if this is the same old problem we've had (are having?) with CAN2/3, where it just goes deaf after a while. I saw it all the time
with the OBD2ECU task, which listens to CAN3 (typically) for Head-Up Display polling requests and fulfills them with data from the metrics.
To make sure it's not my module, I loaded the empty vehicle today and started the CAN buses manually. Even then it happens that CAN2 and CAN3 do not receive any messages after some time. What I noticed is that on the CAN1 status there are more interrupts than received packets. For CAN2 and CAN2 it is the other way around. Since I've only been working with OVMS for a short time, I can't tell if this has any meaning, but maybe it's just a timing problem. Unfortunately the MCP2515 code is beyond my understanding, so I have to rely on help from the core developers for this problem. Kind regards, Simon
There is definitely something funny going on with can1. I thought 3.3.001-285 ran ok but last week I got a flatbed alert from that version. So I've seen this problem with a wide range of recent versions including an edge version I did not build myself (downloaded from api.openvehicles.com). What's interesting is the same builds work without issue on my Cadillac, it's only the Corvette that gets into trouble. Given what I've tried so far I booted ovms-3.3.002-25 on the Corvette and have been getting flatbed alerts every 15 minutes since leaving home today (I think I have that turned off now). I can't easily capture the output of "can can1 status" until I get home and the module joins my home network (and "cut" from the messages page of the ovms iphone app is not implemented) but I see ~2M interrupts, 1.2M px pkts, 30 tx delays, 13K tx overflw, 840 tx fails. There are no err flags (0x00000000) and no other errors. This seems to indicate can1 transmission is broken for me. Craig
Here is can bus status for my Corvette after 4 run cycles in which it was never able to transmit frames on can1. Craig OVMS# can can1 status CAN: can1 Mode: Active Speed: 500000 DBC: none Interrupts: 5115225 Rx pkt: 4236787 Rx ovrflw: 0 Tx pkt: 0 Tx delays: 30 Tx ovrflw: 28916 Tx fails: 840 Err flags: 0x00000000 Rx err: 0 Tx err: 0 Rx invalid: 0 Wdg Resets: 0 Wdg Timer: 3 sec(s) Err Resets: 0
My CAN1 bus works without problems, as before only CAN2 and CAN3 are affected. Enclosed is a current excerpt from the status. Both CAN2 and CAN3 do not provide any new data at the moment, although both buses are still active. For me it is noticeable that currently CAN3 has more packets than interrupts. I have observed the same with CAN2, but never with CAN1. Greg D. had indicated that there was a problem with CAN2/CAN3 in the past where the buses went deaf after a while. Has the problem actually been fixed in the past or is this still the problem that remains unresolved? Is there any other information I could provide to help track down the problem? CAN: can1 Mode: Active Speed: 500000 DBC: none Interrupts: 14256668 Rx pkt: 14245150 Rx ovrflw: 23 Tx pkt: 0 Tx delays: 0 Tx ovrflw: 0 Tx fails: 0 Err flags: 0x00000000 Rx err: 0 Tx err: 0 Rx invalid: 0 Wdg Resets: 0 Wdg Timer: 0 sec(s) Err Resets: 0 CAN: can2 Mode: Active Speed: 125000 DBC: none Interrupts: 101488 Rx pkt: 101483 Rx ovrflw: 0 Tx pkt: 0 Tx delays: 0 Tx ovrflw: 0 Tx fails: 0 Err flags: 0x01000001 Rx err: 0 Tx err: 0 Rx invalid: 0 Wdg Resets: 0 Wdg Timer: 9 sec(s) Err Resets: 0 CAN: can3 Mode: Active Speed: 500000 DBC: none Interrupts: 3036646 Rx pkt: 3044758 Rx ovrflw: 0 Tx pkt: 0 Tx delays: 0 Tx ovrflw: 0 Tx fails: 0 Err flags: 0x01000001 Rx err: 0 Tx err: 0 Rx invalid: 0 Wdg Resets: 0 Wdg Timer: 0 sec(s) Err Resets: 0 Kind regards, Simon
Simon, interrupt counters work different depending on the CAN transceiver & communication type, CAN2/3 are MCP2515 via SPI, while CAN1 is ESP32CAN (loosely SJA1000 compatible) via internal bus. There is generally only a loose connection, as any RX will trigger at least one interrupt, but not all interrupts are RX related, and an RX interrupt can cover multiple buffered packets. But…
Interrupts: 3036646 Rx pkt: 3044758
…that's possibly a hint you've frequent packet bursts on that bus, and that may be the cause you're experiencing the freeze so often. That would lead to a possible bug in the driver's RX handling for situations where new packets come in very fast. The MCP2515 isn't particularly simple to read & control in such situations, our driver may lack some crucial handling.
Err flags: 0x01000001
For the mcp2515 driver, that means… * intstat = 0x01 → RX buffer 0 full * errflag = 0x00 …so no actual error condition. Some development of the error status is possibly readable from the system log and/or CAN log. Regards, Michael Am 14.04.22 um 20:58 schrieb Simon Ehlen:
AW: [Ovmsdev] Not processing canbus frames anymore
My CAN1 bus works without problems, as before only CAN2 and CAN3 are affected. Enclosed is a current excerpt from the status. Both CAN2 and CAN3 do not provide any new data at the moment, although both buses are still active. For me it is noticeable that currently CAN3 has more packets than interrupts. I have observed the same with CAN2, but never with CAN1. Greg D. had indicated that there was a problem with CAN2/CAN3 in the past where the buses went deaf after a while. Has the problem actually been fixed in the past or is this still the problem that remains unresolved? Is there any other information I could provide to help track down the problem? CAN: can1 Mode: Active Speed: 500000 DBC: none Interrupts: 14256668 Rx pkt: 14245150 Rx ovrflw: 23 Tx pkt: 0 Tx delays: 0 Tx ovrflw: 0 Tx fails: 0 Err flags: 0x00000000 Rx err: 0 Tx err: 0 Rx invalid: 0 Wdg Resets: 0 Wdg Timer: 0 sec(s) Err Resets: 0 CAN: can2 Mode: Active Speed: 125000 DBC: none Interrupts: 101488 Rx pkt: 101483 Rx ovrflw: 0 Tx pkt: 0 Tx delays: 0 Tx ovrflw: 0 Tx fails: 0 Err flags: 0x01000001 Rx err: 0 Tx err: 0 Rx invalid: 0 Wdg Resets: 0 Wdg Timer: 9 sec(s) Err Resets: 0 CAN: can3 Mode: Active Speed: 500000 DBC: none Interrupts: 3036646 Rx pkt: 3044758 Rx ovrflw: 0 Tx pkt: 0 Tx delays: 0 Tx ovrflw: 0 Tx fails: 0 Err flags: 0x01000001 Rx err: 0 Tx err: 0 Rx invalid: 0 Wdg Resets: 0 Wdg Timer: 0 sec(s) Err Resets: 0 Kind regards, Simon
_______________________________________________ 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
Hi Michael, On 15/04/2022 10:11 Michael Balzer wrote:
…that's possibly a hint you've frequent packet bursts on that bus, and that may be the cause you're experiencing the freeze so often.
That would lead to a possible bug in the driver's RX handling for situations where new packets come in very fast. The MCP2515 isn't
particularly simple to read & control in such situations, our driver may lack some crucial handling.
I added the CAN3 connection later and felt the problems with CAN2 started to appear from that point on. Can the many burst packets on CAN3 actually affect the handling of the CAN2 packets so that the whole mcp2515 handling comes to a halt? Kind regards, Simon
That looks like RX was working normally, but all TX was just queued. Just a thought: is it possible the ESP32CAN TX buffer is sometimes unavailable on the first frame transmission (or appears to be), not due to an actual frame blocking the buffer, but due to some kind of init race condition? That would lead to esp32can::WriteFrame() returning FAIL causing the frame to be queued in m_txqueue, but as there is no real TX going on at that moment, there never will be a TX callback, so the m_txqueue will grow indefinitely from there on. Regards, Michael Am 14.04.22 um 00:51 schrieb Craig Leres:
Here is can bus status for my Corvette after 4 run cycles in which it was never able to transmit frames on can1.
Craig
OVMS# can can1 status CAN: can1 Mode: Active Speed: 500000 DBC: none
Interrupts: 5115225 Rx pkt: 4236787 Rx ovrflw: 0 Tx pkt: 0 Tx delays: 30 Tx ovrflw: 28916 Tx fails: 840
Err flags: 0x00000000 Rx err: 0 Tx err: 0 Rx invalid: 0 Wdg Resets: 0 Wdg Timer: 3 sec(s) Err Resets: 0
-- Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal Fon 02333 / 833 5735 * Handy 0176 / 206 989 26
This doesn't match my thought:
Tx fails: 840
That means there actually were TX failures or TX aborts from a bus error state. That should manifest in the logs as well, with possibly more detail. Regards, Michael Am 15.04.22 um 09:15 schrieb Michael Balzer:
That looks like RX was working normally, but all TX was just queued.
Just a thought: is it possible the ESP32CAN TX buffer is sometimes unavailable on the first frame transmission (or appears to be), not due to an actual frame blocking the buffer, but due to some kind of init race condition?
That would lead to esp32can::WriteFrame() returning FAIL causing the frame to be queued in m_txqueue, but as there is no real TX going on at that moment, there never will be a TX callback, so the m_txqueue will grow indefinitely from there on.
Regards, Michael
Am 14.04.22 um 00:51 schrieb Craig Leres:
Here is can bus status for my Corvette after 4 run cycles in which it was never able to transmit frames on can1.
Craig
OVMS# can can1 status CAN: can1 Mode: Active Speed: 500000 DBC: none
Interrupts: 5115225 Rx pkt: 4236787 Rx ovrflw: 0 Tx pkt: 0 Tx delays: 30 Tx ovrflw: 28916 Tx fails: 840
Err flags: 0x00000000 Rx err: 0 Tx err: 0 Rx invalid: 0 Wdg Resets: 0 Wdg Timer: 3 sec(s) Err Resets: 0
_______________________________________________ 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
On 4/15/22 01:24, Michael Balzer wrote:
This doesn't match my thought:
Tx fails: 840
That means there actually were TX failures or TX aborts from a bus error state.
That should manifest in the logs as well, with possibly more detail.
I've appended some can messages from the log file on my sd card. Timestamps correspond to when I was driving. Looking at esp32can.cpp I guess errflags (aka error_flags) is a combination of several things, 16 bits of "error_irqs", 8 bits of MODULE_ESP32CAN->SR.U, and 8 bits of MODULE_ESP32CAN->ECC.U. I think 0x800000 is BIT(7) or __CAN_IRQ_BUS_ERR or "IR.7 Bus Error Interrupt". Is it saying it doesn't like my can bus? I haven't changed the way I connect to the high speed can, I tapped into the onstar connector. I guess it's possible the cable got damaged (it's under the right/passenger's seat) but it does seem to be able to receive frames without error. (And I know the engine will not run if there are problems on the high speed can bus!) Craig 2022-04-21 12:03:11.684 PDT E (1213934) can: can1: intr=370416 rxpkt=370190 txpkt=206 errflags=0x8000d9 rxerr=0 txerr=8 rxinval=0 rxovr=0 txovr=0 txdelay=0 txfail=0 wdgreset=0 errreset=0 2022-04-21 12:03:11.684 PDT E (1213934) can: can1: intr=370420 rxpkt=370190 txpkt=206 errflags=0x8000d9 rxerr=0 txerr=40 rxinval=0 rxovr=0 txovr=0 txdelay=0 txfail=0 wdgreset=0 errreset=0 2022-04-21 12:03:11.684 PDT E (1213934) can: can1: intr=370422 rxpkt=370190 txpkt=206 errflags=0x8000d9 rxerr=0 txerr=56 rxinval=0 rxovr=0 txovr=0 txdelay=0 txfail=0 wdgreset=0 errreset=0 2022-04-21 12:03:11.684 PDT E (1213934) can: can1: intr=370423 rxpkt=370190 txpkt=206 errflags=0x8000d9 rxerr=0 txerr=64 rxinval=0 rxovr=0 txovr=0 txdelay=0 txfail=0 wdgreset=0 errreset=0 2022-04-21 12:03:11.684 PDT E (1213934) can: can1: intr=370425 rxpkt=370190 txpkt=206 errflags=0x8000d9 rxerr=0 txerr=80 rxinval=0 rxovr=0 txovr=0 txdelay=0 txfail=0 wdgreset=0 errreset=0 2022-04-21 12:03:11.684 PDT E (1213934) can: can1: intr=370426 rxpkt=370190 txpkt=206 errflags=0x8000d9 rxerr=0 txerr=88 rxinval=0 rxovr=0 txovr=0 txdelay=0 txfail=0 wdgreset=0 errreset=0 2022-04-21 12:03:11.684 PDT E (1213934) can: can1: intr=370427 rxpkt=370190 txpkt=206 errflags=0x8440d9 rxerr=0 txerr=96 rxinval=0 rxovr=0 txovr=0 txdelay=0 txfail=0 wdgreset=0 errreset=0 2022-04-21 12:03:11.684 PDT E (1213934) can: can1: intr=370429 rxpkt=370190 txpkt=206 errflags=0x8040d9 rxerr=0 txerr=112 rxinval=0 rxovr=0 txovr=0 txdelay=0 txfail=0 wdgreset=0 errreset=0 2022-04-21 12:03:11.684 PDT E (1213934) can: can1: intr=370430 rxpkt=370190 txpkt=206 errflags=0x8040d9 rxerr=0 txerr=120 rxinval=0 rxovr=0 txovr=0 txdelay=0 txfail=0 wdgreset=0 errreset=0 2022-04-21 12:03:11.684 PDT E (1213934) can: can1: intr=370433 rxpkt=370190 txpkt=206 errflags=0x204800 rxerr=0 txerr=128 rxinval=0 rxovr=0 txovr=0 txdelay=0 txfail=0 wdgreset=0 errreset=0 2022-04-21 15:50:20.584 PDT E (14842934) can: can1: intr=372932 rxpkt=370190 txpkt=206 errflags=0x8048d9 rxerr=0 txerr=128 rxinval=0 rxovr=0 txovr=0 txdelay=0 txfail=1250 wdgreset=0 errreset=0 2022-04-21 18:33:03.834 PDT E (24605934) can: can1: intr=26259766 rxpkt=903954 txpkt=676 errflags=0x8000d9 rxerr=0 txerr=8 rxinval=0 rxovr=0 txovr=518 txdelay=30 txfail=1250 wdgreset=0 errreset=0 2022-04-21 18:33:03.834 PDT E (24605934) can: can1: intr=26259771 rxpkt=903954 txpkt=676 errflags=0x8000d9 rxerr=0 txerr=48 rxinval=0 rxovr=0 txovr=518 txdelay=30 txfail=1250 wdgreset=0 errreset=0 2022-04-21 18:33:03.834 PDT E (24605934) can: can1: intr=26259772 rxpkt=903954 txpkt=676 errflags=0x8000d9 rxerr=0 txerr=56 rxinval=0 rxovr=0 txovr=518 txdelay=30 txfail=1250 wdgreset=0 errreset=0 2022-04-21 18:33:03.834 PDT E (24605934) can: can1: intr=26259774 rxpkt=903954 txpkt=676 errflags=0x8000d9 rxerr=0 txerr=72 rxinval=0 rxovr=0 txovr=518 txdelay=30 txfail=1250 wdgreset=0 errreset=0 2022-04-21 18:33:03.834 PDT E (24605934) can: can1: intr=26259775 rxpkt=903954 txpkt=676 errflags=0x8000d9 rxerr=0 txerr=80 rxinval=0 rxovr=0 txovr=518 txdelay=30 txfail=1250 wdgreset=0 errreset=0 2022-04-21 18:33:03.834 PDT E (24605934) can: can1: intr=26259777 rxpkt=903954 txpkt=676 errflags=0x8440d9 rxerr=0 txerr=96 rxinval=0 rxovr=0 txovr=518 txdelay=30 txfail=1250 wdgreset=0 errreset=0 2022-04-21 18:33:03.834 PDT E (24605934) can: can1: intr=26259778 rxpkt=903954 txpkt=676 errflags=0x8040d9 rxerr=0 txerr=104 rxinval=0 rxovr=0 txovr=518 txdelay=30 txfail=1250 wdgreset=0 errreset=0 2022-04-21 18:33:03.834 PDT E (24605934) can: can1: intr=26259779 rxpkt=903954 txpkt=676 errflags=0x8040d9 rxerr=0 txerr=112 rxinval=0 rxovr=0 txovr=518 txdelay=30 txfail=1250 wdgreset=0 errreset=0 2022-04-21 18:33:03.834 PDT E (24605934) can: can1: intr=26259783 rxpkt=903954 txpkt=676 errflags=0x204800 rxerr=0 txerr=128 rxinval=0 rxovr=0 txovr=518 txdelay=30 txfail=1250 wdgreset=0 errreset=0 2022-04-21 19:54:04.634 PDT E (29466934) can: can1: intr=26974397 rxpkt=1617705 txpkt=1023 errflags=0x8000d9 rxerr=0 txerr=8 rxinval=0 rxovr=0 txovr=518 txdelay=30 txfail=1532 wdgreset=0 errreset=0 2022-04-21 19:54:04.634 PDT E (29466934) can: can1: intr=26974401 rxpkt=1617705 txpkt=1023 errflags=0x8000d9 rxerr=0 txerr=40 rxinval=0 rxovr=0 txovr=518 txdelay=30 txfail=1532 wdgreset=0 errreset=0 2022-04-21 19:54:04.634 PDT E (29466934) can: can1: intr=26974403 rxpkt=1617705 txpkt=1023 errflags=0x8000d9 rxerr=0 txerr=56 rxinval=0 rxovr=0 txovr=518 txdelay=30 txfail=1532 wdgreset=0 errreset=0 2022-04-21 19:54:04.634 PDT E (29466934) can: can1: intr=26974405 rxpkt=1617705 txpkt=1023 errflags=0x8000d9 rxerr=0 txerr=72 rxinval=0 rxovr=0 txovr=518 txdelay=30 txfail=1532 wdgreset=0 errreset=0 2022-04-21 19:54:04.634 PDT E (29466934) can: can1: intr=26974406 rxpkt=1617705 txpkt=1023 errflags=0x8000d9 rxerr=0 txerr=80 rxinval=0 rxovr=0 txovr=518 txdelay=30 txfail=1532 wdgreset=0 errreset=0 2022-04-21 19:54:04.634 PDT E (29466934) can: can1: intr=26974407 rxpkt=1617705 txpkt=1023 errflags=0x8000d9 rxerr=0 txerr=88 rxinval=0 rxovr=0 txovr=518 txdelay=30 txfail=1532 wdgreset=0 errreset=0 2022-04-21 19:54:04.634 PDT E (29466934) can: can1: intr=26974409 rxpkt=1617705 txpkt=1023 errflags=0x8040d9 rxerr=0 txerr=104 rxinval=0 rxovr=0 txovr=518 txdelay=30 txfail=1532 wdgreset=0 errreset=0 2022-04-21 19:54:04.634 PDT E (29466934) can: can1: intr=26974410 rxpkt=1617705 txpkt=1023 errflags=0x8040d9 rxerr=0 txerr=112 rxinval=0 rxovr=0 txovr=518 txdelay=30 txfail=1532 wdgreset=0 errreset=0 2022-04-21 19:54:04.634 PDT E (29466934) can: can1: intr=26974411 rxpkt=1617705 txpkt=1023 errflags=0x8040d9 rxerr=0 txerr=120 rxinval=0 rxovr=0 txovr=518 txdelay=30 txfail=1532 wdgreset=0 errreset=0 2022-04-21 19:54:04.634 PDT E (29466934) can: can1: intr=26974414 rxpkt=1617705 txpkt=1023 errflags=0x204800 rxerr=0 txerr=128 rxinval=0 rxovr=0 txovr=518 txdelay=30 txfail=1532 wdgreset=0 errreset=0
Craig, your log excerpt shows perfectly normal CAN behaviour for the bus being turned off by the vehicle. The transceiver does 128 retransmission attempts before entering bus-passive state. Example from the UpMiiGo: 2022-04-23 13:38:39.157 CEST E (338630327) can: can1: intr=1083368047 rxpkt=209218 txpkt=215216 errflags=0x8000d9 rxerr=0 txerr=8 rxinval=0 rxovr=0 txovr=9266 txdelay=16024 txfail=18767 wdgreset=0 errreset=0 2022-04-23 13:38:39.157 CEST E (338630327) can: can1: intr=1083368052 rxpkt=209218 txpkt=215216 errflags=0x8000d9 rxerr=0 txerr=48 rxinval=0 rxovr=0 txovr=9266 txdelay=16024 txfail=18767 wdgreset=0 errreset=0 2022-04-23 13:38:39.157 CEST E (338630327) can: can1: intr=1083368055 rxpkt=209218 txpkt=215216 errflags=0x8000d9 rxerr=0 txerr=72 rxinval=0 rxovr=0 txovr=9266 txdelay=16024 txfail=18767 wdgreset=0 errreset=0 2022-04-23 13:38:39.157 CEST E (338630327) can: can1: intr=1083368057 rxpkt=209218 txpkt=215216 errflags=0x8000d9 rxerr=0 txerr=88 rxinval=0 rxovr=0 txovr=9266 txdelay=16024 txfail=18767 wdgreset=0 errreset=0 2022-04-23 13:38:39.157 CEST E (338630327) can: can1: intr=1083368059 rxpkt=209218 txpkt=215216 errflags=0x8040d9 rxerr=0 txerr=104 rxinval=0 rxovr=0 txovr=9266 txdelay=16024 txfail=18767 wdgreset=0 errreset=0 2022-04-23 13:38:39.157 CEST E (338630327) can: can1: intr=1083368061 rxpkt=209218 txpkt=215216 errflags=0x8040d9 rxerr=0 txerr=120 rxinval=0 rxovr=0 txovr=9266 txdelay=16024 txfail=18767 wdgreset=0 errreset=0 2022-04-23 13:38:39.157 CEST E (338630327) can: can1: intr=1083368064 rxpkt=209218 txpkt=215216 errflags=0x204800 rxerr=0 txerr=128 rxinval=0 rxovr=0 txovr=9266 txdelay=16024 txfail=18767 wdgreset=0 errreset=0 2022-04-23 13:38:40.157 CEST D (338631327) v-vweup: PollerStateTicker: [offline] LVPwrState=0 HVChgMode=0 SOC=27.0% LVAutoChg=1 12V=12.1 DCDC_U=12.3 DCDC_I=0.0 ChgEff=0.0 BatI=-0.0 BatIAge=12 => PollState 1->0 2022-04-23 13:38:40.157 CEST I (338631327) v-vweup: PollerStateTicker: Setting car state to OFF 2022-04-23 13:38:40.157 CEST I (338631327) v-vweup: PollSetState: AWAKE -> OFF The transceiver bus error state gets resolved as soon as the bus is turned on again. Regards, Michael Am 22.04.22 um 19:10 schrieb Craig Leres:
On 4/15/22 01:24, Michael Balzer wrote:
This doesn't match my thought:
Tx fails: 840
That means there actually were TX failures or TX aborts from a bus error state.
That should manifest in the logs as well, with possibly more detail.
I've appended some can messages from the log file on my sd card. Timestamps correspond to when I was driving. Looking at esp32can.cpp I guess errflags (aka error_flags) is a combination of several things, 16 bits of "error_irqs", 8 bits of MODULE_ESP32CAN->SR.U, and 8 bits of MODULE_ESP32CAN->ECC.U. I think 0x800000 is BIT(7) or __CAN_IRQ_BUS_ERR or "IR.7 Bus Error Interrupt".
Is it saying it doesn't like my can bus? I haven't changed the way I connect to the high speed can, I tapped into the onstar connector. I guess it's possible the cable got damaged (it's under the right/passenger's seat) but it does seem to be able to receive frames without error. (And I know the engine will not run if there are problems on the high speed can bus!)
Craig
2022-04-21 12:03:11.684 PDT E (1213934) can: can1: intr=370416 rxpkt=370190 txpkt=206 errflags=0x8000d9 rxerr=0 txerr=8 rxinval=0 rxovr=0 txovr=0 txdelay=0 txfail=0 wdgreset=0 errreset=0 2022-04-21 12:03:11.684 PDT E (1213934) can: can1: intr=370420 rxpkt=370190 txpkt=206 errflags=0x8000d9 rxerr=0 txerr=40 rxinval=0 rxovr=0 txovr=0 txdelay=0 txfail=0 wdgreset=0 errreset=0 2022-04-21 12:03:11.684 PDT E (1213934) can: can1: intr=370422 rxpkt=370190 txpkt=206 errflags=0x8000d9 rxerr=0 txerr=56 rxinval=0 rxovr=0 txovr=0 txdelay=0 txfail=0 wdgreset=0 errreset=0 2022-04-21 12:03:11.684 PDT E (1213934) can: can1: intr=370423 rxpkt=370190 txpkt=206 errflags=0x8000d9 rxerr=0 txerr=64 rxinval=0 rxovr=0 txovr=0 txdelay=0 txfail=0 wdgreset=0 errreset=0 2022-04-21 12:03:11.684 PDT E (1213934) can: can1: intr=370425 rxpkt=370190 txpkt=206 errflags=0x8000d9 rxerr=0 txerr=80 rxinval=0 rxovr=0 txovr=0 txdelay=0 txfail=0 wdgreset=0 errreset=0 2022-04-21 12:03:11.684 PDT E (1213934) can: can1: intr=370426 rxpkt=370190 txpkt=206 errflags=0x8000d9 rxerr=0 txerr=88 rxinval=0 rxovr=0 txovr=0 txdelay=0 txfail=0 wdgreset=0 errreset=0 2022-04-21 12:03:11.684 PDT E (1213934) can: can1: intr=370427 rxpkt=370190 txpkt=206 errflags=0x8440d9 rxerr=0 txerr=96 rxinval=0 rxovr=0 txovr=0 txdelay=0 txfail=0 wdgreset=0 errreset=0 2022-04-21 12:03:11.684 PDT E (1213934) can: can1: intr=370429 rxpkt=370190 txpkt=206 errflags=0x8040d9 rxerr=0 txerr=112 rxinval=0 rxovr=0 txovr=0 txdelay=0 txfail=0 wdgreset=0 errreset=0 2022-04-21 12:03:11.684 PDT E (1213934) can: can1: intr=370430 rxpkt=370190 txpkt=206 errflags=0x8040d9 rxerr=0 txerr=120 rxinval=0 rxovr=0 txovr=0 txdelay=0 txfail=0 wdgreset=0 errreset=0 2022-04-21 12:03:11.684 PDT E (1213934) can: can1: intr=370433 rxpkt=370190 txpkt=206 errflags=0x204800 rxerr=0 txerr=128 rxinval=0 rxovr=0 txovr=0 txdelay=0 txfail=0 wdgreset=0 errreset=0
-- Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal Fon 02333 / 833 5735 * Handy 0176 / 206 989 26
I guess I need to revive this thread as I'm still having issues with a v3.3 module in my Corvette. What I see is that things work normally for 1-2 days and then I start getting flatbed alerts because the module doesn't detect when the car is "on". As a test I swapped in my dev module (vintage 2018) and it worked flawlessly for about a month. I swapped the v3.3 module back a few weeks ago and was only able to make one day's worth of trips without flatbed alerts and then they were back. And I filled up last night but the v2 server shows me a 33%. What kind of logging can I enable that would be helpful? My modules currently have 3.3.003-2-gd00de6c0 More recently I started having issues with network registration and gnss reception; at least every few days both cars will transition from RegisteredRoaming to Searching and then back to RegisteredRoaming. They also transition from 12 satellites in view to no satellites in view and back to 12 satellites in view. For the cellular connection I might buy that a local cell tower is out of service and/or maybe my signal strength is too low. But for the gnss I can't see why this would happen, especially given that I have a satellite antenna in the garage, under the same tar-and-gravel roof as the cars, that I used for ntp synchronization (a u-blox ZED-F9T based receiver tracking four constellations...) and it never misses a beat. Not sure if I have two different issues here or if one is related to the "SIM7600 Registration Denied" thread. Craig
Craig, if you set the log level for the canlog monitor (tag "canlog-monitor") to debug, it logs only events, statistics and errors, so won't flood your log. You can then add statistics checkpoints by adding an event script on a suitable ticker, the "can can<n> status" command triggers a status dump to the loggers. That way you may be able to see what leads up to the bus freeze. Regards, Michael Am 24.09.22 um 01:21 schrieb Craig Leres:
I guess I need to revive this thread as I'm still having issues with a v3.3 module in my Corvette. What I see is that things work normally for 1-2 days and then I start getting flatbed alerts because the module doesn't detect when the car is "on".
As a test I swapped in my dev module (vintage 2018) and it worked flawlessly for about a month. I swapped the v3.3 module back a few weeks ago and was only able to make one day's worth of trips without flatbed alerts and then they were back. And I filled up last night but the v2 server shows me a 33%.
What kind of logging can I enable that would be helpful?
My modules currently have 3.3.003-2-gd00de6c0
More recently I started having issues with network registration and gnss reception; at least every few days both cars will transition from RegisteredRoaming to Searching and then back to RegisteredRoaming. They also transition from 12 satellites in view to no satellites in view and back to 12 satellites in view. For the cellular connection I might buy that a local cell tower is out of service and/or maybe my signal strength is too low. But for the gnss I can't see why this would happen, especially given that I have a satellite antenna in the garage, under the same tar-and-gravel roof as the cars, that I used for ntp synchronization (a u-blox ZED-F9T based receiver tracking four constellations...) and it never misses a beat.
Not sure if I have two different issues here or if one is related to the "SIM7600 Registration Denied" thread.
Craig
-- Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal Fon 02333 / 833 5735 * Handy 0176 / 206 989 26
participants (5)
-
Craig Leres -
Greg D. -
Michael Balzer -
Michael Iimura -
Simon Ehlen