Discussion:
[pulseaudio-discuss] HFP HF - Reject SCO Issue
Jomon John
2016-05-25 11:01:26 UTC
Permalink
Hi,

I am trying to configure HFP with Bluez(5.34), Ofono(1.17) and pulseaudio(6) on a Freescale i.MX6 board using Linux 4.1.15 kernel, the idea is to use the target board in HFP/Handsfree Unit role. The bluetooth controller is a Pluggable USB Bluetooth Dongle (0a5c:21e8 - BCM20702A0) with updated firmware.

The procedure followed is,

* Pair & connect with the android mobile phone with the bluetoothctl
* Enable modem and dial number using ofono test scripts

After this the call is being made but the audio routing fails with "Reject SCO : Agent not registered" message from oFono. While checking with btmon its found that the SCO Connect Request has been rejected with the reason of limited resources(0x0d).

Can anyone help me to identify the root cause, I spent a lot of time trying different version combinations, loading firmware and checking logs but still nothing.
-
With Regards
John J
Denis Kenzior
2016-05-25 14:57:25 UTC
Permalink
Hi John,

On 05/25/2016 06:01 AM, Jomon John wrote:
> Hi,
>
> I am trying to configure HFP with Bluez(5.34), Ofono(1.17) and pulseaudio(6) on a Freescale i.MX6 board using Linux 4.1.15 kernel, the idea is to use the target board in HFP/Handsfree Unit role. The bluetooth controller is a Pluggable USB Bluetooth Dongle (0a5c:21e8 - BCM20702A0) with updated firmware.
>
> The procedure followed is,
>
> * Pair & connect with the android mobile phone with the bluetoothctl
> * Enable modem and dial number using ofono test scripts
>
> After this the call is being made but the audio routing fails with "Reject SCO : Agent not registered" message from oFono. While checking with btmon its found that the SCO Connect Request has been rejected with the reason of limited resources(0x0d).
>
> Can anyone help me to identify the root cause, I spent a lot of time trying different version combinations, loading firmware and checking logs but still nothing.

This looks like a problem with PulseAudio configuration. oFono does not
handle SCO data, PulseAudio does that. In order to do that, PulseAudio
needs to register an agent with oFono. Then the SCO socket will be
established and the fd handed off to PulseAudio to process the audio data.

I have no idea how this is accomplished in PulseAudio. This question is
being asked fairly often recently. Does PulseAudio have an
FAQ/documentation for this yet?

Regards,
-Denis
Tanu Kaskinen
2016-05-25 16:22:48 UTC
Permalink
On Wed, 2016-05-25 at 09:57 -0500, Denis Kenzior wrote:
> Hi John,
>
> On 05/25/2016 06:01 AM, Jomon John wrote:
> > Hi,
> >
> > I am trying to configure HFP with Bluez(5.34), Ofono(1.17) and
> > pulseaudio(6) on a Freescale i.MX6 board using Linux 4.1.15 kernel,
> > the idea is to use the target board in HFP/Handsfree Unit role. The
> > bluetooth controller is a Pluggable USB Bluetooth Dongle (0a5c:21e8
> > - BCM20702A0) with updated firmware.
> >
> > The procedure followed is,
> >
> > * Pair & connect with the android mobile phone with the bluetoothctl
> > * Enable modem and dial number using ofono test scripts
> >
> > After this the call is being made but the audio routing fails with
> > "Reject SCO : Agent not registered" message from oFono. While
> > checking with btmon its found that the SCO Connect Request has been
> > rejected with the reason of limited resources(0x0d).
> >
> > Can anyone help me to identify the root cause, I spent a lot of
> > time trying different version combinations, loading firmware and
> > checking logs but still nothing.

> This looks like a problem with PulseAudio configuration. oFono does not 
> handle SCO data, PulseAudio does that. In order to do that, PulseAudio 
> needs to register an agent with oFono. Then the SCO socket will be 
> established and the fd handed off to PulseAudio to process the audio data.
>
> I have no idea how this is accomplished in PulseAudio.  This question is 
> being asked fairly often recently.  Does PulseAudio have an 
> FAQ/documentation for this yet?

In /etc/pulse/default.pa, add parameter headset=ofono to module-
bluetooth-discover. That should be all that's needed at PulseAudio
side.

Denis, would you be willing to help me with the oFono parts, if I write
a document explaining how to make bluetooth audio work with
BlueZ5+PA+oFono?

-- 
Tanu
Tanu Kaskinen
2016-07-13 14:47:30 UTC
Permalink
On Wed, 2016-05-25 at 11:30 -0500, Denis Kenzior wrote:
> On 05/25/2016 11:22 AM, Tanu Kaskinen wrote:
> > Denis, would you be willing to help me with the oFono parts, if I write
> > a document explaining how to make bluetooth audio work with
> > BlueZ5+PA+oFono?
>
> Sure.

It took time, but I have now completed a wiki page about bluetooth in
PulseAudio. Thanks, Denis, for your input. I still haven't tried to use
HFP with oFono myself, so it would be good if someone more experienced
could check that the oFono stuff on the wiki page at least seems
accurate.

Any suggestions for improvements are welcome, or you can also edit the
page yourself if you have write access to the freedesktop.org wiki. I
intend to keep the page up to date, and I might add some more
information later (like explain what module-bluetooth-policy does).

Here's the link:
https://www.freedesktop.org/wiki/Software/PulseAudio/Documentation/User/Bluetooth/

-- 
Tanu
Georg Chini
2016-07-13 15:01:43 UTC
Permalink
On 13.07.2016 16:47, Tanu Kaskinen wrote:
> On Wed, 2016-05-25 at 11:30 -0500, Denis Kenzior wrote:
>> On 05/25/2016 11:22 AM, Tanu Kaskinen wrote:
>>> Denis, would you be willing to help me with the oFono parts, if I write
>>> a document explaining how to make bluetooth audio work with
>>> BlueZ5+PA+oFono?
>> Sure.
> It took time, but I have now completed a wiki page about bluetooth in
> PulseAudio. Thanks, Denis, for your input. I still haven't tried to use
> HFP with oFono myself, so it would be good if someone more experienced
> could check that the oFono stuff on the wiki page at least seems
> accurate.
>
> Any suggestions for improvements are welcome, or you can also edit the
> page yourself if you have write access to the freedesktop.org wiki. I
> intend to keep the page up to date, and I might add some more
> information later (like explain what module-bluetooth-policy does).
>
> Here's the link:
> https://www.freedesktop.org/wiki/Software/PulseAudio/Documentation/User/Bluetooth/
>
> --
There is a patch from Wim out there to support the HSP headset role:

https://lists.freedesktop.org/archives/pulseaudio-discuss/2015-February/023242.html

It was just never reviewed. I can confirm that it works.

Regards
Georg
Tanu Kaskinen
2016-07-13 15:02:59 UTC
Permalink
On Wed, 2016-07-13 at 17:01 +0200, Georg Chini wrote:
> On 13.07.2016 16:47, Tanu Kaskinen wrote:
> > On Wed, 2016-05-25 at 11:30 -0500, Denis Kenzior wrote:
> > > On 05/25/2016 11:22 AM, Tanu Kaskinen wrote:
> > > > Denis, would you be willing to help me with the oFono parts, if I write
> > > > a document explaining how to make bluetooth audio work with
> > > > BlueZ5+PA+oFono?
> > > Sure.
> > It took time, but I have now completed a wiki page about bluetooth in
> > PulseAudio. Thanks, Denis, for your input. I still haven't tried to use
> > HFP with oFono myself, so it would be good if someone more experienced
> > could check that the oFono stuff on the wiki page at least seems
> > accurate.
> >
> > Any suggestions for improvements are welcome, or you can also edit the
> > page yourself if you have write access to the freedesktop.org wiki. I
> > intend to keep the page up to date, and I might add some more
> > information later (like explain what module-bluetooth-policy does).
> >
> > Here's the link:
> > https://www.freedesktop.org/wiki/Software/PulseAudio/Documentation/User/Bluetooth/
> >
> > -- 
> There is a patch from Wim out there to support the HSP headset role:
>
> https://lists.freedesktop.org/archives/pulseaudio-discuss/2015-February/023242.html
>
> It was just never reviewed. I can confirm that it works.

Yep, that's already mentioned on the page.

