[FFmpeg-devel] [PATCH] pthread_frame: make accesses to debug field be protected by owner lock.

[Ronald S. Bultje]

Hi,

On Fri, Apr 7, 2017 at 2:37 AM, wm4 <nfxjfg at googlemail.com> wrote:

> On Thu,  6 Apr 2017 13:48:41 -0400
> "Ronald S. Bultje" <rsbultje at gmail.com> wrote:
>
> > The av_log() is done outside the lock, but this way the accesses to the
> > field (reads and writes) are always protected by a mutex. The av_log()
> > is not run inside the lock context because it may involve user callbacks
> > and doing that in performance-sensitive code is probably not a good idea.
> >
> > This should fix occasional tsan warnings when running fate-h264, like:
> >
> > WARNING: ThreadSanitizer: data race (pid=10916)
> >   Write of size 4 at 0x7d64000174fc by main thread (mutexes: write
> M2313):
> >     #0 update_context_from_user src/libavcodec/pthread_frame.c:335
> (ffmpeg+0x000000df7b06)
> > [..]
> >   Previous read of size 4 at 0x7d64000174fc by thread T1 (mutexes: write
> M2311):
> >     #0 ff_thread_await_progress src/libavcodec/pthread_frame.c:592
> (ffmpeg+0x000000df8b3e)
> > ---
> >  libavcodec/pthread_frame.c | 20 ++++++++++++--------
> >  1 file changed, 12 insertions(+), 8 deletions(-)
> >
> > diff --git a/libavcodec/pthread_frame.c b/libavcodec/pthread_frame.c
> > index c246c2f..8857bfc 100644
> > --- a/libavcodec/pthread_frame.c
> > +++ b/libavcodec/pthread_frame.c
> > @@ -559,6 +559,7 @@ void ff_thread_report_progress(ThreadFrame *f, int
> n, int field)
> >  {
> >      PerThreadContext *p;
> >      atomic_int *progress = f->progress ? (atomic_int*)f->progress->data
> : NULL;
> > +    int debug_mv;
> >
> >      if (!progress ||
> >          atomic_load_explicit(&progress[field], memory_order_relaxed)
> >= n)
> > @@ -566,22 +567,24 @@ void ff_thread_report_progress(ThreadFrame *f,
> int n, int field)
> >
> >      p = f->owner[field]->internal->thread_ctx;
> >
> > -    if (f->owner[field]->debug&FF_DEBUG_THREADS)
> > -        av_log(f->owner[field], AV_LOG_DEBUG,
> > -               "%p finished %d field %d\n", progress, n, field);
> > -
> >      pthread_mutex_lock(&p->progress_mutex);
> > +    debug_mv = f->owner[field]->debug&FF_DEBUG_THREADS;
> >
> >      atomic_store_explicit(&progress[field], n, memory_order_release);
> >
> >      pthread_cond_broadcast(&p->progress_cond);
> >      pthread_mutex_unlock(&p->progress_mutex);
> > +
> > +    if (debug_mv)
> > +        av_log(f->owner[field], AV_LOG_DEBUG,
> > +               "%p finished %d field %d\n", progress, n, field);
> >  }
> >
> >  void ff_thread_await_progress(ThreadFrame *f, int n, int field)
> >  {
> >      PerThreadContext *p;
> >      atomic_int *progress = f->progress ? (atomic_int*)f->progress->data
> : NULL;
> > +    int debug_mv;
> >
> >      if (!progress ||
> >          atomic_load_explicit(&progress[field], memory_order_acquire)
> >= n)
> > @@ -589,14 +592,15 @@ void ff_thread_await_progress(ThreadFrame *f, int
> n, int field)
> >
> >      p = f->owner[field]->internal->thread_ctx;
> >
> > -    if (f->owner[field]->debug&FF_DEBUG_THREADS)
> > -        av_log(f->owner[field], AV_LOG_DEBUG,
> > -               "thread awaiting %d field %d from %p\n", n, field,
> progress);
> > -
> >      pthread_mutex_lock(&p->progress_mutex);
> > +    debug_mv = f->owner[field]->debug&FF_DEBUG_THREADS;
> >      while (atomic_load_explicit(&progress[field],
> memory_order_relaxed) < n)
> >          pthread_cond_wait(&p->progress_cond, &p->progress_mutex);
> >      pthread_mutex_unlock(&p->progress_mutex);
> > +
> > +    if (debug_mv)
> > +        av_log(f->owner[field], AV_LOG_DEBUG,
> > +               "thread awaited %d field %d from %p\n", n, field,
> progress);
> >  }
> >
> >  void ff_thread_finish_setup(AVCodecContext *avctx) {
>
> I'm not sure what "debug_mv" stands for, and I think this is a bit
> overkill. It's run only when FF_DEBUG_THREADS is set (who even sets
> that,


I actually occasionally use it.

and why does access to it need to be synchronized?),


Now that's a really good question.

Let me give my explanation (which is probably similar to Clement's) and
then we can see if others agree with it.

So first of all: is there a race condition here? Really, no. Sort of. A
race condition is (for me) non-static behaviour in output in response to
otherwise identical input. So imagine the following code fragment:

avctx = alloc(threads=2); open(avctx);
for (i=0;i<5;i++)
    decode(avctx, frame);
close(avctx);

Is there a race condition (with my definition)? No. The code will always
give the same return values. Now, let's look at this code fragment:

avctx = alloc(threads=2); open(avctx);
for (i=0;i<5;i++) {
    decode(avctx, frame);
    if (i == 2) { avctx->debug |= THREADS; av_log_set_level(DEBUG); }
}
close(avctx);

Here, a week ago, you got a race condition because user threads would be
synchronized with the next worker thread unlocked, thus allowing
debug&THREADS to be updated mid-frame in an active thread. This was fixed
in 1269cd5.

Is this a big deal? No, honestly. But it's sort-of a race. If you wanted to
debug threading, at least it know always produces the same output.

This patch does not solve a race of that kind. It just removes a tsan
warning about a protected write and an unprotected read in an unrelated
thread that is waiting for the "owner" thread. So why would we do that? My
answer is: primarily to make tsan less noisy. It found "fake" (like this)
and "real" (some having real implications) races, and we will never find
the real races unless we silence the fake ones also. As long as I can do
that without affecting performance and code readability, I'm happy to do
so. If it affects readability or performance, I will obviously leave it
as-is.

so I see no big offense in calling av_log() inside of it.


There's that also... I have no strong opinion on that.

Ronald