[pulseaudio-discuss] pulseaudio fails to work with bluez5 (SCO/eSCO)

[Tanu Kaskinen]

On Thu, 2015-05-14 at 12:24 +0800, 江城 wrote:
> Hi,
> 
> I am trying to bring up bluez5+ofono(1.16)+pulseauido 6.0 on freescale IMX6
> platform. Currently the A2DP works well, but SCO and eSCO failed. following
> is the log. Does anybody know how to fix it.Thanks.

I don't know how to fix it. I can give some debugging hints, though.

> D: [pulseaudio] module-loopback.c: Loopback overall latency is 670.25 ms +
> 680.00 ms + 938869680559.28 ms = 938869681909.53 ms

How to interpret this: the first number is the sink latency snapshot,
the second number is the amount of data buffered internally in
module-loopback, and the third number is the source latency snapshot.

Something went wrong here, the source latency snapshot is bogus. I don't
know if that's the bluetooth source or the alsa source (I wish the log
message would say which loopback instance this is), and I don't know if
that's a bug in pulseaudio or did the kernel report a bogus latency
value (if the value came from the kernel, then it's the alsa source,
because we don't get latency information from the kernel for bluetooth).

The remote device closes the connection later. That may or may not be
related to this bogus latency issue.

> D: [pulseaudio] module-loopback.c: Should buffer 96 bytes, buffered at
> minimum 640 bytes
> I: [pulseaudio] module-loopback.c: New rate of 8027 Hz not within 2â<80>°
> of 8000 Hz, forcing smaller adjustment
> D: [pulseaudio] module-loopback.c: [bluez_sink.B4_F0_AB_94_E0_FB] Updated
> sampling rate to 8016 Hz.
> D: [pulseaudio] module-loopback.c: Loopback overall latency is 0.00 ms +
> 0.00 ms + 25.00 ms = 25.00 ms
> D: [pulseaudio] module-loopback.c: Should buffer 2136 bytes, buffered at
> minimum 0 bytes
> I: [pulseaudio] module-loopback.c: New rate of 7894 Hz not within 2â<80>°
> of 8000 Hz, forcing smaller adjustment
> D: [pulseaudio] module-loopback.c: [alsa_output.default] Updated sampling
> rate to 7984 Hz.
> D: [bluetooth] module-loopback.c: Requesting rewind due to end of underrun.
> I: [alsa-sink-HiFi CS42888-0] module-loopback.c: Could not peek into queue
> D: [bluetooth] module-loopback.c: Requesting rewind due to end of underrun.
> I: [alsa-sink-HiFi CS42888-0] alsa-sink.c: Underrun!
> D: [bluetooth] module-loopback.c: Requesting rewind due to end of underrun.
> I: [alsa-sink-HiFi CS42888-0] alsa-sink.c: Increasing wakeup watermark to
> 30.00 ms
> D: [bluetooth] module-loopback.c: Requesting rewind due to end of underrun.
> I: [alsa-sink-HiFi CS42888-0] module-loopback.c: Could not peek into queue
> D: [bluetooth] module-loopback.c: Requesting rewind due to end of underrun.
> D: [bluetooth] module-loopback.c: Requesting rewind due to end of underrun.
> I: [alsa-sink-HiFi CS42888-0] module-loopback.c: Could not peek into queue
> D: [bluetooth] module-loopback.c: Requesting rewind due to end of underrun.
> D: [bluetooth] module-loopback.c: Requesting rewind due to end of underrun.
> D: [bluetooth] module-loopback.c: Requesting rewind due to end of underrun.
> D: [bluetooth] module-loopback.c: Requesting rewind due to end of underrun.
> D: [bluetooth] module-loopback.c: Requesting rewind due to end of underrun.
> D: [pulseaudio] module-loopback.c: Loopback overall latency is 0.00 ms +
> 0.00 ms + 25.00 ms = 25.00 ms
> D: [pulseaudio] module-loopback.c: Should buffer 2132 bytes, buffered at
> minimum 0 bytes
> I: [pulseaudio] module-loopback.c: New rate of 7894 Hz not within 2â<80>°
> of 7984 Hz, forcing smaller adjustment
> D: [pulseaudio] core-subscribe.c: Dropped redundant event due to change
> event.
> D: [pulseaudio] module-loopback.c: [alsa_output.default] Updated sampling
> rate to 7968 Hz.
> I: [alsa-sink-HiFi CS42888-0] module-loopback.c: Could not peek into queue
> D: [bluetooth] module-loopback.c: Requesting rewind due to end of underrun.
> I: [alsa-sink-HiFi CS42888-0] module-loopback.c: Could not peek into queue
> D: [bluetooth] module-loopback.c: Requesting rewind due to end of underrun.
> I: [alsa-sink-HiFi CS42888-0] module-loopback.c: Could not peek into queue
> D: [bluetooth] module-loopback.c: Requesting rewind due to end of underrun.
> I: [alsa-sink-HiFi CS42888-0] module-loopback.c: Could not peek into queue
> D: [bluetooth] module-loopback.c: Requesting rewind due to end of underrun.
> I: [alsa-sink-HiFi CS42888-0] module-loopback.c: Could not peek into queue
> D: [bluetooth] module-loopback.c: Requesting rewind due to end of underrun.
> I: [alsa-sink-HiFi CS42888-0] module-loopback.c: Could not peek into queue
> D: [bluetooth] module-loopback.c: Requesting rewind due to end of underrun.
> I: [alsa-sink-HiFi CS42888-0] module-loopback.c: Could not peek into queue
> D: [bluetooth] module-loopback.c: Requesting rewind due to end of underrun.
> I: [alsa-sink-HiFi CS42888-0] module-loopback.c: Could not peek into queue
> D: [bluetooth] module-loopback.c: Requesting rewind due to end of underrun.
> I: [alsa-sink-HiFi CS42888-0] module-loopback.c: Could not peek into queue
> I: [alsa-sink-HiFi CS42888-0] module-loopback.c: Could not peek into queue
> D: [bluetooth] module-loopback.c: Requesting rewind due to end of underrun.
> I: [alsa-sink-HiFi CS42888-0] module-loopback.c: Could not peek into queue
> D: [bluetooth] module-loopback.c: Requesting rewind due to end of underrun.
> I: [alsa-sink-HiFi CS42888-0] module-loopback.c: Could not peek into queue
> D: [bluetooth] module-loopback.c: Requesting rewind due to end of underrun.
> I: [alsa-sink-HiFi CS42888-0] module-loopback.c: Could not peek into queue
> D: [bluetooth] module-loopback.c: Requesting rewind due to end of underrun.
> I: [bluetooth] module-bluez5-device.c: FD error: POLLERR POLLHUP
> D: [bluetooth] module-bluez5-device.c: Audio stream torn down

Here we see that the remote device closed the audio connection. I don't
know why it did that.

-- 
Tanu