I'd consider the "dips" logged here as false positives.

Michael, correct me if I'm wrong: your new 12V monitor doesn't yet implement a calmdown phase after charging. The voltage decline after the DC converter switches off is logarithmic, so can easily trigger the "dip" detection in the beginning. That fits these log entries:

13:17:50.184 (vehicle.off)                      assumption: DCDC off
13:17:51.144 (vehicle.aux.12v.charging.dip)     [12vmon] 12v > 14.0 && < 0.09 under avg
13:17:53.144 (vehicle.aux.12v.dip)              [12vmon] 12v <= 14.0 && < 0.25 under avg
13:17:56.754 (vehicle.locked)
13:18:09.144 (vehicle.charge.12v.stop)          [leaf] 12v <= 12.8
13:18:33.174 (vehicle.aux.12v.normal)
13:19:59.174 (vehicle.asleep)                   [leaf] off since 120-130 seconds (awake stale)

Generally I think all aux.12v log entries shortly after a vehicle.off should currently be ignored with regards to 12V diagnosis. (@Michael: check `m_12v_ticker` for my calmdown implementation for the reference voltage measurement)

The same may apply to the start of a 12V charging phase, depending on the way the vehicle detects that state.


IOW, Chris, you should look for "dip" log entries well within a parking / driving / charging phase, when the 12V level should be more or less constant.

You should also have a look at the general 12V level behaviour, e.g. using the 12V chart plugin or creating a chart from the MQTT metric. The V2 Android App also has a 12V chart, if you use V2. When using V2/MQTT, consider raising the update interval to get a higher time resolution.

Btw, also consider shortening the file logging sync period, 30 seconds is rather high.


On the 12V shutdown: even with 30 seconds log flushing, you would have seen the log entries for a shutdown condition, unless you configured the shutdown delay to 0 (default is 2 minutes).

That is, if the 12V level wasn't suddenly getting drastically low, i.e. too low within seconds to keep the ESP32 in operation. That could explain the freeze. Not sure how low that would need to have been.

I'd check for another potential source of such a sudden voltage drop: a mechanical/electrical issue with the OBD connector or cable.

If for example there is a lose wire in the connection, that occasionally causes a short circuit, that would both explain the module freeze and the car fault.


Regards,
Michael


Am 09.02.25 um 04:45 schrieb Michael Geddes via OvmsDev:
Just fyi a 'dip' is 12v voltage decreasing momentarily. A blip is the reverse.  Charging.dip is dipping while charging.

There's a separate low voltage state for the 12v monitor. 

//.ichael

On Sun, 9 Feb 2025, 06:35 Dan Edwards via OvmsDev, <ovmsdev@lists.openvehicles.com> wrote:
Hi Chris,

Not sure if you’ve investigated the I-key system error , but thought I’d add my experience here.
I have been receiving the same I-key system error in my 2012 leaf, with all the same symptoms and resolution as yours. This leaf doesn’t have OVMS installed at the moment, so maybe your issue is not due to OVMS. 
If you google I-key system error , you’ll find posts on issues with the BCM, which have been resolved with cleaning contacts on bcm (if there’s been moisture issues), and others replacing 12v acc battery. 
I’m pretty sure I’ve narrowed it down to 12v battery issues in my case, after inspecting BCM behind glove box in RHD edition, finding no issue, recharging 12v, and removing any known 12v drain like OVMS or odb dongle, just waiting for a recurrence to confirm.
Check your DTCs with leafspy, if it shows a bunch of DTCs including a B2604 BCM Shift PN diag, then likely low 12v, try a 24 hr charge or replace it. 
The OVMS log also shows 12v dip around the same time as your issue. This may explain OVMS shutdown as well if you’ve got it set to shut down due to  low 12v battery, although I though that might be more graceful. 

Cheers Dan

On 9 Feb 2025, at 8:35 am, Chris Box via OvmsDev <ovmsdev@lists.openvehicles.com> wrote:



Hi,

