INVITE sip:7702@192.168.1.101:12000 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.101:5085;branch=z9hG4bK387551a0;rport From: ;tag=as5585c140 To: "7702" ;tag=Z6K0Xg39UBeFH Contact: Call-ID: 9f084620-5b77-122b-1690-00123f09e397 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 218 v=0 o=root 11691 11692 IN IP4 192.168.1.101 s=session c=IN IP4 192.168.1.101 t=0 0 m=audio 16388 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - ------------------------------------------------------------------------ send 876 bytes to udp/[192.168.1.101]:5085 at 23:29:06.012324: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.101:5085;branch=z9hG4bK387551a0;rport=5085 From: ;tag=as5585c140 To: "7702" ;tag=Z6K0Xg39UBeFH Call-ID: 9f084620-5b77-122b-1690-00123f09e397 CSeq: 102 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 Min-SE: 120 Content-Type: application/sdp Content-Disposition: session Content-Length: 269 v=0 o=Comdasysb2bua 428478712116833270 4263274304881350465 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 417 bytes from udp/[192.168.1.70]:5061 at 23:29:06.015824: ------------------------------------------------------------------------ ACK sip:fmc@192.168.1.101:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.1.70:5061;branch=z9hG4bK-6aa62b08;rport From: Traun Leyden ;tag=30041628563c721co1 To: ;tag=cUm1emmcpBjUH Call-ID: e1d30018-3cf110ec@192.168.1.70 CSeq: 101 ACK Max-Forwards: 70 Contact: Traun Leyden User-Agent: Linksys/SPA2002-3.1.9(d) Content-Length: 0 ------------------------------------------------------------------------ recv 382 bytes from udp/[192.168.1.101]:5085 at 23:29:06.016126: ------------------------------------------------------------------------ ACK sip:7702@192.168.1.101:12000 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.101:5085;branch=z9hG4bK28bb4464;rport From: ;tag=as5585c140 To: "7702" ;tag=Z6K0Xg39UBeFH Contact: Call-ID: 9f084620-5b77-122b-1690-00123f09e397 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 ------------------------------------------------------------------------ 2008-02-21 15:29:05 [DEBUG] sofia.c:1391 sofia_handle_sip_i_state() Channel sofia/local/74 entering state [ready] 2008-02-21 15:29:05 [DEBUG] sofia.c:1395 sofia_handle_sip_i_state() Remote SDP: v=0 o=74 67141295 743105015 IN IP4 192.168.1.101 s=- c=IN IP4 192.168.1.101 t=0 0 m=audio 8000 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 2008-02-21 15:29:05 [DEBUG] sofia_glue.c:1427 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMA:8:8000]/[PCMA:8:8000] 2008-02-21 15:29:05 [INFO] sofia_glue.c:1502 sofia_glue_negotiate_sdp() m->m_mode == sdp_sendrecv, inactive,sendonly = 0 2008-02-21 15:29:05 [DEBUG] sofia_glue.c:1033 sofia_glue_tech_set_codec() Set Codec sofia/local/74 PCMA/8000 20 ms 160 samples 2008-02-21 15:29:05 [DEBUG] sofia_glue.c:1391 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101 2008-02-21 15:29:05 [DEBUG] sofia_glue.c:1631 sofia_glue_negotiate_sdp() neither sendonly or inactive 2008-02-21 15:29:05 [DEBUG] sofia_glue.c:1662 sofia_glue_negotiate_sdp() TFLAG_SIP_HOLD not set, doing nothing 2008-02-21 15:29:05 [DEBUG] sofia.c:1677 sofia_handle_sip_i_state() We allow SDP within SIP ACK for "sofia/local/74". Set REINVITE flag... 2008-02-21 15:29:05 [DEBUG] sofia_glue.c:1099 sofia_glue_activate_rtp() AUDIO RTP [sofia/local/74] 192.168.1.101:16386->192.168.1.101:8000 codec: 8 ms: 20 2008-02-21 15:29:05 [DEBUG] switch_rtp.c:546 switch_rtp_create() Starting timer [soft] 160 bytes per 20000ms 2008-02-21 15:29:05 [DEBUG] switch_channel.c:1219 switch_channel_perform_mark_answered() Kill sofia/phone74/7702@192.168.1.101:5085 [BREAK] 2008-02-21 15:29:05 [NOTICE] sofia.c:1680 sofia_handle_sip_i_state() Channel [sofia/local/74] has been answered 2008-02-21 15:29:05 [DEBUG] sofia_glue.c:1099 sofia_glue_activate_rtp() AUDIO RTP [sofia/phone74/7702@192.168.1.101:5085] 192.168.1.101:16388->192.168.1.101:13852 codec: 8 ms: 20 2008-02-21 15:29:05 [DEBUG] switch_rtp.c:546 switch_rtp_create() Starting timer [soft] 160 bytes per 20000ms 2008-02-21 15:29:05 [DEBUG] mod_sofia.c:317 sofia_answer_channel() Local SDP sofia/phone74/7702@192.168.1.101:5085: v=0 o=Comdasysb2bua 1203620157 1203620158 IN IP4 192.168.1.101 s=Comdasysb2bua c=IN IP4 192.168.1.101 t=0 0 m=audio 16388 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 2008-02-21 15:29:05 [DEBUG] switch_core_session.c:347 switch_core_session_receive_message() Kill sofia/phone74/7702@192.168.1.101:5085 [BREAK] 2008-02-21 15:29:05 [NOTICE] switch_ivr_originate.c:825 switch_ivr_originate() Channel [sofia/phone74/7702@192.168.1.101:5085] has been answered 2008-02-21 15:29:05 [DEBUG] switch_ivr_originate.c:846 switch_ivr_originate() Originate Resulted in Success: [sofia/local/74] 2008-02-21 15:29:05 [INFO] mod_fdial.c:581 fdial_main_start_fdial_call() Calling peer successfully. Start a new fdial session... 2008-02-21 15:29:05 [DEBUG] glue.c:108 fdial_glue_set_bridge_variables() Setting bridge variables for transfer between "sofia/phone74/7702@192.168.1.101:5085" and "sofia/local/74"... 2008-02-21 15:29:05 [DEBUG] alien.c:71 fdial_alien_add() (alien): "#0/74@local" -- Adding alien to the given list ... 2008-02-21 15:29:05 [DEBUG] member.c:143 fdial_member_create_thread() (wlan): "#0/74@local" -- creating member thread. 2008-02-21 15:29:05 [DEBUG] member.c:514 fdial_member_main() (alien): "#1/74@local" -- Member loop entered for channel: "sofia/phone74/7702@192.168.1.101:5085". Initializing some stuff ... 2008-02-21 15:29:05 [DEBUG] member.c:593 fdial_member_main() (alien): "#1/74@local" -- Closing the old member is not set in member! Continue ... 2008-02-21 15:29:05 [DEBUG] glue.c:281 fdial_glue_initalize_codec() Raw Codec Activation Success L16@8000hz 1 channel 20ms 2008-02-21 15:29:05 [DEBUG] member.c:1653 fdial_member_set_sln_codec() (alien): "#1/74@local" -- orig read codec settings (PCMA) : sps: 8000, mpf: 20000, spf: 160, bpf: 320, ebpf: 160, noc: 1, pfpp: 1, mfpp: 1 2008-02-21 15:29:05 [DEBUG] member.c:1665 fdial_member_set_sln_codec() (alien): "#1/74@local" -- new read codec settings (L16): sps: 8000, mpf: 20000, spf: 160, bpf: 320, ebpf: 320, noc: 1, pfpp: 1, mfpp: 1 2008-02-21 15:29:05 [DEBUG] glue.c:281 fdial_glue_initalize_codec() Raw Codec Activation Success L16@8000hz 1 channel 20ms 2008-02-21 15:29:05 [DEBUG] member.c:1706 fdial_member_set_sln_codec() (alien): "#1/74@local" -- orig write codec settings (PCMA): sps: 8000, mpf: 20000, spf: 160, bpf: 320, ebpf: 160, noc: 1, pfpp: 1, mfpp: 1 2008-02-21 15:29:05 [DEBUG] member.c:1718 fdial_member_set_sln_codec() (alien): "#1/74@local" -- new write codec settings (L16): sps: 8000, mpf: 20000, spf: 160, bpf: 320, ebpf: 320, noc: 1, pfpp: 1, mfpp: 1 2008-02-21 15:29:05 [DEBUG] member.c:139 fdial_member_create_thread() (alien): "#1/74@local" -- creating outgoing member thread. 2008-02-21 15:29:05 [INFO] member.c:621 fdial_member_main() (alien): "#1/74@local" -- Starting member loop ... 2008-02-21 15:29:05 [INFO] member.c:827 fdial_member_loop() Peer of member "#1" (type: alien) has answered. Call is up now ... 2008-02-21 15:29:05 [DEBUG] sofia.c:1391 sofia_handle_sip_i_state() Channel sofia/phone74/7702@192.168.1.101:5085 entering state [completed] 2008-02-21 15:29:05 [DEBUG] sofia.c:1391 sofia_handle_sip_i_state() Channel sofia/phone74/7702@192.168.1.101:5085 entering state [ready] 2008-02-21 15:29:05 [DEBUG] sofia.c:1391 sofia_handle_sip_i_state() Channel sofia/phone74/7702@192.168.1.101:5085 entering state [completed] 2008-02-21 15:29:05 [DEBUG] sofia.c:1395 sofia_handle_sip_i_state() Remote SDP: v=0 o=root 11691 11692 IN IP4 192.168.1.101 s=session c=IN IP4 192.168.1.101 t=0 0 m=audio 16384 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - 2008-02-21 15:29:05 [DEBUG] sofia_glue.c:1427 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMA:8:8000]/[PCMA:8:8000] 2008-02-21 15:29:05 [INFO] sofia_glue.c:1502 sofia_glue_negotiate_sdp() m->m_mode == sdp_sendrecv, inactive,sendonly = 0 2008-02-21 15:29:05 [DEBUG] sofia_glue.c:998 sofia_glue_tech_set_codec() Already using PCMA 2008-02-21 15:29:05 [DEBUG] sofia_glue.c:1391 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101 2008-02-21 15:29:05 [DEBUG] sofia_glue.c:1631 sofia_glue_negotiate_sdp() neither sendonly or inactive 2008-02-21 15:29:05 [DEBUG] sofia_glue.c:1662 sofia_glue_negotiate_sdp() TFLAG_SIP_HOLD not set, doing nothing 2008-02-21 15:29:05 [DEBUG] sofia_glue.c:1099 sofia_glue_activate_rtp() AUDIO RTP [sofia/phone74/7702@192.168.1.101:5085] 192.168.1.101:16388->192.168.1.101:16384 codec: 8 ms: 20 2008-02-21 15:29:05 [DEBUG] sofia.c:1605 sofia_handle_sip_i_state() Processing Reinvite 2008-02-21 15:29:05 [DEBUG] sofia.c:1391 sofia_handle_sip_i_state() Channel sofia/phone72/7704@192.168.1.101:5085 entering state [ready] 2008-02-21 15:29:05 [DEBUG] sofia.c:1395 sofia_handle_sip_i_state() Remote SDP: v=0 o=root 11691 11691 IN IP4 192.168.1.101 s=session c=IN IP4 192.168.1.101 t=0 0 m=audio 14044 RTP/AVP 3 0 8 101 a=rtpmap:3 GSM/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - 2008-02-21 15:29:05 [DEBUG] sofia_glue.c:1427 sofia_glue_negotiate_sdp() Audio Codec Compare [GSM:3:8000]/[PCMA:8:8000] 2008-02-21 15:29:05 [DEBUG] sofia_glue.c:1427 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMU:0:8000]/[PCMA:8:8000] 2008-02-21 15:29:05 [DEBUG] sofia_glue.c:1427 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMA:8:8000]/[PCMA:8:8000] 2008-02-21 15:29:05 [INFO] sofia_glue.c:1502 sofia_glue_negotiate_sdp() m->m_mode == sdp_sendrecv, inactive,sendonly = 0 2008-02-21 15:29:05 [DEBUG] sofia_glue.c:1033 sofia_glue_tech_set_codec() Set Codec sofia/phone72/7704@192.168.1.101:5085 PCMA/8000 20 ms 160 samples 2008-02-21 15:29:05 [DEBUG] sofia_glue.c:1391 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101 2008-02-21 15:29:05 [DEBUG] sofia_glue.c:1631 sofia_glue_negotiate_sdp() neither sendonly or inactive 2008-02-21 15:29:05 [DEBUG] sofia_glue.c:1662 sofia_glue_negotiate_sdp() TFLAG_SIP_HOLD not set, doing nothing 2008-02-21 15:29:05 [DEBUG] sofia.c:1677 sofia_handle_sip_i_state() We allow SDP within SIP ACK for "sofia/phone72/7704@192.168.1.101:5085". Set REINVITE flag... 2008-02-21 15:29:05 [DEBUG] sofia_glue.c:1099 sofia_glue_activate_rtp() AUDIO RTP [sofia/phone72/7704@192.168.1.101:5085] 192.168.1.101:16384->192.168.1.101:14044 codec: 8 ms: 20 2008-02-21 15:29:05 [DEBUG] switch_rtp.c:546 switch_rtp_create() Starting timer [soft] 160 bytes per 20000ms 2008-02-21 15:29:05 [DEBUG] switch_channel.c:1219 switch_channel_perform_mark_answered() Kill sofia/local/72@192.168.1.101:5060 [BREAK] 2008-02-21 15:29:05 [NOTICE] sofia.c:1680 sofia_handle_sip_i_state() Channel [sofia/phone72/7704@192.168.1.101:5085] has been answered 2008-02-21 15:29:05 [DEBUG] sofia.c:1391 sofia_handle_sip_i_state() Channel sofia/phone74/7702@192.168.1.101:5085 entering state [ready] 2008-02-21 15:29:05 [DEBUG] sofia_glue.c:1099 sofia_glue_activate_rtp() AUDIO RTP [sofia/local/72@192.168.1.101:5060] 192.168.1.101:16390->192.168.1.70:16468 codec: 0 ms: 20 2008-02-21 15:29:05 [DEBUG] switch_rtp.c:546 switch_rtp_create() Starting timer [soft] 160 bytes per 20000ms 2008-02-21 15:29:05 [DEBUG] mod_sofia.c:317 sofia_answer_channel() Local SDP sofia/local/72@192.168.1.101:5060: v=0 o=Comdasysb2bua 1203620155 1203620156 IN IP4 192.168.1.101 s=Comdasysb2bua c=IN IP4 192.168.1.101 t=0 0 m=audio 16390 RTP/AVP 0 101 13 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=rtpmap:13 CN/8000 a=ptime:20 2008-02-21 15:29:05 [DEBUG] switch_core_session.c:347 switch_core_session_receive_message() Kill sofia/local/72@192.168.1.101:5060 [BREAK] 2008-02-21 15:29:05 [NOTICE] switch_ivr_originate.c:825 switch_ivr_originate() Channel [sofia/local/72@192.168.1.101:5060] has been answered 2008-02-21 15:29:05 [DEBUG] switch_ivr_originate.c:846 switch_ivr_originate() Originate Resulted in Success: [sofia/phone72/7704@192.168.1.101:5085] 2008-02-21 15:29:05 [INFO] mod_fdial.c:581 fdial_main_start_fdial_call() Calling peer successfully. Start a new fdial session... 2008-02-21 15:29:05 [DEBUG] glue.c:108 fdial_glue_set_bridge_variables() Setting bridge variables for transfer between "sofia/local/72@192.168.1.101:5060" and "sofia/phone72/7704@192.168.1.101:5085"... 2008-02-21 15:29:05 [DEBUG] alien.c:71 fdial_alien_add() (alien): "#0/72@local" -- Adding alien to the given list ... 2008-02-21 15:29:05 [DEBUG] member.c:143 fdial_member_create_thread() (alien): "#0/72@local" -- creating member thread. 2008-02-21 15:29:05 [DEBUG] member.c:514 fdial_member_main() (wlan): "#1/72@local" -- Member loop entered for channel: "sofia/local/72@192.168.1.101:5060". Initializing some stuff ... 2008-02-21 15:29:05 [DEBUG] mod_sofia.c:1036 sofia_receive_message() Setting the FMC UID "72" of call_id "e1d30018-3cf110ec@192.168.1.70" to sofia_sip 2008-02-21 15:29:05 [DEBUG] switch_core_session.c:347 switch_core_session_receive_message() Kill sofia/local/72@192.168.1.101:5060 [BREAK] 2008-02-21 15:29:05 [DEBUG] member.c:593 fdial_member_main() (wlan): "#1/72@local" -- Closing the old member is not set in member! Continue ... 2008-02-21 15:29:05 [DEBUG] glue.c:281 fdial_glue_initalize_codec() Raw Codec Activation Success L16@8000hz 1 channel 20ms 2008-02-21 15:29:05 [DEBUG] member.c:1653 fdial_member_set_sln_codec() (wlan): "#1/72@local" -- orig read codec settings (PCMU) : sps: 8000, mpf: 20000, spf: 160, bpf: 320, ebpf: 160, noc: 1, pfpp: 1, mfpp: 1 2008-02-21 15:29:05 [DEBUG] member.c:1665 fdial_member_set_sln_codec() (wlan): "#1/72@local" -- new read codec settings (L16): sps: 8000, mpf: 20000, spf: 160, bpf: 320, ebpf: 320, noc: 1, pfpp: 1, mfpp: 1 2008-02-21 15:29:05 [DEBUG] glue.c:281 fdial_glue_initalize_codec() Raw Codec Activation Success L16@8000hz 1 channel 20ms 2008-02-21 15:29:05 [DEBUG] member.c:1706 fdial_member_set_sln_codec() (wlan): "#1/72@local" -- orig write codec settings (PCMU): sps: 8000, mpf: 20000, spf: 160, bpf: 320, ebpf: 160, noc: 1, pfpp: 1, mfpp: 1 2008-02-21 15:29:05 [DEBUG] member.c:1718 fdial_member_set_sln_codec() (wlan): "#1/72@local" -- new write codec settings (L16): sps: 8000, mpf: 20000, spf: 160, bpf: 320, ebpf: 320, noc: 1, pfpp: 1, mfpp: 1 2008-02-21 15:29:05 [DEBUG] member.c:139 fdial_member_create_thread() (wlan): "#1/72@local" -- creating outgoing member thread. 2008-02-21 15:29:05 [INFO] member.c:621 fdial_member_main() (wlan): "#1/72@local" -- Starting member loop ... 2008-02-21 15:29:05 [INFO] member.c:827 fdial_member_loop() Peer of member "#1" (type: wlan) has answered. Call is up now ... 2008-02-21 15:29:05 [DEBUG] sofia.c:1391 sofia_handle_sip_i_state() Channel sofia/local/72@192.168.1.101:5060 entering state [completed] 2008-02-21 15:29:05 [DEBUG] controller.c:134 fdial_controller_thread_run() controller "74@local" loop started... 2008-02-21 15:29:05 [DEBUG] controller.c:147 fdial_controller_thread_run() setup timer successfully. interval: 10 samples: 80 2008-02-21 15:29:05 [DEBUG] member.c:514 fdial_member_main() (wlan): "#2/74@local" -- Member loop entered for channel: "sofia/local/74". Initializing some stuff ... 2008-02-21 15:29:05 [DEBUG] mod_sofia.c:1036 sofia_receive_message() Setting the FMC UID "74" of call_id "9fafe2e2-5b77-122b-1690-00123f09e397" to sofia_sip 2008-02-21 15:29:05 [DEBUG] switch_core_session.c:347 switch_core_session_receive_message() Kill sofia/local/74 [BREAK] 2008-02-21 15:29:05 [DEBUG] member.c:593 fdial_member_main() (wlan): "#2/74@local" -- Closing the old member is not set in member! Continue ... 2008-02-21 15:29:05 [DEBUG] glue.c:281 fdial_glue_initalize_codec() Raw Codec Activation Success L16@8000hz 1 channel 20ms 2008-02-21 15:29:05 [DEBUG] member.c:1175 fdial_member_outgoing_thread_run() (alien): "#1/74@local" -- setup outgoing timer successfully for member. interval: 20 samples: 160 2008-02-21 15:29:05 [INFO] member.c:1183 fdial_member_outgoing_thread_run() (alien): "#1/74@local" -- Starting member loop for outgoing packets... 2008-02-21 15:29:06 [DEBUG] controller.c:134 fdial_controller_thread_run() controller "72@local" loop started... 2008-02-21 15:29:06 [DEBUG] member.c:514 fdial_member_main() (alien): "#2/72@local" -- Member loop entered for channel: "sofia/phone72/7704@192.168.1.101:5085". Initializing some stuff ... 2008-02-21 15:29:06 [DEBUG] member.c:1175 fdial_member_outgoing_thread_run() (wlan): "#1/72@local" -- setup outgoing timer successfully for member. interval: 20 samples: 160 2008-02-21 15:29:06 [DEBUG] member.c:1653 fdial_member_set_sln_codec() (wlan): "#2/74@local" -- orig read codec settings (PCMA) : sps: 8000, mpf: 20000, spf: 160, bpf: 320, ebpf: 160, noc: 1, pfpp: 1, mfpp: 1 2008-02-21 15:29:06 [DEBUG] sofia.c:1391 sofia_handle_sip_i_state() Channel sofia/phone72/7704@192.168.1.101:5085 entering state [completed] 2008-02-21 15:29:06 [DEBUG] sofia.c:1395 sofia_handle_sip_i_state() Remote SDP: v=0 o=root 11691 11692 IN IP4 192.168.1.101 s=session c=IN IP4 192.168.1.101 t=0 0 m=audio 16388 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - 2008-02-21 15:29:06 [DEBUG] sofia_glue.c:1427 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMA:8:8000]/[PCMA:8:8000] 2008-02-21 15:29:06 [INFO] sofia_glue.c:1502 sofia_glue_negotiate_sdp() m->m_mode == sdp_sendrecv, inactive,sendonly = 0 2008-02-21 15:29:06 [DEBUG] sofia_glue.c:998 sofia_glue_tech_set_codec() Already using PCMA 2008-02-21 15:29:06 [DEBUG] sofia_glue.c:1391 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101 2008-02-21 15:29:06 [DEBUG] sofia_glue.c:1631 sofia_glue_negotiate_sdp() neither sendonly or inactive 2008-02-21 15:29:06 [DEBUG] sofia_glue.c:1662 sofia_glue_negotiate_sdp() TFLAG_SIP_HOLD not set, doing nothing 2008-02-21 15:29:06 [DEBUG] sofia_glue.c:1099 sofia_glue_activate_rtp() AUDIO RTP [sofia/phone72/7704@192.168.1.101:5085] 192.168.1.101:16384->192.168.1.101:16388 codec: 8 ms: 20 2008-02-21 15:29:06 [DEBUG] sofia.c:1605 sofia_handle_sip_i_state() Processing Reinvite 2008-02-21 15:29:06 [DEBUG] sofia.c:1391 sofia_handle_sip_i_state() Channel sofia/phone72/7704@192.168.1.101:5085 entering state [ready] 2008-02-21 15:29:06 [DEBUG] sofia.c:1391 sofia_handle_sip_i_state() Channel sofia/local/72@192.168.1.101:5060 entering state [ready] 2008-02-21 15:29:06 [DEBUG] controller.c:147 fdial_controller_thread_run() setup timer successfully. interval: 10 samples: 80 2008-02-21 15:29:06 [DEBUG] member.c:593 fdial_member_main() (alien): "#2/72@local" -- Closing the old member is not set in member! Continue ... 2008-02-21 15:29:06 [DEBUG] glue.c:281 fdial_glue_initalize_codec() Raw Codec Activation Success L16@8000hz 1 channel 20ms 2008-02-21 15:29:06 [DEBUG] member.c:1653 fdial_member_set_sln_codec() (alien): "#2/72@local" -- orig read codec settings (PCMA) : sps: 8000, mpf: 20000, spf: 160, bpf: 320, ebpf: 160, noc: 1, pfpp: 1, mfpp: 1 2008-02-21 15:29:06 [DEBUG] member.c:1665 fdial_member_set_sln_codec() (alien): "#2/72@local" -- new read codec settings (L16): sps: 8000, mpf: 20000, spf: 160, bpf: 320, ebpf: 320, noc: 1, pfpp: 1, mfpp: 1 2008-02-21 15:29:06 [DEBUG] glue.c:281 fdial_glue_initalize_codec() Raw Codec Activation Success L16@8000hz 1 channel 20ms 2008-02-21 15:29:06 [DEBUG] member.c:1706 fdial_member_set_sln_codec() (alien): "#2/72@local" -- orig write codec settings (PCMA): sps: 8000, mpf: 20000, spf: 160, bpf: 320, ebpf: 160, noc: 1, pfpp: 1, mfpp: 1 2008-02-21 15:29:06 [DEBUG] member.c:1718 fdial_member_set_sln_codec() (alien): "#2/72@local" -- new write codec settings (L16): sps: 8000, mpf: 20000, spf: 160, bpf: 320, ebpf: 320, noc: 1, pfpp: 1, mfpp: 1 2008-02-21 15:29:06 [DEBUG] member.c:139 fdial_member_create_thread() (alien): "#2/72@local" -- creating outgoing member thread. 2008-02-21 15:29:06 [INFO] member.c:621 fdial_member_main() (alien): "#2/72@local" -- Starting member loop ... 2008-02-21 15:29:06 [DEBUG] switch_core_io.c:290 switch_core_session_read_frame() Engaging Read Buffer at 320 bytes 2008-02-21 15:29:06 [INFO] member.c:1183 fdial_member_outgoing_thread_run() (wlan): "#1/72@local" -- Starting member loop for outgoing packets... 2008-02-21 15:29:06 [DEBUG] member.c:1665 fdial_member_set_sln_codec() (wlan): "#2/74@local" -- new read codec settings (L16): sps: 8000, mpf: 20000, spf: 160, bpf: 320, ebpf: 320, noc: 1, pfpp: 1, mfpp: 1 2008-02-21 15:29:06 [DEBUG] glue.c:281 fdial_glue_initalize_codec() Raw Codec Activation Success L16@8000hz 1 channel 20ms 2008-02-21 15:29:06 [DEBUG] member.c:1706 fdial_member_set_sln_codec() (wlan): "#2/74@local" -- orig write codec settings (PCMA): sps: 8000, mpf: 20000, spf: 160, bpf: 320, ebpf: 160, noc: 1, pfpp: 1, mfpp: 1 2008-02-21 15:29:06 [DEBUG] member.c:1718 fdial_member_set_sln_codec() (wlan): "#2/74@local" -- new write codec settings (L16): sps: 8000, mpf: 20000, spf: 160, bpf: 320, ebpf: 320, noc: 1, pfpp: 1, mfpp: 1 2008-02-21 15:29:06 [DEBUG] member.c:139 fdial_member_create_thread() (wlan): "#2/74@local" -- creating outgoing member thread. 2008-02-21 15:29:06 [INFO] member.c:621 fdial_member_main() (wlan): "#2/74@local" -- Starting member loop ... 2008-02-21 15:29:06 [DEBUG] member.c:1175 fdial_member_outgoing_thread_run() (alien): "#2/72@local" -- setup outgoing timer successfully for member. interval: 20 samples: 160 2008-02-21 15:29:06 [INFO] member.c:1183 fdial_member_outgoing_thread_run() (alien): "#2/72@local" -- Starting member loop for outgoing packets... 2008-02-21 15:29:06 [DEBUG] member.c:1175 fdial_member_outgoing_thread_run() (wlan): "#2/74@local" -- setup outgoing timer successfully for member. interval: 20 samples: 160 2008-02-21 15:29:06 [INFO] member.c:1183 fdial_member_outgoing_thread_run() (wlan): "#2/74@local" -- Starting member loop for outgoing packets... 2008-02-21 15:29:06 [DEBUG] switch_core_io.c:290 switch_core_session_read_frame() Engaging Read Buffer at 320 bytes 2008-02-21 15:29:06 [DEBUG] switch_core_io.c:290 switch_core_session_read_frame() Engaging Read Buffer at 320 bytes 2008-02-21 15:29:06 [DEBUG] switch_core_io.c:290 switch_core_session_read_frame() Engaging Read Buffer at 320 bytes recv 719 bytes from udp/[192.168.1.70]:5060 at 23:29:10.550954: ------------------------------------------------------------------------ REGISTER sip:192.168.1.101 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.70:5060;branch=z9hG4bK-2a0666d2;rport From: Traun Leyden ;tag=506cf7d6cdde25eo0 To: Traun Leyden Call-ID: b0afeb38-54a7810c@192.168.1.70 CSeq: 143234 REGISTER Max-Forwards: 70 Authorization: Digest username="73",realm="192.168.1.101",nonce="4dc3359f-483f-4db0-b137-34aa4ae87e63",uri="sip:192.168.1.101",algorithm=MD5,response="4965ec3ab540b1b20fa6eb0b2399c92f",qop=auth,nc=00000003,cnonce="b5704765" Contact: Traun Leyden ;expires=14 User-Agent: Linksys/SPA2002-3.1.9(d) Content-Length: 0 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura ------------------------------------------------------------------------ send 542 bytes to udp/[192.168.1.70]:5060 at 23:29:10.560967: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.70:5060;branch=z9hG4bK-2a0666d2;rport=5060 From: Traun Leyden ;tag=506cf7d6cdde25eo0 To: Traun Leyden ;tag=Fp0Bm56pD6mKm Call-ID: b0afeb38-54a7810c@192.168.1.70 CSeq: 143234 REGISTER Contact: Traun Leyden ;expires=14 User-Agent: ComdasysB2BUA1.0.0 (6357) Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO Supported: precondition, timer, pref Content-Length: 0 ------------------------------------------------------------------------ 2008-02-21 15:29:10 [DEBUG] sofia_reg.c:645 sofia_reg_handle_register() Register: From: [73@192.168.1.101] Contact: [Traun Leyden ] Expires: [14] 2008-02-21 15:29:12 [DEBUG] member.c:1891 fdial_member_handle_dtmf() (wlan): "#2/74@local" -- Member received a sign which is part of a feature code: "*" 2008-02-21 15:29:12 [DEBUG] member.c:1891 fdial_member_handle_dtmf() (wlan): "#2/74@local" -- Member received a sign which is part of a feature code: "*" recv 720 bytes from udp/[192.168.1.70]:5061 at 23:29:13.081727: ------------------------------------------------------------------------ REGISTER sip:192.168.1.101 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.70:5061;branch=z9hG4bK-e3914e8d;rport From: Traun Leyden ;tag=8bc68e8520e5eef6o1 To: Traun Leyden Call-ID: 4547ee3c-1a65b9d8@192.168.1.70 CSeq: 119650 REGISTER Max-Forwards: 70 Authorization: Digest username="72",realm="192.168.1.101",nonce="128f5d17-5031-47c1-97ae-8d43e7142c8e",uri="sip:192.168.1.101",algorithm=MD5,response="0c96871fa2a69b8075ff189655e1ee84",qop=auth,nc=00000005,cnonce="68685892" Contact: Traun Leyden ;expires=13 User-Agent: Linksys/SPA2002-3.1.9(d) Content-Length: 0 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura ------------------------------------------------------------------------ 2008-02-21 15:29:13 [DEBUG] sofia_reg.c:645 sofia_reg_handle_register() Register: From: [72@192.168.1.101] Contact: [Traun Leyden ] Expires: [13] send 543 bytes to udp/[192.168.1.70]:5061 at 23:29:13.097730: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.70:5061;branch=z9hG4bK-e3914e8d;rport=5061 From: Traun Leyden ;tag=8bc68e8520e5eef6o1 To: Traun Leyden ;tag=gZS4N0QtaFB6F Call-ID: 4547ee3c-1a65b9d8@192.168.1.70 CSeq: 119650 REGISTER Contact: Traun Leyden ;expires=13 User-Agent: ComdasysB2BUA1.0.0 (6357) Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO Supported: precondition, timer, pref Content-Length: 0 ------------------------------------------------------------------------ 2008-02-21 15:29:13 [DEBUG] member.c:1891 fdial_member_handle_dtmf() (wlan): "#2/74@local" -- Member received a sign which is part of a feature code: "4" 2008-02-21 15:29:14 [DEBUG] dtmf2.c:78 fdial_dtmf2_parse() (wlan): "#2/74@local" -- Received CONSULTATION sequence! 2008-02-21 15:29:14 [DEBUG] dtmf2.c:286 fdial_dtmf2_wait() (wlan): "#2/74@local" -- Waiting "1500000" microseconds for each dtmf 2008-02-21 15:29:16 [DEBUG] dtmf2.c:315 fdial_dtmf2_wait() (wlan): "#2/74@local" -- Member received dtmf "1" 2008-02-21 15:29:16 [DEBUG] dtmf2.c:315 fdial_dtmf2_wait() (wlan): "#2/74@local" -- Member received dtmf "8" 2008-02-21 15:29:17 [DEBUG] dtmf2.c:315 fdial_dtmf2_wait() (wlan): "#2/74@local" -- Member received dtmf "0" 2008-02-21 15:29:17 [DEBUG] dtmf2.c:315 fdial_dtmf2_wait() (wlan): "#2/74@local" -- Member received dtmf "0" 2008-02-21 15:29:18 [DEBUG] dtmf2.c:315 fdial_dtmf2_wait() (wlan): "#2/74@local" -- Member received dtmf "4" 2008-02-21 15:29:19 [DEBUG] dtmf2.c:315 fdial_dtmf2_wait() (wlan): "#2/74@local" -- Member received dtmf "6" 2008-02-21 15:29:19 [DEBUG] dtmf2.c:315 fdial_dtmf2_wait() (wlan): "#2/74@local" -- Member received dtmf "6" 2008-02-21 15:29:19 [DEBUG] dtmf2.c:315 fdial_dtmf2_wait() (wlan): "#2/74@local" -- Member received dtmf "4" 2008-02-21 15:29:20 [DEBUG] dtmf2.c:315 fdial_dtmf2_wait() (wlan): "#2/74@local" -- Member received dtmf "4" 2008-02-21 15:29:20 [DEBUG] dtmf2.c:315 fdial_dtmf2_wait() (wlan): "#2/74@local" -- Member received dtmf "1" 2008-02-21 15:29:21 [DEBUG] dtmf2.c:315 fdial_dtmf2_wait() (wlan): "#2/74@local" -- Member received dtmf "1" 2008-02-21 15:29:21 [DEBUG] dtmf2.c:315 fdial_dtmf2_wait() (wlan): "#2/74@local" -- Member received dtmf "*" 2008-02-21 15:29:22 [DEBUG] dtmf2.c:315 fdial_dtmf2_wait() (wlan): "#2/74@local" -- Member received dtmf "5" recv 719 bytes from udp/[192.168.1.70]:5060 at 23:29:22.569728: ------------------------------------------------------------------------ REGISTER sip:192.168.1.101 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.70:5060;branch=z9hG4bK-6c0395c3;rport From: Traun Leyden ;tag=506cf7d6cdde25eo0 To: Traun Leyden Call-ID: b0afeb38-54a7810c@192.168.1.70 CSeq: 143235 REGISTER Max-Forwards: 70 Authorization: Digest username="73",realm="192.168.1.101",nonce="4dc3359f-483f-4db0-b137-34aa4ae87e63",uri="sip:192.168.1.101",algorithm=MD5,response="99ce5e5d323c9f2a9eebcabd42fdbae7",qop=auth,nc=00000004,cnonce="b5704765" Contact: Traun Leyden ;expires=14 User-Agent: Linksys/SPA2002-3.1.9(d) Content-Length: 0 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura ------------------------------------------------------------------------ 2008-02-21 15:29:22 [DEBUG] sofia_reg.c:645 sofia_reg_handle_register() Register: From: [73@192.168.1.101] Contact: [Traun Leyden ] Expires: [14] send 542 bytes to udp/[192.168.1.70]:5060 at 23:29:22.588227: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.70:5060;branch=z9hG4bK-6c0395c3;rport=5060 From: Traun Leyden ;tag=506cf7d6cdde25eo0 To: Traun Leyden ;tag=H8jXQU8X7Q1rB Call-ID: b0afeb38-54a7810c@192.168.1.70 CSeq: 143235 REGISTER Contact: Traun Leyden ;expires=14 User-Agent: ComdasysB2BUA1.0.0 (6357) Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO Supported: precondition, timer, pref Content-Length: 0 ------------------------------------------------------------------------ 2008-02-21 15:29:22 [DEBUG] dtmf2.c:315 fdial_dtmf2_wait() (wlan): "#2/74@local" -- Member received dtmf "1" recv 720 bytes from udp/[192.168.1.70]:5061 at 23:29:24.112203: ------------------------------------------------------------------------ REGISTER sip:192.168.1.101 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.70:5061;branch=z9hG4bK-8b90089f;rport From: Traun Leyden ;tag=8bc68e8520e5eef6o1 To: Traun Leyden Call-ID: 4547ee3c-1a65b9d8@192.168.1.70 CSeq: 119651 REGISTER Max-Forwards: 70 Authorization: Digest username="72",realm="192.168.1.101",nonce="128f5d17-5031-47c1-97ae-8d43e7142c8e",uri="sip:192.168.1.101",algorithm=MD5,response="f49ce0cfdb31d07de37e972edfaa5af2",qop=auth,nc=00000006,cnonce="68685892" Contact: Traun Leyden ;expires=13 User-Agent: Linksys/SPA2002-3.1.9(d) Content-Length: 0 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura ------------------------------------------------------------------------ 2008-02-21 15:29:24 [DEBUG] sofia_reg.c:645 sofia_reg_handle_register() Register: From: [72@192.168.1.101] Contact: [Traun Leyden ] Expires: [13] send 543 bytes to udp/[192.168.1.70]:5061 at 23:29:24.123831: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.70:5061;branch=z9hG4bK-8b90089f;rport=5061 From: Traun Leyden ;tag=8bc68e8520e5eef6o1 To: Traun Leyden ;tag=jHcpSpS140QBQ Call-ID: 4547ee3c-1a65b9d8@192.168.1.70 CSeq: 119651 REGISTER Contact: Traun Leyden ;expires=13 User-Agent: ComdasysB2BUA1.0.0 (6357) Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO Supported: precondition, timer, pref Content-Length: 0 ------------------------------------------------------------------------ 2008-02-21 15:29:24 [DEBUG] dtmf2.c:333 fdial_dtmf2_wait() (wlan): "#2/74@local" -- Member has received dtmf string: "18004664411*51" 2008-02-21 15:29:24 [DEBUG] features2.c:88 fdial_features2_hold() (wlan): "#2/74@local" -- Hold the first alien ... 2008-02-21 15:29:24 [DEBUG] glue.c:143 fdial_glue_clean_bridge_variables() Cleaning bridge variables between "sofia/phone74/7702@192.168.1.101:5085" and "sofia/local/74"... 2008-02-21 15:29:24 [DEBUG] alien.c:101 fdial_alien_remove() (alien): "#1/74@local" -- Removing alien from the given list... 2008-02-21 15:29:24 [DEBUG] mod_sofia.c:802 sofia_receive_message() Hold sofia/phone74/7702@192.168.1.101:5085 (Disable RTP Timeout)... 2008-02-21 15:29:24 [DEBUG] switch_core_session.c:347 switch_core_session_receive_message() Kill sofia/phone74/7702@192.168.1.101:5085 [BREAK] 2008-02-21 15:29:24 [DEBUG] member.c:2044 fdial_member_hold() (alien): "#1/74@local" -- Hold the alien! 2008-02-21 15:29:24 [DEBUG] alien.c:71 fdial_alien_add() (alien): "#1/74@local" -- Adding alien to the given list ... 2008-02-21 15:29:24 [DEBUG] member.c:1963 fdial_member_transfer() (wlan): "#2/74@local" -- Transfer the member to "18004664411" (controller: 74@local) 2008-02-21 15:29:24 [DEBUG] switch_ivr.c:958 switch_ivr_session_transfer() sofia/local/74 State Change CS_TRANSMIT -> CS_RING 2008-02-21 15:29:24 [DEBUG] switch_core_session.c:644 switch_core_session_signal_state_change() Kill sofia/local/74 [BREAK] 2008-02-21 15:29:24 [DEBUG] switch_core_session.c:347 switch_core_session_receive_message() Kill sofia/local/74 [BREAK] 2008-02-21 15:29:24 [NOTICE] switch_ivr.c:964 switch_ivr_session_transfer() Transfer sofia/local/74 to XML[18004664411@default] 2008-02-21 15:29:24 [DEBUG] member.c:1891 fdial_member_handle_dtmf() (wlan): "#2/74@local" -- Member received a sign which is part of a feature code: "3" 2008-02-21 15:29:24 [DEBUG] member.c:1008 fdial_member_loop() (wlan): "#2/74@local" -- To few samples for member. required: 160 -- read: 80 . 2008-02-21 15:29:24 [INFO] member.c:773 fdial_member_loop() (wlan): "#2/74@local" -- Stopping member loop because channel is not ready! 2008-02-21 15:29:24 [DEBUG] member.c:1028 fdial_member_loop() (wlan): "#2/74@local" -- Set the original codec back to the member 2008-02-21 15:29:24 [DEBUG] member.c:1035 fdial_member_loop() (wlan): "#2/74@local" -- Waiting for outgoing thread of member... send 945 bytes to udp/[192.168.1.101]:5085 at 23:29:24.163773: ------------------------------------------------------------------------ INVITE sip:7702@192.168.1.101:5085 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.101:12002;rport;branch=z9hG4bK15t8SSy6S5Uvj Max-Forwards: 70 From: ;tag=0y6Hce2gN5SUH To: "7702" ;tag=as686e4acb Call-ID: 07a2943256bc08a702597a6f75224d34@192.168.1.101 CSeq: 95699946 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: 282 v=0 o=Comdasysb2bua 5314509551928708326 5744568003224613189 IN IP4 192.168.1.101 s=Comdasysb2bua c=IN IP4 192.168.1.101 t=0 0 m=audio 16388 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=sendonly a=ptime:20 ------------------------------------------------------------------------ 2008-02-21 15:29:24 [DEBUG] switch_core_state_machine.c:400 switch_core_session_run() (sofia/local/74) State RING 2008-02-21 15:29:24 [DEBUG] mod_sofia.c:115 sofia_on_ring() SOFIA RING 2008-02-21 15:29:24 [DEBUG] switch_core_state_machine.c:64 switch_core_standard_on_ring() Standard RING sofia/local/74 2008-02-21 15:29:24 [INFO] mod_dialplan_xml.c:217 dialplan_hunt() Processing 7702->18004664411! 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(18004664411) =~ /^(.*)%23(.*)$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(18004664411) =~ /^\*\*8([0-3])$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(18004664411) =~ /^\*\*81(\d+)$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(18004664411) =~ /^\*\*82(\d+)$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(18004664411) =~ /^\*\*83(\d+)$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(18004664411) =~ /^\*341\*$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(18004664411) =~ /^\*342\*$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(18004664411) =~ /^\*343\*$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(18004664411) =~ /^\*344\*$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(18004664411) =~ /^\*345\*$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(18004664411) =~ /^\*346\*$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(18004664411) =~ /^\*347\*$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(18004664411) =~ /^347$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(18004664411) =~ /^(\*241\*|\*21)$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(18004664411) =~ /^(\*242\*|\*22)$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(18004664411) =~ /^(\*242\*|\*23)$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(18004664411) =~ /^(\*244\*|\*24)$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(18004664411) =~ /^(\*245\*|\*25)$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(18004664411) =~ /^(\*246\*|\*26)$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${sip_req_port}(12002) =~ /^1[23][0-9]{3}$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${fmc_id}(74) =~ /^$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${sip_req_port}(12002) =~ /^1[23][0-9]{3}$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${fmc_id}(74) =~ /^$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${sip_req_port}(12002) =~ /^1[23][0-9]{3}$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${fmc_id}(74) =~ /^$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions caller_id_number(7702) =~ /^72$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions caller_id_number(7702) =~ /^6789$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions caller_id_number(7702) =~ /^6789$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${fmc_id}(74) =~ /^72$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions caller_id_number(7702) =~ /^73$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions caller_id_number(7702) =~ /^6799$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions caller_id_number(7702) =~ /^6799$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${fmc_id}(74) =~ /^73$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions caller_id_number(7702) =~ /^74$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions caller_id_number(7702) =~ /^6799$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions caller_id_number(7702) =~ /^6799$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${fmc_id}(74) =~ /^74$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${fmc_member_type}(wlan) =~ /^gsm$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${fmc_id}(74) =~ /^72$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${fmc_id}(74) =~ /^73$/ 2008-02-21 15:29:24 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2008-02-21 15:29:24 [INFO] switch_core_state_machine.c:111 switch_core_standard_on_ring() No Route, Aborting 2008-02-21 15:29:24 [NOTICE] switch_core_state_machine.c:112 switch_core_standard_on_ring() Hangup sofia/local/74 [CS_RING] [NO_ROUTE_DESTINATION] 2008-02-21 15:29:24 [DEBUG] switch_channel.c:1071 switch_channel_perform_hangup() Kill sofia/local/74 [KILL] 2008-02-21 15:29:24 [DEBUG] switch_core_session.c:644 switch_core_session_signal_state_change() Kill sofia/local/74 [BREAK] 2008-02-21 15:29:24 [DEBUG] switch_core_state_machine.c:394 switch_core_session_run() (sofia/local/74) State HANGUP 2008-02-21 15:29:24 [DEBUG] mod_sofia.c:210 sofia_on_hangup() Channel sofia/local/74 hanging up, cause: NO_ROUTE_DESTINATION 2008-02-21 15:29:24 [DEBUG] mod_sofia.c:227 sofia_on_hangup() Sending BYE to sofia/local/74 2008-02-21 15:29:24 [DEBUG] switch_core_state_machine.c:45 switch_core_standard_on_hangup() Standard HANGUP sofia/local/74, cause: NO_ROUTE_DESTINATION 2008-02-21 15:29:24 [DEBUG] switch_core_session.c:702 switch_core_session_thread() Session 4 (sofia/local/74) Locked, Waiting on external entities 2008-02-21 15:29:24 [DEBUG] sofia.c:288 sofia_event_callback() event [nua_i_state] status [0][INVITE sent] session: sofia/phone74/7702@192.168.1.101:5085 2008-02-21 15:29:24 [DEBUG] sofia.c:1391 sofia_handle_sip_i_state() Channel sofia/phone74/7702@192.168.1.101:5085 entering state [calling] recv 754 bytes from udp/[192.168.1.101]:5085 at 23:29:24.169592: ------------------------------------------------------------------------ INVITE sip:7702@192.168.1.101:12000 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.101:5085;branch=z9hG4bK5dd4cc8c;rport From: ;tag=as5585c140 To: "7702" ;tag=Z6K0Xg39UBeFH Contact: Call-ID: 9f084620-5b77-122b-1690-00123f09e397 CSeq: 103 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 265 v=0 o=root 11691 11693 IN IP4 192.168.1.101 s=session c=IN IP4 192.168.1.101 t=0 0 m=audio 14044 RTP/AVP 3 0 8 101 a=rtpmap:3 GSM/8000 2008-02-21 15:29:24 [INFO] member.c:1276 fdial_member_outgoing_thread_run() (wlan): "#2/74@local" -- Member loop ended for outgoing packets... send 535 bytes to udp/[192.168.1.101]:5068 at 23:29:24.168327: a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - ------------------------------------------------------------------------ send 876 bytes to udp/[192.168.1.101]:5085 at 23:29:24.188744: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.101:5085;branch=z9hG4bK5dd4cc8c;rport=5085 From: ;tag=as5585c140 To: "7702" ;tag=Z6K0Xg39UBeFH Call-ID: 9f084620-5b77-122b-1690-00123f09e397 CSeq: 103 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 Min-SE: 120 Content-Type: application/sdp Content-Disposition: session Content-Length: 269 v=0 o=Comdasysb2bua 428478712116833270 4263274304881350465 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 382 bytes from udp/[192.168.1.101]:5085 at 23:29:24.316167: ------------------------------------------------------------------------ ACK sip:7702@192.168.1.101:12000 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.101:5085;branch=z9hG4bK60fcf3d1;rport From: ;tag=as5585c140 To: "7702" ;tag=Z6K0Xg39UBeFH Contact: Call-ID: 9f084620-5b77-122b-1690-00123f09e397 CSeq: 103 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 ------------------------------------------------------------------------ ------------------------------------------------------------------------ BYE sip:74@192.168.1.101:5068 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.101;rport;branch=z9hG4bK7N9UDrQ85DSHc Max-Forwards: 70 From: "7702" ;tag=D4DtgF5FKm8DD To: ;tag=hgivx Call-ID: 9fafe2e2-5b77-122b-1690-00123f09e397 CSeq: 95699935 BYE 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 Content-Length: 0 ------------------------------------------------------------------------ recv 296 bytes from udp/[192.168.1.101]:5068 at 23:29:24.320610: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.101;rport=5060;branch=z9hG4bK7N9UDrQ85DSHc To: ;tag=hgivx From: "7702" ;tag=D4DtgF5FKm8DD Call-ID: 9fafe2e2-5b77-122b-1690-00123f09e397 CSeq: 95699935 BYE Server: Twinkle/1.1 Content-Length: 0 ------------------------------------------------------------------------ 2008-02-21 15:29:24 [DEBUG] member.c:1038 fdial_member_loop() (wlan): "#2/74@local" -- Outgoing thread of member ended. 2008-02-21 15:29:24 [DEBUG] member.c:1042 fdial_member_loop() (wlan): "#2/74@local" -- Member locked, Waiting on external entities. 2008-02-21 15:29:24 [INFO] member.c:1060 fdial_member_loop() (wlan): "#2/74@local" -- member loop ended - controller: "74@local" controller running: running - channel ready: no - channel state: CS_RING - hangup cause: NO_ROUTE_DESTINATION - close flag set: no - channel transfer flag set: yes 2008-02-21 15:29:24 [DEBUG] member.c:1080 fdial_member_loop() (wlan): "#2/74@local" -- As the member transfer, the controller "74@local" should wait "5" seconds, because it could be, that the member transfer to the same controller back! 2008-02-21 15:29:24 [DEBUG] member.c:1372 fdial_member_cleanup_core_member() (wlan): "#2/74@local" -- Member ended 2008-02-21 15:29:24 [INFO] member.c:1153 fdial_member_loop() __ END OF CORE MEMBER LOOP __ 2008-02-21 15:29:24 [DEBUG] sofia.c:1391 sofia_handle_sip_i_state() Channel sofia/phone72/7704@192.168.1.101:5085 entering state [completed] 2008-02-21 15:29:24 [DEBUG] sofia.c:1395 sofia_handle_sip_i_state() Remote SDP: v=0 o=root 11691 11693 IN IP4 192.168.1.101 s=session c=IN IP4 192.168.1.101 t=0 0 m=audio 14044 RTP/AVP 3 0 8 101 a=rtpmap:3 GSM/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - 2008-02-21 15:29:24 [DEBUG] sofia_glue.c:1427 sofia_glue_negotiate_sdp() Audio Codec Compare [GSM:3:8000]/[PCMA:8:8000] 2008-02-21 15:29:24 [DEBUG] sofia_glue.c:1427 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMU:0:8000]/[PCMA:8:8000] 2008-02-21 15:29:24 [DEBUG] sofia_glue.c:1427 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMA:8:8000]/[PCMA:8:8000] 2008-02-21 15:29:24 [INFO] sofia_glue.c:1502 sofia_glue_negotiate_sdp() m->m_mode == sdp_sendrecv, inactive,sendonly = 0 2008-02-21 15:29:24 [DEBUG] sofia_glue.c:998 sofia_glue_tech_set_codec() Already using PCMA 2008-02-21 15:29:24 [DEBUG] sofia_glue.c:1391 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101 2008-02-21 15:29:24 [DEBUG] sofia_glue.c:1631 sofia_glue_negotiate_sdp() neither sendonly or inactive 2008-02-21 15:29:24 [DEBUG] sofia_glue.c:1662 sofia_glue_negotiate_sdp() TFLAG_SIP_HOLD not set, doing nothing 2008-02-21 15:29:24 [DEBUG] sofia_glue.c:1099 sofia_glue_activate_rtp() AUDIO RTP [sofia/phone72/7704@192.168.1.101:5085] 192.168.1.101:16384->192.168.1.101:14044 codec: 8 ms: 20 2008-02-21 15:29:24 [DEBUG] sofia.c:1605 sofia_handle_sip_i_state() Processing Reinvite 2008-02-21 15:29:24 [DEBUG] sofia.c:1391 sofia_handle_sip_i_state() Channel sofia/phone72/7704@192.168.1.101:5085 entering state [ready] 2008-02-21 15:29:24 [INFO] switch_core_session.c:708 switch_core_session_thread() Session 4 (sofia/local/74) Ended 2008-02-21 15:29:24 [NOTICE] switch_core_session.c:710 switch_core_session_thread() Close Channel sofia/local/74 [CS_HANGUP] recv 728 bytes from udp/[192.168.1.101]:5085 at 23:29:24.221368: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.101:12002;rport;branch=z9hG4bK15t8SSy6S5Uvj;received=192.168.1.101 From: ;tag=0y6Hce2gN5SUH To: "7702" ;tag=as686e4acb Call-ID: 07a2943256bc08a702597a6f75224d34@192.168.1.101 CSeq: 95699946 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Max-Forwards: 70 Contact: Content-Type: application/sdp Content-Length: 218 v=0 o=root 11691 11693 IN IP4 192.168.1.101 s=session c=IN IP4 192.168.1.101 t=0 0 m=audio 16384 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - ------------------------------------------------------------------------ send 342 bytes to udp/[192.168.1.101]:5085 at 23:29:24.453906: ------------------------------------------------------------------------ ACK sip:7702@192.168.1.101:5085 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.101:12002;rport;branch=z9hG4bK2em1UmFaQejFe Max-Forwards: 70 From: ;tag=0y6Hce2gN5SUH To: "7702" ;tag=as686e4acb Call-ID: 07a2943256bc08a702597a6f75224d34@192.168.1.101 CSeq: 95699946 ACK Content-Length: 0 ------------------------------------------------------------------------ 2008-02-21 15:29:24 [DEBUG] sofia.c:1391 sofia_handle_sip_i_state() Channel sofia/phone74/7702@192.168.1.101:5085 entering state [ready] 2008-02-21 15:29:24 [DEBUG] sofia.c:1395 sofia_handle_sip_i_state() Remote SDP: v=0 o=root 11691 11693 IN IP4 192.168.1.101 s=session c=IN IP4 192.168.1.101 t=0 0 m=audio 16384 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - 2008-02-21 15:29:24 [DEBUG] sofia_glue.c:1427 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMA:8:8000]/[PCMA:8:8000] 2008-02-21 15:29:24 [INFO] sofia_glue.c:1502 sofia_glue_negotiate_sdp() m->m_mode == sdp_sendrecv, inactive,sendonly = 0 2008-02-21 15:29:24 [DEBUG] sofia_glue.c:998 sofia_glue_tech_set_codec() Already using PCMA 2008-02-21 15:29:24 [DEBUG] sofia_glue.c:1391 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101 2008-02-21 15:29:24 [DEBUG] sofia_glue.c:1631 sofia_glue_negotiate_sdp() neither sendonly or inactive 2008-02-21 15:29:24 [DEBUG] sofia_glue.c:1662 sofia_glue_negotiate_sdp() TFLAG_SIP_HOLD not set, doing nothing 2008-02-21 15:29:24 [DEBUG] sofia.c:1677 sofia_handle_sip_i_state() We allow SDP within SIP ACK for "sofia/phone74/7702@192.168.1.101:5085". Set REINVITE flag... 2008-02-21 15:29:24 [DEBUG] sofia_glue.c:1099 sofia_glue_activate_rtp() AUDIO RTP [sofia/phone74/7702@192.168.1.101:5085] 192.168.1.101:16388->192.168.1.101:16384 codec: 8 ms: 20