Hi,
I confirm the bug under Mint Qiana, Banshee 2.6.2, playing CDs.
Disabling gapless playback seems to solve it.
I noticed the following in syslog:

Sep  2 09:19:56 bureau pulseaudio[1756]: [alsa-sink-ALC889 Analog] ratelimit.c: 
1859 events suppressed
Sep  2 09:19:56 bureau pulseaudio[1756]: [alsa-sink-ALC889 Analog] 
protocol-native.c: Failed to push data into queue
Sep  2 09:19:56 bureau pulseaudio[1756]: message repeated 10 times: [ 
[alsa-sink-ALC889 Analog] protocol-native.c: Failed to push data into queue]
Sep  2 09:22:54 bureau pulseaudio[1756]: [alsa-sink-ALC889 Analog] ratelimit.c: 
100 events suppressed
Sep  2 09:22:54 bureau pulseaudio[1756]: [alsa-sink-ALC889 Analog] 
protocol-native.c: Failed to push data into queue

-- 
You received this bug notification because you are a member of Desktop
Packages, which is subscribed to pulseaudio in Ubuntu.
https://bugs.launchpad.net/bugs/978604

Title:
  Banshee/Rhythmbox regularly stop playing audio when left on in the
  background

Status in “pulseaudio” package in Ubuntu:
  Confirmed
Status in “pulseaudio” source package in Precise:
  Confirmed

Bug description:
  If Banshee or Rhythmbox is left playing in the background they will
  randomly stop playing in the latest builds of Ubuntu 12.04. Starting a
  new piece of music usually fixes the problem. If left to its own
  devices, the music will start playing again at some random time, at
  some random position. This problem exists on both my desktop machine
  (custom built Intel machine) and my laptop (Macbook 5,1). It has been
  happening for several months now.

  I became frustrated enough to load up pulseaudio in debugging mode.
  The log shows that when the music player just finishes playing one
  piece, and tries to start the next piece, you see something like this:

  -------------------------------
  ( 335.399|  34.388) D: [alsa-sink] sink-input.c: Requesting rewind due to 
corking
  ( 335.400|   0.001) D: [alsa-sink] alsa-sink.c: Requested to rewind 65536 
bytes.
  ( 335.400|   0.000) D: [alsa-sink] alsa-sink.c: Limited to 14820 bytes.
  ( 335.400|   0.000) D: [alsa-sink] alsa-sink.c: before: 3705
  ( 335.400|   0.000) D: [alsa-sink] alsa-sink.c: after: 3705
  ( 335.400|   0.000) D: [alsa-sink] alsa-sink.c: Rewound 14820 bytes.
  ( 335.400|   0.000) D: [alsa-sink] sink.c: Processing rewind...
  ( 335.400|   0.000) D: [alsa-sink] sink.c: latency = 1643
  ( 335.400|   0.000) D: [alsa-sink] sink-input.c: Have to rewind 14820 bytes 
on render memblockq.
  ( 335.400|   0.000) D: [alsa-sink] sink-input.c: Have to rewind 14820 bytes 
on implementor.
  ( 335.400|   0.000) D: [alsa-sink] source.c: Processing rewind...
  ( 335.400|   0.000) D: [pulseaudio] module-suspend-on-idle.c: Sink 
alsa_output.pci-0000_00_1b.0.analog-stereo becomes idle, timeout in 5 seconds.
  ( 335.402|   0.001) D: [alsa-sink] alsa-sink.c: hwbuf_unused=0
  ( 335.402|   0.000) D: [alsa-sink] alsa-sink.c: setting avail_min=15502
  ( 335.402|   0.000) D: [alsa-sink] alsa-sink.c: Requested volume: 0:  34% 1:  
34%
  ( 335.402|   0.000) D: [alsa-sink] alsa-sink.c:            in dB: 0: -28.11 
dB 1: -28.11 dB
  ( 335.402|   0.000) D: [alsa-sink] alsa-sink.c: Got hardware volume: 0:  34% 
1:  34%
  ( 335.402|   0.000) D: [alsa-sink] alsa-sink.c:               in dB: 0: 
-28.00 dB 1: -28.00 dB
  ( 335.402|   0.000) D: [alsa-sink] alsa-sink.c: Calculated software volume: 
