[asterisk-dev] Query about CHECK_BLOCKING(chan) in ast_write()

Tony Mountifield tony at softins.clara.co.uk
Wed Jan 16 09:22:18 CST 2008


While waiting for any replies to my first posting from the experts, I have
been doing some more studying of the usage of CHECK_BLOCKING() and the
flag AST_FLAG_BLOCKING. See below:

Tony Mountifield <tony at softins.clara.co.uk> wrote:
> Yesterday I ported the MeetMe 'F' option (pass through DTMF) back to 1.2,
> and it seems to function, but it flagged up a more general issue that I
> would like some feedback on, either to aid my understanding or to confirm
> that there is a problem that needs addressing.
> 
> Each time I sent a DTMF keypress through the conference, although it
> worked, I had the following message logged to the console:
> 
> Jan 16 10:51:46 WARNING[10600]: channel.c:2262 ast_write: Thread 6750223 Blocking
> 'IAX2/h1peer-19', already blocked by thread 6864913 in procedure ast_waitfor_nandfds
> 
> There are only two channels in the conference: a local SIP phone in
> RFC2833 mode on which I am pressing DTMF keys, and in the above case
> IAX2/h1peer-19 is the channel receiving the passed-through DTMF in
> ast_write() called from MeetMe.
> 
> Looking at line 2262 of channel.c showed the following:
> 
>         CHECK_BLOCKING(chan);
>         switch(fr->frametype) {
>             .
>             .
>             .
>         case AST_FRAME_DTMF:
>                 ast_clear_flag(chan, AST_FLAG_BLOCKING);
>                 ast_mutex_unlock(&chan->lock);
>                 res = do_senddigit(chan,fr->subclass);
>                 ast_mutex_lock(&chan->lock);
>                 CHECK_BLOCKING(chan);
>                 break;
> 
> Trunk is essentially the same, except that it uses ast_channel_lock() and
> has code for audio hooks, so I believe my questions are still relevant to
> current code.
> 
> CHECK_BLOCKING() itself is defined as follows:
> 
> #define CHECK_BLOCKING(c) \
> { \
>   if (ast_test_flag(c, AST_FLAG_BLOCKING)) { \
>     ast_log(LOG_WARNING, "Thread %ld Blocking '%s', already blocked by thread %ld in
> procedure %s\n", (long) pthread_self(), (c)->name, (long) (c)->blocker, %(c)->blockproc); \
>     CRASH; \
>   } else { \
>     (c)->blocker = pthread_self(); \
>     (c)->blockproc = __PRETTY_FUNCTION__; \
>     ast_set_flag(c, AST_FLAG_BLOCKING); \
>   }
> }
> 
> Again, Trunk is identical except that is is wrapped in do ... while(0).
> 
> So the operation of CHECK_BLOCKING() is this: if the channel is not
> blocked, note the current thread and function, and set the blocking flag,
> but otherwise, just issue a warning message, and optionally crash.

I decided to look in detail at the code in Trunk (snapshot from 3 Jan 2008),
to try and understand the correct purpose of AST_FLAG_BLOCKING. I found the
following uses:

1) In chan_phone.c, function phone_read():

        /* Try to read some data... */
        CHECK_BLOCKING(ast);
        res = read(p->fd, p->buf, PHONE_MAX_BUF);
        ast_clear_flag(ast, AST_FLAG_BLOCKING);

At this point, the channel mutex is not locked.

2) In chan_zap.c, function zt_read():

        CHECK_BLOCKING(ast);
        res = read(p->subs[index].zfd, readbuf, p->subs[index].linear ? READ_SIZE * 2 : READ_SIZE);
        ast_clear_flag(ast, AST_FLAG_BLOCKING);

At this point, the channel mutex is not locked, although the pvt is locked.

3) In channel.c, function ast_waitfor_nandfds_classic():

Pseudo-code:
        foreach channel in the supplied channel array {
                Add the fds to the poll list;
                CHECK_BLOCKING(channel);
        }
        ...
        poll(fds, maxfd, timeout);
        foreach channel in the spuulied channel array {
                ast_clear_flag(channel, AST_FLAG_BLOCKING);
        }

4) In channel.c, function ast_waitfor_nandfds_simple() on single channel:

        CHECK_BLOCKING(channel);
        epoll_wait(...);
        ast_clear_flag(channel, AST_FLAG_BLOCKING);

5) In channel.c, function ast_waitfor_nandfds_complex() is effectively the
same as case 3 above, but using epoll_wait().

6) In channel.c, function ast_sendtext():

        CHECK_BLOCKING(chan);
        if (chan->tech->send_text)
                res = chan->tech->send_text(chan, text);
        ast_clear_flag(chan, AST_FLAG_BLOCKING);

The above are all the uses of AST_FLAG_BLOCKING, except those in ast_write().
In all the above cases, it appears that the intention of the flag is to be
set while the channel is NOT locked, but a thread is in a potentially
blocking operation on that channel, such as read(), poll(), etc., so that
we can be alerted (or optionally crash with a coredump) if another thread
also attempts to perform a blocking operation for the same channel.

