Attachment 59487 Details for Bug 48307 – Log of delayed rewind

Log of delayed rewind

log.txt (text/plain), 6.98 KB, created by Tanu Kaskinen on 2012-04-04 11:58:24 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Tanu Kaskinen

Created: 2012-04-04 11:58:24 UTC

Size: 6.98 KB

patch

obsolete

>Apr  3 20:08:39 glyph pulseaudio[1560]: [pulseaudio] core-scache.c: Playing sample "audio-volume-change" on "alsa_output.pci-0000_00_1b.0.analog-stereo"
>Apr  3 20:08:39 glyph pulseaudio[1560]: [pulseaudio] memblockq.c: memblockq requested: maxlength=11776, tlength=0, base=4, prebuf=1, minreq=1 maxrewind=0
>Apr  3 20:08:39 glyph pulseaudio[1560]: [pulseaudio] memblockq.c: memblockq sanitized: maxlength=11776, tlength=11776, base=4, prebuf=4, minreq=4 maxrewind=0
>Apr  3 20:08:39 glyph pulseaudio[1560]: [pulseaudio] module-stream-restore.c: Not restoring device for stream sink-input-by-media-role:event, because already set to 'alsa_output.pci-0000_00_1b.0.analog-stereo'.
>Apr  3 20:08:39 glyph pulseaudio[1560]: [pulseaudio] module-intended-roles.c: Not setting device for stream audio-volume-change, because already set.
>Apr  3 20:08:39 glyph pulseaudio[1560]: [pulseaudio] module-suspend-on-idle.c: Sink alsa_output.pci-0000_00_1b.0.analog-stereo becomes busy.
>Apr  3 20:08:39 glyph pulseaudio[1560]: [pulseaudio] memblockq.c: memblockq requested: maxlength=33554432, tlength=0, base=4, prebuf=0, minreq=1 maxrewind=0
>Apr  3 20:08:39 glyph pulseaudio[1560]: [pulseaudio] memblockq.c: memblockq sanitized: maxlength=33554432, tlength=33554432, base=4, prebuf=0, minreq=4 maxrewind=0
>Apr  3 20:08:39 glyph pulseaudio[1560]: [pulseaudio] core-util.c: posix_madvise() worked fine!
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c: Requested volume: 0:  18% 1:  18%
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c:            in dB: 0: -45.00 dB 1: -45.00 dB
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c: Got hardware volume: 0:  18% 1:  18%
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c:               in dB: 0: -45.00 dB 1: -45.00 dB
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c: Calculated software volume: 0: 100% 1: 100% (accurate-enough=yes)
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c:                      in dB: 0: 0.00 dB 1: 0.00 dB
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] sink.c: Volume not changing
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c: Requested to rewind 352800 bytes.
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c: Limited to 166976 bytes.
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c: before: 41744
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c: after: 41744
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c: Rewound 166976 bytes.
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] sink.c: Processing rewind...
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] sink.c: latency = 1095
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] sink-input.c: Have to rewind 166976 bytes on render memblockq.
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] source.c: Processing rewind...
>Apr  3 20:08:39 glyph pulseaudio[1560]: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Core1.Stream added for object /org/pulseaudio/core1/playback_stream18
>Apr  3 20:08:39 glyph pulseaudio[1560]: [pulseaudio] protocol-native.c: Client gnome-settings-daemon changes volume of sink alsa_output.pci-0000_00_1b.0.analog-stereo.
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c: Requested volume: 0:  24% 1:  24%
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c:            in dB: 0: -37.42 dB 1: -37.42 dB
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c: Got hardware volume: 0:  24% 1:  24%
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c:               in dB: 0: -37.40 dB 1: -37.40 dB
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c: Calculated software volume: 0: 100% 1: 100% (accurate-enough=yes)
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c:                      in dB: 0: -0.03 dB 1: -0.03 dB
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] sink.c: Volume going up to 15586 at 2135715906
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] sink.c: Next volume change in 964627 usec
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] sink.c: Next volume change in 964329 usec
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] sink.c: Next volume change in 963684 usec
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] sink.c: Next volume change in 963521 usec
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] sink.c: Next volume change in 963300 usec
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] sink.c: Next volume change in 963060 usec
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] sink.c: Next volume change in 962776 usec
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] sink.c: Next volume change in 962530 usec
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] sink.c: Next volume change in 962315 usec
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] sink.c: Next volume change in 962050 usec
>Apr  3 20:08:39 glyph pulseaudio[1560]: [alsa-sink] sink.c: Next volume change in 961804 usec
>Apr  3 20:08:40 glyph pulseaudio[1560]: [alsa-sink] sink.c: Volume change to 15586 at 2135715906 was written 23 usec late
>Apr  3 20:08:41 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c: Latency set to 960.00ms
>Apr  3 20:08:41 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c: hwbuf_unused=183456
>Apr  3 20:08:41 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c: setting avail_min=87319
>Apr  3 20:08:41 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c: Requested volume: 0:  24% 1:  24%
>Apr  3 20:08:41 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c:            in dB: 0: -37.42 dB 1: -37.42 dB
>Apr  3 20:08:41 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c: Got hardware volume: 0:  24% 1:  24%
>Apr  3 20:08:41 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c:               in dB: 0: -37.40 dB 1: -37.40 dB
>Apr  3 20:08:41 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c: Calculated software volume: 0: 100% 1: 100% (accurate-enough=yes)
>Apr  3 20:08:41 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c:                      in dB: 0: -0.03 dB 1: -0.03 dB
>Apr  3 20:08:41 glyph pulseaudio[1560]: [alsa-sink] sink.c: Volume not changing
>Apr  3 20:08:41 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c: Requested to rewind 352800 bytes.
>Apr  3 20:08:41 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c: Limited to 166944 bytes.
>Apr  3 20:08:41 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c: before: 41736
>Apr  3 20:08:41 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c: after: 41736
>Apr  3 20:08:41 glyph pulseaudio[1560]: [alsa-sink] alsa-sink.c: Rewound 166944 bytes.
>Apr  3 20:08:41 glyph pulseaudio[1560]: [alsa-sink] sink.c: Processing rewind...
>Apr  3 20:08:41 glyph pulseaudio[1560]: [alsa-sink] sink.c: latency = 469
>Apr  3 20:08:41 glyph pulseaudio[1560]: [alsa-sink] sink-input.c: Have to rewind 166944 bytes on render memblockq.
>Apr  3 20:08:41 glyph pulseaudio[1560]: [alsa-sink] source.c: Processing rewind...
>Apr  3 20:08:41 glyph pulseaudio[1560]: [pulseaudio] protocol-dbus.c: Interface org.PulseAudio.Core1.Stream removed from object /org/pulseaudio/core1/playback_stream18
>

Actions: View

Attachments on bug 48307: 59487

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.