0: 100% 1: 100% (accurate-enough=yes)
  ( 335.402|   0.000) D: [alsa-sink] alsa-sink.c:                      in dB: 
0: -0.11 dB 1: -0.11 dB
  ( 335.402|   0.000) D: [alsa-sink] sink.c: Volume not changing
  ( 335.402|   0.000) D: [alsa-sink] alsa-sink.c: Requested to rewind 65536 
bytes.
  ( 335.402|   0.000) D: [alsa-sink] alsa-sink.c: Limited to 15300 bytes.
  ( 335.402|   0.000) D: [pulseaudio] module-suspend-on-idle.c: Sink 
alsa_output.pci-0000_00_1b.0.analog-stereo becomes idle, timeout in 5 seconds.
  ( 335.402|   0.000) D: [alsa-sink] alsa-sink.c: before: 3825
  ( 335.402|   0.000) D: [pulseaudio] core.c: Hmm, no streams around, trying to 
vacuum.
  ( 335.402|   0.000) D: [alsa-sink] alsa-sink.c: after: 3825
  ( 335.402|   0.000) D: [alsa-sink] alsa-sink.c: Rewound 15300 bytes.
  ( 335.402|   0.000) D: [alsa-sink] sink.c: Processing rewind...
  ( 335.402|   0.000) D: [alsa-sink] sink.c: latency = 1402
  ( 335.402|   0.000) D: [alsa-sink] source.c: Processing rewind...
  ( 335.402|   0.000) I: [pulseaudio] sink-input.c: Freeing input 3 
"'zero-project - 05 - Forest of the unicorns' by 'zero-project'"
  ( 335.402|   0.000) D: [pulseaudio] module-stream-restore.c: Not restoring 
device for stream sink-input-by-media-role:music, because already set to 
'alsa_output.pci-0000_00_1b.0.analog-stereo'.
  ( 335.403|   0.000) D: [pulseaudio] module-intended-roles.c: Not setting 
device for stream Playback Stream, because already set.
  ( 335.403|   0.000) I: [pulseaudio] module-stream-restore.c: Restoring volume 
for sink input sink-input-by-media-role:music.
  ( 335.403|   0.000) I: [pulseaudio] module-stream-restore.c: Restoring mute 
state for sink input sink-input-by-media-role:music.
  ( 335.403|   0.000) D: [pulseaudio] module-suspend-on-idle.c: Sink 
alsa_output.pci-0000_00_1b.0.analog-stereo becomes busy.
  ( 335.403|   0.000) I: [pulseaudio] resampler.c: Forcing resampler 'copy', 
because of fixed, identical sample rates.
  ( 335.403|   0.000) I: [pulseaudio] resampler.c: Using resampler 'copy'
  ( 335.403|   0.000) I: [pulseaudio] resampler.c: Using float32le as working 
format.
  ( 335.403|   0.000) D: [pulseaudio] memblockq.c: memblockq requested: 
maxlength=33554432, tlength=0, base=4, prebuf=0, minreq=1 maxrewind=0
  ( 335.403|   0.000) D: [pulseaudio] memblockq.c: memblockq sanitized: 
maxlength=33554432, tlength=33554432, base=4, prebuf=0, minreq=4 maxrewind=0
  ( 335.403|   0.000) I: [pulseaudio] sink-input.c: Created input 4 "Playback 
Stream" on alsa_output.pci-0000_00_1b.0.analog-stereo with sample spec 
float32le 2ch 44100Hz and channel map front-left,front-right
  ( 335.403|   0.000) I: [pulseaudio] sink-input.c:     media.name = "Playback 
Stream"
  ( 335.403|   0.000) I: [pulseaudio] sink-input.c:     application.name = 
"Banshee"
  ( 335.403|   0.000) I: [pulseaudio] sink-input.c:     native-protocol.peer = 
"UNIX socket client"
  ( 335.403|   0.000) I: [pulseaudio] sink-input.c:     native-protocol.version 
= "26"
  ( 335.403|   0.000) I: [pulseaudio] sink-input.c:     media.role = "music"
  ( 335.403|   0.000) I: [pulseaudio] sink-input.c:     application.process.id 
= "23258"
  ( 335.403|   0.000) I: [pulseaudio] sink-input.c:     