No other channel technologies appear to perform the above operations,
although it makes me wonder whether there are places where they ought to.

The uses of CHECK_BLOCKING() and AST_FLAG_BLOCKING in channel.c:ast_write()
do not appear to follow the above philosophy, and I wonder whether they are
perhaps incorrect. Apologies for the lengthy code quotation, but I wanted
people to see the relevant points and comment without having to look up
channel.c. Relevant lines marked with ==>:

        /*Deadlock avoidance*/
==>     while(ast_channel_trylock(chan)) {
                /*cannot goto done since the channel is not locked*/
                if(count++ > 10) {
                        ast_debug(1, "Deadlock avoided for write to channel '%s'\n", chan->name);
                        return 0;
                }
                usleep(1);
        }
        /* Stop if we're a zombie or need a soft hangup */
        if (ast_test_flag(chan, AST_FLAG_ZOMBIE) || ast_check_hangup(chan))
                goto done;

        /* Handle any pending masquerades */
        if (chan->masq && ast_do_masquerade(chan)) {
                ast_log(LOG_WARNING, "Failed to perform masquerade\n");
                goto done;
        }
        if (chan->masqr) {
                res = 0;        /* XXX explain, why 0 ? */
                goto done;
        }
        if (chan->generatordata) {
                if (ast_test_flag(chan, AST_FLAG_WRITE_INT))
                        ast_deactivate_generator(chan);
                else {
                        if (fr->frametype == AST_FRAME_DTMF_END) {
                                /* There is a generator running while we're in the middle of a digit.
                                 * It's probably inband DTMF, so go ahead and pass it so it can
                                 * stop the generator */
==>                             ast_clear_flag(chan, AST_FLAG_BLOCKING);
==>                             ast_channel_unlock(chan);
                                res = ast_senddigit_end(chan, fr->subclass, fr->len);
==>                             ast_channel_lock(chan);
==>                             CHECK_BLOCKING(chan);
                        } else if (fr->frametype == AST_FRAME_CONTROL && fr->subclass == AST_CONTROL_UNHOLD) {
                                /* This is a side case where Echo is basically being called and the person put themselves on hold and took themselves off hold */
                                res = (chan->tech->indicate == NULL) ? 0 :
                                        chan->tech->indicate(chan, fr->subclass, fr->data, fr->datalen);
                        }
                        res = 0;        /* XXX explain, why 0 ? */
                        goto done;
                }
        }
        /* High bit prints debugging */
        if (chan->fout & DEBUGCHAN_FLAG)
                ast_frame_dump(chan->name, fr, ">>");
==>     CHECK_BLOCKING(chan);
        switch (fr->frametype) {
        case AST_FRAME_CONTROL:
                res = (chan->tech->indicate == NULL) ? 0 :
                        chan->tech->indicate(chan, fr->subclass, fr->data, fr->datalen);
                break;
        case AST_FRAME_DTMF_BEGIN:
                if (chan->audiohooks) {
                        struct ast_frame *old_frame = fr;
                        fr = ast_audiohook_write_list(chan, chan->audiohooks, AST_AUDIOHOOK_DIRECTION_WRITE, fr);
                        if (old_frame != fr)
                                f = fr;
                }
                send_dtmf_event(chan, "Sent", fr->subclass, "Yes", "No");
==>             ast_clear_flag(chan, AST_FLAG_BLOCKING);
==>             ast_channel_unlock(chan);
                res = ast_senddigit_begin(chan, fr->subclass);
==>             ast_channel_lock(chan);
==>             CHECK_BLOCKING(chan);
                break;
        case AST_FRAME_DTMF_END:
                if (chan->audiohooks) {
                        struct ast_frame *old_frame = fr;
                        fr = ast_audiohook_write_list(chan, chan->audiohooks, AST_AUDIOHOOK_DIRECTION_WRITE, fr);
                        if (old_frame != fr)
                                f = fr;
                }
                send_dtmf_event(chan, "Sent", fr->subclass, "No", "Yes");
==>             ast_clear_flag(chan, AST_FLAG_BLOCKING);
==>             ast_channel_unlock(chan);
                res = ast_senddigit_end(chan, fr->subclass, fr->len);
==>             ast_channel_lock(chan);
==>             CHECK_BLOCKING(chan);
                break;

In all the above examples, a completely different philosophy seems to be
followed: set AST_FLAG_BLOCKING to indicate the channel is locked, and then
clear it again just before unlocking. This seems to be pointless, and at
odds with all the other usage, unless my understanding is flawed. I suspect
that ast_write() shouldn't be doing these operations at all, but that the
channel technology drivers should be doing them around any blocking calls.

I see that in the Trunk version of CHECK_BLOCKING(), the warning message
has been changed from LOG_WARNING to LOG_DEBUG. This seems like "we don't
understand why it happens, so lets just hide it"!

Comments?

Cheers
Tony
-- 
Tony Mountifield
Work: tony at softins.co.uk - http://www.softins.co.uk
Play: tony at mountifield.org - http://tony.mountifield.org



More information about the asterisk-dev mailing list