tedsalmon / BlueBus

A Bluetooth module for vehicles equipped with I-Bus
Other
163 stars 39 forks source link

Battery Drain after Bluetooth Call #176

Open jwreford opened 11 months ago

jwreford commented 11 months ago

Over the last six months or so I've experienced a few dead battery situations that seemed to have occurred since plugging in the BlueBus (replacing an Intravee). I can't say with 100% certainty yet but it seems like in some situations, after making a Bluetooth call, the BlueBus doesn't power down or is otherwise keeping the iBus active and other devices awake. Yesterday at around midday I had received a call in the car, and today, around 5PM, my alarm went off because the battery was flat.

I'll try to reproduce the issue and use Navcoder and capture traffic. Are there any logs that I can pull off the BlueBus?

Version: 1.3.2

dertimaushh commented 11 months ago

Try to restore the device. I had the same issue. Now all works fine.

BR, Tim

tedsalmon commented 11 months ago

Over the last six months or so I've experienced a few dead battery situations that seemed to have occurred since plugging in the BlueBus (replacing an Intravee). I can't say with 100% certainty yet but it seems like in some situations, after making a Bluetooth call, the BlueBus doesn't power down or is otherwise keeping the iBus active and other devices awake. Yesterday at around midday I had received a call in the car, and today, around 5PM, my alarm went off because the battery was flat.

I'll try to reproduce the issue and use Navcoder and capture traffic. Are there any logs that I can pull off the BlueBus?

Version: 1.3.2

That’s a decent enough edge case that I could see it causing a problem. I will double check that TEL MUTE and TEL On both get driven back to high and low respectively after ignition off.

-Ted

tedsalmon commented 11 months ago

https://github.com/tedsalmon/BlueBus/blob/master/firmware/application/handler/handler_ibus.c#L685

So it’s definitely possible for MUTE to stay active with the ignition off given the right conditions, so I’ll just stuff another line to ensure mute is also low once the ignition off message is processed.

-Ted

jwreford commented 11 months ago

Thank you kindly. I'll test and report back!

jwreford commented 11 months ago

Sorry for the silly question, but the line you referenced, it's not the extra line you were going to add in is it? Not at all trying to rush you, I'll just keep my eyes on it for when you do add it, and test then.

tedsalmon commented 11 months ago

@jwreford - No — it would be:

UtilsSetPinMode(UTILS_PIN_TEL_MUTE, 0);

I’m on vacation, so it’ll be a week or so before I can add this

jwreford commented 11 months ago

Oh! No worries, enjoy your break! I'll have a go at building it locally and testing. Cheers!

mbt28 commented 10 months ago

I had the same issue recently, do you plan to release a new version?

tedsalmon commented 9 months ago

Here you guys go -- try this: https://t3ddftw.s3.us-east-2.amazonaws.com/BlueBus/firmware/bluebus_1_3_3_rc27.hex

jwreford commented 8 months ago

Thank you!! Testing now, will report back.

maarten-v commented 6 months ago

@jwreford Did you test it? I'm still searching for a mystery problem on my car with battery drains, this could have something to do with it.

jwreford commented 6 months ago

Sorry for the late reply. I thought I was experiencing the same issue after flashing however I think my DB connector was not fully plugged in because I reseated, resolving ann unrelated issue with the mic. That makes me think at some point during testing I loosened it.

I watched the BB logs over USB and made a few test calls, and it seemed to go to sleep correctly afterwards. I put a clamp meter over the main positive battery cable and watched the consumption drop below the sensitivity it could measure after 14 minutes (when the car goes to sleep). When I have some time I’ll also watch the ibus with navcoder to see if it goes quiet. Will report back. But no dead battery so far.

maarten-v commented 6 months ago

So you think a loose DB connector could have caused the drain?
What's the DB connector? Is that one of the connectors on the Bluebus?

jwreford commented 6 months ago

The DB25 connector is the old-style phone module connector in my boot. Other cars might have that or the 54 pin. I don’t know for sure if that was the cause of my drain problem but it seems possible. yes, BB was just me being lazy. I mean BlueBus.

Does your car go to sleep after 14 minutes (if you have an e39 or e46 at least)? One way to tell is take the key out and wait to see if the orange indicator next to the gear shifter (in the auto) goes out. If it doesn’t maybe something is keeping it awake. It might also be useful to try and watch the BlueBus logs to see what is happening.

maarten-v commented 6 months ago