It's happened again. Yesterday while driving the Leaf lost drive mode, forcing pulling over. I couldn't reengage gear until I had disconnected the 12v battery.

Looking at the evidence today, the incident can't be explained by writing random bytes in CommandWakeup(), nor by having the wrong timing. It actually suggests that OVMS locked up ten minutes before the car was impacted.

Here's what happened.

13:15 to 13:17 I drove off from home, but forgot an item so quickly returned back there.

The sd log records this activity just fine, and the last entries before the suspected hang were these:

2025-02-07 13:19:59.174 GMT D (93751944) events: Signal(vehicle.asleep)
2025-02-07 13:22:29.184 GMT I (93901954) housekeeping: 2025-02-07 13:22:28 GMT (RAM: 8b=79028-81980 32b=12560 SPI=3262992-3285432)

There should have been the next housekeeping message at 13:27:29 but none was recorded on the sd. Log flushes are configured to occur after 30 seconds.

The last MQTT metric update my server received was around 13:27:50. This showed it was connected to home wifi.

At 13:28 I unlocked the car, started it and drove off without noticing anything unusual. None of this activity appears in the log.

During the drive there should have been a connection via Hologram to my server, but none was received.

Ten minutes later at 13:38 I was driving when a yellow warning light came on and the car moved to neutral. Essentially the same symptoms as in January: turning off and on would not clear the fault; it couldn't detect brake status meaning it told me to press brake pedal when I already was. Also showed I-key system error.

As I was stranded I used the only option I knew of to clear the fault, and I disconnected the 12v battery. On restoring power and dismissing the fault notice, it was happy to drive.

The log shows this cold start SNTP was at 13:44. On returning home, unfortunately 'boot status' says nothing about a crash, presumably because any information was lost when I pulled power.

So it seems there is some mechanism by which OVMS can lock up, without watchdog oversight. And that ten minutes later it can do something that becomes a critical issue for the car systems.

Chris

Relevant log entries below, all part of the same file. 1970 follows immediately after 13:22:29.184.

