[asterisk-dev] How does a call to ast_read end up in ast_write

[Moises Silva]

Steve,

I have not checked deeply your issue and backtraces, but, the answer
to your question about how a ast_read() ends up in ast_write is that,
in Asterisk, writing is "tied" to reading. That is, as frames arrive,
frames go out. So each time an ast_read() is done in some channel,
Asterisk will check if the channel has a generator active and it will
give it a chance to generate a frame to be written to the channel.
Generators exists to generate (duh!) frames from different sources.
One of such sources is the music on hold engine that writes frame to
channels by reading from audio files. Other generator is registered by
the well known application app_chanspy, which I think generate its
frames from what it reads from the channel is spying to. So, imagine
you are not in a bridge, you just have a channel in StartMusicOnHold
application. All the StartMusicOnHold application does is activate a
generator in the channel, that causes that each time Asterisk reads a
frame from the channel on hold, also will ask the generator to write a
frame to that channel.

If you want to see other generator examples you can grep -rI
ast_generator ./ in your sources tree. This is some of the output I
get from 1.2.24 sources:

./res/res_musiconhold.c:static struct ast_generator moh_file_stream =
./res/res_musiconhold.c:static struct ast_generator mohgen =
./channel.c:static struct ast_generator tonepair = {
./channel.c:static struct ast_generator silence_generator = {
./apps/app_sms.c:static struct ast_generator smsgen = {
./apps/app_chanspy.c:static struct ast_generator spygen = {
./apps/app_externalivr.c:static struct ast_generator gen =
./apps/app_milliwatt.c:static struct ast_generator milliwattgen =
./indications.c:static struct ast_generator playtones = {
./app.c:static struct ast_generator linearstream =

Moy

On Dec 24, 2007 12:35 AM, Stephen Davies <stephen.l.davies at gmail.com> wrote:
> Hi,
>
> I'm trying to track some sort of deadlock in 1.2 involving Local channels
> and calls being placed on/off hold.
> I think the problem bites when both ends of a call have placed the other on
> hold at the same time.
>
> (I've been working in 1.2.24, but the code isn't changed in the most recent.
> I'll investigate 1.4/trunk once I've fixed the clients' immediate problem)
>
> I have three threads involved in the deadlock:
>
>
> The first is the original caller bridging to the Local/...,1 channel:
>
> Thread 24 (process 10764):
> #0  0xffffe410 in __kernel_vsyscall ()
> #1  0x0089eb86 in __nanosleep_nocancel () from /lib/tls/libc.so.6
> #2  0x008d530a in usleep () from /lib/tls/libc.so.6
> #3  0xb7b940bc in local_queue_frame (p=0xb65006b8, isoutbound=Variable
> "isoutbound" is not available.
> ) at chan_local.c:152
> #4  0xb7b944e6 in local_write (ast=0xb6508300, f=0xb710a908) at
> chan_local.c:261
> #5  0x080655ab in ast_write (chan=0xb6508300, fr=0xb7105434) at
> channel.c:2358
> #6  0xb7e2eda2 in moh_files_generator (chan=0xb6508300, data=0xb7101ac0,
> len=160, samples=160) at res_musiconhold.c:271
> #7  0x0806639f in ast_read (chan=0xb6508300) at channel.c:2050
> #8  0x08069778 in ast_channel_bridge (c0=0xb6513e90, c1=0xb6508300,
> config=0xb70f8850, fo=0xb70f7fd0, rc=0xb70f7fd4) at channel.c:3399
> #9  0xb7e02d45 in ast_bridge_call (chan=0xb6513e90, peer=0xb6508300,
> config=0xb70f8850) at res_features.c:1341
> #10 0xb73f8c2b in try_calling (qe=0xb70f8b50, options=Variable "options" is
> not available.
> ) at app_queue.c:2428
> #11 0xb73fd28e in queue_exec (chan=0xb6513e90, data=0xb70fd0a0) at
> app_queue.c:3163
> #12 0x0809058d in pbx_extension_helper (c=0xb6513e90, con=Variable "con" is
> not available.
> ) at pbx.c:574
> #13 0x08091866 in __ast_pbx_run (c=0xb6513e90) at pbx.c:2250
> #14 0x0809340c in pbx_thread (data=0xfffffdfc) at pbx.c:2537
> #15 0x009db371 in start_thread () from /lib/tls/libpthread.so.0
> #16 0x008dbffe in clone () from /lib/tls/libc.so.6
>
>
>  The second is the bridge from the Local/.,2 channel to the end point:
>
>
> Thread 23 (process 11544):
> #0  0xffffe410 in __kernel_vsyscall ()
> #1  0x0089eb86 in __nanosleep_nocancel () from /lib/tls/libc.so.6
> #2  0x008d530a in usleep () from /lib/tls/libc.so.6
> #3  0xb7b941fc in local_queue_frame (p=0xb65006b8, isoutbound=Variable
> "isoutbound" is not available.
> ) at chan_local.c:152
> #4  0xb7b944e6 in local_write (ast=0xb65078f8, f=0x823e018) at
> chan_local.c:261
> #5  0x080655ab in ast_write (chan=0xb65078f8, fr=0x82b9cdc) at
> channel.c:2358
> #6  0xb7e2eda2 in moh_files_generator (chan=0xb65078f8, data=0xb65087d8,
> len=160, samples=160) at res_musiconhold.c:271
> #7  0x0806639f in ast_read (chan=0xb65078f8) at channel.c:2050
> #8  0x08069778 in ast_channel_bridge (c0=0xb65078f8, c1=0x8256d60,
> config=0xb6fc7d50, fo=0xb6fc7200, rc=0xb6fc7204) at channel.c:3399
> #9  0xb7e02d45 in ast_bridge_call (chan=0xb65078f8, peer=0x8256d60,
> config=0xb6fc7d50) at res_features.c:1341
> #10 0xb74a30ba in dial_exec_full (chan=0xb65078f8, data=Variable "data" is
> not available.
> ) at app_dial.c:1633
> #11 0xb74a5a33 in dial_exec (chan=0xfffffdfc, data=0xb7b96cfc) at
> app_dial.c:1680
> #12 0x0809058d in pbx_extension_helper (c=0xb65078f8, con=Variable "con" is
> not available.
> ) at pbx.c:574
> #13 0x08090b4c in ast_spawn_extension (c=0xfffffdfc, context=0xb7b96cfc "",
> exten=0xb7b96cfc "", priority=-1212584708,
>    callerid=0xb7b96cfc "") at pbx.c:2250
> #14 0xb7278ed0 in macro_exec (chan=0xb65078f8, data=0xb6fd3b30) at
> app_macro.c:297
> #15 0x0809058d in pbx_extension_helper (c=0xb65078f8, con=Variable "con" is
> not available.
> ) at pbx.c:574
> #16 0x08090b4c in ast_spawn_extension (c=0xfffffdfc, context=0xb7b96cfc "",
> exten=0xb7b96cfc "", priority=-1212584708,
>    callerid=0xb7b96cfc "") at pbx.c:2250
> #17 0xb7278ed0 in macro_exec (chan=0xb65078f8, data=0xb6fdb0a0) at
> app_macro.c:297
> #18 0x0809058d in pbx_extension_helper (c=0xb65078f8, con=Variable "con" is
> not available.
> ) at pbx.c:574
> #19 0x08091866 in __ast_pbx_run (c=0xb65078f8) at pbx.c:2250
> #20 0x0809340c in pbx_thread (data=0xfffffdfc) at pbx.c:2537
> #21 0x009db371 in start_thread () from /lib/tls/libpthread.so.0
> #22 0x008dbffe in clone () from /lib/tls/libc.so.6
>
>  These two threads are in a sort of soft-deadlock: they are running some
> deadlock-avoiding logic in local_queue_frame, but its not working
> effectively due to the fact that the channel that each is holding was locked
> twice before local_queue_frame was called: once in ast_read and once in
> ast_write.  So the deadlock-avoiding logic unlocks it once, but the
> recursive lock still has one lock active.
>
>  Lastly, the SIP signalling thread is trying to get the one call off hold,
> but is now stuck because it is waiting also to get a lock on one of the
> Local channels.  Given that the SIP signalling thread is stuck, all SIP is
> dead:
>
>  Thread 27 (process 8458):
> #0  0xffffe410 in __kernel_vsyscall ()
> #1  0x009e01de in __lll_mutex_lock_wait () from /lib/tls/libpthread.so.0
> #2  0x009dce47 in _L_mutex_lock_179 () from /lib/tls/libpthread.so.0
> #3  0xb781d24a in ?? ()
> #4  0xb6508300 in ?? ()
> #5  0xb65083cc in ?? ()
> #6  0xb7815f90 in ?? ()
> #7  0xb78164f8 in ?? ()
> #8  0x08062cbd in ast_deactivate_generator (chan=0xb6508300) at
> include/asterisk/lock.h:601
> #9  0xb7e31029 in local_ast_moh_stop (chan=0xb6508300) at
> res_musiconhold.c:939
> #10 0xb7829372 in process_sdp (p=0x0, req=0x0) at chan_sip.c:3801
>
>
> To find the root cause, I'm trying to understand why the call to ast_read
> ended up in ast_write.  I've not had to delve into channel.c gory details
> before, but ast_read is to return a frame - not sure why the moh_generator
> doesn't just return a frame for ast_read to return, and why instead ast_read
> calls moh_generator which then calls ast_write!?
>
>  Thanks for your pointers!
>
>
> Steve
>
>
>
>
> _______________________________________________
> --Bandwidth and Colocation Provided by http://www.api-digital.com--
>
> asterisk-dev mailing list
> To UNSUBSCRIBE or update options visit:
>    http://lists.digium.com/mailman/listinfo/asterisk-dev
>



-- 
"Within C++, there is a much smaller and cleaner language struggling
to get out."