2008-02-21 14:45:10 [INFO] mod_dialplan_xml.c:217 dialplan_hunt() Processing Traun Leyden->7704! 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^(.*)%23(.*)$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^\*\*8([0-3])$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^\*\*81(\d+)$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^\*\*82(\d+)$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^\*\*83(\d+)$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^\*341\*$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^\*342\*$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^\*343\*$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^\*344\*$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^\*345\*$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^\*346\*$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^\*347\*$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^347$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^(\*241\*|\*21)$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^(\*242\*|\*22)$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^(\*242\*|\*23)$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^(\*244\*|\*24)$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^(\*245\*|\*25)$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^(\*246\*|\*26)$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${sip_req_port}(5060) =~ /^1[23][0-9]{3}$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${sip_req_port}(5060) =~ /^1[23][0-9]{3}$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${sip_req_port}(5060) =~ /^1[23][0-9]{3}$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions caller_id_number(72) =~ /^72$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /(.*)/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:273 dialplan_hunt() sofia/local/72@192.168.1.101:5060 State Change CS_RING -> CS_EXECUTE 2008-02-21 14:45:10 [DEBUG] switch_core_session.c:644 switch_core_session_signal_state_change() Kill sofia/local/72@192.168.1.101:5060 [BREAK] 2008-02-21 14:45:10 [DEBUG] switch_core_state_machine.c:406 switch_core_session_run() (sofia/local/72@192.168.1.101:5060) State EXECUTE 2008-02-21 14:45:10 [DEBUG] mod_sofia.c:131 sofia_on_execute() SOFIA EXECUTE 2008-02-21 14:45:10 [DEBUG] switch_core_state_machine.c:121 switch_core_standard_on_execute() Standard EXECUTE 2008-02-21 14:45:10 [NOTICE] switch_core_state_machine.c:134 switch_core_standard_on_execute() Execute set(effective_caller_id_name=7702) 2008-02-21 14:45:10 [DEBUG] mod_dptools.c:463 set_function() SET [effective_caller_id_name]=[7702] 2008-02-21 14:45:10 [NOTICE] switch_core_state_machine.c:134 switch_core_standard_on_execute() Execute set(effective_caller_id_number=7702) 2008-02-21 14:45:10 [DEBUG] mod_dptools.c:463 set_function() SET [effective_caller_id_number]=[7702] 2008-02-21 14:45:10 [NOTICE] switch_core_state_machine.c:134 switch_core_standard_on_execute() Execute fdial(OUT_CALL|WLAN|72|sofia/gateway/gw_phone72/7704@192.168.1.101:5085) 2008-02-21 14:45:10 [DEBUG] mod_fdial.c:129 fdial_main_seperate_function_call_data() OUTGOING call ... 2008-02-21 14:45:10 [DEBUG] mod_fdial.c:314 fdial_main_seperate_parameters() FMC User id is: "72" 2008-02-21 14:45:10 [DEBUG] mod_fdial.c:326 fdial_main_seperate_parameters() FMC User domain set to default (local) 2008-02-21 14:45:10 [DEBUG] mod_fdial.c:352 fdial_main_seperate_parameters() FMC member type is: "WLAN" 2008-02-21 14:45:10 [DEBUG] mod_fdial.c:358 fdial_main_seperate_parameters() Foreign number is: "sofia/gateway/gw_phone72/7704@192.168.1.101:5085" 2008-02-21 14:45:10 [DEBUG] mod_fdial.c:1089 fdial_function() Looking for a controller for user "72" 2008-02-21 14:45:10 [DEBUG] controller.c:478 fdial_controller_find() Finding controller with hash "72@local" ... 2008-02-21 14:45:10 [DEBUG] controller.c:478 fdial_controller_find() Finding controller with hash "72@local" ... 2008-02-21 14:45:10 [DEBUG] mod_fdial.c:446 fdial_main_find_controller() Could not find the controller for the specified user! 2008-02-21 14:45:10 [DEBUG] config.c:102 fdial_config_get_fmc_section_for_user() Looking for fmc section for name "72" 2008-02-21 14:45:10 [DEBUG] config.c:171 fdial_config_get_param_from_fmc_section() fmc param [GSM]=[sofia/gateway/gw_phone72/8312954582] 2008-02-21 14:45:10 [DEBUG] config.c:171 fdial_config_get_param_from_fmc_section() fmc param [WLAN]=[sofia/local/72] 2008-02-21 14:45:10 [DEBUG] config.c:171 fdial_config_get_param_from_fmc_section() fmc param [GSM]=[sofia/gateway/gw_phone72/8312954582] 2008-02-21 14:45:10 [DEBUG] config.c:171 fdial_config_get_param_from_fmc_section() fmc param [GSM]=[sofia/gateway/gw_phone72/8312954582] 2008-02-21 14:45:10 [DEBUG] config.c:171 fdial_config_get_param_from_fmc_section() fmc param [WLAN]=[sofia/local/72] 2008-02-21 14:45:10 [DEBUG] config.c:171 fdial_config_get_param_from_fmc_section() fmc param [FMC_NUMBER]=[7702] 2008-02-21 14:45:10 [INFO] mod_fdial.c:553 fdial_main_start_fdial_call() Calling the destination number "sofia/gateway/gw_phone72/7704@192.168.1.101:5085" ... 2008-02-21 14:45:10 [NOTICE] switch_channel.c:392 switch_channel_set_name() New Chan sofia/phone72/7704@192.168.1.101:5085 [32fed00f-b1ba-4829-aa11-f1e6d8fb3901] 2008-02-21 14:45:10 [DEBUG] mod_sofia.c:1735 sofia_outgoing_channel() sofia/phone72/7704@192.168.1.101:5085 State Change CS_NEW -> CS_INIT 2008-02-21 14:45:10 [DEBUG] switch_core_session.c:644 switch_core_session_signal_state_change() Kill sofia/phone72/7704@192.168.1.101:5085 [BREAK] send 958 bytes to udp/[192.168.1.101]:5085 at 22:45:10.105042: ------------------------------------------------------------------------ INVITE sip:7704@192.168.1.101:5085 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.101:12000;rport;branch=z9hG4bK18Q14yeNcg93D Max-Forwards: 70 From: "7702" ;tag=01yUp0KK49amD To: Call-ID: 7f631a03-5b71-122b-8f8d-00123f09e397 CSeq: 95698619 INVITE Contact: User-Agent: ComdasysB2BUA1.0.0 (6357) Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO Supported: precondition, timer, pref Min-SE: 120 Content-Type: application/sdp Content-Disposition: session Content-Length: 270 Remote-Party-ID: "7702" <7702@192.168.1.101>;screen=yes;privacy=off v=0 o=Comdasysb2bua 4427250951714413323 3994043567193438015 IN IP4 192.168.1.101 s=Comdasysb2bua c=IN IP4 192.168.1.101 t=0 0 m=audio 16384 RTP/AVP 8 101 13 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=rtpmap:13 CN/8000 a=ptime:20 ------------------------------------------------------------------------ recv 551 bytes from udp/[192.168.1.101]:5085 at 22:45:10.105855: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.1.101:12000;rport;branch=z9hG4bK18Q14yeNcg93D;received=192.168.1.101 From: "7702" ;tag=01yUp0KK49amD To: ;tag=as75afb707 Call-ID: 7f631a03-5b71-122b-8f8d-00123f09e397 CSeq: 95698619 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Max-Forwards: 70 Contact: Proxy-Authenticate: Digest realm="asterisk", nonce="4eb4b2e7" Content-Length: 0 ------------------------------------------------------------------------ send 326 bytes to udp/[192.168.1.101]:5085 at 22:45:10.106131: ------------------------------------------------------------------------ ACK sip:7704@192.168.1.101:5085 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.101:12000;rport;branch=z9hG4bK18Q14yeNcg93D Max-Forwards: 70 From: "7702" ;tag=01yUp0KK49amD To: ;tag=as75afb707 Call-ID: 7f631a03-5b71-122b-8f8d-00123f09e397 CSeq: 95698619 ACK Content-Length: 0 ------------------------------------------------------------------------ send 1149 bytes to udp/[192.168.1.101]:5085 at 22:45:10.106685: ------------------------------------------------------------------------ INVITE sip:7704@192.168.1.101:5085 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.101:12000;rport;branch=z9hG4bK2HHt6SZr9rZpS Max-Forwards: 70 From: "7702" ;tag=01yUp0KK49amD To: Call-ID: 7f631a03-5b71-122b-8f8d-00123f09e397 CSeq: 95698620 INVITE Contact: Expires: 3600 User-Agent: ComdasysB2BUA1.0.0 (6357) Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO Supported: precondition, timer, pref Proxy-Authorization: Digest username="7702", realm="asterisk", nonce="4eb4b2e7", algorithm=MD5, uri="sip:7704@192.168.1.101:5085", response="d1c306cd03ce92125e605864535f6fdf" Min-SE: 120 Content-Type: application/sdp Content-Disposition: session Content-Length: 270 Remote-Party-ID: "7702" <7702@192.168.1.101>;screen=yes;privacy=off v=0 o=Comdasysb2bua 4427250951714413323 3994043567193438015 IN IP4 192.168.1.101 s=Comdasysb2bua c=IN IP4 192.168.1.101 t=0 0 m=audio 16384 RTP/AVP 8 101 13 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=rtpmap:13 CN/8000 a=ptime:20 ------------------------------------------------------------------------ recv 450 bytes from udp/[192.168.1.101]:5085 at 22:45:10.111926: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.1.101:12000;rport;branch=z9hG4bK2HHt6SZr9rZpS;received=192.168.1.101 From: "7702" ;tag=01yUp0KK49amD To: Call-ID: 7f631a03-5b71-122b-8f8d-00123f09e397 CSeq: 95698620 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Max-Forwards: 70 Contact: Content-Length: 0 ------------------------------------------------------------------------ recv 783 bytes from udp/[192.168.1.101]:5085 at 22:45:10.116127: ------------------------------------------------------------------------ INVITE sip:74@192.168.1.101:54466 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.101:5085;branch=z9hG4bK5d5234c6;rport From: "7702" ;tag=as2b515e41 To: Contact: Call-ID: 5291a92e573299ce3fc59c111be9e787@192.168.1.101 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 21 Feb 2008 22:45:10 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 263 v=0 o=root 7565 7565 IN IP4 192.168.1.101 s=session c=IN IP4 192.168.1.101 t=0 0 m=audio 18996 RTP/AVP 8 3 0 101 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - ------------------------------------------------------------------------ send 319 bytes to udp/[192.168.1.101]:5085 at 22:45:10.116752: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.1.101:5085;branch=z9hG4bK5d5234c6;rport=5085 From: "7702" ;tag=as2b515e41 To: Call-ID: 5291a92e573299ce3fc59c111be9e787@192.168.1.101 CSeq: 102 INVITE User-Agent: ComdasysB2BUA1.0.0 (6357) Content-Length: 0 ------------------------------------------------------------------------ send 511 bytes to udp/[192.168.1.101]:5085 at 22:45:10.132749: ------------------------------------------------------------------------ SIP/2.0 404 Not Found Via: SIP/2.0/UDP 192.168.1.101:5085;branch=z9hG4bK5d5234c6;rport=5085 From: "7702" ;tag=as2b515e41 To: ;tag=2tH7HNaD6S4Ne Call-ID: 5291a92e573299ce3fc59c111be9e787@192.168.1.101 CSeq: 102 INVITE User-Agent: ComdasysB2BUA1.0.0 (6357) Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO Supported: precondition, timer, pref Content-Length: 0 ------------------------------------------------------------------------ recv 394 bytes from udp/[192.168.1.101]:5085 at 22:45:10.147962: ------------------------------------------------------------------------ ACK sip:74@192.168.1.101:54466 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.101:5085;branch=z9hG4bK5d5234c6;rport From: "7702" ;tag=as2b515e41 To: ;tag=2tH7HNaD6S4Ne Contact: Call-ID: 5291a92e573299ce3fc59c111be9e787@192.168.1.101 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 ------------------------------------------------------------------------ recv 466 bytes from udp/[192.168.1.101]:5085 at 22:45:10.199756: ------------------------------------------------------------------------ SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.1.101:12000;rport;branch=z9hG4bK2HHt6SZr9rZpS;received=192.168.1.101 From: "7702" ;tag=01yUp0KK49amD To: ;tag=as373816f4 Call-ID: 7f631a03-5b71-122b-8f8d-00123f09e397 CSeq: 95698620 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Max-Forwards: 70 Contact: Content-Length: 0 ------------------------------------------------------------------------ recv 535 bytes from udp/[192.168.1.101]:5085 at 22:45:10.200567: ------------------------------------------------------------------------ SIP/2.0 503 Service Unavailable Via: SIP/2.0/UDP 192.168.1.101:12000;rport;branch=z9hG4bK2HHt6SZr9rZpS;received=192.168.1.101 From: "7702" ;tag=01yUp0KK49amD To: ;tag=as373816f4 Call-ID: 7f631a03-5b71-122b-8f8d-00123f09e397 CSeq: 95698620 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Max-Forwards: 70 Contact: Content-Length: 0 X-Asterisk-HangupCause: Unallocated (unassigned) number ------------------------------------------------------------------------ send 326 bytes to udp/[192.168.1.101]:5085 at 22:45:10.200895: ------------------------------------------------------------------------ ACK sip:7704@192.168.1.101:5085 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.101:12000;rport;branch=z9hG4bK2HHt6SZr9rZpS Max-Forwards: 70 From: "7702" ;tag=01yUp0KK49amD To: ;tag=as373816f4 Call-ID: 7f631a03-5b71-122b-8f8d-00123f09e397 CSeq: 95698620 ACK Content-Length: 0 ------------------------------------------------------------------------ send 508 bytes to udp/[192.168.1.70]:5061 at 22:45:10.212541: ------------------------------------------------------------------------ SIP/2.0 503 Service Unavailable Via: SIP/2.0/UDP 192.168.1.70:5061;branch=z9hG4bK-65760e5f;rport=5061 From: Traun Leyden ;tag=7515a600df0460b7o1 To: ;tag=g3ZHHga7D17Fa Call-ID: dd325274-29707ed3@192.168.1.70 CSeq: 101 INVITE User-Agent: ComdasysB2BUA1.0.0 (6357) Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO Supported: precondition, timer, pref Content-Length: 0 ------------------------------------------------------------------------ 2008-02-21 14:45:10 [DEBUG] switch_core_state_machine.c:397 switch_core_session_run() (sofia/phone72/7704@192.168.1.101:5085) State INIT 2008-02-21 14:45:10 [DEBUG] mod_sofia.c:87 sofia_on_init() SOFIA INIT 2008-02-21 14:45:10 [DEBUG] sofia.c:288 sofia_event_callback() event [nua_i_state] status [0][INVITE sent] session: sofia/phone72/7704@192.168.1.101:5085 2008-02-21 14:45:10 [DEBUG] sofia.c:1391 sofia_handle_sip_i_state() Channel sofia/phone72/7704@192.168.1.101:5085 entering state [calling] 2008-02-21 14:45:10 [DEBUG] sofia.c:288 sofia_event_callback() event [nua_r_invite] status [407][Proxy Authentication Required] session: sofia/phone72/7704@192.168.1.101:5085 2008-02-21 14:45:10 [DEBUG] sofia_reg.c:903 sofia_reg_handle_sip_r_challenge() Authenticating '7702' with 'Digest:"asterisk":7702:test'. 2008-02-21 14:45:10 [DEBUG] sofia.c:288 sofia_event_callback() event [nua_i_state] status [0][INVITE sent] session: sofia/phone72/7704@192.168.1.101:5085 2008-02-21 14:45:10 [DEBUG] sofia.c:1391 sofia_handle_sip_i_state() Channel sofia/phone72/7704@192.168.1.101:5085 entering state [calling] 2008-02-21 14:45:10 [NOTICE] switch_channel.c:392 switch_channel_set_name() New Chan sofia/phone74/7702@192.168.1.101:5085 [5d887578-3d49-4fde-9347-92239e617b49] recv 399 bytes from udp/[192.168.1.70]:5061 at 22:45:10.232679: ------------------------------------------------------------------------ ACK sip:7704@192.168.1.101 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.70:5061;branch=z9hG4bK-65760e5f;rport From: Traun Leyden ;tag=7515a600df0460b7o1 To: ;tag=g3ZHHga7D17Fa Call-ID: dd325274-29707ed3@192.168.1.70 CSeq: 101 ACK Max-Forwards: 70 Contact: Traun Leyden User-Agent: Linksys/SPA2002-3.1.9(d) Content-Length: 0 ------------------------------------------------------------------------ 2008-02-21 14:45:10 [DEBUG] sofia.c:1391 sofia_handle_sip_i_state() Channel sofia/phone74/7702@192.168.1.101:5085 entering state [received] 2008-02-21 14:45:10 [DEBUG] sofia.c:1395 sofia_handle_sip_i_state() Remote SDP: v=0 o=root 7565 7565 IN IP4 192.168.1.101 s=session c=IN IP4 192.168.1.101 t=0 0 m=audio 18996 RTP/AVP 8 3 0 101 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - 2008-02-21 14:45:10 [DEBUG] sofia_glue.c:1427 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMA:8:8000]/[PCMA:8:8000] 2008-02-21 14:45:10 [INFO] sofia_glue.c:1502 sofia_glue_negotiate_sdp() m->m_mode == sdp_sendrecv, inactive,sendonly = 0 2008-02-21 14:45:10 [DEBUG] sofia_glue.c:1033 sofia_glue_tech_set_codec() Set Codec sofia/phone74/7702@192.168.1.101:5085 PCMA/8000 20 ms 160 samples 2008-02-21 14:45:10 [DEBUG] sofia_glue.c:1391 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101 2008-02-21 14:45:10 [DEBUG] sofia_glue.c:1631 sofia_glue_negotiate_sdp() neither sendonly or inactive 2008-02-21 14:45:10 [DEBUG] sofia_glue.c:1662 sofia_glue_negotiate_sdp() TFLAG_SIP_HOLD not set, doing nothing 2008-02-21 14:45:10 [DEBUG] sofia.c:1502 sofia_handle_sip_i_state() sofia/phone74/7702@192.168.1.101:5085 State Change CS_NEW -> CS_INIT 2008-02-21 14:45:10 [DEBUG] switch_core_session.c:644 switch_core_session_signal_state_change() Kill sofia/phone74/7702@192.168.1.101:5085 [BREAK] 2008-02-21 14:45:10 [DEBUG] switch_core_state_machine.c:397 switch_core_session_run() (sofia/phone74/7702@192.168.1.101:5085) State INIT 2008-02-21 14:45:10 [DEBUG] mod_sofia.c:87 sofia_on_init() SOFIA INIT 2008-02-21 14:45:10 [DEBUG] mod_sofia.c:100 sofia_on_init() sofia/phone74/7702@192.168.1.101:5085 State Change CS_INIT -> CS_RING 2008-02-21 14:45:10 [DEBUG] switch_core_session.c:644 switch_core_session_signal_state_change() Kill sofia/phone74/7702@192.168.1.101:5085 [BREAK] 2008-02-21 14:45:10 [DEBUG] switch_core_state_machine.c:400 switch_core_session_run() (sofia/phone74/7702@192.168.1.101:5085) State RING 2008-02-21 14:45:10 [DEBUG] mod_sofia.c:115 sofia_on_ring() SOFIA RING 2008-02-21 14:45:10 [DEBUG] switch_core_state_machine.c:64 switch_core_standard_on_ring() Standard RING sofia/phone74/7702@192.168.1.101:5085 2008-02-21 14:45:10 [INFO] mod_dialplan_xml.c:217 dialplan_hunt() Processing 7702->74! 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(74) =~ /^(.*)%23(.*)$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(74) =~ /^\*\*8([0-3])$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(74) =~ /^\*\*81(\d+)$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(74) =~ /^\*\*82(\d+)$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(74) =~ /^\*\*83(\d+)$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(74) =~ /^\*341\*$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(74) =~ /^\*342\*$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(74) =~ /^\*343\*$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(74) =~ /^\*344\*$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(74) =~ /^\*345\*$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(74) =~ /^\*346\*$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(74) =~ /^\*347\*$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(74) =~ /^347$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(74) =~ /^(\*241\*|\*21)$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(74) =~ /^(\*242\*|\*22)$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(74) =~ /^(\*242\*|\*23)$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(74) =~ /^(\*244\*|\*24)$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(74) =~ /^(\*245\*|\*25)$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(74) =~ /^(\*246\*|\*26)$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${sip_req_port}(54466) =~ /^1[23][0-9]{3}$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${sip_req_port}(54466) =~ /^1[23][0-9]{3}$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${sip_req_port}(54466) =~ /^1[23][0-9]{3}$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions caller_id_number(7702) =~ /^72$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions caller_id_number(7702) =~ /^6789$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions caller_id_number(7702) =~ /^6789$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${fmc_id}() =~ /^72$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions caller_id_number(7702) =~ /^73$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions caller_id_number(7702) =~ /^6799$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions caller_id_number(7702) =~ /^6799$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${fmc_id}() =~ /^73$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions caller_id_number(7702) =~ /^74$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions caller_id_number(7702) =~ /^6799$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions caller_id_number(7702) =~ /^6799$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${fmc_id}() =~ /^74$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${fmc_id}() =~ /^72$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${fmc_id}() =~ /^73$/ 2008-02-21 14:45:10 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 14:45:10 [INFO] switch_core_state_machine.c:111 switch_core_standard_on_ring() No Route, Aborting 2008-02-21 14:45:10 [NOTICE] switch_core_state_machine.c:112 switch_core_standard_on_ring() Hangup sofia/phone74/7702@192.168.1.101:5085 [CS_RING] [NO_ROUTE_DESTINATION] 2008-02-21 14:45:10 [DEBUG] switch_channel.c:1071 switch_channel_perform_hangup() Kill sofia/phone74/7702@192.168.1.101:5085 [KILL] 2008-02-21 14:45:10 [DEBUG] switch_core_session.c:644 switch_core_session_signal_state_change() Kill sofia/phone74/7702@192.168.1.101:5085 [BREAK] 2008-02-21 14:45:10 [DEBUG] switch_core_state_machine.c:394 switch_core_session_run() (sofia/phone74/7702@192.168.1.101:5085) State HANGUP 2008-02-21 14:45:10 [DEBUG] mod_sofia.c:210 sofia_on_hangup() Channel sofia/phone74/7702@192.168.1.101:5085 hanging up, cause: NO_ROUTE_DESTINATION 2008-02-21 14:45:10 [DEBUG] mod_sofia.c:234 sofia_on_hangup() Responding to INVITE with: 404 2008-02-21 14:45:10 [DEBUG] sofia.c:288 sofia_event_callback() event [nua_i_state] status [404][Call state] session: sofia/phone74/7702@192.168.1.101:5085 2008-02-21 14:45:10 [DEBUG] sofia.c:1391 sofia_handle_sip_i_state() Channel sofia/phone74/7702@192.168.1.101:5085 entering state [terminated] 2008-02-21 14:45:10 [DEBUG] switch_core_state_machine.c:45 switch_core_standard_on_hangup() Standard HANGUP sofia/phone74/7702@192.168.1.101:5085, cause: NO_ROUTE_DESTINATION 2008-02-21 14:45:10 [DEBUG] switch_core_session.c:702 switch_core_session_thread() Session 3 (sofia/phone74/7702@192.168.1.101:5085) Locked, Waiting on external entities 2008-02-21 14:45:10 [INFO] switch_core_session.c:708 switch_core_session_thread() Session 3 (sofia/phone74/7702@192.168.1.101:5085) Ended 2008-02-21 14:45:10 [NOTICE] switch_core_session.c:710 switch_core_session_thread() Close Channel sofia/phone74/7702@192.168.1.101:5085 [CS_HANGUP] 2008-02-21 14:45:10 [DEBUG] sofia.c:288 sofia_event_callback() event [nua_r_invite] status [180][Ringing] session: sofia/phone72/7704@192.168.1.101:5085 2008-02-21 14:45:10 [DEBUG] sofia.c:288 sofia_event_callback() event [nua_i_state] status [180][Ringing] session: sofia/phone72/7704@192.168.1.101:5085 2008-02-21 14:45:10 [DEBUG] sofia.c:1391 sofia_handle_sip_i_state() Channel sofia/phone72/7704@192.168.1.101:5085 entering state [proceeding] 2008-02-21 14:45:10 [NOTICE] sofia.c:1423 sofia_handle_sip_i_state() Ring-Ready sofia/phone72/7704@192.168.1.101:5085! 2008-02-21 14:45:10 [DEBUG] sofia.c:288 sofia_event_callback() event [nua_r_invite] status [503][Service Unavailable] session: sofia/phone72/7704@192.168.1.101:5085 2008-02-21 14:45:10 [DEBUG] sofia.c:288 sofia_event_callback() event [nua_i_state] status [503][Service Unavailable] session: sofia/phone72/7704@192.168.1.101:5085 2008-02-21 14:45:10 [DEBUG] sofia.c:1391 sofia_handle_sip_i_state() Channel sofia/phone72/7704@192.168.1.101:5085 entering state [terminated] 2008-02-21 14:45:10 [NOTICE] sofia.c:1712 sofia_handle_sip_i_state() Hangup sofia/phone72/7704@192.168.1.101:5085 [CS_INIT] [NORMAL_TEMPORARY_FAILURE] 2008-02-21 14:45:10 [DEBUG] switch_channel.c:1071 switch_channel_perform_hangup() Kill sofia/phone72/7704@192.168.1.101:5085 [KILL] 2008-02-21 14:45:10 [DEBUG] switch_core_session.c:644 switch_core_session_signal_state_change() Kill sofia/phone72/7704@192.168.1.101:5085 [BREAK] 2008-02-21 14:45:10 [DEBUG] switch_ivr_originate.c:877 switch_ivr_originate() Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE] 2008-02-21 14:45:10 [ERR] glue.c:75 fdial_glue_dial() Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE 2008-02-21 14:45:10 [DEBUG] mod_fdial.c:721 fdial_main_start_fdial_call() Calling the peer "sofia/gateway/gw_phone72/7704@192.168.1.101:5085" failed (cause: NORMAL_TEMPORARY_FAILURE). 2008-02-21 14:45:10 [DEBUG] mod_fdial.c:1242 fdial_function() Start outgoing fdial call failed - Hangup member with cause "NORMAL_TEMPORARY_FAILURE"! 2008-02-21 14:45:10 [NOTICE] mod_fdial.c:1258 fdial_function() Hangup sofia/local/72@192.168.1.101:5060 [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE] 2008-02-21 14:45:10 [DEBUG] switch_channel.c:1071 switch_channel_perform_hangup() Kill sofia/local/72@192.168.1.101:5060 [KILL] 2008-02-21 14:45:10 [DEBUG] switch_core_session.c:644 switch_core_session_signal_state_change() Kill sofia/local/72@192.168.1.101:5060 [BREAK] 2008-02-21 14:45:10 [DEBUG] mod_fdial.c:1393 fdial_function() The status of the last mod_fdial call was: error 2008-02-21 14:45:10 [DEBUG] switch_core_state_machine.c:394 switch_core_session_run() (sofia/local/72@192.168.1.101:5060) State HANGUP 2008-02-21 14:45:10 [DEBUG] mod_sofia.c:210 sofia_on_hangup() Channel sofia/local/72@192.168.1.101:5060 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2008-02-21 14:45:10 [DEBUG] mod_sofia.c:234 sofia_on_hangup() Responding to INVITE with: 503 2008-02-21 14:45:10 [DEBUG] sofia.c:288 sofia_event_callback() event [nua_i_state] status [503][Call state] session: sofia/local/72@192.168.1.101:5060 2008-02-21 14:45:10 [DEBUG] sofia.c:1391 sofia_handle_sip_i_state() Channel sofia/local/72@192.168.1.101:5060 entering state [terminated] 2008-02-21 14:45:10 [DEBUG] switch_core_state_machine.c:45 switch_core_standard_on_hangup() Standard HANGUP sofia/local/72@192.168.1.101:5060, cause: NORMAL_TEMPORARY_FAILURE 2008-02-21 14:45:10 [DEBUG] switch_core_session.c:702 switch_core_session_thread() Session 1 (sofia/local/72@192.168.1.101:5060) Locked, Waiting on external entities 2008-02-21 14:45:10 [INFO] switch_core_session.c:708 switch_core_session_thread() Session 1 (sofia/local/72@192.168.1.101:5060) Ended 2008-02-21 14:45:10 [NOTICE] switch_core_session.c:710 switch_core_session_thread() Close Channel sofia/local/72@192.168.1.101:5060 [CS_HANGUP] 2008-02-21 14:45:10 [DEBUG] switch_core_state_machine.c:394 switch_core_session_run() (sofia/phone72/7704@192.168.1.101:5085) State HANGUP 2008-02-21 14:45:10 [DEBUG] mod_sofia.c:210 sofia_on_hangup() Channel sofia/phone72/7704@192.168.1.101:5085 hanging up, cause: NORMAL_TEMPORARY_FAILURE 2008-02-21 14:45:10 [DEBUG] switch_core_state_machine.c:45 switch_core_standard_on_hangup() Standard HANGUP sofia/phone72/7704@192.168.1.101:5085, cause: NORMAL_TEMPORARY_FAILURE 2008-02-21 14:45:10 [DEBUG] switch_core_session.c:702 switch_core_session_thread() Session 2 (sofia/phone72/7704@192.168.1.101:5085) Locked, Waiting on external entities 2008-02-21 14:45:10 [INFO] switch_core_session.c:708 switch_core_session_thread() Session 2 (sofia/phone72/7704@192.168.1.101:5085) Ended 2008-02-21 14:45:10 [NOTICE] switch_core_session.c:710 switch_core_session_thread() Close Channel sofia/phone72/7704@192.168.1.101:5085 [CS_HANGUP] recv 720 bytes from udp/[192.168.1.70]:5061 at 22:45:13.479171: