Bug 45643 - padsp wrapper is racy at startup
Summary: padsp wrapper is racy at startup
Status: RESOLVED MOVED
Alias: None
Product: PulseAudio
Classification: Unclassified
Component: tools (show other bugs)
Version: unspecified
Hardware: Other All
: medium normal
Assignee: pulseaudio-bugs
QA Contact: pulseaudio-bugs
URL:
Whiteboard: triaged
Keywords:
Depends on:
Blocks:
 
Reported: 2012-02-05 02:53 UTC by Sergei Trofimovich
Modified: 2018-07-30 10:31 UTC (History)
2 users (show)

See Also:
i915 platform:
i915 features:


Attachments
padsp-wait-for-context-initialization-in-ioctl-SNDCT.patch (1.34 KB, patch)
2012-02-05 05:14 UTC, Sergei Trofimovich
Details | Splinter Review

Description Sergei Trofimovich 2012-02-05 02:53:22 UTC
Initial symptomes: libmikmod clients SIGSEGV when ran under 'padsp'
wrapper. The reason is padsp returns incorrect buffer fill info:

(reproducer: PADSP_DEBUG=3 padsp mikmod some_files)

utils/padsp.c:fragsize=16384, fragstotal=16, bytes=262144, fragments=16
utils/padsp.c:fragsize=16384, fragstotal=16, bytes=262144, fragments=16

utils/padsp.c:fragsize=16384, fragstotal=16, bytes=-16385, fragments=-1
<mikmod SIGSEGV. When patch mikmod to ignore such strange fragments
I get playing sounds. and log restores state:>
utils/padsp.c:fragsize=16384, fragstotal=16, bytes=245760, fragments=15
...


I've added debug info to padsp.c and stream.c to see where stream state flips
from READY back to _CREATING and I think i'bve figured out where:

Log with additional debug info:
    state=4 - _READY stream state
    state=1 - _CREATING stream state

utils/padsp.c: dsp_open() succeeded, fd=3; state=4
utils/padsp.c: SNDCTL_DSP_SETFRAGMENT: 0x0010000e
utils/padsp.c: SNDCTL_DSP_GETFMTS
utils/padsp.c: SNDCTL_DSP_SETFMT: 16
utils/padsp.c: SNDCTL_DSP_CHANNELS: 2
utils/padsp.c: SNDCTL_DSP_SPEED: 48000
utils/padsp.c: ss: s16le 2ch 48000Hz
utils/padsp.c: SNDCTL_DSP_GETOSPACE
utils/padsp.c: ioctl()
utils/padsp.c:(ctx=(nil)) fragsize=16384, fragstotal=16, bytes=262144, fragments=16 (state=4)

   no player context, but stream is considered ready

utils/padsp.c: fopen(a94final.uni)
utils/padsp.c: fclose()
utils/padsp.c: open(a94final.uni)
utils/padsp.c: fclose()
utils/padsp.c: ioctl()
utils/padsp.c: SNDCTL_DSP_GETOSPACE
utils/padsp.c: ioctl()
utils/padsp.c:(ctx=(nil)) fragsize=16384, fragstotal=16, bytes=262144, fragments=16 (state=4)

utils/padsp.c: ref--, now 1
utils/padsp.c: ioctl()
utils/padsp.c: ref++, now 2
utils/padsp.c: SNDCTL_DSP_GETOSPACE
utils/padsp.c: pa_stream_new() called!

pa_stream_set_state(0xa37f40): 0->1
   created player context and switches stream back to _CREATING

pa_stream_writable_size(0xa37f40) is forky?
pa_stream_writable_size(0xa37f40) is ready? (s->state=1)
   _CREATING i not READY, so fail

utils/padsp.c: pa_stream_writable_size(0xa37f40): Bad state; state=4 (PA_STREAM_CREATING=1)
utils/padsp.c: ioctl()
utils/padsp.c:(ctx=0xa37f40) fragsize=16384, fragstotal=16, bytes=-16385, fragments=-1 (state=4)

   and return garbage to client

A little after..
pa_stream_set_state(0xa37f40): 1->2
utils/padsp.c: stream established.

  something happened in event io thread (io_event_cb was activated and create_playback_stream() started creating)

