Ubuntu
virt-manager package

  1. Bug #1246929
  2. Comment #6

Comment 6 for bug 1246929

Revision history for this message
Raymond (superquad-vortex2) wrote : Re: alsa bug in KVM virtual machines

7.726| 0.000) D: [pulseaudio] reserve-wrap.c: Successfully acquired reservation lock on device 'Audio0'
( 37.726| 0.000) I: [alsa-sink-Intel ICH] alsa-sink.c: Trying resume...
( 37.726| 0.000) D: [alsa-sink-Intel ICH] alsa-util.c: Maximum hw buffer size is 371 ms
( 37.726| 0.000) D: [alsa-sink-Intel ICH] alsa-util.c: Set buffer size first (to 3528 samples), period size second (to 441 samples).
( 37.726| 0.000) D: [alsa-sink-Intel ICH] alsa-sink.c: hwbuf_unused=0
( 37.726| 0.000) D: [alsa-sink-Intel ICH] alsa-sink.c: setting avail_min=1
( 37.726| 0.000) I: [alsa-sink-Intel ICH] alsa-sink.c: Resumed successfully...
( 37.726| 0.000) I: [alsa-sink-Intel ICH] alsa-sink.c: Starting playback.
( 37.726| 0.000) D: [pulseaudio] module-suspend-on-idle.c: Sink alsa_output.pci-0000_00_04.0.analog-stereo becomes idle, timeout in 5 seconds.
( 37.727| 0.000) D: [pulseaudio] memblockq.c: memblockq requested: maxlength=33554432, tlength=0, base=4, prebuf=0, minreq=1 maxrewind=0
( 37.727| 0.000) D: [pulseaudio] memblockq.c: memblockq sanitized: maxlength=33554432, tlength=33554432, base=4, prebuf=0, minreq=4 maxrewind=0
( 37.727| 0.000) I: [pulseaudio] sink-input.c: Created input 0 "ALSA Playback" on alsa_output.pci-0000_00_04.0.analog-stereo with sample spec s16le 2ch 44100Hz and channel map front-left,front-right
( 37.727| 0.000) I: [pulseaudio] sink-input.c: media.name = "ALSA Playback"
( 37.727| 0.000) I: [pulseaudio] sink-input.c: application.name = "ALSA plug-in [plugin-container]"
( 37.727| 0.000) I: [pulseaudio] sink-input.c: native-protocol.peer = "UNIX socket client"
( 37.727| 0.000) I: [pulseaudio] sink-input.c: native-protocol.version = "28"
( 37.727| 0.000) I: [pulseaudio] sink-input.c: application.process.id = "2232"
( 37.727| 0.000) I: [pulseaudio] sink-input.c: application.process.user = "bmullan"
( 37.727| 0.000) I: [pulseaudio] sink-input.c: application.process.host = "bmullan-virtual-machine"
( 37.727| 0.000) I: [pulseaudio] sink-input.c: application.process.binary = "plugin-container"
( 37.727| 0.000) I: [pulseaudio] sink-input.c: application.language = "en_US.UTF-8"
( 37.727| 0.000) I: [pulseaudio] sink-input.c: window.x11.display = ":0"
( 37.727| 0.000) I: [pulseaudio] sink-input.c: application.process.machine_id = "735ddae164ef1ded237a4a095272b03a"
( 37.727| 0.000) I: [pulseaudio] sink-input.c: application.process.session_id = "c2"
( 37.727| 0.000) I: [pulseaudio] sink-input.c: module-stream-restore.id = "sink-input-by-application-name:ALSA plug-in [plugin-container]"
( 37.727| 0.000) I: [pulseaudio] protocol-native.c: Requested tlength=500.00 ms, minreq=20.00 ms
( 37.727| 0.000) D: [pulseaudio] protocol-native.c: Early requests mode enabled, configuring sink latency to minreq.
( 37.727| 0.000) E: [alsa-sink-Intel ICH] alsa-sink.c: ALSA woke us up to write new data to the device, but there was actually nothing to write!
( 37.727| 0.000) E: [alsa-sink-Intel ICH] alsa-sink.c: Most likely this is a bug in the ALSA driver 'snd_intel8x0'. Please report this issue to the ALSA developers.
( 37.727| 0.000) E: [alsa-sink-Intel ICH] alsa-sink.c: We were woken up with POLLOUT set -- however a subsequent snd_pcm_avail() returned 0 or another value < min_avail.
( 37.727| 0.000) D: [pulseaudio] protocol-native.c: Requested latency=20.00 ms, Received latency=80.00 ms
( 37.727| 0.000) D: [pulseaudio] memblockq.c: memblockq requested: maxlength=4194304, tlength=88200, base=4, prebuf=3528, minreq=14112 maxrewind=0
( 37.727| 0.000) D: [pulseaudio] memblockq.c: memblockq sanitized: maxlength=4194304, tlength=88200, base=4, prebuf=3528, minreq=14112 maxrewind=0
( 37.727| 0.000) I: [pulseaudio] protocol-native.c: Final latency 580.00 ms = 340.00 ms + 2*80.00 ms + 80.00 ms
( 37.727| 0.000) D: [alsa-sink-Intel ICH] alsa-sink.c: Requested volume: 0: 28% 1: 28%
( 37.727| 0.000) D: [alsa-sink-Intel ICH] alsa-sink.c: in dB: 0: -33.00 dB 1: -33.00 dB
( 37.727| 0.000) D: [alsa-sink-Intel ICH] alsa-sink.c: Got hardware volume: 0: 28% 1: 28%
( 37.727| 0.000) D: [alsa-sink-Intel ICH] alsa-sink.c: in dB: 0: -33.00 dB 1: -33.00 dB
( 37.727| 0.000) D: [alsa-sink-Intel ICH] alsa-sink.c: Calculated software volume: 0: 100% 1: 100% (accurate-enough=yes)
( 37.727| 0.000) D: [alsa-sink-Intel ICH] alsa-sink.c: in dB: 0: 0.00 dB 1: 0.00 dB
( 37.727| 0.000) D: [alsa-sink-Intel ICH] sink.c: Volume not changing
( 37.727| 0.000) D: [pulseaudio] core-subscribe.c: Dropped redundant event due to change event.
( 37.729| 0.001) D: [alsa-sink-Intel ICH] protocol-native.c: Requesting rewind due to end of underrun.
( 37.729| 0.000) D: [alsa-sink-Intel ICH] alsa-sink.c: Requested to rewind 14112 bytes.
( 37.729| 0.000) D: [alsa-sink-Intel ICH] alsa-sink.c: Limited to 13856 bytes.
( 37.729| 0.000) D: [alsa-sink-Intel ICH] alsa-sink.c: before: 3464
( 37.729| 0.000) D: [alsa-sink-Intel ICH] alsa-sink.c: after: 3464
( 37.729| 0.000) D: [alsa-sink-Intel ICH] alsa-sink.c: Rewound 13856 bytes.
( 37.729| 0.000) D: [alsa-sink-Intel ICH] sink.c: Processing rewind...
( 37.729| 0.000) D: [alsa-sink-Intel ICH] sink.c: latency = 46860
( 37.729| 0.000) D: [alsa-sink-Intel ICH] sink-input.c: Have to rewind 13856 bytes on render memblockq.
( 37.729| 0.000) D: [alsa-sink-Intel ICH] source.c: Processing rewind...
( 37.729| 0.000) D: [alsa-sink-Intel ICH] protocol-native.c: Implicit underrun of 'ALSA Playback'
( 37.729| 0.000) D: [alsa-sink-Intel ICH] sink.c: Found underrun 10372 bytes ago (3740 bytes ahead in playback buffer)
( 37.729| 0.000) D: [alsa-sink-Intel ICH] sink.c: Found underrun 10372 bytes ago (3740 bytes ahead in playback buffer)
( 37.730| 0.000) D: [alsa-sink-Intel ICH] sink.c: Found underrun 10372 bytes ago (3740 bytes ahead in playback buffer)
( 37.730| 0.000) D: [alsa-sink-Intel ICH] sink.c: Found underrun 10372 bytes ago (3740 bytes ahead in playback buffer)
( 37.730| 0.000) D: [alsa-sink-Intel ICH] sink.c: Found underrun 10412 bytes ago (3700 bytes ahead in playback buffer)
( 37.730| 0.000) D: [alsa-sink-Intel ICH] sink.c: Found underrun 10412 bytes ago (3700 bytes ahead in playback buffer)
( 37.730| 0.000) D: [alsa-sink-Intel ICH] sink.c: Found underrun 10412 bytes ago (3700 bytes ahead in playback buffer)
( 37.730| 0.000) D: [alsa-sink-Intel ICH] sink.c: Found underrun 10412 bytes ago (3700 bytes ahead in playback buffer)
( 37.730| 0.000) D: [alsa-sink-Intel ICH] sink.c: Found underrun 10452 bytes ago (3660 bytes ahead in playback buffer)
( 37.730| 0.000) D: [alsa-sink-Intel ICH] sink.c: Found underrun 10452 bytes ago (3660 bytes ahead in playback buffer)
( 37.730| 0.000) D: [alsa-sink-Intel ICH] sink.c: Found underrun 10452 bytes ago (3660 bytes ahead in playback buffer)
( 37.730| 0.000) D: [alsa-sink-Intel ICH] sink.c: Found underrun 10452 bytes ago (3660 bytes ahead in playback buffer)
( 37.730| 0.000) D: [alsa-sink-Intel ICH] sink.c: Found underrun 10452 bytes ago (3660 bytes ahead in playback buffer)
( 37.730| 0.000) D: [alsa-sink-Intel ICH] sink.c: Found underrun 10496 bytes ago (3616 bytes ahead in playback buffer)
( 37.730| 0.000) D: [alsa-sink-Intel ICH] sink.c: Found underrun 10496 bytes ago (3616 bytes ahead in playback buffer)
( 37.731| 0.001) D: [alsa-sink-Intel ICH] sink.c: Found underrun 10656 bytes ago (3456 bytes ahead in playback buffer)
( 37.733| 0.001) D: [alsa-sink-Intel ICH] sink.c: Found underrun 10828 bytes ago (3284 bytes ahead in playback buffer)

the above message seem related to this patch

core, alsa: Better drain reporting

http://cgit.freedesktop.org/pulseaudio/pulseaudio/commit/src/pulsecore/sink.c?id=e87eb85474e0d357d82a9a38097144b607e1ef57