Attachment 96261 Details for Bug 76532 – Output of loading skype with "PULSE_LATENCY_MSEC=30"

Output of loading skype with "PULSE_LATENCY_MSEC=30"

with-latency.log (text/plain), 28.41 KB, created by Ross Lagerwall on 2014-03-23 23:14:10 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Ross Lagerwall

Created: 2014-03-23 23:14:10 UTC

Size: 28.41 KB

patch

obsolete

>I: [pulseaudio] client.c: Created 2 "Native client (UNIX socket client)"
>D: [pulseaudio] protocol-native.c: Protocol version: remote 29, local 29
>I: [pulseaudio] protocol-native.c: Got credentials: uid=1000 gid=1000 success=1
>D: [pulseaudio] protocol-native.c: SHM possible: yes
>D: [pulseaudio] protocol-native.c: Negotiated SHM: yes
>D: [pulseaudio] module-augment-properties.c: Looking for .desktop file for skype
>D: [pulseaudio] sink-input.c: Negotiated format: pcm, format.sample_format = "\"s16le\""  format.rate = "48000"  format.channels = "1"  format.channel_map = "\"mono\""
>I: [pulseaudio] sink-input.c: Trying to change sample rate
>I: [pulseaudio] sink-input.c: Rate changed to 48000 Hz
>I: [pulseaudio] module-stream-restore.c: Restoring volume for sink input sink-input-by-media-role:event.
>I: [pulseaudio] module-stream-restore.c: Restoring mute state for sink input sink-input-by-media-role:event.
>D: [pulseaudio] module-suspend-on-idle.c: Sink alsa_output.pci-0000_00_1b.0.analog-stereo becomes busy, resuming.
>D: [pulseaudio] sink.c: Suspend cause of sink alsa_output.pci-0000_00_1b.0.analog-stereo is 0x0000, resuming
>D: [pulseaudio] reserve-wrap.c: Successfully acquired reservation lock on device 'Audio0'
>I: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Trying resume...
>I: [alsa-sink-ALC887-VD Analog] alsa-util.c: Trying to disable ALSA period wakeups, using timers only
>D: [alsa-sink-ALC887-VD Analog] alsa-util.c: Maximum hw buffer size is 21845 ms
>D: [alsa-sink-ALC887-VD Analog] alsa-util.c: Set buffer size first (to 88200 samples), period size second (to 44100 samples).
>I: [alsa-sink-ALC887-VD Analog] alsa-util.c: ALSA period wakeups disabled
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: hwbuf_unused=0
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: setting avail_min=88009
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: hwbuf_unused=0
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: setting avail_min=87319
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: hwbuf_unused=0
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: setting avail_min=87319
>I: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Time scheduling watermark is 18.38ms
>I: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Resumed successfully...
>D: [pulseaudio] module-suspend-on-idle.c: Sink alsa_output.pci-0000_00_1b.0.analog-stereo becomes idle, timeout in 5 seconds.
>I: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Starting playback.
>D: [alsa-sink-ALC887-VD Analog] ratelimit.c: 2877 events suppressed
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Cutting sleep time for the initial iterations by half.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Cutting sleep time for the initial iterations by half.
>D: [pulseaudio] module-suspend-on-idle.c: Sink alsa_output.pci-0000_00_1b.0.analog-stereo becomes idle, timeout in 5 seconds.
>I: [pulseaudio] resampler.c: Forcing resampler 'copy', because of fixed, identical sample rates.
>D: [pulseaudio] resampler.c: Channel matrix:
>D: [pulseaudio] resampler.c:        I00 
>D: [pulseaudio] resampler.c:     +------
>D: [pulseaudio] resampler.c: O00 | 1.000
>D: [pulseaudio] resampler.c: O01 | 1.000
>I: [pulseaudio] remap_sse.c: Using SSE2 mono to stereo remapping
>D: [pulseaudio] resampler.c: Resampler:
>D: [pulseaudio] resampler.c:   rate 48000 -> 48000 (method copy)
>D: [pulseaudio] resampler.c:   format s16le -> s16le (intermediate s16le)
>D: [pulseaudio] resampler.c:   channels 1 -> 2 (resampling 1)
>D: [pulseaudio] memblockq.c: memblockq requested: maxlength=33554432, tlength=0, base=4, prebuf=0, minreq=1 maxrewind=0
>D: [pulseaudio] memblockq.c: memblockq sanitized: maxlength=33554432, tlength=33554432, base=4, prebuf=0, minreq=4 maxrewind=0
>I: [pulseaudio] sink-input.c: Created input 2 "Event Sound" on alsa_output.pci-0000_00_1b.0.analog-stereo with sample spec s16le 1ch 48000Hz and channel map mono
>I: [pulseaudio] sink-input.c:     window.icon_name = "skype"
>I: [pulseaudio] sink-input.c:     application.icon_name = "skype"
>I: [pulseaudio] sink-input.c:     media.role = "event"
>I: [pulseaudio] sink-input.c:     media.name = "Event Sound"
>I: [pulseaudio] sink-input.c:     application.name = "Skype"
>I: [pulseaudio] sink-input.c:     native-protocol.peer = "UNIX socket client"
>I: [pulseaudio] sink-input.c:     native-protocol.version = "29"
>I: [pulseaudio] sink-input.c:     application.process.id = "762"
>I: [pulseaudio] sink-input.c:     application.process.user = "ross"
>I: [pulseaudio] sink-input.c:     application.process.host = "hobo"
>I: [pulseaudio] sink-input.c:     application.process.binary = "skype"
>I: [pulseaudio] sink-input.c:     application.language = "en_US.UTF-8"
>I: [pulseaudio] sink-input.c:     window.x11.display = ":0"
>I: [pulseaudio] sink-input.c:     application.process.machine_id = "5ce663ad0573416a8b1ced89348b22e5"
>I: [pulseaudio] sink-input.c:     application.process.session_id = "1"
>I: [pulseaudio] sink-input.c:     module-stream-restore.id = "sink-input-by-media-role:event"
>I: [pulseaudio] protocol-native.c: Requested tlength=30.00 ms, minreq=7.50 ms
>D: [pulseaudio] protocol-native.c: Adjust latency mode enabled, configuring sink latency to half of overall latency.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Cutting sleep time for the initial iterations by half.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Cutting sleep time for the initial iterations by half.
>D: [pulseaudio] protocol-native.c: Requested latency=7.50 ms, Received latency=7.50 ms
>D: [pulseaudio] memblockq.c: memblockq requested: maxlength=4194304, tlength=2160, base=2, prebuf=1442, minreq=720 maxrewind=0
>D: [pulseaudio] memblockq.c: memblockq sanitized: maxlength=4194304, tlength=2160, base=2, prebuf=1442, minreq=720 maxrewind=0
>I: [pulseaudio] protocol-native.c: Final latency 30.00 ms = 7.50 ms + 2*7.50 ms + 7.50 ms
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Cutting sleep time for the initial iterations by half.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Latency set to 7.50ms
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: hwbuf_unused=351360
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: setting avail_min=88021
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Requesting rewind due to latency change.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Requested volume: front-left: 21698 /  33% / -28.80 dB,   front-right: 21698 /  33% / -28.80 dB
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Got hardware volume: front-left: 21702 /  33% / -28.80 dB,   front-right: 21702 /  33% / -28.80 dB
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Calculated software volume: front-left: 65524 / 100% / -0.00 dB,   front-right: 65524 / 100% / -0.00 dB (accurate-enough=yes)
>D: [alsa-sink-ALC887-VD Analog] sink.c: Volume going down to 21698 at 239391726
>D: [alsa-sink-ALC887-VD Analog] sink.c: Next volume change in 1829164 usec
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Requested to rewind 352800 bytes.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Limited to 352320 bytes.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: before: 88080
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: after: 88080
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Rewound 352320 bytes.
>D: [alsa-sink-ALC887-VD Analog] sink.c: Processing rewind...
>D: [alsa-sink-ALC887-VD Analog] sink.c: latency = 2133
>D: [alsa-sink-ALC887-VD Analog] sink.c: Volume change to 21698 at 237556728 was written 5867 usec late
>D: [alsa-sink-ALC887-VD Analog] sink-input.c: Have to rewind 352320 bytes on render memblockq.
>D: [alsa-sink-ALC887-VD Analog] source.c: Processing rewind...
>D: [alsa-sink-ALC887-VD Analog] sink-input.c: Requesting rewind due to uncorking
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Requested to rewind 352800 bytes.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Limited to 1120 bytes.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: before: 280
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: after: 280
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Rewound 1120 bytes.
>D: [alsa-sink-ALC887-VD Analog] sink.c: Processing rewind...
>D: [alsa-sink-ALC887-VD Analog] sink.c: latency = 2306
>D: [alsa-sink-ALC887-VD Analog] source.c: Processing rewind...
>D: [pulseaudio] module-suspend-on-idle.c: Sink alsa_output.pci-0000_00_1b.0.analog-stereo becomes busy, resuming.
>D: [alsa-sink-ALC887-VD Analog] protocol-native.c: Requesting rewind due to end of underrun.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Requested to rewind 352800 bytes.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Limited to 1152 bytes.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: before: 288
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: after: 288
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Rewound 1152 bytes.
>D: [alsa-sink-ALC887-VD Analog] sink.c: Processing rewind...
>D: [alsa-sink-ALC887-VD Analog] sink.c: latency = 2224
>D: [alsa-sink-ALC887-VD Analog] sink-input.c: Have to rewind 1152 bytes on render memblockq.
>D: [alsa-sink-ALC887-VD Analog] source.c: Processing rewind...
>D: [alsa-sink-ALC887-VD Analog] sink-input.c: Requesting rewind due to corking
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Requested to rewind 352800 bytes.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Limited to 1088 bytes.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: before: 272
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: after: 272
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Rewound 1088 bytes.
>D: [alsa-sink-ALC887-VD Analog] sink.c: Processing rewind...
>D: [alsa-sink-ALC887-VD Analog] sink.c: latency = 1227
>D: [alsa-sink-ALC887-VD Analog] sink-input.c: Have to rewind 1088 bytes on render memblockq.
>D: [alsa-sink-ALC887-VD Analog] sink-input.c: Have to rewind 544 bytes on implementor.
>D: [alsa-sink-ALC887-VD Analog] flist.c: pulsecore/memblockq.c: list_items flist is full (don't worry)
>D: [alsa-sink-ALC887-VD Analog] flist.c: pulsecore/memblockq.c: list_items flist is full (don't worry)
>D: [alsa-sink-ALC887-VD Analog] flist.c: pulsecore/memblockq.c: list_items flist is full (don't worry)
>D: [alsa-sink-ALC887-VD Analog] flist.c: pulsecore/memblockq.c: list_items flist is full (don't worry)
>D: [alsa-sink-ALC887-VD Analog] flist.c: pulsecore/memblockq.c: list_items flist is full (don't worry)
>D: [alsa-sink-ALC887-VD Analog] source.c: Processing rewind...
>D: [alsa-sink-ALC887-VD Analog] sink.c: Found underrun 1184 bytes ago (160 bytes ahead in playback buffer)
>D: [alsa-sink-ALC887-VD Analog] sink.c: Found underrun 1184 bytes ago (160 bytes ahead in playback buffer)
>D: [pulseaudio] module-suspend-on-idle.c: Sink alsa_output.pci-0000_00_1b.0.analog-stereo becomes idle, timeout in 5 seconds.
>D: [alsa-sink-ALC887-VD Analog] sink.c: Found underrun 1184 bytes ago (160 bytes ahead in playback buffer)
>D: [alsa-sink-ALC887-VD Analog] sink.c: Found underrun 1184 bytes ago (128 bytes ahead in playback buffer)
>D: [alsa-sink-ALC887-VD Analog] sink.c: Found underrun 1184 bytes ago (128 bytes ahead in playback buffer)
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: hwbuf_unused=0
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: setting avail_min=88009
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Requested volume: front-left: 41086 /  63% / -12.17 dB,   front-right: 41086 /  63% / -12.17 dB
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Got hardware volume: front-left: 41350 /  63% / -12.00 dB,   front-right: 41350 /  63% / -12.00 dB
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Calculated software volume: front-left: 65118 /  99% / -0.17 dB,   front-right: 65118 /  99% / -0.17 dB (accurate-enough=yes)
>D: [alsa-sink-ALC887-VD Analog] sink.c: Volume going up to 41086 at 240611376
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Requested to rewind 352800 bytes.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Limited to 1056 bytes.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: before: 264
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: after: 264
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Rewound 1056 bytes.
>D: [alsa-sink-ALC887-VD Analog] sink.c: Processing rewind...
>D: [alsa-sink-ALC887-VD Analog] sink.c: latency = 1166
>D: [alsa-sink-ALC887-VD Analog] source.c: Processing rewind...
>D: [pulseaudio] module-suspend-on-idle.c: Sink alsa_output.pci-0000_00_1b.0.analog-stereo becomes idle, timeout in 5 seconds.
>D: [pulseaudio] core.c: Hmm, no streams around, trying to vacuum.
>I: [pulseaudio] sink-input.c: Freeing input 2 "Event Sound"
>D: [alsa-sink-ALC887-VD Analog] sink.c: Volume change to 41086 at 240605878 was written 21 usec late
>D: [pulseaudio] source-output.c: Negotiated format: pcm, format.sample_format = "\"s16le\""  format.rate = "48000"  format.channels = "1"  format.channel_map = "\"mono\""
>I: [pulseaudio] source-output.c: Trying to change sample rate
>I: [pulseaudio] source-output.c: Rate changed to 48000 Hz
>D: [pulseaudio] module-suspend-on-idle.c: Source alsa_input.pci-0000_00_1b.0.analog-stereo becomes busy, resuming.
>D: [pulseaudio] source.c: Suspend cause of source alsa_input.pci-0000_00_1b.0.analog-stereo is 0x0000, resuming
>I: [alsa-source-ALC887-VD Analog] alsa-source.c: Trying resume...
>I: [alsa-source-ALC887-VD Analog] alsa-util.c: Trying to disable ALSA period wakeups, using timers only
>D: [alsa-source-ALC887-VD Analog] alsa-util.c: Maximum hw buffer size is 21845 ms
>D: [alsa-source-ALC887-VD Analog] alsa-util.c: Set buffer size first (to 88200 samples), period size second (to 44100 samples).
>I: [alsa-source-ALC887-VD Analog] alsa-util.c: ALSA period wakeups disabled
>D: [alsa-source-ALC887-VD Analog] alsa-source.c: hwbuf_unused=0
>D: [alsa-source-ALC887-VD Analog] alsa-source.c: setting avail_min=88009
>I: [alsa-source-ALC887-VD Analog] alsa-source.c: Time scheduling watermark is 18.38ms
>I: [alsa-source-ALC887-VD Analog] alsa-source.c: Resumed successfully...
>I: [alsa-source-ALC887-VD Analog] alsa-source.c: Starting capture.
>D: [pulseaudio] module-suspend-on-idle.c: Source alsa_input.pci-0000_00_1b.0.analog-stereo becomes idle, timeout in 5 seconds.
>D: [pulseaudio] module-suspend-on-idle.c: Source alsa_input.pci-0000_00_1b.0.analog-stereo becomes idle, timeout in 5 seconds.
>I: [pulseaudio] resampler.c: Forcing resampler 'copy', because of fixed, identical sample rates.
>D: [pulseaudio] resampler.c: Channel matrix:
>D: [pulseaudio] resampler.c:        I00   I01 
>D: [pulseaudio] resampler.c:     +------------
>D: [pulseaudio] resampler.c: O00 | 0.500 0.500
>I: [pulseaudio] remap.c: Using generic matrix remapping
>D: [pulseaudio] resampler.c: Resampler:
>D: [pulseaudio] resampler.c:   rate 48000 -> 48000 (method copy)
>D: [pulseaudio] resampler.c:   format s16le -> s16le (intermediate s16le)
>D: [pulseaudio] resampler.c:   channels 2 -> 1 (resampling 1)
>D: [pulseaudio] memblockq.c: memblockq requested: maxlength=33554432, tlength=0, base=4, prebuf=0, minreq=1 maxrewind=0
>D: [pulseaudio] memblockq.c: memblockq sanitized: maxlength=33554432, tlength=33554432, base=4, prebuf=0, minreq=4 maxrewind=0
>I: [pulseaudio] source-output.c: Created output 1 "Input" on alsa_input.pci-0000_00_1b.0.analog-stereo with sample spec s16le 1ch 48000Hz and channel map mono
>I: [pulseaudio] source-output.c:     window.icon_name = "skype"
>I: [pulseaudio] source-output.c:     application.icon_name = "skype"
>I: [pulseaudio] source-output.c:     media.role = "phone"
>I: [pulseaudio] source-output.c:     media.name = "Input"
>I: [pulseaudio] source-output.c:     application.name = "Skype"
>I: [pulseaudio] source-output.c:     native-protocol.peer = "UNIX socket client"
>I: [pulseaudio] source-output.c:     native-protocol.version = "29"
>I: [pulseaudio] source-output.c:     application.process.id = "762"
>I: [pulseaudio] source-output.c:     application.process.user = "ross"
>I: [pulseaudio] source-output.c:     application.process.host = "hobo"
>I: [pulseaudio] source-output.c:     application.process.binary = "skype"
>I: [pulseaudio] source-output.c:     application.language = "en_US.UTF-8"
>I: [pulseaudio] source-output.c:     window.x11.display = ":0"
>I: [pulseaudio] source-output.c:     application.process.machine_id = "5ce663ad0573416a8b1ced89348b22e5"
>I: [pulseaudio] source-output.c:     application.process.session_id = "1"
>I: [pulseaudio] source-output.c:     module-stream-restore.id = "source-output-by-media-role:phone"
>D: [pulseaudio] memblockq.c: memblockq requested: maxlength=4194304, tlength=0, base=2, prebuf=1, minreq=0 maxrewind=0
>D: [pulseaudio] memblockq.c: memblockq sanitized: maxlength=4194304, tlength=4194304, base=2, prebuf=2, minreq=2 maxrewind=0
>I: [pulseaudio] protocol-native.c: Final latency 30.00 ms = 15.00 ms + 15.00 ms
>D: [alsa-source-ALC887-VD Analog] alsa-source.c: latency set to 15.00ms
>D: [alsa-source-ALC887-VD Analog] alsa-source.c: hwbuf_unused=349920
>D: [alsa-source-ALC887-VD Analog] alsa-source.c: setting avail_min=361
>D: [alsa-source-ALC887-VD Analog] alsa-source.c: latency set to 15.00ms
>D: [alsa-source-ALC887-VD Analog] alsa-source.c: hwbuf_unused=349920
>D: [alsa-source-ALC887-VD Analog] alsa-source.c: setting avail_min=361
>D: [alsa-source-ALC887-VD Analog] alsa-source.c: Requested volume: front-left: 16384 /  25% / -36.12 dB,   front-right: 16384 /  25% / -36.12 dB
>D: [alsa-source-ALC887-VD Analog] alsa-source.c: Got hardware volume: front-left: 15843 /  24% / -37.00 dB,   front-right: 15843 /  24% / -37.00 dB
>D: [alsa-source-ALC887-VD Analog] alsa-source.c: Calculated software volume: front-left: 67774 / 103% / 0.87 dB,   front-right: 67774 / 103% / 0.87 dB (accurate-enough=no)
>D: [alsa-source-ALC887-VD Analog] source.c: Volume not changing
>D: [pulseaudio] module-suspend-on-idle.c: Source alsa_input.pci-0000_00_1b.0.analog-stereo becomes busy, resuming.
>D: [pulseaudio] module-suspend-on-idle.c: Source alsa_input.pci-0000_00_1b.0.analog-stereo becomes idle, timeout in 5 seconds.
>D: [alsa-source-ALC887-VD Analog] alsa-source.c: hwbuf_unused=0
>D: [alsa-source-ALC887-VD Analog] alsa-source.c: setting avail_min=87841
>D: [alsa-source-ALC887-VD Analog] alsa-source.c: Requested volume: front-left: 16384 /  25% / -36.12 dB,   front-right: 16384 /  25% / -36.12 dB
>D: [alsa-source-ALC887-VD Analog] alsa-source.c: Got hardware volume: front-left: 15843 /  24% / -37.00 dB,   front-right: 15843 /  24% / -37.00 dB
>D: [alsa-source-ALC887-VD Analog] alsa-source.c: Calculated software volume: front-left: 67774 / 103% / 0.87 dB,   front-right: 67774 / 103% / 0.87 dB (accurate-enough=no)
>D: [alsa-source-ALC887-VD Analog] source.c: Volume not changing
>D: [pulseaudio] module-suspend-on-idle.c: Source alsa_input.pci-0000_00_1b.0.analog-stereo becomes idle, timeout in 5 seconds.
>D: [pulseaudio] core.c: Hmm, no streams around, trying to vacuum.
>I: [pulseaudio] source-output.c: Freeing output 1 "Input"
>D: [pulseaudio] sink-input.c: Negotiated format: pcm, format.sample_format = "\"s16le\""  format.rate = "48000"  format.channels = "1"  format.channel_map = "\"mono\""
>I: [pulseaudio] sink-input.c: Trying to change sample rate
>I: [pulseaudio] sink-input.c: Rate changed to 48000 Hz
>I: [pulseaudio] module-stream-restore.c: Restoring volume for sink input sink-input-by-media-role:event.
>I: [pulseaudio] module-stream-restore.c: Restoring mute state for sink input sink-input-by-media-role:event.
>D: [pulseaudio] module-suspend-on-idle.c: Sink alsa_output.pci-0000_00_1b.0.analog-stereo becomes busy, resuming.
>D: [pulseaudio] module-suspend-on-idle.c: Sink alsa_output.pci-0000_00_1b.0.analog-stereo becomes idle, timeout in 5 seconds.
>I: [pulseaudio] resampler.c: Forcing resampler 'copy', because of fixed, identical sample rates.
>D: [pulseaudio] resampler.c: Channel matrix:
>D: [pulseaudio] resampler.c:        I00 
>D: [pulseaudio] resampler.c:     +------
>D: [pulseaudio] resampler.c: O00 | 1.000
>D: [pulseaudio] resampler.c: O01 | 1.000
>I: [pulseaudio] remap_sse.c: Using SSE2 mono to stereo remapping
>D: [pulseaudio] resampler.c: Resampler:
>D: [pulseaudio] resampler.c:   rate 48000 -> 48000 (method copy)
>D: [pulseaudio] resampler.c:   format s16le -> s16le (intermediate s16le)
>D: [pulseaudio] resampler.c:   channels 1 -> 2 (resampling 1)
>D: [pulseaudio] memblockq.c: memblockq requested: maxlength=33554432, tlength=0, base=4, prebuf=0, minreq=1 maxrewind=0
>D: [pulseaudio] memblockq.c: memblockq sanitized: maxlength=33554432, tlength=33554432, base=4, prebuf=0, minreq=4 maxrewind=0
>I: [pulseaudio] sink-input.c: Created input 3 "Event Sound" on alsa_output.pci-0000_00_1b.0.analog-stereo with sample spec s16le 1ch 48000Hz and channel map mono
>I: [pulseaudio] sink-input.c:     window.icon_name = "skype"
>I: [pulseaudio] sink-input.c:     application.icon_name = "skype"
>I: [pulseaudio] sink-input.c:     media.role = "event"
>I: [pulseaudio] sink-input.c:     media.name = "Event Sound"
>I: [pulseaudio] sink-input.c:     application.name = "Skype"
>I: [pulseaudio] sink-input.c:     native-protocol.peer = "UNIX socket client"
>I: [pulseaudio] sink-input.c:     native-protocol.version = "29"
>I: [pulseaudio] sink-input.c:     application.process.id = "762"
>I: [pulseaudio] sink-input.c:     application.process.user = "ross"
>I: [pulseaudio] sink-input.c:     application.process.host = "hobo"
>I: [pulseaudio] sink-input.c:     application.process.binary = "skype"
>I: [pulseaudio] sink-input.c:     application.language = "en_US.UTF-8"
>I: [pulseaudio] sink-input.c:     window.x11.display = ":0"
>I: [pulseaudio] sink-input.c:     application.process.machine_id = "5ce663ad0573416a8b1ced89348b22e5"
>I: [pulseaudio] sink-input.c:     application.process.session_id = "1"
>I: [pulseaudio] sink-input.c:     module-stream-restore.id = "sink-input-by-media-role:event"
>I: [pulseaudio] protocol-native.c: Requested tlength=30.00 ms, minreq=7.50 ms
>D: [pulseaudio] protocol-native.c: Adjust latency mode enabled, configuring sink latency to half of overall latency.
>D: [pulseaudio] protocol-native.c: Requested latency=7.50 ms, Received latency=7.50 ms
>D: [pulseaudio] memblockq.c: memblockq requested: maxlength=4194304, tlength=2160, base=2, prebuf=1442, minreq=720 maxrewind=0
>D: [pulseaudio] memblockq.c: memblockq sanitized: maxlength=4194304, tlength=2160, base=2, prebuf=1442, minreq=720 maxrewind=0
>I: [pulseaudio] protocol-native.c: Final latency 30.00 ms = 7.50 ms + 2*7.50 ms + 7.50 ms
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Latency set to 7.50ms
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: hwbuf_unused=351360
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: setting avail_min=88021
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Requesting rewind due to latency change.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Requested volume: front-left: 21698 /  33% / -28.80 dB,   front-right: 21698 /  33% / -28.80 dB
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Got hardware volume: front-left: 21702 /  33% / -28.80 dB,   front-right: 21702 /  33% / -28.80 dB
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Calculated software volume: front-left: 65524 / 100% / -0.00 dB,   front-right: 65524 / 100% / -0.00 dB (accurate-enough=yes)
>D: [alsa-sink-ALC887-VD Analog] sink.c: Volume going down to 21698 at 244259610
>D: [alsa-sink-ALC887-VD Analog] ratelimit.c: 702 events suppressed
>D: [alsa-sink-ALC887-VD Analog] sink.c: Next volume change in 1682598 usec
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Requested to rewind 352800 bytes.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Limited to 324384 bytes.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: before: 81096
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: after: 81096
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Rewound 324384 bytes.
>D: [alsa-sink-ALC887-VD Analog] sink.c: Processing rewind...
>D: [alsa-sink-ALC887-VD Analog] sink.c: latency = 1071
>D: [alsa-sink-ALC887-VD Analog] sink.c: Volume change to 21698 at 242570112 was written 6929 usec late
>D: [alsa-sink-ALC887-VD Analog] sink-input.c: Have to rewind 324384 bytes on render memblockq.
>D: [alsa-sink-ALC887-VD Analog] source.c: Processing rewind...
>D: [alsa-sink-ALC887-VD Analog] sink-input.c: Requesting rewind due to uncorking
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Requested to rewind 352800 bytes.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Limited to 1184 bytes.
>D: [pulseaudio] module-suspend-on-idle.c: Sink alsa_output.pci-0000_00_1b.0.analog-stereo becomes busy, resuming.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: before: 296
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: after: 296
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Rewound 1184 bytes.
>D: [alsa-sink-ALC887-VD Analog] sink.c: Processing rewind...
>D: [alsa-sink-ALC887-VD Analog] sink.c: latency = 1046
>D: [alsa-sink-ALC887-VD Analog] source.c: Processing rewind...
>D: [alsa-sink-ALC887-VD Analog] protocol-native.c: Requesting rewind due to end of underrun.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Requested to rewind 352800 bytes.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Limited to 1152 bytes.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: before: 288
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: after: 288
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Rewound 1152 bytes.
>D: [alsa-sink-ALC887-VD Analog] sink.c: Processing rewind...
>D: [alsa-sink-ALC887-VD Analog] sink.c: latency = 1192
>D: [alsa-sink-ALC887-VD Analog] sink-input.c: Have to rewind 1152 bytes on render memblockq.
>D: [alsa-sink-ALC887-VD Analog] source.c: Processing rewind...
>D: [alsa-sink-ALC887-VD Analog] sink-input.c: Requesting rewind due to corking
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Requested to rewind 1184 bytes.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Limited to 1184 bytes.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: before: 296
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: after: 296
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Rewound 1184 bytes.
>D: [alsa-sink-ALC887-VD Analog] sink.c: Processing rewind...
>D: [alsa-sink-ALC887-VD Analog] sink.c: latency = 1119
>D: [alsa-sink-ALC887-VD Analog] sink-input.c: Have to rewind 1184 bytes on render memblockq.
>D: [alsa-sink-ALC887-VD Analog] sink-input.c: Have to rewind 592 bytes on implementor.
>D: [alsa-sink-ALC887-VD Analog] source.c: Processing rewind...
>D: [alsa-sink-ALC887-VD Analog] sink.c: Found underrun 1184 bytes ago (256 bytes ahead in playback buffer)
>D: [alsa-sink-ALC887-VD Analog] sink.c: Found underrun 1184 bytes ago (256 bytes ahead in playback buffer)
>D: [pulseaudio] module-suspend-on-idle.c: Sink alsa_output.pci-0000_00_1b.0.analog-stereo becomes idle, timeout in 5 seconds.
>D: [alsa-sink-ALC887-VD Analog] sink.c: Found underrun 1184 bytes ago (256 bytes ahead in playback buffer)
>D: [alsa-sink-ALC887-VD Analog] sink.c: Found underrun 1184 bytes ago (224 bytes ahead in playback buffer)
>D: [alsa-sink-ALC887-VD Analog] sink.c: Found underrun 1184 bytes ago (224 bytes ahead in playback buffer)
>D: [alsa-sink-ALC887-VD Analog] sink.c: Found underrun 1184 bytes ago (224 bytes ahead in playback buffer)
>D: [alsa-sink-ALC887-VD Analog] sink.c: Found underrun 1184 bytes ago (224 bytes ahead in playback buffer)
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: hwbuf_unused=0
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: setting avail_min=88009
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Requested volume: front-left: 41086 /  63% / -12.17 dB,   front-right: 41086 /  63% / -12.17 dB
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Got hardware volume: front-left: 41350 /  63% / -12.00 dB,   front-right: 41350 /  63% / -12.00 dB
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Calculated software volume: front-left: 65118 /  99% / -0.17 dB,   front-right: 65118 /  99% / -0.17 dB (accurate-enough=yes)
>D: [alsa-sink-ALC887-VD Analog] sink.c: Volume going up to 41086 at 242592776
>D: [alsa-sink-ALC887-VD Analog] sink.c: Next volume change in 15133 usec
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Requested to rewind 352800 bytes.
>D: [pulseaudio] module-suspend-on-idle.c: Sink alsa_output.pci-0000_00_1b.0.analog-stereo becomes idle, timeout in 5 seconds.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Limited to 1152 bytes.
>D: [pulseaudio] core.c: Hmm, no streams around, trying to vacuum.
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: before: 288
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: after: 288
>D: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Rewound 1152 bytes.
>D: [alsa-sink-ALC887-VD Analog] sink.c: Processing rewind...
>D: [alsa-sink-ALC887-VD Analog] sink.c: latency = 1107
>D: [alsa-sink-ALC887-VD Analog] sink.c: Next volume change in 9107 usec
>D: [alsa-sink-ALC887-VD Analog] source.c: Processing rewind...
>D: [alsa-sink-ALC887-VD Analog] sink.c: Next volume change in 9053 usec
>I: [pulseaudio] sink-input.c: Freeing input 3 "Event Sound"
>D: [alsa-sink-ALC887-VD Analog] sink.c: Volume change to 41086 at 242586778 was written 25 usec late
>I: [pulseaudio] module-suspend-on-idle.c: Source alsa_input.pci-0000_00_1b.0.analog-stereo idle for too long, suspending ...
>D: [pulseaudio] source.c: Suspend cause of source alsa_input.pci-0000_00_1b.0.analog-stereo is 0x0004, suspending
>I: [alsa-source-ALC887-VD Analog] alsa-source.c: Device suspended...
>D: [pulseaudio] core.c: Hmm, no streams around, trying to vacuum.
>I: [pulseaudio] module-suspend-on-idle.c: Sink alsa_output.pci-0000_00_1b.0.analog-stereo idle for too long, suspending ...
>D: [pulseaudio] sink.c: Suspend cause of sink alsa_output.pci-0000_00_1b.0.analog-stereo is 0x0004, suspending
>I: [alsa-sink-ALC887-VD Analog] alsa-sink.c: Device suspended...

Actions: View

Attachments on bug 76532: 96261 | 96262

Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.