Broken up high pitched playback after cold boot (rare)

[tfabris]

On rare occasions, after getting in the car and starting the car, the stereo connects to the empeg and plays music, but the music is "broken up", in other words it alternates quickly between music playing and tiny breaks of silence. It sounds like "crackling".

In addition, the music that is playing is at a higher pitch than it should be (Alvin and the Chipmunks sound).

In addition, the available controls on the car stereo touch screen are (intermittently only) not the full set of controls. There are fewer controls on the screen, for example there is no "next track" or "previous track" control available. This indicates that the initial reconnection handshake process did not complete correctly and not all features are available to the head unit.

The problem is resolved by rebooting the Bluetooth module by sleeping and waking the empeg (long press on empeg top button).

My initial guess it that this seems to be a problem that occurs during the auto-reconnection process, where my iPhone and the empeg are fighting over control of the A2DP channel. However this is hard to prove because the repro condition is very rare and it is hard to catch in the debugger.

To Do:

• Try to catch this in the debugger by doing a large number of power cycles while watching on the debug cable.

Note: This might be related to issue #67 - Perhaps it is the same root cause with a slightly different manifestation.

[tfabris]

Got another repro. Conditions of the repro were:

• The BGE was originally paired with my etekcity standalone unit in the house. Moved the BGE to the car.

• After starting car, the car paired with my iPhone first.

• Used the car touch screen and paired the BGE as a music device, and also re-paired the phone as a phone device.

• After the pairing was done, the BGE output was crackling and chipmunk.

• AVRCP commands such as pause play next etc worked.

• AVRCP track titles worked.

• Switching to a different input pauses the player correctl,y but does not solve problem.

• Performing a "power off" of the car stereo headunit and back on, also pauses player correctly, but does not fix issue. Note that this doesn’t really power off the head unit; it just sleeps it, so this isn't really telling us anything.

• As before, the problem is solved by any actions which reboot the BGE, including rebooting the empeg itself.

Suspicion: this is an I2S slave/master sync timing problem. Hm. Wonder if it would work to boot the BGE in analog mode and then switch it to I2S after boot. Give the sync a chance to get settled on the empeg DSP before kicking it into gear.

[tfabris]

More thoughts:

Sometimes the AVRCP commands are fine and sometimes they’re messed up when this happens.

Unlikely to be an I2S sync issue then.

[tfabris]

I have added an additional place where the code issues the command "A2DP STREAMING START", and there is a slim chance that it might fix this issue. Not sure. The version where I introduced this change was 1.0.96 with the commit number of 95bac912b5e978ff5a6ab6ba7a8c8fdee9439bb9 .

[tfabris]

Wait to see if the additional "streaming start" commands have prevented this from recurring.

If this issue recurs, then consider trying your earlier idea of booting the BGE in analog audio mode and then switching it to digital mode at some point after bootup.

[tfabris]

This issue reproduced just now. So the additional streaming start commands didn’t help.

Avrcp commands and track titles worked just like before.

I did not catch the issue in the debugger so I don’t have any more details about it.

[tfabris]

To do: try starting in analog mode then switching to digital.

[tfabris]

Version 1.0.99, commit 191aa5ed48fa99942c4f0290dd021c83fb46440b contains the following change:

Attempt to fix issue #70 (Broken up high pitched playback on cold boot) by booting the module into analog mode, then changing it to digital and doing another reset. This happens in two places: At boot, and at pairtime.

The issue is so rare that I need to just check this in and live with it a while to see if it fixes it.

[tfabris]

Nope, version 1.0.99 induces a new bug. The command that switches the unit back to digital mode is not always interpreted and sometimes the player simply never switches back to digital. We get silence.