Ah ok thanks! Yes it's an E46, but it's very random. Sometimes I can leave the car for a week and it starts, next time i drive the car for an hour and the next day it's completely empty.
I'm pretty sure now with testing that if I unplug fuse 41 (for the radio, navigation, screen) I don't have a problem.
I'll try to keep an eye on the orange indicator, if I have one on the SMG. And also pinpoint if it has anything to do with the Bluebus.

maarten-v commented 5 months ago

My battery just randomly drained again while I had the Bluebus disconnected, so Bluebus is not to blame in my case.

jwreford commented 5 months ago

Hey @tedsalmon, I've been testing for a few weeks and no drain issues so I think this is solved!

jwreford commented 4 months ago

Hey again again @tedsalmon! Sorry for all the messages. The alarm went off today which happens when the battery drains low enough. I connected a jumpstarter to the battery to unlock the doors using the key to deactivate the alarm, and then disconnected the jumpstarter.

The Bluebus blue light was on, and so was the Nav. The video module was warm also so I'm guessing something was keeping the bus awake and everything powered on, which I measured previously draws about 4 amps. I connected via USB and grabbed some logs (without rebooting) and saw messages like this, a few a second:

[90519873] DEBUG: IBus: RX[17]: 68 0F 3B 21 62 01 40 69 76 65 72 73 61 72 79 20 6F [SELF] [90519890] DEBUG: IBus: RX[8]: 68 06 3B A5 62 01 00 93 [SELF] [90520372] DEBUG: IBus: RX[17]: 68 0F 3B 21 62 01 40 76 65 72 73 61 72 79 20 45 43 [SELF] [90520389] DEBUG: IBus: RX[8]: 68 06 3B A5 62 01 00 93 [SELF] [90520873] DEBUG: IBus: RX[17]: 68 0F 3B 21 62 01 40 65 72 73 61 72 79 20 45 64 51 [SELF] [90520890] DEBUG: IBus: RX[8]: 68 06 3B A5 62 01 00 93 [SELF] [90521372] DEBUG: IBus: RX[17]: 68 0F 3B 21 62 01 40 72 73 61 72 79 20 45 64 69 5D [SELF] [90521389] DEBUG: IBus: RX[8]: 68 06 3B A5 62 01 00 93 [SELF] [90521872] DEBUG: IBus: RX[17]: 68 0F 3B 21 62 01 40 73 61 72 79 20 45 64 69 74 5B [SELF] [90521889] DEBUG: IBus: RX[8]: 68 06 3B A5 62 01 00 93 [SELF] [90522373] DEBUG: IBus: RX[17]: 68 0F 3B 21 62 01 40 61 72 79 20 45 64 69 74 69 41 [SELF] [90522390] DEBUG: IBus: RX[8]: 68 06 3B A5 62 01 00 93 [SELF] [90522873] DEBUG: IBus: RX[17]: 68 0F 3B 21 62 01 40 72 79 20 45 64 69 74 69 6F 4F [SELF] [90522890] DEBUG: IBus: RX[8]: 68 06 3B A5 62 01 00 93 [SELF] [90523372] DEBUG: IBus: RX[17]: 68 0F 3B 21 62 01 40 79 20 45 64 69 74 69 6F 6E 53 [SELF] [90523389] DEBUG: IBus: RX[8]: 68 06 3B A5 62 01 00 93 [SELF] [90524872] DEBUG: IBus: RX[17]: 68 0F 3B 21 62 01 40 54 68 65 20 4D 61 6E 27 73 31 [SELF] [90524889] DEBUG: IBus: RX[8]: 68 06 3B A5 62 01 00 93 [SELF] [90527872] DEBUG: IBus: RX[17]: 68 0F 3B 21 62 01 40 68 65 20 4D 61 6E 27 73 20 45 [SELF] [90527889] DEBUG: IBus: RX[8]: 68 06 3B A5 62 01 00 93 [SELF] [90528373] DEBUG: IBus: RX[17]: 68 0F 3B 21 62 01 40 65 20 4D 61 6E 27 73 20 54 79 [SELF]

They continued for a few minutes until I rebooted. Then these more normal-looking logs:

[0] DEBUG: PCM51XX Responded to Poll [5] DEBUG: PCM51XX VOLL Set to 0x48 [9] DEBUG: PCM51XX VOLR Set to 0x48 [13] ERROR: UART[2]: GERR FERR [18] ERROR: UART[1]: GERR PERR

BlueBus Firmware: 1.3.3
Try HELP or ?