utils/padsp.c: SNDCTL_DSP_GETOSPACE
utils/padsp.c: ioctl()
utils/padsp.c:(ctx=0xa37f40) fragsize=16384, fragstotal=16, bytes=245760, fragments=15 (state=4)

  and things got back to normal
Comment 1 Sergei Trofimovich 2012-02-05 05:14:31 UTC
Created attachment 56624 [details] [review]
padsp-wait-for-context-initialization-in-ioctl-SNDCT.patch

Patch seems to fix error for me.
We just wait until context initializes in io actions.
Comment 2 Arun Raghavan 2012-02-08 21:50:50 UTC
This looks a bit odd. fd_info_new(), which is called from dsp_open(), only returns when the context is READY.
Comment 3 Sergei Trofimovich 2012-02-11 07:51:18 UTC
(In reply to comment #2)
> This looks a bit odd. fd_info_new(), which is called from dsp_open(), only returns when the context is READY.

Right. Let's consider the following code:

dsp_open calls:
    fd_info_new()
    ...
    i->io_event = api->io_new(api, i->thread_fd, i->io_flags, io_event_cb, i);

Before any IO occurs the state s READY, and it's seen in trace, but later.
When io occurs 'io_event_cb' is triggered (callback called asynchronously,
right?)

Let's looks at where it does there:
io_event_cb:
    // no idea what it does, but looks like it unblocks clients
    pa_threaded_mainloop_signal(i->mainloop, 0); 

    // and then starts actual stream initialization
    if (flags & PA_IO_EVENT_INPUT) {
        if (!i->play_stream) {
            if (create_playback_stream(i) < 0)

create_playback_stream:
    // stream _DROPS_ initialization state down to: PA_STREAM_UNCONNECTED and then to PA_STREAM_CREATING
    i->play_stream = pa_stream_new(i->context, stream_name(), &i->sample_spec, NULL);

    pa_stream_set_state_callback(i->play_stream, stream_state_cb, i);
    pa_stream_set_write_callback(i->play_stream, stream_request_cb, i);
    pa_stream_set_latency_update_callback(i->play_stream, stream_latency_update_cb, i);
Comment 4 Colin Guthrie 2012-03-13 17:28:49 UTC
Let's make sure we get to this one for 2.0.
Comment 5 Arun Raghavan 2012-03-15 00:02:14 UTC
(In reply to comment #3)
> (In reply to comment #2)
> > This looks a bit odd. fd_info_new(), which is called from dsp_open(), only returns when the context is READY.
> 
> Right. Let's consider the following code:
> 
> dsp_open calls:
>     fd_info_new()
>     ...
>     i->io_event = api->io_new(api, i->thread_fd, i->io_flags, io_event_cb, i);
> 
> Before any IO occurs the state s READY, and it's seen in trace, but later.
> When io occurs 'io_event_cb' is triggered (callback called asynchronously,
> right?)

Yes, this registers an async callback when some I/O occurs.

> Let's looks at where it does there:
> io_event_cb:
>     // no idea what it does, but looks like it unblocks clients
>     pa_threaded_mainloop_signal(i->mainloop, 0); 

This is standard POSIX condition semantics -- the main thread is being told that some condition it is waiting for has been met.

>     // and then starts actual stream initialization
>     if (flags & PA_IO_EVENT_INPUT) {
>         if (!i->play_stream) {
>             if (create_playback_stream(i) < 0)
> 
> create_playback_stream:
>     // stream _DROPS_ initialization state down to: PA_STREAM_UNCONNECTED and
> then to PA_STREAM_CREATING
>     i->play_stream = pa_stream_new(i->context, stream_name(), &i->sample_spec,
> NULL);

This creates a new stream, doesn't mess with an existing stream.

This could go faster if you have some sort of quick test case for me to reproduce the issue locally.
Comment 6 Arun Raghavan 2012-04-02 22:57:00 UTC
Dropping as 2.0 blocker, but let's continue pinning down the actual problem
Comment 7 GitLab Migration User 2018-07-30 10:31:56 UTC
-- GitLab Migration Automatic Message --

This bug has been migrated to freedesktop.org's GitLab instance and has been closed from further activity.

You can subscribe and participate further through the new bug through this link to our GitLab instance: https://gitlab.freedesktop.org/pulseaudio/pulseaudio/issues/490.


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.