``` 0001002 AVRCPAY_STATUS 0000003 --^ AVRCP RSP 247305 13000 1 0001000 AVRCP 2 GET_PLAY_STATUS 0000002 --^ AVRCP RSP 247305 14000 1 0000001 Built in Arduino Serial has been started. 0000000 BlueGiga Serial has been started. 0000001 Empeg Serial has been started. 0000001 --^ Sending to empeg: W 0000001 BlueGigaEmpeg Version 1.0.99 0000003 Arduino chip type: AT Mega 2560 - Good. 0000005 Serial receive buffer size: 256 - Good. 0000004 Serial xmit buffer size: 128 - Good. 0000004 Pausing empeg for convenience while setting global chip defaults. 0000006 --^ Sending to empeg: W 0000002 Setting Defaults. 0000003 --^ SET CONTROL ESCAPE - 00 0 0000004 --^ SET CONTROL ECHO 5 0000002 --^ SET CONTROL BATTERY 0 0 0 0 0000004 --^ SET CONTROL CONFIG 0000 0000 0000 5100 0000005 --^ SET CONTROL CODEC 0000003 --^ SET CONTROL CODEC SBC JOINT_STEREO 44100 0 SET CONTROL CODEC APT-X_LL SET CONTROL CODEC APT-X SET CONTROL CODEC AAC 0000016 --^ SET BT CLASS 280428 0000001 --^ SET PROFILE SPP 0000002 --^ SET PROFILE A2DP SOURCE 0000003 --^ SET PROFILE AVRCP TARGET 1 0000003 --^ SET BT NAME empeg Car 0000003 --^ SET BT SSP 1 0 0000002 --^ SET BT AUTH * 0000 0000003 --^ SET CONTROL AUDIO INTERNAL INTERNAL EVENT KEEPALIVE 0000007 --^ SET CONTROL PREAMP 0 0 0000002 --^ SET CONTROL MICBIAS 0 0 0000003 --^ SET CONTROL GAIN 9 0 0000003 Done Setting Defaults. 0000002 --^ Sending to empeg: W 0000003 Performing soft reset of Bluetooth module. 0000004 --^ RESET 0000002 Clearing global variables. 0000005 IGNORED: AVRCP 2 GET_PLAY_STATUS 0001504 --^ SET CONTROL AUDIO INTERNAL I2S_SLAVE EVENT KEEPALIVE 16 0000001 --^ Sending to empeg: W 0000001 Performing soft reset of Bluetooth module. 0000001 --^ RESET 0000002 Clearing global variables. 0000396 IGNORED: WRAP THOR AI (6.2.0 build 1122) 0000004 IGNORED: Copyright (c) 2003-2017 Silicon Labs Inc. 0000117 IGNORED: READY. 0001605 CONNECT 0 A2DP 19 0000196 CONNECT 1 A2DP 19 0000002 --^ A2DP STREAMING START 0000050 A2DP STREAMING START 0 0000002 --^ Sending to empeg: C 0000015 AUDIO ROUTE 0 A2DP LEFT RIGHT 0000004 --^ SET CONTROL RECONNECT 2888 0 0 17 0 NONE A2DP 0000489 First timestamp after bootup detected, but we are already connected to Bluetooth. Not pausing player. 0000205 A2DP CODEC SBC JOINT_STEREO 44100 BITPOOL 2-53 0000330 RING 2 48:f0:7b:57:15:20 17 AVRCP 0000003 --^ A2DP STREAMING START ... ... 0000999 AVRCP 2 GET_PLAY_STATUS 0000003 --^ AVRCP RSP 247305 33000 2 set 0000741 SET BT BDADDR 88:6b:0f:9b:13:6b 0000007 SET BT NAME empeg Car 0000010 SET BT CLASS 280428 0000007 SET BT AUTH * 0000 0000023 SET BT IDENT BT:47 f000 6.2.0 Bluegiga iWRAP 0000009 SET BT LAP 9e8b33 0000015 SET BT PAGEMODE 4 2000 1 0000011 SET BT PAIRCOUNT 1 0000012 SET BT PAIR 48:f0:7b:57:15:20 26746a110fa134471a3492f0e7fc0d0e 0000003 ------------------------------------ 0000001 Pairing buddy device address: 0000000 48:f0:7b:57:15:20 0000002 ------------------------------------ 0000006 SET BT POWER 6 6 6 0000015 SET BT ROLE 0 f 2580 0000019 SET BT SCO a 1 4d d 2 48 0000016 SET BT SNIFF 0 20 1 8 0000005 SET BT SSP 1 0 0000011 SET BT MTU 667 0000016 SET CONTROL AUDIO INTERNAL INTERNAL EVENT KEEPALIVE 0000015 SET CONTROL BAUD 115200,8n1 0000019 SET CONTROL CD 00 0 0000024 SET CONTROL CODEC SBC JOINT_STEREO 44100 0 0000020 SET CONTROL CONFIG 0000 0000 0000 5100 0000008 SET CONTROL ECHO 5 0000016 SET CONTROL ESCAPE - 00 0 0000013 SET CONTROL GAIN 9 0 0000015 SET CONTROL MICBIAS 0 0 0000027 SET CONTROL MSC DTE 00 00 00 00 00 00 0000014 SET CONTROL PIO 00 00 00 0000014 SET CONTROL PREAMP 0 0 0000012 SET CONTROL READY 00 0000016 SET CONTROL VREGEN 0 00 0000030 SET CONTROL RECONNECT 2888 0 0 0017 0 NONE A2DP 0000005 SET PROFILE A2DP SOURCE 0000029 SET PROFILE AVRCP TARGET 01 0000003 SET 0000011 AVRCP 2 GET_PLAY_STATUS 0000003 --^ AVRCP RSP 247305 33000 2 ```

[tfabris]

I implemented a workaround for the issue induced in 1.0.99; the digital command not being interpreted all the time was fixed by just adding a delay before every chip reset attempt. After that, I had the "boot into analog and then switch to digital" feature working, and things seemed to be working pretty well...

... then I got another repro of issue #70. :( :( :(

On the one hand, darn, it didn't fix it.

On the other hand, I lucked into a repro pretty quick, so I got my answer about whether or not my analog-then-digital trick had any effect on the problem.

I have reverted the changes from 1.0.99, but kept the "delay before every chip reset" thing, because that's super useful to have and I think it should probably have been there all along.

New version is 1.1.2 with commit 3c77c10f366e9cbec090a59cc23ac993992accd2.

[tfabris]

TO DO: Next time you get a repro, try the following:

