[pulseaudio-discuss] RAOP2 trouble with Logitech UE Air Speaker

Toby Haynes tjwhaynes at gmail.com
Tue Apr 15 19:58:07 PDT 2014


I''ve collected network traffic between my Fedora 20 laptop (192.168.1.109)
and the Logitech UE Air Speaker (192.168.1.103) using

tshark -p -i wlp3s0 -w logitech-ue.pcap host 192.168.1.103

I've also included the output log from pulseaudio-raop2. The two files can
be downloaded using the following links (you should not need to sign into
Google to get them).

https://drive.google.com/file/d/0B6e6VZu2JQS-Q2NhVFVBVDFqeTg/edit?usp=sharing
https://drive.google.com/file/d/0B6e6VZu2JQS-TWxSVTdpZFdrYU0/edit?usp=sharing

The capture begins before the pulseaudio-raop2 code is started and covers
starting QuodLibet, ensuring that QuodLibet is using the Logitech sink and
clicking Play in QuodLibet. I'm happy to perform experiments, hack on the
code and use a debugger to step through code/memory.

I really appreciate any help,

Thanks,
Toby Haynes


On Tue, Apr 15, 2014 at 3:15 PM, Martin Blanchard <tchaik at gmx.com> wrote:

> Hello Toby,
>
> From what I can read here, the server is responding with '500 Internal
> Server Error' to the rtsp RECORD request sent by pulseaudio. We may find
> quite a lot of reasons to this, and I'm afraid pulseaudio's log won't be
> enough to debug the issue...
>
> Is it possible to you to dump the network traffic down to a file while
> this is happening ? You can use WireShark [1] for example, available in
> fedora repos. The dump will hopefully help identify the problem...
>
> Thanks,
> Martin
>
> [1] http://www.wireshark.org
>
> On Mon, 2014-04-14 at 22:09 -0400, Toby Haynes wrote:
> > I've been trying to get my Logitech UE Air Speaker to receive audio
> > from either of my Fedora 20 or Ubuntu 13.10 installations (both
> > 64bit). The speaker works reasonably with the android app Streambels
> > so I know it is properly associated with the network and functional.
> >
> >
> > I've compiled the latest git repository from
> > hfujita.github.io/pulseaudio-raop2/ and run the newly built
> > pulseaudio
> >
> > ./src/pulseaudio -n -F src/default.pa -p $(pwd)/src/ --log-time=1
> > -vvvv 2>&1 | tee pulse.log
> >
> >
> > I can see the Logitech UE Air Speaker in the list of devices from
> > pavucontol and I can select it for the Quod Libet music player.
> > Attempting to start playing a song gets:
> >
> > ( 333.067| 125.120) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > ( 333.067|   0.000) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > ( 333.067|   0.000) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > ( 333.068|   0.000) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > ( 333.068|   0.000) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > ( 333.068|   0.000) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > ( 333.068|   0.000) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > ( 333.068|   0.000) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > ( 333.068|   0.000) D: [raop-sink] sink-input.c: Requesting rewind due
> > to uncorking
> > ( 333.068|   0.000) D: [lt-pulseaudio] module-suspend-on-idle.c: Sink
> > raop_output.Logitech-UE-Air-Speaker-39DB34.local becomes busy,
> > resuming.
> > ( 333.068|   0.000) D: [raop-sink] module-raop-sink.c: RAOP: RUNNING
> > ( 333.068|   0.000) D: [raop-sink] rtsp_client.c: Attempting to
> > connect to server '192.168.1.102:1167'
> > ( 333.070|   0.001) D: [lt-pulseaudio] rtsp_client.c: Established RTSP
> > connection from local ip 192.168.1.109
> > ( 333.070|   0.000) D: [lt-pulseaudio] rtsp_client.c: Sending command:
> > OPTIONS
> > ( 333.073|   0.003) D: [lt-pulseaudio] rtsp_client.c: Full response
> > received. Dispatching
> > ( 333.073|   0.000) D: [lt-pulseaudio] raop_client.c: RAOP: OPTIONS
> > ( 333.074|   0.000) D: [lt-pulseaudio] rtsp_client.c: Sending command:
> > ANNOUNCE
> > ( 333.078|   0.004) D: [lt-pulseaudio] rtsp_client.c: Full response
> > received. Dispatching
> > ( 333.078|   0.000) D: [lt-pulseaudio] raop_client.c: Socket bound to
> > port 6001 (SOCK_DGRAM)
> > ( 333.078|   0.000) D: [lt-pulseaudio] raop_client.c: Socket bound to
> > port 6002 (SOCK_DGRAM)
> > ( 333.078|   0.000) D: [lt-pulseaudio] rtsp_client.c: Sending command:
> > SETUP
> > ( 334.075|   0.996) D: [lt-pulseaudio] rtsp_client.c: Full response
> > received. Dispatching
> > ( 334.075|   0.000) D: [lt-pulseaudio] raop_client.c: RAOP: SETUP
> > ( 334.075|   0.000) D: [lt-pulseaudio] raop_client.c: Using
> > server_port=1324, control_port=1325 & timing_port=1326
> > ( 334.075|   0.000) D: [lt-pulseaudio] raop_client.c: Connected to
> > 192.168.1.102 on port 1324 (SOCK_DGRAM)
> > ( 334.075|   0.000) D: [lt-pulseaudio] raop_client.c: Connected to
> > 192.168.1.102 on port 1325 (SOCK_DGRAM)
> > ( 334.075|   0.000) D: [lt-pulseaudio] raop_client.c: Connected to
> > 192.168.1.102 on port 1326 (SOCK_DGRAM)
> > ( 334.075|   0.000) D: [lt-pulseaudio] module-raop-sink.c: Connection
> > authenticated, syncing with server...
> > ( 334.075|   0.000) D: [lt-pulseaudio] rtsp_client.c: Sending command:
> > RECORD
> > ( 335.582|   1.506) W: [lt-pulseaudio] rtsp_client.c: Unexpected
> > response: RTSP/1.0 500 Internal Server Error
> > ( 335.582|   0.000) W: [lt-pulseaudio] rtsp_client.c: Unexpected
> > response: Server: AirTunes/103.2
> > ( 335.582|   0.000) W: [lt-pulseaudio] rtsp_client.c: Unexpected
> > response: CSeq: 4
> > ( 335.582|   0.000) W: [lt-pulseaudio] rtsp_client.c: Unexpected
> > response:
> >
> >
> > and the song stays at position 0.00. Pausing the song gets
> >
> > ( 970.603| 635.021) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > ( 970.603|   0.000) D: [raop-sink] sink-input.c: Requesting rewind due
> > to corking
> > ( 970.603|   0.000) D: [raop-sink] module-raop-sink.c: RAOP: IDLE
> > ( 970.603|   0.000) D: [raop-sink] rtsp_client.c: Sending command:
> > FLUSH
> > ( 970.603|   0.000) D: [lt-pulseaudio] module-suspend-on-idle.c: Sink
> > raop_output.Logitech-UE-Air-Speaker-39DB34.local becomes idle, timeout
> > in 5 seconds.
> > ( 971.447|   0.844) W: [lt-pulseaudio] rtsp_client.c: Unexpected
> > response: RTSP/1.0 455 Method Not Valid In This State
> > ( 971.447|   0.000) W: [lt-pulseaudio] rtsp_client.c: Unexpected
> > response: Server: AirTunes/103.2
> > ( 971.447|   0.000) W: [lt-pulseaudio] rtsp_client.c: Unexpected
> > response: CSeq: 5
> > ( 971.447|   0.000) W: [lt-pulseaudio] rtsp_client.c: Unexpected
> > response:
> > ( 975.604|   4.156) I: [lt-pulseaudio] module-suspend-on-idle.c: Sink
> > raop_output.Logitech-UE-Air-Speaker-39DB34.local idle for too long,
> > suspending ...
> > ( 975.604|   0.000) D: [lt-pulseaudio] sink.c: Suspend cause of sink
> > raop_output.Logitech-UE-Air-Speaker-39DB34.local is 0x0004, suspending
> > ( 975.604|   0.000) D: [raop-sink] module-raop-sink.c: RAOP: SUSPENDED
> > ( 975.604|   0.000) D: [raop-sink] rtsp_client.c: Sending command:
> > TEARDOWN
> > ( 975.604|   0.000) I: [lt-pulseaudio] core.c: All sinks and sources
> > are suspended, vacuuming memory
> > ( 975.617|   0.012) D: [lt-pulseaudio] rtsp_client.c: Full response
> > received. Dispatching
> > ( 975.617|   0.000) D: [lt-pulseaudio] raop_client.c: RAOP: TEARDOWN
> > ( 975.617|   0.000) D: [lt-pulseaudio] raop_client.c: RTSP control
> > channel closed (teardown)
> > ( 975.617|   0.000) D: [lt-pulseaudio] module-raop-sink.c: Connection
> > closed, informing IO thread...
> >
> >
> > Attempting to play again gets the same issue.
> >
> >
> > Double clicking on a new track however looks like it is actually
> > workin - however, no sound is heard from the Air Speaker. Manually
> > adjusting the volume on the speaker has no impact.
> >
> > (1010.990|   7.400) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > (1010.990|   0.000) D: [raop-sink] sink-input.c: Requesting rewind due
> > to corking
> > (1010.990|   0.000) D: [raop-sink] module-raop-sink.c: RAOP: IDLE
> > (1010.990|   0.000) D: [raop-sink] rtsp_client.c: Sending command:
> > FLUSH
> > (1010.990|   0.000) D: [lt-pulseaudio] module-suspend-on-idle.c: Sink
> > raop_output.Logitech-UE-Air-Speaker-39DB34.local becomes idle, timeout
> > in 5 seconds.
> > (1010.991|   0.001) D: [lt-pulseaudio] module-raop-sink.c: Volume
> > adjusted: orig=99957 adjusted=89072
> > (1010.991|   0.000) D: [lt-pulseaudio] module-raop-sink.c: Requested
> > volume: front-left: 99957 / 153%,   front-right: 99957 / 153%
> > (1010.991|   0.000) D: [lt-pulseaudio] module-raop-sink.c: Got
> > hardware volume: front-left: 89072 / 136%,   front-right: 89072 / 136%
> > (1010.991|   0.000) D: [lt-pulseaudio] module-raop-sink.c: Calculated
> > software volume: front-left: 65536 / 100% / 0.00 dB,   front-right:
> > 65536 / 100% / 0.00 dB
> > (1010.991|   0.000) D: [lt-pulseaudio] raop_client.c: volume=89072
> > db=0.000000
> > (1010.991|   0.000) D: [lt-pulseaudio] rtsp_client.c: Sending command:
> > SET_PARAMETER
> > (1010.991|   0.000) D: [lt-pulseaudio] module-suspend-on-idle.c: Sink
> > raop_output.Logitech-UE-Air-Speaker-39DB34.local becomes idle, timeout
> > in 5 seconds.
> > (1010.991|   0.000) D: [lt-pulseaudio] core.c: Hmm, no streams around,
> > trying to vacuum.
> > (1010.991|   0.000) I: [lt-pulseaudio] sink-input.c: Freeing input 1
> > "'Shame for You' by 'Lily Allen'"
> > (1010.991|   0.000) I: [lt-pulseaudio] client.c: Freed 3 "Quod Libet"
> > (1010.991|   0.000) I: [lt-pulseaudio] protocol-native.c: Connection
> > died.
> > (1010.994|   0.002) W: [lt-pulseaudio] rtsp_client.c: Unexpected
> > response: RTSP/1.0 455 Method Not Valid In This State
> > (1010.994|   0.000) W: [lt-pulseaudio] rtsp_client.c: Unexpected
> > response: Server: AirTunes/103.2
> > (1010.994|   0.000) W: [lt-pulseaudio] rtsp_client.c: Unexpected
> > response: CSeq: 5
> > (1010.994|   0.000) W: [lt-pulseaudio] rtsp_client.c: Unexpected
> > response:
> > (1010.997|   0.002) I: [lt-pulseaudio] client.c: Created 4 "Native
> > client (UNIX socket client)"
> > (1010.997|   0.000) D: [lt-pulseaudio] protocol-native.c: Protocol
> > version: remote 29, local 29
> > (1010.997|   0.000) I: [lt-pulseaudio] protocol-native.c: Got
> > credentials: uid=1000 gid=1000 success=1
> > (1010.997|   0.000) D: [lt-pulseaudio] protocol-native.c: SHM
> > possible: yes
> > (1010.997|   0.000) D: [lt-pulseaudio] protocol-native.c: Negotiated
> > SHM: yes
> > (1010.997|   0.000) D: [lt-pulseaudio] module-augment-properties.c:
> > Looking for .desktop file for python2.7
> > (1010.998|   0.001) D: [lt-pulseaudio] rtsp_client.c: Full response
> > received. Dispatching
> > (1010.998|   0.000) D: [lt-pulseaudio] raop_client.c: RAOP:
> > SET_PARAMETER
> > (1011.076|   0.077) I: [lt-pulseaudio] module-stream-restore.c:
> > Restoring device for stream sink-input-by-media-role:music.
> > (1011.076|   0.000) D: [lt-pulseaudio] module-intended-roles.c: Not
> > setting device for stream pulsesink probe, because already set.
> > (1011.076|   0.000) D: [lt-pulseaudio] sink-input.c: Negotiated
> > format: pcm, format.sample_format = "\"s16le\""  format.rate = "44100"
> > format.channels = "2"
> > (1011.076|   0.000) I: [lt-pulseaudio] module-stream-restore.c:
> > Restoring volume for sink input sink-input-by-media-role:music.
> > (1011.076|   0.000) I: [lt-pulseaudio] module-stream-restore.c:
> > Restoring mute state for sink input sink-input-by-media-role:music.
> > (1011.076|   0.000) D: [lt-pulseaudio] module-suspend-on-idle.c: Sink
> > raop_output.Logitech-UE-Air-Speaker-39DB34.local becomes busy,
> > resuming.
> > (1011.076|   0.000) D: [lt-pulseaudio] memblockq.c: memblockq
> > requested: maxlength=33554432, tlength=0, base=4, prebuf=0, minreq=1
> > maxrewind=0
> > (1011.076|   0.000) D: [lt-pulseaudio] memblockq.c: memblockq
> > sanitized: maxlength=33554432, tlength=33554432, base=4, prebuf=0,
> > minreq=4 maxrewind=0
> > (1011.076|   0.000) I: [lt-pulseaudio] sink-input.c: Created input 2
> > "pulsesink probe" on raop_output.Logitech-UE-Air-Speaker-39DB34.local
> > with sample spec s16le 2ch 44100Hz and channel map
> > front-left,front-right
> > (1011.076|   0.000) I: [lt-pulseaudio] sink-input.c:     media.name =
> > "pulsesink probe"
> > (1011.076|   0.000) I: [lt-pulseaudio] sink-input.c:
> > application.name = "Quod Libet"
> > (1011.076|   0.000) I: [lt-pulseaudio] sink-input.c:
> > native-protocol.peer = "UNIX socket client"
> > (1011.076|   0.000) I: [lt-pulseaudio] sink-input.c:
> > native-protocol.version = "29"
> > (1011.076|   0.000) I: [lt-pulseaudio] sink-input.c:     media.role =
> > "music"
> > (1011.076|   0.000) I: [lt-pulseaudio] sink-input.c:
> > application.icon_name = "quodlibet"
> > (1011.076|   0.000) I: [lt-pulseaudio] sink-input.c:
> > application.process.id = "19885"
> > (1011.076|   0.000) I: [lt-pulseaudio] sink-input.c:
> > application.process.user = "thaynes"
> > (1011.076|   0.000) I: [lt-pulseaudio] sink-input.c:
> > application.process.host = "nexus6.torolab.ibm.com"
> > (1011.076|   0.000) I: [lt-pulseaudio] sink-input.c:
> > application.process.binary = "python2.7"
> > (1011.076|   0.000) I: [lt-pulseaudio] sink-input.c:
> > application.language = "en_US.utf8"
> > (1011.076|   0.000) I: [lt-pulseaudio] sink-input.c:
> > window.x11.display = ":0"
> > (1011.076|   0.000) I: [lt-pulseaudio] sink-input.c:
> > application.process.machine_id = "dd52b532d0cb43738efff1f3e90d00f2"
> > (1011.076|   0.000) I: [lt-pulseaudio] sink-input.c:
> > application.process.session_id = "4"
> > (1011.076|   0.000) I: [lt-pulseaudio] sink-input.c:
> > module-stream-restore.id = "sink-input-by-media-role:music"
> > (1011.076|   0.000) I: [lt-pulseaudio] protocol-native.c: Requested
> > tlength=272.11 ms, minreq=20.00 ms
> > (1011.076|   0.000) D: [lt-pulseaudio] protocol-native.c: Adjust
> > latency mode enabled, configuring sink latency to half of overall
> > latency.
> > (1011.076|   0.000) D: [lt-pulseaudio] protocol-native.c: Requested
> > latency=116.05 ms, Received latency=250.00 ms
> > (1011.076|   0.000) D: [lt-pulseaudio] memblockq.c: memblockq
> > requested: maxlength=4194304, tlength=51156, base=4, prebuf=47632,
> > minreq=3528 maxrewind=0
> > (1011.076|   0.000) D: [lt-pulseaudio] memblockq.c: memblockq
> > sanitized: maxlength=4194304, tlength=51156, base=4, prebuf=47632,
> > minreq=3528 maxrewind=0
> > (1011.076|   0.000) I: [lt-pulseaudio] protocol-native.c: Final
> > latency 540.00 ms = 250.00 ms + 2*20.00 ms + 250.00 ms
> > (1011.076|   0.000) D: [lt-pulseaudio] module-raop-sink.c: Volume
> > adjusted: orig=66683 adjusted=66320
> > (1011.076|   0.000) D: [lt-pulseaudio] module-raop-sink.c: Requested
> > volume: front-left: 66683 / 102%,   front-right: 66683 / 102%
> > (1011.076|   0.000) D: [lt-pulseaudio] module-raop-sink.c: Got
> > hardware volume: front-left: 66320 / 101%,   front-right: 66320 / 101%
> > (1011.076|   0.000) D: [lt-pulseaudio] module-raop-sink.c: Calculated
> > software volume: front-left: 65536 / 100% / 0.00 dB,   front-right:
> > 65536 / 100% / 0.00 dB
> > (1011.076|   0.000) D: [lt-pulseaudio] raop_client.c: volume=66320
> > db=0.000000
> > (1011.076|   0.000) D: [lt-pulseaudio] rtsp_client.c: Sending command:
> > SET_PARAMETER
> > (1011.080|   0.003) D: [lt-pulseaudio] rtsp_client.c: Full response
> > received. Dispatching
> > (1011.080|   0.000) D: [lt-pulseaudio] raop_client.c: RAOP:
> > SET_PARAMETER
> > (1011.217|   0.136) D: [lt-pulseaudio] module-raop-sink.c: Volume
> > adjusted: orig=99957 adjusted=89072
> > (1011.217|   0.000) D: [lt-pulseaudio] module-raop-sink.c: Requested
> > volume: front-left: 99957 / 153%,   front-right: 99957 / 153%
> > (1011.217|   0.000) D: [lt-pulseaudio] module-raop-sink.c: Got
> > hardware volume: front-left: 89072 / 136%,   front-right: 89072 / 136%
> > (1011.217|   0.000) D: [lt-pulseaudio] module-raop-sink.c: Calculated
> > software volume: front-left: 65536 / 100% / 0.00 dB,   front-right:
> > 65536 / 100% / 0.00 dB
> > (1011.217|   0.000) D: [lt-pulseaudio] raop_client.c: volume=89072
> > db=0.000000
> > (1011.217|   0.000) D: [lt-pulseaudio] rtsp_client.c: Sending command:
> > SET_PARAMETER
> > (1011.217|   0.000) D: [lt-pulseaudio] module-suspend-on-idle.c: Sink
> > raop_output.Logitech-UE-Air-Speaker-39DB34.local becomes idle, timeout
> > in 5 seconds.
> > (1011.217|   0.000) D: [lt-pulseaudio] core.c: Hmm, no streams around,
> > trying to vacuum.
> > (1011.218|   0.000) I: [lt-pulseaudio] sink-input.c: Freeing input 2
> > "pulsesink probe"
> > (1011.218|   0.000) I: [lt-pulseaudio] module-stream-restore.c:
> > Restoring device for stream sink-input-by-media-role:music.
> > (1011.218|   0.000) D: [lt-pulseaudio] module-intended-roles.c: Not
> > setting device for stream Playback Stream, because already set.
> > (1011.218|   0.000) D: [lt-pulseaudio] sink-input.c: Negotiated
> > format: pcm, format.sample_format = "\"s16le\""  format.channels = "2"
> > format.rate = "48000"  format.channel_map = "\"front-left,front-right
> > \""
> > (1011.218|   0.000) I: [lt-pulseaudio] sink-input.c: Trying to change
> > sample rate
> > (1011.218|   0.000) I: [lt-pulseaudio] module-stream-restore.c:
> > Restoring volume for sink input sink-input-by-media-role:music.
> > (1011.218|   0.000) I: [lt-pulseaudio] module-stream-restore.c:
> > Restoring mute state for sink input sink-input-by-media-role:music.
> > (1011.218|   0.000) D: [lt-pulseaudio] module-suspend-on-idle.c: Sink
> > raop_output.Logitech-UE-Air-Speaker-39DB34.local becomes busy,
> > resuming.
> > (1011.218|   0.000) I: [lt-pulseaudio] resampler.c: Using resampler
> > 'speex-float-1'
> > (1011.218|   0.000) I: [lt-pulseaudio] resampler.c: Using float32le as
> > working format.
> > (1011.218|   0.000) I: [lt-pulseaudio] resampler.c: Choosing speex
> > quality setting 1.
> > (1011.218|   0.000) D: [lt-pulseaudio] memblockq.c: memblockq
> > requested: maxlength=33554432, tlength=0, base=4, prebuf=0, minreq=1
> > maxrewind=0
> > (1011.218|   0.000) D: [lt-pulseaudio] memblockq.c: memblockq
> > sanitized: maxlength=33554432, tlength=33554432, base=4, prebuf=0,
> > minreq=4 maxrewind=0
> > (1011.218|   0.000) I: [lt-pulseaudio] sink-input.c: Created input 3
> > "Playback Stream" on raop_output.Logitech-UE-Air-Speaker-39DB34.local
> > with sample spec s16le 2ch 48000Hz and channel map
> > front-left,front-right
> > (1011.218|   0.000) I: [lt-pulseaudio] sink-input.c:     media.name =
> > "Playback Stream"
> > (1011.218|   0.000) I: [lt-pulseaudio] sink-input.c:
> > application.name = "Quod Libet"
> > (1011.218|   0.000) I: [lt-pulseaudio] sink-input.c:
> > native-protocol.peer = "UNIX socket client"
> > (1011.218|   0.000) I: [lt-pulseaudio] sink-input.c:
> > native-protocol.version = "29"
> > (1011.218|   0.000) I: [lt-pulseaudio] sink-input.c:     media.role =
> > "music"
> > (1011.218|   0.000) I: [lt-pulseaudio] sink-input.c:
> > application.icon_name = "quodlibet"
> > (1011.218|   0.000) I: [lt-pulseaudio] sink-input.c:
> > application.process.id = "19885"
> > (1011.218|   0.000) I: [lt-pulseaudio] sink-input.c:
> > application.process.user = "thaynes"
> > (1011.218|   0.000) I: [lt-pulseaudio] sink-input.c:
> > application.process.host = "nexus6.torolab.ibm.com"
> > (1011.218|   0.000) I: [lt-pulseaudio] sink-input.c:
> > application.process.binary = "python2.7"
> > (1011.218|   0.000) I: [lt-pulseaudio] sink-input.c:
> > application.language = "en_US.utf8"
> > (1011.218|   0.000) I: [lt-pulseaudio] sink-input.c:
> > window.x11.display = ":0"
> > (1011.218|   0.000) I: [lt-pulseaudio] sink-input.c:
> > application.process.machine_id = "dd52b532d0cb43738efff1f3e90d00f2"
> > (1011.218|   0.000) I: [lt-pulseaudio] sink-input.c:
> > application.process.session_id = "4"
> > (1011.218|   0.000) I: [lt-pulseaudio] sink-input.c:
> > module-stream-restore.id = "sink-input-by-media-role:music"
> > (1011.218|   0.000) I: [lt-pulseaudio] protocol-native.c: Requested
> > tlength=200.00 ms, minreq=10.00 ms
> > (1011.218|   0.000) D: [lt-pulseaudio] protocol-native.c: Adjust
> > latency mode enabled, configuring sink latency to half of overall
> > latency.
> > (1011.218|   0.000) D: [lt-pulseaudio] protocol-native.c: Requested
> > latency=90.00 ms, Received latency=250.00 ms
> > (1011.218|   0.000) D: [lt-pulseaudio] memblockq.c: memblockq
> > requested: maxlength=4194304, tlength=51840, base=4, prebuf=0,
> > minreq=1920 maxrewind=0
> > (1011.218|   0.000) D: [lt-pulseaudio] memblockq.c: memblockq
> > sanitized: maxlength=4194304, tlength=51840, base=4, prebuf=0,
> > minreq=1920 maxrewind=0
> > (1011.219|   0.000) I: [lt-pulseaudio] protocol-native.c: Final
> > latency 520.00 ms = 250.00 ms + 2*10.00 ms + 250.00 ms
> > (1011.219|   0.000) D: [lt-pulseaudio] module-raop-sink.c: Volume
> > adjusted: orig=66683 adjusted=66320
> > (1011.219|   0.000) D: [lt-pulseaudio] module-raop-sink.c: Requested
> > volume: front-left: 66683 / 102%,   front-right: 66683 / 102%
> > (1011.219|   0.000) D: [lt-pulseaudio] module-raop-sink.c: Got
> > hardware volume: front-left: 66320 / 101%,   front-right: 66320 / 101%
> > (1011.219|   0.000) D: [lt-pulseaudio] module-raop-sink.c: Calculated
> > software volume: front-left: 65536 / 100% / 0.00 dB,   front-right:
> > 65536 / 100% / 0.00 dB
> > (1011.219|   0.000) D: [lt-pulseaudio] raop_client.c: volume=66320
> > db=0.000000
> > (1011.219|   0.000) D: [lt-pulseaudio] rtsp_client.c: Sending command:
> > SET_PARAMETER
> > (1011.221|   0.002) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > (1011.221|   0.000) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > (1011.221|   0.000) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > (1011.221|   0.000) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > (1011.221|   0.000) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > (1011.222|   0.000) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > (1011.222|   0.000) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > (1011.222|   0.000) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > (1011.222|   0.000) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > (1011.222|   0.000) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > (1011.222|   0.000) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > (1011.222|   0.000) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > (1011.222|   0.000) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > (1011.222|   0.000) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > (1011.222|   0.000) D: [raop-sink] protocol-native.c: Requesting
> > rewind due to end of underrun.
> > (1011.222|   0.000) D: [raop-sink] sink-input.c: Requesting rewind due
> > to uncorking
> > (1011.222|   0.000) D: [lt-pulseaudio] module-suspend-on-idle.c: Sink
> > raop_output.Logitech-UE-Air-Speaker-39DB34.local becomes busy,
> > resuming.
> > (1011.222|   0.000) D: [raop-sink] module-raop-sink.c: RAOP: RUNNING
> > (1011.947|   0.725) D: [lt-pulseaudio] rtsp_client.c: Full response
> > received. Dispatching
> > (1011.947|   0.000) D: [lt-pulseaudio] raop_client.c: RAOP:
> > SET_PARAMETER
> > (1011.947|   0.000) D: [lt-pulseaudio] rtsp_client.c: Full response
> > received. Dispatching
> > (1011.947|   0.000) D: [lt-pulseaudio] raop_client.c: RAOP:
> > SET_PARAMETER
> > (1012.788|   0.840) D: [raop-sink] module-raop-sink.c: Received
> > control packet.
> > (1012.788|   0.000) D: [raop-sink] raop_client.c: Resending 1 packets
> > starting at 47073
> > (1021.737|   8.949) D: [raop-sink] module-raop-sink.c: Received
> > control packet.
> > (1021.738|   0.000) D: [raop-sink] raop_client.c: Resending 1 packets
> > starting at 48180
> > (1021.738|   0.000) D: [raop-sink] module-raop-sink.c: Received
> > control packet.
> > (1021.738|   0.000) D: [raop-sink] raop_client.c: Resending 1 packets
> > starting at 48181
> > (1021.745|   0.007) D: [raop-sink] module-raop-sink.c: Received
> > control packet.
> > (1021.745|   0.000) D: [raop-sink] raop_client.c: Resending 1 packets
> > starting at 48182
> > (1021.746|   0.001) D: [raop-sink] module-raop-sink.c: Received
> > control packet.
> > (1021.747|   0.000) D: [raop-sink] raop_client.c: Resending 1 packets
> > starting at 48183
> > (1021.752|   0.005) D: [raop-sink] module-raop-sink.c: Received
> > control packet.
> >
> >
> > I'm looking for suggestions for next diagnostic steps. Any help is
> > much appreciated.
> >
> > Thanks,
> > Toby Haynes
> >
> > _______________________________________________
> > pulseaudio-discuss mailing list
> > pulseaudio-discuss at lists.freedesktop.org
> > http://lists.freedesktop.org/mailman/listinfo/pulseaudio-discuss
>
>
> _______________________________________________
> pulseaudio-discuss mailing list
> pulseaudio-discuss at lists.freedesktop.org
> http://lists.freedesktop.org/mailman/listinfo/pulseaudio-discuss
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freedesktop.org/archives/pulseaudio-discuss/attachments/20140415/1f6c53b4/attachment-0001.html>


More information about the pulseaudio-discuss mailing list