2025-02-07 13:17:50.184 GMT D (93622984) vehicle-poll: Pollers: Queue SetState()
2025-02-07 13:17:50.184 GMT D (93622984) vehicle-poll: Pollers: PollState(0)
2025-02-07 13:17:50.184 GMT D (93622984) events: Signal(vehicle.off)
2025-02-07 13:17:51.144 GMT D (93623944) events: Signal(vehicle.aux.12v.charging.dip)
2025-02-07 13:17:53.144 GMT D (93625944) events: Signal(vehicle.aux.12v.dip)
2025-02-07 13:17:54.824 GMT E (93627624) can: can2: intr=15711227 rxpkt=15730955 txpkt=100 errflags=0x22401c02 rxerr=0 txerr=0 rxinval=0 rxovr=0 txovr=0 txdelay=0 txfail=0 wdgreset=0 errreset=0 txqueue=0
2025-02-07 13:17:56.754 GMT D (93629554) events: Signal(vehicle.locked)
2025-02-07 13:17:59.744 GMT E (93632544) can: can2: intr=15716706 rxpkt=15736447 txpkt=100 errflags=0x23401c01 rxerr=0 txerr=0 rxinval=0 rxovr=0 txovr=0 txdelay=0 txfail=0 wdgreset=0 errreset=0 txqueue=0
2025-02-07 13:18:09.144 GMT D (93641944) events: Signal(vehicle.charge.12v.stop)
2025-02-07 13:18:10.144 GMT I (93642944) powermgmt: No longer charging 12V battery..
2025-02-07 13:18:33.174 GMT D (93665944) events: Signal(vehicle.aux.12v.normal)
2025-02-07 13:18:33.764 GMT E (93666534) can: can2: intr=15754521 rxpkt=15774368 txpkt=100 errflags=0x22401c02 rxerr=0 txerr=0 rxinval=0 rxovr=0 txovr=0 txdelay=0 txfail=0 wdgreset=0 errreset=0 txqueue=0
2025-02-07 13:18:45.174 GMT I (93677944) ovms-server-v3: Connection is <redacted>
2025-02-07 13:18:45.174 GMT I (93677944) ovms-server-v3: Status: Connecting...
2025-02-07 13:18:45.224 GMT D (93677994) events: Signal(server.v3.connecting)
2025-02-07 13:18:48.624 GMT I (93681394) ovms-server-v3: Connection successful
2025-02-07 13:18:48.644 GMT I (93681414) ovms-server-v3: Status: OVMS V3 MQTT login successful
2025-02-07 13:18:48.644 GMT D (93681414) events: Signal(server.v3.connected)
2025-02-07 13:18:49.174 GMT I (93681944) ovms-server-v3: Subscribe to MQTT topics
2025-02-07 13:18:49.174 GMT I (93681944) ovms-server-v3: Transmit all metrics
2025-02-07 13:18:49.464 GMT I (93682234) ovms-server-v3: Subscription acknowledged
2025-02-07 13:19:59.174 GMT D (93751944) events: Signal(vehicle.asleep)
2025-02-07 13:22:29.184 GMT I (93901954) housekeeping: 2025-02-07 13:22:28 GMT (RAM: 8b=79028-81980 32b=12560 SPI=3262992-3285432)
1970-01-01 00:00:08.424 GMT I (7994) command: OpenLogfile: now logging to file '/sd/logs/log'
1970-01-01 00:00:13.474 GMT D (13034) events: Signal(system.event)
1970-01-01 00:00:13.474 GMT D (13034) events: Signal(system.wifi.scan.done)
1970-01-01 00:00:19.424 GMT I (18984) cellular: State: Enter Identify state
1970-01-01 00:00:19.434 GMT I (18994) cellular: Identified cellular modem: SIM7600/Experimental support for SIMCOM SIM7600
1970-01-01 00:00:19.434 GMT I (18994) cellular: Set modem driver to 'SIM7600'
1970-01-01 00:00:19.434 GMT I (18994) cellular: State: Enter PoweredOn state
1970-01-01 00:00:19.424 GMT D (18994) events: Signal(system.modem.installed)
1970-01-01 00:00:19.434 GMT D (19004) events: Signal(system.modem.poweredon)
1970-01-01 00:00:23.474 GMT D (23034) events: Signal(system.event)
1970-01-01 00:00:23.474 GMT D (23034) events: Signal(system.wifi.scan.done)
1970-01-01 00:00:33.474 GMT D (33034) events: Signal(system.event)
1970-01-01 00:00:33.474 GMT D (33034) events: Signal(system.wifi.scan.done)
1970-01-01 00:00:39.434 GMT I (38994) cellular: State: Enter MuxStart state
1970-01-01 00:00:39.444 GMT I (39004) gsm-mux: Start MUX
1970-01-01 00:00:39.444 GMT D (39004) events: Signal(system.modem.muxstart)
1970-01-01 00:00:39.444 GMT I (39014) gsm-mux: Channel #0 is open
1970-01-01 00:00:39.464 GMT I (39024) gsm-mux: Channel #1 is open
1970-01-01 00:00:39.464 GMT I (39024) gsm-mux: Channel #2 is open
1970-01-01 00:00:39.474 GMT I (39034) gsm-mux: Channel #3 is open
1970-01-01 00:00:39.484 GMT I (39044) gsm-mux: Channel #4 is open
1970-01-01 00:00:40.414 GMT I (39984) cellular: State: Enter NetWait state
1970-01-01 00:00:40.414 GMT D (39984) events: Signal(system.modem.netwait)
1970-01-01 00:00:43.474 GMT D (43034) events: Signal(system.event)
1970-01-01 00:00:43.474 GMT D (43034) events: Signal(system.wifi.scan.done)
1970-01-01 00:00:46.054 GMT D (45624) events: Signal(vehicle.awake)
1970-01-01 00:00:50.444 GMT I (50014) cellular: Network Registration status: RegisteredRoaming
1970-01-01 00:00:51.414 GMT I (50984) cellular: State: Enter NetStart state
1970-01-01 00:00:51.434 GMT D (50994) events: Signal(vehicle.aux.12v.blip)
1970-01-01 00:00:51.434 GMT D (50994) events: Signal(system.modem.netstart)
1970-01-01 00:00:51.444 GMT D (51004) events: Signal(vehicle.charge.12v.start)
1970-01-01 00:00:51.434 GMT I (51004) cellular: Network Mode: LTE,Online
1970-01-01 00:00:52.414 GMT I (51984) powermgmt: Charging 12V battery..
1970-01-01 00:00:52.464 GMT I (52034) cellular: PPP Connection is ready to start
1970-01-01 00:00:53.424 GMT I (52984) cellular: State: Enter NetMode state
1970-01-01 00:00:53.424 GMT I (52984) gsm-ppp: Initialising...
1970-01-01 00:00:53.434 GMT D (52994) events: Signal(system.modem.netmode)
1970-01-01 00:00:53.484 GMT D (53044) events: Signal(system.event)
1970-01-01 00:00:53.484 GMT D (53044) events: Signal(system.wifi.scan.done)
1970-01-01 00:00:53.594 GMT I (53154) gsm-ppp: StatusCallBack: None
1970-01-01 00:00:53.594 GMT I (53154) gsm-ppp: status_cb: Connected
1970-01-01 00:00:53.594 GMT I (53154) gsm-ppp:    our_ipaddr  = 100.83.212.151
1970-01-01 00:00:53.594 GMT I (53154) gsm-ppp:    his_ipaddr  = 10.64.64.64
1970-01-01 00:00:53.594 GMT I (53154) gsm-ppp:    netmask     = 255.255.255.255
1970-01-01 00:00:53.594 GMT I (53154) gsm-ppp:    DNS#0       = 8.8.8.8
1970-01-01 00:00:53.584 GMT I (53154) gsm-ppp:    DNS#1       = 8.8.4.4
1970-01-01 00:00:53.594 GMT I (53154) gsm-ppp:    our6_ipaddr = ::
1970-01-01 00:00:53.594 GMT D (53154) events: Signal(network.interface.up)
1970-01-01 00:00:53.604 GMT D (53164) events: Signal(system.modem.gotip)
1970-01-01 00:00:53.604 GMT I (53164) netmanager: Interface priority is pp2 (100.83.212.151/255.255.255.255 gateway 10.64.64.64)
1970-01-01 00:00:53.604 GMT I (53164) netmanager: Set DNS#2 0.0.0.0
1970-01-01 00:00:53.594 GMT I (53164) netmanager: MODEM up (with WIFI client down): starting network with MODEM
1970-01-01 00:00:53.594 GMT D (53164) events: Signal(network.modem.up)
1970-01-01 00:00:53.594 GMT D (53164) events: Signal(network.up)
1970-01-01 00:00:53.604 GMT I (53174) time: Starting SNTP client
1970-01-01 00:00:53.604 GMT D (53174) events: Signal(network.interface.change)
1970-01-01 00:00:53.614 GMT D (53174) events: Signal(network.mgr.init)
1970-01-01 00:00:53.614 GMT I (53174) webserver: Launching Web Server
2025-02-07 13:44:08.584 GMT I (53184) webserver: Binding to port 80 (http)
2025-02-07 13:44:08.584 GMT I (53184) ssh: Launching SSH Server

_______________________________________________
OvmsDev mailing list
OvmsDev@lists.openvehicles.com
http://lists.openvehicles.com/mailman/listinfo/ovmsdev
_______________________________________________
OvmsDev mailing list
OvmsDev@lists.openvehicles.com
http://lists.openvehicles.com/mailman/listinfo/ovmsdev

_______________________________________________
OvmsDev mailing list
OvmsDev@lists.openvehicles.com
http://lists.openvehicles.com/mailman/listinfo/ovmsdev


-- 
Michael Balzer * Am Rahmen 5 * D-58313 Herdecke
Fon 02330 9104094 * Handy 0176 20698926