Comment 3 for bug 660567

Hi David

Here's the log. I ran it like this, so I could also see the pulseaudio log interspersed with the output of my test program:

 $ LANG=C pulseaudio -vvvv 2>&1 | tee ~/pulseverbose.log & (sleep 1 ; ../src/beep/beep )

Of course there is a lot of messages before playing the first tone, but after that pulse is quiet while playing until I call pa_simple_drain:

[0.343553] play done
[0.343609] not calling pa_simple_drain()
[0.357608] playing 680 hz tone volume 50 for 500 ms
[0.834818] play done
[0.834878] not calling pa_simple_drain()
[0.848907] playing 440 hz tone volume 50 for 500 ms
[1.302643] play done
(I call pa_simple_drain here)
D: protocol-native.c: Underrun on 'beep', 0 bytes in queue.
[3.504083] pa_simple_drain() done
[3.517146] playing 680 hz tone volume 50 for 500 ms
D: protocol-native.c: Requesting rewind due to end of underrun.
D: alsa-sink.c: Requested to rewind 9992 bytes.
D: alsa-sink.c: Limited to 9992 bytes.
D: alsa-sink.c: before: 2498
D: alsa-sink.c: after: 2498
D: alsa-sink.c: Rewound 9992 bytes.
D: sink.c: Processing rewind...
D: sink-input.c: Have to rewind 9992 bytes on render memblockq.
D: source.c: Processing rewind...

The only message pa_simple_drain() causes, is the underrun (which happens after the buffer runs out, but long before pa_simple_drain() returns - this is visible from observing it in real time, I could make a filter to put timestamps on the pulse log entries that would make this clearer). This underrun (and the subsequent recovery stanza) seems to be normal behaviour when the buffer runs out, as it also happens at the start of the program, and would be expected when calling pa_simple_drain(), but I would also expect pa_simple_drain() to return immediately when the underrun occurs.