--
Tanu
Arun Raghavan
2016-07-14 03:33:31 UTC
Permalink
On Wed, 13 Jul 2016, at 08:31 PM, Georg Chini wrote:
> On 13.07.2016 16:47, Tanu Kaskinen wrote:
> > On Wed, 2016-05-25 at 11:30 -0500, Denis Kenzior wrote:
> >> On 05/25/2016 11:22 AM, Tanu Kaskinen wrote:
> >>> Denis, would you be willing to help me with the oFono parts, if I write
> >>> a document explaining how to make bluetooth audio work with
> >>> BlueZ5+PA+oFono?
> >> Sure.
> > It took time, but I have now completed a wiki page about bluetooth in
> > PulseAudio. Thanks, Denis, for your input. I still haven't tried to use
> > HFP with oFono myself, so it would be good if someone more experienced
> > could check that the oFono stuff on the wiki page at least seems
> > accurate.
> >
> > Any suggestions for improvements are welcome, or you can also edit the
> > page yourself if you have write access to the freedesktop.org wiki. I
> > intend to keep the page up to date, and I might add some more
> > information later (like explain what module-bluetooth-policy does).
> >
> > Here's the link:
> > https://www.freedesktop.org/wiki/Software/PulseAudio/Documentation/User/Bluetooth/
> >
> > --
> There is a patch from Wim out there to support the HSP headset role:
>
> https://lists.freedesktop.org/archives/pulseaudio-discuss/2015-February/023242.html
>
> It was just never reviewed. I can confirm that it works.

I did review it, but unfortunately posted comments on IRC. I'll try to
dig that out and put them up (or just fix them) at some point.

Regards,
Arun
Georg Chini
2016-05-25 16:30:53 UTC
Permalink
On 25.05.2016 16:57, Denis Kenzior wrote:
> Hi John,
>
> On 05/25/2016 06:01 AM, Jomon John wrote:
>> Hi,
>>
>> I am trying to configure HFP with Bluez(5.34), Ofono(1.17) and
>> pulseaudio(6) on a Freescale i.MX6 board using Linux 4.1.15 kernel,
>> the idea is to use the target board in HFP/Handsfree Unit role. The
>> bluetooth controller is a Pluggable USB Bluetooth Dongle (0a5c:21e8 -
>> BCM20702A0) with updated firmware.
>>
>> The procedure followed is,
>>
>> * Pair & connect with the android mobile phone with the bluetoothctl
>> * Enable modem and dial number using ofono test scripts
>>
>> After this the call is being made but the audio routing fails with
>> "Reject SCO : Agent not registered" message from oFono. While
>> checking with btmon its found that the SCO Connect Request has been
>> rejected with the reason of limited resources(0x0d).
>>
>> Can anyone help me to identify the root cause, I spent a lot of time
>> trying different version combinations, loading firmware and checking
>> logs but still nothing.
>

Did you load module-bluetooth-discover with headset=ofono as argument?
Normally this should be sufficient to make it work. When the connection
is established,
pulseaudio automatically loads loopback modules for the phone. You might
have
to check if the modules have the correct source / sink.
Additionally to observing the log files, you can debug what is going on
by using
dbus-monitor to see the messages on the dbus.

> This looks like a problem with PulseAudio configuration. oFono does
> not handle SCO data, PulseAudio does that. In order to do that,
> PulseAudio needs to register an agent with oFono. Then the SCO socket
> will be established and the fd handed off to PulseAudio to process the
> audio data.
>
> I have no idea how this is accomplished in PulseAudio. This question
> is being asked fairly often recently. Does PulseAudio have an
> FAQ/documentation for this yet?
>

Unfortunately there is no HowTo as far as I know. Most stuff you find on
the net is outdated.

> Regards,
> -Denis
>
> _______________________________________________
> ofono mailing list
> ***@ofono.org
> https://lists.ofono.org/mailman/listinfo/ofono
Jomon John
2016-05-26 18:22:20 UTC
Permalink
Hi,

Thank you for the support.

> Did you load module-bluetooth-discover with headset=ofono as argument?
> Normally this should be sufficient to make it work. When the connection
> is established,

Yes, module-bluetooth-discover is loaded, also tried with "ofono" and "auto" arguments, but nothing till now.

> pulseaudio automatically loads loopback modules for the phone. You might
> have to check if the modules have the correct source / sink.

Could you please provide further more details regrading the source sink setup.

> Additionally to observing the log files, you can debug what is going on
> by using dbus-monitor to see the messages on the dbus.

Yup, i will share the logs.

Regards,
John J
Jomon John
2016-05-27 19:18:22 UTC
Permalink
Hi All,

>> Did you load module-bluetooth-discover with headset=ofono as argument?
>> Normally this should be sufficient to make it work. When the connection
>> is established,
> Yes, module-bluetooth-discover is loaded, also tried with "ofono" and "auto" arguments, but nothing till now.
>> pulseaudio automatically loads loopback modules for the phone. You might
>> have to check if the modules have the correct source / sink.
> Could you please provide further more details regrading the source sink setup.
>> Additionally to observing the log files, you can debug what is going on
>> by using dbus-monitor to see the messages on the dbus.

Thanks, SCO transport is working now, even though i cant hear anything on headset sco traffic is visible via btmon during phone call.The issues were,

* The build system(Yocto) was not properly enabling the ofono backend for pulseaudio, took some time to identify this.
* Configured default.pa with proper module name name(module-bluez5-discover) and arguments
* device, module and card restore modules are causing issues, so disabled it !!

Currently trying to change volume with alsamixer is giving following message,

alsa-plugins-1.0.29/pulse/pulse.c:243:(pulse_connect) PulseAudio: Unable to connect: Connection refused
cannot open mixer: Connection refused

~
Best Regards,
John J
Georg Chini
2016-05-28 12:11:47 UTC
Permalink
On 27.05.2016 21:18, Jomon John wrote:
> Hi All,
>
>>> Did you load module-bluetooth-discover with headset=ofono as argument?
>>> Normally this should be sufficient to make it work. When the connection
>>> is established,
>> Yes, module-bluetooth-discover is loaded, also tried with "ofono" and "auto" arguments, but nothing till now.
>>> pulseaudio automatically loads loopback modules for the phone. You might
>>> have to check if the modules have the correct source / sink.
>> Could you please provide further more details regrading the source sink setup.
>>> Additionally to observing the log files, you can debug what is going on
>>> by using dbus-monitor to see the messages on the dbus.
> Thanks, SCO transport is working now, even though i cant hear anything on headset sco traffic is visible via btmon during phone call.The issues were,
>
> * The build system(Yocto) was not properly enabling the ofono backend for pulseaudio, took some time to identify this.
> * Configured default.pa with proper module name name(module-bluez5-discover) and arguments
> * device, module and card restore modules are causing issues, so disabled it !!
>
> Currently trying to change volume with alsamixer is giving following message,
>
> alsa-plugins-1.0.29/pulse/pulse.c:243:(pulse_connect) PulseAudio: Unable to connect: Connection refused
> cannot open mixer: Connection refused
>
>
Did you check with "pacmd list-sinks" and "pacmd list-sources" if the
bluetooth sink and source are
available? Did you check if loopback modules get loaded?
If they get loaded, please check if they are loaded correctly. There
must be one module with source
set to your phone and sink set to your default sound device and one
module in the other direction.
You should also see some output of the loopback modules in the
pulseaudio log.
Jomon John
2016-06-07 07:53:20 UTC
Permalink
Hi,