application.process.user = "themadhatter"
  ( 335.403|   0.000) I: [pulseaudio] sink-input.c:     
application.process.host = "themadhatter-desktop"
  ( 335.403|   0.000) I: [pulseaudio] sink-input.c:     
application.process.binary = "mono"
  ( 335.403|   0.000) I: [pulseaudio] sink-input.c:     application.icon_name = 
"media-player-banshee"
  ( 335.403|   0.000) I: [pulseaudio] sink-input.c:     window.x11.display = 
":0"
  ( 335.403|   0.000) I: [pulseaudio] sink-input.c:     application.language = 
"en_US.UTF-8"
  ( 335.403|   0.000) I: [pulseaudio] sink-input.c:     
application.process.machine_id = "8128ee9200ba7ce4b9230dbf00000001"
  ( 335.403|   0.000) I: [pulseaudio] sink-input.c:     
application.process.session_id = 
"8128ee9200ba7ce4b9230dbf00000001-1334106345.520104-1231006243"
  ( 335.403|   0.000) I: [pulseaudio] sink-input.c:     
module-stream-restore.id = "sink-input-by-media-role:music"
  ( 335.403|   0.000) I: [pulseaudio] protocol-native.c: Requested 
tlength=200.00 ms, minreq=10.00 ms
  ( 335.403|   0.000) D: [pulseaudio] protocol-native.c: Adjust latency mode 
enabled, configuring sink latency to half of overall latency.
  ( 335.403|   0.000) D: [pulseaudio] memblockq.c: memblockq requested: 
maxlength=4194304, tlength=38808, base=8, prebuf=0, minreq=3528 maxrewind=0
  ( 335.403|   0.000) D: [pulseaudio] memblockq.c: memblockq sanitized: 
maxlength=4194304, tlength=38808, base=8, prebuf=0, minreq=3528 maxrewind=0
  ( 335.403|   0.000) I: [pulseaudio] protocol-native.c: Final latency 200.00 
ms = 90.00 ms + 2*10.00 ms + 90.00 ms
  ( 335.403|   0.000) D: [alsa-sink] alsa-sink.c: Latency set to 90.00ms
  ( 335.403|   0.000) D: [alsa-sink] alsa-sink.c: hwbuf_unused=49660
  ( 335.403|   0.000) D: [alsa-sink] alsa-sink.c: setting avail_min=15503
  ( 335.403|   0.000) D: [alsa-sink] alsa-sink.c: Requesting rewind due to 
latency change.
  ( 335.403|   0.000) D: [alsa-sink] alsa-sink.c: Requested volume: 0:  34% 1:  
34%
  ( 335.403|   0.000) D: [alsa-sink] alsa-sink.c:            in dB: 0: -28.11 
dB 1: -28.11 dB
  ( 335.403|   0.000) D: [alsa-sink] alsa-sink.c: Got hardware volume: 0:  34% 
1:  34%
  ( 335.403|   0.000) D: [alsa-sink] alsa-sink.c:               in dB: 0: 
-28.00 dB 1: -28.00 dB
  ( 335.403|   0.000) D: [alsa-sink] alsa-sink.c: Calculated software volume: 
0: 100% 1: 100% (accurate-enough=yes)
  ( 335.403|   0.000) D: [alsa-sink] alsa-sink.c:                      in dB: 
0: -0.11 dB 1: -0.11 dB
  ( 335.403|   0.000) D: [alsa-sink] sink.c: Volume not changing
  ( 335.403|   0.000) D: [alsa-sink] alsa-sink.c: Requested to rewind 65536 
bytes.
  ( 335.403|   0.000) D: [alsa-sink] alsa-sink.c: Limited to 65120 bytes.
  ( 335.403|   0.000) D: [alsa-sink] alsa-sink.c: before: 16280
  ( 335.403|   0.000) D: [alsa-sink] alsa-sink.c: after: 16280
  ( 335.403|   0.000) D: [alsa-sink] alsa-sink.c: Rewound 65120 bytes.
  ( 335.403|   0.000) D: [alsa-sink] sink.c: Processing rewind...
  ( 335.403|   0.000) D: [alsa-sink] sink.c: latency = 897
  ( 335.404|   0.000) D: [alsa-sink] sink-input.c: Have to rewind 65120 bytes 