• unpair the empeg from the stereo main screen and re pair. If that fixes it then the problem is upstream of the i2s connection.

• press the RESET/PAIR BUTTON. This will reset the Bluetooth chip without dropping power. Does that fix it? If not it’s definitely an i2s sync issue perhaps at the hardware level.

[tfabris]

I got another repro.

Deleting the empeg car's pairing from the car stereo touch screen (as suggested in the prior comment) made it forget its security key, and then I was unable to re-pair solely from the touch screen. If I delete the security key from one device, then I have to delete it from the other device, or they won't re-pair. So I couldn't do that first diagnostic test.

I was forced to move on to the second diagnostic test: pressing the reset/pair button. This allowed me to re-pair without a power cycle. The re-pair cured the crackling problem, so whatever the problem is, it can be solved in software without a hardware power cycle.

This indicates that the problem is less likely to be a hardware issue. So I don’t think it’s I2S Synch problems, unless the "reset" command on the BlueGigaEmpeg chip also resets the I2S input. My experimental code of "boot to analog, reset, switch to digital, reset" did not solve the problem, I still got a repro with that, so either the resets are unrelated, or, perhaps, I2S hardware synch might still have a chance to get messed up at any startup of the software (including resets).

I think it's more likely, though, that it's Bluetooth related. Some issue in the software somewhere.

Looking back over prior notes, I see that sometimes when this problem occurs, we get issues with the AVRCP connection, i.e., track controls are limited such as Prev/Next not being there on the car touch screen. I think this also points the problem even more towards a Bluetooth issue of some kind.

To do:

• Try to catch it in the debugger and look for differences in the pairing/connection process between a good connection (no crackle) and a bad connection (crackling).
• See if merely disconnecting via the car touch screen (not deleting) lets it reconnect without the crackle. That would mean a bluetooth reconnection without a reset, and would rule out I2S problems I think for sure.
• See if you can get a repro on the Etekcity receiver in the house. You haven't gotten one there yet. One idea is to see if this is another side effect of the iPhone fighting for control of the stereo: See if you can force a repro by pairing both the iPhone and the empeg to the Etekcity receiver.

[tfabris]

Unable to repro on the Etekcity receiver in the house. The Etekcity receiver handles multiple devices better than the Honda stereo. Etekcity receiver allows both the iPhone and the Empeg to be paired with it at the same time and both can stream audio to it at the same time. It plays whichever one was playing the most recently. Pause one and the other one picks up the audio stream. So the two devices don't fight over the connection. I haven't had a repro of the crackling issue yet in this configuration.

[tfabris]

Got another repro. No debugger, but more info on conditions:

• Physical coldness wasn’t a part of it. It was a fairly nice day and i had only shut off my car for an hour or two. I didn’t expect physical coldness was a part of it but this just confirms that.

• Repro was after starting the car and heading out of the driveway.

• I had actually reshuffled the player but I don’t think that’s related. I had the volume fairly well down until after the reshuffle so didn’t notice for sure if the repro existed before the reshuffle. I expect it was already reproing when I reshuffled.

• AVRCP commands and track titles worked perfectly.

• From the Honda stereo front panel, I disconnected and reconnected the Bluetooth device. This fixed the problem. This means that it does not require a reset of power, nor a reset of the Bluetooth module software to fix. Just a Bluetooth reconnect.

Beginning to suspect this is a Honda bug, but I need to catch this in the debugger to be sure.

[tfabris]