On 27.05.2016 21:18, Jomon John wrote:
>> Hi All,
>>
>>>> Did you load module-bluetooth-discover with headset=ofono as argument?
>>>> Normally this should be sufficient to make it work. When the connection
>>>> is established,
>>> Yes, module-bluetooth-discover is loaded, also tried with "ofono" and "auto" arguments, but nothing till now.
>>>> pulseaudio automatically loads loopback modules for the phone. You might
>>>> have to check if the modules have the correct source / sink.
>>> Could you please provide further more details regrading the source sink setup.
>>>> Additionally to observing the log files, you can debug what is going on
>>>> by using dbus-monitor to see the messages on the dbus.
>> Thanks, SCO transport is working now, even though i cant hear anything on headset sco traffic is visible via btmon during phone call.The issues were,
>>
>> * The build system(Yocto) was not properly enabling the ofono backend for pulseaudio, took some time to identify this.
>> * Configured default.pa with proper module name name(module-bluez5-discover) and arguments
>> * device, module and card restore modules are causing issues, so disabled it !!
>>
>> Currently trying to change volume with alsamixer is giving following message,
>>
>>      alsa-plugins-1.0.29/pulse/pulse.c:243:(pulse_connect) PulseAudio: Unable to connect: Connection refused
>>      cannot open mixer: Connection refused
>>
>>
> Did you check with "pacmd list-sinks" and "pacmd list-sources" if the
> bluetooth sink and source are
> available? Did you check if loopback modules get loaded?
> If they get loaded, please check if they are loaded correctly. There
> must be one module with source
> set to your phone and sink set to your default sound device and one
> module in the other direction.
> You should also see some output of the loopback modules in the
> pulseaudio log.

Thanks for the support, things are getting more and more interesting because now,

* A2DP is working fine, but i cant find bluez source or sink in pacmd or pactl outputs, but same time the loading of module loopback with bluez_source is shown in journalctl logs of pulseaudio.

