[MPlayer-dev-eng] [PATCH] Make volume restore with pulseaudio work
Marcus Blumhagen
marcus.blumhagen at web.de
Mon Oct 19 14:02:26 CEST 2009
On Sun, Oct 18, 2009 at 09:38:27AM +0200, Reimar Döffinger wrote:
> On Sat, Oct 17, 2009 at 06:46:10PM +0200, Marcus Blumhagen wrote:
> > Volume control inside mplayer also works flawlessly. Also setting the
> > initial volume of mplayer using -volume works and results in the
> > specified value rather then the restored volume.
>
> Maybe my mail didn't get through, but I asked why -volume stops working when
> pa_cvolume_reset is not called.
> Probably it would be more correct to call pa_cvolume_init, but the documentation
> says the volume is not set to valid, and I have not found any function to
> do that.
Disabling the call of pa_cvolume_reset results in the following error,
when -volume >-1 is specified:
$ mplayer -v -noconfig all -volume 0 -ao pulse Elephants_Dream_HD.avi
[...]
Assertion 'channels > 0' failed at pulse/volume.c:76, function pa_cvolume_set(). Aborting.
MPlayer interrupted by signal 6 in module: av_init
[...]
For the full output have a look at the attachment.
I think this has to do with pa_cvolume_init being called in
pulsecore/protocol-native.c, which results in volume.channels being
set to 0. The definition of that function is this:
pa_cvolume* pa_cvolume_init(pa_cvolume *a) {
unsigned c;
pa_assert(a);
a->channels = 0;
for (c = 0; c < PA_CHANNELS_MAX; c++)
a->values[c] = PA_VOLUME_INVALID;
return a;
}
In contrast to that pa_cvolume_reset will set volume.channels to the
actual requested number of channels and values[] to PA_VOLUME_NORM.
So I think pa_cvolume_reset is the correct way to initialize the pulse
audio stream of mplayer, because it doesn´t interfere with volume
restoration and sets the volume to PA_VOLUME_NORM if
module-stream-restore is not loaded. I had a closer look at the output
of pulseaudio -vvvvC and saw that no matter what -volume is set to
module-stream-restore restores the volume of the stream, but after the
stream is initialized the volume will be set to the requested value of
-volume. I think this is related to how -volume works in mplayer but
haven´t checked that. My guess would be that mplayer waits for the
audio output being ready and then applies -volume.
For reference I attached a rather long log of pulseaudio -vvvvC with
timestamps activated after it was started, so the interesting part is
timestamped. I ran mplayer -volume 0 and mplayer -volume 50, here is
an excerpt of the relevant output:
pulseaudio log of mplayer -volume 50 ...:
[...]
( 0.004| 0.000) I: module-stream-restore.c: Restoring volume for sink input sink-input-by-application-name:MPlayer.
[...]
( 0.037| 0.016) D: protocol-native.c: Client mplayer changes volume of sink input audio stream.
( 0.038| 0.000) D: alsa-sink.c: Requested volume: 0: 50% 1: 50%
[...]
pulseaudio log of mplayer -volume 0 ...:
[...]
( 12.803| 0.000) I: module-stream-restore.c: Restoring volume for sink input sink-input-by-application-name:MPlayer.
[...]
( 12.825| 0.006) D: protocol-native.c: Client mplayer changes volume of sink input audio stream.
( 12.825| 0.000) D: alsa-sink.c: Requested volume: 0: 0% 1: 0%
I hope this clears up things a little bit and this patch can make its
way into svn. ;)
Marcus
--
Marcus Blumhagen
"Any intelligent fool can make things bigger, more complex, and more
violent. It takes a touch of genius -- and a lot of courage -- to move
in the opposite direction."
-- Albert Einstein
-------------- next part --------------
MPlayer SVN-r29779-4.3.4 (C) 2000-2009 MPlayer Team
CPU vendor name: AuthenticAMD max cpuid level: 1
CPU: AMD Athlon(tm) 64 X2 Dual Core Processor 5000+ (Family: 15, Model: 107, Stepping: 1)
extended cpuid-level: 24
extended cache-info: 33587520
Detected cache-line size is 64 bytes
CPUflags: MMX: 1 MMX2: 1 3DNow: 1 3DNowExt: 1 SSE: 1 SSE2: 1 SSSE3: 0
Compiled for x86 CPU with extensions: MMX MMX2 3DNow 3DNowExt SSE SSE2 CMOV
get_path('codecs.conf') -> '/home/natas/.mplayer/codecs.conf'
Reading /home/natas/.mplayer/codecs.conf: Can't open '/home/natas/.mplayer/codecs.conf': No such file or directory
Reading /etc/mplayer/codecs.conf: Can't open '/etc/mplayer/codecs.conf': No such file or directory
Using built-in default codecs.conf.
Configuration: --prefix=/usr --confdir=/etc/mplayer
CommandLine: '-v' '-noconfig' 'all' '-volume' '0' '-ao' 'pulse' 'Elephants_Dream_HD.avi'
init_freetype
Using MMX (with tiny bit MMX2) Optimized OnScreenDisplay
get_path('fonts') -> '/home/natas/.mplayer/fonts'
Using nanosleep() timing
get_path('input.conf') -> '/home/natas/.mplayer/input.conf'
Parsing input config file /home/natas/.mplayer/input.conf
Input config file /home/natas/.mplayer/input.conf parsed: 68 binds
get_path('Elephants_Dream_HD.avi.conf') -> '/home/natas/.mplayer/Elephants_Dream_HD.avi.conf'
Playing Elephants_Dream_HD.avi.
get_path('sub/') -> '/home/natas/.mplayer/sub/'
[file] File size is 854537054 bytes
STREAM: [file] Elephants_Dream_HD.avi
STREAM: Description: File
STREAM: Author: Albeu
STREAM: Comment: based on the code from ??? (probably Arpi)
LAVF_check: AVI format
AVI file format detected.
list_end=0xFFAE
======= AVI Header =======
us/frame: 41667 (fps=24.000)
max bytes/sec: 0
padding: 0
MainAVIHeader.dwFlags: (272) HAS_INDEX IS_INTERLEAVED
frames total: 39 initial: 0
streams: 2
Suggested BufferSize: 0
Size: 1920 x 1080
==========================
list_end=0x12C
==> Found video stream: 0
[aviheader] Video stream found, -vid 0
====== STREAM Header =====
Type: vids FCC: MP42 (3234504D)
Flags: 0
Priority: 0 Language: 0
InitialFrames: 0
Rate: 5000000/208333 = 24.000
Start: 0 Len: 15691
Suggested BufferSize: 1127016
Quality 0
Sample size: 0
==========================
Found 'bih', 40 bytes of 40
======= VIDEO Format ======
biSize 40
biWidth 1920
biHeight 1080
biPlanes 1
biBitCount 24
biCompression 842289229='MP42'
biSizeImage 6220800
===========================
Regenerating keyframe table for DIVX3 video.
====== AVI Super Index Header ========
FCC (indx) dwSize (72) wLongsPerEntry(4)
bIndexSubType (0) bIndexType (0)
nEntriesInUse (3) dwChunkId (00dc)
dwReserved[0] (0) dwReserved[1] (0) dwReserved[2] (0)
===========================
ODML (00dc): [0] 0x000000000011fac6 0x0158 39
ODML (00dc): [1] 0x000000002fe0c646 0x1d3a8 14961
ODML (00dc): [2] 0x0000000032ef0f8e 0x15b8 691
list_end=0x200
==> Found audio stream: 1
[aviheader] Audio stream found, -aid 1
====== STREAM Header =====
Type: auds FCC: (0)
Flags: 1
Priority: 0 Language: 0
InitialFrames: 0
Rate: 56000/1 = 56000.000
Start: 0 Len: 36614144
Suggested BufferSize: 7168
Quality -1
Sample size: 1
==========================
Found 'wf', 18 bytes of 18
======= WAVE Format =======
Format Tag: 8192 (0x2000)
Channels: 5
Samplerate: 48000
avg byte/sec: 56000
Block align: 1
bits/sample: 0
cbSize: 0
==========================================================================
====== AVI Super Index Header ========
FCC (indx) dwSize (72) wLongsPerEntry(4)
bIndexSubType (0) bIndexType (0)
nEntriesInUse (3) dwChunkId (01wb)
dwReserved[0] (0) dwReserved[1] (0) dwReserved[2] (0)
===========================
ODML (01wb): [0] 0x000000000011fc1e 0x0108 103936
ODML (01wb): [1] 0x000000002fe299ee 0x13080 34908160
ODML (01wb): [2] 0x0000000032ef2546 0x0e18 1602048
list_end=0x30C
AVI: dmlh found (size=248) (total_frames=15691)
list_end=0xFFF4
hdr=Software size=41
Software : AVI-Mux GUI 1.17.5, Apr 5 2006 18:41:17
list_end=0x11FD26
Found movie at 0x10000 - 0x11FD26
Reading INDEX block, 68 chunks for 39 frames (fpos=1178926).
Additional RIFF header...
list_end=0x32EF335E
Found movie at 0x10000 - 0x32EF335E
AVI: ODML: Building ODML index (2 superindexchunks).
====== AVI Standard Index Header ========
FCC (ix00) dwSize (336) wLongsPerEntry(2)
bIndexSubType (0) bIndexType (1)
nEntriesInUse (39) dwChunkId (00dc)
qwBaseOffset (0x1000C) dwReserved3 (0)
===========================
====== AVI Standard Index Header ========
FCC (ix00) dwSize (119712) wLongsPerEntry(2)
bIndexSubType (0) bIndexType (1)
nEntriesInUse (14961) dwChunkId (00dc)
qwBaseOffset (0x120192) dwReserved3 (0)
===========================
====== AVI Standard Index Header ========
FCC (ix00) dwSize (5552) wLongsPerEntry(2)
bIndexSubType (0) bIndexType (1)
nEntriesInUse (691) dwChunkId (00dc)
qwBaseOffset (0x120192) dwReserved3 (0)
===========================
====== AVI Standard Index Header ========
FCC (ix01) dwSize (256) wLongsPerEntry(2)
bIndexSubType (0) bIndexType (1)
nEntriesInUse (29) dwChunkId (01wb)
qwBaseOffset (0x1000C) dwReserved3 (0)
===========================
====== AVI Standard Index Header ========
FCC (ix01) dwSize (77944) wLongsPerEntry(2)
bIndexSubType (0) bIndexType (1)
nEntriesInUse (9740) dwChunkId (01wb)
qwBaseOffset (0x120192) dwReserved3 (0)
===========================
====== AVI Standard Index Header ========
FCC (ix01) dwSize (3600) wLongsPerEntry(2)
bIndexSubType (0) bIndexType (1)
nEntriesInUse (447) dwChunkId (01wb)
qwBaseOffset (0x120192) dwReserved3 (0)
===========================
AVI index offset: 0x0 (movi=0x10000 idx0=0x1000C idx1=0x10E14)
Auto-selected AVI audio ID = 1
Auto-selected AVI video ID = 0
AVI: Searching for audio stream (id:1)
AVI video size=817358648 (15691) audio size=36614144 (36614144)
VIDEO: [MP42] 1920x1080 24bpp 24.000 fps 10001.5 kbps (1220.9 kbyte/s)
Auto-selected AVI audio ID = 1
[V] filefmt:3 fourcc:0x3234504D size:1920x1080 fps:24.000 ftime:=0.0417
Clip info:
Software: AVI-Mux GUI 1.17.5, Apr 5 2006 18:41:17
get_path('sub/') -> '/home/natas/.mplayer/sub/'
X11 opening display: :0.0
vo: X11 color mask: FFFFFF (R:FF0000 G:FF00 B:FF)
vo: X11 running at 1280x1024 with depth 24 and 32 bpp (":0.0" => local display)
[x11] Detected wm supports NetWM.
[x11] Detected wm supports FULLSCREEN state.
[x11] Detected wm supports ABOVE state.
[x11] Detected wm supports BELOW state.
[x11] Current fstype setting honours FULLSCREEN ABOVE BELOW X atoms
[VO_XV] Using Xv Adapter #0 (NV17 Video Texture)
[xv common] Drawing no colorkey.
[xv common] Maximum source image dimensions: 2046x2046
==========================================================================
Opening video decoder: [ffmpeg] FFmpeg's libavcodec codec family
INFO: libavcodec init OK!
Selected video codec: [ffmp42] vfm: ffmpeg (FFmpeg MSMPEG-4 v2)
==========================================================================
==========================================================================
Opening audio decoder: [liba52] AC3 decoding with liba52
dec_audio: Allocating 3840 bytes for input buffer.
dec_audio: Allocating 6144 + 65536 = 71680 bytes for output buffer.
Using SSE optimized IMDCT transform
AC3: 5.1 (3f+2r+lfe) 48000 Hz 448.0 kbit/s
A52 flags before a52_frame: 0x2A
A52 flags after a52_frame: 0xA
Using MMX optimized resampler
AUDIO: 48000 Hz, 2 ch, s16le, 448.0 kbit/29.17% (ratio: 56000->192000)
Selected audio codec: [a52] afm: liba52 (AC3-liba52)
==========================================================================
Building audio filter chain for 48000Hz/2ch/s16le -> 0Hz/0ch/??...
[libaf] Adding filter dummy
[dummy] Was reinitialized: 48000Hz/2ch/s16le
[dummy] Was reinitialized: 48000Hz/2ch/s16le
Trying preferred audio driver 'pulse', options '[none]'
AO: [pulse] 48000Hz 2ch s16le (2 bytes per sample)
AO: Description: PulseAudio audio output
AO: Author: Lennart Poettering
Building audio filter chain for 48000Hz/2ch/s16le -> 48000Hz/2ch/s16le...
[dummy] Was reinitialized: 48000Hz/2ch/s16le
[dummy] Was reinitialized: 48000Hz/2ch/s16le
Assertion 'channels > 0' failed at pulse/volume.c:76, function pa_cvolume_set(). Aborting.
MPlayer interrupted by signal 6 in module: av_init
- MPlayer crashed. This shouldn't happen.
It can be a bug in the MPlayer code _or_ in your drivers _or_ in your
gcc version. If you think it's MPlayer's fault, please read
DOCS/HTML/en/bugreports.html and follow the instructions there. We can't and
won't help unless you provide this information when reporting a possible bug.
-------------- next part --------------
I: main.c: setrlimit(RLIMIT_NICE, (31, 31)) fehlgeschlagen: Die Operation ist nicht erlaubt
D: core-rtclock.c: Timer slack is set to 50 us.
I: core-util.c: Failed to acquire high-priority scheduling: Datei oder Verzeichnis nicht gefunden
I: main.c: Dies ist PulseAudio 0.9.19
D: main.c: Kompilier-Host: x86_64-pc-linux-gnu
D: main.c: Kompilier-CFLAGS: -g -O2 -g -Wall -O2 -Wall -W -Wextra -pipe -Wno-long-long -Winline -Wvla -Wno-overlength-strings -Wunsafe-loop-optimizations -Wundef -Wformat=2 -Wlogical-op -Wsign-compare -Wformat-security -Wmissing-include-dirs -Wformat-nonliteral -Wold-style-definition -Wpointer-arith -Winit-self -Wdeclaration-after-statement -Wfloat-equal -Wmissing-prototypes -Wstrict-prototypes -Wredundant-decls -Wmissing-declarations -Wmissing-noreturn -Wshadow -Wendif-labels -Wcast-align -Wstrict-aliasing=2 -Wwrite-strings -Wno-unused-parameter -ffast-math -Wp,-D_FORTIFY_SOURCE=2 -fno-common -fdiagnostics-show-option
D: main.c: Laufe auf Host: Linux x86_64 2.6.30-amd64-custom #1 SMP PREEMPT Sun Oct 11 19:17:23 CEST 2009
D: main.c: 2 CPUs gefunden.
I: main.c: Seitengröße ist 4096 Bytes.
D: main.c: Kompiliere mit Valgrind-Unterstützung: nein
D: main.c: Läuft im Valgrind-Modus: no
D: main.c: Optimiertes Build: ja
D: main.c: Alle Ansprüche aktiviert.
I: main.c: System- ID ist db26de6e1db656e815073c29482401b4.
I: main.c: System- ID ist db26de6e1db656e815073c29482401b4-1255946427.480604-1277222009.
I: main.c: Nutze Laufzeit-Verzeichnis /home/natas/.pulse/db26de6e1db656e815073c29482401b4-runtime.
I: main.c: Nutze Zustands-Verzeichnis /home/natas/.pulse.
I: main.c: Modul-Verzeichnis /usr/lib/pulse-0.9.19/modules benutzen.
I: main.c: Laufe im System-Modus: no
I: main.c: Neue hochauslösende Timer verfügbar! Guten Appetit!
I: cpu-x86.c: CPU flags: MMX SSE SSE2 SSE3 MMXEXT 3DNOW 3DNOWEXT
I: svolume_mmx.c: Initialising MMX optimized functions.
I: remap_mmx.c: Initialising MMX optimized remappers.
I: svolume_sse.c: Initialising SSE2 optimized functions.
I: remap_sse.c: Initialising SSE2 optimized remappers.
I: sconv_sse.c: Initialising SSE2 optimized conversions.
D: memblock.c: Using shared memory pool with 1024 slots of size 64,0 KB each, total size is 64,0 MB, maximum usable slot size is 65472
D: database-gdbm.c: Opened GDBM database '/home/natas/.pulse/db26de6e1db656e815073c29482401b4-device-volumes.x86_64-pc-linux-gnu.gdbm'
I: module-device-restore.c: Sucessfully opened database file '/home/natas/.pulse/db26de6e1db656e815073c29482401b4-device-volumes'.
I: module.c: Loaded "module-device-restore" (index: #0; argument: "").
D: database-gdbm.c: Opened GDBM database '/home/natas/.pulse/db26de6e1db656e815073c29482401b4-stream-volumes.x86_64-pc-linux-gnu.gdbm'
I: module-stream-restore.c: Sucessfully opened database file '/home/natas/.pulse/db26de6e1db656e815073c29482401b4-stream-volumes'.
I: module.c: Loaded "module-stream-restore" (index: #1; argument: "").
D: database-gdbm.c: Opened GDBM database '/home/natas/.pulse/db26de6e1db656e815073c29482401b4-card-database.x86_64-pc-linux-gnu.gdbm'
I: module-card-restore.c: Sucessfully opened database file '/home/natas/.pulse/db26de6e1db656e815073c29482401b4-card-database'.
I: module.c: Loaded "module-card-restore" (index: #2; argument: "").
I: module.c: Loaded "module-augment-properties" (index: #3; argument: "").
D: dbus-util.c: Successfully connected to D-Bus session bus 63caddefe43dff2615df47d34adc38be as :1.54
D: reserve-wrap.c: Successfully acquired reservation lock on device 'Audio0'
D: reserve-wrap.c: Successfully create reservation lock monitor for device 'Audio0'
D: alsa-util.c: Trying front:Live with SND_PCM_NO_AUTO_FORMAT ...
D: alsa-util.c: Managed to open front:Live
D: alsa-util.c: Maximum hw buffer size is 371 ms
D: alsa-util.c: Set buffer size first, period size second.
I: alsa-sink.c: Successfully opened device front:Live.
I: alsa-sink.c: Successfully enabled mmap() mode.
I: alsa-sink.c: Successfully enabled timer-based scheduling mode.
I: (alsa-lib)control.c: Invalid CTL front:Live
I: alsa-mixer.c: Unable to attach to mixer front:Live: Datei oder Verzeichnis nicht gefunden
I: alsa-mixer.c: Successfully attached to mixer 'hw:0'
D: alsa-mixer.c: Probing path 'Master'
D: alsa-sink.c: Probed mixer path Master:
D: alsa-mixer.c: Path Master ((null)), direction=1, priority=0, probed=yes, supported=yes, has_mute=yes, has_volume=yes, has_dB=yes, min_volume=0, max_volume=31, min_dB=-46,5, max_dB=0
D: alsa-mixer.c: Element Master, direction=1, switch=1, volume=1, enumeration=0, required=0, required_absent=0, mask=0x6, n_channels=2, override_map=no
I: module-device-restore.c: Restoring volume for sink headphones.
I: module-device-restore.c: Restoring mute state for sink headphones.
I: sink.c: Created sink 0 "headphones" with sample spec s16le 2ch 44100Hz and channel map front-left,front-right
I: sink.c: alsa.resolution_bits = "16"
I: sink.c: device.api = "alsa"
I: sink.c: device.class = "sound"
I: sink.c: alsa.class = "generic"
I: sink.c: alsa.subclass = "generic-mix"
I: sink.c: alsa.name = "ADC Capture/Standard PCM Playback"
I: sink.c: alsa.id = "emu10k1"
I: sink.c: alsa.subdevice = "2"
I: sink.c: alsa.subdevice_name = "subdevice #2"
I: sink.c: alsa.device = "0"
I: sink.c: alsa.card = "0"
I: sink.c: alsa.card_name = "SB Live! Value [CT4670]"
I: sink.c: alsa.long_card_name = "SB Live! Value [CT4670] (rev.5, serial:0x201102) at 0xdc00, irq 19"
I: sink.c: alsa.driver_name = "snd_emu10k1"
I: sink.c: device.bus_path = "pci-0000:01:07.0"
I: sink.c: sysfs.path = "/devices/pci0000:00/0000:00:09.0/0000:01:07.0/sound/card0"
I: sink.c: device.bus = "pci"
I: sink.c: device.vendor.id = "1102"
I: sink.c: device.vendor.name = "Creative Labs"
I: sink.c: device.product.id = "0002"
I: sink.c: device.product.name = "SB Live! EMU10k1"
I: sink.c: device.string = "front:Live"
I: sink.c: device.buffering.buffer_size = "65536"
I: sink.c: device.buffering.fragment_size = "65536"
I: sink.c: device.access_mode = "mmap+timer"
I: sink.c: device.description = "Kopfhörer"
I: sink.c: alsa.mixer_name = "TriTech TR28602"
I: sink.c: alsa.components = "AC97a:54524123"
I: sink.c: device.icon_name = "audio-card-pci"
D: core-subscribe.c: Dropped redundant event due to change event.
I: source.c: Created source 0 "headphones.monitor" with sample spec s16le 2ch 44100Hz and channel map front-left,front-right
I: source.c: device.description = "Monitor of Kopfhörer"
I: source.c: device.class = "monitor"
I: source.c: device.icon_name = "audio-input-microphone"
I: alsa-sink.c: Using 1,0 fragments of size 65536 bytes (371,52ms), buffer size is 65536 bytes (371,52ms)
I: alsa-sink.c: Time scheduling watermark is 20,00ms
D: alsa-sink.c: hwbuf_unused=0
D: alsa-sink.c: setting avail_min=15502
D: alsa-mixer.c: Activating path Master
D: alsa-mixer.c: Path Master ((null)), direction=1, priority=0, probed=yes, supported=yes, has_mute=yes, has_volume=yes, has_dB=yes, min_volume=0, max_volume=31, min_dB=-46,5, max_dB=0
D: alsa-mixer.c: Element Master, direction=1, switch=1, volume=1, enumeration=0, required=0, required_absent=0, mask=0x6, n_channels=2, override_map=no
I: alsa-sink.c: Hardware volume ranges from -46,50 dB to 0,00 dB.
I: alsa-sink.c: No particular base volume set, fixing to 0 dB
I: alsa-sink.c: Using hardware volume control. Hardware dB scale supported.
I: alsa-sink.c: Using hardware mute control.
D: alsa-util.c: snd_pcm_dump():
D: alsa-util.c: Hooks PCM
D: alsa-util.c: Its setup is:
D: alsa-util.c: stream : PLAYBACK
D: alsa-util.c: access : MMAP_INTERLEAVED
D: alsa-util.c: format : S16_LE
D: alsa-util.c: subformat : STD
D: alsa-util.c: channels : 2
D: alsa-util.c: rate : 44100
D: alsa-util.c: exact rate : 44100 (44100/1)
D: alsa-util.c: msbits : 16
D: alsa-util.c: buffer_size : 16384
D: alsa-util.c: period_size : 16384
D: alsa-util.c: period_time : 371519
D: alsa-util.c: tstamp_mode : ENABLE
D: alsa-util.c: period_step : 1
D: alsa-util.c: avail_min : 16384
D: alsa-util.c: period_event : 0
D: alsa-util.c: start_threshold : -1
D: alsa-util.c: stop_threshold : 4611686018427387904
D: alsa-util.c: silence_threshold: 0
D: alsa-util.c: silence_size : 0
D: alsa-util.c: boundary : 4611686018427387904
D: alsa-util.c: Slave: Hardware PCM card 0 'SB Live! Value [CT4670]' device 0 subdevice 2
D: alsa-util.c: Its setup is:
D: alsa-util.c: stream : PLAYBACK
D: alsa-util.c: access : MMAP_INTERLEAVED
D: alsa-util.c: format : S16_LE
D: alsa-util.c: subformat : STD
D: alsa-util.c: channels : 2
D: alsa-util.c: rate : 44100
D: alsa-util.c: exact rate : 44100 (44100/1)
D: alsa-util.c: msbits : 16
D: alsa-util.c: buffer_size : 16384
D: alsa-util.c: period_size : 16384
D: alsa-util.c: period_time : 371519
D: alsa-util.c: tstamp_mode : ENABLE
D: alsa-util.c: period_step : 1
D: alsa-util.c: avail_min : 16384
D: alsa-util.c: period_event : 0
D: alsa-util.c: start_threshold : -1
D: alsa-util.c: stop_threshold : 4611686018427387904
D: alsa-util.c: silence_threshold: 0
D: alsa-util.c: silence_size : 0
D: alsa-util.c: boundary : 4611686018427387904
D: alsa-util.c: appl_ptr : 0
D: alsa-util.c: hw_ptr : 0
D: alsa-sink.c: Thread starting up
D: core-util.c: SCHED_RR worked.
I: core-util.c: Successfully enabled SCHED_RR scheduling for thread, with priority 5.
D: alsa-sink.c: Requested volume: 0: 17% 1: 17%
D: alsa-sink.c: Got hardware volume: 0: 17% 1: 17%
D: alsa-sink.c: Calculated software volume: 0: 100% 1: 100% (accurate-enough=yes)
I: alsa-sink.c: Starting playback.
D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
I: module.c: Loaded "module-alsa-sink" (index: #4; argument: "device=front:Live sink_name=headphones sink_properties=device.description=Kopfhörer control=Master").
D: alsa-util.c: Trying rear:Live with SND_PCM_NO_AUTO_FORMAT ...
D: alsa-util.c: Managed to open rear:Live
D: alsa-util.c: Maximum hw buffer size is 371 ms
D: alsa-util.c: Set buffer size first, period size second.
I: alsa-sink.c: Successfully opened device rear:Live.
I: alsa-sink.c: Successfully enabled mmap() mode.
I: alsa-sink.c: Successfully enabled timer-based scheduling mode.
I: (alsa-lib)control.c: Invalid CTL rear:Live
I: alsa-mixer.c: Unable to attach to mixer rear:Live: Datei oder Verzeichnis nicht gefunden
I: alsa-mixer.c: Successfully attached to mixer 'hw:0'
D: alsa-mixer.c: Probing path 'Surround'
D: alsa-sink.c: Probed mixer path Surround:
D: alsa-mixer.c: Path Surround ((null)), direction=1, priority=0, probed=yes, supported=yes, has_mute=no, has_volume=yes, has_dB=yes, min_volume=0, max_volume=100, min_dB=-40, max_dB=0
D: alsa-mixer.c: Element Surround, direction=1, switch=0, volume=1, enumeration=0, required=0, required_absent=0, mask=0x6, n_channels=2, override_map=no
D: core-subscribe.c: Dropped redundant event due to change event.
I: module-device-restore.c: Restoring volume for sink hifi.
I: sink.c: Created sink 1 "hifi" with sample spec s16le 2ch 44100Hz and channel map front-left,front-right
I: sink.c: alsa.resolution_bits = "16"
I: sink.c: device.api = "alsa"
I: sink.c: device.class = "sound"
I: sink.c: alsa.class = "generic"
I: sink.c: alsa.subclass = "generic-mix"
I: sink.c: alsa.name = "ADC Capture/Standard PCM Playback"
I: sink.c: alsa.id = "emu10k1"
I: sink.c: alsa.subdevice = "3"
I: sink.c: alsa.subdevice_name = "subdevice #3"
I: sink.c: alsa.device = "0"
I: sink.c: alsa.card = "0"
I: sink.c: alsa.card_name = "SB Live! Value [CT4670]"
I: sink.c: alsa.long_card_name = "SB Live! Value [CT4670] (rev.5, serial:0x201102) at 0xdc00, irq 19"
I: sink.c: alsa.driver_name = "snd_emu10k1"
I: sink.c: device.bus_path = "pci-0000:01:07.0"
I: sink.c: sysfs.path = "/devices/pci0000:00/0000:00:09.0/0000:01:07.0/sound/card0"
I: sink.c: device.bus = "pci"
I: sink.c: device.vendor.id = "1102"
I: sink.c: device.vendor.name = "Creative Labs"
I: sink.c: device.product.id = "0002"
I: sink.c: device.product.name = "SB Live! EMU10k1"
I: sink.c: device.string = "rear:Live"
I: sink.c: device.buffering.buffer_size = "65536"
I: sink.c: device.buffering.fragment_size = "65536"
I: sink.c: device.access_mode = "mmap+timer"
I: sink.c: device.description = "Hifi-Anlage"
I: sink.c: alsa.mixer_name = "TriTech TR28602"
I: sink.c: alsa.components = "AC97a:54524123"
I: sink.c: device.icon_name = "audio-card-pci"
D: core-subscribe.c: Dropped redundant event due to change event.
I: source.c: Created source 1 "hifi.monitor" with sample spec s16le 2ch 44100Hz and channel map front-left,front-right
I: source.c: device.description = "Monitor of Hifi-Anlage"
I: source.c: device.class = "monitor"
I: source.c: device.icon_name = "audio-input-microphone"
I: alsa-sink.c: Using 1,0 fragments of size 65536 bytes (371,52ms), buffer size is 65536 bytes (371,52ms)
I: alsa-sink.c: Time scheduling watermark is 20,00ms
D: alsa-sink.c: hwbuf_unused=0
D: alsa-sink.c: setting avail_min=15502
D: alsa-mixer.c: Activating path Surround
D: alsa-mixer.c: Path Surround ((null)), direction=1, priority=0, probed=yes, supported=yes, has_mute=no, has_volume=yes, has_dB=yes, min_volume=0, max_volume=100, min_dB=-40, max_dB=0
D: alsa-mixer.c: Element Surround, direction=1, switch=0, volume=1, enumeration=0, required=0, required_absent=0, mask=0x6, n_channels=2, override_map=no
I: alsa-sink.c: Hardware volume ranges from -40,00 dB to 0,00 dB.
I: alsa-sink.c: No particular base volume set, fixing to 0 dB
I: alsa-sink.c: Using hardware volume control. Hardware dB scale supported.
I: alsa-sink.c: Driver does not support hardware mute control, falling back to software mute control.
D: alsa-util.c: snd_pcm_dump():
D: alsa-util.c: Hooks PCM
D: alsa-util.c: Its setup is:
D: alsa-util.c: stream : PLAYBACK
D: alsa-util.c: access : MMAP_INTERLEAVED
D: alsa-util.c: format : S16_LE
D: alsa-util.c: subformat : STD
D: alsa-util.c: channels : 2
D: alsa-util.c: rate : 44100
D: alsa-util.c: exact rate : 44100 (44100/1)
D: alsa-util.c: msbits : 16
D: alsa-util.c: buffer_size : 16384
D: alsa-util.c: period_size : 16384
D: alsa-util.c: period_time : 371519
D: alsa-util.c: tstamp_mode : ENABLE
D: alsa-util.c: period_step : 1
D: alsa-util.c: avail_min : 16384
D: alsa-util.c: period_event : 0
D: alsa-util.c: start_threshold : -1
D: alsa-util.c: stop_threshold : 4611686018427387904
D: alsa-util.c: silence_threshold: 0
D: alsa-util.c: silence_size : 0
D: alsa-util.c: boundary : 4611686018427387904
D: alsa-util.c: Slave: Hardware PCM card 0 'SB Live! Value [CT4670]' device 0 subdevice 3
D: alsa-util.c: Its setup is:
D: alsa-util.c: stream : PLAYBACK
D: alsa-util.c: access : MMAP_INTERLEAVED
D: alsa-util.c: format : S16_LE
D: alsa-util.c: subformat : STD
D: alsa-util.c: channels : 2
D: alsa-util.c: rate : 44100
D: alsa-util.c: exact rate : 44100 (44100/1)
D: alsa-util.c: msbits : 16
D: alsa-util.c: buffer_size : 16384
D: alsa-util.c: period_size : 16384
D: alsa-util.c: period_time : 371519
D: alsa-util.c: tstamp_mode : ENABLE
D: alsa-util.c: period_step : 1
D: alsa-util.c: avail_min : 16384
D: alsa-util.c: period_event : 0
D: alsa-util.c: start_threshold : -1
D: alsa-util.c: stop_threshold : 4611686018427387904
D: alsa-util.c: silence_threshold: 0
D: alsa-util.c: silence_size : 0
D: alsa-util.c: boundary : 4611686018427387904
D: alsa-util.c: appl_ptr : 0
D: alsa-util.c: hw_ptr : 0
D: alsa-sink.c: Thread starting up
D: alsa-sink.c: Requested volume: 0: 27% 1: 27%
D: core-util.c: SCHED_RR worked.
I: core-util.c: Successfully enabled SCHED_RR scheduling for thread, with priority 5.
D: alsa-sink.c: Got hardware volume: 0: 27% 1: 27%
D: alsa-sink.c: Calculated software volume: 0: 100% 1: 100% (accurate-enough=yes)
I: alsa-sink.c: Starting playback.
D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
I: module.c: Loaded "module-alsa-sink" (index: #5; argument: "device=rear:Live sink_name=hifi sink_properties=device.description=Hifi-Anlage control=Surround").
D: cli-command.c: Checking for existance of '/usr/lib/pulse-0.9.19/modules/module-udev-detect.so': success
D: module-udev-detect.c: /dev/snd/controlC0 is accessible: yes
D: module-udev-detect.c: /devices/pci0000:00/0000:00:09.0/0000:01:07.0/sound/card0 is busy: yes
I: module-udev-detect.c: Found 1 cards.
I: module.c: Loaded "module-udev-detect" (index: #6; argument: "").
D: cli-command.c: Checking for existance of '/usr/lib/pulse-0.9.19/modules/module-esound-protocol-unix.so': success
I: module.c: Loaded "module-esound-protocol-unix" (index: #7; argument: "").
I: module.c: Loaded "module-native-protocol-unix" (index: #8; argument: "").
D: cli-command.c: Checking for existance of '/usr/lib/pulse-0.9.19/modules/module-gconf.so': success
I: module.c: Loaded "module-gconf" (index: #9; argument: "").
D: core-subscribe.c: Dropped redundant event due to change event.
I: module-default-device-restore.c: Restored default sink 'headphones'.
D: core-subscribe.c: Dropped redundant event due to change event.
I: module-default-device-restore.c: Restored default source 'headphones.monitor'.
I: module.c: Loaded "module-default-device-restore" (index: #10; argument: "").
I: module.c: Loaded "module-rescue-streams" (index: #11; argument: "").
I: module.c: Loaded "module-always-sink" (index: #12; argument: "").
I: module.c: Loaded "module-intended-roles" (index: #13; argument: "").
D: module-suspend-on-idle.c: Sink headphones becomes idle, timeout in 5 seconds.
D: module-suspend-on-idle.c: Sink hifi becomes idle, timeout in 5 seconds.
I: module.c: Loaded "module-suspend-on-idle" (index: #14; argument: "").
D: dbus-util.c: Successfully connected to D-Bus system bus 6af983f8abe983d911ba0be34adc383d as :1.57
I: client.c: Created 0 "ConsoleKit Session /org/freedesktop/ConsoleKit/Session1"
D: module-console-kit.c: Added new session /org/freedesktop/ConsoleKit/Session1
I: client.c: Created 1 "ConsoleKit Session /org/freedesktop/ConsoleKit/Session3"
D: module-console-kit.c: Added new session /org/freedesktop/ConsoleKit/Session3
I: module.c: Loaded "module-console-kit" (index: #15; argument: "").
I: module.c: Loaded "module-position-event-sounds" (index: #16; argument: "").
I: module.c: Loaded "module-cork-music-on-phone" (index: #17; argument: "").
D: module-cli.c: Managed to open /dev/tty.
I: client.c: Created 2 "Unknown client"
I: module.c: Loaded "module-cli" (index: #18; argument: "exit_on_eof=1").
D: main.c: Got org.pulseaudio.Server!
I: main.c: Start des Daemons abgeschlossen.
D: module-console-kit.c: dbus: interface=org.freedesktop.DBus, path=/org/freedesktop/DBus, member=NameAcquired
I: module-suspend-on-idle.c: Sink hifi idle for too long, suspending ...
D: sink.c: Suspend cause of sink hifi is 0x0004, suspending
I: alsa-sink.c: Device suspended...
I: module-suspend-on-idle.c: Sink headphones idle for too long, suspending ...
D: sink.c: Suspend cause of sink headphones is 0x0004, suspending
I: alsa-sink.c: Device suspended...
D: reserve-wrap.c: Device lock status of reserve-monitor-wrapper at Audio0 changed: not busy
D: module-udev-detect.c: /dev/snd/controlC0 is accessible: yes
D: module-udev-detect.c: /devices/pci0000:00/0000:00:09.0/0000:01:07.0/sound/card0 is busy: yes
( 0.000| 0.000) I: client.c: Created 3 "Native client (UNIX socket client)"
( 0.001| 0.001) D: protocol-native.c: Protocol version: remote 16, local 16
( 0.001| 0.000) I: protocol-native.c: Got credentials: uid=1000 gid=1000 success=1
( 0.001| 0.000) D: protocol-native.c: SHM possible: yes
( 0.001| 0.000) D: protocol-native.c: Negotiated SHM: yes
( 0.002| 0.000) D: module-augment-properties.c: Looking for .desktop file for mplayer
( 0.004| 0.001) D: module-intended-roles.c: Not setting device for stream audio stream, because it lacks role.
( 0.004| 0.000) I: module-stream-restore.c: Restoring volume for sink input sink-input-by-application-name:MPlayer.
( 0.004| 0.000) D: sink.c: Suspend cause of sink headphones is 0x0000, resuming
( 0.005| 0.001) D: reserve-wrap.c: Successfully acquired reservation lock on device 'Audio0'
( 0.005| 0.000) I: alsa-sink.c: Trying resume...
( 0.007| 0.001) D: alsa-util.c: Maximum hw buffer size is 371 ms
( 0.007| 0.000) D: alsa-util.c: Set buffer size first, period size second.
( 0.007| 0.000) D: alsa-sink.c: hwbuf_unused=0
( 0.007| 0.000) D: alsa-sink.c: setting avail_min=15502
( 0.007| 0.000) I: alsa-sink.c: Resumed successfully...
( 0.007| 0.000) I: alsa-sink.c: Starting playback.
( 0.007| 0.000) D: module-suspend-on-idle.c: Sink headphones becomes idle, timeout in 5 seconds.
( 0.007| 0.000) D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
( 0.007| 0.000) D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
( 0.007| 0.000) D: module-suspend-on-idle.c: Sink headphones becomes busy.
( 0.007| 0.000) I: resampler.c: Using resampler 'ffmpeg'
( 0.007| 0.000) I: resampler.c: Using s16le as working format.
( 0.018| 0.010) D: memblockq.c: memblockq requested: maxlength=33554432, tlength=0, base=4, prebuf=0, minreq=1 maxrewind=0
( 0.018| 0.000) D: memblockq.c: memblockq sanitized: maxlength=33554432, tlength=33554432, base=4, prebuf=0, minreq=4 maxrewind=0
( 0.018| 0.000) I: sink-input.c: Created input 0 "audio stream" on headphones with sample spec s16le 2ch 48000Hz and channel map front-left,front-right
( 0.018| 0.000) I: sink-input.c: media.name = "audio stream"
( 0.018| 0.000) I: sink-input.c: application.name = "MPlayer"
( 0.018| 0.000) I: sink-input.c: native-protocol.peer = "UNIX socket client"
( 0.018| 0.000) I: sink-input.c: native-protocol.version = "16"
( 0.018| 0.000) I: sink-input.c: application.process.id = "8347"
( 0.018| 0.000) I: sink-input.c: application.process.user = "natas"
( 0.018| 0.000) I: sink-input.c: application.process.host = "Hellraiser"
( 0.018| 0.000) I: sink-input.c: application.process.binary = "mplayer"
( 0.018| 0.000) I: sink-input.c: application.language = "C"
( 0.018| 0.000) I: sink-input.c: window.x11.display = ":0.0"
( 0.018| 0.000) I: sink-input.c: application.process.machine_id = "db26de6e1db656e815073c29482401b4"
( 0.018| 0.000) I: sink-input.c: application.process.session_id = "db26de6e1db656e815073c29482401b4-1255946427.480604-1277222009"
( 0.018| 0.000) I: sink-input.c: module-stream-restore.id = "sink-input-by-application-name:MPlayer"
( 0.019| 0.000) I: protocol-native.c: Requested tlength=250,00 ms, minreq=20,00 ms
( 0.019| 0.000) D: protocol-native.c: Traditional mode enabled, modifying sink usec only for compat with minreq.
( 0.019| 0.000) D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
( 0.019| 0.000) D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
( 0.020| 0.000) D: memblockq.c: memblockq requested: maxlength=4194304, tlength=48000, base=4, prebuf=44164, minreq=3840 maxrewind=0
( 0.020| 0.000) D: memblockq.c: memblockq sanitized: maxlength=4194304, tlength=48000, base=4, prebuf=44164, minreq=3840 maxrewind=0
( 0.020| 0.000) I: protocol-native.c: Final latency 460,00 ms = 210,00 ms + 2*20,00 ms + 210,00 ms
( 0.020| 0.000) D: alsa-sink.c: Requested volume: 0: 17% 1: 17%
( 0.020| 0.000) D: alsa-sink.c: Got hardware volume: 0: 17% 1: 17%
( 0.020| 0.000) D: alsa-sink.c: Calculated software volume: 0: 100% 1: 100% (accurate-enough=yes)
( 0.020| 0.000) D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
( 0.020| 0.000) D: alsa-sink.c: Latency set to 210,00ms
( 0.020| 0.000) D: alsa-sink.c: hwbuf_unused=28492
( 0.020| 0.000) D: alsa-sink.c: setting avail_min=15503
( 0.020| 0.000) D: alsa-sink.c: Requesting rewind due to latency change.
( 0.021| 0.000) D: alsa-sink.c: Requested to rewind 65536 bytes.
( 0.021| 0.000) D: alsa-sink.c: Limited to 59648 bytes.
( 0.021| 0.000) D: alsa-sink.c: before: 14912
( 0.021| 0.000) D: alsa-sink.c: after: 14912
( 0.021| 0.000) D: alsa-sink.c: Rewound 59648 bytes.
( 0.021| 0.000) D: sink.c: Processing rewind...
( 0.021| 0.000) D: sink-input.c: Have to rewind 59648 bytes on render memblockq.
( 0.021| 0.000) D: source.c: Processing rewind...
( 0.021| 0.000) D: core-subscribe.c: Dropped redundant event due to change event.
( 0.021| 0.000) D: reserve-wrap.c: Device lock status of reserve-monitor-wrapper at Audio0 changed: not busy
( 0.037| 0.016) D: protocol-native.c: Client mplayer changes volume of sink input audio stream.
( 0.038| 0.000) D: alsa-sink.c: Requested volume: 0: 50% 1: 50%
( 0.038| 0.000) D: alsa-sink.c: Got hardware volume: 0: 50% 1: 50%
( 0.038| 0.000) D: alsa-sink.c: Calculated software volume: 0: 100% 1: 100% (accurate-enough=yes)
( 0.038| 0.000) I: module-device-restore.c: Storing volume/mute/port for device sink:headphones.
( 0.101| 0.063) D: protocol-native.c: Requesting rewind due to end of underrun.
( 0.102| 0.000) D: alsa-sink.c: Requested to rewind 65536 bytes.
( 0.102| 0.000) D: alsa-sink.c: Limited to 19256 bytes.
( 0.102| 0.000) D: alsa-sink.c: before: 4814
( 0.102| 0.000) D: alsa-sink.c: after: 4814
( 0.102| 0.000) D: alsa-sink.c: Rewound 19256 bytes.
( 0.102| 0.000) D: sink.c: Processing rewind...
( 0.102| 0.000) D: sink-input.c: Have to rewind 19256 bytes on render memblockq.
( 0.102| 0.000) D: source.c: Processing rewind...
( 0.257| 0.155) D: protocol-native.c: Underrun on 'audio stream', 0 bytes in queue.
( 0.549| 0.291) D: protocol-native.c: Requesting rewind due to end of underrun.
( 0.549| 0.000) D: alsa-sink.c: Requested to rewind 65536 bytes.
( 0.549| 0.000) D: alsa-sink.c: Limited to 33484 bytes.
( 0.549| 0.000) D: alsa-sink.c: before: 8371
( 0.549| 0.000) D: alsa-sink.c: after: 8371
( 0.549| 0.000) D: alsa-sink.c: Rewound 33484 bytes.
( 0.549| 0.000) D: sink.c: Processing rewind...
( 0.549| 0.000) D: sink-input.c: Have to rewind 33484 bytes on render memblockq.
( 0.549| 0.000) D: source.c: Processing rewind...
( 1.683| 1.133) D: protocol-native.c: Underrun on 'audio stream', 0 bytes in queue.
( 2.196| 0.513) D: alsa-sink.c: Requested volume: 0: 50% 1: 50%
( 2.197| 0.000) D: alsa-sink.c: Got hardware volume: 0: 50% 1: 50%
( 2.197| 0.000) D: alsa-sink.c: Calculated software volume: 0: 100% 1: 100% (accurate-enough=yes)
( 2.197| 0.000) D: alsa-sink.c: hwbuf_unused=0
( 2.197| 0.000) D: alsa-sink.c: setting avail_min=15502
( 2.197| 0.000) D: alsa-sink.c: Requested to rewind 65536 bytes.
( 2.197| 0.000) D: alsa-sink.c: Limited to 32212 bytes.
( 2.197| 0.000) D: alsa-sink.c: before: 8053
( 2.197| 0.000) D: alsa-sink.c: after: 8053
( 2.197| 0.000) D: alsa-sink.c: Rewound 32212 bytes.
( 2.198| 0.000) D: sink.c: Processing rewind...
( 2.198| 0.000) D: source.c: Processing rewind...
( 2.198| 0.000) D: module-suspend-on-idle.c: Sink headphones becomes idle, timeout in 5 seconds.
( 2.198| 0.000) D: module-suspend-on-idle.c: Sink headphones becomes idle, timeout in 5 seconds.
( 2.198| 0.000) D: core.c: Hmm, no streams around, trying to vacuum.
( 2.200| 0.001) I: sink-input.c: Freeing input 0 "audio stream"
( 2.201| 0.001) I: client.c: Freed 3 "MPlayer"
( 2.202| 0.000) I: protocol-native.c: Connection died.
( 7.203| 5.001) I: module-suspend-on-idle.c: Sink headphones idle for too long, suspending ...
( 7.204| 0.000) D: sink.c: Suspend cause of sink headphones is 0x0004, suspending
( 7.207| 0.002) I: alsa-sink.c: Device suspended...
( 7.207| 0.000) D: reserve-wrap.c: Device lock status of reserve-monitor-wrapper at Audio0 changed: not busy
( 7.208| 0.000) D: module-udev-detect.c: /dev/snd/controlC0 is accessible: yes
( 7.224| 0.015) D: module-udev-detect.c: /devices/pci0000:00/0000:00:09.0/0000:01:07.0/sound/card0 is busy: yes
( 10.042| 2.818) I: module-device-restore.c: Synced.
( 12.799| 2.756) I: client.c: Created 4 "Native client (UNIX socket client)"
( 12.800| 0.001) D: protocol-native.c: Protocol version: remote 16, local 16
( 12.800| 0.000) I: protocol-native.c: Got credentials: uid=1000 gid=1000 success=1
( 12.800| 0.000) D: protocol-native.c: SHM possible: yes
( 12.800| 0.000) D: protocol-native.c: Negotiated SHM: yes
( 12.801| 0.000) D: module-augment-properties.c: Looking for .desktop file for mplayer
( 12.803| 0.001) D: module-intended-roles.c: Not setting device for stream audio stream, because it lacks role.
( 12.803| 0.000) I: module-stream-restore.c: Restoring volume for sink input sink-input-by-application-name:MPlayer.
( 12.803| 0.000) D: sink.c: Suspend cause of sink headphones is 0x0000, resuming
( 12.804| 0.001) D: reserve-wrap.c: Successfully acquired reservation lock on device 'Audio0'
( 12.804| 0.000) I: alsa-sink.c: Trying resume...
( 12.805| 0.001) D: alsa-util.c: Maximum hw buffer size is 371 ms
( 12.805| 0.000) D: alsa-util.c: Set buffer size first, period size second.
( 12.805| 0.000) D: alsa-sink.c: hwbuf_unused=0
( 12.805| 0.000) D: alsa-sink.c: setting avail_min=15502
( 12.805| 0.000) I: alsa-sink.c: Resumed successfully...
( 12.805| 0.000) D: module-suspend-on-idle.c: Sink headphones becomes idle, timeout in 5 seconds.
( 12.805| 0.000) I: alsa-sink.c: Starting playback.
( 12.806| 0.000) D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
( 12.806| 0.000) D: module-suspend-on-idle.c: Sink headphones becomes busy.
( 12.806| 0.000) D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
( 12.806| 0.000) I: resampler.c: Using resampler 'ffmpeg'
( 12.806| 0.000) I: resampler.c: Using s16le as working format.
( 12.816| 0.010) D: memblockq.c: memblockq requested: maxlength=33554432, tlength=0, base=4, prebuf=0, minreq=1 maxrewind=0
( 12.816| 0.000) D: memblockq.c: memblockq sanitized: maxlength=33554432, tlength=33554432, base=4, prebuf=0, minreq=4 maxrewind=0
( 12.816| 0.000) I: sink-input.c: Created input 1 "audio stream" on headphones with sample spec s16le 2ch 48000Hz and channel map front-left,front-right
( 12.816| 0.000) I: sink-input.c: media.name = "audio stream"
( 12.816| 0.000) I: sink-input.c: application.name = "MPlayer"
( 12.816| 0.000) I: sink-input.c: native-protocol.peer = "UNIX socket client"
( 12.816| 0.000) I: sink-input.c: native-protocol.version = "16"
( 12.816| 0.000) I: sink-input.c: application.process.id = "8350"
( 12.816| 0.000) I: sink-input.c: application.process.user = "natas"
( 12.816| 0.000) I: sink-input.c: application.process.host = "Hellraiser"
( 12.816| 0.000) I: sink-input.c: application.process.binary = "mplayer"
( 12.816| 0.000) I: sink-input.c: application.language = "C"
( 12.816| 0.000) I: sink-input.c: window.x11.display = ":0.0"
( 12.816| 0.000) I: sink-input.c: application.process.machine_id = "db26de6e1db656e815073c29482401b4"
( 12.816| 0.000) I: sink-input.c: application.process.session_id = "db26de6e1db656e815073c29482401b4-1255946427.480604-1277222009"
( 12.816| 0.000) I: sink-input.c: module-stream-restore.id = "sink-input-by-application-name:MPlayer"
( 12.817| 0.000) I: protocol-native.c: Requested tlength=250,00 ms, minreq=20,00 ms
( 12.817| 0.000) D: protocol-native.c: Traditional mode enabled, modifying sink usec only for compat with minreq.
( 12.817| 0.000) D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
( 12.817| 0.000) D: memblockq.c: memblockq requested: maxlength=4194304, tlength=48000, base=4, prebuf=44164, minreq=3840 maxrewind=0
( 12.817| 0.000) D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
( 12.817| 0.000) D: memblockq.c: memblockq sanitized: maxlength=4194304, tlength=48000, base=4, prebuf=44164, minreq=3840 maxrewind=0
( 12.817| 0.000) I: protocol-native.c: Final latency 460,00 ms = 210,00 ms + 2*20,00 ms + 210,00 ms
( 12.817| 0.000) D: alsa-sink.c: Requested volume: 0: 50% 1: 50%
( 12.818| 0.000) D: alsa-sink.c: Got hardware volume: 0: 50% 1: 50%
( 12.818| 0.000) D: alsa-sink.c: Calculated software volume: 0: 100% 1: 100% (accurate-enough=yes)
( 12.818| 0.000) D: alsa-sink.c: Cutting sleep time for the initial iterations by half.
( 12.818| 0.000) D: alsa-sink.c: Latency set to 210,00ms
( 12.818| 0.000) D: alsa-sink.c: hwbuf_unused=28492
( 12.818| 0.000) D: alsa-sink.c: setting avail_min=15503
( 12.818| 0.000) D: alsa-sink.c: Requesting rewind due to latency change.
( 12.818| 0.000) D: alsa-sink.c: Requested to rewind 65536 bytes.
( 12.818| 0.000) D: alsa-sink.c: Limited to 59816 bytes.
( 12.818| 0.000) D: alsa-sink.c: before: 14954
( 12.818| 0.000) D: alsa-sink.c: after: 14954
( 12.818| 0.000) D: alsa-sink.c: Rewound 59816 bytes.
( 12.818| 0.000) D: sink.c: Processing rewind...
( 12.818| 0.000) D: sink-input.c: Have to rewind 59816 bytes on render memblockq.
( 12.818| 0.000) D: source.c: Processing rewind...
( 12.818| 0.000) D: core-subscribe.c: Dropped redundant event due to change event.
( 12.818| 0.000) D: reserve-wrap.c: Device lock status of reserve-monitor-wrapper at Audio0 changed: not busy
( 12.825| 0.006) D: protocol-native.c: Client mplayer changes volume of sink input audio stream.
( 12.825| 0.000) D: alsa-sink.c: Requested volume: 0: 0% 1: 0%
( 12.825| 0.000) D: alsa-sink.c: Got hardware volume: 0: 17% 1: 17%
( 12.825| 0.000) D: alsa-sink.c: Calculated software volume: 0: 0% 1: 0% (accurate-enough=no)
( 12.825| 0.000) D: alsa-sink.c: Requested to rewind 65536 bytes.
( 12.825| 0.000) D: alsa-sink.c: Limited to 32212 bytes.
( 12.825| 0.000) D: alsa-sink.c: before: 8053
( 12.825| 0.000) D: alsa-sink.c: after: 8053
( 12.825| 0.000) D: alsa-sink.c: Rewound 32212 bytes.
( 12.825| 0.000) D: sink.c: Processing rewind...
( 12.826| 0.000) D: sink-input.c: Have to rewind 32212 bytes on render memblockq.
( 12.826| 0.000) D: source.c: Processing rewind...
( 12.826| 0.000) I: module-stream-restore.c: Storing volume/mute/device for stream sink-input-by-application-name:MPlayer.
( 12.834| 0.007) D: protocol-native.c: Requesting rewind due to end of underrun.
( 12.834| 0.000) D: alsa-sink.c: Requested to rewind 65536 bytes.
( 12.834| 0.000) D: alsa-sink.c: Limited to 32052 bytes.
( 12.834| 0.000) D: alsa-sink.c: before: 8013
( 12.834| 0.000) D: alsa-sink.c: after: 8013
( 12.834| 0.000) D: alsa-sink.c: Rewound 32052 bytes.
( 12.834| 0.000) D: sink.c: Processing rewind...
( 12.834| 0.000) D: sink-input.c: Have to rewind 32052 bytes on render memblockq.
( 12.834| 0.000) D: source.c: Processing rewind...
( 12.988| 0.154) D: protocol-native.c: Underrun on 'audio stream', 0 bytes in queue.
( 13.063| 0.074) D: protocol-native.c: Requesting rewind due to end of underrun.
( 13.063| 0.000) D: alsa-sink.c: Requested to rewind 16644 bytes.
( 13.063| 0.000) D: alsa-sink.c: Limited to 16644 bytes.
( 13.063| 0.000) D: alsa-sink.c: before: 4161
( 13.063| 0.000) D: alsa-sink.c: after: 4161
( 13.063| 0.000) D: alsa-sink.c: Rewound 16644 bytes.
( 13.063| 0.000) D: sink.c: Processing rewind...
( 13.063| 0.000) D: sink-input.c: Have to rewind 16644 bytes on render memblockq.
( 13.063| 0.000) D: source.c: Processing rewind...
( 14.092| 1.029) D: protocol-native.c: Underrun on 'audio stream', 0 bytes in queue.
( 14.615| 0.522) D: alsa-sink.c: Requested volume: 0: 50% 1: 50%
( 14.615| 0.000) D: alsa-sink.c: Got hardware volume: 0: 50% 1: 50%
( 14.615| 0.000) D: alsa-sink.c: Calculated software volume: 0: 100% 1: 100% (accurate-enough=yes)
( 14.615| 0.000) D: alsa-sink.c: hwbuf_unused=0
( 14.616| 0.000) D: alsa-sink.c: setting avail_min=15502
( 14.616| 0.000) D: alsa-sink.c: Requested to rewind 65536 bytes.
( 14.616| 0.000) D: alsa-sink.c: Limited to 30388 bytes.
( 14.616| 0.000) D: alsa-sink.c: before: 7597
( 14.616| 0.000) D: alsa-sink.c: after: 7597
( 14.616| 0.000) D: alsa-sink.c: Rewound 30388 bytes.
( 14.616| 0.000) D: sink.c: Processing rewind...
( 14.616| 0.000) D: module-suspend-on-idle.c: Sink headphones becomes idle, timeout in 5 seconds.
( 14.616| 0.000) D: source.c: Processing rewind...
( 14.616| 0.000) D: module-suspend-on-idle.c: Sink headphones becomes idle, timeout in 5 seconds.
( 14.616| 0.000) D: core.c: Hmm, no streams around, trying to vacuum.
( 14.618| 0.001) I: sink-input.c: Freeing input 1 "audio stream"
( 14.619| 0.000) I: client.c: Freed 4 "MPlayer"
( 14.619| 0.000) I: protocol-native.c: Connection died.
( 18.390| 3.771) D: cli.c: CLI got EOF from user.
( 18.391| 0.000) I: main.c: Herunterfahren des Daemon gestartet.
( 18.391| 0.000) I: module.c: Unloading "module-device-restore" (index: #0).
( 18.392| 0.000) I: module.c: Unloaded "module-device-restore" (index: #0).
( 18.392| 0.000) I: module.c: Unloading "module-stream-restore" (index: #1).
( 18.393| 0.001) I: module.c: Unloaded "module-stream-restore" (index: #1).
( 18.393| 0.000) I: module.c: Unloading "module-card-restore" (index: #2).
( 18.394| 0.000) I: module.c: Unloaded "module-card-restore" (index: #2).
( 18.394| 0.000) I: module.c: Unloading "module-augment-properties" (index: #3).
( 18.394| 0.000) I: module.c: Unloaded "module-augment-properties" (index: #3).
( 18.394| 0.000) I: module.c: Unloading "module-alsa-sink" (index: #4).
( 18.395| 0.000) D: core-subscribe.c: Dropped redundant event due to change event.
( 18.395| 0.000) D: alsa-sink.c: Thread shutting down
( 18.396| 0.000) I: sink.c: Freeing sink 0 "headphones"
( 18.396| 0.000) I: source.c: Freeing source 0 "headphones.monitor"
( 18.400| 0.004) I: module.c: Unloaded "module-alsa-sink" (index: #4).
( 18.401| 0.000) I: module.c: Unloading "module-alsa-sink" (index: #5).
( 18.401| 0.000) D: alsa-sink.c: Thread shutting down
( 18.402| 0.000) I: sink.c: Freeing sink 1 "hifi"
( 18.402| 0.000) I: source.c: Freeing source 1 "hifi.monitor"
( 18.405| 0.002) I: module.c: Unloaded "module-alsa-sink" (index: #5).
( 18.406| 0.000) I: module.c: Unloading "module-udev-detect" (index: #6).
( 18.406| 0.000) I: module.c: Unloaded "module-udev-detect" (index: #6).
( 18.407| 0.000) I: module.c: Unloading "module-esound-protocol-unix" (index: #7).
( 18.407| 0.000) I: module.c: Unloaded "module-esound-protocol-unix" (index: #7).
( 18.407| 0.000) I: module.c: Unloading "module-native-protocol-unix" (index: #8).
( 18.408| 0.000) I: module.c: Unloaded "module-native-protocol-unix" (index: #8).
( 18.408| 0.000) I: module.c: Unloading "module-gconf" (index: #9).
( 18.412| 0.003) I: module.c: Unloaded "module-gconf" (index: #9).
( 18.412| 0.000) I: module.c: Unloading "module-default-device-restore" (index: #10).
( 18.412| 0.000) I: module.c: Unloaded "module-default-device-restore" (index: #10).
( 18.413| 0.000) I: module.c: Unloading "module-rescue-streams" (index: #11).
( 18.413| 0.000) I: module.c: Unloaded "module-rescue-streams" (index: #11).
( 18.413| 0.000) I: module.c: Unloading "module-always-sink" (index: #12).
( 18.413| 0.000) I: module.c: Unloaded "module-always-sink" (index: #12).
( 18.414| 0.000) I: module.c: Unloading "module-intended-roles" (index: #13).
( 18.414| 0.000) I: module.c: Unloaded "module-intended-roles" (index: #13).
( 18.414| 0.000) I: module.c: Unloading "module-suspend-on-idle" (index: #14).
( 18.414| 0.000) I: module.c: Unloaded "module-suspend-on-idle" (index: #14).
( 18.415| 0.000) I: module.c: Unloading "module-console-kit" (index: #15).
( 18.415| 0.000) D: module-console-kit.c: Removing session /org/freedesktop/ConsoleKit/Session1
( 18.415| 0.000) I: client.c: Freed 0 "ConsoleKit Session /org/freedesktop/ConsoleKit/Session1"
( 18.415| 0.000) D: module-console-kit.c: Removing session /org/freedesktop/ConsoleKit/Session3
( 18.415| 0.000) I: client.c: Freed 1 "ConsoleKit Session /org/freedesktop/ConsoleKit/Session3"
( 18.426| 0.011) I: module.c: Unloaded "module-console-kit" (index: #15).
( 18.427| 0.000) I: module.c: Unloading "module-position-event-sounds" (index: #16).
( 18.427| 0.000) I: module.c: Unloaded "module-position-event-sounds" (index: #16).
( 18.427| 0.000) I: module.c: Unloading "module-cork-music-on-phone" (index: #17).
( 18.427| 0.000) I: module.c: Unloaded "module-cork-music-on-phone" (index: #17).
( 18.428| 0.000) I: module.c: Unloading "module-cli" (index: #18).
( 18.428| 0.000) I: client.c: Freed 2 "Unknown client"
( 18.428| 0.000) I: module.c: Unloaded "module-cli" (index: #18).
( 18.428| 0.000) I: main.c: Daemon beendet.
More information about the MPlayer-dev-eng
mailing list