[pulseaudio-tickets] [PulseAudio] #542: Regression: Cannot use alsa sink in 0.9.15 that would play in 0.9.14

Thu Apr 16 05:36:14 PDT 2009

#542: Regression: Cannot use alsa sink in 0.9.15 that would play in 0.9.14
---------------------------+------------------------------------------------
 Reporter:  avuton         |       Owner:  lennart
     Type:  defect         |      Status:  new    
 Priority:  normal         |   Milestone:         
Component:  module-alsa-*  |    Severity:  major  
 Keywords:                 |  
---------------------------+------------------------------------------------
 After updating to pulseaudio-0.9.15 I found there was a specific sound
 card (sink) that was no longer usable. Putting debug in the logs I found
 the below. MPD acts normal when the sink is open, so there's not even an
 error being thrown here.

 I have X, alsa, asyncns, avahi, dbus, glib and hal compiled in, everything
 else not.

 Sample output from when I try to play on this sink:

 {{{
 Apr 16 05:26:25 rocket pulseaudio[19632]: alsa-sink.c: Requested to rewind
 32768 bytes.
 Apr 16 05:26:25 rocket pulseaudio[19632]: alsa-sink.c: Limited to 1700
 bytes.
 Apr 16 05:26:25 rocket pulseaudio[19632]: alsa-sink.c: before: 425
 Apr 16 05:26:25 rocket pulseaudio[19632]: alsa-sink.c: after: 425
 Apr 16 05:26:25 rocket pulseaudio[19632]: alsa-sink.c: Rewound 1700 bytes.
 Apr 16 05:26:25 rocket pulseaudio[19632]: sink.c: Processing rewind...
 Apr 16 05:26:25 rocket pulseaudio[19632]: sink-input.c: Have to rewind
 1700 bytes on render memblockq.
 Apr 16 05:26:25 rocket pulseaudio[19632]: source.c: Processing rewind...
 Apr 16 05:26:26 rocket pulseaudio[19632]: protocol-native.c: Underrun on
 'Shawn's Headphones', 0 bytes in queue.
 Apr 16 05:26:26 rocket pulseaudio[19632]: ratelimit.c: 149 events
 suppressed
 Apr 16 05:26:26 rocket pulseaudio[19632]: alsa-sink.c: Wakeup from ALSA!
 Apr 16 05:26:26 rocket pulseaudio[19632]: alsa-sink.c: Underrun!
 Apr 16 05:26:27 rocket pulseaudio[19632]: alsa-sink.c: Wakeup from ALSA!
 Apr 16 05:26:27 rocket pulseaudio[19632]: alsa-sink.c: Underrun!
 Apr 16 05:26:27 rocket pulseaudio[19632]: alsa-sink.c: Wakeup from ALSA!
 Apr 16 05:26:27 rocket pulseaudio[19632]: alsa-sink.c: Underrun!
 Apr 16 05:26:27 rocket pulseaudio[19632]: alsa-sink.c: Wakeup from ALSA!
 Apr 16 05:26:27 rocket pulseaudio[19632]: alsa-sink.c: Underrun!
 Apr 16 05:26:27 rocket pulseaudio[19632]: alsa-sink.c: Wakeup from ALSA!
 Apr 16 05:26:27 rocket pulseaudio[19632]: alsa-sink.c: Underrun!
 Apr 16 05:26:27 rocket pulseaudio[19632]: alsa-sink.c: Wakeup from ALSA!
 Apr 16 05:26:27 rocket pulseaudio[19632]: protocol-native.c: Requesting
 rewind due to end of underrun.
 Apr 16 05:26:27 rocket pulseaudio[19632]: alsa-sink.c: Requested to rewind
 32768 bytes.
 Apr 16 05:26:27 rocket pulseaudio[19632]: alsa-sink.c: Limited to 1768
 bytes.
 Apr 16 05:26:27 rocket pulseaudio[19632]: alsa-sink.c: before: 442
 Apr 16 05:26:27 rocket pulseaudio[19632]: alsa-sink.c: after: 442
 Apr 16 05:26:27 rocket pulseaudio[19632]: alsa-sink.c: Rewound 1768 bytes.
 Apr 16 05:26:27 rocket pulseaudio[19632]: sink.c: Processing rewind...
 Apr 16 05:26:27 rocket pulseaudio[19632]: sink-input.c: Have to rewind
 1768 bytes on render memblockq.
 Apr 16 05:26:27 rocket pulseaudio[19632]: source.c: Processing rewind...
 Apr 16 05:26:29 rocket pulseaudio[19632]: protocol-native.c: Underrun on
 'Shawn's Headphones', 0 bytes in queue.
 Apr 16 05:26:30 rocket pulseaudio[19632]: protocol-native.c: Requesting
 rewind due to end of underrun.
 Apr 16 05:26:30 rocket pulseaudio[19632]: alsa-sink.c: Requested to rewind
 32768 bytes.
 Apr 16 05:26:30 rocket pulseaudio[19632]: alsa-sink.c: Limited to 1296
 bytes.
 Apr 16 05:26:30 rocket pulseaudio[19632]: alsa-sink.c: before: 324
 Apr 16 05:26:30 rocket pulseaudio[19632]: alsa-sink.c: after: 324
 Apr 16 05:26:30 rocket pulseaudio[19632]: alsa-sink.c: Rewound 1296 bytes.
 Apr 16 05:26:30 rocket pulseaudio[19632]: sink.c: Processing rewind...
 Apr 16 05:26:30 rocket pulseaudio[19632]: sink-input.c: Have to rewind
 1296 bytes on render memblockq.
 Apr 16 05:26:30 rocket pulseaudio[19632]: source.c: Processing rewind...
 Apr 16 05:26:31 rocket pulseaudio[19632]: protocol-native.c: Underrun on
 'Shawn's Headphones', 0 bytes in queue.
 }}}

 More output:
 {{{
 Apr 16 05:32:07 rocket pulseaudio[19632]: client.c: Created 4 "Native
 client (TCP/IP client from 10.0.0.1:36340)"
 Apr 16 05:32:07 rocket pulseaudio[19632]: protocol-native.c: Client
 authenticated anonymously.
 Apr 16 05:32:07 rocket pulseaudio[19632]: protocol-native.c: Protocol
 version: remote 14, local 15
 Apr 16 05:32:07 rocket pulseaudio[19632]: protocol-native.c: SHM possible:
 no
 Apr 16 05:32:07 rocket pulseaudio[19632]: protocol-native.c: Negotiated
 SHM: no
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Trying resume...
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-util.c: Maximum hw buffer
 size is 341 ms
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: hwbuf_unused=0
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: setting
 avail_min=481
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Resumed
 successfully...
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Starting playback.
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Cutting sleep time
 for the initial iterations by half.
 Apr 16 05:32:07 rocket pulseaudio[19632]: module-suspend-on-idle.c: Sink
 alsa_output.pci_1102_2_sound_card_0 becomes idle.
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Cutting sleep time
 for the initial iterations by half.
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Cutting sleep time
 for the initial iterations by half.
 Apr 16 05:32:07 rocket pulseaudio[19632]: module-suspend-on-idle.c: Sink
 alsa_output.pci_1102_2_sound_card_0 becomes busy.
 Apr 16 05:32:07 rocket pulseaudio[19632]: resampler.c: Using resampler
 'speex-float-3'
 Apr 16 05:32:07 rocket pulseaudio[19632]: resampler.c: Using float32le as
 working format.
 Apr 16 05:32:07 rocket pulseaudio[19632]: resampler.c: Choosing speex
 quality setting 3.
 Apr 16 05:32:07 rocket pulseaudio[19632]: memblockq.c: memblockq
 requested: maxlength=33554432, tlength=0, base=4, prebuf=0, minreq=1
 maxrewind=0
 Apr 16 05:32:07 rocket pulseaudio[19632]: memblockq.c: memblockq
 sanitized: maxlength=33554432, tlength=33554432, base=4, prebuf=0,
 minreq=4 maxrewind=0
 Apr 16 05:32:07 rocket pulseaudio[19632]: sink-input.c: Created input 2
 "Shawn's Headphones" on alsa_output.pci_1102_2_sound_card_0 with sample
 spec s16le 2ch 44100Hz and channel map front-left,front-right
 Apr 16 05:32:07 rocket pulseaudio[19632]: protocol-native.c: Requested
 tlength=250.00 ms, minreq=20.00 ms
 Apr 16 05:32:07 rocket pulseaudio[19632]: protocol-native.c: Traditional
 mode enabled, modifying sink usec only for compat with minreq.
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Cutting sleep time
 for the initial iterations by half.
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Cutting sleep time
 for the initial iterations by half.
 Apr 16 05:32:07 rocket pulseaudio[19632]: memblockq.c: memblockq
 requested: maxlength=4194304, tlength=44100, base=4, prebuf=40576,
 minreq=3528 maxrewind=0
 Apr 16 05:32:07 rocket pulseaudio[19632]: memblockq.c: memblockq
 sanitized: maxlength=4194304, tlength=44100, base=4, prebuf=40576,
 minreq=3528 maxrewind=0
 Apr 16 05:32:07 rocket pulseaudio[19632]: protocol-native.c: Final latency
 420.67 ms = 210.00 ms + 2*20.00 ms + 170.67 ms
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Cutting sleep time
 for the initial iterations by half.
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Latency set to
 170.67ms
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: hwbuf_unused=4
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: setting
 avail_min=483
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Requesting rewind
 due to latency change.
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Requested to rewind
 32768 bytes.
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Limited to 1740
 bytes.
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: before: 435
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: after: 435
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Rewound 1740 bytes.
 Apr 16 05:32:07 rocket pulseaudio[19632]: sink.c: Processing rewind...
 Apr 16 05:32:07 rocket pulseaudio[19632]: sink-input.c: Have to rewind
 1740 bytes on render memblockq.
 Apr 16 05:32:07 rocket pulseaudio[19632]: source.c: Processing rewind...
 Apr 16 05:32:07 rocket pulseaudio[19632]: core-subscribe.c: Dropped
 redundant event due to change event.
 Apr 16 05:32:07 rocket pulseaudio[19632]: client.c: Created 5 "Native
 client (TCP/IP client from 10.0.0.1:36341)"
 Apr 16 05:32:07 rocket pulseaudio[19632]: protocol-native.c: Client
 authenticated anonymously.
 Apr 16 05:32:07 rocket pulseaudio[19632]: protocol-native.c: Protocol
 version: remote 14, local 15
 Apr 16 05:32:07 rocket pulseaudio[19632]: protocol-native.c: SHM possible:
 no
 Apr 16 05:32:07 rocket pulseaudio[19632]: protocol-native.c: Negotiated
 SHM: no
 Apr 16 05:32:07 rocket pulseaudio[19632]: protocol-native.c: Requesting
 rewind due to end of underrun.
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Requested to rewind
 32764 bytes.
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Limited to 1440
 bytes.
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: before: 360
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: after: 360
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Rewound 1440 bytes.
 Apr 16 05:32:07 rocket pulseaudio[19632]: sink.c: Processing rewind...
 Apr 16 05:32:07 rocket pulseaudio[19632]: sink-input.c: Have to rewind
 1440 bytes on render memblockq.
 Apr 16 05:32:07 rocket pulseaudio[19632]: source.c: Processing rewind...
 Apr 16 05:32:07 rocket pulseaudio[19632]: ratelimit.c: 25 events
 suppressed
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Wakeup from ALSA!
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Underrun!
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Wakeup from ALSA!
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Wakeup from ALSA!
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Wakeup from ALSA!
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Wakeup from ALSA!
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Wakeup from ALSA!
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Wakeup from ALSA!
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Wakeup from ALSA!
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Wakeup from ALSA!
 Apr 16 05:32:07 rocket pulseaudio[19632]: alsa-sink.c: Wakeup from ALSA!
 }}}

-- 
Ticket URL: <http://pulseaudio.org/ticket/542>
PulseAudio <http://pulseaudio.org/>
The PulseAudio Sound Server