module.c: Loaded "module-loopback" (index: #28; argument: "source="bluez_source.CC_C3_EA_0A_15_90" source_dont_move="true" sink_input_properties="media.role=music"").

* Same for HFP, nothing related to bluez_* in pactl or pacmd outputs. Again i can see the audio levels changing in pavucontrol (connected from external machine with PULSE_SERVER) but only one side audio is working which is from device side mic to other end. on the other side (calling phone to device) the levels are changing but seems to be not routed to the default sink (since the levels are not changing in the default sink)

Loaded "module-loopback" (index: #30; argument: "source="bluez_source.CC_C3_EA_0A_15_90" source_dont_move="true" sink_input_properties="media.role=phone"").
card.c: Changed profile of card 1 "bluez_card.CC_C3_EA_0A_15_90" to headset_audio_gateway

some more information regarding the setup,

* Everything is run as root user who is member of audio and pulse groups
* PA daemon is not in system mode
* ofono and bluez is available on dbus system bus but pulseaudio is on dbus session bus (is this the right way ??)

Please advice,

With regards,
John J
Georg Chini
2016-06-07 08:31:50 UTC
Permalink
On 07.06.2016 09:53, Jomon John wrote:
> Hi,
>
> On 27.05.2016 21:18, Jomon John wrote:
>>> Hi All,
>>>
>>>>> Did you load module-bluetooth-discover with headset=ofono as argument?
>>>>> Normally this should be sufficient to make it work. When the connection
>>>>> is established,
>>>> Yes, module-bluetooth-discover is loaded, also tried with "ofono" and "auto" arguments, but nothing till now.
>>>>> pulseaudio automatically loads loopback modules for the phone. You might
>>>>> have to check if the modules have the correct source / sink.
>>>> Could you please provide further more details regrading the source sink setup.
>>>>> Additionally to observing the log files, you can debug what is going on
>>>>> by using dbus-monitor to see the messages on the dbus.
>>> Thanks, SCO transport is working now, even though i cant hear anything on headset sco traffic is visible via btmon during phone call.The issues were,
>>>
>>> * The build system(Yocto) was not properly enabling the ofono backend for pulseaudio, took some time to identify this.
>>> * Configured default.pa with proper module name name(module-bluez5-discover) and arguments
>>> * device, module and card restore modules are causing issues, so disabled it !!
>>>
>>> Currently trying to change volume with alsamixer is giving following message,
>>>
>>> alsa-plugins-1.0.29/pulse/pulse.c:243:(pulse_connect) PulseAudio: Unable to connect: Connection refused
>>> cannot open mixer: Connection refused
>>>
>>>
>> Did you check with "pacmd list-sinks" and "pacmd list-sources" if the
>> bluetooth sink and source are
>> available? Did you check if loopback modules get loaded?
>> If they get loaded, please check if they are loaded correctly. There
>> must be one module with source
>> set to your phone and sink set to your default sound device and one
>> module in the other direction.
>> You should also see some output of the loopback modules in the
>> pulseaudio log.
> Thanks for the support, things are getting more and more interesting because now,
>
> * A2DP is working fine, but i cant find bluez source or sink in pacmd or pactl outputs, but same time the loading of module loopback with bluez_source is shown in journalctl logs of pulseaudio.
>
> module.c: Loaded "module-loopback" (index: #28; argument: "source="bluez_source.CC_C3_EA_0A_15_90" source_dont_move="true" sink_input_properties="media.role=music"").
Mh, that is strange, pacmd list-sources should definitely show the bluez
source, you can see from
the arguments of the loopback module that the source exists.

>
> * Same for HFP, nothing related to bluez_* in pactl or pacmd outputs. Again i can see the audio levels changing in pavucontrol (connected from external machine with PULSE_SERVER) but only one side audio is working which is from device side mic to other end. on the other side (calling phone to device) the levels are changing but seems to be not routed to the default sink (since the levels are not changing in the default sink)
>
> Loaded "module-loopback" (index: #30; argument: "source="bluez_source.CC_C3_EA_0A_15_90" source_dont_move="true" sink_input_properties="media.role=phone"").
> card.c: Changed profile of card 1 "bluez_card.CC_C3_EA_0A_15_90" to headset_audio_gateway
>
> some more information regarding the setup,
>
> * Everything is run as root user who is member of audio and pulse groups
> * PA daemon is not in system mode
> * ofono and bluez is available on dbus system bus but pulseaudio is on dbus session bus (is this the right way ??)
>
>
Is there only one loopback module? There should be two, one from the
bluez source to the default sink and
one from the default source to the bluez sink.
Jomon John
2016-06-07 10:11:33 UTC
Permalink
Hi,
 
Thank you for the help,

>>> Did you check with "pacmd list-sinks" and "pacmd list-sources" if the
>>> bluetooth sink and source are
>>> available? Did you check if loopback modules get loaded?
>>> If they get loaded, please check if they are loaded correctly. There
>>> must be one module with source
>>> set to your phone and sink set to your default sound device and one
>>> module in the other direction.
>>> You should also see some output of the loopback modules in the
>>> pulseaudio log.
>> Thanks for the support, things are getting more and more interesting because now,
>>
>> * A2DP is working fine, but i cant find bluez source or sink in pacmd or pactl outputs, but same time the loading of module loopback with bluez_source is shown in journalctl logs of pulseaudio.
>>
>>      module.c: Loaded "module-loopback" (index: #28; argument: "source="bluez_source.CC_C3_EA_0A_15_90" source_dont_move="true" sink_input_properties="media.role=music"").

>Mh, that is strange, pacmd list-sources should definitely show the bluez
>source, you can see from
>the arguments of the loopback module that the source exists.

Is this anyway related to dbus configuration or selected bus (ssystem vs session) ?

>> * Same for HFP, nothing related to bluez_* in pactl or pacmd outputs. Again i can see the audio levels changing in pavucontrol (connected from external machine with PULSE_SERVER) but only one side audio is working which is from device side mic to other end. on the other side (calling phone to device) the levels are changing but seems to be not routed to the default sink (since the levels are not changing in the default sink)
>>
>>      Loaded "module-loopback" (index: #30; argument: "source="bluez_source.CC_C3_EA_0A_15_90" source_dont_move="true" sink_input_properties="media.role=phone"").
>>      card.c: Changed profile of card 1 "bluez_card.CC_C3_EA_0A_15_90" to headset_audio_gateway
>>
>> some more information regarding the setup,
>>
>> * Everything is run as root user who is member of audio and pulse groups
>> * PA daemon is not in system mode
>> * ofono and bluez is available on dbus system bus but pulseaudio is on dbus session bus (is this the right way ??)

>Is there only one loopback module? There should be two, one from the
>bluez source to the default sink and
>one from the default source to the bluez sink.

You were right, as per the logs the module-loopback loaded two times,

[pulseaudio] module.c: Loaded "module-loopback" (index: #41; argument: "sink="bluez_sink.CC_C3_EA_0A_15_90" sink_dont_move="true" source_output_properties="media.role=phone"")

[pulseaudio] module.c: Loaded "module-loopback" (index: #42; argument: "source="bluez_source.CC_C3_EA_0A_15_90" source_dont_move="true" sink_input_properties="media.role=phone"").

The audio from default source is channeled to phone but i cant hear any output audio from phone on the board while HFP session, so is there any way to control or verify the the source sink routing during the HFP session.

With Regards,

John J
Georg Chini
2016-06-07 10:55:33 UTC
Permalink
On 07.06.2016 12:11, Jomon John wrote:
>
>> * Same for HFP, nothing related to bluez_* in pactl or pacmd outputs. Again i can see the audio levels changing in pavucontrol (connected from external machine with PULSE_SERVER) but only one side audio is working which is from device side mic to other end. on the other side (calling phone to device) the levels are changing but seems to be not routed to the default sink (since the levels are not changing in the default sink)
>>
>> Loaded "module-loopback" (index: #30; argument: "source="bluez_source.CC_C3_EA_0A_15_90" source_dont_move="true" sink_input_properties="media.role=phone"").
>> card.c: Changed profile of card 1 "bluez_card.CC_C3_EA_0A_15_90" to headset_audio_gateway
>>
>> some more information regarding the setup,
>>
>> * Everything is run as root user who is member of audio and pulse groups
>> * PA daemon is not in system mode
>> * ofono and bluez is available on dbus system bus but pulseaudio is on dbus session bus (is this the right way ??)
>> Is there only one loopback module? There should be two, one from the
>> bluez source to the default sink and
>> one from the default source to the bluez sink.
> You were right, as per the logs the module-loopback loaded two times,
>
> [pulseaudio] module.c: Loaded "module-loopback" (index: #41; argument: "sink="bluez_sink.CC_C3_EA_0A_15_90" sink_dont_move="true" source_output_properties="media.role=phone"")
>
> [pulseaudio] module.c: Loaded "module-loopback" (index: #42; argument: "source="bluez_source.CC_C3_EA_0A_15_90" source_dont_move="true" sink_input_properties="media.role=phone"").
>
> The audio from default source is channeled to phone but i cant hear any output audio from phone on the board while HFP session, so is there any way to control or verify the the source sink routing during the HFP session.
>
>
What does pacmd list-cards show? Is the bluez device listed there? Can
you check (with pavucontrol
or in the logs) if the loopback from the phone goes to the correct sink?
Do you see messages in the
pulseaudio debug log from both loopback modules?
Jomon John
2016-06-07 12:47:13 UTC
Permalink
> On 07.06.2016 12:11, Jomon John wrote:
> >> * Same for HFP, nothing related to bluez_* in pactl or pacmd outputs. Again i can see the audio levels changing in pavucontrol (connected from external machine with PULSE_SERVER) but only one side audio is working which is from device side mic to other end.  on the other side (calling phone to device) the levels are changing but seems to be not routed to the default sink (since the levels are not changing in the default sink)
>>>
>>>        Loaded "module-loopback" (index: #30; argument: "source="bluez_source.CC_C3_EA_0A_15_90" source_dont_move="true" sink_input_properties="media.role=phone"").
>>>        card.c: Changed profile of card 1 "bluez_card.CC_C3_EA_0A_15_90" to headset_audio_gateway
>>>
>>> some more information regarding the setup,
>>>
>>> * Everything is run as root user who is member of audio and pulse groups
>>> * PA daemon is not in system mode
>>> * ofono and bluez is available on dbus system bus but pulseaudio is on dbus session bus (is this the right way ??)
>>> Is there only one loopback module? There should be two, one from the
>>> bluez source to the default sink and
>>> one from the default source to the bluez sink.
>> You were right, as per the logs the module-loopback loaded two times,
>>
>>       [pulseaudio] module.c: Loaded "module-loopback" (index: #41; argument: "sink="bluez_sink.CC_C3_EA_0A_15_90" sink_dont_move="true" source_output_properties="media.role=phone"")
>>
>>       [pulseaudio] module.c: Loaded "module-loopback" (index: #42; argument: "source="bluez_source.CC_C3_EA_0A_15_90" source_dont_move="true" sink_input_properties="media.role=phone"").
>>     
>> The audio from default source is channeled to phone but i cant hear any output audio from phone on the board while HFP session, so is there any way to control or verify the the source sink routing during the HFP session.

> What does pacmd list-cards show? Is the bluez device listed there?

Yes, the bluez device is listed in the output,

index: 1
name: <bluez_card.CC_C3_EA_0A_15_90>
driver: <module-bluez5-device.c>
owner module: 24
properties:
device.description = "Jo XT1033"
device.string = "CC:C3:EA:0A:17:97"
device.api = "bluez"
device.class = "sound"
device.bus = "bluetooth"
device.form_factor = "phone"
bluez.path = "/org/bluez/hci0/dev_CC_C3_EA_0A_15_90"
bluez.class = "0x5a020c"
bluez.alias = "Jo_XT1033"
device.icon_name = "audio-card-bluetooth"
profiles:
a2dp_source: High Fidelity Capture (A2DP Source) (priority 10, available: unknown)
headset_audio_gateway: Headset Audio Gateway (HSP/HFP) (priority 20, available: no)
off: Off (priority 0, available: yes)
active profile: <a2dp_source>
sources:
bluez_source.CC_C3_EA_0A_15_90/#2: Jo XT1033
ports:
phone-output: Phone (priority 0, latency offset 0 usec, available: no)
properties:

phone-input: Phone (priority 0, latency offset 0 usec, available: unknown)
properties:

> Can you check (with pavucontrol
> or in the logs) if the loopback from the phone goes to the correct sink?

As per the level changes shown in pavucontrol the audio from the other end of the phone reaching the bluez source, but level changes are not shown in the default sink, so i assume that the routing doesn't work between bluez source to default sink, also i didnt find much info about this on logs, what should i look for ?

> Do you see messages in the
> pulseaudio debug log from both loopback modules?

yes, Other than the module load messages i didn't find much (oh sure, discarding all the "Could not peek into queue" and "Requesting rewind due to end of underrun" )

[pulseaudio] module.c: Loaded "module-loopback" (index: #41; argument: "sink="bluez_sink.CC_C3_EA_0A_15_90" sink_dont_move="true" source_output_properties="media.role=phone"").
[bluetooth] module-loopback.c: Max request changed
[bluetooth] module-loopback.c: Skipping 6218 bytes
[pulseaudio] module.c: Loaded "module-loopback" (index: #42; argument: "source="bluez_source.CC_C3_EA_0A_15_90" source_dont_move="true" sink_input_properties="media.role=phone"").
[pulseaudio] module-loopback.c: Loopback overall latency is 353.36 ms + 2.50 ms + 4.62 ms = 360.47 ms
[pulseaudio] module-loopback.c: Should buffer 96 bytes, buffered at minimum 0 bytes
.
.
[pulseaudio] module-loopback.c: Loopback overall latency is 854.23 ms + 13.00 ms + 16.09 ms = 883.32 ms
[pulseaudio] module-loopback.c: Should buffer 96 bytes, buffered at minimum 0 bytes
[pulseaudio] module-loopback.c: [bluez_sink.CC_C3_EA_0A_15_90] Updated sampling rate to 8000 Hz.
[alsa-sink-HiFi wm8962-0] module-loopback.c: Max request changed
[alsa-sink-HiFi wm8962-0] module-loopback.c: Max request changed


With Regards,
John J
Georg Chini
2016-06-07 13:22:05 UTC
Permalink
On 07.06.2016 14:47, Jomon John wrote:
>
>> On 07.06.2016 12:11, Jomon John wrote:
>>>> * Same for HFP, nothing related to bluez_* in pactl or pacmd outputs. Again i can see the audio levels changing in pavucontrol (connected from external machine with PULSE_SERVER) but only one side audio is working which is from device side mic to other end. on the other side (calling phone to device) the levels are changing but seems to be not routed to the default sink (since the levels are not changing in the default sink)
>>>>
>>>> Loaded "module-loopback" (index: #30; argument: "source="bluez_source.CC_C3_EA_0A_15_90" source_dont_move="true" sink_input_properties="media.role=phone"").
>>>> card.c: Changed profile of card 1 "bluez_card.CC_C3_EA_0A_15_90" to headset_audio_gateway
>>>>
>>>> some more information regarding the setup,
>>>>
>>>> * Everything is run as root user who is member of audio and pulse groups
>>>> * PA daemon is not in system mode
>>>> * ofono and bluez is available on dbus system bus but pulseaudio is on dbus session bus (is this the right way ??)
>>>> Is there only one loopback module? There should be two, one from the
>>>> bluez source to the default sink and
>>>> one from the default source to the bluez sink.
>>> You were right, as per the logs the module-loopback loaded two times,
>>>
>>> [pulseaudio] module.c: Loaded "module-loopback" (index: #41; argument: "sink="bluez_sink.CC_C3_EA_0A_15_90" sink_dont_move="true" source_output_properties="media.role=phone"")
>>>
>>> [pulseaudio] module.c: Loaded "module-loopback" (index: #42; argument: "source="bluez_source.CC_C3_EA_0A_15_90" source_dont_move="true" sink_input_properties="media.role=phone"").
>>>
>>> The audio from default source is channeled to phone but i cant hear any output audio from phone on the board while HFP session, so is there any way to control or verify the the source sink routing during the HFP session.
>> What does pacmd list-cards show? Is the bluez device listed there?
> Yes, the bluez device is listed in the output,
>
> index: 1
> name: <bluez_card.CC_C3_EA_0A_15_90>
> driver: <module-bluez5-device.c>
> owner module: 24
> properties:
> device.description = "Jo XT1033"
> device.string = "CC:C3:EA:0A:17:97"
> device.api = "bluez"
> device.class = "sound"
> device.bus = "bluetooth"
> device.form_factor = "phone"
> bluez.path = "/org/bluez/hci0/dev_CC_C3_EA_0A_15_90"
> bluez.class = "0x5a020c"
> bluez.alias = "Jo_XT1033"
> device.icon_name = "audio-card-bluetooth"
> profiles:
> a2dp_source: High Fidelity Capture (A2DP Source) (priority 10, available: unknown)
> headset_audio_gateway: Headset Audio Gateway (HSP/HFP) (priority 20, available: no)
> off: Off (priority 0, available: yes)
> active profile: <a2dp_source>
> sources:
> bluez_source.CC_C3_EA_0A_15_90/#2: Jo XT1033
> ports:
> phone-output: Phone (priority 0, latency offset 0 usec, available: no)
> properties:
>
> phone-input: Phone (priority 0, latency offset 0 usec, available: unknown)
> properties:
>
>> Can you check (with pavucontrol
>> or in the logs) if the loopback from the phone goes to the correct sink?
> As per the level changes shown in pavucontrol the audio from the other end of the phone reaching the bluez source, but level changes are not shown in the default sink, so i assume that the routing doesn't work between bluez source to default sink, also i didnt find much info about this on logs, what should i look for ?
>
>> Do you see messages in the
>> pulseaudio debug log from both loopback modules?
> yes, Other than the module load messages i didn't find much (oh sure, discarding all the "Could not peek into queue" and "Requesting rewind due to end of underrun" )
>
> [pulseaudio] module.c: Loaded "module-loopback" (index: #41; argument: "sink="bluez_sink.CC_C3_EA_0A_15_90" sink_dont_move="true" source_output_properties="media.role=phone"").
> [bluetooth] module-loopback.c: Max request changed
> [bluetooth] module-loopback.c: Skipping 6218 bytes
> [pulseaudio] module.c: Loaded "module-loopback" (index: #42; argument: "source="bluez_source.CC_C3_EA_0A_15_90" source_dont_move="true" sink_input_properties="media.role=phone"").
> [pulseaudio] module-loopback.c: Loopback overall latency is 353.36 ms + 2.50 ms + 4.62 ms = 360.47 ms
> [pulseaudio] module-loopback.c: Should buffer 96 bytes, buffered at minimum 0 bytes
> .
> .
> [pulseaudio] module-loopback.c: Loopback overall latency is 854.23 ms + 13.00 ms + 16.09 ms = 883.32 ms
> [pulseaudio] module-loopback.c: Should buffer 96 bytes, buffered at minimum 0 bytes
> [pulseaudio] module-loopback.c: [bluez_sink.CC_C3_EA_0A_15_90] Updated sampling rate to 8000 Hz.
> [alsa-sink-HiFi wm8962-0] module-loopback.c: Max request changed
> [alsa-sink-HiFi wm8962-0] module-loopback.c: Max request changed
>
>
The loopback modules should provide messages every 10 seconds. There
should also be
messages like

[pulseaudio] module-loopback.c: [bluez_sink.CC_C3_EA_0A_15_90] Updated sampling rate to 8000 Hz

for the other loopback. There you can see what sink is used for the
second loopback.
Underruns or "cannot peek into queue" messages should only occur at the
startup of the
modules but not during normal operation. Could you post the relevant
parts of your log?
Jomon John
2016-06-07 15:23:50 UTC
Permalink
Hi,
 
On 07.06.2016 14:47, Jomon John wrote:
>>    
>>> On 07.06.2016 12:11, Jomon John wrote:
>>>>> * Same for HFP, nothing related to bluez_* in pactl or pacmd outputs. Again i can see the audio levels changing in pavucontrol (connected from external machine with PULSE_SERVER) but only one side audio is working which is from device side mic to other end.   on the other side (calling phone to device) the levels are changing but seems to be not routed to the default sink (since the levels are not changing in the default sink)
>>>>>
>>>>>          Loaded "module-loopback" (index: #30; argument: "source="bluez_source.CC_C3_EA_0A_15_90" source_dont_move="true" sink_input_properties="media.role=phone"").
>>>>>          card.c: Changed profile of card 1 "bluez_card.CC_C3_EA_0A_15_90" to headset_audio_gateway
>>>>>
>>>>> some more information regarding the setup,
>>>>>
>>>>> * Everything is run as root user who is member of audio and pulse groups
>>>>> * PA daemon is not in system mode
>>>>> * ofono and bluez is available on dbus system bus but pulseaudio is on dbus session bus (is this the right way ??)
>>>>> Is there only one loopback module? There should be two, one from the
>>>>> bluez source to the default sink and
>>>>> one from the default source to the bluez sink.
>>>> You were right, as per the logs the module-loopback loaded two times,
>>>>
>>>>         [pulseaudio] module.c: Loaded "module-loopback" (index: #41; argument: "sink="bluez_sink.CC_C3_EA_0A_15_90" sink_dont_move="true" source_output_properties="media.role=phone"")
>>>>
>>>>         [pulseaudio] module.c: Loaded "module-loopback" (index: #42; argument: "source="bluez_source.CC_C3_EA_0A_15_90" source_dont_move="true" sink_input_properties="media.role=phone"").
>>>>       
>>>> The audio from default source is channeled to phone but i cant hear any output audio from phone on the board while HFP session, so is there any way to control or verify the the source sink routing during the HFP session.
>>> What does pacmd list-cards show? Is the bluez device listed there?
>> Yes, the bluez device is listed in the output,
>>
>>        index: 1
>>        name: <bluez_card.CC_C3_EA_0A_15_90>
>>        driver: <module-bluez5-device.c>
>>        owner module: 24
>>        properties:
>>                device.description = "Jo XT1033"
>>                device.string = "CC:C3:EA:0A:17:97"
>>                device.api = "bluez"
>>                device.class = "sound"
>>                device.bus = "bluetooth"
>>                device.form_factor = "phone"
>>                bluez.path = "/org/bluez/hci0/dev_CC_C3_EA_0A_15_90"
>>                bluez.class = "0x5a020c"
>>                bluez.alias = "Jo_XT1033"
>>                device.icon_name = "audio-card-bluetooth"
>>        profiles:
>>                a2dp_source: High Fidelity Capture (A2DP Source) (priority 10, available: unknown)
>>                headset_audio_gateway: Headset Audio Gateway (HSP/HFP) (priority 20, available: no)
>>                off: Off (priority 0, available: yes)
>>        active profile: <a2dp_source>
>>        sources:
>>                bluez_source.CC_C3_EA_0A_15_90/#2: Jo XT1033
>>        ports:
>>                phone-output: Phone (priority 0, latency offset 0 usec, available: no)
>>                        properties:
>>                               
>>                phone-input: Phone (priority 0, latency offset 0 usec, available: unknown)
>>                        properties:
>>                                       
>> Can you check (with pavucontrol or in the logs) if the loopback from the phone goes to the correct sink?
>> As per the level changes shown in pavucontrol the audio from the other end of the phone reaching the bluez source, but level changes are not shown in the default sink, so i assume that the routing doesn't work between bluez source to default sink, also i didnt find much info about this on logs, what should i look for ?
>>
>>> Do you see messages in the
>>> pulseaudio debug log from both loopback modules?
>> yes, Other than the module load messages i didn't find much (oh sure, discarding all the "Could not peek into queue" and "Requesting rewind due to end of underrun" )
>>
>>        [pulseaudio] module.c: Loaded "module-loopback" (index: #41; argument: "sink="bluez_sink.CC_C3_EA_0A_15_90" sink_dont_move="true" source_output_properties="media.role=phone"").
>>        [bluetooth] module-loopback.c: Max request changed
>>        [bluetooth] module-loopback.c: Skipping 6218 bytes
>>        [pulseaudio] module.c: Loaded "module-loopback" (index: #42; argument: "source="bluez_source.CC_C3_EA_0A_15_90" source_dont_move="true" sink_input_properties="media.role=phone"").
>>        [pulseaudio] module-loopback.c: Loopback overall latency is 353.36 ms + 2.50 ms + 4.62 ms = 360.47 ms
>>        [pulseaudio] module-loopback.c: Should buffer 96 bytes, buffered at minimum 0 bytes
>>        .
>>        .
>>        [pulseaudio] module-loopback.c: Loopback overall latency is 854.23 ms + 13.00 ms + 16.09 ms = 883.32 ms
>>        [pulseaudio] module-loopback.c: Should buffer 96 bytes, buffered at minimum 0 bytes
>>        [pulseaudio] module-loopback.c: [bluez_sink.CC_C3_EA_0A_15_90] Updated sampling rate to 8000 Hz.
>>        [alsa-sink-HiFi wm8962-0] module-loopback.c: Max request changed
>>        [alsa-sink-HiFi wm8962-0] module-loopback.c: Max request changed
>>

>The loopback modules should provide messages every 10 seconds. There should also be messages like
>[pulseaudio] module-loopback.c: [bluez_sink.CC_C3_EA_0A_15_90] Updated sampling rate to 8000 Hz
>for the other loopback.

Yes, such messages are there.

>There you can see what sink is used for the second loopback. Underruns or "cannot peek into queue" messages should only occur at the startup of the modules but not during normal operation. Could you post the relevant parts of your log?

This part looks suspicious,

D: [pulseaudio] module-loopback.c: Should buffer 96 bytes, buffered at minimum 48 bytes
D: [pulseaudio] module-loopback.c: [bluez_sink.CC_C3_EA_0A_17_97] Updated sampling rate to 8000 Hz.
I: [bluetooth] module-bluez5-device.c: FD error: POLLERR POLLHUP
D: [bluetooth] module-bluez5-device.c: Audio stream torn down
D: [pulseaudio] bluez5-util.c: Transport /card_1 state changed from playing to idle
D: [pulseaudio] card.c: Setting card bluez_card.CC_C3_EA_0A_17_97 profile headset_audio_gateway to availability status unknown
D: [pulseaudio] module-bluetooth-policy.c: Setting card 'bluez_card.CC_C3_EA_0A_17_97' to profile 'off'
D: [pulseaudio] module-rescue-streams.c: No evacuation sink found.
I: [pulseaudio] source-output.c: Freeing output 7 "Peak detect"
D: [bluetooth] sink.c: Requesting rewind due to started move


the complete log is pated @ http://pastebin.com/cddrcAxb

With Regards,
John J
Georg Chini
2016-06-07 19:10:48 UTC
Permalink
On 07.06.2016 17:23, Jomon John wrote:
> Hi,
>
> On 07.06.2016 14:47, Jomon John wrote:
>>>
>>>> On 07.06.2016 12:11, Jomon John wrote:
>>>>>> * Same for HFP, nothing related to bluez_* in pactl or pacmd outputs. Again i can see the audio levels changing in pavucontrol (connected from external machine with PULSE_SERVER) but only one side audio is working which is from device side mic to other end. on the other side (calling phone to device) the levels are changing but seems to be not routed to the default sink (since the levels are not changing in the default sink)
>>>>>>
>>>>>> Loaded "module-loopback" (index: #30; argument: "source="bluez_source.CC_C3_EA_0A_15_90" source_dont_move="true" sink_input_properties="media.role=phone"").
>>>>>> card.c: Changed profile of card 1 "bluez_card.CC_C3_EA_0A_15_90" to headset_audio_gateway
>>>>>>
>>>>>> some more information regarding the setup,
>>>>>>
>>>>>> * Everything is run as root user who is member of audio and pulse groups
>>>>>> * PA daemon is not in system mode
>>>>>> * ofono and bluez is available on dbus system bus but pulseaudio is on dbus session bus (is this the right way ??)
>>>>>> Is there only one loopback module? There should be two, one from the
>>>>>> bluez source to the default sink and
>>>>>> one from the default source to the bluez sink.
>>>>> You were right, as per the logs the module-loopback loaded two times,
>>>>>
>>>>> [pulseaudio] module.c: Loaded "module-loopback" (index: #41; argument: "sink="bluez_sink.CC_C3_EA_0A_15_90" sink_dont_move="true" source_output_properties="media.role=phone"")
>>>>>
>>>>> [pulseaudio] module.c: Loaded "module-loopback" (index: #42; argument: "source="bluez_source.CC_C3_EA_0A_15_90" source_dont_move="true" sink_input_properties="media.role=phone"").
>>>>>
>>>>> The audio from default source is channeled to phone but i cant hear any output audio from phone on the board while HFP session, so is there any way to control or verify the the source sink routing during the HFP session.
>>>> What does pacmd list-cards show? Is the bluez device listed there?
>>> Yes, the bluez device is listed in the output,
>>>
>>> index: 1
>>> name: <bluez_card.CC_C3_EA_0A_15_90>
>>> driver: <module-bluez5-device.c>
>>> owner module: 24
>>> properties:
>>> device.description = "Jo XT1033"
>>> device.string = "CC:C3:EA:0A:17:97"
>>> device.api = "bluez"
>>> device.class = "sound"
>>> device.bus = "bluetooth"
>>> device.form_factor = "phone"
>>> bluez.path = "/org/bluez/hci0/dev_CC_C3_EA_0A_15_90"
>>> bluez.class = "0x5a020c"
>>> bluez.alias = "Jo_XT1033"
>>> device.icon_name = "audio-card-bluetooth"
>>> profiles:
>>> a2dp_source: High Fidelity Capture (A2DP Source) (priority 10, available: unknown)
>>> headset_audio_gateway: Headset Audio Gateway (HSP/HFP) (priority 20, available: no)
>>> off: Off (priority 0, available: yes)
>>> active profile: <a2dp_source>
>>> sources:
>>> bluez_source.CC_C3_EA_0A_15_90/#2: Jo XT1033
>>> ports:
>>> phone-output: Phone (priority 0, latency offset 0 usec, available: no)
>>> properties:
>>>
>>> phone-input: Phone (priority 0, latency offset 0 usec, available: unknown)
>>> properties:
>>>
>>> Can you check (with pavucontrol or in the logs) if the loopback from the phone goes to the correct sink?
>>> As per the level changes shown in pavucontrol the audio from the other end of the phone reaching the bluez source, but level changes are not shown in the default sink, so i assume that the routing doesn't work between bluez source to default sink, also i didnt find much info about this on logs, what should i look for ?
>>>
>>>> Do you see messages in the
>>>> pulseaudio debug log from both loopback modules?
>>> yes, Other than the module load messages i didn't find much (oh sure, discarding all the "Could not peek into queue" and "Requesting rewind due to end of underrun" )
>>>
>>> [pulseaudio] module.c: Loaded "module-loopback" (index: #41; argument: "sink="bluez_sink.CC_C3_EA_0A_15_90" sink_dont_move="true" source_output_properties="media.role=phone"").
>>> [bluetooth] module-loopback.c: Max request changed
>>> [bluetooth] module-loopback.c: Skipping 6218 bytes
>>> [pulseaudio] module.c: Loaded "module-loopback" (index: #42; argument: "source="bluez_source.CC_C3_EA_0A_15_90" source_dont_move="true" sink_input_properties="media.role=phone"").
>>> [pulseaudio] module-loopback.c: Loopback overall latency is 353.36 ms + 2.50 ms + 4.62 ms = 360.47 ms
>>> [pulseaudio] module-loopback.c: Should buffer 96 bytes, buffered at minimum 0 bytes
>>> .
>>> .
>>> [pulseaudio] module-loopback.c: Loopback overall latency is 854.23 ms + 13.00 ms + 16.09 ms = 883.32 ms
>>> [pulseaudio] module-loopback.c: Should buffer 96 bytes, buffered at minimum 0 bytes
>>> [pulseaudio] module-loopback.c: [bluez_sink.CC_C3_EA_0A_15_90] Updated sampling rate to 8000 Hz.
>>> [alsa-sink-HiFi wm8962-0] module-loopback.c: Max request changed
>>> [alsa-sink-HiFi wm8962-0] module-loopback.c: Max request changed
>>>
>> The loopback modules should provide messages every 10 seconds. There should also be messages like
>> [pulseaudio] module-loopback.c: [bluez_sink.CC_C3_EA_0A_15_90] Updated sampling rate to 8000 Hz
>> for the other loopback.
> Yes, such messages are there.
>
>> There you can see what sink is used for the second loopback. Underruns or "cannot peek into queue" messages should only occur at the startup of the modules but not during normal operation. Could you post the relevant parts of your log?
> This part looks suspicious,
>
> D: [pulseaudio] module-loopback.c: Should buffer 96 bytes, buffered at minimum 48 bytes
> D: [pulseaudio] module-loopback.c: [bluez_sink.CC_C3_EA_0A_17_97] Updated sampling rate to 8000 Hz.
> I: [bluetooth] module-bluez5-device.c: FD error: POLLERR POLLHUP
> D: [bluetooth] module-bluez5-device.c: Audio stream torn down
> D: [pulseaudio] bluez5-util.c: Transport /card_1 state changed from playing to idle
> D: [pulseaudio] card.c: Setting card bluez_card.CC_C3_EA_0A_17_97 profile headset_audio_gateway to availability status unknown
> D: [pulseaudio] module-bluetooth-policy.c: Setting card 'bluez_card.CC_C3_EA_0A_17_97' to profile 'off'
> D: [pulseaudio] module-rescue-streams.c: No evacuation sink found.
> I: [pulseaudio] source-output.c: Freeing output 7 "Peak detect"
> D: [bluetooth] sink.c: Requesting rewind due to started move
>
>
> the complete log is pated @ http://pastebin.com/cddrcAxb
>
Looking at the log it seems like there is no data coming from the bluez
sink. Is there anything
in the bluetoothd log? I've also seen that you load module-role-cork.
Perhaps you should not
use it at the moment, it might interfere if the stream does not have the
correct role set.
Jomon John
2016-06-09 16:59:52 UTC
Permalink
Hi,

>>>>> What does pacmd list-cards show? Is the bluez device listed there?
>>>> Yes, the bluez device is listed in the output,
>>>>
>>>>          index: 1
>>>>          name: <bluez_card.CC_C3_EA_0A_15_90>
>>>>          driver: <module-bluez5-device.c>
>>>>          owner module: 24
>>>>          properties:
>>>>                  device.description = "Jo XT1033"
>>>>                  device.string = "CC:C3:EA:0A:17:97"
>>>>                  device.api = "bluez"
>>>>                  device.class = "sound"
>>>>                  device.bus = "bluetooth"
>>>>                  device.form_factor = "phone"
>>>>                  bluez.path = "/org/bluez/hci0/dev_CC_C3_EA_0A_15_90"
>>>>                  bluez.class = "0x5a020c"
>>>>                  bluez.alias = "Jo_XT1033"
>>>>                  device.icon_name = "audio-card-bluetooth"
>>>>          profiles:
>>>>                  a2dp_source: High Fidelity Capture (A2DP Source) (priority 10, available: unknown)
>>>>                  headset_audio_gateway: Headset Audio Gateway (HSP/HFP) (priority 20, available: no)
>>>>                  off: Off (priority 0, available: yes)
>>>>          active profile: <a2dp_source>
>>>>          sources:
>>>>                  bluez_source.CC_C3_EA_0A_15_90/#2: Jo XT1033
>>>>          ports:
>>>>                  phone-output: Phone (priority 0, latency offset 0 usec, available: no)
>>>>                          properties:
>>>>                                 
>>>>                  phone-input: Phone (priority 0, latency offset 0 usec, available: unknown)
>>>>                          properties:

Now again 'pacmd list-cards' and other list commands doesn't shows the bluez source/sink in outputs during A2DP or HFP session, looks like something weired happening.
                  
>>>> Can you check (with pavucontrol or in the logs) if the loopback from the phone goes to the correct sink?
>>>> As per the level changes shown in pavucontrol the audio from the other end of the phone reaching the bluez source, but level changes are not shown in the default sink, so i assume that the routing doesn't work between bluez source to default sink, also i  didnt find much info about this on logs, what should i look for ?
>>>>
>>>>> Do you see messages in the
>>>>> pulseaudio debug log from both loopback modules?
>>>> yes, Other than the module load messages i didn't find much (oh sure, discarding all the "Could not peek into queue" and "Requesting rewind due to end of underrun" )
>>>>
>>>>          [pulseaudio] module.c: Loaded "module-loopback" (index: #41; argument: "sink="bluez_sink.CC_C3_EA_0A_15_90" sink_dont_move="true" source_output_properties="media.role=phone"").
>>>>          [bluetooth] module-loopback.c: Max request changed
>>>>          [bluetooth] module-loopback.c: Skipping 6218 bytes
>>>>          [pulseaudio] module.c: Loaded "module-loopback" (index: #42; argument: "source="bluez_source.CC_C3_EA_0A_15_90" source_dont_move="true" sink_input_properties="media.role=phone"").
>>>>          [pulseaudio] module-loopback.c: Loopback overall latency is 353.36 ms + 2.50 ms + 4.62 ms = 360.47 ms
>>>>          [pulseaudio] module-loopback.c: Should buffer 96 bytes, buffered at minimum 0 bytes
>>>>          .
>>>>          .
>>>>          [pulseaudio] module-loopback.c: Loopback overall latency is 854.23 ms + 13.00 ms + 16.09 ms = 883.32 ms
>>>>          [pulseaudio] module-loopback.c: Should buffer 96 bytes, buffered at minimum 0 bytes
>>>>          [pulseaudio] module-loopback.c: [bluez_sink.CC_C3_EA_0A_15_90] Updated sampling rate to 8000 Hz.
>>>>          [alsa-sink-HiFi wm8962-0] module-loopback.c: Max request changed
>>>>          [alsa-sink-HiFi wm8962-0] module-loopback.c: Max request changed
>>>>
>>> The loopback modules should provide messages every 10 seconds. There should also be messages like
>>> [pulseaudio] module-loopback.c: [bluez_sink.CC_C3_EA_0A_15_90] Updated sampling rate to 8000 Hz
>>> for the other loopback.
>> Yes, such messages are there.
>>
>>> There you can see what sink is used for the second loopback. Underruns or "cannot peek into queue" messages should only occur at the startup of the modules but not during normal operation. Could you post the relevant parts of your log?
>> This part looks suspicious,
>>
>>        D: [pulseaudio] module-loopback.c: Should buffer 96 bytes, buffered at minimum 48 bytes
>>        D: [pulseaudio] module-loopback.c: [bluez_sink.CC_C3_EA_0A_17_97] Updated sampling rate to 8000 Hz.
>>        I: [bluetooth] module-bluez5-device.c: FD error: POLLERR POLLHUP
>>        D: [bluetooth] module-bluez5-device.c: Audio stream torn down
>>        D: [pulseaudio] bluez5-util.c: Transport /card_1 state changed from playing to idle
>>        D: [pulseaudio] card.c: Setting card bluez_card.CC_C3_EA_0A_17_97 profile headset_audio_gateway to availability status unknown
>>        D: [pulseaudio] module-bluetooth-policy.c: Setting card 'bluez_card.CC_C3_EA_0A_17_97' to profile 'off'
>>        D: [pulseaudio] module-rescue-streams.c: No evacuation sink found.
>>        I: [pulseaudio] source-output.c: Freeing output 7 "Peak detect"
>>        D: [bluetooth] sink.c: Requesting rewind due to started move
>>
>>
>> the complete log is pated @ http://pastebin.com/cddrcAxb
>>
> Looking at the log it seems like there is no data coming from the bluez sink.

How did you identified this ?, could you please point the associated error message.

> Is there anything in the bluetoothd log?

I didn't found anything fishy, the full bluetoothd log is pated @ http://pastebin.com/5MXugskH

> I've also seen that you load module-role-cork. Perhaps you should not
> use it at the moment, it might interfere if the stream does not have the correct role set.

Thank you, removed this.

Finally a clarification question regarding bluez_sink and bluez_source, the input from default source (mic) goes to bluez_sink and output from bluez_source routed to default sink(headphone/speaker), hence the name sink input ans source output, is this right ?
Georg Chini
2016-06-09 19:37:18 UTC
Permalink
On 09.06.2016 18:59, Jomon John wrote:
> Hi,
>
>>>>>> What does pacmd list-cards show? Is the bluez device listed there?
>>>>> Yes, the bluez device is listed in the output,
>>>>>
>>>>> index: 1
>>>>> name: <bluez_card.CC_C3_EA_0A_15_90>
>>>>> driver: <module-bluez5-device.c>
>>>>> owner module: 24
>>>>> properties:
>>>>> device.description = "Jo XT1033"
>>>>> device.string = "CC:C3:EA:0A:17:97"
>>>>> device.api = "bluez"
>>>>> device.class = "sound"
>>>>> device.bus = "bluetooth"
>>>>> device.form_factor = "phone"
>>>>> bluez.path = "/org/bluez/hci0/dev_CC_C3_EA_0A_15_90"
>>>>> bluez.class = "0x5a020c"
>>>>> bluez.alias = "Jo_XT1033"
>>>>> device.icon_name = "audio-card-bluetooth"
>>>>> profiles:
>>>>> a2dp_source: High Fidelity Capture (A2DP Source) (priority 10, available: unknown)
>>>>> headset_audio_gateway: Headset Audio Gateway (HSP/HFP) (priority 20, available: no)
>>>>> off: Off (priority 0, available: yes)
>>>>> active profile: <a2dp_source>
>>>>> sources:
>>>>> bluez_source.CC_C3_EA_0A_15_90/#2: Jo XT1033
>>>>> ports:
>>>>> phone-output: Phone (priority 0, latency offset 0 usec, available: no)
>>>>> properties:
>>>>>
>>>>> phone-input: Phone (priority 0, latency offset 0 usec, available: unknown)
>>>>> properties:
> Now again 'pacmd list-cards' and other list commands doesn't shows the bluez source/sink in outputs during A2DP or HFP session, looks like something weired happening.

Mh, this is really strange. I have no idea. Do I understand right that
you can sometimes see them and sometimes not?
Have you tried a recent pulseaudio version?

>
>>>>> Can you check (with pavucontrol or in the logs) if the loopback from the phone goes to the correct sink?
>>>>> As per the level changes shown in pavucontrol the audio from the other end of the phone reaching the bluez source, but level changes are not shown in the default sink, so i assume that the routing doesn't work between bluez source to default sink, also i didnt find much info about this on logs, what should i look for ?
>>>>>
>>>>>> Do you see messages in the
>>>>>> pulseaudio debug log from both loopback modules?
>>>>> yes, Other than the module load messages i didn't find much (oh sure, discarding all the "Could not peek into queue" and "Requesting rewind due to end of underrun" )
>>>>>
>>>>> [pulseaudio] module.c: Loaded "module-loopback" (index: #41; argument: "sink="bluez_sink.CC_C3_EA_0A_15_90" sink_dont_move="true" source_output_properties="media.role=phone"").
>>>>> [bluetooth] module-loopback.c: Max request changed
>>>>> [bluetooth] module-loopback.c: Skipping 6218 bytes
>>>>> [pulseaudio] module.c: Loaded "module-loopback" (index: #42; argument: "source="bluez_source.CC_C3_EA_0A_15_90" source_dont_move="true" sink_input_properties="media.role=phone"").
>>>>> [pulseaudio] module-loopback.c: Loopback overall latency is 353.36 ms + 2.50 ms + 4.62 ms = 360.47 ms
>>>>> [pulseaudio] module-loopback.c: Should buffer 96 bytes, buffered at minimum 0 bytes
>>>>> .
>>>>> .
>>>>> [pulseaudio] module-loopback.c: Loopback overall latency is 854.23 ms + 13.00 ms + 16.09 ms = 883.32 ms
>>>>> [pulseaudio] module-loopback.c: Should buffer 96 bytes, buffered at minimum 0 bytes
>>>>> [pulseaudio] module-loopback.c: [bluez_sink.CC_C3_EA_0A_15_90] Updated sampling rate to 8000 Hz.
>>>>> [alsa-sink-HiFi wm8962-0] module-loopback.c: Max request changed
>>>>> [alsa-sink-HiFi wm8962-0] module-loopback.c: Max request changed
>>>>>
>>>> The loopback modules should provide messages every 10 seconds. There should also be messages like
>>>> [pulseaudio] module-loopback.c: [bluez_sink.CC_C3_EA_0A_15_90] Updated sampling rate to 8000 Hz
>>>> for the other loopback.
>>> Yes, such messages are there.
>>>
>>>> There you can see what sink is used for the second loopback. Underruns or "cannot peek into queue" messages should only occur at the startup of the modules but not during normal operation. Could you post the relevant parts of your log?
>>> This part looks suspicious,
>>>
>>> D: [pulseaudio] module-loopback.c: Should buffer 96 bytes, buffered at minimum 48 bytes
>>> D: [pulseaudio] module-loopback.c: [bluez_sink.CC_C3_EA_0A_17_97] Updated sampling rate to 8000 Hz.
>>> I: [bluetooth] module-bluez5-device.c: FD error: POLLERR POLLHUP
>>> D: [bluetooth] module-bluez5-device.c: Audio stream torn down
>>> D: [pulseaudio] bluez5-util.c: Transport /card_1 state changed from playing to idle
>>> D: [pulseaudio] card.c: Setting card bluez_card.CC_C3_EA_0A_17_97 profile headset_audio_gateway to availability status unknown
>>> D: [pulseaudio] module-bluetooth-policy.c: Setting card 'bluez_card.CC_C3_EA_0A_17_97' to profile 'off'
>>> D: [pulseaudio] module-rescue-streams.c: No evacuation sink found.
>>> I: [pulseaudio] source-output.c: Freeing output 7 "Peak detect"
>>> D: [bluetooth] sink.c: Requesting rewind due to started move
>>>
>>>
>>> the complete log is pated @ http://pastebin.com/cddrcAxb
>>>
>> Looking at the log it seems like there is no data coming from the bluez sink.
> How did you identified this ?, could you please point the associated error message.

It is rather the absence of messages in the log. You only get regular
reports from one
loopback module. The fact that the messages from the second loopback are
missing
shows that this module is hanging somehow. I have seen this, when the
module does
not receive data, but there may also be another cause for it.

>
>> Is there anything in the bluetoothd log?
> I didn't found anything fishy, the full bluetoothd log is pated @ http://pastebin.com/5MXugskH
>
>> I've also seen that you load module-role-cork. Perhaps you should not
>> use it at the moment, it might interfere if the stream does not have the correct role set.
> Thank you, removed this.
>
> Finally a clarification question regarding bluez_sink and bluez_source, the input from default source (mic) goes to bluez_sink and output from bluez_source routed to default sink(headphone/speaker), hence the name sink input ans source output, is this right ?
>
Personally I find the names "sink input" and "source output" somewhat
confusing. The source output
is the connector of a stream to the source and the sink input the
connector to the sink.
Since a sink can play back multiple streams at the same time, multiple
sink inputs can be connected
to one sink. Likewise the signal of a source can go to multiple
destinations, so a source can be connected
to multiple source outputs.
In your case you have:

bluez_source -> (source_output_1 -> loopback_1 -> sink_input_1) .->
default_sink

and

PC mic -> (source_output_2 -> loopback_2 -> sink_input_2) -> bluez_sink

where the parts within the brackets all belong to module-loopback.
Loading...