[564] DEBUG: BM83: RX: AA 00 03 30 00 00 CD [571] DEBUG: BM83: TX: AA 00 02 14 30 BA [577] DEBUG: BM83: TX: AA 00 03 02 00 51 AA [584] DEBUG: BM83: TX: AA 00 03 02 00 52 A9 [606] DEBUG: BM83: RX: AA 00 03 2D 05 01 CA [612] DEBUG: BM83: TX: AA 00 02 14 2D BD [619] DEBUG: BM83: RX: AA 00 03 00 02 00 FB [625] DEBUG: BM83: RX: AA 00 03 01 02 00 FA [632] DEBUG: BM83: TX: AA 00 02 14 01 E9 [638] DEBUG: BT: Power On [643] DEBUG: BM83: TX: AA 00 01 0E F1 [649] DEBUG: BM83: RX: AA 00 03 01 0F 00 ED [656] DEBUG: BM83: TX: AA 00 02 14 01 E9 [662] DEBUG: BT: Standby On [668] DEBUG: BM83: RX: AA 00 03 00 0E 00 EF [674] DEBUG: BM83: RX: AA 00 10 1F 02 02 DB 49 E7 5B A2 90 01 A3 63 6B 7D C1 C4 C1 [684] DEBUG: BM83: TX: AA 00 02 14 1F CB [692] DEBUG: Add PD: 1 [699] DEBUG: Handler: Not connecting to new device 0 1 0 [707] DEBUG: BT: Rewrite Pairing Profile [714] DEBUG: Add PD: 0 [722] DEBUG: Handler: Not connecting to new device 0 1 0 [730] DEBUG: BT: Rewrite Pairing Profile [739] DEBUG: Handler: Not connecting to new device 0 1 0 [747] DEBUG: IBus: RX[17]: 68 0F 3B A5 62 01 06 4E 6F 20 44 65 76 69 63 65 A5 [SELF] [765] DEBUG: IBus: RX[5]: 68 03 80 01 EA [SELF] [1014] DEBUG: IBus: RX[5]: 68 03 3B 01 51 [SELF] [1025] DEBUG: IBus: RX[6]: 3B 04 68 02 40 15 [1034] INFO: GT Detected [1264] DEBUG: IBus: RX[5]: 68 03 7F 01 15 [SELF] [1275] DEBUG: IBus: RX[6]: 7F 04 68 02 40 51 [1284] INFO: NAV Detected [1514] DEBUG: IBus: RX[5]: 68 03 C0 01 AA [SELF] [1764] DEBUG: IBus: RX[5]: 68 03 ED 01 87 [SELF] [1774] DEBUG: IBus: RX[6]: ED 04 68 02 00 83 [1782] INFO: VM Detected [2014] DEBUG: IBus: RX[5]: 18 03 68 01 72 [SELF] [2264] DEBUG: IBus: RX[5]: 80 03 D0 01 52 [SELF] [2515] DEBUG: IBus: RX[6]: C8 04 FF 02 39 08 [SELF] [2764] DEBUG: IBus: RX[5]: 18 03 80 10 8B [SELF]

Although maybe at this point the battery was so low that the nav wasn't able to start correctly and kept itself awake.

Looking at the set of logs pre-reboot with Navcoder they seem to be from RAD -> GT continuously scrolling the song title that was playing before I last turned the car off. I'm guessing this is Bluebus pretending to be the radio, sending them to the board nav's graphics driver to then display on the monitor.

Anyway, after rebooting the BB via the serial console, but not doing anything else, the song scrolling messages stopped. Stating the obvious, but the ignition was off/key wasn't inserted, and had been since the day before.

The next time the issue happens, is there a command I can run to see what state it thinks the car is in (ignition, doors, etc)?

Hopefully that helps! Josh.

tedsalmon commented 4 months ago

@jwreford,

I'm sure it's not easy, but is there a chance you could grab a log while the ignition is on and then immediately after you turn it off? I'm wondering if perhaps your radio isn't sending the CD Changer "stop playing" message...

-Ted

jwreford commented 4 months ago

Sure, no problem! Say tuned, I'll get some logs. Might take me a couple of days.

jwreford commented 4 months ago

@tedsalmon iBUS-Logs-2.txt NavCoder-Logs-2

Message 49072 looks like the stop message (ignore that I highlighted the wrong one in the screenshot) I appreciate all the help you've given me so far! It's a pain troubleshooting something that only happens occasionally.

I'm going to stick a battery monitor on the battery and see if I can catch it the next time it starts dropping. Then I'll see what happens if I inject the RAD->CDC stop message myself.