<html>
    <head>
      <base href="https://bugs.freedesktop.org/" />
    </head>
    <body><table border="1" cellspacing="0" cellpadding="8">
        <tr>
          <th>Bug ID</th>
          <td><a class="bz_bug_link 
          bz_status_NEW "
   title="NEW - [regression] DYNAMIC_LATENCY introduced in module-combine causes a race contition between pa_sink_render_into_full and sink_update_requested_latency_cb in alsa-sink.c"
   href="https://bugs.freedesktop.org/show_bug.cgi?id=90489">90489</a>
          </td>
        </tr>

        <tr>
          <th>Summary</th>
          <td>[regression] DYNAMIC_LATENCY introduced in module-combine causes a race contition between pa_sink_render_into_full and sink_update_requested_latency_cb in alsa-sink.c
          </td>
        </tr>

        <tr>
          <th>Product</th>
          <td>PulseAudio
          </td>
        </tr>

        <tr>
          <th>Version</th>
          <td>unspecified
          </td>
        </tr>

        <tr>
          <th>Hardware</th>
          <td>All
          </td>
        </tr>

        <tr>
          <th>OS</th>
          <td>All
          </td>
        </tr>

        <tr>
          <th>Status</th>
          <td>NEW
          </td>
        </tr>

        <tr>
          <th>Severity</th>
          <td>normal
          </td>
        </tr>

        <tr>
          <th>Priority</th>
          <td>medium
          </td>
        </tr>

        <tr>
          <th>Component</th>
          <td>modules
          </td>
        </tr>

        <tr>
          <th>Assignee</th>
          <td>pulseaudio-bugs@lists.freedesktop.org
          </td>
        </tr>

        <tr>
          <th>Reporter</th>
          <td>marcel132132@gmail.com
          </td>
        </tr>

        <tr>
          <th>QA Contact</th>
          <td>pulseaudio-bugs@lists.freedesktop.org
          </td>
        </tr>

        <tr>
          <th>CC</th>
          <td>lennart@poettering.net
          </td>
        </tr></table>
      <p>
        <div>
        <pre>When sink_update_requested_latency() in src/modules/module-combine-sink.c:790
is called, it posts a SINK_INPUT_MESSAGE_SET_REQUESTED_LATENCY message to all
of it's output sinks. If one of the sinks is created by module-alsa-sink,
sink_update_requested_latency_cb() in src/alsa/alsa-sink.c:1507 is called to
handle the latency change. This function, except updating the latency,
sometimes also creates a rewind request. 

If the rewind request gets processed before the pa_sink_render_into_full() is
called, everything will work as supposed. However if not, the
"!s->thread_info.rewind_requested" assertion is being triggered on
src/pulsecore/sink.c:1323, causing whole server to abort.

Commit that introduced this is here:
<a href="http://cgit.freedesktop.org/pulseaudio/pulseaudio/commit/?id=23f120aabbf4d48d7012e196cf95d89ec6b6d8c8">http://cgit.freedesktop.org/pulseaudio/pulseaudio/commit/?id=23f120aabbf4d48d7012e196cf95d89ec6b6d8c8</a>

Here's the part of PulseAudio's output:

[...]
I: [pulseaudio] protocol-native.c: Requested tlength=272,11 ms, minreq=20,00 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=116,05 ms, Received
latency=116,05 ms
D: [pulseaudio] memblockq.c: memblockq requested: maxlength=4194304,
tlength=27528, base=4, prebuf=24004, minreq=3528 maxrewind=0
D: [pulseaudio] memblockq.c: memblockq sanitized: maxlength=4194304,
tlength=27528, base=4, prebuf=24004, minreq=3528 maxrewind=0
I: [pulseaudio] protocol-native.c: Final latency 272,11 ms = 116,05 ms +
2*20,00 ms + 116,05 ms
D: [combine] module-combine-sink.c: Sink update requested latency 116,05
D: [combine] protocol-native.c: max_request changed, trying to update from
27528 to 42336.
D: [combine] protocol-native.c: Notifying client about increased tlength
D: [alsa-sink-CX20757 Analog] alsa-sink.c: Latency set to 116,05ms
D: [alsa-sink-CX20757 Analog] alsa-sink.c: hwbuf_unused=332300
D: [alsa-sink-CX20757 Analog] alsa-sink.c: setting avail_min=87311
D: [alsa-sink-CX20757 Analog] module-combine-sink.c: Sink input update max
request 20468
D: [alsa-sink-CX20757 Analog] alsa-sink.c: Requesting rewind due to latency
change.
D: [combine] module-combine-sink.c: Sink update max request 20468
E: [alsa-sink-CX20757 Analog] sink.c: Assertion
'!s->thread_info.rewind_requested' failed at pulsecore/sink.c:1239, 

The assertion is almost always triggered when following conditions are met:

- /etc/pulse/default.pa contains:

# alsa_output.pci-0000_00_14.2.analog-stereo is the name of default output sink
load-module module-combine-sink sink_name=media
slaves=alsa_output.pci-0000_00_14.2.analog-stereo resample_method=speex-float-1
format=s16le rate=44100 channels=2 
load-module module-sine sink=media frequency=440

set-default-source media.monitor

- module-sine's outputs to the sink created by module-combine-sink and is muted
- Audacity is starting while some program (Rhythmbox in my case) is playing
sounds using the native protocol.</pre>
        </div>
      </p>
      <hr>
      <span>You are receiving this mail because:</span>
      
      <ul>
          <li>You are the QA Contact for the bug.</li>
          <li>You are the assignee for the bug.</li>
      </ul>
    </body>
</html>