[asterisk-dev] Asterisk core dumps when using blind transfers and channel OOH323 from asterisk-addons

Dinesh Nair dinesh at alphaque.com
Thu Jul 27 07:54:33 MST 2006


devs,

first up, all this on asterisk 1.2.10 on FreeBSD 6.1.

i've trying to debug a problem when a SIP device attempts to blind transfer 
a OOH323 device to another SIP device. the debug/verbose logs are in 
sip_ooh323_debug1.txt as attached.

however when a SIP device attempts to transfer a OOH323 device to a simple 
dialplan (see below), it works as per debug log sip_ooh323_debug2.txt.

exten => 6000,1,Directory(default,local,f)
exten => 6000,2,Hangup()

also, when the OOH323 device attempts to blind transfer the SIP device, 
everything works just dandy.

it's failing in set_format() in channel.c because of the seemingly odd 
value of fmt passed to it, i think. any clues as to what may be going on ?

note, i think the bug is somewhere in the ooh323c channel and not in 
asterisk per se, but for the life of me, i can't seem to see where they 
weirdly large fmt numbers are being passed in.

any clues as to where to poke around would be much appreciated. also, if 
someone could explain the mechanics of a blind transfer and what the 
channel drivers need to provide asterisk core, i could go look into ooh323c 
and see what's missing.

