[Ovmsdev] Another incident
Michael Balzer
dexter at expeedo.de
Sun Feb 9 17:23:54 HKT 2025
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 at 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 at 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
>> <http://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 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 * Am Rahmen 5 * D-58313 Herdecke
Fon 02330 9104094 * Handy 0176 20698926
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.openvehicles.com/pipermail/ovmsdev/attachments/20250209/1e842046/attachment-0001.htm>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: OpenPGP_signature.asc
Type: application/pgp-signature
Size: 203 bytes
Desc: OpenPGP digital signature
URL: <http://lists.openvehicles.com/pipermail/ovmsdev/attachments/20250209/1e842046/attachment-0001.sig>
More information about the OvmsDev
mailing list