I-Bus TX Buffer Overflows When `CONFIG_SETTING_TEL_VOL > 14` and `context->uiMode == CONFIG_UI_CD53`

[heinzboehmer]

CONFIG_UI_CD53 sets volStepMax = 1, which means that when the call volume offset is sufficiently high, a bunch of commands will get written to the I-Bus TX buffer and it will overflow before HandlerBTCallStatus()exits. This results in no resetting of the volume level once a call is over.

Here's a log snippet showcasing the behavior:

[488935] DEBUG: Call > TCU
[488943] DEBUG: Call > Begin
[488953] DEBUG: Call > Volume: +15
[489090] DEBUG: BT: R: 'AVRCP_PAUSE 11'
[489099] DEBUG: BT: Paused
[489107] DEBUG: IBus: RX[6]: 50 04 68 32 11 1F 
[489118] DEBUG: IBus: RX[6]: 50 04 68 32 11 1F 
[489129] DEBUG: IBus: RX[6]: 50 04 68 32 11 1F 
[489140] DEBUG: IBus: RX[6]: 50 04 68 32 11 1F 
[489151] DEBUG: IBus: RX[6]: 50 04 68 32 11 1F 
[489162] DEBUG: IBus: RX[6]: 50 04 68 32 11 1F 
[489173] DEBUG: IBus: RX[6]: 50 04 68 32 11 1F 
[489183] DEBUG: IBus: RX[6]: 50 04 68 32 11 1F 
[489194] DEBUG: IBus: RX[6]: 50 04 68 32 11 1F 
[489205] DEBUG: IBus: RX[6]: 50 04 68 32 11 1F 
[489216] DEBUG: IBus: RX[6]: 50 04 68 32 11 1F 
[489227] DEBUG: IBus: RX[6]: 50 04 68 32 11 1F 
[489238] DEBUG: IBus: RX[6]: 50 04 68 32 11 1F 
[489249] DEBUG: IBus: RX[6]: 50 04 68 32 11 1F 
[489259] DEBUG: IBus: RX[6]: 50 04 68 32 11 1F 
[489270] DEBUG: IBus: RX[7]: 80 05 BF 18 00 00 22 
[489282] DEBUG: IBus: RX[8]: 80 06 BF 19 13 15 00 26 
[489320] DEBUG: IBus: RX[13]: C8 0B 80 23 42 32 50 61 75 73 65 64 26 [SELF]
[489335] DEBUG: IBus: RX[13]: C8 0B 80 23 42 32 50 61 75 73 65 64 26 
[489706] DEBUG: BT: R: 'AT 13 10 +CIEV: 2,3'
[489954] DEBUG: BT: R: 'AT 13 10 +CIEV: 1,1'
[489964] DEBUG: BT: R: 'AT 13 10 +CIEV: 2,0'
[489974] DEBUG: BT: R: 'CALL_ACTIVE 13'
[490065] DEBUG: IBus: RX[14]: 80 0C FF 24 01 00 20 37 3A 35 34 50 4D 67 
[490298] DEBUG: BT: W: 'STATUS AVRCP'
[490329] DEBUG: BT: R: 'LINK 11 CONNECTED AVRCP A475B9E51B67 PAUSED'
[490351] DEBUG: BT: R: 'OK'
[490360] DEBUG: IBus: RX[13]: C8 0B 80 23 42 32 50 61 75 73 65 64 26 [SELF]
[491032] DEBUG: IBus: RX[7]: 80 05 BF 18 00 00 22 
[491857] DEBUG: IBus: RX[7]: 5B 05 80 83 00 00 5D 
[491876] DEBUG: IBus: RX[12]: 80 0A BF 13 03 00 00 00 00 00 20 05 
[493038] DEBUG: IBus: RX[7]: 80 05 BF 18 00 00 22 
[495047] DEBUG: IBus: RX[7]: 80 05 BF 18 00 00 22 
[495307] DEBUG: BT: W: 'STATUS AVRCP'
[495338] DEBUG: BT: R: 'LINK 11 CONNECTED AVRCP A475B9E51B67 PAUSED'
[495360] DEBUG: BT: R: 'OK'
[495369] DEBUG: IBus: RX[13]: C8 0B 80 23 42 32 50 61 75 73 65 64 26 [SELF]
[495383] DEBUG: IBus: RX[9]: D0 07 BF 5C FF 3F FF 00 0B 
[496232] DEBUG: IBus: RX[5]: 68 03 18 01 72 
[496249] DEBUG: IBus: RX[6]: 18 04 68 02 00 76 [SELF]
[497049] DEBUG: IBus: RX[7]: 80 05 BF 18 00 00 22 
[497720] DEBUG: BT: R: 'SCO_CLOSE 13'
[497728] DEBUG: Call > TCU
[497736] DEBUG: Call > End
[497746] DEBUG: Call > Volume: -15
[497763] DEBUG: IBus: RX[7]: 18 05 FF BB 01 10 48 [SELF]
[497838] DEBUG: BT: R: 'AT 13 10 +CIEV: 1,0'
[497847] DEBUG: BT: R: 'CALL_END 13'
[497940] DEBUG: BT: R: 'A2DP_STREAM_START 10'
[498014] DEBUG: BT: R: 'AVRCP_PLAY 11'
[498023] DEBUG: BT: Playing

Note that the 15 expected volume I-Bus commands are not sent, as the buffer overflows and the handler does not see them. IBusCommandBlueBusSetStatus() is the only thing sent.

Another quick snippet after adding logging on overflow:

[52846] DEBUG: Call > TCU
[52853] DEBUG: Call > End
[52862] DEBUG: Call > Volume: -15
[52869] ERROR: IBus: TX Buffer Overflow.

I "fixed" this locally by increasing the TX buffer size: https://github.com/tedsalmon/BlueBus/commit/93fc478243792ee3ef2804b5d202d9152a30ba2c

Wasn't sure if you'd rather increase the TX buffer size, decrease the max call offset or write a feature that blocks adding more commands to the buffer until there's space. Decided to open an issue instead of a PR to leave the fix approach up to you, Ted.

Not super high priority, but figured I'd let you know about it.

[tedsalmon]

@heinzboehmer

Great find! Let me think about the best fix here --- most likely increasing the size of the TX buffer as it is common to queue frames while waiting for the bus to become available. I'll probably still lower the call volume offset max value to something more sensible.

Thanks! -Ted

[heinzboehmer]

Makes sense!

Also, I think the current call vol offset max is fine. Phone calls on my phone are super quiet, so I have my offset set to something like +13.

Running on a CD53 with a V1 board and an S23 if that matters.