-- 
Regards,                           /\_/\   "All dogs go to heaven."
dinesh at alphaque.com                (0 0)   http://www.openmalaysiablog.com/
+==========================----oOO--(_)--OOo----==========================+
| for a in past present future; do                                        |
|   for b in clients employers associates relatives neighbours pets; do   |
|   echo "The opinions here in no way reflect the opinions of my $a $b."  |
| done; done                                                              |
+=========================================================================+
-------------- next part --------------
Jul 27 21:16:31 VERBOSE[9523] logger.c:     -- Transferring OOH323/alphaque-5398 to '6952' (context phones) priority 1
Jul 27 21:16:31 DEBUG[9523] channel.c: Planning to masquerade channel OOH323/alphaque-5398 into the structure of AsyncGoto/OOH323/alphaque-5398
Jul 27 21:16:31 DEBUG[9523] channel.c: Done planning to masquerade channel OOH323/alphaque-5398 into the structure of AsyncGoto/OOH323/alphaque-5398
Jul 27 21:16:31 DEBUG[9523] channel.c: Actually Masquerading OOH323/alphaque-5398(6) into the structure of AsyncGoto/OOH323/alphaque-5398(6)
Jul 27 21:16:31 DEBUG[9523] channel.c: Got clone lock for masquerade on 'OOH323/alphaque-5398' at 0x813bccc
Jul 27 21:16:31 DEBUG[9523] channel.c: OOH323/alphaque-5398 Before ast_translator_best_choice fmt=8 native=8
Jul 27 21:16:31 DEBUG[9523] channel.c: OOH323/alphaque-5398 After ast_translator_free_path
Jul 27 21:16:31 DEBUG[9523] channel.c: OOH323/alphaque-5398 After ast_translator_build_path
Jul 27 21:16:31 DEBUG[9523] channel.c: Set channel OOH323/alphaque-5398 to write format alaw
Jul 27 21:16:31 DEBUG[9523] channel.c: OOH323/alphaque-5398 Before ast_translator_best_choice fmt=8 native=8
Jul 27 21:16:31 DEBUG[9523] channel.c: OOH323/alphaque-5398 After ast_translator_free_path
Jul 27 21:16:31 DEBUG[9523] channel.c: OOH323/alphaque-5398 After ast_translator_build_path
Jul 27 21:16:31 DEBUG[9523] channel.c: Set channel OOH323/alphaque-5398 to read format alaw
Jul 27 21:16:31 DEBUG[9523] channel.c: Putting channel OOH323/alphaque-5398 in 8/8 formats
Jul 27 21:16:31 DEBUG[9523] channel.c: Released clone lock on 'AsyncGoto/OOH323/alphaque-5398<ZOMBIE>'
Jul 27 21:16:31 DEBUG[9523] channel.c: Done Masquerading OOH323/alphaque-5398 (6)
Jul 27 21:16:31 DEBUG[9523] channel.c: Hanging up zombie 'AsyncGoto/OOH323/alphaque-5398<ZOMBIE>'
Jul 27 21:16:31 DEBUG[9523] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Jul 27 21:16:31 DEBUG[9523] pbx.c: Spawn extension (phones,86940,2) exited non-zero on 'SIP/6951-3838'
Jul 27 21:16:31 DEBUG[9523] channel.c: Hanging up channel 'SIP/6951-3838'
Jul 27 21:16:31 DEBUG[9523] chan_sip.c: Hangup call SIP/6951-3838, SIP callid J3Xr6mLV75AaZNNk at 192.168.1.198)
Jul 27 21:16:31 DEBUG[9523] chan_sip.c: update_call_counter(6951) - decrement call limit counter
Jul 27 21:16:31 DEBUG[9523] chan_sip.c: Updating call counter for incoming call
Jul 27 21:16:31 DEBUG[9523] devicestate.c: Changing state for AsyncGoto/OOH323/alphaque - state 4 (Invalid)
Jul 27 21:16:31 DEBUG[9523] devicestate.c: Changing state for AsyncGoto/OOH323/alphaque - state 4 (Invalid)
Jul 27 21:16:31 DEBUG[9523] chan_sip.c: Checking device state for peer 6951
Jul 27 21:16:31 DEBUG[9523] devicestate.c: Changing state for SIP/6951 - state 1 (Not in use)
Jul 27 21:16:31 DEBUG[9523] pbx.c: Launching 'Macro'
Jul 27 21:16:31 VERBOSE[9523] logger.c:     -- Executing Macro("OOH323/alphaque-5398", "stdexten|6952|SIP/6952") in new stack
Jul 27 21:16:31 DEBUG[9523] pbx.c: Launching 'DBget'
Jul 27 21:16:31 VERBOSE[9523] logger.c:     -- Executing DBget("OOH323/alphaque-5398", "fwdno=DND/6952") in new stack
Jul 27 21:16:31 WARNING[9523] app_db.c: This application has been deprecated, please use the ${DB(family/key)} function instead.
Jul 27 21:16:31 VERBOSE[9523] logger.c:     -- DBget: varname=fwdno, family=DND, key=6952
Jul 27 21:16:31 DEBUG[9523] db.c: Unable to find key '6952' in family 'DND'
Jul 27 21:16:31 VERBOSE[9523] logger.c:     -- DBget: Value not found in database.
Jul 27 21:16:31 DEBUG[9523] pbx.c: Expression result is '0'
Jul 27 21:16:31 DEBUG[9523] pbx.c: Launching 'GotoIf'
Jul 27 21:16:31 VERBOSE[9523] logger.c:     -- Executing GotoIf("OOH323/alphaque-5398", "0?s-NOANSWER|1:s-CFU|1") in new stack
Jul 27 21:16:31 VERBOSE[9523] logger.c:     -- Goto (macro-stdexten,s-CFU,1)
Jul 27 21:16:31 DEBUG[9523] pbx.c: Launching 'DBget'
Jul 27 21:16:31 VERBOSE[9523] logger.c:     -- Executing DBget("OOH323/alphaque-5398", "fwdno=CFU/6952") in new stack
Jul 27 21:16:31 VERBOSE[9523] logger.c:     -- DBget: varname=fwdno, family=CFU, key=6952
Jul 27 21:16:31 DEBUG[9523] db.c: Unable to find key '6952' in family 'CFU'
Jul 27 21:16:31 VERBOSE[9523] logger.c:     -- DBget: Value not found in database.
Jul 27 21:16:31 DEBUG[9523] pbx.c: Expression result is '0'
Jul 27 21:16:31 DEBUG[9523] pbx.c: Launching 'GotoIf'
Jul 27 21:16:31 VERBOSE[9523] logger.c:     -- Executing GotoIf("OOH323/alphaque-5398", "0?3:s-DIAL|1") in new stack
Jul 27 21:16:31 VERBOSE[9523] logger.c:     -- Goto (macro-stdexten,s-DIAL,1)
Jul 27 21:16:31 DEBUG[9523] pbx.c: Launching 'Dial'
Jul 27 21:16:31 VERBOSE[9523] logger.c:     -- Executing Dial("OOH323/alphaque-5398", "SIP/6952|40|owWtT") in new stack
Jul 27 21:16:31 DEBUG[9523] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP)
Jul 27 21:16:31 DEBUG[9523] chan_sip.c: Setting NAT on RTP to 0
Jul 27 21:16:31 DEBUG[9523] chan_sip.c: Setting NAT on VRTP to 0
Jul 27 21:16:31 DEBUG[9523] channel.c: Not copying variable STACK-macro-stdexten-s-DIAL-1.
Jul 27 21:16:31 DEBUG[9523] channel.c: Not copying variable MACRO_DEPTH.
Jul 27 21:16:31 DEBUG[9523] channel.c: Not copying variable STACK-macro-stdexten-s-CFU-2.
Jul 27 21:16:31 DEBUG[9523] channel.c: Not copying variable DBGETSTATUS.
Jul 27 21:16:31 DEBUG[9523] channel.c: Not copying variable STACK-macro-stdexten-s-CFU-1.
Jul 27 21:16:31 DEBUG[9523] channel.c: Not copying variable STACK-macro-stdexten-s-2.
Jul 27 21:16:31 DEBUG[9523] channel.c: Not copying variable STACK-macro-stdexten-s-1.
Jul 27 21:16:31 DEBUG[9523] channel.c: Not copying variable ARG2.
Jul 27 21:16:31 DEBUG[9523] channel.c: Not copying variable ARG1.
Jul 27 21:16:31 DEBUG[9523] channel.c: Not copying variable MACRO_PRIORITY.
Jul 27 21:16:31 DEBUG[9523] channel.c: Not copying variable MACRO_CONTEXT.
Jul 27 21:16:31 DEBUG[9523] channel.c: Not copying variable MACRO_EXTEN.
Jul 27 21:16:31 DEBUG[9523] channel.c: Not copying variable STACK-phones-6952-1.
Jul 27 21:16:31 DEBUG[9523] channel.c: Not copying variable BLINDTRANSFER.
Jul 27 21:16:31 DEBUG[9523] channel.c: Not copying variable BRIDGEPEER.
Jul 27 21:16:31 DEBUG[9523] channel.c: Not copying variable DIALEDPEERNUMBER.
Jul 27 21:16:31 DEBUG[9523] chan_sip.c: Outgoing Call for 6952
Jul 27 21:16:31 DEBUG[9523] chan_sip.c: Updating call counter for outgoing call
Jul 27 21:16:31 VERBOSE[9523] logger.c:     -- Called 6952
Jul 27 21:16:31 DEBUG[9523] channel.c: SIP/6952-c438 Before ast_translator_best_choice fmt=8 native=8
Jul 27 21:16:31 DEBUG[9523] channel.c: SIP/6952-c438 After ast_translator_free_path
Jul 27 21:16:31 DEBUG[9523] channel.c: SIP/6952-c438 After ast_translator_build_path
Jul 27 21:16:31 DEBUG[9523] channel.c: Set channel SIP/6952-c438 to read format alaw
Jul 27 21:16:31 DEBUG[9523] channel.c: OOH323/alphaque-5398 Before ast_translator_best_choice fmt=8 native=8
Jul 27 21:16:31 DEBUG[9523] channel.c: OOH323/alphaque-5398 After ast_translator_free_path
Jul 27 21:16:31 DEBUG[9523] channel.c: OOH323/alphaque-5398 After ast_translator_build_path
Jul 27 21:16:31 DEBUG[9523] channel.c: Set channel OOH323/alphaque-5398 to write format alaw
Jul 27 21:16:31 DEBUG[9523] channel.c: OOH323/alphaque-5398 Before ast_translator_best_choice fmt=8 native=8
Jul 27 21:16:31 DEBUG[9523] channel.c: OOH323/alphaque-5398 After ast_translator_free_path
Jul 27 21:16:31 DEBUG[9523] channel.c: OOH323/alphaque-5398 After ast_translator_build_path
Jul 27 21:16:31 DEBUG[9523] channel.c: Set channel OOH323/alphaque-5398 to read format alaw
Jul 27 21:16:31 DEBUG[9523] channel.c: SIP/6952-c438 Before ast_translator_best_choice fmt=8 native=8
Jul 27 21:16:31 DEBUG[9523] channel.c: SIP/6952-c438 After ast_translator_free_path
Jul 27 21:16:31 DEBUG[9523] channel.c: SIP/6952-c438 After ast_translator_build_path
Jul 27 21:16:31 DEBUG[9523] channel.c: Set channel SIP/6952-c438 to write format alaw
Jul 27 21:16:31 DEBUG[9523] app_queue.c: Device 'AsyncGoto/OOH323/alphaque' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
Jul 27 21:16:31 DEBUG[9523] app_queue.c: Device 'AsyncGoto/OOH323/alphaque' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
Jul 27 21:16:31 DEBUG[9523] app_queue.c: Device 'SIP/6951' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
Jul 27 21:16:31 DEBUG[9523] src/chan_h323.c: Oooh, format changed to 8
Jul 27 21:16:31 DEBUG[9523] src/chan_h323.c: This is a test message
Jul 27 21:16:31 DEBUG[9523] src/chan_h323.c: read format 222181426
Jul 27 21:16:31 DEBUG[9523] src/chan_h323.c: write format 1818313482
Jul 27 21:16:31 DEBUG[9523] channel.c:  Before ast_translator_best_choice fmt=222181426 native=8
-------------- next part --------------
Jul 27 22:43:18 VERBOSE[8581] logger.c:     -- Transferring OOH323/alphaque-5e9d to '6000' (context phones) priority 1
Jul 27 22:43:18 DEBUG[8581] channel.c: Planning to masquerade channel OOH323/alphaque-5e9d into the structure of AsyncGoto/OOH323/alphaque-5e9d
Jul 27 22:43:18 DEBUG[8581] channel.c: Done planning to masquerade channel OOH323/alphaque-5e9d into the structure of AsyncGoto/OOH323/alphaque-5e9d
Jul 27 22:43:18 DEBUG[8581] channel.c: Actually Masquerading OOH323/alphaque-5e9d(6) into the structure of AsyncGoto/OOH323/alphaque-5e9d(6)
Jul 27 22:43:18 DEBUG[8581] channel.c: Got clone lock for masquerade on 'OOH323/alphaque-5e9d' at 0x813bccc
Jul 27 22:43:18 DEBUG[8581] channel.c: OOH323/alphaque-5e9d Before ast_translator_best_choice fmt=8 native=8
Jul 27 22:43:18 DEBUG[8581] channel.c: OOH323/alphaque-5e9d After ast_translator_free_path
Jul 27 22:43:18 DEBUG[8581] channel.c: OOH323/alphaque-5e9d After ast_translator_build_path
Jul 27 22:43:18 DEBUG[8581] channel.c: Set channel OOH323/alphaque-5e9d to write format alaw
Jul 27 22:43:18 DEBUG[8581] channel.c: OOH323/alphaque-5e9d Before ast_translator_best_choice fmt=8 native=8
Jul 27 22:43:18 DEBUG[8581] channel.c: OOH323/alphaque-5e9d After ast_translator_free_path
Jul 27 22:43:18 DEBUG[8581] channel.c: OOH323/alphaque-5e9d After ast_translator_build_path
Jul 27 22:43:18 DEBUG[8581] channel.c: Set channel OOH323/alphaque-5e9d to read format alaw
Jul 27 22:43:18 DEBUG[8581] channel.c: Putting channel OOH323/alphaque-5e9d in 8/8 formats
Jul 27 22:43:18 DEBUG[8581] channel.c: Released clone lock on 'AsyncGoto/OOH323/alphaque-5e9d<ZOMBIE>'
Jul 27 22:43:18 DEBUG[8581] channel.c: Done Masquerading OOH323/alphaque-5e9d (6)
Jul 27 22:43:18 DEBUG[8581] channel.c: Hanging up zombie 'AsyncGoto/OOH323/alphaque-5e9d<ZOMBIE>'
Jul 27 22:43:18 DEBUG[8581] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Jul 27 22:43:18 DEBUG[8581] pbx.c: Spawn extension (phones,86940,2) exited non-zero on 'SIP/6951-086e0000'
Jul 27 22:43:18 DEBUG[8581] channel.c: Hanging up channel 'SIP/6951-086e0000'
Jul 27 22:43:18 DEBUG[8581] chan_sip.c: Hangup call SIP/6951-086e0000, SIP callid z4KOrEZLPjZXzYp1 at 192.168.1.198)
Jul 27 22:43:18 DEBUG[8581] chan_sip.c: update_call_counter(6951) - decrement call limit counter
Jul 27 22:43:18 DEBUG[8581] chan_sip.c: Updating call counter for incoming call
Jul 27 22:43:18 DEBUG[8581] devicestate.c: Changing state for AsyncGoto/OOH323/alphaque - state 4 (Invalid)
Jul 27 22:43:18 DEBUG[8581] devicestate.c: Changing state for AsyncGoto/OOH323/alphaque - state 4 (Invalid)
Jul 27 22:43:18 DEBUG[8581] chan_sip.c: Checking device state for peer 6951
Jul 27 22:43:18 DEBUG[8581] devicestate.c: Changing state for SIP/6951 - state 1 (Not in use)
Jul 27 22:43:18 DEBUG[8581] pbx.c: Launching 'Directory'
Jul 27 22:43:18 VERBOSE[8581] logger.c:     -- Executing Directory("OOH323/alphaque-5e9d", "default|local|f") in new stack
Jul 27 22:43:18 DEBUG[8581] config.c: Parsing /usr/local/etc/asterisk/voicemail.conf
Jul 27 22:43:18 DEBUG[8581] channel.c: OOH323/alphaque-5e9d Before ast_translator_best_choice fmt=2 native=8
Jul 27 22:43:18 DEBUG[8581] channel.c: OOH323/alphaque-5e9d After ast_translator_free_path
Jul 27 22:43:18 DEBUG[8581] channel.c: OOH323/alphaque-5e9d After ast_translator_build_path
Jul 27 22:43:18 DEBUG[8581] channel.c: Set channel OOH323/alphaque-5e9d to write format gsm
Jul 27 22:43:18 DEBUG[8581] channel.c: Scheduling timer at 160 sample intervals
Jul 27 22:43:18 VERBOSE[8581] logger.c:     -- Playing 'dir-intro-fn' (language 'en')
Jul 27 22:43:18 DEBUG[8581] app_queue.c: Device 'AsyncGoto/OOH323/alphaque' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
Jul 27 22:43:18 DEBUG[8581] app_queue.c: Device 'AsyncGoto/OOH323/alphaque' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
Jul 27 22:43:18 DEBUG[8581] app_queue.c: Device 'SIP/6951' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
Jul 27 22:43:18 DEBUG[8581] chan_sip.c: = Found Their Call ID: z4KOrEZLPjZXzYp1 at 192.168.1.198 Their Tag EHqdqEcTs4Q4CPxA Our tag: as4ea68174
Jul 27 22:43:18 DEBUG[8581] chan_sip.c: Stopping retransmission on 'z4KOrEZLPjZXzYp1 at 192.168.1.198' of Request 102: Match Found


More information about the asterisk-dev mailing list