I was attempting to get APT-X-LL codec working on my Honda (issue #30), and the Honda did not work with APTXLL, it fell back to SBC codec.

However, when I did this... I got two repros of crackling chipmunk playback in a very short time, almost back-to-back but not quite, on the Honda stereo, with the APT-X-LL turned on. I don't know if it's related, but I could imagine that the process of trying the unsupported codec and then dropping back to SBC might cause the handshaking process of the initial connection steps to be flakier and might partially "let the iPhone in the door", causing the problem.

Did my APTXLL attempt truly increase the repro frequency of this problem?

If so:

• Try it a bunch of times to get a baseline frequency.
• Try it without the iPhone in the picture. Does the problem go away if the iPhone isn't trying to get in the door?
• Try to catch it in the debugger and see if there is any difference in the initial handshaking/connection messages which indicate that the problem has occurred.

[tfabris]

Still not certain if the APTXLL configuration increases the frequency, but maybe possibly it might?

Got two repros in a row with the following steps:

• BlueGigaEmpeg is configured for APT-X-LL codec to increase repro frequency.
• iPhone is set to "full power" mode.
• Confirmed that iPhone is paired in the settings screen of the car stereo.
• iPhone is plugged into dock on car dash.
• iPhone is running Waze (not sure if this is required for the repro but I think it might be).
• Connect Arduino debug cable to computer.
• Open up the Serial Monitor.
• Instead of instantly powering on the stereo at the same instant as launching the serial monitor, instead, launch the serial monitor and wait for the first bootup text of the serial monitor to appear, and THEN press the ignition button in the car. Repro seemt to be best if you press the ignition button at exactly the time that the bootup text in the serial monitor first appears. Like, right as it's sending the large group of all the SET CONTROL commands.

I got two repros in a row that way and they are attached to this comment, along with a baseline run.

Biggest difference I see between the baseline and the repro is that, with the repro, it's the car stereo ringing the empeg, not the other way round. Both are supposed to work fine though.

To do:

• Reconfirm that all non-repros are when the empeg makes the call, and that all repros are when the car stereo rings the empeg.
• Try for some repros with the iphone out of the picture.

Issue 70 Chipmunk second in a row repro back to back.txt Issue 70 Crackling Chipmunk Repro Debug Output.txt Baseline Good Playback Debug Output.txt

[tfabris]

Oh my God, that's it.

A2DP CODEC SBC JOINT_STEREO 44100 BITPOOL 2-53

 vs,

A2DP CODEC SBC JOINT_STEREO 48000 BITPOOL 2-53

Somehow when the car rings up the empeg, it tries to do it at 48khz instead of 44.1 khz, and the WT32i lets it, even though its music data is at the wrong frequency.

To do:

• Find out if I can control this with further detail settings on the WT32i, perhaps some way to prevent the car from even trying that stunt.
• If I can't, then I can simply detect the "A2DP CODEC SBC JOINT_STEREO 48000 BITPOOL 2-53" message (or sub-portions thereof, more likely) and just fscking reboot the BGE.

[tfabris]

I can't find any settings on the WT32i that control the sampling rate between 44.1khz and 48khz, that I'm not already using and setting correctly to 44.1khz.

My only guess is that there is something going on where the Honda stereo is conflating different memory locations and combining the iPhone connection (which might be supporting 48khz) with a ring to the incorrect address (the BGE) with the wrong audio sampling frequency set.

My only solution I think is to detect when this bug occurs (the 48000 message) and do a RESET.

[tfabris]

I experimentally implemented some code (not checked in yet) which did the thing: Detected the 48000 message and did a RESET.

It took a bunch of retries to get a repro. When the repro finally occurred, the code worked as designed: It prevented the crackling playback. The Bluetooth module reconnected to the stereo after the reboot, and the playback was correct-sounding.

But it wasn't perfect. There was a side effect: When the Bluetooth module reconnected to the headunit that second time, there was an interesting problem with AVRCP. Play/pause/next/prev still worked and were indicated on the screen, but track titles were not functioning. The touch screen was a simplified version with fewer control buttons and there was a single "unknown track" message on the screen, indicating that the car stereo also knew that something was weird about the AVRCP handshake.

Unfortunately, I didn't save a debug log of the side effect, I didn't notice it until after shutting down the Serial Monitor software.

To do:

• Try to get a log of the side effect of the workaround, and see if you can tell what the root of the problem is by looking at the messages.

[tfabris]

Got another repro (off the debugger). My experimental detection code correctly rebooted the unit, and then I also got the AVRCP problem side-effect again.

Attempted experimental fix for issue #70 is checked in, in version 1.1.4 with commit number 1b2843a409c439d7285559158d5e64ee645d7622.

This reboots the module if it detects a 48khz connection, and then reboots a second time to see if that can fix the AVRCP issues that happen immediately after that.

To do:

• Try for another repro and see if it fixes the issue entirely or if it has the same AVRCP problem.
• If it has the same AVRCP problem, try to catch that in the debugger for detailed log output of the issue.

[tfabris]

The "double reboot" fix in commit 1b2843a409c439d7285559158d5e64ee645d7622 indeed seems to have fixed the problem, at least it fixed it during the one repro I had after implementing it. The repro occurred during the pairing process, when I was freshly re-pairing the updated module to my car stereo. After the module rebooted itself twice, it reconnected and all the AVRCP stuff was working correctly as intended.

However it has an unpleasant side effect:

• If the issue occurs during the pairing process, then the user sees the pairing process succeed, then fail as the module disconnects and reconnects automatically after the pairing is complete. So for a short moment, the user is staring at a screen saying that the device is not connected. Then it reconnects automatically a moment later.

This is a very bad user experience. However if the original problem (the 48000 problem) is caused by a bug in the stereo head unit, then maybe hardly any users will see this. Since this product has only a small number of users overall, there's a good chance that I'm the only one who will ever experience the issue. So maybe that's not too bad, since I know what's going on in these cases.

To do:

• Double check that the "Double Reboot" trick works to fix the AVRCP problems on a "regular" repro, i.e., a normal reconnect that is not in the middle of the pairing process.

• Obtain a debug log of the root cause of the AVRCP problems with only a "Single Reboot" implemented in the work around. You still want to know what causes the AVRCP problems in this case.

[tfabris]

Got more debug logs of the AVRCP problem side effect. I did this by using custom code that performs a single reboot when the 48k problem occurs. States are interesting and more research is needed.

By the way, even with only a single reboot in the code, the "bad AVRCP screen" problem side effect is only intermittent. So it's an intermittent state resulting from a bug that is intermittent to begin with. Sigh.

Here are all the possible sub-states. We start with the intermittent bug where the codec is set at 48k instead of at 44.1k. When that intermittent bug hits, then we have three possible states after that:

• Good state: The 48k problem occurs and the code reboots the module, and after the reboot everything is fine.

• Honda bug bad screen state: The 48k problem occurs and the code reboots the module, and after the reboot everything is fine except that the Honda screen doesn't show the track data, it shows a simplified control screen, no track titles, and just "empeg Car" as the name of the device. This is fixed simply by refreshing the Honda screen (pressing HOME followed by AUDIO again). This is definitely a Honda bug and I don't need to worry about this state.

• Bad AVRCP data: The 48k problem occurs and the code reboots the module. After the reboot, the Honda screen shows a simplified set of controls, doesn't show track data, and this is not fixed by refreshing the Honda screen. This is the state I need to fix.

Attaching debug logs of each of these states.

Issue 70 with single 48k reboot and good correct avrcp functionality after the reboot.txt Issue 70 with single 48k Reboot with messed up AVRCP screen on Honda which was solved by refreshing honda screen.txt Issue 70 with single 48k reboot and bad AVRCP screen on honda which was NOT fixed with a refresh of the screen.txt

[tfabris]

The logs show that there is no difference in the messages coming from the WT32i chip between the "good" and "bad" AVRCP screen states on the Honda.

To me, this says that I can't finesse this by detecting some specific state on the messages coming from the serial port. I can possibly try to live with the double reboot and see if that indeed fixes the issue, but that's about it.

To Do:

• Re-insert the Double Reboot code into your testbed BGE unit, then try to get a large number of the 48k-problem repros. Check for the Honda AVRCP screen state problem after each repro.
• If you don't see the bad AVRCP screen state problem on the Honda after a large number of repros, then consider it fixed to the best of your ability and close the bug.
• If you do still see the bad AVRCP screen state problem on any of the repros, then see if switching inputs off of the bluetooth and back again fixes it.

Reminder: Your current best repro steps (doesn't repro it every time) are:

• BlueGigaEmpeg is configured for APT-X-LL codec to increase repro frequency (only works on your one special testbed module with APTXLL test license installed).
• iPhone is set to "full power" mode.
• Confirmed that iPhone is paired in the settings screen of the car stereo.
• iPhone is plugged into dock on car dash.
• iPhone is running Waze (not sure if this is required for the repro but I think it might be).
• Connect Arduino debug cable to computer.
• Open up the Serial Monitor.
• Instead of instantly powering on the stereo at the same instant as launching the serial monitor, instead, launch the serial monitor and wait for the first bootup text of the serial monitor to appear, and THEN press the ignition button in the car. Repro seemt to be best if you press the ignition button at exactly the time that the bootup text in the serial monitor first appears. Like, right as it's sending the large group of all the SET CONTROL commands.

[tfabris]

I think the ultimate solution would be to find out how to prevent other folks from ringing us up (a previously paired host stereo doing a successful RING command against us). Then we would depend entirely on our autoReconnect to initiate the reconnect. However I can't figure out how to do this. The SET BT LAP command does not work for this. So continue to test workarounds for this.

[tfabris]

To do:

• Try to test your theory that this is caused by a them-rings-you-up problem by turning off auto reconnect temporarily. Force the other guy to ring you up and see if the repro frequency goes up.

• With the Double Reboot code running into your testbed BGE unit, then try to get a large number of the 48k-problem repros. Check for the Honda AVRCP screen state problem after each repro.

• If you don't see the bad AVRCP screen state problem on the Honda after a large number of repros, then consider it fixed to the best of your ability and close the bug.

• If you do still see the bad AVRCP screen state problem on any of the repros, then see if switching inputs off of the bluetooth and back again fixes it.

[tfabris]

Indeed changing AutoReconnectMode to 0 and turning off the iPhone's bluetooth connection makes the repro happen. It is not a frequent repro that way, but it tells us the following:

• It's definitely due to the Honda ringing me up instead of the other way around.

• The iPhone fighting for control of the Honda stereo is definitely not the cause. This is a big deal: You were highly suspicious that the Honda was conflating the iPhone and the Empeg, and it's not, at least, not in bluetooth.

• Though I wonder if this was a "the iPhone was the last thing paired and so the stereo tries to go at 48k on the new thing paired". I only got the repro once with the iPhone off and it might have been after the iPhone had been previously the music player.

• Though I did have the iphone plugged into the Honda USB (ie ipod mode) but that should't affect this. Should it? Not sure, anything's possible.

[tfabris]

Easier repro, seems to be timing dependent.

• BGE is configured for APTX-LL audio and you're using your APTX-LL testbed module for this repro. Even though the Honda doesn't support APTX-LL, the prioritization of APTX-LL seems to increase the repro frequency.
• You're on the debug channel so you can see what's happening.
• iPhone is on and paired and docked. iPhone is connected as a Phone. Not Sure if having Waze running is helpful or not.
• Empeg is paired and Reconnect mode is set to 1.
• From car stereo touch screen, connnect and disconnect and connect and disconnect the empeg continuously.
• Give it the slightest heartbeat of time before each reconnect. But don't give it so long that auto reconnect successfully kicks in, you want the Honda to ring the BGE, not the other way around. The timing here seems to be a factor in the repro. Go through the menus to reconnect at normal speed and then there's just a tiny breath before hitting that last connect button.
• At some point you'll get a repro.
• After the repro, the BGE will reboot and then auto reconnect.
• Go to Audio screen to see if the AVRCP is messed up after the auto reconnect.

[tfabris]

I got several repros using the latest steps, the double reboot, and the AVRCP screen on the honda was correct every time.

I'm going to call this one Fixed (or at least worked around) for now, and move on to issue #67.

[tfabris]

Turns out I don't need A2DP for the repro. I can get the repro very frequently with the following:

• BGE configured for default SBC codec.
• BGE configured for only doing STREAMING START commands on receipt of RING or CONNECT message on channels 2,3 instead of previous 1,2,3. (This is part of experimental fix to issue #60).
• You're on the debug channel so you can see what's happening.
• iPhone is on and paired and docked. iPhone is connected as a Phone. Waze does not need to be running.
• Empeg is paired and Reconnect mode is set to 1.
• From car stereo touch screen, connnect and disconnect and connect and disconnect the empeg continuously.
• Go through the menus to reconnect at normal speed. Not particularly fast, but not slow either.
• After a connection go to audio screen and then go back to menu, settings for the next reconnect.

With that I got a repro almost every time.

Important:

• It didn't seem to matter if I had a double reboot programmed or a single reboot programmed. The car stereo still looked fine on the AVRCP screen if I went to it from another menu.
• So therefore on your next update set it back to single reboot.

[tfabris]

This morning when freshly re-pairing I had a fairly bad UX where the 48k reboot happened several times in a row after pairing. This was with the unit configured for the SBC codec and a single reboot.

To do:

• Try to get a repro of the above problem (lots of reboots during pairing) in the debugger and see if you can narrow down the root cause of the behavior.

[tfabris]

To do:

• Look at your code which does a "SET CONTROL CODEC" all by itself before re-issuing the new code commands. The idea was to clear out the existing codecs before adding new ones, but you don't need to do this actually and I'm wondering if this is the thing causing the headunit to try to connect at 48k. Perhaps 48k is the default and you're accidentally setting it for a moment. Nope, it wasn't that. Go through and see if there are other similar things though. The spec says the WT32i does not support 48k in source mode, yet here we are in source mode getting a 48k request. Why? Does it think it's in sink mode? Is a RING always assumed to be sink mode?

[tfabris]

To do:

• Look at additional options under SET CONTROL AUDIO and see if the "internal" routing is related to the settings for the LOOPBACK command which, although I'm not calling that command, has a 48k setting which might be a factor. Maybe loopback defaults to 48k and somehow the chip is taking it when a RING comes in? Dunno, investigate.

[tfabris]

None of the set control audio or loopback commands had any effect. I also tried a whole bunch of different other things grasping at straws until I stumbled on this:

• If you issue the Streaming Start command too early, when the A2DP audio and data channels are still getting set up, such as issuing it when there is a data channel but not an audio channel yet, then you get silence (issue #67).
• If you issue the Streaming Start command too late, then you get the 48k chipmunk problem induced quite frequently and reliably on RING commands coming in. This was induced when I did the streaming start only on RING 2 and RING 3 but not on RING 1. I think this means that the chipmunk problem only comes when the RING XX numbers come out of order.

To do:

• Get some intelligent code in place instead of the dumb code which detects the correct RING and CONNECT commands and only issues the STREAMING START when the second A2DP channel has connected, regardless of which port number it's on.

[tfabris]

The intelligent code did not fix the infinite reboot loop.

The reboot loop now occurs any time that the stereo rings us as opposed to us ringing the stereo.

It's possible that the only reason I ever avoid the ring-to-me is because in all my prior testing I always had the iPhone connecting to the Honda and so the Honda didn't try to ring me right away every time.

Once I take the iPhone out of the picture, or the Honda gets into a mode where it thinks it doesn't need to ring the iPhone, then I get the 48k problem and it triggers infinite reboots.

TO DO:

• Confirm this theory: The reason that the pairing process worked without a 48k issue before, is due to the new pairing code which alternates listening and searching. You've been trying to pair during that process in your recent tests and that has been inducing the initial 48k issue on pairing.
• Get a tech support request in for reconnect/pair/48k issues.

[tfabris]

Tested my recent theories. Nope, they were wrong.

• It isn't because of the new pairing code, that's fine.
• It isn't because of the iPhone either being in the picture or out of the picture, that's fine (phew).

Turns out that it's merely because the HONDA STEREO NEEDED A REBOOT.

The honda stereo sometimes gets in a state where it only ever wants to do 48k and no amount of reconnecting seems to help in that case. Power cycle the Honda and everything is fine after that. I have taken several debug logs showing the 48k workaround functioning fine in both 1.1.7 and 1.1.8, with and without the new intelligent streaming start behavior. The ones which functioned fine are always after a fresh reboot of the Honda stereo. This is fine, I don't even need to update the dox because they already say to reboot your stereo.

I have a tech support request into Silicon Labs but I find it likely that my current workaround will have to stand as-is. This is a Honda bug of some stripe.

To do:

• Save off a backup copy of 1.1.7 milestone code before intelligent streaming start.
• Check in 1.1.8, after intelligent streaming start.
• Test on all devices. Already tested on Honda and Onkyo, now test on remaining devices:
  • Plantronics
  • Etekcity
  • Kenwood

[tfabris]

I believe that the final state of the workaround for this issue is now checked in with version 1.1.8, commit aa4714e16631d2e00532451237b136d01a93c956.

To do:

• Test to on all devices to make sure no regression. Already tested on Honda and Onkyo, now test on remaining devices:
  • Plantronics
  • Etekcity
  • Kenwood
• Wait for a tech support response from Silicon Labs about the 48k problem. If they have some awesome magic that will permanently fix it, then implement that. If not, then your work around is livable and you can close this bug.

[tfabris]

(Note: the bug below has been converted into separate issue #78).

With one of the in-process fix builds for this issue being experimented with on the debugger, I got a case of where the car touch screen has NO NAME on the screen and simplified control set, i.e., bad AVRCP somehow. Refreshing the screen and even going from BT to radio and back to BT again didn't fix it. Pause and play and next track still work though. In any case I need to analyze this at some point in the near future. Attached is that log output. The repro for this seems to be:

• Have things connected and playing to the Honda successfully.
• Turn off the car ignition but leave the empeg and BGE functioning because you have the USB debug cable still attached to the computer.
• When the car comes back up, you get the "bad screen" state on the Honda.

Issue 70 in 1.1.9 - Got a state of bad AVRCP and simplified controls on the car touchscreen.txt

[tfabris]

Version 1.1.9, commit 719835123e95d44247dc48d84e7d0a2d896f3862, contains a few minor tweaks to the behavior of the code which issues the Streaming Start commands. It's mostly the same behavior but there are a few additional bits of bullet proofing. This needs to be retested on all devices you have access to.

• Already tested on:
  • Plantronics
  • Etekcity

To Do:

• Test 1.1.9 on:
  • Honda
  • Kenwood
  • Onkyo
• Wait for a tech support response from Silicon Labs about the 48k problem. If they have some awesome magic that will permanently fix it, then implement that. If not, then your work around is livable and you can close this bug.

[tfabris]

After more testing I am now convinced that my new way of doing STREAMING START commands is inducing issue #70 as opposed to helping it. The Honda needs the reboot fix with the new method almost every time whereas the old method only repropduces issue #70 once in a blue moon.

Example of a perfectly good session that would have repro'd issue 70 with the new method.

0009786 RING 0 48:f0:7b:57:15:20 19 A2DP
0000002 Detected first A2DP channel connection. Waiting for second one.
0000101 RING 1 48:f0:7b:57:15:20 17 AVRCP
0000003 --^ A2DP STREAMING START               THIS IS THE OLD METHOD HERE
0000176 RING 2 48:f0:7b:57:15:20 19 A2DP
0000002 Detected second A2DP channel connection. Starting audio stream now. THIS MESSAGE ONLY INFORMATION, NO ACTION TAKEN
0000002 --^ A2DP STREAMING START     THIS IS THE OLD METHOD HERE
0000021 AVRCP 1 GET_CAPABILITIES 2
0000003 --^ AVRCP RSP 02FF

[tfabris]

Version 1.1.10, commit number f2c327aff62d75fea7e1c0d55417f86586be0323, returns the "streaming start" behavior back to pre-1.1.8 behavior, which reduces the repro frequency significantly.

I still need to understand when the correct time to issue the "streaming start" is on all devices. There are catch-22s where I can't issue it at certain times with certain device or else I induce bugs on other devices.

Already tested on:

• Kenwood
• Etekcity
• Plantronics

To do:

• Retest on:
  • Honda
  • Onkyo
• Wait for tech support response from Silicon Labs about the 48khz issue to see if there is any magic to be found.

[tfabris]

Retested 1.1.10 on everything but Onkyo so far and it's working fine.

Got response from tech support. I was missing the command "SET BT PAGEMODE" which controls whether or not iWrap answers RING commands and whether or not it is visible in the inquiry.

To do:

• Remove the code related to "SET BT LAP". Your whole point of having that code was to try to make the device not visible for inquiry. Turns out that's not the right command. SET BT PAGEMODE is actually the right command for that.
• Try adding SET BT PAGEMODE.
• Pages modes are as follows:
  • 0 = "0-0" - Not visible, does not answer RINGs.
  • 1 = "1-0" - Visible, does not answer RINGs.
  • 2 = "0-1" - Not visible, answers RINGs.
  • 3 = "1-1" - Visible, Answers rings.
  • 4 = Programmatic, acts like mode 3 ("1-1") when not connected, and like mode 0 ("0-0") when not connected. (default)
• Try to set it so that you are in the following modes:
  • Once connected, switch to mode 0.
  • During pairing, mode 4.
  • If not connected and there is an existing pairing buddy: Mode 0.
  • If not connected and there is no pairing buddy: Mode 4.
• The default parameters of SET BT PAGEMODE are:
  • SET BT PAGEMODE 4 2000 1
    • 4 is the mode
    • 2000 is hex (8192 dec), it is the connection timeout when pair is attempted (2000 translates to 5120ms).
    • 1 is the scan mode, trading power for connectibility (0 is high availability and high power consumption, 2 is low availability and low power consumption, 1 is default).

If that works, test on all devices and see if it fixes issues 67 and 70 by refusing all RINGs.

[tfabris]

SET BT PAGEMODE turns out to be a non-starter. It interferes with the ability to reconnect in the Honda, it lets the iPhone in the door before the empeg has a chance to connect and then I don't get the iPhone+Empeg feature on my Honda that I need. This is even when I set it to mode "1". Only modes 3 and 4 work for this.

I have sent another email to tech support asking about the A2DP STREAMING START. Waiting for result.

[tfabris]

The tech support conversation with Silicon Labs is not going well. I'm basically asking "When" and they're answering "yes", meaning they're not understanding my question.

To Do:

• Get an example of the 48k reboot in the log. A clean one from a fresh power up of both modules.
• Get one where the 48k reboot did not occur. Again, a clean one from a fresh power up.

Compare the two. Was there a difference in the connection channel order or the timing of the Streaming Start command in those cases? If not, then you're stuck and this is just a Honda bug that you can't control. Close it.

[tfabris]

Got a pretty good answer from tech support. Their answer was, essentially:

• Issue the Streaming Start when you get the second A2DP connection.
• If it doesn't work, issue it again later and see if that fixes it.

Though this is a good official answer, I am skeptical because I think this is what induced the 48k problem the most frequently. This is the behavior of the "intelligent" streaming start that I implemented earlier and my memory is telling me that this was the inducer of the 48k problem.

Need to do an experiment to be certain. But I think it's really like this in practice:

Issue streaming start after second and third RING or CONNECT (regardless of a2dp or avrcp):

     RING 0 48:f0:7b:57:15:20 19 A2DP
     RING 1 48:f0:7b:57:15:20 17 AVRCP
     --^ A2DP STREAMING START
     RING 2 48:f0:7b:57:15:20 19 A2DP
     --^ A2DP STREAMING START

... This seems to be good and rarely if ever induces either issue #67 or issue #70. I think the only reason I ever got issue #67 is becase I was triggering off of "RING 1" or "RING 2" or somesuch, and if the messages came out of order with RING 1 coming first, then I wasn't issuing the command on the second ring receipt and it induced #67. Not sure.

This works well on some devices but I think that this might intermittently induce the 48k problem on the Honda stereo:

     RING 0 48:f0:7b:57:15:20 19 A2DP
     RING 1 48:f0:7b:57:15:20 17 AVRCP
     RING 2 48:f0:7b:57:15:20 19 A2DP
     --^ A2DP STREAMING START

To do:

• Return the code which did "only the second A2DP receipt gets a streaming start".
• See if that induces or reduces the 48k issue #70.
• If so, write code which issues a streaming start on the second and third receipt of any connect or ring command, regardless of the channel number and regardless of whether it's AVRCP or A2DP either way.
• See if that makes things better and fixes issue #70 and/or induces or reduces the silent playback issue #67.

[tfabris]

I have 48k repros both with the SILabs method and also with my new 1.1.13 method.

Need to compare these in detail and see if there's a difference.

Issue 70 repro with 1.1.13 new behavior - proof that it's not always the SIlabs method.txt

Baseline good reconnect behavior with 1.1.13 and Honda.txt

Issue 70 repro with Silicon Labs suggested method - proof it is bad.txt

Baseline good reconnect behavior with Honda and 1.1.13.txt

Baseline good pairing behavior with Honda and 1.1.13 - both kinds of pairs.txt

[tfabris]

This also might be micro timing, as I'm getting a lot of inducements of both this and issue #79 with the debug cable hooked up. Don't seem to hit either of them without the cable.

[tfabris]

I'm increasingly convinced that this is due to bad SiLabs method (only send streaming on receipt #2) and that 1.1.13 new behavior fixes it.

I'm able to get it to happen with the serial cable disconnected on SiLabs method, but not very often if at all with the serial cable disconnected and using 1.1.13 new behavior.

Any cases where I see it happen in 1.1.13 is usually when I'm heisenberging the timing with the serial cable connected.

I think issue #70 occurs when you issue the streaming start simply TOO LATE or NOT ENOUGH.

[tfabris]

To do:

• Try to figure out how to get the STREAMING START timing to happen as fast as possible, using the 1.1.13 method.

[tfabris]

I am hoping that version 1.1.13 (currently on a side branch at the moment, not yet checked into master) will fix this.

Keep in mind that micro timing of the "streaming start" command might be a factor on the Honda.

To do:

• See if you get repros on 1.1.13 with the debug cable detached.
• If not, see if you get repros with the debug cable attached. If so, then try to mitigate by trying to send the messages faster by moving things around.

[tfabris]

I have gotten an occasional repro on 1.1.13 with no debug cable, and the streaming start happening as fast as I can get it. I don't know if I can get the microtiming faster or not.

[tfabris]

This occasionally repros on 1.1.13 but no more frequently than before.

The workaround successfully takes care of it, so close this issue after you merge 1.1.13 to Master.