vapp01*CLI> iax2 set debug on IAX2 Debugging Enabled [Sep 24 12:47:35] Rx-Frame Retry[ No] -- OSeqno: 000 ISeqno: 000 Type: IAX Subclass: NEW [Sep 24 12:47:35] Timestamp: 00014ms SCall: 06625 DCall: 00000 [192.168.255.37:4569] [Sep 24 12:47:35] VERSION : 2 [Sep 24 12:47:35] CALLED NUMBER : 1000 [Sep 24 12:47:35] CODEC_PREFS : () [Sep 24 12:47:35] CALLING NUMBER : 2008 [Sep 24 12:47:35] CALLING PRESNTN : 0 [Sep 24 12:47:35] CALLING TYPEOFN : 0 [Sep 24 12:47:35] CALLING TRANSIT : 0 [Sep 24 12:47:35] CALLING NAME : Paolo Audiberti [Sep 24 12:47:35] LANGUAGE : en [Sep 24 12:47:35] USERNAME : specialai [Sep 24 12:47:35] FORMAT : 1 [Sep 24 12:47:35] CAPABILITY : 1795 [Sep 24 12:47:35] ADSICPE : 2 [Sep 24 12:47:35] DATE TIME : 2009-09-24 15:47:34 [Sep 24 12:47:35] [Sep 24 12:47:35] DEBUG[24191]: chan_iax2.c:1853 calltoken_required: Determining if address 192.168.255.37 with username specialai requires calltoken validation. Optional = 0 calltoken_required = 3 [Sep 24 12:47:35] DEBUG[24191]: chan_iax2.c:1985 peercnt_add: ip callno count incremented to 2 for 192.168.255.37 [Sep 24 12:47:35] DEBUG[24191]: chan_iax2.c:1668 update_max_nontrunk: New max nontrunk callno is 1905 [Sep 24 12:47:35] DEBUG[24191]: chan_iax2.c:2489 __find_callno: Creating new call structure 1904 [Sep 24 12:47:35] DEBUG[24191]: chan_iax2.c:9377 socket_process: Received packet 0, (6, 1) [Sep 24 12:47:35] DEBUG[24191]: chan_iax2.c:9638 socket_process: IAX subclass 1 received [Sep 24 12:47:35] DEBUG[24191]: chan_iax2.c:9647 socket_process: For call=1904, set last=14 [Sep 24 12:47:35] DEBUG[24191]: frame.c:1222 ast_codec_choose: Could not find preferred codec - Returning zero codec [Sep 24 12:47:35] -- Accepting UNAUTHENTICATED call from 192.168.255.37: > requested format = g723, > requested prefs = (), > actual format = gsm, > host prefs = (), > priority = mine [Sep 24 12:47:35] DEBUG[24195]: chan_iax2.c:2956 send_packet: Sending 3 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:35] Tx-Frame Retry[000] -- OSeqno: 000 ISeqno: 001 Type: IAX Subclass: ACCEPT [Sep 24 12:47:35] Timestamp: 00003ms SCall: 01904 DCall: 06625 [192.168.255.37:4569] [Sep 24 12:47:35] FORMAT : 2 [Sep 24 12:47:35] [Sep 24 12:47:36] Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 001 Type: IAX Subclass: ACK [Sep 24 12:47:36] Timestamp: 00003ms SCall: 06625 DCall: 01904 [192.168.255.37:4569] [Sep 24 12:47:36] DEBUG[24192]: chan_iax2.c:9377 socket_process: Received packet 1, (6, 4) [Sep 24 12:47:36] DEBUG[24192]: chan_iax2.c:9474 socket_process: Cancelling transmission of packet 0 [Sep 24 12:47:36] DEBUG[24192]: chan_iax2.c:9638 socket_process: IAX subclass 4 received [Sep 24 12:47:36] DEBUG[24258]: pbx.c:3101 pbx_extension_helper: Launching 'Goto' [Sep 24 12:47:36] -- Executing [1000@inbound-calls:1] Goto("IAX2/specialai-1904", "s,1") in new stack [Sep 24 12:47:36] -- Goto (inbound-calls,s,1) [Sep 24 12:47:36] DEBUG[24258]: pbx.c:2935 pbx_substitute_variables_helper_full: Function result is '2008' [Sep 24 12:47:36] DEBUG[24258]: pbx.c:3101 pbx_extension_helper: Launching 'NoOp' [Sep 24 12:47:36] -- Executing [s@inbound-calls:1] NoOp("IAX2/specialai-1904", "Answered inbound-call from 2008") in new stack [Sep 24 12:47:36] DEBUG[24258]: pbx.c:3101 pbx_extension_helper: Launching 'Goto' [Sep 24 12:47:36] -- Executing [s@inbound-calls:2] Goto("IAX2/specialai-1904", "od-welcome,s,1") in new stack [Sep 24 12:47:36] -- Goto (od-welcome,s,1) [Sep 24 12:47:36] DEBUG[24258]: pbx.c:3101 pbx_extension_helper: Launching 'NoOp' [Sep 24 12:47:36] -- Executing [s@od-welcome:1] NoOp("IAX2/specialai-1904", "WELCOME") in new stack [Sep 24 12:47:36] DEBUG[24258]: pbx.c:3101 pbx_extension_helper: Launching 'Set' [Sep 24 12:47:36] -- Executing [s@od-welcome:2] Set("IAX2/specialai-1904", "CHANNEL(language)=en") in new stack [Sep 24 12:47:36] DEBUG[24258]: pbx.c:3101 pbx_extension_helper: Launching 'Playback' [Sep 24 12:47:36] -- Executing [s@od-welcome:3] Playback("IAX2/specialai-1904", "specialai/welcome-cricket-debt") in new stack [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:5059 iax2_answer: Answering IAX2 call [Sep 24 12:47:36] DEBUG[24258]: devicestate.c:452 ast_devstate_changed_literal: Notification of state change to be queued on device/channel IAX2/specialai [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:5074 iax2_indicate: Indicating condition -1 [Sep 24 12:47:36] DEBUG[24173]: devicestate.c:325 _ast_device_state: No provider found, checking channel drivers for IAX2 - specialai [Sep 24 12:47:36] DEBUG[24173]: chan_iax2.c:13119 iax2_devicestate: Checking device state for device specialai [Sep 24 12:47:36] DEBUG[24173]: chan_iax2.c:13127 iax2_devicestate: iax2_devicestate: Found peer. What's device state of specialai? addr=637511872, defaddr=0 maxms=2000, lastms=15 [Sep 24 12:47:36] DEBUG[24173]: devicestate.c:443 do_state_change: Changing state for IAX2/specialai - state 2 (In use) [Sep 24 12:47:36] DEBUG[24197]: app_queue.c:766 handle_statechange: Device 'IAX2/specialai' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Sep 24 12:47:36] DEBUG[24195]: chan_iax2.c:2956 send_packet: Sending 6 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] Tx-Frame Retry[000] -- OSeqno: 001 ISeqno: 001 Type: CONTROL Subclass: ANSWER [Sep 24 12:47:36] Timestamp: 00006ms SCall: 01904 DCall: 06625 [192.168.255.37:4569] [Sep 24 12:47:36] DEBUG[24195]: chan_iax2.c:2956 send_packet: Sending 9 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] Tx-Frame Retry[000] -- OSeqno: 002 ISeqno: 001 Type: CONTROL Subclass: (255?) [Sep 24 12:47:36] Timestamp: 00009ms SCall: 01904 DCall: 06625 [192.168.255.37:4569] [Sep 24 12:47:36] Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 002 Type: IAX Subclass: ACK [Sep 24 12:47:36] Timestamp: 00006ms SCall: 06625 DCall: 01904 [192.168.255.37:4569] [Sep 24 12:47:36] DEBUG[24193]: chan_iax2.c:9377 socket_process: Received packet 1, (6, 4) [Sep 24 12:47:36] DEBUG[24193]: chan_iax2.c:9474 socket_process: Cancelling transmission of packet 1 [Sep 24 12:47:36] DEBUG[24193]: chan_iax2.c:9638 socket_process: IAX subclass 4 received [Sep 24 12:47:36] Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 003 Type: IAX Subclass: ACK [Sep 24 12:47:36] Timestamp: 00009ms SCall: 06625 DCall: 01904 [192.168.255.37:4569] [Sep 24 12:47:36] DEBUG[24193]: chan_iax2.c:9377 socket_process: Received packet 1, (6, 4) [Sep 24 12:47:36] DEBUG[24193]: chan_iax2.c:9474 socket_process: Cancelling transmission of packet 2 [Sep 24 12:47:36] DEBUG[24193]: chan_iax2.c:9638 socket_process: IAX subclass 4 received [Sep 24 12:47:36] Rx-Frame Retry[ No] -- OSeqno: 001 ISeqno: 003 Type: CONTROL Subclass: (20?) [Sep 24 12:47:36] Timestamp: 00017ms SCall: 06625 DCall: 01904 [192.168.255.37:4569] [Sep 24 12:47:36] DEBUG[24185]: chan_iax2.c:9377 socket_process: Received packet 1, (4, 20) [Sep 24 12:47:36] DEBUG[24185]: chan_iax2.c:2956 send_packet: Sending 17 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] Tx-Frame Retry[-01] -- OSeqno: 003 ISeqno: 002 Type: IAX Subclass: ACK [Sep 24 12:47:36] Timestamp: 00017ms SCall: 01904 DCall: 06625 [192.168.255.37:4569] [Sep 24 12:47:36] DEBUG[24185]: chan_iax2.c:10778 socket_process: For call=1904, set last=17 [Sep 24 12:47:36] Rx-Frame Retry[ No] -- OSeqno: 002 ISeqno: 003 Type: CONTROL Subclass: (20?) [Sep 24 12:47:36] Timestamp: 00020ms SCall: 06625 DCall: 01904 [192.168.255.37:4569] [Sep 24 12:47:36] DEBUG[24186]: chan_iax2.c:9377 socket_process: Received packet 2, (4, 20) [Sep 24 12:47:36] DEBUG[24186]: chan_iax2.c:2956 send_packet: Sending 20 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] Tx-Frame Retry[-01] -- OSeqno: 003 ISeqno: 003 Type: IAX Subclass: ACK [Sep 24 12:47:36] Timestamp: 00020ms SCall: 01904 DCall: 06625 [192.168.255.37:4569] [Sep 24 12:47:36] DEBUG[24186]: chan_iax2.c:10778 socket_process: For call=1904, set last=20 [Sep 24 12:47:36] Rx-Frame Retry[ No] -- OSeqno: 003 ISeqno: 003 Type: CONTROL Subclass: (20?) [Sep 24 12:47:36] Timestamp: 00023ms SCall: 06625 DCall: 01904 [192.168.255.37:4569] [Sep 24 12:47:36] DEBUG[24186]: chan_iax2.c:9377 socket_process: Received packet 3, (4, 20) [Sep 24 12:47:36] DEBUG[24186]: chan_iax2.c:2956 send_packet: Sending 23 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] Tx-Frame Retry[-01] -- OSeqno: 003 ISeqno: 004 Type: IAX Subclass: ACK [Sep 24 12:47:36] Timestamp: 00023ms SCall: 01904 DCall: 06625 [192.168.255.37:4569] [Sep 24 12:47:36] DEBUG[24186]: chan_iax2.c:10778 socket_process: For call=1904, set last=23 [Sep 24 12:47:36] Rx-Frame Retry[ No] -- OSeqno: 004 ISeqno: 003 Type: VOICE Subclass: 2 [Sep 24 12:47:36] Timestamp: 00454ms SCall: 06625 DCall: 01904 [192.168.255.37:4569] [Sep 24 12:47:36] DEBUG[24188]: chan_iax2.c:9377 socket_process: Received packet 4, (2, 2) [Sep 24 12:47:36] DEBUG[24188]: chan_iax2.c:9590 socket_process: Ooh, voice format changed to 2 [Sep 24 12:47:36] DEBUG[24188]: chan_iax2.c:2956 send_packet: Sending 454 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] Tx-Frame Retry[-01] -- OSeqno: 003 ISeqno: 005 Type: IAX Subclass: ACK [Sep 24 12:47:36] Timestamp: 00454ms SCall: 01904 DCall: 06625 [192.168.255.37:4569] [Sep 24 12:47:36] DEBUG[24188]: chan_iax2.c:10778 socket_process: For call=1904, set last=454 [Sep 24 12:47:36] DEBUG[24258]: channel.c:3616 set_format: Set channel IAX2/specialai-1904 to write format slin [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:5395 calc_timestamp: predicted timestamp skew (442) > max (160), using real ts instead. [Sep 24 12:47:36] DEBUG[24258]: channel.c:2362 ast_settimeout: Scheduling timer at 160 sample intervals [Sep 24 12:47:36] -- Playing 'specialai/welcome-cricket-debt.slin' (language 'en') [Sep 24 12:47:36] DEBUG[24195]: chan_iax2.c:2956 send_packet: Sending 460 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] Tx-Frame Retry[000] -- OSeqno: 003 ISeqno: 005 Type: VOICE Subclass: 2 [Sep 24 12:47:36] Timestamp: 00460ms SCall: 01904 DCall: 06625 [192.168.255.37:4569] [Sep 24 12:47:36] Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 004 Type: IAX Subclass: ACK [Sep 24 12:47:36] Timestamp: 00460ms SCall: 06625 DCall: 01904 [192.168.255.37:4569] [Sep 24 12:47:36] DEBUG[24189]: chan_iax2.c:9377 socket_process: Received packet 5, (6, 4) [Sep 24 12:47:36] DEBUG[24189]: chan_iax2.c:9474 socket_process: Cancelling transmission of packet 3 [Sep 24 12:47:36] DEBUG[24189]: chan_iax2.c:9638 socket_process: IAX subclass 4 received [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 480 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24190]: chan_iax2.c:10778 socket_process: For call=1904, set last=474 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 500 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24191]: chan_iax2.c:10778 socket_process: For call=1904, set last=494 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 520 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24192]: chan_iax2.c:10778 socket_process: For call=1904, set last=514 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 540 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24184]: chan_iax2.c:10778 socket_process: For call=1904, set last=534 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 560 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24193]: chan_iax2.c:10778 socket_process: For call=1904, set last=554 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 580 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24185]: chan_iax2.c:10778 socket_process: For call=1904, set last=574 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 600 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24187]: chan_iax2.c:10778 socket_process: For call=1904, set last=594 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 620 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24186]: chan_iax2.c:10778 socket_process: For call=1904, set last=614 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 640 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24188]: chan_iax2.c:10778 socket_process: For call=1904, set last=634 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 660 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24189]: chan_iax2.c:10778 socket_process: For call=1904, set last=654 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 680 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24190]: chan_iax2.c:10778 socket_process: For call=1904, set last=674 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 700 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24191]: chan_iax2.c:10778 socket_process: For call=1904, set last=694 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 720 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24192]: chan_iax2.c:10778 socket_process: For call=1904, set last=714 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 740 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24184]: chan_iax2.c:10778 socket_process: For call=1904, set last=734 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 760 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24193]: chan_iax2.c:10778 socket_process: For call=1904, set last=754 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 780 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24185]: chan_iax2.c:10778 socket_process: For call=1904, set last=774 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 800 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24187]: chan_iax2.c:10778 socket_process: For call=1904, set last=794 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 820 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24186]: chan_iax2.c:10778 socket_process: For call=1904, set last=814 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 840 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24188]: chan_iax2.c:10778 socket_process: For call=1904, set last=834 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 860 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24189]: chan_iax2.c:10778 socket_process: For call=1904, set last=854 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 880 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24190]: chan_iax2.c:10778 socket_process: For call=1904, set last=874 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 900 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24191]: chan_iax2.c:10778 socket_process: For call=1904, set last=894 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 920 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24192]: chan_iax2.c:10778 socket_process: For call=1904, set last=914 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 940 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24184]: chan_iax2.c:10778 socket_process: For call=1904, set last=934 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 960 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24193]: chan_iax2.c:10778 socket_process: For call=1904, set last=954 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 980 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24185]: chan_iax2.c:10778 socket_process: For call=1904, set last=974 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1000 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24187]: chan_iax2.c:10778 socket_process: For call=1904, set last=994 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1020 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:36] DEBUG[24186]: chan_iax2.c:10778 socket_process: For call=1904, set last=1014 [Sep 24 12:47:36] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1040 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24188]: chan_iax2.c:10778 socket_process: For call=1904, set last=1034 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1060 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24189]: chan_iax2.c:10778 socket_process: For call=1904, set last=1054 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1080 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24190]: chan_iax2.c:10778 socket_process: For call=1904, set last=1074 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1100 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24191]: chan_iax2.c:10778 socket_process: For call=1904, set last=1094 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1120 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24192]: chan_iax2.c:10778 socket_process: For call=1904, set last=1114 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1140 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24184]: chan_iax2.c:10778 socket_process: For call=1904, set last=1134 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1160 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24193]: chan_iax2.c:10778 socket_process: For call=1904, set last=1154 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1180 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24185]: chan_iax2.c:10778 socket_process: For call=1904, set last=1174 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1200 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24187]: chan_iax2.c:10778 socket_process: For call=1904, set last=1194 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1220 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24186]: chan_iax2.c:10778 socket_process: For call=1904, set last=1214 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1240 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24188]: chan_iax2.c:10778 socket_process: For call=1904, set last=1234 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1260 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24189]: chan_iax2.c:10778 socket_process: For call=1904, set last=1254 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1280 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24190]: chan_iax2.c:10778 socket_process: For call=1904, set last=1274 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1300 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24191]: chan_iax2.c:10778 socket_process: For call=1904, set last=1294 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1320 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24192]: chan_iax2.c:10778 socket_process: For call=1904, set last=1314 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1340 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24184]: chan_iax2.c:10778 socket_process: For call=1904, set last=1334 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1360 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24193]: chan_iax2.c:10778 socket_process: For call=1904, set last=1354 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1380 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24185]: chan_iax2.c:10778 socket_process: For call=1904, set last=1374 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1400 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24187]: chan_iax2.c:10778 socket_process: For call=1904, set last=1394 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1420 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24186]: chan_iax2.c:10778 socket_process: For call=1904, set last=1414 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1440 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24188]: chan_iax2.c:10778 socket_process: For call=1904, set last=1434 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1460 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24189]: chan_iax2.c:10778 socket_process: For call=1904, set last=1454 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1480 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24190]: chan_iax2.c:10778 socket_process: For call=1904, set last=1474 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1500 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24191]: chan_iax2.c:10778 socket_process: For call=1904, set last=1494 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1520 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24192]: chan_iax2.c:10778 socket_process: For call=1904, set last=1514 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1540 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24184]: chan_iax2.c:10778 socket_process: For call=1904, set last=1534 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1560 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24193]: chan_iax2.c:10778 socket_process: For call=1904, set last=1554 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1580 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24185]: chan_iax2.c:10778 socket_process: For call=1904, set last=1574 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1600 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24187]: chan_iax2.c:10778 socket_process: For call=1904, set last=1594 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1620 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24186]: chan_iax2.c:10778 socket_process: For call=1904, set last=1614 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1640 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24188]: chan_iax2.c:10778 socket_process: For call=1904, set last=1634 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1660 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24189]: chan_iax2.c:10778 socket_process: For call=1904, set last=1654 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1680 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24190]: chan_iax2.c:10778 socket_process: For call=1904, set last=1674 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1700 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24191]: chan_iax2.c:10778 socket_process: For call=1904, set last=1694 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1720 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24192]: chan_iax2.c:10778 socket_process: For call=1904, set last=1714 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1740 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24184]: chan_iax2.c:10778 socket_process: For call=1904, set last=1734 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1760 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24193]: chan_iax2.c:10778 socket_process: For call=1904, set last=1754 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1780 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24185]: chan_iax2.c:10778 socket_process: For call=1904, set last=1774 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1800 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24187]: chan_iax2.c:10778 socket_process: For call=1904, set last=1794 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1820 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24186]: chan_iax2.c:10778 socket_process: For call=1904, set last=1814 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1840 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24188]: chan_iax2.c:10778 socket_process: For call=1904, set last=1834 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1860 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24189]: chan_iax2.c:10778 socket_process: For call=1904, set last=1854 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1880 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24190]: chan_iax2.c:10778 socket_process: For call=1904, set last=1874 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1900 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24191]: chan_iax2.c:10778 socket_process: For call=1904, set last=1894 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1920 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24192]: chan_iax2.c:10778 socket_process: For call=1904, set last=1914 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1940 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24184]: chan_iax2.c:10778 socket_process: For call=1904, set last=1934 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1960 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24193]: chan_iax2.c:10778 socket_process: For call=1904, set last=1954 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 1980 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24185]: chan_iax2.c:10778 socket_process: For call=1904, set last=1974 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2000 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24187]: chan_iax2.c:10778 socket_process: For call=1904, set last=1994 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2020 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:37] DEBUG[24186]: chan_iax2.c:10778 socket_process: For call=1904, set last=2014 [Sep 24 12:47:37] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2040 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24189]: chan_iax2.c:10778 socket_process: For call=1904, set last=2034 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2060 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24190]: chan_iax2.c:10778 socket_process: For call=1904, set last=2054 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2080 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24184]: chan_iax2.c:10778 socket_process: For call=1904, set last=2074 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2100 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24193]: chan_iax2.c:10778 socket_process: For call=1904, set last=2094 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2120 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24185]: chan_iax2.c:10778 socket_process: For call=1904, set last=2114 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2140 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24187]: chan_iax2.c:10778 socket_process: For call=1904, set last=2134 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2160 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24186]: chan_iax2.c:10778 socket_process: For call=1904, set last=2154 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2180 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24188]: chan_iax2.c:10778 socket_process: For call=1904, set last=2174 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2200 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24189]: chan_iax2.c:10778 socket_process: For call=1904, set last=2194 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2220 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24190]: chan_iax2.c:10778 socket_process: For call=1904, set last=2214 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2240 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24191]: chan_iax2.c:10778 socket_process: For call=1904, set last=2234 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2260 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24192]: chan_iax2.c:10778 socket_process: For call=1904, set last=2254 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2280 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24184]: chan_iax2.c:10778 socket_process: For call=1904, set last=2274 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2300 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24193]: chan_iax2.c:10778 socket_process: For call=1904, set last=2294 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2320 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24185]: chan_iax2.c:10778 socket_process: For call=1904, set last=2314 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2340 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24187]: chan_iax2.c:10778 socket_process: For call=1904, set last=2334 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2360 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24186]: chan_iax2.c:10778 socket_process: For call=1904, set last=2354 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2380 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24188]: chan_iax2.c:10778 socket_process: For call=1904, set last=2374 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2400 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24189]: chan_iax2.c:10778 socket_process: For call=1904, set last=2394 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2420 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24190]: chan_iax2.c:10778 socket_process: For call=1904, set last=2414 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2440 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24191]: chan_iax2.c:10778 socket_process: For call=1904, set last=2434 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2460 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24192]: chan_iax2.c:10778 socket_process: For call=1904, set last=2454 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2480 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24193]: chan_iax2.c:10778 socket_process: For call=1904, set last=2474 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2500 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24185]: chan_iax2.c:10778 socket_process: For call=1904, set last=2494 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2520 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24187]: chan_iax2.c:10778 socket_process: For call=1904, set last=2514 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2540 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24186]: chan_iax2.c:10778 socket_process: For call=1904, set last=2534 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2560 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2580 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2600 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2620 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] Rx-Frame Retry[ No] -- OSeqno: 005 ISeqno: 004 Type: CONTROL Subclass: (20?) [Sep 24 12:47:38] Timestamp: 02537ms SCall: 06625 DCall: 01904 [192.168.255.37:4569] [Sep 24 12:47:38] DEBUG[24188]: chan_iax2.c:9377 socket_process: Received packet 5, (4, 20) [Sep 24 12:47:38] DEBUG[24188]: chan_iax2.c:2956 send_packet: Sending 2537 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 006 Type: IAX Subclass: ACK [Sep 24 12:47:38] Timestamp: 02537ms SCall: 01904 DCall: 06625 [192.168.255.37:4569] [Sep 24 12:47:38] DEBUG[24188]: chan_iax2.c:10778 socket_process: For call=1904, set last=2537 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2640 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2956 send_packet: Sending 2660 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] Rx-Frame Retry[ No] -- OSeqno: 006 ISeqno: 004 Type: IAX Subclass: HANGUP [Sep 24 12:47:38] Timestamp: 02657ms SCall: 06625 DCall: 01904 [192.168.255.37:4569] [Sep 24 12:47:38] CAUSE CODE : 16 [Sep 24 12:47:38] [Sep 24 12:47:38] DEBUG[24189]: chan_iax2.c:9377 socket_process: Received packet 6, (6, 5) [Sep 24 12:47:38] DEBUG[24189]: chan_iax2.c:9638 socket_process: IAX subclass 5 received [Sep 24 12:47:38] DEBUG[24189]: chan_iax2.c:9647 socket_process: For call=1904, set last=2657 [Sep 24 12:47:38] DEBUG[24189]: chan_iax2.c:9942 socket_process: Immediately destroying 1904, having received hangup [Sep 24 12:47:38] DEBUG[24189]: chan_iax2.c:2956 send_packet: Sending 2657 on 1904/6625 to 192.168.255.37:4569 [Sep 24 12:47:38] Tx-Frame Retry[-01] -- OSeqno: 004 ISeqno: 007 Type: IAX Subclass: ACK [Sep 24 12:47:38] Timestamp: 02657ms SCall: 01904 DCall: 06625 [192.168.255.37:4569] [Sep 24 12:47:38] DEBUG[24258]: channel.c:2362 ast_settimeout: Scheduling timer at 0 sample intervals [Sep 24 12:47:38] DEBUG[24258]: channel.c:3616 set_format: Set channel IAX2/specialai-1904 to write format gsm [Sep 24 12:47:38] DEBUG[24258]: pbx.c:3701 __ast_pbx_run: Spawn extension (od-welcome,s,3) exited non-zero on 'IAX2/specialai-1904' [Sep 24 12:47:38] == Spawn extension (od-welcome, s, 3) exited non-zero on 'IAX2/specialai-1904' [Sep 24 12:47:38] DEBUG[24258]: channel.c:1610 ast_softhangup_nolock: Soft-Hanging up channel 'IAX2/specialai-1904' [Sep 24 12:47:38] DEBUG[24258]: pbx.c:2935 pbx_substitute_variables_helper_full: Function result is '2008' [Sep 24 12:47:38] DEBUG[24258]: pbx.c:2935 pbx_substitute_variables_helper_full: Function result is 's' [Sep 24 12:47:38] DEBUG[24258]: pbx.c:3101 pbx_extension_helper: Launching 'NoOp' [Sep 24 12:47:38] -- Executing [h@od-welcome:1] NoOp("IAX2/specialai-1904", "Hangup call from 2008 to s") in new stack [Sep 24 12:47:38] DEBUG[24258]: pbx.c:3101 pbx_extension_helper: Launching 'Hangup' [Sep 24 12:47:38] -- Executing [h@od-welcome:2] Hangup("IAX2/specialai-1904", "") in new stack [Sep 24 12:47:38] DEBUG[24258]: pbx.c:3842 __ast_pbx_run: Spawn extension (od-welcome,h,2) exited non-zero on 'IAX2/specialai-1904' [Sep 24 12:47:38] == Spawn extension (od-welcome, h, 2) exited non-zero on 'IAX2/specialai-1904' [Sep 24 12:47:38] DEBUG[24258]: channel.c:1703 ast_hangup: Hanging up channel 'IAX2/specialai-1904' [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:4749 iax2_hangup: We're hanging up IAX2/specialai-1904 now... [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:4766 iax2_hangup: Really destroying IAX2/specialai-1904 now... [Sep 24 12:47:38] DEBUG[24258]: chan_iax2.c:2321 sched_delay_remove: schedule decrement of callno used for 192.168.255.37 in 60 seconds [Sep 24 12:47:38] -- Hungup 'IAX2/specialai-1904' vapp01*CLI> Disconnected from Asterisk server [Sep 24 12:47:38] Executing last minute cleanups Asterisk ending (0). Asterisk ended with exit status 127 Asterisk died with code 127. Automatically restarting Asterisk.