[pulseaudio-discuss] Bluetooth devices no longer detected after upgrade from 2.0 to 4.0

[Mikel Astiz]

Hi Georg,

On Sun, Jun 30, 2013 at 2:48 PM, Georg Chini <georg at chini.tk> wrote:
> Hi again,
>
>
> On 30.06.2013 12:57, Mikel Astiz wrote:
>>
>> Hi Georg,
>>
>> On Sun, Jun 30, 2013 at 11:00 AM, Georg Chini <georg at chini.tk> wrote:
>>>
>>> On 30.06.2013 10:28, Mikel Astiz wrote:
>>>>
>>>> Hi Georg,
>>>>
>>>> On Sat, Jun 29, 2013 at 9:39 PM, Georg Chini <georg at chini.tk> wrote:
>>>>>
>>>>> On 28.06.2013 08:23, Mikel Astiz wrote:
>>>>>>
>>>>>> Hi Georg,
>>>>>>
>>>>>> On Thu, Jun 27, 2013 at 1:31 PM, Georg Chini <georg at chini.tk> wrote:
>>>>>>>
>>>>>>> On 27.06.2013 08:22, Mikel Astiz wrote:
>>>>>>>>
>>>>>>>> Hi Georg,
>>>>>>>>
>>>>>>>> On Wed, Jun 26, 2013 at 8:45 PM, Georg Chini <georg at chini.tk> wrote:
>>>>>>>>>
>>>>>>>>> Hi Mikel,
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> On 26.06.2013 16:54, Mikel Astiz wrote:
>>>>>>>>>>
>>>>>>>>>> Hi Georg,
>>>>>>>>>>
>>>>>>>>>> On Wed, Jun 26, 2013 at 3:27 PM, Georg Chini <georg at chini.tk>
>>>>>>>>>> wrote:
>>>>>>>>>
>>>>>>>>>
>>>>>>>>>>> Later on I decided to keep the modules around and just move them
>>>>>>>>>>> to
>>>>>>>>>>> the
>>>>>>>>>>> right
>>>>>>>>>>> source/sink when needed and move them to the default sound card
>>>>>>>>>>> and
>>>>>>>>>>> mute
>>>>>>>>>>> them when not in use.
>>>>>>>>>>
>>>>>>>>>> As a side suggestion, you probably want to use the profile
>>>>>>>>>> availability to do this (if profile is available, it means
>>>>>>>>>> 'playing').
>>>>>>>>>>
>>>>>>>>>>> The problem is that this does no longer work. Pavucontrol still
>>>>>>>>>>> shows
>>>>>>>>>>> the
>>>>>>>>>>> correct
>>>>>>>>>>> sink/source but I do not get any sound when the modules are
>>>>>>>>>>> reused.
>>>>>>>>>>> It
>>>>>>>>>>> seems
>>>>>>>>>>> to be
>>>>>>>>>>> a problem of resampling, the modules start to behave strangely as
>>>>>>>>>>> soon
>>>>>>>>>>> as
>>>>>>>>>>> sink and
>>>>>>>>>>> source are moved the first time.
>>>>>>>>>>> In the debug output I get endless repetition of:
>>>>>>>>>>>
>>>>>>>>>>> [alsa-sink-VT1828S Analog] module-loopback.c: Could not peek into
>>>>>>>>>>> queue
>>>>>>>>>>> [alsa-sink-VT1828S Analog] module-loopback.c: Requesting rewind
>>>>>>>>>>> due
>>>>>>>>>>> to
>>>>>>>>>>> end
>>>>>>>>>>> of underrun.
>>>>>>>>>>> [alsa-sink-VT1828S Analog] module-loopback.c: Requesting rewind
>>>>>>>>>>> due
>>>>>>>>>>> to
>>>>>>>>>>> end
>>>>>>>>>>> of underrun.
>>>>>>>>>>> [alsa-sink-VT1828S Analog] module-loopback.c: Requesting rewind
>>>>>>>>>>> due
>>>>>>>>>>> to
>>>>>>>>>>> end
>>>>>>>>>>> of underrun.
>>>>>>>>>>> [alsa-sink-VT1828S Analog] module-loopback.c: Requesting rewind
>>>>>>>>>>> due
>>>>>>>>>>> to
>>>>>>>>>>> end
>>>>>>>>>>> of underrun.
>>>>>>>>>>>
>>>>>>>>>>> The initial approach of using fresh modules each time the phone
>>>>>>>>>>> goes
>>>>>>>>>>> to
>>>>>>>>>>> "playing" still
>>>>>>>>>>> works fine.
>>>>>>>>>>
>>>>>>>>>> I think you hit a real issue here. I've experienced similar issues
>>>>>>>>>> too
>>>>>>>>>> at some point, but I can't reproduce it anymore.
>>>>>>>>>>
>>>>>>>>>> Can you tell us which exact states the source (assuming A2DP from
>>>>>>>>>> the
>>>>>>>>>> phone) and the source-output have? They should in theory be both
>>>>>>>>>> in
>>>>>>>>>> RUNNING state.
>>>>>>>>>
>>>>>>>>> Sorry, I cannot find out. You can find a log of a complete session
>>>>>>>>> on
>>>>>>>>> http://philipp.chini.tk/pulse/pulse-session.log
>>>>>>>>> Maybe there is something useful in it. If not, please tell me how
>>>>>>>>> to
>>>>>>>>> get
>>>>>>>>> the state of the source or what else I can do to locate the
>>>>>>>>> problem.
>>>>>>>>
>>>>>>>> You should use 'pactl list sources' and 'pactl list source-outputs',
>>>>>>>> during the issue you describe about rewind requests.
>>>>>>>>
>>>>>>> All sources and source-outputs are in RUNNING state. The output
>>>>>>> for the relevant module (now it's A2DP from the phone, so only one
>>>>>>> module needed) looks like this:
>>>>>>>        index: 6
>>>>>>>            driver: <module-loopback.c>
>>>>>>>            flags: START_CORKED
>>>>>>>            state: RUNNING
>>>>>>
>>>>>> This looks good. Have you checked if the bar in pavucontrol shows some
>>>>>> audio corresponding to this source?
>>>>>>
>>>>>>>            source: 2 <alsa_input.pci-0000_00_1b.0.analog-stereo>
>>>>>>>            volume: 0: 100% 1: 100%
>>>>>>>                    0: -0,00 dB 1: -0,00 dB
>>>>>>>                    balance 0,00
>>>>>>>            muted: yes
>>>>>>
>>>>>> Is it muted?
>>>>>>
>>>>>>>            current latency: 0,00 ms
>>>>>>>            requested latency: 135,29 ms
>>>>>>>            sample spec: s16le 2ch 44100Hz
>>>>>>>            channel map: front-left,front-right
>>>>>>>                         Stereo
>>>>>>>            resample method: (null)
>>>>>>>            owner module: 27
>>>>>>>            properties:
>>>>>>>                    media.role = "abstract"
>>>>>>>                    module-stream-restore.id =
>>>>>>> "source-output-by-media-role:abstract"
>>>>>>>                    media.name = "Loopback to Internes Audio Analog
>>>>>>> Stereo"
>>>>>>>                    media.icon_name = "audio-card-pci"
>>>>>>>
>>>>>>> Maybe the "resample method: (null)" is the problem?
>>>>>>
>>>>>> No, I don't think the resample method is relevant here. It also shows
>>>>>> as null for me, and the audio just works.
>>>>>>
>>>>>> Cheers,
>>>>>> Mikel
>>>>>
>>>>> Hi Mikel,
>>>>>
>>>>> after a bit of testing, I found an easy way to reproduce the problem.
>>>>> It seems to occur when the phone is in "connected" state and you try
>>>>> to move the source away from the loopback module. Pacmd shows the
>>>>> bluetooth source as "SUSPENDED" while the source-output is "RUNNING".
>>>>
>>>> This looks perfectly fine to me. The Bluetooth source is no longer in
>>>> use (you moved away the source-output) and therefore SUSPENDED, as
>>>> opposed to the source-output which is pulling audio from the alsa card
>>>> (your sound card, I guess).
>>>>
>>>> You should check whether your alsa source is RUNNING. If not, you
>>>> might have hit an issue. I however think this is completely unrelated
>>>> to the Bluetooth modules.
>>>>
>>>>> Doing the following triggers the problem:
>>>>>
>>>>> 1) insert a loopback module with source=your_phone
>>>>> 2) wait until the phone is no longer playing
>>>>> 3) with pavucontrol move the source of the loopback module to another
>>>>> device
>>>>>
>>>>> What is strange is that the messages start after the source has already
>>>>> changed.
>>>>> I inserted a few log statements in module-loopback.c and got:
>>>>>
>>>>> [bluetooth] module-loopback.c: Source Output detach
>>>>> bluez_source.00_12_D1_8C_FC_80
>>>>> [pulseaudio] module-loopback.c: Source Output moving to
>>>>> alsa_input.pci-0000_00_1b.0.analog-stereo
>>>>> [alsa-source-VT1828S Analog] module-loopback.c: Source Output attach
>>>>> alsa_input.pci-0000_00_1b.0.analog-stereo
>>>>> [alsa-sink-USB Audio] module-loopback.c: Requesting rewind due to end
>>>>> of
>>>>> underrun.
>>>>> [alsa-sink-USB Audio] module-loopback.c: Requesting rewind due to end
>>>>> of
>>>>> underrun.
>>>>> ...
>>>>
>>>> Have you tried loading module-loopback (regardless of BT devices) with
>>>> the same sink and source (as resulted from your sequence above, i.e.
>>>> probably from alsa to alsa) and see if the issue with the rewinds
>>>> reproduces?
>>>>
>>>> Cheers,
>>>> Mikel
>>>
>>> Hi Mikel,
>>>
>>> this only happens with the BT device and only if the phone is not
>>> playing. I can move the source to another device when the phone
>>> is playing without any issue. I can also move other source devices
>>> around without triggering the problem. The BT source is suspended
>>> even if module-suspend-on-idle is not loaded. Maybe the problem is
>>
>> If the phone is streaming no audio the source will be suspended
>> regardless of module-suspend-on-idle. If you have a closer look,
>> you'll see that the suspend cause is USER.
>>
>>> that when the phone goes inactive the effective profile is "off" and not
>>> the one that was last used. The issue is also triggered if I load the
>>> loopback module for a2dp_source, wait until the phone is inactive
>>> and then switch to hfgw.
>>
>> Can you describe again the actual issue you're having? I'd like to
>> distinguish whether there's some inconsistent state in PA or not.
>
>
> See below.
>
>
>>
>> If I get this right, you switch the profile to hfgw and move the
>> source-output to the corresponding source. At this point, the question
>> is whether hfgw is actually streaming audio or not. If yes, BlueZ
>> should be in 'playing' state and PA should expose the profile as
>> 'available: yes' (use pacmd to check this). The source should be
>> RUNNING and the source-output too. Besides, you should see the audio
>> bars moving in pavucontrol for the hfgw source and also in the
>> playback tab (show: "All stream").
>
>
> Yes, all of this is the case. The problem occurs AFTER the phone goes
> from playing to connected.
>
> In my script, I do the following:
> Initially, there is no loopback module loaded. When the phone goes
> to "playing" (regardless if it is a2dp_source or hfgw) I insert loopback
> modules. If it is hfgw one from my microphone to the phone and one
> from the phone to my sound output, if it is a2dp_source only one from
> the phone to my sound output.
> When the phone switches back to "connected" instead of unloading
> the module(s) I move them to my default sink and source and mute the
> source-output so that I do not hear the microphone on my sound output.
> When the phone goes to "playing" again I reuse the loopback modules,
> unmuting them and moving them back to the BT source/sink.
> I keep different modules around for a2dp and hfgw, so when a phone
> is able to do both and both have been playing at some time, then I have
> 3 modules loaded. This worked fine with Pulseaudio 2.0.
> With 4.0 the problem occurs at the moment the modules are moved away
> from the BT source.
>
> To make sure the issue is not triggered by my script I tried to reproduce
> it without any additional software. That is what I described a few mails
> ago.
> You get the phone to "playing" and then insert the loopback module manually
> using pactl. This works fine, you can hear the sound. Then wait until the
> phone goes back to "connected" state. If you now reconnect the same profile,
> sound is still audible.
> But if you move the source after the phone played and is back to connected
> (again, manually with pavucontrol) the issue will start. So to trigger the
> problem,
> the following conditions must be met:
>
> - While the phone is playing (it doesn't matter if it is a2dp_source or
> hfgw),
>    a loopback module with the phone as source is inserted
> - The phone goes back to "connected" and the source-output of the loopback
>    module is still connected to the (now suspended) BT source
> - In this situation you move the source away from the source-output of the
>    loopback module
>
> The exact symptom is that the loopback module is unusable from that moment
> on
> (no sound, regardless which sink/source you choose) and with debug logging
> the
> rewind messages can be seen and continue until the module is unloaded.

I was able to reproduce this issue and submitted a patch to fix it: "
loopback: Fix cork state not updated after move".

Please check if this patch solves your problem.

Cheers,
Mikel