2008-02-22 09:19:21 [INFO] mod_dialplan_xml.c:217 dialplan_hunt() Processing 7702->7704! 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^(.*)%23(.*)$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^\*\*8([0-3])$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^\*\*81(\d+)$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^\*\*82(\d+)$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^\*\*83(\d+)$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^\*341\*$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^\*342\*$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^\*343\*$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^\*344\*$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^\*345\*$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^\*346\*$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^\*347\*$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^347$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^(\*241\*|\*21)$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^(\*242\*|\*22)$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^(\*242\*|\*23)$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^(\*244\*|\*24)$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^(\*245\*|\*25)$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^(\*246\*|\*26)$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${sip_req_port}(12002) =~ /^1[23][0-9]{3}$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${fmc_id}() =~ /^$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${enterprise}() =~ /^$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^7702$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${sip_req_port}(12002) =~ /^1[23][0-9]{3}$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${fmc_id}() =~ /^$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${enterprise}() =~ /^$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^7703$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${sip_req_port}(12002) =~ /^1[23][0-9]{3}$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${fmc_id}() =~ /^$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${enterprise}() =~ /^$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(7704) =~ /^7704$/ 2008-02-22 09:19:21 [DEBUG] mod_dialplan_xml.c:273 dialplan_hunt() sofia/phone74/7702@192.168.1.101:5085 State Change CS_RING -> CS_EXECUTE 2008-02-22 09:19:21 [DEBUG] switch_core_session.c:644 switch_core_session_signal_state_change() Kill sofia/phone74/7702@192.168.1.101:5085 [BREAK] 2008-02-22 09:19:21 [DEBUG] switch_core_state_machine.c:406 switch_core_session_run() (sofia/phone74/7702@192.168.1.101:5085) State EXECUTE 2008-02-22 09:19:21 [DEBUG] mod_sofia.c:131 sofia_on_execute() SOFIA EXECUTE 2008-02-22 09:19:21 [DEBUG] switch_core_state_machine.c:121 switch_core_standard_on_execute() Standard EXECUTE 2008-02-22 09:19:21 [NOTICE] switch_core_state_machine.c:134 switch_core_standard_on_execute() Execute check_cf_always() 2008-02-22 09:19:21 [DEBUG] switch_core_session.c:644 switch_core_session_signal_state_change() Kill sofia/phone72/7704@192.168.1.101:5085 [BREAK] 2008-02-22 09:19:21 [DEBUG] switch_ivr_originate.c:625 switch_ivr_originate() Raw Codec Activation Success L16@8000hz 1 channel 20ms send 534 bytes to udp/[192.168.1.70]:5061 at 17:19:21.597991: ------------------------------------------------------------------------ SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.1.70:5061;branch=z9hG4bK-7c066f57;rport=5061 From: Traun Leyden ;tag=444575f6ad0ca17o1 To: ;tag=1m9DKeNaDgX0K Call-ID: 9db3b6ff-80cfeef7@192.168.1.70 CSeq: 101 INVITE Contact: 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-22 09:19:21 [DEBUG] sofia.c:288 sofia_event_callback() event [nua_i_state] status [180][Ringing] session: sofia/local/72@192.168.1.101:5060 2008-02-22 09:19:21 [DEBUG] sofia.c:1391 sofia_handle_sip_i_state() Channel sofia/local/72@192.168.1.101:5060 entering state [early] 2008-02-22 09:19:21 [NOTICE] mod_sofia.c:977 sofia_receive_message() Ring-Ready sofia/local/72@192.168.1.101:5060! 2008-02-22 09:19:21 [DEBUG] switch_core_session.c:347 switch_core_session_receive_message() Kill sofia/local/72@192.168.1.101:5060 [BREAK] 2008-02-22 09:19:21 [DEBUG] switch_core_state_machine.c:400 switch_core_session_run() (sofia/phone72/7704@192.168.1.101:5085) State RING 2008-02-22 09:19:21 [DEBUG] mod_sofia.c:115 sofia_on_ring() SOFIA RING 2008-02-22 09:19:21 [DEBUG] glue.c:19 fdial_on_ring() CUSTOM RING 2008-02-22 09:19:21 [DEBUG] glue.c:22 fdial_on_ring() sofia/phone72/7704@192.168.1.101:5085 State Change CS_RING -> CS_TRANSMIT 2008-02-22 09:19:21 [DEBUG] switch_core_session.c:644 switch_core_session_signal_state_change() Kill sofia/phone72/7704@192.168.1.101:5085 [BREAK] 2008-02-22 09:19:21 [DEBUG] switch_core_state_machine.c:412 switch_core_session_run() (sofia/phone72/7704@192.168.1.101:5085) State TRANSMIT 2008-02-22 09:19:21 [DEBUG] mod_sofia.c:260 sofia_on_transmit() SOFIA TRANSMIT 2008-02-22 09:19:21 [DEBUG] switch_core_state_machine.c:198 switch_core_standard_on_transmit() Standard TRANSMIT 2008-02-22 09:19:21 [DEBUG] mod_call_forward.c:123 regnum_to_sip_uid() dest_num: 7704 2008-02-22 09:19:21 [DEBUG] mod_call_forward.c:143 regnum_to_sip_uid() dest_num matched with sip_uid: 4 2008-02-22 09:19:22 [DEBUG] mod_call_forward.c:640 check_cf() call forwarding not enabled for sip uid: 4 and cf_type: ALWAYS 2008-02-22 09:19:22 [NOTICE] switch_core_state_machine.c:134 switch_core_standard_on_execute() Execute fdial(INC_CALL|WLAN|74) 2008-02-22 09:19:22 [DEBUG] mod_fdial.c:122 fdial_main_seperate_function_call_data() INCOMING call ... 2008-02-22 09:19:22 [DEBUG] mod_fdial.c:314 fdial_main_seperate_parameters() FMC User id is: "74" 2008-02-22 09:19:22 [DEBUG] mod_fdial.c:326 fdial_main_seperate_parameters() FMC User domain set to default (local) 2008-02-22 09:19:22 [DEBUG] mod_fdial.c:352 fdial_main_seperate_parameters() FMC member type is: "WLAN" 2008-02-22 09:19:22 [INFO] mod_fdial.c:1004 fdial_function() Starting main fdial call for incoming... 2008-02-22 09:19:22 [DEBUG] controller.c:478 fdial_controller_find() Finding controller with hash "74@local" ... 2008-02-22 09:19:22 [DEBUG] controller.c:478 fdial_controller_find() Finding controller with hash "74@local" ... 2008-02-22 09:19:22 [DEBUG] mod_fdial.c:446 fdial_main_find_controller() Could not find the controller for the specified user! 2008-02-22 09:19:22 [DEBUG] config.c:97 fdial_config_get_fmc_section_for_user() Looking for fmc section for name "74" with XML_DB 2008-02-22 09:19:22 [DEBUG] config.c:187 fdial_config_get_param_from_fmc_section() fmc param [GSM]=[sofia/gateway/gw_phone72/8312954582] 2008-02-22 09:19:22 [DEBUG] config.c:187 fdial_config_get_param_from_fmc_section() fmc param [WLAN]=[sofia/local/72] 2008-02-22 09:19:22 [DEBUG] config.c:187 fdial_config_get_param_from_fmc_section() fmc param [GSM]=[sofia/gateway/gw_phone72/8312954582] 2008-02-22 09:19:22 [DEBUG] config.c:187 fdial_config_get_param_from_fmc_section() fmc param [GSM]=[sofia/gateway/gw_phone72/8312954582] 2008-02-22 09:19:22 [DEBUG] config.c:187 fdial_config_get_param_from_fmc_section() fmc param [WLAN]=[sofia/local/72] 2008-02-22 09:19:22 [DEBUG] config.c:187 fdial_config_get_param_from_fmc_section() fmc param [FMC_NUMBER]=[7702] 2008-02-22 09:19:22 [INFO] mod_fdial.c:555 fdial_main_start_fdial_call() Calling the destination number "sofia/local/72" ... 2008-02-22 09:19:22 [NOTICE] switch_channel.c:392 switch_channel_set_name() New Chan sofia/local/72 [63c0bfe5-3a05-4efd-afeb-5e1b4f8e9f59] 2008-02-22 09:19:22 [DEBUG] mod_sofia.c:1735 sofia_outgoing_channel() sofia/local/72 State Change CS_NEW -> CS_INIT 2008-02-22 09:19:22 [DEBUG] switch_core_session.c:644 switch_core_session_signal_state_change() Kill sofia/local/72 [BREAK] 2008-02-22 09:19:22 [DEBUG] switch_core_state_machine.c:397 switch_core_session_run() (sofia/local/72) State INIT 2008-02-22 09:19:22 [DEBUG] mod_sofia.c:87 sofia_on_init() SOFIA INIT send 991 bytes to udp/[192.168.1.70]:5061 at 17:19:22.072149: ------------------------------------------------------------------------ INVITE sip:72@192.168.1.70:5061 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.101;rport;branch=z9hG4bKDeac68H4gHH7S Max-Forwards: 70 From: "7702" ;tag=2X26m95DaSKKF To: Call-ID: 2643c0c8-5c0d-122b-518b-00123f09e397 CSeq: 95732045 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: 317 Remote-Party-ID: "7702" <7702@192.168.1.101>;screen=yes;privacy=off v=0 o=Comdasysb2bua 8549115425014498993 2320150514936752307 IN IP4 192.168.1.101 s=Comdasysb2bua c=IN IP4 192.168.1.101 t=0 0 m=audio 16386 RTP/AVP 8 0 3 101 13 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=rtpmap:13 CN/8000 a=ptime:20 ------------------------------------------------------------------------ 2008-02-22 09:19:22 [DEBUG] sofia.c:288 sofia_event_callback() event [nua_i_state] status [0][INVITE sent] session: sofia/local/72 2008-02-22 09:19:22 [DEBUG] sofia.c:1391 sofia_handle_sip_i_state() Channel sofia/local/72 entering state [calling] 2008-02-22 09:19:22 [DEBUG] mod_sofia.c:100 sofia_on_init() sofia/local/72 State Change CS_INIT -> CS_RING 2008-02-22 09:19:22 [DEBUG] switch_core_session.c:644 switch_core_session_signal_state_change() Kill sofia/local/72 [BREAK] 2008-02-22 09:19:22 [DEBUG] switch_core_state_machine.c:400 switch_core_session_run() (sofia/local/72) State RING 2008-02-22 09:19:22 [DEBUG] mod_sofia.c:115 sofia_on_ring() SOFIA RING 2008-02-22 09:19:22 [DEBUG] glue.c:19 fdial_on_ring() CUSTOM RING 2008-02-22 09:19:22 [DEBUG] glue.c:22 fdial_on_ring() sofia/local/72 State Change CS_RING -> CS_TRANSMIT 2008-02-22 09:19:22 [DEBUG] switch_core_session.c:644 switch_core_session_signal_state_change() Kill sofia/local/72 [BREAK] 2008-02-22 09:19:22 [DEBUG] switch_core_state_machine.c:412 switch_core_session_run() (sofia/local/72) State TRANSMIT 2008-02-22 09:19:22 [DEBUG] mod_sofia.c:260 sofia_on_transmit() SOFIA TRANSMIT 2008-02-22 09:19:22 [DEBUG] switch_core_state_machine.c:198 switch_core_standard_on_transmit() Standard TRANSMIT 2008-02-22 09:19:22 [DEBUG] switch_ivr_originate.c:625 switch_ivr_originate() Raw Codec Activation Success L16@8000hz 1 channel 20ms recv 305 bytes from udp/[192.168.1.70]:5061 at 17:19:22.095673: ------------------------------------------------------------------------ SIP/2.0 100 Trying To: From: "7702" ;tag=2X26m95DaSKKF Call-ID: 2643c0c8-5c0d-122b-518b-00123f09e397 CSeq: 95732045 INVITE Via: SIP/2.0/UDP 192.168.1.101;branch=z9hG4bKDeac68H4gHH7S;rport=5060 Server: Linksys/SPA2002-3.1.9(d) Content-Length: 0 ------------------------------------------------------------------------ recv 331 bytes from udp/[192.168.1.70]:5061 at 17:19:22.122443: ------------------------------------------------------------------------ SIP/2.0 486 Busy Here To: ;tag=997284f1679e8b7ai1 From: "7702" ;tag=2X26m95DaSKKF Call-ID: 2643c0c8-5c0d-122b-518b-00123f09e397 CSeq: 95732045 INVITE Via: SIP/2.0/UDP 192.168.1.101;branch=z9hG4bKDeac68H4gHH7S;rport=5060 Server: Linksys/SPA2002-3.1.9(d) Content-Length: 0 ------------------------------------------------------------------------ send 322 bytes to udp/[192.168.1.70]:5061 at 17:19:22.122840: ------------------------------------------------------------------------ ACK sip:72@192.168.1.70:5061 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.101;rport;branch=z9hG4bKDeac68H4gHH7S Max-Forwards: 70 From: "7702" ;tag=2X26m95DaSKKF To: ;tag=997284f1679e8b7ai1 Call-ID: 2643c0c8-5c0d-122b-518b-00123f09e397 CSeq: 95732045 ACK Content-Length: 0 ------------------------------------------------------------------------ 2008-02-22 09:19:22 [DEBUG] sofia.c:288 sofia_event_callback() event [nua_r_invite] status [486][Busy Here] session: sofia/local/72 2008-02-22 09:19:22 [DEBUG] sofia.c:288 sofia_event_callback() event [nua_i_state] status [486][Busy Here] session: sofia/local/72 2008-02-22 09:19:22 [DEBUG] sofia.c:1391 sofia_handle_sip_i_state() Channel sofia/local/72 entering state [terminated] 2008-02-22 09:19:22 [NOTICE] sofia.c:1712 sofia_handle_sip_i_state() Hangup sofia/local/72 [CS_TRANSMIT] [USER_BUSY] 2008-02-22 09:19:22 [DEBUG] switch_channel.c:1071 switch_channel_perform_hangup() Kill sofia/local/72 [KILL] 2008-02-22 09:19:22 [DEBUG] switch_core_session.c:644 switch_core_session_signal_state_change() Kill sofia/local/72 [BREAK] 2008-02-22 09:19:22 [DEBUG] switch_ivr_originate.c:877 switch_ivr_originate() Originate Resulted in Error Cause: 17 [USER_BUSY] 2008-02-22 09:19:22 [ERR] glue.c:75 fdial_glue_dial() Originate Failed. Cause: USER_BUSY 2008-02-22 09:19:22 [DEBUG] mod_fdial.c:723 fdial_main_start_fdial_call() Calling the peer "sofia/local/72" failed (cause: USER_BUSY). 2008-02-22 09:19:22 [DEBUG] switch_core_state_machine.c:394 switch_core_session_run() (sofia/local/72) State HANGUP 2008-02-22 09:19:22 [DEBUG] mod_sofia.c:210 sofia_on_hangup() Channel sofia/local/72 hanging up, cause: USER_BUSY 2008-02-22 09:19:22 [DEBUG] switch_core_state_machine.c:45 switch_core_standard_on_hangup() Standard HANGUP sofia/local/72, cause: USER_BUSY 2008-02-22 09:19:22 [DEBUG] switch_core_session.c:702 switch_core_session_thread() Session 4 (sofia/local/72) Locked, Waiting on external entities 2008-02-22 09:19:22 [INFO] switch_core_session.c:708 switch_core_session_thread() Session 4 (sofia/local/72) Ended 2008-02-22 09:19:22 [NOTICE] switch_core_session.c:710 switch_core_session_thread() Close Channel sofia/local/72 [CS_HANGUP] 2008-02-22 09:19:22 [DEBUG] mod_call_forward.c:123 regnum_to_sip_uid() dest_num: 7704 2008-02-22 09:19:22 [DEBUG] mod_call_forward.c:143 regnum_to_sip_uid() dest_num matched with sip_uid: 4 2008-02-22 09:19:22 [DEBUG] mod_call_forward.c:640 check_cf() call forwarding not enabled for sip uid: 4 and cf_type: BUSY 2008-02-22 09:19:22 [DEBUG] switch_ivr.c:1620 switch_ivr_check_cf() Check_cf internal api call. status returned: 14, output: 2008-02-22 09:19:22 [DEBUG] mod_fdial.c:1056 fdial_function() Start incoming fdial call failed - Hangup member with cause "USER_BUSY"! 2008-02-22 09:19:22 [NOTICE] mod_fdial.c:1058 fdial_function() Hangup sofia/phone74/7702@192.168.1.101:5085 [CS_EXECUTE] [USER_BUSY] 2008-02-22 09:19:22 [DEBUG] switch_channel.c:1071 switch_channel_perform_hangup() Kill sofia/phone74/7702@192.168.1.101:5085 [KILL] 2008-02-22 09:19:22 [DEBUG] switch_core_session.c:644 switch_core_session_signal_state_change() Kill sofia/phone74/7702@192.168.1.101:5085 [BREAK] 2008-02-22 09:19:22 [DEBUG] mod_fdial.c:1395 fdial_function() The status of the last mod_fdial call was: error 2008-02-22 09:19:22 [DEBUG] switch_core_state_machine.c:394 switch_core_session_run() (sofia/phone74/7702@192.168.1.101:5085) State HANGUP 2008-02-22 09:19:22 [DEBUG] mod_sofia.c:210 sofia_on_hangup() Channel sofia/phone74/7702@192.168.1.101:5085 hanging up, cause: USER_BUSY 2008-02-22 09:19:22 [DEBUG] mod_sofia.c:234 sofia_on_hangup() Responding to INVITE with: 486 2008-02-22 09:19:22 [DEBUG] switch_core_state_machine.c:45 switch_core_standard_on_hangup() Standard HANGUP sofia/phone74/7702@192.168.1.101:5085, cause: USER_BUSY 2008-02-22 09:19:22 [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-22 09:19:22 [INFO] switch_core_session.c:708 switch_core_session_thread() Session 3 (sofia/phone74/7702@192.168.1.101:5085) Ended 2008-02-22 09:19:22 [NOTICE] switch_core_session.c:710 switch_core_session_thread() Close Channel sofia/phone74/7702@192.168.1.101:5085 [CS_HANGUP]