Running mplayer under opensuse 11.2 with audio out == pulseaudio gives latency problems. The current pulseaudio in opensuse is 0.9,.21 with 64 patches added (most I assume is from pulseaudio git). mplayer uses the latency (the value of pa_stream_get_latency) to calculate the timestamp of current player audio sample. It calculates the timestamp of current played sample as: timestamp of next sample to be written to audio device - latency. This works well with pulseaudio when audio is flowing continuously. Not when a pause is done (like when user pauses movie), or a flush of data (like when user jumps to new place in movie). I have analysed what happens trying to find the cause. Below is a log. In it I output timing info when that is sent from server, when write to stream is done, and when cork and flush is called. The info for timing info is: time usec since last timing info, sinc usec, buffer size in bytes and as usec, and transport usec. You can see that after a cork 1 (pause) the sinc usec varies a little for a while and then turns to zero, while buffer remains constant. And after cork 0, audio is out of sync with video and latency is unstable - that is it give A-V sync values with plus and minus values. Later on you can se a flush, buffer turns zero but sinc usec remains. For me it looks like sinc usec is the main problem. After a cork 1 (pause) both sinc usec and buffer size should remain constant. After a flush both sinc usec and buffer size should turn zero. sinc usec can retain the device latency - but the timing value contains a lot more. Trying to understand the core I see that sinc usec is device latency plus length of thread_info.render_memblockq. What is render_memblockq? Is it for doing resampling? Even though a player like mplayer will do resampling to match audio device. And even if it is a resampling space it should not change after a pause, and should flush all data at a flush. In mplayer is works like: decoded-buffer -> resampling-buffer -> output-buffer -> send to audio-device. A flush will reset all buffers in mplayer, not just the decoded-buffer that could correspond to the server buffer in pulseaudio. As it is now I can even make the defective oss driver under opensuse 11.2 work better then pulseaudio because it at least handles flush correctly. Below is my log. Dan TIMING info 34491 sinc usec 1964561 buffer bytes 0 buffer usec 0 transport usec 364 TIMING info 54374 sinc usec 1909166 buffer bytes 0 buffer usec 0 transport usec 198 TIMING info 46495 sinc usec 1862673 buffer bytes 0 buffer usec 0 transport usec 228 WRITE len 48000 WRITE len 32224 TIMING info 37777 sinc usec 206979 buffer bytes 43744 buffer usec 227833 transport usec 3822 TIMING info 6236 sinc usec 200611 buffer bytes 43744 buffer usec 227833 transport usec 107 TIMING info 20265 sinc usec 180363 buffer bytes 43744 buffer usec 227833 transport usec 133 WRITE len 4256 TIMING info 40329 sinc usec 140022 buffer bytes 48000 buffer usec 250000 transport usec 116 TIMING info 82672 sinc usec 208621 buffer bytes 18948 buffer usec 98687 transport usec 2507 WRITE len 29052 TIMING info 160831 sinc usec 208444 buffer bytes 17144 buffer usec 89291 transport usec 2626 WRITE len 30856 WRITE len 36504 TIMING info 320346 sinc usec 208450 buffer bytes 22928 buffer usec 119416 transport usec 2150 WRITE len 25072 WRITE len 36472 WRITE len 36464 WRITE len 36468 TIMING info 638341 sinc usec 139353 buffer bytes 48000 buffer usec 250000 transport usec 220 WRITE len 36504 WRITE len 36496 WRITE len 36644 WRITE len 36536 WRITE len 36504 WRITE len 36500 TIMING info 1280522 sinc usec 190337 buffer bytes 11428 buffer usec 59520 transport usec 108 WRITE len 36572 WRITE len 36504 WRITE len 36532 WRITE len 36504 WRITE len 36536 WRITE len 36500 WRITE len 36504 WRITE len 36536 TIMING info 1503143 sinc usec 206842 buffer bytes 11844 buffer usec 61687 transport usec 2663 WRITE len 36156 WRITE len 36780 WRITE len 36500 WRITE len 36536 WRITE len 36504 WRITE len 36500 WRITE len 36536 WRITE len 36540 TIMING info 1500669 sinc usec 207371 buffer bytes 15716 buffer usec 81854 transport usec 2395 WRITE len 32284 WRITE len 36504 WRITE len 36500 CORK 1 (pause) TIMING info 591739 sinc usec 186062 buffer bytes 11500 buffer usec 59895 transport usec 176 TIMING info 345 sinc usec 185904 buffer bytes 11500 buffer usec 59895 transport usec 305 TIMING info 10184 sinc usec 175530 buffer bytes 11500 buffer usec 59895 transport usec 83 TIMING info 20231 sinc usec 155320 buffer bytes 11500 buffer usec 59895 transport usec 111 TIMING info 40325 sinc usec 115018 buffer bytes 11500 buffer usec 59895 transport usec 169 TIMING info 80365 sinc usec 209708 buffer bytes 11500 buffer usec 59895 transport usec 197 TIMING info 160450 sinc usec 209641 buffer bytes 11500 buffer usec 59895 transport usec 206 TIMING info 320633 sinc usec 209801 buffer bytes 11500 buffer usec 59895 transport usec 215 TIMING info 640910 sinc usec 139666 buffer bytes 11500 buffer usec 59895 transport usec 169 TIMING info 1280635 sinc usec 190999 buffer bytes 11500 buffer usec 59895 transport usec 164 TIMING info 1501087 sinc usec 209963 buffer bytes 11500 buffer usec 59895 transport usec 243 TIMING info 948182 sinc usec 0 buffer bytes 11500 buffer usec 59895 transport usec 50 TIMING info 10198 sinc usec 0 buffer bytes 11500 buffer usec 59895 transport usec 85 TIMING info 20192 sinc usec 0 buffer bytes 11500 buffer usec 59895 transport usec 85 TIMING info 40261 sinc usec 0 buffer bytes 11500 buffer usec 59895 transport usec 132 TIMING info 80328 sinc usec 0 buffer bytes 11500 buffer usec 59895 transport usec 154 TIMING info 160386 sinc usec 0 buffer bytes 11500 buffer usec 59895 transport usec 137 TIMING info 320337 sinc usec 0 buffer bytes 11500 buffer usec 59895 transport usec 138 TIMING info 640868 sinc usec 0 buffer bytes 11500 buffer usec 59895 transport usec 138 TIMING info 1281131 sinc usec 0 buffer bytes 11500 buffer usec 59895 transport usec 140 TIMING info 1500990 sinc usec 0 buffer bytes 11500 buffer usec 59895 transport usec 133 TIMING info 1501739 sinc usec 0 buffer bytes 11500 buffer usec 59895 transport usec 141 TIMING info 1501747 sinc usec 0 buffer bytes 11500 buffer usec 59895 transport usec 142 TIMING info 1501529 sinc usec 0 buffer bytes 11500 buffer usec 59895 transport usec 136 TIMING info 1501729 sinc usec 0 buffer bytes 11500 buffer usec 59895 transport usec 139 TIMING info 1501268 sinc usec 0 buffer bytes 11500 buffer usec 59895 transport usec 137 CORK 0 (resume) TIMING info 517365 sinc usec 0 buffer bytes 11500 buffer usec 59895 transport usec 209 TIMING info 10208 sinc usec 209818 buffer bytes 11500 buffer usec 59895 transport usec 9939 TIMING info 36 sinc usec 209666 buffer bytes 11500 buffer usec 59895 transport usec 83 WRITE len 36500 A:6.509862 V:6.172833 A-V: 0.337 -- unstable and out of sync -- TIMING info 10668 sinc usec 198636 buffer bytes 48000 buffer usec 250000 transport usec 50 TIMING info 20186 sinc usec 178464 buffer bytes 48000 buffer usec 250000 transport usec 79 TIMING info 40210 sinc usec 138258 buffer bytes 48000 buffer usec 250000 transport usec 99 TIMING info 61500 sinc usec 208292 buffer bytes 22744 buffer usec 118458 transport usec 73 TIMING info 10175 sinc usec 198116 buffer bytes 22744 buffer usec 118458 transport usec 67 WRITE len 25256 TIMING info 20546 sinc usec 177567 buffer bytes 48000 buffer usec 250000 transport usec 72 TIMING info 40204 sinc usec 137357 buffer bytes 48000 buffer usec 250000 transport usec 91 TIMING info 80996 sinc usec 188002 buffer bytes 22716 buffer usec 118312 transport usec 80 WRITE len 25284 TIMING info 160941 sinc usec 161748 buffer bytes 22120 buffer usec 115208 transport usec 86 WRITE len 22716 WRITE len 25284 WRITE len 22116 TIMING info 320879 sinc usec 181967 buffer bytes 26688 buffer usec 139000 transport usec 168 WRITE len 21312 WRITE len 21912 A:7.006400 V:7.007000 A-V: -0.001 -- stable here -- WRITE len 22148 WRITE len 18740 WRITE len 20864 WRITE len 22080 - log data deleted - TIMING info 1500798 sinc usec 207318 buffer bytes 15364 buffer usec 80020 transport usec 2708 WRITE len 32636 WRITE len 36500 FLUSH TIMING info 340126 sinc usec 207877 buffer bytes 19092 buffer usec 99437 transport usec 2197 TIMING info 300 sinc usec 207701 buffer bytes 0 buffer usec 0 transport usec 2337 WRITE len 48000 TIMING info 7760 sinc usec 199804 buffer bytes 48000 buffer usec 250000 transport usec 80 TIMING info 21707 sinc usec 178095 buffer bytes 48000 buffer usec 250000 transport usec 1588 TIMING info 39284 sinc usec 138820 buffer bytes 48000 buffer usec 250000 transport usec 152 A:28.892986 V:28.945583 A-V: -0.053 - out of sync - TIMING info 82350 sinc usec 207805 buffer bytes 18948 buffer usec 98687 transport usec 2180 WRITE len 29052 TIMING info 160388 sinc usec 207798 buffer bytes 17212 buffer usec 89645 transport usec 2314 WRITE len 30788 WRITE len 36500 TIMING info 320439 sinc usec 207942 buffer bytes 22956 buffer usec 119562 transport usec 2125 WRITE len 25044 WRITE len 36504 WRITE len 36532 A:29.865042 V:29.863167 A-V: 0.002 - stable here - WRITE len 36504 TIMING info 638912 sinc usec 139563 buffer bytes 48000 buffer usec 250000 transport usec 148 WRITE len 36500 WRITE len 36504 WRITE len 36536
