[Mar 6 21:46:18] VERBOSE[27968] logger.c: <--- SIP read from 111.111.111.111:5060 ---> INVITE sip:011990123456789@asterisk.tel SIP/2.0 Via: SIP/2.0/UDP 111.111.111.111:5060;branch=z9hG4bK1421c3c5;rport From: "0000000000" ;tag=as0e16677e To: Contact: Call-ID: 0b32cd1413fb040b553c9bdb78540446@111.111.111.111 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Wed, 07 Mar 2007 02:46:18 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 287 v=0 o=root 2808 2808 IN IP4 111.111.111.111 s=session c=IN IP4 111.111.111.111 t=0 0 m=audio 11400 RTP/AVP 8 0 3 97 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:97 iLBC/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - <-------------> [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Header 0: INVITE sip:011990123456789@asterisk.tel SIP/2.0 (51) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Header 1: Via: SIP/2.0/UDP 111.111.111.111:5060;branch=z9hG4bK1421c3c5;rport (63) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Header 2: From: "0000000000" ;tag=as0e16677e (63) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Header 3: To: (42) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Header 4: Contact: (38) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Header 5: Call-ID: 0b32cd1413fb040b553c9bdb78540446@111.111.111.111 (54) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Header 6: CSeq: 102 INVITE (16) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Header 8: Max-Forwards: 70 (16) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Header 9: Date: Wed, 07 Mar 2007 02:46:18 GMT (35) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Header 11: Content-Type: application/sdp (29) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Header 12: Content-Length: 287 (19) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Header 13: (0) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Line: v=0 (3) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Line: o=root 2808 2808 IN IP4 111.111.111.111 (36) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Line: s=session (9) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Line: c=IN IP4 111.111.111.111 (21) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Line: t=0 0 (5) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Line: m=audio 11400 RTP/AVP 8 0 3 97 101 (34) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Line: a=rtpmap:3 GSM/8000 (19) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Line: a=rtpmap:97 iLBC/8000 (21) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Line: a=fmtp:101 0-16 (15) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Line: a=silenceSupp:off - - - - (25) [Mar 6 21:46:18] VERBOSE[27968] logger.c: --- (13 headers 13 lines) --- [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Setting NAT on RTP to Off [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Setting NAT on VRTP to Off [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Setting NAT on UDPTL to Off [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Allocating new SIP dialog for 0b32cd1413fb040b553c9bdb78540446@111.111.111.111 - INVITE (With RTP) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Mar 6 21:46:18] VERBOSE[27968] logger.c: Sending to 111.111.111.111 : 5060 (NAT) [Mar 6 21:46:18] VERBOSE[27968] logger.c: Using INVITE request as basis request - 0b32cd1413fb040b553c9bdb78540446@111.111.111.111 [Mar 6 21:46:18] VERBOSE[27968] logger.c: Found peer 'home' [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Setting NAT on RTP to Off [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Setting NAT on VRTP to Off [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Setting NAT on UDPTL to Off [Mar 6 21:46:18] VERBOSE[27968] logger.c: Found RTP audio format 8 [Mar 6 21:46:18] VERBOSE[27968] logger.c: Found RTP audio format 0 [Mar 6 21:46:18] VERBOSE[27968] logger.c: Found RTP audio format 3 [Mar 6 21:46:18] VERBOSE[27968] logger.c: Found RTP audio format 97 [Mar 6 21:46:18] VERBOSE[27968] logger.c: Found RTP audio format 101 [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Peer doesn't provide T.38 UDPTL [Mar 6 21:46:18] VERBOSE[27968] logger.c: Peer audio RTP is at port 111.111.111.111:11400 [Mar 6 21:46:18] VERBOSE[27968] logger.c: Found description format PCMA for ID 8 [Mar 6 21:46:18] VERBOSE[27968] logger.c: Found description format PCMU for ID 0 [Mar 6 21:46:18] VERBOSE[27968] logger.c: Found description format GSM for ID 3 [Mar 6 21:46:18] VERBOSE[27968] logger.c: Found description format iLBC for ID 97 [Mar 6 21:46:18] VERBOSE[27968] logger.c: Found description format telephone-event for ID 101 [Mar 6 21:46:18] VERBOSE[27968] logger.c: Got unsupported a:fmtp in SDP offer [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: T38 state changed to 0 on channel [Mar 6 21:46:18] VERBOSE[27968] logger.c: Capabilities: us - 0x10e (gsm|ulaw|alaw|g729), peer - audio=0x40e (gsm|ulaw|alaw|ilbc)/video=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) [Mar 6 21:46:18] VERBOSE[27968] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Mar 6 21:46:18] VERBOSE[27968] logger.c: Peer audio RTP is at port 111.111.111.111:11400 [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: We're settling with these formats: 0xe (gsm|ulaw|alaw) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Checking SIP call limits for device [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: Updating call counter for incoming call [Mar 6 21:46:18] VERBOSE[27968] logger.c: Looking for 011990123456789 in home (domain asterisk.tel) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: *** Joint capabilities are 0xe (gsm|ulaw|alaw) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: *** Our capabilities are 0x10e (gsm|ulaw|alaw|g729) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: This channel will not be able to handle video. [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: build_route: Contact hop: [Mar 6 21:46:18] VERBOSE[27968] logger.c: list_route: hop: [Mar 6 21:46:18] DEBUG[27968] chan_sip.c: SIP/111.111.111.111-0a1c89f0: New call is still down.... Trying... [Mar 6 21:46:18] VERBOSE[27968] logger.c: <--- Transmitting (no NAT) to 111.111.111.111:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 111.111.111.111:5060;branch=z9hG4bK1421c3c5;received=111.111.111.111;rport=5060 From: "0000000000" ;tag=as0e16677e To: Call-ID: 0b32cd1413fb040b553c9bdb78540446@111.111.111.111 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Mar 6 21:46:18] DEBUG[27968] devicestate.c: Notification of state change to be queued on device/channel SIP/111.111.111.111-0a1c89f0 [Mar 6 21:46:18] DEBUG[27954] devicestate.c: No provider found, checking channel drivers for SIP - 111.111.111.111 [Mar 6 21:46:18] DEBUG[27954] chan_sip.c: Checking device state for peer 111.111.111.111 [Mar 6 21:46:18] DEBUG[27954] devicestate.c: Changing state for SIP/111.111.111.111 - state 2 (In use) [Mar 6 21:46:18] DEBUG[28919] pbx.c: Launching 'Macro' [Mar 6 21:46:18] VERBOSE[28919] logger.c: -- Executing [011990123456789@home:1] Macro("SIP/111.111.111.111-0a1c89f0", "dial|SIP/provider.tel/990123456789") in new stack [Mar 6 21:46:18] DEBUG[28919] pbx.c: Launching 'Dial' [Mar 6 21:46:18] VERBOSE[28919] logger.c: -- Executing [s@macro-dial:1] Dial("SIP/111.111.111.111-0a1c89f0", "SIP/provider.tel/990123456789||") in new stack [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Our T38 capability (3856) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Setting NAT on RTP to Off [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Setting NAT on UDPTL to Off [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: *** Our native formats are 0x100 (g729) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: *** Joint capabilities are 0x0 (nothing) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: *** Our capabilities are 0x100 (g729) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x100 (g729) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: This channel will not be able to handle video. [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Early remote bridge setting SIP '775523532ab3d8365e4645536315122b@222.222.222.222' - Sending media to 111.111.111.111 [Mar 6 21:46:18] DEBUG[28919] rtp.c: Seeded SDP of 'SIP/provider.tel-0a218a30' with that of 'SIP/111.111.111.111-0a1c89f0' [Mar 6 21:46:18] DEBUG[28919] channel.c: Not copying variable STACK-macro-dial-s-1. [Mar 6 21:46:18] DEBUG[28919] channel.c: Not copying variable MACRO_DEPTH. [Mar 6 21:46:18] DEBUG[28919] channel.c: Not copying variable ARG1. [Mar 6 21:46:18] DEBUG[28919] channel.c: Not copying variable MACRO_PRIORITY. [Mar 6 21:46:18] DEBUG[28919] channel.c: Not copying variable MACRO_CONTEXT. [Mar 6 21:46:18] DEBUG[28919] channel.c: Not copying variable MACRO_EXTEN. [Mar 6 21:46:18] DEBUG[28919] channel.c: Not copying variable STACK-home-011990123456789-1. [Mar 6 21:46:18] DEBUG[28919] channel.c: Not copying variable SIPCALLID. [Mar 6 21:46:18] DEBUG[28919] channel.c: Not copying variable SIPUSERAGENT. [Mar 6 21:46:18] DEBUG[28919] channel.c: Not copying variable SIPDOMAIN. [Mar 6 21:46:18] DEBUG[28919] channel.c: Not copying variable SIPURI. [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Outgoing Call for 990123456789 [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Updating call counter for outgoing call [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Our T38 capability (3856), joint T38 capability (3856) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: ** Our capability: 0x100 (g729) Video flag: False [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [Mar 6 21:46:18] VERBOSE[28919] logger.c: Audio is at 222.222.222.222 port 14826 [Mar 6 21:46:18] VERBOSE[28919] logger.c: Adding codec 0x100 (g729) to SDP [Mar 6 21:46:18] VERBOSE[28919] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: -- Done with adding codecs to SDP [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Done building SDP. Settling with this capability: 0x100 (g729) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Header 0: INVITE sip:990123456789@provider.tel SIP/2.0 (44) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Header 1: Via: SIP/2.0/UDP 222.222.222.222:5060;branch=z9hG4bK1fec5a84;rport (64) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Header 2: From: "0000000000" ;tag=as50f61ef3 (64) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Header 3: To: (35) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Header 4: Contact: (39) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Header 5: Call-ID: 775523532ab3d8365e4645536315122b@222.222.222.222 (55) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Header 6: CSeq: 102 INVITE (16) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Header 7: User-Agent: Asterisk PBX (18) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Header 8: Max-Forwards: 70 (16) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Header 9: Date: Wed, 07 Mar 2007 02:46:18 GMT (35) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Header 11: Supported: replaces (19) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Header 12: Content-Type: application/sdp (29) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Header 13: Content-Length: 263 (19) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Header 14: (0) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Line: v=0 (3) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Line: o=root 27906 27906 IN IP4 111.111.111.111 (38) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Line: s=session (9) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Line: c=IN IP4 111.111.111.111 (21) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Line: t=0 0 (5) [Mar 6 21:46:18] DEBUG[28919] chan_sip.c: Line: m=audio 11400 RTP/AVP 18 101 (28) [Mar 6 21:46:19] DEBUG[28919] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) [Mar 6 21:46:19] DEBUG[28919] chan_sip.c: Line: a=fmtp:18 annexb=no (19) [Mar 6 21:46:19] DEBUG[28919] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 6 21:46:19] DEBUG[28919] chan_sip.c: Line: a=fmtp:101 0-16 (15) [Mar 6 21:46:19] DEBUG[28919] chan_sip.c: Line: a=silenceSupp:off - - - - (25) [Mar 6 21:46:19] DEBUG[28919] chan_sip.c: Line: a=ptime:20 (10) [Mar 6 21:46:19] DEBUG[28919] chan_sip.c: Line: a=sendrecv (10) [Mar 6 21:46:19] VERBOSE[28919] logger.c: Reliably Transmitting (no NAT) to 333.333.333.333:5060: INVITE sip:990123456789@provider.tel SIP/2.0 Via: SIP/2.0/UDP 222.222.222.222:5060;branch=z9hG4bK1fec5a84;rport From: "0000000000" ;tag=as50f61ef3 To: Contact: Call-ID: 775523532ab3d8365e4645536315122b@222.222.222.222 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Wed, 07 Mar 2007 02:46:18 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 263 v=0 o=root 27906 27906 IN IP4 111.111.111.111 s=session c=IN IP4 111.111.111.111 t=0 0 m=audio 11400 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Mar 6 21:46:19] DEBUG[28919] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #12537 [Mar 6 21:46:19] VERBOSE[28919] logger.c: -- Called provider.tel/990123456789 [Mar 6 21:46:19] DEBUG[28919] channel.c: Set channel SIP/provider.tel-0a218a30 to read format slin [Mar 6 21:46:19] DEBUG[28919] channel.c: Set channel SIP/111.111.111.111-0a1c89f0 to write format slin [Mar 6 21:46:19] DEBUG[28919] channel.c: Set channel SIP/111.111.111.111-0a1c89f0 to read format slin [Mar 6 21:46:19] DEBUG[28919] channel.c: Set channel SIP/provider.tel-0a218a30 to write format slin [Mar 6 21:46:19] VERBOSE[27968] logger.c: <--- SIP read from 333.333.333.333:5060 ---> SIP/2.0 407 Proxy Authentication Required CSeq: 102 INVITE Via: SIP/2.0/UDP 222.222.222.222:5060;branch=z9hG4bK1fec5a84;rport From: "0000000000" ;tag=as50f61ef3 Call-ID: 775523532ab3d8365e4645536315122b@222.222.222.222 To: Contact: Proxy-Authenticate: DIGEST realm="VoipSwitch", nonce="117323558007020206603462009310" Content-Length: 0 <-------------> [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 0: SIP/2.0 407 Proxy Authentication Required (41) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 1: CSeq: 102 INVITE (16) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 2: Via: SIP/2.0/UDP 222.222.222.222:5060;branch=z9hG4bK1fec5a84;rport (64) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 3: From: "0000000000" ;tag=as50f61ef3 (64) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 4: Call-ID: 775523532ab3d8365e4645536315122b@222.222.222.222 (55) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 5: To: (35) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 6: Contact: (48) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 7: Proxy-Authenticate: DIGEST realm="VoipSwitch", nonce="117323558007020206603462009310" (85) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 8: Content-Length: 0 (17) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 9: (0) [Mar 6 21:46:19] VERBOSE[27968] logger.c: --- (9 headers 0 lines) --- [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Acked pending invite 102 [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #12537 [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Stopping retransmission on '775523532ab3d8365e4645536315122b@222.222.222.222' of Request 102: Match Not Found [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: SIP response 407 to standard invite [Mar 6 21:46:19] VERBOSE[27968] logger.c: Transmitting (no NAT) to 333.333.333.333:5060: ACK sip:990123456789@provider.tel SIP/2.0 Via: SIP/2.0/UDP 222.222.222.222:5060;branch=z9hG4bK1fec5a84;rport From: "0000000000" ;tag=as50f61ef3 To: Contact: Call-ID: 775523532ab3d8365e4645536315122b@222.222.222.222 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Auth attempt 1 on INVITE [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: ** Our capability: 0x100 (g729) Video flag: False [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [Mar 6 21:46:19] VERBOSE[27968] logger.c: Audio is at 222.222.222.222 port 14826 [Mar 6 21:46:19] VERBOSE[27968] logger.c: Adding codec 0x100 (g729) to SDP [Mar 6 21:46:19] VERBOSE[27968] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: -- Done with adding codecs to SDP [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Done building SDP. Settling with this capability: 0x100 (g729) [Mar 6 21:46:19] VERBOSE[27968] logger.c: Reliably Transmitting (no NAT) to 333.333.333.333:5060: INVITE sip:990123456789@provider.tel SIP/2.0 Via: SIP/2.0/UDP 222.222.222.222:5060;branch=z9hG4bK71135ade;rport From: "0000000000" ;tag=as50f61ef3 To: Contact: Call-ID: 775523532ab3d8365e4645536315122b@222.222.222.222 CSeq: 103 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Proxy-Authorization: Digest username="user", realm="VoipSwitch", algorithm=MD5, uri="sip:990123456789@provider.tel", nonce="117323558007020206603462009310", response="aa63038cf58868d66e3149042a2cf992", opaque="" Date: Wed, 07 Mar 2007 02:46:19 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 263 v=0 o=root 27906 27907 IN IP4 111.111.111.111 s=session c=IN IP4 111.111.111.111 t=0 0 m=audio 11400 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #12539 [Mar 6 21:46:19] VERBOSE[27968] logger.c: <--- SIP read from 333.333.333.333:5060 ---> SIP/2.0 100 Trying CSeq: 103 INVITE Via: SIP/2.0/UDP 222.222.222.222:5060;branch=z9hG4bK71135ade;rport From: "0000000000" ;tag=as50f61ef3 Call-ID: 775523532ab3d8365e4645536315122b@222.222.222.222 To: ;tag=0703460702205391035938029 Contact: Content-Length: 0 <-------------> [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 0: SIP/2.0 100 Trying (18) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 1: CSeq: 103 INVITE (16) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 2: Via: SIP/2.0/UDP 222.222.222.222:5060;branch=z9hG4bK71135ade;rport (64) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 3: From: "0000000000" ;tag=as50f61ef3 (64) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 4: Call-ID: 775523532ab3d8365e4645536315122b@222.222.222.222 (55) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 5: To: ;tag=0703460702205391035938029 (65) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 6: Contact: (48) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 7: Content-Length: 0 (17) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 8: (0) [Mar 6 21:46:19] VERBOSE[27968] logger.c: --- (8 headers 0 lines) --- [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: *** SIP TIMER: Cancelling retransmission #12539 - INVITE (got response) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '775523532ab3d8365e4645536315122b@222.222.222.222' Request 103: Found [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: SIP response 100 to standard invite [Mar 6 21:46:19] VERBOSE[27968] logger.c: <--- SIP read from 333.333.333.333:5060 ---> SIP/2.0 183 Session Progress CSeq: 103 INVITE Via: SIP/2.0/UDP 222.222.222.222:5060;branch=z9hG4bK71135ade;rport From: "0000000000" ;tag=as50f61ef3 Call-ID: 775523532ab3d8365e4645536315122b@222.222.222.222 To: ;tag=0703460702205391035938029 Contact: Content-Type: application/sdp Content-Length: 217 v=0 o=VoipSwitch 9028 9028 IN IP4 333.333.333.333 s=VoipSIP i=Audio Session c=IN IP4 333.333.333.333 t=0 0 m=audio 8028 RTP/AVP 18 101 a=rtpmap:18 G729/8000/1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 <-------------> [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 0: SIP/2.0 183 Session Progress (28) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 1: CSeq: 103 INVITE (16) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 2: Via: SIP/2.0/UDP 222.222.222.222:5060;branch=z9hG4bK71135ade;rport (64) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 3: From: "0000000000" ;tag=as50f61ef3 (64) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 4: Call-ID: 775523532ab3d8365e4645536315122b@222.222.222.222 (55) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 5: To: ;tag=0703460702205391035938029 (65) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 6: Contact: (48) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 7: Content-Type: application/sdp (29) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 8: Content-Length: 217 (19) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 9: (0) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Line: v=0 (3) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Line: o=VoipSwitch 9028 9028 IN IP4 333.333.333.333 (44) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Line: s=VoipSIP (9) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Line: i=Audio Session (15) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Line: c=IN IP4 333.333.333.333 (23) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Line: t=0 0 (5) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Line: m=audio 8028 RTP/AVP 18 101 (27) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Line: a=rtpmap:18 G729/8000/1 (23) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Line: a=fmtp:101 0-15 (15) [Mar 6 21:46:19] VERBOSE[27968] logger.c: --- (9 headers 10 lines) --- [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '775523532ab3d8365e4645536315122b@222.222.222.222' Request 103: Found [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: SIP response 183 to standard invite [Mar 6 21:46:19] VERBOSE[27968] logger.c: Found RTP audio format 18 [Mar 6 21:46:19] VERBOSE[27968] logger.c: Found RTP audio format 101 [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Peer doesn't provide T.38 UDPTL [Mar 6 21:46:19] VERBOSE[27968] logger.c: Peer audio RTP is at port 333.333.333.333:8028 [Mar 6 21:46:19] VERBOSE[27968] logger.c: Found description format G729 for ID 18 [Mar 6 21:46:19] VERBOSE[27968] logger.c: Found description format telephone-event for ID 101 [Mar 6 21:46:19] VERBOSE[27968] logger.c: Got unsupported a:fmtp in SDP offer [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: T38 state changed to 0 on channel SIP/provider.tel-0a218a30 [Mar 6 21:46:19] VERBOSE[27968] logger.c: Capabilities: us - 0x100 (g729), peer - audio=0x100 (g729)/video=0x0 (nothing), combined - 0x100 (g729) [Mar 6 21:46:19] VERBOSE[27968] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Mar 6 21:46:19] VERBOSE[27968] logger.c: Peer audio RTP is at port 333.333.333.333:8028 [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: We're settling with these formats: 0x100 (g729) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: We have an owner, now see if we need to change this call [Mar 6 21:46:19] VERBOSE[27968] logger.c: <--- SIP read from 333.333.333.333:5060 ---> SIP/2.0 180 Ringing CSeq: 103 INVITE Via: SIP/2.0/UDP 222.222.222.222:5060;branch=z9hG4bK71135ade;rport From: "0000000000" ;tag=as50f61ef3 Call-ID: 775523532ab3d8365e4645536315122b@222.222.222.222 To: ;tag=0703460702205391035938029 Contact: Content-Type: application/sdp Content-Length: 217 v=0 o=VoipSwitch 9028 9028 IN IP4 333.333.333.333 s=VoipSIP i=Audio Session c=IN IP4 333.333.333.333 t=0 0 m=audio 8028 RTP/AVP 18 101 a=rtpmap:18 G729/8000/1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 <-------------> [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 0: SIP/2.0 180 Ringing (19) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 1: CSeq: 103 INVITE (16) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 2: Via: SIP/2.0/UDP 222.222.222.222:5060;branch=z9hG4bK71135ade;rport (64) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 3: From: "0000000000" ;tag=as50f61ef3 (64) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 4: Call-ID: 775523532ab3d8365e4645536315122b@222.222.222.222 (55) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 5: To: ;tag=0703460702205391035938029 (65) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 6: Contact: (48) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 7: Content-Type: application/sdp (29) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 8: Content-Length: 217 (19) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Header 9: (0) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Line: v=0 (3) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Line: o=VoipSwitch 9028 9028 IN IP4 333.333.333.333 (44) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Line: s=VoipSIP (9) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Line: i=Audio Session (15) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Line: c=IN IP4 333.333.333.333 (23) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Line: t=0 0 (5) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Line: m=audio 8028 RTP/AVP 18 101 (27) [Mar 6 21:46:19] VERBOSE[28919] logger.c: -- Call on SIP/provider.tel-0a218a30 left from hold [Mar 6 21:46:19] VERBOSE[28919] logger.c: -- SIP/provider.tel-0a218a30 is making progress passing it to SIP/111.111.111.111-0a1c89f0 [Mar 6 21:46:19] DEBUG[28919] chan_sip.c: Early remote bridge setting SIP '0b32cd1413fb040b553c9bdb78540446@111.111.111.111' - Sending media to 333.333.333.333 [Mar 6 21:46:19] DEBUG[28919] rtp.c: Setting early bridge SDP of 'SIP/111.111.111.111-0a1c89f0' with that of 'SIP/provider.tel-0a218a30' [Mar 6 21:46:19] DEBUG[28919] chan_sip.c: Setting framing from config on incoming call [Mar 6 21:46:19] DEBUG[28919] chan_sip.c: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True [Mar 6 21:46:19] DEBUG[28919] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Mar 6 21:46:19] VERBOSE[28919] logger.c: Audio is at 222.222.222.222 port 16984 [Mar 6 21:46:19] VERBOSE[28919] logger.c: Adding codec 0x4 (ulaw) to SDP [Mar 6 21:46:19] VERBOSE[28919] logger.c: Adding codec 0x8 (alaw) to SDP [Mar 6 21:46:19] VERBOSE[28919] logger.c: Adding codec 0x2 (gsm) to SDP [Mar 6 21:46:19] VERBOSE[28919] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Mar 6 21:46:19] DEBUG[28919] chan_sip.c: -- Done with adding codecs to SDP [Mar 6 21:46:19] DEBUG[28919] chan_sip.c: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) [Mar 6 21:46:19] VERBOSE[28919] logger.c: <--- Transmitting (no NAT) to 111.111.111.111:5060 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 111.111.111.111:5060;branch=z9hG4bK1421c3c5;received=111.111.111.111;rport=5060 From: "0000000000" ;tag=as0e16677e To: ;tag=as1c0f4d36 Call-ID: 0b32cd1413fb040b553c9bdb78540446@111.111.111.111 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 290 v=0 o=root 27906 27906 IN IP4 333.333.333.333 s=session c=IN IP4 333.333.333.333 t=0 0 m=audio 8028 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Line: a=rtpmap:18 G729/8000/1 (23) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Line: a=fmtp:101 0-15 (15) [Mar 6 21:46:19] VERBOSE[27968] logger.c: --- (9 headers 10 lines) --- [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '775523532ab3d8365e4645536315122b@222.222.222.222' Request 103: Found [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: SIP response 180 to standard invite [Mar 6 21:46:19] DEBUG[27968] devicestate.c: Notification of state change to be queued on device/channel SIP/provider.tel-0a218a30 [Mar 6 21:46:19] DEBUG[27954] devicestate.c: No provider found, checking channel drivers for SIP - provider.tel [Mar 6 21:46:19] DEBUG[27954] chan_sip.c: Checking device state for peer provider.tel [Mar 6 21:46:19] DEBUG[27954] devicestate.c: Changing state for SIP/provider.tel - state 1 (Not in use) [Mar 6 21:46:19] VERBOSE[27968] logger.c: Found RTP audio format 18 [Mar 6 21:46:19] VERBOSE[27968] logger.c: Found RTP audio format 101 [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: Peer doesn't provide T.38 UDPTL [Mar 6 21:46:19] VERBOSE[27968] logger.c: Peer audio RTP is at port 333.333.333.333:8028 [Mar 6 21:46:19] VERBOSE[27968] logger.c: Found description format G729 for ID 18 [Mar 6 21:46:19] VERBOSE[27968] logger.c: Found description format telephone-event for ID 101 [Mar 6 21:46:19] VERBOSE[27968] logger.c: Got unsupported a:fmtp in SDP offer [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: T38 state changed to 0 on channel SIP/provider.tel-0a218a30 [Mar 6 21:46:19] VERBOSE[27968] logger.c: Capabilities: us - 0x100 (g729), peer - audio=0x100 (g729)/video=0x0 (nothing), combined - 0x100 (g729) [Mar 6 21:46:19] VERBOSE[27968] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Mar 6 21:46:19] VERBOSE[27968] logger.c: Peer audio RTP is at port 333.333.333.333:8028 [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: We're settling with these formats: 0x100 (g729) [Mar 6 21:46:19] DEBUG[27968] chan_sip.c: We have an owner, now see if we need to change this call [Mar 6 21:46:19] VERBOSE[28919] logger.c: -- SIP/provider.tel-0a218a30 is ringing [Mar 6 21:46:19] DEBUG[28919] rtp.c: Setting early bridge SDP of 'SIP/111.111.111.111-0a1c89f0' with that of 'SIP/provider.tel-0a218a30' [Mar 6 21:46:19] DEBUG[28919] channel.c: Driver for channel 'SIP/111.111.111.111-0a1c89f0' does not support indication 3, emulating it [Mar 6 21:46:19] DEBUG[28919] channel.c: Prodding channel 'SIP/111.111.111.111-0a1c89f0' [Mar 6 21:46:19] DEBUG[28919] channel.c: Scheduling timer at 160 sample intervals [Mar 6 21:46:19] VERBOSE[28919] logger.c: -- Call on SIP/provider.tel-0a218a30 left from hold [Mar 6 21:46:19] DEBUG[28919] channel.c: Scheduling timer at 0 sample intervals [Mar 6 21:46:19] VERBOSE[28919] logger.c: -- SIP/provider.tel-0a218a30 is making progress passing it to SIP/111.111.111.111-0a1c89f0 [Mar 6 21:46:19] DEBUG[28919] rtp.c: Setting early bridge SDP of 'SIP/111.111.111.111-0a1c89f0' with that of 'SIP/provider.tel-0a218a30'