on render memblockq.
  ( 335.404|   0.000) D: [alsa-sink] source.c: Processing rewind...
  ( 335.405|   0.001) W: [alsa-sink] ratelimit.c: 173 events suppressed
  ( 335.405|   0.000) W: [alsa-sink] protocol-native.c: Failed to push data 
into queue
  ( 335.405|   0.000) D: [alsa-sink] protocol-native.c: Requesting rewind due 
to end of underrun.
  ( 335.405|   0.000) D: [alsa-sink] protocol-native.c: Requesting rewind due 
to end of underrun.
  ( 335.405|   0.000) D: [alsa-sink] sink-input.c: Requesting rewind due to 
uncorking
  ( 335.405|   0.000) D: [alsa-sink] alsa-sink.c: Requested to rewind 65536 
bytes.
  ( 335.405|   0.000) D: [pulseaudio] module-suspend-on-idle.c: Sink 
alsa_output.pci-0000_00_1b.0.analog-stereo becomes busy.
  ( 335.405|   0.000) D: [alsa-sink] alsa-sink.c: Limited to 15300 bytes.
  ( 335.405|   0.000) D: [alsa-sink] alsa-sink.c: before: 3825
  ( 335.405|   0.000) D: [alsa-sink] alsa-sink.c: after: 3825
  ( 335.405|   0.000) D: [alsa-sink] alsa-sink.c: Rewound 15300 bytes.
  ( 335.405|   0.000) D: [alsa-sink] sink.c: Processing rewind...
  ( 335.405|   0.000) D: [alsa-sink] sink.c: latency = 795
  ( 335.405|   0.000) D: [alsa-sink] source.c: Processing rewind...
  ( 335.407|   0.001) W: [alsa-sink] protocol-native.c: Failed to push data 
into queue
  ( 335.408|   0.001) W: [alsa-sink] protocol-native.c: Failed to push data 
into queue
  ( 335.409|   0.000) W: [alsa-sink] protocol-native.c: Failed to push data 
into queue
  ( 335.409|   0.000) W: [alsa-sink] protocol-native.c: Failed to push data 
into queue
  --------------------------------------------------

  When the music randomly starts playing again:
  --------------------------------------------------

  ( 469.282| 133.873) D: [alsa-sink] protocol-native.c: Requesting rewind due 
to rewrite.
  ( 469.283|   0.000) D: [alsa-sink] alsa-sink.c: Requested to rewind 65536 
bytes.
  ( 469.283|   0.000) D: [alsa-sink] alsa-sink.c: Limited to 15620 bytes.
  ( 469.283|   0.000) D: [alsa-sink] alsa-sink.c: before: 3905
  ( 469.283|   0.000) D: [alsa-sink] alsa-sink.c: after: 3905
  ( 469.283|   0.000) D: [alsa-sink] alsa-sink.c: Rewound 15620 bytes.
  ( 469.283|   0.000) D: [alsa-sink] sink.c: Processing rewind...
  ( 469.283|   0.000) D: [alsa-sink] sink.c: latency = 1297
  ( 469.283|   0.000) D: [alsa-sink] sink-input.c: Have to rewind 15620 bytes 
on render memblockq.
  ( 469.283|   0.000) D: [alsa-sink] sink-input.c: Have to rewind 31240 bytes 
on implementor.
  ( 469.283|   0.000) D: [alsa-sink] source.c: Processing rewind...
  ( 469.283|   0.000) D: [alsa-sink] protocol-native.c: Underrun on 'Playback 
Stream', 0 bytes in queue.
  ( 469.283|   0.000) D: [alsa-sink] protocol-native.c: Requesting rewind due 
to rewrite.
  ( 469.283|   0.000) D: [alsa-sink] alsa-sink.c: Requested to rewind 65536 
bytes.
  ( 469.283|   0.000) D: [alsa-sink] alsa-sink.c: Limited to 15620 bytes.
  ( 469.283|   0.000) D: [alsa-sink] alsa-sink.c: before: 3905
  ( 469.283|   0.000) D: [alsa-sink] alsa-sink.c: after: 3905
  ( 469.283|   0.000) D: [alsa-sink] alsa-sink.c: Rewound 15620 bytes.
  ( 469.283|   0.000) D: [alsa-sink] sink.c: Processing rewind...
  ( 469.283|   0.000) D: [alsa-sink] sink.c: latency = 1085
  ( 469.283|   0.000) D: [alsa-sink] sink-input.c: Have to rewind 15620 bytes 
