Aug 10 15:58:49 NOTICE[26543] cdr.c: CDR simple logging enabled. Aug 10 15:58:49 NOTICE[26543] res_odbc.c: registered database handle 'asterisk' dsn->[SQLAst1] Aug 10 15:58:49 NOTICE[26543] res_odbc.c: Connecting asterisk Aug 10 15:58:49 NOTICE[26543] res_odbc.c: res_odbc: Connected to asterisk [SQLAst1] Aug 10 15:58:49 NOTICE[26543] res_odbc.c: res_odbc loaded. Aug 10 15:58:49 NOTICE[26543] config.c: Registered Config Engine odbc Aug 10 15:58:49 WARNING[26543] pbx.c: Requested contexts didn't get merged Aug 10 15:58:59 VERBOSE[26558] logger.c: <-- SIP read from 216.254.64.3:5070: INVITE sip:9999@66.54.199.45 SIP/2.0 Via: SIP/2.0/UDP 216.254.64.3:5070;rport;branch=z9hG4bK823888 To: From: "6666" ;tag=808 Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 CSeq: 485 INVITE Max-Forwards: 20 User-Agent: Express Talk 2.02 Contact: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, INFO, REFER, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 357 v=0 o=- 819214683 819214712 IN IP4 216.254.64.3 s=Express Talk c=IN IP4 216.254.64.3 t=0 0 m=audio 8000 RTP/AVP 0 8 96 3 13 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:96 G726-32/8000 a=rtpmap:3 GSM/8000 a=rtpmap:13 CN/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=sendrecv a=local:10.0.1.27 8000 a=domain:216.254.64.3 Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 0: INVITE sip:9999@66.54.199.45 SIP/2.0 (36) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 1: Via: SIP/2.0/UDP 216.254.64.3:5070;rport;branch=z9hG4bK823888 (61) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 2: To: (27) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 3: From: "6666" ;tag=808 (44) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 4: Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 (51) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 5: CSeq: 485 INVITE (16) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 6: Max-Forwards: 20 (16) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 7: User-Agent: Express Talk 2.02 (29) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 8: Contact: (37) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, INFO, REFER, NOTIFY (61) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 10: Supported: replaces (19) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 11: Content-Type: application/sdp (29) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 12: Content-Length: 357 (19) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 13: (0) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: v=0 (3) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: o=- 819214683 819214712 IN IP4 216.254.64.3 (43) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: s=Express Talk (14) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: c=IN IP4 216.254.64.3 (21) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: t=0 0 (5) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: m=audio 8000 RTP/AVP 0 8 96 3 13 101 (36) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: a=rtpmap:96 G726-32/8000 (24) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: a=rtpmap:3 GSM/8000 (19) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: a=rtpmap:13 CN/8000 (19) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: a=fmtp:101 0-16 (15) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: a=sendrecv (10) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: a=local:10.0.1.27 8000 (22) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: a=domain:216.254.64.3 (21) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: (0) Aug 10 15:58:59 VERBOSE[26558] logger.c: --- (13 headers 17 lines)Aug 10 15:58:59 VERBOSE[26558] logger.c: --- (13 headers 17 lines)--- Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Allocating new SIP dialog for 1155233663-3888-HP15690206501@216.254.64.3 - INVITE (With RTP) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Begin: parsing SIP "Supported: replaces" Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Found SIP option: -replaces- Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Matched SIP option: replaces Aug 10 15:58:59 DEBUG[26558] chan_sip.c: * SIP extension value: 1 for call 1155233663-3888-HP15690206501@216.254.64.3 Aug 10 15:58:59 VERBOSE[26558] logger.c: Using INVITE request as basis request - 1155233663-3888-HP15690206501@216.254.64.3 Aug 10 15:58:59 VERBOSE[26558] logger.c: Sending to 216.254.64.3 : 5070 (NAT) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Setting NAT on RTP to 524288 Aug 10 15:58:59 VERBOSE[26558] logger.c: Reliably Transmitting (NAT) to 216.254.64.3:5070: SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 216.254.64.3:5070;branch=z9hG4bK823888;received=216.254.64.3;rport=5070 From: "6666" ;tag=808 To: ;tag=as1ecfed40 Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 CSeq: 485 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Proxy-Authenticate: Digest realm="asterisk", nonce="4d547326" Content-Length: 0 --- Aug 10 15:58:59 DEBUG[26558] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #11 Aug 10 15:58:59 VERBOSE[26558] logger.c: Scheduling destruction of call '1155233663-3888-HP15690206501@216.254.64.3' in 15000 ms Aug 10 15:58:59 VERBOSE[26558] logger.c: Found user '6666' Aug 10 15:58:59 VERBOSE[26558] logger.c: <-- SIP read from 216.254.64.3:5070: ACK sip:9999@66.54.199.45 SIP/2.0 Via: SIP/2.0/UDP 216.254.64.3:5070;rport;branch=z9hG4bK823888 To: ;tag=as1ecfed40 From: "6666" ;tag=808 Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 CSeq: 485 ACK Max-Forwards: 20 User-Agent: Express Talk 2.02 Content-Length: 0 Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 0: ACK sip:9999@66.54.199.45 SIP/2.0 (33) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 1: Via: SIP/2.0/UDP 216.254.64.3:5070;rport;branch=z9hG4bK823888 (61) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 2: To: ;tag=as1ecfed40 (42) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 3: From: "6666" ;tag=808 (44) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 4: Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 (51) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 5: CSeq: 485 ACK (13) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 6: Max-Forwards: 20 (16) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 7: User-Agent: Express Talk 2.02 (29) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 8: Content-Length: 0 (17) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 9: (0) Aug 10 15:58:59 VERBOSE[26558] logger.c: --- (9 headers 0 lines)Aug 10 15:58:59 VERBOSE[26558] logger.c: --- (9 headers 0 lines)--- Aug 10 15:58:59 DEBUG[26558] chan_sip.c: = Found Their Call ID: 1155233663-3888-HP15690206501@216.254.64.3 Their Tag 808 Our tag: as1ecfed40 Aug 10 15:58:59 DEBUG[26558] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Aug 10 15:58:59 DEBUG[26558] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #11 Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Stopping retransmission on '1155233663-3888-HP15690206501@216.254.64.3' of Response 485: Match Found Aug 10 15:58:59 VERBOSE[26558] logger.c: <-- SIP read from 216.254.64.3:5070: INVITE sip:9999@66.54.199.45 SIP/2.0 Via: SIP/2.0/UDP 216.254.64.3:5070;rport;branch=z9hG4bK833888 To: From: "6666" ;tag=808 Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 CSeq: 486 INVITE Max-Forwards: 20 User-Agent: Express Talk 2.02 Contact: Proxy-Authorization: Digest username="6666",realm="asterisk",nonce="4d547326",uri="sip:9999@66.54.199.45",response="0ac1471ce907a6173db4c84fd92c2c37",opaque="" Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, INFO, REFER, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 357 v=0 o=- 819214683 819214712 IN IP4 216.254.64.3 s=Express Talk c=IN IP4 216.254.64.3 t=0 0 m=audio 8000 RTP/AVP 0 8 96 3 13 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:96 G726-32/8000 a=rtpmap:3 GSM/8000 a=rtpmap:13 CN/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=sendrecv a=local:10.0.1.27 8000 a=domain:216.254.64.3 Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 0: INVITE sip:9999@66.54.199.45 SIP/2.0 (36) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 1: Via: SIP/2.0/UDP 216.254.64.3:5070;rport;branch=z9hG4bK833888 (61) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 2: To: (27) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 3: From: "6666" ;tag=808 (44) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 4: Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 (51) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 5: CSeq: 486 INVITE (16) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 6: Max-Forwards: 20 (16) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 7: User-Agent: Express Talk 2.02 (29) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 8: Contact: (37) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 9: Proxy-Authorization: Digest username="6666",realm="asterisk",nonce="4d547326",uri="sip:9999@66.54.199.45",response="0ac1471ce907a6173db4c84fd92c2c37",opaque="" (159) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, INFO, REFER, NOTIFY (61) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 11: Supported: replaces (19) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 12: Content-Type: application/sdp (29) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 13: Content-Length: 357 (19) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 14: (0) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: v=0 (3) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: o=- 819214683 819214712 IN IP4 216.254.64.3 (43) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: s=Express Talk (14) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: c=IN IP4 216.254.64.3 (21) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: t=0 0 (5) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: m=audio 8000 RTP/AVP 0 8 96 3 13 101 (36) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: a=rtpmap:96 G726-32/8000 (24) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: a=rtpmap:3 GSM/8000 (19) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: a=rtpmap:13 CN/8000 (19) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: a=fmtp:101 0-16 (15) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: a=sendrecv (10) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: a=local:10.0.1.27 8000 (22) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: a=domain:216.254.64.3 (21) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: (0) Aug 10 15:58:59 VERBOSE[26558] logger.c: --- (14 headers 17 lines)Aug 10 15:58:59 VERBOSE[26558] logger.c: --- (14 headers 17 lines)--- Aug 10 15:58:59 DEBUG[26558] chan_sip.c: = Found Their Call ID: 1155233663-3888-HP15690206501@216.254.64.3 Their Tag 808 Our tag: as1ecfed40 Aug 10 15:58:59 DEBUG[26558] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Aug 10 15:58:59 VERBOSE[26558] logger.c: Using INVITE request as basis request - 1155233663-3888-HP15690206501@216.254.64.3 Aug 10 15:58:59 VERBOSE[26558] logger.c: Sending to 216.254.64.3 : 5070 (NAT) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Setting NAT on RTP to 524288 Aug 10 15:58:59 VERBOSE[26558] logger.c: Found user '6666' Aug 10 15:58:59 VERBOSE[26558] logger.c: Found RTP audio format 0 Aug 10 15:58:59 VERBOSE[26558] logger.c: Found RTP audio format 8 Aug 10 15:58:59 VERBOSE[26558] logger.c: Found RTP audio format 96 Aug 10 15:58:59 VERBOSE[26558] logger.c: Found RTP audio format 3 Aug 10 15:58:59 VERBOSE[26558] logger.c: Found RTP audio format 13 Aug 10 15:58:59 VERBOSE[26558] logger.c: Found RTP audio format 101 Aug 10 15:58:59 VERBOSE[26558] logger.c: Peer audio RTP is at port 216.254.64.3:8000 Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Peer audio RTP is at port 216.254.64.3:8000 Aug 10 15:58:59 VERBOSE[26558] logger.c: Found description format PCMU Aug 10 15:58:59 VERBOSE[26558] logger.c: Found description format PCMA Aug 10 15:58:59 VERBOSE[26558] logger.c: Found description format G726-32 Aug 10 15:58:59 VERBOSE[26558] logger.c: Found description format GSM Aug 10 15:58:59 VERBOSE[26558] logger.c: Found description format CN Aug 10 15:58:59 VERBOSE[26558] logger.c: Found description format telephone-event Aug 10 15:58:59 VERBOSE[26558] logger.c: Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x1e (gsm|ulaw|alaw|g726)/video=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) Aug 10 15:58:59 VERBOSE[26558] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x3 (telephone-event|CN), combined - 0x1 (telephone-event) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Checking SIP call limits for device 6666 Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Updating call counter for incoming call Aug 10 15:58:59 VERBOSE[26558] logger.c: Looking for 9999 in testusers (domain 66.54.199.45) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: build_route: Contact hop: Aug 10 15:58:59 VERBOSE[26558] logger.c: list_route: hop: Aug 10 15:58:59 VERBOSE[26558] logger.c: Transmitting (NAT) to 216.254.64.3:5070: SIP/2.0 100 Trying Via: SIP/2.0/UDP 216.254.64.3:5070;branch=z9hG4bK833888;received=216.254.64.3;rport=5070 From: "6666" ;tag=808 To: Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 CSeq: 486 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Aug 10 15:58:59 DEBUG[26546] chan_sip.c: Checking device state for peer 6666 Aug 10 15:58:59 DEBUG[26546] devicestate.c: Changing state for SIP/6666 - state 2 (In use) Aug 10 15:58:59 DEBUG[26564] pbx.c: Launching 'AGI' Aug 10 15:58:59 VERBOSE[26564] logger.c: -- Executing AGI("SIP/6666-9611", "agi://localhost/ccswitch") in new stack Aug 10 15:58:59 DEBUG[26564] res_agi.c: Wow, connected! Aug 10 15:58:59 DEBUG[26564] chan_sip.c: sip_answer(SIP/6666-9611) Aug 10 15:58:59 VERBOSE[26564] logger.c: We're at 66.54.199.45 port 13880 Aug 10 15:58:59 VERBOSE[26564] logger.c: Adding codec 0x2 (gsm) to SDP Aug 10 15:58:59 VERBOSE[26564] logger.c: Adding codec 0x4 (ulaw) to SDP Aug 10 15:58:59 VERBOSE[26564] logger.c: Adding codec 0x8 (alaw) to SDP Aug 10 15:58:59 VERBOSE[26564] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Aug 10 15:58:59 VERBOSE[26564] logger.c: Reliably Transmitting (NAT) to 216.254.64.3:5070: SIP/2.0 200 OK Via: SIP/2.0/UDP 216.254.64.3:5070;branch=z9hG4bK833888;received=216.254.64.3;rport=5070 From: "6666" ;tag=808 To: ;tag=as51133505 Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 CSeq: 486 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 263 v=0 o=root 26543 26543 IN IP4 66.54.199.45 s=session c=IN IP4 66.54.199.45 t=0 0 m=audio 13880 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 - - - - --- Aug 10 15:58:59 DEBUG[26564] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #13 Aug 10 15:58:59 DEBUG[26546] chan_sip.c: Checking device state for peer 6666 Aug 10 15:58:59 DEBUG[26546] devicestate.c: Changing state for SIP/6666 - state 2 (In use) Aug 10 15:58:59 DEBUG[26565] app_queue.c: Device 'SIP/6666' changed to state '2' (In use) but we don't care because they're not a member of any queue. Aug 10 15:58:59 DEBUG[26566] app_queue.c: Device 'SIP/6666' changed to state '2' (In use) but we don't care because they're not a member of any queue. Aug 10 15:58:59 VERBOSE[26564] logger.c: -- AGI Script Executing Application: (Background) Options: (ccs/enterac) Aug 10 15:58:59 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:58:59 DEBUG[26564] rtp.c: Ooh, format changed from unknown to ulaw Aug 10 15:58:59 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:58:59 VERBOSE[26564] logger.c: -- Playing 'ccs/enterac' (language 'en') Aug 10 15:58:59 VERBOSE[26558] logger.c: <-- SIP read from 216.254.64.3:5070: ACK sip:9999@66.54.199.45 SIP/2.0 Via: SIP/2.0/UDP 216.254.64.3:5070;rport;branch=z9hG4bK843888 To: ;tag=as51133505 From: "6666" ;tag=808 Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 CSeq: 486 ACK Max-Forwards: 20 User-Agent: Express Talk 2.02 Proxy-Authorization: Digest username="6666",realm="asterisk",nonce="4d547326",uri="sip:9999@66.54.199.45",response="0ac1471ce907a6173db4c84fd92c2c37",opaque="" Content-Length: 0 Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 0: ACK sip:9999@66.54.199.45 SIP/2.0 (33) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 1: Via: SIP/2.0/UDP 216.254.64.3:5070;rport;branch=z9hG4bK843888 (61) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 2: To: ;tag=as51133505 (42) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 3: From: "6666" ;tag=808 (44) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 4: Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 (51) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 5: CSeq: 486 ACK (13) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 6: Max-Forwards: 20 (16) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 7: User-Agent: Express Talk 2.02 (29) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 8: Proxy-Authorization: Digest username="6666",realm="asterisk",nonce="4d547326",uri="sip:9999@66.54.199.45",response="0ac1471ce907a6173db4c84fd92c2c37",opaque="" (159) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 9: Content-Length: 0 (17) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 10: (0) Aug 10 15:58:59 VERBOSE[26558] logger.c: --- (10 headers 0 lines)Aug 10 15:58:59 VERBOSE[26558] logger.c: --- (10 headers 0 lines)--- Aug 10 15:58:59 DEBUG[26558] chan_sip.c: = Found Their Call ID: 1155233663-3888-HP15690206501@216.254.64.3 Their Tag 808 Our tag: as51133505 Aug 10 15:58:59 DEBUG[26558] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Aug 10 15:58:59 DEBUG[26558] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #13 Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Stopping retransmission on '1155233663-3888-HP15690206501@216.254.64.3' of Response 486: Match Found Aug 10 15:58:59 VERBOSE[26558] logger.c: <-- SIP read from 216.254.64.3:4501: Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Header 0: (0) Aug 10 15:58:59 DEBUG[26558] chan_sip.c: Line: (0) Aug 10 15:58:59 VERBOSE[26558] logger.c: --- (0 headers 1 lines)Aug 10 15:58:59 VERBOSE[26558] logger.c: --- (0 headers 1 lines)--- Aug 10 15:58:59 DEBUG[26564] chan_sip.c: Oooh, format changed to 2 Aug 10 15:58:59 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to read format ulaw Aug 10 15:58:59 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:58:59 DEBUG[26564] rtp.c: Ooh, format changed from ulaw to gsm Aug 10 15:59:01 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:01 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:01 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format ulaw Aug 10 15:59:05 DEBUG[26564] rtp.c: Sending dtmf: 49 (1), at 216.254.64.3 Aug 10 15:59:05 DEBUG[26564] rtp.c: Sending dtmf: 50 (2), at 216.254.64.3 Aug 10 15:59:05 DEBUG[26564] rtp.c: Sending dtmf: 51 (3), at 216.254.64.3 Aug 10 15:59:06 DEBUG[26564] rtp.c: Sending dtmf: 35 (#), at 216.254.64.3 Aug 10 15:59:06 VERBOSE[26564] logger.c: -- AGI Script Executing Application: (Background) Options: (ccs/youhave) Aug 10 15:59:06 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:06 DEBUG[26564] rtp.c: Difference is 34832, ms is 4374 Aug 10 15:59:06 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:06 VERBOSE[26564] logger.c: -- Playing 'ccs/youhave' (language 'en') Aug 10 15:59:07 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:07 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:07 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format ulaw Aug 10 15:59:07 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:07 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:07 VERBOSE[26564] logger.c: -- Playing 'digits/80' (language 'en') Aug 10 15:59:07 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:07 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:07 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format ulaw Aug 10 15:59:07 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:07 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:07 VERBOSE[26564] logger.c: -- Playing 'digits/3' (language 'en') Aug 10 15:59:08 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:08 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:08 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format ulaw Aug 10 15:59:08 VERBOSE[26564] logger.c: -- AGI Script Executing Application: (Background) Options: (ccs/dollarsand) Aug 10 15:59:08 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:08 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:08 VERBOSE[26564] logger.c: -- Playing 'ccs/dollarsand' (language 'en') Aug 10 15:59:09 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:09 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:09 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format ulaw Aug 10 15:59:09 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:09 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:09 VERBOSE[26564] logger.c: -- Playing 'digits/50' (language 'en') Aug 10 15:59:10 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:10 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:10 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format ulaw Aug 10 15:59:10 VERBOSE[26564] logger.c: -- AGI Script Executing Application: (Background) Options: (ccs/centsremaining) Aug 10 15:59:10 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:10 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:10 VERBOSE[26564] logger.c: -- Playing 'ccs/centsremaining' (language 'en') Aug 10 15:59:11 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:11 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:11 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format ulaw Aug 10 15:59:11 VERBOSE[26564] logger.c: -- AGI Script Executing Application: (Background) Options: (ccs/youhave) Aug 10 15:59:11 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:11 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:11 VERBOSE[26564] logger.c: -- Playing 'ccs/youhave' (language 'en') Aug 10 15:59:12 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:12 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:12 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format ulaw Aug 10 15:59:12 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:12 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:12 VERBOSE[26564] logger.c: -- Playing 'digits/5' (language 'en') Aug 10 15:59:12 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:12 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:12 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format ulaw Aug 10 15:59:12 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:12 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:12 VERBOSE[26564] logger.c: -- Playing 'digits/hundred' (language 'en') Aug 10 15:59:13 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:13 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:13 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format ulaw Aug 10 15:59:13 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:13 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:13 VERBOSE[26564] logger.c: -- Playing 'digits/50' (language 'en') Aug 10 15:59:14 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:14 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:14 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format ulaw Aug 10 15:59:14 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:14 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:14 VERBOSE[26564] logger.c: -- Playing 'digits/6' (language 'en') Aug 10 15:59:14 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:14 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:14 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format ulaw Aug 10 15:59:14 VERBOSE[26564] logger.c: -- AGI Script Executing Application: (Background) Options: (ccs/hyperspaceminutes) Aug 10 15:59:14 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:14 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:14 VERBOSE[26564] logger.c: -- Playing 'ccs/hyperspaceminutes' (language 'en') Aug 10 15:59:16 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:16 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:16 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format ulaw Aug 10 15:59:16 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:16 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:16 VERBOSE[26564] logger.c: -- Playing 'digits/7' (language 'en') Aug 10 15:59:16 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:16 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:16 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format ulaw Aug 10 15:59:16 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:16 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:16 VERBOSE[26564] logger.c: -- Playing 'digits/hundred' (language 'en') Aug 10 15:59:17 VERBOSE[26558] logger.c: <-- SIP read from 216.254.64.3:5070: Aug 10 15:59:17 VERBOSE[26558] logger.c: --- (0 headers 0 lines)Aug 10 15:59:17 VERBOSE[26558] logger.c: --- (0 headers 0 lines) Nat keepalive Aug 10 15:59:17 VERBOSE[26558] logger.c: --- (0 headers 0 lines) Nat keepalive --- Aug 10 15:59:17 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:17 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:17 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format ulaw Aug 10 15:59:17 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:17 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:17 VERBOSE[26564] logger.c: -- Playing 'digits/70' (language 'en') Aug 10 15:59:18 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:18 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:18 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format ulaw Aug 10 15:59:18 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:18 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:18 VERBOSE[26564] logger.c: -- Playing 'digits/7' (language 'en') Aug 10 15:59:19 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:19 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:19 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format ulaw Aug 10 15:59:19 VERBOSE[26564] logger.c: -- AGI Script Executing Application: (Background) Options: (ccs/enterdst) Aug 10 15:59:19 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:19 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:19 VERBOSE[26564] logger.c: -- Playing 'ccs/enterdst' (language 'en') Aug 10 15:59:21 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:21 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:21 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format ulaw Aug 10 15:59:21 DEBUG[26564] rtp.c: Sending dtmf: 55 (7), at 216.254.64.3 Aug 10 15:59:21 DEBUG[26564] rtp.c: Sending dtmf: 55 (7), at 216.254.64.3 Aug 10 15:59:22 DEBUG[26564] rtp.c: Sending dtmf: 55 (7), at 216.254.64.3 Aug 10 15:59:22 DEBUG[26564] rtp.c: Sending dtmf: 55 (7), at 216.254.64.3 Aug 10 15:59:22 DEBUG[26564] rtp.c: Sending dtmf: 35 (#), at 216.254.64.3 Aug 10 15:59:22 VERBOSE[26564] logger.c: -- AGI Script Executing Application: (Background) Options: (ccs/youhave) Aug 10 15:59:22 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:22 DEBUG[26564] rtp.c: Difference is 8144, ms is 1038 Aug 10 15:59:22 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:22 VERBOSE[26564] logger.c: -- Playing 'ccs/youhave' (language 'en') Aug 10 15:59:23 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:23 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:23 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format ulaw Aug 10 15:59:23 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:23 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:23 VERBOSE[26564] logger.c: -- Playing 'digits/15' (language 'en') Aug 10 15:59:24 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:24 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:24 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format ulaw Aug 10 15:59:24 VERBOSE[26564] logger.c: -- AGI Script Executing Application: (Background) Options: (ccs/minutesand) Aug 10 15:59:24 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:24 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:24 VERBOSE[26564] logger.c: -- Playing 'ccs/minutesand' (language 'en') Aug 10 15:59:25 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:25 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:25 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format ulaw Aug 10 15:59:25 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:25 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:25 VERBOSE[26564] logger.c: -- Playing 'digits/12' (language 'en') Aug 10 15:59:26 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:26 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:26 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format ulaw Aug 10 15:59:26 VERBOSE[26564] logger.c: -- AGI Script Executing Application: (Background) Options: (ccs/secondsremaining) Aug 10 15:59:26 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:26 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:26 VERBOSE[26564] logger.c: -- Playing 'ccs/secondsremaining' (language 'en') Aug 10 15:59:28 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:28 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:28 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format ulaw Aug 10 15:59:28 VERBOSE[26564] logger.c: -- AGI Script Executing Application: (SetCDRUserField) Options: () Aug 10 15:59:28 VERBOSE[26564] logger.c: -- AGI Script Executing Application: (ResetCDR) Options: (w) Aug 10 15:59:28 VERBOSE[26564] logger.c: > cdr_odbc: Query Successful! Aug 10 15:59:28 DEBUG[26564] pbx.c: Function result is '"6666" <6666>' Aug 10 15:59:28 DEBUG[26564] pbx.c: Function result is '6666' Aug 10 15:59:28 DEBUG[26564] pbx.c: Function result is '9999' Aug 10 15:59:28 DEBUG[26564] pbx.c: Function result is 'testusers' Aug 10 15:59:28 DEBUG[26564] pbx.c: Function result is 'SIP/6666-9611' Aug 10 15:59:28 DEBUG[26564] pbx.c: Function result is '(null)' Aug 10 15:59:28 DEBUG[26564] pbx.c: Function result is 'ResetCDR' Aug 10 15:59:28 DEBUG[26564] pbx.c: Function result is 'w' Aug 10 15:59:28 DEBUG[26564] pbx.c: Function result is '2006-08-10 15:58:59' Aug 10 15:59:28 DEBUG[26564] pbx.c: Function result is '2006-08-10 15:58:59' Aug 10 15:59:28 DEBUG[26564] pbx.c: Function result is '2006-08-10 15:59:28' Aug 10 15:59:28 DEBUG[26564] pbx.c: Function result is '29' Aug 10 15:59:28 DEBUG[26564] pbx.c: Function result is '29' Aug 10 15:59:28 DEBUG[26564] pbx.c: Function result is 'ANSWERED' Aug 10 15:59:28 DEBUG[26564] pbx.c: Function result is 'DOCUMENTATION' Aug 10 15:59:28 DEBUG[26564] pbx.c: Function result is '(null)' Aug 10 15:59:28 DEBUG[26564] pbx.c: Function result is '1155239939.0' Aug 10 15:59:28 DEBUG[26564] pbx.c: Function result is '(null)' Aug 10 15:59:28 VERBOSE[26564] logger.c: -- AGI Script Executing Application: (SetCDRUserField) Options: (00DBAE74-2D5E-40E7-9DDB-91F406833570) Aug 10 15:59:28 VERBOSE[26564] logger.c: -- AGI Script Executing Application: (Dial) Options: (SIP/17184095245|60|L(912000)) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Setting NAT on RTP to 524288 Aug 10 15:59:28 DEBUG[26564] channel.c: Not copying variable LIMIT_WARNING_FILE. Aug 10 15:59:28 DEBUG[26564] channel.c: Not copying variable STACK-testusers-9999-1. Aug 10 15:59:28 DEBUG[26564] channel.c: Not copying variable SIPCALLID. Aug 10 15:59:28 DEBUG[26564] channel.c: Not copying variable SIPUSERAGENT. Aug 10 15:59:28 DEBUG[26564] channel.c: Not copying variable SIPDOMAIN. Aug 10 15:59:28 DEBUG[26564] channel.c: Not copying variable SIPURI. Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Outgoing Call for 17184095245 Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Updating call counter for outgoing call Aug 10 15:59:28 VERBOSE[26564] logger.c: We're at 66.54.199.45 port 19494 Aug 10 15:59:28 VERBOSE[26564] logger.c: Adding codec 0x2 (gsm) to SDP Aug 10 15:59:28 VERBOSE[26564] logger.c: Adding codec 0x4 (ulaw) to SDP Aug 10 15:59:28 VERBOSE[26564] logger.c: Adding codec 0x8 (alaw) to SDP Aug 10 15:59:28 VERBOSE[26564] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Header 0: INVITE sip:17184095245@216.254.64.3:4501;rinstance=7cae05431a8c0d97 SIP/2.0 (75) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Header 1: Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK41a7671e;rport (63) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Header 2: From: "6666" ;tag=as75456b0a (51) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Header 3: To: (66) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Header 4: Contact: (32) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Header 5: Call-ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 (54) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Header 6: CSeq: 102 INVITE (16) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Header 8: Max-Forwards: 70 (16) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Header 9: Date: Thu, 10 Aug 2006 19:59:28 GMT (35) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Header 11: Content-Type: application/sdp (29) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Header 12: Content-Length: 263 (19) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Header 13: (0) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Line: v=0 (3) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Line: o=root 26543 26543 IN IP4 66.54.199.45 (38) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Line: s=session (9) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Line: c=IN IP4 66.54.199.45 (21) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Line: t=0 0 (5) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Line: m=audio 19494 RTP/AVP 3 0 8 101 (31) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Line: a=rtpmap:3 GSM/8000 (19) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Line: a=fmtp:101 0-16 (15) Aug 10 15:59:28 DEBUG[26564] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Aug 10 15:59:28 VERBOSE[26564] logger.c: 13 headers, 12 lines Aug 10 15:59:28 VERBOSE[26564] logger.c: Reliably Transmitting (NAT) to 216.254.64.3:4501: INVITE sip:17184095245@216.254.64.3:4501;rinstance=7cae05431a8c0d97 SIP/2.0 Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK41a7671e;rport From: "6666" ;tag=as75456b0a To: Contact: Call-ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 10 Aug 2006 19:59:28 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 263 v=0 o=root 26543 26543 IN IP4 66.54.199.45 s=session c=IN IP4 66.54.199.45 t=0 0 m=audio 19494 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 - - - - --- Aug 10 15:59:28 DEBUG[26564] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #14 Aug 10 15:59:28 VERBOSE[26564] logger.c: -- Called 17184095245 Aug 10 15:59:28 DEBUG[26564] channel.c: Set channel SIP/17184095245-acda to read format slin Aug 10 15:59:28 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format slin Aug 10 15:59:28 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to read format slin Aug 10 15:59:28 DEBUG[26564] channel.c: Set channel SIP/17184095245-acda to write format slin Aug 10 15:59:28 VERBOSE[26558] logger.c: <-- SIP read from 216.254.64.3:4501: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK41a7671e;rport=5060 Contact: To: ;tag=9c787400 From: "6666";tag=as75456b0a Call-ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 CSeq: 102 INVITE User-Agent: X-Lite release 1002tx stamp 29712 Content-Length: 0 Aug 10 15:59:28 DEBUG[26558] chan_sip.c: Header 0: SIP/2.0 180 Ringing (19) Aug 10 15:59:28 DEBUG[26558] chan_sip.c: Header 1: Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK41a7671e;rport=5060 (68) Aug 10 15:59:28 DEBUG[26558] chan_sip.c: Header 2: Contact: (71) Aug 10 15:59:28 DEBUG[26558] chan_sip.c: Header 3: To: ;tag=9c787400 (79) Aug 10 15:59:28 DEBUG[26558] chan_sip.c: Header 4: From: "6666";tag=as75456b0a (50) Aug 10 15:59:28 DEBUG[26558] chan_sip.c: Header 5: Call-ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 (54) Aug 10 15:59:28 DEBUG[26558] chan_sip.c: Header 6: CSeq: 102 INVITE (16) Aug 10 15:59:28 DEBUG[26558] chan_sip.c: Header 7: User-Agent: X-Lite release 1002tx stamp 29712 (45) Aug 10 15:59:28 DEBUG[26558] chan_sip.c: Header 8: Content-Length: 0 (17) Aug 10 15:59:28 DEBUG[26558] chan_sip.c: Header 9: (0) Aug 10 15:59:28 VERBOSE[26558] logger.c: --- (9 headers 0 lines)Aug 10 15:59:28 VERBOSE[26558] logger.c: --- (9 headers 0 lines)--- Aug 10 15:59:28 DEBUG[26558] chan_sip.c: = Found Their Call ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 Their Tag Our tag: as75456b0a Aug 10 15:59:28 DEBUG[26558] chan_sip.c: *** SIP TIMER: Cancelling retransmission #14 - INVITE (got response) Aug 10 15:59:28 DEBUG[26558] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '417d992248a6cef32f4b450e407c41d5@66.54.199.45' Request 102: Found Aug 10 15:59:28 DEBUG[26558] chan_sip.c: SIP response 180 to standard invite Aug 10 15:59:28 VERBOSE[26564] logger.c: -- SIP/17184095245-acda is ringing Aug 10 15:59:28 DEBUG[26564] channel.c: Driver for channel 'SIP/6666-9611' does not support indication 3, emulating it Aug 10 15:59:28 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format slin Aug 10 15:59:28 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:28 DEBUG[26546] chan_sip.c: Checking device state for peer 17184095245 Aug 10 15:59:28 DEBUG[26546] devicestate.c: Changing state for SIP/17184095245 - state 6 (Ringing) Aug 10 15:59:28 DEBUG[26567] app_queue.c: Device 'SIP/17184095245' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. Aug 10 15:59:28 DEBUG[26564] channel.c: Generator got voice, switching to phase locked mode Aug 10 15:59:28 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:28 DEBUG[26564] rtp.c: Difference is 1376, ms is 192 Aug 10 15:59:29 DEBUG[26564] rtp.c: RTCP NAT: Got RTCP from other end. Now sending to address 216.254.64.3:4503 Aug 10 15:59:29 DEBUG[26564] rtp.c: Got RTCP report of 132 bytes Aug 10 15:59:29 VERBOSE[26558] logger.c: <-- SIP read from 216.254.64.3:4501: SIP/2.0 200 OK Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK41a7671e;rport=5060 Contact: To: ;tag=9c787400 From: "6666";tag=as75456b0a Call-ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 CSeq: 102 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp User-Agent: X-Lite release 1002tx stamp 29712 Content-Length: 236 v=0 o=- 7 2 IN IP4 10.0.1.27 s= c=IN IP4 10.0.1.27 t=0 0 m=audio 4502 RTP/AVP 3 0 8 101 a=fmtp:101 0-15 a=rtpmap:101 telephone-event/8000 a=sendrecv a=x-rtp-session-id:4A75B416D2CC47FE9BEEC400BF3CF132 Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 1: Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK41a7671e;rport=5060 (68) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 2: Contact: (71) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 3: To: ;tag=9c787400 (79) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 4: From: "6666";tag=as75456b0a (50) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 5: Call-ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 (54) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 6: CSeq: 102 INVITE (16) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO (81) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 8: Content-Type: application/sdp (29) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 9: User-Agent: X-Lite release 1002tx stamp 29712 (45) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 10: Content-Length: 236 (19) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 11: (0) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: v=0 (3) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: o=- 7 2 IN IP4 10.0.1.27 (24) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: s= (27) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: c=IN IP4 10.0.1.27 (18) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: t=0 0 (5) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: m=audio 4502 RTP/AVP 3 0 8 101 (30) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=fmtp:101 0-15 (15) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=sendrecv (10) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=x-rtp-session-id:4A75B416D2CC47FE9BEEC400BF3CF132 (51) Aug 10 15:59:29 VERBOSE[26558] logger.c: --- (11 headers 10 lines)Aug 10 15:59:29 VERBOSE[26558] logger.c: --- (11 headers 10 lines)--- Aug 10 15:59:29 DEBUG[26558] chan_sip.c: = Found Their Call ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 Their Tag 9c787400 Our tag: as75456b0a Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Acked pending invite 102 Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Stopping retransmission on '417d992248a6cef32f4b450e407c41d5@66.54.199.45' of Request 102: Match Found Aug 10 15:59:29 DEBUG[26558] chan_sip.c: SIP response 200 to standard invite Aug 10 15:59:29 VERBOSE[26558] logger.c: Found RTP audio format 3 Aug 10 15:59:29 VERBOSE[26558] logger.c: Found RTP audio format 0 Aug 10 15:59:29 VERBOSE[26558] logger.c: Found RTP audio format 8 Aug 10 15:59:29 VERBOSE[26558] logger.c: Found RTP audio format 101 Aug 10 15:59:29 VERBOSE[26558] logger.c: Peer audio RTP is at port 10.0.1.27:4502 Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Peer audio RTP is at port 10.0.1.27:4502 Aug 10 15:59:29 VERBOSE[26558] logger.c: Found description format telephone-event Aug 10 15:59:29 VERBOSE[26558] logger.c: Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0xe (gsm|ulaw|alaw)/video=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) Aug 10 15:59:29 VERBOSE[26558] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: build_route: Contact hop: Aug 10 15:59:29 VERBOSE[26558] logger.c: list_route: hop: Aug 10 15:59:29 VERBOSE[26558] logger.c: set_destination: Parsing for address/port to send to Aug 10 15:59:29 VERBOSE[26558] logger.c: set_destination: set destination to 216.254.64.3, port 4501 Aug 10 15:59:29 VERBOSE[26558] logger.c: Transmitting (NAT) to 216.254.64.3:4501: ACK sip:17184095245@216.254.64.3:4501;rinstance=7cae05431a8c0d97 SIP/2.0 Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK76c4a0b0;rport From: "6666" ;tag=as75456b0a To: ;tag=9c787400 Contact: Call-ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Aug 10 15:59:29 VERBOSE[26564] logger.c: -- SIP/17184095245-acda answered SIP/6666-9611 Aug 10 15:59:29 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format slin Aug 10 15:59:29 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:29 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to read format slin Aug 10 15:59:29 DEBUG[26564] channel.c: Set channel SIP/17184095245-acda to write format slin Aug 10 15:59:29 DEBUG[26564] channel.c: Set channel SIP/17184095245-acda to read format slin Aug 10 15:59:29 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format slin Aug 10 15:59:29 VERBOSE[26564] logger.c: -- Attempting native bridge of SIP/6666-9611 and SIP/17184095245-acda Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Sending reinvite on SIP '1155233663-3888-HP15690206501@216.254.64.3' - It's audio soon redirected to IP 10.0.1.27 Aug 10 15:59:29 VERBOSE[26564] logger.c: set_destination: Parsing for address/port to send to Aug 10 15:59:29 VERBOSE[26564] logger.c: set_destination: set destination to 216.254.64.3, port 5070 Aug 10 15:59:29 VERBOSE[26564] logger.c: We're at 66.54.199.45 port 13880 Aug 10 15:59:29 VERBOSE[26564] logger.c: Adding codec 0x2 (gsm) to SDP Aug 10 15:59:29 VERBOSE[26564] logger.c: Adding codec 0x4 (ulaw) to SDP Aug 10 15:59:29 VERBOSE[26564] logger.c: Adding codec 0x8 (alaw) to SDP Aug 10 15:59:29 VERBOSE[26564] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 0: INVITE sip:6666@216.254.64.3:5070 SIP/2.0 (41) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 1: Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK141d725a;rport (63) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 2: From: ;tag=as51133505 (44) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 3: To: "6666" ;tag=808 (42) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 4: Contact: (32) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 5: Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 (51) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 6: CSeq: 102 INVITE (16) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 8: Max-Forwards: 70 (16) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 10: X-asterisk-info: SIP re-invite (RTP bridge) (43) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 11: Content-Type: application/sdp (29) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 12: Content-Length: 256 (19) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 13: (0) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: v=0 (3) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: o=root 26543 26544 IN IP4 10.0.1.27 (35) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: s=session (9) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: c=IN IP4 10.0.1.27 (18) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: t=0 0 (5) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: m=audio 4502 RTP/AVP 3 0 8 101 (30) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: a=rtpmap:3 GSM/8000 (19) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: a=fmtp:101 0-16 (15) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Aug 10 15:59:29 VERBOSE[26564] logger.c: 13 headers, 12 lines Aug 10 15:59:29 VERBOSE[26564] logger.c: Reliably Transmitting (NAT) to 216.254.64.3:5070: INVITE sip:6666@216.254.64.3:5070 SIP/2.0 Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK141d725a;rport From: ;tag=as51133505 To: "6666" ;tag=808 Contact: Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY X-asterisk-info: SIP re-invite (RTP bridge) Content-Type: application/sdp Content-Length: 256 v=0 o=root 26543 26544 IN IP4 10.0.1.27 s=session c=IN IP4 10.0.1.27 t=0 0 m=audio 4502 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 - - - - --- Aug 10 15:59:29 DEBUG[26564] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #16 Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Sending reinvite on SIP '417d992248a6cef32f4b450e407c41d5@66.54.199.45' - It's audio soon redirected to IP 216.254.64.3 Aug 10 15:59:29 VERBOSE[26564] logger.c: set_destination: Parsing for address/port to send to Aug 10 15:59:29 VERBOSE[26564] logger.c: set_destination: set destination to 216.254.64.3, port 4501 Aug 10 15:59:29 VERBOSE[26564] logger.c: We're at 66.54.199.45 port 19494 Aug 10 15:59:29 VERBOSE[26564] logger.c: Adding codec 0x2 (gsm) to SDP Aug 10 15:59:29 VERBOSE[26564] logger.c: Adding codec 0x4 (ulaw) to SDP Aug 10 15:59:29 VERBOSE[26564] logger.c: Adding codec 0x8 (alaw) to SDP Aug 10 15:59:29 VERBOSE[26564] logger.c: Adding codec 0x10 (g726) to SDP Aug 10 15:59:29 VERBOSE[26564] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 0: INVITE sip:17184095245@216.254.64.3:4501;rinstance=7cae05431a8c0d97 SIP/2.0 (75) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 1: Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK7ef73ff4;rport (63) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 2: From: "6666" ;tag=as75456b0a (51) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 3: To: ;tag=9c787400 (79) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 4: Contact: (32) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 5: Call-ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 (54) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 6: CSeq: 103 INVITE (16) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 8: Max-Forwards: 70 (16) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 10: X-asterisk-info: SIP re-invite (RTP bridge) (43) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 11: Content-Type: application/sdp (29) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 12: Content-Length: 293 (19) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Header 13: (0) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: v=0 (3) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: o=root 26543 26544 IN IP4 216.254.64.3 (38) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: s=session (9) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: c=IN IP4 216.254.64.3 (21) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: t=0 0 (5) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: m=audio 8000 RTP/AVP 3 0 8 111 101 (34) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: a=rtpmap:3 GSM/8000 (19) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: a=rtpmap:111 G726-32/8000 (25) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: a=fmtp:101 0-16 (15) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Aug 10 15:59:29 VERBOSE[26564] logger.c: 13 headers, 13 lines Aug 10 15:59:29 VERBOSE[26564] logger.c: Reliably Transmitting (NAT) to 216.254.64.3:4501: INVITE sip:17184095245@216.254.64.3:4501;rinstance=7cae05431a8c0d97 SIP/2.0 Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK7ef73ff4;rport From: "6666" ;tag=as75456b0a To: ;tag=9c787400 Contact: Call-ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 CSeq: 103 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY X-asterisk-info: SIP re-invite (RTP bridge) Content-Type: application/sdp Content-Length: 293 v=0 o=root 26543 26544 IN IP4 216.254.64.3 s=session c=IN IP4 216.254.64.3 t=0 0 m=audio 8000 RTP/AVP 3 0 8 111 101 a=rtpmap:3 GSM/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:111 G726-32/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Aug 10 15:59:29 DEBUG[26564] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #17 Aug 10 15:59:29 DEBUG[26564] rtp.c: RTP NAT: Got audio from other end. Now sending to address 216.254.64.3:4502 Aug 10 15:59:29 DEBUG[26564] rtp.c: Oooh, 'SIP/17184095245-acda' changed end address to 216.254.64.3:4502 (format 14) Aug 10 15:59:29 DEBUG[26564] rtp.c: Oooh, 'SIP/17184095245-acda' changed end vaddress to 0.0.0.0:0 (format 14) Aug 10 15:59:29 DEBUG[26564] rtp.c: Oooh, 'SIP/17184095245-acda' was 10.0.1.27:4502/(format 14) Aug 10 15:59:29 DEBUG[26564] rtp.c: Oooh, 'SIP/17184095245-acda' was 0.0.0.0:0/(format 14) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Deferring reinvite on SIP '1155233663-3888-HP15690206501@216.254.64.3' - It's audio will be redirected to IP 216.254.64.3 Aug 10 15:59:29 DEBUG[26564] rtp.c: Ooh, format changed from unknown to ulaw Aug 10 15:59:29 DEBUG[26546] chan_sip.c: Checking device state for peer 17184095245 Aug 10 15:59:29 DEBUG[26546] devicestate.c: Changing state for SIP/17184095245 - state 2 (In use) Aug 10 15:59:29 DEBUG[26568] app_queue.c: Device 'SIP/17184095245' changed to state '2' (In use) but we don't care because they're not a member of any queue. Aug 10 15:59:29 VERBOSE[26558] logger.c: <-- SIP read from 216.254.64.3:5070: SIP/2.0 200 OK Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK141d725a;rport To: "6666" ;tag=808 From: ;tag=as51133505 Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 CSeq: 102 INVITE User-Agent: Express Talk 2.02 Contact: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY Accept: application/sdp Supported: replaces Content-Type: application/sdp Content-Length: 301 v=0 o=- 819214683 819214715 IN IP4 216.254.64.3 s=Express Talk c=IN IP4 10.0.1.27 t=0 0 m=audio 8000 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=sendrecv a=local:10.0.1.27 8000 a=domain:216.254.64.3 Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 1: Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK141d725a;rport (63) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 2: To: "6666" ;tag=808 (42) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 3: From: ;tag=as51133505 (44) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 4: Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 (51) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 5: CSeq: 102 INVITE (16) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 6: User-Agent: Express Talk 2.02 (29) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 7: Contact: (37) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 8: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY (55) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 9: Accept: application/sdp (23) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 10: Supported: replaces (19) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 11: Content-Type: application/sdp (29) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 12: Content-Length: 301 (19) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 13: (0) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: v=0 (3) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: o=- 819214683 819214715 IN IP4 216.254.64.3 (43) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: s=Express Talk (14) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: c=IN IP4 10.0.1.27 (18) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: t=0 0 (5) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: m=audio 8000 RTP/AVP 3 0 8 101 (30) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=rtpmap:3 GSM/8000 (19) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=fmtp:101 0-16 (15) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=sendrecv (10) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=local:10.0.1.27 8000 (22) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=domain:216.254.64.3 (21) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: (0) Aug 10 15:59:29 VERBOSE[26558] logger.c: --- (13 headers 15 lines)Aug 10 15:59:29 VERBOSE[26558] logger.c: --- (13 headers 15 lines)--- Aug 10 15:59:29 DEBUG[26558] chan_sip.c: = No match Their Call ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 Their Tag 9c787400 Our tag: as75456b0a Aug 10 15:59:29 DEBUG[26558] chan_sip.c: = Found Their Call ID: 1155233663-3888-HP15690206501@216.254.64.3 Their Tag 808 Our tag: as51133505 Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Acked pending invite 102 Aug 10 15:59:29 DEBUG[26558] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #16 Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Stopping retransmission on '1155233663-3888-HP15690206501@216.254.64.3' of Request 102: Match Found Aug 10 15:59:29 DEBUG[26558] chan_sip.c: SIP response 200 to RE-invite on outgoing call 1155233663-3888-HP15690206501@216.254.64.3 Aug 10 15:59:29 VERBOSE[26558] logger.c: Found RTP audio format 3 Aug 10 15:59:29 VERBOSE[26558] logger.c: Found RTP audio format 0 Aug 10 15:59:29 VERBOSE[26558] logger.c: Found RTP audio format 8 Aug 10 15:59:29 VERBOSE[26558] logger.c: Found RTP audio format 101 Aug 10 15:59:29 VERBOSE[26558] logger.c: Peer audio RTP is at port 10.0.1.27:8000 Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Peer audio RTP is at port 10.0.1.27:8000 Aug 10 15:59:29 VERBOSE[26558] logger.c: Found description format GSM Aug 10 15:59:29 VERBOSE[26558] logger.c: Found description format PCMU Aug 10 15:59:29 VERBOSE[26558] logger.c: Found description format PCMA Aug 10 15:59:29 VERBOSE[26558] logger.c: Found description format telephone-event Aug 10 15:59:29 VERBOSE[26558] logger.c: Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0xe (gsm|ulaw|alaw)/video=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) Aug 10 15:59:29 VERBOSE[26558] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: build_route: Contact hop: Aug 10 15:59:29 VERBOSE[26558] logger.c: list_route: hop: Aug 10 15:59:29 VERBOSE[26558] logger.c: set_destination: Parsing for address/port to send to Aug 10 15:59:29 VERBOSE[26558] logger.c: set_destination: set destination to 216.254.64.3, port 5070 Aug 10 15:59:29 VERBOSE[26558] logger.c: Transmitting (NAT) to 216.254.64.3:5070: ACK sip:6666@216.254.64.3:5070 SIP/2.0 Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK0d11e599;rport From: ;tag=as51133505 To: "6666" ;tag=808 Contact: Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Sending pending reinvite on '1155233663-3888-HP15690206501@216.254.64.3' Aug 10 15:59:29 VERBOSE[26558] logger.c: set_destination: Parsing for address/port to send to Aug 10 15:59:29 VERBOSE[26558] logger.c: set_destination: set destination to 216.254.64.3, port 5070 Aug 10 15:59:29 VERBOSE[26558] logger.c: We're at 66.54.199.45 port 13880 Aug 10 15:59:29 VERBOSE[26558] logger.c: Adding codec 0x2 (gsm) to SDP Aug 10 15:59:29 VERBOSE[26558] logger.c: Adding codec 0x4 (ulaw) to SDP Aug 10 15:59:29 VERBOSE[26558] logger.c: Adding codec 0x8 (alaw) to SDP Aug 10 15:59:29 VERBOSE[26558] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 0: INVITE sip:6666@216.254.64.3:5070 SIP/2.0 (41) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 1: Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK377ff518;rport (63) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 2: From: ;tag=as51133505 (44) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 3: To: "6666" ;tag=808 (42) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 4: Contact: (32) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 5: Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 (51) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 6: CSeq: 103 INVITE (16) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 8: Max-Forwards: 70 (16) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 10: X-asterisk-info: SIP re-invite (RTP bridge) (43) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 11: Content-Type: application/sdp (29) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 12: Content-Length: 262 (19) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 13: (0) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: v=0 (3) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: o=root 26543 26545 IN IP4 216.254.64.3 (38) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: s=session (9) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: c=IN IP4 216.254.64.3 (21) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: t=0 0 (5) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: m=audio 4502 RTP/AVP 3 0 8 101 (30) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=rtpmap:3 GSM/8000 (19) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=fmtp:101 0-16 (15) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Aug 10 15:59:29 VERBOSE[26558] logger.c: 13 headers, 12 lines Aug 10 15:59:29 VERBOSE[26558] logger.c: Reliably Transmitting (NAT) to 216.254.64.3:5070: INVITE sip:6666@216.254.64.3:5070 SIP/2.0 Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK377ff518;rport From: ;tag=as51133505 To: "6666" ;tag=808 Contact: Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 CSeq: 103 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY X-asterisk-info: SIP re-invite (RTP bridge) Content-Type: application/sdp Content-Length: 262 v=0 o=root 26543 26545 IN IP4 216.254.64.3 s=session c=IN IP4 216.254.64.3 t=0 0 m=audio 4502 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 - - - - --- Aug 10 15:59:29 DEBUG[26558] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #18 Aug 10 15:59:29 DEBUG[26564] rtp.c: Oooh, 'SIP/6666-9611' changed end address to 10.0.1.27:8000 (format 14) Aug 10 15:59:29 DEBUG[26564] rtp.c: Oooh, 'SIP/6666-9611' was 216.254.64.3:8000/(format 30) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Deferring reinvite on SIP '417d992248a6cef32f4b450e407c41d5@66.54.199.45' - It's audio will be redirected to IP 10.0.1.27 Aug 10 15:59:29 VERBOSE[26558] logger.c: <-- SIP read from 216.254.64.3:4501: SIP/2.0 200 OK Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK7ef73ff4;rport=5060 Contact: To: ;tag=9c787400 From: "6666";tag=as75456b0a Call-ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 CSeq: 103 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp User-Agent: X-Lite release 1002tx stamp 29712 Content-Length: 236 v=0 o=- 7 2 IN IP4 10.0.1.27 s= c=IN IP4 10.0.1.27 t=0 0 m=audio 4502 RTP/AVP 3 0 8 101 a=fmtp:101 0-15 a=rtpmap:101 telephone-event/8000 a=sendrecv a=x-rtp-session-id:4A75B416D2CC47FE9BEEC400BF3CF132 Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 1: Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK7ef73ff4;rport=5060 (68) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 2: Contact: (71) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 3: To: ;tag=9c787400 (79) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 4: From: "6666";tag=as75456b0a (50) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 5: Call-ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 (54) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 6: CSeq: 103 INVITE (16) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO (81) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 8: Content-Type: application/sdp (29) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 9: User-Agent: X-Lite release 1002tx stamp 29712 (45) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 10: Content-Length: 236 (19) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 11: (0) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: v=0 (3) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: o=- 7 2 IN IP4 10.0.1.27 (24) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: s= (27) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: c=IN IP4 10.0.1.27 (18) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: t=0 0 (5) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: m=audio 4502 RTP/AVP 3 0 8 101 (30) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=fmtp:101 0-15 (15) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=sendrecv (10) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=x-rtp-session-id:4A75B416D2CC47FE9BEEC400BF3CF132 (51) Aug 10 15:59:29 VERBOSE[26558] logger.c: --- (11 headers 10 lines)Aug 10 15:59:29 VERBOSE[26558] logger.c: --- (11 headers 10 lines)--- Aug 10 15:59:29 DEBUG[26558] chan_sip.c: = Found Their Call ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 Their Tag 9c787400 Our tag: as75456b0a Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Acked pending invite 103 Aug 10 15:59:29 DEBUG[26558] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #17 Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Stopping retransmission on '417d992248a6cef32f4b450e407c41d5@66.54.199.45' of Request 103: Match Found Aug 10 15:59:29 DEBUG[26558] chan_sip.c: SIP response 200 to RE-invite on outgoing call 417d992248a6cef32f4b450e407c41d5@66.54.199.45 Aug 10 15:59:29 VERBOSE[26558] logger.c: Found RTP audio format 3 Aug 10 15:59:29 VERBOSE[26558] logger.c: Found RTP audio format 0 Aug 10 15:59:29 VERBOSE[26558] logger.c: Found RTP audio format 8 Aug 10 15:59:29 VERBOSE[26558] logger.c: Found RTP audio format 101 Aug 10 15:59:29 VERBOSE[26558] logger.c: Peer audio RTP is at port 10.0.1.27:4502 Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Peer audio RTP is at port 10.0.1.27:4502 Aug 10 15:59:29 VERBOSE[26558] logger.c: Found description format telephone-event Aug 10 15:59:29 VERBOSE[26558] logger.c: Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0xe (gsm|ulaw|alaw)/video=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) Aug 10 15:59:29 VERBOSE[26558] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: build_route: Retaining previous route: Aug 10 15:59:29 VERBOSE[26558] logger.c: set_destination: Parsing for address/port to send to Aug 10 15:59:29 VERBOSE[26558] logger.c: set_destination: set destination to 216.254.64.3, port 4501 Aug 10 15:59:29 VERBOSE[26558] logger.c: Transmitting (NAT) to 216.254.64.3:4501: ACK sip:17184095245@216.254.64.3:4501;rinstance=7cae05431a8c0d97 SIP/2.0 Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK64f1eb6b;rport From: "6666" ;tag=as75456b0a To: ;tag=9c787400 Contact: Call-ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 CSeq: 103 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Sending pending reinvite on '417d992248a6cef32f4b450e407c41d5@66.54.199.45' Aug 10 15:59:29 VERBOSE[26558] logger.c: set_destination: Parsing for address/port to send to Aug 10 15:59:29 VERBOSE[26558] logger.c: set_destination: set destination to 216.254.64.3, port 4501 Aug 10 15:59:29 VERBOSE[26558] logger.c: We're at 66.54.199.45 port 19494 Aug 10 15:59:29 VERBOSE[26558] logger.c: Adding codec 0x2 (gsm) to SDP Aug 10 15:59:29 VERBOSE[26558] logger.c: Adding codec 0x4 (ulaw) to SDP Aug 10 15:59:29 VERBOSE[26558] logger.c: Adding codec 0x8 (alaw) to SDP Aug 10 15:59:29 VERBOSE[26558] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 0: INVITE sip:17184095245@216.254.64.3:4501;rinstance=7cae05431a8c0d97 SIP/2.0 (75) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 1: Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK7d21a99d;rport (63) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 2: From: "6666" ;tag=as75456b0a (51) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 3: To: ;tag=9c787400 (79) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 4: Contact: (32) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 5: Call-ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 (54) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 6: CSeq: 104 INVITE (16) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 8: Max-Forwards: 70 (16) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 10: X-asterisk-info: SIP re-invite (RTP bridge) (43) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 11: Content-Type: application/sdp (29) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 12: Content-Length: 256 (19) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 13: (0) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: v=0 (3) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: o=root 26543 26545 IN IP4 10.0.1.27 (35) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: s=session (9) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: c=IN IP4 10.0.1.27 (18) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: t=0 0 (5) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: m=audio 8000 RTP/AVP 3 0 8 101 (30) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=rtpmap:3 GSM/8000 (19) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=fmtp:101 0-16 (15) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Aug 10 15:59:29 VERBOSE[26558] logger.c: 13 headers, 12 lines Aug 10 15:59:29 VERBOSE[26558] logger.c: Reliably Transmitting (NAT) to 216.254.64.3:4501: INVITE sip:17184095245@216.254.64.3:4501;rinstance=7cae05431a8c0d97 SIP/2.0 Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK7d21a99d;rport From: "6666" ;tag=as75456b0a To: ;tag=9c787400 Contact: Call-ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 CSeq: 104 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY X-asterisk-info: SIP re-invite (RTP bridge) Content-Type: application/sdp Content-Length: 256 v=0 o=root 26543 26545 IN IP4 10.0.1.27 s=session c=IN IP4 10.0.1.27 t=0 0 m=audio 8000 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 - - - - --- Aug 10 15:59:29 DEBUG[26558] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #19 Aug 10 15:59:29 DEBUG[26564] rtp.c: Oooh, 'SIP/17184095245-acda' changed end address to 10.0.1.27:4502 (format 14) Aug 10 15:59:29 DEBUG[26564] rtp.c: Oooh, 'SIP/17184095245-acda' changed end vaddress to 0.0.0.0:0 (format 14) Aug 10 15:59:29 DEBUG[26564] rtp.c: Oooh, 'SIP/17184095245-acda' was 216.254.64.3:4502/(format 14) Aug 10 15:59:29 DEBUG[26564] rtp.c: Oooh, 'SIP/17184095245-acda' was 0.0.0.0:0/(format 14) Aug 10 15:59:29 DEBUG[26564] chan_sip.c: Deferring reinvite on SIP '1155233663-3888-HP15690206501@216.254.64.3' - It's audio will be redirected to IP 10.0.1.27 Aug 10 15:59:29 VERBOSE[26558] logger.c: <-- SIP read from 216.254.64.3:4501: SIP/2.0 200 OK Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK7d21a99d;rport=5060 Contact: To: ;tag=9c787400 From: "6666";tag=as75456b0a Call-ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 CSeq: 104 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp User-Agent: X-Lite release 1002tx stamp 29712 Content-Length: 236 v=0 o=- 7 2 IN IP4 10.0.1.27 s= c=IN IP4 10.0.1.27 t=0 0 m=audio 4502 RTP/AVP 3 0 8 101 a=fmtp:101 0-15 a=rtpmap:101 telephone-event/8000 a=sendrecv a=x-rtp-session-id:4A75B416D2CC47FE9BEEC400BF3CF132 Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 1: Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK7d21a99d;rport=5060 (68) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 2: Contact: (71) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 3: To: ;tag=9c787400 (79) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 4: From: "6666";tag=as75456b0a (50) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 5: Call-ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 (54) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 6: CSeq: 104 INVITE (16) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 7: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO (81) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 8: Content-Type: application/sdp (29) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 9: User-Agent: X-Lite release 1002tx stamp 29712 (45) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 10: Content-Length: 236 (19) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 11: (0) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: v=0 (3) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: o=- 7 2 IN IP4 10.0.1.27 (24) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: s= (27) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: c=IN IP4 10.0.1.27 (18) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: t=0 0 (5) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: m=audio 4502 RTP/AVP 3 0 8 101 (30) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=fmtp:101 0-15 (15) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=sendrecv (10) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: a=x-rtp-session-id:4A75B416D2CC47FE9BEEC400BF3CF132 (51) Aug 10 15:59:29 VERBOSE[26558] logger.c: --- (11 headers 10 lines)Aug 10 15:59:29 VERBOSE[26558] logger.c: --- (11 headers 10 lines)--- Aug 10 15:59:29 DEBUG[26558] chan_sip.c: = Found Their Call ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 Their Tag 9c787400 Our tag: as75456b0a Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Acked pending invite 104 Aug 10 15:59:29 DEBUG[26558] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #19 Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Stopping retransmission on '417d992248a6cef32f4b450e407c41d5@66.54.199.45' of Request 104: Match Found Aug 10 15:59:29 DEBUG[26558] chan_sip.c: SIP response 200 to RE-invite on outgoing call 417d992248a6cef32f4b450e407c41d5@66.54.199.45 Aug 10 15:59:29 VERBOSE[26558] logger.c: Found RTP audio format 3 Aug 10 15:59:29 VERBOSE[26558] logger.c: Found RTP audio format 0 Aug 10 15:59:29 VERBOSE[26558] logger.c: Found RTP audio format 8 Aug 10 15:59:29 VERBOSE[26558] logger.c: Found RTP audio format 101 Aug 10 15:59:29 VERBOSE[26558] logger.c: Peer audio RTP is at port 10.0.1.27:4502 Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Peer audio RTP is at port 10.0.1.27:4502 Aug 10 15:59:29 VERBOSE[26558] logger.c: Found description format telephone-event Aug 10 15:59:29 VERBOSE[26558] logger.c: Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0xe (gsm|ulaw|alaw)/video=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) Aug 10 15:59:29 VERBOSE[26558] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: build_route: Retaining previous route: Aug 10 15:59:29 VERBOSE[26558] logger.c: set_destination: Parsing for address/port to send to Aug 10 15:59:29 VERBOSE[26558] logger.c: set_destination: set destination to 216.254.64.3, port 4501 Aug 10 15:59:29 VERBOSE[26558] logger.c: Transmitting (NAT) to 216.254.64.3:4501: ACK sip:17184095245@216.254.64.3:4501;rinstance=7cae05431a8c0d97 SIP/2.0 Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK0618c1a0;rport From: "6666" ;tag=as75456b0a To: ;tag=9c787400 Contact: Call-ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 CSeq: 104 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Aug 10 15:59:29 VERBOSE[26558] logger.c: <-- SIP read from 216.254.64.3:4501: Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Header 0: (0) Aug 10 15:59:29 DEBUG[26558] chan_sip.c: Line: (0) Aug 10 15:59:29 VERBOSE[26558] logger.c: --- (0 headers 1 lines)Aug 10 15:59:29 VERBOSE[26558] logger.c: --- (0 headers 1 lines)--- Aug 10 15:59:30 DEBUG[26558] chan_sip.c: SIP TIMER: Rescheduling retransmission #18 (1) INVITE - 5 Aug 10 15:59:30 DEBUG[26558] chan_sip.c: ** SIP timers: Rescheduling retransmission 2 to 1000 ms (t1 500 ms (Retrans id #18)) Aug 10 15:59:30 VERBOSE[26558] logger.c: Retransmitting #1 (NAT) to 216.254.64.3:5070: INVITE sip:6666@216.254.64.3:5070 SIP/2.0 Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK377ff518;rport From: ;tag=as51133505 To: "6666" ;tag=808 Contact: Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 CSeq: 103 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY X-asterisk-info: SIP re-invite (RTP bridge) Content-Type: application/sdp Content-Length: 262 v=0 o=root 26543 26545 IN IP4 216.254.64.3 s=session c=IN IP4 216.254.64.3 t=0 0 m=audio 4502 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 - - - - --- Aug 10 15:59:30 VERBOSE[26558] logger.c: <-- SIP read from 216.254.64.3:5070: SIP/2.0 200 OK Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK377ff518;rport To: "6666" ;tag=808 From: ;tag=as51133505 Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 CSeq: 103 INVITE User-Agent: Express Talk 2.02 Contact: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY Accept: application/sdp Supported: replaces Content-Type: application/sdp Content-Length: 301 v=0 o=- 819214683 819214717 IN IP4 216.254.64.3 s=Express Talk c=IN IP4 10.0.1.27 t=0 0 m=audio 8000 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=sendrecv a=local:10.0.1.27 8000 a=domain:216.254.64.3 Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 1: Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK377ff518;rport (63) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 2: To: "6666" ;tag=808 (42) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 3: From: ;tag=as51133505 (44) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 4: Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 (51) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 5: CSeq: 103 INVITE (16) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 6: User-Agent: Express Talk 2.02 (29) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 7: Contact: (37) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 8: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY (55) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 9: Accept: application/sdp (23) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 10: Supported: replaces (19) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 11: Content-Type: application/sdp (29) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 12: Content-Length: 301 (19) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 13: (0) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: v=0 (3) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: o=- 819214683 819214717 IN IP4 216.254.64.3 (43) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: s=Express Talk (14) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: c=IN IP4 10.0.1.27 (18) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: t=0 0 (5) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: m=audio 8000 RTP/AVP 3 0 8 101 (30) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: a=rtpmap:3 GSM/8000 (19) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: a=fmtp:101 0-16 (15) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: a=sendrecv (10) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: a=local:10.0.1.27 8000 (22) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: a=domain:216.254.64.3 (21) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: (0) Aug 10 15:59:30 VERBOSE[26558] logger.c: --- (13 headers 15 lines)Aug 10 15:59:30 VERBOSE[26558] logger.c: --- (13 headers 15 lines)--- Aug 10 15:59:30 DEBUG[26558] chan_sip.c: = No match Their Call ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 Their Tag 9c787400 Our tag: as75456b0a Aug 10 15:59:30 DEBUG[26558] chan_sip.c: = Found Their Call ID: 1155233663-3888-HP15690206501@216.254.64.3 Their Tag 808 Our tag: as51133505 Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Acked pending invite 103 Aug 10 15:59:30 DEBUG[26558] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #18 Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Stopping retransmission on '1155233663-3888-HP15690206501@216.254.64.3' of Request 103: Match Found Aug 10 15:59:30 DEBUG[26558] chan_sip.c: SIP response 200 to RE-invite on outgoing call 1155233663-3888-HP15690206501@216.254.64.3 Aug 10 15:59:30 VERBOSE[26558] logger.c: Found RTP audio format 3 Aug 10 15:59:30 VERBOSE[26558] logger.c: Found RTP audio format 0 Aug 10 15:59:30 VERBOSE[26558] logger.c: Found RTP audio format 8 Aug 10 15:59:30 VERBOSE[26558] logger.c: Found RTP audio format 101 Aug 10 15:59:30 VERBOSE[26558] logger.c: Peer audio RTP is at port 10.0.1.27:8000 Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Peer audio RTP is at port 10.0.1.27:8000 Aug 10 15:59:30 VERBOSE[26558] logger.c: Found description format GSM Aug 10 15:59:30 VERBOSE[26558] logger.c: Found description format PCMU Aug 10 15:59:30 VERBOSE[26558] logger.c: Found description format PCMA Aug 10 15:59:30 VERBOSE[26558] logger.c: Found description format telephone-event Aug 10 15:59:30 VERBOSE[26558] logger.c: Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0xe (gsm|ulaw|alaw)/video=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) Aug 10 15:59:30 VERBOSE[26558] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: build_route: Retaining previous route: Aug 10 15:59:30 VERBOSE[26558] logger.c: set_destination: Parsing for address/port to send to Aug 10 15:59:30 VERBOSE[26558] logger.c: set_destination: set destination to 216.254.64.3, port 5070 Aug 10 15:59:30 VERBOSE[26558] logger.c: Transmitting (NAT) to 216.254.64.3:5070: ACK sip:6666@216.254.64.3:5070 SIP/2.0 Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK6d60e1ce;rport From: ;tag=as51133505 To: "6666" ;tag=808 Contact: Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 CSeq: 103 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Sending pending reinvite on '1155233663-3888-HP15690206501@216.254.64.3' Aug 10 15:59:30 VERBOSE[26558] logger.c: set_destination: Parsing for address/port to send to Aug 10 15:59:30 VERBOSE[26558] logger.c: set_destination: set destination to 216.254.64.3, port 5070 Aug 10 15:59:30 VERBOSE[26558] logger.c: We're at 66.54.199.45 port 13880 Aug 10 15:59:30 VERBOSE[26558] logger.c: Adding codec 0x2 (gsm) to SDP Aug 10 15:59:30 VERBOSE[26558] logger.c: Adding codec 0x4 (ulaw) to SDP Aug 10 15:59:30 VERBOSE[26558] logger.c: Adding codec 0x8 (alaw) to SDP Aug 10 15:59:30 VERBOSE[26558] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 0: INVITE sip:6666@216.254.64.3:5070 SIP/2.0 (41) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 1: Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK6eb6bec9;rport (63) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 2: From: ;tag=as51133505 (44) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 3: To: "6666" ;tag=808 (42) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 4: Contact: (32) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 5: Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 (51) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 6: CSeq: 104 INVITE (16) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 8: Max-Forwards: 70 (16) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 10: X-asterisk-info: SIP re-invite (RTP bridge) (43) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 11: Content-Type: application/sdp (29) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 12: Content-Length: 256 (19) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 13: (0) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: v=0 (3) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: o=root 26543 26546 IN IP4 10.0.1.27 (35) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: s=session (9) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: c=IN IP4 10.0.1.27 (18) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: t=0 0 (5) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: m=audio 4502 RTP/AVP 3 0 8 101 (30) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: a=rtpmap:3 GSM/8000 (19) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: a=fmtp:101 0-16 (15) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Aug 10 15:59:30 VERBOSE[26558] logger.c: 13 headers, 12 lines Aug 10 15:59:30 VERBOSE[26558] logger.c: Reliably Transmitting (NAT) to 216.254.64.3:5070: INVITE sip:6666@216.254.64.3:5070 SIP/2.0 Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK6eb6bec9;rport From: ;tag=as51133505 To: "6666" ;tag=808 Contact: Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 CSeq: 104 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY X-asterisk-info: SIP re-invite (RTP bridge) Content-Type: application/sdp Content-Length: 256 v=0 o=root 26543 26546 IN IP4 10.0.1.27 s=session c=IN IP4 10.0.1.27 t=0 0 m=audio 4502 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 - - - - --- Aug 10 15:59:30 DEBUG[26558] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #20 Aug 10 15:59:30 VERBOSE[26558] logger.c: <-- SIP read from 216.254.64.3:5070: SIP/2.0 200 OK Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK6eb6bec9;rport To: "6666" ;tag=808 From: ;tag=as51133505 Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 CSeq: 104 INVITE User-Agent: Express Talk 2.02 Contact: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY Accept: application/sdp Supported: replaces Content-Type: application/sdp Content-Length: 301 v=0 o=- 819214683 819214729 IN IP4 216.254.64.3 s=Express Talk c=IN IP4 10.0.1.27 t=0 0 m=audio 8000 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=sendrecv a=local:10.0.1.27 8000 a=domain:216.254.64.3 Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 1: Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK6eb6bec9;rport (63) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 2: To: "6666" ;tag=808 (42) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 3: From: ;tag=as51133505 (44) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 4: Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 (51) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 5: CSeq: 104 INVITE (16) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 6: User-Agent: Express Talk 2.02 (29) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 7: Contact: (37) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 8: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY (55) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 9: Accept: application/sdp (23) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 10: Supported: replaces (19) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 11: Content-Type: application/sdp (29) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 12: Content-Length: 301 (19) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Header 13: (0) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: v=0 (3) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: o=- 819214683 819214729 IN IP4 216.254.64.3 (43) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: s=Express Talk (14) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: c=IN IP4 10.0.1.27 (18) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: t=0 0 (5) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: m=audio 8000 RTP/AVP 3 0 8 101 (30) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: a=rtpmap:3 GSM/8000 (19) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: a=fmtp:101 0-16 (15) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: a=sendrecv (10) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: a=local:10.0.1.27 8000 (22) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: a=domain:216.254.64.3 (21) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Line: (0) Aug 10 15:59:30 VERBOSE[26558] logger.c: --- (13 headers 15 lines)Aug 10 15:59:30 VERBOSE[26558] logger.c: --- (13 headers 15 lines)--- Aug 10 15:59:30 DEBUG[26558] chan_sip.c: = No match Their Call ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 Their Tag 9c787400 Our tag: as75456b0a Aug 10 15:59:30 DEBUG[26558] chan_sip.c: = Found Their Call ID: 1155233663-3888-HP15690206501@216.254.64.3 Their Tag 808 Our tag: as51133505 Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Acked pending invite 104 Aug 10 15:59:30 DEBUG[26558] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #20 Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Stopping retransmission on '1155233663-3888-HP15690206501@216.254.64.3' of Request 104: Match Found Aug 10 15:59:30 DEBUG[26558] chan_sip.c: SIP response 200 to RE-invite on outgoing call 1155233663-3888-HP15690206501@216.254.64.3 Aug 10 15:59:30 VERBOSE[26558] logger.c: Found RTP audio format 3 Aug 10 15:59:30 VERBOSE[26558] logger.c: Found RTP audio format 0 Aug 10 15:59:30 VERBOSE[26558] logger.c: Found RTP audio format 8 Aug 10 15:59:30 VERBOSE[26558] logger.c: Found RTP audio format 101 Aug 10 15:59:30 VERBOSE[26558] logger.c: Peer audio RTP is at port 10.0.1.27:8000 Aug 10 15:59:30 DEBUG[26558] chan_sip.c: Peer audio RTP is at port 10.0.1.27:8000 Aug 10 15:59:30 VERBOSE[26558] logger.c: Found description format GSM Aug 10 15:59:30 VERBOSE[26558] logger.c: Found description format PCMU Aug 10 15:59:30 VERBOSE[26558] logger.c: Found description format PCMA Aug 10 15:59:30 VERBOSE[26558] logger.c: Found description format telephone-event Aug 10 15:59:30 VERBOSE[26558] logger.c: Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0xe (gsm|ulaw|alaw)/video=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) Aug 10 15:59:30 VERBOSE[26558] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Aug 10 15:59:30 DEBUG[26558] chan_sip.c: build_route: Retaining previous route: Aug 10 15:59:30 VERBOSE[26558] logger.c: set_destination: Parsing for address/port to send to Aug 10 15:59:30 VERBOSE[26558] logger.c: set_destination: set destination to 216.254.64.3, port 5070 Aug 10 15:59:30 VERBOSE[26558] logger.c: Transmitting (NAT) to 216.254.64.3:5070: ACK sip:6666@216.254.64.3:5070 SIP/2.0 Via: SIP/2.0/UDP 66.54.199.45:5060;branch=z9hG4bK6096fe73;rport From: ;tag=as51133505 To: "6666" ;tag=808 Contact: Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 CSeq: 104 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Aug 10 15:59:32 VERBOSE[26558] logger.c: <-- SIP read from 216.254.64.3:4501: BYE sip:6666@66.54.199.45 SIP/2.0 Via: SIP/2.0/UDP 10.0.1.27:4501;branch=z9hG4bK-d87543-0460e77c1021634d-1--d87543-;rport Max-Forwards: 70 Contact: To: "6666";tag=as75456b0a From: ;tag=9c787400 Call-ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 CSeq: 2 BYE User-Agent: X-Lite release 1002tx stamp 29712 Reason: SIP;description="User Hung Up" Content-Length: 0 Aug 10 15:59:32 DEBUG[26558] chan_sip.c: Header 0: BYE sip:6666@66.54.199.45 SIP/2.0 (33) Aug 10 15:59:32 DEBUG[26558] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.0.1.27:4501;branch=z9hG4bK-d87543-0460e77c1021634d-1--d87543-;rport (87) Aug 10 15:59:32 DEBUG[26558] chan_sip.c: Header 2: Max-Forwards: 70 (16) Aug 10 15:59:32 DEBUG[26558] chan_sip.c: Header 3: Contact: (71) Aug 10 15:59:32 DEBUG[26558] chan_sip.c: Header 4: To: "6666";tag=as75456b0a (48) Aug 10 15:59:32 DEBUG[26558] chan_sip.c: Header 5: From: ;tag=9c787400 (81) Aug 10 15:59:32 DEBUG[26558] chan_sip.c: Header 6: Call-ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 (54) Aug 10 15:59:32 DEBUG[26558] chan_sip.c: Header 7: CSeq: 2 BYE (11) Aug 10 15:59:32 DEBUG[26558] chan_sip.c: Header 8: User-Agent: X-Lite release 1002tx stamp 29712 (45) Aug 10 15:59:32 DEBUG[26558] chan_sip.c: Header 9: Reason: SIP;description="User Hung Up" (38) Aug 10 15:59:32 DEBUG[26558] chan_sip.c: Header 10: Content-Length: 0 (17) Aug 10 15:59:32 DEBUG[26558] chan_sip.c: Header 11: (0) Aug 10 15:59:32 VERBOSE[26558] logger.c: --- (11 headers 0 lines)Aug 10 15:59:32 VERBOSE[26558] logger.c: --- (11 headers 0 lines)--- Aug 10 15:59:32 DEBUG[26558] chan_sip.c: = Found Their Call ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 Their Tag 9c787400 Our tag: as75456b0a Aug 10 15:59:32 DEBUG[26558] chan_sip.c: **** Received BYE (8) - Command in SIP BYE Aug 10 15:59:32 VERBOSE[26558] logger.c: Sending to 10.0.1.27 : 4501 (NAT) Aug 10 15:59:32 VERBOSE[26558] logger.c: Transmitting (NAT) to 216.254.64.3:4501: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.0.1.27:4501;branch=z9hG4bK-d87543-0460e77c1021634d-1--d87543-;received=216.254.64.3;rport=4501 From: ;tag=9c787400 To: "6666";tag=as75456b0a Call-ID: 417d992248a6cef32f4b450e407c41d5@66.54.199.45 CSeq: 2 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 X-Asterisk-HangupCause: Normal Clearing --- Aug 10 15:59:32 DEBUG[26564] rtp.c: Oooh, got a hangup Aug 10 15:59:32 DEBUG[26564] channel.c: Returning from native bridge, channels: SIP/6666-9611, SIP/17184095245-acda Aug 10 15:59:32 DEBUG[26564] channel.c: Hanging up channel 'SIP/17184095245-acda' Aug 10 15:59:32 DEBUG[26564] chan_sip.c: Hangup call SIP/17184095245-acda, SIP callid 417d992248a6cef32f4b450e407c41d5@66.54.199.45) Aug 10 15:59:32 DEBUG[26564] chan_sip.c: update_call_counter(17184095245) - decrement call limit counter Aug 10 15:59:32 DEBUG[26564] chan_sip.c: Updating call counter for outgoing call Aug 10 15:59:32 DEBUG[26564] app_dial.c: Exiting with DIALSTATUS=ANSWER. Aug 10 15:59:32 DEBUG[26546] chan_sip.c: Checking device state for peer 17184095245 Aug 10 15:59:32 DEBUG[26546] devicestate.c: Changing state for SIP/17184095245 - state 1 (Not in use) Aug 10 15:59:32 DEBUG[26569] app_queue.c: Device 'SIP/17184095245' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Aug 10 15:59:32 VERBOSE[26564] logger.c: -- AGI Script Executing Application: (ResetCDR) Options: (w) Aug 10 15:59:32 VERBOSE[26564] logger.c: > cdr_odbc: Query Successful! Aug 10 15:59:32 DEBUG[26564] pbx.c: Function result is '"6666" <6666>' Aug 10 15:59:32 DEBUG[26564] pbx.c: Function result is '6666' Aug 10 15:59:32 DEBUG[26564] pbx.c: Function result is '9999' Aug 10 15:59:32 DEBUG[26564] pbx.c: Function result is 'testusers' Aug 10 15:59:32 DEBUG[26564] pbx.c: Function result is 'SIP/6666-9611' Aug 10 15:59:32 DEBUG[26564] pbx.c: Function result is 'SIP/17184095245-acda' Aug 10 15:59:32 DEBUG[26564] pbx.c: Function result is 'ResetCDR' Aug 10 15:59:32 DEBUG[26564] pbx.c: Function result is 'w' Aug 10 15:59:32 DEBUG[26564] pbx.c: Function result is '2006-08-10 15:59:28' Aug 10 15:59:32 DEBUG[26564] pbx.c: Function result is '2006-08-10 15:59:29' Aug 10 15:59:32 DEBUG[26564] pbx.c: Function result is '2006-08-10 15:59:32' Aug 10 15:59:32 DEBUG[26564] pbx.c: Function result is '4' Aug 10 15:59:32 DEBUG[26564] pbx.c: Function result is '3' Aug 10 15:59:32 DEBUG[26564] pbx.c: Function result is 'ANSWERED' Aug 10 15:59:32 DEBUG[26564] pbx.c: Function result is 'DOCUMENTATION' Aug 10 15:59:32 DEBUG[26564] pbx.c: Function result is '(null)' Aug 10 15:59:32 DEBUG[26564] pbx.c: Function result is '1155239939.0' Aug 10 15:59:32 DEBUG[26564] pbx.c: Function result is '00DBAE74-2D5E-40E7-9DDB-91F406833570' Aug 10 15:59:32 VERBOSE[26564] logger.c: -- AGI Script Executing Application: (SetCDRUserField) Options: () Aug 10 15:59:32 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:32 DEBUG[26564] rtp.c: Difference is 22824, ms is 2873 Aug 10 15:59:32 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:32 VERBOSE[26564] logger.c: -- Playing 'digits/7' (language 'en') Aug 10 15:59:32 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:32 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:32 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format slin Aug 10 15:59:32 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:32 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:32 VERBOSE[26564] logger.c: -- Playing 'digits/hundred' (language 'en') Aug 10 15:59:33 VERBOSE[26558] logger.c: Destroying call '417d992248a6cef32f4b450e407c41d5@66.54.199.45' Aug 10 15:59:33 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:33 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:33 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format slin Aug 10 15:59:33 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:33 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:33 VERBOSE[26564] logger.c: -- Playing 'digits/70' (language 'en') Aug 10 15:59:34 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:34 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:34 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format slin Aug 10 15:59:34 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:34 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:34 VERBOSE[26564] logger.c: -- Playing 'digits/7' (language 'en') Aug 10 15:59:34 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:34 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:34 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format slin Aug 10 15:59:34 VERBOSE[26564] logger.c: -- AGI Script Executing Application: (Background) Options: (ccs/anothercall) Aug 10 15:59:34 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format gsm Aug 10 15:59:34 DEBUG[26564] channel.c: Scheduling timer at 160 sample intervals Aug 10 15:59:34 VERBOSE[26564] logger.c: -- Playing 'ccs/anothercall' (language 'en') Aug 10 15:59:35 VERBOSE[26558] logger.c: <-- SIP read from 216.254.64.3:5070: BYE sip:9999@66.54.199.45 SIP/2.0 Via: SIP/2.0/UDP 216.254.64.3:5070;rport;branch=z9hG4bK853888 To: ;tag=as51133505 From: "6666" ;tag=808 Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 CSeq: 487 BYE Max-Forwards: 20 User-Agent: Express Talk 2.02 Content-Length: 0 Aug 10 15:59:35 DEBUG[26558] chan_sip.c: Header 0: BYE sip:9999@66.54.199.45 SIP/2.0 (33) Aug 10 15:59:35 DEBUG[26558] chan_sip.c: Header 1: Via: SIP/2.0/UDP 216.254.64.3:5070;rport;branch=z9hG4bK853888 (61) Aug 10 15:59:35 DEBUG[26558] chan_sip.c: Header 2: To: ;tag=as51133505 (42) Aug 10 15:59:35 DEBUG[26558] chan_sip.c: Header 3: From: "6666" ;tag=808 (44) Aug 10 15:59:35 DEBUG[26558] chan_sip.c: Header 4: Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 (51) Aug 10 15:59:35 DEBUG[26558] chan_sip.c: Header 5: CSeq: 487 BYE (13) Aug 10 15:59:35 DEBUG[26558] chan_sip.c: Header 6: Max-Forwards: 20 (16) Aug 10 15:59:35 DEBUG[26558] chan_sip.c: Header 7: User-Agent: Express Talk 2.02 (29) Aug 10 15:59:35 DEBUG[26558] chan_sip.c: Header 8: Content-Length: 0 (17) Aug 10 15:59:35 DEBUG[26558] chan_sip.c: Header 9: (0) Aug 10 15:59:35 VERBOSE[26558] logger.c: --- (9 headers 0 lines)Aug 10 15:59:35 VERBOSE[26558] logger.c: --- (9 headers 0 lines)--- Aug 10 15:59:35 DEBUG[26558] chan_sip.c: = Found Their Call ID: 1155233663-3888-HP15690206501@216.254.64.3 Their Tag 808 Our tag: as51133505 Aug 10 15:59:35 DEBUG[26558] chan_sip.c: **** Received BYE (8) - Command in SIP BYE Aug 10 15:59:35 VERBOSE[26558] logger.c: Sending to 216.254.64.3 : 5070 (NAT) Aug 10 15:59:35 VERBOSE[26558] logger.c: Transmitting (NAT) to 216.254.64.3:5070: SIP/2.0 200 OK Via: SIP/2.0/UDP 216.254.64.3:5070;branch=z9hG4bK853888;received=216.254.64.3;rport=5070 From: "6666" ;tag=808 To: ;tag=as51133505 Call-ID: 1155233663-3888-HP15690206501@216.254.64.3 CSeq: 487 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 X-Asterisk-HangupCause: Normal Clearing --- Aug 10 15:59:35 DEBUG[26564] channel.c: Scheduling timer at 0 sample intervals Aug 10 15:59:35 DEBUG[26564] channel.c: Set channel SIP/6666-9611 to write format slin Aug 10 15:59:35 DEBUG[26564] res_agi.c: SIP/6666-9611 hungup Aug 10 15:59:35 DEBUG[26564] pbx.c: Spawn extension (testusers,9999,1) exited non-zero on 'SIP/6666-9611' Aug 10 15:59:35 VERBOSE[26564] logger.c: > cdr_odbc: Query Successful! Aug 10 15:59:35 DEBUG[26564] pbx.c: Function result is '"6666" <6666>' Aug 10 15:59:35 DEBUG[26564] pbx.c: Function result is '6666' Aug 10 15:59:35 DEBUG[26564] pbx.c: Function result is '9999' Aug 10 15:59:35 DEBUG[26564] pbx.c: Function result is 'testusers' Aug 10 15:59:35 DEBUG[26564] pbx.c: Function result is 'SIP/6666-9611' Aug 10 15:59:35 DEBUG[26564] pbx.c: Function result is 'SIP/17184095245-acda' Aug 10 15:59:35 DEBUG[26564] pbx.c: Function result is 'BackGround' Aug 10 15:59:35 DEBUG[26564] pbx.c: Function result is 'ccs/anothercall' Aug 10 15:59:35 DEBUG[26564] pbx.c: Function result is '2006-08-10 15:59:32' Aug 10 15:59:35 DEBUG[26564] pbx.c: Function result is '(null)' Aug 10 15:59:35 DEBUG[26564] pbx.c: Function result is '2006-08-10 15:59:35' Aug 10 15:59:35 DEBUG[26564] pbx.c: Function result is '3' Aug 10 15:59:35 DEBUG[26564] pbx.c: Function result is '0' Aug 10 15:59:35 DEBUG[26564] pbx.c: Function result is 'NO ANSWER' Aug 10 15:59:35 DEBUG[26564] pbx.c: Function result is 'DOCUMENTATION' Aug 10 15:59:35 DEBUG[26564] pbx.c: Function result is '(null)' Aug 10 15:59:35 DEBUG[26564] pbx.c: Function result is '1155239939.0' Aug 10 15:59:35 DEBUG[26564] pbx.c: Function result is '(null)' Aug 10 15:59:35 DEBUG[26564] channel.c: Hanging up channel 'SIP/6666-9611' Aug 10 15:59:35 DEBUG[26564] chan_sip.c: Hangup call SIP/6666-9611, SIP callid 1155233663-3888-HP15690206501@216.254.64.3) Aug 10 15:59:35 DEBUG[26564] chan_sip.c: update_call_counter(6666) - decrement call limit counter Aug 10 15:59:35 DEBUG[26564] chan_sip.c: Updating call counter for outgoing call Aug 10 15:59:35 DEBUG[26546] chan_sip.c: Checking device state for peer 6666 Aug 10 15:59:35 DEBUG[26546] devicestate.c: Changing state for SIP/6666 - state 1 (Not in use) Aug 10 15:59:35 DEBUG[26570] app_queue.c: Device 'SIP/6666' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Aug 10 15:59:36 VERBOSE[26558] logger.c: Destroying call '1155233663-3888-HP15690206501@216.254.64.3' Aug 10 15:59:37 VERBOSE[26563] logger.c: Executing last minute cleanups Aug 10 15:59:37 VERBOSE[26563] logger.c: == Destroying musiconhold processes Aug 10 15:59:37 DEBUG[26563] res_musiconhold.c: killing 26548! Aug 10 15:59:37 DEBUG[26563] res_musiconhold.c: mpg123 pid 26548 and child died after 104 bytes read Aug 10 15:59:37 DEBUG[26563] asterisk.c: Asterisk ending (0).