Asterisk SVN-trunk-r38389M, Copyright (C) 1999 - 2006 Digium, Inc. and others. Created by Mark Spencer Asterisk comes with ABSOLUTELY NO WARRANTY; type 'show warranty' for details. This is free software, with components licensed under the GNU General Public License version 2 and other licenses; you are welcome to redistribute it under certain conditions. Type 'show license' for details. ========================================================================= Connected to Asterisk SVN-trunk-r38389M currently running on my (pid = 32318) my*CLI> Verbosity is at least 100 my*CLI> [2006-08-01 17:06:26] DEBUG[32324]: sched.c:331 ast_sched_runq: ast_sched_runq() [2006-08-01 17:06:26] DEBUG[32324]: sched.c:152 ast_sched_wait: ast_sched_wait() my*CLI> [2006-08-01 17:06:27] DEBUG[32324]: sched.c:331 ast_sched_runq: ast_sched_runq() [2006-08-01 17:06:27] DEBUG[32324]: sched.c:152 ast_sched_wait: ast_sched_wait() my*CLI> [2006-08-01 17:06:28] DEBUG[32324]: sched.c:331 ast_sched_runq: ast_sched_runq() [2006-08-01 17:06:28] DEBUG[32324]: sched.c:152 ast_sched_wait: ast_sched_wait() my*CLI> [2006-08-01 17:06:29] DEBUG[32324]: sched.c:331 ast_sched_runq: ast_sched_runq() [2006-08-01 17:06:29] DEBUG[32324]: sched.c:152 ast_sched_wait: ast_sched_wait() my*CLI> <-- SIP read from AT320_IP:5060: INVITE sip:1005@pbx.varna.net SIP/2.0 Via: SIP/2.0/UDP AT320_IP:5060;branch=z9hG4bKmg1ook9mDwOyYSkw Max-Forwards: 70 User-Agent: phone V1.49.002 CFG0 From: "1070" ;tag=pqXcAkXWW76hTMgN To: "1005" Call-ID: bkQ0wWXareCYQjP0@AT320_IP Contact: CSeq: 1 INVITE Supported: replaces Content-Type: application/sdp Content-Length: 294 v=0 o=- 84017063 65751352 IN IP4 AT320_IP s=SIP CALL c=IN IP4 AT320_IP t=0 0 m=audio 10722 RTP/AVP 8 0 18 4 3 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=rtpmap:4 G723/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 0: INVITE sip:1005@pbx.varna.net SIP/2.0 (37) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP AT320_IP:5060;branch=z9hG4bKmg1ook9mDwOyYSkw (67) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 2: Max-Forwards: 70 (16) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 3: User-Agent: phone V1.49.002 CFG0 (33) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 4: From: "1070" ;tag=pqXcAkXWW76hTMgN (58) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 5: To: "1005" (35) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 6: Call-ID: bkQ0wWXareCYQjP0@AT320_IP (40) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 7: Contact: (39) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 8: CSeq: 1 INVITE (14) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 9: Supported: replaces (19) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 10: Content-Type: application/sdp (29) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 11: Content-Length: 294 (19) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 12: (0) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: v=0 (3) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: o=- 84017063 65751352 IN IP4 AT320_IP (43) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: s=SIP CALL (10) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: c=IN IP4 AT320_IP (23) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: t=0 0 (5) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: m=audio 10722 RTP/AVP 8 0 18 4 3 101 (36) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: a=rtpmap:18 G729/8000 (21) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: a=rtpmap:4 G723/8000 (20) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: a=rtpmap:3 GSM/8000 (19) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: a=fmtp:101 0-15 (15) --- (12 headers 13 lines)--- [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4105 sip_alloc: Allocating new SIP dialog for bkQ0wWXareCYQjP0@AT320_IP - INVITE (With RTP) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:13974 handle_request: **** Received INVITE (5) - Command in SIP INVITE [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:1619 parse_sip_options: Begin: parsing SIP "Supported: replaces" [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:1627 parse_sip_options: Found SIP option: -replaces- [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:1633 parse_sip_options: Matched SIP option: replaces Sending to AT320_IP : 5060 (no NAT) Using INVITE request as basis request - bkQ0wWXareCYQjP0@AT320_IP [2006-08-01 17:06:30] DEBUG[32324]: acl.c:213 ast_apply_ha: ##### Testing AT320_IP with 0.0.0.0 [2006-08-01 17:06:30] DEBUG[32324]: acl.c:213 ast_apply_ha: ##### Testing AT320_IP with AT320_IP [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:8620 check_user_full: Setting NAT on RTP to Off Found user '1070' Found RTP audio format 8 Found RTP audio format 0 Found RTP audio format 18 Found RTP audio format 4 Found RTP audio format 3 Found RTP audio format 101 Peer audio RTP is at port AT320_IP:10722 Found description format PCMA for ID 8 Found description format PCMU for ID 0 Found description format G729 for ID 18 Found description format G723 for ID 4 Found description format GSM for ID 3 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4830 process_sdp: T38 state changed to 0 on channel Capabilities: us - 0xc2e (gsm|ulaw|alaw|g726|adpcm|ilbc), peer - audio=0x10f (g723|gsm|ulaw|alaw|g729)/video=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) my*CLI> Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port AT320_IP:10722 [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4900 process_sdp: We're settling with these formats: 0xe (gsm|ulaw|alaw) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:12787 handle_request_invite: Checking SIP call limits for device 1070 [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:2878 update_call_counter: Updating call counter for incoming call Looking for 1005 in Internal (domain pbx.varna.net) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:3607 sip_new: *** Our native formats are 0x8 (alaw) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:3608 sip_new: *** Joint capabilities are 0xe (gsm|ulaw|alaw) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:3609 sip_new: *** Our capabilities are 0xc2e (gsm|ulaw|alaw|g726|adpcm|ilbc) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:3610 sip_new: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:3633 sip_new: This channel will not be able to handle video. [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:7586 build_route: build_route: Contact hop: list_route: hop: [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:12857 handle_request_invite: SIP/1070-0079317c: New call is still down.... Trying... Transmitting (no NAT) to AT320_IP:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP AT320_IP:5060;branch=z9hG4bKmg1ook9mDwOyYSkw;received=AT320_IP From: "1070" ;tag=pqXcAkXWW76hTMgN To: "1005" Call-ID: bkQ0wWXareCYQjP0@AT320_IP CSeq: 1 INVITE User-Agent: PBX.Varna.Net Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 --- [2006-08-01 17:06:30] DEBUG[32324]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/1070-0079317c [2006-08-01 17:06:30] DEBUG[32324]: sched.c:331 ast_sched_runq: ast_sched_runq() [2006-08-01 17:06:30] DEBUG[32324]: sched.c:152 ast_sched_wait: ast_sched_wait() my*CLI> [2006-08-01 17:06:30] DEBUG[32665]: pbx.c:1675 pbx_extension_helper: Launching 'Dial' -- Executing [1005@Internal:1] Dial("SIP/1070-0079317c", "SIP/1005||TWHKtwhk") in new stack [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:14594 sip_request_call: Asked to create a SIP channel with formats: 0x8 (alaw) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4105 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:2519 create_addr_from_peer: Setting NAT on RTP to Off [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:3607 sip_new: *** Our native formats are 0x8 (alaw) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:3608 sip_new: *** Joint capabilities are 0x0 (nothing) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:3609 sip_new: *** Our capabilities are 0xc2e (gsm|ulaw|alaw|g726|adpcm|ilbc) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:3610 sip_new: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:3612 sip_new: *** Our preferred formats from the incoming channel are 0x8 (alaw) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:3633 sip_new: This channel will not be able to handle video. [2006-08-01 17:06:30] DEBUG[32665]: channel.c:2980 ast_channel_inherit_variables: Not copying variable STACK-Internal-1005-1. [2006-08-01 17:06:30] DEBUG[32665]: channel.c:2980 ast_channel_inherit_variables: Not copying variable SIPCALLID. [2006-08-01 17:06:30] DEBUG[32665]: channel.c:2980 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. [2006-08-01 17:06:30] DEBUG[32665]: channel.c:2980 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [2006-08-01 17:06:30] DEBUG[32665]: channel.c:2980 ast_channel_inherit_variables: Not copying variable SIPURI. [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:2717 sip_call: Outgoing Call for 1005 [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:2878 update_call_counter: Updating call counter for outgoing call [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:2725 sip_call: Our T38 capability (0), joint T38 capability (0) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:5805 add_sdp: ** Our capability: 0xc2e (gsm|ulaw|alaw|g726|adpcm|ilbc) Video flag: False [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:5806 add_sdp: ** Our prefcodec: 0x8 (alaw) Audio is at 217.145.81.12 port 33254 Adding codec 0x8 (alaw) to SDP Adding codec 0x4 (ulaw) to SDP Adding codec 0x2 (gsm) to SDP Adding codec 0x800 (g726) to SDP Adding codec 0x20 (adpcm) to SDP Adding codec 0x400 (ilbc) to SDP Adding non-codec 0x1 (telephone-event) to SDP my*CLI> [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:5958 add_sdp: -- Done with adding codecs to SDP [2006-08-01 17:06:30] DEBUG[32665]: channel.c:2135 ast_internal_timing_enabled: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=21) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:5997 add_sdp: Done building SDP. Settling with this capability: 0xc2e (gsm|ulaw|alaw|g726|adpcm|ilbc) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4325 parse_request: Header 0: INVITE sip:1005@SPA2100_IP:5060 SIP/2.0 (43) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP 217.145.81.12:5060;branch=z9hG4bK528090af;rport (64) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4325 parse_request: Header 2: From: "1070" ;tag=as71d8dd71 (52) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4325 parse_request: Header 3: To: (34) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4325 parse_request: Header 4: Contact: (33) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4325 parse_request: Header 5: Call-ID: 45cc0f1374b1f5325c8c8b260c7a4707@217.145.81.12 (55) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4325 parse_request: Header 6: CSeq: 102 INVITE (16) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4325 parse_request: Header 7: User-Agent: PBX.Varna.Net (25) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4325 parse_request: Header 8: Max-Forwards: 70 (16) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4325 parse_request: Header 9: Date: Tue, 01 Aug 2006 14:06:30 GMT (35) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4325 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4325 parse_request: Header 11: Supported: replaces (19) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4325 parse_request: Header 12: Content-Type: application/sdp (29) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4325 parse_request: Header 13: Content-Length: 350 (19) my*CLI> [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4325 parse_request: Header 14: (0) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4357 parse_request: Line: v=0 (3) [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4357 parse_request: Line: o=root 32318 32318 IN IP4 217.145.81.12 (39) my*CLI> [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4357 parse_request: Line: s=session (9) my*CLI> [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4357 parse_request: Line: c=IN IP4 217.145.81.12 (22) my*CLI> [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4357 parse_request: Line: t=0 0 (5) my*CLI> [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4357 parse_request: Line: m=audio 33254 RTP/AVP 8 0 3 111 5 97 101 (40) my*CLI> [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4357 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) my*CLI> [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4357 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) my*CLI> [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4357 parse_request: Line: a=rtpmap:3 GSM/8000 (19) my*CLI> [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4357 parse_request: Line: a=rtpmap:111 G726-32/8000 (25) my*CLI> [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4357 parse_request: Line: a=rtpmap:5 DVI4/8000 (20) my*CLI> [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4357 parse_request: Line: a=rtpmap:97 iLBC/8000 (21) my*CLI> [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4357 parse_request: Line: a=fmtp:97 mode=20 (17) my*CLI> [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4357 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) my*CLI> [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4357 parse_request: Line: a=fmtp:101 0-16 (15) my*CLI> [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:4357 parse_request: Line: a=sendrecv (10) my*CLI> Reliably Transmitting (no NAT) to SPA2100_IP:5060: INVITE sip:1005@SPA2100_IP:5060 SIP/2.0 Via: SIP/2.0/UDP 217.145.81.12:5060;branch=z9hG4bK528090af;rport From: "1070" ;tag=as71d8dd71 To: Contact: Call-ID: 45cc0f1374b1f5325c8c8b260c7a4707@217.145.81.12 CSeq: 102 INVITE User-Agent: PBX.Varna.Net Max-Forwards: 70 Date: Tue, 01 Aug 2006 14:06:30 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 350 v=0 o=root 32318 32318 IN IP4 217.145.81.12 s=session c=IN IP4 217.145.81.12 t=0 0 m=audio 33254 RTP/AVP 8 0 3 111 5 97 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:111 G726-32/8000 a=rtpmap:5 DVI4/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=sendrecv --- [2006-08-01 17:06:30] DEBUG[32321]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 1070 my*CLI> [2006-08-01 17:06:30] DEBUG[32321]: chan_sip.c:14538 sip_devicestate: Checking device state for peer 1070 my*CLI> [2006-08-01 17:06:30] DEBUG[32321]: devicestate.c:287 do_state_change: Changing state for SIP/1070 - state 1 (Not in use) my*CLI> [2006-08-01 17:06:30] DEBUG[32321]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 1070 my*CLI> [2006-08-01 17:06:30] DEBUG[32321]: chan_sip.c:14538 sip_devicestate: Checking device state for peer 1070 my*CLI> [2006-08-01 17:06:30] DEBUG[32324]: sched.c:152 ast_sched_wait: ast_sched_wait() my*CLI> [2006-08-01 17:06:30] DEBUG[32665]: sched.c:218 ast_sched_add_variable: ast_sched_add() my*CLI> [2006-08-01 17:06:30] DEBUG[32665]: chan_sip.c:1910 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #153 my*CLI> [2006-08-01 17:06:30] DEBUG[32665]: sched.c:218 ast_sched_add_variable: ast_sched_add() my*CLI> -- Called 1005 my*CLI> <-- SIP read from SPA2100_IP:5060: SIP/2.0 100 Trying To: From: "1070" ;tag=as71d8dd71 Call-ID: 45cc0f1374b1f5325c8c8b260c7a4707@217.145.81.12 CSeq: 102 INVITE Via: SIP/2.0/UDP 217.145.81.12:5060;branch=z9hG4bK528090af Server: Sipura/SPA2100-3.2.5(d) Content-Length: 0 [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 0: SIP/2.0 100 Trying (18) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 1: To: (34) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 2: From: "1070" ;tag=as71d8dd71 (52) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 3: Call-ID: 45cc0f1374b1f5325c8c8b260c7a4707@217.145.81.12 (55) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 4: CSeq: 102 INVITE (16) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 5: Via: SIP/2.0/UDP 217.145.81.12:5060;branch=z9hG4bK528090af (58) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 6: Server: Sipura/SPA2100-3.2.5(d) (31) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 7: Content-Length: 0 (17) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 8: (0) --- (8 headers 0 lines)--- [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4153 find_call: = Found Their Call ID: 45cc0f1374b1f5325c8c8b260c7a4707@217.145.81.12 Their Tag Our tag: as71d8dd71 [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:2046 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #153 - INVITE (got response) [2006-08-01 17:06:30] DEBUG[32324]: sched.c:262 ast_sched_del: ast_sched_del() [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:2055 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '45cc0f1374b1f5325c8c8b260c7a4707@217.145.81.12' Request 102: Found [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:11148 handle_response_invite: SIP response 100 to standard invite [2006-08-01 17:06:30] DEBUG[32324]: sched.c:262 ast_sched_del: ast_sched_del() [2006-08-01 17:06:30] DEBUG[32324]: sched.c:331 ast_sched_runq: ast_sched_runq() [2006-08-01 17:06:30] DEBUG[32324]: sched.c:152 ast_sched_wait: ast_sched_wait() <-- SIP read from SPA2100_IP:5060: SIP/2.0 180 Ringing To: ;tag=9e71eb27b6018cf9i0 From: "1070" ;tag=as71d8dd71 Call-ID: 45cc0f1374b1f5325c8c8b260c7a4707@217.145.81.12 CSeq: 102 INVITE Via: SIP/2.0/UDP 217.145.81.12:5060;branch=z9hG4bK528090af Server: Sipura/SPA2100-3.2.5(d) Remote-Party-ID: 1005 ;screen=yes;party=called Content-Length: 0 [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 0: SIP/2.0 180 Ringing (19) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 1: To: ;tag=9e71eb27b6018cf9i0 (57) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 2: From: "1070" ;tag=as71d8dd71 (52) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 3: Call-ID: 45cc0f1374b1f5325c8c8b260c7a4707@217.145.81.12 (55) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 4: CSeq: 102 INVITE (16) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 5: Via: SIP/2.0/UDP 217.145.81.12:5060;branch=z9hG4bK528090af (58) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 6: Server: Sipura/SPA2100-3.2.5(d) (31) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 7: Remote-Party-ID: 1005 ;screen=yes;party=called (70) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 8: Content-Length: 0 (17) [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 9: (0) --- (9 headers 0 lines)--- [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:4153 find_call: = Found Their Call ID: 45cc0f1374b1f5325c8c8b260c7a4707@217.145.81.12 Their Tag Our tag: as71d8dd71 [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:2055 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '45cc0f1374b1f5325c8c8b260c7a4707@217.145.81.12' Request 102: Found [2006-08-01 17:06:30] DEBUG[32324]: chan_sip.c:11148 handle_response_invite: SIP response 180 to standard invite [2006-08-01 17:06:30] DEBUG[32324]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/1005-006b89fc [2006-08-01 17:06:30] DEBUG[32321]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 1005 [2006-08-01 17:06:30] DEBUG[32321]: chan_sip.c:14538 sip_devicestate: Checking device state for peer 1005 my*CLI> [2006-08-01 17:06:30] DEBUG[32321]: devicestate.c:287 do_state_change: Changing state for SIP/1005 - state 1 (Not in use) -- SIP/1005-006b89fc is ringing my*CLI> [2006-08-01 17:06:30] DEBUG[32324]: sched.c:331 ast_sched_runq: Transmitting (no NAT) to AT320_IP:5060: SIP/2.0 180 Ringing Via: SIP/2.0/UDP AT320_IP:5060;branch=z9hG4bKmg1ook9mDwOyYSkw;received=AT320_IP From: "1070" ;tag=pqXcAkXWW76hTMgN To: "1005" ;tag=as60a46ee1 Call-ID: bkQ0wWXareCYQjP0@AT320_IP CSeq: 1 INVITE User-Agent: PBX.Varna.Net Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 --- ast_sched_runq() [2006-08-01 17:06:30] DEBUG[32324]: sched.c:152 ast_sched_wait: ast_sched_wait() my*CLI> [2006-08-01 17:06:31] DEBUG[32324]: sched.c:331 ast_sched_runq: ast_sched_runq() [2006-08-01 17:06:31] DEBUG[32324]: sched.c:152 ast_sched_wait: ast_sched_wait() my*CLI> [2006-08-01 17:06:32] DEBUG[32324]: sched.c:331 ast_sched_runq: ast_sched_runq() [2006-08-01 17:06:32] DEBUG[32324]: sched.c:152 ast_sched_wait: ast_sched_wait() my*CLI> <-- SIP read from SPA2100_IP:5060: SIP/2.0 200 OK To: ;tag=9e71eb27b6018cf9i0 From: "1070" ;tag=as71d8dd71 Call-ID: 45cc0f1374b1f5325c8c8b260c7a4707@217.145.81.12 CSeq: 102 INVITE Via: SIP/2.0/UDP 217.145.81.12:5060;branch=z9hG4bK528090af Contact: 1005 Server: Sipura/SPA2100-3.2.5(d) Remote-Party-ID: 1005 ;screen=yes;party=called Content-Length: 261 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura Content-Type: application/sdp v=0 o=- 43590517 43590517 IN IP4 SPA2100_IP s=- c=IN IP4 SPA2100_IP t=0 0 m=audio 16464 RTP/AVP 8 100 101 a=rtpmap:8 PCMA/8000 a=rtpmap:100 NSE/8000 a=fmtp:100 192-193 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 0: SIP/2.0 200 OK (14) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 1: To: ;tag=9e71eb27b6018cf9i0 (57) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 2: From: "1070" ;tag=as71d8dd71 (52) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 3: Call-ID: 45cc0f1374b1f5325c8c8b260c7a4707@217.145.81.12 (55) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 4: CSeq: 102 INVITE (16) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 5: Via: SIP/2.0/UDP 217.145.81.12:5060;branch=z9hG4bK528090af (58) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 6: Contact: 1005 (44) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 7: Server: Sipura/SPA2100-3.2.5(d) (31) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 8: Remote-Party-ID: 1005 ;screen=yes;party=called (70) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 9: Content-Length: 261 (19) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 10: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 11: Supported: x-sipura (19) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 12: Content-Type: application/sdp (29) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 13: (0) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: v=0 (3) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: o=- 43590517 43590517 IN IP4 SPA2100_IP (43) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: s=- (3) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: c=IN IP4 SPA2100_IP (23) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: t=0 0 (5) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: m=audio 16464 RTP/AVP 8 100 101 (31) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: a=rtpmap:100 NSE/8000 (21) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: a=fmtp:100 192-193 (18) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: a=fmtp:101 0-15 (15) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: a=ptime:20 (10) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4357 parse_request: Line: a=sendrecv (10) --- (13 headers 13 lines)--- [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4153 find_call: = Found Their Call ID: 45cc0f1374b1f5325c8c8b260c7a4707@217.145.81.12 Their Tag 9e71eb27b6018cf9i0 Our tag: as71d8dd71 [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:1995 __sip_ack: Acked pending invite 102 [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:2013 __sip_ack: Stopping retransmission on '45cc0f1374b1f5325c8c8b260c7a4707@217.145.81.12' of Request 102: Match Not Found [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:11148 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 8 Found RTP audio format 100 Found RTP audio format 101 Peer audio RTP is at port SPA2100_IP:16464 Found description format PCMA for ID 8 Found description format NSE for ID 100 Got unsupported a:fmtp in SDP offer Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer Got unsupported a:ptime in SDP offer [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4830 process_sdp: T38 state changed to 0 on channel SIP/1005-006b89fc Capabilities: us - 0xc2e (gsm|ulaw|alaw|g726|adpcm|ilbc), peer - audio=0x8 (alaw)/video=0x0 (nothing), combined - 0x8 (alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port SPA2100_IP:16464 [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4900 process_sdp: We're settling with these formats: 0x8 (alaw) [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4907 process_sdp: We have an owner, now see if we need to change this call my*CLI> [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:2878 update_call_counter: Updating call counter for outgoing call [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:7586 build_route: build_route: Contact hop: 1005 list_route: hop: [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:5336 reqprep: Strict routing enforced for session 45cc0f1374b1f5325c8c8b260c7a4707@217.145.81.12 set_destination: Parsing for address/port to send to my*CLI> set_destination: set destination to SPA2100_IP, port 5060 my*CLI> Transmitting (no NAT) to SPA2100_IP:5060: ACK sip:1005@SPA2100_IP:5060 SIP/2.0 Via: SIP/2.0/UDP 217.145.81.12:5060;branch=z9hG4bK78bc7241;rport From: "1070" ;tag=as71d8dd71 To: ;tag=9e71eb27b6018cf9i0 Contact: Call-ID: 45cc0f1374b1f5325c8c8b260c7a4707@217.145.81.12 CSeq: 102 ACK User-Agent: PBX.Varna.Net Max-Forwards: 70 Content-Length: 0 --- my*CLI> [2006-08-01 17:06:32] DEBUG[32324]: sched.c:331 ast_sched_runq: ast_sched_runq() my*CLI> [2006-08-01 17:06:32] DEBUG[32665]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/1005-006b89fc my*CLI> [2006-08-01 17:06:32] DEBUG[32324]: sched.c:152 ast_sched_wait: ast_sched_wait() my*CLI> -- SIP/1005-006b89fc answered SIP/1070-0079317c [2006-08-01 17:06:32] DEBUG[32665]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/1070-0079317c [2006-08-01 17:06:32] DEBUG[32665]: chan_sip.c:3318 sip_answer: SIP answering channel: SIP/1070-0079317c [2006-08-01 17:06:32] DEBUG[32665]: chan_sip.c:5805 add_sdp: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True [2006-08-01 17:06:32] DEBUG[32665]: chan_sip.c:5806 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 217.145.81.12 port 12770 Adding codec 0x8 (alaw) to SDP Adding codec 0x4 (ulaw) to SDP Adding codec 0x2 (gsm) to SDP Adding non-codec 0x1 (telephone-event) to SDP [2006-08-01 17:06:32] DEBUG[32665]: chan_sip.c:5958 add_sdp: -- Done with adding codecs to SDP [2006-08-01 17:06:32] DEBUG[32665]: channel.c:2135 ast_internal_timing_enabled: Internal timing is enabled (option_internal_timing=1048576 chan->timingfd=18) [2006-08-01 17:06:32] DEBUG[32665]: chan_sip.c:5997 add_sdp: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) Reliably Transmitting (no NAT) to AT320_IP:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP AT320_IP:5060;branch=z9hG4bKmg1ook9mDwOyYSkw;received=AT320_IP From: "1070" ;tag=pqXcAkXWW76hTMgN To: "1005" ;tag=as60a46ee1 Call-ID: bkQ0wWXareCYQjP0@AT320_IP CSeq: 1 INVITE User-Agent: PBX.Varna.Net Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 250 v=0 o=root 32318 32318 IN IP4 217.145.81.12 s=session c=IN IP4 217.145.81.12 t=0 0 m=audio 12770 RTP/AVP 8 0 3 101 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-16 a=sendrecv --- [2006-08-01 17:06:32] DEBUG[32665]: sched.c:218 ast_sched_add_variable: ast_sched_add() [2006-08-01 17:06:32] DEBUG[32665]: chan_sip.c:1910 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #155 my*CLI> [2006-08-01 17:06:32] DEBUG[32321]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 1005 [2006-08-01 17:06:32] DEBUG[32321]: chan_sip.c:14538 sip_devicestate: Checking device state for peer 1005 [2006-08-01 17:06:32] DEBUG[32321]: devicestate.c:287 do_state_change: Changing state for SIP/1005 - state 1 (Not in use) [2006-08-01 17:06:32] DEBUG[32321]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 1070 [2006-08-01 17:06:32] DEBUG[32321]: chan_sip.c:14538 sip_devicestate: Checking device state for peer 1070 [2006-08-01 17:06:32] DEBUG[32321]: devicestate.c:287 do_state_change: Changing state for SIP/1070 - state 1 (Not in use) [2006-08-01 17:06:32] DEBUG[32321]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 1070 [2006-08-01 17:06:32] DEBUG[32321]: chan_sip.c:14538 sip_devicestate: Checking device state for peer 1070 my*CLI> <-- SIP read from AT320_IP:5060: ACK sip:1005@217.145.81.12 SIP/2.0 Via: SIP/2.0/UDP AT320_IP:5060;branch=z9hG4bKy8qaAtXOabc7C27K Max-Forwards: 70 User-Agent: phone V1.49.002 CFG0 From: "1070" ;tag=pqXcAkXWW76hTMgN To: "1005" ;tag=as60a46ee1 Call-ID: bkQ0wWXareCYQjP0@AT320_IP Contact: CSeq: 1 ACK Content-Length: 0 my*CLI> [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 0: ACK sip:1005@217.145.81.12 SIP/2.0 (34) my*CLI> [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP AT320_IP:5060;branch=z9hG4bKy8qaAtXOabc7C27K (67) my*CLI> [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 2: Max-Forwards: 70 (16) my*CLI> [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 3: User-Agent: phone V1.49.002 CFG0 (33) my*CLI> [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 4: From: "1070" ;tag=pqXcAkXWW76hTMgN (58) my*CLI> [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 5: To: "1005" ;tag=as60a46ee1 (50) my*CLI> [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 6: Call-ID: bkQ0wWXareCYQjP0@AT320_IP (40) my*CLI> [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 7: Contact: (39) my*CLI> [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 8: CSeq: 1 ACK (11) my*CLI> [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 9: Content-Length: 0 (17) my*CLI> [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 10: (0) my*CLI> --- (10 headers 0 lines)--- my*CLI> [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4153 find_call: = No match Their Call ID: 45cc0f1374b1f5325c8c8b260c7a4707@217.145.81.12 Their Tag 9e71eb27b6018cf9i0 Our tag: as71d8dd71 my*CLI> [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:4153 find_call: = Found Their Call ID: bkQ0wWXareCYQjP0@AT320_IP Their Tag pqXcAkXWW76hTMgN Our tag: as60a46ee1 my*CLI> [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:13974 handle_request: **** Received ACK (6) - Command in SIP ACK my*CLI> [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:2003 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #155 my*CLI> [2006-08-01 17:06:32] DEBUG[32324]: sched.c:262 ast_sched_del: ast_sched_del() my*CLI> [2006-08-01 17:06:32] DEBUG[32324]: chan_sip.c:2013 __sip_ack: Stopping retransmission on 'bkQ0wWXareCYQjP0@AT320_IP' of Response 1: Match Not Found my*CLI> [2006-08-01 17:06:32] DEBUG[32324]: sched.c:331 ast_sched_runq: ast_sched_runq() my*CLI> [2006-08-01 17:06:32] DEBUG[32324]: sched.c:152 ast_sched_wait: ast_sched_wait() my*CLI> [2006-08-01 17:06:33] DEBUG[32324]: sched.c:331 ast_sched_runq: ast_sched_runq() my*CLI> [2006-08-01 17:06:33] DEBUG[32324]: sched.c:152 ast_sched_wait: ast_sched_wait() my*CLI> [2006-08-01 17:06:34] DEBUG[32324]: sched.c:331 ast_sched_runq: ast_sched_runq() my*CLI> [2006-08-01 17:06:34] DEBUG[32324]: sched.c:152 ast_sched_wait: ast_sched_wait() my*CLI> [2006-08-01 17:06:35] DEBUG[32324]: sched.c:331 ast_sched_runq: ast_sched_runq() my*CLI> [2006-08-01 17:06:35] DEBUG[32324]: sched.c:152 ast_sched_wait: ast_sched_wait() my*CLI> <-- SIP read from AT320_IP:5060: REFER sip:1005@217.145.81.12 SIP/2.0 Via: SIP/2.0/UDP AT320_IP:5060;branch=z9hG4bKS3nk7Z9ApvkHuvyO Max-Forwards: 70 User-Agent: phone V1.49.002 CFG0 From: "1070" ;tag=pqXcAkXWW76hTMgN To: "1005" ;tag=as60a46ee1 Call-ID: bkQ0wWXareCYQjP0@AT320_IP Contact: CSeq: 2 REFER Refer-To: "1007" Referred-By: Content-Length: 0 my*CLI> [2006-08-01 17:06:36] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 0: REFER sip:1005@217.145.81.12 SIP/2.0 (36) [2006-08-01 17:06:36] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 1: Via: SIP/2.0/UDP AT320_IP:5060;branch=z9hG4bKS3nk7Z9ApvkHuvyO (67) [2006-08-01 17:06:36] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 2: Max-Forwards: 70 (16) my*CLI> [2006-08-01 17:06:36] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 3: User-Agent: phone V1.49.002 CFG0 (33) my*CLI> [2006-08-01 17:06:36] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 4: From: "1070" ;tag=pqXcAkXWW76hTMgN (58) my*CLI> [2006-08-01 17:06:36] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 5: To: "1005" ;tag=as60a46ee1 (50) my*CLI> [2006-08-01 17:06:36] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 6: Call-ID: bkQ0wWXareCYQjP0@AT320_IP (40) my*CLI> [2006-08-01 17:06:36] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 7: Contact: (39) my*CLI> [2006-08-01 17:06:36] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 8: CSeq: 2 REFER (13) my*CLI> [2006-08-01 17:06:36] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 9: Refer-To: "1007" (41) my*CLI> [2006-08-01 17:06:36] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 10: Referred-By: (37) my*CLI> [2006-08-01 17:06:36] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 11: Content-Length: 0 (17) my*CLI> [2006-08-01 17:06:36] DEBUG[32324]: chan_sip.c:4325 parse_request: Header 12: (0) my*CLI> --- (12 headers 0 lines)--- my*CLI> [2006-08-01 17:06:36] DEBUG[32324]: chan_sip.c:4153 find_call: = No match Their Call ID: 45cc0f1374b1f5325c8c8b260c7a4707@217.145.81.12 Their Tag 9e71eb27b6018cf9i0 Our tag: as71d8dd71 my*CLI> [2006-08-01 17:06:36] DEBUG[32324]: chan_sip.c:4153 find_call: = Found Their Call ID: bkQ0wWXareCYQjP0@AT320_IP Their Tag pqXcAkXWW76hTMgN Our tag: as60a46ee1 my*CLI> [2006-08-01 17:06:36] DEBUG[32324]: chan_sip.c:13974 handle_request: **** Received REFER (9) - Command in SIP REFER my*CLI> Call bkQ0wWXareCYQjP0@AT320_IP got a SIP call transfer from caller: (REFER)! my*CLI> SIP transfer to extension 1007@Internal by 1070@pbx.varna.net my*CLI> [2006-08-01 17:06:36] DEBUG[32324]: chan_sip.c:13325 handle_request_refer: SIP blind transfer: Transferer channel SIP/1070-0079317c, transferee channel SIP/1005-006b89fc my*CLI> [2006-08-01 17:06:36] DEBUG[32324]: chan_sip.c:13341 handle_request_refer: Got SIP transfer, applying to bridged peer 'SIP/1005-006b89fc' my*CLI> Transmitting (no NAT) to AT320_IP:5060: SIP/2.0 202 Accepted Via: SIP/2.0/UDP AT320_IP:5060;branch=z9hG4bKS3nk7Z9ApvkHuvyO;received=AT320_IP From: "1070" ;tag=pqXcAkXWW76hTMgN To: "1005" ;tag=as60a46ee1 Call-ID: bkQ0wWXareCYQjP0@AT320_IP CSeq: 2 REFER User-Agent: PBX.Varna.Net Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 --- my*CLI> [2006-08-01 17:06:36] DEBUG[32324]: chan_sip.c:13379 handle_request_refer: chan1->name: SIP/1070-0079317c my*CLI> [2006-08-01 17:06:36] ERROR[32324]: ../include/asterisk/lock.h:405 __ast_pthread_mutex_unlock: Segmentation fault (core dumped)