on render memblockq.
  ( 469.283|   0.000) D: [alsa-sink] sink-input.c: Have to rewind 31240 bytes 
on implementor.
  ( 469.283|   0.000) D: [alsa-sink] source.c: Processing rewind...
  ( 469.283|   0.000) D: [alsa-sink] protocol-native.c: Requesting rewind due 
to rewrite.
  ( 469.283|   0.000) D: [alsa-sink] alsa-sink.c: Requested to rewind 65536 
bytes.
  ( 469.283|   0.000) D: [alsa-sink] alsa-sink.c: Limited to 15460 bytes.
  ( 469.283|   0.000) D: [alsa-sink] alsa-sink.c: before: 3865
  ( 469.283|   0.000) D: [alsa-sink] alsa-sink.c: after: 3865
  ( 469.283|   0.000) D: [alsa-sink] alsa-sink.c: Rewound 15460 bytes.
  ( 469.283|   0.000) D: [alsa-sink] sink.c: Processing rewind...
  ( 469.284|   0.000) D: [alsa-sink] sink.c: latency = 1309
  ( 469.284|   0.000) D: [alsa-sink] sink-input.c: Have to rewind 15460 bytes 
on render memblockq.
  ( 469.284|   0.000) D: [alsa-sink] sink-input.c: Have to rewind 30920 bytes 
on implementor.
  ( 469.284|   0.000) D: [alsa-sink] source.c: Processing rewind...
  ( 469.284|   0.000) D: [alsa-sink] protocol-native.c: Requesting rewind due 
to rewrite.
  ( 469.284|   0.000) D: [alsa-sink] alsa-sink.c: Requested to rewind 65536 
bytes.
  ( 469.284|   0.000) D: [alsa-sink] alsa-sink.c: Limited to 15620 bytes.
  ( 469.284|   0.000) D: [alsa-sink] alsa-sink.c: before: 3905
  ( 469.284|   0.000) D: [alsa-sink] alsa-sink.c: after: 3905
  ( 469.284|   0.000) D: [alsa-sink] alsa-sink.c: Rewound 15620 bytes.
  ( 469.284|   0.000) D: [alsa-sink] sink.c: Processing rewind...
  ( 469.284|   0.000) D: [alsa-sink] sink.c: latency = 1137
  ( 469.284|   0.000) D: [alsa-sink] sink-input.c: Have to rewind 15620 bytes 
on render memblockq.
  ( 469.284|   0.000) D: [alsa-sink] sink-input.c: Have to rewind 31240 bytes 
on implementor.
  ( 469.284|   0.000) D: [alsa-sink] source.c: Processing rewind...
  ( 469.284|   0.000) D: [alsa-sink] protocol-native.c: Requesting rewind due 
to rewrite.
  ( 469.284|   0.000) D: [alsa-sink] alsa-sink.c: Requested to rewind 65536 
bytes.
  ( 469.284|   0.000) D: [alsa-sink] alsa-sink.c: Limited to 15620 bytes.
  ( 469.284|   0.000) D: [alsa-sink] alsa-sink.c: before: 3905
  ( 469.284|   0.000) D: [alsa-sink] alsa-sink.c: after: 3905
  ( 469.284|   0.000) D: [alsa-sink] alsa-sink.c: Rewound 15620 bytes.
  ( 469.284|   0.000) D: [alsa-sink] sink.c: Processing rewind...
  ( 469.284|   0.000) D: [alsa-sink] sink.c: latency = 976
  .... etc.
  Basically what looks like the same thing over and over again with slightly 
different numbers.
  ----------------------------------------------------

  Do please let me know what I can do to help. :). I have attached the
  full log below.

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/pulseaudio/+bug/978604/+subscriptions

-- 
Mailing list: https://launchpad.net/~desktop-packages
Post to     : desktop-packages@lists.launchpad.net
Unsubscribe : https://launchpad.net/~desktop-packages
More help   : https://help.launchpad.net/ListHelp

Reply via email to